Random hang/timeout in System.Reflection.Metadata.Tests in CI

[stephentoub]

https://mc.dot.net/#/user/stephentoub/pr~2Fjenkins~2Fdotnet~2Fcorefx~2Fmaster~2F/test~2Ffunctional~2Fcli~2F/39ad031acb4bda1d91f5654e70e31fef299e50bd/workItem/System.Reflection.Metadata.Tests/wilogs

2018-02-22 10:12:36,642: INFO: proc(54): run_and_log_output: Output: Discovering: System.Reflection.Metadata.Tests
2018-02-22 10:12:36,884: INFO: proc(54): run_and_log_output: Output: Discovered:  System.Reflection.Metadata.Tests
2018-02-22 10:12:37,059: INFO: proc(54): run_and_log_output: Output: Starting:    System.Reflection.Metadata.Tests

...

2018-02-22 10:32:35,798: ERROR: job(44): kill: Job running for too long. Killing...
2018-02-22 10:32:35,803: ERROR: executor(398): _execute_command: Executor timed out after 1200 seconds and was killed.
2018-02-22 10:32:35,803: INFO: event(43): send: Sending event type WorkItemTimeout
2018-02-22 10:32:35,876: INFO: saferequests(90): request_with_retry: Response complete with status code '201'
2018-02-22 10:32:35,877: INFO: executor(417): _execute_command: Finished _execute_command, exit code: -3

[tmat]

I don't know where to find any useful information from the MC.

I can see this - which suggest (I guess) that there is a widespread failure that's affecting more than SRM tests:

[danmoseley]

@tmat if you click on the test library name and then expand the "failed" section you see the logs. Although in this case it just shows that it timed out. Until dumpling is back and giving us dumps for timeouts, your only resort is to use the "repro tool" to get a VM. Let me know if you want me to share info on that.

However in this case I would be inclined to not investigate unless it happened again, since there may be bigger problems.

[stephentoub]

Happened again here, but this time on Ubuntu:
https://mc.dot.net/#/user/dotnet-maestro-bot/pr~2Fjenkins~2Fdotnet~2Fcorefx~2Fmaster~2F/test~2Ffunctional~2Fcli~2F/f31d24f0f1ff748ee84a9f67a7b4e4e2c80dc544/workItem/System.Reflection.Metadata.Tests/wilogs

2018-03-07 14:38:45,013: INFO: proc(54): run_and_log_output: Output: xUnit.net console test runner (64-bit .NET Core)
2018-03-07 14:38:45,013: INFO: proc(54): run_and_log_output: Output: Copyright (C) 2014 Outercurve Foundation.
2018-03-07 14:38:45,014: INFO: proc(54): run_and_log_output: Output: 
2018-03-07 14:38:45,089: INFO: proc(54): run_and_log_output: Output: Discovering: System.Reflection.Metadata.Tests
2018-03-07 14:38:45,408: INFO: proc(54): run_and_log_output: Output: Discovered:  System.Reflection.Metadata.Tests
2018-03-07 14:38:45,600: INFO: proc(54): run_and_log_output: Output: Starting:    System.Reflection.Metadata.Tests
Killed

and

2018-03-07 14:58:19,123: INFO: servicebusrepository(97): renew_workitem_lock: renew_workitem_lock Status Code: 200
2018-03-07 14:58:44,686: ERROR: job(44): kill: Job running for too long. Killing...
2018-03-07 14:58:44,716: ERROR: job(47): kill: Ignored error process no longer exists (pid=13290)
2018-03-07 14:58:44,717: ERROR: executor(398): _execute_command: Executor timed out after 1200 seconds and was killed.

[stephentoub]

Also on Windows here:
https://mc.dot.net/#/user/stephentoub/pr~2Fjenkins~2Fdotnet~2Fcorefx~2Fmaster~2F/test~2Ffunctional~2Fcli~2F/14247d6382d934cc160f053a8f6951b432675863/workItem/System.Reflection.Metadata.Tests/wilogs

[stephentoub]

Again here on Fedora:
https://mc.dot.net/#/user/dotnet-maestro-bot/pr~2Fjenkins~2Fdotnet~2Fcorefx~2Fmaster~2F/test~2Ffunctional~2Fcli~2F/e66bf8e62fb9057bc3446fcaded0598004b9e2de/workItem/System.Reflection.Metadata.Tests/wilogs

[stephentoub]

Again here on Debian:
https://mc.dot.net/#/user/dotnet-maestro-bot/pr~2Fjenkins~2Fdotnet~2Fcorefx~2Fmaster~2F/test~2Ffunctional~2Fcli~2F/4c14dbf0ac87f4b945c48d8191cda21a86de7778/workItem/System.Reflection.Metadata.Tests/wilogs

[stephentoub]

Again on Windows 8:
https://mc.dot.net/#/user/stephentoub/pr~2Fjenkins~2Fdotnet~2Fcorefx~2Fmaster~2F/test~2Ffunctional~2Fcli~2F/ef54f662eaaef296234b757dd0472f3c5668530d/workItem/System.Reflection.Metadata.Tests/wilogs

[stephentoub]

Again on macOS:
https://mc.dot.net/#/user/jkotas/pr~2Fjenkins~2Fdotnet~2Fcorefx~2Fmaster~2F/test~2Ffunctional~2Fcli~2F/a327a1bfaf988ecb8a45dc6b61462ada4f1af52d/workItem/System.Reflection.Metadata.Tests/wilogs