[lttng-dev] Lttng trace showing empty result while doing lttng view

Jonathan Rajotte-Julien jonathan.rajotte-julien at efficios.com
Tue Apr 4 21:20:30 UTC 2017 

On Tue, Apr 04, 2017 at 10:12:35AM +0530, abhishekk at uurmi.com wrote:
> Hi,
> > Not sure I understand which version of lttng-modules you are
> currently using.
>  Sorry that was typo, I meant version 2.10 of lttng kernel modules and
> version 2.5 of lttng tools. Please find the modinfo result below.

If there is no peculiar reasons to use lttng-tools 2.5 with a HEAD of the
lttng-modules master branch project, I recommend that you start fresh and
reinstall the following from source: userspace-rcu v0.9.3, lttng-modules v2.9.1, lttng-ust v2.9.0,
lttng-tools v2.9.4.

Make sure to remove previously installed packages and all libs and header
installed related to lttng.

Could you provide the content of config.status (generated after ./configure) for
userspace-rcu, lttng-ust, lttng-tool. So we can address the compilation issue
from the parallel thread [1].

Cheers

[1] https://lists.lttng.org/pipermail/lttng-dev/2017-April/026989.html

> pi at raspberrypi-BKe28DDGW7:~ $ modinfo lttng-tracer
> filename:       /lib/modules/4.4.44-v7+/extra/lttng-tracer.ko
> version:        2.10.0-pre
> description:    LTTng Events
> author:         Mathieu Desnoyers 
> license:        GPL and additional rights
> srcversion:     93F12D7CDB1873B93DF8BE4
> depends:       
> lttng-lib-ring-buffer,lttng-kretprobes,lttng-clock,lttng-kprobes,lttng-statedump,lttng-ftrace
> vermagic:       4.4.44-v7+ SMP mod_unload modversions ARMv7
>  
>  >Can you share with us the result of 'modinfo lttng-tracer'?
>  >Could you pastebinit (or equivalent) the log produced by the
> lttng-sessiond in
>  >verbose mode (lttng-sessiond -vvv).
> please find below.
> PI at RASPBERRYPI-BKE28DDGW7:~ $ SUDO LTTNG-SESSIOND -VVV
> DEBUG3 - 04:41:38.701706 [1086/1086]: Creating LTTng run directory:
> /var/run/lttng (in create_lttng_rundir() at main.c:4690)
> DEBUG2 - 04:41:38.701861 [1086/1086]: Kernel consumer err path:
> /var/run/lttng/kconsumerd/error (in main() at main.c:5078)
> DEBUG2 - 04:41:38.701880 [1086/1086]: Kernel consumer cmd path:
> /var/run/lttng/kconsumerd/command (in main() at main.c:5080)
> DEBUG1 - 04:41:38.701933 [1086/1086]: Client socket path
> /var/run/lttng/client-lttng-sessiond (in main() at main.c:5138)
> DEBUG1 - 04:41:38.701951 [1086/1086]: Application socket path
> /var/run/lttng/lttng-ust-sock-5 (in main() at main.c:5139)
> DEBUG1 - 04:41:38.701966 [1086/1086]: Application wait path
> /lttng-ust-wait-5 (in main() at main.c:5140)
> DEBUG1 - 04:41:38.701981 [1086/1086]: LTTng run directory path:
> /var/run/lttng (in main() at main.c:5141)
> DEBUG2 - 04:41:38.702014 [1086/1086]: UST consumer 32 bits err path:
> /var/run/lttng/ustconsumerd32/error (in main() at main.c:5150)
> DEBUG2 - 04:41:38.702030 [1086/1086]: UST consumer 32 bits cmd path:
> /var/run/lttng/ustconsumerd32/command (in main() at main.c:5152)
> DEBUG2 - 04:41:38.702064 [1086/1086]: UST consumer 64 bits err path:
> /var/run/lttng/ustconsumerd64/error (in main() at main.c:5161)
> DEBUG2 - 04:41:38.702079 [1086/1086]: UST consumer 64 bits cmd path:
> /var/run/lttng/ustconsumerd64/command (in main() at main.c:5163)
> DEBUG3 - 04:41:38.702338 [1086/1086]: Created hashtable size 4 at
> 0x550de0a0 of type 1 (in lttng_ht_new() at hashtable.c:127)
> DEBUG3 - 04:41:38.702363 [1086/1086]: Created hashtable size 4 at
> 0x550de320 of type 1 (in lttng_ht_new() at hashtable.c:127)
> DEBUG3 - 04:41:38.702383 [1086/1086]: Created hashtable size 4 at
> 0x550de500 of type 1 (in lttng_ht_new() at hashtable.c:127)
> DEBUG3 - 04:41:38.702640 [1086/1086]: Created hashtable size 4 at
> 0x550de708 of type 1 (in lttng_ht_new() at hashtable.c:127)
> DEBUG2 - 04:41:38.702661 [1086/1086]: Creating consumer directory:
> /var/run/lttng/kconsumerd (in set_consumer_sockets() at main.c:4732)
> DEBUG1 - 04:41:38.755859 [1086/1086]: Modprobe successfully
> lttng-tracer (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.761092 [1086/1086]: Modprobe successfully
> lttng-lib-ring-buffer (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.771345 [1086/1086]: Modprobe successfully
> lttng-ring-buffer-client-discard (in modprobe_lttng() at
> modprobe.c:190)
> DEBUG1 - 04:41:38.781390 [1086/1086]: Modprobe successfully
> lttng-ring-buffer-client-overwrite (in modprobe_lttng() at
> modprobe.c:190)
> DEBUG1 - 04:41:38.791401 [1086/1086]: Modprobe successfully
> lttng-ring-buffer-metadata-client (in modprobe_lttng() at
> modprobe.c:190)
> DEBUG1 - 04:41:38.801943 [1086/1086]: Modprobe successfully
> lttng-ring-buffer-client-mmap-discard (in modprobe_lttng() at
> modprobe.c:190)
> DEBUG1 - 04:41:38.811961 [1086/1086]: Modprobe successfully
> lttng-ring-buffer-client-mmap-overwrite (in modprobe_lttng() at
> modprobe.c:190)
> DEBUG1 - 04:41:38.821920 [1086/1086]: Modprobe successfully
> lttng-ring-buffer-metadata-mmap-client (in modprobe_lttng() at
> modprobe.c:190)
> DEBUG1 - 04:41:38.829615 [1086/1086]: Modprobe successfully
> lttng-types (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.834756 [1086/1086]: Modprobe successfully
> lttng-ftrace (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.839917 [1086/1086]: Modprobe successfully
> lttng-kprobes (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.845104 [1086/1086]: Modprobe successfully
> lttng-kretprobes (in modprobe_lttng() at modprobe.c:190)
> DEBUG2 - 04:41:38.845198 [1086/1086]: Kernel tracer version validated
> (major version 2) (in kernel_validate_version() at kernel.c:701)
> DEBUG1 - 04:41:38.853708 [1086/1086]: Modprobe successfully
> lttng-probe-asoc (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.862249 [1086/1086]: Modprobe successfully
> lttng-probe-block (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.870416 [1086/1086]: Modprobe successfully
> lttng-probe-btrfs (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.878920 [1086/1086]: Modprobe successfully
> lttng-probe-compaction (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.884270 [1086/1086]: Modprobe successfully
> lttng-probe-ext3 (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.892863 [1086/1086]: Modprobe successfully
> lttng-probe-ext4 (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.901249 [1086/1086]: Modprobe successfully
> lttng-probe-gpio (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.909818 [1086/1086]: Modprobe successfully
> lttng-probe-irq (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.915031 [1086/1086]: Modprobe successfully
> lttng-probe-jbd (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.923627 [1086/1086]: Modprobe successfully
> lttng-probe-jbd2 (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.931509 [1086/1086]: Modprobe successfully
> lttng-probe-kmem (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.936862 [1086/1086]: Modprobe successfully
> lttng-probe-kvm (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.942096 [1086/1086]: Modprobe successfully
> lttng-probe-kvm-x86 (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.947239 [1086/1086]: Modprobe successfully
> lttng-probe-kvm-x86-mmu (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.952458 [1086/1086]: Modprobe successfully
> lttng-probe-lock (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.961008 [1086/1086]: Modprobe successfully
> lttng-probe-module (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.969459 [1086/1086]: Modprobe successfully
> lttng-probe-napi (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.978036 [1086/1086]: Modprobe successfully
> lttng-probe-net (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.986109 [1086/1086]: Modprobe successfully
> lttng-probe-power (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:38.994188 [1086/1086]: Modprobe successfully
> lttng-probe-printk (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.216487 [1086/1086]: Modprobe successfully
> lttng-probe-random (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.107144 [1086/1086]: Modprobe successfully
> lttng-probe-rcu (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.192769 [1086/1086]: Modprobe successfully
> lttng-probe-regmap (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.245820 [1086/1086]: Modprobe successfully
> lttng-probe-regulator (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.297071 [1086/1086]: Modprobe successfully
> lttng-probe-rpm (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.377675 [1086/1086]: Modprobe successfully
> lttng-probe-sched (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.458216 [1086/1086]: Modprobe successfully
> lttng-probe-scsi (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.543405 [1086/1086]: Modprobe successfully
> lttng-probe-signal (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.627664 [1086/1086]: Modprobe successfully
> lttng-probe-skb (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.708022 [1086/1086]: Modprobe successfully
> lttng-probe-sock (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.787606 [1086/1086]: Modprobe successfully
> lttng-probe-statedump (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.868531 [1086/1086]: Modprobe successfully
> lttng-probe-sunrpc (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39953995 [1086/1086]: Modprobe successfully
> lttng-probe-timer (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.104008 [1086/1086]: Modprobe successfully
> lttng-probe-udp (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.112143 [1086/1086]: Modprobe successfully
> lttng-probe-vmscan (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.120207 [1086/1086]: Modprobe successfully
> lttng-probe-v4l2 (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.128172 [1086/1086]: Modprobe successfully
> lttng-probe-workqueue (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.136462 [1086/1086]: Modprobe successfully
> lttng-probe-writeback (in modprobe_lttng() at modprobe.c:190)
> DEBUG1 - 04:41:39.136534 [1086/1086]: Kernel tracer fd 7 (in
> init_kernel_tracer() at main.c:2535)
> DEBUG2 - 04:41:39.136566 [1086/1086]: Creating consumer directory:
> /var/run/lttng/ustconsumerd64 (in set_consumer_sockets() at
> main.c:4732)
> DEBUG2 - 04:41:39.136838 [1086/1086]: Creating consumer directory:
> /var/run/lttng/ustconsumerd32 (in set_consumer_sockets() at
> main.c:4732)
> DEBUG3 - 04:41:39.137038 [1086/1086]: Session daemon client socket 10
> and application socket 11 created (in init_daemon_socket() at
> main.c:4598)
> DEBUG1 - 04:41:39.137166 [1086/1086]: All permissions are set (in
> set_permissions() at main.c:4678)
> DEBUG3 - 04:41:39.137228 [1086/1086]: Created hashtable size 4 at
> 0x550e0048 of type 2 (in lttng_ht_new() at hashtable.c:127)
> DEBUG3 - 04:41:39.137248 [1086/1086]: Global buffer per UID registry
> initialized (in buffer_reg_init_uid_registry() at
> buffer-registry.c:99)
> DEBUG3 - 04:41:39.137267 [1086/1086]: Created hashtable size 4 at
> 0x550e0270 of type 2 (in lttng_ht_new() at hashtable.c:127)
> DEBUG3 - 04:41:39.137283 [1086/1086]: Global buffer per PID registry
> initialized (in buffer_reg_init_pid_registry() at
> buffer-registry.c:220)
> DEBUG1 - 04:41:39.137335 [1086/1086]: epoll set max size is 311472 (in
> compat_epoll_set_max_size() at compat-epoll.c:290)
> DEBUG1 - 04:41:39.137357 [1086/1086]: Command subsystem initialized
> (in cmd_init() at cmd.c:3227)
> DEBUG1 - 04:41:39.137456 [1086/1086]: Pid 1086 written in file
> /var/run/lttng/lttng-sessiond.pid (in utils_create_pid_file() at
> utils.c:467)
> DEBUG1 - 04:41:39.137549 [1086/1086]: Pid 5345 written in file
> /var/run/lttng/jul.port (in utils_create_pid_file() at utils.c:467)
> DEBUG1 - 04:41:39.137620 [1086/1086]: TCP inet operation timeout set
> to 216 sec (in lttcomm_inet_init() at inet.c:529)
> DEBUG1 - 04:41:39.137643 [1086/1086]: Health check time delta in
> seconds set to 236 (in health_init() at health.c:73)
> DEBUG1 - 04:41:39.137844 [1086/1188]: [ht-thread] startup. (in
> thread_ht_cleanup() at ht-cleanup.c:36)
> DEBUG1 - 04:41:39137916 [1086/1190]: [thread] Manage client started
> (in thread_manage_clients() at main.c:3948)
> DEBUG1 - 04:41:39.138137 [1086/1190]: Accepting client command ... (in
> thread_manage_clients() at main.c:3995)
> DEBUG1 - 04:41:39.138253 [1086/1193]: [thread] Manage application
> started (in thread_manage_apps() at main.c:1425)
> DEBUG1 - 04:41:39.138319 [1086/1194]: [ust-thread] Manage application
> notify command (in ust_thread_manage_notify() at ust-thread.c:39)
> DEBUG1 - 04:41:39.138038 [1086/1191]: [thread] Dispatch UST command
> started (in thread_dispatch_ust_registration() at main.c:1711)
> DEBUG1 - 04:41:39.138788 [1086/1191]: Futex n to 1 prepare done (in
> futex_nto1_prepare() at futex.c:75)
> DEBUG1 - 04:41:39.138968 [1086/1191]: Woken up but nothing in the UST
> command queue (in thread_dispatch_ust_registration() at main.c:1734)
> DEBUG1 - 04:41:39.138185 [1086/1192]: [thread] Manage application
> registration started (in thread_registration_apps() at main.c:1935)
> DEBUG3 - 04:41:39.138202 [1086/1188]: [ht-thread] Polling on 2 fds.
> (in thread_ht_cleanup() at ht-cleanup.c:64)
> DEBUG3 - 04:41:39.138566 [1086/1194]: [ust-thread] Manage notify
> polling on 2 fds (in ust_thread_manage_notify() at ust-thread.c:68)
> DEBUG1 - 04:41:39.138586 [1086/1193]: Apps thread polling on 2 fds (in
> thread_manage_apps() at main.c:1455)
> DEBUG1 - 04:41:39.138603 [1086/1195]: [jul-thread] Manage JUL
> application registration. (in jul_thread_manage_registration() at
> jul-thread.c:260)
> DEBUG3 - 04:41:39.139593 [1086/1195]: URI string: tcp://localhost (in
> uri_parse() at uri.c:293)
> DEBUG1 - 04:41:39.139744 [1086/1192]: Notifying applications of
> session daemon state: 1 (in notify_ust_apps() at main.c:756)
> DEBUG1 - 04:41:39.140036 [1086/1192]: Got the wait shm fd 26 (in
> get_wait_shm() at shm.c:115)
> DEBUG1 - 04:41:39.140255 [1086/1192]: Futex wait update active 1 (in
> futex_wait_update() at futex.c:63)
> DEBUG1 - 04:41:39.140442 [1086/1192]: Accepting application
> registration (in thread_registration_apps() at main.c:1972)
> DEBUG1 - 04:41:39.137859 [1086/1189]: [thread] Manage health check
> started (in thread_manage_health() at main.c:3762)
> DEBUG2 - 04:41:39.140418 [1086/1195]: IP address resolved to 127.0.0.1
> (in set_ip_address() at uri.c:134)
> DEBUG3 - 04:41:39.140884 [1086/1195]: URI dtype: 1, proto: 1, host:
> localhost, subdir: , ctrl: 0, data: 0 (in uri_parse() at uri.c:507)
> DEBUG1 - 04:41:39.140941 [1086/1195]: [jul-thread] Listening on TCP
> port 5345 and socket 27 (in init_tcp_socket() at jul-thread.c:158)
> DEBUG3 - 04:41:39.141006 [1086/1195]: [jul-thread] Manage JUL polling
> on 2 fds (in jul_thread_manage_registration() at jul-thread.c:288)
> DEBUG1 - 04:41:39.138615 [1086/1196]: [thread] Thread manage kernel
> started (in thread_manage_kernel() at main.c:957)
> DEBUG1 - 04:41:39.141147 [1086/1196]: Updating kernel poll set (in
> update_kernel_poll() at main.c:817)
> DEBUG1 - 04:41:39.141166 [1086/1196]: Thread kernel polling on 2 fds
> (in thread_manage_kernel() at main.c:1002)
> DEBUG1 - 04:41:39138664 [1086/1197]: [load-session-thread] Load
> session (in thread_load_session() at load-session-thread.c:90)
> DEBUG1 - 04:41:39.141624 [1086/1189]: Health check ready (in
> thread_manage_health() at main.c:3827)
> I/O warning : failed to load external entity
> "/usr/share/xml/lttng/session.xsd"
> XML Error: Failed to locate the main schema resource at
> '/usr/share/xml/lttng/session.xsd'.
> Error: XSD parsing failed
> Error: Session load failed: Invalid session configuration
> 
> Thanks & Regards
> Abhishek Kumar
> 7801078513 
> 
> ----- Original Message -----
> From: "Jonathan Rajotte-Julien" 
> To:
> Cc:
> Sent:Mon, 3 Apr 2017 11:20:24 -0400
> Subject:Re: [lttng-dev] Lttng trace showing empty result while doing
> lttng view
> 
>  On Mon, Apr 03, 2017 at 11:56:57AM +0530, abhishekk at uurmi.com wrote:
>  > 
>  > 
>  > I am trying to trace raspberry (I am using raspberry 3 B ) Linux
>  > kernel by using lttng. The problem i am facing is after the
> successful
>  > completion of running following commands i am not able to see
> tracing
>  > result. It seems tracing file is empty. 1. lltng create mysession
>  > 
>  > 2. lttng enable-event -a -k 
>  > 
>  > 3. lttng start 
>  > 
>  > 4 lttng stop 5
>  > 
>  > . lttng view
>  > 
>  > Note:- I am not facing any error while running above command and
>  > kernel tracing file is generated at proper path. And I am not
> facing
>  > this problem when i am tracing for user space application. 
>  > 
>  > I am using version 2.9 of kernel modules and version 2.5 of lttng
>  > modules.Kernel modules are loaded i can see using lsmod. 
> 
>  Not sure I understand which version of lttng-modules you are
> currently using.
> 
>  Can you share with us the result of 'modinfo lttng-tracer'?
>  Could you pastebinit (or equivalent) the log produced by the
> lttng-sessiond in
>  verbose mode (lttng-sessiond -vvv).
> 
>  Please take a look at the bug reporting guidelines [1].
> 
>  Cheers
> 
>  [1] http://lttng.org/community/#bug-reporting-guidelines
> 
>  > Thanks & Regards
>  > Abhishek Kumar
>  > 7801078513 
>  > 
>  > -------------------------
>  > Email sent using E-interact Webmail
> 
>  > _______________________________________________
>  > lttng-dev mailing list
>  > lttng-dev at lists.lttng.org
>  > https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
> 
>  -- 
>  Jonathan Rajotte-Julien
>  EfficiOS
> 
> -------------------------
> Email sent using E-interact Webmail

-- 
Jonathan Rajotte-Julien
EfficiOS

More information about the lttng-dev mailing list