Ceph » CephFS

[ 1105.463449] general protection fault: 0000 [#1] SMP
[ 1105.464311] Modules linked in: netconsole nfsd auth_rpcgss oid_registry nfs_acl lockd grace sunrpc ceph libceph libcrc32c fscache
[ 1105.465722] CPU: 0 PID: 2862 Comm: nfsd Not tainted 4.11.0-rc3+ #5
[ 1105.466287] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-1.fc25 04/01/2014
[ 1105.467200] task: ffff88007c510000 task.stack: ffffc90000668000
[ 1105.467746] RIP: 0010:queued_spin_lock_slowpath+0xe5/0x180
[ 1105.468273] RSP: 0018:ffffc9000066bbd0 EFLAGS: 00010202
[ 1105.468776] RAX: 726f63735f6f10ef RBX: ffff880002039020 RCX: ffff88007fc1a180
[ 1105.469383] RDX: 0000000000000738 RSI: 000000001ce4b200 RDI: ffff88007af6bac8
[ 1105.469994] RBP: ffffc9000066bbd0 R08: 0000000000040000 R09: 0000000000000000
[ 1105.470616] R10: 0000000000000000 R11: ffffc9000066bad6 R12: ffff88007af6ba00
[ 1105.471248] R13: ffff88007cab5000 R14: ffff88003645b000 R15: 0000000000000000
[ 1105.471857] FS:  0000000000000000(0000) GS:ffff88007fc00000(0000) knlGS:0000000000000000
[ 1105.472734] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1105.473284] CR2: 00007f5d310f05b8 CR3: 000000007a071000 CR4: 00000000001406f0
[ 1105.473889] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 1105.474511] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 1105.475137] Call Trace:
[ 1105.475520]  _raw_spin_lock+0x1b/0x20
[ 1105.475949]  drop_inode_snap_realm+0x1e/0x90 [ceph]
[ 1105.476455]  __ceph_remove_cap+0x175/0x1f0 [ceph]
[ 1105.476935]  ceph_queue_caps_release+0x37/0x50 [ceph]
[ 1105.477450]  ceph_destroy_inode+0x25/0x1d0 [ceph]
[ 1105.477928]  destroy_inode+0x36/0x60
[ 1105.478341]  evict+0x124/0x180
[ 1105.478730]  iput+0x1ab/0x230
[ 1105.479115]  dentry_unlink_inode+0xaf/0x150
[ 1105.479582]  __dentry_kill+0xb3/0x150
[ 1105.480004]  dput+0x21a/0x250
[ 1105.480391]  fh_put+0x42/0x120 [nfsd]
[ 1105.480814]  nfsd4_proc_compound+0x287/0x5f0 [nfsd]
[ 1105.481320]  nfsd_dispatch+0x89/0x170 [nfsd]
[ 1105.481782]  svc_process_common+0x41a/0x5a0 [sunrpc]
[ 1105.482294]  svc_process+0x131/0x1a0 [sunrpc]
[ 1105.482756]  nfsd+0xe4/0x150 [nfsd]
[ 1105.483188]  kthread+0xfc/0x130
[ 1105.483580]  ? nfsd_destroy+0x60/0x60 [nfsd]
[ 1105.484036]  ? kthread_create_on_node+0x40/0x40
[ 1105.484524]  ret_from_fork+0x29/0x40
[ 1105.484942] Code: 02 89 c2 45 31 c9 c1 e2 10 85 d2 74 41 c1 ea 12 83 e0 03 83 ea 01 48 c1 e0 04 48 63 d2 48 05 80 a1 01 00 48 03 04 d5 c0 d3 c4 81 <48> 89 08 8b 41 08 85 c0 75 09 f3 90 8b 41 08 85 c0 74 f7 4c 8b 
[ 1105.486609] RIP: queued_spin_lock_slowpath+0xe5/0x180 RSP: ffffc9000066bbd0
[ 1105.487646] ---[ end trace 39dbfceea3ccd399 ]---
[ 1105.488571] nfsd (2862) used greatest stack depth: 12712 bytes left

I got several oops at other places. seem like random memory corruption, It only happens when cephfs is exported by nfsd.

Jeff, could you take a look.

Sorry I didn't see this sooner. Is this still cropping up?

So what might be helpful the next time this happens locally for you is to chase down where it oopsed. Open the uncompressed kernel (or kmod) with gdb and list the spot where it crashed. Here's what I get with the above stack trace, but I don't have your kconfig and build env so the offsets may not match.

$ gdb vmlinux
(gdb) list *(queued_spin_lock_slowpath+0xe5)
0xffffffff810f1265 is in queued_spin_lock_slowpath (kernel/locking/qspinlock.c:185).
180        /*
181         * Use release semantics to make sure that the MCS node is properly
182         * initialized before changing the tail code.
183         */
184        return (u32)xchg_release(&l->tail,
185                     tail >> _Q_TAIL_OFFSET) << _Q_TAIL_OFFSET;
186    }
187    
188    #else /* _Q_PENDING_BITS == 8 */
189    

With that we can try to infer what the cause of the crash was.

Even better would be to get a vmcore so we can look and see whether the whole inode is trashed or what the i_snap_realm is set to, etc...

Huh...looking through the other failed tests. This one is interesting:

[ 5173.583311] ceph: ceph_add_cap: couldn't find snap realm 100
[ 5173.589401] BUG: unable to handle kernel paging request at ffffff9d99a49cb7
[ 5173.596369] IP: tcp_cleanup_rbuf+0x2a/0x120
[ 5173.600558] PGD 60ae12067 
[ 5173.600558] PUD 0 
[ 5173.603266] 
[ 5173.606786] Oops: 0000 [#1] SMP

We didn't get a stack trace there, but the ceph_add_cap message is something I haven't seen. Could this be triggered somehow by the server sending us bogus realm numbers? Is 0x100 a typical value for realmino?

It seems the crash no longer happen after rebase the testing branch against 4.11 kernel

Jeff Layton wrote:

Sorry I didn't see this sooner. Is this still cropping up?

So what might be helpful the next time this happens locally for you is to chase down where it oopsed. Open the uncompressed kernel (or kmod) with gdb and list the spot where it crashed. Here's what I get with the above stack trace, but I don't have your kconfig and build env so the offsets may not match.

[...]

With that we can try to infer what the cause of the crash was.

Even better would be to get a vmcore so we can look and see whether the whole inode is trashed or what the i_snap_realm is set to, etc...

Huh...looking through the other failed tests. This one is interesting:

[...]

We didn't get a stack trace there, but the ceph_add_cap message is something I haven't seen. Could this be triggered somehow by the server sending us bogus realm numbers? Is 0x100 a typical value for realmino?

mds can send 0x100 realmino when client access unlinked inode. It shouldn't cause problem