On 03/28/2017 10:25 AM, Bart Van Assche wrote:
> On Tue, 2017-03-28 at 08:06 -0600, Jens Axboe wrote:
>> On Mon, Mar 27 2017, Bart Van Assche wrote:
>>> Hello Jens,
>>>
>>> If I leave the srp-test software running for a few minutes using the
>>> following command:
>>>
>>> # while ~bart/software/infiniband/srp-test/run_tests -d -r 30; do :; done
>>>
>>> then after some time the following complaint appears for multiple
>>> kworkers:
>>>
>>> INFO: task kworker/9:0:65 blocked for more than 480 seconds.
>>> Tainted: G I 4.11.0-rc4-dbg+ #5
>>> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
>>> kworker/9:0 D 0 65 2 0x00000000
>>> Workqueue: dio/dm-0 dio_aio_complete_work
>>> Call Trace:
>>> __schedule+0x3df/0xc10
>>> schedule+0x38/0x90
>>> rwsem_down_write_failed+0x2c4/0x4c0
>>> call_rwsem_down_write_failed+0x17/0x30
>>> down_write+0x5a/0x70
>>> __generic_file_fsync+0x43/0x90
>>> ext4_sync_file+0x2d0/0x550
>>> vfs_fsync_range+0x46/0xa0
>>> dio_complete+0x181/0x1b0
>>> dio_aio_complete_work+0x17/0x20
>>> process_one_work+0x208/0x6a0
>>> worker_thread+0x49/0x4a0
>>> kthread+0x107/0x140
>>> ret_from_fork+0x2e/0x40
>>>
>>> I had not yet observed this behavior with kernel v4.10 or older. If this
>>> happens and I check the queue state with the following script:
>>
>> Can you include the 'state' file in your script?
>>
>> Do you know when this started happening? You say it doesn't happen in
>> 4.10, but did it pass earlier in the 4.11-rc cycle?
>>
>> Does it reproduce with dm?
>>
>> I can't tell from your report if this is new in the 4.11 series,
>>
>>> The kernel tree I used in my tests is the result of merging the
>>> following commits:
>>> * commit 3dca2c2f3d3b from git://git.kernel.dk/linux-block.git
>>> ("Merge branch 'for-4.12/block' into for-next")
>>> * commit f88ab0c4b481 from
>>> git://git.kernel.org/pub/scm/linux/kernel/git/mkp/scsi.git
>>> ("scsi: libsas: fix ata xfer length")
>>> * commit ad0376eb1483 from
>>> git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
>>> ("Merge tag 'edac_for_4.11_2' of
>>> git://git.kernel.org/pub/scm/linux/kernel/git/bp/bp")
>>
>> Can we try and isolate it a bit - -rc4 alone, for instance?
>
> Hello Jens,
>
> Sorry but performing a bisect would be hard: without recent SCSI and block
> layer fixes this test triggers other failures before the lockup reported in
> this e-mail is triggered. See e.g.
> https://marc.info/?l=linux-scsi&m=148979716822799.
Yeah, I realize that. Not necessarily a huge problem. If I can reproduce
it here, then I can poke enough at it to find out wtf is going on here.
> I do not know whether it would be possible to modify the test such that only
> the dm driver is involved but no SCSI code.
How about the other way around? Just SCSI, but no dm?
> When I reran the test this morning the hang was triggered by the 02-sq-on-mq
> test. This means that dm was used in blk-sq mode and that blk-mq was used for
> the ib_srp SCSI device instances.
>
> Please find below the updated script and its output.
Thanks for running it again, but it's the wrong state file. I should have
been more clear. The one I'm interested in is in the mq/<num>/ directories,
like the 'tags' etc files.
>
> ---
>
> #!/bin/bash
>
> show_state() {
> local a dev=$1
>
> for a in device/state queue/scheduler; do
> [ -e "$dev/$a" ] && grep -aH '' "$dev/$a"
> done
> }
>
> cd /sys/class/block || exit $?
> for dev in *; do
> if [ -e "$dev/mq" ]; then
> echo "$dev"
> pending=0
> for f in "$dev"/mq/*/{pending,*/rq_list}; do
> [ -e "$f" ] || continue
> if { read -r line1 && read -r line2; } <"$f"; then
> echo "$f"
> echo "$line1 $line2" >/dev/null
> head -n 9 "$f"
> ((pending++))
> fi
> done
> (
> busy=0
> cd /sys/kernel/debug/block >&/dev/null &&
> for d in "$dev"/mq/*; do
> [ ! -d "$d" ] && continue
> grep -q '^busy=0$' "$d/tags" && continue
> ((busy++))
> for f in "$d"/{dispatch,tags*,cpu*/rq_list}; do
Ala:
for f in "$d"/{dispatch,state,tags*,cpu*/rq_list}; do
Also, can you include the involved dm devices as well for this state
dump?
--
Jens Axboe
