Skip to content

Instantly share code, notes, and snippets.

@mcgrof
Created April 12, 2022 22:10
Show Gist options
  • Save mcgrof/8f80e72f9f3bae20dcc3d45a06f30379 to your computer and use it in GitHub Desktop.
Save mcgrof/8f80e72f9f3bae20dcc3d45a06f30379 to your computer and use it in GitHub Desktop.
blktests srp/011 fails with an NMI on v5.17-rc7
[ 139.510017] scsi host5: ib_srp: Already connected to target port with id_ext=505400fffea6d62d;ioc_guid=505400fffea6d62d;dest=fe80:0000:0000:0000:5054:00ff:fec2:d9c8
[ 139.514734] sd 4:0:0:1: [sdg] 65536 512-byte logical blocks: (33.6 MB/32.0 MiB)
[ 139.520420] sd 4:0:0:1: [sdg] Write Protect is off
[ 139.525071] sd 4:0:0:1: [sdg] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[ 139.529885] sd 4:0:0:0: [sde] Attached SCSI disk
[ 139.532471] sd 4:0:0:1: [sdg] Optimal transfer size 126976 bytes
[ 139.562305] sd 4:0:0:2: [sdf] Attached SCSI disk
[ 160.581512] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 160.585060] rcu: 7-...0: (1 GPs behind) idle=e25/1/0x4000000000000000 softirq=10541/10542 fqs=2250
[ 160.587717] (detected by 6, t=5252 jiffies, g=12225, q=11280)
[ 160.589747] Sending NMI from CPU 6 to CPUs 7:
[ 160.591505] NMI backtrace for cpu 7
[ 160.591521] CPU: 7 PID: 2874 Comm: systemd-udevd Kdump: loaded Tainted: G E 5.17.0-rc7 #1
[ 160.591526] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 160.591530] RIP: 0010:native_queued_spin_lock_slowpath+0x28/0x200
[ 160.591568] Code: 00 00 0f 1f 44 00 00 41 54 55 53 48 89 fb 66 90 ba 01 00 00 00 8b 03 85 c0 75 0d f0 0f b1 13 85 c0 75 f2 5b 5d 41 5c c3 f3 90 <eb> e9 81 fe 00 01 00 00 74 45 40 30 f6 85 f6 75 67 f0 0f ba 2b 08
[ 160.591570] RSP: 0018:ffffb46f401f8e58 EFLAGS: 00000002
[ 160.591573] RAX: 0000000000000001 RBX: ffff8c4b8f015a90 RCX: 0000000000070029
[ 160.591576] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff8c4b8f015a90
[ 160.591576] RBP: ffff8c4b8f015a80 R08: ffff8c4bbdefd7c0 R09: ffff8c4bbfe0e800
[ 160.591577] R10: ffffffff912060c0 R11: ffffb46f401f8ff8 R12: 0000000000000282
[ 160.591578] R13: ffff8c4b8f0177e0 R14: ffff8c4bbeb0c460 R15: ffff8c4b8f015a90
[ 160.591579] FS: 00007eff866168c0(0000) GS:ffff8c4cbfdc0000(0000) knlGS:0000000000000000
[ 160.591581] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 160.591582] CR2: 000055d195e81000 CR3: 00000001172da002 CR4: 0000000000770ee0
[ 160.591584] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 160.591585] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 160.591586] PKRU: 55555554
[ 160.591588] Call Trace:
[ 160.591593] <IRQ>
[ 160.591597] _raw_spin_lock_irqsave+0x44/0x50
[ 160.591633] srp_recv_done+0x11e/0x480 [ib_srp]
[ 160.591653] ? _raw_spin_lock_bh+0x13/0x30
[ 160.591656] __ib_process_cq+0x83/0x180 [ib_core]
[ 160.591732] ib_poll_handler+0x2b/0xc0 [ib_core]
[ 160.591743] irq_poll_softirq+0x8e/0x120
[ 160.591760] __do_softirq+0xec/0x2ea
[ 160.591765] do_softirq.part.0+0x9b/0xd0
[ 160.591774] </IRQ>
[ 160.591775] <TASK>
[ 160.591775] __local_bh_enable_ip+0x73/0x80
[ 160.591784] rxe_poll_cq+0xed/0x100 [rdma_rxe]
[ 160.591807] __ib_process_cq+0x54/0x180 [ib_core]
[ 160.591818] ib_process_cq_direct+0x2c/0x50 [ib_core]
[ 160.591828] ? kernel_text_address+0x13/0xd0
[ 160.591834] ? filemap_read+0xb9/0x2d0
[ 160.591845] ? __kernel_text_address+0xe/0x30
[ 160.591847] ? unwind_get_return_address+0x1b/0x30
[ 160.591854] ? create_prof_cpu_mask+0x20/0x20
[ 160.591859] ? arch_stack_walk+0x75/0xf0
[ 160.591864] ? filemap_read+0xb9/0x2d0
[ 160.591866] ? _raw_spin_lock_irqsave+0x44/0x50
[ 160.591868] ? create_object.isra.0+0x1c8/0x330
[ 160.591879] ? _raw_spin_unlock_irqrestore+0x25/0x40
[ 160.591881] ? kmem_cache_alloc+0x2af/0x420
[ 160.591888] ? mempool_alloc+0x5f/0x1a0
[ 160.591891] ? __blk_rq_map_sg+0x11c/0x560
[ 160.591901] __srp_get_tx_iu+0x20/0xa0 [ib_srp]
[ 160.591904] srp_queuecommand+0xbe/0x98a [ib_srp]
[ 160.591907] ? scsi_alloc_sgtables+0xb9/0x3f0 [scsi_mod]
[ 160.591943] ? blk_mq_get_tag+0x249/0x2b0
[ 160.591952] ? sd_init_command+0x4bd/0xd40 [sd_mod]
[ 160.591958] ? scsi_init_command+0x102/0x1a0 [scsi_mod]
[ 160.591966] scsi_queue_rq+0x37b/0xb10 [scsi_mod]
[ 160.591978] __blk_mq_try_issue_directly+0x14f/0x1c0
[ 160.591986] blk_mq_plug_issue_direct.constprop.0+0xaf/0x1b0
[ 160.591989] blk_mq_flush_plug_list+0x322/0x3a0
[ 160.591992] blk_flush_plug+0x102/0x160
[ 160.591998] blk_finish_plug+0x21/0x30
[ 160.591999] read_pages+0x16d/0x240
[ 160.592003] page_cache_ra_unbounded+0x182/0x210
[ 160.592005] force_page_cache_ra+0xc7/0x100
[ 160.592007] filemap_get_pages+0xe9/0x5e0
[ 160.592009] ? atime_needs_update+0xfc/0x170
[ 160.592019] filemap_read+0xb9/0x2d0
[ 160.592022] ? security_compute_av_user+0x10/0x120
[ 160.592029] ? ptep_set_access_flags+0x2f/0x40
[ 160.592033] ? _raw_spin_unlock+0x16/0x30
[ 160.592035] ? wp_page_reuse+0x61/0x70
[ 160.592039] ? do_wp_page+0x1da/0x2f0
[ 160.592041] ? preempt_count_add+0x68/0xa0
[ 160.592048] ? aa_file_perm+0x11c/0x4c0
[ 160.592056] blkdev_read_iter+0xac/0x1c0
[ 160.592064] new_sync_read+0x115/0x1a0
[ 160.592071] vfs_read+0xf1/0x190
[ 160.592074] ksys_read+0x5f/0xe0
[ 160.592076] do_syscall_64+0x38/0xc0
[ 160.592085] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 160.592087] RIP: 0033:0x7eff86bc010e
[ 160.592104] Code: 0f 1f 40 00 48 8b 15 b9 ae 00 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb ba 0f 1f 00 64 8b 04 25 18 00 00 00 85 c0 75 14 0f 05 <48> 3d 00 f0 ff ff 77 5a c3 66 0f 1f 84 00 00 00 00 00 48 83 ec 28
[ 160.592106] RSP: 002b:00007fff70669c48 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 160.592107] RAX: ffffffffffffffda RBX: 000055d195e42e98 RCX: 00007eff86bc010e
[ 160.592108] RDX: 0000000000040000 RSI: 000055d195e42ea8 RDI: 000000000000000f
[ 160.592109] RBP: 000055d195d7bc70 R08: 000055d195e42e80 R09: 00007eff86ba4c00
[ 160.592110] R10: 0000000000000400 R11: 0000000000000246 R12: 0000000000000000
[ 160.592111] R13: 0000000000040000 R14: 000055d195e42e80 R15: 000055d195d7bcc0
[ 160.592113] </TASK>
[ 171.189646] scsi host4: SRP abort called
[ 171.202048] sd 4:0:0:2: [sdf] tag#43 FAILED Result: hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
[ 171.207343] sd 4:0:0:2: [sdf] tag#43 CDB: Read(10) 28 00 00 00 00 48 00 00 30 00
[ 171.211265] I/O error, dev sdf, sector 72 op 0x0:(READ) flags 0x80700 phys_seg 6 prio class 0
[ 171.215718] scsi host4: SRP abort called
[ 171.218551] sd 4:0:0:2: [sdf] tag#42 FAILED Result: hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
[ 171.223031] sd 4:0:0:2: [sdf] tag#42 CDB: Read(10) 28 00 00 00 00 28 00 00 10 00
[ 171.226856] I/O error, dev sdf, sector 40 op 0x0:(READ) flags 0x80700 phys_seg 2 prio class 0
[ 171.231275] scsi host4: SRP abort called
[ 171.233715] sd 4:0:0:2: [sdf] tag#41 FAILED Result: hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
[ 171.237449] sd 4:0:0:2: [sdf] tag#41 CDB: Read(10) 28 00 00 00 00 10 00 00 08 00
[ 171.240538] I/O error, dev sdf, sector 16 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0
[ 223.602066] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 223.604259] rcu: 7-...0: (1 GPs behind) idle=e25/1/0x4000000000000000 softirq=10541/10542 fqs=8985
[ 223.605778] (detected by 2, t=21007 jiffies, g=12225, q=19748)
[ 223.606717] Sending NMI from CPU 2 to CPUs 7:
[ 223.607538] NMI backtrace for cpu 7
[ 223.607559] CPU: 7 PID: 2874 Comm: systemd-udevd Kdump: loaded Tainted: G E 5.17.0-rc7 #1
[ 223.607564] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 223.607569] RIP: 0010:native_queued_spin_lock_slowpath+0x28/0x200
[ 223.607616] Code: 00 00 0f 1f 44 00 00 41 54 55 53 48 89 fb 66 90 ba 01 00 00 00 8b 03 85 c0 75 0d f0 0f b1 13 85 c0 75 f2 5b 5d 41 5c c3 f3 90 <eb> e9 81 fe 00 01 00 00 74 45 40 30 f6 85 f6 75 67 f0 0f ba 2b 08
[ 223.607618] RSP: 0018:ffffb46f401f8e58 EFLAGS: 00000002
[ 223.607622] RAX: 0000000000000001 RBX: ffff8c4b8f015a90 RCX: 0000000000070029
[ 223.607625] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff8c4b8f015a90
[ 223.607626] RBP: ffff8c4b8f015a80 R08: ffff8c4bbdefd7c0 R09: ffff8c4bbfe0e800
[ 223.607628] R10: ffffffff912060c0 R11: ffffb46f401f8ff8 R12: 0000000000000282
[ 223.607629] R13: ffff8c4b8f0177e0 R14: ffff8c4bbeb0c460 R15: ffff8c4b8f015a90
[ 223.607630] FS: 00007eff866168c0(0000) GS:ffff8c4cbfdc0000(0000) knlGS:0000000000000000
[ 223.607632] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 223.607633] CR2: 000055d195e81000 CR3: 00000001172da002 CR4: 0000000000770ee0
[ 223.607637] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 223.607638] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 223.607639] PKRU: 55555554
[ 223.607642] Call Trace:
[ 223.607647] <IRQ>
[ 223.607652] _raw_spin_lock_irqsave+0x44/0x50
[ 223.607694] srp_recv_done+0x11e/0x480 [ib_srp]
[ 223.607719] ? _raw_spin_lock_bh+0x13/0x30
[ 223.607726] __ib_process_cq+0x83/0x180 [ib_core]
[ 223.607810] ib_poll_handler+0x2b/0xc0 [ib_core]
[ 223.607824] irq_poll_softirq+0x8e/0x120
[ 223.607842] __do_softirq+0xec/0x2ea
[ 223.607848] do_softirq.part.0+0x9b/0xd0
[ 223.607860] </IRQ>
[ 223.607860] <TASK>
[ 223.607861] __local_bh_enable_ip+0x73/0x80
[ 223.607871] rxe_poll_cq+0xed/0x100 [rdma_rxe]
[ 223.607899] __ib_process_cq+0x54/0x180 [ib_core]
[ 223.607912] ib_process_cq_direct+0x2c/0x50 [ib_core]
[ 223.607926] ? kernel_text_address+0x13/0xd0
[ 223.607932] ? filemap_read+0xb9/0x2d0
[ 223.607946] ? __kernel_text_address+0xe/0x30
[ 223.607948] ? unwind_get_return_address+0x1b/0x30
[ 223.607956] ? create_prof_cpu_mask+0x20/0x20
[ 223.607962] ? arch_stack_walk+0x75/0xf0
[ 223.607968] ? filemap_read+0xb9/0x2d0
[ 223.607970] ? _raw_spin_lock_irqsave+0x44/0x50
[ 223.607973] ? create_object.isra.0+0x1c8/0x330
[ 223.607985] ? _raw_spin_unlock_irqrestore+0x25/0x40
[ 223.607988] ? kmem_cache_alloc+0x2af/0x420
[ 223.607995] ? mempool_alloc+0x5f/0x1a0
[ 223.607998] ? __blk_rq_map_sg+0x11c/0x560
[ 223.608009] __srp_get_tx_iu+0x20/0xa0 [ib_srp]
[ 223.608013] srp_queuecommand+0xbe/0x98a [ib_srp]
[ 223.608018] ? scsi_alloc_sgtables+0xb9/0x3f0 [scsi_mod]
[ 223.608062] ? blk_mq_get_tag+0x249/0x2b0
[ 223.608072] ? sd_init_command+0x4bd/0xd40 [sd_mod]
[ 223.608081] ? scsi_init_command+0x102/0x1a0 [scsi_mod]
[ 223.608091] scsi_queue_rq+0x37b/0xb10 [scsi_mod]
[ 223.608108] __blk_mq_try_issue_directly+0x14f/0x1c0
[ 223.608117] blk_mq_plug_issue_direct.constprop.0+0xaf/0x1b0
[ 223.608121] blk_mq_flush_plug_list+0x322/0x3a0
[ 223.608125] blk_flush_plug+0x102/0x160
[ 223.608132] blk_finish_plug+0x21/0x30
[ 223.608134] read_pages+0x16d/0x240
[ 223.608137] page_cache_ra_unbounded+0x182/0x210
[ 223.608140] force_page_cache_ra+0xc7/0x100
[ 223.608142] filemap_get_pages+0xe9/0x5e0
[ 223.608145] ? atime_needs_update+0xfc/0x170
[ 223.608153] filemap_read+0xb9/0x2d0
[ 223.608155] ? security_compute_av_user+0x10/0x120
[ 223.608163] ? ptep_set_access_flags+0x2f/0x40
[ 223.608167] ? _raw_spin_unlock+0x16/0x30
[ 223.608170] ? wp_page_reuse+0x61/0x70
[ 223.608175] ? do_wp_page+0x1da/0x2f0
[ 223.608177] ? preempt_count_add+0x68/0xa0
[ 223.608185] ? aa_file_perm+0x11c/0x4c0
[ 223.608195] blkdev_read_iter+0xac/0x1c0
[ 223.608204] new_sync_read+0x115/0x1a0
[ 223.608211] vfs_read+0xf1/0x190
[ 223.608215] ksys_read+0x5f/0xe0
[ 223.608219] do_syscall_64+0x38/0xc0
[ 223.608228] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 223.608231] RIP: 0033:0x7eff86bc010e
[ 223.608251] Code: 0f 1f 40 00 48 8b 15 b9 ae 00 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb ba 0f 1f 00 64 8b 04 25 18 00 00 00 85 c0 75 14 0f 05 <48> 3d 00 f0 ff ff 77 5a c3 66 0f 1f 84 00 00 00 00 00 48 83 ec 28
[ 223.608252] RSP: 002b:00007fff70669c48 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 223.608254] RAX: ffffffffffffffda RBX: 000055d195e42e98 RCX: 00007eff86bc010e
[ 223.608256] RDX: 0000000000040000 RSI: 000055d195e42ea8 RDI: 000000000000000f
[ 223.608257] RBP: 000055d195d7bc70 R08: 000055d195e42e80 R09: 00007eff86ba4c00
[ 223.608258] R10: 0000000000000400 R11: 0000000000000246 R12: 0000000000000000
[ 223.608259] R13: 0000000000040000 R14: 000055d195e42e80 R15: 000055d195d7bcc0
[ 223.608261] </TASK>
[ 286.626716] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 286.629529] rcu: 7-...0: (1 GPs behind) idle=e25/1/0x4000000000000000 softirq=10541/10542 fqs=15606
[ 286.631513] (detected by 6, t=36763 jiffies, g=12225, q=26367)
[ 286.632668] Sending NMI from CPU 6 to CPUs 7:
[ 286.633643] NMI backtrace for cpu 7
[ 286.633657] CPU: 7 PID: 2874 Comm: systemd-udevd Kdump: loaded Tainted: G E 5.17.0-rc7 #1
[ 286.633662] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 286.633667] RIP: 0010:native_queued_spin_lock_slowpath+0x28/0x200
[ 286.633707] Code: 00 00 0f 1f 44 00 00 41 54 55 53 48 89 fb 66 90 ba 01 00 00 00 8b 03 85 c0 75 0d f0 0f b1 13 85 c0 75 f2 5b 5d 41 5c c3 f3 90 <eb> e9 81 fe 00 01 00 00 74 45 40 30 f6 85 f6 75 67 f0 0f ba 2b 08
[ 286.633711] RSP: 0018:ffffb46f401f8e58 EFLAGS: 00000002
[ 286.633714] RAX: 0000000000000001 RBX: ffff8c4b8f015a90 RCX: 0000000000070029
[ 286.633717] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff8c4b8f015a90
[ 286.633718] RBP: ffff8c4b8f015a80 R08: ffff8c4bbdefd7c0 R09: ffff8c4bbfe0e800
[ 286.633719] R10: ffffffff912060c0 R11: ffffb46f401f8ff8 R12: 0000000000000282
[ 286.633720] R13: ffff8c4b8f0177e0 R14: ffff8c4bbeb0c460 R15: ffff8c4b8f015a90
[ 286.633721] FS: 00007eff866168c0(0000) GS:ffff8c4cbfdc0000(0000) knlGS:0000000000000000
[ 286.633722] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 286.633723] CR2: 000055d195e81000 CR3: 00000001172da002 CR4: 0000000000770ee0
[ 286.633726] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 286.633727] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 286.633728] PKRU: 55555554
[ 286.633731] Call Trace:
[ 286.633734] <IRQ>
[ 286.633738] _raw_spin_lock_irqsave+0x44/0x50
[ 286.633776] srp_recv_done+0x11e/0x480 [ib_srp]
[ 286.633795] ? _raw_spin_lock_bh+0x13/0x30
[ 286.633801] __ib_process_cq+0x83/0x180 [ib_core]
[ 286.633872] ib_poll_handler+0x2b/0xc0 [ib_core]
[ 286.633883] irq_poll_softirq+0x8e/0x120
[ 286.633900] __do_softirq+0xec/0x2ea
[ 286.633905] do_softirq.part.0+0x9b/0xd0
[ 286.633914] </IRQ>
[ 286.633915] <TASK>
[ 286.633915] __local_bh_enable_ip+0x73/0x80
[ 286.633926] rxe_poll_cq+0xed/0x100 [rdma_rxe]
[ 286.633950] __ib_process_cq+0x54/0x180 [ib_core]
[ 286.633961] ib_process_cq_direct+0x2c/0x50 [ib_core]
[ 286.633972] ? kernel_text_address+0x13/0xd0
[ 286.633977] ? filemap_read+0xb9/0x2d0
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment