[ltt-dev] issues with lttv 0.12.7
Mathieu Desnoyers
compudj at krystal.dyndns.org
Mon Jun 29 11:20:10 EDT 2009
* Dany Madden (dany.r.madden at gmail.com) wrote:
> Hello,
>
> We are testing the following in SLES 11 ia32 and ran into some issues. We
> would appreciate if someone could confirm if these are real bugs or if they
> are problems with our setup.
>
> lttv: 0.12.7
> lttng: 0.72 (patched in sles11 2.6.27.19 kernel)
> lttcontrol: 0.64
>
> ISSUE1: We see WARNING **: No channel for marker named
> userspace.thread_brand found (more warnings below.) Is this significant? If
> not, is there a way to silent it? I've seen a similar posting in the ltt-dev
> mailing list that says to run ltt-armall. I did that, however, I am still
> seeing the warnings. Please see below for the ltt-armall output. These
> warnings maybe causing ISSUE4.
grep find_hook lttv/lttv/*.c
See g_warning in there. Needs to be fixed. Low priority.
>
> ISSUE2: -e event.name=fork used to work when tested in sles10sp2 (lttv
> 0.8.47, lttcontrol 0.10, lttng for 2.6.16.60 kernel) but it no longer
> working in the lttv 0.12. Has the usage changed? Are there any documentation
> that tells me how the -e is used?
>
./lttv -m textDump -e event.name=kernel.process_fork -t /tmp/trace
The event name has changed. See the ltt-armall output.
>
> ISSUE3: lttv --memory causes segmentation fault. This is the gdb backtrace:
> (gdb) run --memory -m textDump -t /tmp/trace1
> Starting program: /usr/bin/lttv.real --memory -m textDump -t /tmp/trace1
> [Thread debugging using libthread_db enabled]
> ** Message: Memory summary before main
> GLib Memory statistics (successful operations):
> blocks of | allocated | freed | allocated | freed | n_bytes
> n_bytes | n_times by | n_times by | n_times by | n_times by | remaining
> | malloc() | free() | realloc() | realloc() |
> ===========|============|============|============|============|===========
> 4 | 0 | 0 | 1 | 1 | +0
> 12 | 1 | 0 | 0 | 0 | +12
> 15 | 2 | 0 | 0 | 0 | +30
> 16 | 0 | 0 | 2 | 1 | +16
> 27 | 2 | 2 | 0 | 0 | +0
> 32 | 0 | 1 | 1 | 0 | +0
> 36 | 1 | 0 | 0 | 0 | +36
> 64 | 0 | 1 | 1 | 0 | +0
> GLib Memory statistics (failing operations):
> --- none ---
> Total bytes: allocated=264, zero-initialized=48 (18.18%), freed=170
> (64.39%), remaining=94
>
> Program received signal SIGSEGV, Segmentation fault.
> 0xb7daed7b in realloc () from /lib/libc.so.6
> (gdb) bt
> #0 0xb7daed7b in realloc () from /lib/libc.so.6
> #1 0xb7ef5bb3 in profiler_try_realloc (mem=0x806d018, n_bytes=4096) at
> gmem.c:559
> #2 0xb7ef6779 in profiler_realloc (mem=0x806d018, n_bytes=4096) at
> gmem.c:581
> #3 0xb7ef604a in IA__g_realloc (mem=0x806d018, n_bytes=4096) at gmem.c:170
> #4 0xb7ed7b89 in IA__g_quark_from_string (string=0x80bcde8 "syscall 115")
> at gdataset.c:683
> #5 0x0805db85 in init (self=0x80b0200, ts=0x8078f28) at state.c:1915
> #6 0x08060d0f in init (self=0x80b0200, ts=0x8078f28) at stats.c:200
> #7 0xb7cda173 in process_traceset (hook_data=0x0, call_data=0x0) at
> batchAnalysis.c:83
> #8 0x08054346 in lttv_hooks_call (h=0x806f478, call_data=0x0) at hook.c:272
> #9 0x08052a8d in main (argc=6, argv=0xbffff684) at main.c:219
>
Hrm, maybe a problem at the glib level ? You should try :
- with a newer lttv version
- with an updated glib
to see if the problem persists.
>
> ISSUE4: lttv --tatal is aborting. This is the gdb backtrace.
> (gdb) run --fatal -m textDump -t /tmp/trace1
> The program being debugged has been started already.
> Start it from the beginning? (y or n) y
> Starting program: /usr/bin/lttv.real --fatal -m textDump -t /tmp/trace1
> [Thread debugging using libthread_db enabled]
>
> ** WARNING **: No channel for marker named userspace.thread_brand found
> aborting...
>
> Program received signal SIGABRT, Aborted.
> 0xffffe430 in __kernel_vsyscall ()
> (gdb) bt
> #0 0xffffe430 in __kernel_vsyscall ()
> #1 0xb7d68990 in raise () from /lib/libc.so.6
> #2 0xb7d6a2c8 in abort () from /lib/libc.so.6
> #3 0xb7ef7cdc in IA__g_logv (log_domain=0x0, log_level=G_LOG_LEVEL_WARNING,
> format=0x8069b74 "No channel for marker named %s.%s found",
> args1=0xbffff38c "\230D\a\b`L\a\b") at gmessages.c:497
> #4 0xb7ef7d16 in IA__g_log (log_domain=0x0, log_level=G_LOG_LEVEL_WARNING,
> format=0x8069b74 "No channel for marker named %s.%s found") at
> gmessages.c:517
> #5 0x08061b5e in lttv_trace_find_hook (t=0x8076d50, channel_name=110,
> event_name=131, fields=0xbffff4c4, h=0x805ab70 <thread_brand>,
> hook_data=0x0,
> trace_hooks=0xbffff518) at tracecontext.c:983
> #6 0x0805a034 in lttv_state_add_event_hooks (self=0x80a0000) at
> state.c:3492
> #7 0xb7fd617b in process_traceset (hook_data=0x0, call_data=0x0) at
> batchAnalysis.c:84
> #8 0x08054346 in lttv_hooks_call (h=0x8072368, call_data=0x0) at hook.c:272
> #9 0x08052a8d in main (argc=6, argv=0xbffff684) at main.c:219
>
> Below are additional detail on our setup. Thanks in advance for your help!
>
lttv_trace_find_hook needs to have its g_warning changed into a
non-fatal log message. Patches are welcome.
Thanks,
Mathieu
>
> ---> These modules are built into the kernel:
> ltt-marker-control
> ltt-tracer
> ltt-serialize
> ltt-relay
>
> ---> These are the modules that I loaded:
> xracer5:~ # lsmod | grep ltt
> ltt_type_serializer 2332 4 trap_trace,syscall_trace,mm_
> trace,kernel_trace
> ltt_trace_control 8400 0
> ltt_statedump 8104 0
> xracer5:~ # lsmod | grep trace
> ltt_type_serializer 2332 4
> trap_trace,syscall_trace,mm_trace,kernel_trace
> ipc_trace 2048 4
> kernel_trace 11112 31
> ltt_trace_control 8400 0
> mm_trace 4832 12
> fs_trace 5176 16
> syscall_trace 1584 2
> trap_trace 1560 2
>
> ---> I ran ltt-armall
> xracer5:/dany # ltt-armall
> Connecting all markers
> Connecting fd_state file_descriptor
> Connecting fs buffer_wait_end
> Connecting fs buffer_wait_start
> Connecting fs close
> Connecting fs exec
> Connecting fs ioctl
> Connecting fs llseek
> Connecting fs lseek
> Connecting fs open
> Connecting fs pollfd
> Connecting fs pread64
> Connecting fs pwrite64
> Connecting fs read
> Connecting fs readv
> Connecting fs select
> Connecting fs write
> Connecting fs writev
> Connecting global_state statedump_end
> Connecting input input_event
> Connecting ipc call
> Connecting ipc msg_create
> Connecting ipc sem_create
> Connecting ipc shm_create
> Connecting irq_state idt_table
> Connecting irq_state interrupt
> Connecting kernel irq_entry
> Connecting kernel irq_exit
> Connecting kernel kthread_create
> Connecting kernel kthread_stop
> Connecting kernel kthread_stop_ret
> Connecting kernel module_free
> Connecting kernel module_load
> Connecting kernel printk
> Connecting kernel process_exit
> Connecting kernel process_fork
> Connecting kernel process_free
> Connecting kernel process_wait
> Connecting kernel sched_migrate_task
> Connecting kernel sched_schedule
> Connecting kernel sched_try_wakeup
> Connecting kernel sched_wait_task
> Connecting kernel sched_wakeup_new_task
> Connecting kernel send_signal
> Connecting kernel softirq_entry
> Connecting kernel softirq_exit
> Connecting kernel softirq_raise
> Connecting kernel syscall_entry
> Connecting kernel syscall_exit
> Connecting kernel tasklet_high_entry
> Connecting kernel tasklet_high_exit
> Connecting kernel tasklet_low_entry
> Connecting kernel tasklet_low_exit
> Connecting kernel timer_itimer_expired
> Connecting kernel timer_itimer_set
> Connecting kernel timer_set
> Connecting kernel timer_timeout
> Connecting kernel timer_update_time
> Connecting kernel trap_entry
> Connecting kernel trap_exit
> Connecting kernel vprintk
> Connecting mm handle_fault_entry
> Connecting mm handle_fault_exit
> Connecting mm huge_page_alloc
> Connecting mm huge_page_free
> Connecting mm page_alloc
> Connecting mm page_free
> Connecting mm swap_file_close
> Connecting mm swap_file_open
> Connecting mm swap_in
> Connecting mm swap_out
> Connecting mm wait_on_page_end
> Connecting mm wait_on_page_start
> Connecting module_state list_module
> Connecting netif_state network_ip_interface
> Connecting netif_state network_ipv4_interface
> Connecting softirq_state softirq_vec
> Connecting swap_state statedump_swap_files
> Connecting syscall_state sys_call_table
> Connecting task_state process_state
> Connecting vm_state vm_map
> Connecting high-rate markers to tap
>
> ---> compiled and ran this ltttest program
> #include <stdio.h>
> void write_to_console(int id)
> {
> printf("%d:Hello\n", id);
> sleep(1); /* Force the process to give up the CPU */
> printf(" %d:World!\n", id);
> }
>
> int main(void)
> {
> printf("parent pid:%d\n", getpid());
> if(!fork())
> write_to_console(1);
> else
> if(!fork())
> write_to_console(2);
>
> sleep(5);
> return 0;
> }
>
> ---> lttctl -C -w /tmp/trace1 trace1
> ---> ./ltttest
> ---> lttctl -D trace1
> ---> lttv -m textDump -e state.pid=3933 -e event.name=fork -t
> /tmp/trace1
>
>
> ** (process:3938): WARNING **: No channel for marker named
> userspace.thread_brand found
>
> ** (process:3938): WARNING **: No channel for marker named
> block._blk_request_issue found
>
> ** (process:3938): WARNING **: No channel for marker named
> block._blk_request_complete found
>
> ** (process:3938): WARNING **: No channel for marker named
> userspace.function_entry found
>
> ** (process:3938): WARNING **: No channel for marker named
> userspace.function_exit found
> Trace set contains 1 traces
>
> ....
>
> ---> lttv --memory -m textDump -e
> event.name=page_alloc -t /tmp/trace1/
> ** Message: Memory summary before main
> GLib Memory statistics (successful operations):
> blocks of | allocated | freed | allocated | freed | n_bytes
> n_bytes | n_times by | n_times by | n_times by | n_times by | remaining
> | malloc() | free() | realloc() | realloc() |
> ===========|============|============|============|============|===========
> 4 | 0 | 0 | 1 | 1 | +0
> 12 | 1 | 0 | 0 | 0 | +12
> 15 | 2 | 0 | 0 | 0 | +30
> 16 | 0 | 0 | 2 | 1 | +16
> 27 | 2 | 2 | 0 | 0 | +0
> 32 | 0 | 1 | 1 | 0 | +0
> 36 | 1 | 0 | 0 | 0 | +36
> 64 | 0 | 1 | 1 | 0 | +0
> GLib Memory statistics (failing operations):
> --- none ---
> Total bytes: allocated=264, zero-initialized=48 (18.18%), freed=170
> (64.39%),
> remaining=94
> /usr/bin/lttv: line 15: 6494 Segmentation fault $0.real $*
>
> xracer5:~ # echo $?
> 139
>
>
> ---> lttv -m textDump -t
> /tmp/trace1/ --fatal
>
> ** WARNING **: No channel for marker named userspace.thread_brand found
> aborting...
> /usr/bin/lttv: line 15: 6463 Aborted $0.real $*
>
> xracer5:~# echo $?
> 134
>
>
> -----
> ~ Dany Madden
>
>
>
> --
> -----
> ~ Dany Madden
> _______________________________________________
> ltt-dev mailing list
> ltt-dev at lists.casi.polymtl.ca
> http://lists.casi.polymtl.ca/cgi-bin/mailman/listinfo/ltt-dev
--
Mathieu Desnoyers
OpenPGP key fingerprint: 8CD5 52C3 8E3C 4140 715F BA06 3F25 A8FE 3BAE 9A68
More information about the lttng-dev
mailing list