[ltt-dev] issues with lttv 0.12.7
Mathieu Desnoyers
compudj at krystal.dyndns.org
Wed Jul 1 16:55:21 EDT 2009
* Mathieu Desnoyers (compudj at krystal.dyndns.org) wrote:
> * Dany Madden (dany.r.madden at gmail.com) wrote:
> > Thanks for your quick response. I applied the following patch and --fatal
> > segmentation fault is not happening anymore.
> >
>
> I've also changed the other g_warning for g_info in this function. Will
> be in the next LTTV release.
>
Done, released in lttv 0.12.17.
Mathieu
> Thanks,
>
> Mathieu
>
> >
> > --- lttv-0.12.7-20012009.back/lttv/lttv//tracecontext.c 2009-06-29
> > 17:54:50.000000000 +0000
> > +++ lttv-0.12.7-20012009/lttv/lttv//tracecontext.c 2009-06-29
> > 18:01:14.000000000 +0000
> > @@ -980,9 +980,11 @@ int lttv_trace_find_hook(LttTrace *t, GQ
> >
> > group = g_datalist_id_get_data(&t->tracefiles, channel_name);
> > if (unlikely(!group || group->len == 0)) {
> > - g_warning("No channel for marker named %s.%s found",
> > - g_quark_to_string(channel_name), g_quark_to_string(event_name));
> > - return 1;
> > +// g_warning("No channel for marker named %s.%s found",
> > +// g_quark_to_string(channel_name), g_quark_to_string(event_name));
> > + g_log(G_LOG_DOMAIN, G_LOG_LEVEL_INFO, "No channel for marker named
> > %s.%s found",
> > + g_quark_to_string(channel_name), g_quark_to_string(event_name));
> > + return 1;
> > }
> >
> > Thanks,
> > Dany
> >
> > On Mon, Jun 29, 2009 at 8:20 AM, Mathieu Desnoyers <
> > compudj at krystal.dyndns.org> wrote:
> >
> > > * 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
> > >
> >
> >
> >
> > --
> > -----
> > ~ 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
>
> _______________________________________________
> 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