Bug #59684
closedBug #62081: tasks/fscrypt-common does not finish, timesout
Test failure: test_fscrypt_dummy_encryption_with_quick_group (tasks.cephfs.test_fscrypt.TestFscrypt)
0%
Description
dmesg trace shows:
2023-05-08T02:14:27.573581+00:00 smithi184 kernel: [ 1313.056547] <TASK> 2023-05-08T02:14:27.573581+00:00 smithi184 kernel: [ 1313.056550] ? read_partial_message_chunk+0x8b/0x90 [libceph] 2023-05-08T02:14:27.573585+00:00 smithi184 kernel: [ 1313.056572] ceph_con_v1_try_read+0x17cc/0x1e00 [libceph] 2023-05-08T02:14:27.573585+00:00 smithi184 kernel: [ 1313.056599] ceph_con_workfn+0x383/0x730 [libceph] 2023-05-08T02:14:27.573586+00:00 smithi184 kernel: [ 1313.056613] process_one_work+0x238/0x500 2023-05-08T02:14:27.573586+00:00 smithi184 kernel: [ 1313.056635] ? process_one_work+0x500/0x500 2023-05-08T02:14:27.573586+00:00 smithi184 kernel: [ 1313.056638] worker_thread+0x56/0x3b0 2023-05-08T02:14:27.573587+00:00 smithi184 kernel: [ 1313.056644] ? process_one_work+0x500/0x500 2023-05-08T02:14:27.573587+00:00 smithi184 kernel: [ 1313.056648] kthread+0xe5/0x110 2023-05-08T02:14:27.573591+00:00 smithi184 kernel: [ 1313.056652] ? kthread_complete_and_exit+0x20/0x20 2023-05-08T02:14:27.573591+00:00 smithi184 kernel: [ 1313.056656] ret_from_fork+0x1f/0x30 2023-05-08T02:14:27.573591+00:00 smithi184 kernel: [ 1313.056667] </TASK>
Seems to be related to sparse reads with fscrypt.
Updated by Xiubo Li 12 months ago
This warning was because the bad crc/signature when reading from socket:
2023-05-08T02:14:27.557521+00:00 smithi184 kernel: [ 1313.048582] libceph: osd7 (1)172.21.15.55:6820 socket error on read 2023-05-08T02:14:27.573535+00:00 smithi184 kernel: [ 1313.056303] ------------[ cut here ]------------ 2023-05-08T02:14:27.573543+00:00 smithi184 kernel: [ 1313.056320] WARNING: CPU: 7 PID: 107 at net/ceph/osd_client.c:5781 osd_sparse_read+0x5f8/0x650 [libceph] 2023-05-08T02:14:27.573544+00:00 smithi184 kernel: [ 1313.056353] Modules linked in: ceph libceph fscache netfs veth xfs xt_conntrack nft_chain_nat xt_MASQUERADE nf_nat nf_conntrack_netlink nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 xfrm_user xfrm_algo xt_addrtype nft_compat nf_tables libcrc32c nfnetlink br_netfilter bridge stp llc rdma_ucm ib_uverbs rdma_cm iw_cm ib_cm ib_core overlay ipmi_ssif intel_rapl_msr intel_rapl_common sb_edac x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul ghash_clmulni_intel sha512_ssse3 aesni_intel crypto_simd cryptd joydev wmi acpi_ipmi ipmi_si ipmi_devintf ipmi_msghandler acpi_power_meter mei_me acpi_pad mei ioatdma kvm_intel kvm irqbypass sch_fq_codel scsi_transport_iscsi lp parport ramoops reed_solomon efi_pstore configfs nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 hid_generic usbhid hid igb i2c_algo_bit ixgbe nvme crc32_pclmul dca ahci i2c_i801 lpc_ich ptp i2c_smbus libahci nvme_core pps_core mdio 2023-05-08T02:14:27.573545+00:00 smithi184 kernel: [ 1313.056479] CPU: 7 PID: 107 Comm: kworker/7:2 Not tainted 6.3.0-g88d7b7ea2321 #1 2023-05-08T02:14:27.573546+00:00 smithi184 kernel: [ 1313.056482] Hardware name: Supermicro SYS-5018R-WR/X10SRW-F, BIOS 2.0 12/17/2015 2023-05-08T02:14:27.573546+00:00 smithi184 kernel: [ 1313.056484] Workqueue: ceph-msgr ceph_con_workfn [libceph] 2023-05-08T02:14:27.573546+00:00 smithi184 kernel: [ 1313.056504] RIP: 0010:osd_sparse_read+0x5f8/0x650 [libceph] 2023-05-08T02:14:27.573547+00:00 smithi184 kernel: [ 1313.056520] Code: ff ff ff 5a 59 e9 a9 fa ff ff 48 89 de 4c 89 d7 ba 01 00 00 00 4c 89 14 24 48 29 c6 e8 41 86 ff ff 4c 8b 14 24 e9 e6 fa ff ff <0f> 0b e9 c0 fb ff ff 66 90 e9 75 fa ff ff e8 d5 84 ff ff 41 b9 21 2023-05-08T02:14:27.573562+00:00 smithi184 kernel: [ 1313.056522] RSP: 0018:ffffa13ec100fd30 EFLAGS: 00010286 2023-05-08T02:14:27.573573+00:00 smithi184 kernel: [ 1313.056525] RAX: 0000000000000000 RBX: ffff955c40820f38 RCX: 00000000202eb1be 2023-05-08T02:14:27.573573+00:00 smithi184 kernel: [ 1313.056527] RDX: 0000000000000000 RSI: ffff955c0c606400 RDI: ffff955c0b587820 2023-05-08T02:14:27.573574+00:00 smithi184 kernel: [ 1313.056529] RBP: ffff955c0b5874d0 R08: 0000000000000002 R09: 0000000000000001 2023-05-08T02:14:27.573574+00:00 smithi184 kernel: [ 1313.056531] R10: ffff955c0c606480 R11: 0000000000000001 R12: ffff955c0b587820 2023-05-08T02:14:27.573574+00:00 smithi184 kernel: [ 1313.056533] R13: ffff955c0b587000 R14: ffff955c0b587000 R15: ffff955c0b587970 2023-05-08T02:14:27.573575+00:00 smithi184 kernel: [ 1313.056535] FS: 0000000000000000(0000) GS:ffff95635fdc0000(0000) knlGS:0000000000000000 2023-05-08T02:14:27.573575+00:00 smithi184 kernel: [ 1313.056537] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 2023-05-08T02:14:27.573579+00:00 smithi184 kernel: [ 1313.056539] CR2: 00007ff6dce5b000 CR3: 0000000105e00006 CR4: 00000000003706e0 2023-05-08T02:14:27.573580+00:00 smithi184 kernel: [ 1313.056541] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 2023-05-08T02:14:27.573580+00:00 smithi184 kernel: [ 1313.056543] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 2023-05-08T02:14:27.573580+00:00 smithi184 kernel: [ 1313.056545] Call Trace: 2023-05-08T02:14:27.573581+00:00 smithi184 kernel: [ 1313.056547] <TASK> 2023-05-08T02:14:27.573581+00:00 smithi184 kernel: [ 1313.056550] ? read_partial_message_chunk+0x8b/0x90 [libceph] 2023-05-08T02:14:27.573585+00:00 smithi184 kernel: [ 1313.056572] ceph_con_v1_try_read+0x17cc/0x1e00 [libceph] 2023-05-08T02:14:27.573585+00:00 smithi184 kernel: [ 1313.056599] ceph_con_workfn+0x383/0x730 [libceph] 2023-05-08T02:14:27.573586+00:00 smithi184 kernel: [ 1313.056613] process_one_work+0x238/0x500 2023-05-08T02:14:27.573586+00:00 smithi184 kernel: [ 1313.056635] ? process_one_work+0x500/0x500 2023-05-08T02:14:27.573586+00:00 smithi184 kernel: [ 1313.056638] worker_thread+0x56/0x3b0 2023-05-08T02:14:27.573587+00:00 smithi184 kernel: [ 1313.056644] ? process_one_work+0x500/0x500 2023-05-08T02:14:27.573587+00:00 smithi184 kernel: [ 1313.056648] kthread+0xe5/0x110 2023-05-08T02:14:27.573591+00:00 smithi184 kernel: [ 1313.056652] ? kthread_complete_and_exit+0x20/0x20 2023-05-08T02:14:27.573591+00:00 smithi184 kernel: [ 1313.056656] ret_from_fork+0x1f/0x30 2023-05-08T02:14:27.573591+00:00 smithi184 kernel: [ 1313.056667] </TASK> 2023-05-08T02:14:27.573592+00:00 smithi184 kernel: [ 1313.056668] irq event stamp: 15006735 2023-05-08T02:14:27.573592+00:00 smithi184 kernel: [ 1313.056670] hardirqs last enabled at (15006741): [<ffffffff9312ee4e>] __up_console_sem+0x5e/0x70 2023-05-08T02:14:27.573592+00:00 smithi184 kernel: [ 1313.056681] hardirqs last disabled at (15006766): [<ffffffff9312ee33>] __up_console_sem+0x43/0x70 2023-05-08T02:14:27.573596+00:00 smithi184 kernel: [ 1313.056684] softirqs last enabled at (15006762): [<ffffffff930a345f>] __irq_exit_rcu+0x8f/0xc0 2023-05-08T02:14:27.573597+00:00 smithi184 kernel: [ 1313.056692] softirqs last disabled at (15006777): [<ffffffff930a345f>] __irq_exit_rcu+0x8f/0xc0 2023-05-08T02:14:27.573597+00:00 smithi184 kernel: [ 1313.056695] ---[ end trace 0000000000000000 ]--- 2023-05-08T02:14:27.573597+00:00 smithi184 kernel: [ 1313.056700] libceph: read_partial_message 00000000b1f6d729 front crc 1373592970 != exp. 1 2023-05-08T02:14:27.573603+00:00 smithi184 kernel: [ 1313.065037] libceph: osd7 (1)172.21.15.55:6820 bad crc/signature 2023-05-08T02:14:29.293553+00:00 smithi184 kernel: [ 1314.784780] libceph: osd2 (1)172.21.15.26:6819 socket error on read 2023-05-08T02:14:29.309511+00:00 smithi184 kernel: [ 1314.789646] libceph: read_partial_message 00000000819da6ce front crc 1936051288 != exp. 1 2023-05-08T02:14:29.309518+00:00 smithi184 kernel: [ 1314.798056] libceph: osd2 (1)172.21.15.26:6819 bad crc/signature 2023-05-08T02:14:47.097552+00:00 smithi184 kernel: [ 1332.585802] libceph: mon0 (1)172.21.15.26:6789 session established 2023-05-08T02:14:47.097565+00:00 smithi184 kernel: [ 1332.586078] libceph: client5217 fsid cd27d0a3-96da-447f-a7ee-e36363679d66
First time see this failure like this.
Updated by Kotresh Hiremath Ravishankar 12 months ago
Updated by Xiubo Li 12 months ago
Kotresh Hiremath Ravishankar wrote:
Seen in yuri's reef run
https://pulpito.ceph.com/yuriw-2023-05-09_19:37:41-fs-wip-yuri10-testing-2023-05-08-0849-reef-distro-default-smithi/7268716
This is a different one with the call trace in comment#1:
2023-05-09T21:26:39.174368+00:00 smithi119 kernel: [ 5073.484972] WARNING: CPU: 7 PID: 181009 at fs/crypto/keyring.c:95 fscrypt_put_master_key_activeref+0x121/0x140 2023-05-09T21:26:39.174370+00:00 smithi119 kernel: [ 5073.484977] Modules linked in: ceph libceph fscache netfs veth xfs xt_conntrack nft_chain_nat xt_MASQUERADE nf_nat nf_conntrack_netlink nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 xfrm_user xfrm_algo xt_addrtype nft_compat nf_tables libcrc32c nfnetlink br_netfilter bridge stp llc rdma_ucm ib_uverbs rdma_cm iw_cm ib_cm ib_core overlay ipmi_ssif intel_rapl_msr intel_rapl_common sb_edac x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul ghash_clmulni_intel sha512_ssse3 aesni_intel joydev crypto_simd cryptd mei_me mei ioatdma wmi acpi_ipmi ipmi_si ipmi_devintf ipmi_msghandler acpi_pad acpi_power_meter kvm_intel kvm irqbypass sch_fq_codel scsi_transport_iscsi lp parport ramoops reed_solomon efi_pstore configfs nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 igb hid_generic i2c_algo_bit usbhid hid ixgbe dca i2c_i801 crc32_pclmul ptp nvme lpc_ich ahci i2c_smbus pps_core libahci nvme_core mdio 2023-05-09T21:26:39.174372+00:00 smithi119 kernel: [ 5073.485065] CPU: 7 PID: 181009 Comm: kworker/7:2 Tainted: G W 6.3.0-gf1e69e4d3654 #1 2023-05-09T21:26:39.174373+00:00 smithi119 kernel: [ 5073.485067] Hardware name: Supermicro SYS-5018R-WR/X10SRW-F, BIOS 2.0 12/17/2015 2023-05-09T21:26:39.174375+00:00 smithi119 kernel: [ 5073.485069] Workqueue: ceph-msgr ceph_con_workfn [libceph] 2023-05-09T21:26:39.174376+00:00 smithi119 kernel: [ 5073.485094] RIP: 0010:fscrypt_put_master_key_activeref+0x121/0x140 2023-05-09T21:26:39.174377+00:00 smithi119 kernel: [ 5073.485096] Code: 00 00 41 c6 84 24 a8 02 00 00 00 4c 89 e7 5b 5d 41 5c 41 5d e9 10 fc ff ff 48 8d be a8 00 00 00 be 03 00 00 00 e9 bf 49 23 00 <0f> 0b 5b 5d 41 5c 41 5d c3 0f 0b e9 54 ff ff ff 0f 0b e9 66 ff ff 2023-05-09T21:26:39.174379+00:00 smithi119 kernel: [ 5073.485098] RSP: 0018:ffffaa6dc2e8fb68 EFLAGS: 00010246 2023-05-09T21:26:39.174380+00:00 smithi119 kernel: [ 5073.485101] RAX: 0000000000000001 RBX: ffff9b963b56d808 RCX: 0000000000000000 2023-05-09T21:26:39.174381+00:00 smithi119 kernel: [ 5073.485103] RDX: 0000000000000002 RSI: ffff9b9587bbd400 RDI: 0000000000000000 2023-05-09T21:26:39.174382+00:00 smithi119 kernel: [ 5073.485104] RBP: ffff9b96cd150000 R08: ffff9b963a1085a8 R09: ffff9b963a1085a8 2023-05-09T21:26:39.174383+00:00 smithi119 kernel: [ 5073.485106] R10: 0000000000000000 R11: 0000000000000001 R12: ffff9b9587bbd400 2023-05-09T21:26:39.174385+00:00 smithi119 kernel: [ 5073.485107] R13: ffff9b9587bbd550 R14: ffff9b963b56d808 R15: ffff9b96960a0a20 2023-05-09T21:26:39.174386+00:00 smithi119 kernel: [ 5073.485109] FS: 0000000000000000(0000) GS:ffff9b9cdfdc0000(0000) knlGS:0000000000000000 2023-05-09T21:26:39.174387+00:00 smithi119 kernel: [ 5073.485111] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 2023-05-09T21:26:39.174388+00:00 smithi119 kernel: [ 5073.485112] CR2: 00007f7dbf41ba50 CR3: 000000010c722003 CR4: 00000000003706e0 2023-05-09T21:26:39.174389+00:00 smithi119 kernel: [ 5073.485114] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 2023-05-09T21:26:39.174391+00:00 smithi119 kernel: [ 5073.485115] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 2023-05-09T21:26:39.174410+00:00 smithi119 kernel: [ 5073.485117] Call Trace: 2023-05-09T21:26:39.174412+00:00 smithi119 kernel: [ 5073.485119] <TASK> 2023-05-09T21:26:39.174413+00:00 smithi119 kernel: [ 5073.485121] put_crypt_info+0x8b/0xf0 2023-05-09T21:26:39.174414+00:00 smithi119 kernel: [ 5073.485125] fscrypt_put_encryption_info+0x19/0x30 2023-05-09T21:26:39.174415+00:00 smithi119 kernel: [ 5073.485128] ceph_evict_inode+0x6e/0x2b0 [ceph] 2023-05-09T21:26:39.174416+00:00 smithi119 kernel: [ 5073.485142] evict+0xcc/0x1c0 2023-05-09T21:26:39.174418+00:00 smithi119 kernel: [ 5073.485147] writepages_finish+0x297/0x570 [ceph] 2023-05-09T21:26:39.174419+00:00 smithi119 kernel: [ 5073.485164] __complete_request+0x1c/0x80 [libceph] 2023-05-09T21:26:39.174420+00:00 smithi119 kernel: [ 5073.485180] osd_dispatch+0x60/0xcd0 [libceph] 2023-05-09T21:26:39.174421+00:00 smithi119 kernel: [ 5073.485196] ? ceph_con_process_message+0x69/0x160 [libceph] 2023-05-09T21:26:39.174423+00:00 smithi119 kernel: [ 5073.485209] ? lock_release+0xc9/0x270 2023-05-09T21:26:39.174424+00:00 smithi119 kernel: [ 5073.485214] ? __mutex_unlock_slowpath+0x45/0x280 2023-05-09T21:26:39.174425+00:00 smithi119 kernel: [ 5073.485220] ceph_con_process_message+0x78/0x160 [libceph] 2023-05-09T21:26:39.174427+00:00 smithi119 kernel: [ 5073.485234] ? calc_signature+0x108/0x130 [libceph] 2023-05-09T21:26:39.174428+00:00 smithi119 kernel: [ 5073.485250] ceph_con_v1_try_read+0x11a0/0x1e00 [libceph] 2023-05-09T21:26:39.174429+00:00 smithi119 kernel: [ 5073.485267] ? ceph_con_workfn+0x2e/0x730 [libceph] 2023-05-09T21:26:39.174430+00:00 smithi119 kernel: [ 5073.485281] ? process_one_work+0x1be/0x500 2023-05-09T21:26:39.174432+00:00 smithi119 kernel: [ 5073.485288] ceph_con_workfn+0x383/0x730 [libceph] 2023-05-09T21:26:39.174433+00:00 smithi119 kernel: [ 5073.485302] process_one_work+0x238/0x500 2023-05-09T21:26:39.174434+00:00 smithi119 kernel: [ 5073.485309] ? process_one_work+0x500/0x500 2023-05-09T21:26:39.174436+00:00 smithi119 kernel: [ 5073.485312] worker_thread+0x56/0x3b0 2023-05-09T21:26:39.174437+00:00 smithi119 kernel: [ 5073.485316] ? process_one_work+0x500/0x500
And have been fixed last week by:
https://patchwork.kernel.org/project/ceph-devel/list/?series=746047.
Updated by Kotresh Hiremath Ravishankar 12 months ago
Hi Xiubo,
Thank you for the update. I will update that tracker for the record.
Thanks,
Kotresh H R
Updated by Xiubo Li 8 months ago
- Status changed from New to Duplicate
- Parent task set to #62081
This should be the same sparse-read issue with tracer https://tracker.ceph.com/issues/59684.
Updated by Venky Shankar about 1 month ago
- Related to Bug #65136: QA failure: test_fscrypt_dummy_encryption_with_quick_group added