Great findings! I'll also try to look into this new problem by next monday; I'm falling a bit behind on my 'investigations', but I'll keep you updated if anything comes up.
-PL On Mar 6, 2013 6:09 PM, "Amit Balboul" <[email protected]> wrote: > Hi All, > > Regarding the last mail about tracing system calls on Android using LTTng, > The issue of not receiving enabled event to trace from the kernel can be > fixed patching src/bin/lttng-sessiond/kernel.c (patch attached) > In the function *kernel_list_events,* fscanf-ing the events exported by > the kernel using the fp must not use the syntax *%m* as it is obsolete > (in Android), > thus the fscanf returns 0 and won't read the kernel events (first > condition false). > Instead I use a pre-allocated buffer for the string and use the > *%[^;]*syntax, and omitting the memory free (attached is the patch). > > The resulting output is (sessiond is run with verbose debug prints): > > root@android:/data/lttng/bin # *./lttng list -k* > DEBUG1 [10239/10290]: Wait for client response (in thread_manage_clients() > at main.c:3242) > DEBUG1 [10239/10290]: Receiving data from client ... (in > thread_manage_clients() at main.c:3287) > DEBUG1 [10239/10290]: Nothing recv() from client... continuing (in > thread_manage_clients() at main.c:3291) > DEBUG1 [10239/10290]: Clean command context structure (in > clean_command_ctx() at main.c:482) > DEBUG1 [10239/10290]: Accepting client command ... (in > thread_manage_clients() at main.c:3200) > DEBUG1 [10239/10290]: Wait for client response (in thread_manage_clients() > at main.c:3242) > DEBUG1 [10239/10290]: Receiving data from client ... (in > thread_manage_clients() at main.c:3287) > DEBUG1 [10239/10290]: Processing client command 14 (in > process_client_msg() at main.c:2227) > DEBUG1 [10239/10290]: Kernel list events done (61 events) (in > kernel_list_events() at kernel.c:653) > DEBUG1 [10239/10290]: Sending response (size: 35640, retcode: Success) (in > thread_manage_clients() at main.c:3338) > DEBUG1 [10239/10290]: Clean command context structure (in > clean_command_ctx() at main.c:482) > DEBUG1 [10239/10290]: Accepting client command ... (in > thread_manage_clients() at main.c:3200) > Kernel events: > ------------- > block_rq_abort (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_rq_requeue (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_rq_complete (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_rq_insert (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_rq_issue (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_bio_bounce (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_bio_complete (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_bio_backmerge (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_bio_frontmerge (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_bio_queue (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_getrq (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_sleeprq (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_plug (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_unplug (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_split (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_bio_remap (loglevel: TRACE_EMERG (0)) (type: tracepoint) > block_rq_remap (loglevel: TRACE_EMERG (0)) (type: tracepoint) > irq_handler_entry (loglevel: TRACE_EMERG (0)) (type: tracepoint) > irq_handler_exit (loglevel: TRACE_EMERG (0)) (type: tracepoint) > softirq_entry (loglevel: TRACE_EMERG (0)) (type: tracepoint) > softirq_exit (loglevel: TRACE_EMERG (0)) (type: tracepoint) > softirq_raise (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_kthread_stop (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_kthread_stop_ret (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_wakeup (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_wakeup_new (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_switch (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_migrate_task (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_process_free (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_process_exit (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_wait_task (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_process_wait (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_process_fork (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_stat_wait (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_stat_sleep (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_stat_iowait (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_stat_runtime (loglevel: TRACE_EMERG (0)) (type: tracepoint) > sched_pi_setprio (loglevel: TRACE_EMERG (0)) (type: tracepoint) > signal_generate (loglevel: TRACE_EMERG (0)) (type: tracepoint) > signal_deliver (loglevel: TRACE_EMERG (0)) (type: tracepoint) > signal_overflow_fail (loglevel: TRACE_EMERG (0)) (type: tracepoint) > signal_lose_info (loglevel: TRACE_EMERG (0)) (type: tracepoint) > lttng_statedump_start (loglevel: TRACE_EMERG (0)) (type: tracepoint) > lttng_statedump_end (loglevel: TRACE_EMERG (0)) (type: tracepoint) > lttng_statedump_process_state (loglevel: TRACE_EMERG (0)) (type: > tracepoint) > lttng_statedump_file_descriptor (loglevel: TRACE_EMERG (0)) (type: > tracepoint) > lttng_statedump_vm_map (loglevel: TRACE_EMERG (0)) (type: tracepoint) > lttng_statedump_network_interface (loglevel: TRACE_EMERG (0)) (type: > tracepoint) > lttng_statedump_interrupt (loglevel: TRACE_EMERG (0)) (type: > tracepoint) > timer_init (loglevel: TRACE_EMERG (0)) (type: tracepoint) > timer_start (loglevel: TRACE_EMERG (0)) (type: tracepoint) > timer_expire_entry (loglevel: TRACE_EMERG (0)) (type: tracepoint) > timer_expire_exit (loglevel: TRACE_EMERG (0)) (type: tracepoint) > timer_cancel (loglevel: TRACE_EMERG (0)) (type: tracepoint) > hrtimer_init (loglevel: TRACE_EMERG (0)) (type: tracepoint) > hrtimer_start (loglevel: TRACE_EMERG (0)) (type: tracepoint) > hrtimer_expire_entry (loglevel: TRACE_EMERG (0)) (type: tracepoint) > hrtimer_expire_exit (loglevel: TRACE_EMERG (0)) (type: tracepoint) > hrtimer_cancel (loglevel: TRACE_EMERG (0)) (type: tracepoint) > itimer_state (loglevel: TRACE_EMERG (0)) (type: tracepoint) > itimer_expire (loglevel: TRACE_EMERG (0)) (type: tracepoint) > > root@android:/data/lttng/bin # > > Now I'm facing the issue of starting the traces: > debugging the sessiond, consumerd and lttng I concluded that the issue is > due to splice system call failure. > even using a MMAP output type channel, the metadata channel is SPLICE type > (hard-coded). > Problem persists also when using relayd to pass the traces through the > network. > Ignoring the splice failure means closing of the metadata channel > (maybe??) but need not affect the traces channel (right ?) > Attached is a debug log of each thread of the sessiond, right after > invoking "*./lttng start*". (with extra informative my prints) > > Please keep me in touch with any progress in this issue, > Thank you, > Amit. > > > > > > > ---------- Forwarded message ---------- > From: Amit Balboul <[email protected]> > Date: Wed, Feb 27, 2013 at 4:37 PM > Subject: Re: [lttng-dev] compiling LTTng for android > To: PLSTC <[email protected]> > > > Hey Pierre, > > Some major progress has been achieved, following is the summary: > > 1. Modules issue: > I built (for ARM/Android) and installed latest stable version of busybox > on the device. > Seeing the code tries to run (hardcoded) /sbin/modprobe, made a soft link > to busybox's modeprobe. > Also, created /lib/modules/<version+build> directory and pushed the > <version+build> directory from /lib/modules on the machine. > Now session daemon modprobes the desired modules successfully, (some are > not present though as mentioned before) - no need to use insmod. > > 2. epoll_create1 issue: > epoll_create1 patch was OK, I accidentally defined EPOLL_CLOEXEC as > 0x02000000 instead of 02000000 (fixed). > > The running scenario: > > 1. Run ./lttng-sessiond -d -vvv > > Then: (commands are in bold, output is in blue for readability) > > root@android:/data/lttng/install_sysroot/bin # *./lttng create s1* > > Session s1 created. > Traces will be written in /data/lttng-traces/s1-20130227-161145 > root@android:/data/lttng/install_sysroot/bin # *./lttng enable-channel ch > -k* > Kernel channel ch enabled for session s1 > root@android:/data/lttng/install_sysroot/bin # *./lttng enable-event ev > -k -a* > All kernel events are enabled in channel channel0 > root@android:/data/lttng/install_sysroot/bin # *./lttng list s1* > Tracing session s1: [inactive] > Trace path: /data/lttng-traces/s1-20130227-161145 > > === Domain: Kernel === > > Channels: > ------------- > - channel0: [enabled] > > Attributes: > overwrite mode: 0 > subbufers size: 262144 > number of subbufers: 4 > switch timer interval: 0 > read timer interval: 200 > output: splice() > > Events: > None > > - ch: [enabled] > > Attributes: > overwrite mode: 0 > subbufers size: 262144 > number of subbufers: 4 > switch timer interval: 0 > read timer interval: 200 > output: splice() > > Events: > None > > root@android:/data/lttng/install_sysroot/bin # *./lttng list -k * > > Kernel events: > ------------- > > root@android:/data/lttng/install_sysroot/bin # *./lttng start* > Tracing started for session s1 > root@android:/data/lttng/install_sysroot/bin # *./lttng stop * > > Waiting for data availability > Tracing stopped for session s1 > root@android:/data/lttng/install_sysroot/bin # > > *Now: (this is not surprising because the kernel events list is empty...)* > the folder /data/lttng-traces/s1-20130227-161145/kernel contains: > total 0 > -rwxrwxrwx 1 0 0 0 Feb 27 14:18 ch_0 > -rwxrwxrwx 1 0 0 0 Feb 27 14:18 ch_1 > -rwxrwxrwx 1 0 0 0 Feb 27 14:18 channel0_0 > -rwxrwxrwx 1 0 0 0 Feb 27 14:18 channel0_1 > -rwxrwxrwx 1 0 0 0 Feb 27 14:18 metadata > > *By the way:* > When running the same scenario but creating the channel with *--output > mmap*, still no data but the size of the first two files in the traces > directory are 4Kb (I didn't bother to investigate them as I assume it is > just the header - not the traces payload). > > Another issue: at this point, listing the sessions gives: > root@android:/data/lttng/install_sysroot/bin # *./lttng list s1 * > > Tracing session s1: [inactive] > Trace path: /data/lttng-traces/s1-20130227-161145 > > === Domain: Kernel === > > Error: No kernel consumer detected > 99|root@android:/data/lttng/install_sysroot/bin # *./lttng list -k * > > Error: Unable to list kernel events > Error: Command error > 1|root@android:/data/lttng/install_sysroot/bin # > > So currently I'm facing these issues: > 1. Kernel events list is empty. > 2. Listing the session/ kernel events after creating session, channel, > event, start, stop - results in "no kernel consumer detected" > > If you have some insights please share them with me.. > > Thanks > > Amit. > > > On Tue, Feb 26, 2013 at 7:35 PM, PLSTC <[email protected]> wrote: > >> The modules you can't find are the same I am also missing I believe; I >> think they are only compiled when certain kernel config defines are met >> (and those might simply be unavailable under ARM). >> >> As for what you pointed in your first mail, I believe modprobe isn't >> available on ARM, did you mean that some modules were not found when using >> insmod? >> >> For the epoll_create1 problem, what kind of patch did you apply to add >> support for the epoll_create1 function? >> >> >> On Tue, Feb 26, 2013 at 11:29 AM, Amit Balboul <[email protected] >> > wrote: >> >>> Ok I got : >>> lttng-kretprobes.ko >>> lttng-kprobes.ko >>> , the other two are missing. >>> >>> >>> ---------- Forwarded message ---------- >>> From: Amit Balboul <[email protected]> >>> Date: Tue, Feb 26, 2013 at 5:49 PM >>> Subject: Re: [lttng-dev] compiling LTTng for android >>> To: PLSTC <[email protected]> >>> >>> >>> One more thing: >>> >>> The list of modules you gave my is not identical to mine: >>> a. I pushed the modules from my machine to my folder in the device (not >>> to /system/lib) as you directed me, and insmoded them manually. >>> b. I pushed the whole tree under /lib/modules/<KERNEL_VER_BUILD>/ which >>> includes the modules.* and the sub directories: >>> >>> /lib/modules/3.0.31-gd5a18e0/extra$ ll >>> total 2464 >>> drwxr-xr-x 4 root root 4096 Feb 26 15:58 ./ >>> drwxr-xr-x 3 root root 4096 Feb 26 15:58 ../ >>> drwxr-xr-x 2 root root 4096 Feb 26 15:58 lib/ >>> -rw-r--r-- 1 root root 167184 Feb 26 15:58 >>> lttng-ring-buffer-client-discard.ko >>> -rw-r--r-- 1 root root 167206 Feb 26 15:58 >>> lttng-ring-buffer-client-mmap-discard.ko >>> -rw-r--r-- 1 root root 178586 Feb 26 15:58 >>> lttng-ring-buffer-client-mmap-overwrite.ko >>> -rw-r--r-- 1 root root 178564 Feb 26 15:58 >>> lttng-ring-buffer-client-overwrite.ko >>> -rw-r--r-- 1 root root 137179 Feb 26 15:58 >>> lttng-ring-buffer-metadata-client.ko >>> -rw-r--r-- 1 root root 137233 Feb 26 15:58 >>> lttng-ring-buffer-metadata-mmap-client.ko >>> -rw-r--r-- 1 root root 213451 Feb 26 15:58 lttng-statedump.ko >>> -rw-r--r-- 1 root root 1314235 Feb 26 15:58 lttng-tracer.ko >>> drwxr-xr-x 2 root root 4096 Feb 26 15:58 probes/ >>> >>> /lib/modules/3.0.31-gd5a18e0/extra/lib$ ll >>> total 732 >>> drwxr-xr-x 2 root root 4096 Feb 26 15:58 ./ >>> drwxr-xr-x 4 root root 4096 Feb 26 15:58 ../ >>> -rw-r--r-- 1 root root 738964 Feb 26 15:58 lttng-lib-ring-buffer.ko >>> >>> /lib/modules/3.0.31-gd5a18e0/extra/probes$ ll >>> total 2872 >>> drwxr-xr-x 2 root root 4096 Feb 26 15:58 ./ >>> drwxr-xr-x 4 root root 4096 Feb 26 15:58 ../ >>> -rw-r--r-- 1 root root 162872 Feb 26 15:58 lttng-probe-asoc.ko >>> -rw-r--r-- 1 root root 171049 Feb 26 15:58 lttng-probe-block.ko >>> -rw-r--r-- 1 root root 81165 Feb 26 15:58 lttng-probe-compaction.ko >>> -rw-r--r-- 1 root root 333215 Feb 26 15:58 lttng-probe-ext4.ko >>> -rw-r--r-- 1 root root 80413 Feb 26 15:58 lttng-probe-gpio.ko >>> -rw-r--r-- 1 root root 84256 Feb 26 15:58 lttng-probe-irq.ko >>> -rw-r--r-- 1 root root 135453 Feb 26 15:58 lttng-probe-jbd2.ko >>> -rw-r--r-- 1 root root 105399 Feb 26 15:58 lttng-probe-kmem.ko >>> -rw-r--r-- 1 root root 76240 Feb 26 15:58 lttng-probe-lttng.ko >>> -rw-r--r-- 1 root root 88059 Feb 26 15:58 lttng-probe-module.ko >>> -rw-r--r-- 1 root root 154032 Feb 26 15:58 lttng-probe-napi.ko >>> -rw-r--r-- 1 root root 142038 Feb 26 15:58 lttng-probe-net.ko >>> -rw-r--r-- 1 root root 93564 Feb 26 15:58 lttng-probe-power.ko >>> -rw-r--r-- 1 root root 85530 Feb 26 15:58 lttng-probe-regulator.ko >>> -rw-r--r-- 1 root root 138121 Feb 26 15:58 lttng-probe-sched.ko >>> -rw-r--r-- 1 root root 152909 Feb 26 15:58 lttng-probe-scsi.ko >>> -rw-r--r-- 1 root root 107491 Feb 26 15:58 lttng-probe-signal.ko >>> -rw-r--r-- 1 root root 142711 Feb 26 15:58 lttng-probe-skb.ko >>> -rw-r--r-- 1 root root 181983 Feb 26 15:58 lttng-probe-statedump.ko >>> -rw-r--r-- 1 root root 126731 Feb 26 15:58 lttng-probe-timer.ko >>> -rw-r--r-- 1 root root 86591 Feb 26 15:58 lttng-probe-workqueue.ko >>> -rw-r--r-- 1 root root 133886 Feb 26 15:58 lttng-probe-writeback.ko >>> -rw-r--r-- 1 root root 30863 Feb 26 15:58 lttng-types.ko >>> >>> Looking at the files shows I miss: >>> lttng-kretprobes.ko >>> lttng-kprobes.ko >>> lttng-ftrace.ko >>> lttng-probe-kvm.ko >>> >>> >>> On Tue, Feb 26, 2013 at 3:56 PM, PLSTC <[email protected]> wrote: >>> >>>> Back on the last email: >>>> >>>> Here's the insmod list I ended up building; you might not have compiled >>>> all those modules, depending on your kernel config and on the architecture >>>> used, so some might simply be absent from your output directory. >>>> >>>> insmod /system/lib/modules/lttng-types.ko >>>> insmod /system/lib/modules/lttng-kretprobes.ko >>>> insmod /system/lib/modules/lttng-kprobes.ko >>>> insmod /system/lib/modules/lttng-ftrace.ko >>>> insmod /system/lib/modules/lttng-lib-ring-buffer.ko >>>> insmod /system/lib/modules/lttng-statedump.ko >>>> insmod /system/lib/modules/lttng-tracer.ko >>>> insmod /system/lib/modules/lttng-probe-timer.ko >>>> insmod /system/lib/modules/lttng-probe-statedump.ko >>>> insmod /system/lib/modules/lttng-probe-signal.ko >>>> insmod /system/lib/modules/lttng-probe-sched.ko >>>> insmod /system/lib/modules/lttng-probe-lttng.ko >>>> insmod /system/lib/modules/lttng-probe-kvm.ko >>>> insmod /system/lib/modules/lttng-probe-irq.ko >>>> insmod /system/lib/modules/lttng-probe-block.ko >>>> insmod /system/lib/modules/lttng-ring-buffer-metadata-mmap-client.ko >>>> insmod /system/lib/modules/lttng-ring-buffer-metadata-client.ko >>>> insmod /system/lib/modules/lttng-ring-buffer-client-overwrite.ko >>>> insmod /system/lib/modules/lttng-ring-buffer-client-mmap-overwrite.ko >>>> insmod /system/lib/modules/lttng-ring-buffer-client-mmap-discard.ko >>>> insmod /system/lib/modules/lttng-ring-buffer-client-discard.ko >>>> >>>> >>>> We also haven't had time recently to test if the kprobes/kretprobes >>>> worked, but they probably do; we decided to focus a bit more on the >>>> 'tracepoints' aspect instead. >>>> >>>> Anyway, good luck with your exploration, and if you find something >>>> interesting, I'd love to know more about it! >>>> >>>> -PL >>>> >>>> On Tue, Feb 26, 2013 at 8:06 AM, PLSTC <[email protected]> wrote: >>>> >>>>> Hey Amit, >>>>> >>>>> Good news indeed it seems! >>>>> >>>>> When it comes to pushing the libs/bin, we haven't found any better way >>>>> than using adb push yet; of course, if all the projects were included >>>>> directly in Android's external, we would simply flash the device after >>>>> each >>>>> build, but currently we're still having trouble generating the correct >>>>> Android makefiles. >>>>> >>>>> As for the modules, I might still have a dep load list somewhere I >>>>> could send you in a few hours, I remember fighting to get the order >>>>> right... >>>>> >>>>> Also, once everything loads, could you tell me what kind of output >>>>> 'lttng list -k' provides you? Here, we're having trouble listing the >>>>> 'default' kernel trace points provided by HAVE_TRACEPOINTS, and the >>>>> returned list is simply empty (which is a bit strange). >>>>> >>>>> -PL >>>>> >>>> >>>> >>> >>> >> > >
_______________________________________________ lttng-dev mailing list [email protected] http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
