Re: [PATCH v3] sched/core: Always flush pending blk_plug

[Paul Gortmaker]

[Re: [PATCH v3] sched/core: Always flush pending blk_plug] On 10/07/2022 (Sun 09:01) Hillf Danton wrote:

> Looks like a ABBA deadlock that should be fed to lockdep, given what was
> blocking flusher (pid 213).

[,,,]

> Make lock_buffer have mutex_lock() semantics in attempt to catch the
> deadlock above.
> 
> Only for thoughts now.

Thanks for the test patch - I'm keeping it as a reference for future
use.

So, preempt-rt issues an early lockdep splat at partition probe bootup,
both with and without the original v3 patch from this thread.

Of course then I figured I'd try the debug patch on vanilla v5.19-rc3
and we get pretty much the same lockdep complaint.


   sd 1:0:0:0: Attached scsi generic sg1 type 0
   sd 1:0:0:0: [sdb] Preferred minimum I/O size 512 bytes
   scsi 2:0:0:0: CD-ROM            HL-DT-ST DVD-ROM DH30N    A101 PQ: 0 ANSI: 5

   =====================================
   WARNING: bad unlock balance detected!
   5.19.0-rc3-dirty #2 Not tainted
   -------------------------------------
   swapper/2/0 is trying to release lock (buffer_head_lock) at:
   [<ffffffffbc494a6b>] end_buffer_async_read+0x5b/0x180
   but there are no more locks to release!
   
   other info that might help us debug this:
   1 lock held by swapper/2/0:
    #0: ffff8bee27744080 (&ret->b_uptodate_lock){....}-{2:2}, at: end_buffer_async_read+0x47/0x180
   
   stack backtrace:
   CPU: 2 PID: 0 Comm: swapper/2 Not tainted 5.19.0-rc3-dirty #2
   Hardware name: Dell Inc. Precision WorkStation T5500  /0D883F, BIOS A16 05/28/2013
   Call Trace:
    <IRQ>
    dump_stack_lvl+0x40/0x5c
    lock_release+0x245/0x3f0
    unlock_buffer+0x15/0x30
    end_buffer_async_read+0x5b/0x180
    end_bio_bh_io_sync+0x1e/0x40
    blk_update_request+0x9a/0x470
    scsi_end_request+0x27/0x190
    scsi_io_completion+0x3c/0x580
    blk_complete_reqs+0x39/0x50
    __do_softirq+0x11d/0x344
    irq_exit_rcu+0xa9/0xc0
    common_interrupt+0xa5/0xc0
    </IRQ>
    <TASK>
    asm_common_interrupt+0x27/0x40
   RIP: 0010:cpuidle_enter_state+0x12d/0x3f0
   Code: 49 43 0f 84 b7 02 00 00 31 ff e8 fe 1c 74 ff 45 84 ff 74 12 9c 58 f6 c4 02 0f 85 8e 02 00 00 31 ff e8 97 95 7a ff fb 45 85 f6 <0f> 88 12 01 00 00 49 63 d6 4c 2b 24 24 48 8d 04 52 48 8d 04 82 49
   RSP: 0000:ffffa2890013fe90 EFLAGS: 00000206
   RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000002
   RDX: 0000000080000002 RSI: ffffffffbd78d911 RDI: 00000000ffffffff
   RBP: ffff8bee2739a400 R08: 0000000000000000 R09: 00000000001faf40
   R10: ffffa2890013fdc8 R11: 0000000000000000 R12: 00000000a7b149d6
   R13: ffffffffbdbee3a0 R14: 0000000000000003 R15: 0000000000000001
    cpuidle_enter+0x24/0x40
    do_idle+0x1e3/0x230
    cpu_startup_entry+0x14/0x20
    start_secondary+0xe8/0xf0
    secondary_startup_64_no_verify+0xe0/0xeb
    </TASK>
    sda: sda1 sda2 sda3
   sd 0:0:0:0: [sda] Attached SCSI disk
    sdb: sdb1 sdb2
   sd 1:0:0:0: [sdb] Attached SCSI disk

Not quite sure what to make of that.

Paul.
--