[ltt-dev] Kernel crashes when creating a trace

[Mathieu Desnoyers]

* Ashwin Tanugula (ashwin.tanugula at broadcom.com) wrote:
> 
> 
> * Ashwin Tanugula (ashwin.tanugula at broadcom.com) wrote:
> > Hi Mathieu,
[...]
> > 
> > I patched my kernel (MIPS) with the patch-2.6.31.5-lttng-0.165.tar.bz2 patchset.
> > 
> 
> >>Can you try with 0.167 instead and see if the problem is still there
> >>first ? I fixed mostly problems with 32-bit machines and erroneous
> >>types. I'm not sure if your MIPS flavor is 32 or 64-bit. However the
> >>32-bit problem occured at trace teardown, not at trace creation.
> 
> I tried 0.167 and I still see the same problem
> 

OK. Can you give me a copy of your .config ?

It would also help to know where it gets stucked. You can get this
information with SYSRQ-W  (show-blocked-tasks).

Thanks,

Mathieu


> Linux Trace Toolkit Trace Contro------------[ cut here ]------------
> WARNING: at arch/mips/kernel/trace-clock.c:77 trace_clock_async_tsc_read+0x30/0x17c()
> 
> 
> Controlling tModules linked in:race : trace1
> 
> 
> lttctl: CreatinCall Trace:
> g trace
> [<80018b84>] dump_stack+0x8/0x34
> [<8003e59c>] warn_slowpath_common+0x70/0x98
> [<8001bfc0>] trace_clock_async_tsc_read+0x30/0x17c
> [<80086a18>] trace_clock_read_synthetic_tsc+0x94/0xbc
> [<80086d14>] get_synthetic_tsc+0xe0/0x1a0
> [<8001c1b0>] get_trace_clock+0x34/0x17c
> [<8023019c>] ltt_trace_alloc+0x60/0x56c
> [<8023cb8c>] alloc_write+0x130/0x17c
> [<800c201c>] vfs_write+0xbc/0x180
> [<800c2b24>] sys_write+0x60/0x130
> [<8000339c>] stack_done+0x20/0x3c
> 
> ---[ end trace 8ffc6c83ddb229ea ]---
> ------------[ cut here ]------------
> WARNING: at arch/mips/kernel/trace-clock.c:77 trace_clock_async_tsc_read+0x30/0x17c()
> Modules linked in:
> Call Trace:
> [<80018b84>] dump_stack+0x8/0x34
> [<8003e59c>] warn_slowpath_common+0x70/0x98
> [<8001bfc0>] trace_clock_async_tsc_read+0x30/0x17c
> [<80086a18>] trace_clock_read_synthetic_tsc+0x94/0xbc
> [<8001c014>] trace_clock_async_tsc_read+0x84/0x17c
> [<80086a18>] trace_clock_read_synthetic_tsc+0x94/0xbc
> [<80086d14>] get_synthetic_tsc+0xe0/0x1a0
> [<8001c1b0>] get_trace_clock+0x34/0x17c
> [<8023019c>] ltt_trace_alloc+0x60/0x56c
> [<8023cb8c>] alloc_write+0x130/0x17c
> [<800c201c>] vfs_write+0xbc/0x180
> [<800c2b24>] sys_write+0x60/0x130
> [<8000339c>] stack_done+0x20/0x3c
> 
> ---[ end trace 8ffc6c83ddb229eb ]---
> > I am using the ltt-control-0.72-23102009.tar.gz control package.
> > 
> > I tried ltt-control-0.71-30092009, but it has the same problem.
> > 
> > I am able to patch and compile the kernel fine, but when I try to create a trace, then my kernel crashes.
> > 
> > Here is the dump.
> > 
> > # lttctl -c trace2
> > Linux Trace Toolkit Trace Contro------------[ cut here ]------------
> > WARNING: at arch/mips/kernel/trace-clock.c:77 
> > trace_clock_async_tsc_read+0x30/0x17c()
> 
> >>At least some of my own warnings are kicking in. There is nothing like safety nets when things go wrong :)
> 
> >>So this warning is:
> 
> >>WARN_ON(!async_tsc_refcount || !async_tsc_enabled);
> 
> >>So I think the problem that there is a trace clock read within the
> >>get_trace_clock() call. Hrm. mips get_trace_clock is calling get_synthetic_tsc(), which reads the trace clock. That's wrong.
> 
> >>I seem to be going back and forth between mutexes and spinlocks to protect the trace clock:
> 
> >>Also the fact that the enabling synthetic tsc uses trace_clock_read_synthetic_tsc()is not good, because it uses a layer that depends on reading the 32 lsb, which creates a circular dependency.
> 
> >>To make things clearer:
> 
> >>- synthetic TSC extends the MIPS 32-bit cycle counter to 64-bit.
> >>- MIPS trace clock modifies that synthetic TSC values to ensure it works
> >>fine on MIPS processors that have no synchronized TSCs.
> 
> >>So currently, these two layers are well separated, but they are so dependent on each other that I might have to restructure that a bit.
> >>The solution is not clear to me currently. I think I'll sleep on it and try poking this tomorrow.
> 
> >>If you remove the WARN_ON from arch/mips/kernel/trace-clock.c:77, does it help ?
> 
> No, removing WARN_ON just does not dump the debug messages.
> 
> It hangs the system.
> 
> Thank you very much for your help.
> 
> Ashwin
> 

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