Project

General

Profile

Bug #324 » lttng_not_tracing_after_reboot_PL3_DemoApp_Sep7.txt

Jesus Garcia, 09/09/2012 10:55 PM

 
PL-3:~ # date
Fri Sep 7 16:31:24 EDT 2012
PL-3:~ # ps -eaf | egrep "trace|lttng|TestApp|demo"
root 7288 1 0 14:41 ? 00:00:00 /opt/trace_ea/bin/TraceEa
root 7306 7288 0 14:41 ? 00:00:00 /opt/trace_ea/bin/TraceEa
root 8139 1 0 14:46 ? 00:00:00 /opt/trace/sbin/trace_p
root 15764 1 0 16:08 ? 00:00:00 lttng-sessiond -vvv
root 16442 15764 0 16:13 ? 00:00:00 lttng-consumerd --quiet -u --consumerd-cmd-sock /var/run/lttng/ustconsumerd64/command --consumerd-err-sock /var/run/lttng/ustconsumerd64/error
root 17912 17860 0 16:31 pts/0 00:00:00 egrep trace|lttng|TestApp|demo
PL-3:~ #
PL-3:~ # lttng -h
LTTng Trace Control 2.0.4 - Annedd'ale

usage: lttng [OPTIONS] <COMMAND>

Options:
-h, --help Show this help
--list-options Simple listing of lttng options
--list-commands Simple listing of lttng commands
-v, --verbose Increase verbosity
-q, --quiet Quiet mode
-g, --group NAME Unix tracing group name. (default: tracing)
-n, --no-sessiond Don't spawn a session daemon
--sessiond-path PATH Session daemon full path

Commands:
add-context Add context to event and/or channel
calibrate Quantify LTTng overhead
create Create tracing session
destroy Tear down tracing session
enable-channel Enable tracing channel
enable-event Enable tracing event
disable-channel Disable tracing channel
disable-event Disable tracing event
list List possible tracing options
set-session Set current session name
start Start tracing
stop Stop tracing
version Show version information
view Start trace viewer

Each command also has its own -h, --help option.

Please see the lttng(1) man page for full documentation.
See http://lttng.org for updates, bug reports and news.
PL-3:~ #
PL-3:~ #
PL-3:~ # lttng list
Currently no available tracing session
PL-3:~ #
PL-3:~ # lttng list -u
UST events:
-------------
None

PL-3:~ #
PL-3:~ # lttng create ses1
Session ses1 created.
Traces will be written in /root/lttng-traces/ses1-20120907-163202
PL-3:~ #
PL-3:~ #
PL-3:~ # lttng enable-event ust_tests_demo* -u
UST event ust_tests_demo* created in channel channel0
PL-3:~ #
PL-3:~ #
PL-3:~ # lttng list
Available tracing sessions:
1) ses1 (/root/lttng-traces/ses1-20120907-163202) [inactive]

Use lttng list <session_name> for more details
PL-3:~ #
PL-3:~ #
PL-3:~ # cd /cluster/temp/garc
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc # ll
total 972
-rwxr-xr-x 1 root root 25094 Sep 6 12:04 demo
-rwxr-xr-x 1 root root 119 Sep 6 12:06 demo-trace
-rwxr-xr-x 1 root root 43499 Sep 6 12:04 liblttng-ust-provider-ust-tests-demo.so
-rwxr-xr-x 1 root root 24692 Sep 6 12:04 liblttng-ust-provider-ust-tests-demo3.so
-rw-r--r-- 1 root root 883973 Sep 7 15:49 lttngoutput.txt
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc # LTTNG_UST_DEBUG=1 ./demo-trace 80 &
[1] 18002
PL-3:/cluster/temp/garc # liblttng_ust_tracepoint[18003/18003]: just registered a tracepoints section from 0x7f15a6f11bf8 and having 1 tracepoints (in tracepoint_register_lib() at tracepoint.c:639)
liblttng_ust_tracepoint[18003/18003]: registered tracepoint: lttng_ust:metadata (in tracepoint_register_lib() at tracepoint.c:644)
libust[18003/18003]: just registered probe lttng_ust containing 1 events (in ltt_probe_register() at ltt-probes.c:109)
libust[18003/18003]: Registered event probe "lttng_ust:metadata" with signature "const char *, str" (in ltt_probe_register() at ltt-probes.c:118)
libust[18003/18003]: LTT : ltt ring buffer client init
(in ltt_ring_buffer_metadata_client_init() at ltt-ring-buffer-metadata-client.h:334)
libust[18003/18003]: LTT : ltt ring buffer client init
(in ltt_ring_buffer_client_overwrite_init() at ltt-ring-buffer-client.h:584)
libust[18003/18003]: LTT : ltt ring buffer client init
(in ltt_ring_buffer_client_discard_init() at ltt-ring-buffer-client.h:584)
libust[18003/18005]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
libust[18003/18005]: Waiting for local apps sessiond (in wait_for_sessiond() at lttng-ust-comm.c:638)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18003]: just registered probe ust_tests_demo3 containing 1 events (in ltt_probe_register() at ltt-probes.c:109)
libust[18003/18003]: Registered event probe "ust_tests_demo3:done" with signature "int, value" (in ltt_probe_register() at ltt-probes.c:118)
liblttng_ust_tracepoint[18003/18003]: Registering probe to tracepoint ust_tests_demo3:done (in __tracepoint_probe_register() at tracepoint.c:427)
libust[18003/18003]: just registered probe ust_tests_demo2 containing 1 events (in ltt_probe_register() at ltt-probes.c:109)
libust[18003/18003]: Registered event probe "ust_tests_demo2:loop" with signature "int, anint, int, netint, long *, values, char *, text, size_t, textlen, double, doublearg, float, floatarg" (in ltt_probe_register() at ltt-probes.c:118)
liblttng_ust_tracepoint[18003/18003]: Registering probe to tracepoint ust_tests_demo2:loop (in __tracepoint_probe_register() at tracepoint.c:427)
libust[18003/18003]: just registered probe ust_tests_demo containing 2 events (in ltt_probe_register() at ltt-probes.c:109)
libust[18003/18003]: Registered event probe "ust_tests_demo:starting" with signature "int, value" (in ltt_probe_register() at ltt-probes.c:118)
liblttng_ust_tracepoint[18003/18003]: Registering probe to tracepoint ust_tests_demo:starting (in __tracepoint_probe_register() at tracepoint.c:427)
libust[18003/18003]: Registered event probe "ust_tests_demo:done" with signature "int, value" (in ltt_probe_register() at ltt-probes.c:118)
liblttng_ust_tracepoint[18003/18003]: Registering probe to tracepoint ust_tests_demo:done (in __tracepoint_probe_register() at tracepoint.c:427)
liblttng_ust_tracepoint[18003/18003]: just registered a tracepoints section from 0x602158 and having 4 tracepoints (in tracepoint_register_lib() at tracepoint.c:639)
liblttng_ust_tracepoint[18003/18003]: registered tracepoint: ust_tests_demo3:done (in tracepoint_register_lib() at tracepoint.c:644)
liblttng_ust_tracepoint[18003/18003]: registered tracepoint: ust_tests_demo2:loop (in tracepoint_register_lib() at tracepoint.c:644)
liblttng_ust_tracepoint[18003/18003]: registered tracepoint: ust_tests_demo:done (in tracepoint_register_lib() at tracepoint.c:644)
liblttng_ust_tracepoint[18003/18003]: registered tracepoint: ust_tests_demo:starting (in tracepoint_register_lib() at tracepoint.c:644)
Demo program starting.

PL-3:/cluster/temp/garc # lttng list -u
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
UST events:
-------------

PID: 18003 - Name: ./demo
ust_tests_demo2:loop (loglevel: TRACE_WARNING (4)) (type: tracepoint)
ust_tests_demo:done (loglevel: TRACE_CRIT (2)) (type: tracepoint)
ust_tests_demo:starting (loglevel: TRACE_CRIT (2)) (type: tracepoint)
ust_tests_demo3:done (loglevel: TRACE_WARNING (4)) (type: tracepoint)

PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc # lttng start
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
liblttng_ust_tracepoint[18003/18004]: Registering probe to tracepoint lttng_ust:metadata (in __tracepoint_probe_register() at tracepoint.c:427)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
Tracing started for session ses1
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc # lttng list
Available tracing sessions:
1) ses1 (/root/lttng-traces/ses1-20120907-163202) [active]

Use lttng list <session_name> for more details
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc # lttng list -u
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
libust[18003/18004]: message received
(in ust_listener_thread() at lttng-ust-comm.c:783)
libust[18003/18004]: message successfully sent (in send_reply() at lttng-ust-comm.c:217)
UST events:
-------------

PID: 18003 - Name: ./demo
ust_tests_demo2:loop (loglevel: TRACE_WARNING (4)) (type: tracepoint)
ust_tests_demo:done (loglevel: TRACE_CRIT (2)) (type: tracepoint)
ust_tests_demo:starting (loglevel: TRACE_CRIT (2)) (type: tracepoint)
ust_tests_demo3:done (loglevel: TRACE_WARNING (4)) (type: tracepoint)

PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc # ps -eaf | egrep "trace|lttng|TestApp|demo"
root 7288 1 0 14:41 ? 00:00:00 /opt/trace_ea/bin/TraceEa
root 7306 7288 0 14:41 ? 00:00:00 /opt/trace_ea/bin/TraceEa
root 8139 1 0 14:46 ? 00:00:00 /opt/trace/sbin/trace_p
root 15764 1 0 16:08 ? 00:00:00 lttng-sessiond -vvv
root 16442 15764 0 16:13 ? 00:00:00 lttng-consumerd --quiet -u --consumerd-cmd-sock /var/run/lttng/ustconsumerd64/command --consumerd-err-sock /var/run/lttng/ustconsumerd64/error
root 18002 17860 0 16:32 pts/0 00:00:00 /bin/sh ./demo-trace 80
root 18003 18002 0 16:32 pts/0 00:00:00 ./demo 80
root 18079 17860 0 16:34 pts/0 00:00:00 egrep trace|lttng|TestApp|demo
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc # Tracing... done.
liblttng_ust_tracepoint[18003/18003]: just unregistered a tracepoints section from 0x602158 (in tracepoint_unregister_lib() at tracepoint.c:679)
libust[18003/18003]: just unregistered probe ust_tests_demo (in ltt_probe_unregister() at ltt-probes.c:131)
libust[18003/18003]: just unregistered probe ust_tests_demo2 (in ltt_probe_unregister() at ltt-probes.c:131)
libust[18003/18003]: just unregistered probe ust_tests_demo3 (in ltt_probe_unregister() at ltt-probes.c:131)
liblttng_ust_tracepoint[18003/18003]: Un-registering probe from tracepoint lttng_ust:metadata (in __tracepoint_probe_unregister() at tracepoint.c:470)
liblttng_ust_tracepoint[18003/18003]: Un-registering probe from tracepoint ust_tests_demo:done (in __tracepoint_probe_unregister() at tracepoint.c:470)
liblttng_ust_tracepoint[18003/18003]: Un-registering probe from tracepoint ust_tests_demo:starting (in __tracepoint_probe_unregister() at tracepoint.c:470)
liblttng_ust_tracepoint[18003/18003]: Un-registering probe from tracepoint ust_tests_demo2:loop (in __tracepoint_probe_unregister() at tracepoint.c:470)
liblttng_ust_tracepoint[18003/18003]: Un-registering probe from tracepoint ust_tests_demo3:done (in __tracepoint_probe_unregister() at tracepoint.c:470)
libust[18003/18003]: LTT : ltt ring buffer client exit
(in ltt_ring_buffer_client_discard_exit() at ltt-ring-buffer-client.h:590)
libust[18003/18003]: LTT : ltt ring buffer client exit
(in ltt_ring_buffer_client_overwrite_exit() at ltt-ring-buffer-client.h:590)
libust[18003/18003]: LTT : ltt ring buffer client exit
(in ltt_ring_buffer_metadata_client_exit() at ltt-ring-buffer-metadata-client.h:340)
libust[18003/18003]: just unregistered probe lttng_ust (in ltt_probe_unregister() at ltt-probes.c:131)
liblttng_ust_tracepoint[18003/18003]: just unregistered a tracepoints section from 0x7f15a6f11bf8 (in tracepoint_unregister_lib() at tracepoint.c:679)

[1]+ Done LTTNG_UST_DEBUG=1 ./demo-trace 80
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc # ps -eaf | egrep "trace|lttng|TestApp|demo"
root 7288 1 0 14:41 ? 00:00:00 /opt/trace_ea/bin/TraceEa
root 7306 7288 0 14:41 ? 00:00:00 /opt/trace_ea/bin/TraceEa
root 8139 1 0 14:46 ? 00:00:00 /opt/trace/sbin/trace_p
root 15764 1 0 16:08 ? 00:00:00 lttng-sessiond -vvv
root 16442 15764 0 16:13 ? 00:00:00 lttng-consumerd --quiet -u --consumerd-cmd-sock /var/run/lttng/ustconsumerd64/command --consumerd-err-sock /var/run/lttng/ustconsumerd64/error
root 18103 17860 0 16:34 pts/0 00:00:00 egrep trace|lttng|TestApp|demo
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc # lttng stop
Tracing stopped for session ses1
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc # lttng list
Available tracing sessions:
1) ses1 (/root/lttng-traces/ses1-20120907-163202) [inactive]

Use lttng list <session_name> for more details
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc # lttng list -u
UST events:
-------------
None

PL-3:/cluster/temp/garc #
PL-3:/cluster/temp/garc # cd /root/lttng-traces/
PL-3:~/lttng-traces # ll
total 0
drwxrwx--- 3 root root 60 Sep 7 16:32 ses1-20120907-163202
PL-3:~/lttng-traces # ll ses1-20120907-163202
total 0
drwxrwx--- 3 root root 60 Sep 7 16:33 ust
PL-3:~/lttng-traces # ll ses1-20120907-163202/ust/
total 0
drwxrwx--- 2 root root 40 Sep 7 16:33 demo-18003-20120907-163251
PL-3:~/lttng-traces # ll ses1-20120907-163202/ust/demo-18003-20120907-163251/
total 0
PL-3:~/lttng-traces #
PL-3:~/lttng-traces #
PL-3:~/lttng-traces # date
Fri Sep 7 16:35:36 EDT 2012
PL-3:~/lttng-traces #
(4-4/5)