Back to build
Raw log | Switch to full mode | Login

[==========] Running 2 tests from 1 test suite. [----------] Global test environment set-up. [----------] 2 tests from DetachTest [ RUN ] DetachTest.SpawnedAppNotDetached [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 4 MB buffers, buffering mode=oneshot [VERBOSE2:trace_manager.cc(156)] Registering provider {424992:cpuperf_provider} [VERBOSE1:trace_session.cc(56)] Adding provider #1 {424992:cpuperf_provider}, buffer size 4MB [VERBOSE2:tracee.cc(133)] #1 {424992:cpuperf_provider}: Transitioning from ready to start pending [VERBOSE2:trace_session.cc(253)] Transitioning from ready to started [VERBOSE2:tracee.cc(147)] #1 {424992:cpuperf_provider}: pending=0x3 [VERBOSE2:tracee.cc(133)] #1 {424992:cpuperf_provider}: Transitioning from start pending to started [VERBOSE2:trace_session.cc(152)] tracee #1 {424992:cpuperf_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 {425119:ktrace_provider} [VERBOSE1:trace_session.cc(56)] Adding provider #2 {425119:ktrace_provider}, buffer size 4MB [VERBOSE2:tracee.cc(133)] #2 {425119:ktrace_provider}: Transitioning from ready to start pending [VERBOSE2:trace_session.cc(253)] Transitioning from started to started [INFO:record.cc(815)] Spawning: /pkg/bin/run_awhile 60 [VERBOSE2:tracee.cc(147)] #2 {425119:ktrace_provider}: pending=0x3 [VERBOSE2:tracee.cc(133)] #2 {425119:ktrace_provider}: Transitioning from start pending to started [VERBOSE2:trace_session.cc(152)] tracee #1 {424992:cpuperf_provider} ready [VERBOSE2:trace_session.cc(152)] tracee #2 {425119:ktrace_provider} ready [VERBOSE2:trace_session.cc(158)] All providers reporting started Starting trace; will stop in 1 seconds... Stopping trace... [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 {424992:cpuperf_provider}: Transitioning from started to stopping [VERBOSE2:tracee.cc(133)] #2 {425119:ktrace_provider}: Transitioning from started to stopping [VERBOSE2:tracee.cc(147)] #1 {424992:cpuperf_provider}: pending=0x4 [VERBOSE2:tracee.cc(133)] #1 {424992:cpuperf_provider}: Transitioning from stopping to stopped [VERBOSE2:tracee.cc(579)] #1 {424992:cpuperf_provider}: writing provider info record [VERBOSE2:tracee.cc(271)] #1 {424992:cpuperf_provider}: Writing chunk for rolling buffer 0: vmo offset 0x80, size 0x3fff80, by-record [VERBOSE2:tracee.cc(147)] #2 {425119:ktrace_provider}: pending=0x4 [VERBOSE2:tracee.cc(133)] #2 {425119:ktrace_provider}: Transitioning from stopping to stopped [VERBOSE2:tracee.cc(579)] #2 {425119:ktrace_provider}: writing provider info record [VERBOSE2:tracee.cc(271)] #2 {425119:ktrace_provider}: Writing chunk for rolling buffer 0: vmo offset 0x80, size 0x3fff80, by-record [INFO:tracee.cc(435)] #2 {425119:ktrace_provider} 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: 0x2ad28,0x0, size 0x3fff80 [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 Trace file written to /data/trace.json [INFO:detach_tests.cc(38)] Trace exited, checking for helper presence [ OK ] DetachTest.SpawnedAppNotDetached (1535 ms) [ RUN ] DetachTest.SpawnedAppDetached [INFO:trace_manager.cc(96)] Starting trace with 4 MB buffers, buffering mode=oneshot [VERBOSE1:trace_session.cc(56)] Adding provider #1 {424992:cpuperf_provider}, buffer size 4MB [VERBOSE2:tracee.cc(133)] #1 {424992:cpuperf_provider}: Transitioning from ready to start pending [VERBOSE2:trace_session.cc(253)] Transitioning from ready to started [VERBOSE1:trace_session.cc(56)] Adding provider #2 {425119:ktrace_provider}, buffer size 4MB [VERBOSE2:tracee.cc(133)] #2 {425119:ktrace_provider}: Transitioning from ready to start pending [VERBOSE2:trace_session.cc(253)] Transitioning from started to started [VERBOSE2:tracee.cc(147)] #1 {424992:cpuperf_provider}: pending=0x3 [VERBOSE2:tracee.cc(133)] #1 {424992:cpuperf_provider}: Transitioning from start pending to started [VERBOSE2:trace_session.cc(152)] tracee #1 {424992:cpuperf_provider} ready [VERBOSE2:trace_session.cc(152)] tracee #2 {425119:ktrace_provider} not ready [VERBOSE2:tracee.cc(147)] #2 {425119:ktrace_provider}: pending=0x3 [VERBOSE2:tracee.cc(133)] #2 {425119:ktrace_provider}: Transitioning from start pending to started [VERBOSE2:trace_session.cc(152)] tracee #1 {424992:cpuperf_provider} ready [VERBOSE2:trace_session.cc(152)] tracee #2 {425119:ktrace_provider} ready [VERBOSE2:trace_session.cc(158)] All providers reporting started [VERBOSE1:trace_session.cc(109)] Marking session as having started [INFO:record.cc(815)] Spawning: /pkg/bin/run_awhile 60 Starting trace; will stop in 1 seconds... Stopping trace... [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 {424992:cpuperf_provider}: Transitioning from started to stopping [VERBOSE2:tracee.cc(133)] #2 {425119:ktrace_provider}: Transitioning from started to stopping [VERBOSE2:tracee.cc(147)] #1 {424992:cpuperf_provider}: pending=0x4 [VERBOSE2:tracee.cc(133)] #1 {424992:cpuperf_provider}: Transitioning from stopping to stopped [VERBOSE2:tracee.cc(579)] #1 {424992:cpuperf_provider}: writing provider info record [VERBOSE2:tracee.cc(271)] #1 {424992:cpuperf_provider}: Writing chunk for rolling buffer 0: vmo offset 0x80, size 0x3fff80, by-record [VERBOSE2:tracee.cc(147)] #2 {425119:ktrace_provider}: pending=0x4 [VERBOSE2:tracee.cc(133)] #2 {425119:ktrace_provider}: Transitioning from stopping to stopped [VERBOSE2:tracee.cc(579)] #2 {425119:ktrace_provider}: writing provider info record [VERBOSE2:tracee.cc(271)] #2 {425119:ktrace_provider}: Writing chunk for rolling buffer 0: vmo offset 0x80, size 0x3fff80, by-record [INFO:tracee.cc(435)] #2 {425119:ktrace_provider} 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: 0x843f8,0x0, size 0x3fff80 [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 Trace file written to /data/trace.json [INFO:detach_tests.cc(65)] Trace exited, checking for helper presence [INFO:detach_tests.cc(76)] Process 425738 present [ OK ] DetachTest.SpawnedAppDetached (1491 ms) [----------] 2 tests from DetachTest (3026 ms total) [----------] Global test environment tear-down [==========] 2 tests from 1 test suite ran. (3026 ms total) [ PASSED ] 2 tests.