Ceph » Linux kernel client

On the next attempt:

$ sudo ./check generic/205
FSTYP         -- ceph
PLATFORM      -- Linux/x86_64 cephfs 4.9.0+
MKFS_OPTIONS  -- 192.168.1.149:/scratch
MOUNT_OPTIONS -- -o context=system_u:object_r:nfs_t:s0 192.168.1.149:/scratch /mnt/scratch

generic/205     [not run] Reflink not supported by scratch filesystem type: ceph
Not run: generic/205
Passed all 0 tests

...with no crash. So it seems likely that this occurred during the mount or unmount perhaps? The message about a dropped unsafe request may be a hint there.

Hit a very similar crash in testing today. This time it crashed while doing the list_del_init in cleanup_session_requests(). Almost the same spot, but not exactly. I think we may have a memory scribble.

I'll plan to add some strategic BUG_ONs -- see if we're maybe freeing the reqs while they're still on s_unsafe? I'll also see if I can set up kdump and get a vmcore. That might tell us a bit more about how we get a zeroed out object here.

It might also not hurt to make a dedicated slabcache for ceph_mds_request objects. That way we could do some memory poisoning of just those objects too.

if op == CEPH_SESSION_CLOSE, handle_session() unregisters the session. Maybe it's use-after-free bug. (I didn't check it carefully)

Yeah, could be a use-after-free, or maybe a refcounting imbalance in the session handling? I kicked off another xfstests run and it didn't occur, so I'm guessing it may be a race of some sort.

xfstests does do a bunch of mounting and unmounting in quick succession and this oops is occurring in the session teardown code, so maybe it's related to that somehow?

I added this just before the kfree(req) in ceph_mdsc_release_request:

BUG_ON(!list_empty(&req->r_unsafe_item));

...and kicked off an xfstests run before bedtime last night. This was on the console this morning:

[43351.124014] run fstests generic/205 at 2017-02-06 22:52:49
[43415.014713] ------------[ cut here ]------------
[43415.015243] kernel BUG at fs/ceph/mds_client.c:587!
[43415.015759] invalid opcode: 0000 [#1] SMP
[43415.016190] Modules linked in: ceph(OE) libceph(OE) loop rpcsec_gss_krb5 nfsv4 dns_resolver nfs fscache ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ip_set nfnetlink ebtable_nat ebtable_broute bridge stp llc ip6table_raw ip6table_mangle ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_security iptable_raw iptable_mangle iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_security ebtable_filter ebtables ip6table_filter ip6_tables crct10dif_pclmul crc32_pclmul ghash_clmulni_intel ppdev joydev acpi_cpufreq i2c_piix4 parport_pc pcspkr nfsd tpm_tis parport virtio_balloon tpm_tis_core qemu_fw_cfg tpm auth_rpcgss nfs_acl lockd grace sunrpc xfs libcrc32c qxl virtio_console drm_kms_helper virtio_blk virtio_net ttm floppy drm ata_generic virtio_pci
[43415.023469]  crc32c_intel virtio_ring serio_raw pata_acpi virtio [last unloaded: libceph]
[43415.024331] CPU: 0 PID: 7618 Comm: umount Tainted: G           OE   4.10.0-rc5+ #8
[43415.025125] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-1.fc25 04/01/2014
[43415.026033] task: ffff9ee239c9d880 task.stack: ffffc275833b8000
[43415.026663] RIP: 0010:ceph_mdsc_release_request+0x169/0x170 [ceph]
[43415.027313] RSP: 0018:ffffc275833bbdc0 EFLAGS: 00010287
[43415.027860] RAX: ffff9ee2335f7b30 RBX: ffff9ee2335f4f30 RCX: 0000000100000000
[43415.028607] RDX: ffff9ee22e30d688 RSI: ffff9ee2335f4f58 RDI: ffff9ee22eb3fc00
[43415.029355] RBP: ffffc275833bbdd0 R08: ffff9ee229ea0a40 R09: 0000000000000001
[43415.030120] R10: 0000000000000000 R11: 0000000000000001 R12: ffff9ee2335f4c00
[43415.030857] R13: ffff9ee229eec010 R14: ffff9ee22eb3fc08 R15: ffff9ee2335f4c00
[43415.031638] FS:  00007fe9e3c86340(0000) GS:ffff9ee23fc00000(0000) knlGS:0000000000000000
[43415.032484] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[43415.033090] CR2: 00005623e6999c28 CR3: 000000012cd0c000 CR4: 00000000000406f0
[43415.033830] Call Trace:
[43415.034108]  __unregister_request+0xc3/0x200 [ceph]
[43415.034628]  ceph_mdsc_pre_umount+0x131/0x1f0 [ceph]
[43415.035163]  ceph_kill_sb+0x2b/0x70 [ceph]
[43415.035600]  deactivate_locked_super+0x43/0x70
[43415.036074]  deactivate_super+0x5a/0x60
[43415.036481]  cleanup_mnt+0x3f/0x90
[43415.036845]  __cleanup_mnt+0x12/0x20
[43415.037232]  task_work_run+0x80/0xa0
[43415.037611]  exit_to_usermode_loop+0xaa/0xb0
[43415.038069]  syscall_return_slowpath+0xaa/0xb0
[43415.038540]  entry_SYSCALL_64_fastpath+0xa7/0xa9
[43415.039031] RIP: 0033:0x7fe9e2ceffd7
[43415.039414] RSP: 002b:00007ffe6835a1b8 EFLAGS: 00000246 ORIG_RAX: 00000000000000a6
[43415.040200] RAX: 0000000000000000 RBX: 000055c9a6dea080 RCX: 00007fe9e2ceffd7
[43415.040940] RDX: 0000000000000001 RSI: 0000000000000000 RDI: 000055c9a6df2350
[43415.041679] RBP: 000055c9a6df2350 R08: 000055c9a6df2370 R09: 0000000000000014
[43415.042424] R10: 000055c9a6dede40 R11: 0000000000000246 R12: 00007fe9e3a6d184
[43415.043374] R13: 0000000000000000 R14: 000055c9a6dea260 R15: 00007ffe6835a440
[43415.044341] Code: 8b bb 58 fd ff ff 48 8d b3 90 00 00 00 48 83 c3 68 e8 dc 20 ff ff 48 8b 03 48 39 c3 75 0d 4c 89 e7 e8 4c 85 9c e1 5b 41 5c 5d c3 <0f> 0b 0f 1f 44 00 00 66 66 66 66 90 55 48 89 e5 41 55 41 54 49 
[43415.046730] RIP: ceph_mdsc_release_request+0x169/0x170 [ceph] RSP: ffffc275833bbdc0
[43415.049061] ---[ end trace e740b673f6130a3f ]---

So it seems likely that we have a ceph_mds_request refcounting imbalance somewhere that is causing reqs to be freed before it has been removed from the s_unsafe list.

In my testing, it always happens in the unmount codepath during generic/205 test. I'll plan to have a look at that test and see whether we can narrow it down to certain codepaths.

I think wait_requests() should remove request from unsafe list before calling __unregister_request()

Zheng Yan wrote:

I think wait_requests() should remove request from unsafe list before calling __unregister_request()

Maybe. Would it be better instead to do it in __unregister_request? It's protected by the same lock you need for the stuff in that function, so removing it there would make sense to me.

Is there ever a time you'd want to remove it from the request tree but leave it on the s_unsafe list?

Jeff Layton wrote:

Is there ever a time you'd want to remove it from the request tree but leave it on the s_unsafe list?

I don't think there is

On second thought, I don't really like that since __register_request doesn't put the thing on the list. I'm going to go with your original idea of list_del_init'ing it in wait_requests, and then add a WARN_ON_ONCE() in __unregister_request if the list isn't empty at that point. I ran xfstests on ceph last night with a patch like that and got no panics and no warnings, so I think it's safe enough.