Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Ming Lei]

Cc raid and dm list.

On Thu, May 16, 2024 at 06:24:18PM +0800, Changhui Zhong wrote:
> Hello,
> 
> when create lvm raid1, the command hang on for a long time.
> please help check it and let me know if you need any info/testing for
> it, thanks.
> 
> repo:https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git
> branch:for-next
> commit: 59ef8180748269837975c9656b586daa16bb9def
> 
> reproducer:
> dd if=/dev/zero bs=1M count=2000 of=file0.img
> dd if=/dev/zero bs=1M count=2000 of=file1.img
> dd if=/dev/zero bs=1M count=2000 of=file2.img
> dd if=/dev/zero bs=1M count=2000 of=file4.img
> losetup -fP --show file0.img
> losetup -fP --show file1.img
> losetup -fP --show file2.img
> losetup -fP --show file3.img
> pvcreate -y  /dev/loop0 /dev/loop1 /dev/loop2 /dev/loop3
> vgcreate  black_bird  /dev/loop0 /dev/loop1 /dev/loop2 /dev/loop3
> lvcreate --type raid1 -m 3 -n non_synced_primary_raid_3legs_1   -L 1G
> black_bird        /dev/loop0:0-300     /dev/loop1:0-300
> /dev/loop2:0-300  /dev/loop3:0-300
> 
> 
> console log:
> May 21 21:57:41 dell-per640-04 journal: Create raid1
> May 21 21:57:41 dell-per640-04 kernel: device-mapper: raid:
> Superblocks created for new raid set
> May 21 21:57:42 dell-per640-04 kernel: md/raid1:mdX: not clean --
> starting background reconstruction
> May 21 21:57:42 dell-per640-04 kernel: md/raid1:mdX: active with 4 out
> of 4 mirrors
> May 21 21:57:42 dell-per640-04 kernel: mdX: bitmap file is out of
> date, doing full recovery
> May 21 21:57:42 dell-per640-04 kernel: md: resync of RAID array mdX
> May 21 21:57:42 dell-per640-04 systemd[1]: Started Device-mapper event daemon.
> May 21 21:57:42 dell-per640-04 dmeventd[42170]: dmeventd ready for processing.
> May 21 21:57:42 dell-per640-04 dmeventd[42170]: Monitoring RAID device
> black_bird-non_synced_primary_raid_3legs_1 for events.
> May 21 21:57:45 dell-per640-04 restraintd[1446]: *** Current Time: Tue
> May 21 21:57:45 2024  Localwatchdog at: Tue May 21 22:56:45 2024
> May 21 21:58:45 dell-per640-04 restraintd[1446]: *** Current Time: Tue
> May 21 21:58:45 2024  Localwatchdog at: Tue May 21 22:56:45 2024
> May 21 21:59:45 dell-per640-04 restraintd[1446]: *** Current Time: Tue
> May 21 21:59:45 2024  Localwatchdog at: Tue May 21 22:56:45 2024
> May 21 21:59:53 dell-per640-04 kernel: INFO: task mdX_resync:42168
> blocked for more than 122 seconds.
> May 21 21:59:53 dell-per640-04 kernel:      Not tainted 6.9.0+ #1
> May 21 21:59:53 dell-per640-04 kernel: "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> May 21 21:59:53 dell-per640-04 kernel: task:mdX_resync      state:D
> stack:0     pid:42168 tgid:42168 ppid:2      flags:0x00004000
> May 21 21:59:53 dell-per640-04 kernel: Call Trace:
> May 21 21:59:53 dell-per640-04 kernel: <TASK>
> May 21 21:59:53 dell-per640-04 kernel: __schedule+0x222/0x670
> May 21 21:59:53 dell-per640-04 kernel: ? blk_mq_flush_plug_list+0x5/0x20
> May 21 21:59:53 dell-per640-04 kernel: schedule+0x2c/0xb0
> May 21 21:59:53 dell-per640-04 kernel: raise_barrier+0x107/0x200 [raid1]
> May 21 21:59:53 dell-per640-04 kernel: ?
> __pfx_autoremove_wake_function+0x10/0x10
> May 21 21:59:53 dell-per640-04 kernel: raid1_sync_request+0x12d/0xa50 [raid1]
> May 21 21:59:53 dell-per640-04 kernel: ?
> __pfx_raid1_sync_request+0x10/0x10 [raid1]
> May 21 21:59:53 dell-per640-04 kernel: md_do_sync+0x660/0x1040
> May 21 21:59:53 dell-per640-04 kernel: ?
> __pfx_autoremove_wake_function+0x10/0x10
> May 21 21:59:53 dell-per640-04 kernel: md_thread+0xad/0x160
> May 21 21:59:53 dell-per640-04 kernel: ? __pfx_md_thread+0x10/0x10
> May 21 21:59:53 dell-per640-04 kernel: kthread+0xdc/0x110
> May 21 21:59:53 dell-per640-04 kernel: ? __pfx_kthread+0x10/0x10
> May 21 21:59:53 dell-per640-04 kernel: ret_from_fork+0x2d/0x50
> May 21 21:59:53 dell-per640-04 kernel: ? __pfx_kthread+0x10/0x10
> May 21 21:59:53 dell-per640-04 kernel: ret_from_fork_asm+0x1a/0x30
> May 21 21:59:53 dell-per640-04 kernel: </TASK>
> 
> 
> --
> Best Regards,
>      Changhui
> 

-- 
Ming

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Yu Kuai]

Hi,

在 2024/05/16 19:21, Ming Lei 写道:
> Cc raid and dm list.
> 
> On Thu, May 16, 2024 at 06:24:18PM +0800, Changhui Zhong wrote:
>> Hello,
>>
>> when create lvm raid1, the command hang on for a long time.
>> please help check it and let me know if you need any info/testing for
>> it, thanks.

Is this a new test, or a new problem?
>>
>> repo:https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git
>> branch:for-next
>> commit: 59ef8180748269837975c9656b586daa16bb9def
>>
>> reproducer:
>> dd if=/dev/zero bs=1M count=2000 of=file0.img
>> dd if=/dev/zero bs=1M count=2000 of=file1.img
>> dd if=/dev/zero bs=1M count=2000 of=file2.img
>> dd if=/dev/zero bs=1M count=2000 of=file4.img
>> losetup -fP --show file0.img
>> losetup -fP --show file1.img
>> losetup -fP --show file2.img
>> losetup -fP --show file3.img

above dd creat file4, here is file3.

>> pvcreate -y  /dev/loop0 /dev/loop1 /dev/loop2 /dev/loop3
>> vgcreate  black_bird  /dev/loop0 /dev/loop1 /dev/loop2 /dev/loop3
>> lvcreate --type raid1 -m 3 -n non_synced_primary_raid_3legs_1   -L 1G
>> black_bird        /dev/loop0:0-300     /dev/loop1:0-300
>> /dev/loop2:0-300  /dev/loop3:0-300

I don't understand what /dev/loopx:0-300 means, and I remove them, fix
the above file4 typo, test on a xfs filesystem, and I can't reporduce
the problem.

>>
>>
>> console log:
>> May 21 21:57:41 dell-per640-04 journal: Create raid1
>> May 21 21:57:41 dell-per640-04 kernel: device-mapper: raid:
>> Superblocks created for new raid set
>> May 21 21:57:42 dell-per640-04 kernel: md/raid1:mdX: not clean --
>> starting background reconstruction
>> May 21 21:57:42 dell-per640-04 kernel: md/raid1:mdX: active with 4 out
>> of 4 mirrors
>> May 21 21:57:42 dell-per640-04 kernel: mdX: bitmap file is out of
>> date, doing full recovery
>> May 21 21:57:42 dell-per640-04 kernel: md: resync of RAID array mdX
>> May 21 21:57:42 dell-per640-04 systemd[1]: Started Device-mapper event daemon.
>> May 21 21:57:42 dell-per640-04 dmeventd[42170]: dmeventd ready for processing.
>> May 21 21:57:42 dell-per640-04 dmeventd[42170]: Monitoring RAID device
>> black_bird-non_synced_primary_raid_3legs_1 for events.
>> May 21 21:57:45 dell-per640-04 restraintd[1446]: *** Current Time: Tue
>> May 21 21:57:45 2024  Localwatchdog at: Tue May 21 22:56:45 2024
>> May 21 21:58:45 dell-per640-04 restraintd[1446]: *** Current Time: Tue
>> May 21 21:58:45 2024  Localwatchdog at: Tue May 21 22:56:45 2024
>> May 21 21:59:45 dell-per640-04 restraintd[1446]: *** Current Time: Tue
>> May 21 21:59:45 2024  Localwatchdog at: Tue May 21 22:56:45 2024
>> May 21 21:59:53 dell-per640-04 kernel: INFO: task mdX_resync:42168
>> blocked for more than 122 seconds.
>> May 21 21:59:53 dell-per640-04 kernel:      Not tainted 6.9.0+ #1
>> May 21 21:59:53 dell-per640-04 kernel: "echo 0 >
>> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
>> May 21 21:59:53 dell-per640-04 kernel: task:mdX_resync      state:D
>> stack:0     pid:42168 tgid:42168 ppid:2      flags:0x00004000
>> May 21 21:59:53 dell-per640-04 kernel: Call Trace:
>> May 21 21:59:53 dell-per640-04 kernel: <TASK>
>> May 21 21:59:53 dell-per640-04 kernel: __schedule+0x222/0x670
>> May 21 21:59:53 dell-per640-04 kernel: ? blk_mq_flush_plug_list+0x5/0x20
>> May 21 21:59:53 dell-per640-04 kernel: schedule+0x2c/0xb0
>> May 21 21:59:53 dell-per640-04 kernel: raise_barrier+0x107/0x200 [raid1]

Unless this is a deadlock, raise_barrier() should be waiting for normal
IO that is issued to underlying disk to return. If you can reporduce the
problem, can you check IO from underlying loop disks?

cat /sys/block/loopx/inflight

Thanks,
Kuai

>> May 21 21:59:53 dell-per640-04 kernel: ?
>> __pfx_autoremove_wake_function+0x10/0x10
>> May 21 21:59:53 dell-per640-04 kernel: raid1_sync_request+0x12d/0xa50 [raid1]
>> May 21 21:59:53 dell-per640-04 kernel: ?
>> __pfx_raid1_sync_request+0x10/0x10 [raid1]
>> May 21 21:59:53 dell-per640-04 kernel: md_do_sync+0x660/0x1040
>> May 21 21:59:53 dell-per640-04 kernel: ?
>> __pfx_autoremove_wake_function+0x10/0x10
>> May 21 21:59:53 dell-per640-04 kernel: md_thread+0xad/0x160
>> May 21 21:59:53 dell-per640-04 kernel: ? __pfx_md_thread+0x10/0x10
>> May 21 21:59:53 dell-per640-04 kernel: kthread+0xdc/0x110
>> May 21 21:59:53 dell-per640-04 kernel: ? __pfx_kthread+0x10/0x10
>> May 21 21:59:53 dell-per640-04 kernel: ret_from_fork+0x2d/0x50
>> May 21 21:59:53 dell-per640-04 kernel: ? __pfx_kthread+0x10/0x10
>> May 21 21:59:53 dell-per640-04 kernel: ret_from_fork_asm+0x1a/0x30
>> May 21 21:59:53 dell-per640-04 kernel: </TASK>
>>
>>
>> --
>> Best Regards,
>>       Changhui
>>
> 

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Changhui Zhong]

On Thu, May 16, 2024 at 7:42 PM Yu Kuai <yukuai1@huaweicloud.com> wrote:
>
> Hi,
>
> 在 2024/05/16 19:21, Ming Lei 写道:
> > Cc raid and dm list.
> >
> > On Thu, May 16, 2024 at 06:24:18PM +0800, Changhui Zhong wrote:
> >> Hello,
> >>
> >> when create lvm raid1, the command hang on for a long time.
> >> please help check it and let me know if you need any info/testing for
> >> it, thanks.
>
> Is this a new test, or a new problem?

it is a new problem, I am not hit this issue on 6.9.0-rc4+

> >>
> >> repo:https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git
> >> branch:for-next
> >> commit: 59ef8180748269837975c9656b586daa16bb9def
> >>
> >> reproducer:
> >> dd if=/dev/zero bs=1M count=2000 of=file0.img
> >> dd if=/dev/zero bs=1M count=2000 of=file1.img
> >> dd if=/dev/zero bs=1M count=2000 of=file2.img
> >> dd if=/dev/zero bs=1M count=2000 of=file4.img
> >> losetup -fP --show file0.img
> >> losetup -fP --show file1.img
> >> losetup -fP --show file2.img
> >> losetup -fP --show file3.img
>
> above dd creat file4, here is file3.

yeah，this is my spelling mistake, I created 4 files, file0/1/2/3

>
> >> pvcreate -y  /dev/loop0 /dev/loop1 /dev/loop2 /dev/loop3
> >> vgcreate  black_bird  /dev/loop0 /dev/loop1 /dev/loop2 /dev/loop3
> >> lvcreate --type raid1 -m 3 -n non_synced_primary_raid_3legs_1   -L 1G
> >> black_bird        /dev/loop0:0-300     /dev/loop1:0-300
> >> /dev/loop2:0-300  /dev/loop3:0-300
>
> I don't understand what /dev/loopx:0-300 means, and I remove them, fix
> the above file4 typo, test on a xfs filesystem, and I can't reporduce
> the problem.
>

I want to specify the space from disk blocks 0 to 300 of the loop
device to create raid1，not all space of loop device，
follow reproducer setps I can reproduced it 100%

> >>
> >>
> >> console log:
> >> May 21 21:57:41 dell-per640-04 journal: Create raid1
> >> May 21 21:57:41 dell-per640-04 kernel: device-mapper: raid:
> >> Superblocks created for new raid set
> >> May 21 21:57:42 dell-per640-04 kernel: md/raid1:mdX: not clean --
> >> starting background reconstruction
> >> May 21 21:57:42 dell-per640-04 kernel: md/raid1:mdX: active with 4 out
> >> of 4 mirrors
> >> May 21 21:57:42 dell-per640-04 kernel: mdX: bitmap file is out of
> >> date, doing full recovery
> >> May 21 21:57:42 dell-per640-04 kernel: md: resync of RAID array mdX
> >> May 21 21:57:42 dell-per640-04 systemd[1]: Started Device-mapper event daemon.
> >> May 21 21:57:42 dell-per640-04 dmeventd[42170]: dmeventd ready for processing.
> >> May 21 21:57:42 dell-per640-04 dmeventd[42170]: Monitoring RAID device
> >> black_bird-non_synced_primary_raid_3legs_1 for events.
> >> May 21 21:57:45 dell-per640-04 restraintd[1446]: *** Current Time: Tue
> >> May 21 21:57:45 2024  Localwatchdog at: Tue May 21 22:56:45 2024
> >> May 21 21:58:45 dell-per640-04 restraintd[1446]: *** Current Time: Tue
> >> May 21 21:58:45 2024  Localwatchdog at: Tue May 21 22:56:45 2024
> >> May 21 21:59:45 dell-per640-04 restraintd[1446]: *** Current Time: Tue
> >> May 21 21:59:45 2024  Localwatchdog at: Tue May 21 22:56:45 2024
> >> May 21 21:59:53 dell-per640-04 kernel: INFO: task mdX_resync:42168
> >> blocked for more than 122 seconds.
> >> May 21 21:59:53 dell-per640-04 kernel:      Not tainted 6.9.0+ #1
> >> May 21 21:59:53 dell-per640-04 kernel: "echo 0 >
> >> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> >> May 21 21:59:53 dell-per640-04 kernel: task:mdX_resync      state:D
> >> stack:0     pid:42168 tgid:42168 ppid:2      flags:0x00004000
> >> May 21 21:59:53 dell-per640-04 kernel: Call Trace:
> >> May 21 21:59:53 dell-per640-04 kernel: <TASK>
> >> May 21 21:59:53 dell-per640-04 kernel: __schedule+0x222/0x670
> >> May 21 21:59:53 dell-per640-04 kernel: ? blk_mq_flush_plug_list+0x5/0x20
> >> May 21 21:59:53 dell-per640-04 kernel: schedule+0x2c/0xb0
> >> May 21 21:59:53 dell-per640-04 kernel: raise_barrier+0x107/0x200 [raid1]
>
> Unless this is a deadlock, raise_barrier() should be waiting for normal
> IO that is issued to underlying disk to return. If you can reporduce the
> problem, can you check IO from underlying loop disks?
>
> cat /sys/block/loopx/inflight

when this issue was triggered, the log I collected：

[root@storageqe-103 ~]# cat /sys/block/loop0/inflight
       0        0
[root@storageqe-103 ~]# cat /sys/block/loop1/inflight
       0        0
[root@storageqe-103 ~]# cat /sys/block/loop2/inflight
       0        0
[root@storageqe-103 ~]# cat /sys/block/loop3/inflight
       0        0
[root@storageqe-103 ~]#


and the command "lvs" hang on also，

[root@storageqe-103 ~]# lvs
^C  Interrupted...
  Giving up waiting for lock.
  Can't get lock for black_bird.
  Cannot process volume group black_bird
  LV   VG                 Attr       LSize    Pool Origin Data%  Meta%
 Move Log Cpy%Sync Convert
  home rhel_storageqe-103 -wi-ao---- <368.43g
  root rhel_storageqe-103 -wi-ao----   70.00g
  swap rhel_storageqe-103 -wi-ao----    7.70g
[root@storageqe-103 ~]#

[ 1352.761630] INFO: task mdX_resync:1547 blocked for more than 1105 seconds.
[ 1352.769336]       Not tainted 6.9.0+ #1
[ 1352.773629] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 1352.782372] task:mdX_resync      state:D stack:0     pid:1547
tgid:1547  ppid:2      flags:0x00004000
[ 1352.782380] Call Trace:
[ 1352.782382]  <TASK>
[ 1352.782386]  __schedule+0x222/0x670
[ 1352.782396]  schedule+0x2c/0xb0
[ 1352.782402]  raise_barrier+0x107/0x200 [raid1]
[ 1352.782415]  ? __pfx_autoremove_wake_function+0x10/0x10
[ 1352.782423]  raid1_sync_request+0x12d/0xa50 [raid1]
[ 1352.782435]  ? prepare_to_wait_event+0x5f/0x190
[ 1352.782442]  md_do_sync+0x660/0x1040
[ 1352.782449]  ? __pfx_autoremove_wake_function+0x10/0x10
[ 1352.782457]  md_thread+0xad/0x160
[ 1352.782462]  ? __pfx_md_thread+0x10/0x10
[ 1352.782465]  kthread+0xdc/0x110
[ 1352.782470]  ? __pfx_kthread+0x10/0x10
[ 1352.782474]  ret_from_fork+0x2d/0x50
[ 1352.782481]  ? __pfx_kthread+0x10/0x10
[ 1352.782485]  ret_from_fork_asm+0x1a/0x30
[ 1352.782491]  </TASK>

Thanks，
Changhui

>
> Thanks,
> Kuai
>
> >> May 21 21:59:53 dell-per640-04 kernel: ?
> >> __pfx_autoremove_wake_function+0x10/0x10
> >> May 21 21:59:53 dell-per640-04 kernel: raid1_sync_request+0x12d/0xa50 [raid1]
> >> May 21 21:59:53 dell-per640-04 kernel: ?
> >> __pfx_raid1_sync_request+0x10/0x10 [raid1]
> >> May 21 21:59:53 dell-per640-04 kernel: md_do_sync+0x660/0x1040
> >> May 21 21:59:53 dell-per640-04 kernel: ?
> >> __pfx_autoremove_wake_function+0x10/0x10
> >> May 21 21:59:53 dell-per640-04 kernel: md_thread+0xad/0x160
> >> May 21 21:59:53 dell-per640-04 kernel: ? __pfx_md_thread+0x10/0x10
> >> May 21 21:59:53 dell-per640-04 kernel: kthread+0xdc/0x110
> >> May 21 21:59:53 dell-per640-04 kernel: ? __pfx_kthread+0x10/0x10
> >> May 21 21:59:53 dell-per640-04 kernel: ret_from_fork+0x2d/0x50
> >> May 21 21:59:53 dell-per640-04 kernel: ? __pfx_kthread+0x10/0x10
> >> May 21 21:59:53 dell-per640-04 kernel: ret_from_fork_asm+0x1a/0x30
> >> May 21 21:59:53 dell-per640-04 kernel: </TASK>
> >>
> >>
> >> --
> >> Best Regards,
> >>       Changhui
> >>
> >
>
>

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Yu Kuai]

Hi,

在 2024/05/17 10:25, Changhui Zhong 写道:
> On Thu, May 16, 2024 at 7:42 PM Yu Kuai <yukuai1@huaweicloud.com> wrote:
>>
>> Hi,
>>
>> 在 2024/05/16 19:21, Ming Lei 写道:
>>> Cc raid and dm list.
>>>
>>> On Thu, May 16, 2024 at 06:24:18PM +0800, Changhui Zhong wrote:
>>>> Hello,
>>>>
>>>> when create lvm raid1, the command hang on for a long time.
>>>> please help check it and let me know if you need any info/testing for
>>>> it, thanks.
>>
>> Is this a new test, or a new problem?
> 
> it is a new problem, I am not hit this issue on 6.9.0-rc4+

There is just one patch for raid1 applied since v6.9-rc4, and I think
it's not related. Perhaps can you try to bisect?

> 
>>>>
>>>> repo:https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git
>>>> branch:for-next
>>>> commit: 59ef8180748269837975c9656b586daa16bb9def
>>>>
>>>> reproducer:
>>>> dd if=/dev/zero bs=1M count=2000 of=file0.img
>>>> dd if=/dev/zero bs=1M count=2000 of=file1.img
>>>> dd if=/dev/zero bs=1M count=2000 of=file2.img
>>>> dd if=/dev/zero bs=1M count=2000 of=file4.img
>>>> losetup -fP --show file0.img
>>>> losetup -fP --show file1.img
>>>> losetup -fP --show file2.img
>>>> losetup -fP --show file3.img
>>
>> above dd creat file4, here is file3.
> 
> yeah，this is my spelling mistake, I created 4 files, file0/1/2/3
> 
>>
>>>> pvcreate -y  /dev/loop0 /dev/loop1 /dev/loop2 /dev/loop3
>>>> vgcreate  black_bird  /dev/loop0 /dev/loop1 /dev/loop2 /dev/loop3
>>>> lvcreate --type raid1 -m 3 -n non_synced_primary_raid_3legs_1   -L 1G
>>>> black_bird        /dev/loop0:0-300     /dev/loop1:0-300
>>>> /dev/loop2:0-300  /dev/loop3:0-300
>>
>> I don't understand what /dev/loopx:0-300 means, and I remove them, fix
>> the above file4 typo, test on a xfs filesystem, and I can't reporduce
>> the problem.
>>
> 
> I want to specify the space from disk blocks 0 to 300 of the loop
> device to create raid1，not all space of loop device，
> follow reproducer setps I can reproduced it 100%

Okay, I add the 0-300 and I still can't reporduce it, have no clue yet.
> 
>>>>
>>>>
>>>> console log:
>>>> May 21 21:57:41 dell-per640-04 journal: Create raid1
>>>> May 21 21:57:41 dell-per640-04 kernel: device-mapper: raid:
>>>> Superblocks created for new raid set
>>>> May 21 21:57:42 dell-per640-04 kernel: md/raid1:mdX: not clean --
>>>> starting background reconstruction
>>>> May 21 21:57:42 dell-per640-04 kernel: md/raid1:mdX: active with 4 out
>>>> of 4 mirrors
>>>> May 21 21:57:42 dell-per640-04 kernel: mdX: bitmap file is out of
>>>> date, doing full recovery
>>>> May 21 21:57:42 dell-per640-04 kernel: md: resync of RAID array mdX
>>>> May 21 21:57:42 dell-per640-04 systemd[1]: Started Device-mapper event daemon.
>>>> May 21 21:57:42 dell-per640-04 dmeventd[42170]: dmeventd ready for processing.
>>>> May 21 21:57:42 dell-per640-04 dmeventd[42170]: Monitoring RAID device
>>>> black_bird-non_synced_primary_raid_3legs_1 for events.
>>>> May 21 21:57:45 dell-per640-04 restraintd[1446]: *** Current Time: Tue
>>>> May 21 21:57:45 2024  Localwatchdog at: Tue May 21 22:56:45 2024
>>>> May 21 21:58:45 dell-per640-04 restraintd[1446]: *** Current Time: Tue
>>>> May 21 21:58:45 2024  Localwatchdog at: Tue May 21 22:56:45 2024
>>>> May 21 21:59:45 dell-per640-04 restraintd[1446]: *** Current Time: Tue
>>>> May 21 21:59:45 2024  Localwatchdog at: Tue May 21 22:56:45 2024
>>>> May 21 21:59:53 dell-per640-04 kernel: INFO: task mdX_resync:42168
>>>> blocked for more than 122 seconds.
>>>> May 21 21:59:53 dell-per640-04 kernel:      Not tainted 6.9.0+ #1
>>>> May 21 21:59:53 dell-per640-04 kernel: "echo 0 >
>>>> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
>>>> May 21 21:59:53 dell-per640-04 kernel: task:mdX_resync      state:D
>>>> stack:0     pid:42168 tgid:42168 ppid:2      flags:0x00004000
>>>> May 21 21:59:53 dell-per640-04 kernel: Call Trace:
>>>> May 21 21:59:53 dell-per640-04 kernel: <TASK>
>>>> May 21 21:59:53 dell-per640-04 kernel: __schedule+0x222/0x670
>>>> May 21 21:59:53 dell-per640-04 kernel: ? blk_mq_flush_plug_list+0x5/0x20
>>>> May 21 21:59:53 dell-per640-04 kernel: schedule+0x2c/0xb0
>>>> May 21 21:59:53 dell-per640-04 kernel: raise_barrier+0x107/0x200 [raid1]
>>
>> Unless this is a deadlock, raise_barrier() should be waiting for normal
>> IO that is issued to underlying disk to return. If you can reporduce the
>> problem, can you check IO from underlying loop disks?
>>
>> cat /sys/block/loopx/inflight
> 
> when this issue was triggered, the log I collected：
> 
> [root@storageqe-103 ~]# cat /sys/block/loop0/inflight
>         0        0
> [root@storageqe-103 ~]# cat /sys/block/loop1/inflight
>         0        0
> [root@storageqe-103 ~]# cat /sys/block/loop2/inflight
>         0        0
> [root@storageqe-103 ~]# cat /sys/block/loop3/inflight
>         0        0
> [root@storageqe-103 ~]#

Thanks for the test, this do look like a deadlock, beside
raise_barrier(), is there any other victim? I can't reporduce this,
and I have no clue yet. The possible next step might be bisect to
locate the blame commit first. Maybe related to dm-raid1.

Thanks,
Kuai

> 
> 
> and the command "lvs" hang on also，
> 
> [root@storageqe-103 ~]# lvs
> ^C  Interrupted...
>    Giving up waiting for lock.
>    Can't get lock for black_bird.
>    Cannot process volume group black_bird
>    LV   VG                 Attr       LSize    Pool Origin Data%  Meta%
>   Move Log Cpy%Sync Convert
>    home rhel_storageqe-103 -wi-ao---- <368.43g
>    root rhel_storageqe-103 -wi-ao----   70.00g
>    swap rhel_storageqe-103 -wi-ao----    7.70g
> [root@storageqe-103 ~]#
> 
> [ 1352.761630] INFO: task mdX_resync:1547 blocked for more than 1105 seconds.
> [ 1352.769336]       Not tainted 6.9.0+ #1
> [ 1352.773629] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [ 1352.782372] task:mdX_resync      state:D stack:0     pid:1547
> tgid:1547  ppid:2      flags:0x00004000
> [ 1352.782380] Call Trace:
> [ 1352.782382]  <TASK>
> [ 1352.782386]  __schedule+0x222/0x670
> [ 1352.782396]  schedule+0x2c/0xb0
> [ 1352.782402]  raise_barrier+0x107/0x200 [raid1]
> [ 1352.782415]  ? __pfx_autoremove_wake_function+0x10/0x10
> [ 1352.782423]  raid1_sync_request+0x12d/0xa50 [raid1]
> [ 1352.782435]  ? prepare_to_wait_event+0x5f/0x190
> [ 1352.782442]  md_do_sync+0x660/0x1040
> [ 1352.782449]  ? __pfx_autoremove_wake_function+0x10/0x10
> [ 1352.782457]  md_thread+0xad/0x160
> [ 1352.782462]  ? __pfx_md_thread+0x10/0x10
> [ 1352.782465]  kthread+0xdc/0x110
> [ 1352.782470]  ? __pfx_kthread+0x10/0x10
> [ 1352.782474]  ret_from_fork+0x2d/0x50
> [ 1352.782481]  ? __pfx_kthread+0x10/0x10
> [ 1352.782485]  ret_from_fork_asm+0x1a/0x30
> [ 1352.782491]  </TASK>
> 
> Thanks，
> Changhui
> 
>>
>> Thanks,
>> Kuai
>>
>>>> May 21 21:59:53 dell-per640-04 kernel: ?
>>>> __pfx_autoremove_wake_function+0x10/0x10
>>>> May 21 21:59:53 dell-per640-04 kernel: raid1_sync_request+0x12d/0xa50 [raid1]
>>>> May 21 21:59:53 dell-per640-04 kernel: ?
>>>> __pfx_raid1_sync_request+0x10/0x10 [raid1]
>>>> May 21 21:59:53 dell-per640-04 kernel: md_do_sync+0x660/0x1040
>>>> May 21 21:59:53 dell-per640-04 kernel: ?
>>>> __pfx_autoremove_wake_function+0x10/0x10
>>>> May 21 21:59:53 dell-per640-04 kernel: md_thread+0xad/0x160
>>>> May 21 21:59:53 dell-per640-04 kernel: ? __pfx_md_thread+0x10/0x10
>>>> May 21 21:59:53 dell-per640-04 kernel: kthread+0xdc/0x110
>>>> May 21 21:59:53 dell-per640-04 kernel: ? __pfx_kthread+0x10/0x10
>>>> May 21 21:59:53 dell-per640-04 kernel: ret_from_fork+0x2d/0x50
>>>> May 21 21:59:53 dell-per640-04 kernel: ? __pfx_kthread+0x10/0x10
>>>> May 21 21:59:53 dell-per640-04 kernel: ret_from_fork_asm+0x1a/0x30
>>>> May 21 21:59:53 dell-per640-04 kernel: </TASK>
>>>>
>>>>
>>>> --
>>>> Best Regards,
>>>>        Changhui
>>>>
>>>
>>
>>
> 
> .
> 

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Changhui Zhong]

On Fri, May 17, 2024 at 10:49 AM Yu Kuai <yukuai1@huaweicloud.com> wrote:
>
>
> Thanks for the test, this do look like a deadlock, beside
> raise_barrier(), is there any other victim? I can't reporduce this,
> and I have no clue yet. The possible next step might be bisect to
> locate the blame commit first. Maybe related to dm-raid1.
>
> Thanks,
> Kuai
>

Hi，Yu Kuai

I tried to do git bisect and got the following result, please help check，

[czhong@vm linux-block]$ git bisect start
[czhong@vm linux-block]$ git bisect bad
[czhong@vm linux-block]$ git bisect good
d0487577e6e0b640d71375a6ec2f9e8a2d3555f2
Bisecting: 2652 revisions left to test after this (roughly 11 steps)
[895621f1c81695da7660fe909173e9f98619e89c] bnxt_en: Don't support
offline self test when RoCE driver is loaded
[czhong@vm linux-block]$
[czhong@vm linux-block]$ git bisect good
Bisecting: 1219 revisions left to test after this (roughly 10 steps)
[6c60000f0b9ae7da630a5715a9ba33042d87e7fd] Merge tag 'soc-dt-6.10' of
git://git.kernel.org/pub/scm/linux/kernel/git/soc/soc
[czhong@vm linux-block]$
[czhong@vm linux-block]$ git bisect good
Bisecting: 612 revisions left to test after this (roughly 9 steps)
[87caef42200cd44f8b808ec2f8ac2257f3e0a8c1] Merge tag
'hardening-6.10-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/kees/linux
[czhong@vm linux-block]$
[czhong@vm linux-block]$ git bisect bad
Bisecting: 303 revisions left to test after this (roughly 8 steps)
[25c73642cc5baea5b91bbb9b1f5fcd93672bfa08] Merge tag
'keys-next-6.10-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/jarkko/linux-tpmdd
[czhong@vm linux-block]$ git bisect good
Bisecting: 155 revisions left to test after this (roughly 7 steps)
[f4e8d80292859809ea135e9f4c43bae47e4f58bc] Merge tag 'vfs-6.10.rw' of
git://git.kernel.org/pub/scm/linux/kernel/git/vfs/vfs
[czhong@vm linux-block]$
[czhong@vm linux-block]$ git bisect good
Bisecting: 77 revisions left to test after this (roughly 6 steps)
[ac5f71a3d9d7eb540f6bf7e794eb4a3e4c3f11dd] io_uring/net: add provided
buffer support for IORING_OP_SEND
[czhong@vm linux-block]$ git bisect good
Bisecting: 37 revisions left to test after this (roughly 5 steps)
[0c9f4ac808b017a0013cee92a30de980550145d5] Merge tag
'for-6.10/block-20240511' of git://git.kernel.dk/linux
[czhong@vm linux-block]$ git bisect bad
Bisecting: 19 revisions left to test after this (roughly 4 steps)
[a3166c51702bb00b8f8b84022090cbab8f37be1a] blk-throttle: delay
initialization until configuration
[czhong@vm linux-block]$
[czhong@vm linux-block]$ git bisect bad
Bisecting: 9 revisions left to test after this (roughly 3 steps)
[e8b4869bc78da1a71f2a2ab476caf50c1dcfeed0] block: add a
blk_alloc_discard_bio helper
[czhong@vm linux-block]$ git bisect good
Bisecting: 4 revisions left to test after this (roughly 2 steps)
[3a861560ccb35f2a4f0a4b8207fa7c2a35fc7f31] bcache: fix variable length
array abuse in btree_iter
[czhong@vm linux-block]$ git bisect good
Bisecting: 2 revisions left to test after this (roughly 1 step)
[99dc422335d8b2bd4d105797241d3e715bae90e9] block: support to account
io_ticks precisely
[czhong@vm linux-block]$
[czhong@vm linux-block]$ git bisect bad
Bisecting: 0 revisions left to test after this (roughly 0 steps)
[060406c61c7cb4bbd82a02d179decca9c9bb3443] block: add plug while submitting IO
[czhong@vm linux-block]$ git bisect bad
060406c61c7cb4bbd82a02d179decca9c9bb3443 is the first bad commit
commit 060406c61c7cb4bbd82a02d179decca9c9bb3443
Author: Yu Kuai <yukuai3@huawei.com>
Date:   Thu May 9 20:38:25 2024 +0800

    block: add plug while submitting IO

    So that if caller didn't use plug, for example, __blkdev_direct_IO_simple()
    and __blkdev_direct_IO_async(), block layer can still benefit from caching
    nsec time in the plug.

    Signed-off-by: Yu Kuai <yukuai3@huawei.com>
    Link: https://lore.kernel.org/r/20240509123825.3225207-1-yukuai1@huaweicloud.com
    Signed-off-by: Jens Axboe <axboe@kernel.dk>

 block/blk-core.c | 6 ++++++
 1 file changed, 6 insertions(+)
[czhong@vm linux-block]$

Thanks，
Changhui

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Changhui Zhong]

On Sun, May 19, 2024 at 2:44 PM Changhui Zhong <czhong@redhat.com> wrote:
>
> On Fri, May 17, 2024 at 10:49 AM Yu Kuai <yukuai1@huaweicloud.com> wrote:
> >
> >
> > Thanks for the test, this do look like a deadlock, beside
> > raise_barrier(), is there any other victim? I can't reporduce this,
> > and I have no clue yet. The possible next step might be bisect to
> > locate the blame commit first. Maybe related to dm-raid1.
> >
> > Thanks,
> > Kuai
> >
>
> Hi，Yu Kuai
>
> I tried to do git bisect and got the following result, please help check，
>
> [czhong@vm linux-block]$ git bisect start
> [czhong@vm linux-block]$ git bisect bad
> [czhong@vm linux-block]$ git bisect good
> d0487577e6e0b640d71375a6ec2f9e8a2d3555f2
> Bisecting: 2652 revisions left to test after this (roughly 11 steps)
> [895621f1c81695da7660fe909173e9f98619e89c] bnxt_en: Don't support
> offline self test when RoCE driver is loaded
> [czhong@vm linux-block]$
> [czhong@vm linux-block]$ git bisect good
> Bisecting: 1219 revisions left to test after this (roughly 10 steps)
> [6c60000f0b9ae7da630a5715a9ba33042d87e7fd] Merge tag 'soc-dt-6.10' of
> git://git.kernel.org/pub/scm/linux/kernel/git/soc/soc
> [czhong@vm linux-block]$
> [czhong@vm linux-block]$ git bisect good
> Bisecting: 612 revisions left to test after this (roughly 9 steps)
> [87caef42200cd44f8b808ec2f8ac2257f3e0a8c1] Merge tag
> 'hardening-6.10-rc1' of
> git://git.kernel.org/pub/scm/linux/kernel/git/kees/linux
> [czhong@vm linux-block]$
> [czhong@vm linux-block]$ git bisect bad
> Bisecting: 303 revisions left to test after this (roughly 8 steps)
> [25c73642cc5baea5b91bbb9b1f5fcd93672bfa08] Merge tag
> 'keys-next-6.10-rc1' of
> git://git.kernel.org/pub/scm/linux/kernel/git/jarkko/linux-tpmdd
> [czhong@vm linux-block]$ git bisect good
> Bisecting: 155 revisions left to test after this (roughly 7 steps)
> [f4e8d80292859809ea135e9f4c43bae47e4f58bc] Merge tag 'vfs-6.10.rw' of
> git://git.kernel.org/pub/scm/linux/kernel/git/vfs/vfs
> [czhong@vm linux-block]$
> [czhong@vm linux-block]$ git bisect good
> Bisecting: 77 revisions left to test after this (roughly 6 steps)
> [ac5f71a3d9d7eb540f6bf7e794eb4a3e4c3f11dd] io_uring/net: add provided
> buffer support for IORING_OP_SEND
> [czhong@vm linux-block]$ git bisect good
> Bisecting: 37 revisions left to test after this (roughly 5 steps)
> [0c9f4ac808b017a0013cee92a30de980550145d5] Merge tag
> 'for-6.10/block-20240511' of git://git.kernel.dk/linux
> [czhong@vm linux-block]$ git bisect bad
> Bisecting: 19 revisions left to test after this (roughly 4 steps)
> [a3166c51702bb00b8f8b84022090cbab8f37be1a] blk-throttle: delay
> initialization until configuration
> [czhong@vm linux-block]$
> [czhong@vm linux-block]$ git bisect bad
> Bisecting: 9 revisions left to test after this (roughly 3 steps)
> [e8b4869bc78da1a71f2a2ab476caf50c1dcfeed0] block: add a
> blk_alloc_discard_bio helper
> [czhong@vm linux-block]$ git bisect good
> Bisecting: 4 revisions left to test after this (roughly 2 steps)
> [3a861560ccb35f2a4f0a4b8207fa7c2a35fc7f31] bcache: fix variable length
> array abuse in btree_iter
> [czhong@vm linux-block]$ git bisect good
> Bisecting: 2 revisions left to test after this (roughly 1 step)
> [99dc422335d8b2bd4d105797241d3e715bae90e9] block: support to account
> io_ticks precisely
> [czhong@vm linux-block]$
> [czhong@vm linux-block]$ git bisect bad
> Bisecting: 0 revisions left to test after this (roughly 0 steps)
> [060406c61c7cb4bbd82a02d179decca9c9bb3443] block: add plug while submitting IO
> [czhong@vm linux-block]$ git bisect bad
> 060406c61c7cb4bbd82a02d179decca9c9bb3443 is the first bad commit
> commit 060406c61c7cb4bbd82a02d179decca9c9bb3443
> Author: Yu Kuai <yukuai3@huawei.com>
> Date:   Thu May 9 20:38:25 2024 +0800
>
>     block: add plug while submitting IO
>
>     So that if caller didn't use plug, for example, __blkdev_direct_IO_simple()
>     and __blkdev_direct_IO_async(), block layer can still benefit from caching
>     nsec time in the plug.
>
>     Signed-off-by: Yu Kuai <yukuai3@huawei.com>
>     Link: https://lore.kernel.org/r/20240509123825.3225207-1-yukuai1@huaweicloud.com
>     Signed-off-by: Jens Axboe <axboe@kernel.dk>
>
>  block/blk-core.c | 6 ++++++
>  1 file changed, 6 insertions(+)
> [czhong@vm linux-block]$
>
> Thanks，
> Changhui

update with  git bisect log：
[czhong@vm linux-block]$ git bisect log
git bisect start
# bad: [59ef8180748269837975c9656b586daa16bb9def] Merge branch
'block-6.10' into for-next
git bisect bad 59ef8180748269837975c9656b586daa16bb9def
# good: [d0487577e6e0b640d71375a6ec2f9e8a2d3555f2] Merge tag
'md-6.10-20240502' of
https://git.kernel.org/pub/scm/linux/kernel/git/song/md into
for-6.10/block
git bisect good d0487577e6e0b640d71375a6ec2f9e8a2d3555f2
# good: [895621f1c81695da7660fe909173e9f98619e89c] bnxt_en: Don't
support offline self test when RoCE driver is loaded
git bisect good 895621f1c81695da7660fe909173e9f98619e89c
# good: [6c60000f0b9ae7da630a5715a9ba33042d87e7fd] Merge tag
'soc-dt-6.10' of git://git.kernel.org/pub/scm/linux/kernel/git/soc/soc
git bisect good 6c60000f0b9ae7da630a5715a9ba33042d87e7fd
# bad: [87caef42200cd44f8b808ec2f8ac2257f3e0a8c1] Merge tag
'hardening-6.10-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/kees/linux
git bisect bad 87caef42200cd44f8b808ec2f8ac2257f3e0a8c1
# good: [25c73642cc5baea5b91bbb9b1f5fcd93672bfa08] Merge tag
'keys-next-6.10-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/jarkko/linux-tpmdd
git bisect good 25c73642cc5baea5b91bbb9b1f5fcd93672bfa08
# good: [f4e8d80292859809ea135e9f4c43bae47e4f58bc] Merge tag
'vfs-6.10.rw' of git://git.kernel.org/pub/scm/linux/kernel/git/vfs/vfs
git bisect good f4e8d80292859809ea135e9f4c43bae47e4f58bc
# good: [ac5f71a3d9d7eb540f6bf7e794eb4a3e4c3f11dd] io_uring/net: add
provided buffer support for IORING_OP_SEND
git bisect good ac5f71a3d9d7eb540f6bf7e794eb4a3e4c3f11dd
# bad: [0c9f4ac808b017a0013cee92a30de980550145d5] Merge tag
'for-6.10/block-20240511' of git://git.kernel.dk/linux
git bisect bad 0c9f4ac808b017a0013cee92a30de980550145d5
# bad: [a3166c51702bb00b8f8b84022090cbab8f37be1a] blk-throttle: delay
initialization until configuration
git bisect bad a3166c51702bb00b8f8b84022090cbab8f37be1a
# good: [e8b4869bc78da1a71f2a2ab476caf50c1dcfeed0] block: add a
blk_alloc_discard_bio helper
git bisect good e8b4869bc78da1a71f2a2ab476caf50c1dcfeed0
# good: [3a861560ccb35f2a4f0a4b8207fa7c2a35fc7f31] bcache: fix
variable length array abuse in btree_iter
git bisect good 3a861560ccb35f2a4f0a4b8207fa7c2a35fc7f31
# bad: [99dc422335d8b2bd4d105797241d3e715bae90e9] block: support to
account io_ticks precisely
git bisect bad 99dc422335d8b2bd4d105797241d3e715bae90e9
# bad: [060406c61c7cb4bbd82a02d179decca9c9bb3443] block: add plug
while submitting IO
git bisect bad 060406c61c7cb4bbd82a02d179decca9c9bb3443
# first bad commit: [060406c61c7cb4bbd82a02d179decca9c9bb3443] block:
add plug while submitting IO
[czhong@vm linux-block]$

Thanks，

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Yu Kuai]

Hi, Changhui

在 2024/05/20 8:39, Changhui Zhong 写道:
> [czhong@vm linux-block]$ git bisect bad
> 060406c61c7cb4bbd82a02d179decca9c9bb3443 is the first bad commit
> commit 060406c61c7cb4bbd82a02d179decca9c9bb3443
> Author: Yu Kuai<yukuai3@huawei.com>
> Date:   Thu May 9 20:38:25 2024 +0800
> 
>      block: add plug while submitting IO
> 
>      So that if caller didn't use plug, for example, __blkdev_direct_IO_simple()
>      and __blkdev_direct_IO_async(), block layer can still benefit from caching
>      nsec time in the plug.
> 
>      Signed-off-by: Yu Kuai<yukuai3@huawei.com>
>      Link:https://lore.kernel.org/r/20240509123825.3225207-1-yukuai1@huaweicloud.com
>      Signed-off-by: Jens Axboe<axboe@kernel.dk>
> 
>   block/blk-core.c | 6 ++++++
>   1 file changed, 6 insertions(+)

Thanks for the test!

I was surprised to see this blamed commit, and after taking a look at
raid1 barrier code, I found that there are some known problems, fixed in
raid10, while raid1 still unfixed. So I wonder this patch maybe just
making the exist problem easier to reporduce.

I'll start cooking patches to sync raid10 fixes to raid1, meanwhile,
can you change your script to test raid10 as well, if raid10 is fine,
I'll give you these patches later to test raid1.

Thanks,
Kuai

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Yu Kuai]

Hi,

在 2024/05/20 10:55, Yu Kuai 写道:
> Hi, Changhui
> 
> 在 2024/05/20 8:39, Changhui Zhong 写道:
>> [czhong@vm linux-block]$ git bisect bad
>> 060406c61c7cb4bbd82a02d179decca9c9bb3443 is the first bad commit
>> commit 060406c61c7cb4bbd82a02d179decca9c9bb3443
>> Author: Yu Kuai<yukuai3@huawei.com>
>> Date:   Thu May 9 20:38:25 2024 +0800
>>
>>      block: add plug while submitting IO
>>
>>      So that if caller didn't use plug, for example, 
>> __blkdev_direct_IO_simple()
>>      and __blkdev_direct_IO_async(), block layer can still benefit 
>> from caching
>>      nsec time in the plug.
>>
>>      Signed-off-by: Yu Kuai<yukuai3@huawei.com>
>>      
>> Link:https://lore.kernel.org/r/20240509123825.3225207-1-yukuai1@huaweicloud.com 
>>
>>      Signed-off-by: Jens Axboe<axboe@kernel.dk>
>>
>>   block/blk-core.c | 6 ++++++
>>   1 file changed, 6 insertions(+)
> 
> Thanks for the test!
> 
> I was surprised to see this blamed commit, and after taking a look at
> raid1 barrier code, I found that there are some known problems, fixed in
> raid10, while raid1 still unfixed. So I wonder this patch maybe just
> making the exist problem easier to reporduce.
> 
> I'll start cooking patches to sync raid10 fixes to raid1, meanwhile,
> can you change your script to test raid10 as well, if raid10 is fine,
> I'll give you these patches later to test raid1.

Hi,

Sorry to ask, but since I can't reporduce the problem, and based on
code reiview, there are multiple potential problems, can you also
reporduce the problem with following debug patch(just add some debug
info, no functional changes). So that I can make sure of details of
the problem.

diff --git a/drivers/md/raid1.c b/drivers/md/raid1.c
index 113135e7b5f2..b35b847a9e8b 100644
--- a/drivers/md/raid1.c
+++ b/drivers/md/raid1.c
@@ -936,6 +936,45 @@ static void flush_pending_writes(struct r1conf *conf)
                 spin_unlock_irq(&conf->device_lock);
  }

+static bool waiting_barrier(struct r1conf *conf, int idx)
+{
+       int nr = atomic_read(&conf->nr_waiting[idx]);
+
+       if (nr) {
+               printk("%s: idx %d nr_waiting %d\n", __func__, idx, nr);
+               return true;
+       }
+
+       return false;
+}
+
+static bool waiting_pending(struct r1conf *conf, int idx)
+{
+       int nr;
+
+       if (test_bit(MD_RECOVERY_INTR, &conf->mddev->recovery))
+               return false;
+
+       if (conf->array_frozen) {
+               printk("%s: array is frozen\n", __func__);
+               return true;
+       }
+
+       nr = atomic_read(&conf->nr_pending[idx]);
+       if (nr) {
+               printk("%s: idx %d nr_pending %d\n", __func__, idx, nr);
+               return true;
+       }
+
+       nr = atomic_read(&conf->barrier[idx]);
+       if (nr >= RESYNC_DEPTH) {
+               printk("%s: idx %d barrier %d exceeds %d\n", __func__, 
idx, nr, RESYNC_DEPTH);
+               return true;
+       }
+
+       return false;
+}
+
  /* Barriers....
   * Sometimes we need to suspend IO while we do something else,
   * either some resync/recovery, or reconfigure the array.
@@ -967,8 +1006,7 @@ static int raise_barrier(struct r1conf *conf, 
sector_t sector_nr)
         spin_lock_irq(&conf->resync_lock);

         /* Wait until no block IO is waiting */
-       wait_event_lock_irq(conf->wait_barrier,
-                           !atomic_read(&conf->nr_waiting[idx]),
+       wait_event_lock_irq(conf->wait_barrier, !waiting_barrier(conf, idx),
                             conf->resync_lock);

         /* block any new IO from starting */
@@ -990,11 +1028,7 @@ static int raise_barrier(struct r1conf *conf, 
sector_t sector_nr)
          * C: while conf->barrier[idx] >= RESYNC_DEPTH, meaning reaches
          *    max resync count which allowed on current I/O barrier bucket.
          */
-       wait_event_lock_irq(conf->wait_barrier,
-                           (!conf->array_frozen &&
-                            !atomic_read(&conf->nr_pending[idx]) &&
-                            atomic_read(&conf->barrier[idx]) < 
RESYNC_DEPTH) ||
-                               test_bit(MD_RECOVERY_INTR, 
&conf->mddev->recovery),
+       wait_event_lock_irq(conf->wait_barrier, !waiting_pending(conf, idx),
                             conf->resync_lock);

         if (test_bit(MD_RECOVERY_INTR, &conf->mddev->recovery)) {

Thanks,
Kuai

> 
> Thanks,
> Kuai
> 
> .
> 

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Changhui Zhong]

On Mon, May 20, 2024 at 3:27 PM Yu Kuai <yukuai1@huaweicloud.com> wrote:
>
> Hi,
>
> 在 2024/05/20 10:55, Yu Kuai 写道:
> > Hi, Changhui
> >
> > 在 2024/05/20 8:39, Changhui Zhong 写道:
> >> [czhong@vm linux-block]$ git bisect bad
> >> 060406c61c7cb4bbd82a02d179decca9c9bb3443 is the first bad commit
> >> commit 060406c61c7cb4bbd82a02d179decca9c9bb3443
> >> Author: Yu Kuai<yukuai3@huawei.com>
> >> Date:   Thu May 9 20:38:25 2024 +0800
> >>
> >>      block: add plug while submitting IO
> >>
> >>      So that if caller didn't use plug, for example,
> >> __blkdev_direct_IO_simple()
> >>      and __blkdev_direct_IO_async(), block layer can still benefit
> >> from caching
> >>      nsec time in the plug.
> >>
> >>      Signed-off-by: Yu Kuai<yukuai3@huawei.com>
> >>
> >> Link:https://lore.kernel.org/r/20240509123825.3225207-1-yukuai1@huaweicloud.com
> >>
> >>      Signed-off-by: Jens Axboe<axboe@kernel.dk>
> >>
> >>   block/blk-core.c | 6 ++++++
> >>   1 file changed, 6 insertions(+)
> >
> > Thanks for the test!
> >
> > I was surprised to see this blamed commit, and after taking a look at
> > raid1 barrier code, I found that there are some known problems, fixed in
> > raid10, while raid1 still unfixed. So I wonder this patch maybe just
> > making the exist problem easier to reporduce.
> >
> > I'll start cooking patches to sync raid10 fixes to raid1, meanwhile,
> > can you change your script to test raid10 as well, if raid10 is fine,
> > I'll give you these patches later to test raid1.
>
> Hi,
>
> Sorry to ask, but since I can't reporduce the problem, and based on
> code reiview, there are multiple potential problems, can you also
> reporduce the problem with following debug patch(just add some debug
> info, no functional changes). So that I can make sure of details of
> the problem.
>

Hi，Kuai

yeah， I can test your patch，
but I hit a problem when applying the patch, please help check it, and
I will test it again after you fix it.

```
patching file drivers/md/raid1.c
patch: **** malformed patch at line 42: idx, nr, RESYNC_DEPTH);
```

Thanks,
Changhui

> diff --git a/drivers/md/raid1.c b/drivers/md/raid1.c
> index 113135e7b5f2..b35b847a9e8b 100644
> --- a/drivers/md/raid1.c
> +++ b/drivers/md/raid1.c
> @@ -936,6 +936,45 @@ static void flush_pending_writes(struct r1conf *conf)
>                  spin_unlock_irq(&conf->device_lock);
>   }
>
> +static bool waiting_barrier(struct r1conf *conf, int idx)
> +{
> +       int nr = atomic_read(&conf->nr_waiting[idx]);
> +
> +       if (nr) {
> +               printk("%s: idx %d nr_waiting %d\n", __func__, idx, nr);
> +               return true;
> +       }
> +
> +       return false;
> +}
> +
> +static bool waiting_pending(struct r1conf *conf, int idx)
> +{
> +       int nr;
> +
> +       if (test_bit(MD_RECOVERY_INTR, &conf->mddev->recovery))
> +               return false;
> +
> +       if (conf->array_frozen) {
> +               printk("%s: array is frozen\n", __func__);
> +               return true;
> +       }
> +
> +       nr = atomic_read(&conf->nr_pending[idx]);
> +       if (nr) {
> +               printk("%s: idx %d nr_pending %d\n", __func__, idx, nr);
> +               return true;
> +       }
> +
> +       nr = atomic_read(&conf->barrier[idx]);
> +       if (nr >= RESYNC_DEPTH) {
> +               printk("%s: idx %d barrier %d exceeds %d\n", __func__,
> idx, nr, RESYNC_DEPTH);
> +               return true;
> +       }
> +
> +       return false;
> +}
> +
>   /* Barriers....
>    * Sometimes we need to suspend IO while we do something else,
>    * either some resync/recovery, or reconfigure the array.
> @@ -967,8 +1006,7 @@ static int raise_barrier(struct r1conf *conf,
> sector_t sector_nr)
>          spin_lock_irq(&conf->resync_lock);
>
>          /* Wait until no block IO is waiting */
> -       wait_event_lock_irq(conf->wait_barrier,
> -                           !atomic_read(&conf->nr_waiting[idx]),
> +       wait_event_lock_irq(conf->wait_barrier, !waiting_barrier(conf, idx),
>                              conf->resync_lock);
>
>          /* block any new IO from starting */
> @@ -990,11 +1028,7 @@ static int raise_barrier(struct r1conf *conf,
> sector_t sector_nr)
>           * C: while conf->barrier[idx] >= RESYNC_DEPTH, meaning reaches
>           *    max resync count which allowed on current I/O barrier bucket.
>           */
> -       wait_event_lock_irq(conf->wait_barrier,
> -                           (!conf->array_frozen &&
> -                            !atomic_read(&conf->nr_pending[idx]) &&
> -                            atomic_read(&conf->barrier[idx]) <
> RESYNC_DEPTH) ||
> -                               test_bit(MD_RECOVERY_INTR,
> &conf->mddev->recovery),
> +       wait_event_lock_irq(conf->wait_barrier, !waiting_pending(conf, idx),
>                              conf->resync_lock);
>
>          if (test_bit(MD_RECOVERY_INTR, &conf->mddev->recovery)) {
>
> Thanks,
> Kuai
>
> >
> > Thanks,
> > Kuai
> >
> > .
> >
>

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Changhui Zhong]

On Mon, May 20, 2024 at 10:55 AM Yu Kuai <yukuai1@huaweicloud.com> wrote:
>
> Hi, Changhui
>
> 在 2024/05/20 8:39, Changhui Zhong 写道:
> > [czhong@vm linux-block]$ git bisect bad
> > 060406c61c7cb4bbd82a02d179decca9c9bb3443 is the first bad commit
> > commit 060406c61c7cb4bbd82a02d179decca9c9bb3443
> > Author: Yu Kuai<yukuai3@huawei.com>
> > Date:   Thu May 9 20:38:25 2024 +0800
> >
> >      block: add plug while submitting IO
> >
> >      So that if caller didn't use plug, for example, __blkdev_direct_IO_simple()
> >      and __blkdev_direct_IO_async(), block layer can still benefit from caching
> >      nsec time in the plug.
> >
> >      Signed-off-by: Yu Kuai<yukuai3@huawei.com>
> >      Link:https://lore.kernel.org/r/20240509123825.3225207-1-yukuai1@huaweicloud.com
> >      Signed-off-by: Jens Axboe<axboe@kernel.dk>
> >
> >   block/blk-core.c | 6 ++++++
> >   1 file changed, 6 insertions(+)
>
> Thanks for the test!
>
> I was surprised to see this blamed commit, and after taking a look at
> raid1 barrier code, I found that there are some known problems, fixed in
> raid10, while raid1 still unfixed. So I wonder this patch maybe just
> making the exist problem easier to reporduce.
>
> I'll start cooking patches to sync raid10 fixes to raid1, meanwhile,
> can you change your script to test raid10 as well, if raid10 is fine,
> I'll give you these patches later to test raid1.
>
> Thanks,
> Kuai
>

Hi， Kuai

I tested raid10 and trigger this issue too，

[  332.435340] Create raid10
[  332.573160] device-mapper: raid: Superblocks created for new raid set
[  332.595273] md/raid10:mdX: not clean -- starting background reconstruction
[  332.595277] md/raid10:mdX: active with 4 out of 4 devices
[  332.597017] mdX: bitmap file is out of date, doing full recovery
[  332.603712] md: resync of RAID array mdX
[  492.173892] INFO: task mdX_resync:3092 blocked for more than 122 seconds.
[  492.180694]       Not tainted 6.9.0+ #1
[  492.184536] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[  492.192365] task:mdX_resync      state:D stack:0     pid:3092
tgid:3092  ppid:2      flags:0x00004000
[  492.192368] Call Trace:
[  492.192370]  <TASK>
[  492.192371]  __schedule+0x222/0x670
[  492.192377]  schedule+0x2c/0xb0
[  492.192381]  raise_barrier+0xc3/0x190 [raid10]
[  492.192387]  ? __pfx_autoremove_wake_function+0x10/0x10
[  492.192392]  raid10_sync_request+0x2c3/0x1ae0 [raid10]
[  492.192397]  ? __schedule+0x22a/0x670
[  492.192398]  ? prepare_to_wait_event+0x5f/0x190
[  492.192401]  md_do_sync+0x660/0x1040
[  492.192405]  ? __pfx_autoremove_wake_function+0x10/0x10
[  492.192408]  md_thread+0xad/0x160
[  492.192410]  ? __pfx_md_thread+0x10/0x10
[  492.192411]  kthread+0xdc/0x110
[  492.192414]  ? __pfx_kthread+0x10/0x10
[  492.192416]  ret_from_fork+0x2d/0x50
[  492.192420]  ? __pfx_kthread+0x10/0x10
[  492.192421]  ret_from_fork_asm+0x1a/0x30
[  492.192424]  </TASK>

Thanks，
Changhui

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Yu Kuai]

[-- Attachment #1: Type: text/plain, Size: 3430 bytes --]

Hi,

在 2024/05/20 18:38, Changhui Zhong 写道:
> On Mon, May 20, 2024 at 10:55 AM Yu Kuai <yukuai1@huaweicloud.com> wrote:
>>
>> Hi, Changhui
>>
>> 在 2024/05/20 8:39, Changhui Zhong 写道:
>>> [czhong@vm linux-block]$ git bisect bad
>>> 060406c61c7cb4bbd82a02d179decca9c9bb3443 is the first bad commit
>>> commit 060406c61c7cb4bbd82a02d179decca9c9bb3443
>>> Author: Yu Kuai<yukuai3@huawei.com>
>>> Date:   Thu May 9 20:38:25 2024 +0800
>>>
>>>       block: add plug while submitting IO
>>>
>>>       So that if caller didn't use plug, for example, __blkdev_direct_IO_simple()
>>>       and __blkdev_direct_IO_async(), block layer can still benefit from caching
>>>       nsec time in the plug.
>>>
>>>       Signed-off-by: Yu Kuai<yukuai3@huawei.com>
>>>       Link:https://lore.kernel.org/r/20240509123825.3225207-1-yukuai1@huaweicloud.com
>>>       Signed-off-by: Jens Axboe<axboe@kernel.dk>
>>>
>>>    block/blk-core.c | 6 ++++++
>>>    1 file changed, 6 insertions(+)
>>
>> Thanks for the test!
>>
>> I was surprised to see this blamed commit, and after taking a look at
>> raid1 barrier code, I found that there are some known problems, fixed in
>> raid10, while raid1 still unfixed. So I wonder this patch maybe just
>> making the exist problem easier to reporduce.
>>
>> I'll start cooking patches to sync raid10 fixes to raid1, meanwhile,
>> can you change your script to test raid10 as well, if raid10 is fine,
>> I'll give you these patches later to test raid1.
>>
>> Thanks,
>> Kuai
>>
> 
> Hi， Kuai
> 
> I tested raid10 and trigger this issue too，

Thanks for the test! Since raid10 has the same problem as well, then the
problem seems to be more common in raid. And related code to raid10 is
more simpler, attached is a patch to add debuginfo to raid10.

BTW, Xiao can reporduce the problem as well, and will lend a hand as
well.

Thanks,
Kuai
> 
> [  332.435340] Create raid10
> [  332.573160] device-mapper: raid: Superblocks created for new raid set
> [  332.595273] md/raid10:mdX: not clean -- starting background reconstruction
> [  332.595277] md/raid10:mdX: active with 4 out of 4 devices
> [  332.597017] mdX: bitmap file is out of date, doing full recovery
> [  332.603712] md: resync of RAID array mdX
> [  492.173892] INFO: task mdX_resync:3092 blocked for more than 122 seconds.
> [  492.180694]       Not tainted 6.9.0+ #1
> [  492.184536] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [  492.192365] task:mdX_resync      state:D stack:0     pid:3092
> tgid:3092  ppid:2      flags:0x00004000
> [  492.192368] Call Trace:
> [  492.192370]  <TASK>
> [  492.192371]  __schedule+0x222/0x670
> [  492.192377]  schedule+0x2c/0xb0
> [  492.192381]  raise_barrier+0xc3/0x190 [raid10]
> [  492.192387]  ? __pfx_autoremove_wake_function+0x10/0x10
> [  492.192392]  raid10_sync_request+0x2c3/0x1ae0 [raid10]
> [  492.192397]  ? __schedule+0x22a/0x670
> [  492.192398]  ? prepare_to_wait_event+0x5f/0x190
> [  492.192401]  md_do_sync+0x660/0x1040
> [  492.192405]  ? __pfx_autoremove_wake_function+0x10/0x10
> [  492.192408]  md_thread+0xad/0x160
> [  492.192410]  ? __pfx_md_thread+0x10/0x10
> [  492.192411]  kthread+0xdc/0x110
> [  492.192414]  ? __pfx_kthread+0x10/0x10
> [  492.192416]  ret_from_fork+0x2d/0x50
> [  492.192420]  ? __pfx_kthread+0x10/0x10
> [  492.192421]  ret_from_fork_asm+0x1a/0x30
> [  492.192424]  </TASK>
> 
> Thanks，
> Changhui
> 
> 
> .
> 

[-- Attachment #2: 0001-raid10-debuginfo.patch --]
[-- Type: text/plain, Size: 3823 bytes --]

From d443a5bc43ecd41386e8e9103cd5e16914a1a2c3 Mon Sep 17 00:00:00 2001
From: Yu Kuai <yukuai3@huawei.com>
Date: Mon, 20 May 2024 19:43:29 +0800
Subject: [PATCH] tmp

Signed-off-by: Yu Kuai <yukuai3@huawei.com>
---
 drivers/md/raid10.c | 49 ++++++++++++++++++++++++++++++++++++++++-----
 1 file changed, 44 insertions(+), 5 deletions(-)

diff --git a/drivers/md/raid10.c b/drivers/md/raid10.c
index a4556d2e46bf..bc05d4ff5185 100644
--- a/drivers/md/raid10.c
+++ b/drivers/md/raid10.c
@@ -331,6 +331,7 @@ static void raid_end_bio_io(struct r10bio *r10_bio)
 	 */
 	allow_barrier(conf);
 
+	printk("%s: r10_bio %px done\n", __func__, r10_bio);
 	free_r10bio(r10_bio);
 }
 
@@ -899,6 +900,34 @@ static void flush_pending_writes(struct r10conf *conf)
 		spin_unlock_irq(&conf->device_lock);
 }
 
+static bool barrier_waiting(struct r10conf *conf)
+{
+	if (conf->nr_waiting) {
+		printk("%s: nr_waiting %d\n", __func__, conf->nr_waiting);
+		return false;
+	}
+
+	return true;
+}
+
+static bool try_raise_barrier(struct r10conf *conf)
+{
+	int nr;
+
+	if (conf->barrier >= RESYNC_DEPTH) {
+		printk_ratelimited("%s: resync depth exceed limit\n", __func__);
+		return false;
+	}
+
+	nr = atomic_read(&conf->nr_pending);
+	if (nr) {
+		printk("%s: nr_pending %d\n", __func__, nr);
+		return false;
+	}
+
+	return true;
+}
+
 /* Barriers....
  * Sometimes we need to suspend IO while we do something else,
  * either some resync/recovery, or reconfigure the array.
@@ -929,14 +958,13 @@ static void raise_barrier(struct r10conf *conf, int force)
 		force = false;
 
 	/* Wait until no block IO is waiting (unless 'force') */
-	wait_event_barrier(conf, force || !conf->nr_waiting);
+	wait_event_barrier(conf, force || barrier_waiting(conf));
 
 	/* block any new IO from starting */
 	WRITE_ONCE(conf->barrier, conf->barrier + 1);
 
 	/* Now wait for all pending IO to complete */
-	wait_event_barrier(conf, !atomic_read(&conf->nr_pending) &&
-				 conf->barrier < RESYNC_DEPTH);
+	wait_event_barrier(conf, try_raise_barrier(conf));
 
 	write_sequnlock_irq(&conf->resync_lock);
 }
@@ -1006,8 +1034,10 @@ static bool wait_barrier(struct r10conf *conf, bool nowait)
 {
 	bool ret = true;
 
-	if (wait_barrier_nolock(conf))
+	if (wait_barrier_nolock(conf)) {
+		printk("%s: nr_pending: %d\n", __func__, atomic_read(&conf->nr_pending));
 		return true;
+	}
 
 	write_seqlock_irq(&conf->resync_lock);
 	if (conf->barrier) {
@@ -1024,9 +1054,12 @@ static bool wait_barrier(struct r10conf *conf, bool nowait)
 			wake_up(&conf->wait_barrier);
 	}
 	/* Only increment nr_pending when we wait */
-	if (ret)
+	if (ret) {
 		atomic_inc(&conf->nr_pending);
+		printk("%s: nr_pending: %d\n", __func__, atomic_read(&conf->nr_pending));
+	}
 	write_sequnlock_irq(&conf->resync_lock);
+
 	return ret;
 }
 
@@ -1035,6 +1068,8 @@ static void allow_barrier(struct r10conf *conf)
 	if ((atomic_dec_and_test(&conf->nr_pending)) ||
 			(conf->array_freeze_pending))
 		wake_up_barrier(conf);
+
+	printk("%s: nr_pending: %d\n", __func__, atomic_read(&conf->nr_pending));
 }
 
 static void freeze_array(struct r10conf *conf, int extra)
@@ -1187,6 +1222,8 @@ static void raid10_read_request(struct mddev *mddev, struct bio *bio,
 
 	if (!regular_request_wait(mddev, conf, bio, r10_bio->sectors))
 		return;
+
+	printk("%s: r10_bio %px start\n", __func__, r10_bio);
 	rdev = read_balance(conf, r10_bio, &max_sectors);
 	if (!rdev) {
 		if (err_rdev) {
@@ -1374,6 +1411,8 @@ static void raid10_write_request(struct mddev *mddev, struct bio *bio,
 	sectors = r10_bio->sectors;
 	if (!regular_request_wait(mddev, conf, bio, sectors))
 		return;
+
+	printk("%s: r10_bio %px start\n", __func__, r10_bio);
 	if (test_bit(MD_RECOVERY_RESHAPE, &mddev->recovery) &&
 	    (mddev->reshape_backwards
 	     ? (bio->bi_iter.bi_sector < conf->reshape_safe &&
-- 
2.39.2

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Changhui Zhong]

On Tue, May 21, 2024 at 9:09 AM Yu Kuai <yukuai1@huaweicloud.com> wrote:

>
> Thanks for the test! Since raid10 has the same problem as well, then the
> problem seems to be more common in raid. And related code to raid10 is
> more simpler, attached is a patch to add debuginfo to raid10.
>
> BTW, Xiao can reporduce the problem as well, and will lend a hand as
> well.
>
> Thanks,
> Kuai


Hi, Yu Kuai and Xiao

thanks for  efforts on this issue，
after applying the debug patch, I got the following results, please check it

[  597.491083] Create raid10
[  597.647987] device-mapper: raid: Superblocks created for new raid set
[  597.680540] md/raid10:mdX: not clean -- starting background reconstruction
[  597.680549] md/raid10:mdX: active with 4 out of 4 devices
[  597.683779] mdX: bitmap file is out of date, doing full recovery
[  597.692971] md: resync of RAID array mdX
[  597.753583] try_raise_barrier: resync depth exceed limit
[  597.759540] try_raise_barrier: resync depth exceed limit
[  597.765504] try_raise_barrier: resync depth exceed limit
[  597.771432] try_raise_barrier: resync depth exceed limit
[  597.779400] barrier_waiting: nr_waiting 1
[  597.783879] barrier_waiting: nr_waiting 1
[  597.788356] barrier_waiting: nr_waiting 1
[  597.792838] barrier_waiting: nr_waiting 1
[  597.797327] barrier_waiting: nr_waiting 1
[  597.801806] barrier_waiting: nr_waiting 1
[  597.806288] barrier_waiting: nr_waiting 1
[  597.810780] barrier_waiting: nr_waiting 1
[  597.815252] barrier_waiting: nr_waiting 1
[  597.819737] barrier_waiting: nr_waiting 1
[  597.824232] barrier_waiting: nr_waiting 1
[  597.828714] barrier_waiting: nr_waiting 1
[  597.833196] barrier_waiting: nr_waiting 1
[  597.837678] barrier_waiting: nr_waiting 1
[  597.842160] barrier_waiting: nr_waiting 1
[  597.846640] barrier_waiting: nr_waiting 1
[  597.851128] barrier_waiting: nr_waiting 1
[  597.855610] barrier_waiting: nr_waiting 1
[  597.860094] barrier_waiting: nr_waiting 1
[  597.864576] barrier_waiting: nr_waiting 1
[  597.869060] barrier_waiting: nr_waiting 1
[  597.873548] barrier_waiting: nr_waiting 1
[  597.878032] barrier_waiting: nr_waiting 1
[  597.882522] barrier_waiting: nr_waiting 1
[  597.883457] barrier_waiting: nr_waiting 1
[  597.891503] barrier_waiting: nr_waiting 1
[  597.895987] barrier_waiting: nr_waiting 1
[  597.900459] barrier_waiting: nr_waiting 1
[  597.904940] barrier_waiting: nr_waiting 1
[  597.909421] barrier_waiting: nr_waiting 1
[  597.913900] barrier_waiting: nr_waiting 1
[  597.918377] barrier_waiting: nr_waiting 1
[  597.922857] barrier_waiting: nr_waiting 1
[  597.927350] barrier_waiting: nr_waiting 1
[  597.931841] barrier_waiting: nr_waiting 1
[  597.936322] barrier_waiting: nr_waiting 1
[  597.940805] barrier_waiting: nr_waiting 1
[  597.945284] barrier_waiting: nr_waiting 1
[  597.949766] barrier_waiting: nr_waiting 1
[  597.954246] barrier_waiting: nr_waiting 1
[  597.958726] barrier_waiting: nr_waiting 1
[  597.963205] barrier_waiting: nr_waiting 1
[  597.967683] barrier_waiting: nr_waiting 1
[  597.972163] barrier_waiting: nr_waiting 1
[  597.976641] barrier_waiting: nr_waiting 1
[  597.981119] barrier_waiting: nr_waiting 1
[  597.985601] barrier_waiting: nr_waiting 1
[  597.990082] barrier_waiting: nr_waiting 1
[  597.994562] barrier_waiting: nr_waiting 1
[  597.999043] barrier_waiting: nr_waiting 1
[  598.003522] barrier_waiting: nr_waiting 1
[  598.008000] barrier_waiting: nr_waiting 1
[  598.012485] barrier_waiting: nr_waiting 1
[  598.016964] barrier_waiting: nr_waiting 1
[  598.021451] barrier_waiting: nr_waiting 1
[  598.025931] barrier_waiting: nr_waiting 1
[  598.030409] barrier_waiting: nr_waiting 1
[  598.034888] barrier_waiting: nr_waiting 1
[  598.039368] barrier_waiting: nr_waiting 1
[  598.043848] barrier_waiting: nr_waiting 1
[  598.048325] barrier_waiting: nr_waiting 1
[  598.052805] barrier_waiting: nr_waiting 1
[  598.057283] barrier_waiting: nr_waiting 1
[  598.061767] barrier_waiting: nr_waiting 1
[  598.066246] barrier_waiting: nr_waiting 1
[  598.070726] barrier_waiting: nr_waiting 1
[  598.075206] barrier_waiting: nr_waiting 1
[  598.079689] barrier_waiting: nr_waiting 1
[  598.084170] barrier_waiting: nr_waiting 1
[  598.088648] barrier_waiting: nr_waiting 1
[  598.093130] barrier_waiting: nr_waiting 1
[  598.097646] barrier_waiting: nr_waiting 1
[  598.102126] barrier_waiting: nr_waiting 1
[  598.106605] barrier_waiting: nr_waiting 1
[  598.111085] barrier_waiting: nr_waiting 1
[  598.115566] barrier_waiting: nr_waiting 1
[  598.120043] barrier_waiting: nr_waiting 1
[  598.124522] barrier_waiting: nr_waiting 1
[  598.129001] barrier_waiting: nr_waiting 1
[  598.133481] barrier_waiting: nr_waiting 1
[  598.137958] barrier_waiting: nr_waiting 1
[  598.142442] barrier_waiting: nr_waiting 1
[  598.146921] barrier_waiting: nr_waiting 1
[  598.151400] barrier_waiting: nr_waiting 1
[  598.155878] barrier_waiting: nr_waiting 1
[  598.160359] barrier_waiting: nr_waiting 1
[  598.164838] barrier_waiting: nr_waiting 1
[  598.169319] barrier_waiting: nr_waiting 1
[  598.173803] barrier_waiting: nr_waiting 1
[  598.178282] barrier_waiting: nr_waiting 1
[  598.182762] barrier_waiting: nr_waiting 1
[  598.187241] barrier_waiting: nr_waiting 1
[  598.191722] barrier_waiting: nr_waiting 1
[  598.196201] barrier_waiting: nr_waiting 1
[  598.200678] barrier_waiting: nr_waiting 1
[  598.205159] barrier_waiting: nr_waiting 1
[  598.209640] barrier_waiting: nr_waiting 1
[  598.214120] barrier_waiting: nr_waiting 1
[  598.218599] barrier_waiting: nr_waiting 1
[  598.223078] barrier_waiting: nr_waiting 1
[  598.227557] barrier_waiting: nr_waiting 1
[  598.232036] barrier_waiting: nr_waiting 1
[  598.236519] barrier_waiting: nr_waiting 1
[  598.240999] barrier_waiting: nr_waiting 1
[  598.245478] barrier_waiting: nr_waiting 1
[  598.249959] barrier_waiting: nr_waiting 1
[  598.254439] barrier_waiting: nr_waiting 1
[  598.258917] barrier_waiting: nr_waiting 1
[  598.263397] barrier_waiting: nr_waiting 1
[  598.267880] barrier_waiting: nr_waiting 1
[  598.272362] barrier_waiting: nr_waiting 1
[  598.276842] barrier_waiting: nr_waiting 1
[  598.281322] barrier_waiting: nr_waiting 1
[  598.285802] barrier_waiting: nr_waiting 1
[  598.290281] barrier_waiting: nr_waiting 1
[  598.294758] barrier_waiting: nr_waiting 1
[  598.299256] barrier_waiting: nr_waiting 1
[  598.303737] barrier_waiting: nr_waiting 1
[  598.308219] barrier_waiting: nr_waiting 1
[  598.312698] barrier_waiting: nr_waiting 1
[  598.317176] barrier_waiting: nr_waiting 1
[  598.321659] barrier_waiting: nr_waiting 1
[  598.326138] barrier_waiting: nr_waiting 1
[  598.330617] barrier_waiting: nr_waiting 1
[  598.335100] barrier_waiting: nr_waiting 1
[  598.339580] barrier_waiting: nr_waiting 1
[  598.344057] barrier_waiting: nr_waiting 1
[  598.348536] barrier_waiting: nr_waiting 1
[  598.353016] barrier_waiting: nr_waiting 1
[  598.357496] barrier_waiting: nr_waiting 1
[  598.361973] barrier_waiting: nr_waiting 1
[  598.366453] barrier_waiting: nr_waiting 1
[  598.370932] barrier_waiting: nr_waiting 1
[  598.375412] barrier_waiting: nr_waiting 1
[  598.379890] barrier_waiting: nr_waiting 1
[  598.384371] barrier_waiting: nr_waiting 1
[  598.388856] barrier_waiting: nr_waiting 1
[  598.393326] barrier_waiting: nr_waiting 1
[  598.397805] barrier_waiting: nr_waiting 1
[  598.402288] barrier_waiting: nr_waiting 1
[  598.406772] barrier_waiting: nr_waiting 1
[  598.411251] barrier_waiting: nr_waiting 1
[  598.415729] barrier_waiting: nr_waiting 1
[  598.420209] barrier_waiting: nr_waiting 1
[  598.424686] barrier_waiting: nr_waiting 1
[  598.429165] barrier_waiting: nr_waiting 1
[  598.433644] barrier_waiting: nr_waiting 1
[  598.438125] barrier_waiting: nr_waiting 1
[  598.442604] barrier_waiting: nr_waiting 1
[  598.447083] barrier_waiting: nr_waiting 1
[  598.451571] barrier_waiting: nr_waiting 1
[  598.456050] barrier_waiting: nr_waiting 1
[  598.460531] barrier_waiting: nr_waiting 1
[  598.465010] barrier_waiting: nr_waiting 1
[  598.469498] barrier_waiting: nr_waiting 1
[  598.473981] barrier_waiting: nr_waiting 1
[  598.478460] barrier_waiting: nr_waiting 1
[  598.482940] barrier_waiting: nr_waiting 1
[  598.487421] barrier_waiting: nr_waiting 1
[  598.491901] barrier_waiting: nr_waiting 1
[  598.496382] barrier_waiting: nr_waiting 1
[  598.500860] barrier_waiting: nr_waiting 1
[  598.505338] barrier_waiting: nr_waiting 1
[  598.509837] barrier_waiting: nr_waiting 1
[  598.514317] barrier_waiting: nr_waiting 1
[  598.518797] barrier_waiting: nr_waiting 1
[  598.523276] barrier_waiting: nr_waiting 1
[  598.527756] barrier_waiting: nr_waiting 1
[  598.532241] barrier_waiting: nr_waiting 1
[  598.536719] barrier_waiting: nr_waiting 1
[  598.541199] barrier_waiting: nr_waiting 1
[  598.545679] barrier_waiting: nr_waiting 1
[  598.550159] barrier_waiting: nr_waiting 1
[  598.554639] barrier_waiting: nr_waiting 1
[  598.559118] barrier_waiting: nr_waiting 1
[  598.563597] barrier_waiting: nr_waiting 1
[  598.568077] barrier_waiting: nr_waiting 1
[  598.572561] barrier_waiting: nr_waiting 1
[  598.577038] barrier_waiting: nr_waiting 1
[  598.581517] barrier_waiting: nr_waiting 1
[  598.585995] barrier_waiting: nr_waiting 1
[  598.590475] barrier_waiting: nr_waiting 1
[  598.594953] barrier_waiting: nr_waiting 1
[  598.599434] barrier_waiting: nr_waiting 1
[  598.603913] barrier_waiting: nr_waiting 1
[  598.608392] barrier_waiting: nr_waiting 1
[  598.612871] barrier_waiting: nr_waiting 1
[  598.617349] barrier_waiting: nr_waiting 1
[  598.621828] barrier_waiting: nr_waiting 1
[  598.626308] barrier_waiting: nr_waiting 1
[  598.630787] barrier_waiting: nr_waiting 1
[  598.635272] barrier_waiting: nr_waiting 1
[  598.639753] barrier_waiting: nr_waiting 1
[  598.644231] barrier_waiting: nr_waiting 1
[  598.648712] barrier_waiting: nr_waiting 1
[  598.653192] barrier_waiting: nr_waiting 1
[  598.657671] barrier_waiting: nr_waiting 1
[  598.662150] barrier_waiting: nr_waiting 1
[  598.666630] barrier_waiting: nr_waiting 1
[  598.671111] barrier_waiting: nr_waiting 1
[  598.675589] barrier_waiting: nr_waiting 1
[  598.680068] barrier_waiting: nr_waiting 1
[  598.684547] barrier_waiting: nr_waiting 1
[  598.689024] barrier_waiting: nr_waiting 1
[  598.693501] barrier_waiting: nr_waiting 1
[  598.697982] barrier_waiting: nr_waiting 1
[  598.702462] barrier_waiting: nr_waiting 1
[  598.706945] barrier_waiting: nr_waiting 1
[  598.711425] barrier_waiting: nr_waiting 1
[  598.715989] barrier_waiting: nr_waiting 1
[  598.720523] barrier_waiting: nr_waiting 1
[  598.725014] barrier_waiting: nr_waiting 1
[  598.729500] barrier_waiting: nr_waiting 1
[  598.733983] barrier_waiting: nr_waiting 1
[  598.738465] barrier_waiting: nr_waiting 1
[  598.742947] barrier_waiting: nr_waiting 1
[  598.747426] barrier_waiting: nr_waiting 1
[  598.751909] barrier_waiting: nr_waiting 1
[  598.756390] barrier_waiting: nr_waiting 1
[  598.760869] barrier_waiting: nr_waiting 1
[  598.765360] barrier_waiting: nr_waiting 1
[  598.769839] barrier_waiting: nr_waiting 1
[  598.774318] barrier_waiting: nr_waiting 1
[  598.778801] barrier_waiting: nr_waiting 1
[  598.783280] barrier_waiting: nr_waiting 1
[  598.787758] barrier_waiting: nr_waiting 1
[  598.792242] barrier_waiting: nr_waiting 1
[  598.796723] barrier_waiting: nr_waiting 1
[  598.801200] barrier_waiting: nr_waiting 1
[  598.805688] barrier_waiting: nr_waiting 1
[  598.810166] barrier_waiting: nr_waiting 1
[  598.814646] barrier_waiting: nr_waiting 1
[  598.819126] barrier_waiting: nr_waiting 1
[  598.823606] barrier_waiting: nr_waiting 1
[  598.828086] barrier_waiting: nr_waiting 1
[  598.832574] barrier_waiting: nr_waiting 1
[  598.837052] barrier_waiting: nr_waiting 1
[  598.841531] barrier_waiting: nr_waiting 1
[  598.846012] barrier_waiting: nr_waiting 1
[  598.850491] barrier_waiting: nr_waiting 1
[  598.854969] barrier_waiting: nr_waiting 1
[  598.859456] barrier_waiting: nr_waiting 1
[  598.863934] barrier_waiting: nr_waiting 1
[  598.868412] barrier_waiting: nr_waiting 1
[  598.872895] barrier_waiting: nr_waiting 1
[  598.877374] barrier_waiting: nr_waiting 1
[  598.881853] barrier_waiting: nr_waiting 1
[  598.886334] barrier_waiting: nr_waiting 1
[  598.890813] barrier_waiting: nr_waiting 1
[  598.895293] barrier_waiting: nr_waiting 1
[  598.899774] barrier_waiting: nr_waiting 1
[  598.904253] barrier_waiting: nr_waiting 1
[  598.908735] barrier_waiting: nr_waiting 1
[  598.913215] barrier_waiting: nr_waiting 1
[  598.917694] barrier_waiting: nr_waiting 1
[  598.922173] barrier_waiting: nr_waiting 1
[  598.926663] barrier_waiting: nr_waiting 1
[  598.931153] barrier_waiting: nr_waiting 1
[  598.935638] barrier_waiting: nr_waiting 1
[  598.940115] barrier_waiting: nr_waiting 1
[  598.944599] barrier_waiting: nr_waiting 1
[  598.949080] barrier_waiting: nr_waiting 1
[  598.953561] barrier_waiting: nr_waiting 1
[  598.958042] barrier_waiting: nr_waiting 1
[  598.962523] barrier_waiting: nr_waiting 1
[  598.967006] barrier_waiting: nr_waiting 1
[  598.971486] barrier_waiting: nr_waiting 1
[  598.975965] barrier_waiting: nr_waiting 1
[  598.980446] barrier_waiting: nr_waiting 1
[  598.984923] barrier_waiting: nr_waiting 1
[  598.989408] barrier_waiting: nr_waiting 1
[  598.993890] barrier_waiting: nr_waiting 1
[  598.998367] barrier_waiting: nr_waiting 1
[  599.002844] barrier_waiting: nr_waiting 1
[  599.007328] barrier_waiting: nr_waiting 1
[  599.011800] barrier_waiting: nr_waiting 1
[  599.016278] barrier_waiting: nr_waiting 1
[  599.020756] barrier_waiting: nr_waiting 1
[  599.025241] barrier_waiting: nr_waiting 1
[  599.029720] barrier_waiting: nr_waiting 1
[  599.034199] barrier_waiting: nr_waiting 1
[  599.038682] barrier_waiting: nr_waiting 1
[  599.043161] barrier_waiting: nr_waiting 1
[  599.047641] barrier_waiting: nr_waiting 1
[  599.052120] barrier_waiting: nr_waiting 1
[  599.056601] barrier_waiting: nr_waiting 1
[  599.061082] barrier_waiting: nr_waiting 1
[  599.065567] barrier_waiting: nr_waiting 1
[  599.070045] barrier_waiting: nr_waiting 1
[  599.074522] barrier_waiting: nr_waiting 1
[  599.079006] barrier_waiting: nr_waiting 1
[  599.083486] barrier_waiting: nr_waiting 1
[  599.087968] barrier_waiting: nr_waiting 1
[  599.092448] barrier_waiting: nr_waiting 1
[  599.096929] barrier_waiting: nr_waiting 1
[  599.101407] barrier_waiting: nr_waiting 1
[  599.105886] barrier_waiting: nr_waiting 1
[  599.110366] barrier_waiting: nr_waiting 1
[  599.114850] barrier_waiting: nr_waiting 1
[  599.119332] barrier_waiting: nr_waiting 1
[  599.123809] barrier_waiting: nr_waiting 1
[  599.128293] barrier_waiting: nr_waiting 1
[  599.132765] barrier_waiting: nr_waiting 1
[  599.137242] barrier_waiting: nr_waiting 1
[  599.141723] barrier_waiting: nr_waiting 1
[  599.146203] barrier_waiting: nr_waiting 1
[  599.150682] barrier_waiting: nr_waiting 1
[  599.155165] barrier_waiting: nr_waiting 1
[  599.159644] barrier_waiting: nr_waiting 1
[  599.164124] barrier_waiting: nr_waiting 1
[  599.168603] barrier_waiting: nr_waiting 1
[  599.173080] barrier_waiting: nr_waiting 1
[  599.177564] barrier_waiting: nr_waiting 1
[  599.182043] barrier_waiting: nr_waiting 1
[  599.186525] barrier_waiting: nr_waiting 1
[  599.191008] barrier_waiting: nr_waiting 1
[  599.195488] barrier_waiting: nr_waiting 1
[  599.199967] barrier_waiting: nr_waiting 1
[  599.204448] barrier_waiting: nr_waiting 1
[  599.208928] barrier_waiting: nr_waiting 1
[  599.213408] barrier_waiting: nr_waiting 1
[  599.217890] barrier_waiting: nr_waiting 1
[  599.222370] barrier_waiting: nr_waiting 1
[  599.226850] barrier_waiting: nr_waiting 1
[  599.231329] barrier_waiting: nr_waiting 1
[  599.235811] barrier_waiting: nr_waiting 1
[  599.240289] barrier_waiting: nr_waiting 1
[  599.244767] barrier_waiting: nr_waiting 1
[  599.249247] barrier_waiting: nr_waiting 1
[  599.253731] barrier_waiting: nr_waiting 1
[  599.258212] barrier_waiting: nr_waiting 1
[  599.262691] barrier_waiting: nr_waiting 1
[  599.267170] barrier_waiting: nr_waiting 1
[  599.271650] barrier_waiting: nr_waiting 1
[  599.276128] barrier_waiting: nr_waiting 1
[  599.280606] barrier_waiting: nr_waiting 1
[  599.285084] barrier_waiting: nr_waiting 1
[  599.289569] barrier_waiting: nr_waiting 1
[  599.294040] barrier_waiting: nr_waiting 1
[  599.298522] barrier_waiting: nr_waiting 1
[  599.303006] barrier_waiting: nr_waiting 1
[  599.307483] barrier_waiting: nr_waiting 1
[  599.311961] barrier_waiting: nr_waiting 1
[  599.316442] barrier_waiting: nr_waiting 1
[  599.320923] barrier_waiting: nr_waiting 1
[  599.325403] barrier_waiting: nr_waiting 1
[  599.329884] barrier_waiting: nr_waiting 1
[  599.334363] barrier_waiting: nr_waiting 1
[  599.338842] barrier_waiting: nr_waiting 1
[  599.343322] barrier_waiting: nr_waiting 1
[  599.347801] barrier_waiting: nr_waiting 1
[  599.352282] barrier_waiting: nr_waiting 1
[  599.356762] barrier_waiting: nr_waiting 1
[  599.361246] barrier_waiting: nr_waiting 1
[  599.365727] barrier_waiting: nr_waiting 1
[  599.370206] barrier_waiting: nr_waiting 1
[  599.374685] barrier_waiting: nr_waiting 1
[  599.379166] barrier_waiting: nr_waiting 1
[  599.383647] barrier_waiting: nr_waiting 1
[  599.388125] barrier_waiting: nr_waiting 1
[  599.392605] barrier_waiting: nr_waiting 1
[  599.397083] barrier_waiting: nr_waiting 1
[  599.401562] barrier_waiting: nr_waiting 1
[  599.406044] barrier_waiting: nr_waiting 1
[  599.410525] barrier_waiting: nr_waiting 1
[  599.415008] barrier_waiting: nr_waiting 1
[  599.419486] barrier_waiting: nr_waiting 1
[  599.423968] barrier_waiting: nr_waiting 1
[  599.428446] barrier_waiting: nr_waiting 1
[  599.432924] barrier_waiting: nr_waiting 1
[  599.437409] barrier_waiting: nr_waiting 1
[  599.441890] barrier_waiting: nr_waiting 1
[  599.446373] barrier_waiting: nr_waiting 1
[  599.450859] barrier_waiting: nr_waiting 1
[  599.455337] barrier_waiting: nr_waiting 1
[  599.459819] barrier_waiting: nr_waiting 1
[  599.464306] barrier_waiting: nr_waiting 1
[  599.468783] barrier_waiting: nr_waiting 1
[  599.473262] barrier_waiting: nr_waiting 1
[  599.477744] barrier_waiting: nr_waiting 1
[  599.482224] barrier_waiting: nr_waiting 1
[  599.486704] barrier_waiting: nr_waiting 1
[  599.491190] barrier_waiting: nr_waiting 1
[  599.495670] barrier_waiting: nr_waiting 1
[  599.500150] barrier_waiting: nr_waiting 1
[  599.504629] barrier_waiting: nr_waiting 1
[  599.509106] barrier_waiting: nr_waiting 1
[  599.513588] barrier_waiting: nr_waiting 1
[  599.518072] barrier_waiting: nr_waiting 1
[  599.522552] barrier_waiting: nr_waiting 1
[  599.527030] barrier_waiting: nr_waiting 1
[  599.531509] barrier_waiting: nr_waiting 1
[  599.535988] barrier_waiting: nr_waiting 1
[  599.540470] barrier_waiting: nr_waiting 1
[  599.544955] barrier_waiting: nr_waiting 1
[  599.549426] barrier_waiting: nr_waiting 1
[  599.553904] barrier_waiting: nr_waiting 1
[  599.558384] barrier_waiting: nr_waiting 1
[  599.562863] barrier_waiting: nr_waiting 1
[  599.567342] barrier_waiting: nr_waiting 1
[  599.571820] barrier_waiting: nr_waiting 1
[  599.576298] barrier_waiting: nr_waiting 1
[  599.580779] barrier_waiting: nr_waiting 1
[  599.585254] wait_barrier: nr_pending: 1
[  599.589540] try_raise_barrier: nr_pending 1
[  599.589547] raid10_read_request: r10_bio ff3b41340eb53600 start
[  599.594209] try_raise_barrier: nr_pending 1
[  599.605582] try_raise_barrier: nr_pending 1
[  599.605674] allow_barrier: nr_pending: 0
[  599.610620] wait_barrier: nr_pending: 1
[  599.614653] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  599.618935] try_raise_barrier: nr_pending 1
[  599.618938] try_raise_barrier: nr_pending 1
[  599.618965] raid10_read_request: r10_bio ff3b4134184a6100 start
[  599.641092] try_raise_barrier: nr_pending 1
[  599.641145] allow_barrier: nr_pending: 0
[  599.646251] wait_barrier: nr_pending: 1
[  599.650157] raid_end_bio_io: r10_bio ff3b4134184a6100 done
[  599.654437] try_raise_barrier: nr_pending 1
[  599.654446] raid10_read_request: r10_bio ff3b41340eb53900 start
[  599.654575] allow_barrier: nr_pending: 0
[  599.654583] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  599.682715] wait_barrier: nr_pending: 1
[  599.687000] try_raise_barrier: nr_pending 1
[  599.687012] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  599.691672] try_raise_barrier: nr_pending 1
[  599.703020] try_raise_barrier: nr_pending 1
[  599.703069] allow_barrier: nr_pending: 0
[  599.708037] wait_barrier: nr_pending: 1
[  599.712092] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  599.716368] try_raise_barrier: nr_pending 1
[  599.716372] try_raise_barrier: nr_pending 1
[  599.716377] raid10_read_request: r10_bio ff3b41340eb53900 start
[  599.738510] try_raise_barrier: nr_pending 1
[  599.738554] allow_barrier: nr_pending: 0
[  599.743663] wait_barrier: nr_pending: 1
[  599.747583] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  599.751853] try_raise_barrier: nr_pending 1
[  599.751857] try_raise_barrier: nr_pending 1
[  599.751864] raid10_read_request: r10_bio ff3b41340eb53600 start
[  599.773945] try_raise_barrier: nr_pending 1
[  599.774058] allow_barrier: nr_pending: 0
[  599.779116] wait_barrier: nr_pending: 1
[  599.783020] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  599.787298] try_raise_barrier: nr_pending 1
[  599.787307] raid10_read_request: r10_bio ff3b41340eb53900 start
[  599.787461] allow_barrier: nr_pending: 0
[  599.787469] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  599.815585] wait_barrier: nr_pending: 1
[  599.819872] try_raise_barrier: nr_pending 1
[  599.819883] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  599.824546] try_raise_barrier: nr_pending 1
[  599.835892] try_raise_barrier: nr_pending 1
[  599.835904] allow_barrier: nr_pending: 0
[  599.840922] wait_barrier: nr_pending: 1
[  599.844957] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  599.849235] try_raise_barrier: nr_pending 1
[  599.849239] try_raise_barrier: nr_pending 1
[  599.849244] raid10_read_request: r10_bio ff3b41340eb53600 start
[  599.871381] try_raise_barrier: nr_pending 1
[  599.871463] allow_barrier: nr_pending: 0
[  599.876542] wait_barrier: nr_pending: 1
[  599.880451] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  599.884730] try_raise_barrier: nr_pending 1
[  599.884735] try_raise_barrier: nr_pending 1
[  599.884740] raid10_read_request: r10_bio ff3b41340eb53900 start
[  599.884889] allow_barrier: nr_pending: 0
[  599.884897] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  599.917789] wait_barrier: nr_pending: 1
[  599.922088] raid10_read_request: r10_bio ff3b41340eb53900 start
[  599.922159] try_raise_barrier: nr_pending 1
[  599.928829] allow_barrier: nr_pending: 0
[  599.933736] wait_barrier: nr_pending: 1
[  599.937771] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  599.942045] try_raise_barrier: nr_pending 1
[  599.942049] try_raise_barrier: nr_pending 1
[  599.942058] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  599.964202] try_raise_barrier: nr_pending 1
[  599.964262] allow_barrier: nr_pending: 0
[  599.969461] wait_barrier: nr_pending: 1
[  599.973275] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  599.977553] try_raise_barrier: nr_pending 1
[  599.977559] try_raise_barrier: nr_pending 1
[  599.977562] raid10_read_request: r10_bio ff3b41340eb53900 start
[  599.977715] allow_barrier: nr_pending: 0
[  599.977723] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.010600] wait_barrier: nr_pending: 1
[  600.014887] try_raise_barrier: nr_pending 1
[  600.014898] raid10_read_request: r10_bio ff3b41340eb53600 start
[  600.019559] try_raise_barrier: nr_pending 1
[  600.030909] try_raise_barrier: nr_pending 1
[  600.030917] allow_barrier: nr_pending: 0
[  600.036049] wait_barrier: nr_pending: 1
[  600.039974] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  600.044253] try_raise_barrier: nr_pending 1
[  600.044257] try_raise_barrier: nr_pending 1
[  600.044263] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  600.066363] try_raise_barrier: nr_pending 1
[  600.066461] allow_barrier: nr_pending: 0
[  600.071440] wait_barrier: nr_pending: 1
[  600.075443] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  600.079722] try_raise_barrier: nr_pending 1
[  600.079727] try_raise_barrier: nr_pending 1
[  600.079731] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.079868] allow_barrier: nr_pending: 0
[  600.079875] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.112682] wait_barrier: nr_pending: 1
[  600.116967] try_raise_barrier: nr_pending 1
[  600.116978] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.121640] try_raise_barrier: nr_pending 1
[  600.132990] try_raise_barrier: nr_pending 1
[  600.133057] allow_barrier: nr_pending: 0
[  600.138070] wait_barrier: nr_pending: 1
[  600.142062] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.146337] try_raise_barrier: nr_pending 1
[  600.146342] try_raise_barrier: nr_pending 1
[  600.146348] raid10_read_request: r10_bio ff3b41340eb53600 start
[  600.168487] try_raise_barrier: nr_pending 1
[  600.168532] allow_barrier: nr_pending: 0
[  600.173662] wait_barrier: nr_pending: 1
[  600.177563] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  600.181840] try_raise_barrier: nr_pending 1
[  600.181845] try_raise_barrier: nr_pending 1
[  600.181849] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.181983] allow_barrier: nr_pending: 0
[  600.181991] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.214790] wait_barrier: nr_pending: 1
[  600.219075] try_raise_barrier: nr_pending 1
[  600.219087] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  600.223748] try_raise_barrier: nr_pending 1
[  600.235099] try_raise_barrier: nr_pending 1
[  600.235150] allow_barrier: nr_pending: 0
[  600.240130] wait_barrier: nr_pending: 1
[  600.244170] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  600.248446] try_raise_barrier: nr_pending 1
[  600.248450] try_raise_barrier: nr_pending 1
[  600.248456] raid10_read_request: r10_bio ff3b41340eb53600 start
[  600.270600] try_raise_barrier: nr_pending 1
[  600.270648] allow_barrier: nr_pending: 0
[  600.275752] wait_barrier: nr_pending: 1
[  600.279676] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  600.283952] try_raise_barrier: nr_pending 1
[  600.283956] try_raise_barrier: nr_pending 1
[  600.283961] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.284093] allow_barrier: nr_pending: 0
[  600.284100] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.316975] wait_barrier: nr_pending: 1
[  600.321262] try_raise_barrier: nr_pending 1
[  600.321273] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.325936] try_raise_barrier: nr_pending 1
[  600.337279] allow_barrier: nr_pending: 0
[  600.337649] wait_barrier: nr_pending: 1
[  600.341674] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.345947] try_raise_barrier: nr_pending 1
[  600.345951] try_raise_barrier: nr_pending 1
[  600.345958] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  600.368088] try_raise_barrier: nr_pending 1
[  600.368129] allow_barrier: nr_pending: 0
[  600.373070] wait_barrier: nr_pending: 1
[  600.377153] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  600.381430] try_raise_barrier: nr_pending 1
[  600.381434] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.381555] allow_barrier: nr_pending: 0
[  600.381562] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.409730] wait_barrier: nr_pending: 1
[  600.414012] try_raise_barrier: nr_pending 1
[  600.414015] raid10_read_request: r10_bio ff3b41340eb53600 start
[  600.418685] try_raise_barrier: nr_pending 1
[  600.430034] try_raise_barrier: nr_pending 1
[  600.430085] allow_barrier: nr_pending: 0
[  600.435126] wait_barrier: nr_pending: 1
[  600.439107] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  600.443388] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  600.443462] try_raise_barrier: nr_pending 1
[  600.443466] try_raise_barrier: nr_pending 1
[  600.465548] try_raise_barrier: nr_pending 1
[  600.465585] allow_barrier: nr_pending: 0
[  600.470613] wait_barrier: nr_pending: 1
[  600.474627] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  600.478903] try_raise_barrier: nr_pending 1
[  600.478910] try_raise_barrier: nr_pending 1
[  600.478912] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.479045] allow_barrier: nr_pending: 0
[  600.479053] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.511838] wait_barrier: nr_pending: 1
[  600.516124] try_raise_barrier: nr_pending 1
[  600.516135] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.520797] try_raise_barrier: nr_pending 1
[  600.532156] try_raise_barrier: nr_pending 1
[  600.532225] allow_barrier: nr_pending: 0
[  600.537288] wait_barrier: nr_pending: 1
[  600.541229] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.545505] try_raise_barrier: nr_pending 1
[  600.545509] try_raise_barrier: nr_pending 1
[  600.545515] raid10_read_request: r10_bio ff3b41340eb53600 start
[  600.567662] try_raise_barrier: nr_pending 1
[  600.567696] allow_barrier: nr_pending: 0
[  600.572778] wait_barrier: nr_pending: 1
[  600.576742] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  600.581017] try_raise_barrier: nr_pending 1
[  600.581023] try_raise_barrier: nr_pending 1
[  600.581028] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.581145] allow_barrier: nr_pending: 0
[  600.581152] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.613893] wait_barrier: nr_pending: 1
[  600.618178] try_raise_barrier: nr_pending 1
[  600.618188] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  600.622851] try_raise_barrier: nr_pending 1
[  600.634242] try_raise_barrier: nr_pending 1
[  600.634317] allow_barrier: nr_pending: 0
[  600.639159] wait_barrier: nr_pending: 1
[  600.643299] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  600.647575] try_raise_barrier: nr_pending 1
[  600.647579] raid10_read_request: r10_bio ff3b41340eb53600 start
[  600.647579] try_raise_barrier: nr_pending 1
[  600.647633] allow_barrier: nr_pending: 0
[  600.647637] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  600.680526] wait_barrier: nr_pending: 1
[  600.684819] try_raise_barrier: nr_pending 1
[  600.684841] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.689492] try_raise_barrier: nr_pending 1
[  600.700853] try_raise_barrier: nr_pending 1
[  600.700910] allow_barrier: nr_pending: 0
[  600.706030] wait_barrier: nr_pending: 1
[  600.709914] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.714193] try_raise_barrier: nr_pending 1
[  600.714197] try_raise_barrier: nr_pending 1
[  600.714205] raid10_read_request: r10_bio ff3b4134184a6100 start
[  600.714376] allow_barrier: nr_pending: 0
[  600.714383] raid_end_bio_io: r10_bio ff3b4134184a6100 done
[  600.747144] wait_barrier: nr_pending: 1
[  600.751430] try_raise_barrier: nr_pending 1
[  600.751442] raid10_read_request: r10_bio ff3b4134184a6b00 start
[  600.756102] try_raise_barrier: nr_pending 1
[  600.767448] try_raise_barrier: nr_pending 1
[  600.767537] allow_barrier: nr_pending: 0
[  600.772502] wait_barrier: nr_pending: 1
[  600.776516] raid_end_bio_io: r10_bio ff3b4134184a6b00 done
[  600.780795] try_raise_barrier: nr_pending 1
[  600.780799] try_raise_barrier: nr_pending 1
[  600.780808] raid10_read_request: r10_bio ff3b4134184a7f00 start
[  600.802876] try_raise_barrier: nr_pending 1
[  600.803016] allow_barrier: nr_pending: 0
[  600.808000] wait_barrier: nr_pending: 1
[  600.811943] raid_end_bio_io: r10_bio ff3b4134184a7f00 done
[  600.816225] try_raise_barrier: nr_pending 1
[  600.816229] try_raise_barrier: nr_pending 1
[  600.816245] raid10_read_request: r10_bio ff3b4134184a7400 start
[  600.838385] try_raise_barrier: nr_pending 1
[  600.838448] allow_barrier: nr_pending: 0
[  600.843556] wait_barrier: nr_pending: 1
[  600.847451] raid_end_bio_io: r10_bio ff3b4134184a7400 done
[  600.851722] try_raise_barrier: nr_pending 1
[  600.851726] try_raise_barrier: nr_pending 1
[  600.851732] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.851897] allow_barrier: nr_pending: 0
[  600.851904] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.884632] wait_barrier: nr_pending: 1
[  600.888917] try_raise_barrier: nr_pending 1
[  600.888929] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.893588] try_raise_barrier: nr_pending 1
[  600.904881] try_raise_barrier: nr_pending 1
[  600.905028] allow_barrier: nr_pending: 0
[  600.909930] wait_barrier: nr_pending: 1
[  600.913958] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  600.918233] try_raise_barrier: nr_pending 1
[  600.918237] try_raise_barrier: nr_pending 1
[  600.918245] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  600.940401] try_raise_barrier: nr_pending 1
[  600.940502] allow_barrier: nr_pending: 0
[  600.945589] wait_barrier: nr_pending: 1
[  600.949477] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  600.953755] try_raise_barrier: nr_pending 1
[  600.953760] try_raise_barrier: nr_pending 1
[  600.953765] raid10_read_request: r10_bio ff3b41340eb53600 start
[  600.953893] allow_barrier: nr_pending: 0
[  600.953901] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  600.986653] wait_barrier: nr_pending: 1
[  600.990939] try_raise_barrier: nr_pending 1
[  600.990949] raid10_read_request: r10_bio ff3b41340eb53900 start
[  600.995611] try_raise_barrier: nr_pending 1
[  601.006963] try_raise_barrier: nr_pending 1
[  601.007109] allow_barrier: nr_pending: 0
[  601.011808] wait_barrier: nr_pending: 1
[  601.016031] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  601.020309] try_raise_barrier: nr_pending 1
[  601.020313] try_raise_barrier: nr_pending 1
[  601.020319] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  601.042453] allow_barrier: nr_pending: 0
[  601.042803] wait_barrier: nr_pending: 1
[  601.046853] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  601.051120] try_raise_barrier: nr_pending 1
[  601.051125] raid10_read_request: r10_bio ff3b41340eb53600 start
[  601.051126] try_raise_barrier: nr_pending 1
[  601.051145] try_raise_barrier: nr_pending 1
[  601.051415] allow_barrier: nr_pending: 0
[  601.051422] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  601.088815] wait_barrier: nr_pending: 1
[  601.093099] try_raise_barrier: nr_pending 1
[  601.093111] raid10_read_request: r10_bio ff3b41340eb53900 start
[  601.097772] try_raise_barrier: nr_pending 1
[  601.109103] try_raise_barrier: nr_pending 1
[  601.109172] allow_barrier: nr_pending: 0
[  601.114259] wait_barrier: nr_pending: 1
[  601.118177] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  601.122446] try_raise_barrier: nr_pending 1
[  601.122450] try_raise_barrier: nr_pending 1
[  601.122459] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  601.144607] try_raise_barrier: nr_pending 1
[  601.144650] allow_barrier: nr_pending: 0
[  601.149688] wait_barrier: nr_pending: 1
[  601.153683] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  601.157960] try_raise_barrier: nr_pending 1
[  601.157964] try_raise_barrier: nr_pending 1
[  601.157970] raid10_read_request: r10_bio ff3b41340eb53600 start
[  601.180129] try_raise_barrier: nr_pending 1
[  601.180240] allow_barrier: nr_pending: 0
[  601.185207] wait_barrier: nr_pending: 1
[  601.189209] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  601.193485] try_raise_barrier: nr_pending 1
[  601.193497] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  601.193706] allow_barrier: nr_pending: 0
[  601.193714] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  601.221868] wait_barrier: nr_pending: 1
[  601.226153] try_raise_barrier: nr_pending 1
[  601.226164] raid10_read_request: r10_bio ff3b41340eb53900 start
[  601.230826] try_raise_barrier: nr_pending 1
[  601.242175] try_raise_barrier: nr_pending 1
[  601.242239] allow_barrier: nr_pending: 0
[  601.247321] wait_barrier: nr_pending: 1
[  601.251249] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  601.255526] try_raise_barrier: nr_pending 1
[  601.255530] try_raise_barrier: nr_pending 1
[  601.255536] raid10_read_request: r10_bio ff3b41340eb53600 start
[  601.277688] try_raise_barrier: nr_pending 1
[  601.277818] allow_barrier: nr_pending: 0
[  601.282730] wait_barrier: nr_pending: 1
[  601.286761] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  601.291037] try_raise_barrier: nr_pending 1
[  601.291043] try_raise_barrier: nr_pending 1
[  601.291047] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  601.313190] try_raise_barrier: nr_pending 1
[  601.313248] allow_barrier: nr_pending: 0
[  601.318267] wait_barrier: nr_pending: 1
[  601.322269] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  601.326544] try_raise_barrier: nr_pending 1
[  601.326551] try_raise_barrier: nr_pending 1
[  601.326556] raid10_read_request: r10_bio ff3b41340eb53600 start
[  601.326708] allow_barrier: nr_pending: 0
[  601.326716] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  601.359595] wait_barrier: nr_pending: 1
[  601.363882] try_raise_barrier: nr_pending 1
[  601.363893] raid10_read_request: r10_bio ff3b41340eb53900 start
[  601.368556] try_raise_barrier: nr_pending 1
[  601.379906] try_raise_barrier: nr_pending 1
[  601.379973] allow_barrier: nr_pending: 0
[  601.385040] wait_barrier: nr_pending: 1
[  601.388979] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  601.393255] try_raise_barrier: nr_pending 1
[  601.393260] try_raise_barrier: nr_pending 1
[  601.393268] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  601.415361] try_raise_barrier: nr_pending 1
[  601.415483] allow_barrier: nr_pending: 0
[  601.420443] wait_barrier: nr_pending: 1
[  601.424436] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  601.428713] try_raise_barrier: nr_pending 1
[  601.428716] try_raise_barrier: nr_pending 1
[  601.428723] raid10_read_request: r10_bio ff3b41340eb53600 start
[  601.450871] try_raise_barrier: nr_pending 1
[  601.450916] allow_barrier: nr_pending: 0
[  601.455878] wait_barrier: nr_pending: 1
[  601.459951] raid_end_bio_io: r10_bio ff3b41340eb53600 done
[  601.464227] try_raise_barrier: nr_pending 1
[  601.464231] raid10_read_request: r10_bio ff3b41340eb52d00 start
[  601.481634] try_raise_barrier: nr_pending 1
[  601.486439] allow_barrier: nr_pending: 0
[  601.486947] wait_barrier: nr_pending: 1
[  601.490841] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
[  601.495112] try_raise_barrier: nr_pending 1
[  601.495116] try_raise_barrier: nr_pending 1
[  601.495122] raid10_read_request: r10_bio ff3b41340eb53900 start
[  601.517260] try_raise_barrier: nr_pending 1
[  601.517346] allow_barrier: nr_pending: 0
[  601.522456] wait_barrier: nr_pending: 1
[  601.526326] raid_end_bio_io: r10_bio ff3b41340eb53900 done
[  601.530603] try_raise_barrier: nr_pending 1
[  601.530608] try_raise_barrier: nr_pending 1
[  601.530612] raid10_write_request: r10_bio ff3b41340eb52d00 start
[  601.552782] try_raise_barrier: nr_pending 1
[  737.970751] INFO: task mdX_resync:3115 blocked for more than 122 seconds.
[  737.978361]       Not tainted 6.9.0+ #1
[  737.982654] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[  737.991398] task:mdX_resync      state:D stack:0     pid:3115
tgid:3115  ppid:2      flags:0x00004000
[  737.991407] Call Trace:
[  737.991410]  <TASK>
[  737.991414]  __schedule+0x222/0x670
[  737.991426]  schedule+0x2c/0xb0
[  737.991434]  raise_barrier+0xca/0x1a0 [raid10]
[  737.991450]  ? __pfx_autoremove_wake_function+0x10/0x10
[  737.991459]  raid10_sync_request+0x2c3/0x19d0 [raid10]
[  737.991472]  ? __switch_to_asm+0x39/0x70
[  737.991478]  ? finish_task_switch.isra.0+0x8e/0x2a0
[  737.991487]  ? __schedule+0x22a/0x670
[  737.991491]  ? prepare_to_wait_event+0x5f/0x190
[  737.991498]  md_do_sync+0x660/0x1040
[  737.991508]  ? __pfx_autoremove_wake_function+0x10/0x10
[  737.991517]  md_thread+0xad/0x160
[  737.991521]  ? __pfx_md_thread+0x10/0x10
[  737.991524]  kthread+0xdc/0x110
[  737.991531]  ? __pfx_kthread+0x10/0x10
[  737.991535]  ret_from_fork+0x2d/0x50
[  737.991544]  ? __pfx_kthread+0x10/0x10
[  737.991547]  ret_from_fork_asm+0x1a/0x30
[  737.991553]  </TASK>
[  860.850998] INFO: task mdX_resync:3115 blocked for more than 245 seconds.
[  860.858606]       Not tainted 6.9.0+ #1
[  860.862902] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[  860.871649] task:mdX_resync      state:D stack:0     pid:3115
tgid:3115  ppid:2      flags:0x00004000
[  860.871658] Call Trace:
[  860.871660]  <TASK>
[  860.871664]  __schedule+0x222/0x670
[  860.871674]  schedule+0x2c/0xb0
[  860.871681]  raise_barrier+0xca/0x1a0 [raid10]
[  860.871696]  ? __pfx_autoremove_wake_function+0x10/0x10
[  860.871704]  raid10_sync_request+0x2c3/0x19d0 [raid10]
[  860.871717]  ? __switch_to_asm+0x39/0x70
[  860.871722]  ? finish_task_switch.isra.0+0x8e/0x2a0
[  860.871729]  ? __schedule+0x22a/0x670
[  860.871733]  ? prepare_to_wait_event+0x5f/0x190
[  860.871740]  md_do_sync+0x660/0x1040
[  860.871748]  ? __pfx_autoremove_wake_function+0x10/0x10
[  860.871756]  md_thread+0xad/0x160
[  860.871761]  ? __pfx_md_thread+0x10/0x10
[  860.871765]  kthread+0xdc/0x110
[  860.871770]  ? __pfx_kthread+0x10/0x10
[  860.871774]  ret_from_fork+0x2d/0x50
[  860.871781]  ? __pfx_kthread+0x10/0x10
[  860.871785]  ret_from_fork_asm+0x1a/0x30
[  860.871790]  </TASK>

Thanks,
Changhui

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Yu Kuai]

Hi,

在 2024/05/21 12:28, Changhui Zhong 写道:
> On Tue, May 21, 2024 at 9:09 AM Yu Kuai <yukuai1@huaweicloud.com> wrote:
> 
>>
>> Thanks for the test! Since raid10 has the same problem as well, then the
>> problem seems to be more common in raid. And related code to raid10 is
>> more simpler, attached is a patch to add debuginfo to raid10.
>>
>> BTW, Xiao can reporduce the problem as well, and will lend a hand as
>> well.
>>
>> Thanks,
>> Kuai
> 
> 
> Hi, Yu Kuai and Xiao
> 
> thanks for  efforts on this issue，
> after applying the debug patch, I got the following results, please check it
> 
> [  597.491083] Create raid10
> [  597.647987] device-mapper: raid: Superblocks created for new raid set
> [  597.680540] md/raid10:mdX: not clean -- starting background reconstruction
> [  597.680549] md/raid10:mdX: active with 4 out of 4 devices
> [  597.683779] mdX: bitmap file is out of date, doing full recovery
> [  597.692971] md: resync of RAID array mdX
> [  597.753583] try_raise_barrier: resync depth exceed limit
> [  597.759540] try_raise_barrier: resync depth exceed limit
> [  597.765504] try_raise_barrier: resync depth exceed limit
> [  597.771432] try_raise_barrier: resync depth exceed limit
> [  597.779400] barrier_waiting: nr_waiting 1
> [  597.783879] barrier_waiting: nr_waiting 1
> [  597.788356] barrier_waiting: nr_waiting 1
> [  597.792838] barrier_waiting: nr_waiting 1
> [  597.797327] barrier_waiting: nr_waiting 1
> [  597.801806] barrier_waiting: nr_waiting 1
> [  597.806288] barrier_waiting: nr_waiting 1
> [  597.810780] barrier_waiting: nr_waiting 1
> [  597.815252] barrier_waiting: nr_waiting 1
> [  597.819737] barrier_waiting: nr_waiting 1
> [  597.824232] barrier_waiting: nr_waiting 1
> [  597.828714] barrier_waiting: nr_waiting 1
> [  597.833196] barrier_waiting: nr_waiting 1
> [  597.837678] barrier_waiting: nr_waiting 1
> [  597.842160] barrier_waiting: nr_waiting 1
> [  597.846640] barrier_waiting: nr_waiting 1
> [  597.851128] barrier_waiting: nr_waiting 1
> [  597.855610] barrier_waiting: nr_waiting 1
> [  597.860094] barrier_waiting: nr_waiting 1
> [  597.864576] barrier_waiting: nr_waiting 1
> [  597.869060] barrier_waiting: nr_waiting 1
> [  597.873548] barrier_waiting: nr_waiting 1
> [  597.878032] barrier_waiting: nr_waiting 1
> [  597.882522] barrier_waiting: nr_waiting 1
> [  597.883457] barrier_waiting: nr_waiting 1
> [  597.891503] barrier_waiting: nr_waiting 1
> [  597.895987] barrier_waiting: nr_waiting 1
> [  597.900459] barrier_waiting: nr_waiting 1
> [  597.904940] barrier_waiting: nr_waiting 1
> [  597.909421] barrier_waiting: nr_waiting 1
> [  597.913900] barrier_waiting: nr_waiting 1
> [  597.918377] barrier_waiting: nr_waiting 1
> [  597.922857] barrier_waiting: nr_waiting 1
> [  597.927350] barrier_waiting: nr_waiting 1
> [  597.931841] barrier_waiting: nr_waiting 1
> [  597.936322] barrier_waiting: nr_waiting 1
> [  597.940805] barrier_waiting: nr_waiting 1
> [  597.945284] barrier_waiting: nr_waiting 1
> [  597.949766] barrier_waiting: nr_waiting 1
> [  597.954246] barrier_waiting: nr_waiting 1
> [  597.958726] barrier_waiting: nr_waiting 1
> [  597.963205] barrier_waiting: nr_waiting 1
> [  597.967683] barrier_waiting: nr_waiting 1
> [  597.972163] barrier_waiting: nr_waiting 1
> [  597.976641] barrier_waiting: nr_waiting 1
> [  597.981119] barrier_waiting: nr_waiting 1
> [  597.985601] barrier_waiting: nr_waiting 1
> [  597.990082] barrier_waiting: nr_waiting 1
> [  597.994562] barrier_waiting: nr_waiting 1
> [  597.999043] barrier_waiting: nr_waiting 1
> [  598.003522] barrier_waiting: nr_waiting 1
> [  598.008000] barrier_waiting: nr_waiting 1
> [  598.012485] barrier_waiting: nr_waiting 1
> [  598.016964] barrier_waiting: nr_waiting 1
> [  598.021451] barrier_waiting: nr_waiting 1
> [  598.025931] barrier_waiting: nr_waiting 1
> [  598.030409] barrier_waiting: nr_waiting 1
> [  598.034888] barrier_waiting: nr_waiting 1
> [  598.039368] barrier_waiting: nr_waiting 1
> [  598.043848] barrier_waiting: nr_waiting 1
> [  598.048325] barrier_waiting: nr_waiting 1
> [  598.052805] barrier_waiting: nr_waiting 1
> [  598.057283] barrier_waiting: nr_waiting 1
> [  598.061767] barrier_waiting: nr_waiting 1
> [  598.066246] barrier_waiting: nr_waiting 1
> [  598.070726] barrier_waiting: nr_waiting 1
> [  598.075206] barrier_waiting: nr_waiting 1
> [  598.079689] barrier_waiting: nr_waiting 1
> [  598.084170] barrier_waiting: nr_waiting 1
> [  598.088648] barrier_waiting: nr_waiting 1
> [  598.093130] barrier_waiting: nr_waiting 1
> [  598.097646] barrier_waiting: nr_waiting 1
> [  598.102126] barrier_waiting: nr_waiting 1
> [  598.106605] barrier_waiting: nr_waiting 1
> [  598.111085] barrier_waiting: nr_waiting 1
> [  598.115566] barrier_waiting: nr_waiting 1
> [  598.120043] barrier_waiting: nr_waiting 1
> [  598.124522] barrier_waiting: nr_waiting 1
> [  598.129001] barrier_waiting: nr_waiting 1
> [  598.133481] barrier_waiting: nr_waiting 1
> [  598.137958] barrier_waiting: nr_waiting 1
> [  598.142442] barrier_waiting: nr_waiting 1
> [  598.146921] barrier_waiting: nr_waiting 1
> [  598.151400] barrier_waiting: nr_waiting 1
> [  598.155878] barrier_waiting: nr_waiting 1
> [  598.160359] barrier_waiting: nr_waiting 1
> [  598.164838] barrier_waiting: nr_waiting 1
> [  598.169319] barrier_waiting: nr_waiting 1
> [  598.173803] barrier_waiting: nr_waiting 1
> [  598.178282] barrier_waiting: nr_waiting 1
> [  598.182762] barrier_waiting: nr_waiting 1
> [  598.187241] barrier_waiting: nr_waiting 1
> [  598.191722] barrier_waiting: nr_waiting 1
> [  598.196201] barrier_waiting: nr_waiting 1
> [  598.200678] barrier_waiting: nr_waiting 1
> [  598.205159] barrier_waiting: nr_waiting 1
> [  598.209640] barrier_waiting: nr_waiting 1
> [  598.214120] barrier_waiting: nr_waiting 1
> [  598.218599] barrier_waiting: nr_waiting 1
> [  598.223078] barrier_waiting: nr_waiting 1
> [  598.227557] barrier_waiting: nr_waiting 1
> [  598.232036] barrier_waiting: nr_waiting 1
> [  598.236519] barrier_waiting: nr_waiting 1
> [  598.240999] barrier_waiting: nr_waiting 1
> [  598.245478] barrier_waiting: nr_waiting 1
> [  598.249959] barrier_waiting: nr_waiting 1
> [  598.254439] barrier_waiting: nr_waiting 1
> [  598.258917] barrier_waiting: nr_waiting 1
> [  598.263397] barrier_waiting: nr_waiting 1
> [  598.267880] barrier_waiting: nr_waiting 1
> [  598.272362] barrier_waiting: nr_waiting 1
> [  598.276842] barrier_waiting: nr_waiting 1
> [  598.281322] barrier_waiting: nr_waiting 1
> [  598.285802] barrier_waiting: nr_waiting 1
> [  598.290281] barrier_waiting: nr_waiting 1
> [  598.294758] barrier_waiting: nr_waiting 1
> [  598.299256] barrier_waiting: nr_waiting 1
> [  598.303737] barrier_waiting: nr_waiting 1
> [  598.308219] barrier_waiting: nr_waiting 1
> [  598.312698] barrier_waiting: nr_waiting 1
> [  598.317176] barrier_waiting: nr_waiting 1
> [  598.321659] barrier_waiting: nr_waiting 1
> [  598.326138] barrier_waiting: nr_waiting 1
> [  598.330617] barrier_waiting: nr_waiting 1
> [  598.335100] barrier_waiting: nr_waiting 1
> [  598.339580] barrier_waiting: nr_waiting 1
> [  598.344057] barrier_waiting: nr_waiting 1
> [  598.348536] barrier_waiting: nr_waiting 1
> [  598.353016] barrier_waiting: nr_waiting 1
> [  598.357496] barrier_waiting: nr_waiting 1
> [  598.361973] barrier_waiting: nr_waiting 1
> [  598.366453] barrier_waiting: nr_waiting 1
> [  598.370932] barrier_waiting: nr_waiting 1
> [  598.375412] barrier_waiting: nr_waiting 1
> [  598.379890] barrier_waiting: nr_waiting 1
> [  598.384371] barrier_waiting: nr_waiting 1
> [  598.388856] barrier_waiting: nr_waiting 1
> [  598.393326] barrier_waiting: nr_waiting 1
> [  598.397805] barrier_waiting: nr_waiting 1
> [  598.402288] barrier_waiting: nr_waiting 1
> [  598.406772] barrier_waiting: nr_waiting 1
> [  598.411251] barrier_waiting: nr_waiting 1
> [  598.415729] barrier_waiting: nr_waiting 1
> [  598.420209] barrier_waiting: nr_waiting 1
> [  598.424686] barrier_waiting: nr_waiting 1
> [  598.429165] barrier_waiting: nr_waiting 1
> [  598.433644] barrier_waiting: nr_waiting 1
> [  598.438125] barrier_waiting: nr_waiting 1
> [  598.442604] barrier_waiting: nr_waiting 1
> [  598.447083] barrier_waiting: nr_waiting 1
> [  598.451571] barrier_waiting: nr_waiting 1
> [  598.456050] barrier_waiting: nr_waiting 1
> [  598.460531] barrier_waiting: nr_waiting 1
> [  598.465010] barrier_waiting: nr_waiting 1
> [  598.469498] barrier_waiting: nr_waiting 1
> [  598.473981] barrier_waiting: nr_waiting 1
> [  598.478460] barrier_waiting: nr_waiting 1
> [  598.482940] barrier_waiting: nr_waiting 1
> [  598.487421] barrier_waiting: nr_waiting 1
> [  598.491901] barrier_waiting: nr_waiting 1
> [  598.496382] barrier_waiting: nr_waiting 1
> [  598.500860] barrier_waiting: nr_waiting 1
> [  598.505338] barrier_waiting: nr_waiting 1
> [  598.509837] barrier_waiting: nr_waiting 1
> [  598.514317] barrier_waiting: nr_waiting 1
> [  598.518797] barrier_waiting: nr_waiting 1
> [  598.523276] barrier_waiting: nr_waiting 1
> [  598.527756] barrier_waiting: nr_waiting 1
> [  598.532241] barrier_waiting: nr_waiting 1
> [  598.536719] barrier_waiting: nr_waiting 1
> [  598.541199] barrier_waiting: nr_waiting 1
> [  598.545679] barrier_waiting: nr_waiting 1
> [  598.550159] barrier_waiting: nr_waiting 1
> [  598.554639] barrier_waiting: nr_waiting 1
> [  598.559118] barrier_waiting: nr_waiting 1
> [  598.563597] barrier_waiting: nr_waiting 1
> [  598.568077] barrier_waiting: nr_waiting 1
> [  598.572561] barrier_waiting: nr_waiting 1
> [  598.577038] barrier_waiting: nr_waiting 1
> [  598.581517] barrier_waiting: nr_waiting 1
> [  598.585995] barrier_waiting: nr_waiting 1
> [  598.590475] barrier_waiting: nr_waiting 1
> [  598.594953] barrier_waiting: nr_waiting 1
> [  598.599434] barrier_waiting: nr_waiting 1
> [  598.603913] barrier_waiting: nr_waiting 1
> [  598.608392] barrier_waiting: nr_waiting 1
> [  598.612871] barrier_waiting: nr_waiting 1
> [  598.617349] barrier_waiting: nr_waiting 1
> [  598.621828] barrier_waiting: nr_waiting 1
> [  598.626308] barrier_waiting: nr_waiting 1
> [  598.630787] barrier_waiting: nr_waiting 1
> [  598.635272] barrier_waiting: nr_waiting 1
> [  598.639753] barrier_waiting: nr_waiting 1
> [  598.644231] barrier_waiting: nr_waiting 1
> [  598.648712] barrier_waiting: nr_waiting 1
> [  598.653192] barrier_waiting: nr_waiting 1
> [  598.657671] barrier_waiting: nr_waiting 1
> [  598.662150] barrier_waiting: nr_waiting 1
> [  598.666630] barrier_waiting: nr_waiting 1
> [  598.671111] barrier_waiting: nr_waiting 1
> [  598.675589] barrier_waiting: nr_waiting 1
> [  598.680068] barrier_waiting: nr_waiting 1
> [  598.684547] barrier_waiting: nr_waiting 1
> [  598.689024] barrier_waiting: nr_waiting 1
> [  598.693501] barrier_waiting: nr_waiting 1
> [  598.697982] barrier_waiting: nr_waiting 1
> [  598.702462] barrier_waiting: nr_waiting 1
> [  598.706945] barrier_waiting: nr_waiting 1
> [  598.711425] barrier_waiting: nr_waiting 1
> [  598.715989] barrier_waiting: nr_waiting 1
> [  598.720523] barrier_waiting: nr_waiting 1
> [  598.725014] barrier_waiting: nr_waiting 1
> [  598.729500] barrier_waiting: nr_waiting 1
> [  598.733983] barrier_waiting: nr_waiting 1
> [  598.738465] barrier_waiting: nr_waiting 1
> [  598.742947] barrier_waiting: nr_waiting 1
> [  598.747426] barrier_waiting: nr_waiting 1
> [  598.751909] barrier_waiting: nr_waiting 1
> [  598.756390] barrier_waiting: nr_waiting 1
> [  598.760869] barrier_waiting: nr_waiting 1
> [  598.765360] barrier_waiting: nr_waiting 1
> [  598.769839] barrier_waiting: nr_waiting 1
> [  598.774318] barrier_waiting: nr_waiting 1
> [  598.778801] barrier_waiting: nr_waiting 1
> [  598.783280] barrier_waiting: nr_waiting 1
> [  598.787758] barrier_waiting: nr_waiting 1
> [  598.792242] barrier_waiting: nr_waiting 1
> [  598.796723] barrier_waiting: nr_waiting 1
> [  598.801200] barrier_waiting: nr_waiting 1
> [  598.805688] barrier_waiting: nr_waiting 1
> [  598.810166] barrier_waiting: nr_waiting 1
> [  598.814646] barrier_waiting: nr_waiting 1
> [  598.819126] barrier_waiting: nr_waiting 1
> [  598.823606] barrier_waiting: nr_waiting 1
> [  598.828086] barrier_waiting: nr_waiting 1
> [  598.832574] barrier_waiting: nr_waiting 1
> [  598.837052] barrier_waiting: nr_waiting 1
> [  598.841531] barrier_waiting: nr_waiting 1
> [  598.846012] barrier_waiting: nr_waiting 1
> [  598.850491] barrier_waiting: nr_waiting 1
> [  598.854969] barrier_waiting: nr_waiting 1
> [  598.859456] barrier_waiting: nr_waiting 1
> [  598.863934] barrier_waiting: nr_waiting 1
> [  598.868412] barrier_waiting: nr_waiting 1
> [  598.872895] barrier_waiting: nr_waiting 1
> [  598.877374] barrier_waiting: nr_waiting 1
> [  598.881853] barrier_waiting: nr_waiting 1
> [  598.886334] barrier_waiting: nr_waiting 1
> [  598.890813] barrier_waiting: nr_waiting 1
> [  598.895293] barrier_waiting: nr_waiting 1
> [  598.899774] barrier_waiting: nr_waiting 1
> [  598.904253] barrier_waiting: nr_waiting 1
> [  598.908735] barrier_waiting: nr_waiting 1
> [  598.913215] barrier_waiting: nr_waiting 1
> [  598.917694] barrier_waiting: nr_waiting 1
> [  598.922173] barrier_waiting: nr_waiting 1
> [  598.926663] barrier_waiting: nr_waiting 1
> [  598.931153] barrier_waiting: nr_waiting 1
> [  598.935638] barrier_waiting: nr_waiting 1
> [  598.940115] barrier_waiting: nr_waiting 1
> [  598.944599] barrier_waiting: nr_waiting 1
> [  598.949080] barrier_waiting: nr_waiting 1
> [  598.953561] barrier_waiting: nr_waiting 1
> [  598.958042] barrier_waiting: nr_waiting 1
> [  598.962523] barrier_waiting: nr_waiting 1
> [  598.967006] barrier_waiting: nr_waiting 1
> [  598.971486] barrier_waiting: nr_waiting 1
> [  598.975965] barrier_waiting: nr_waiting 1
> [  598.980446] barrier_waiting: nr_waiting 1
> [  598.984923] barrier_waiting: nr_waiting 1
> [  598.989408] barrier_waiting: nr_waiting 1
> [  598.993890] barrier_waiting: nr_waiting 1
> [  598.998367] barrier_waiting: nr_waiting 1
> [  599.002844] barrier_waiting: nr_waiting 1
> [  599.007328] barrier_waiting: nr_waiting 1
> [  599.011800] barrier_waiting: nr_waiting 1
> [  599.016278] barrier_waiting: nr_waiting 1
> [  599.020756] barrier_waiting: nr_waiting 1
> [  599.025241] barrier_waiting: nr_waiting 1
> [  599.029720] barrier_waiting: nr_waiting 1
> [  599.034199] barrier_waiting: nr_waiting 1
> [  599.038682] barrier_waiting: nr_waiting 1
> [  599.043161] barrier_waiting: nr_waiting 1
> [  599.047641] barrier_waiting: nr_waiting 1
> [  599.052120] barrier_waiting: nr_waiting 1
> [  599.056601] barrier_waiting: nr_waiting 1
> [  599.061082] barrier_waiting: nr_waiting 1
> [  599.065567] barrier_waiting: nr_waiting 1
> [  599.070045] barrier_waiting: nr_waiting 1
> [  599.074522] barrier_waiting: nr_waiting 1
> [  599.079006] barrier_waiting: nr_waiting 1
> [  599.083486] barrier_waiting: nr_waiting 1
> [  599.087968] barrier_waiting: nr_waiting 1
> [  599.092448] barrier_waiting: nr_waiting 1
> [  599.096929] barrier_waiting: nr_waiting 1
> [  599.101407] barrier_waiting: nr_waiting 1
> [  599.105886] barrier_waiting: nr_waiting 1
> [  599.110366] barrier_waiting: nr_waiting 1
> [  599.114850] barrier_waiting: nr_waiting 1
> [  599.119332] barrier_waiting: nr_waiting 1
> [  599.123809] barrier_waiting: nr_waiting 1
> [  599.128293] barrier_waiting: nr_waiting 1
> [  599.132765] barrier_waiting: nr_waiting 1
> [  599.137242] barrier_waiting: nr_waiting 1
> [  599.141723] barrier_waiting: nr_waiting 1
> [  599.146203] barrier_waiting: nr_waiting 1
> [  599.150682] barrier_waiting: nr_waiting 1
> [  599.155165] barrier_waiting: nr_waiting 1
> [  599.159644] barrier_waiting: nr_waiting 1
> [  599.164124] barrier_waiting: nr_waiting 1
> [  599.168603] barrier_waiting: nr_waiting 1
> [  599.173080] barrier_waiting: nr_waiting 1
> [  599.177564] barrier_waiting: nr_waiting 1
> [  599.182043] barrier_waiting: nr_waiting 1
> [  599.186525] barrier_waiting: nr_waiting 1
> [  599.191008] barrier_waiting: nr_waiting 1
> [  599.195488] barrier_waiting: nr_waiting 1
> [  599.199967] barrier_waiting: nr_waiting 1
> [  599.204448] barrier_waiting: nr_waiting 1
> [  599.208928] barrier_waiting: nr_waiting 1
> [  599.213408] barrier_waiting: nr_waiting 1
> [  599.217890] barrier_waiting: nr_waiting 1
> [  599.222370] barrier_waiting: nr_waiting 1
> [  599.226850] barrier_waiting: nr_waiting 1
> [  599.231329] barrier_waiting: nr_waiting 1
> [  599.235811] barrier_waiting: nr_waiting 1
> [  599.240289] barrier_waiting: nr_waiting 1
> [  599.244767] barrier_waiting: nr_waiting 1
> [  599.249247] barrier_waiting: nr_waiting 1
> [  599.253731] barrier_waiting: nr_waiting 1
> [  599.258212] barrier_waiting: nr_waiting 1
> [  599.262691] barrier_waiting: nr_waiting 1
> [  599.267170] barrier_waiting: nr_waiting 1
> [  599.271650] barrier_waiting: nr_waiting 1
> [  599.276128] barrier_waiting: nr_waiting 1
> [  599.280606] barrier_waiting: nr_waiting 1
> [  599.285084] barrier_waiting: nr_waiting 1
> [  599.289569] barrier_waiting: nr_waiting 1
> [  599.294040] barrier_waiting: nr_waiting 1
> [  599.298522] barrier_waiting: nr_waiting 1
> [  599.303006] barrier_waiting: nr_waiting 1
> [  599.307483] barrier_waiting: nr_waiting 1
> [  599.311961] barrier_waiting: nr_waiting 1
> [  599.316442] barrier_waiting: nr_waiting 1
> [  599.320923] barrier_waiting: nr_waiting 1
> [  599.325403] barrier_waiting: nr_waiting 1
> [  599.329884] barrier_waiting: nr_waiting 1
> [  599.334363] barrier_waiting: nr_waiting 1
> [  599.338842] barrier_waiting: nr_waiting 1
> [  599.343322] barrier_waiting: nr_waiting 1
> [  599.347801] barrier_waiting: nr_waiting 1
> [  599.352282] barrier_waiting: nr_waiting 1
> [  599.356762] barrier_waiting: nr_waiting 1
> [  599.361246] barrier_waiting: nr_waiting 1
> [  599.365727] barrier_waiting: nr_waiting 1
> [  599.370206] barrier_waiting: nr_waiting 1
> [  599.374685] barrier_waiting: nr_waiting 1
> [  599.379166] barrier_waiting: nr_waiting 1
> [  599.383647] barrier_waiting: nr_waiting 1
> [  599.388125] barrier_waiting: nr_waiting 1
> [  599.392605] barrier_waiting: nr_waiting 1
> [  599.397083] barrier_waiting: nr_waiting 1
> [  599.401562] barrier_waiting: nr_waiting 1
> [  599.406044] barrier_waiting: nr_waiting 1
> [  599.410525] barrier_waiting: nr_waiting 1
> [  599.415008] barrier_waiting: nr_waiting 1
> [  599.419486] barrier_waiting: nr_waiting 1
> [  599.423968] barrier_waiting: nr_waiting 1
> [  599.428446] barrier_waiting: nr_waiting 1
> [  599.432924] barrier_waiting: nr_waiting 1
> [  599.437409] barrier_waiting: nr_waiting 1
> [  599.441890] barrier_waiting: nr_waiting 1
> [  599.446373] barrier_waiting: nr_waiting 1
> [  599.450859] barrier_waiting: nr_waiting 1
> [  599.455337] barrier_waiting: nr_waiting 1
> [  599.459819] barrier_waiting: nr_waiting 1
> [  599.464306] barrier_waiting: nr_waiting 1
> [  599.468783] barrier_waiting: nr_waiting 1
> [  599.473262] barrier_waiting: nr_waiting 1
> [  599.477744] barrier_waiting: nr_waiting 1
> [  599.482224] barrier_waiting: nr_waiting 1
> [  599.486704] barrier_waiting: nr_waiting 1
> [  599.491190] barrier_waiting: nr_waiting 1
> [  599.495670] barrier_waiting: nr_waiting 1
> [  599.500150] barrier_waiting: nr_waiting 1
> [  599.504629] barrier_waiting: nr_waiting 1
> [  599.509106] barrier_waiting: nr_waiting 1
> [  599.513588] barrier_waiting: nr_waiting 1
> [  599.518072] barrier_waiting: nr_waiting 1
> [  599.522552] barrier_waiting: nr_waiting 1
> [  599.527030] barrier_waiting: nr_waiting 1
> [  599.531509] barrier_waiting: nr_waiting 1
> [  599.535988] barrier_waiting: nr_waiting 1
> [  599.540470] barrier_waiting: nr_waiting 1
> [  599.544955] barrier_waiting: nr_waiting 1
> [  599.549426] barrier_waiting: nr_waiting 1
> [  599.553904] barrier_waiting: nr_waiting 1
> [  599.558384] barrier_waiting: nr_waiting 1
> [  599.562863] barrier_waiting: nr_waiting 1
> [  599.567342] barrier_waiting: nr_waiting 1
> [  599.571820] barrier_waiting: nr_waiting 1
> [  599.576298] barrier_waiting: nr_waiting 1
> [  599.580779] barrier_waiting: nr_waiting 1
> [  599.585254] wait_barrier: nr_pending: 1
> [  599.589540] try_raise_barrier: nr_pending 1
> [  599.589547] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  599.594209] try_raise_barrier: nr_pending 1
> [  599.605582] try_raise_barrier: nr_pending 1
> [  599.605674] allow_barrier: nr_pending: 0
> [  599.610620] wait_barrier: nr_pending: 1
> [  599.614653] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  599.618935] try_raise_barrier: nr_pending 1
> [  599.618938] try_raise_barrier: nr_pending 1
> [  599.618965] raid10_read_request: r10_bio ff3b4134184a6100 start
> [  599.641092] try_raise_barrier: nr_pending 1
> [  599.641145] allow_barrier: nr_pending: 0
> [  599.646251] wait_barrier: nr_pending: 1
> [  599.650157] raid_end_bio_io: r10_bio ff3b4134184a6100 done
> [  599.654437] try_raise_barrier: nr_pending 1
> [  599.654446] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  599.654575] allow_barrier: nr_pending: 0
> [  599.654583] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  599.682715] wait_barrier: nr_pending: 1
> [  599.687000] try_raise_barrier: nr_pending 1
> [  599.687012] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  599.691672] try_raise_barrier: nr_pending 1
> [  599.703020] try_raise_barrier: nr_pending 1
> [  599.703069] allow_barrier: nr_pending: 0
> [  599.708037] wait_barrier: nr_pending: 1
> [  599.712092] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  599.716368] try_raise_barrier: nr_pending 1
> [  599.716372] try_raise_barrier: nr_pending 1
> [  599.716377] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  599.738510] try_raise_barrier: nr_pending 1
> [  599.738554] allow_barrier: nr_pending: 0
> [  599.743663] wait_barrier: nr_pending: 1
> [  599.747583] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  599.751853] try_raise_barrier: nr_pending 1
> [  599.751857] try_raise_barrier: nr_pending 1
> [  599.751864] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  599.773945] try_raise_barrier: nr_pending 1
> [  599.774058] allow_barrier: nr_pending: 0
> [  599.779116] wait_barrier: nr_pending: 1
> [  599.783020] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  599.787298] try_raise_barrier: nr_pending 1
> [  599.787307] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  599.787461] allow_barrier: nr_pending: 0
> [  599.787469] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  599.815585] wait_barrier: nr_pending: 1
> [  599.819872] try_raise_barrier: nr_pending 1
> [  599.819883] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  599.824546] try_raise_barrier: nr_pending 1
> [  599.835892] try_raise_barrier: nr_pending 1
> [  599.835904] allow_barrier: nr_pending: 0
> [  599.840922] wait_barrier: nr_pending: 1
> [  599.844957] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  599.849235] try_raise_barrier: nr_pending 1
> [  599.849239] try_raise_barrier: nr_pending 1
> [  599.849244] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  599.871381] try_raise_barrier: nr_pending 1
> [  599.871463] allow_barrier: nr_pending: 0
> [  599.876542] wait_barrier: nr_pending: 1
> [  599.880451] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  599.884730] try_raise_barrier: nr_pending 1
> [  599.884735] try_raise_barrier: nr_pending 1
> [  599.884740] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  599.884889] allow_barrier: nr_pending: 0
> [  599.884897] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  599.917789] wait_barrier: nr_pending: 1
> [  599.922088] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  599.922159] try_raise_barrier: nr_pending 1
> [  599.928829] allow_barrier: nr_pending: 0
> [  599.933736] wait_barrier: nr_pending: 1
> [  599.937771] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  599.942045] try_raise_barrier: nr_pending 1
> [  599.942049] try_raise_barrier: nr_pending 1
> [  599.942058] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  599.964202] try_raise_barrier: nr_pending 1
> [  599.964262] allow_barrier: nr_pending: 0
> [  599.969461] wait_barrier: nr_pending: 1
> [  599.973275] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  599.977553] try_raise_barrier: nr_pending 1
> [  599.977559] try_raise_barrier: nr_pending 1
> [  599.977562] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  599.977715] allow_barrier: nr_pending: 0
> [  599.977723] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.010600] wait_barrier: nr_pending: 1
> [  600.014887] try_raise_barrier: nr_pending 1
> [  600.014898] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  600.019559] try_raise_barrier: nr_pending 1
> [  600.030909] try_raise_barrier: nr_pending 1
> [  600.030917] allow_barrier: nr_pending: 0
> [  600.036049] wait_barrier: nr_pending: 1
> [  600.039974] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  600.044253] try_raise_barrier: nr_pending 1
> [  600.044257] try_raise_barrier: nr_pending 1
> [  600.044263] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  600.066363] try_raise_barrier: nr_pending 1
> [  600.066461] allow_barrier: nr_pending: 0
> [  600.071440] wait_barrier: nr_pending: 1
> [  600.075443] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  600.079722] try_raise_barrier: nr_pending 1
> [  600.079727] try_raise_barrier: nr_pending 1
> [  600.079731] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.079868] allow_barrier: nr_pending: 0
> [  600.079875] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.112682] wait_barrier: nr_pending: 1
> [  600.116967] try_raise_barrier: nr_pending 1
> [  600.116978] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.121640] try_raise_barrier: nr_pending 1
> [  600.132990] try_raise_barrier: nr_pending 1
> [  600.133057] allow_barrier: nr_pending: 0
> [  600.138070] wait_barrier: nr_pending: 1
> [  600.142062] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.146337] try_raise_barrier: nr_pending 1
> [  600.146342] try_raise_barrier: nr_pending 1
> [  600.146348] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  600.168487] try_raise_barrier: nr_pending 1
> [  600.168532] allow_barrier: nr_pending: 0
> [  600.173662] wait_barrier: nr_pending: 1
> [  600.177563] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  600.181840] try_raise_barrier: nr_pending 1
> [  600.181845] try_raise_barrier: nr_pending 1
> [  600.181849] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.181983] allow_barrier: nr_pending: 0
> [  600.181991] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.214790] wait_barrier: nr_pending: 1
> [  600.219075] try_raise_barrier: nr_pending 1
> [  600.219087] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  600.223748] try_raise_barrier: nr_pending 1
> [  600.235099] try_raise_barrier: nr_pending 1
> [  600.235150] allow_barrier: nr_pending: 0
> [  600.240130] wait_barrier: nr_pending: 1
> [  600.244170] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  600.248446] try_raise_barrier: nr_pending 1
> [  600.248450] try_raise_barrier: nr_pending 1
> [  600.248456] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  600.270600] try_raise_barrier: nr_pending 1
> [  600.270648] allow_barrier: nr_pending: 0
> [  600.275752] wait_barrier: nr_pending: 1
> [  600.279676] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  600.283952] try_raise_barrier: nr_pending 1
> [  600.283956] try_raise_barrier: nr_pending 1
> [  600.283961] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.284093] allow_barrier: nr_pending: 0
> [  600.284100] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.316975] wait_barrier: nr_pending: 1
> [  600.321262] try_raise_barrier: nr_pending 1
> [  600.321273] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.325936] try_raise_barrier: nr_pending 1
> [  600.337279] allow_barrier: nr_pending: 0
> [  600.337649] wait_barrier: nr_pending: 1
> [  600.341674] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.345947] try_raise_barrier: nr_pending 1
> [  600.345951] try_raise_barrier: nr_pending 1
> [  600.345958] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  600.368088] try_raise_barrier: nr_pending 1
> [  600.368129] allow_barrier: nr_pending: 0
> [  600.373070] wait_barrier: nr_pending: 1
> [  600.377153] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  600.381430] try_raise_barrier: nr_pending 1
> [  600.381434] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.381555] allow_barrier: nr_pending: 0
> [  600.381562] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.409730] wait_barrier: nr_pending: 1
> [  600.414012] try_raise_barrier: nr_pending 1
> [  600.414015] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  600.418685] try_raise_barrier: nr_pending 1
> [  600.430034] try_raise_barrier: nr_pending 1
> [  600.430085] allow_barrier: nr_pending: 0
> [  600.435126] wait_barrier: nr_pending: 1
> [  600.439107] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  600.443388] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  600.443462] try_raise_barrier: nr_pending 1
> [  600.443466] try_raise_barrier: nr_pending 1
> [  600.465548] try_raise_barrier: nr_pending 1
> [  600.465585] allow_barrier: nr_pending: 0
> [  600.470613] wait_barrier: nr_pending: 1
> [  600.474627] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  600.478903] try_raise_barrier: nr_pending 1
> [  600.478910] try_raise_barrier: nr_pending 1
> [  600.478912] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.479045] allow_barrier: nr_pending: 0
> [  600.479053] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.511838] wait_barrier: nr_pending: 1
> [  600.516124] try_raise_barrier: nr_pending 1
> [  600.516135] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.520797] try_raise_barrier: nr_pending 1
> [  600.532156] try_raise_barrier: nr_pending 1
> [  600.532225] allow_barrier: nr_pending: 0
> [  600.537288] wait_barrier: nr_pending: 1
> [  600.541229] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.545505] try_raise_barrier: nr_pending 1
> [  600.545509] try_raise_barrier: nr_pending 1
> [  600.545515] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  600.567662] try_raise_barrier: nr_pending 1
> [  600.567696] allow_barrier: nr_pending: 0
> [  600.572778] wait_barrier: nr_pending: 1
> [  600.576742] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  600.581017] try_raise_barrier: nr_pending 1
> [  600.581023] try_raise_barrier: nr_pending 1
> [  600.581028] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.581145] allow_barrier: nr_pending: 0
> [  600.581152] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.613893] wait_barrier: nr_pending: 1
> [  600.618178] try_raise_barrier: nr_pending 1
> [  600.618188] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  600.622851] try_raise_barrier: nr_pending 1
> [  600.634242] try_raise_barrier: nr_pending 1
> [  600.634317] allow_barrier: nr_pending: 0
> [  600.639159] wait_barrier: nr_pending: 1
> [  600.643299] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  600.647575] try_raise_barrier: nr_pending 1
> [  600.647579] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  600.647579] try_raise_barrier: nr_pending 1
> [  600.647633] allow_barrier: nr_pending: 0
> [  600.647637] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  600.680526] wait_barrier: nr_pending: 1
> [  600.684819] try_raise_barrier: nr_pending 1
> [  600.684841] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.689492] try_raise_barrier: nr_pending 1
> [  600.700853] try_raise_barrier: nr_pending 1
> [  600.700910] allow_barrier: nr_pending: 0
> [  600.706030] wait_barrier: nr_pending: 1
> [  600.709914] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.714193] try_raise_barrier: nr_pending 1
> [  600.714197] try_raise_barrier: nr_pending 1
> [  600.714205] raid10_read_request: r10_bio ff3b4134184a6100 start
> [  600.714376] allow_barrier: nr_pending: 0
> [  600.714383] raid_end_bio_io: r10_bio ff3b4134184a6100 done
> [  600.747144] wait_barrier: nr_pending: 1
> [  600.751430] try_raise_barrier: nr_pending 1
> [  600.751442] raid10_read_request: r10_bio ff3b4134184a6b00 start
> [  600.756102] try_raise_barrier: nr_pending 1
> [  600.767448] try_raise_barrier: nr_pending 1
> [  600.767537] allow_barrier: nr_pending: 0
> [  600.772502] wait_barrier: nr_pending: 1
> [  600.776516] raid_end_bio_io: r10_bio ff3b4134184a6b00 done
> [  600.780795] try_raise_barrier: nr_pending 1
> [  600.780799] try_raise_barrier: nr_pending 1
> [  600.780808] raid10_read_request: r10_bio ff3b4134184a7f00 start
> [  600.802876] try_raise_barrier: nr_pending 1
> [  600.803016] allow_barrier: nr_pending: 0
> [  600.808000] wait_barrier: nr_pending: 1
> [  600.811943] raid_end_bio_io: r10_bio ff3b4134184a7f00 done
> [  600.816225] try_raise_barrier: nr_pending 1
> [  600.816229] try_raise_barrier: nr_pending 1
> [  600.816245] raid10_read_request: r10_bio ff3b4134184a7400 start
> [  600.838385] try_raise_barrier: nr_pending 1
> [  600.838448] allow_barrier: nr_pending: 0
> [  600.843556] wait_barrier: nr_pending: 1
> [  600.847451] raid_end_bio_io: r10_bio ff3b4134184a7400 done
> [  600.851722] try_raise_barrier: nr_pending 1
> [  600.851726] try_raise_barrier: nr_pending 1
> [  600.851732] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.851897] allow_barrier: nr_pending: 0
> [  600.851904] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.884632] wait_barrier: nr_pending: 1
> [  600.888917] try_raise_barrier: nr_pending 1
> [  600.888929] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.893588] try_raise_barrier: nr_pending 1
> [  600.904881] try_raise_barrier: nr_pending 1
> [  600.905028] allow_barrier: nr_pending: 0
> [  600.909930] wait_barrier: nr_pending: 1
> [  600.913958] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  600.918233] try_raise_barrier: nr_pending 1
> [  600.918237] try_raise_barrier: nr_pending 1
> [  600.918245] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  600.940401] try_raise_barrier: nr_pending 1
> [  600.940502] allow_barrier: nr_pending: 0
> [  600.945589] wait_barrier: nr_pending: 1
> [  600.949477] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  600.953755] try_raise_barrier: nr_pending 1
> [  600.953760] try_raise_barrier: nr_pending 1
> [  600.953765] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  600.953893] allow_barrier: nr_pending: 0
> [  600.953901] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  600.986653] wait_barrier: nr_pending: 1
> [  600.990939] try_raise_barrier: nr_pending 1
> [  600.990949] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  600.995611] try_raise_barrier: nr_pending 1
> [  601.006963] try_raise_barrier: nr_pending 1
> [  601.007109] allow_barrier: nr_pending: 0
> [  601.011808] wait_barrier: nr_pending: 1
> [  601.016031] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  601.020309] try_raise_barrier: nr_pending 1
> [  601.020313] try_raise_barrier: nr_pending 1
> [  601.020319] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  601.042453] allow_barrier: nr_pending: 0
> [  601.042803] wait_barrier: nr_pending: 1
> [  601.046853] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  601.051120] try_raise_barrier: nr_pending 1
> [  601.051125] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  601.051126] try_raise_barrier: nr_pending 1
> [  601.051145] try_raise_barrier: nr_pending 1
> [  601.051415] allow_barrier: nr_pending: 0
> [  601.051422] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  601.088815] wait_barrier: nr_pending: 1
> [  601.093099] try_raise_barrier: nr_pending 1
> [  601.093111] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  601.097772] try_raise_barrier: nr_pending 1
> [  601.109103] try_raise_barrier: nr_pending 1
> [  601.109172] allow_barrier: nr_pending: 0
> [  601.114259] wait_barrier: nr_pending: 1
> [  601.118177] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  601.122446] try_raise_barrier: nr_pending 1
> [  601.122450] try_raise_barrier: nr_pending 1
> [  601.122459] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  601.144607] try_raise_barrier: nr_pending 1
> [  601.144650] allow_barrier: nr_pending: 0
> [  601.149688] wait_barrier: nr_pending: 1
> [  601.153683] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  601.157960] try_raise_barrier: nr_pending 1
> [  601.157964] try_raise_barrier: nr_pending 1
> [  601.157970] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  601.180129] try_raise_barrier: nr_pending 1
> [  601.180240] allow_barrier: nr_pending: 0
> [  601.185207] wait_barrier: nr_pending: 1
> [  601.189209] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  601.193485] try_raise_barrier: nr_pending 1
> [  601.193497] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  601.193706] allow_barrier: nr_pending: 0
> [  601.193714] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  601.221868] wait_barrier: nr_pending: 1
> [  601.226153] try_raise_barrier: nr_pending 1
> [  601.226164] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  601.230826] try_raise_barrier: nr_pending 1
> [  601.242175] try_raise_barrier: nr_pending 1
> [  601.242239] allow_barrier: nr_pending: 0
> [  601.247321] wait_barrier: nr_pending: 1
> [  601.251249] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  601.255526] try_raise_barrier: nr_pending 1
> [  601.255530] try_raise_barrier: nr_pending 1
> [  601.255536] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  601.277688] try_raise_barrier: nr_pending 1
> [  601.277818] allow_barrier: nr_pending: 0
> [  601.282730] wait_barrier: nr_pending: 1
> [  601.286761] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  601.291037] try_raise_barrier: nr_pending 1
> [  601.291043] try_raise_barrier: nr_pending 1
> [  601.291047] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  601.313190] try_raise_barrier: nr_pending 1
> [  601.313248] allow_barrier: nr_pending: 0
> [  601.318267] wait_barrier: nr_pending: 1
> [  601.322269] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  601.326544] try_raise_barrier: nr_pending 1
> [  601.326551] try_raise_barrier: nr_pending 1
> [  601.326556] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  601.326708] allow_barrier: nr_pending: 0
> [  601.326716] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  601.359595] wait_barrier: nr_pending: 1
> [  601.363882] try_raise_barrier: nr_pending 1
> [  601.363893] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  601.368556] try_raise_barrier: nr_pending 1
> [  601.379906] try_raise_barrier: nr_pending 1
> [  601.379973] allow_barrier: nr_pending: 0
> [  601.385040] wait_barrier: nr_pending: 1
> [  601.388979] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  601.393255] try_raise_barrier: nr_pending 1
> [  601.393260] try_raise_barrier: nr_pending 1
> [  601.393268] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  601.415361] try_raise_barrier: nr_pending 1
> [  601.415483] allow_barrier: nr_pending: 0
> [  601.420443] wait_barrier: nr_pending: 1
> [  601.424436] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  601.428713] try_raise_barrier: nr_pending 1
> [  601.428716] try_raise_barrier: nr_pending 1
> [  601.428723] raid10_read_request: r10_bio ff3b41340eb53600 start
> [  601.450871] try_raise_barrier: nr_pending 1
> [  601.450916] allow_barrier: nr_pending: 0
> [  601.455878] wait_barrier: nr_pending: 1
> [  601.459951] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> [  601.464227] try_raise_barrier: nr_pending 1
> [  601.464231] raid10_read_request: r10_bio ff3b41340eb52d00 start
> [  601.481634] try_raise_barrier: nr_pending 1
> [  601.486439] allow_barrier: nr_pending: 0
> [  601.486947] wait_barrier: nr_pending: 1
> [  601.490841] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> [  601.495112] try_raise_barrier: nr_pending 1
> [  601.495116] try_raise_barrier: nr_pending 1
> [  601.495122] raid10_read_request: r10_bio ff3b41340eb53900 start
> [  601.517260] try_raise_barrier: nr_pending 1
> [  601.517346] allow_barrier: nr_pending: 0
> [  601.522456] wait_barrier: nr_pending: 1
> [  601.526326] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> [  601.530603] try_raise_barrier: nr_pending 1
> [  601.530608] try_raise_barrier: nr_pending 1
> [  601.530612] raid10_write_request: r10_bio ff3b41340eb52d00 start
> [  601.552782] try_raise_barrier: nr_pending 1

Thanks for the test!

Now the problem is clear. r10_bio is generated and never complete, while
IO never issued to underlying loop device, and I can reporduce this
problem as well now.

The blamed commit from git bisect is correct, and there are two
conditions for this problem:

1) plug is not used for caller;
2) for raid1/raid10, bio plug is enabled;

__submit_bio_noacct
  current->bio_list = ...;
  blk_start_plug

   dm_submit_bio
    md_handle_request
     raid10_write_request
      -> generate new bio for underlying disks
      raid1_add_bio_to_plug -> bio added to plug

  blk_finish_plug
   raid10_unplug
    raid1_submit_write
     submit_bio_noacct
      if (current->bio_list)
       -> bio_list is not empty
       bio_list_add(&current->bio_list[0], bio)

  current->bio_list = NULL
  -> the bio is in bio_list, and it's dropped.

Can you give the following patch a test? It should be a final test...

Thanks,
Kuai

diff --git a/block/blk-core.c b/block/blk-core.c
index 01186333c88e..1e9208024e47 100644
--- a/block/blk-core.c
+++ b/block/blk-core.c
@@ -613,9 +613,13 @@ static inline blk_status_t 
blk_check_zone_append(struct request_queue *q,

  static void __submit_bio(struct bio *bio)
  {
+       struct blk_plug plug;
+
         if (unlikely(!blk_crypto_bio_prep(&bio)))
                 return;

+       blk_start_plug(&plug);
+
         if (!bio->bi_bdev->bd_has_submit_bio) {
                 blk_mq_submit_bio(bio);
         } else if (likely(bio_queue_enter(bio) == 0)) {
@@ -624,6 +628,8 @@ static void __submit_bio(struct bio *bio)
                 disk->fops->submit_bio(bio);
                 blk_queue_exit(disk->queue);
         }
+
+       blk_finish_plug(&plug);
  }

  /*
@@ -648,13 +654,11 @@ static void __submit_bio(struct bio *bio)
  static void __submit_bio_noacct(struct bio *bio)
  {
         struct bio_list bio_list_on_stack[2];
-       struct blk_plug plug;

         BUG_ON(bio->bi_next);

         bio_list_init(&bio_list_on_stack[0]);
         current->bio_list = bio_list_on_stack;
-       blk_start_plug(&plug);

         do {
                 struct request_queue *q = bdev_get_queue(bio->bi_bdev);
@@ -688,23 +692,19 @@ static void __submit_bio_noacct(struct bio *bio)
                 bio_list_merge(&bio_list_on_stack[0], 
&bio_list_on_stack[1]);
         } while ((bio = bio_list_pop(&bio_list_on_stack[0])));

-       blk_finish_plug(&plug);
         current->bio_list = NULL;
  }

  static void __submit_bio_noacct_mq(struct bio *bio)
  {
         struct bio_list bio_list[2] = { };
-       struct blk_plug plug;

         current->bio_list = bio_list;
-       blk_start_plug(&plug);

         do {
                 __submit_bio(bio);
         } while ((bio = bio_list_pop(&bio_list[0])));

-       blk_finish_plug(&plug);
         current->bio_list = NULL;
  }

> [  737.970751] INFO: task mdX_resync:3115 blocked for more than 122 seconds.
> [  737.978361]       Not tainted 6.9.0+ #1
> [  737.982654] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [  737.991398] task:mdX_resync      state:D stack:0     pid:3115
> tgid:3115  ppid:2      flags:0x00004000
> [  737.991407] Call Trace:
> [  737.991410]  <TASK>
> [  737.991414]  __schedule+0x222/0x670
> [  737.991426]  schedule+0x2c/0xb0
> [  737.991434]  raise_barrier+0xca/0x1a0 [raid10]
> [  737.991450]  ? __pfx_autoremove_wake_function+0x10/0x10
> [  737.991459]  raid10_sync_request+0x2c3/0x19d0 [raid10]
> [  737.991472]  ? __switch_to_asm+0x39/0x70
> [  737.991478]  ? finish_task_switch.isra.0+0x8e/0x2a0
> [  737.991487]  ? __schedule+0x22a/0x670
> [  737.991491]  ? prepare_to_wait_event+0x5f/0x190
> [  737.991498]  md_do_sync+0x660/0x1040
> [  737.991508]  ? __pfx_autoremove_wake_function+0x10/0x10
> [  737.991517]  md_thread+0xad/0x160
> [  737.991521]  ? __pfx_md_thread+0x10/0x10
> [  737.991524]  kthread+0xdc/0x110
> [  737.991531]  ? __pfx_kthread+0x10/0x10
> [  737.991535]  ret_from_fork+0x2d/0x50
> [  737.991544]  ? __pfx_kthread+0x10/0x10
> [  737.991547]  ret_from_fork_asm+0x1a/0x30
> [  737.991553]  </TASK>
> [  860.850998] INFO: task mdX_resync:3115 blocked for more than 245 seconds.
> [  860.858606]       Not tainted 6.9.0+ #1
> [  860.862902] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [  860.871649] task:mdX_resync      state:D stack:0     pid:3115
> tgid:3115  ppid:2      flags:0x00004000
> [  860.871658] Call Trace:
> [  860.871660]  <TASK>
> [  860.871664]  __schedule+0x222/0x670
> [  860.871674]  schedule+0x2c/0xb0
> [  860.871681]  raise_barrier+0xca/0x1a0 [raid10]
> [  860.871696]  ? __pfx_autoremove_wake_function+0x10/0x10
> [  860.871704]  raid10_sync_request+0x2c3/0x19d0 [raid10]
> [  860.871717]  ? __switch_to_asm+0x39/0x70
> [  860.871722]  ? finish_task_switch.isra.0+0x8e/0x2a0
> [  860.871729]  ? __schedule+0x22a/0x670
> [  860.871733]  ? prepare_to_wait_event+0x5f/0x190
> [  860.871740]  md_do_sync+0x660/0x1040
> [  860.871748]  ? __pfx_autoremove_wake_function+0x10/0x10
> [  860.871756]  md_thread+0xad/0x160
> [  860.871761]  ? __pfx_md_thread+0x10/0x10
> [  860.871765]  kthread+0xdc/0x110
> [  860.871770]  ? __pfx_kthread+0x10/0x10
> [  860.871774]  ret_from_fork+0x2d/0x50
> [  860.871781]  ? __pfx_kthread+0x10/0x10
> [  860.871785]  ret_from_fork_asm+0x1a/0x30
> [  860.871790]  </TASK>
> 
> Thanks,
> Changhui
> 
> .
> 

Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds

[Changhui Zhong]

On Tue, May 21, 2024 at 5:17 PM Yu Kuai <yukuai1@huaweicloud.com> wrote:
>
> Hi,
>
> 在 2024/05/21 12:28, Changhui Zhong 写道:
> > On Tue, May 21, 2024 at 9:09 AM Yu Kuai <yukuai1@huaweicloud.com> wrote:
> >
> >>
> >> Thanks for the test! Since raid10 has the same problem as well, then the
> >> problem seems to be more common in raid. And related code to raid10 is
> >> more simpler, attached is a patch to add debuginfo to raid10.
> >>
> >> BTW, Xiao can reporduce the problem as well, and will lend a hand as
> >> well.
> >>
> >> Thanks,
> >> Kuai
> >
> >
> > Hi, Yu Kuai and Xiao
> >
> > thanks for  efforts on this issue，
> > after applying the debug patch, I got the following results, please check it
> >
> > [  597.491083] Create raid10
> > [  597.647987] device-mapper: raid: Superblocks created for new raid set
> > [  597.680540] md/raid10:mdX: not clean -- starting background reconstruction
> > [  597.680549] md/raid10:mdX: active with 4 out of 4 devices
> > [  597.683779] mdX: bitmap file is out of date, doing full recovery
> > [  597.692971] md: resync of RAID array mdX
> > [  597.753583] try_raise_barrier: resync depth exceed limit
> > [  597.759540] try_raise_barrier: resync depth exceed limit
> > [  597.765504] try_raise_barrier: resync depth exceed limit
> > [  597.771432] try_raise_barrier: resync depth exceed limit
> > [  597.779400] barrier_waiting: nr_waiting 1
> > [  597.783879] barrier_waiting: nr_waiting 1
> > [  597.788356] barrier_waiting: nr_waiting 1
> > [  597.792838] barrier_waiting: nr_waiting 1
> > [  597.797327] barrier_waiting: nr_waiting 1
> > [  597.801806] barrier_waiting: nr_waiting 1
> > [  597.806288] barrier_waiting: nr_waiting 1
> > [  597.810780] barrier_waiting: nr_waiting 1
> > [  597.815252] barrier_waiting: nr_waiting 1
> > [  597.819737] barrier_waiting: nr_waiting 1
> > [  597.824232] barrier_waiting: nr_waiting 1
> > [  597.828714] barrier_waiting: nr_waiting 1
> > [  597.833196] barrier_waiting: nr_waiting 1
> > [  597.837678] barrier_waiting: nr_waiting 1
> > [  597.842160] barrier_waiting: nr_waiting 1
> > [  597.846640] barrier_waiting: nr_waiting 1
> > [  597.851128] barrier_waiting: nr_waiting 1
> > [  597.855610] barrier_waiting: nr_waiting 1
> > [  597.860094] barrier_waiting: nr_waiting 1
> > [  597.864576] barrier_waiting: nr_waiting 1
> > [  597.869060] barrier_waiting: nr_waiting 1
> > [  597.873548] barrier_waiting: nr_waiting 1
> > [  597.878032] barrier_waiting: nr_waiting 1
> > [  597.882522] barrier_waiting: nr_waiting 1
> > [  597.883457] barrier_waiting: nr_waiting 1
> > [  597.891503] barrier_waiting: nr_waiting 1
> > [  597.895987] barrier_waiting: nr_waiting 1
> > [  597.900459] barrier_waiting: nr_waiting 1
> > [  597.904940] barrier_waiting: nr_waiting 1
> > [  597.909421] barrier_waiting: nr_waiting 1
> > [  597.913900] barrier_waiting: nr_waiting 1
> > [  597.918377] barrier_waiting: nr_waiting 1
> > [  597.922857] barrier_waiting: nr_waiting 1
> > [  597.927350] barrier_waiting: nr_waiting 1
> > [  597.931841] barrier_waiting: nr_waiting 1
> > [  597.936322] barrier_waiting: nr_waiting 1
> > [  597.940805] barrier_waiting: nr_waiting 1
> > [  597.945284] barrier_waiting: nr_waiting 1
> > [  597.949766] barrier_waiting: nr_waiting 1
> > [  597.954246] barrier_waiting: nr_waiting 1
> > [  597.958726] barrier_waiting: nr_waiting 1
> > [  597.963205] barrier_waiting: nr_waiting 1
> > [  597.967683] barrier_waiting: nr_waiting 1
> > [  597.972163] barrier_waiting: nr_waiting 1
> > [  597.976641] barrier_waiting: nr_waiting 1
> > [  597.981119] barrier_waiting: nr_waiting 1
> > [  597.985601] barrier_waiting: nr_waiting 1
> > [  597.990082] barrier_waiting: nr_waiting 1
> > [  597.994562] barrier_waiting: nr_waiting 1
> > [  597.999043] barrier_waiting: nr_waiting 1
> > [  598.003522] barrier_waiting: nr_waiting 1
> > [  598.008000] barrier_waiting: nr_waiting 1
> > [  598.012485] barrier_waiting: nr_waiting 1
> > [  598.016964] barrier_waiting: nr_waiting 1
> > [  598.021451] barrier_waiting: nr_waiting 1
> > [  598.025931] barrier_waiting: nr_waiting 1
> > [  598.030409] barrier_waiting: nr_waiting 1
> > [  598.034888] barrier_waiting: nr_waiting 1
> > [  598.039368] barrier_waiting: nr_waiting 1
> > [  598.043848] barrier_waiting: nr_waiting 1
> > [  598.048325] barrier_waiting: nr_waiting 1
> > [  598.052805] barrier_waiting: nr_waiting 1
> > [  598.057283] barrier_waiting: nr_waiting 1
> > [  598.061767] barrier_waiting: nr_waiting 1
> > [  598.066246] barrier_waiting: nr_waiting 1
> > [  598.070726] barrier_waiting: nr_waiting 1
> > [  598.075206] barrier_waiting: nr_waiting 1
> > [  598.079689] barrier_waiting: nr_waiting 1
> > [  598.084170] barrier_waiting: nr_waiting 1
> > [  598.088648] barrier_waiting: nr_waiting 1
> > [  598.093130] barrier_waiting: nr_waiting 1
> > [  598.097646] barrier_waiting: nr_waiting 1
> > [  598.102126] barrier_waiting: nr_waiting 1
> > [  598.106605] barrier_waiting: nr_waiting 1
> > [  598.111085] barrier_waiting: nr_waiting 1
> > [  598.115566] barrier_waiting: nr_waiting 1
> > [  598.120043] barrier_waiting: nr_waiting 1
> > [  598.124522] barrier_waiting: nr_waiting 1
> > [  598.129001] barrier_waiting: nr_waiting 1
> > [  598.133481] barrier_waiting: nr_waiting 1
> > [  598.137958] barrier_waiting: nr_waiting 1
> > [  598.142442] barrier_waiting: nr_waiting 1
> > [  598.146921] barrier_waiting: nr_waiting 1
> > [  598.151400] barrier_waiting: nr_waiting 1
> > [  598.155878] barrier_waiting: nr_waiting 1
> > [  598.160359] barrier_waiting: nr_waiting 1
> > [  598.164838] barrier_waiting: nr_waiting 1
> > [  598.169319] barrier_waiting: nr_waiting 1
> > [  598.173803] barrier_waiting: nr_waiting 1
> > [  598.178282] barrier_waiting: nr_waiting 1
> > [  598.182762] barrier_waiting: nr_waiting 1
> > [  598.187241] barrier_waiting: nr_waiting 1
> > [  598.191722] barrier_waiting: nr_waiting 1
> > [  598.196201] barrier_waiting: nr_waiting 1
> > [  598.200678] barrier_waiting: nr_waiting 1
> > [  598.205159] barrier_waiting: nr_waiting 1
> > [  598.209640] barrier_waiting: nr_waiting 1
> > [  598.214120] barrier_waiting: nr_waiting 1
> > [  598.218599] barrier_waiting: nr_waiting 1
> > [  598.223078] barrier_waiting: nr_waiting 1
> > [  598.227557] barrier_waiting: nr_waiting 1
> > [  598.232036] barrier_waiting: nr_waiting 1
> > [  598.236519] barrier_waiting: nr_waiting 1
> > [  598.240999] barrier_waiting: nr_waiting 1
> > [  598.245478] barrier_waiting: nr_waiting 1
> > [  598.249959] barrier_waiting: nr_waiting 1
> > [  598.254439] barrier_waiting: nr_waiting 1
> > [  598.258917] barrier_waiting: nr_waiting 1
> > [  598.263397] barrier_waiting: nr_waiting 1
> > [  598.267880] barrier_waiting: nr_waiting 1
> > [  598.272362] barrier_waiting: nr_waiting 1
> > [  598.276842] barrier_waiting: nr_waiting 1
> > [  598.281322] barrier_waiting: nr_waiting 1
> > [  598.285802] barrier_waiting: nr_waiting 1
> > [  598.290281] barrier_waiting: nr_waiting 1
> > [  598.294758] barrier_waiting: nr_waiting 1
> > [  598.299256] barrier_waiting: nr_waiting 1
> > [  598.303737] barrier_waiting: nr_waiting 1
> > [  598.308219] barrier_waiting: nr_waiting 1
> > [  598.312698] barrier_waiting: nr_waiting 1
> > [  598.317176] barrier_waiting: nr_waiting 1
> > [  598.321659] barrier_waiting: nr_waiting 1
> > [  598.326138] barrier_waiting: nr_waiting 1
> > [  598.330617] barrier_waiting: nr_waiting 1
> > [  598.335100] barrier_waiting: nr_waiting 1
> > [  598.339580] barrier_waiting: nr_waiting 1
> > [  598.344057] barrier_waiting: nr_waiting 1
> > [  598.348536] barrier_waiting: nr_waiting 1
> > [  598.353016] barrier_waiting: nr_waiting 1
> > [  598.357496] barrier_waiting: nr_waiting 1
> > [  598.361973] barrier_waiting: nr_waiting 1
> > [  598.366453] barrier_waiting: nr_waiting 1
> > [  598.370932] barrier_waiting: nr_waiting 1
> > [  598.375412] barrier_waiting: nr_waiting 1
> > [  598.379890] barrier_waiting: nr_waiting 1
> > [  598.384371] barrier_waiting: nr_waiting 1
> > [  598.388856] barrier_waiting: nr_waiting 1
> > [  598.393326] barrier_waiting: nr_waiting 1
> > [  598.397805] barrier_waiting: nr_waiting 1
> > [  598.402288] barrier_waiting: nr_waiting 1
> > [  598.406772] barrier_waiting: nr_waiting 1
> > [  598.411251] barrier_waiting: nr_waiting 1
> > [  598.415729] barrier_waiting: nr_waiting 1
> > [  598.420209] barrier_waiting: nr_waiting 1
> > [  598.424686] barrier_waiting: nr_waiting 1
> > [  598.429165] barrier_waiting: nr_waiting 1
> > [  598.433644] barrier_waiting: nr_waiting 1
> > [  598.438125] barrier_waiting: nr_waiting 1
> > [  598.442604] barrier_waiting: nr_waiting 1
> > [  598.447083] barrier_waiting: nr_waiting 1
> > [  598.451571] barrier_waiting: nr_waiting 1
> > [  598.456050] barrier_waiting: nr_waiting 1
> > [  598.460531] barrier_waiting: nr_waiting 1
> > [  598.465010] barrier_waiting: nr_waiting 1
> > [  598.469498] barrier_waiting: nr_waiting 1
> > [  598.473981] barrier_waiting: nr_waiting 1
> > [  598.478460] barrier_waiting: nr_waiting 1
> > [  598.482940] barrier_waiting: nr_waiting 1
> > [  598.487421] barrier_waiting: nr_waiting 1
> > [  598.491901] barrier_waiting: nr_waiting 1
> > [  598.496382] barrier_waiting: nr_waiting 1
> > [  598.500860] barrier_waiting: nr_waiting 1
> > [  598.505338] barrier_waiting: nr_waiting 1
> > [  598.509837] barrier_waiting: nr_waiting 1
> > [  598.514317] barrier_waiting: nr_waiting 1
> > [  598.518797] barrier_waiting: nr_waiting 1
> > [  598.523276] barrier_waiting: nr_waiting 1
> > [  598.527756] barrier_waiting: nr_waiting 1
> > [  598.532241] barrier_waiting: nr_waiting 1
> > [  598.536719] barrier_waiting: nr_waiting 1
> > [  598.541199] barrier_waiting: nr_waiting 1
> > [  598.545679] barrier_waiting: nr_waiting 1
> > [  598.550159] barrier_waiting: nr_waiting 1
> > [  598.554639] barrier_waiting: nr_waiting 1
> > [  598.559118] barrier_waiting: nr_waiting 1
> > [  598.563597] barrier_waiting: nr_waiting 1
> > [  598.568077] barrier_waiting: nr_waiting 1
> > [  598.572561] barrier_waiting: nr_waiting 1
> > [  598.577038] barrier_waiting: nr_waiting 1
> > [  598.581517] barrier_waiting: nr_waiting 1
> > [  598.585995] barrier_waiting: nr_waiting 1
> > [  598.590475] barrier_waiting: nr_waiting 1
> > [  598.594953] barrier_waiting: nr_waiting 1
> > [  598.599434] barrier_waiting: nr_waiting 1
> > [  598.603913] barrier_waiting: nr_waiting 1
> > [  598.608392] barrier_waiting: nr_waiting 1
> > [  598.612871] barrier_waiting: nr_waiting 1
> > [  598.617349] barrier_waiting: nr_waiting 1
> > [  598.621828] barrier_waiting: nr_waiting 1
> > [  598.626308] barrier_waiting: nr_waiting 1
> > [  598.630787] barrier_waiting: nr_waiting 1
> > [  598.635272] barrier_waiting: nr_waiting 1
> > [  598.639753] barrier_waiting: nr_waiting 1
> > [  598.644231] barrier_waiting: nr_waiting 1
> > [  598.648712] barrier_waiting: nr_waiting 1
> > [  598.653192] barrier_waiting: nr_waiting 1
> > [  598.657671] barrier_waiting: nr_waiting 1
> > [  598.662150] barrier_waiting: nr_waiting 1
> > [  598.666630] barrier_waiting: nr_waiting 1
> > [  598.671111] barrier_waiting: nr_waiting 1
> > [  598.675589] barrier_waiting: nr_waiting 1
> > [  598.680068] barrier_waiting: nr_waiting 1
> > [  598.684547] barrier_waiting: nr_waiting 1
> > [  598.689024] barrier_waiting: nr_waiting 1
> > [  598.693501] barrier_waiting: nr_waiting 1
> > [  598.697982] barrier_waiting: nr_waiting 1
> > [  598.702462] barrier_waiting: nr_waiting 1
> > [  598.706945] barrier_waiting: nr_waiting 1
> > [  598.711425] barrier_waiting: nr_waiting 1
> > [  598.715989] barrier_waiting: nr_waiting 1
> > [  598.720523] barrier_waiting: nr_waiting 1
> > [  598.725014] barrier_waiting: nr_waiting 1
> > [  598.729500] barrier_waiting: nr_waiting 1
> > [  598.733983] barrier_waiting: nr_waiting 1
> > [  598.738465] barrier_waiting: nr_waiting 1
> > [  598.742947] barrier_waiting: nr_waiting 1
> > [  598.747426] barrier_waiting: nr_waiting 1
> > [  598.751909] barrier_waiting: nr_waiting 1
> > [  598.756390] barrier_waiting: nr_waiting 1
> > [  598.760869] barrier_waiting: nr_waiting 1
> > [  598.765360] barrier_waiting: nr_waiting 1
> > [  598.769839] barrier_waiting: nr_waiting 1
> > [  598.774318] barrier_waiting: nr_waiting 1
> > [  598.778801] barrier_waiting: nr_waiting 1
> > [  598.783280] barrier_waiting: nr_waiting 1
> > [  598.787758] barrier_waiting: nr_waiting 1
> > [  598.792242] barrier_waiting: nr_waiting 1
> > [  598.796723] barrier_waiting: nr_waiting 1
> > [  598.801200] barrier_waiting: nr_waiting 1
> > [  598.805688] barrier_waiting: nr_waiting 1
> > [  598.810166] barrier_waiting: nr_waiting 1
> > [  598.814646] barrier_waiting: nr_waiting 1
> > [  598.819126] barrier_waiting: nr_waiting 1
> > [  598.823606] barrier_waiting: nr_waiting 1
> > [  598.828086] barrier_waiting: nr_waiting 1
> > [  598.832574] barrier_waiting: nr_waiting 1
> > [  598.837052] barrier_waiting: nr_waiting 1
> > [  598.841531] barrier_waiting: nr_waiting 1
> > [  598.846012] barrier_waiting: nr_waiting 1
> > [  598.850491] barrier_waiting: nr_waiting 1
> > [  598.854969] barrier_waiting: nr_waiting 1
> > [  598.859456] barrier_waiting: nr_waiting 1
> > [  598.863934] barrier_waiting: nr_waiting 1
> > [  598.868412] barrier_waiting: nr_waiting 1
> > [  598.872895] barrier_waiting: nr_waiting 1
> > [  598.877374] barrier_waiting: nr_waiting 1
> > [  598.881853] barrier_waiting: nr_waiting 1
> > [  598.886334] barrier_waiting: nr_waiting 1
> > [  598.890813] barrier_waiting: nr_waiting 1
> > [  598.895293] barrier_waiting: nr_waiting 1
> > [  598.899774] barrier_waiting: nr_waiting 1
> > [  598.904253] barrier_waiting: nr_waiting 1
> > [  598.908735] barrier_waiting: nr_waiting 1
> > [  598.913215] barrier_waiting: nr_waiting 1
> > [  598.917694] barrier_waiting: nr_waiting 1
> > [  598.922173] barrier_waiting: nr_waiting 1
> > [  598.926663] barrier_waiting: nr_waiting 1
> > [  598.931153] barrier_waiting: nr_waiting 1
> > [  598.935638] barrier_waiting: nr_waiting 1
> > [  598.940115] barrier_waiting: nr_waiting 1
> > [  598.944599] barrier_waiting: nr_waiting 1
> > [  598.949080] barrier_waiting: nr_waiting 1
> > [  598.953561] barrier_waiting: nr_waiting 1
> > [  598.958042] barrier_waiting: nr_waiting 1
> > [  598.962523] barrier_waiting: nr_waiting 1
> > [  598.967006] barrier_waiting: nr_waiting 1
> > [  598.971486] barrier_waiting: nr_waiting 1
> > [  598.975965] barrier_waiting: nr_waiting 1
> > [  598.980446] barrier_waiting: nr_waiting 1
> > [  598.984923] barrier_waiting: nr_waiting 1
> > [  598.989408] barrier_waiting: nr_waiting 1
> > [  598.993890] barrier_waiting: nr_waiting 1
> > [  598.998367] barrier_waiting: nr_waiting 1
> > [  599.002844] barrier_waiting: nr_waiting 1
> > [  599.007328] barrier_waiting: nr_waiting 1
> > [  599.011800] barrier_waiting: nr_waiting 1
> > [  599.016278] barrier_waiting: nr_waiting 1
> > [  599.020756] barrier_waiting: nr_waiting 1
> > [  599.025241] barrier_waiting: nr_waiting 1
> > [  599.029720] barrier_waiting: nr_waiting 1
> > [  599.034199] barrier_waiting: nr_waiting 1
> > [  599.038682] barrier_waiting: nr_waiting 1
> > [  599.043161] barrier_waiting: nr_waiting 1
> > [  599.047641] barrier_waiting: nr_waiting 1
> > [  599.052120] barrier_waiting: nr_waiting 1
> > [  599.056601] barrier_waiting: nr_waiting 1
> > [  599.061082] barrier_waiting: nr_waiting 1
> > [  599.065567] barrier_waiting: nr_waiting 1
> > [  599.070045] barrier_waiting: nr_waiting 1
> > [  599.074522] barrier_waiting: nr_waiting 1
> > [  599.079006] barrier_waiting: nr_waiting 1
> > [  599.083486] barrier_waiting: nr_waiting 1
> > [  599.087968] barrier_waiting: nr_waiting 1
> > [  599.092448] barrier_waiting: nr_waiting 1
> > [  599.096929] barrier_waiting: nr_waiting 1
> > [  599.101407] barrier_waiting: nr_waiting 1
> > [  599.105886] barrier_waiting: nr_waiting 1
> > [  599.110366] barrier_waiting: nr_waiting 1
> > [  599.114850] barrier_waiting: nr_waiting 1
> > [  599.119332] barrier_waiting: nr_waiting 1
> > [  599.123809] barrier_waiting: nr_waiting 1
> > [  599.128293] barrier_waiting: nr_waiting 1
> > [  599.132765] barrier_waiting: nr_waiting 1
> > [  599.137242] barrier_waiting: nr_waiting 1
> > [  599.141723] barrier_waiting: nr_waiting 1
> > [  599.146203] barrier_waiting: nr_waiting 1
> > [  599.150682] barrier_waiting: nr_waiting 1
> > [  599.155165] barrier_waiting: nr_waiting 1
> > [  599.159644] barrier_waiting: nr_waiting 1
> > [  599.164124] barrier_waiting: nr_waiting 1
> > [  599.168603] barrier_waiting: nr_waiting 1
> > [  599.173080] barrier_waiting: nr_waiting 1
> > [  599.177564] barrier_waiting: nr_waiting 1
> > [  599.182043] barrier_waiting: nr_waiting 1
> > [  599.186525] barrier_waiting: nr_waiting 1
> > [  599.191008] barrier_waiting: nr_waiting 1
> > [  599.195488] barrier_waiting: nr_waiting 1
> > [  599.199967] barrier_waiting: nr_waiting 1
> > [  599.204448] barrier_waiting: nr_waiting 1
> > [  599.208928] barrier_waiting: nr_waiting 1
> > [  599.213408] barrier_waiting: nr_waiting 1
> > [  599.217890] barrier_waiting: nr_waiting 1
> > [  599.222370] barrier_waiting: nr_waiting 1
> > [  599.226850] barrier_waiting: nr_waiting 1
> > [  599.231329] barrier_waiting: nr_waiting 1
> > [  599.235811] barrier_waiting: nr_waiting 1
> > [  599.240289] barrier_waiting: nr_waiting 1
> > [  599.244767] barrier_waiting: nr_waiting 1
> > [  599.249247] barrier_waiting: nr_waiting 1
> > [  599.253731] barrier_waiting: nr_waiting 1
> > [  599.258212] barrier_waiting: nr_waiting 1
> > [  599.262691] barrier_waiting: nr_waiting 1
> > [  599.267170] barrier_waiting: nr_waiting 1
> > [  599.271650] barrier_waiting: nr_waiting 1
> > [  599.276128] barrier_waiting: nr_waiting 1
> > [  599.280606] barrier_waiting: nr_waiting 1
> > [  599.285084] barrier_waiting: nr_waiting 1
> > [  599.289569] barrier_waiting: nr_waiting 1
> > [  599.294040] barrier_waiting: nr_waiting 1
> > [  599.298522] barrier_waiting: nr_waiting 1
> > [  599.303006] barrier_waiting: nr_waiting 1
> > [  599.307483] barrier_waiting: nr_waiting 1
> > [  599.311961] barrier_waiting: nr_waiting 1
> > [  599.316442] barrier_waiting: nr_waiting 1
> > [  599.320923] barrier_waiting: nr_waiting 1
> > [  599.325403] barrier_waiting: nr_waiting 1
> > [  599.329884] barrier_waiting: nr_waiting 1
> > [  599.334363] barrier_waiting: nr_waiting 1
> > [  599.338842] barrier_waiting: nr_waiting 1
> > [  599.343322] barrier_waiting: nr_waiting 1
> > [  599.347801] barrier_waiting: nr_waiting 1
> > [  599.352282] barrier_waiting: nr_waiting 1
> > [  599.356762] barrier_waiting: nr_waiting 1
> > [  599.361246] barrier_waiting: nr_waiting 1
> > [  599.365727] barrier_waiting: nr_waiting 1
> > [  599.370206] barrier_waiting: nr_waiting 1
> > [  599.374685] barrier_waiting: nr_waiting 1
> > [  599.379166] barrier_waiting: nr_waiting 1
> > [  599.383647] barrier_waiting: nr_waiting 1
> > [  599.388125] barrier_waiting: nr_waiting 1
> > [  599.392605] barrier_waiting: nr_waiting 1
> > [  599.397083] barrier_waiting: nr_waiting 1
> > [  599.401562] barrier_waiting: nr_waiting 1
> > [  599.406044] barrier_waiting: nr_waiting 1
> > [  599.410525] barrier_waiting: nr_waiting 1
> > [  599.415008] barrier_waiting: nr_waiting 1
> > [  599.419486] barrier_waiting: nr_waiting 1
> > [  599.423968] barrier_waiting: nr_waiting 1
> > [  599.428446] barrier_waiting: nr_waiting 1
> > [  599.432924] barrier_waiting: nr_waiting 1
> > [  599.437409] barrier_waiting: nr_waiting 1
> > [  599.441890] barrier_waiting: nr_waiting 1
> > [  599.446373] barrier_waiting: nr_waiting 1
> > [  599.450859] barrier_waiting: nr_waiting 1
> > [  599.455337] barrier_waiting: nr_waiting 1
> > [  599.459819] barrier_waiting: nr_waiting 1
> > [  599.464306] barrier_waiting: nr_waiting 1
> > [  599.468783] barrier_waiting: nr_waiting 1
> > [  599.473262] barrier_waiting: nr_waiting 1
> > [  599.477744] barrier_waiting: nr_waiting 1
> > [  599.482224] barrier_waiting: nr_waiting 1
> > [  599.486704] barrier_waiting: nr_waiting 1
> > [  599.491190] barrier_waiting: nr_waiting 1
> > [  599.495670] barrier_waiting: nr_waiting 1
> > [  599.500150] barrier_waiting: nr_waiting 1
> > [  599.504629] barrier_waiting: nr_waiting 1
> > [  599.509106] barrier_waiting: nr_waiting 1
> > [  599.513588] barrier_waiting: nr_waiting 1
> > [  599.518072] barrier_waiting: nr_waiting 1
> > [  599.522552] barrier_waiting: nr_waiting 1
> > [  599.527030] barrier_waiting: nr_waiting 1
> > [  599.531509] barrier_waiting: nr_waiting 1
> > [  599.535988] barrier_waiting: nr_waiting 1
> > [  599.540470] barrier_waiting: nr_waiting 1
> > [  599.544955] barrier_waiting: nr_waiting 1
> > [  599.549426] barrier_waiting: nr_waiting 1
> > [  599.553904] barrier_waiting: nr_waiting 1
> > [  599.558384] barrier_waiting: nr_waiting 1
> > [  599.562863] barrier_waiting: nr_waiting 1
> > [  599.567342] barrier_waiting: nr_waiting 1
> > [  599.571820] barrier_waiting: nr_waiting 1
> > [  599.576298] barrier_waiting: nr_waiting 1
> > [  599.580779] barrier_waiting: nr_waiting 1
> > [  599.585254] wait_barrier: nr_pending: 1
> > [  599.589540] try_raise_barrier: nr_pending 1
> > [  599.589547] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  599.594209] try_raise_barrier: nr_pending 1
> > [  599.605582] try_raise_barrier: nr_pending 1
> > [  599.605674] allow_barrier: nr_pending: 0
> > [  599.610620] wait_barrier: nr_pending: 1
> > [  599.614653] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  599.618935] try_raise_barrier: nr_pending 1
> > [  599.618938] try_raise_barrier: nr_pending 1
> > [  599.618965] raid10_read_request: r10_bio ff3b4134184a6100 start
> > [  599.641092] try_raise_barrier: nr_pending 1
> > [  599.641145] allow_barrier: nr_pending: 0
> > [  599.646251] wait_barrier: nr_pending: 1
> > [  599.650157] raid_end_bio_io: r10_bio ff3b4134184a6100 done
> > [  599.654437] try_raise_barrier: nr_pending 1
> > [  599.654446] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  599.654575] allow_barrier: nr_pending: 0
> > [  599.654583] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  599.682715] wait_barrier: nr_pending: 1
> > [  599.687000] try_raise_barrier: nr_pending 1
> > [  599.687012] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  599.691672] try_raise_barrier: nr_pending 1
> > [  599.703020] try_raise_barrier: nr_pending 1
> > [  599.703069] allow_barrier: nr_pending: 0
> > [  599.708037] wait_barrier: nr_pending: 1
> > [  599.712092] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  599.716368] try_raise_barrier: nr_pending 1
> > [  599.716372] try_raise_barrier: nr_pending 1
> > [  599.716377] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  599.738510] try_raise_barrier: nr_pending 1
> > [  599.738554] allow_barrier: nr_pending: 0
> > [  599.743663] wait_barrier: nr_pending: 1
> > [  599.747583] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  599.751853] try_raise_barrier: nr_pending 1
> > [  599.751857] try_raise_barrier: nr_pending 1
> > [  599.751864] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  599.773945] try_raise_barrier: nr_pending 1
> > [  599.774058] allow_barrier: nr_pending: 0
> > [  599.779116] wait_barrier: nr_pending: 1
> > [  599.783020] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  599.787298] try_raise_barrier: nr_pending 1
> > [  599.787307] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  599.787461] allow_barrier: nr_pending: 0
> > [  599.787469] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  599.815585] wait_barrier: nr_pending: 1
> > [  599.819872] try_raise_barrier: nr_pending 1
> > [  599.819883] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  599.824546] try_raise_barrier: nr_pending 1
> > [  599.835892] try_raise_barrier: nr_pending 1
> > [  599.835904] allow_barrier: nr_pending: 0
> > [  599.840922] wait_barrier: nr_pending: 1
> > [  599.844957] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  599.849235] try_raise_barrier: nr_pending 1
> > [  599.849239] try_raise_barrier: nr_pending 1
> > [  599.849244] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  599.871381] try_raise_barrier: nr_pending 1
> > [  599.871463] allow_barrier: nr_pending: 0
> > [  599.876542] wait_barrier: nr_pending: 1
> > [  599.880451] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  599.884730] try_raise_barrier: nr_pending 1
> > [  599.884735] try_raise_barrier: nr_pending 1
> > [  599.884740] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  599.884889] allow_barrier: nr_pending: 0
> > [  599.884897] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  599.917789] wait_barrier: nr_pending: 1
> > [  599.922088] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  599.922159] try_raise_barrier: nr_pending 1
> > [  599.928829] allow_barrier: nr_pending: 0
> > [  599.933736] wait_barrier: nr_pending: 1
> > [  599.937771] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  599.942045] try_raise_barrier: nr_pending 1
> > [  599.942049] try_raise_barrier: nr_pending 1
> > [  599.942058] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  599.964202] try_raise_barrier: nr_pending 1
> > [  599.964262] allow_barrier: nr_pending: 0
> > [  599.969461] wait_barrier: nr_pending: 1
> > [  599.973275] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  599.977553] try_raise_barrier: nr_pending 1
> > [  599.977559] try_raise_barrier: nr_pending 1
> > [  599.977562] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  599.977715] allow_barrier: nr_pending: 0
> > [  599.977723] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.010600] wait_barrier: nr_pending: 1
> > [  600.014887] try_raise_barrier: nr_pending 1
> > [  600.014898] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  600.019559] try_raise_barrier: nr_pending 1
> > [  600.030909] try_raise_barrier: nr_pending 1
> > [  600.030917] allow_barrier: nr_pending: 0
> > [  600.036049] wait_barrier: nr_pending: 1
> > [  600.039974] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  600.044253] try_raise_barrier: nr_pending 1
> > [  600.044257] try_raise_barrier: nr_pending 1
> > [  600.044263] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  600.066363] try_raise_barrier: nr_pending 1
> > [  600.066461] allow_barrier: nr_pending: 0
> > [  600.071440] wait_barrier: nr_pending: 1
> > [  600.075443] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  600.079722] try_raise_barrier: nr_pending 1
> > [  600.079727] try_raise_barrier: nr_pending 1
> > [  600.079731] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.079868] allow_barrier: nr_pending: 0
> > [  600.079875] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.112682] wait_barrier: nr_pending: 1
> > [  600.116967] try_raise_barrier: nr_pending 1
> > [  600.116978] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.121640] try_raise_barrier: nr_pending 1
> > [  600.132990] try_raise_barrier: nr_pending 1
> > [  600.133057] allow_barrier: nr_pending: 0
> > [  600.138070] wait_barrier: nr_pending: 1
> > [  600.142062] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.146337] try_raise_barrier: nr_pending 1
> > [  600.146342] try_raise_barrier: nr_pending 1
> > [  600.146348] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  600.168487] try_raise_barrier: nr_pending 1
> > [  600.168532] allow_barrier: nr_pending: 0
> > [  600.173662] wait_barrier: nr_pending: 1
> > [  600.177563] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  600.181840] try_raise_barrier: nr_pending 1
> > [  600.181845] try_raise_barrier: nr_pending 1
> > [  600.181849] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.181983] allow_barrier: nr_pending: 0
> > [  600.181991] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.214790] wait_barrier: nr_pending: 1
> > [  600.219075] try_raise_barrier: nr_pending 1
> > [  600.219087] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  600.223748] try_raise_barrier: nr_pending 1
> > [  600.235099] try_raise_barrier: nr_pending 1
> > [  600.235150] allow_barrier: nr_pending: 0
> > [  600.240130] wait_barrier: nr_pending: 1
> > [  600.244170] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  600.248446] try_raise_barrier: nr_pending 1
> > [  600.248450] try_raise_barrier: nr_pending 1
> > [  600.248456] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  600.270600] try_raise_barrier: nr_pending 1
> > [  600.270648] allow_barrier: nr_pending: 0
> > [  600.275752] wait_barrier: nr_pending: 1
> > [  600.279676] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  600.283952] try_raise_barrier: nr_pending 1
> > [  600.283956] try_raise_barrier: nr_pending 1
> > [  600.283961] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.284093] allow_barrier: nr_pending: 0
> > [  600.284100] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.316975] wait_barrier: nr_pending: 1
> > [  600.321262] try_raise_barrier: nr_pending 1
> > [  600.321273] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.325936] try_raise_barrier: nr_pending 1
> > [  600.337279] allow_barrier: nr_pending: 0
> > [  600.337649] wait_barrier: nr_pending: 1
> > [  600.341674] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.345947] try_raise_barrier: nr_pending 1
> > [  600.345951] try_raise_barrier: nr_pending 1
> > [  600.345958] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  600.368088] try_raise_barrier: nr_pending 1
> > [  600.368129] allow_barrier: nr_pending: 0
> > [  600.373070] wait_barrier: nr_pending: 1
> > [  600.377153] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  600.381430] try_raise_barrier: nr_pending 1
> > [  600.381434] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.381555] allow_barrier: nr_pending: 0
> > [  600.381562] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.409730] wait_barrier: nr_pending: 1
> > [  600.414012] try_raise_barrier: nr_pending 1
> > [  600.414015] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  600.418685] try_raise_barrier: nr_pending 1
> > [  600.430034] try_raise_barrier: nr_pending 1
> > [  600.430085] allow_barrier: nr_pending: 0
> > [  600.435126] wait_barrier: nr_pending: 1
> > [  600.439107] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  600.443388] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  600.443462] try_raise_barrier: nr_pending 1
> > [  600.443466] try_raise_barrier: nr_pending 1
> > [  600.465548] try_raise_barrier: nr_pending 1
> > [  600.465585] allow_barrier: nr_pending: 0
> > [  600.470613] wait_barrier: nr_pending: 1
> > [  600.474627] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  600.478903] try_raise_barrier: nr_pending 1
> > [  600.478910] try_raise_barrier: nr_pending 1
> > [  600.478912] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.479045] allow_barrier: nr_pending: 0
> > [  600.479053] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.511838] wait_barrier: nr_pending: 1
> > [  600.516124] try_raise_barrier: nr_pending 1
> > [  600.516135] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.520797] try_raise_barrier: nr_pending 1
> > [  600.532156] try_raise_barrier: nr_pending 1
> > [  600.532225] allow_barrier: nr_pending: 0
> > [  600.537288] wait_barrier: nr_pending: 1
> > [  600.541229] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.545505] try_raise_barrier: nr_pending 1
> > [  600.545509] try_raise_barrier: nr_pending 1
> > [  600.545515] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  600.567662] try_raise_barrier: nr_pending 1
> > [  600.567696] allow_barrier: nr_pending: 0
> > [  600.572778] wait_barrier: nr_pending: 1
> > [  600.576742] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  600.581017] try_raise_barrier: nr_pending 1
> > [  600.581023] try_raise_barrier: nr_pending 1
> > [  600.581028] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.581145] allow_barrier: nr_pending: 0
> > [  600.581152] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.613893] wait_barrier: nr_pending: 1
> > [  600.618178] try_raise_barrier: nr_pending 1
> > [  600.618188] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  600.622851] try_raise_barrier: nr_pending 1
> > [  600.634242] try_raise_barrier: nr_pending 1
> > [  600.634317] allow_barrier: nr_pending: 0
> > [  600.639159] wait_barrier: nr_pending: 1
> > [  600.643299] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  600.647575] try_raise_barrier: nr_pending 1
> > [  600.647579] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  600.647579] try_raise_barrier: nr_pending 1
> > [  600.647633] allow_barrier: nr_pending: 0
> > [  600.647637] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  600.680526] wait_barrier: nr_pending: 1
> > [  600.684819] try_raise_barrier: nr_pending 1
> > [  600.684841] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.689492] try_raise_barrier: nr_pending 1
> > [  600.700853] try_raise_barrier: nr_pending 1
> > [  600.700910] allow_barrier: nr_pending: 0
> > [  600.706030] wait_barrier: nr_pending: 1
> > [  600.709914] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.714193] try_raise_barrier: nr_pending 1
> > [  600.714197] try_raise_barrier: nr_pending 1
> > [  600.714205] raid10_read_request: r10_bio ff3b4134184a6100 start
> > [  600.714376] allow_barrier: nr_pending: 0
> > [  600.714383] raid_end_bio_io: r10_bio ff3b4134184a6100 done
> > [  600.747144] wait_barrier: nr_pending: 1
> > [  600.751430] try_raise_barrier: nr_pending 1
> > [  600.751442] raid10_read_request: r10_bio ff3b4134184a6b00 start
> > [  600.756102] try_raise_barrier: nr_pending 1
> > [  600.767448] try_raise_barrier: nr_pending 1
> > [  600.767537] allow_barrier: nr_pending: 0
> > [  600.772502] wait_barrier: nr_pending: 1
> > [  600.776516] raid_end_bio_io: r10_bio ff3b4134184a6b00 done
> > [  600.780795] try_raise_barrier: nr_pending 1
> > [  600.780799] try_raise_barrier: nr_pending 1
> > [  600.780808] raid10_read_request: r10_bio ff3b4134184a7f00 start
> > [  600.802876] try_raise_barrier: nr_pending 1
> > [  600.803016] allow_barrier: nr_pending: 0
> > [  600.808000] wait_barrier: nr_pending: 1
> > [  600.811943] raid_end_bio_io: r10_bio ff3b4134184a7f00 done
> > [  600.816225] try_raise_barrier: nr_pending 1
> > [  600.816229] try_raise_barrier: nr_pending 1
> > [  600.816245] raid10_read_request: r10_bio ff3b4134184a7400 start
> > [  600.838385] try_raise_barrier: nr_pending 1
> > [  600.838448] allow_barrier: nr_pending: 0
> > [  600.843556] wait_barrier: nr_pending: 1
> > [  600.847451] raid_end_bio_io: r10_bio ff3b4134184a7400 done
> > [  600.851722] try_raise_barrier: nr_pending 1
> > [  600.851726] try_raise_barrier: nr_pending 1
> > [  600.851732] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.851897] allow_barrier: nr_pending: 0
> > [  600.851904] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.884632] wait_barrier: nr_pending: 1
> > [  600.888917] try_raise_barrier: nr_pending 1
> > [  600.888929] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.893588] try_raise_barrier: nr_pending 1
> > [  600.904881] try_raise_barrier: nr_pending 1
> > [  600.905028] allow_barrier: nr_pending: 0
> > [  600.909930] wait_barrier: nr_pending: 1
> > [  600.913958] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  600.918233] try_raise_barrier: nr_pending 1
> > [  600.918237] try_raise_barrier: nr_pending 1
> > [  600.918245] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  600.940401] try_raise_barrier: nr_pending 1
> > [  600.940502] allow_barrier: nr_pending: 0
> > [  600.945589] wait_barrier: nr_pending: 1
> > [  600.949477] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  600.953755] try_raise_barrier: nr_pending 1
> > [  600.953760] try_raise_barrier: nr_pending 1
> > [  600.953765] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  600.953893] allow_barrier: nr_pending: 0
> > [  600.953901] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  600.986653] wait_barrier: nr_pending: 1
> > [  600.990939] try_raise_barrier: nr_pending 1
> > [  600.990949] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  600.995611] try_raise_barrier: nr_pending 1
> > [  601.006963] try_raise_barrier: nr_pending 1
> > [  601.007109] allow_barrier: nr_pending: 0
> > [  601.011808] wait_barrier: nr_pending: 1
> > [  601.016031] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  601.020309] try_raise_barrier: nr_pending 1
> > [  601.020313] try_raise_barrier: nr_pending 1
> > [  601.020319] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  601.042453] allow_barrier: nr_pending: 0
> > [  601.042803] wait_barrier: nr_pending: 1
> > [  601.046853] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  601.051120] try_raise_barrier: nr_pending 1
> > [  601.051125] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  601.051126] try_raise_barrier: nr_pending 1
> > [  601.051145] try_raise_barrier: nr_pending 1
> > [  601.051415] allow_barrier: nr_pending: 0
> > [  601.051422] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  601.088815] wait_barrier: nr_pending: 1
> > [  601.093099] try_raise_barrier: nr_pending 1
> > [  601.093111] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  601.097772] try_raise_barrier: nr_pending 1
> > [  601.109103] try_raise_barrier: nr_pending 1
> > [  601.109172] allow_barrier: nr_pending: 0
> > [  601.114259] wait_barrier: nr_pending: 1
> > [  601.118177] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  601.122446] try_raise_barrier: nr_pending 1
> > [  601.122450] try_raise_barrier: nr_pending 1
> > [  601.122459] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  601.144607] try_raise_barrier: nr_pending 1
> > [  601.144650] allow_barrier: nr_pending: 0
> > [  601.149688] wait_barrier: nr_pending: 1
> > [  601.153683] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  601.157960] try_raise_barrier: nr_pending 1
> > [  601.157964] try_raise_barrier: nr_pending 1
> > [  601.157970] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  601.180129] try_raise_barrier: nr_pending 1
> > [  601.180240] allow_barrier: nr_pending: 0
> > [  601.185207] wait_barrier: nr_pending: 1
> > [  601.189209] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  601.193485] try_raise_barrier: nr_pending 1
> > [  601.193497] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  601.193706] allow_barrier: nr_pending: 0
> > [  601.193714] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  601.221868] wait_barrier: nr_pending: 1
> > [  601.226153] try_raise_barrier: nr_pending 1
> > [  601.226164] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  601.230826] try_raise_barrier: nr_pending 1
> > [  601.242175] try_raise_barrier: nr_pending 1
> > [  601.242239] allow_barrier: nr_pending: 0
> > [  601.247321] wait_barrier: nr_pending: 1
> > [  601.251249] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  601.255526] try_raise_barrier: nr_pending 1
> > [  601.255530] try_raise_barrier: nr_pending 1
> > [  601.255536] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  601.277688] try_raise_barrier: nr_pending 1
> > [  601.277818] allow_barrier: nr_pending: 0
> > [  601.282730] wait_barrier: nr_pending: 1
> > [  601.286761] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  601.291037] try_raise_barrier: nr_pending 1
> > [  601.291043] try_raise_barrier: nr_pending 1
> > [  601.291047] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  601.313190] try_raise_barrier: nr_pending 1
> > [  601.313248] allow_barrier: nr_pending: 0
> > [  601.318267] wait_barrier: nr_pending: 1
> > [  601.322269] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  601.326544] try_raise_barrier: nr_pending 1
> > [  601.326551] try_raise_barrier: nr_pending 1
> > [  601.326556] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  601.326708] allow_barrier: nr_pending: 0
> > [  601.326716] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  601.359595] wait_barrier: nr_pending: 1
> > [  601.363882] try_raise_barrier: nr_pending 1
> > [  601.363893] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  601.368556] try_raise_barrier: nr_pending 1
> > [  601.379906] try_raise_barrier: nr_pending 1
> > [  601.379973] allow_barrier: nr_pending: 0
> > [  601.385040] wait_barrier: nr_pending: 1
> > [  601.388979] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  601.393255] try_raise_barrier: nr_pending 1
> > [  601.393260] try_raise_barrier: nr_pending 1
> > [  601.393268] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  601.415361] try_raise_barrier: nr_pending 1
> > [  601.415483] allow_barrier: nr_pending: 0
> > [  601.420443] wait_barrier: nr_pending: 1
> > [  601.424436] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  601.428713] try_raise_barrier: nr_pending 1
> > [  601.428716] try_raise_barrier: nr_pending 1
> > [  601.428723] raid10_read_request: r10_bio ff3b41340eb53600 start
> > [  601.450871] try_raise_barrier: nr_pending 1
> > [  601.450916] allow_barrier: nr_pending: 0
> > [  601.455878] wait_barrier: nr_pending: 1
> > [  601.459951] raid_end_bio_io: r10_bio ff3b41340eb53600 done
> > [  601.464227] try_raise_barrier: nr_pending 1
> > [  601.464231] raid10_read_request: r10_bio ff3b41340eb52d00 start
> > [  601.481634] try_raise_barrier: nr_pending 1
> > [  601.486439] allow_barrier: nr_pending: 0
> > [  601.486947] wait_barrier: nr_pending: 1
> > [  601.490841] raid_end_bio_io: r10_bio ff3b41340eb52d00 done
> > [  601.495112] try_raise_barrier: nr_pending 1
> > [  601.495116] try_raise_barrier: nr_pending 1
> > [  601.495122] raid10_read_request: r10_bio ff3b41340eb53900 start
> > [  601.517260] try_raise_barrier: nr_pending 1
> > [  601.517346] allow_barrier: nr_pending: 0
> > [  601.522456] wait_barrier: nr_pending: 1
> > [  601.526326] raid_end_bio_io: r10_bio ff3b41340eb53900 done
> > [  601.530603] try_raise_barrier: nr_pending 1
> > [  601.530608] try_raise_barrier: nr_pending 1
> > [  601.530612] raid10_write_request: r10_bio ff3b41340eb52d00 start
> > [  601.552782] try_raise_barrier: nr_pending 1
>
> Thanks for the test!
>
> Now the problem is clear. r10_bio is generated and never complete, while
> IO never issued to underlying loop device, and I can reporduce this
> problem as well now.
>
> The blamed commit from git bisect is correct, and there are two
> conditions for this problem:
>
> 1) plug is not used for caller;
> 2) for raid1/raid10, bio plug is enabled;
>
> __submit_bio_noacct
>   current->bio_list = ...;
>   blk_start_plug
>
>    dm_submit_bio
>     md_handle_request
>      raid10_write_request
>       -> generate new bio for underlying disks
>       raid1_add_bio_to_plug -> bio added to plug
>
>   blk_finish_plug
>    raid10_unplug
>     raid1_submit_write
>      submit_bio_noacct
>       if (current->bio_list)
>        -> bio_list is not empty
>        bio_list_add(&current->bio_list[0], bio)
>
>   current->bio_list = NULL
>   -> the bio is in bio_list, and it's dropped.
>
> Can you give the following patch a test? It should be a final test...

Hi，Kuai

yeah, I would like to testing the fix patch，but I hit the patching
issue with new patch：
```
patching file block/blk-core.c
patch: **** malformed patch at line 6: blk_check_zone_append(struct
request_queue *q,
```
I don’t know if it is caused by a format error.
please add the patch as an attachment, just like the debuginfo patch
you gave me this morning.

Thanks，
Changhui


>
> Thanks,
> Kuai
>
> diff --git a/block/blk-core.c b/block/blk-core.c
> index 01186333c88e..1e9208024e47 100644
> --- a/block/blk-core.c
> +++ b/block/blk-core.c
> @@ -613,9 +613,13 @@ static inline blk_status_t
> blk_check_zone_append(struct request_queue *q,
>
>   static void __submit_bio(struct bio *bio)
>   {
> +       struct blk_plug plug;
> +
>          if (unlikely(!blk_crypto_bio_prep(&bio)))
>                  return;
>
> +       blk_start_plug(&plug);
> +
>          if (!bio->bi_bdev->bd_has_submit_bio) {
>                  blk_mq_submit_bio(bio);
>          } else if (likely(bio_queue_enter(bio) == 0)) {
> @@ -624,6 +628,8 @@ static void __submit_bio(struct bio *bio)
>                  disk->fops->submit_bio(bio);
>                  blk_queue_exit(disk->queue);
>          }
> +
> +       blk_finish_plug(&plug);
>   }
>
>   /*
> @@ -648,13 +654,11 @@ static void __submit_bio(struct bio *bio)
>   static void __submit_bio_noacct(struct bio *bio)
>   {
>          struct bio_list bio_list_on_stack[2];
> -       struct blk_plug plug;
>
>          BUG_ON(bio->bi_next);
>
>          bio_list_init(&bio_list_on_stack[0]);
>          current->bio_list = bio_list_on_stack;
> -       blk_start_plug(&plug);
>
>          do {
>                  struct request_queue *q = bdev_get_queue(bio->bi_bdev);
> @@ -688,23 +692,19 @@ static void __submit_bio_noacct(struct bio *bio)
>                  bio_list_merge(&bio_list_on_stack[0],
> &bio_list_on_stack[1]);
>          } while ((bio = bio_list_pop(&bio_list_on_stack[0])));
>
> -       blk_finish_plug(&plug);
>          current->bio_list = NULL;
>   }
>
>   static void __submit_bio_noacct_mq(struct bio *bio)
>   {
>          struct bio_list bio_list[2] = { };
> -       struct blk_plug plug;
>
>          current->bio_list = bio_list;
> -       blk_start_plug(&plug);
>
>          do {
>                  __submit_bio(bio);
>          } while ((bio = bio_list_pop(&bio_list[0])));
>
> -       blk_finish_plug(&plug);
>          current->bio_list = NULL;
>   }
>
> > [  737.970751] INFO: task mdX_resync:3115 blocked for more than 122 seconds.
> > [  737.978361]       Not tainted 6.9.0+ #1
> > [  737.982654] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > disables this message.
> > [  737.991398] task:mdX_resync      state:D stack:0     pid:3115
> > tgid:3115  ppid:2      flags:0x00004000
> > [  737.991407] Call Trace:
> > [  737.991410]  <TASK>
> > [  737.991414]  __schedule+0x222/0x670
> > [  737.991426]  schedule+0x2c/0xb0
> > [  737.991434]  raise_barrier+0xca/0x1a0 [raid10]
> > [  737.991450]  ? __pfx_autoremove_wake_function+0x10/0x10
> > [  737.991459]  raid10_sync_request+0x2c3/0x19d0 [raid10]
> > [  737.991472]  ? __switch_to_asm+0x39/0x70
> > [  737.991478]  ? finish_task_switch.isra.0+0x8e/0x2a0
> > [  737.991487]  ? __schedule+0x22a/0x670
> > [  737.991491]  ? prepare_to_wait_event+0x5f/0x190
> > [  737.991498]  md_do_sync+0x660/0x1040
> > [  737.991508]  ? __pfx_autoremove_wake_function+0x10/0x10
> > [  737.991517]  md_thread+0xad/0x160
> > [  737.991521]  ? __pfx_md_thread+0x10/0x10
> > [  737.991524]  kthread+0xdc/0x110
> > [  737.991531]  ? __pfx_kthread+0x10/0x10
> > [  737.991535]  ret_from_fork+0x2d/0x50
> > [  737.991544]  ? __pfx_kthread+0x10/0x10
> > [  737.991547]  ret_from_fork_asm+0x1a/0x30
> > [  737.991553]  </TASK>
> > [  860.850998] INFO: task mdX_resync:3115 blocked for more than 245 seconds.
> > [  860.858606]       Not tainted 6.9.0+ #1
> > [  860.862902] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > disables this message.
> > [  860.871649] task:mdX_resync      state:D stack:0     pid:3115
> > tgid:3115  ppid:2      flags:0x00004000
> > [  860.871658] Call Trace:
> > [  860.871660]  <TASK>
> > [  860.871664]  __schedule+0x222/0x670
> > [  860.871674]  schedule+0x2c/0xb0
> > [  860.871681]  raise_barrier+0xca/0x1a0 [raid10]
> > [  860.871696]  ? __pfx_autoremove_wake_function+0x10/0x10
> > [  860.871704]  raid10_sync_request+0x2c3/0x19d0 [raid10]
> > [  860.871717]  ? __switch_to_asm+0x39/0x70
> > [  860.871722]  ? finish_task_switch.isra.0+0x8e/0x2a0
> > [  860.871729]  ? __schedule+0x22a/0x670
> > [  860.871733]  ? prepare_to_wait_event+0x5f/0x190
> > [  860.871740]  md_do_sync+0x660/0x1040
> > [  860.871748]  ? __pfx_autoremove_wake_function+0x10/0x10
> > [  860.871756]  md_thread+0xad/0x160
> > [  860.871761]  ? __pfx_md_thread+0x10/0x10
> > [  860.871765]  kthread+0xdc/0x110
> > [  860.871770]  ? __pfx_kthread+0x10/0x10
> > [  860.871774]  ret_from_fork+0x2d/0x50
> > [  860.871781]  ? __pfx_kthread+0x10/0x10
> > [  860.871785]  ret_from_fork_asm+0x1a/0x30
> > [  860.871790]  </TASK>
> >
> > Thanks,
> > Changhui
> >
> > .
> >
>


-- 

Changhui  Zhong

Quality Engineer,Kernel QE

Red Hat

Red Hat Beijing - Raycom