Re: 2.6.18-mm2 - oops in cache_alloc_refill()

Valdis.Kletnieks
2006-09-29T03:20:30Z

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

On Thu, 28 Sep 2006 01:46:23 PDT, Andrew Morton said:
> ftp://ftp.kernel.org/pub/linux/kernel/people/akpm/patches/2.6/2.6.18/2.6.18-mm2/

Yowza. This has been one of the most unstable -mm I've personally tried since
2.6.0 came out (and I've tried to give each and every single one a shot).

Something is giving cache_alloc_refill() massive indigestion, I'm taking
lots of oopsen in it. Usually within 5-10 minutes I'm dead in the water.

>From an untainted kernel:

Sep 28 21:51:59 turing-police kernel: [ 526.046000] BUG: unable to handle kernel paging request at virtual address 00100104
Sep 28 21:51:59 turing-police kernel: [ 526.046000] printing eip:
Sep 28 21:51:59 turing-police kernel: [ 526.046000] c0150c43
Sep 28 21:51:59 turing-police kernel: [ 526.046000] *pde = 00000000

as far as it got logging it to disk - at that point the machine locked up
hard, even alt-sysrq was dead, had to power-cycle. Long time since that
happened. Admittedly, that's not much to go on, but it shows that I'm having
issues in cache_alloc_refill() even when untainted. I'll probably get more
complete untainted traces while playing bisect-the-mm tomorrow....

Another few traces, more complete, almost same EIP (inside cache_alloc_refill
both times), but admittedly nvidia-tainted:

Sep 28 21:40:07 turing-police kernel: [ 825.672000] BUG: unable to handle kernel paging request at virtual address 646c617a
Sep 28 21:40:07 turing-police kernel: [ 825.672000] printing eip:
Sep 28 21:40:07 turing-police kernel: [ 825.672000] c0150f9b
Sep 28 21:40:07 turing-police kernel: [ 825.672000] *pde = 00000000
Sep 28 21:40:07 turing-police kernel: [ 825.672000] Oops: 0002 [#1]
Sep 28 21:40:07 turing-police kernel: [ 825.672000] PREEMPT
Sep 28 21:40:07 turing-police kernel: [ 825.672000] last sysfs file: /devices/system/cpu/cpu0/cpufreq/scaling_setspeed
Sep 28 21:40:07 turing-police kernel: [ 825.672000] Modules linked in: aes cryptomgr xt_SECMARK xt_CONNSECMARK ip6table_
mangle iptable_mangle nf_conntrack_ftp xt_pkttype ipt_REJECT nf_conntrack_ipv4 ipt_LOG iptable_filter ip_tables xt_tcpudp
nf_conntrack_ipv6 xt_state nf_conntrack ip6t_LOG xt_limit ip6table_filter ip6_tables x_tables thermal sony_acpi processo
r fan button battery ac nfnetlink i8k floppy nvram orinoco_cs orinoco hermes pcmcia firmware_class nvidia yenta_socket oh
ci1394 ieee1394 rsrc_nonstatic intel_agp pcmcia_core agpgart iTCO_wdt rtc
Sep 28 21:40:07 turing-police kernel: [ 825.672000] CPU: 0
Sep 28 21:40:07 turing-police kernel: [ 825.672000] EIP: 0060:[<c0150f9b>] Tainted: P VLI
Sep 28 21:40:07 turing-police kernel: [ 825.672000] EFLAGS: 00210002 (2.6.18-mm2 #1)
Sep 28 21:40:07 turing-police kernel: [ 825.672000] EIP is at cache_alloc_refill+0x12a/0x453
Sep 28 21:40:07 turing-police kernel: [ 825.672000] eax: effdf4d0 ebx: effdfa40 ecx: 00000001 edx: 646c6176
Sep 28 21:40:07 turing-police kernel: [ 825.672000] esi: dffedd00 edi: effdf4c0 ebp: def37f0c esp: def37ec8
Sep 28 21:40:07 turing-police kernel: [ 825.672000] ds: 007b es: 007b ss: 0068
Sep 28 21:40:07 turing-police kernel: [ 825.672000] Process badpost (pid: 3474, ti=def36000 task=dfe9aaa0 task.ti=def36000)
Sep 28 21:40:07 turing-police kernel: [ 825.672000] Stack: effe03e0 66666174 000000d0 effe18c0 00000003 effdfa40 00000000 ffffffff
Sep 28 21:40:07 turing-police kernel: [ 825.672000] 00000000 ffffffff 00000001 def37fbc 01200011 00000000 00200286 fffffff4
Sep 28 21:40:07 turing-police kernel: [ 825.672000] dfe9aaa0 def37f18 c0150e68 def37fbc def37f5c c0111b6a def37fbc bfda5158
Sep 28 21:40:07 turing-police kernel: [ 825.672000] Call Trace:
Sep 28 21:40:07 turing-police kernel: [ 825.672000] [<c0150e68>] kmem_cache_alloc+0x25/0x2e
Sep 28 21:40:07 turing-police kernel: [ 825.672000] [<c0111b6a>] copy_process+0xa2/0x1183
Sep 28 21:40:07 turing-police kernel: [ 825.672000] [<c0112dbf>] do_fork+0x8d/0x172
Sep 28 21:40:07 turing-police kernel: [ 825.672000] [<c0101216>] sys_clone+0x25/0x2a
Sep 28 21:40:07 turing-police kernel: [ 825.672000] [<c0102d23>] syscall_call+0x7/0xb
Sep 28 21:40:07 turing-police kernel: [ 825.672000] DWARF2 unwinder stuck at syscall_call+0x7/0xb
Sep 28 21:40:07 turing-police kernel: [ 825.672000]
Sep 28 21:40:07 turing-police kernel: [ 825.672000] Leftover inexact backtrace:
Sep 28 21:40:07 turing-police kernel: [ 825.672000]
Sep 28 21:40:07 turing-police kernel: [ 825.672000] =======================
Sep 28 21:40:07 turing-police kernel: [ 825.672000] Code: 9e 1c 89 46 14 8b 5d d0 89 54 8b 10 41 89 0b 8b 46 10 89 45 c0
8b 55 c8 3b 42 1c 73 09 ff 4d cc 83 7d cc ff 75 bd 8b 16 8b 46 04 <89> 42 04 89 10 c7 06 00 01 10 00 c7 46 04 00 02 20 0
0 83 7e 14
Sep 28 21:40:07 turing-police kernel: [ 825.672000] EIP: [<c0150f9b>] cache_alloc_refill+0x12a/0x453 SS:ESP 0068:def37ec8
Sep 28 21:40:07 turing-police kernel: [ 825.672000] <6>note: badpost[3474] exited with preempt_count 1

And then a second oops at the same exact EIP as the untainted one:

Sep 28 21:40:11 turing-police kernel: [ 829.630000] BUG: unable to handle kernel paging request at virtual address 646c617a
Sep 28 21:40:11 turing-police kernel: [ 829.630000] printing eip:
Sep 28 21:40:11 turing-police kernel: [ 829.630000] c0150f9b
Sep 28 21:40:11 turing-police kernel: [ 829.630000] *pde = 00000000
Sep 28 21:40:11 turing-police kernel: [ 829.630000] Oops: 0002 [#2]
Sep 28 21:40:11 turing-police kernel: [ 829.630000] PREEMPT
Sep 28 21:40:11 turing-police kernel: [ 829.630000] last sysfs file: /devices/system/cpu/cpu0/cpufreq/scaling_setspeed
Sep 28 21:40:11 turing-police kernel: [ 829.630000] Modules linked in: aes cryptomgr xt_SECMARK xt_CONNSECMARK ip6table_
mangle iptable_mangle nf_conntrack_ftp xt_pkttype ipt_REJECT nf_conntrack_ipv4 ipt_LOG iptable_filter ip_tables xt_tcpudp
nf_conntrack_ipv6 xt_state nf_conntrack ip6t_LOG xt_limit ip6table_filter ip6_tables x_tables thermal sony_acpi processo
r fan button battery ac nfnetlink i8k floppy nvram orinoco_cs orinoco hermes pcmcia firmware_class nvidia yenta_socket oh
ci1394 ieee1394 rsrc_nonstatic intel_agp pcmcia_core agpgart iTCO_wdt rtc
Sep 28 21:40:11 turing-police kernel: [ 829.630000] CPU: 0
Sep 28 21:40:11 turing-police kernel: [ 829.630000] EIP: 0060:[<c0150f9b>] Tainted: P VLI
Sep 28 21:40:11 turing-police kernel: [ 829.630000] EFLAGS: 00210002 (2.6.18-mm2 #1)
Sep 28 21:40:11 turing-police kernel: [ 829.630000] EIP is at cache_alloc_refill+0x12a/0x453
Sep 28 21:40:11 turing-police kernel: [ 829.630000] eax: effdf4d0 ebx: effdfa40 ecx: 00000000 edx: 646c6176
Sep 28 21:40:11 turing-police kernel: [ 829.630000] esi: dffedd00 edi: effdf4c0 ebp: e11d3f0c esp: e11d3ec8
Sep 28 21:40:11 turing-police kernel: [ 829.630000] ds: 007b es: 007b ss: 0068

I've seen mostly 3 different stack traces for this:

EIP is at cache_alloc_refill+0x12d/0x453
eax: 00000167 ebx: effdfa40 ecx: 00000001 edx: d9eede00
esi: daf19700 edi: effdf4c0 ebp: db237f0c esp: db237ec8
ds: 007b es: 007b ss: 0068
Process procmail (pid: 3206, ti=db236000 task=db299550 task.ti=db236000)
Stack: effe03e0 00000001 000000d0 effe18c0 00000003 effdfa40 00000000 ffffffff
00000000 ffffffff 00000001 db237fbc 01200011 00000000 00200286 fffffff4
db299550 db237f18 c0150e68 db237fbc db237f5c c0111b6a db237fbc bfbc3678
Call Trace:
[<c0150e68>] kmem_cache_alloc+0x25/0x2e
[<c0111b6a>] copy_process+0xa2/0x1183
[<c0112dbf>] do_fork+0x8d/0x172
[<c0101216>] sys_clone+0x25/0x2a
[<c0102d23>] syscall_call+0x7/0xb

and

EIP is at cache_alloc_refill+0x12d/0x453
eax: 00000167 ebx: effdfa40 ecx: 00000000 edx: d9eede00
esi: daf19700 edi: effdf4c0 ebp: dceedda8 esp: dceedd64
ds: 007b es: 007b ss: 0068
Process fetchmail (pid: 2752, ti=dceec000 task=dbfb9aa0 task.ti=dceec000)
Stack: effe03e0 00000001 000000d0 effe18c0 00000004 effdfa40 00000000 e2774500
dceeddd4 c02fe47b 0000014f 0000014f 0000000f 00000473 00200286 00000f80
db1c1680 dceeddb4 c015130c db1c1680 dceeddd8 c02d2fb9 00000001 000000d0
Call Trace:
[<c015130c>] __kmalloc+0x48/0x55
[<c02d2fb9>] __alloc_skb+0x4f/0xf7
[<c02f4b2a>] tcp_sendmsg+0x14c/0x965
[<c030bdf4>] inet_sendmsg+0x3b/0x48
[<c02cdb8b>] sock_aio_write+0xf5/0x102
[<c0153691>] do_sync_write+0xae/0xec
[<c0153e6b>] vfs_write+0xbc/0x157
[<c01543be>] sys_write+0x3b/0x60
[<c0102d23>] syscall_call+0x7/0xb

and

EIP is at cache_alloc_refill+0x12d/0x453
eax: 00000167 ebx: effdfa40 ecx: 00000000 edx: d9eede00
esi: daf19700 edi: effdf4c0 ebp: ddb2fdc4 esp: ddb2fd80
ds: 007b es: 007b ss: 0068
Process Eterm (pid: 2700, ti=ddb2e000 task=e39ab000 task.ti=ddb2e000)
Stack: effe03e0 00000001 000000d0 effe18c0 00000004 effdfa40 00000000 00000017
00170001 00200082 ddb2fdd0 00200082 00000000 00000000 00200286 00000f80
ee80cd80 ddb2fdd0 c015130c ee80cd80 ddb2fdf4 c02d2fb9 00000000 000000d0
Call Trace:
[<c015130c>] __kmalloc+0x48/0x55
[<c02d2fb9>] __alloc_skb+0x4f/0xf7
[<c02cfef1>] sock_alloc_send_skb+0x5a/0x17b
[<c03258b9>] unix_stream_sendmsg+0x13b/0x2e6
[<c02cdb8b>] sock_aio_write+0xf5/0x102
[<c0153691>] do_sync_write+0xae/0xec
[<c0153e6b>] vfs_write+0xbc/0x157
[<c01543be>] sys_write+0x3b/0x60
[<c0102d23>] syscall_call+0x7/0xb

[-- Attachment #2: Type: application/pgp-signature, Size: 226 bytes --]