Re: [Bug 8473] New: Oops: 0010 [1] SMP

Re: [Bug 8473] New: Oops: 0010 [1] SMP

[Andrew Morton]

On Sun, 13 May 2007 14:02:50 -0700 bugme-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=8473

Please follow up via emailed reply-to-all.

In fact, please report -mm bugs via email.  bugzilla is more suited to
longer-term problems, and -mm bugs are super-short-term, we hope.


>            Summary: Oops: 0010 [1] SMP
>     Kernel Version: 2.6.21-mm2
>             Status: NEW
>           Severity: high
>              Owner: akpm@osdl.org
>          Submitter: Nicolas.Mailhot@LaPoste.net
> 
> 
> Most recent kernel where this bug did *NOT* occur: 2.6.21-mm1 (though I didn't
> test it that long)
> Distribution: Fedora Devel
> Hardware Environment: AMD C2 on CK804
> Software Environment: Normal workload (building a small package)
> Problem Description:
> 
> Steps to reproduce:
> May 13 22:59:43 rousalka kernel: Unable to handle kernel NULL pointer
> dereference at 0000000000000000 RIP: 
> May 13 22:59:43 rousalka kernel: [<0000000000000000>]
> May 13 22:59:43 rousalka kernel: PGD bf1a067 PUD f295067 PMD 0 
> May 13 22:59:43 rousalka kernel: Oops: 0010 [1] SMP 
> May 13 22:59:43 rousalka kernel: CPU 0 
> May 13 22:59:43 rousalka kernel: Pid: 8758, comm: bash Not tainted
> 2.6.21-9.mm2.fc7.nim #1
> May 13 22:59:43 rousalka kernel: RIP: 0010:[<0000000000000000>] 
> [<0000000000000000>]
> May 13 22:59:43 rousalka kernel: RSP: 0018:ffff81000ffedee0  EFLAGS: 00010296
> May 13 22:59:43 rousalka kernel: RAX: ffffffff804426a0 RBX: ffff81000abe6a80
> RCX: 00007fff565bbdc4
> May 13 22:59:43 rousalka kernel: RDX: 0000000000005410 RSI: ffff81000abe6a80
> RDI: ffff810009cc6fa0
> May 13 22:59:43 rousalka kernel: RBP: 00007fff565bbdc4 R08: 0000000000000000
> R09: 00000000009033a4
> May 13 22:59:43 rousalka kernel: R10: 0000000000000008 R11: 0000000000000246
> R12: 0000000000005410
> May 13 22:59:43 rousalka kernel: R13: 00000000000000ff R14: 00000000000000ff
> R15: 0000000000000000
> May 13 22:59:43 rousalka kernel: FS:  00002b2d544faf40(0000)
> GS:ffffffff8056b000(0000) knlGS:0000000000000000
> May 13 22:59:43 rousalka kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> May 13 22:59:43 rousalka kernel: CR2: 0000000000000000 CR3: 000000000bdf4000
> CR4: 00000000000006e0
> May 13 22:59:43 rousalka kernel: Process bash (pid: 8758, threadinfo
> ffff81000ffec000, task ffff81000bc82ac0)
> May 13 22:59:43 rousalka kernel: Stack:  ffffffff8028545d ffff81000abe6a80
> 00007fff565bbdc4 00007fff565bbdc4
> May 13 22:59:43 rousalka kernel: ffffffff802856ca 0000000000005410
> 00000000000000ff ffff81000abe6a80
> May 13 22:59:43 rousalka kernel: 0000000000000000 00007fff565bbdc4
> 0000000000005410 00000000000000ff
> May 13 22:59:43 rousalka kernel: Call Trace:
> May 13 22:59:43 rousalka kernel: [<ffffffff8028545d>] do_ioctl+0x55/0x6b
> May 13 22:59:43 rousalka kernel: [<ffffffff802856ca>] vfs_ioctl+0x257/0x270
> May 13 22:59:43 rousalka kernel: [<ffffffff8028573c>] sys_ioctl+0x59/0x79
> May 13 22:59:43 rousalka kernel: [<ffffffff8020955c>] tracesys+0xdc/0xe1
> May 13 22:59:43 rousalka kernel: 
> May 13 22:59:43 rousalka kernel: INFO: lockdep is turned off.
> May 13 22:59:43 rousalka kernel: 
> May 13 22:59:43 rousalka kernel: Code:  Bad RIP value.
> May 13 22:59:43 rousalka kernel: RIP  [<0000000000000000>]
> May 13 22:59:43 rousalka kernel: RSP <ffff81000ffedee0>
> May 13 22:59:43 rousalka kernel: CR2: 0000000000000000

Anything you can do to make that wordwrapping go away for ever would be
great, thanks.

I don't know what would have caused this.  do_ioctl() did a jump-to-zero,
but it has code in there to explicitly test for null pointers.

Perhaps some weird race, although I find it hard to imagine how we could
have such a race in any ioctl which bash is likely to be calling.

Is it repeatable at all?

Re: [Bug 8473] New: Oops: 0010 [1] SMP

[Nicolas Mailhot]

[-- Attachment #1: Type: text/plain, Size: 1301 bytes --]

Le dimanche 13 mai 2007 à 15:47 -0700, Andrew Morton a écrit :
> On Sun, 13 May 2007 14:02:50 -0700 bugme-daemon@bugzilla.kernel.org wrote:
> 
> > http://bugzilla.kernel.org/show_bug.cgi?id=8473
> 
> Please follow up via emailed reply-to-all.
> 
> In fact, please report -mm bugs via email.  bugzilla is more suited to
> longer-term problems, and -mm bugs are super-short-term, we hope.

Can't attach trace screenshots or long log dumps to mails :(

> May 13 22:59:43 rousalka kernel: Unable to handle kernel NULL pointer
> dereference at 0000000000000000 RIP: 
> May 13 22:59:43 rousalka kernel: [<0000000000000000>]

> Anything you can do to make that wordwrapping go away for ever would be
> great, thanks.

You have the full kernel log with no wrapping there
http://bugzilla.kernel.org/attachment.cgi?id=11492

> I don't know what would have caused this.  do_ioctl() did a jump-to-zero,
> but it has code in there to explicitly test for null pointers.
> 
> Perhaps some weird race, although I find it hard to imagine how we could
> have such a race in any ioctl which bash is likely to be calling.
> 
> Is it repeatable at all?

It happened once so far. The load was moderate (and certainly not
comparable to what I did for Mel yesterday)

-- 
Nicolas Mailhot

[-- Attachment #2: Ceci est une partie de message numériquement signée --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: [Bug 8473] New: Oops: 0010 [1] SMP

[Nicolas Mailhot]

[-- Attachment #1: Type: text/plain, Size: 2253 bytes --]

Le lundi 14 mai 2007 à 01:25 +0200, Nicolas Mailhot a écrit :

> It happened once so far. The load was moderate (and certainly not
> comparable to what I did for Mel yesterday)

Make that twice. The interesting thing is it was preceded by CD/DVD
access just before, to something is rotten there.

10:52:35 ISO 9660 Extensions: RRIP_1991A
11:52:36 Unable to handle kernel NULL pointer dereference at 0000000000000000 RIP: 
11:52:36 [<0000000000000000>]
11:52:36 PGD 2438a067 PUD c484067 PMD 0 
11:52:36 Oops: 0010 [1] SMP 
11:52:36 CPU 1 
11:52:36 Pid: 30655, comm: bash Not tainted 2.6.21-11.mm2.fc7.nim #1
11:52:36 RIP: 0010:[<0000000000000000>]  [<0000000000000000>]
11:52:36 RSP: 0000:ffff810006199ee0  EFLAGS: 00010296
11:52:36 RAX: ffffffff804426a0 RBX: ffff81000903f800 RCX: 00007fff8a5e9874
11:52:36 RDX: 0000000000005410 RSI: ffff81000903f800 RDI: ffff810006a37b88
11:52:36 RBP: 00007fff8a5e9874 R08: 0000000000000000 R09: 0000000000000004
11:52:36 R10: 0000000000000008 R11: 0000000000000246 R12: 0000000000005410
11:52:36 R13: 00000000000000ff R14: 00000000000000ff R15: 0000000000000008
11:52:36 FS:  00002b1c204ccf40(0000) GS:ffff810004017180(0000) knlGS:0000000000000000
11:52:36 CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
11:52:36 CR2: 0000000000000000 CR3: 000000000f83b000 CR4: 00000000000006e0
11:52:36 Process bash (pid: 30655, threadinfo ffff810006198000, task ffff810024319c80)
11:52:36 Stack:  ffffffff80285451 ffff81000903f800 00007fff8a5e9874 00007fff8a5e9874
11:52:36 ffffffff802856be 0000000000005410 00000000000000ff ffff81000903f800
11:52:36 0000000000000000 00007fff8a5e9874 0000000000005410 00000000000000ff
11:52:36 Call Trace:
11:52:36 [<ffffffff80285451>] do_ioctl+0x55/0x6b
11:52:36 [<ffffffff802856be>] vfs_ioctl+0x257/0x270
11:52:36 [<ffffffff80285730>] sys_ioctl+0x59/0x79
11:52:36 [<ffffffff8020955c>] tracesys+0xdc/0xe1
11:52:36 
11:52:36 INFO: lockdep is turned off.
11:52:36 
11:52:36 Code:  Bad RIP value.
11:52:36 RIP  [<0000000000000000>]
11:52:36 RSP <ffff810006199ee0>
11:52:36 CR2: 0000000000000000

I'd try rc2-mm1, but I don't know if the patches of Mel Gorman &
Christoph Lameter for bug #8464 have been merged yet

Regards,

-- 
Nicolas Mailhot

[-- Attachment #2: Ceci est une partie de message numériquement signée --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: [Bug 8473] New: Oops: 0010 [1] SMP

[Randy Dunlap]

On Thu, 17 May 2007 12:00:02 +0200 Nicolas Mailhot wrote:

> Le lundi 14 mai 2007 à 01:25 +0200, Nicolas Mailhot a écrit :
> 
> > It happened once so far. The load was moderate (and certainly not
> > comparable to what I did for Mel yesterday)
> 
> Make that twice. The interesting thing is it was preceded by CD/DVD
> access just before, to something is rotten there.
> 
> 10:52:35 ISO 9660 Extensions: RRIP_1991A
> 11:52:36 Unable to handle kernel NULL pointer dereference at 0000000000000000 RIP: 
> 11:52:36 [<0000000000000000>]
> 11:52:36 PGD 2438a067 PUD c484067 PMD 0 
> 11:52:36 Oops: 0010 [1] SMP 
> 11:52:36 CPU 1 
> 11:52:36 Pid: 30655, comm: bash Not tainted 2.6.21-11.mm2.fc7.nim #1

so just what is this kernel?  A hybrid of -mm and -fc7 or what?

> 11:52:36 RIP: 0010:[<0000000000000000>]  [<0000000000000000>]
> 11:52:36 RSP: 0000:ffff810006199ee0  EFLAGS: 00010296
> 11:52:36 RAX: ffffffff804426a0 RBX: ffff81000903f800 RCX: 00007fff8a5e9874
> 11:52:36 RDX: 0000000000005410 RSI: ffff81000903f800 RDI: ffff810006a37b88
> 11:52:36 RBP: 00007fff8a5e9874 R08: 0000000000000000 R09: 0000000000000004
> 11:52:36 R10: 0000000000000008 R11: 0000000000000246 R12: 0000000000005410
> 11:52:36 R13: 00000000000000ff R14: 00000000000000ff R15: 0000000000000008
> 11:52:36 FS:  00002b1c204ccf40(0000) GS:ffff810004017180(0000) knlGS:0000000000000000
> 11:52:36 CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> 11:52:36 CR2: 0000000000000000 CR3: 000000000f83b000 CR4: 00000000000006e0
> 11:52:36 Process bash (pid: 30655, threadinfo ffff810006198000, task ffff810024319c80)
> 11:52:36 Stack:  ffffffff80285451 ffff81000903f800 00007fff8a5e9874 00007fff8a5e9874
> 11:52:36 ffffffff802856be 0000000000005410 00000000000000ff ffff81000903f800
> 11:52:36 0000000000000000 00007fff8a5e9874 0000000000005410 00000000000000ff
> 11:52:36 Call Trace:
> 11:52:36 [<ffffffff80285451>] do_ioctl+0x55/0x6b
> 11:52:36 [<ffffffff802856be>] vfs_ioctl+0x257/0x270
> 11:52:36 [<ffffffff80285730>] sys_ioctl+0x59/0x79
> 11:52:36 [<ffffffff8020955c>] tracesys+0xdc/0xe1
> 11:52:36 
> 11:52:36 INFO: lockdep is turned off.
> 11:52:36 
> 11:52:36 Code:  Bad RIP value.
> 11:52:36 RIP  [<0000000000000000>]
> 11:52:36 RSP <ffff810006199ee0>
> 11:52:36 CR2: 0000000000000000
> 
> I'd try rc2-mm1, but I don't know if the patches of Mel Gorman &
> Christoph Lameter for bug #8464 have been merged yet

Can you boot with "kstack=32" so that we can see more of the stack?


---
~Randy
*** Remember to use Documentation/SubmitChecklist when testing your code ***

Re: [Bug 8473] New: Oops: 0010 [1] SMP

[Nicolas Mailhot]

[-- Attachment #1: Type: text/plain, Size: 1265 bytes --]

Le jeudi 17 mai 2007 à 09:45 -0700, Randy Dunlap a écrit :
> On Thu, 17 May 2007 12:00:02 +0200 Nicolas Mailhot wrote:
> 
> > Le lundi 14 mai 2007 à 01:25 +0200, Nicolas Mailhot a écrit :
> > 
> > > It happened once so far. The load was moderate (and certainly not
> > > comparable to what I did for Mel yesterday)
> > 
> > Make that twice. The interesting thing is it was preceded by CD/DVD
> > access just before, to something is rotten there.
> > 
> > 10:52:35 ISO 9660 Extensions: RRIP_1991A
> > 11:52:36 Unable to handle kernel NULL pointer dereference at 0000000000000000 RIP: 
> > 11:52:36 [<0000000000000000>]
> > 11:52:36 PGD 2438a067 PUD c484067 PMD 0 
> > 11:52:36 Oops: 0010 [1] SMP 
> > 11:52:36 CPU 1 
> > 11:52:36 Pid: 30655, comm: bash Not tainted 2.6.21-11.mm2.fc7.nim #1
> 
> so just what is this kernel?  A hybrid of -mm and -fc7 or what?

-mm + md-improve-partition-detection-in-md-array.patch revert + Mel's
patches for bug #8464 + the fedora nouveau patch

the fc7.nim is there because it was build in an F7 buildroot, not
because it carries the full Fedora patchset

> Can you boot with "kstack=32" so that we can see more of the stack?

I can try. It's not triggering quickly though

-- 
Nicolas Mailhot

[-- Attachment #2: Ceci est une partie de message numériquement signée --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: [Bug 8473] New: Oops: 0010 [1] SMP

[Nicolas Mailhot]

[-- Attachment #1: Type: text/plain, Size: 2710 bytes --]

Le jeudi 17 mai 2007 à 18:59 +0200, Nicolas Mailhot a écrit :
> Le jeudi 17 mai 2007 à 09:45 -0700, Randy Dunlap a écrit :
> 
> > Can you boot with "kstack=32" so that we can see more of the stack?
> 
> I can try. It's not triggering quickly though

Seems I was completely wrong about the trigger, but anyway it happened
again, this time on 2.6.22-rc2.mm1.cfs14 (and I had kept kstack=32)

 BUG: using smp_processor_id() in preemptible [00000001] code: bash/3857
 caller is oops_begin+0xb/0x6f
 
 Call Trace:
 [<ffffffff8020ab4d>] show_trace+0x34/0x4f
 [<ffffffff8020ab7a>] dump_stack+0x12/0x17
 [<ffffffff8030d92d>] debug_smp_processor_id+0xad/0xbc
 [<ffffffff8042388f>] oops_begin+0xb/0x6f
 [<ffffffff8042520b>] do_page_fault+0x66a/0x7c0
 [<ffffffff804234bd>] error_exit+0x0/0x84
 
 Unable to handle kernel NULL pointer dereference at 0000000000000000 RIP: 
 [<0000000000000000>]
 PGD bdd2067 PUD c133067 PMD 0 
 Oops: 0010 [1] PREEMPT SMP 
 CPU 1 
 Pid: 3857, comm: bash Not tainted 2.6.22-0.8.rc2.mm1.cfs14.fc8.nim #1
 RIP: 0010:[<0000000000000000>]  [<0000000000000000>]
 RSP: 0018:ffff81000cb03ee0  EFLAGS: 00010296
 RAX: ffffffff8044dbc0 RBX: ffff81000c3aa8c0 RCX: 00007fff549dcae4
 RDX: 0000000000005410 RSI: ffff81000c3aa8c0 RDI: ffff81000ba913d8
 RBP: 00007fff549dcae4 R08: 0000000000000000 R09: 00000000ffffffff
 R10: 0000000000000008 R11: 0000000000000246 R12: 0000000000005410
 R13: 00000000000000ff R14: 00000000000000ff R15: 0000000000000000
 FS:  00002b06560d8f40(0000) GS:ffff810004017180(0000) knlGS:0000000000000000
 CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
 CR2: 0000000000000000 CR3: 000000000bc55000 CR4: 00000000000006e0
 Process bash (pid: 3857, threadinfo ffff81000cb02000, task ffff81000adc59a0)
 Stack:  ffffffff8028ada9 ffff81000c3aa8c0 00007fff549dcae4 00007fff549dcae4
 ffffffff8028b016 0000000000005410 00000000000000ff ffff81000c3aa8c0
 0000000000000000 00007fff549dcae4 0000000000005410 00000000000000ff
 ffffffff8028b088 0000000000000000 0000000080209571 00000000ffffffff
 00007fff549dce87 0000000000000f11 00007fff549dcfb8 00007fff549dddb0
 ffffffff802095dc 0000000000000246 0000000000000008 00000000ffffffff
 0000000000000000 ffffffffffffffda ffffffffffffffff 00007fff549dcae4
 0000000000005410 00000000000000ff 0000000000000010 0000003d340c9117
 Call Trace:
 Inexact backtrace:
 [<ffffffff8028ada9>] do_ioctl+0x55/0x6b
 [<ffffffff8028b016>] vfs_ioctl+0x257/0x270
 [<ffffffff8028b088>] sys_ioctl+0x59/0x79
 [<ffffffff802095dc>] tracesys+0xdc/0xe1
 
 INFO: lockdep is turned off.
 
 Code:  Bad RIP value.
 RIP  [<0000000000000000>]
 RSP <ffff81000cb03ee0>
 CR2: 0000000000000000

-- 
Nicolas Mailhot

[-- Attachment #2: Ceci est une partie de message numériquement signée --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: [Bug 8473] New: Oops: 0010 [1] SMP

[Björn Steinbrink]

On 2007.05.26 21:10:15 +0200, Nicolas Mailhot wrote:
> Le jeudi 17 mai 2007 à 18:59 +0200, Nicolas Mailhot a écrit :
> > Le jeudi 17 mai 2007 à 09:45 -0700, Randy Dunlap a écrit :
> > 
> > > Can you boot with "kstack=32" so that we can see more of the stack?
> > 
> > I can try. It's not triggering quickly though
> 
> Seems I was completely wrong about the trigger, but anyway it happened
> again, this time on 2.6.22-rc2.mm1.cfs14 (and I had kept kstack=32)
> 
>  BUG: using smp_processor_id() in preemptible [00000001] code: bash/3857
>  caller is oops_begin+0xb/0x6f
>  
>  Call Trace:
>  [<ffffffff8020ab4d>] show_trace+0x34/0x4f
>  [<ffffffff8020ab7a>] dump_stack+0x12/0x17
>  [<ffffffff8030d92d>] debug_smp_processor_id+0xad/0xbc
>  [<ffffffff8042388f>] oops_begin+0xb/0x6f
>  [<ffffffff8042520b>] do_page_fault+0x66a/0x7c0
>  [<ffffffff804234bd>] error_exit+0x0/0x84
>  
>  Unable to handle kernel NULL pointer dereference at 0000000000000000 RIP: 
>  [<0000000000000000>]
>  PGD bdd2067 PUD c133067 PMD 0 
>  Oops: 0010 [1] PREEMPT SMP 
>  CPU 1 
>  Pid: 3857, comm: bash Not tainted 2.6.22-0.8.rc2.mm1.cfs14.fc8.nim #1
>  RIP: 0010:[<0000000000000000>]  [<0000000000000000>]
>  RSP: 0018:ffff81000cb03ee0  EFLAGS: 00010296
>  RAX: ffffffff8044dbc0 RBX: ffff81000c3aa8c0 RCX: 00007fff549dcae4
>  RDX: 0000000000005410 RSI: ffff81000c3aa8c0 RDI: ffff81000ba913d8
>  RBP: 00007fff549dcae4 R08: 0000000000000000 R09: 00000000ffffffff
>  R10: 0000000000000008 R11: 0000000000000246 R12: 0000000000005410
>  R13: 00000000000000ff R14: 00000000000000ff R15: 0000000000000000
>  FS:  00002b06560d8f40(0000) GS:ffff810004017180(0000) knlGS:0000000000000000
>  CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
>  CR2: 0000000000000000 CR3: 000000000bc55000 CR4: 00000000000006e0
>  Process bash (pid: 3857, threadinfo ffff81000cb02000, task ffff81000adc59a0)
>  Stack:  ffffffff8028ada9 ffff81000c3aa8c0 00007fff549dcae4 00007fff549dcae4
>  ffffffff8028b016 0000000000005410 00000000000000ff ffff81000c3aa8c0
>  0000000000000000 00007fff549dcae4 0000000000005410 00000000000000ff
>  ffffffff8028b088 0000000000000000 0000000080209571 00000000ffffffff
>  00007fff549dce87 0000000000000f11 00007fff549dcfb8 00007fff549dddb0
>  ffffffff802095dc 0000000000000246 0000000000000008 00000000ffffffff
>  0000000000000000 ffffffffffffffda ffffffffffffffff 00007fff549dcae4
>  0000000000005410 00000000000000ff 0000000000000010 0000003d340c9117
>  Call Trace:
>  Inexact backtrace:
>  [<ffffffff8028ada9>] do_ioctl+0x55/0x6b
>  [<ffffffff8028b016>] vfs_ioctl+0x257/0x270
>  [<ffffffff8028b088>] sys_ioctl+0x59/0x79
>  [<ffffffff802095dc>] tracesys+0xdc/0xe1
>  
>  INFO: lockdep is turned off.
>  
>  Code:  Bad RIP value.
>  RIP  [<0000000000000000>]
>  RSP <ffff81000cb03ee0>
>  CR2: 0000000000000000

This is do_tty_hangup() exchanging the fops while we're waiting for the
lock. The new fops (hung_up_tty_fops) only have the unlocked variant and
thus we Oops our way.

The following program reproduces it quite easily on a SMP box. I'm
running it from X as root like this:
while true; do xterm /path/to/program; done

#include <pthread.h>
#include <stdio.h>
#include <unistd.h>

#include <sys/ioctl.h>

pid_t pid;

void *thread(void *arg)
{
	while (1)
		ioctl(0, TIOCSPGRP, &pid);
}

int main()
{
	pthread_t t;

	pid = getpid();

	pthread_create(&t, NULL, thread, NULL);
	sleep(1);
	vhangup();
	perror("vhangup");
	return 0;
}

I'm not exactly sure how to solve that in a clean way, though. Moving
the call to lock_kernel() up would make the Oops go away, but could
result in the wrong error code being returned. Checking for ioctl first
and unlocked_ioctl last would cause useless locking. And retrying the
unlocked ioctl doesn't look nice either :-(

Björn

Re: [Bug 8473] New: Oops: 0010 [1] SMP

[Andrew Morton]

On Fri, 8 Jun 2007 05:06:29 +0200 Björn Steinbrink <B.Steinbrink@gmx.de> wrote:

> On 2007.05.26 21:10:15 +0200, Nicolas Mailhot wrote:
> > Le jeudi 17 mai 2007 à 18:59 +0200, Nicolas Mailhot a écrit :
> > > Le jeudi 17 mai 2007 à 09:45 -0700, Randy Dunlap a écrit :
> > > 
> > > > Can you boot with "kstack=32" so that we can see more of the stack?
> > > 
> > > I can try. It's not triggering quickly though
> > 
> > Seems I was completely wrong about the trigger, but anyway it happened
> > again, this time on 2.6.22-rc2.mm1.cfs14 (and I had kept kstack=32)
> > 
> >  BUG: using smp_processor_id() in preemptible [00000001] code: bash/3857
> >  caller is oops_begin+0xb/0x6f
> >  
> >  Call Trace:
> >  [<ffffffff8020ab4d>] show_trace+0x34/0x4f
> >  [<ffffffff8020ab7a>] dump_stack+0x12/0x17
> >  [<ffffffff8030d92d>] debug_smp_processor_id+0xad/0xbc
> >  [<ffffffff8042388f>] oops_begin+0xb/0x6f
> >  [<ffffffff8042520b>] do_page_fault+0x66a/0x7c0
> >  [<ffffffff804234bd>] error_exit+0x0/0x84

hm that was dumb.  I'll stick a raw_smp_processor_id() in there.

> >  Unable to handle kernel NULL pointer dereference at 0000000000000000 RIP: 
> >  [<0000000000000000>]
> >  PGD bdd2067 PUD c133067 PMD 0 
> >  Oops: 0010 [1] PREEMPT SMP 
> >  CPU 1 
> >  Pid: 3857, comm: bash Not tainted 2.6.22-0.8.rc2.mm1.cfs14.fc8.nim #1
> >  RIP: 0010:[<0000000000000000>]  [<0000000000000000>]
> >  RSP: 0018:ffff81000cb03ee0  EFLAGS: 00010296
> >  RAX: ffffffff8044dbc0 RBX: ffff81000c3aa8c0 RCX: 00007fff549dcae4
> >  RDX: 0000000000005410 RSI: ffff81000c3aa8c0 RDI: ffff81000ba913d8
> >  RBP: 00007fff549dcae4 R08: 0000000000000000 R09: 00000000ffffffff
> >  R10: 0000000000000008 R11: 0000000000000246 R12: 0000000000005410
> >  R13: 00000000000000ff R14: 00000000000000ff R15: 0000000000000000
> >  FS:  00002b06560d8f40(0000) GS:ffff810004017180(0000) knlGS:0000000000000000
> >  CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> >  CR2: 0000000000000000 CR3: 000000000bc55000 CR4: 00000000000006e0
> >  Process bash (pid: 3857, threadinfo ffff81000cb02000, task ffff81000adc59a0)
> >  Stack:  ffffffff8028ada9 ffff81000c3aa8c0 00007fff549dcae4 00007fff549dcae4
> >  ffffffff8028b016 0000000000005410 00000000000000ff ffff81000c3aa8c0
> >  0000000000000000 00007fff549dcae4 0000000000005410 00000000000000ff
> >  ffffffff8028b088 0000000000000000 0000000080209571 00000000ffffffff
> >  00007fff549dce87 0000000000000f11 00007fff549dcfb8 00007fff549dddb0
> >  ffffffff802095dc 0000000000000246 0000000000000008 00000000ffffffff
> >  0000000000000000 ffffffffffffffda ffffffffffffffff 00007fff549dcae4
> >  0000000000005410 00000000000000ff 0000000000000010 0000003d340c9117
> >  Call Trace:
> >  Inexact backtrace:
> >  [<ffffffff8028ada9>] do_ioctl+0x55/0x6b
> >  [<ffffffff8028b016>] vfs_ioctl+0x257/0x270
> >  [<ffffffff8028b088>] sys_ioctl+0x59/0x79
> >  [<ffffffff802095dc>] tracesys+0xdc/0xe1
> >  
> >  INFO: lockdep is turned off.
> >  
> >  Code:  Bad RIP value.
> >  RIP  [<0000000000000000>]
> >  RSP <ffff81000cb03ee0>
> >  CR2: 0000000000000000
> 
> This is do_tty_hangup() exchanging the fops while we're waiting for the
> lock. The new fops (hung_up_tty_fops) only have the unlocked variant and
> thus we Oops our way.

ah, yes, that explains it, thanks.  Culprit:

commit e10cc1df1d2014f68a4bdcf73f6dd122c4561f94
Author: Paul Fulghum <paulkf@microgate.com>
Date:   Thu May 10 22:22:50 2007 -0700

    tty: add compat_ioctl
    
    Add compat_ioctl method for tty code to allow processing of 32 bit ioctl
    calls on 64 bit systems by tty core, tty drivers, and line disciplines.
    
    Based on patch by Arnd Bergmann:
    http://www.uwsg.iu.edu/hypermail/linux/kernel/0511.0/1732.html
    
    [akpm@linux-foundation.org: make things static]
    Signed-off-by: Paul Fulghum <paulkf@microgate.com>
    Acked-by: Arnd Bergmann <arnd@arndb.de>
    Cc: Alan Cox <alan@lxorguk.ukuu.org.uk>
    Signed-off-by: Andrew Morton <akpm@linux-foundation.org>
    Signed-off-by: Linus Torvalds <torvalds@linux-foundation.org>


> The following program reproduces it quite easily on a SMP box. I'm
> running it from X as root like this:
> while true; do xterm /path/to/program; done
> 
> #include <pthread.h>
> #include <stdio.h>
> #include <unistd.h>
> 
> #include <sys/ioctl.h>
> 
> pid_t pid;
> 
> void *thread(void *arg)
> {
> 	while (1)
> 		ioctl(0, TIOCSPGRP, &pid);
> }
> 
> int main()
> {
> 	pthread_t t;
> 
> 	pid = getpid();
> 
> 	pthread_create(&t, NULL, thread, NULL);
> 	sleep(1);
> 	vhangup();
> 	perror("vhangup");
> 	return 0;
> }
> 
> I'm not exactly sure how to solve that in a clean way, though. Moving
> the call to lock_kernel() up would make the Oops go away, but could
> result in the wrong error code being returned. Checking for ioctl first
> and unlocked_ioctl last would cause useless locking. And retrying the
> unlocked ioctl doesn't look nice either :-(
> 
> Björn

Re: [Bug 8473] New: Oops: 0010 [1] SMP

[Paul Fulghum]

On Thu, 2007-06-07 at 20:16 -0700, Andrew Morton wrote:
> On Fri, 8 Jun 2007 05:06:29 +0200 Björn Steinbrink <B.Steinbrink@gmx.de> wrote:
> > This is do_tty_hangup() exchanging the fops while we're waiting for the
> > lock. The new fops (hung_up_tty_fops) only have the unlocked variant and
> > thus we Oops our way.
> 
> ah, yes, that explains it, thanks.  Culprit:
> 
> commit e10cc1df1d2014f68a4bdcf73f6dd122c4561f94
> Author: Paul Fulghum <paulkf@microgate.com>
> Date:   Thu May 10 22:22:50 2007 -0700
> 
>     tty: add compat_ioctl
>     
>     Add compat_ioctl method for tty code to allow processing of 32 bit ioctl
>     calls on 64 bit systems by tty core, tty drivers, and line disciplines.

OK, the change of hung_up_tty_ioctl() from locked to unlocked
is not necessary for this patch. On the surface it seemed a clever
way of not needing two different functions to do the same simple:

return cmd == TIOCSPGRP ? -ENOTTY : -EIO;

which does not need any locking for its own sake. But clearly
the hangup behavior requires the locked version.

I'll redo the patch with hung_up_tty_ioctl remaining locked.

That will separate the compat ioctl stuff from this issue.

-- 
Paul Fulghum
Microgate Systems, Ltd

Re: [Bug 8473] New: Oops: 0010 [1] SMP

[Paul Fulghum]

On Fri, 2007-06-08 at 05:06 +0200, Björn Steinbrink wrote:
> This is do_tty_hangup() exchanging the fops while we're waiting for the
> lock. The new fops (hung_up_tty_fops) only have the unlocked variant and
> thus we Oops our way.
> 
> The following program reproduces it quite easily on a SMP box. I'm
> running it from X as root like this:
> while true; do xterm /path/to/program; done

I am unable to reproduce the oops on either i386 SMP or x86_64 SMP
using your test program. This is against plain 2.6.21 with only
my compat ioctl patch applied.

Here is a patch that restores the locked ioctl for hung_up_tty_ioctl.
Can you try it and see if it removes your oops?

--- a/drivers/char/tty_io.c	2007-06-08 10:07:39.000000000 -0500
+++ b/drivers/char/tty_io.c	2007-06-08 10:09:59.000000000 -0500
@@ -1150,8 +1150,14 @@ static unsigned int hung_up_tty_poll(str
 	return POLLIN | POLLOUT | POLLERR | POLLHUP | POLLRDNORM | POLLWRNORM;
 }
 
-static long hung_up_tty_ioctl(struct file * file,
-			      unsigned int cmd, unsigned long arg)
+static int hung_up_tty_ioctl(struct inode * inode, struct file * file,
+			     unsigned int cmd, unsigned long arg)
+{
+	return cmd == TIOCSPGRP ? -ENOTTY : -EIO;
+}
+
+static long hung_up_tty_compat_ioctl(struct file * file,
+				     unsigned int cmd, unsigned long arg)
 {
 	return cmd == TIOCSPGRP ? -ENOTTY : -EIO;
 }
@@ -1199,8 +1205,8 @@ static const struct file_operations hung
 	.read		= hung_up_tty_read,
 	.write		= hung_up_tty_write,
 	.poll		= hung_up_tty_poll,
-	.unlocked_ioctl = hung_up_tty_ioctl,
-	.compat_ioctl	= hung_up_tty_ioctl,
+	.ioctl		= hung_up_tty_ioctl,
+	.compat_ioctl	= hung_up_tty_compat_ioctl,
 	.release	= tty_release,
 };
 

Re: [Bug 8473] New: Oops: 0010 [1] SMP

[Paul Fulghum]

On Fri, 2007-06-08 at 10:16 -0500, Paul Fulghum wrote:
> On Fri, 2007-06-08 at 05:06 +0200, Björn Steinbrink wrote:
> > This is do_tty_hangup() exchanging the fops while we're waiting for the
> > lock. The new fops (hung_up_tty_fops) only have the unlocked variant and
> > thus we Oops our way.
...
> Here is a patch that restores the locked ioctl for hung_up_tty_ioctl.
> Can you try it and see if it removes your oops?

Unfortunately I can't get the timing right to trigger this,
but it is very clear the locked ioctl fop must not be
allowed to disappear like my original patch allows.

Andrew:

Would you prefer I resend the entire compat ioctl patch or
submit an incremental patch like in my message I'm quoting above?

-- 
Paul Fulghum
Microgate Systems, Ltd

Re: [Bug 8473] New: Oops: 0010 [1] SMP

[Andrew Morton]

On Fri, 08 Jun 2007 14:20:48 -0500
Paul Fulghum <paulkf@microgate.com> wrote:

> On Fri, 2007-06-08 at 10:16 -0500, Paul Fulghum wrote:
> > On Fri, 2007-06-08 at 05:06 +0200, Bj__rn Steinbrink wrote:
> > > This is do_tty_hangup() exchanging the fops while we're waiting for the
> > > lock. The new fops (hung_up_tty_fops) only have the unlocked variant and
> > > thus we Oops our way.
> ...
> > Here is a patch that restores the locked ioctl for hung_up_tty_ioctl.
> > Can you try it and see if it removes your oops?
> 
> Unfortunately I can't get the timing right to trigger this,
> but it is very clear the locked ioctl fop must not be
> allowed to disappear like my original patch allows.
> 
> Andrew:
> 
> Would you prefer I resend the entire compat ioctl patch or
> submit an incremental patch like in my message I'm quoting above?
> 

The compat_ioctl patch is in mainline, and has been for some time.

Hence a patch against mainline would be appropriate, thanks.

[PATCH] tty restore locked ioctl file op

[Paul Fulghum]

Restore tty locked ioctl handler which was replaced with
an unlocked ioctl handler in hung_up_tty_fops by the patch:

commit e10cc1df1d2014f68a4bdcf73f6dd122c4561f94
Author: Paul Fulghum <paulkf@microgate.com>
Date:   Thu May 10 22:22:50 2007 -0700

    tty: add compat_ioctl

This was reported in:
[Bug 8473] New: Oops: 0010 [1] SMP

The bug is caused by switching to hung_up_tty_fops in do_tty_hangup.
An ioctl call can be waiting on BLK after testing for existence of
the locked ioctl handler in the normal tty fops, but before calling
the locked ioctl handler. If a hangup occurs at that point, the
locked ioctl fop is NULL and an oops occurs.

Signed-off-by: Paul Fulghum <paulkf@microgate.com>

--- a/drivers/char/tty_io.c	2007-06-08 14:26:10.000000000 -0500
+++ b/drivers/char/tty_io.c	2007-06-08 14:28:58.000000000 -0500
@@ -1173,8 +1173,14 @@ static unsigned int hung_up_tty_poll(str
 	return POLLIN | POLLOUT | POLLERR | POLLHUP | POLLRDNORM | POLLWRNORM;
 }
 
-static long hung_up_tty_ioctl(struct file * file,
-			      unsigned int cmd, unsigned long arg)
+static int hung_up_tty_ioctl(struct inode * inode, struct file * file,
+			     unsigned int cmd, unsigned long arg)
+{
+	return cmd == TIOCSPGRP ? -ENOTTY : -EIO;
+}
+
+static long hung_up_tty_compat_ioctl(struct file * file,
+				     unsigned int cmd, unsigned long arg)
 {
 	return cmd == TIOCSPGRP ? -ENOTTY : -EIO;
 }
@@ -1222,8 +1228,8 @@ static const struct file_operations hung
 	.read		= hung_up_tty_read,
 	.write		= hung_up_tty_write,
 	.poll		= hung_up_tty_poll,
-	.unlocked_ioctl = hung_up_tty_ioctl,
-	.compat_ioctl	= hung_up_tty_ioctl,
+	.ioctl		= hung_up_tty_ioctl,
+	.compat_ioctl	= hung_up_tty_compat_ioctl,
 	.release	= tty_release,
 };
 

Re: [PATCH] tty restore locked ioctl file op

[Björn Steinbrink]

On 2007.06.08 15:34:17 -0500, Paul Fulghum wrote:
> Restore tty locked ioctl handler which was replaced with
> an unlocked ioctl handler in hung_up_tty_fops by the patch:
> 
> commit e10cc1df1d2014f68a4bdcf73f6dd122c4561f94
> Author: Paul Fulghum <paulkf@microgate.com>
> Date:   Thu May 10 22:22:50 2007 -0700
> 
>     tty: add compat_ioctl
> 
> This was reported in:
> [Bug 8473] New: Oops: 0010 [1] SMP
> 
> The bug is caused by switching to hung_up_tty_fops in do_tty_hangup.
> An ioctl call can be waiting on BLK after testing for existence of
> the locked ioctl handler in the normal tty fops, but before calling
> the locked ioctl handler. If a hangup occurs at that point, the
> locked ioctl fop is NULL and an oops occurs.

Sorry for the delay, your mails didn't make it into my inbox, and I
usually just mark threads on which I'm Cc'ed as read in my lkml mailbox,
thus I didn't notice it earlier. Any traces of the lost mails on your
side?

The patch works as expected, no Oops in sight. Regarding the
reproducability, it might be that it was easier to trigger on rc1. When
I retried today with rc4, I only got 2 Oopses in a minute, while the
first test had spitten out about 20 Oopses in 10 seconds (not sure if I
really had rc1 running back then, though).

Thanks,
Björn

> Signed-off-by: Paul Fulghum <paulkf@microgate.com>
> 
> --- a/drivers/char/tty_io.c	2007-06-08 14:26:10.000000000 -0500
> +++ b/drivers/char/tty_io.c	2007-06-08 14:28:58.000000000 -0500
> @@ -1173,8 +1173,14 @@ static unsigned int hung_up_tty_poll(str
>  	return POLLIN | POLLOUT | POLLERR | POLLHUP | POLLRDNORM | POLLWRNORM;
>  }
>  
> -static long hung_up_tty_ioctl(struct file * file,
> -			      unsigned int cmd, unsigned long arg)
> +static int hung_up_tty_ioctl(struct inode * inode, struct file * file,
> +			     unsigned int cmd, unsigned long arg)
> +{
> +	return cmd == TIOCSPGRP ? -ENOTTY : -EIO;
> +}
> +
> +static long hung_up_tty_compat_ioctl(struct file * file,
> +				     unsigned int cmd, unsigned long arg)
>  {
>  	return cmd == TIOCSPGRP ? -ENOTTY : -EIO;
>  }
> @@ -1222,8 +1228,8 @@ static const struct file_operations hung
>  	.read		= hung_up_tty_read,
>  	.write		= hung_up_tty_write,
>  	.poll		= hung_up_tty_poll,
> -	.unlocked_ioctl = hung_up_tty_ioctl,
> -	.compat_ioctl	= hung_up_tty_ioctl,
> +	.ioctl		= hung_up_tty_ioctl,
> +	.compat_ioctl	= hung_up_tty_compat_ioctl,
>  	.release	= tty_release,
>  };
>  
> 
> 
> 
> -
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

Re: [PATCH] tty restore locked ioctl file op

[Paul Fulghum]

Björn Steinbrink wrote:
> Sorry for the delay, your mails didn't make it into my inbox, and I
> usually just mark threads on which I'm Cc'ed as read in my lkml mailbox,
> thus I didn't notice it earlier. Any traces of the lost mails on your
> side?

No clues on this end.

> The patch works as expected, no Oops in sight. Regarding the
> reproducability, it might be that it was easier to trigger on rc1. When
> I retried today with rc4, I only got 2 Oopses in a minute, while the
> first test had spitten out about 20 Oopses in 10 seconds (not sure if I
> really had rc1 running back then, though).

I'm sure it's very timing dependent.
I'm confident with this fix.

Thanks for your help.

--
Paul