[Linux-cachefs] Ceph, outstanding request error
Milosz Tanski
milosz at adfin.com
Thu May 23 12:47:50 UTC 2013
David,
Does the mailing list strip away attachments? I just looked at my gmail and
it looks like Included it.
I've been using UML for my testing since the constant reboots get old. It
helps since I'm using EC2 (since that's where I can setup a decent Ceph
cluster) and have access to gdb. Below is the oops plus a more detailed
stack trace.
I took a bit of time to look into it, but the whole thing seamed fishy
because it's asserting to see if the the lock is taken... and caller
function it does just that. I've tried looking for a why it's happening but
was unsuccessful and went back to mainline.
- Milosz
FS-Cache: Assertion failed
BUG: failure at fs/fscache/operation.c:270/fscache_start_operations()!
Kernel panic - not syncing: BUG!
CPU: 0 PID: 10 Comm: kworker/u2:1 Not tainted 3.10.0-rc1-00133-ge7ebb75 #2
Workqueue: fscache_operation fscache_op_work_func [fscache]
7f091c48 603c8947 7f090000 7f9b1361 7f25f080 00000001 7f26d440 7f091c90
60299eb8 7f091d90 602951c5 7f26d440 3000000008 7f091da0 7f091cc0
7f091cd0
00000007 00000007 00000006 7f091ae0 00000010 0000010e 7f9af330
7f091ae0
Call Trace:
7f091c88: [<60299eb8>] dump_stack+0x17/0x19
7f091c98: [<602951c5>] panic+0xf4/0x1e9
7f091d38: [<6002b10e>] set_signals+0x1e/0x40
7f091d58: [<6005b89e>] __wake_up+0x4e/0x70
7f091d98: [<7f9aa003>] fscache_start_operations+0x43/0x50 [fscache]
7f091da8: [<7f9aa1e3>] fscache_op_complete+0x1d3/0x220 [fscache]
7f091db8: [<60082985>] unlock_page+0x55/0x60
7f091de8: [<7fb25bb0>] cachefiles_read_copier+0x250/0x330 [cachefiles]
7f091e58: [<7f9ab03c>] fscache_op_work_func+0xac/0x120 [fscache]
7f091e88: [<6004d5b0>] process_one_work+0x250/0x3a0
7f091ef8: [<6004edc7>] worker_thread+0x177/0x2a0
7f091f38: [<6004ec50>] worker_thread+0x0/0x2a0
7f091f58: [<60054418>] kthread+0xd8/0xe0
7f091f68: [<6005bb27>] finish_task_switch.isra.64+0x37/0xa0
7f091fd8: [<600185cf>] new_thread_handler+0x8f/0xb0
Modules linked in: ceph cachefiles fscache
Pid: 10, comm: kworker/u2:1 Not tainted 3.10.0-rc1-00133-ge7ebb75
RIP: 0033:[<00007ffff784e707>]
RSP: 00007fffffffe3e8 EFLAGS: 00000206
RAX: 0000000000000000 RBX: 00000000000029c9 RCX: ffffffffffffffff
RDX: 0000000000000000 RSI: 0000000000000013 RDI: 00000000000029c9
RBP: 00007fffffffe410 R08: 0000000000000000 R09: 00007fffffffe410
R10: 00007fffffffe180 R11: 0000000000000206 R12: 00000000000029c5
R13: 00007fffffffe5e0 R14: 0000000000000006 R15: 00000000603b2180
Call Trace:
7f091c28: [<6001b20f>] panic_exit+0x2f/0x50
7f091c48: [<60058bc2>] notifier_call_chain+0x42/0x70
7f091c88: [<60058c11>] atomic_notifier_call_chain+0x11/0x20
7f091c98: [<602951e0>] panic+0x10f/0x1e9
7f091d38: [<6002b10e>] set_signals+0x1e/0x40
7f091d58: [<6005b89e>] __wake_up+0x4e/0x70
7f091d98: [<7f9aa003>] fscache_start_operations+0x43/0x50 [fscache]
7f091da8: [<7f9aa1e3>] fscache_op_complete+0x1d3/0x220 [fscache]
7f091db8: [<60082985>] unlock_page+0x55/0x60
7f091de8: [<7fb25bb0>] cachefiles_read_copier+0x250/0x330 [cachefiles]
7f091e58: [<7f9ab03c>] fscache_op_work_func+0xac/0x120 [fscache]
7f091e88: [<6004d5b0>] process_one_work+0x250/0x3a0
7f091ef8: [<6004edc7>] worker_thread+0x177/0x2a0
7f091f38: [<6004ec50>] worker_thread+0x0/0x2a0
7f091f58: [<60054418>] kthread+0xd8/0xe0
7f091f68: [<6005bb27>] finish_task_switch.isra.64+0x37/0xa0
7f091fd8: [<600185cf>] new_thread_handler+0x8f/0xb0
[New LWP 10702]
[New LWP 10701]
[New LWP 10700]
Program received signal SIGTERM, Terminated.
0x00007ffff784e707 in kill () from /lib/x86_64-linux-gnu/libc.so.6
(gdb) bt
#0 0x00007ffff784e707 in kill () from /lib/x86_64-linux-gnu/libc.so.6
#1 0x000000006002bfdb in os_dump_core () at arch/um/os-Linux/util.c:111
#2 0x000000006001b225 in panic_exit (self=<optimized out>,
unused1=<optimized out>, unused2=<optimized out>) at
arch/um/kernel/um_arch.c:240
#3 0x0000000060058bc2 in notifier_call_chain (nl=<optimized out>, val=0,
v=0x6047b200, nr_to_call=-2, nr_calls=0x0) at kernel/notifier.c:93
#4 0x0000000060058c11 in __atomic_notifier_call_chain (nr_calls=0x0,
nr_to_call=-1, v=<optimized out>, val=<optimized out>, nh=<optimized out>)
at kernel/notifier.c:182
#5 atomic_notifier_call_chain (nh=<optimized out>, val=<optimized out>,
v=<optimized out>) at kernel/notifier.c:191
#6 0x00000000602951e0 in panic (fmt=0x7f9b1361 "BUG!") at
kernel/panic.c:127
#7 0x000000007f9aa003 in ?? ()
#8 0x000000007f091de0 in ?? ()
#9 0x000000007f9aa1e3 in ?? ()
#10 0x000000007f091dd0 in ?? ()
#11 0x0000000060082985 in wake_up_page (bit=0, page=0x7f2d8740) at
mm/filemap.c:610
#12 unlock_page (page=0x7f2d8740) at mm/filemap.c:611
#13 0x000000007f9aa1e3 in ?? ()
#14 0x000000007f091dd0 in ?? ()
#15 0x0000000060082985 in wake_up_page (bit=0, page=0x7f9aa003) at
mm/filemap.c:610
#16 unlock_page (page=0x7f9aa003) at mm/filemap.c:611
#17 0x000000007fb25bb0 in ?? ()
#18 0x0000000000000001 in ?? ()
#19 0x0000000000000000 in ?? ()
(gdb) p modules
$1 = {next = 0x7fe45488, prev = 0x7f9b30a8}
(gdb) p p *((struct module *) 0x7f9b30a0)
No symbol "p" in current context.
(gdb) p *((struct module *) 0x7f9b30a0)
$2 = {state = MODULE_STATE_LIVE, list = {next = 0x603d87c0, prev =
0x7fb2c968}, name = "fscache", '\000' <repeats 48 times>, mkobj = {kobj =
{name = 0x7f2b4ce0 "fscache", entry = {next = 0x7fb2c9b8, prev =
0x7f07c948}, parent = 0x7f02a4d0
state_in_sysfs = 1, state_add_uevent_sent = 1,
state_remove_uevent_sent = 0, uevent_suppress = 0}, mod = 0x7f9b30a0,
drivers_dir = 0x0, mp = 0x7f2bad80}, modinfo_attrs = 0x7e51b000, version =
0x0, srcversion = 0x0, holders_dir = 0x7
gpl_crcs = 0x0, gpl_future_syms = 0x0, gpl_future_crcs = 0x0,
num_gpl_future_syms = 0, num_exentries = 0, extable = 0x0, init =
0x7f9ba000, module_init = 0x0, module_core = 0x7f9a5000, init_size = 0,
core_size = 80408, init_text_size =
bug_list = {next = 0x603e7060, prev = 0x7fb2cab8}, bug_table = 0x0,
symtab = 0x7f9b3c98, core_symtab = 0x7f9b3c98, num_symtab = 411,
core_num_syms = 411, strtab = 0x7f9b6320 "", core_strtab = 0x7f9b6320 "",
sect_attrs = 0x7f3c3800, note
next = 0x7f9b3260, prev = 0x7f9b3260}, waiter = 0x7f2975c0, exit =
0x7f9ae4cc, refptr = 0x61badeb0}
(gdb) add-symbol-file fs/fscache/fscache.ko 0x7f9a5000
add symbol table from file "fs/fscache/fscache.ko" at
.text_addr = 0x7f9a5000
(y or n) y
Reading symbols from /mnt/mtanski/src/linux-fs/fs/fscache/fscache.ko...done.
(gdb) bt
#0 0x00007ffff784e707 in kill () from /lib/x86_64-linux-gnu/libc.so.6
#1 0x000000006002bfdb in os_dump_core () at arch/um/os-Linux/util.c:111
#2 0x000000006001b225 in panic_exit (self=<optimized out>,
unused1=<optimized out>, unused2=<optimized out>) at
arch/um/kernel/um_arch.c:240
#3 0x0000000060058bc2 in notifier_call_chain (nl=<optimized out>, val=0,
v=0x6047b200, nr_to_call=-2, nr_calls=0x0) at kernel/notifier.c:93
#4 0x0000000060058c11 in __atomic_notifier_call_chain (nr_calls=0x0,
nr_to_call=-1, v=<optimized out>, val=<optimized out>, nh=<optimized out>)
at kernel/notifier.c:182
#5 atomic_notifier_call_chain (nh=<optimized out>, val=<optimized out>,
v=<optimized out>) at kernel/notifier.c:191
#6 0x00000000602951e0 in panic (fmt=0x7f9b1361 "BUG!") at
kernel/panic.c:127
#7 0x000000007f9aa003 in fscache_start_operations (object=<optimized out>)
at fs/fscache/operation.c:270
#8 0x000000007f9aa1e3 in fscache_op_complete (op=0x7f2d8740,
cancelled=true) at fs/fscache/operation.c:389
#9 0x000000007fb25bb0 in ?? ()
#10 0x0000000000000001 in ?? ()
#11 0x0000000000000000 in ?? ()
(gdb) p modules
$3 = {next = 0x7fe45488, prev = 0x7f9b30a8}
(gdb) p modules.prev
$4 = (struct list_head *) 0x7f9b30a8
(gdb) p *modules.prev
$5 = {next = 0x603d87c0, prev = 0x7fb2c968}
(gdb) p *((struct module *) 0x7fb2c960)
$6 = {state = MODULE_STATE_LIVE, list = {next = 0x7f9b30a8, prev =
0x7fe45488}, name = "cachefiles", '\000' <repeats 45 times>, mkobj = {kobj
= {name = 0x7e4dfca0 "cachefiles", entry = {next = 0x7fe454d8, prev =
0x7f9b30f8}, parent = 0x7f
state_in_sysfs = 1, state_add_uevent_sent = 1,
state_remove_uevent_sent = 0, uevent_suppress = 0}, mod = 0x7fb2c960,
drivers_dir = 0x0, mp = 0x7f2ad2c0}, modinfo_attrs = 0x7f34ec00, version =
0x0, srcversion = 0x0, holders_dir = 0x7
gpl_crcs = 0x0, gpl_future_syms = 0x0, gpl_future_crcs = 0x0,
num_gpl_future_syms = 0, num_exentries = 0, extable = 0x0, init =
0x7fb30000, module_init = 0x0, module_core = 0x7fb20000, init_size = 0,
core_size = 60017, init_text_size =
bug_list = {next = 0x7f9b31f8, prev = 0x7fe455d8}, bug_table = 0x0,
symtab = 0x7fb2d050, core_symtab = 0x7fb2d050, num_symtab = 150,
core_num_syms = 150, strtab = 0x7fb2de60 "", core_strtab = 0x7fb2de60 "",
sect_attrs = 0x7f3c3000, note
next = 0x7f2ee550, prev = 0x7f2ee550}, waiter = 0x7f2975c0, exit =
0x7fb28ac0, refptr = 0x61badec0}
(gdb) add-symbol-file fs/cachefiles/cachefiles.ko 0x7fb20000
add symbol table from file "fs/cachefiles/cachefiles.ko" at
.text_addr = 0x7fb20000
(y or n) y
Reading symbols from
/mnt/mtanski/src/linux-fs/fs/cachefiles/cachefiles.ko...done.
(gdb) bt
#0 0x00007ffff784e707 in kill () from /lib/x86_64-linux-gnu/libc.so.6
#1 0x000000006002bfdb in os_dump_core () at arch/um/os-Linux/util.c:111
#2 0x000000006001b225 in panic_exit (self=<optimized out>,
unused1=<optimized out>, unused2=<optimized out>) at
arch/um/kernel/um_arch.c:240
#3 0x0000000060058bc2 in notifier_call_chain (nl=<optimized out>, val=0,
v=0x6047b200, nr_to_call=-2, nr_calls=0x0) at kernel/notifier.c:93
#4 0x0000000060058c11 in __atomic_notifier_call_chain (nr_calls=0x0,
nr_to_call=-1, v=<optimized out>, val=<optimized out>, nh=<optimized out>)
at kernel/notifier.c:182
#5 atomic_notifier_call_chain (nh=<optimized out>, val=<optimized out>,
v=<optimized out>) at kernel/notifier.c:191
#6 0x00000000602951e0 in panic (fmt=0x7f9b1361 "BUG!") at
kernel/panic.c:127
#7 0x000000007f9aa003 in fscache_start_operations (object=<optimized out>)
at fs/fscache/operation.c:270
#8 0x000000007f9aa1e3 in fscache_op_complete (op=0x7f2d8740,
cancelled=true) at fs/fscache/operation.c:389
#9 0x000000007fb25bb0 in fscache_retrieval_complete (n_pages=1,
op=0x7f2d8740) at include/linux/fscache-cache.h:200
#10 cachefiles_read_copier (_op=0x7f2d8740) at fs/cachefiles/rdwr.c:203
#11 0x000000007f9ab03c in fscache_op_work_func (work=0x7f2d8740) at
fs/fscache/operation.c:526
#12 0x000000006004d5b0 in process_one_work (worker=0x7f070640,
work=<optimized out>) at kernel/workqueue.c:2172
#13 0x000000006004edc7 in worker_thread (__worker=0x7f070640) at
kernel/workqueue.c:2287
#14 0x0000000060054418 in kthread (_create=0x7f063cf0) at
kernel/kthread.c:200
#15 0x00000000600185cf in new_thread_handler () at
arch/um/kernel/process.c:140
#16 0xaaaaaaaaaaaaaaaa in ?? ()
#17 0x000000007f08e9c0 in ?? ()
#18 0x00000000603d31a0 in ?? ()
#19 0x0000000000000000 in ?? ()
(gdb) p module
No symbol "module" in current context.
(gdb) p modules
$7 = {next = 0x7fe45488, prev = 0x7f9b30a8}
(gdb) p *((struct module *) 0x7fe45480)
$8 = {state = MODULE_STATE_LIVE, list = {next = 0x7fb2c968, prev =
0x603d87c0}, name = "ceph", '\000' <repeats 51 times>, mkobj = {kobj =
{name = 0x7f34a720 "ceph", entry = {next = 0x7f02a4c0, prev = 0x7fb2c9b8},
parent = 0x7f02a4d0, kset
state_in_sysfs = 1, state_add_uevent_sent = 1,
state_remove_uevent_sent = 0, uevent_suppress = 0}, mod = 0x7fe45480,
drivers_dir = 0x0, mp = 0x0}, modinfo_attrs = 0x7e4b0400, version = 0x0,
srcversion = 0x0, holders_dir = 0x7f2eee00
gpl_future_syms = 0x0, gpl_future_crcs = 0x0, num_gpl_future_syms = 0,
num_exentries = 0, extable = 0x0, init = 0x7fe4c0ec, module_init = 0x0,
module_core = 0x7fe26000, init_size = 0, core_size = 148997, init_text_size
= 0, core_text_si
next = 0x7fb2cab8, prev = 0x603e7060}, bug_table = 0x0, symtab =
0x7fe45a10, core_symtab = 0x7fe45a10, num_symtab = 457, core_num_syms =
457, strtab = 0x7fe484e8 "", core_strtab = 0x7fe484e8 "", sect_attrs =
0x7f26f800, notes_attrs =
prev = 0x7f2eee90}, waiter = 0x7f287540, exit = 0x7fe3e8de, refptr =
0x61baded0}
(gdb) add-symbol-file fs/ceph/ceph.ko 0x7fe26000
add symbol table from file "fs/ceph/ceph.ko" at
.text_addr = 0x7fe26000
(y or n) y
Reading symbols from /mnt/mtanski/src/linux-fs/fs/ceph/ceph.ko...done.
(gdb) bt
#0 0x00007ffff784e707 in kill () from /lib/x86_64-linux-gnu/libc.so.6
#1 0x000000006002bfdb in os_dump_core () at arch/um/os-Linux/util.c:111
#2 0x000000006001b225 in panic_exit (self=<optimized out>,
unused1=<optimized out>, unused2=<optimized out>) at
arch/um/kernel/um_arch.c:240
#3 0x0000000060058bc2 in notifier_call_chain (nl=<optimized out>, val=0,
v=0x6047b200, nr_to_call=-2, nr_calls=0x0) at kernel/notifier.c:93
#4 0x0000000060058c11 in __atomic_notifier_call_chain (nr_calls=0x0,
nr_to_call=-1, v=<optimized out>, val=<optimized out>, nh=<optimized out>)
at kernel/notifier.c:182
#5 atomic_notifier_call_chain (nh=<optimized out>, val=<optimized out>,
v=<optimized out>) at kernel/notifier.c:191
#6 0x00000000602951e0 in panic (fmt=0x7f9b1361 "BUG!") at
kernel/panic.c:127
#7 0x000000007f9aa003 in fscache_start_operations (object=<optimized out>)
at fs/fscache/operation.c:270
#8 0x000000007f9aa1e3 in fscache_op_complete (op=0x7f2d8740,
cancelled=true) at fs/fscache/operation.c:389
#9 0x000000007fb25bb0 in fscache_retrieval_complete (n_pages=1,
op=0x7f2d8740) at include/linux/fscache-cache.h:200
#10 cachefiles_read_copier (_op=0x7f2d8740) at fs/cachefiles/rdwr.c:203
#11 0x000000007f9ab03c in fscache_op_work_func (work=0x7f2d8740) at
fs/fscache/operation.c:526
#12 0x000000006004d5b0 in process_one_work (worker=0x7f070640,
work=<optimized out>) at kernel/workqueue.c:2172
#13 0x000000006004edc7 in worker_thread (__worker=0x7f070640) at
kernel/workqueue.c:2287
#14 0x0000000060054418 in kthread (_create=0x7f063cf0) at
kernel/kthread.c:200
#15 0x00000000600185cf in new_thread_handler () at
arch/um/kernel/process.c:140
#16 0xaaaaaaaaaaaaaaaa in ?? ()
#17 0x000000007f08e9c0 in ?? ()
#18 0x00000000603d31a0 in ?? ()
#19 0x0000000000000000 in ?? ()
(gdb) up
#1 0x000000006002bfdb in os_dump_core () at arch/um/os-Linux/util.c:111
111 kill(0, SIGTERM);
(gdb)
#2 0x000000006001b225 in panic_exit (self=<optimized out>,
unused1=<optimized out>, unused2=<optimized out>) at
arch/um/kernel/um_arch.c:240
240 os_dump_core();
(gdb)
#3 0x0000000060058bc2 in notifier_call_chain (nl=<optimized out>, val=0,
v=0x6047b200, nr_to_call=-2, nr_calls=0x0) at kernel/notifier.c:93
93 ret = nb->notifier_call(nb, val, v);
(gdb)
#4 0x0000000060058c11 in __atomic_notifier_call_chain (nr_calls=0x0,
nr_to_call=-1, v=<optimized out>, val=<optimized out>, nh=<optimized out>)
at kernel/notifier.c:182
182 ret = notifier_call_chain(&nh->head, val, v, nr_to_call,
nr_calls);
(gdb)
#5 atomic_notifier_call_chain (nh=<optimized out>, val=<optimized out>,
v=<optimized out>) at kernel/notifier.c:191
191 return __atomic_notifier_call_chain(nh, val, v, -1, NULL);
(gdb)
#6 0x00000000602951e0 in panic (fmt=0x7f9b1361 "BUG!") at
kernel/panic.c:127
127 atomic_notifier_call_chain(&panic_notifier_list, 0, buf);
(gdb)
#7 0x000000007f9aa003 in fscache_start_operations (object=<optimized out>)
at fs/fscache/operation.c:270
270 ASSERT(spin_is_locked(&object->lock));
On Thu, May 23, 2013 at 6:25 AM, David Howells <dhowells at redhat.com> wrote:
> Milosz Tanski <milosz at adfin.com> wrote:
>
> > I'm testing this against linus' master. I had some Oops with your fscache
> > branch so I came back to mainline.
>
> Did you save the oops?
>
> Also, when did you last try my fscache branch? I updated it on Tuesday and
> prior to that, a couple of weeks ago.
>
> Further, you sent me a patch email, but forgot to include the patch.
>
> David
>
More information about the Linux-cachefs
mailing list