* [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds
@ 2024-05-16 10:24 Changhui Zhong
2024-05-16 11:21 ` Ming Lei
0 siblings, 1 reply; 18+ messages in thread
From: Changhui Zhong @ 2024-05-16 10:24 UTC (permalink / raw)
To: Linux Block Devices; +Cc: Ming Lei
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
^ permalink raw reply [flat|nested] 18+ messages in thread* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-16 10:24 [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds Changhui Zhong @ 2024-05-16 11:21 ` Ming Lei 2024-05-16 11:42 ` Yu Kuai 0 siblings, 1 reply; 18+ messages in thread From: Ming Lei @ 2024-05-16 11:21 UTC (permalink / raw) To: Changhui Zhong Cc: Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni 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 ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-16 11:21 ` Ming Lei @ 2024-05-16 11:42 ` Yu Kuai 2024-05-17 2:25 ` Changhui Zhong 0 siblings, 1 reply; 18+ messages in thread From: Yu Kuai @ 2024-05-16 11:42 UTC (permalink / raw) To: Ming Lei, Changhui Zhong Cc: Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yukuai (C) 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 >> > ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-16 11:42 ` Yu Kuai @ 2024-05-17 2:25 ` Changhui Zhong 2024-05-17 2:49 ` Yu Kuai 0 siblings, 1 reply; 18+ messages in thread From: Changhui Zhong @ 2024-05-17 2:25 UTC (permalink / raw) To: Yu Kuai Cc: Ming Lei, Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yukuai (C) 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 > >> > > > > ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-17 2:25 ` Changhui Zhong @ 2024-05-17 2:49 ` Yu Kuai 2024-05-19 6:44 ` Changhui Zhong 0 siblings, 1 reply; 18+ messages in thread From: Yu Kuai @ 2024-05-17 2:49 UTC (permalink / raw) To: Changhui Zhong, Yu Kuai Cc: Ming Lei, Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yukuai (C) 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 >>>> >>> >> >> > > . > ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-17 2:49 ` Yu Kuai @ 2024-05-19 6:44 ` Changhui Zhong 2024-05-20 0:39 ` Changhui Zhong 0 siblings, 1 reply; 18+ messages in thread From: Changhui Zhong @ 2024-05-19 6:44 UTC (permalink / raw) To: Yu Kuai Cc: Ming Lei, Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yukuai (C) 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 ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-19 6:44 ` Changhui Zhong @ 2024-05-20 0:39 ` Changhui Zhong 2024-05-20 2:55 ` Yu Kuai 0 siblings, 1 reply; 18+ messages in thread From: Changhui Zhong @ 2024-05-20 0:39 UTC (permalink / raw) To: Yu Kuai Cc: Ming Lei, Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yukuai (C) 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， ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-20 0:39 ` Changhui Zhong @ 2024-05-20 2:55 ` Yu Kuai 2024-05-20 7:27 ` Yu Kuai 2024-05-20 10:38 ` Changhui Zhong 0 siblings, 2 replies; 18+ messages in thread From: Yu Kuai @ 2024-05-20 2:55 UTC (permalink / raw) To: Changhui Zhong, Yu Kuai Cc: Ming Lei, Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yukuai (C) 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 ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-20 2:55 ` Yu Kuai @ 2024-05-20 7:27 ` Yu Kuai 2024-05-20 10:47 ` Changhui Zhong 2024-05-20 10:38 ` Changhui Zhong 1 sibling, 1 reply; 18+ messages in thread From: Yu Kuai @ 2024-05-20 7:27 UTC (permalink / raw) To: Yu Kuai, Changhui Zhong Cc: Ming Lei, Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yukuai (C) 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 > > . > ^ permalink raw reply related [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-20 7:27 ` Yu Kuai @ 2024-05-20 10:47 ` Changhui Zhong 0 siblings, 0 replies; 18+ messages in thread From: Changhui Zhong @ 2024-05-20 10:47 UTC (permalink / raw) To: Yu Kuai Cc: Ming Lei, Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yukuai (C) 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 > > > > . > > > ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-20 2:55 ` Yu Kuai 2024-05-20 7:27 ` Yu Kuai @ 2024-05-20 10:38 ` Changhui Zhong 2024-05-21 1:08 ` Yu Kuai 1 sibling, 1 reply; 18+ messages in thread From: Changhui Zhong @ 2024-05-20 10:38 UTC (permalink / raw) To: Yu Kuai Cc: Ming Lei, Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yukuai (C) 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 ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-20 10:38 ` Changhui Zhong @ 2024-05-21 1:08 ` Yu Kuai 2024-05-21 4:28 ` Changhui Zhong 0 siblings, 1 reply; 18+ messages in thread From: Yu Kuai @ 2024-05-21 1:08 UTC (permalink / raw) To: Changhui Zhong, Yu Kuai Cc: Ming Lei, Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yukuai (C), yangerkun@huawei.com [-- 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 ^ permalink raw reply related [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-21 1:08 ` Yu Kuai @ 2024-05-21 4:28 ` Changhui Zhong 2024-05-21 9:17 ` Yu Kuai 0 siblings, 1 reply; 18+ messages in thread From: Changhui Zhong @ 2024-05-21 4:28 UTC (permalink / raw) To: Yu Kuai Cc: Ming Lei, Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yukuai (C), yangerkun@huawei.com 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 ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-21 4:28 ` Changhui Zhong @ 2024-05-21 9:17 ` Yu Kuai 2024-05-21 11:39 ` Changhui Zhong 0 siblings, 1 reply; 18+ messages in thread From: Yu Kuai @ 2024-05-21 9:17 UTC (permalink / raw) To: Changhui Zhong, Yu Kuai Cc: Ming Lei, Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yangerkun@huawei.com, yukuai (C) 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(¤t->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 > > . > ^ permalink raw reply related [flat|nested] 18+ messages in thread
* Re: [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds 2024-05-21 9:17 ` Yu Kuai @ 2024-05-21 11:39 ` Changhui Zhong 2024-05-21 20:03 ` [PATCH -next] block: fix bio lost for plug enabeld bio based device Yu Kuai 0 siblings, 1 reply; 18+ messages in thread From: Changhui Zhong @ 2024-05-21 11:39 UTC (permalink / raw) To: Yu Kuai Cc: Ming Lei, Linux Block Devices, dm-devel, Mike Snitzer, Mikulas Patocka, Song Liu, linux-raid, Xiao Ni, yangerkun@huawei.com, yukuai (C) 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(¤t->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 ^ permalink raw reply [flat|nested] 18+ messages in thread
* [PATCH -next] block: fix bio lost for plug enabeld bio based device 2024-05-21 11:39 ` Changhui Zhong @ 2024-05-21 20:03 ` Yu Kuai 2024-05-22 0:38 ` Changhui Zhong 2024-05-22 1:38 ` Jens Axboe 0 siblings, 2 replies; 18+ messages in thread From: Yu Kuai @ 2024-05-21 20:03 UTC (permalink / raw) To: czhong, xni, axboe, yukuai3 Cc: linux-block, linux-kernel, yukuai1, yi.zhang, yangerkun From: Yu Kuai <yukuai3@huawei.com> With the following two conditions, bio will be lost: 1) blk plug is not enabled, for example, __blkdev_direct_IO_simple() and __blkdev_direct_IO_async(); 2) bio plug is enabled, for example write IO for raid1/raid10 while bitmap is enabled; Root cause is that blk_finish_plug() will add the bio to curent->bio_list, while such bio will not be handled: __submit_bio_noacct current->bio_list = bio_list_on_stack; blk_start_plug do { dm_submit_bio md_handle_request raid10_write_request -> generate new bio for underlying disks raid1_add_bio_to_plug -> bio is added to plug } while ((bio = bio_list_pop(&bio_list_on_stack[0]))) -> previous bio are all handled blk_finish_plug raid10_unplug raid1_submit_write submit_bio_noacct if (current->bio_list) bio_list_add(¤t->bio_list[0], bio) -> add new bio current->bio_list = NULL -> new bio is lost Fix the problem by moving plug into the while loop, so that current->bio_list will still be handled after blk_finish_plug(). By the way, enable plug for raid1/raid10 in this case will also prevent delay IO handling into daemon thread, which should also improve IO performance. Fixes: 060406c61c7c ("block: add plug while submitting IO") Reported-by: Changhui Zhong <czhong@redhat.com> Closes: https://lore.kernel.org/all/CAGVVp+Xsmzy2G9YuEatfMT6qv1M--YdOCQ0g7z7OVmcTbBxQAg@mail.gmail.com/ Signed-off-by: Yu Kuai <yukuai3@huawei.com> --- block/blk-core.c | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/block/blk-core.c b/block/blk-core.c index 01186333c88e..dd29d5465af6 100644 --- a/block/blk-core.c +++ b/block/blk-core.c @@ -613,9 +613,14 @@ static inline blk_status_t blk_check_zone_append(struct request_queue *q, static void __submit_bio(struct bio *bio) { + /* If plug is not used, add new plug here to cache nsecs time. */ + 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 +629,8 @@ static void __submit_bio(struct bio *bio) disk->fops->submit_bio(bio); blk_queue_exit(disk->queue); } + + blk_finish_plug(&plug); } /* @@ -648,13 +655,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 +693,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; } -- 2.39.2 ^ permalink raw reply related [flat|nested] 18+ messages in thread
* Re: [PATCH -next] block: fix bio lost for plug enabeld bio based device 2024-05-21 20:03 ` [PATCH -next] block: fix bio lost for plug enabeld bio based device Yu Kuai @ 2024-05-22 0:38 ` Changhui Zhong 2024-05-22 1:38 ` Jens Axboe 1 sibling, 0 replies; 18+ messages in thread From: Changhui Zhong @ 2024-05-22 0:38 UTC (permalink / raw) To: Yu Kuai; +Cc: xni, axboe, yukuai3, linux-block, linux-kernel, yi.zhang, yangerkun On Tue, May 21, 2024 at 8:10 PM Yu Kuai <yukuai1@huaweicloud.com> wrote: > > From: Yu Kuai <yukuai3@huawei.com> > > With the following two conditions, bio will be lost: > > 1) blk plug is not enabled, for example, __blkdev_direct_IO_simple() and > __blkdev_direct_IO_async(); > 2) bio plug is enabled, for example write IO for raid1/raid10 while > bitmap is enabled; > > Root cause is that blk_finish_plug() will add the bio to > curent->bio_list, while such bio will not be handled: > > __submit_bio_noacct > current->bio_list = bio_list_on_stack; > blk_start_plug > > do { > dm_submit_bio > md_handle_request > raid10_write_request > -> generate new bio for underlying disks > raid1_add_bio_to_plug -> bio is added to plug > } while ((bio = bio_list_pop(&bio_list_on_stack[0]))) > -> previous bio are all handled > > blk_finish_plug > raid10_unplug > raid1_submit_write > submit_bio_noacct > if (current->bio_list) > bio_list_add(¤t->bio_list[0], bio) > -> add new bio > > current->bio_list = NULL > -> new bio is lost > > Fix the problem by moving plug into the while loop, so that > current->bio_list will still be handled after blk_finish_plug(). > > By the way, enable plug for raid1/raid10 in this case will also prevent > delay IO handling into daemon thread, which should also improve IO > performance. > > Fixes: 060406c61c7c ("block: add plug while submitting IO") > Reported-by: Changhui Zhong <czhong@redhat.com> > Closes: https://lore.kernel.org/all/CAGVVp+Xsmzy2G9YuEatfMT6qv1M--YdOCQ0g7z7OVmcTbBxQAg@mail.gmail.com/ > Signed-off-by: Yu Kuai <yukuai3@huawei.com> > --- > block/blk-core.c | 13 +++++++------ > 1 file changed, 7 insertions(+), 6 deletions(-) > > diff --git a/block/blk-core.c b/block/blk-core.c > index 01186333c88e..dd29d5465af6 100644 > --- a/block/blk-core.c > +++ b/block/blk-core.c > @@ -613,9 +613,14 @@ static inline blk_status_t blk_check_zone_append(struct request_queue *q, > > static void __submit_bio(struct bio *bio) > { > + /* If plug is not used, add new plug here to cache nsecs time. */ > + 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 +629,8 @@ static void __submit_bio(struct bio *bio) > disk->fops->submit_bio(bio); > blk_queue_exit(disk->queue); > } > + > + blk_finish_plug(&plug); > } > > /* > @@ -648,13 +655,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 +693,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; > } > > -- > 2.39.2 > Hi， Kuai the raid1 and raid10 issue has been fixed by this patch， please feel free to add: Tested-by: Changhui Zhong <czhong@redhat.com> Thanks， ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH -next] block: fix bio lost for plug enabeld bio based device 2024-05-21 20:03 ` [PATCH -next] block: fix bio lost for plug enabeld bio based device Yu Kuai 2024-05-22 0:38 ` Changhui Zhong @ 2024-05-22 1:38 ` Jens Axboe 1 sibling, 0 replies; 18+ messages in thread From: Jens Axboe @ 2024-05-22 1:38 UTC (permalink / raw) To: czhong, xni, yukuai3, Yu Kuai Cc: linux-block, linux-kernel, yi.zhang, yangerkun On Wed, 22 May 2024 04:03:08 +0800, Yu Kuai wrote: > With the following two conditions, bio will be lost: > > 1) blk plug is not enabled, for example, __blkdev_direct_IO_simple() and > __blkdev_direct_IO_async(); > 2) bio plug is enabled, for example write IO for raid1/raid10 while > bitmap is enabled; > > [...] Applied, thanks! [1/1] block: fix bio lost for plug enabeld bio based device commit: 9a42891c35d50a8472b42c61256867b4dfcc1941 Best regards, -- Jens Axboe ^ permalink raw reply [flat|nested] 18+ messages in thread
end of thread, other threads:[~2024-05-22 1:38 UTC | newest] Thread overview: 18+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2024-05-16 10:24 [bug report] INFO: task mdX_resync:42168 blocked for more than 122 seconds Changhui Zhong 2024-05-16 11:21 ` Ming Lei 2024-05-16 11:42 ` Yu Kuai 2024-05-17 2:25 ` Changhui Zhong 2024-05-17 2:49 ` Yu Kuai 2024-05-19 6:44 ` Changhui Zhong 2024-05-20 0:39 ` Changhui Zhong 2024-05-20 2:55 ` Yu Kuai 2024-05-20 7:27 ` Yu Kuai 2024-05-20 10:47 ` Changhui Zhong 2024-05-20 10:38 ` Changhui Zhong 2024-05-21 1:08 ` Yu Kuai 2024-05-21 4:28 ` Changhui Zhong 2024-05-21 9:17 ` Yu Kuai 2024-05-21 11:39 ` Changhui Zhong 2024-05-21 20:03 ` [PATCH -next] block: fix bio lost for plug enabeld bio based device Yu Kuai 2024-05-22 0:38 ` Changhui Zhong 2024-05-22 1:38 ` Jens Axboe
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.