[Linux-cachefs] Kernel trace for 2.6.36.2
Mark Moseley
moseleymark at gmail.com
Tue Jan 4 18:00:04 UTC 2011
Latest testing on a 2.6.36.2 kernel, 64-bit, Debian Lenny. Ran under
heavy load for a few hours before this:
[38607.552070] IP: [<ffffffff811a4187>]
__fscache_read_or_alloc_pages+0x157/0x360
[38607.567128] last sysfs file:
/sys/devices/system/cpu/cpu7/cache/index2/shared_cpu_map
[38607.604773] Pid: 30970, comm: httpd Not tainted 2.6.36.2 #1
0XDN97/PowerEdge R610
[38607.612286] RIP: 0010:[<ffffffff811a4187>] [<ffffffff811a4187>]
__fscache_read_or_alloc_pages+0x157/0x360
[38607.734181] [<ffffffff81248d4b>] __nfs_readpages_from_fscache+0x6b/0x1d0
[38607.740991] [<ffffffff8122a674>] nfs_readpages+0xd4/0x200
[38607.746495] [<ffffffff81116b8d>] ? alloc_pages_current+0x9d/0x110
[38607.752695] [<ffffffff810e695e>] __do_page_cache_readahead+0x13e/0x200
[38607.759325] [<ffffffff810e6a3c>] ra_submit+0x1c/0x20
[38607.764402] [<ffffffff810e6c55>] ondemand_readahead+0x115/0x240
[38607.770424] [<ffffffff810e6e91>] page_cache_sync_readahead+0x31/0x50
[38607.776883] [<ffffffff810dea14>] generic_file_aio_read+0x4c4/0x700
[38607.783168] [<ffffffff8121dc01>] nfs_file_read+0xd1/0x120
[38607.788674] [<ffffffff8112b011>] do_sync_read+0xd1/0x120
[38607.794092] [<ffffffff812985fa>] ? security_file_permission+0x7a/0x90
[38607.800636] [<ffffffff8112be40>] vfs_read+0xf0/0x210
[38607.805703] [<ffffffff8112c050>] sys_read+0x50/0x90
[38607.810688] [<ffffffff81002f9b>] system_call_fastpath+0x16/0x1b
[38607.836457] RIP [<ffffffff811a4187>]
__fscache_read_or_alloc_pages+0x157/0x360
[38676.019551] IP: [<ffffffff811a4187>]
__fscache_read_or_alloc_pages+0x157/0x360
[38676.019569] last sysfs file:
/sys/devices/system/cpu/cpu7/cache/index2/shared_cpu_map
[38676.019598] Pid: 30673, comm: httpd Tainted: G D 2.6.36.2
#1 0XDN97/PowerEdge R610
[38676.019600] RIP: 0010:[<ffffffff811a4187>] [<ffffffff811a4187>]
__fscache_read_or_alloc_pages+0x157/0x360
[38676.019656] [<ffffffff81248d4b>] __nfs_readpages_from_fscache+0x6b/0x1d0
[38676.019665] [<ffffffff8122a674>] nfs_readpages+0xd4/0x200
[38676.019671] [<ffffffff81116b8d>] ? alloc_pages_current+0x9d/0x110
[38676.019679] [<ffffffff810e695e>] __do_page_cache_readahead+0x13e/0x200
[38676.019683] [<ffffffff810e6a3c>] ra_submit+0x1c/0x20
[38676.019686] [<ffffffff810e6c55>] ondemand_readahead+0x115/0x240
[38676.019690] [<ffffffff810e6e91>] page_cache_sync_readahead+0x31/0x50
[38676.019694] [<ffffffff810dea14>] generic_file_aio_read+0x4c4/0x700
[38676.019698] [<ffffffff8121dc01>] nfs_file_read+0xd1/0x120
[38676.019703] [<ffffffff8112b011>] do_sync_read+0xd1/0x120
[38676.019709] [<ffffffff812985fa>] ? security_file_permission+0x7a/0x90
[38676.019713] [<ffffffff8112be40>] vfs_read+0xf0/0x210
[38676.019716] [<ffffffff8112c050>] sys_read+0x50/0x90
[38676.019722] [<ffffffff81002f9b>] system_call_fastpath+0x16/0x1b
[38676.019746] RIP [<ffffffff811a4187>]
__fscache_read_or_alloc_pages+0x157/0x360
moseley at desktop:/tmp$ cat err
[38607.544175] BUG: unable to handle kernel NULL pointer dereference
at 0000000000000040
[38607.552070] IP: [<ffffffff811a4187>]
__fscache_read_or_alloc_pages+0x157/0x360
[38607.559348] PGD 10c887067 PUD 11124c067 PMD 0
[38607.563856] Oops: 0000 [#1] SMP
[38607.567128] last sysfs file:
/sys/devices/system/cpu/cpu7/cache/index2/shared_cpu_map
[38607.574997] CPU 4
[38607.576837] Modules linked in: xt_mac ipt_addrtype ioatdma dca loop
fan joydev evdev psmouse usbhid hid serio_raw
d power_meter button processor dcdbas ehci_hcd uhci_hcd thermal
thermal_sys sg sd_mod sr_mod crc_t10dif cdrom [last u
[38607.603263]
[38607.604773] Pid: 30970, comm: httpd Not tainted 2.6.36.2 #1
0XDN97/PowerEdge R610
[38607.612286] RIP: 0010:[<ffffffff811a4187>] [<ffffffff811a4187>]
__fscache_read_or_alloc_pages+0x157/0x360
[38607.621992] RSP: 0018:ffff88010c8eba78 EFLAGS: 00010246
[38607.627319] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffff88010c8ea000
[38607.634470] RDX: 0000000000000000 RSI: ffff88010c8eb9e8 RDI: ffff880130005d80
[38607.641617] RBP: ffff88010c8ebab8 R08: ffff88010c8ea000 R09: 0000000000000008
[38607.648764] R10: 0000000000000007 R11: 0000000000000000 R12: ffff8801efa94640
[38607.655914] R13: ffff88010c8ebc08 R14: ffff8801fda37840 R15: ffff88010c8ebb24
[38607.663062] FS: 000003f1095c36e0(0000) GS:ffff880133a40000(0000)
knlGS:0000000000000000
[38607.671183] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[38607.676946] CR2: 0000000000000040 CR3: 00000000015d1000 CR4: 00000000000006f0
[38607.684097] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[38607.691248] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[38607.698399] Process httpd (pid: 30970, threadinfo ffff88010c8ea000,
task ffff88009de35c80)
[38607.706691] Stack:
[38607.708717] ffff88022ab12900 ffff8801698bee70 ffff8801b961d140
00000000ffffff97
[38607.715993] <0> ffff88010c8ebb24 0000000000000001 ffff8801698bed58
ffff8801698bee70
[38607.723751] <0> ffff88010c8ebb08 ffffffff81248d4b ffff8801000200da
000201da00000000
[38607.731709] Call Trace:
[38607.734181] [<ffffffff81248d4b>] __nfs_readpages_from_fscache+0x6b/0x1d0
[38607.740991] [<ffffffff8122a674>] nfs_readpages+0xd4/0x200
[38607.746495] [<ffffffff81116b8d>] ? alloc_pages_current+0x9d/0x110
[38607.752695] [<ffffffff810e695e>] __do_page_cache_readahead+0x13e/0x200
[38607.759325] [<ffffffff810e6a3c>] ra_submit+0x1c/0x20
[38607.764402] [<ffffffff810e6c55>] ondemand_readahead+0x115/0x240
[38607.770424] [<ffffffff810e6e91>] page_cache_sync_readahead+0x31/0x50
[38607.776883] [<ffffffff810dea14>] generic_file_aio_read+0x4c4/0x700
[38607.783168] [<ffffffff8121dc01>] nfs_file_read+0xd1/0x120
[38607.788674] [<ffffffff8112b011>] do_sync_read+0xd1/0x120
[38607.794092] [<ffffffff812985fa>] ? security_file_permission+0x7a/0x90
[38607.800636] [<ffffffff8112be40>] vfs_read+0xf0/0x210
[38607.805703] [<ffffffff8112c050>] sys_read+0x50/0x90
[38607.810688] [<ffffffff81002f9b>] system_call_fastpath+0x16/0x1b
[38607.816709] Code: 06 48 8b 7a 28 ff d0 48 c7 c1 94 c3 d5 81 48 c7
c2 9c c3 d5 81 48 8b 75 d0 4c 89 f7 e8 93 fb ff
> 8b 40 40 a8 04 0f 84 f5 00 00 00 f0 ff 05 ea 82 bb 00 71 09
[38607.836457] RIP [<ffffffff811a4187>]
__fscache_read_or_alloc_pages+0x157/0x360
[38607.843820] RSP <ffff88010c8eba78>
[38607.847324] CR2: 0000000000000040
[38607.851086] ---[ end trace 93e63baadcc78f99 ]---
Followed a few seconds later by:
[38676.016830] CacheFiles: Error: Overlong wait for old active object to go away
[38676.016834] object: OBJc36cf
[38676.016837] objstate=OBJECT_LOOKING_UP fl=0 wbusy=2 ev=0[7b]
[38676.016839] ops=0 inp=0 exc=0
[38676.016842] parent=ffff8801fe3c0280
[38676.016844] cookie=ffff8801fdc8d960 [pr=ffff88022977c460
nd=ffff8801698beba0 fl=7]
[38676.016847] key=[44]
'0001000027b4008000000000ac2804014aae00054dab008000000000400000009bdf51454000000000000000'
[38676.016859] xobject: OBJc36ce
[38676.016862] xobjstate=OBJECT_DYING fl=0 wbusy=0 ev=20[7]
[38676.016864] xops=1 inp=1 exc=0
[38676.016866] xparent=ffff8801fe3c0280
[38676.016867] xcookie=NULL
[38676.016927] [kworke] preemptive burial: OBJc36ce [OBJECT_DYING]
ffff8801d5bb0a80
[38676.017234] [kworke] preemptive burial: OBJc36cf [OBJECT_DYING]
ffff88005784bec0
[38676.019545] BUG: unable to handle kernel NULL pointer dereference
at 0000000000000040
[38676.019551] IP: [<ffffffff811a4187>]
__fscache_read_or_alloc_pages+0x157/0x360
[38676.019562] PGD 10ca78067 PUD 113fc3067 PMD 0
[38676.019566] Oops: 0000 [#2] SMP
[38676.019569] last sysfs file:
/sys/devices/system/cpu/cpu7/cache/index2/shared_cpu_map
[38676.019573] CPU 2
[38676.019574] Modules linked in: xt_mac ipt_addrtype ioatdma dca loop
fan joydev evdev psmouse usbhid hid serio_raw pcspkr ghes i7core_edac
edac_core hed power_meter button processor dcdbas ehci_hcd uhci_hcd
thermal thermal_sys sg sd_mod sr_mod crc_t10dif cdrom [last unloaded:
scsi_wait_scan]
[38676.019594]
[38676.019598] Pid: 30673, comm: httpd Tainted: G D 2.6.36.2
#1 0XDN97/PowerEdge R610
[38676.019600] RIP: 0010:[<ffffffff811a4187>] [<ffffffff811a4187>]
__fscache_read_or_alloc_pages+0x157/0x360
[38676.019606] RSP: 0000:ffff880063d99a78 EFLAGS: 00010246
[38676.019608] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffff880063d98000
[38676.019611] RDX: 0000000000000000 RSI: ffff880063d999e8 RDI: ffff880130005e10
[38676.019613] RBP: ffff880063d99ab8 R08: ffff880063d98000 R09: 0000000000000008
[38676.019615] R10: 0000000000000007 R11: 0000000000000000 R12: ffff8801fdc8d960
[38676.019618] R13: ffff880063d99c08 R14: ffff8801ef85ee40 R15: ffff880063d99b24
[38676.019621] FS: 000003f1095c36e0(0000) GS:ffff880133a20000(0000)
knlGS:0000000000000000
[38676.019623] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[38676.019626] CR2: 0000000000000040 CR3: 00000000015cf000 CR4: 00000000000006f0
[38676.019628] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[38676.019630] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[38676.019633] Process httpd (pid: 30673, threadinfo ffff880063d98000,
task ffff8800a8a74560)
[38676.019635] Stack:
[38676.019636] ffff8801f46df100 ffff8801698bee70 ffff88015eb4fbc0
00000000ffffff97
[38676.019640] <0> ffff880063d99b24 0000000000000001 ffff8801698bed58
ffff8801698bee70
[38676.019643] <0> ffff880063d99b08 ffffffff81248d4b ffff8801000200da
000201da00000000
[38676.019647] Call Trace:
[38676.019656] [<ffffffff81248d4b>] __nfs_readpages_from_fscache+0x6b/0x1d0
[38676.019665] [<ffffffff8122a674>] nfs_readpages+0xd4/0x200
[38676.019671] [<ffffffff81116b8d>] ? alloc_pages_current+0x9d/0x110
[38676.019679] [<ffffffff810e695e>] __do_page_cache_readahead+0x13e/0x200
[38676.019683] [<ffffffff810e6a3c>] ra_submit+0x1c/0x20
[38676.019686] [<ffffffff810e6c55>] ondemand_readahead+0x115/0x240
[38676.019690] [<ffffffff810e6e91>] page_cache_sync_readahead+0x31/0x50
[38676.019694] [<ffffffff810dea14>] generic_file_aio_read+0x4c4/0x700
[38676.019698] [<ffffffff8121dc01>] nfs_file_read+0xd1/0x120
[38676.019703] [<ffffffff8112b011>] do_sync_read+0xd1/0x120
[38676.019709] [<ffffffff812985fa>] ? security_file_permission+0x7a/0x90
[38676.019713] [<ffffffff8112be40>] vfs_read+0xf0/0x210
[38676.019716] [<ffffffff8112c050>] sys_read+0x50/0x90
[38676.019722] [<ffffffff81002f9b>] system_call_fastpath+0x16/0x1b
[38676.019724] Code: 06 48 8b 7a 28 ff d0 48 c7 c1 94 c3 d5 81 48 c7
c2 9c c3 d5 81 48 8b 75 d0 4c 89 f7 e8 93 fb ff ff 89 c3 85 c0 78 50
49 8b 46 70 <48> 8b 40 40 a8 04 0f 84 f5 00 00 00 f0 ff 05 ea 82 bb 00
71 09
[38676.019746] RIP [<ffffffff811a4187>]
__fscache_read_or_alloc_pages+0x157/0x360
[38676.019750] RSP <ffff880063d99a78>
[38676.019752] CR2: 0000000000000040
[38676.019754] ---[ end trace 93e63baadcc78f9a ]---
If there's anything else helpful I can provide, just shout.
More information about the Linux-cachefs
mailing list