[lttng-dev] User space tracing

Mon Sep 10 10:50:31 EDT 2012

Hi,

In your example, you are running the tracer as root (with "sudo") but
your application is run by your own user. Somebody correct me if I'm
wrong, but I assume that in a case like this the root tracer will not
see the other user's applications.

Could you try running the lttng commands without sudo, so that it
creates a session for your user only.

Cheers,
Alexandre

On 12-09-10 03:32 AM, Per Nilsson wrote:
> Hi,
> I am trying to get started with userspace tracing with LTTng, but I am having a hard time to get it to work.
> I'm using Ubunto 11.04, with kernel version: 2.6.38-8-generic.
>
> I downloaded and compiled the following lttng software:
>
> Userspace-rcu-0.7.4
> Lttng-ust-2.0.5
> Lttng-tools-2-0.4
> Babeltrace-1.0.0-rc5
>
> Maybe some one can tell me what is wrong.
>
> // This is command line command I use to start the trace session.
>
> per at per-VirtualBox:~$ sudo lttng create foo
> [sudo] password for per:
> Session foo created.
> Traces will be written in /home/per/lttng-traces/foo-20120905-135905
> per at per-VirtualBox:~$ sudo lttng enable-event -a -u
> All UST events are enabled in channel channel0
> per at per-VirtualBox:~$ sudo lttng start
> Tracing started for session foo
> per at per-VirtualBox:~$ sudo lttng stop
> Tracing stopped for session foo
> per at per-VirtualBox:~$ sudo ls /home/per/lttng-traces/foo-20120905-135905/ust
> per at per-VirtualBox:~$ sudo babeltrace /home/per/lttng-traces/foo-20120905-135905/ust
> [error] Cannot open any trace for reading.
>
> [error] opening trace "/home/per/lttng-traces/foo-20120905-135905/ust" for reading.
>
> [error] none of the specified trace paths could be opened.
>
> // This is the traces from the lttng-sessiond
>
> per at per-VirtualBox:~$ sudo lttng-sessiond --verbose --verbose-consumer
> DEBUG3: Creating LTTng run directory: /var/run/lttng [in create_lttng_rundir() at main.c:4317]
> DEBUG1: Client socket path /var/run/lttng/client-lttng-sessiond [in main() at main.c:4609]
> DEBUG1: Application socket path /var/run/lttng/apps-lttng-sessiond [in main() at main.c:4610]
> DEBUG1: LTTng run directory path: /var/run/lttng [in main() at main.c:4611]
> DEBUG3: Created hashtable size 4 at 0x1d4e0a0 of type 1 [in lttng_ht_new() at hashtable.c:96]
> DEBUG3: Created hashtable size 4 at 0x1d4e340 of type 1 [in lttng_ht_new() at hashtable.c:96]
> FATAL: Module lttng_tracer not found.
> Error: Unable to load module lttng-tracer
> DEBUG1: Failed to open /proc/lttng [in init_kernel_tracer() at main.c:1871]
> Error: Unable to remove module lttng-tracer
> Warning: No kernel tracer available
> DEBUG1: Signal handler set for SIGTERM, SIGPIPE and SIGINT [in set_signal_handler() at main.c:4451]
> Warning: No tracing group detected
> DEBUG1: epoll set max size is 100188 [in compat_epoll_set_max_size() at compat-epoll.c:224]
> DEBUG1: Thread manage kernel started [in thread_manage_kernel() at main.c:876]
> DEBUG1: Updating kernel poll set [in update_kernel_poll() at main.c:748]
> DEBUG1: Thread kernel polling on 2 fds [in thread_manage_kernel() at main.c:905]
> DEBUG1: [thread] Manage application started [in thread_manage_apps() at main.c:1179]
> DEBUG1: Apps thread polling on 2 fds [in thread_manage_apps() at main.c:1200]
> DEBUG1: [thread] Manage application registration started [in thread_registration_apps() at main.c:1392]
> DEBUG1: Notifying applications of session daemon state: 1 [in notify_ust_apps() at main.c:687]
> DEBUG1: Got the wait shm fd 17 [in get_wait_shm() at shm.c:117]
> DEBUG1: Futex wait update active 1 [in futex_wait_update() at futex.c:62]
> DEBUG1: Accepting application registration [in thread_registration_apps() at main.c:1423]
> DEBUG1: [thread] Dispatch UST command started [in thread_dispatch_ust_registration() at main.c:1324]
> DEBUG1: Futex n to 1 prepare done [in futex_nto1_prepare() at futex.c:73]
> DEBUG1: Woken up but nothing in the UST command queue [in thread_dispatch_ust_registration() at main.c:1334]
> DEBUG1: [thread] Manage client started [in thread_manage_clients() at main.c:3794]
> DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3826]
> DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3863]
> DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3898]
> DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3902]
> DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:534]
> DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3826]
> DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3863]
> DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3898]
> DEBUG1: Processing client command 8 [in process_client_msg() at main.c:3309]
> DEBUG3: mkdir() recursive /home/per/lttng-traces/foo-20120905-135905 with mode 504 for uid 0 and gid 0 [in run_as_mkdir_recursive() at runas.c:339]
> DEBUG1: Using run_as_clone [in run_as() at runas.c:323]
> DEBUG1: Tracing session foo created in /home/per/lttng-traces/foo-20120905-135905 with ID 1 by UID 0 GID 0 [in session_create() at session.c:232]
> DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3936]
> DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:534]
> DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3826]
> DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3863]
> DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3898]
> DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3902]
> DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:534]
> DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3826]
> DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3863]
> DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3898]
> DEBUG1: Processing client command 6 [in process_client_msg() at main.c:3309]
> DEBUG1: Getting session foo by name [in process_client_msg() at main.c:3364]
> DEBUG1: Creating UST session [in create_ust_session() at main.c:1965]
> DEBUG3: Created hashtable size 4 at 0x1d55840 of type 1 [in lttng_ht_new() at hashtable.c:96]
> DEBUG3: Created hashtable size 4 at 0x1d55b00 of type 1 [in lttng_ht_new() at hashtable.c:96]
> DEBUG3: Created hashtable size 4 at 0x1d55dc0 of type 0 [in lttng_ht_new() at hashtable.c:96]
> DEBUG3: mkdir() recursive /home/per/lttng-traces/foo-20120905-135905/ust with mode 504 for uid 0 and gid 0 [in run_as_mkdir_recursive() at runas.c:339]
> DEBUG1: Using run_as_clone [in run_as() at runas.c:323]
> DEBUG1: Spawning consumerd [in spawn_consumerd() at main.c:1659]
> DEBUG1: [thread] Manage consumer started [in thread_manage_consumer() at main.c:982]
> DEBUG1: Using 64-bit UST consumer at: /usr/local/lib/lttng/libexec/lttng-consumerd [in spawn_consumerd() at main.c:1733]
> DEBUG3: Created hashtable size 4 at 0x247d030 of type 1 [in lttng_ht_new() at hashtable.c:96]
> DEBUG3: Created hashtable size 4 at 0x247d2f0 of type 1 [in lttng_ht_new() at hashtable.c:96]
> DEBUG1: Connecting to error socket /var/run/lttng/ustconsumerd64/error [in main() at lttng-consumerd.c:349]
> DEBUG1: Updating poll fd array [in consumer_update_poll_array() at consumer.c:521]
> DEBUG1: polling on 1 fd [in lttng_consumer_thread_poll_fds() at consumer.c:1013]
> DEBUG1: Creating command socket /var/run/lttng/ustconsumerd64/command [in lttng_consumer_thread_receive_fds() at consumer.c:1160]
> DEBUG1: Sending ready command to lttng-sessiond [in lttng_consumer_thread_receive_fds() at consumer.c:1173]
> DEBUG1: consumer command socket ready [in thread_manage_consumer() at main.c:1062]
> DEBUG3: Created hashtable size 4 at 0x1d57720 of type 0 [in lttng_ht_new() at hashtable.c:96]
> DEBUG3: Created hashtable size 4 at 0x1d579e0 of type 1 [in lttng_ht_new() at hashtable.c:96]
> DEBUG3: Created hashtable size 4 at 0x1d57f00 of type 1 [in lttng_ht_new() at hashtable.c:96]
> DEBUG1: UST app creating event * for all apps for session id 1 [in ust_app_create_event_glb() at ust-app.c:1916]
> DEBUG1: Event UST * created in channel channel0 [in event_ust_enable_tracepoint() at event.c:486]
> DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3936]
> DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:534]
> DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3826]
> DEBUG1: Connection on client_socket [in lttng_consumer_thread_receive_fds() at consumer.c:1196]
> DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3863]
> DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3898]
> DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3902]
> DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:534]
> DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3826]
> DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3863]
> DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3898]
> DEBUG1: Processing client command 16 [in process_client_msg() at main.c:3309]
> DEBUG1: Getting session foo by name [in process_client_msg() at main.c:3364]
> DEBUG1: Starting all UST traces [in ust_app_start_trace_all() at ust-app.c:2207]
> DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3936]
> DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:534]
> DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3826]
> DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3863]
> DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3898]
> DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3902]
> DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:534]
> DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3826]
> DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3863]
> DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3898]
> DEBUG1: Processing client command 17 [in process_client_msg() at main.c:3309]
> DEBUG1: Getting session foo by name [in process_client_msg() at main.c:3364]
> DEBUG1: Stopping all UST traces [in ust_app_stop_trace_all() at ust-app.c:2233]
> DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3936]
> DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:534]
> DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3826]
>
> // this is the traces from the small test application
>
> per at per-VirtualBox:/usr/local/src/lttng-ust-2.0.5/doc/examples/gen-tp$ export LTTNG_UST_DEBUG=1
> per at per-VirtualBox:/usr/local/src/lttng-ust-2.0.5/doc/examples/gen-tp$ ./sample liblttng_ust_tracepoint[1748/1748]: just registered a tracepoints section from 0x7f431694fc38 and having 1 tracepoints (in tracepoint_register_lib() at tracepoint.c:641)
> liblttng_ust_tracepoint[1748/1748]: registered tracepoint: lttng_ust:metadata (in tracepoint_register_lib() at tracepoint.c:646)
> libust[1748/1748]: LTT : ltt ring buffer client init
>  (in ltt_ring_buffer_metadata_client_init() at ltt-ring-buffer-metadata-client.h:334)
> libust[1748/1748]: LTT : ltt ring buffer client init
>  (in ltt_ring_buffer_client_overwrite_init() at ltt-ring-buffer-client.h:584)
> libust[1748/1748]: LTT : ltt ring buffer client init
>  (in ltt_ring_buffer_client_discard_init() at ltt-ring-buffer-client.h:584)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Waiting for local apps sessiond (in wait_for_sessiond() at lttng-ust-comm.c:638)
> libust[1748/1750]: Linux kernels 2.6.33 to 3.0 (with the exception of stable versions) do not support FUTEX_WAKE on read-only memory mappings correctly. Please upgrade your kernel (fix is commit 9ea71503a8ed9184d2d0b8ccc4d269d05f7940ae in Linux kernel mainline). LTTng-UST will use polling mode fallback. (in wait_for_sessiond() at lttng-ust-comm.c:651)
> libust[1748/1750]: Error: futex: Bad address (in wait_for_sessiond() at lttng-ust-comm.c:653)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1748]: just registered probe sample_tracepoint containing 1 events (in ltt_probe_register() at ltt-probes.c:109)
> libust[1748/1748]: Registered event probe "sample_tracepoint:message" with signature "char *, text" (in ltt_probe_register() at ltt-probes.c:118)
> liblttng_ust_tracepoint[1748/1748]: just registered a tracepoints section from 0x602138 and having 1 tracepoints (in tracepoint_register_lib() at tracepoint.c:641)
> liblttng_ust_tracepoint[1748/1748]: registered tracepoint: sample_tracepoint:message (in tracepoint_register_lib() at tracepoint.c:646)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1749]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
> libust[1748/1750]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:716)
>
> BR
> /Per Nilsson
>
>
>
>
>
>
> _______________________________________________
> lttng-dev mailing list
> lttng-dev at lists.lttng.org
> http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.lttng.org/pipermail/lttng-dev/attachments/20120910/85a612ba/attachment-0001.html>