[ltt-dev] issues with lttv 0.12

Dany Madden dany.r.madden at gmail.com
Thu Jun 25 15:02:53 EDT 2009


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.

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?


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


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!


---> 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.casi.polymtl.ca/pipermail/lttng-dev/attachments/20090625/80d88196/attachment-0002.htm>


More information about the lttng-dev mailing list