We observed the following crashes in 5.6.0 and 5.6.2 on multiple runs, both on bare metal and on GCE. The GCE traces look like this: [ 182.906051] ------------[ cut here ]------------ [ 182.910956] WARNING: CPU: 0 PID: 306 at ../../../../../../../../usr/src/linux-5.6.2-coreos/crypto/algapi.c:404 crypto_wait_for_test+0x59/0x70 [ 182.923933] Modules linked in: crc_t10dif(+) crct10dif_generic crct10dif_common aesni_intel(+) virtio_scsi glue_helper libaes crypto_simd virtio_net scsi_mod cryptd net_failover failover dm_mirror dm_region_hash dm_log dm_mod [ 182.944397] CPU: 0 PID: 306 Comm: systemd-udevd Not tainted 5.6.2-flatcar #1 [ 182.951604] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 182.960969] RIP: 0010:crypto_wait_for_test+0x59/0x70 [ 182.966089] Code: 9d fd ff ff 48 8d bb 88 01 00 00 e8 f1 aa 39 00 85 c0 75 16 48 89 de bf 02 00 00 00 e8 40 df ff ff 48 89 df 5b e9 17 e2 ff ff <0f> 0b eb f3 0f 0b eb ef 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 [ 182.984974] RSP: 0018:ffffbf35801cfbe0 EFLAGS: 00010286 [ 182.990371] RAX: 00000000fffffe00 RBX: ffffa077614bcc00 RCX: 0000000000000000 [ 182.997711] RDX: 00000000fffffe00 RSI: 0000000000000000 RDI: ffffa077614bcd90 [ 183.004965] RBP: 0000000000000000 R08: 00005f8940000000 R09: 0000000000000101 [ 183.012219] R10: 0000000000000139 R11: 0000000000000000 R12: ffffffffc04e777a [ 183.019483] R13: ffffffffc04e77fa R14: fffffffffffffff4 R15: ffffffffc04e7740 [ 183.026946] FS: 00007fdcbf39b940(0000) GS:ffffa0776c000000(0000) knlGS:0000000000000000 [ 183.035156] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 183.041132] CR2: 0000561c782e30c8 CR3: 00000001227de001 CR4: 00000000001606f0 [ 183.048414] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 183.055763] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 183.063574] Call Trace: [ 183.066241] crypto_register_alg+0x59/0x60 [ 183.070658] simd_skcipher_create_compat+0x16d/0x190 [crypto_simd] [ 183.077076] simd_register_skciphers_compat+0x7e/0xe0 [crypto_simd] [ 183.083463] ? 0xffffffffc04ea000 [ 183.086896] init_module+0xdd/0x1000 [aesni_intel] [ 183.091852] ? do_one_initcall+0x46/0x200 [ 183.095995] ? _cond_resched+0x15/0x30 [ 183.099861] ? kmem_cache_alloc_trace+0x155/0x220 [ 183.104730] ? do_init_module+0x5a/0x220 [ 183.108777] ? load_module+0x20e7/0x2380 [ 183.112822] ? ima_post_read_file+0xf4/0x100 [ 183.117391] ? __do_sys_finit_module+0xa8/0x110 [ 183.122050] ? __do_sys_finit_module+0xa8/0x110 [ 183.127066] ? do_syscall_64+0x4e/0x160 [ 183.131056] ? entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 183.136435] ---[ end trace 0b335532e6f66ae6 ]--- [ 183.024765] systemd-udevd[257]: cpu0: Worker [306] processing SEQNUM=820 killed [ 183.788715] systemd-udevd[257]: 0:0:1:0: Worker [310] processing SEQNUM=974 killed […] [ 246.946745] INFO: task systemd-udevd:310 blocked for more than 122 seconds. [ 246.953880] Tainted: G W 5.6.2-flatcar #1 [ 246.959832] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 246.967774] systemd-udevd D 0 310 257 0x800041a4 [ 246.973391] Call Trace: [ 246.975966] ? __schedule+0x2db/0x700 [ 246.979789] ? kvm_sched_clock_read+0xd/0x20 [ 246.984218] schedule+0x40/0xb0 [ 246.987495] rwsem_down_write_slowpath+0x2ed/0x4a0 [ 246.992441] ? __switch_to_asm+0x40/0x70 [ 246.996480] ? __switch_to_asm+0x40/0x70 [ 247.000550] ? __switch_to_asm+0x34/0x70 [ 247.004596] blocking_notifier_chain_register+0x22/0x50 [ 247.009939] ? 0xffffffffc0486000 [ 247.013386] init_module+0xc/0x1000 [crc_t10dif] [ 247.018132] do_one_initcall+0x46/0x200 [ 247.022097] ? _cond_resched+0x15/0x30 [ 247.025961] ? kmem_cache_alloc_trace+0x155/0x220 [ 247.030805] do_init_module+0x5a/0x220 [ 247.034699] load_module+0x20e7/0x2380 [ 247.038583] ? ima_post_read_file+0xf4/0x100 [ 247.042974] ? __do_sys_finit_module+0xa8/0x110 [ 247.047670] __do_sys_finit_module+0xa8/0x110 [ 247.052215] do_syscall_64+0x4e/0x160 [ 247.057154] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 247.062335] RIP: 0033:0x7fdcbfb35389 [ 247.066035] Code: Bad RIP value. [ 247.069377] RSP: 002b:00007ffcb1814e98 EFLAGS: 00000246 ORIG_RAX: 0000000000000139 [ 247.077062] RAX: ffffffffffffffda RBX: 00005595495df080 RCX: 00007fdcbfb35389 [ 247.084322] RDX: 0000000000000000 RSI: 00007fdcbfc9386d RDI: 000000000000000f [ 247.091590] RBP: 00007fdcbfc9386d R08: 0000000000000000 R09: 0000000000000001 [ 247.098840] R10: 000000000000000f R11: 0000000000000246 R12: 0000000000000000 [ 247.106101] R13: 00005595495b0f70 R14: 0000000000020000 R15: 00005595495df080 [ 247.113870] INFO: task cryptomgr_probe:353 blocked for more than 123 seconds. [ 247.121139] Tainted: G W 5.6.2-flatcar #1 [ 247.127122] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 247.135114] cryptomgr_probe D 0 353 2 0x80004080 [ 247.140814] Call Trace: [ 247.143426] ? __schedule+0x2db/0x700 [ 247.147296] ? update_load_avg+0x7e/0x5e0 [ 247.151532] schedule+0x40/0xb0 [ 247.154794] rwsem_down_read_slowpath+0x370/0x470 [ 247.159647] blocking_notifier_call_chain+0x27/0x60 [ 247.164751] crypto_probing_notify+0x1f/0x50 [ 247.169158] crypto_wait_for_test+0x1a/0x70 [ 247.173550] crypto_register_instance+0xed/0x110 [ 247.178336] cryptd_alloc_aead+0xabf/0xbb0 [cryptd] [ 247.183461] ? crypto_alg_put+0x40/0x40 [ 247.187413] cryptomgr_probe+0x3f/0x80 [ 247.191333] kthread+0x112/0x130 [ 247.194691] ? kthread_park+0x80/0x80 [ 247.198471] ret_from_fork+0x35/0x40 The bare-metal trace looks like this: [ 186.655173] ------------[ cut here ]------------ [ 186.686097] WARNING: CPU: 0 PID: 328 at ../../../../../../../../usr/src/linux-5.6.0-coreos/crypto/algapi.c:404 crypto_wait_for_test+0x59/0x70 [ 186.686098] Modules linked in: hid_generic usbhid hid crc_t10dif(+) ehci_pci crct10dif_generic crct10dif_common ehci_hcd aesni_intel(+) glue_helper libaes crypto_simd usbcore igb ahci libahci libata i2c_algo_bit i2c_core hwmon cryptd ptp scsi_mod usb_common pps_core dm_mirror dm_region_hash dm_log dm_mod [ 185.880994] systemd-udevd[282]: cpu0: Worker [328] processing SEQNUM=944 killed [ 186.864494] CPU: 0 PID: 328 Comm: systemd-udevd Not tainted 5.6.0-flatcar #1 [ 186.864495] Hardware name: Supermicro MBI-6418A-T5H/B1SA4-2550F, BIOS 2.0a 05/05/2015 [ 186.005178] systemd-udevd[282]: cpu3: Worker [334] processing SEQNUM=947 killed [ 186.864498] RIP: 0010:crypto_wait_for_test+0x59/0x70 [ 186.864501] Code: 9d fd ff ff 48 8d bb 88 01 00 00 e8 91 a9 39 00 85 c0 75 16 48 89 de bf 02 00 00 00 e8 40 df ff ff 48 89 df 5b e9 17 e2 ff ff <0f> 0b eb f3 0f 0b eb ef 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 [ 186.864503] RSP: 0018:ffff99be4023bbe0 EFLAGS: 00010286 [ 186.864505] RAX: 00000000fffffe00 RBX: ffff8ebce1586800 RCX: 0000000000000000 [ 186.864506] RDX: 00000000fffffe00 RSI: 0000000000000000 RDI: ffff8ebce1586990 [ 186.864507] RBP: 0000000000000000 R08: ffffffffb3403e30 R09: 0000002b47532412 [ 186.864508] R10: 0000000000000000 R11: 0000002b47532412 R12: ffffffffc051d5ba [ 186.864509] R13: ffffffffc051d63a R14: fffffffffffffff4 R15: ffffffffc051d580 [ 186.864511] FS: 00007ff85b0bd940(0000) GS:ffff8ebe37c00000(0000) knlGS:0000000000000000 [ 186.864516] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 187.325607] CR2: 00005648b9c810c8 CR3: 00000001217b0000 CR4: 00000000001006f0 [ 187.325608] Call Trace: [ 186.133412] systemd-udevd[282]: cpu2: Worker [339] processing SEQNUM=946 killed [ 187.325617] crypto_register_alg+0x59/0x60 [ 187.325622] simd_skcipher_create_compat+0x16d/0x190 [crypto_simd] [ 187.325629] simd_register_skciphers_compat+0x7e/0xe0 [crypto_simd] [ 187.325632] ? 0xffffffffc03e5000 [ 187.325639] init_module+0xdd/0x1000 [aesni_intel] [ 187.552585] ? do_one_initcall+0x46/0x200 [ 187.552589] ? _cond_resched+0x15/0x30 [ 186.588969] systemd-udevd[282]: cpu1: Worker [344] processing SEQNUM=945 killed [ 187.552592] ? kmem_cache_alloc_trace+0x155/0x220 [ 187.552596] ? do_init_module+0x5a/0x220 [ 187.552598] ? load_module+0x20e7/0x2380 [ 187.552603] ? ima_post_read_file+0xf4/0x100 [ 187.552607] ? __do_sys_finit_module+0xa8/0x110 [ 187.751720] ? __do_sys_finit_module+0xa8/0x110 [ 187.751725] ? do_syscall_64+0x4e/0x160 [ 187.751728] ? entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 187.751731] ---[ end trace 0e8a1e38d3de29a9 ]--- […] [ 370.585075] INFO: task systemd-udevd:328 blocked for more than 122 seconds. [ 370.603822] Tainted: G W 5.6.0-flatcar #1 [ 370.621569] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 370.641648] systemd-udevd D 0 328 282 0x80004184 [ 370.659432] Call Trace: [ 370.674173] ? __schedule+0x2db/0x700 [ 370.690328] ? __switch_to_asm+0x34/0x70 [ 370.706657] ? __switch_to_asm+0x34/0x70 [ 370.722748] schedule+0x40/0xb0 [ 370.737961] rwsem_down_read_slowpath+0x370/0x470 [ 370.754854] ? kmem_cache_alloc_trace+0x155/0x220 [ 370.771806] blocking_notifier_call_chain+0x27/0x60 [ 370.788960] crypto_probing_notify+0x1f/0x50 [ 370.805479] crypto_wait_for_test+0x1a/0x70 [ 370.821924] crypto_register_alg+0x59/0x60 [ 370.838214] simd_skcipher_create_compat+0x16d/0x190 [crypto_simd] [ 370.856856] simd_register_skciphers_compat+0x7e/0xe0 [crypto_simd] [ 370.875667] ? 0xffffffffc03e5000 [ 370.891457] init_module+0xdd/0x1000 [aesni_intel] [ 370.908800] ? do_one_initcall+0x46/0x200 [ 370.925287] ? _cond_resched+0x15/0x30 [ 370.941503] ? kmem_cache_alloc_trace+0x155/0x220 [ 370.958544] ? do_init_module+0x5a/0x220 [ 370.974573] ? load_module+0x20e7/0x2380 [ 370.990475] ? ima_post_read_file+0xf4/0x100 [ 371.006690] ? __do_sys_finit_module+0xa8/0x110 [ 371.023239] ? __do_sys_finit_module+0xa8/0x110 [ 371.039622] ? do_syscall_64+0x4e/0x160 [ 371.055079] ? entry_SYSCALL_64_after_hwframe+0x44/0xa9 Press Enter for emergency shell or wait 0 minutes 30 seconds for reboot. [ 371.071924] INFO: task systemd-udevd:342 blocked for more than 246 seconds. [ 371.090560] Tainted: G W 5.6.0-flatcar #1 [ 371.107917] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 371.127621] systemd-udevd D 0 342 282 0x80004184 [ 371.145080] Call Trace: [ 371.159355] ? __schedule+0x2db/0x700 [ 371.174913] schedule+0x40/0xb0 [ 371.189863] rwsem_down_write_slowpath+0x2ed/0x4a0 [ 371.206560] ? __switch_to_asm+0x40/0x70 [ 371.222327] ? __switch_to_asm+0x40/0x70 [ 371.237907] ? __switch_to_asm+0x34/0x70 [ 371.253358] blocking_notifier_chain_register+0x22/0x50 [ 371.270297] ? 0xffffffffc0443000 [ 371.285267] init_module+0xc/0x1000 [crc_t10dif] [ 371.301604] do_one_initcall+0x46/0x200 [ 371.317149] ? _cond_resched+0x15/0x30 [ 371.332540] ? kmem_cache_alloc_trace+0x155/0x220 [ 371.349015] do_init_module+0x5a/0x220 [ 371.364551] load_module+0x20e7/0x2380 [ 371.379860] ? ima_post_read_file+0xf4/0x100 [ 371.395554] ? __do_sys_finit_module+0xa8/0x110 [ 371.411298] __do_sys_finit_module+0xa8/0x110 [ 371.426644] do_syscall_64+0x4e/0x160 [ 371.441253] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 371.457429] RIP: 0033:0x7ff85b857389 [ 371.472144] Code: Bad RIP value. [ 371.486624] RSP: 002b:00007ffd23810dd8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139 [ 371.505960] RAX: ffffffffffffffda RBX: 0000558347a0e990 RCX: 00007ff85b857389 [ 371.524997] RDX: 0000000000000000 RSI: 00007ff85b9b586d RDI: 000000000000000f [ 371.544130] RBP: 00007ff85b9b586d R08: 0000000000000000 R09: 0000000000000001 [ 371.563228] R10: 000000000000000f R11: 0000000000000246 R12: 0000000000000000 [ 371.582236] R13: 0000558347a330b0 R14: 0000000000020000 R15: 0000558347a0e990 [ 371.601322] INFO: task cryptomgr_probe:389 blocked for more than 246 seconds. [ 371.620605] Tainted: G W 5.6.0-flatcar #1 [ 371.638550] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 371.658770] cryptomgr_probe D 0 389 2 0x80004080 [ 371.676575] Call Trace: [ 371.691114] ? __schedule+0x2db/0x700 [ 371.706879] ? sched_clock_cpu+0xc/0xb0 [ 371.722818] schedule+0x40/0xb0 [ 371.737961] rwsem_down_read_slowpath+0x370/0x470 [ 371.754787] blocking_notifier_call_chain+0x27/0x60 [ 371.771881] ? wake_up_q+0xa0/0xa0 [ 371.787480] crypto_probing_notify+0x1f/0x50 [ 371.803986] crypto_wait_for_test+0x50/0x70 [ 371.820544] crypto_register_instance+0xed/0x110 [ 371.837526] cryptd_alloc_aead+0xabf/0xbb0 [cryptd] [ 371.854728] ? crypto_alg_put+0x40/0x40 [ 371.870669] cryptomgr_probe+0x3f/0x80 [ 371.886325] kthread+0x112/0x130 [ 371.901170] ? kthread_park+0x80/0x80 [ 371.916212] ret_from_fork+0x35/0x40
I've seen what looks like the same issue come up on 5.6.7 and 5.6.14. This kernel includes some debian patches, for what it's worth. I rebuilt it with lock debugging and it looks like some notifier-related semaphore lock is being held by a bunch of different tasks. [ 183.821049] WARNING: CPU: 0 PID: 138 at crypto/algapi.c:404 crypto_wait_for_test+0x59/0x70 [ 183.829429] Modules linked in: crc32c_intel(+) efivarfs crc_t10dif(+) crct10dif_generic crct10dif_pclmul crct10dif_common virtio_scsi scsi_mod virtio_net net_failover failover aesni_intel(+) libaes crypto_simd cryptd glue_helper virtio_pci i2c_piix4 psmouse virtio_ring virtio button [ 183.854635] CPU: 0 PID: 138 Comm: systemd-udevd Not tainted 5.6.14 #1 [ 183.861296] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 183.870633] RIP: 0010:crypto_wait_for_test+0x59/0x70 [ 183.875710] Code: 8d fd ff ff 48 8d bd 88 01 00 00 e8 21 fc 48 00 85 c0 75 16 48 89 ee bf 02 00 00 00 e8 40 db ff ff 48 89 ef 5d e9 67 e0 ff ff <0f> 0b eb f3 0f 0b eb ef 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 [ 183.894612] RSP: 0018:ffff9fb44022fc08 EFLAGS: 00010286 [ 183.899948] RAX: 00000000fffffe00 RBX: ffffffffc02342b8 RCX: 0000000000000000 [ 183.907200] RDX: 00000000fffffe00 RSI: 0000000000000006 RDI: ffff8d805a5f0040 [ 183.914447] RBP: ffff8d7ff4822c00 R08: 0000000000000000 R09: 0000000000000000 [ 183.921706] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000 [ 183.928957] R13: ffffffffc023423a R14: ffff8d8047dec000 R15: ffffffffc0234200 [ 183.936205] FS: 00007fe19d5f1880(0000) GS:ffff8d805a400000(0000) knlGS:0000000000000000 [ 183.944421] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 183.950289] CR2: 000056440e23f070 CR3: 0000000134888006 CR4: 00000000003606f0 [ 183.957550] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 183.964799] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 183.972046] Call Trace: [ 183.974610] crypto_register_alg+0x56/0x70 [ 183.978833] simd_aead_create_compat+0x15d/0x180 [crypto_simd] [ 183.984784] simd_register_aeads_compat+0x64/0x630 [crypto_simd] [ 183.990905] ? 0xffffffffc0242000 [ 183.994349] aesni_init+0xff/0x1000 [aesni_intel] [ 183.999171] ? do_one_initcall+0x5d/0x2c0 [ 184.003304] ? do_init_module+0x23/0x230 [ 184.007341] ? rcu_read_lock_sched_held+0x52/0x60 [ 184.012155] ? do_init_module+0x23/0x230 [ 184.016200] ? kmem_cache_alloc_trace+0x260/0x2a0 [ 184.021017] ? do_init_module+0x5c/0x230 [ 184.025062] ? load_module+0x2381/0x2570 [ 184.029109] ? __do_sys_finit_module+0xaa/0x110 [ 184.033761] ? __do_sys_finit_module+0xaa/0x110 [ 184.038421] ? do_syscall_64+0x5a/0x230 [ 184.042379] ? entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 184.047724] irq event stamp: 9906 [ 184.051148] hardirqs last enabled at (9905): [<ffffffff8ecdbb54>] _raw_spin_unlock_irq+0x24/0x30 [ 184.060137] hardirqs last disabled at (9906): [<ffffffff8e40391c>] trace_hardirqs_off_thunk+0x1a/0x1c [ 184.069471] softirqs last enabled at (9782): [<ffffffff8f00035d>] __do_softirq+0x35d/0x3f1 [ 184.077957] softirqs last disabled at (9767): [<ffffffff8e494949>] irq_exit+0xb9/0xc0 [ 184.085958] ---[ end trace ec497009adfc1f9a ]--- [ 242.923659] INFO: task systemd-udevd:137 blocked for more than 120 seconds. [ 242.931295] Tainted: G W 5.6.14 #1 [ 242.936766] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 242.944731] systemd-udevd D 0 137 124 0x80004004 [ 242.950390] Call Trace: [ 242.953007] ? __schedule+0x370/0x960 [ 242.956805] ? schedule+0x4a/0xb0 [ 242.960287] ? rwsem_down_write_slowpath+0x32c/0x640 [ 242.965431] ? blocking_notifier_chain_register+0x26/0x60 [ 242.970997] ? blocking_notifier_chain_register+0x26/0x60 [ 242.976562] ? 0xffffffffc0188000 [ 242.980043] ? crc_t10dif_mod_init+0xc/0x1000 [crc_t10dif] [ 242.985665] ? do_one_initcall+0x5d/0x2c0 [ 242.989806] ? do_init_module+0x23/0x230 [ 242.993911] ? rcu_read_lock_sched_held+0x52/0x60 [ 242.998819] ? do_init_module+0x23/0x230 [ 243.002877] ? kmem_cache_alloc_trace+0x260/0x2a0 [ 243.007754] ? do_init_module+0x5c/0x230 [ 243.011815] ? load_module+0x2381/0x2570 [ 243.015925] ? __do_sys_finit_module+0xaa/0x110 [ 243.020675] ? __do_sys_finit_module+0xaa/0x110 [ 243.025438] ? do_syscall_64+0x5a/0x230 [ 243.029439] ? entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 243.034808] INFO: task cryptomgr_probe:201 blocked for more than 120 seconds. [ 243.042116] Tainted: G W 5.6.14 #1 [ 243.047472] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 243.055559] cryptomgr_probe D 0 201 2 0x80004000 [ 243.061211] Call Trace: [ 243.063824] ? __schedule+0x370/0x960 [ 243.067622] ? schedule+0x4a/0xb0 [ 243.071060] ? rwsem_down_read_slowpath+0x27e/0x600 [ 243.076112] ? down_read+0x99/0x120 [ 243.079788] ? down_read+0x99/0x120 [ 243.083430] ? blocking_notifier_call_chain+0x34/0x70 [ 243.088769] ? crypto_probing_notify+0x20/0x50 [ 243.093456] ? crypto_wait_for_test+0x50/0x70 [ 243.097949] ? crypto_register_instance+0xe9/0x110 [ 243.102882] ? cryptd_create+0x450/0x490 [cryptd] [ 243.107724] ? cryptomgr_probe+0x38/0xc0 [ 243.111783] ? kthread+0xf9/0x130 [ 243.115229] ? cryptomgr_notify+0x580/0x580 [ 243.119582] ? kthread_park+0x90/0x90 [ 243.123504] ? ret_from_fork+0x3a/0x50 [ 243.127475] [ 243.127475] Showing all locks held in the system: [ 243.133797] 1 lock held by khungtaskd/18: [ 243.138058] #0: ffffffff8f85fd00 (rcu_read_lock){....}, at: debug_show_all_locks+0x15/0x161 [ 243.146786] 1 lock held by systemd-udevd/137: [ 243.151905] #0: ffffffff8f8d4568 ((crypto_chain).rwsem){++++}, at: blocking_notifier_chain_register+0x26/0x60 [ 243.162332] 1 lock held by cryptomgr_test/195: [ 243.167107] #0: ffffffff8f8d4568 ((crypto_chain).rwsem){++++}, at: blocking_notifier_call_chain+0x34/0x70 [ 243.176922] 1 lock held by cryptomgr_probe/201: [ 243.181591] #0: ffffffff8f8d4568 ((crypto_chain).rwsem){++++}, at: blocking_notifier_call_chain+0x34/0x70 [ 243.191427] 1 lock held by modprobe/255: [ 243.195480] #0: ffffffff8f8d4568 ((crypto_chain).rwsem){++++}, at: blocking_notifier_call_chain+0x34/0x70 [ 243.205274] [ 243.206884] ============================================= Worryingly blocking_notifier_chain_register gets a write lock while blocking_notifier_call_chain gets a read lock, which if I'm reading the "held locks" lines correctly that means the semaphore is simultaneously held by read holders and write holders (it's entirely possible I'm reading this wrong and all these tasks are just simultaneously waiting for something else).
Can you blacklist crc-t10dif and see if this still happens? There is a race condition in crc-t10dif in that it registers the notifier too early and it may race against its own crypto alloc call.
> Can you blacklist crc-t10dif and see if this still happens? There is a race > condition in crc-t10dif in that it registers the notifier too early and it > may race against its own crypto alloc call. I don't think that can be it, because the stack traces show that crc_t10dif_mod_init() is blocked on crypto_register_notifier(). So it never got to crypto_alloc_shash(). I'm more inclined to blame the fact that cryptomgr_schedule_probe() waits for the requested module to be loaded, while it holds crypto_chain.rwsem for read via blocking_notifier_call_chain(). That will deadlock if loading the requested module needs to wait for crc-t10dif.ko to also be loaded, for any reason. I don't immediately see why that would happen, as crc-t10dif.ko is a library module, not a crypto API module. Maybe userspace is serializing the module loading? It would be helpful to have a way to reproduce this. Also, I'm guessing that crc-t10dif.ko is being inserted as a dependency of the SCSI disk module sd.ko, so blacklisting it wouldn't work. Can you try this patch? diff --git a/crypto/algboss.c b/crypto/algboss.c index 535f1f87e6c1..5ebccbd6b74e 100644 --- a/crypto/algboss.c +++ b/crypto/algboss.c @@ -178,8 +178,6 @@ static int cryptomgr_schedule_probe(struct crypto_larval *larval) if (IS_ERR(thread)) goto err_put_larval; - wait_for_completion_interruptible(&larval->completion); - return NOTIFY_STOP;
Applying that patch seems to fix the lockup for me. I can look to try and find a minimal repro. I have other configurations that run in GCE that don't hit this lockup, so something unique about the order modules are loaded or userspace comes up sounds like a plausible trigger.
OK, after some more experimentation I think the trigger here was Debian moving some of the CRYPTO_* libs into modules. Moving them back into the kernel image seems to make the problem go away. Which I guess still means there might be a bug here, but unfortunately I can't bound it within v5.5..v5.6 because the trigger wasn't a commit but a config change. I'll add another comment once I figure out what the actual config changes are.
Thanks Eric. Your patch looks correct, I have no idea why I put that wait in there at all :) The actual larval users would be waiting after the notify returns anyway. Please send it to the list when you're ready.
Ah, I assumed the patch was just for debugging purposes, if that's the actual fix that's fantastic. Thanks a lot!
Fix sent out: https://lkml.kernel.org/linux-crypto/20200604185253.5119-1-ebiggers@kernel.org