Re: blk-mq + bfq IO hangs after writing partition table

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On Fri, Dec 01, 2017 at 12:18:25PM +0000, Ivan Kozik wrote:
> On Fri, Dec 1, 2017 at 8:50 AM, Ming Lei <ming.lei@xxxxxxxxxx> wrote:
> > Could you run the following script[1] and provide us the result after
> > the IO hang is triggered?
> >
> >         #./dump-blk-info /dev/sdX       #/dev/sdX is name of your USB disk
> >
> > [1] http://people.redhat.com/minlei/tests/tools/dump-blk-info
> 
> Hi Ming,
> 
> Thanks for taking a look.  I have pasted and attached (in case of
> gmail corruption) these files:
> 
> Samsung-128GB-before: Samsung 128GB USB 3.0 Fit plugged into HP 8460p,
> before gdisk write
> 
> Samsung-128GB-after:  Samsung 128GB USB 3.0 Fit plugged into HP 8460p,
> after gdisk write
> 
> Generic-4GB-after:    some awful generic but working 4GB USB flash
> drive plugged into HP 8460p, after gdisk write
> 
> I have reproduced this again on the same kernel revision and blk-mq bfq with:
> 
> minimized cmdline: scsi_mod.use_blk_mq=y
> gdisk writing the partition table as-is, no changes
> 
> and confirmed again that kyber never triggers this.
> 
> Thanks,
> 
> Ivan
> 
> 
> 
> 
> Samsung-128GB-before
> =============sdc/hctx0==================
> $active
> 0
> 
> $busy
> 
> $/sys/kernel/debug/block/sdc//hctx0/cpu0
>     $completed
>     3 14
>     $dispatched
>     3 14
>     $merged
>     0
>     $rq_list
> 
> $/sys/kernel/debug/block/sdc//hctx0/cpu1
>     $completed
>     159 76
>     $dispatched
>     159 76
>     $merged
>     0
>     $rq_list
> 
> $/sys/kernel/debug/block/sdc//hctx0/cpu2
>     $completed
>     84 57
>     $dispatched
>     84 57
>     $merged
>     0
>     $rq_list
> 
> $/sys/kernel/debug/block/sdc//hctx0/cpu3
>     $completed
>     154 54
>     $dispatched
>     155 54
>     $merged
>     1
>     $rq_list
> 
> $ctx_map
> 00000000: 00
> 
> $dispatch
> 
> $dispatched
>        0    8
>        1    701
>        2    0
>        4    0
>        8    0
>       16    0
>       32+    0
> 
> $flags
> alloc_policy=FIFO SHOULD_MERGE|SG_MERGE
> 
> $io_poll
> considered=0
> invoked=0
> success=0
> 
> $queued
> 602
> 
> $run
> 843
> 
> $sched_tags
> nr_tags=2
> nr_reserved_tags=0
> active_queues=0
> 
> bitmap_tags:
> depth=2
> busy=1
> bits_per_word=64
> map_nr=1
> alloc_hint={0, 1, 0, 0, 0, 1, 1, 0}
> wake_batch=1
> wake_index=0
> ws={
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
> }
> round_robin=0
> 
> $sched_tags_bitmap
> 00000000: 01
> 
> $state
> 
> 
> $tags
> nr_tags=1
> nr_reserved_tags=0
> active_queues=0
> 
> bitmap_tags:
> depth=1
> busy=0
> bits_per_word=64
> map_nr=1
> alloc_hint={0, 0, 0, 0, 0, 0, 0, 0}
> wake_batch=1
> wake_index=0
> ws={
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
> }
> round_robin=0
> 
> $tags_bitmap
> 00000000: 00
> 
> 
> 
> 
> Samsung-128GB-after
> =============sdc/hctx0==================
> $active
> 0
> 
> $busy
> 
> $/sys/kernel/debug/block/sdc//hctx0/cpu0
>     $completed
>     3 14
>     $dispatched
>     3 14
>     $merged
>     0
>     $rq_list
> 
> $/sys/kernel/debug/block/sdc//hctx0/cpu1
>     $completed
>     159 95
>     $dispatched
>     159 96
>     $merged
>     0
>     $rq_list
> 
> $/sys/kernel/debug/block/sdc//hctx0/cpu2
>     $completed
>     84 58
>     $dispatched
>     84 58
>     $merged
>     0
>     $rq_list
> 
> $/sys/kernel/debug/block/sdc//hctx0/cpu3
>     $completed
>     154 54
>     $dispatched
>     155 54
>     $merged
>     1
>     $rq_list
> 
> $ctx_map
> 00000000: 00
> 
> $dispatch
> 
> $dispatched
>        0    8
>        1    721
>        2    0
>        4    0
>        8    0
>       16    0
>       32+    0
> 
> $flags
> alloc_policy=FIFO SHOULD_MERGE|SG_MERGE
> 
> $io_poll
> considered=0
> invoked=0
> success=0
> 
> $queued
> 623
> 
> $run
> 887
> 
> $sched_tags
> nr_tags=2
> nr_reserved_tags=0
> active_queues=0
> 
> bitmap_tags:
> depth=2
> busy=2
> bits_per_word=64
> map_nr=1
> alloc_hint={0, 0, 0, 0, 0, 1, 1, 0}
> wake_batch=1
> wake_index=0
> ws={
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=active},
>     {.wait_cnt=1, .wait=active},
>     {.wait_cnt=1, .wait=active},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
> }
> round_robin=0
> 
> $sched_tags_bitmap
> 00000000: 03
> 
> $state
> 
> 
> $tags
> nr_tags=1
> nr_reserved_tags=0
> active_queues=0
> 
> bitmap_tags:
> depth=1
> busy=0
> bits_per_word=64
> map_nr=1
> alloc_hint={0, 0, 0, 0, 0, 0, 0, 0}
> wake_batch=1
> wake_index=0
> ws={
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
> }
> round_robin=0
> 
> $tags_bitmap
> 00000000: 00
> 
> 
> 
> 
> Generic-4GB-after
> =============sdc/hctx0==================
> $active
> 0
> 
> $busy
> 
> $/sys/kernel/debug/block/sdc//hctx0/cpu0
>     $completed
>     94 32
>     $dispatched
>     94 33
>     $merged
>     0
>     $rq_list
> 
> $/sys/kernel/debug/block/sdc//hctx0/cpu1
>     $completed
>     561 113
>     $dispatched
>     562 113
>     $merged
>     0
>     $rq_list
> 
> $/sys/kernel/debug/block/sdc//hctx0/cpu2
>     $completed
>     251 179
>     $dispatched
>     251 179
>     $merged
>     4
>     $rq_list
> 
> $/sys/kernel/debug/block/sdc//hctx0/cpu3
>     $completed
>     228 63
>     $dispatched
>     228 63
>     $merged
>     0
>     $rq_list
> 
> $ctx_map
> 00000000: 00
> 
> $dispatch
> 
> $dispatched
>        0    21
>        1    1707
>        2    0
>        4    0
>        8    0
>       16    0
>       32+    0
> 
> $flags
> alloc_policy=FIFO SHOULD_MERGE|SG_MERGE
> 
> $io_poll
> considered=0
> invoked=0
> success=0
> 
> $queued
> 1523
> 
> $run
> 2000
> 
> $sched_tags
> nr_tags=2
> nr_reserved_tags=0
> active_queues=0
> 
> bitmap_tags:
> depth=2
> busy=2
> bits_per_word=64
> map_nr=1
> alloc_hint={0, 0, 0, 0, 1, 1, 0, 0}
> wake_batch=1
> wake_index=0
> ws={
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=active},
>     {.wait_cnt=1, .wait=active},
>     {.wait_cnt=1, .wait=active},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},
>     {.wait_cnt=1, .wait=inactive},

Hi Ivan,

Thanks for your post and test!

Basically all IO hang happen inside get_request(), and seems this issue
isn't related with recent change in V4.15, could you run V4.14 to see if
there is such issue?

I guess it might be related with sbitmap_queue's wakeup because SCSI
always run queue after one request is completed, and there isn't any
request in hctx->dispatch, and for all requests in scheduler queue,
there is always chance to dispatch them from SCSI's restart(scsi_end_request).

Maybe need Jens/Omar to take a look.

Thanks,
Ming



[Index of Archives]     [Linux RAID]     [Linux SCSI]     [Linux ATA RAID]     [IDE]     [Linux Wireless]     [Linux Kernel]     [ATH6KL]     [Linux Bluetooth]     [Linux Netdev]     [Kernel Newbies]     [Security]     [Git]     [Netfilter]     [Bugtraq]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Device Mapper]

  Powered by Linux