Ceph » Linux kernel client

Oh, actually this is a BUG_ON:

<2>[ 1642.059333] kernel BUG at fs/ceph/inode.c:1347!

...so you should be able to just look at what that is.

Jeff Layton wrote:

Oh, actually this is a BUG_ON:

<2>[ 1642.059333] kernel BUG at fs/ceph/inode.c:1347!

...so you should be able to just look at what that is.

Yeah, it is.

This will be very reproduceable every time when mounting it like:

1. mount.ceph 192.168195.165:40954:// /mnt/cephfs ---> only if the source path has more than 1 slash at the end
2. touch /mnt/cephfs/a.txt or mkdir /mnt/cephfs/mydir ....

I have posted one patch to remove the extra slash in the source path.
And IMO we should also fix this in the ceph-mds server side.

Thanks.

The following the debug logs:

<5>[ 202.436834] FS-Cache: Loaded
<7>[ 1630.113406] ceph: do_getattr inode 0000000031bc061b mask AsLsXsFs mode 040755
<7>[ 1630.114338] ceph: fill_trace 000000006fa7810f is_dentry 0 is_target 1
<7>[ 1630.114341] ceph: get_inode on 1=1.fffffffffffffffe got 0000000031bc061b
<7>[ 1630.114343] ceph: fill_inode 0000000031bc061b ino 1.fffffffffffffffe v 18 had 17
<7>[ 1630.114344] ceph: 0000000031bc061b mode 040755 uid.gid 0.0
<7>[ 1630.114346] ceph: fill_fragtree 1.fffffffffffffffe
<7>[ 1630.114348] ceph: fill_trace done err=0
<7>[ 1630.114399] ceph: do_getattr result=0
<7>[ 1630.114428] ceph: statfs
<7>[ 1630.117151] ceph: kill_sb 00000000285d2d00
<7>[ 1630.117251] ceph: evict_inode 0000000031bc061b ino 1.fffffffffffffffe
<7>[ 1630.117900] ceph: sync_fs (non-blocking)
<7>[ 1630.117902] ceph: sync_fs (non-blocking) done
<7>[ 1630.117903] ceph: sync_fs (blocking)
<7>[ 1633.022078] ceph: sync_fs (blocking) done
<7>[ 1633.022098] ceph: put_super
<7>[ 1633.022125] ceph: evict_inode 000000005c319d6b ino 10000000003.fffffffffffffffe
<7>[ 1633.027017] ceph: destroy_fs_client 000000003d009504
<7>[ 1633.027048] ceph: destroy_mount_options 00000000db9011c9
<7>[ 1633.027205] ceph: destroy_fs_client 000000003d009504 done
<7>[ 1638.123943] ceph: ceph_mount
<7>[ 1638.123947] ceph: parse_mount_options 000000006c16d4b4, dev_name '192.168.195.165:40029:///'
<7>[ 1638.123948] ceph: device name '192.168.195.165:40029'
<7>[ 1638.123949] ceph: server path '///'
<7>[ 1638.124500] ceph: set_super 00000000e3a4524f data 00000000ecaead59
<7>[ 1638.124503] ceph: get_sb using new client 00000000ecaead59
<7>[ 1638.124626] ceph: mount start 00000000ecaead59
<6>[ 1638.127806] libceph: mon0 (1)192.168.195.165:40029 session established
<6>[ 1638.128991] libceph: client4278 fsid 28c57f53-b797-4d8d-825b-be4ce18f08c9
<7>[ 1638.129016] ceph: mount opening path //
<7>[ 1638.129049] ceph: open_root_inode opening '//'
<7>[ 1638.137348] ceph: fill_trace 0000000071d8f821 is_dentry 0 is_target 1
<7>[ 1638.137351] ceph: alloc_inode 00000000d2e9263c
<7>[ 1638.137354] ceph: get_inode created new inode 00000000d2e9263c 1.ffffffffffffffff ino 1
<7>[ 1638.137355] ceph: get_inode on 1=1.ffffffffffffffff got 00000000d2e9263c
<7>[ 1638.137356] ceph: fill_inode 00000000d2e9263c ino 1.ffffffffffffffff v 20 had 0
<7>[ 1638.137359] ceph: 00000000d2e9263c mode 040755 uid.gid 0.0
<7>[ 1638.137360] ceph: truncate_size 0 > 18446744073709551615
<7>[ 1638.137362] ceph: 00000000d2e9263c got snap_caps pAsLsXsFscrl
<7>[ 1638.137362] ceph: fill_fragtree 1.ffffffffffffffff
<7>[ 1638.137363] ceph: fill_trace done err=0
<7>[ 1638.137461] ceph: open_root_inode success
<7>[ 1638.137466] ceph: open_root_inode success, root dentry is 00000000deced2f0
<7>[ 1638.137485] ceph: mount success
<7>[ 1638.137486] ceph: root 00000000deced2f0 inode 00000000d2e9263c ino 1.ffffffffffffffff
<7>[ 1642.058106] ceph: do_getattr inode 00000000d2e9263c SNAPDIR
<7>[ 1642.058123] ceph: do_getattr inode 00000000d2e9263c SNAPDIR
<7>[ 1642.059293] ceph: fill_trace 000000009abb9c2c is_dentry 1 is_target 1
<7>[ 1642.059296] ceph: fill_inode 00000000d2e9263c ino 1.ffffffffffffffff v 20 had 20
<7>[ 1642.059298] ceph: 00000000d2e9263c mode 040755 uid.gid 0.0
<7>[ 1642.059300] ceph: 00000000d2e9263c got snap_caps pAsLsXsFs
<7>[ 1642.059301] ceph: fill_fragtree 1.ffffffffffffffff
<7>[ 1642.059303] ceph: get_or_create_frag added 1.ffffffffffffffff frag 0
<7>[ 1642.059304] ceph: fill_dirfrag 1.ffffffffffffffff frag 0 ndist=0
<7>[ 1642.059305] ceph: alloc_inode 00000000e98f4cb8
<7>[ 1642.059309] ceph: get_inode created new inode 00000000e98f4cb8 10000000003.fffffffffffffffe ino 10000000003
<7>[ 1642.059310] ceph: get_inode on 1099511627779=10000000003.fffffffffffffffe got 00000000e98f4cb8
<7>[ 1642.059311] ceph: fill_inode 00000000e98f4cb8 ino 10000000003.fffffffffffffffe v 33 had 0
<7>[ 1642.059312] ceph: 00000000e98f4cb8 mode 0100644 uid.gid 0.0
<7>[ 1642.059313] ceph: size 0 -> 0
<7>[ 1642.059313] ceph: truncate_seq 0 -> 1
<7>[ 1642.059314] ceph: truncate_size 0 -> 18446744073709551615
<7>[ 1642.059317] ceph: lxb -- ceph_snap(dir): FFFFFFFFFFFFFFFF, dvino.snap: FFFFFFFFFFFFFFFE
<4>[ 1642.059332] ------------[ cut here ]------------
<2>[ 1642.059333] kernel BUG at fs/ceph/inode.c:1347!
<4>[ 1642.059360] invalid opcode: 0000 [#1] SMP PTI
<4>[ 1642.059429] CPU: 2 PID: 150 Comm: kworker/2:1 Tainted: G E 5.4.0-rc5+ #1
<4>[ 1642.059481] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 05/19/2017
<4>[ 1642.059587] Workqueue: ceph-msgr ceph_con_workfn [libceph]
<4>[ 1642.059616] RIP: 0010:ceph_fill_trace+0x936/0xad0 [ceph]
<4>[ 1642.059665] Code: ff 0f 0b 0f 0b 0f 0b 4c 89 fa 48 c7 c6 5d af a7 c0 48 c7 c7 30 04 a9 c0 4c 89 1c 24 e8 33 fb ab e6 4c 8b 1c 24 e9 16 fe ff ff <0f> 0b 49 8b 56 40 4d 89 f9 4d 89 f8 4c 89 5c 24 08 48 c7 c6 48 eb
<4>[ 1642.059730] RSP: 0018:ffffa1af84ba7c70 EFLAGS: 00010297
<4>[ 1642.059748] RAX: 0000000000000000 RBX: fffffffffffffffe RCX: 0000000000000006
<4>[ 1642.059817] RDX: 0000000000000000 RSI: 0000000000000092 RDI: ffff9360aec97900
<4>[ 1642.059901] RBP: ffff935f55cd34b0 R08: 0000000000000001 R09: 00000000000006cd
<4>[ 1642.059954] R10: 00000000000257dc R11: ffff935f55cd55b0 R12: ffff93609cd52000
<4>[ 1642.059979] R13: 0000000000000000 R14: ffff935fc46b4800 R15: ffff9360a9ab7e00
<4>[ 1642.060054] FS: 0000000000000000(0000) GS:ffff9360aec80000(0000) knlGS:0000000000000000
<4>[ 1642.060111] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[ 1642.060189] CR2: 0000557dc234e010 CR3: 0000000427bb2004 CR4: 00000000003606e0
<4>[ 1642.060234] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
<4>[ 1642.060268] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
<4>[ 1642.060282] Call Trace:
<4>[ 1642.060331] dispatch+0x2ac/0x12b0 [ceph]
<4>[ 1642.060359] ceph_con_workfn+0xd40/0x27c0 [libceph]
<4>[ 1642.060463] ? __switch_to_asm+0x40/0x70
<4>[ 1642.060475] ? __switch_to_asm+0x34/0x70
<4>[ 1642.060484] ? __switch_to_asm+0x40/0x70
<4>[ 1642.060494] ? __switch_to_asm+0x34/0x70
<4>[ 1642.060503] ? __switch_to_asm+0x40/0x70
<4>[ 1642.060535] ? __switch_to_asm+0x40/0x70
<4>[ 1642.060544] ? __switch_to_asm+0x34/0x70
<4>[ 1642.061070] ? __switch_to+0x80/0x440
<4>[ 1642.061497] ? __switch_to_asm+0x34/0x70
<4>[ 1642.062031] process_one_work+0x1b0/0x350
<4>[ 1642.062951] worker_thread+0x50/0x3b0
<4>[ 1642.063491] kthread+0xfb/0x130
<4>[ 1642.064030] ? process_one_work+0x350/0x350
<4>[ 1642.064574] ? kthread_park+0x90/0x90
<4>[ 1642.065085] ret_from_fork+0x35/0x40
<4>[ 1642.065618] Modules linked in: ceph(E) libceph fscache vsock_diag tcp_diag udp_diag raw_diag inet_diag unix_diag af_packet_diag netlink_diag ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ip6table_nat ip6table_mangle ip6table_raw ip6table_security iptable_nat nf_nat iptable_mangle iptable_raw iptable_security nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 ip_set nfnetlink ebtable_filter ebtables ip6table_filter ip6_tables bnep vmw_vsock_vmci_transport vsock sunrpc snd_seq_midi snd_seq_midi_event snd_ens1371 snd_ac97_codec intel_rapl_msr intel_rapl_common ac97_bus snd_rawmidi snd_seq crct10dif_pclmul btusb btrtl crc32_pclmul btbcm snd_seq_device btintel bluetooth snd_pcm ghash_clmulni_intel vmw_balloon joydev snd_timer snd ecdh_generic ecc soundcore rfkill intel_rapl_perf gameport pcspkr vmw_vmci i2c_piix4 xfs libcrc32c vmwgfx drm_kms_helper ttm drm mptspi scsi_transport_spi mptscsih mptbase serio_raw crc32c_intel e1000 ata_generic pata_acpi
<4>[ 1642.070811] ---[ end trace 37ae9aab31404157 ]---
<4>[ 1642.071274] RIP: 0010:ceph_fill_trace+0x936/0xad0 [ceph]
<4>[ 1642.071754] Code: ff 0f 0b 0f 0b 0f 0b 4c 89 fa 48 c7 c6 5d af a7 c0 48 c7 c7 30 04 a9 c0 4c 89 1c 24 e8 33 fb ab e6 4c 8b 1c 24 e9 16 fe ff ff <0f> 0b 49 8b 56 40 4d 89 f9 4d 89 f8 4c 89 5c 24 08 48 c7 c6 48 eb
<4>[ 1642.073682] RSP: 0018:ffffa1af84ba7c70 EFLAGS: 00010297
<4>[ 1642.074383] RAX: 0000000000000000 RBX: fffffffffffffffe RCX: 0000000000000006
<4>[ 1642.075090] RDX: 0000000000000000 RSI: 0000000000000092 RDI: ffff9360aec97900
<4>[ 1642.075619] RBP: ffff935f55cd34b0 R08: 0000000000000001 R09: 00000000000006cd
<4>[ 1642.076261] R10: 00000000000257dc R11: ffff935f55cd55b0 R12: ffff93609cd52000
<4>[ 1642.076867] R13: 0000000000000000 R14: ffff935fc46b4800 R15: ffff9360a9ab7e00
<4>[ 1642.077512] FS: 0000000000000000(0000) GS:ffff9360aec80000(0000) knlGS:0000000000000000
<4>[ 1642.078151] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[ 1642.078707] CR2: 0000557dc234e010 CR3: 0000000427bb2004 CR4: 00000000003606e0
<4>[ 1642.079248] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
<4>[ 1642.079872] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400

This should fix it in MDS: https://github.com/ceph/ceph/pull/31713

UPDATE: PR was closed

Xiubo Li wrote:

Jeff Layton wrote:

Oh, actually this is a BUG_ON:

<2>[ 1642.059333] kernel BUG at fs/ceph/inode.c:1347!

...so you should be able to just look at what that is.

Yeah, it is.

This will be very reproduceable every time when mounting it like:

1. mount.ceph 192.168195.165:40954:// /mnt/cephfs ---> only if the source path has more than 1 slash at the end
2. touch /mnt/cephfs/a.txt or mkdir /mnt/cephfs/mydir ....

I have posted one patch to remove the extra slash in the source path.
And IMO we should also fix this in the ceph-mds server side.

No. '//' has special meaning in 'client <-> mds' protocol. client should remove the extra slash when building request

Thanks.

Fixed in the kclient side:
https://patchwork.kernel.org/patch/11305675/

Just a quick update: I've pushed these backports to all the relevant stable kernels (4.9, 4.14, 4.19, 5.4 and 5.5). Greg has already picked them, as you can see in his git tree here:

https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git/

I guess this issue can now be closed.

Thanks, @Luis !