[ltt-dev] issues with lttv 0.12.7

Mathieu Desnoyers compudj at krystal.dyndns.org
Wed Jul 1 16:51:39 EDT 2009


* Dany Madden (dany.r.madden at gmail.com) wrote:
> Hi Mathieu,
> 
> As you suggested, I've tested <lttv --memory -m textDump -t /tmp/trace1>
> command with glib 2.21.2 and lttv-0.12.16-19062009. I still see the same
> segfault and bt. Any more suggestions? :)
> 

./configure CFLAGS=-g && make && make install

gdb lttv.real
(gdb) set args --debug -v --fatal --memory -m textDump -t /tmp/trace
...
bt full

should provide useful output.. but it looks like there is something
wrong with the glib memory profiler due to our extensive use of the
gquarks. Maybe we overflow one of its tables...

One thing to try would be to allocate the strings ourself elsewhere and
use g_quark_from_static_string. It seems particularly important in
ltt/marker.c, where we generate a quark for each channel, event and
field name. refs :

http://library.gnome.org/devel/glib/unstable/glib-Memory-Allocation.html
http://library.gnome.org/devel/glib/unstable/glib-Quarks.html

Thanks,

Mathieu


> 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:
> > ...
> >
> 
> >
> > 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.
> 
> 
> I am still seeing the same bt with lttv-0.12.16-19062009 and glib 2.21.2
> ...
> 
> 
> > >
> > > ---> 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

-- 
Mathieu Desnoyers
OpenPGP key fingerprint: 8CD5 52C3 8E3C 4140 715F  BA06 3F25 A8FE 3BAE 9A68




More information about the lttng-dev mailing list