[==========] Running 4 tests from 4 test suites.
[----------] Global test environment set-up.
[----------] 1 test from Oneshot
[ RUN ] Oneshot.FillBuffer
[INFO:run_test.cc(271)] Running tspec data/oneshot.tspec, output file /tmp/test.trace
[INFO:run_test.cc(213)] Launching: fuchsia-pkg://fuchsia.com/trace#meta/trace.cmx
[INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config
[VERBOSE1:trace_manager.cc(202)] Starting configured provider: cpuperf
[VERBOSE2:trace_manager.cc(203)] URL: fuchsia-pkg://fuchsia.com/cpuperf_provider#meta/cpuperf_provider.cmx
[VERBOSE2:trace_manager.cc(210)] Args:
[VERBOSE1:trace_manager.cc(202)] Starting configured provider: ktrace
[VERBOSE2:trace_manager.cc(203)] URL: fuchsia-pkg://fuchsia.com/ktrace_provider#meta/ktrace_provider.cmx
[VERBOSE2:trace_manager.cc(210)] Args:
[INFO:trace_manager.cc(96)] Starting trace with 1 MB buffers, buffering mode=oneshot
[VERBOSE2:trace_manager.cc(156)] Registering provider {438426:ktrace_provider}
[VERBOSE1:trace_session.cc(56)] Adding provider #1 {438426:ktrace_provider}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from ready to started
[VERBOSE2:tracee.cc(147)] #1 {438426:ktrace_provider}: pending=0x3
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from start pending to started
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(158)] All providers reporting started
[VERBOSE1:trace_session.cc(109)] Marking session as having started
[VERBOSE2:trace_manager.cc(156)] Registering provider {438810:fill-buffer}
[VERBOSE1:trace_session.cc(56)] Adding provider #2 {438810:fill-buffer}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #2 {438810:fill-buffer}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from started to started
[VERBOSE2:tracee.cc(579)] #2 {438810:fill-buffer}: writing provider info record
[WARNING:garnet/bin/trace_manager/tracee.cc(369)] #2 {438810:fill-buffer}: 43698 records were dropped
[VERBOSE2:tracee.cc(271)] #2 {438810:fill-buffer}: Writing chunk for rolling buffer 0: vmo offset 0x80, size 0xfff80, by-record
[INFO:tracee.cc(435)] #2 {438810:fill-buffer} trace stats
[INFO:tracee.cc(436)] Wrapped count: 0
[INFO:tracee.cc(437)] # records dropped: 43698
[INFO:tracee.cc(438)] Durable buffer: 0x0, size 0x0
[INFO:tracee.cc(441)] Non-durable buffer: 0xfff60,0x0, size 0xfff80
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(158)] All providers reporting started
[INFO:trace_manager.cc(135)] Stopping trace
[VERBOSE1:trace_session.cc(93)] Stopping trace
[VERBOSE2:trace_session.cc(253)] Transitioning from started to stopping
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from started to stopping
[VERBOSE2:tracee.cc(147)] #1 {438426:ktrace_provider}: pending=0x4
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from stopping to stopped
[VERBOSE2:tracee.cc(579)] #1 {438426:ktrace_provider}: writing provider info record
[VERBOSE2:tracee.cc(271)] #1 {438426:ktrace_provider}: Writing chunk for rolling buffer 0: vmo offset 0x80, size 0xfff80, by-record
[VERBOSE1:trace_session.cc(204)] Marking session as stopped, no more tracees
[VERBOSE2:trace_session.cc(253)] Transitioning from stopping to stopped
[INFO:trace_manager.cc(138)] Stopped trace
[INFO:run_test.cc(239)] Application exited with return reason/code 1/0
[INFO:run_test.cc(261)] return_code 0
[INFO:run_test.cc(296)] Verifying tspec data/oneshot.tspec, output file /tmp/test.trace
[INFO:run_test.cc(213)] Launching: fuchsia-pkg://fuchsia.com/trace_tests#meta/basic_integration_test_app.cmx
[INFO:run_test.cc(239)] Application exited with return reason/code 1/0
[INFO:run_test.cc(261)] return_code 0
[ OK ] Oneshot.FillBuffer (3744 ms)
[----------] 1 test from Oneshot (3744 ms total)
[----------] 1 test from Circular
[ RUN ] Circular.FillBuffer
[INFO:run_test.cc(271)] Running tspec data/circular.tspec, output file /tmp/test.trace
[INFO:run_test.cc(213)] Launching: fuchsia-pkg://fuchsia.com/trace#meta/trace.cmx
[INFO:trace_manager.cc(96)] Starting trace with 1 MB buffers, buffering mode=circular
[VERBOSE1:trace_session.cc(56)] Adding provider #1 {438426:ktrace_provider}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from ready to started
[VERBOSE2:tracee.cc(147)] #1 {438426:ktrace_provider}: pending=0x3
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from start pending to started
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(158)] All providers reporting started
[VERBOSE1:trace_session.cc(109)] Marking session as having started
[VERBOSE2:trace_manager.cc(156)] Registering provider {441164:fill-buffer}
[VERBOSE1:trace_session.cc(56)] Adding provider #3 {441164:fill-buffer}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #3 {441164:fill-buffer}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from started to started
[VERBOSE2:tracee.cc(579)] #3 {441164:fill-buffer}: writing provider info record
[VERBOSE2:tracee.cc(271)] #3 {441164:fill-buffer}: Writing chunk for durable: vmo offset 0x80, size 0xc0, by-size
[VERBOSE2:tracee.cc(271)] #3 {441164:fill-buffer}: Writing chunk for rolling buffer 1: vmo offset 0x88040, size 0x77fa0, by-size
[VERBOSE2:tracee.cc(271)] #3 {441164:fill-buffer}: Writing chunk for rolling buffer 0: vmo offset 0x10080, size 0x30240, by-size
[INFO:tracee.cc(435)] #3 {441164:fill-buffer} trace stats
[INFO:tracee.cc(436)] Wrapped count: 6
[INFO:tracee.cc(437)] # records dropped: 0
[INFO:tracee.cc(438)] Durable buffer: 0xc0, size 0x10000
[INFO:tracee.cc(441)] Non-durable buffer: 0x30240,0x77fa0, size 0x77fc0
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(158)] All providers reporting started
[INFO:trace_manager.cc(135)] Stopping trace
[VERBOSE1:trace_session.cc(93)] Stopping trace
[VERBOSE2:trace_session.cc(253)] Transitioning from started to stopping
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from started to stopping
[VERBOSE2:tracee.cc(147)] #1 {438426:ktrace_provider}: pending=0x4
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from stopping to stopped
[VERBOSE2:tracee.cc(579)] #1 {438426:ktrace_provider}: writing provider info record
[VERBOSE2:tracee.cc(271)] #1 {438426:ktrace_provider}: Writing chunk for durable: vmo offset 0x80, size 0x10, by-size
[VERBOSE2:tracee.cc(271)] #1 {438426:ktrace_provider}: Writing chunk for rolling buffer 0: vmo offset 0x10080, size 0x77fc0, by-record
[VERBOSE1:trace_session.cc(204)] Marking session as stopped, no more tracees
[VERBOSE2:trace_session.cc(253)] Transitioning from stopping to stopped
[INFO:trace_manager.cc(138)] Stopped trace
[INFO:run_test.cc(239)] Application exited with return reason/code 1/0
[INFO:run_test.cc(261)] return_code 0
[INFO:run_test.cc(296)] Verifying tspec data/circular.tspec, output file /tmp/test.trace
[INFO:run_test.cc(213)] Launching: fuchsia-pkg://fuchsia.com/trace_tests#meta/basic_integration_test_app.cmx
[INFO:run_test.cc(239)] Application exited with return reason/code 1/0
[INFO:run_test.cc(261)] return_code 0
[ OK ] Circular.FillBuffer (3357 ms)
[----------] 1 test from Circular (3357 ms total)
[----------] 1 test from Streaming
[ RUN ] Streaming.FillBuffer
[INFO:run_test.cc(271)] Running tspec data/streaming.tspec, output file /tmp/test.trace
[INFO:run_test.cc(213)] Launching: fuchsia-pkg://fuchsia.com/trace#meta/trace.cmx
[INFO:trace_manager.cc(96)] Starting trace with 1 MB buffers, buffering mode=streaming
[VERBOSE1:trace_session.cc(56)] Adding provider #1 {438426:ktrace_provider}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from ready to started
[VERBOSE2:tracee.cc(147)] #1 {438426:ktrace_provider}: pending=0x3
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from start pending to started
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(158)] All providers reporting started
[VERBOSE1:trace_session.cc(109)] Marking session as having started
[VERBOSE2:trace_manager.cc(156)] Registering provider {442970:fill-buffer}
[VERBOSE1:trace_session.cc(56)] Adding provider #4 {442970:fill-buffer}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #4 {442970:fill-buffer}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from started to started
[VERBOSE2:tracee.cc(579)] #4 {442970:fill-buffer}: writing provider info record
[WARNING:garnet/bin/trace_manager/tracee.cc(369)] #4 {442970:fill-buffer}: 45060 records were dropped
[VERBOSE2:tracee.cc(271)] #4 {442970:fill-buffer}: Writing chunk for durable: vmo offset 0x80, size 0xc0, by-size
[VERBOSE2:tracee.cc(271)] #4 {442970:fill-buffer}: Writing chunk for rolling buffer 0: vmo offset 0x10080, size 0x77fa0, by-size
[VERBOSE2:tracee.cc(271)] #4 {442970:fill-buffer}: Writing chunk for rolling buffer 1: vmo offset 0x88040, size 0x77fa0, by-size
[INFO:tracee.cc(435)] #4 {442970:fill-buffer} trace stats
[INFO:tracee.cc(436)] Wrapped count: 1
[INFO:tracee.cc(437)] # records dropped: 45060
[INFO:tracee.cc(438)] Durable buffer: 0xc0, size 0x10000
[INFO:tracee.cc(441)] Non-durable buffer: 0x77fa0,0x77fa0, size 0x77fc0
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(158)] All providers reporting started
[INFO:trace_manager.cc(135)] Stopping trace
[VERBOSE1:trace_session.cc(93)] Stopping trace
[VERBOSE2:trace_session.cc(253)] Transitioning from started to stopping
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from started to stopping
[VERBOSE2:tracee.cc(147)] #1 {438426:ktrace_provider}: pending=0x4
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from stopping to stopped
[VERBOSE2:tracee.cc(579)] #1 {438426:ktrace_provider}: writing provider info record
[VERBOSE2:tracee.cc(271)] #1 {438426:ktrace_provider}: Writing chunk for durable: vmo offset 0x80, size 0x10, by-size
[VERBOSE2:tracee.cc(271)] #1 {438426:ktrace_provider}: Writing chunk for rolling buffer 0: vmo offset 0x10080, size 0x77fc0, by-record
[VERBOSE1:trace_session.cc(204)] Marking session as stopped, no more tracees
[VERBOSE2:trace_session.cc(253)] Transitioning from stopping to stopped
[INFO:trace_manager.cc(138)] Stopped trace
[INFO:run_test.cc(239)] Application exited with return reason/code 1/0
[INFO:run_test.cc(261)] return_code 0
[INFO:run_test.cc(296)] Verifying tspec data/streaming.tspec, output file /tmp/test.trace
[INFO:run_test.cc(213)] Launching: fuchsia-pkg://fuchsia.com/trace_tests#meta/basic_integration_test_app.cmx
[INFO:run_test.cc(239)] Application exited with return reason/code 1/0
[INFO:run_test.cc(261)] return_code 0
[ OK ] Streaming.FillBuffer (3487 ms)
[----------] 1 test from Streaming (3487 ms total)
[----------] 1 test from TwoProvidersOneEngine
[ RUN ] TwoProvidersOneEngine.ErrorHandling
[VERBOSE2:trace_manager.cc(156)] Registering provider {443879:provider1}
[VERBOSE2:trace_manager.cc(156)] Registering provider {443879:provider2}
[INFO:trace_integration_tests.cc(83)] /pkg/bin/two_providers_one_engine started
[INFO:run_test.cc(271)] Running tspec data/simple.tspec, output file /tmp/test.trace
[INFO:run_test.cc(213)] Launching: fuchsia-pkg://fuchsia.com/trace#meta/trace.cmx
[INFO:trace_manager.cc(96)] Starting trace with 1 MB buffers, buffering mode=oneshot
[VERBOSE1:trace_session.cc(56)] Adding provider #1 {438426:ktrace_provider}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from ready to started
[VERBOSE1:trace_session.cc(56)] Adding provider #5 {443879:provider1}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #5 {443879:provider1}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from started to started
[VERBOSE1:trace_session.cc(56)] Adding provider #6 {443879:provider2}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #6 {443879:provider2}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from started to started
[VERBOSE2:tracee.cc(147)] #1 {438426:ktrace_provider}: pending=0x3
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from start pending to started
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(152)] tracee #5 {443879:provider1} not ready
[VERBOSE2:trace_session.cc(152)] tracee #6 {443879:provider2} not ready
Session for process 443879: engine is already started. Is there perchance two providers in this app?
[VERBOSE2:tracee.cc(147)] #6 {443879:provider2}: pending=0x4
[VERBOSE2:tracee.cc(133)] #6 {443879:provider2}: Transitioning from start pending to stopped
[VERBOSE2:tracee.cc(579)] #6 {443879:provider2}: writing provider info record
[ERROR:garnet/bin/trace_manager/tracee.cc(361)] #6 {443879:provider2}: header corrupt, bad magic: 0x0
[ERROR:garnet/bin/trace_manager/trace_session.cc(174)] Problem reading provider output, skipping
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(152)] tracee #5 {443879:provider1} not ready
[VERBOSE2:tracee.cc(147)] #5 {443879:provider1}: pending=0x3
[VERBOSE2:tracee.cc(133)] #5 {443879:provider1}: Transitioning from start pending to started
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(152)] tracee #5 {443879:provider1} ready
[VERBOSE2:trace_session.cc(158)] All providers reporting started
[VERBOSE1:trace_session.cc(109)] Marking session as having started
[VERBOSE2:trace_manager.cc(156)] Registering provider {444380:simple}
[VERBOSE1:trace_session.cc(56)] Adding provider #7 {444380:simple}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #7 {444380:simple}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from started to started
[VERBOSE2:tracee.cc(579)] #7 {444380:simple}: writing provider info record
[VERBOSE2:tracee.cc(271)] #7 {444380:simple}: Writing chunk for rolling buffer 0: vmo offset 0x80, size 0xfff80, by-record
[INFO:tracee.cc(435)] #7 {444380:simple} trace stats
[INFO:tracee.cc(436)] Wrapped count: 0
[INFO:tracee.cc(437)] # records dropped: 0
[INFO:tracee.cc(438)] Durable buffer: 0x0, size 0x0
[INFO:tracee.cc(441)] Non-durable buffer: 0x2a0,0x0, size 0xfff80
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(152)] tracee #5 {443879:provider1} ready
[VERBOSE2:trace_session.cc(158)] All providers reporting started
[INFO:trace_manager.cc(135)] Stopping trace
[VERBOSE1:trace_session.cc(93)] Stopping trace
[VERBOSE2:trace_session.cc(253)] Transitioning from started to stopping
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from started to stopping
[VERBOSE2:tracee.cc(133)] #5 {443879:provider1}: Transitioning from started to stopping
[VERBOSE2:tracee.cc(147)] #5 {443879:provider1}: pending=0x4
[VERBOSE2:tracee.cc(133)] #5 {443879:provider1}: Transitioning from stopping to stopped
[VERBOSE2:tracee.cc(579)] #5 {443879:provider1}: writing provider info record
[VERBOSE2:tracee.cc(271)] #5 {443879:provider1}: Writing chunk for rolling buffer 0: vmo offset 0x80, size 0xfff80, by-record
[VERBOSE2:tracee.cc(147)] #1 {438426:ktrace_provider}: pending=0x4
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from stopping to stopped
[VERBOSE2:tracee.cc(579)] #1 {438426:ktrace_provider}: writing provider info record
[VERBOSE2:tracee.cc(271)] #1 {438426:ktrace_provider}: Writing chunk for rolling buffer 0: vmo offset 0x80, size 0xfff80, by-record
[VERBOSE1:trace_session.cc(204)] Marking session as stopped, no more tracees
[VERBOSE2:trace_session.cc(253)] Transitioning from stopping to stopped
[INFO:trace_manager.cc(138)] Stopped trace
[INFO:run_test.cc(239)] Application exited with return reason/code 1/0
[INFO:run_test.cc(261)] return_code 0
[INFO:run_test.cc(296)] Verifying tspec data/simple.tspec, output file /tmp/test.trace
[INFO:run_test.cc(213)] Launching: fuchsia-pkg://fuchsia.com/trace_tests#meta/basic_integration_test_app.cmx
[INFO:run_test.cc(239)] Application exited with return reason/code 1/0
[INFO:run_test.cc(261)] return_code 0
[INFO:run_test.cc(271)] Running tspec data/simple.tspec, output file /tmp/test.trace
[INFO:run_test.cc(213)] Launching: fuchsia-pkg://fuchsia.com/trace#meta/trace.cmx
[INFO:trace_manager.cc(96)] Starting trace with 1 MB buffers, buffering mode=oneshot
[VERBOSE1:trace_session.cc(56)] Adding provider #1 {438426:ktrace_provider}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from ready to started
[VERBOSE1:trace_session.cc(56)] Adding provider #5 {443879:provider1}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #5 {443879:provider1}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from started to started
[VERBOSE1:trace_session.cc(56)] Adding provider #6 {443879:provider2}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #6 {443879:provider2}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from started to started
[VERBOSE2:tracee.cc(147)] #1 {438426:ktrace_provider}: pending=0x3
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from start pending to started
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(152)] tracee #5 {443879:provider1} not ready
Session for process 443879: engine is already started. Is there perchance two providers in this app?
[VERBOSE2:trace_session.cc(152)] tracee #6 {443879:provider2} not ready
[VERBOSE2:tracee.cc(147)] #6 {443879:provider2}: pending=0x4
[VERBOSE2:tracee.cc(133)] #6 {443879:provider2}: Transitioning from start pending to stopped
[VERBOSE2:tracee.cc(579)] #6 {443879:provider2}: writing provider info record
[ERROR:garnet/bin/trace_manager/tracee.cc(361)] #6 {443879:provider2}: header corrupt, bad magic: 0x0
[ERROR:garnet/bin/trace_manager/trace_session.cc(174)] Problem reading provider output, skipping
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(152)] tracee #5 {443879:provider1} not ready
[VERBOSE2:tracee.cc(147)] #5 {443879:provider1}: pending=0x3
[VERBOSE2:tracee.cc(133)] #5 {443879:provider1}: Transitioning from start pending to started
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(152)] tracee #5 {443879:provider1} ready
[VERBOSE2:trace_session.cc(158)] All providers reporting started
[VERBOSE1:trace_session.cc(109)] Marking session as having started
[VERBOSE2:trace_manager.cc(156)] Registering provider {445147:simple}
[VERBOSE1:trace_session.cc(56)] Adding provider #8 {445147:simple}, buffer size 1MB
[VERBOSE2:tracee.cc(133)] #8 {445147:simple}: Transitioning from ready to start pending
[VERBOSE2:trace_session.cc(253)] Transitioning from started to started
[VERBOSE2:tracee.cc(579)] #8 {445147:simple}: writing provider info record
[VERBOSE2:tracee.cc(271)] #8 {445147:simple}: Writing chunk for rolling buffer 0: vmo offset 0x80, size 0xfff80, by-record
[INFO:tracee.cc(435)] #8 {445147:simple} trace stats
[INFO:tracee.cc(436)] Wrapped count: 0
[INFO:tracee.cc(437)] # records dropped: 0
[INFO:tracee.cc(438)] Durable buffer: 0x0, size 0x0
[INFO:tracee.cc(441)] Non-durable buffer: 0x2a0,0x0, size 0xfff80
[VERBOSE2:trace_session.cc(152)] tracee #1 {438426:ktrace_provider} ready
[VERBOSE2:trace_session.cc(152)] tracee #5 {443879:provider1} ready
[VERBOSE2:trace_session.cc(158)] All providers reporting started
[INFO:trace_manager.cc(135)] Stopping trace
[VERBOSE1:trace_session.cc(93)] Stopping trace
[VERBOSE2:trace_session.cc(253)] Transitioning from started to stopping
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from started to stopping
[VERBOSE2:tracee.cc(133)] #5 {443879:provider1}: Transitioning from started to stopping
[VERBOSE2:tracee.cc(147)] #1 {438426:ktrace_provider}: pending=0x4
[VERBOSE2:tracee.cc(133)] #1 {438426:ktrace_provider}: Transitioning from stopping to stopped
[VERBOSE2:tracee.cc(579)] #1 {438426:ktrace_provider}: writing provider info record
[VERBOSE2:tracee.cc(271)] #1 {438426:ktrace_provider}: Writing chunk for rolling buffer 0: vmo offset 0x80, size 0xfff80, by-record
[VERBOSE2:tracee.cc(147)] #5 {443879:provider1}: pending=0x4
[VERBOSE2:tracee.cc(133)] #5 {443879:provider1}: Transitioning from stopping to stopped
[VERBOSE2:tracee.cc(579)] #5 {443879:provider1}: writing provider info record
[VERBOSE2:tracee.cc(271)] #5 {443879:provider1}: Writing chunk for rolling buffer 0: vmo offset 0x80, size 0xfff80, by-record
[VERBOSE1:trace_session.cc(204)] Marking session as stopped, no more tracees
[VERBOSE2:trace_session.cc(253)] Transitioning from stopping to stopped
[INFO:trace_manager.cc(138)] Stopped trace
[INFO:run_test.cc(239)] Application exited with return reason/code 1/0
[INFO:run_test.cc(261)] return_code 0
[INFO:run_test.cc(296)] Verifying tspec data/simple.tspec, output file /tmp/test.trace
[INFO:run_test.cc(213)] Launching: fuchsia-pkg://fuchsia.com/trace_tests#meta/basic_integration_test_app.cmx
[INFO:run_test.cc(239)] Application exited with return reason/code 1/0
[INFO:run_test.cc(261)] return_code 0
[INFO:trace_integration_tests.cc(96)] /pkg/bin/two_providers_one_engine terminated
[ OK ] TwoProvidersOneEngine.ErrorHandling (339 ms)
[----------] 1 test from TwoProvidersOneEngine (339 ms total)
[----------] Global test environment tear-down
[==========] 4 tests from 4 test suites ran. (10927 ms total)
[ PASSED ] 4 tests.
YOU HAVE 1 DISABLED TEST