[uml-devel] Diagnosed and repeatable kernel mode panic in schedule() for 2.6!

5 messages, 2 authors, 2004-02-18 · open the first message on its own page

[uml-devel] Diagnosed and repeatable kernel mode panic in schedule() for 2.6!

From: BlaisorBlade <hidden>
Date: 2004-02-15 19:28:49

While searching the archives, I noticed that this command:

while /bin/true ; do /bin/true ; done

created some problems (task_struct leak and OOM) time ago (at least until 
2.6.0-test2, more or less). See "Re: [uml-devel] oops and memory leak with 
uml-patch-2.5.67-1".

I've rerun this command under a 2.6.2 with my patch collection (but with the 
/proc/meminfo bug, i.e. MemTotal = 0) and host 2.4.24-skas (which contains 
the Ingo Molnar's fixlet about LDT loading) and got, instead, this:

Kernel panic: Kernel mode fault at addr 0x1f, ip 0x400d1397
Kernel panic: kernel BUG at kernel/exit.c:793!

And then the kernel exited (even if it tried to trigger some other panics, see 
the end of the attached output). If anyone is able to reproduce the bug, then 
he can go straight debugging, if he doesn't want to read this. I think I 
cannot give you the binary, since I have a 56k modem and it's 6,7Mega even 
compressed (stripping debug symbols is useless for debug). However I could 
try stripping the config and such things, if you absolutely can't reproduce 
it.

The second message is of interest because the BUG line of interest reads as:
  schedule();
  BUG();

and this is fairly interesting. But this report is all a fun: the kernel 
continues to run after a panic call because the call suddenly exited without 
a return (search this message for "sudden"), the runqueue datas are 
inconsistent (maybe because of the memory leak in the above message), we 
don't know where the "array" value comes from (a compiler bug? An error 
in the debugging info? A reused variable? Do you need the gdb disassemble of 
schedule?). Also, since the problems appear in schedule(), this could relate 
with the hang after the "NET: Registered protocol family 2" message, since 
that comes from a not-working wait queue.

Note: in that moment about 10/20 processes were running.

I was able to reproduce both ones under gdb, and I've attached the whole 
debugging session output; here I summarize it, since that output is way too 
long and this is the offending code, inside schedule():

        idx = sched_find_first_bit(array->bitmap);
        queue = array->queue + idx;
        next = list_entry(queue->next, task_t, run_list);

        if (next->activated > 0) { //THIS IS THE LINE!

With gdb, I got this:
(gdb) where
#0  panic (fmt=0xa018f8e0 "Kernel mode fault at addr 0x%lx, ip 0x%lx") at 
include/asm/thread_info.h:49
#1  0xa0018ac8 in segv (address=31, ip=1074598807, is_write=0, 
is_user=1074598807, sc=0xa1e59148)
    at arch/um/kernel/trap_kern.c:167
#2  0xa0018e97 in segv_handler (sig=11, regs=0xa1e59148) at 
arch/um/kernel/trap_user.c:67
#3  0xa001e573 in sig_handler_common_skas (sig=11, sc_ptr=0x58) at 
arch/um/kernel/skas/trap_user.c:33
#4  0xa0018fa0 in sig_handler (sig=0, sc=
      {gs = 0, __gsh = 0, fs = 0, __fsh = 0, es = 43, __esh = 0, ds = 43, 
__dsh = 0, edi = 2694560988, esi = 2716176348, ebp = 2694560956, esp = 
2694560884, ebx = 3, edx = 2687144876, ecx = 4294967267, eax = 140, trapno = 
14, err = 4, eip = 2684545927, cs = 35, __csh = 0, eflags = 66179, 
esp_at_signal = 2694560884, ss = 43, __ssh = 0, fpstate = 0x0, oldmask = 
369106944, cr2 = 31})
    at arch/um/kernel/trap_user.c:103
#5  <signal handler called>
#6  schedule () at kernel/sched.c:1677
#7  0xa0014584 in interrupt_end () at arch/um/kernel/process_kern.c:138
#8  0xa001d498 in userspace (regs=0xa1e59148) at 
arch/um/kernel/skas/process.c:174
#9  0xa001dd54 in fork_handler (sig=10) at 
arch/um/kernel/skas/process_kern.c:103
#10 <signal handler called>
#11 0xa01559dd in syscall () at include/linux/slab.h:92
#12 0xa002cd76 in os_usr1_process (pid=26614) at arch/um/os-Linux/process.c:96
#13 0xa001d53f in new_thread (stack=Cannot access memory at address 0x8
) at arch/um/kernel/skas/process.c:197
Previous frame inner to this frame (corrupt stack?)

(gdb) print next
$2 = (task_t *) 0xffffffe3
(gdb) print &next->activated
$3 = (int *) 0x1f (the address in the fault message)

(gdb) print array
$4 = (prio_array_t *) 0x3

(gdb) print rq
No symbol "rq" in current context.

Contents of this_rq are in the attached debug session log.

Also, in the panic call, I discovered that current->pid was 99, and that is 
the father of the true processes:

root [~: slack90: 6 (0)] # ps -ef
...
root        99     1  0  1997 tty1     00:00:01 -bash
root       100     1  0  1997 tty6     00:00:00 -bash
root       383    99  0  1997 tty1     00:00:00 /bin/true

About array = 0x3, I would point to someone else getting the same problem:
"[uml-devel] wait queues broken?" (but there, array was NULL).

While going on in the panic call, all of a sudden (maybe after 
local_irq_enable, which on UML is unblock_signals() ) I got to this point, 
and then to the BUG() call above (missing details are in the attached 
output):

(gdb) next
69                      sys_sync();
(gdb) next
thread_wait (sw=0xa001d578, fb=0xa09bb554) at 
arch/um/kernel/skas/process.c:210
210     }
(gdb) where
#0  thread_wait (sw=0xa001d578, fb=0xa09bb554) at 
arch/um/kernel/skas/process.c:210
#1  0xa001dd07 in fork_handler (sig=10) at 
arch/um/kernel/skas/process_kern.c:94
#2  <signal handler called>
#3  0xa01559dd in syscall () at include/linux/slab.h:92
Previous frame inner to this frame (corrupt stack?)

Then, it seems that running notifier_chan_list called some function that 
sleeped and that the calls to scheduled panicked and then tended to loop 
infinitely (at least, until I debugged it; when doing continue, finally the 
program exited).

Hope you have fun figuring it out!
-- 
Paolo Giarrusso, aka Blaisorblade
Linux registered user n. 292729





[uml-devel] Re: Diagnosed and repeatable kernel mode panic in schedule() for 2.6!

From: Ingo Molnar <hidden>
Date: 2004-02-16 09:56:14

* BlaisorBlade [off-list ref] wrote:
While searching the archives, I noticed that this command:

while /bin/true ; do /bin/true ; done
Kernel panic: Kernel mode fault at addr 0x1f, ip 0x400d1397
Kernel panic: kernel BUG at kernel/exit.c:793!
can you reproduce this crash even if you boot up UML via init=/bin/bash?

	Ingo


-------------------------------------------------------
SF.Net is sponsored by: Speed Start Your Linux Apps Now.
Build and deploy apps & Web services for Linux with
a free DVD software kit from IBM. Click Now!
http://ads.osdn.com/?ad_id=1356&alloc_id=3438&op=click
_______________________________________________
User-mode-linux-devel mailing list
User-mode-linux-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/user-mode-linux-devel

Re: [uml-devel] Re: Diagnosed and repeatable kernel mode panic in schedule() for 2.6!

From: BlaisorBlade <hidden>
Date: 2004-02-16 19:26:59

Alle 10:53, lunedì 16 febbraio 2004, Ingo Molnar ha scritto:
* BlaisorBlade [off-list ref] wrote:
quoted
While searching the archives, I noticed that this command:

while /bin/true ; do /bin/true ; done

Kernel panic: Kernel mode fault at addr 0x1f, ip 0x400d1397
Kernel panic: kernel BUG at kernel/exit.c:793!
can you reproduce this crash even if you boot up UML via init=/bin/bash?
Yes (test with the same binary):
bash-2.05b# while /bin/true; do /bin/true; done
Kernel panic: Kernel mode fault at addr 0x1f, ip 0x400d1397

However, I discovered that an old 2.6.0 kernel works well. I think that had 
2.6.0-test9 patch; so I think that this is related with the NET: Registered 
... hang, which was solved with the same patch. That does not happen on 
different compilation env.s, but I think that is random: a crazy pointer 
failing in different places.
-- 
Paolo Giarrusso, aka Blaisorblade
Linux registered user n. 292729



-------------------------------------------------------
SF.Net is sponsored by: Speed Start Your Linux Apps Now.
Build and deploy apps & Web services for Linux with
a free DVD software kit from IBM. Click Now!
http://ads.osdn.com/?ad_id56&alloc_id438&opÌk
_______________________________________________
User-mode-linux-devel mailing list
User-mode-linux-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/user-mode-linux-devel

Re: [uml-devel] Re: Diagnosed and repeatable kernel mode panic in schedule() for 2.6!

From: Ingo Molnar <hidden>
Date: 2004-02-16 19:29:56

* BlaisorBlade [off-list ref] wrote:
However, I discovered that an old 2.6.0 kernel works well. I think
that had 2.6.0-test9 patch; so I think that this is related with the
NET: Registered ... hang, which was solved with the same patch. That
does not happen on different compilation env.s, but I think that is
random: a crazy pointer failing in different places.
i cannot reproduce using 2.6.2-rc3-mm1, so it's likely some recent
breakage.

	Ingo


-------------------------------------------------------
SF.Net is sponsored by: Speed Start Your Linux Apps Now.
Build and deploy apps & Web services for Linux with
a free DVD software kit from IBM. Click Now!
http://ads.osdn.com/?ad_id=1356&alloc_id=3438&op=click
_______________________________________________
User-mode-linux-devel mailing list
User-mode-linux-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/user-mode-linux-devel

Re: [uml-devel] Re: Diagnosed and repeatable kernel mode panic in schedule() for 2.6!

From: BlaisorBlade <hidden>
Date: 2004-02-18 18:19:08

Alle 10:53, lunedì 16 febbraio 2004, Ingo Molnar ha scritto:
* BlaisorBlade [off-list ref] wrote:
quoted
While searching the archives, I noticed that this command:

while /bin/true ; do /bin/true ; done

Kernel panic: Kernel mode fault at addr 0x1f, ip 0x400d1397
Kernel panic: kernel BUG at kernel/exit.c:793!
can you reproduce this crash even if you boot up UML via init=/bin/bash?
Now, with 2.6.3-rc2-1um, I get this message (the command was while cat 
/dev/null; do cat /dev/null; done; both with normal init and init=/bin/sh). 
Note I did not press SysRq, nor did it with mconsole; it was done by Uml 
itself (panic_exit...). However, the last time I remember that the notifier 
chain was corrupted.

The decoding of part of the "Call stack" follows (but it is normal that most 
calls are seriously screwed away? I.e. they are just values in the stack, not 
actual calls).

Kernel panic: Kernel mode fault at addr 0x94, ip 0x40059923
Kernel panic: kernel BUG at kernel/exit.c:793!

 <6>SysRq : Show Regs

EIP: 0023:[<4005b476>] CPU: 0 Not tainted ESP: 002b:bffffd44 EFLAGS: 00000286
    Not tainted
EAX: ffffffda EBX: 00000000 ECX: 00000000 EDX: 000018c0
ESI: ffffffff EDI: 00000000 EBP: 00000000 DS: 002b ES: 002b
Call Trace: [<a00c4021>] [<a001991f>] [<a00836ed>] [<a0040186>] [<a003240d>]
   [<a0032498>] [<a003492c>] [<a0026000>] [<a0034ba4>] [<a001e298>] 
[<a0017b7e>]
   [<a001e30d>] [<a001d445>] [<a001d723>] [<a001dfd4>] [<a001dfbc>] 
[<a012de98>]
   [<a001df1b>] [<a0149cdd>]

(gdb) info line *0xa00c4021
Line 327 of "drivers/char/sysrq.c" starts at address 0xa00c4021 
<handle_sysrq+49>
   and ends at 0xa00c4030 <__handle_sysrq_nolock>.
(gdb) info line *0xa001991f
Line 398 of "arch/um/kernel/um_arch.c" starts at address 0xa001991f 
<panic_exit+31> and ends at 0xa0019924 <panic_exit+36>.

(gdb) info line *0xa00836ed
Line 467 of "fs/fs-writeback.c" starts at address 0xa00836db <sync_inodes+75> 
and ends at 0xa00836f3 <sync_inodes+99>.
(gdb) info line *0xa0040186
Line 169 of "kernel/sys.c" starts at address 0xa0040180 
<notifier_call_chain+32>
   and ends at 0xa0040188 <notifier_call_chain+40>.
(gdb) info line *0xa003240d
Line 78 of "kernel/panic.c" starts at address 0xa003240d <panic+125> and ends 
at 0xa0032419 <panic+137>.
(gdb) info line *0xa0032498
Line 69 of "kernel/panic.c" starts at address 0xa0032493 <panic+259> and ends 
at 0xa00324a0 <print_tainted>.
(gdb) info line *0xa0018c19
Line 154 of "arch/um/kernel/trap_kern.c" starts at address 0xa0018c19 
<segv+121> and ends at 0xa0018c1c <segv+124>.
(gdb) info line *0xa0018d28
Line 161 of "arch/um/kernel/trap_kern.c" starts at address 0xa0018d28 
<segv+392> and ends at 0xa0018d3f <segv+415>.
(gdb) info line *0xa012e19a
Line 92 of "include/linux/slab.h" starts at address 0xa011fe16 
<unix_seq_open+22> and ends at 0xa01c3632 <af_unix_exit+18>.
(gdb) info line *0xa012e19a
Line 92 of "include/linux/slab.h" starts at address 0xa011fe16 
<unix_seq_open+22> and ends at 0xa01c3632 <af_unix_exit+18>.
(gdb) info line *0xa0016f1d
Line 69 of "arch/um/kernel/signal_user.c" starts at address 0xa0016f0e 
<change_signals+62>
   and ends at 0xa0016f24 <change_signals+84>.
(gdb) info line *0xa00190f7
Line 67 of "arch/um/kernel/trap_user.c" starts at address 0xa00190c2 
<segv_handler+306> and ends at 0xa00191b0 <usr2_handler>.
(gdb) info line *0xa001905f
Line 64 of "arch/um/kernel/trap_user.c" starts at address 0xa001905f 
<segv_handler+207>
   and ends at 0xa0019065 <segv_handler+213>.
(gdb) info line *0xa001e7f3
Line 35 of "arch/um/kernel/skas/trap_user.c" starts at address 0xa001e7f3 
<sig_handler_common_skas+115>
   and ends at 0xa001e7f8 <sig_handler_common_skas+120>.
(gdb) info line *0xa0019200
Line 103 of "arch/um/kernel/trap_user.c" starts at address 0xa00191f0 
<sig_handler+32> and ends at 0xa0019210 <alarm_handler>.
(gdb) info line *0xa012de98
Line 92 of "include/linux/slab.h" starts at address 0xa011fe16 
<unix_seq_open+22> and ends at 0xa01c3632 <af_unix_exit+18>.
(gdb) info line *0xa002ee65
Line 1680 of "kernel/sched.c" starts at address 0xa002ee65 <schedule+453> and 
ends at 0xa002ee70 <schedule+464>.
(gdb) info line *0xa012e19a
Line 92 of "include/linux/slab.h" starts at address 0xa011fe16 
<unix_seq_open+22> and ends at 0xa01c3632 <af_unix_exit+18>.
(gdb) info line *0xa00170a4
Line 127 of "arch/um/kernel/signal_user.c" starts at address 0xa0017099 
<set_signals+105>
   and ends at 0xa00170ab <set_signals+123>.
(gdb) info line *0xa002e55a
Line 301 of "kernel/sched.c" starts at address 0xa002e555 
<wake_up_forked_process+357>
   and ends at 0xa002e55d <wake_up_forked_process+365>.
(gdb) info line *0xa002e408
Line 780 of "kernel/sched.c" starts at address 0xa002e408 
<wake_up_forked_process+24>
   and ends at 0xa002e412 <wake_up_forked_process+34>.
(gdb) info line *0xa0031e4f
Line 1138 of "kernel/fork.c" starts at address 0xa0031e4f <do_fork+63> and 
ends at 0xa0031e52 <do_fork+66>.
(gdb) info line *0xa0031f47
Line 1157 of "kernel/fork.c" starts at address 0xa0031f40 <do_fork+304> and 
ends at 0xa0031f4c <do_fork+316>.
(gdb) info line *0xa0018a84
Line 90 of "arch/um/kernel/trap_kern.c" starts at address 0xa0018a7b 
<handle_page_fault+331>
   and ends at 0xa0018a8c <handle_page_fault+348>.
(gdb) info line *0xa001898c
Line 93 of "arch/um/kernel/trap_kern.c" starts at address 0xa001898c 
<handle_page_fault+92>
   and ends at 0xa0018997 <handle_page_fault+103>.

-- 
Paolo Giarrusso, aka Blaisorblade
Linux registered user n. 292729




-------------------------------------------------------
SF.Net is sponsored by: Speed Start Your Linux Apps Now.
Build and deploy apps & Web services for Linux with
a free DVD software kit from IBM. Click Now!
http://ads.osdn.com/?ad_id56&alloc_id438&opÌk
_______________________________________________
User-mode-linux-devel mailing list
User-mode-linux-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/user-mode-linux-devel
Keyboard shortcuts
hback out one level
jnext message in thread
kprevious message in thread
ldrill in
Escclose help / fold thread tree
?toggle this help