[ltt-dev] issues with lttv 0.12.7
Dany Madden
dany.r.madden at gmail.com
Mon Jun 29 14:36:53 EDT 2009
Thanks for your quick response. I applied the following patch and --fatal
segmentation fault is not happening anymore.
--- 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.casi.polymtl.ca/pipermail/lttng-dev/attachments/20090629/60dc1d4d/attachment-0003.htm>
More information about the lttng-dev
mailing list