Skip to contentSkip to conversation

New: Oops: 0010 [1] SMP

Bug 8473 In review Andrew Morton 5 participants 15 messages May 13, 2007 – Jun 9, 2007 1 message not in the archive Char and misc drivers

lore
Share & tools
lore

A message that is not in the archive (sent off-list or not yet received): [email protected]

Andrew Morton

author
#1 lore raw
Quoted 1 line · On Sun, 13 May 2007 14:02:50 -0700 [email protected] 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.

Quoted 54 lines
           Summary: Oops: 0010 [1] SMP
    Kernel Version: 2.6.21-mm2
            Status: NEW
          Severity: high
             Owner: [email protected]
         Submitter: [email protected]

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
Quoted 8 lines
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?

#2 lore raw
Quoted 8 lines · Andrew Morton
Quoted 1 line · On Sun, 13 May 2007 14:02:50 -0700 [email protected] 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 :(

Quoted 6 lines
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

Quoted 7 lines

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)

Signature · 1 line
Nicolas Mailhot
#3 lore raw
Quoted 2 lines · Nicolas Mailhot

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,

Signature · 1 line
Nicolas Mailhot
#4 lore raw
Quoted 8 lines · On Thu, 17 May 2007 12:00:02 +0200 Nicolas Mailhot wrote:
Quoted 2 lines · Nicolas Mailhot

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.

Quoted 7 lines

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?

Quoted 27 lines

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

Quoted 2 lines

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 ***

#5 lore raw
Quoted 18 lines · Randy Dunlap
Quoted 8 lines · On Thu, 17 May 2007 12:00:02 +0200 Nicolas Mailhot wrote:
Quoted 2 lines · Nicolas Mailhot

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.

Quoted 7 lines

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

Quoted 1 line

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

Quoted 1 line

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

I can try. It's not triggering quickly though

Signature · 1 line
Nicolas Mailhot
#6 lore raw
Quoted 5 lines · Nicolas Mailhot
Quoted 1 line · Randy Dunlap

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
Signature · 1 line
Nicolas Mailhot
#7 lore raw
Quoted 53 lines · Nicolas Mailhot
Quoted 5 lines · Nicolas Mailhot
Quoted 1 line · Randy Dunlap

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
Quoted 6 lines

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

author Acked-by Arnd Bergmann
#8 lore raw
Quoted 14 lines · On Fri, 8 Jun 2007 05:06:29 +0200 Björn Steinbrink <[email protected]> wrote:
Quoted 13 lines · Nicolas Mailhot
Quoted 5 lines · Nicolas Mailhot
Quoted 1 line · Randy Dunlap

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
Quoted 7 lines
Quoted 7 lines
 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.

Quoted 34 lines
Quoted 34 lines
 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.

Quoted 8 lines
Quoted 4 lines
 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 <[email protected]>
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

[[email protected]: make things static]
Signed-off-by Paul Fulghum <[email protected]>
Acked-by Arnd Bergmann <[email protected]>
Cc Alan Cox <[email protected]>
Signed-off-by Andrew Morton <[email protected]>
Signed-off-by Linus Torvalds <[email protected]>
Quoted 38 lines

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

#9 lore raw
Quoted 7 lines · Andrew Morton
Quoted 3 lines · On Fri, 8 Jun 2007 05:06:29 +0200 Björn Steinbrink <[email protected]> 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:

Quoted 8 lines

commit e10cc1df1d2014f68a4bdcf73f6dd122c4561f94

Author: Paul Fulghum <[email protected]>
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.

Signature · 2 lines
Paul Fulghum
Microgate Systems, Ltd
#10 lore raw
In reply to Björn Steinbrink
Quoted 7 lines · Björn Steinbrink

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?

drivers/char/tty_io.c +10 -4
@@ -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,
 };
#11 lore raw
Quoted 4 lines · Paul Fulghum
Quoted 3 lines · Björn Steinbrink

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.

...

Quoted 2 lines

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?

Signature · 2 lines
Paul Fulghum
Microgate Systems, Ltd
author
#12 lore raw
Quoted 9 lines · On Fri, 08 Jun 2007 14:20:48 -0500 Paul Fulghum <[email protected]> wrote:
Quoted 4 lines · Paul Fulghum
Quoted 3 lines · Bj__rn Steinbrink

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.

...

Quoted 2 lines

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?

Quoted 9 lines

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.

#13 lore raw

PATCH 1/1 tty restore locked ioctl file op

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 <[email protected]>
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 <[email protected]>
drivers/char/tty_io.c +10 -4
@@ -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,
 };
#14 lore raw

Re: [PATCH] tty restore locked ioctl file op

Quoted 9 lines · 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 <[email protected]>
Date:   Thu May 10 22:22:50 2007 -0700

tty: add compat_ioctl

Quoted 8 lines

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

Quoted 40 lines
Signed-off-by Paul Fulghum <[email protected]>
drivers/char/tty_io.c +10 -5
@@ -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 [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

#15 lore raw

Re: [PATCH] tty restore locked ioctl file op

Quoted 4 lines · Björn Steinbrink

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.

Quoted 5 lines

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