Re: missing data in traces

Jan Altenberg <[email protected]> Thu, 20 Dec 2007 16:31:32 +0100
Newsgroups gmane.linux.kernel.tracing
Message-ID <[email protected]>
Hi,

sorry for the late response. I'm kind of busy at the moment.

> >> Unfortunately, rendering this populated trace data is causing a new
> >> segfault in the viewer:
> >>
> >> Core was generated by `/usr/local/bin/lttv.real -m guievents -m
> >> guifilter -m guicontrolflow -m resourc'.
> >> Program terminated with signal 11, Segmentation fault.
> >> #0  0x0000000000414686 in irq_entry (hook_data=<value optimized out>,
> >>     call_data=<value optimized out>) at state.c:1981
> >> 1981      g_array_set_size(irqst->mode_stack, irqst->mode_stack->len + 1);
> >> (gdb) bt
> >> #0  0x0000000000414686 in irq_entry (hook_data=<value optimized out>,
> >>     call_data=<value optimized out>) at state.c:1981
> >> #1  0x000000000040ca6f in lttv_hooks_call_merge (h1=0xa84460,
> >>     call_data1=0xa843a0, h2=0xab01d8, call_data2=0xa843a0) at hook.c:333
> >> #2  0x0000000000418a93 in lttv_process_traceset_middle (self=0x9cb7e0, end=
> >>       {tv_sec = 999, tv_nsec = 587766197}, nb_events=6000, end_position=0x0)
> >>     at tracecontext.c:768
> >> #3  0x00002b9228cb59c6 in execute_events_requests (tab=0x8b48b0)
> >>     at callbacks.c:1446
> >> #4  0x00002b9226e40fca in g_main_context_dispatch ()
> >>    from /opt/gnome/lib64/libglib-2.0.so.0
> >> #5  0x00002b9226e44055 in g_str_equal () from
> >> /opt/gnome/lib64/libglib-2.0.so.0
> >> #6  0x00002b9226e44365 in g_main_loop_run ()
> >>    from /opt/gnome/lib64/libglib-2.0.so.0
> >> #7  0x00002b9227685563 in gtk_main () from
> >> /opt/gnome/lib64/libgtk-x11-2.0.so.0
> >> #8  0x00002b9228cb2096 in window_creation_hook (
> >>     hook_data=<value optimized out>, call_data=<value optimized out>)
> >>     at init_module.c:129
> >> #9  0x000000000040cb0a in lttv_hooks_call (h=0x531158, call_data=0x0)
> >>     at hook.c:272
> >> #10 0x000000000040b09d in main (argc=13, argv=0x7fff840bc168) at main.c:219
> >>
> >> This one isnt as obvious to me as the last one, so I have no patch to
> >> offer.  Any advice is appreciated!
> >>     
> >
> > Hmmmm, I think I ran into that a few days ago on one of my machines.
> > What happened on my machine was:
> >
> > irq_entry()
> > {
> > ...
> >
> > /* update irq status */
> >   s->cpu_state->last_irq = irq;
> >   irq_push_mode(&ts->irq_states[irq], LTTV_IRQ_BUSY);
> > }
> >
> > irq_entry calls irq_push_mode for the current irq number:
> >
> > static void irq_push_mode(LttvIRQState *irqst, LttvIRQMode state)
> > {
> >   g_array_set_size(irqst->mode_stack, irqst->mode_stack->len + 1);
> > -> That's the call, which causes LTTV to segfault.
> >
> > irq_states is a garray, which gets created by:
> > nb_irq = tcs->nb_irqs
> > ...
> > tcs->irq_states = g_new(LttvIRQState, nb_irq);
> > ...
> >
> > nb_irqs gets initialized in create_name_tables:
> > name_tables->nb_irqs = 256;
> >
> > Now lets have a look at the interrupt table of my testbox:
> >            CPU0       CPU1       
> >   0:         44          0   IO-APIC-edge      timer
> >   1:          0       1726   IO-APIC-edge      i8042
> >   7:          0          0   IO-APIC-edge      parport0
> >   9:          0          0   IO-APIC-fasteoi   acpi
> >  12:          6      11139   IO-APIC-edge      i8042
> >  14:          0         37   IO-APIC-edge      ide0
> >  18:          0          3   IO-APIC-fasteoi   ohci1394
> >  21:          0          0   IO-APIC-fasteoi   sata_nv
> >  22:         67      69032   IO-APIC-fasteoi   sata_nv, HDA Intel
> >  23:          0          0   IO-APIC-fasteoi   ohci_hcd:usb1
> > 1279:        132     150698   PCI-MSI-edge      eth0
> >
> > eth0 has an interrupt number > 255!
> >
> > So, irq_entry will call
> > irq_push_mode(&ts->irq_states[1279], LTTV_IRQ_BUSY);
> > which causes a segfault.
> >
> >   
> I think you may be on to something.  My system has an eth0 at 4342!

CCed Mathieu.

Just to make sure, your facing the same issue: Could you try, what
happens with attached patch?

---
 lttv/lttv/state.c |    6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

Index: lttv-0.10.0-pre5-05122007/lttv/lttv/state.c
===================================================================
--- lttv-0.10.0-pre5-05122007.orig/lttv/lttv/state.c
+++ lttv-0.10.0-pre5-05122007/lttv/lttv/state.c
@@ -1829,9 +1829,9 @@ create_name_tables(LttvTraceState *tcs) 
     }
     */
 
-    name_tables->nb_irqs = 256;
-    name_tables->irq_names = g_new(GQuark, 256);
-    for(i = 0 ; i < 256 ; i++) {
+    name_tables->nb_irqs = 5000;
+    name_tables->irq_names = g_new(GQuark, 5000);
+    for(i = 0 ; i < 5000 ; i++) {
       g_string_printf(fe_name, "irq %d", i);
       name_tables->irq_names[i] = g_quark_from_string(fe_name->str);
     }