Test failure tracing/eventpipe/reverse/reverse/reverse.sh

[VincentBu]

Run: runtime 20210902.89

Failed test:

Mono Linux arm64 Release no_tiered_compilation @ (Ubuntu.1804.Arm64.Open)[email protected]/dotnet-buildtools/prereqs:ubuntu-18.04-helix-arm64v8-20210531091519-97d8652

- tracing/eventpipe/reverse/reverse/reverse.sh

Error message:

cmdLine:/root/helix/work/workitem/tracing/eventpipe/reverse/reverse/reverse.sh Timed Out (timeout in milliseconds: 600000 from variable __TestTimeout, start: 9/2/2021 11:07:14 PM, end: 9/2/2021 11:17:14 PM)

Return code:      -100
Raw output file:      /root/helix/work/workitem/uploads/Reports/tracing.eventpipe/reverse/reverse/reverse.output.txt
Raw output:
BEGIN EXECUTION
/root/helix/work/correlation/corerun -p System.Reflection.Metadata.MetadataUpdater.IsSupported=false reverse.dll ''
0.0s: ::== Running test: TEST_RuntimeIsResilientToServerClosing
0.0s: Server name is '/tmp/DOTNET_TRACE_TESTS_hlxlgzgp.o4v'
0.1s: running sub-process: /root/helix/work/correlation/corerun /root/helix/work/workitem/tracing/eventpipe/reverse/reverse/reverse.dll 0
0.2s: subprocess started: True
0.2s: subprocess PID: 1412
0.3s: Waiting for connection
0.3s: Got a connection
0.3s: Shutting down Reverse Server at /tmp/DOTNET_TRACE_TESTS_hlxlgzgp.o4v
0.4s: { Magic=System.Byte[]; ClrInstanceId=9ba97073-71f7-40cc-8dbc-f88486c0818a; ProcessId=1412; Unused=0; }
0.4s: Waiting for connection
0.4s: Got a connection
0.4s: Shutting down Reverse Server at /tmp/DOTNET_TRACE_TESTS_hlxlgzgp.o4v
0.4s: { Magic=System.Byte[]; ClrInstanceId=9ba97073-71f7-40cc-8dbc-f88486c0818a; ProcessId=1412; Unused=0; }
0.4s: Waiting for connection
0.4s: Got a connection
0.4s: Shutting down Reverse Server at /tmp/DOTNET_TRACE_TESTS_hlxlgzgp.o4v
0.4s: { Magic=System.Byte[]; ClrInstanceId=9ba97073-71f7-40cc-8dbc-f88486c0818a; ProcessId=1412; Unused=0; }
0.4s: Waiting for connection
0.4s: Got a connection
0.4s: Shutting down Reverse Server at /tmp/DOTNET_TRACE_TESTS_hlxlgzgp.o4v
0.4s: { Magic=System.Byte[]; ClrInstanceId=9ba97073-71f7-40cc-8dbc-f88486c0818a; ProcessId=1412; Unused=0; }
0.4s: Sending 'exit' to subprocess stdin
0.6s: ================= Subprocess Exited =================
0.6s: SubProcess exited - Exit code: 0
0.6s: ----------------------------------------
0.6s: Subprocess stdout:
0.5s: Subprocess started!  Waiting for input...
0.5s: Received 'exit'.  Exiting...
0.6s: Subprocess stderr:
0.6s: ----------------------------------------
0.6s: Test passed: True
0.6s:
0.6s: ::== Running test: TEST_RuntimeConnectsToExistingServer
0.6s: Waiting for connection
0.6s: Server name is /tmp/DOTNET_TRACE_TESTS_bl0j55dv.xnv
0.6s: running sub-process: /root/helix/work/correlation/corerun /root/helix/work/workitem/tracing/eventpipe/reverse/reverse/reverse.dll 0
0.6s: subprocess started: True
0.6s: subprocess PID: 1449
0.6s: Standard Diagnostics Server connection not created yet -> try again in 100 ms
0.7s: Got a connection
0.7s: Shutting down Reverse Server at /tmp/DOTNET_TRACE_TESTS_bl0j55dv.xnv
0.7s: { Magic=System.Byte[]; ClrInstanceId=dd0987f9-f02d-4f5e-bbb8-ea27eb4d4251; ProcessId=1449; Unused=0; }
0.7s: Sending 'exit' to subprocess stdin
0.9s: ================= Subprocess Exited =================
0.9s: SubProcess exited - Exit code: 0
0.9s: ----------------------------------------
0.9s: Subprocess stdout:
0.3s: Subprocess started!  Waiting for input...
0.3s: Received 'exit'.  Exiting...
0.9s: Subprocess stderr:
0.9s: ----------------------------------------
0.9s: Test passed: True
0.9s:
0.9s: ::== Running test: TEST_CanConnectServerAndClientAtSameTime
0.9s: Server name is '/tmp/DOTNET_TRACE_TESTS_1mg2it2x.5es'
0.9s: running sub-process: /root/helix/work/correlation/corerun /root/helix/work/workitem/tracing/eventpipe/reverse/reverse/reverse.dll 0
0.9s: subprocess started: True
0.9s: subprocess PID: 1462
0.9s: Standard Diagnostics Server connection not created yet -> try again in 100 ms
1.0s: Waiting for reverse connection
1.0s: Got reverse connection
1.0s: { Magic=System.Byte[]; ClrInstanceId=1bb76951-be5f-48eb-afdf-df88df54d7a0; ProcessId=1462; Unused=0; }
1.0s: Starting EventPipeSession over standard connection
1.1s: Started EventPipeSession over sta


Stack trace
   at tracing_eventpipe._reverse_reverse_reverse_._reverse_reverse_reverse_sh()

[lateralusX]

Probably same root cause as #58781.

[lateralusX]

Should be fixed by #58996.