2009-03-18 18:27:21

by Metzger, Markus T

[permalink] [raw]
Subject: [patch] x86, bts: use atomic memory allocation

Ds_request_bts() needs to allocate memory. It uses GFP_KERNEL.

Hw-branch-tracer calls ds_request_bts() within on_each_cpu().

Use atomic memory allocation to allow it to be used in that context.


Signed-off-by: Markus Metzger <[email protected]>
---

Index: git-tip/arch/x86/kernel/ds.c
===================================================================
--- git-tip.orig/arch/x86/kernel/ds.c 2009-03-17 12:26:07.000000000 +0100
+++ git-tip/arch/x86/kernel/ds.c 2009-03-17 13:30:09.000000000 +0100
@@ -255,8 +255,13 @@ static inline struct ds_context *ds_get_
struct ds_context *new_context = NULL;
unsigned long irq;

- /* Chances are small that we already have a context. */
- new_context = kzalloc(sizeof(*new_context), GFP_KERNEL);
+ /*
+ * Chances are small that we already have a context.
+ *
+ * Contexts for per-cpu tracing are allocated using
+ * smp_call_function(). We must not sleep.
+ */
+ new_context = kzalloc(sizeof(*new_context), GFP_ATOMIC);
if (!new_context)
return NULL;

@@ -662,8 +667,12 @@ struct bts_tracer *ds_request_bts(struct
if (ovfl)
goto out;

+ /*
+ * Per-cpu tracing is typically requested using smp_call_function().
+ * We must not sleep.
+ */
error = -ENOMEM;
- tracer = kzalloc(sizeof(*tracer), GFP_KERNEL);
+ tracer = kzalloc(sizeof(*tracer), GFP_ATOMIC);
if (!tracer)
goto out;
tracer->ovfl = ovfl;
@@ -722,8 +731,12 @@ struct pebs_tracer *ds_request_pebs(stru
if (ovfl)
goto out;

+ /*
+ * Per-cpu tracing is typically requested using smp_call_function().
+ * We must not sleep.
+ */
error = -ENOMEM;
- tracer = kzalloc(sizeof(*tracer), GFP_KERNEL);
+ tracer = kzalloc(sizeof(*tracer), GFP_ATOMIC);
if (!tracer)
goto out;
tracer->ovfl = ovfl;
---------------------------------------------------------------------
Intel GmbH
Dornacher Strasse 1
85622 Feldkirchen/Muenchen Germany
Sitz der Gesellschaft: Feldkirchen bei Muenchen
Geschaeftsfuehrer: Douglas Lusk, Peter Gleissner, Hannes Schwaderer
Registergericht: Muenchen HRB 47456 Ust.-IdNr.
VAT Registration No.: DE129385895
Citibank Frankfurt (BLZ 502 109 00) 600119052

This e-mail and any attachments may contain confidential material for
the sole use of the intended recipient(s). Any review or distribution
by others is strictly prohibited. If you are not the intended
recipient, please contact the sender and delete all copies.


2009-03-19 16:12:37

by Ingo Molnar

[permalink] [raw]
Subject: Re: [patch] x86, bts: use atomic memory allocation


* Markus Metzger <[email protected]> wrote:

> Ds_request_bts() needs to allocate memory. It uses GFP_KERNEL.
>
> Hw-branch-tracer calls ds_request_bts() within on_each_cpu().
>
> Use atomic memory allocation to allow it to be used in that context.

the hw-branch-tracer still crashes during bootup. Have you tried the
config i sent to you, and have you tried to reproduce it? I've
attached another config that crashes.

Ingo


Attachments:
(No filename) (441.00 B)
config (60.62 kB)
crash.log (58.44 kB)
Download all attachments

2009-03-20 08:09:29

by Metzger, Markus T

[permalink] [raw]
Subject: RE: [patch] x86, bts: use atomic memory allocation

>-----Original Message-----
>From: Ingo Molnar [mailto:[email protected]]
>Sent: Thursday, March 19, 2009 5:12 PM
>To: Metzger, Markus T


>> Ds_request_bts() needs to allocate memory. It uses GFP_KERNEL.
>>
>> Hw-branch-tracer calls ds_request_bts() within on_each_cpu().
>>
>> Use atomic memory allocation to allow it to be used in that context.
>
>the hw-branch-tracer still crashes during bootup. Have you tried the
>config i sent to you, and have you tried to reproduce it? I've
>attached another config that crashes.

The first config boots OK.
The second config boots OK with the additional changes to keep the GFP_KERNEL
and move the ds_request_bts() calls out of the on_each_cpu() in the hw-branch-tracer.

I don't know yet what exactly causes the crash and if there is a simpler fix.

I'm not sure I did it right, though. None of the configs worked as-is. I had to
answer a few additional questions for each one.
Here's what I did:
$ cp config.bad .config
$ make oldconfig
<press return a few times>
$ make

What's strange in the log you sent is that I do not see any
"[ds] using <whatever> configuration" messages.
I don't see any error message, either. It simply stops when it starts testing
the hw-branch-tracer.

When I boot that configuration (without the additional patches), I get some
error dumps on the screen including a call trace. Unfortunately, the interesting
part scrolls out of the top of my screen and the boot stops.
Are those logs stored somewhere? I looked in /var/log/messages but I only
found messages from successful boots; /var/log/dmesg also seems to contain only
the last successful boot.
If I can't get the logs, is there a way to restrict the depth of the call trace?


I then bootet a defconfig kernel with some debugging enabled and I get the following
message:
[ 1.731080] inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
[ 1.731180] swapper/0 [HC1[1]:SC0[0]:HE0:SE1] takes:
[ 1.731180] (ds_lock){?.+...}, at: [<ffffffff8101560f>] ds_put_context+0x21/0xf3

How would I read this error message?
It's pretty clear that something is wrong with ds_lock, but what exactly is the
error condition that was detected?

Here's the full error log:
[ 1.730182] =================================
[ 1.730538] [ INFO: inconsistent lock state ]
[ 1.730719] 2.6.29-rc8 #1 SMP Thu Mar 19 20:39:13 CET 2009
[ 1.730900] ---------------------------------
[ 1.731080] inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
[ 1.731180] swapper/0 [HC1[1]:SC0[0]:HE0:SE1] takes:
[ 1.731180] (ds_lock){?.+...}, at: [<ffffffff8101560f>] ds_put_context+0x21/0xf3
[ 1.731180] {HARDIRQ-ON-W} state was registered at:
[ 1.731180] [<ffffffff8105f4f0>] __lock_acquire+0x29c/0xb61
[ 1.731180] [<ffffffff8106077c>] lock_acquire+0xbc/0xe0
[ 1.731180] [<ffffffff814bb19c>] _spin_lock+0x2c/0x38
[ 1.731180] [<ffffffff81015ab1>] ds_request+0xee/0x214
[ 1.731180] [<ffffffff81015e41>] ds_request_bts+0xab/0x18d
[ 1.731180] [<ffffffff81015f44>] ds_request_bts_cpu+0x21/0x23
[ 1.731180] [<ffffffff81016583>] ds_selftest_bts+0x74/0x161
[ 1.731180] [<ffffffff817dd553>] ds_selftest+0x12/0x6e
[ 1.731180] [<ffffffff8100905c>] do_one_initcall+0x56/0x130
[ 1.731180] [<ffffffff817d78dd>] kernel_init+0x139/0x191
[ 1.731180] [<ffffffff8100cc3a>] child_rip+0xa/0x20
[ 1.731180] [<ffffffffffffffff>] 0xffffffffffffffff
[ 1.731180] irq event stamp: 48158
[ 1.731180] hardirqs last enabled at (48157): [<ffffffff8100c63c>] restore_args+0x0/0x30
[ 1.731180] hardirqs last disabled at (48158): [<ffffffff8100b967>] save_args+0x67/0x70
[ 1.731180] softirqs last enabled at (48084): [<ffffffff81042964>] __do_softirq+0x197/0x1a6
[ 1.731180] softirqs last disabled at (48067): [<ffffffff8100cd3c>] call_softirq+0x1c/0x34
[ 1.731180]
[ 1.731180] other info that might help us debug this:
[ 1.731180] no locks held by swapper/0.
[ 1.731180]
[ 1.731180] stack backtrace:
[ 1.731180] Pid: 0, comm: swapper Not tainted 2.6.29-rc8 #1 SMP Thu Mar 19 20:39:13 CET 2009
[ 1.731180] Call Trace:
[ 1.731180] <IRQ> [<ffffffff8105e8f5>] valid_state+0x179/0x18c
[ 1.731180] [<ffffffff8105e727>] ? check_usage_forwards+0x0/0x55
[ 1.731180] [<ffffffff8105e9e3>] mark_lock+0xdb/0x1ff
[ 1.731180] [<ffffffff8105f482>] __lock_acquire+0x22e/0xb61
[ 1.731180] [<ffffffff8105e92a>] ? mark_lock+0x22/0x1ff
[ 1.731180] [<ffffffff8106077c>] lock_acquire+0xbc/0xe0
[ 1.731180] [<ffffffff8101560f>] ? ds_put_context+0x21/0xf3
[ 1.731180] [<ffffffff814bb19c>] _spin_lock+0x2c/0x38
[ 1.731180] [<ffffffff8101560f>] ? ds_put_context+0x21/0xf3
[ 1.731180] [<ffffffff8101560f>] ds_put_context+0x21/0xf3
[ 1.731180] [<ffffffff810157d3>] ds_free_bts+0x73/0x7f
[ 1.731180] [<ffffffff81015822>] ds_release_bts_noirq+0x43/0x4b
[ 1.731180] [<ffffffff81016278>] ds_release_bts_noirq_wrap+0x9/0xb
[ 1.731180] [<ffffffff81065308>] generic_smp_call_function_single_interrupt+0x97/0xe3
[ 1.731180] [<ffffffff8101e18a>] smp_call_function_single_interrupt+0x13/0x23
[ 1.731180] [<ffffffff8100c8d3>] call_function_single_interrupt+0x13/0x20
[ 1.731180] <EOI> [<ffffffff814bd7db>] ? __atomic_notifier_call_chain+0x0/0x87
[ 1.731180] [<ffffffff81012827>] ? mwait_idle+0x7c/0x99
[ 1.731180] [<ffffffff8101281e>] ? mwait_idle+0x73/0x99
[ 1.731180] [<ffffffff814bd871>] ? atomic_notifier_call_chain+0xf/0x11
[ 1.731180] [<ffffffff8100a89b>] ? enter_idle+0x20/0x22
[ 1.731180] [<ffffffff8100abb9>] ? cpu_idle+0x57/0x86
[ 1.731180] [<ffffffff814b53d4>] ? start_secondary+0x18e/0x192
[ 1.742370] failed.
[ 1.742550] ------------[ cut here ]------------


thanks,
markus.
---------------------------------------------------------------------
Intel GmbH
Dornacher Strasse 1
85622 Feldkirchen/Muenchen Germany
Sitz der Gesellschaft: Feldkirchen bei Muenchen
Geschaeftsfuehrer: Douglas Lusk, Peter Gleissner, Hannes Schwaderer
Registergericht: Muenchen HRB 47456 Ust.-IdNr.
VAT Registration No.: DE129385895
Citibank Frankfurt (BLZ 502 109 00) 600119052

This e-mail and any attachments may contain confidential material for
the sole use of the intended recipient(s). Any review or distribution
by others is strictly prohibited. If you are not the intended
recipient, please contact the sender and delete all copies.

2009-03-20 08:37:37

by Andi Kleen

[permalink] [raw]
Subject: Re: [patch] x86, bts: use atomic memory allocation


>
> When I boot that configuration (without the additional patches), I get some
> error dumps on the screen including a call trace. Unfortunately, the interesting
> part scrolls out of the top of my screen and the boot stops.

Standard ways to handle that:
- boot with vga=0x0f07 to get smaller fonts (if it doesn't work use vga=ask and select suitable number)
- use a serial console, possibly with earlyprintk
- use firescope if the system has a ieee1394 connection. That can access the log buffer. You
need a 1394 cable, but those are easy to get. See Documentation/debugging-via-ohci1394.txt

For this particular case it might be enough to move the selftest to run much later
and then use netconsole or similar after it has been set up.

-Andi

2009-03-20 16:24:05

by Metzger, Markus T

[permalink] [raw]
Subject: RE: [patch] x86, bts: use atomic memory allocation

>-----Original Message-----
>From: Metzger, Markus T
>Sent: Friday, March 20, 2009 9:08 AM
>To: Ingo Molnar


>>> Ds_request_bts() needs to allocate memory. It uses GFP_KERNEL.
>>>
>>> Hw-branch-tracer calls ds_request_bts() within on_each_cpu().
>>>
>>> Use atomic memory allocation to allow it to be used in that context.
>>
>>the hw-branch-tracer still crashes during bootup. Have you tried the
>>config i sent to you, and have you tried to reproduce it? I've
>>attached another config that crashes.
>
>The first config boots OK.
>The second config boots OK with the additional changes to keep the GFP_KERNEL
>and move the ds_request_bts() calls out of the on_each_cpu() in the hw-branch-tracer.

I must have been asleep this morning.
The first config boots OK.
The second config does not boot, at all. Even if I completely disable DS support in the config.
However, with the new patches, it boots as far as with DS disabled.
It then hangs after CFA self-test.

With DS enabled and without the patches, it stops with a call trace somewhere in
the hw-branch-tracer selftest.


>I then bootet a defconfig kernel with some debugging enabled and I get the following
>message:
>[ 1.731080] inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
>[ 1.731180] swapper/0 [HC1[1]:SC0[0]:HE0:SE1] takes:
>[ 1.731180] (ds_lock){?.+...}, at: [<ffffffff8101560f>] ds_put_context+0x21/0xf3

I fixed this, as well, meanwhile.


regards,
markus.
---------------------------------------------------------------------
Intel GmbH
Dornacher Strasse 1
85622 Feldkirchen/Muenchen Germany
Sitz der Gesellschaft: Feldkirchen bei Muenchen
Geschaeftsfuehrer: Douglas Lusk, Peter Gleissner, Hannes Schwaderer
Registergericht: Muenchen HRB 47456 Ust.-IdNr.
VAT Registration No.: DE129385895
Citibank Frankfurt (BLZ 502 109 00) 600119052

This e-mail and any attachments may contain confidential material for
the sole use of the intended recipient(s). Any review or distribution
by others is strictly prohibited. If you are not the intended
recipient, please contact the sender and delete all copies.

2009-03-20 18:56:29

by Ingo Molnar

[permalink] [raw]
Subject: Re: [patch] x86, bts: use atomic memory allocation


* Metzger, Markus T <[email protected]> wrote:

> >-----Original Message-----
> >From: Ingo Molnar [mailto:[email protected]]
> >Sent: Thursday, March 19, 2009 5:12 PM
> >To: Metzger, Markus T
>
>
> >> Ds_request_bts() needs to allocate memory. It uses GFP_KERNEL.
> >>
> >> Hw-branch-tracer calls ds_request_bts() within on_each_cpu().
> >>
> >> Use atomic memory allocation to allow it to be used in that context.
> >
> >the hw-branch-tracer still crashes during bootup. Have you tried the
> >config i sent to you, and have you tried to reproduce it? I've
> >attached another config that crashes.
>
> The first config boots OK.

> The second config boots OK with the additional changes to keep the
> GFP_KERNEL and move the ds_request_bts() calls out of the
> on_each_cpu() in the hw-branch-tracer.
>
> I don't know yet what exactly causes the crash and if there is a
> simpler fix.

hm, this was an AMD box - so perhaps they dont have a compatible DS
implementation?

Ingo

2009-03-20 19:00:32

by Markus Metzger

[permalink] [raw]
Subject: Re: [patch] x86, bts: use atomic memory allocation

On Fri, 2009-03-20 at 19:55 +0100, Ingo Molnar wrote:
> * Metzger, Markus T <[email protected]> wrote:
>

> > The second config boots OK with the additional changes to keep the
> > GFP_KERNEL and move the ds_request_bts() calls out of the
> > on_each_cpu() in the hw-branch-tracer.
> >
> > I don't know yet what exactly causes the crash and if there is a
> > simpler fix.
>
> hm, this was an AMD box - so perhaps they dont have a compatible DS
> implementation?

Hmmm, could be.

In that case, ds_cfg should be zero-initialized and ds_request should
return -EOPNOTSUPP. I'll try to simulate that.

regards,
markus.

2009-03-25 09:07:56

by Metzger, Markus T

[permalink] [raw]
Subject: RE: [patch] x86, bts: use atomic memory allocation

>-----Original Message-----
>From: Ingo Molnar [mailto:[email protected]]
>Sent: Friday, March 20, 2009 7:56 PM
>To: Metzger, Markus T


>> >> Ds_request_bts() needs to allocate memory. It uses GFP_KERNEL.
>> >>
>> >> Hw-branch-tracer calls ds_request_bts() within on_each_cpu().
>> >>
>> >> Use atomic memory allocation to allow it to be used in that context.
>> >
>> >the hw-branch-tracer still crashes during bootup. Have you tried the
>> >config i sent to you, and have you tried to reproduce it? I've
>> >attached another config that crashes.
>>
>> The first config boots OK.
>
>> The second config boots OK with the additional changes to keep the
>> GFP_KERNEL and move the ds_request_bts() calls out of the
>> on_each_cpu() in the hw-branch-tracer.
>>
>> I don't know yet what exactly causes the crash and if there is a
>> simpler fix.
>
>hm, this was an AMD box - so perhaps they dont have a compatible DS
>implementation?

If no trace hardware is detected, the hw-branch tracer returns -EOPNOTSUPP.
I doubt that there is an incompatible DS implementation.


I found a bug that leads to a kernel crash.

If the tracing task exits, it disables bts tracing for all its children and then
frees the trace buffer. If the children are currently executing, the buffer
may be freed while the hardware is still tracing. This might cause the hardware to
overwrite memory.

I would need to wait until the traced task is rescheduled, trigger a rescheduling,
or actively disable tracing on the traced task's cpu.

Unfortunately, most of the ptrace exit code is executed with irq's disabled and
tasklist_lock write-held.
I am currently trying to find a way to do this at a time when irq's are enabled.

This affects the ptrace bts extension for .29 and tip/tracing/hw-branch-tracing.
The hw-branch-tracer is not affected.


regards,
markus.
---------------------------------------------------------------------
Intel GmbH
Dornacher Strasse 1
85622 Feldkirchen/Muenchen Germany
Sitz der Gesellschaft: Feldkirchen bei Muenchen
Geschaeftsfuehrer: Douglas Lusk, Peter Gleissner, Hannes Schwaderer
Registergericht: Muenchen HRB 47456 Ust.-IdNr.
VAT Registration No.: DE129385895
Citibank Frankfurt (BLZ 502 109 00) 600119052

This e-mail and any attachments may contain confidential material for
the sole use of the intended recipient(s). Any review or distribution
by others is strictly prohibited. If you are not the intended
recipient, please contact the sender and delete all copies.