Catastrophic errors should create a failed work item in AzDO with the logs attached

[ViktorHofer]

If a catastrophic error occures (MC term) i.e. when the docker image can't be fetched, the leg will fail but the test explorer doesn't show a failed item for it. To understand why the leg turned red you need to go into MC where you fetch the infra log.

We should add a work item failure entry in AzDO test explorer if something like this happens and attach the execution log.

Example: https://dev.azure.com/dnceng/public/_build/results?buildId=175448&view=logs

cc @alexperovich @safern

[safern]

The problem here is that the azure pipelines reporter is part of the workitem execution as a HelixPostCommand:

https://github.com/dotnet/arcade/blob/master/src/Microsoft.DotNet.Helix/Sdk/tools/azure-pipelines/AzurePipelines.MonoQueue.targets#L7

IMHO there should be something like a WorkItemPostCommands that run after the workitem, no matter what, but this shouldn't be a step in the workitem's script. There should be another script that is executed by helix after the workitem is done. That way we would be able to get this failures into azure pipelines.

[markwilkie]

I think I remember hearing that this is on the backlog. @Chrisboh ?

[ViktorHofer]

This is currently happening a lot in corefx because of docker image fetch errors (@MattGal knows about it). As we just migrated to the AzDO Test Explorer features devs will probably be confused. I hope we can make this ask happen soon.

[Chrisboh]

@alexperovich I believe is working on this. Alex can you provide an update?

[alexperovich]

This PR #2658 contains a fix that will include logs as an attachment in the test result created if a work item doesn't output results and returns a non-zero exit code. It doesn't fix the case where work items timeout. That requires feature work in the helix client code.

[ViktorHofer]

https://dev.azure.com/dnceng/public/_build/results?buildId=177761&view=logs (switch to attempt 1) is a perfect example why we need this. The test execution started but failed because of a long running test (exit code -3). The test results weren't created and also no work item was created in the AzDO Test Explorer that would indicate that something crashed. The only indication at the moment is the failing leg.

cc @ericstj: that's the reason why this wasn' reported.

[ViktorHofer]

Another example: https://mc.dot.net/#/user/dotnet-bot/pr~2Fdotnet~2Fcorefx~2Frefs~2Fpull~2F37414~2Fmerge/test~2Ffunctional~2Fcli~2F/20190503.23/workItem/Microsoft.Win32.SystemEvents.Tests/wilogs

C:\dotnetbuild\work\688d3729-d9a3-4600-99ca-8a7ecb1f3dae\Work\b7fe115e-6de6-4093-a46d-53c70eecebca\Exec>"C:\dotnetbuild\work\688d3729-d9a3-4600-99ca-8a7ecb1f3dae\Payload\dotnet.exe" xunit.console.dll Microsoft.Win32.SystemEvents.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=nonnetcoreapptests -notrait category=nonwindowstests -notrait category=IgnoreForCI -notrait category=failing -notrait category=OuterLoop  
  Discovering: Microsoft.Win32.SystemEvents.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  Microsoft.Win32.SystemEvents.Tests (found 26 of 27 test cases)
  Starting:    Microsoft.Win32.SystemEvents.Tests (parallel test collections = on, max threads = 2)
   Microsoft.Win32.SystemEvents.Tests: [Long Running Test] 'Microsoft.Win32.SystemEventsTests.CreateTimerTests.ConcurrentTimers', Elapsed: 00:02:11
   Microsoft.Win32.SystemEvents.Tests: [Long Running Test] 'Microsoft.Win32.SystemEventsTests.CreateTimerTests.ConcurrentTimers', Elapsed: 00:04:11
   Microsoft.Win32.SystemEvents.Tests: [Long Running Test] 'Microsoft.Win32.SystemEventsTests.CreateTimerTests.ConcurrentTimers', Elapsed: 00:06:11
   Microsoft.Win32.SystemEvents.Tests: [Long Running Test] 'Microsoft.Win32.SystemEventsTests.CreateTimerTests.ConcurrentTimers', Elapsed: 00:08:11
   Microsoft.Win32.SystemEvents.Tests: [Long Running Test] 'Microsoft.Win32.SystemEventsTests.CreateTimerTests.ConcurrentTimers', Elapsed: 00:10:11
   Microsoft.Win32.SystemEvents.Tests: [Long Running Test] 'Microsoft.Win32.SystemEventsTests.CreateTimerTests.ConcurrentTimers', Elapsed: 00:12:12
   Microsoft.Win32.SystemEvents.Tests: [Long Running Test] 'Microsoft.Win32.SystemEventsTests.CreateTimerTests.ConcurrentTimers', Elapsed: 00:14:12

Exit code: -3. No work item created.

[ViktorHofer]

We are frequently hitting cases where a work item fails but doesn't produce any logs. It's impossible to diagnose what happens in such a case but I assume setting up the machine fails, i.e. docker. This just happened on OSX: https://mc.dot.net/#/user/dotnet-bot/pr~2Fdotnet~2Fcorefx~2Frefs~2Fpull~2F37367~2Fmerge/test~2Ffunctional~2Fcli~2F/20190507.18

It doesn't fix the case where work items timeout. That requires feature work in the helix client code.

It would be great if we could fix the reporting back to AzDO and the cases where no logs are created and are not retrievable from inside AzDO.

cc @markwilkie @stephentoub

[alexperovich]

That error is a problem where the work item didn't even start. It failed to download/unzip the payloads. It looks like a problem with a specific machine. @MattGal is going to disable it.

This specific case we could never have reported anything to AzDO because the work item never ran.

[safern]

In my honest opinion as I stated earlier is that the azure pipelines reporter should run independently of if the work item ran or not. We should get logs always, we should even care more of doing that if we want to get rid of Mission control. I don’t like the fact that half the results and logs are to be seen on MC and the other half on Azure Test Explorer.

[markwilkie]

@alexperovich - thoughts on next steps?

[alexperovich]

The solution to this problem is to modify the helix client to have support for one or more commands that will be run after the regular work item command. This would allow us to have the azure pipelines reporter run even when the work item command hits a timeout. This work is also needed for dump collection. I don't know if we have come to any decision on when this work needs to be done and/or what epic it should be under.

[ChadNedzlek]

This was done long ago.