Build reports success when an AfterTargets errors #3345

cdmihai · 2018-05-25T00:23:39Z

Steps to reproduce

1.proj

<Project DefaultTargets="Build">
    <Target Name="Build">
        <MSBuild Projects="2.proj" Targets="Build"/>
    </Target>
</Project>

2.proj

<Project DefaultTargets="Build">
    <Target Name="Build" />

    <Target Name="IndirectBuild" AfterTargets="Build">
        <Error Text="Induce failure" />
    </Target>
</Project>

build with

set MSBUILDNOINPROCNODE=1

msbuild.exe 1.proj /clp:ShowCommandLine /m:1 /verbosity:n /nr:false /bl /fl /flp:v=diagnostic

Expected behavior

Build fails because of the <Error> task

Actual behavior

Build succeeds:

Build started 5/24/2018 5:35:56 PM.
Project "e:\delete\repro\1.proj" on node 2 (default targets).
Project "e:\delete\repro\1.proj" (1) is building "e:\delete\repro\2.proj" (2) on node 2 (Build target(s)).
e:\delete\repro\2.proj(5,9): error : Induce failure
Done Building Project "e:\delete\repro\2.proj" (Build target(s)) -- FAILED.

Done Building Project "e:\delete\repro\1.proj" (default targets).

Deferred Messages

  Detailed Build Summary
  ======================


  ============================== Build Hierarchy (IDs represent configurations) =====================================================
  Id                  : Exclusive Time   Total Time   Path (Targets)
  -----------------------------------------------------------------------------------------------------------------------------------
  0                   : 0.101s           0.120s       e:\delete\repro\1.proj ()
  . 1                 : 0.018s           0.018s       e:\delete\repro\2.proj (Build)

  ============================== Node Utilization (IDs represent configurations) ====================================================
  Timestamp:            2        Duration   Cumulative
  -----------------------------------------------------------------------------------------------------------------------------------
  636628053566714538:   0        0.096s     0.096s #
  636628053567674882:   1        0.018s     0.114s
  636628053567855025:   0        0.007s     0.121s
  -----------------------------------------------------------------------------------------------------------------------------------
  Utilization:          100.0    Average Utilization: 100.0

Build succeeded.

"e:\delete\repro\1.proj" (default target) (1) ->
"e:\delete\repro\2.proj" (Build target) (2) ->
(IndirectBuild target) ->
  e:\delete\repro\2.proj(5,9): error : Induce failure

    0 Warning(s)
    1 Error(s)

Time Elapsed 00:00:00.22

The text was updated successfully, but these errors were encountered:

cdmihai · 2018-05-25T00:46:25Z

Changing 2.proj to the following makes it work.

<Project DefaultTargets="Build">
    <Target Name="Build" DependsOnTargets="IndirectBuild"/>

    <Target Name="IndirectBuild">
        <Error Text="Induce failure" />
    </Target>
</Project>

Project "e:\delete\repro\1.proj" on node 2 (default targets).
Project "e:\delete\repro\1.proj" (1) is building "e:\delete\repro\2.proj" (2) on node 2 (Build target(s)).
e:\delete\repro\2.proj(5,9): error : Induce failure
Done Building Project "e:\delete\repro\2.proj" (Build target(s)) -- FAILED.

Done Building Project "e:\delete\repro\1.proj" (default targets) -- FAILED.

Deferred Messages

  Detailed Build Summary
  ======================


  ============================== Build Hierarchy (IDs represent configurations) =====================================================
  Id                  : Exclusive Time   Total Time   Path (Targets)
  -----------------------------------------------------------------------------------------------------------------------------------
  0                   : 0.099s           0.118s       e:\delete\repro\1.proj ()
  . 1                 : 0.018s           0.018s       e:\delete\repro\2.proj (Build)

  ============================== Node Utilization (IDs represent configurations) ====================================================
  Timestamp:            2        Duration   Cumulative
  -----------------------------------------------------------------------------------------------------------------------------------
  636628059279846253:   0        0.094s     0.094s #
  636628059280786685:   1        0.018s     0.112s
  636628059280966525:   0        0.007s     0.119s
  -----------------------------------------------------------------------------------------------------------------------------------
  Utilization:          100.0    Average Utilization: 100.0

Build FAILED.

"e:\delete\repro\1.proj" (default target) (1) ->
"e:\delete\repro\2.proj" (Build target) (2) ->
(IndirectBuild target) ->
  e:\delete\repro\2.proj(5,9): error : Induce failure

    0 Warning(s)
    1 Error(s)

Time Elapsed 00:00:00.23

rainersigwald · 2018-05-25T15:54:08Z

I think the reason that this is happening is that from a certain point of view the MSBuild request is succeeding. It's legal to "partially" build another project by specifying an entry-point target, and the result of that request should be success if all of the targets that must run before that target and that target itself succeed.

Consider a small project:

Deploy DependsOn
Build DependsOn
Initialize

If you call the target Build, Deploy won't run, so its success or failure is irrelevant to the result of Build.

In this situation,

Deploy2 AfterTargets
Build2 DependsOn
Initialize2

There's no way to run Build2 without also running Deploy2. But if the entry-point is Build2, what should the result be if Initialize2 and Build2 pass but Deploy2 fails? It's arguable that the request succeeded because Build2 succeeded. But I agree with single-proc MSBuild that that's not the intuitive, reasonable answer.

Note that this has been this way since MSBuild 4.5:

S:\repro\Microsoft\msbuild\issues\3345>C:\Windows\Microsoft.NET\Framework\v4.0.30319\MSBuild.exe 1.proj
Microsoft (R) Build Engine version 4.7.3056.0
[Microsoft .NET Framework, version 4.0.30319.42000]
Copyright (C) Microsoft Corporation. All rights reserved.

Build started 5/25/2018 10:53:54 AM.
Project "S:\repro\Microsoft\msbuild\issues\3345\1.proj" on node 2 (default targets).
Project "S:\repro\Microsoft\msbuild\issues\3345\1.proj" (1) is building "S:\repro\Microsoft\msbuild\issues\3345\2.proj" (2) on node 2 (Build target(s)).
S:\repro\Microsoft\msbuild\issues\3345\2.proj(5,9): error : Induce failure
Done Building Project "S:\repro\Microsoft\msbuild\issues\3345\2.proj" (Build target(s)) -- FAILED.

Done Building Project "S:\repro\Microsoft\msbuild\issues\3345\1.proj" (default targets).


Build succeeded.

"S:\repro\Microsoft\msbuild\issues\3345\1.proj" (default target) (1) ->
"S:\repro\Microsoft\msbuild\issues\3345\2.proj" (Build target) (2) ->
(IndirectBuild target) ->
  S:\repro\Microsoft\msbuild\issues\3345\2.proj(5,9): error : Induce failure

    0 Warning(s)
    1 Error(s)

Time Elapsed 00:00:00.38

rainersigwald · 2018-05-25T16:25:49Z

In an internal forum, I got the question

Does the bug also affect targets named “AfterBuild”?

It does not, assuming the standard pattern of targets, which is:

https://github.com/Microsoft/msbuild/blob/e7ea68da3ee0929a07cc36e877a32d5e444efefb/src/Tasks/Microsoft.Common.CurrentVersion.targets#L832-L842

That creates a target build order dependency that requires that AfterBuild (and anything that says AfterTargets="AfterBuild") complete successfully before the Build target can attempt to run.

When the standard DefaultTargets="Build" applies, this bug arises only for targets with AfterTargets="Build".

`helix.proj` is built with the target `Test`, but does important work in `Wait`. Since that target was hooked to `Test` by an `AfterTargets`, it hit a bug in MSBuild that failed `AfterTargets` targets don't fail a build that builds the target they hook. Restructure the targets (transparently to callers) to avoid that situation and observe failures in `Wait`.

…1683) `helix.proj` is built with the target `Test`, but does important work in `Wait`. Since that target was hooked to `Test` by an `AfterTargets`, it hit a bug in MSBuild that failed `AfterTargets` targets don't fail a build that builds the target they hook. Restructure the targets (transparently to callers) to avoid that situation and observe failures in `Wait`.

Two issues: 1) Replace AfterTargets="Build" with BeforeTargets="AfterBuild" Workaround for dotnet/msbuild#3345 2) System.ValueTuple Seems like the System.ValueTuple package is missing lib/net472/_._, so lib/net47/System.ValueTuple.dll is identified as a runtime dependency although it is not.

japj · 2019-09-16T13:47:23Z

We hit this (not failing, but an error occurred in AfterTargets) behavior too today.

msbuild binlog analysis did not show initial error, but then if you look with $error search you can find it and it is not obvious why the build was actually not failing (ContinueOnError="false", etc was all set correctly).

Glad I found this bug to explain what was happening, not sure if this sufficiently clear for everyone though.

mmitche · 2019-11-14T18:16:45Z

Is there a plan to fix this? It's let a couple bugs through our CI system recently.

mmitche · 2019-11-14T18:46:36Z

Changing 2.proj to the following makes it work.

<Project DefaultTargets="Build">
    <Target Name="Build" DependsOnTargets="IndirectBuild"/>

    <Target Name="IndirectBuild">
        <Error Text="Induce failure" />
    </Target>
</Project>

@rainersigwald

Maybe I'm misunderstanding this, but wouldn't this change the target order? In the original, you're running:

Build then IndirectBuild

In the fixed version, you run IndirectBuild before Build.

rainersigwald · 2019-11-14T19:55:20Z

@mmitche that's true, but usually not interesting; the Build target is generally empty and exists only to aggregate/order other targets.

`BuildResult` had code in one of its constructors specifically to handle AfterTargets failures, making sure that they are propagated to the referenced target. This didn't work in multi-proc builds for multiple reasons: 1) The process orchestrating the build may have had no visibility into targets other than those requested to be executed by the worker process. This means that the `existingResults` argument typically didn't contain results for the targets with AfterTargets specified, meaning it had no way of knowing that they had failed. 2) The process orchestrating the build may not have loaded the project file handled by the worker process. This means that the `additionalTargetsToCheck` argument could have been `null`, again making it impossible for `BuildResult` to detect the dependency. This change moves the logic of calculating target failures to the worker process, namely to `TargetBuilder`. A new flag `AfterTargetsHaveFailed` is introduced and calculated for each requested target after all targets have executed. This flag is then passed back as part of `TargetResult` and trivially used in `BuildResult`'s `OverallResult`. Note that targets with failed AfterTargets can still succeed in terms of their `ResultCode`, i.e. the failure is kept only in form of this bolt-on bit. The now unused `GetAfterTargetsForDefaultTargets` is deleted. Fixes dotnet#3345

`BuildResult` had code in one of its constructors specifically to handle AfterTargets failures, making sure that they are propagated to the referenced target. This didn't work in multi-proc builds for multiple reasons: 1) The process orchestrating the build may have had no visibility into targets other than those requested to be executed by the worker process. This means that the `existingResults` argument typically didn't contain results for the targets with AfterTargets specified, meaning it had no way of knowing that they had failed. 2) The process orchestrating the build may not have loaded the project file handled by the worker process. This means that the `additionalTargetsToCheck` argument could have been `null`, again making it impossible for `BuildResult` to detect the dependency. This change moves the logic of calculating target failures to the worker process, namely to `TargetBuilder`. A new flag `AfterTargetsHaveFailed` is introduced and calculated for each requested target after all targets have executed. This flag is then passed back as part of `TargetResult` and trivially used in `BuildResult`'s `OverallResult`. Note that targets with failed AfterTargets can still succeed in terms of their `ResultCode`, i.e. the failure is kept only in form of this bolt-on bit. The now unused `GetAfterTargetsForDefaultTargets` is deleted. Fixes #3345

cdmihai added the bug label May 25, 2018

cdmihai assigned cdmihai and unassigned cdmihai May 25, 2018

rainersigwald changed the title ~~Build reports success when errors are present~~ Build reports success when an AfterTargets errors May 25, 2018

This was referenced Jul 18, 2018

Generate shim in build dotnet/sdk#2413

Merged

Fix ILRepack target on Linux dotnet/android#1979

Merged

rainersigwald mentioned this issue Aug 16, 2018

BuildInParallel=true MSBuild task doesn't halt when inner project has an error in an AfterTarget #3623

Closed

rainersigwald mentioned this issue Jan 15, 2019

Error in AfterSigning.proj doesn't fail the build dotnet/arcade#1800

Closed

rainersigwald mentioned this issue Mar 1, 2019

Move definitions of BeforeBuild and AfterBuild targets to .props instead of .targets files #1680

Open

rainersigwald mentioned this issue Mar 8, 2019

Fix deployment of ILAsm when building from VS dotnet/roslyn#33502

Merged

ericstj mentioned this issue Mar 15, 2019

DeployToSymStore failure won't always fail the build dotnet/arcade#2267

Open

cdmihai removed their assignment Mar 29, 2019

tmat mentioned this issue May 23, 2019

DevDivInsertionFiles: Fix dependency error reporting dotnet/roslyn#35924

Merged

rainersigwald mentioned this issue Aug 23, 2019

Fix a typo and address remaining service reference TODO items dotnet/aspnetcore#13364

Merged

dagood mentioned this issue Oct 23, 2019

Arcade allows build to pass as green even when target shows error and build output is corrupted dotnet/arcade#4183

Closed

riarenas mentioned this issue Nov 7, 2019

Catch Build Errors in Insertion Manifests dotnet/arcade#4307

Merged

dagood mentioned this issue Nov 20, 2019

fix: Unable to pack Microsoft.VisualBasic.Forms dotnet/winforms#2396

Merged

rainersigwald assigned ladipro Mar 20, 2020

ladipro mentioned this issue Mar 24, 2020

Don't swallow AfterTargets failures in multi-proc builds #5195

Merged

ladipro closed this as completed in #5195 Mar 31, 2020

RussKie mentioned this issue Apr 1, 2020

Break the build if there are any errors in publish tasks gitextensions/gitextensions#7929

Merged

msftgits unassigned ladipro Jul 22, 2020

f1x3d mentioned this issue Mar 27, 2022

Use better approach for pre/post-build MSBuild targets Azure/azure-functions-dotnet-worker#842

Merged

7 tasks

AR-May added the triaged label Feb 21, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Build reports success when an AfterTargets errors #3345

Build reports success when an AfterTargets errors #3345

cdmihai commented May 25, 2018 •

edited

Loading

cdmihai commented May 25, 2018

rainersigwald commented May 25, 2018

rainersigwald commented May 25, 2018

japj commented Sep 16, 2019

mmitche commented Nov 14, 2019

mmitche commented Nov 14, 2019 •

edited

Loading

rainersigwald commented Nov 14, 2019

Build reports success when an AfterTargets errors #3345

Build reports success when an AfterTargets errors #3345

Comments

cdmihai commented May 25, 2018 • edited Loading

Steps to reproduce

Expected behavior

Actual behavior

cdmihai commented May 25, 2018

rainersigwald commented May 25, 2018

rainersigwald commented May 25, 2018

japj commented Sep 16, 2019

mmitche commented Nov 14, 2019

mmitche commented Nov 14, 2019 • edited Loading

rainersigwald commented Nov 14, 2019

cdmihai commented May 25, 2018 •

edited

Loading

mmitche commented Nov 14, 2019 •

edited

Loading