Build reports success when an AfterTargets errors

[cdmihai]

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

[cdmihai]

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]

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]

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".