Skip to content

[Long Running Test] pauseonstart.sh #58893

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
ViktorHofer opened this issue Sep 9, 2021 · 4 comments
Closed

[Long Running Test] pauseonstart.sh #58893

ViktorHofer opened this issue Sep 9, 2021 · 4 comments
Labels
area-Tracing-mono untriaged New issue has not been triaged by the area owner

Comments

@ViktorHofer
Copy link
Member 

Microsoft.DotNet.XUnitConsoleRunner v2.5.0 (64-bit .NET 6.0.0-rc.1.21430.1)
  Discovering: tracing.eventcounter.XUnitWrapper (method display = ClassAndMethod, method display options = None)
  Discovered:  tracing.eventcounter.XUnitWrapper (found 8 test cases)
  Starting:    tracing.eventcounter.XUnitWrapper (parallel test collections = on, max threads = 4)
  Finished:    tracing.eventcounter.XUnitWrapper
  Discovering: tracing.eventpipe.XUnitWrapper (method display = ClassAndMethod, method display options = None)
  Discovered:  tracing.eventpipe.XUnitWrapper (found 13 test cases)
  Starting:    tracing.eventpipe.XUnitWrapper (parallel test collections = on, max threads = 4)
   tracing.eventpipe.XUnitWrapper: [Long Running Test] 'tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.sh', Elapsed: 00:02:12
   tracing.eventpipe.XUnitWrapper: [Long Running Test] 'tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.sh', Elapsed: 00:04:13
   tracing.eventpipe.XUnitWrapper: [Long Running Test] 'tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.sh', Elapsed: 00:06:14
   tracing.eventpipe.XUnitWrapper: [Long Running Test] 'tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.sh', Elapsed: 00:08:15
Attempting to collect crash dump: /cores/crashdump_33452.dmp
Invoking: sudo /tmp/helix/working/9D910970/p/createdump --name "/cores/crashdump_33452.dmp" 33452 --withheap
createdump stdout:
Gathering state for process 33452 

createdump stderr:
CLRDataCreateInstance(ICLRDataEnumMemoryRegions) FAILED 80131c4f

Failed to collect crash dump
Attempting to collect crash dump: /cores/crashdump_33422.dmp
Invoking: sudo /tmp/helix/working/9D910970/p/createdump --name "/cores/crashdump_33422.dmp" 33422 --withheap
createdump stdout:
Gathering state for process 33422 

createdump stderr:
CLRDataCreateInstance(ICLRDataEnumMemoryRegions) FAILED 80131c4f

Failed to collect crash dump
    tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.sh [FAIL]
      
      cmdLine:/private/tmp/helix/working/9D910970/w/AF73099B/e/tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.sh Timed Out (timeout in milliseconds: 600000 from variable __TestTimeout, start: 9/8/2021 5:33:42 PM, end: 9/8/2021 5:43:42 PM)
      
      Return code:      -100
      Raw output file:      /tmp/helix/working/9D910970/w/AF73099B/uploads/Reports/tracing.eventpipe/pauseonstart/pauseonstart/pauseonstart.output.txt
      Raw output:
      BEGIN EXECUTION
      /tmp/helix/working/9D910970/p/corerun -p System.Reflection.Metadata.MetadataUpdater.IsSupported=false pauseonstart.dll ''
        0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-27095-1631133741-socket
        0.0s: Deleted
        0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32903-1631135128-socket
        0.0s: Deleted
        0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32092-1631134750-socket
        0.0s: Deleted
        0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32052-1631134716-socket
        0.0s: Deleted
        0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32012-1631134676-socket
        0.0s: Deleted
        0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32883-1631135055-socket
        0.0s: Deleted
        0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32793-1631134901-socket
        0.0s: Deleted
        0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32833-1631134938-socket
        0.0s: Deleted
        0.1s: ::== Running test: TEST_RuntimeResumesExecutionWithCommand
        0.1s: Server name is '/var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/DOTNET_TRACE_TESTS_vjfknvx4.lb4'
        0.2s: running sub-process: /private/tmp/helix/working/9D910970/p/corerun /private/tmp/helix/working/9D910970/w/AF73099B/e/tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.dll 0
        0.4s: subprocess started: True
        0.4s: subprocess PID: 33431
        0.6s: { Magic=System.Byte[]; ClrInstanceId=9cb2fdb0-5cb6-4507-9567-9ebdff4d8572; ProcessId=33431; Unused=0; }
        0.6s: Sent: { Header={ Magic=System.Byte[]; Size=20; CommandSet=4; CommandId=1; Reserved=0 }; }
        0.6s: received: { Header={ Magic=System.Byte[]; Size=24; CommandSet=255; CommandId=0; Reserved=0 }; Payload=[ 0x00 0x00 0x00 0x00  ]}
        0.6s: Sending 'exit' to subprocess stdin
        0.7s: ================= Subprocess Exited =================
        0.7s: SubProcess exited - Exit code: 0
        0.7s: ----------------------------------------
        0.7s: Subprocess stdout: 
        0.5s: Subprocess started!  Waiting for input...
        0.5s: Received 'exit'.  Exiting...
        0.7s: Subprocess stderr: 
        0.7s: ----------------------------------------
        0.7s: Test passed: True
        0.7s: 
        0.7s: ::== Running test: TEST_TracesHaveRelevantEvents
        0.7s: Server name is '/var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/DOTNET_TRACE_TESTS_yxr0kj2f.r2k'
        0.7s: running sub-process: /private/tmp/helix/working/9D910970/p/corerun /private/tmp/helix/working/9D910970/w/AF73099B/e/tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.dll 0
        0.7s: subprocess started: True
        0.7s: subprocess PID: 33433
        0.8s: { Magic=System.Byte[]; ClrInstanceId=9b1fd41e-1cf2-4c7a-854d-98d3a2081e1c; ProcessId=33433; Unused=0; }
        0.8s: Starting EventPipeSession over standard connection
        0.9s: Started EventPipeSession over standard connection with session id: 0x7fd2da700100
        0.9s: Send ResumeRuntime Diagnostics IPC Command
        0.9s: Sent: { Header={ Magic=System.Byte[]; Size=20; CommandSet=4; CommandId=1; Reserved=0 }; }
        0.9s: received: { Header={ Magic=System.Byte[]; Size=24; CommandSet=255; CommandId=0; Reserved=0 }; Payload=[ 0x00 0x00 0x00 0x00  ]}
        2.9s: Stopping EventPipeSession over standard connection
        3.3s: Stopped EventPipeSession over standard connection
        3.3s: Sending 'exit' to subprocess stdin
        3.3s: ================= Subprocess Exited =================
        3.3s: SubProcess exited - Exit code: 0
        3.3s: ----------------------------------------
        3.3s: Subprocess stdout: 
        0.3s: Subprocess started!  Waiting for input...
        2.5s: Received 'exit'.  Exiting...
        3.3s: Subprocess stderr: 
        3.3s: ----------------------------------------
        3.4s: isStartupEventPresent: True
        3.4s: Test passed: True
        3.4s: 
        3.4s: ::== Running test: TEST_MultipleSessionsCanBeStartedWhilepaused
        3.4s: Server name is '/var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/DOTNET_TRACE_TESTS_oqvdgqm5.f1j'
        3.4s: running sub-process: /private/tmp/helix/working/9D910970/p/corerun /private/tmp/helix/working/9D910970/w/AF73099B/e/tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.dll 0
        3.4s: subprocess started: True
        3.4s: subprocess PID: 33452
        3.5s: Standard Diagnostics Server connection not created yet -> try again in 100 ms
        3.6s: { Magic=System.Byte[]; ClrInstanceId=9e4fd643-db31-4603-b5ba-cf53ed31120a; ProcessId=33452; Unused=0; }
        3.6s: Starting EventPipeSession over standard connection
        3.7s: Started EventPipeSession over standard connection with session id: 0x7fdffbd1f270
        3.7s: Starting EventPipeSession over standard connection
        3.7s: Started EventPipeSession over standard connection with session id: 0x7fdffbd20110
        3.7s: Starting EventPipeSession over standard connection
        3.7s: Started EventPipeSession over standard connection with session id: 0x7fdffbd202a0
        3.7s: Send ResumeRuntime Diagnostics IPC Command
        3.7s: Sent: { Header={ Magic=System.Byte[]; Size=20; CommandSet=4; CommandId=1; Reserved=0 }; }
        3.7s: received: { Header={ Magic=System.Byte[]; Size=24; CommandSet=255; CommandId=0; Reserved=0 }; Payload=[ 0x00 0x00 0x00 0x00  ]}
        5.9s: Stopping EventPipeSession over standard connection
      
      cmdLine:/private/tmp/helix/working/9D910970/w/AF73099B/e/tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.sh Timed Out (timeout in milliseconds: 600000 from variable __TestTimeout, start: 9/8/2021 5:33:42 PM, end: 9/8/2021 5:43:42 PM)
      Test Harness Exitcode is : -100
      To run the test:
      > set CORE_ROOT=/tmp/helix/working/9D910970/p
      > /private/tmp/helix/working/9D910970/w/AF73099B/e/tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.sh
      Expected: True
      Actual:   False
      Stack Trace:
           at tracing_eventpipe._pauseonstart_pauseonstart_pauseonstart_._pauseonstart_pauseonstart_pauseonstart_sh()
      Output:
        
        cmdLine:/private/tmp/helix/working/9D910970/w/AF73099B/e/tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.sh Timed Out (timeout in milliseconds: 600000 from variable __TestTimeout, start: 9/8/2021 5:33:42 PM, end: 9/8/2021 5:43:42 PM)
        
        Return code:      -100
        Raw output file:      /tmp/helix/working/9D910970/w/AF73099B/uploads/Reports/tracing.eventpipe/pauseonstart/pauseonstart/pauseonstart.output.txt
        Raw output:
        BEGIN EXECUTION
        /tmp/helix/working/9D910970/p/corerun -p System.Reflection.Metadata.MetadataUpdater.IsSupported=false pauseonstart.dll ''
          0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-27095-1631133741-socket
          0.0s: Deleted
          0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32903-1631135128-socket
          0.0s: Deleted
          0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32092-1631134750-socket
          0.0s: Deleted
          0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32052-1631134716-socket
          0.0s: Deleted
          0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32012-1631134676-socket
          0.0s: Deleted
          0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32883-1631135055-socket
          0.0s: Deleted
          0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32793-1631134901-socket
          0.0s: Deleted
          0.0s: Attempting to delete the zombied pipe: /var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/dotnet-diagnostic-32833-1631134938-socket
          0.0s: Deleted
          0.1s: ::== Running test: TEST_RuntimeResumesExecutionWithCommand
          0.1s: Server name is '/var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/DOTNET_TRACE_TESTS_vjfknvx4.lb4'
          0.2s: running sub-process: /private/tmp/helix/working/9D910970/p/corerun /private/tmp/helix/working/9D910970/w/AF73099B/e/tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.dll 0
          0.4s: subprocess started: True
          0.4s: subprocess PID: 33431
          0.6s: { Magic=System.Byte[]; ClrInstanceId=9cb2fdb0-5cb6-4507-9567-9ebdff4d8572; ProcessId=33431; Unused=0; }
          0.6s: Sent: { Header={ Magic=System.Byte[]; Size=20; CommandSet=4; CommandId=1; Reserved=0 }; }
          0.6s: received: { Header={ Magic=System.Byte[]; Size=24; CommandSet=255; CommandId=0; Reserved=0 }; Payload=[ 0x00 0x00 0x00 0x00  ]}
          0.6s: Sending 'exit' to subprocess stdin
          0.7s: ================= Subprocess Exited =================
          0.7s: SubProcess exited - Exit code: 0
          0.7s: ----------------------------------------
          0.7s: Subprocess stdout: 
          0.5s: Subprocess started!  Waiting for input...
          0.5s: Received 'exit'.  Exiting...
          0.7s: Subprocess stderr: 
          0.7s: ----------------------------------------
          0.7s: Test passed: True
          0.7s: 
          0.7s: ::== Running test: TEST_TracesHaveRelevantEvents
          0.7s: Server name is '/var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/DOTNET_TRACE_TESTS_yxr0kj2f.r2k'
          0.7s: running sub-process: /private/tmp/helix/working/9D910970/p/corerun /private/tmp/helix/working/9D910970/w/AF73099B/e/tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.dll 0
          0.7s: subprocess started: True
          0.7s: subprocess PID: 33433
          0.8s: { Magic=System.Byte[]; ClrInstanceId=9b1fd41e-1cf2-4c7a-854d-98d3a2081e1c; ProcessId=33433; Unused=0; }
          0.8s: Starting EventPipeSession over standard connection
          0.9s: Started EventPipeSession over standard connection with session id: 0x7fd2da700100
          0.9s: Send ResumeRuntime Diagnostics IPC Command
          0.9s: Sent: { Header={ Magic=System.Byte[]; Size=20; CommandSet=4; CommandId=1; Reserved=0 }; }
          0.9s: received: { Header={ Magic=System.Byte[]; Size=24; CommandSet=255; CommandId=0; Reserved=0 }; Payload=[ 0x00 0x00 0x00 0x00  ]}
          2.9s: Stopping EventPipeSession over standard connection
          3.3s: Stopped EventPipeSession over standard connection
          3.3s: Sending 'exit' to subprocess stdin
          3.3s: ================= Subprocess Exited =================
          3.3s: SubProcess exited - Exit code: 0
          3.3s: ----------------------------------------
          3.3s: Subprocess stdout: 
          0.3s: Subprocess started!  Waiting for input...
          2.5s: Received 'exit'.  Exiting...
          3.3s: Subprocess stderr: 
          3.3s: ----------------------------------------
          3.4s: isStartupEventPresent: True
          3.4s: Test passed: True
          3.4s: 
          3.4s: ::== Running test: TEST_MultipleSessionsCanBeStartedWhilepaused
          3.4s: Server name is '/var/folders/pt/4mwrxs9929v54x9rjgvjvk480000gy/T/DOTNET_TRACE_TESTS_oqvdgqm5.f1j'
          3.4s: running sub-process: /private/tmp/helix/working/9D910970/p/corerun /private/tmp/helix/working/9D910970/w/AF73099B/e/tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.dll 0
          3.4s: subprocess started: True
          3.4s: subprocess PID: 33452
          3.5s: Standard Diagnostics Server connection not created yet -> try again in 100 ms
          3.6s: { Magic=System.Byte[]; ClrInstanceId=9e4fd643-db31-4603-b5ba-cf53ed31120a; ProcessId=33452; Unused=0; }
          3.6s: Starting EventPipeSession over standard connection
          3.7s: Started EventPipeSession over standard connection with session id: 0x7fdffbd1f270
          3.7s: Starting EventPipeSession over standard connection
          3.7s: Started EventPipeSession over standard connection with session id: 0x7fdffbd20110
          3.7s: Starting EventPipeSession over standard connection
          3.7s: Started EventPipeSession over standard connection with session id: 0x7fdffbd202a0
          3.7s: Send ResumeRuntime Diagnostics IPC Command
          3.7s: Sent: { Header={ Magic=System.Byte[]; Size=20; CommandSet=4; CommandId=1; Reserved=0 }; }
          3.7s: received: { Header={ Magic=System.Byte[]; Size=24; CommandSet=255; CommandId=0; Reserved=0 }; Payload=[ 0x00 0x00 0x00 0x00  ]}
          5.9s: Stopping EventPipeSession over standard connection
        
        cmdLine:/private/tmp/helix/working/9D910970/w/AF73099B/e/tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.sh Timed Out (timeout in milliseconds: 600000 from variable __TestTimeout, start: 9/8/2021 5:33:42 PM, end: 9/8/2021 5:43:42 PM)
        Test Harness Exitcode is : -100
        To run the test:
        > set CORE_ROOT=/tmp/helix/working/9D910970/p
        > /private/tmp/helix/working/9D910970/w/AF73099B/e/tracing/eventpipe/pauseonstart/pauseonstart/pauseonstart.sh

Build: https://dev.azure.com/dnceng/public/_build/results?buildId=1349846&view=ms.vss-test-web.build-test-results-tab&runId=39507584&resultId=102430&paneView=dotnet-dnceng.dnceng-build-release-tasks.helix-test-information-tab

Configuration: Mono OSX x64 Release no_tiered_compilation @ OSX.1014.Amd64.Open
@ghost
Copy link

ghost commented Sep 9, 2021

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

@ghost ghost added the untriaged New issue has not been triaged by the area owner label Sep 9, 2021
@am11 am11 mentioned this issue Sep 9, 2021
Merged
@josalem
Copy link
Contributor

josalem commented Sep 9, 2021

@lateralusX

@lateralusX
Copy link
Member

Dup of #58781

@lateralusX
Copy link
Member

Should be fixed by #58996.

@ghost ghost locked as resolved and limited conversation to collaborators Nov 3, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
area-Tracing-mono untriaged New issue has not been triaged by the area owner
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@ViktorHofer @lateralusX @josalem