* Lockup of (raid5 or raid6) + vdo after taking out a disk under load
@ 2024-07-12 6:53 Konstantin Kharlamov
2024-07-12 8:35 ` Yu Kuai
0 siblings, 1 reply; 12+ messages in thread
From: Konstantin Kharlamov @ 2024-07-12 6:53 UTC (permalink / raw)
To: Song Liu, Yu Kuai, linux-raid, linux-kernel
(this is a dup of yesterday's bugzilla bug 219030 as some maintainers
prefer bugreporting over bugzilla some over ML, and the cases are
indistinguishable)
We're seeing this on both LTS `6.1.97` as well the newest stable
`6.9.8` (note though that VDO was only merged in 6.9, so for upstream
it's probably the only one that matters. Traces below are from 6.9.8).
Creating a raid5 (alternatively raid6) + VDO, then starting a load and
after a minute physically taking out a disk of the VG results in a
lockup stack getting spammed over and over.
Seems unreproducible by removing a disk through software means of
`/sys/block/sdX/device/delete`, i.e. it seem to only happen when either
removing the disk physically or by disabling power on the JBOD slot
with a command like `sg_ses --dev-slot-num=9 --set=3:4:1 /dev/sg26`.
Also when lockup happens, `reboot -ff` no longer does anything.
When looking at repeating stacktraces, the execution seems to loop
around `raid5_get_active_stripe`, `raid5_compute_sector`,
`raid5_release_stripe`.
# Steps to reproduce
1. Create raid5 LV + VDO by executing a `./mk_lvm_raid5.sh /dev/sdX1
/dev/sdY1 /dev/sdZ1` where `mk_lvm_raid5.sh` has the following content:
#!/bin/bash
set -exu
if [ "$#" -ne 3 ]; then
echo "Wrong number of parameters.
Usage: $(basename $0) disk1 disk2 disk3"
exit 1
fi
# create the VG
pvcreate -f "$1" "$2" "$3"
vgcreate p_r5 "$1" "$2" "$3"
# create the LV
lvcreate --type raid5 -i 2 -L 21474836480b -I 64K -n
vdo_internal_deco_vol p_r5 -y
lvconvert -y --type vdo-pool --virtualsize 107374182400B -n
deco_vol p_r5/vdo_internal_deco_vol
2. Start load by executing `fio ./fio-30%write.fio` with the `fio-
30%write.fio` having the following content:
[test IOPS]
blocksize=8k
filename=/dev/p_r5/deco_vol
filesize=100G
direct=1
buffered=0
ioengine=libaio
iodepth=32
rw=randrw
rwmixwrite=30
numjobs=4
group_reporting
time_based
runtime=99h
clat_percentiles=0
unlink=1
3. Wait for about a minute
4. Remove a disk of the volume group, either physically, or by turning
off jbod slot's power (DO NOT use /…/device/delete).
5. Wait 30 seconds
## Expected
`dmesg -w` won't show anything interesting
## Actual
`dmesg -w` starts showing up traces as follows (not sure why the
missing line numbers, I have debug symbols locally, I can decode them
manually with `gdb` if needed):
[…]
[ 869.086048] mpt3sas_cm0: log_info(0x31110e05): originator(PL),
code(0x11), sub_code(0x0e05)
[ 869.139959] mpt3sas_cm0: mpt3sas_transport_port_remove: removed:
sas_addr(0x5002538a67b01303)
[ 869.140085] mpt3sas_cm0: removing handle(0x0022),
sas_addr(0x5002538a67b01303)
[ 869.140191] mpt3sas_cm0: enclosure logical
id(0x50015b2140128f7f), slot(12)
[ 869.140293] mpt3sas_cm0: enclosure level(0x0000), connector
name( )
[ 893.262506] watchdog: BUG: soft lockup - CPU#5 stuck for 26s!
[mdX_raid5:24608]
[ 893.262641] Modules linked in: dm_raid mptctl mptbase bonding
fcoe libfcoe 8021q garp mrp libfc stp llc scsi_transport_fc
sch_fq_codel softdog dm_round_robin scsi_dh_alua intel_rapl_msr
coretemp intel_rapl_common sb_edac x86_pkg_temp_thermal
intel_powerclamp ast kvm_intel drm_shmem_helper drm_kms_helper kvm
crct10dif_pclmul crc32_pclmul ghash_clmulni_intel sha512_ssse3
sha256_ssse3 sha1_ssse3 aesni_intel crypto_simd cryptd rapl
intel_cstate wdat_wdt intel_pch_thermal ipmi_ssif dm_multipath
acpi_ipmi sg ipmi_si ipmi_devintf ipmi_msghandler acpi_pad
acpi_power_meter ramoops reed_solomon efi_pstore drm ip_tables x_tables
autofs4 raid10 raid456 async_raid6_recov async_memcpy async_pq
async_xor xor async_tx raid6_pq libcrc32c raid0 ses enclosure mlx5_ib
ib_core raid1 ixgbe igb mlx5_core mdio_devres xfrm_algo i2c_algo_bit
e1000e mpt3sas hwmon dca mdio i2c_i801 ahci lpc_ich ptp i2c_smbus
mfd_core raid_class libahci pps_core libphy scsi_transport_sas
[ 893.264033] CPU: 5 PID: 24608 Comm: mdX_raid5 Not tainted 6.9.8-
bstrg #3
[ 893.264254] Hardware name: AIC HA401-LB2/LIBRA, BIOS LIBBV071
04/19/2017
[ 893.264479] RIP: 0010:_raw_spin_lock_irqsave+0xe/0x30
[ 893.264714] Code: 48 89 ef 5d e9 13 33 47 ff 0f 1f 00 90 90 90
90 90 90 90 90 90 90 90 90 90 90 90 90 0f 1f 44 00 00 41 54 55 48 89 fd
9c 41 5c <fa> bf 01 00 00 00 e8 07 96 43 ff 48 89 ef e8 df 32 47 ff 4c
89 e0
[ 893.265229] RSP: 0018:ffffbc306091fd70 EFLAGS: 00000246
[ 893.265502] RAX: 0000000000000001 RBX: 0000000000000001 RCX:
0000000000000000
[ 893.265783] RDX: 0000000000000001 RSI: 0000000000000003 RDI:
ffff9fbacf48c430
[ 893.266069] RBP: ffff9fbacf48c430 R08: ffff9fcac1254d58 R09:
00000000ffffffff
[ 893.266366] R10: 0000000000000000 R11: ffffbc306091fe20 R12:
0000000000000246
[ 893.266664] R13: ffff9fcac1254dc0 R14: 0000000000000000 R15:
0000000000739d18
[ 893.266968] FS: 0000000000000000(0000)
GS:ffff9fc9fff40000(0000) knlGS:0000000000000000
[ 893.267282] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 893.267603] CR2: 000055f91452ff88 CR3: 0000000124c74004 CR4:
00000000003706f0
[ 893.267933] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
[ 893.268268] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7:
0000000000000400
[ 893.268605] Call Trace:
[ 893.268945] <IRQ>
[ 893.269285] ? watchdog_timer_fn+0x24b/0x2d0
[ 893.269638] ? __pfx_watchdog_timer_fn+0x10/0x10
[ 893.269990] ? __hrtimer_run_queues+0x112/0x2b0
[ 893.270347] ? hrtimer_interrupt+0x101/0x240
[ 893.270708] ? __sysvec_apic_timer_interrupt+0x6e/0x180
[ 893.271075] ? sysvec_apic_timer_interrupt+0x9d/0xd0
[ 893.271448] </IRQ>
[ 893.271816] <TASK>
[ 893.272184] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
[ 893.272568] ? _raw_spin_lock_irqsave+0xe/0x30
[ 893.272956] __wake_up+0x1d/0x60
[ 893.273345] md_wakeup_thread+0x38/0x70
[ 893.273738] raid5d+0x32a/0x5d0 [raid456]
[ 893.274147] md_thread+0xc1/0x170
[ 893.274545] ? __pfx_autoremove_wake_function+0x10/0x10
[ 893.274951] ? __pfx_md_thread+0x10/0x10
[ 893.275358] kthread+0xff/0x130
[ 893.275760] ? __pfx_kthread+0x10/0x10
[ 893.276172] ret_from_fork+0x30/0x50
[ 893.276568] ? __pfx_kthread+0x10/0x10
[ 893.276961] ret_from_fork_asm+0x1a/0x30
[ 893.277351] </TASK>
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: Lockup of (raid5 or raid6) + vdo after taking out a disk under load
2024-07-12 6:53 Lockup of (raid5 or raid6) + vdo after taking out a disk under load Konstantin Kharlamov
@ 2024-07-12 8:35 ` Yu Kuai
2024-07-12 12:11 ` Konstantin Kharlamov
0 siblings, 1 reply; 12+ messages in thread
From: Yu Kuai @ 2024-07-12 8:35 UTC (permalink / raw)
To: Konstantin Kharlamov, Song Liu, linux-raid, linux-kernel,
yukuai (C),
yangerkun
Hi,
在 2024/07/12 14:53, Konstantin Kharlamov 写道:
> (this is a dup of yesterday's bugzilla bug 219030 as some maintainers
> prefer bugreporting over bugzilla some over ML, and the cases are
> indistinguishable)
At least I'll keep an eye on ML, not bugzilla.
>
> We're seeing this on both LTS `6.1.97` as well the newest stable
> `6.9.8` (note though that VDO was only merged in 6.9, so for upstream
> it's probably the only one that matters. Traces below are from 6.9.8).
>
> Creating a raid5 (alternatively raid6) + VDO, then starting a load and
> after a minute physically taking out a disk of the VG results in a
> lockup stack getting spammed over and over.
>
> Seems unreproducible by removing a disk through software means of
> `/sys/block/sdX/device/delete`, i.e. it seem to only happen when either
> removing the disk physically or by disabling power on the JBOD slot
> with a command like `sg_ses --dev-slot-num=9 --set=3:4:1 /dev/sg26`.
>
> Also when lockup happens, `reboot -ff` no longer does anything.
>
> When looking at repeating stacktraces, the execution seems to loop
> around `raid5_get_active_stripe`, `raid5_compute_sector`,
> `raid5_release_stripe`.
>
> # Steps to reproduce
>
> 1. Create raid5 LV + VDO by executing a `./mk_lvm_raid5.sh /dev/sdX1
> /dev/sdY1 /dev/sdZ1` where `mk_lvm_raid5.sh` has the following content:
>
> #!/bin/bash
>
> set -exu
>
> if [ "$#" -ne 3 ]; then
> echo "Wrong number of parameters.
> Usage: $(basename $0) disk1 disk2 disk3"
> exit 1
> fi
>
> # create the VG
> pvcreate -f "$1" "$2" "$3"
> vgcreate p_r5 "$1" "$2" "$3"
>
> # create the LV
> lvcreate --type raid5 -i 2 -L 21474836480b -I 64K -n
> vdo_internal_deco_vol p_r5 -y
> lvconvert -y --type vdo-pool --virtualsize 107374182400B -n
> deco_vol p_r5/vdo_internal_deco_vol
>
> 2. Start load by executing `fio ./fio-30%write.fio` with the `fio-
> 30%write.fio` having the following content:
>
> [test IOPS]
> blocksize=8k
> filename=/dev/p_r5/deco_vol
> filesize=100G
> direct=1
> buffered=0
> ioengine=libaio
> iodepth=32
> rw=randrw
> rwmixwrite=30
> numjobs=4
> group_reporting
> time_based
> runtime=99h
> clat_percentiles=0
> unlink=1
>
> 3. Wait for about a minute
> 4. Remove a disk of the volume group, either physically, or by turning
> off jbod slot's power (DO NOT use /…/device/delete).
Looks like this is because IO is failed from raid level, and then dm
level keep retry this IO(This will be related to the step 4), hence
raid5d stuck in the loop to hanlde new IO.
Can you give the following patch a test to confirm this?
Thanks!
Kuai
diff --git a/drivers/md/raid5.c b/drivers/md/raid5.c
index c14cf2410365..a0f784cd664c 100644
--- a/drivers/md/raid5.c
+++ b/drivers/md/raid5.c
@@ -6776,7 +6776,9 @@ static void raid5d(struct md_thread *thread)
while ((bio = remove_bio_from_retry(conf, &offset))) {
int ok;
+
spin_unlock_irq(&conf->device_lock);
+ cond_resched();
ok = retry_aligned_read(conf, bio, offset);
spin_lock_irq(&conf->device_lock);
if (!ok)
@@ -6790,11 +6792,11 @@ static void raid5d(struct md_thread *thread)
break;
handled += batch_size;
- if (mddev->sb_flags & ~(1 << MD_SB_CHANGE_PENDING)) {
- spin_unlock_irq(&conf->device_lock);
+ spin_unlock_irq(&conf->device_lock);
+ if (mddev->sb_flags & ~(1 << MD_SB_CHANGE_PENDING))
md_check_recovery(mddev);
- spin_lock_irq(&conf->device_lock);
- }
+ cond_resched();
+ spin_lock_irq(&conf->device_lock);
}
pr_debug("%d stripes handled\n", handled);
> 5. Wait 30 seconds
>
> ## Expected
>
> `dmesg -w` won't show anything interesting
>
> ## Actual
>
> `dmesg -w` starts showing up traces as follows (not sure why the
> missing line numbers, I have debug symbols locally, I can decode them
> manually with `gdb` if needed):
>
> […]
> [ 869.086048] mpt3sas_cm0: log_info(0x31110e05): originator(PL),
> code(0x11), sub_code(0x0e05)
> [ 869.139959] mpt3sas_cm0: mpt3sas_transport_port_remove: removed:
> sas_addr(0x5002538a67b01303)
> [ 869.140085] mpt3sas_cm0: removing handle(0x0022),
> sas_addr(0x5002538a67b01303)
> [ 869.140191] mpt3sas_cm0: enclosure logical
> id(0x50015b2140128f7f), slot(12)
> [ 869.140293] mpt3sas_cm0: enclosure level(0x0000), connector
> name( )
> [ 893.262506] watchdog: BUG: soft lockup - CPU#5 stuck for 26s!
> [mdX_raid5:24608]
> [ 893.262641] Modules linked in: dm_raid mptctl mptbase bonding
> fcoe libfcoe 8021q garp mrp libfc stp llc scsi_transport_fc
> sch_fq_codel softdog dm_round_robin scsi_dh_alua intel_rapl_msr
> coretemp intel_rapl_common sb_edac x86_pkg_temp_thermal
> intel_powerclamp ast kvm_intel drm_shmem_helper drm_kms_helper kvm
> crct10dif_pclmul crc32_pclmul ghash_clmulni_intel sha512_ssse3
> sha256_ssse3 sha1_ssse3 aesni_intel crypto_simd cryptd rapl
> intel_cstate wdat_wdt intel_pch_thermal ipmi_ssif dm_multipath
> acpi_ipmi sg ipmi_si ipmi_devintf ipmi_msghandler acpi_pad
> acpi_power_meter ramoops reed_solomon efi_pstore drm ip_tables x_tables
> autofs4 raid10 raid456 async_raid6_recov async_memcpy async_pq
> async_xor xor async_tx raid6_pq libcrc32c raid0 ses enclosure mlx5_ib
> ib_core raid1 ixgbe igb mlx5_core mdio_devres xfrm_algo i2c_algo_bit
> e1000e mpt3sas hwmon dca mdio i2c_i801 ahci lpc_ich ptp i2c_smbus
> mfd_core raid_class libahci pps_core libphy scsi_transport_sas
> [ 893.264033] CPU: 5 PID: 24608 Comm: mdX_raid5 Not tainted 6.9.8-
> bstrg #3
> [ 893.264254] Hardware name: AIC HA401-LB2/LIBRA, BIOS LIBBV071
> 04/19/2017
> [ 893.264479] RIP: 0010:_raw_spin_lock_irqsave+0xe/0x30
> [ 893.264714] Code: 48 89 ef 5d e9 13 33 47 ff 0f 1f 00 90 90 90
> 90 90 90 90 90 90 90 90 90 90 90 90 90 0f 1f 44 00 00 41 54 55 48 89 fd
> 9c 41 5c <fa> bf 01 00 00 00 e8 07 96 43 ff 48 89 ef e8 df 32 47 ff 4c
> 89 e0
> [ 893.265229] RSP: 0018:ffffbc306091fd70 EFLAGS: 00000246
> [ 893.265502] RAX: 0000000000000001 RBX: 0000000000000001 RCX:
> 0000000000000000
> [ 893.265783] RDX: 0000000000000001 RSI: 0000000000000003 RDI:
> ffff9fbacf48c430
> [ 893.266069] RBP: ffff9fbacf48c430 R08: ffff9fcac1254d58 R09:
> 00000000ffffffff
> [ 893.266366] R10: 0000000000000000 R11: ffffbc306091fe20 R12:
> 0000000000000246
> [ 893.266664] R13: ffff9fcac1254dc0 R14: 0000000000000000 R15:
> 0000000000739d18
> [ 893.266968] FS: 0000000000000000(0000)
> GS:ffff9fc9fff40000(0000) knlGS:0000000000000000
> [ 893.267282] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 893.267603] CR2: 000055f91452ff88 CR3: 0000000124c74004 CR4:
> 00000000003706f0
> [ 893.267933] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
> 0000000000000000
> [ 893.268268] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7:
> 0000000000000400
> [ 893.268605] Call Trace:
> [ 893.268945] <IRQ>
> [ 893.269285] ? watchdog_timer_fn+0x24b/0x2d0
> [ 893.269638] ? __pfx_watchdog_timer_fn+0x10/0x10
> [ 893.269990] ? __hrtimer_run_queues+0x112/0x2b0
> [ 893.270347] ? hrtimer_interrupt+0x101/0x240
> [ 893.270708] ? __sysvec_apic_timer_interrupt+0x6e/0x180
> [ 893.271075] ? sysvec_apic_timer_interrupt+0x9d/0xd0
> [ 893.271448] </IRQ>
> [ 893.271816] <TASK>
> [ 893.272184] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
> [ 893.272568] ? _raw_spin_lock_irqsave+0xe/0x30
> [ 893.272956] __wake_up+0x1d/0x60
> [ 893.273345] md_wakeup_thread+0x38/0x70
> [ 893.273738] raid5d+0x32a/0x5d0 [raid456]
> [ 893.274147] md_thread+0xc1/0x170
> [ 893.274545] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 893.274951] ? __pfx_md_thread+0x10/0x10
> [ 893.275358] kthread+0xff/0x130
> [ 893.275760] ? __pfx_kthread+0x10/0x10
> [ 893.276172] ret_from_fork+0x30/0x50
> [ 893.276568] ? __pfx_kthread+0x10/0x10
> [ 893.276961] ret_from_fork_asm+0x1a/0x30
> [ 893.277351] </TASK>
>
> .
>
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: Lockup of (raid5 or raid6) + vdo after taking out a disk under load
2024-07-12 8:35 ` Yu Kuai
@ 2024-07-12 12:11 ` Konstantin Kharlamov
2024-07-13 11:06 ` Yu Kuai
0 siblings, 1 reply; 12+ messages in thread
From: Konstantin Kharlamov @ 2024-07-12 12:11 UTC (permalink / raw)
To: Yu Kuai, Song Liu, linux-raid, linux-kernel, yukuai (C), yangerkun
On Fri, 2024-07-12 at 16:35 +0800, Yu Kuai wrote:
> Hi,
>
> 在 2024/07/12 14:53, Konstantin Kharlamov 写道:
>
> > # Steps to reproduce
> >
> > 1. Create raid5 LV + VDO by executing a `./mk_lvm_raid5.sh
> > /dev/sdX1
> > /dev/sdY1 /dev/sdZ1` where `mk_lvm_raid5.sh` has the following
> > content:
> >
> > #!/bin/bash
> >
> > set -exu
> >
> > if [ "$#" -ne 3 ]; then
> > echo "Wrong number of parameters.
> > Usage: $(basename $0) disk1 disk2 disk3"
> > exit 1
> > fi
> >
> > # create the VG
> > pvcreate -f "$1" "$2" "$3"
> > vgcreate p_r5 "$1" "$2" "$3"
> >
> > # create the LV
> > lvcreate --type raid5 -i 2 -L 21474836480b -I 64K -n
> > vdo_internal_deco_vol p_r5 -y
> > lvconvert -y --type vdo-pool --virtualsize 107374182400B -n
> > deco_vol p_r5/vdo_internal_deco_vol
> >
> > 2. Start load by executing `fio ./fio-30%write.fio` with the `fio-
> > 30%write.fio` having the following content:
> >
> > [test IOPS]
> > blocksize=8k
> > filename=/dev/p_r5/deco_vol
> > filesize=100G
> > direct=1
> > buffered=0
> > ioengine=libaio
> > iodepth=32
> > rw=randrw
> > rwmixwrite=30
> > numjobs=4
> > group_reporting
> > time_based
> > runtime=99h
> > clat_percentiles=0
> > unlink=1
> >
> > 3. Wait for about a minute
> > 4. Remove a disk of the volume group, either physically, or by
> > turning
> > off jbod slot's power (DO NOT use /…/device/delete).
>
> Looks like this is because IO is failed from raid level, and then dm
> level keep retry this IO(This will be related to the step 4), hence
> raid5d stuck in the loop to hanlde new IO.
>
> Can you give the following patch a test to confirm this?
>
> Thanks!
> Kuai
>
> diff --git a/drivers/md/raid5.c b/drivers/md/raid5.c
> index c14cf2410365..a0f784cd664c 100644
> --- a/drivers/md/raid5.c
> +++ b/drivers/md/raid5.c
> @@ -6776,7 +6776,9 @@ static void raid5d(struct md_thread *thread)
>
> while ((bio = remove_bio_from_retry(conf, &offset)))
> {
> int ok;
> +
> spin_unlock_irq(&conf->device_lock);
> + cond_resched();
> ok = retry_aligned_read(conf, bio, offset);
> spin_lock_irq(&conf->device_lock);
> if (!ok)
> @@ -6790,11 +6792,11 @@ static void raid5d(struct md_thread *thread)
> break;
> handled += batch_size;
>
> - if (mddev->sb_flags & ~(1 << MD_SB_CHANGE_PENDING)) {
> - spin_unlock_irq(&conf->device_lock);
> + spin_unlock_irq(&conf->device_lock);
> + if (mddev->sb_flags & ~(1 << MD_SB_CHANGE_PENDING))
> md_check_recovery(mddev);
> - spin_lock_irq(&conf->device_lock);
> - }
> + cond_resched();
> + spin_lock_irq(&conf->device_lock);
> }
> pr_debug("%d stripes handled\n", handled);
Thank you for the quick answer! FTR, I had applied the diff by manually
editing the code because tabs got converted to spaces in the text, so
it wasn't applicable. Hopefully I got everything correct. (in
retrospection, I could've used `--ignore-whitespace`. Oh, well…)
So, there are both good and bad news.
Good news: you diff seems to have fixed the problem! I would have to
test more extensively in another environment to be completely sure, but
by following the minimal steps-to-reproduce I can no longer reproduce
the problem, so it seems to have fixed the problem.
Bad news: there's a new lockup now 😄 This one seems to happen after
the disk is returned back; unless the action of returning back matches
accidentally the appearing stacktraces, which still might be possible
even though I re-tested multiple times. It's because the traces
(below) seems not to always appear. However, even when traces do not
appear, IO load on the fio that's running in the background drops to
zero, so something seems definitely wrong.
[ 475.353727] sd 0:0:25:0: [sdbu] Attached SCSI disk
[ 615.173084] INFO: task dm-vdo0:bioQ0:11500 blocked for more than 122 seconds.
[ 615.173326] Not tainted 6.9.8-bstrg #4
[ 615.173525] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 615.173735] task:dm-vdo0:bioQ0 state:D stack:0 pid:11500 tgid:11500 ppid:2 flags:0x00004000
[ 615.173961] Call Trace:
[ 615.174180] <TASK>
[ 615.174402] __schedule+0x376/0xb30
[ 615.174636] schedule+0x2f/0x110
[ 615.174862] schedule_timeout+0x15a/0x170
[ 615.175092] ? _raw_spin_unlock_irqrestore+0x1e/0x40
[ 615.175326] ? __wake_up+0x40/0x60
[ 615.175563] wait_woken+0x73/0x80
[ 615.175793] raid5_make_request+0x5dc/0x12f0 [raid456]
[ 615.176033] ? kmem_cache_alloc+0x4e/0x2f0
[ 615.176257] ? __pfx_woken_wake_function+0x10/0x10
[ 615.176496] md_handle_request+0x15e/0x2a0
[ 615.176730] raid_map+0x31/0x60 [dm_raid]
[ 615.176966] __map_bio+0x181/0x1b0
[ 615.177203] dm_submit_bio+0x194/0x550
[ 615.177440] __submit_bio+0x97/0x130
[ 615.177680] submit_bio_noacct_nocheck+0x18c/0x3c0
[ 615.177925] submit_data_vio+0xba/0x100
[ 615.178171] work_queue_runner+0x215/0x290
[ 615.178416] ? __pfx_autoremove_wake_function+0x10/0x10
[ 615.178664] ? __pfx_work_queue_runner+0x10/0x10
[ 615.178914] kthread+0xff/0x130
[ 615.179168] ? __pfx_kthread+0x10/0x10
[ 615.179422] ret_from_fork+0x30/0x50
[ 615.179687] ? __pfx_kthread+0x10/0x10
[ 615.179947] ret_from_fork_asm+0x1a/0x30
[ 615.180215] </TASK>
[ 615.180475] INFO: task dm-vdo0:bioQ1:11501 blocked for more than 122 seconds.
[ 615.180750] Not tainted 6.9.8-bstrg #4
[ 615.181028] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 615.181319] task:dm-vdo0:bioQ1 state:D stack:0 pid:11501 tgid:11501 ppid:2 flags:0x00004000
[ 615.181624] Call Trace:
[ 615.181926] <TASK>
[ 615.182228] __schedule+0x376/0xb30
[ 615.182529] schedule+0x2f/0x110
[ 615.182821] schedule_timeout+0x15a/0x170
[ 615.183117] ? _raw_spin_unlock_irqrestore+0x1e/0x40
[ 615.183410] ? __wake_up+0x40/0x60
[ 615.183701] wait_woken+0x73/0x80
[ 615.183987] raid5_make_request+0x5dc/0x12f0 [raid456]
[ 615.184280] ? mempool_alloc+0x61/0x1b0
[ 615.184565] ? kmem_cache_alloc+0x4e/0x2f0
[ 615.184845] ? __pfx_woken_wake_function+0x10/0x10
[ 615.185126] md_handle_request+0x15e/0x2a0
[ 615.185402] raid_map+0x31/0x60 [dm_raid]
[ 615.185695] __map_bio+0x181/0x1b0
[ 615.185979] dm_submit_bio+0x194/0x550
[ 615.186255] __submit_bio+0x97/0x130
[ 615.186529] submit_bio_noacct_nocheck+0x18c/0x3c0
[ 615.186804] submit_data_vio+0xba/0x100
[ 615.187076] work_queue_runner+0x215/0x290
[ 615.187350] ? __pfx_autoremove_wake_function+0x10/0x10
[ 615.187628] ? __pfx_work_queue_runner+0x10/0x10
[ 615.187905] kthread+0xff/0x130
[ 615.188180] ? __pfx_kthread+0x10/0x10
[ 615.188456] ret_from_fork+0x30/0x50
[ 615.188729] ? __pfx_kthread+0x10/0x10
[ 615.189002] ret_from_fork_asm+0x1a/0x30
[ 615.189276] </TASK>
[ 615.189541] INFO: task dm-vdo0:bioQ3:11504 blocked for more than 122 seconds.
[ 615.189823] Not tainted 6.9.8-bstrg #4
[ 615.190102] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 615.190392] task:dm-vdo0:bioQ3 state:D stack:0 pid:11504 tgid:11504 ppid:2 flags:0x00004000
[ 615.190694] Call Trace:
[ 615.190989] <TASK>
[ 615.191283] __schedule+0x376/0xb30
[ 615.191580] schedule+0x2f/0x110
[ 615.191875] schedule_timeout+0x15a/0x170
[ 615.192168] ? _raw_spin_unlock_irqrestore+0x1e/0x40
[ 615.192463] ? __wake_up+0x40/0x60
[ 615.192757] wait_woken+0x73/0x80
[ 615.193057] raid5_make_request+0x5dc/0x12f0 [raid456]
[ 615.193365] ? mempool_alloc+0x61/0x1b0
[ 615.193663] ? kmem_cache_alloc+0x4e/0x2f0
[ 615.193961] ? __pfx_woken_wake_function+0x10/0x10
[ 615.194257] md_handle_request+0x15e/0x2a0
[ 615.194548] raid_map+0x31/0x60 [dm_raid]
[ 615.194836] __map_bio+0x181/0x1b0
[ 615.195114] dm_submit_bio+0x194/0x550
[ 615.195386] __submit_bio+0x97/0x130
[ 615.195657] submit_bio_noacct_nocheck+0x18c/0x3c0
[ 615.195932] submit_data_vio+0xba/0x100
[ 615.196206] work_queue_runner+0x215/0x290
[ 615.196488] ? __pfx_autoremove_wake_function+0x10/0x10
[ 615.196767] ? __pfx_work_queue_runner+0x10/0x10
[ 615.197044] kthread+0xff/0x130
[ 615.197321] ? __pfx_kthread+0x10/0x10
[ 615.197596] ret_from_fork+0x30/0x50
[ 615.197868] ? __pfx_kthread+0x10/0x10
[ 615.198141] ret_from_fork_asm+0x1a/0x30
[ 615.198415] </TASK>
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: Lockup of (raid5 or raid6) + vdo after taking out a disk under load
2024-07-12 12:11 ` Konstantin Kharlamov
@ 2024-07-13 11:06 ` Yu Kuai
2024-07-13 13:50 ` Konstantin Kharlamov
0 siblings, 1 reply; 12+ messages in thread
From: Yu Kuai @ 2024-07-13 11:06 UTC (permalink / raw)
To: Konstantin Kharlamov, Yu Kuai, Song Liu, linux-raid,
linux-kernel, yangerkun, yukuai (C)
Hi,
在 2024/07/12 20:11, Konstantin Kharlamov 写道:
> Good news: you diff seems to have fixed the problem! I would have to
> test more extensively in another environment to be completely sure, but
> by following the minimal steps-to-reproduce I can no longer reproduce
> the problem, so it seems to have fixed the problem.
That's good. :)
>
> Bad news: there's a new lockup now 😄 This one seems to happen after
> the disk is returned back; unless the action of returning back matches
> accidentally the appearing stacktraces, which still might be possible
> even though I re-tested multiple times. It's because the traces
> (below) seems not to always appear. However, even when traces do not
> appear, IO load on the fio that's running in the background drops to
> zero, so something seems definitely wrong.
Ok, I need to investigate more for this. The call stack is not much
helpful.
At first, can the problem reporduce with raid1/raid10? If not, this is
probably a raid5 bug.
The best will be that if I can reporduce this problem myself.
The problem is that I don't understand the step 4: turning off jbod
slot's power, is this only possible for a real machine, or can I do
this in my VM?
Thanks,
Kuai
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: Lockup of (raid5 or raid6) + vdo after taking out a disk under load
2024-07-13 11:06 ` Yu Kuai
@ 2024-07-13 13:50 ` Konstantin Kharlamov
2024-07-15 1:56 ` Yu Kuai
0 siblings, 1 reply; 12+ messages in thread
From: Konstantin Kharlamov @ 2024-07-13 13:50 UTC (permalink / raw)
To: Yu Kuai, Song Liu, linux-raid, linux-kernel, yangerkun, yukuai (C)
On Sat, 2024-07-13 at 19:06 +0800, Yu Kuai wrote:
> Hi,
>
> 在 2024/07/12 20:11, Konstantin Kharlamov 写道:
> > Good news: you diff seems to have fixed the problem! I would have
> > to
> > test more extensively in another environment to be completely sure,
> > but
> > by following the minimal steps-to-reproduce I can no longer
> > reproduce
> > the problem, so it seems to have fixed the problem.
>
> That's good. :)
> >
> > Bad news: there's a new lockup now 😄 This one seems to happen
> > after
> > the disk is returned back; unless the action of returning back
> > matches
> > accidentally the appearing stacktraces, which still might be
> > possible
> > even though I re-tested multiple times. It's because the traces
> > (below) seems not to always appear. However, even when traces do
> > not
> > appear, IO load on the fio that's running in the background drops
> > to
> > zero, so something seems definitely wrong.
>
> Ok, I need to investigate more for this. The call stack is not much
> helpful.
Is it not helpful because of missing line numbers or in general? If
it's the missing line numbers I'll try to fix that. We're using some
Debian scripts that create deb packages, and well, they don't work well
with debug information (it's being put to separate package, but even if
it's installed the kernel traces still don't have line numbers). I
didn't investigate into it, but I can if that will help.
> At first, can the problem reporduce with raid1/raid10? If not, this
> is
> probably a raid5 bug.
This is not reproducible with raid1 (i.e. no lockups for raid1), I
tested that. I didn't test raid10, if you want I can try (but probably
only after the weekend, because today I was asked to give the nodes
away, for the weekend at least, to someone else).
> The best will be that if I can reporduce this problem myself.
> The problem is that I don't understand the step 4: turning off jbod
> slot's power, is this only possible for a real machine, or can I do
> this in my VM?
Well, let's say that if it is possible, I don't know a way to do that.
The `sg_ses` commands that I used
sg_ses --dev-slot-num=9 --set=3:4:1 /dev/sg26 # turning off
sg_ses --dev-slot-num=9 --clear=3:4:1 /dev/sg26 # turning on
…sets and clears the value of the 3:4:1 bit, where the bit is defined
by the JBOD's manufacturer datasheet. The 3:4:1 specifically is defined
by "AIC" manufacturer. That means the command as is unlikely to work on
a different hardware.
Well, while on it, do you have any thoughts why just using a `echo 1 >
/sys/block/sdX/device/delete` doesn't reproduce it? Does perhaps kernel
not emulate device disappearance too well?
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: Lockup of (raid5 or raid6) + vdo after taking out a disk under load
2024-07-13 13:50 ` Konstantin Kharlamov
@ 2024-07-15 1:56 ` Yu Kuai
2024-07-22 17:56 ` Konstantin Kharlamov
0 siblings, 1 reply; 12+ messages in thread
From: Yu Kuai @ 2024-07-15 1:56 UTC (permalink / raw)
To: Konstantin Kharlamov, Yu Kuai, Song Liu, linux-raid,
linux-kernel, yangerkun, yukuai (C)
Hi,
在 2024/07/13 21:50, Konstantin Kharlamov 写道:
> On Sat, 2024-07-13 at 19:06 +0800, Yu Kuai wrote:
>> Hi,
>>
>> 在 2024/07/12 20:11, Konstantin Kharlamov 写道:
>>> Good news: you diff seems to have fixed the problem! I would have
>>> to
>>> test more extensively in another environment to be completely sure,
>>> but
>>> by following the minimal steps-to-reproduce I can no longer
>>> reproduce
>>> the problem, so it seems to have fixed the problem.
>>
>> That's good. :)
>>>
>>> Bad news: there's a new lockup now 😄 This one seems to happen
>>> after
>>> the disk is returned back; unless the action of returning back
>>> matches
>>> accidentally the appearing stacktraces, which still might be
>>> possible
>>> even though I re-tested multiple times. It's because the traces
>>> (below) seems not to always appear. However, even when traces do
>>> not
>>> appear, IO load on the fio that's running in the background drops
>>> to
>>> zero, so something seems definitely wrong.
>>
>> Ok, I need to investigate more for this. The call stack is not much
>> helpful.
>
> Is it not helpful because of missing line numbers or in general? If
> it's the missing line numbers I'll try to fix that. We're using some
> Debian scripts that create deb packages, and well, they don't work well
> with debug information (it's being put to separate package, but even if
> it's installed the kernel traces still don't have line numbers). I
> didn't investigate into it, but I can if that will help.
Line number will be helpful. Meanwhile, can you check if the underlying
disks has IO while raid5 stuck, by /sys/block/[device]/inflight.
>
>> At first, can the problem reporduce with raid1/raid10? If not, this
>> is
>> probably a raid5 bug.
>
> This is not reproducible with raid1 (i.e. no lockups for raid1), I
> tested that. I didn't test raid10, if you want I can try (but probably
> only after the weekend, because today I was asked to give the nodes
> away, for the weekend at least, to someone else).
Yes, please try raid10 as well. For now I'll say this is a raid5
problem.
>
>> The best will be that if I can reporduce this problem myself.
>> The problem is that I don't understand the step 4: turning off jbod
>> slot's power, is this only possible for a real machine, or can I do
>> this in my VM?
>
> Well, let's say that if it is possible, I don't know a way to do that.
> The `sg_ses` commands that I used
>
> sg_ses --dev-slot-num=9 --set=3:4:1 /dev/sg26 # turning off
> sg_ses --dev-slot-num=9 --clear=3:4:1 /dev/sg26 # turning on
>
> …sets and clears the value of the 3:4:1 bit, where the bit is defined
> by the JBOD's manufacturer datasheet. The 3:4:1 specifically is defined
> by "AIC" manufacturer. That means the command as is unlikely to work on
> a different hardware.
I never do this before, I'll try.
>
> Well, while on it, do you have any thoughts why just using a `echo 1 >
> /sys/block/sdX/device/delete` doesn't reproduce it? Does perhaps kernel
> not emulate device disappearance too well?
echo 1 > delete just delete the disk from kernel, and scsi/dm-raid will
know that this disk is deleted. However, the disk will stay in kernel
for the other way, dm-raid does not aware that underlying disks are
problematic and IO will still be generated and issued.
Thanks,
Kuai
> .
>
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: Lockup of (raid5 or raid6) + vdo after taking out a disk under load
2024-07-15 1:56 ` Yu Kuai
@ 2024-07-22 17:56 ` Konstantin Kharlamov
2024-07-23 14:34 ` Konstantin Kharlamov
2024-07-31 14:14 ` Konstantin Kharlamov
0 siblings, 2 replies; 12+ messages in thread
From: Konstantin Kharlamov @ 2024-07-22 17:56 UTC (permalink / raw)
To: Yu Kuai, Song Liu, linux-raid, linux-kernel, yangerkun, yukuai (C)
Hi, sorry for the delay, I had to give away the nodes and we had a week
of teambuilding and company party, so for the past week I only managed
to hack away stripping debug symbols, get another node and set it up.
Experiments below are based off of vanilla 6.9.8 kernel *without* your
patch.
On Mon, 2024-07-15 at 09:56 +0800, Yu Kuai wrote:
> Line number will be helpful.
So, after tinkering with building scripts I managed to build modules
with debug symbols (not the kernel itself but should be good enough),
but for some reason kernel doesn't show line numbers in stacktraces. No
idea what could be causing it, so I had to decode line numbers
manually, below is an output where I inserted line numbers for raid456
manually after decoding them with `gdb`.
[…]
[ 1677.293366] <TASK>
[ 1677.293661] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
[ 1677.293972] ? _raw_spin_unlock_irq+0x10/0x30
[ 1677.294276] ? _raw_spin_unlock_irq+0xa/0x30
[ 1677.294586] raid5d at drivers/md/raid5.c:6572
[ 1677.294910] md_thread+0xc1/0x170
[ 1677.295228] ? __pfx_autoremove_wake_function+0x10/0x10
[ 1677.295545] ? __pfx_md_thread+0x10/0x10
[ 1677.295870] kthread+0xff/0x130
[ 1677.296189] ? __pfx_kthread+0x10/0x10
[ 1677.296498] ret_from_fork+0x30/0x50
[ 1677.296810] ? __pfx_kthread+0x10/0x10
[ 1677.297112] ret_from_fork_asm+0x1a/0x30
[ 1677.297424] </TASK>
[…]
[ 1705.296253] <TASK>
[ 1705.296554] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
[ 1705.296864] ? _raw_spin_unlock_irq+0x10/0x30
[ 1705.297172] ? _raw_spin_unlock_irq+0xa/0x30
[ 1677.294586] raid5d at drivers/md/raid5.c:6597
[ 1705.297794] md_thread+0xc1/0x170
[ 1705.298099] ? __pfx_autoremove_wake_function+0x10/0x10
[ 1705.298409] ? __pfx_md_thread+0x10/0x10
[ 1705.298714] kthread+0xff/0x130
[ 1705.299022] ? __pfx_kthread+0x10/0x10
[ 1705.299333] ret_from_fork+0x30/0x50
[ 1705.299641] ? __pfx_kthread+0x10/0x10
[ 1705.299947] ret_from_fork_asm+0x1a/0x30
[ 1705.300257] </TASK>
[…]
[ 1733.296255] <TASK>
[ 1733.296556] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
[ 1733.296862] ? _raw_spin_unlock_irq+0x10/0x30
[ 1733.297170] ? _raw_spin_unlock_irq+0xa/0x30
[ 1677.294586] raid5d at drivers/md/raid5.c:6572
[ 1733.297792] md_thread+0xc1/0x170
[ 1733.298096] ? __pfx_autoremove_wake_function+0x10/0x10
[ 1733.298403] ? __pfx_md_thread+0x10/0x10
[ 1733.298711] kthread+0xff/0x130
[ 1733.299018] ? __pfx_kthread+0x10/0x10
[ 1733.299330] ret_from_fork+0x30/0x50
[ 1733.299637] ? __pfx_kthread+0x10/0x10
[ 1733.299943] ret_from_fork_asm+0x1a/0x30
[ 1733.300251] </TASK>
> Meanwhile, can you check if the underlying
> disks has IO while raid5 stuck, by /sys/block/[device]/inflight.
The two devices that are left after the 3rd one is removed has these
numbers that don't change with time:
[Mon Jul 22 20:18:06 @ ~]:> for d in dm-19 dm-17; do echo -n $d; cat
/sys/block/$d/inflight; done
dm-19 9 1
dm-17 11 2
[Mon Jul 22 20:18:11 @ ~]:> for d in dm-19 dm-17; do echo -n $d; cat
/sys/block/$d/inflight; done
dm-19 9 1
dm-17 11 2
They also don't change after I return the disk back (which is to be
expected I guess, given that the lockup doesn't go away).
> >
> > > At first, can the problem reporduce with raid1/raid10? If not,
> > > this
> > > is
> > > probably a raid5 bug.
> >
> > This is not reproducible with raid1 (i.e. no lockups for raid1), I
> > tested that. I didn't test raid10, if you want I can try (but
> > probably
> > only after the weekend, because today I was asked to give the nodes
> > away, for the weekend at least, to someone else).
>
> Yes, please try raid10 as well. For now I'll say this is a raid5
> problem.
Tested: raid10 works just fine, i.e. no lockup and fio continues
having non-zero IOPS.
> > > The best will be that if I can reporduce this problem myself.
> > > The problem is that I don't understand the step 4: turning off
> > > jbod
> > > slot's power, is this only possible for a real machine, or can I
> > > do
> > > this in my VM?
> >
> > Well, let's say that if it is possible, I don't know a way to do
> > that.
> > The `sg_ses` commands that I used
> >
> > sg_ses --dev-slot-num=9 --set=3:4:1 /dev/sg26 # turning
> > off
> > sg_ses --dev-slot-num=9 --clear=3:4:1 /dev/sg26 # turning
> > on
> >
> > …sets and clears the value of the 3:4:1 bit, where the bit is
> > defined
> > by the JBOD's manufacturer datasheet. The 3:4:1 specifically is
> > defined
> > by "AIC" manufacturer. That means the command as is unlikely to
> > work on
> > a different hardware.
>
> I never do this before, I'll try.
> >
> > Well, while on it, do you have any thoughts why just using a `echo
> > 1 >
> > /sys/block/sdX/device/delete` doesn't reproduce it? Does perhaps
> > kernel
> > not emulate device disappearance too well?
>
> echo 1 > delete just delete the disk from kernel, and scsi/dm-raid
> will
> know that this disk is deleted. However, the disk will stay in kernel
> for the other way, dm-raid does not aware that underlying disks are
> problematic and IO will still be generated and issued.
>
> Thanks,
> Kuai
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: Lockup of (raid5 or raid6) + vdo after taking out a disk under load
2024-07-22 17:56 ` Konstantin Kharlamov
@ 2024-07-23 14:34 ` Konstantin Kharlamov
2024-07-31 14:14 ` Konstantin Kharlamov
1 sibling, 0 replies; 12+ messages in thread
From: Konstantin Kharlamov @ 2024-07-23 14:34 UTC (permalink / raw)
To: Yu Kuai, Song Liu, linux-raid, linux-kernel, yangerkun, yukuai (C)
On Mon, 2024-07-22 at 20:56 +0300, Konstantin Kharlamov wrote:
> On Mon, 2024-07-15 at 09:56 +0800, Yu Kuai wrote:
> > Line number will be helpful.
>
> So, after tinkering with building scripts I managed to build modules
> with debug symbols (not the kernel itself but should be good enough),
> but for some reason kernel doesn't show line numbers in stacktraces.
> No idea what could be causing it
FTR, getting a kernel with debug info doesn't seem to be on the
horizon. I tried researching into that and apparently kernel has
`bindeb-pkg` target that we're using to build the kernel, and it
unconditionally strips it (similarly to deb-pkg and srcdeb-pkg targets,
at scripts/Makefile.package:121). I found a few places in code where I
removed the stripping and replaced `strip` to `false` to make sure I
get an error if something else tries to do that, but at this point I'm
stuck with kernel succeeding the build, but leaving missing binaries
behind.
I might try digging into why installing `-dbg` package doesn't make
lines appear in stacktraces, but I presume it would take some time.
Meanwhile, as far as raid456 driver concerned, I can decode it manually
by feeding stacktrace offsets to gdb.
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: Lockup of (raid5 or raid6) + vdo after taking out a disk under load
2024-07-22 17:56 ` Konstantin Kharlamov
2024-07-23 14:34 ` Konstantin Kharlamov
@ 2024-07-31 14:14 ` Konstantin Kharlamov
2024-07-31 20:41 ` Bryan Gurney
2024-07-31 21:33 ` Matthew Sakai
1 sibling, 2 replies; 12+ messages in thread
From: Konstantin Kharlamov @ 2024-07-31 14:14 UTC (permalink / raw)
To: Yu Kuai, Song Liu, linux-raid, linux-kernel, yangerkun, yukuai (C)
Cc: dm-devel, Matthew Sakai
CC'ing VDO maintainers, because the problem is only reproducible with
VDO, so potentially they might have some ideas.
On Mon, 2024-07-22 at 20:56 +0300, Konstantin Kharlamov wrote:
> Hi, sorry for the delay, I had to give away the nodes and we had a
> week
> of teambuilding and company party, so for the past week I only
> managed
> to hack away stripping debug symbols, get another node and set it up.
>
> Experiments below are based off of vanilla 6.9.8 kernel *without*
> your
> patch.
>
> On Mon, 2024-07-15 at 09:56 +0800, Yu Kuai wrote:
> > Line number will be helpful.
>
> So, after tinkering with building scripts I managed to build modules
> with debug symbols (not the kernel itself but should be good enough),
> but for some reason kernel doesn't show line numbers in stacktraces.
> No
> idea what could be causing it, so I had to decode line numbers
> manually, below is an output where I inserted line numbers for
> raid456
> manually after decoding them with `gdb`.
>
> […]
> [ 1677.293366] <TASK>
> [ 1677.293661] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
> [ 1677.293972] ? _raw_spin_unlock_irq+0x10/0x30
> [ 1677.294276] ? _raw_spin_unlock_irq+0xa/0x30
> [ 1677.294586] raid5d at drivers/md/raid5.c:6572
> [ 1677.294910] md_thread+0xc1/0x170
> [ 1677.295228] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 1677.295545] ? __pfx_md_thread+0x10/0x10
> [ 1677.295870] kthread+0xff/0x130
> [ 1677.296189] ? __pfx_kthread+0x10/0x10
> [ 1677.296498] ret_from_fork+0x30/0x50
> [ 1677.296810] ? __pfx_kthread+0x10/0x10
> [ 1677.297112] ret_from_fork_asm+0x1a/0x30
> [ 1677.297424] </TASK>
> […]
> [ 1705.296253] <TASK>
> [ 1705.296554] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
> [ 1705.296864] ? _raw_spin_unlock_irq+0x10/0x30
> [ 1705.297172] ? _raw_spin_unlock_irq+0xa/0x30
> [ 1677.294586] raid5d at drivers/md/raid5.c:6597
> [ 1705.297794] md_thread+0xc1/0x170
> [ 1705.298099] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 1705.298409] ? __pfx_md_thread+0x10/0x10
> [ 1705.298714] kthread+0xff/0x130
> [ 1705.299022] ? __pfx_kthread+0x10/0x10
> [ 1705.299333] ret_from_fork+0x30/0x50
> [ 1705.299641] ? __pfx_kthread+0x10/0x10
> [ 1705.299947] ret_from_fork_asm+0x1a/0x30
> [ 1705.300257] </TASK>
> […]
> [ 1733.296255] <TASK>
> [ 1733.296556] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
> [ 1733.296862] ? _raw_spin_unlock_irq+0x10/0x30
> [ 1733.297170] ? _raw_spin_unlock_irq+0xa/0x30
> [ 1677.294586] raid5d at drivers/md/raid5.c:6572
> [ 1733.297792] md_thread+0xc1/0x170
> [ 1733.298096] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 1733.298403] ? __pfx_md_thread+0x10/0x10
> [ 1733.298711] kthread+0xff/0x130
> [ 1733.299018] ? __pfx_kthread+0x10/0x10
> [ 1733.299330] ret_from_fork+0x30/0x50
> [ 1733.299637] ? __pfx_kthread+0x10/0x10
> [ 1733.299943] ret_from_fork_asm+0x1a/0x30
> [ 1733.300251] </TASK>
>
> > Meanwhile, can you check if the underlying
> > disks has IO while raid5 stuck, by /sys/block/[device]/inflight.
>
> The two devices that are left after the 3rd one is removed has these
> numbers that don't change with time:
>
> [Mon Jul 22 20:18:06 @ ~]:> for d in dm-19 dm-17; do echo -n $d;
> cat
> /sys/block/$d/inflight; done
> dm-19 9 1
> dm-17 11 2
> [Mon Jul 22 20:18:11 @ ~]:> for d in dm-19 dm-17; do echo -n $d;
> cat
> /sys/block/$d/inflight; done
> dm-19 9 1
> dm-17 11 2
>
> They also don't change after I return the disk back (which is to be
> expected I guess, given that the lockup doesn't go away).
>
> > >
> > > > At first, can the problem reporduce with raid1/raid10? If not,
> > > > this
> > > > is
> > > > probably a raid5 bug.
> > >
> > > This is not reproducible with raid1 (i.e. no lockups for raid1),
> > > I
> > > tested that. I didn't test raid10, if you want I can try (but
> > > probably
> > > only after the weekend, because today I was asked to give the
> > > nodes
> > > away, for the weekend at least, to someone else).
> >
> > Yes, please try raid10 as well. For now I'll say this is a raid5
> > problem.
>
> Tested: raid10 works just fine, i.e. no lockup and fio continues
> having non-zero IOPS.
>
> > > > The best will be that if I can reporduce this problem myself.
> > > > The problem is that I don't understand the step 4: turning off
> > > > jbod
> > > > slot's power, is this only possible for a real machine, or can
> > > > I
> > > > do
> > > > this in my VM?
> > >
> > > Well, let's say that if it is possible, I don't know a way to do
> > > that.
> > > The `sg_ses` commands that I used
> > >
> > > sg_ses --dev-slot-num=9 --set=3:4:1 /dev/sg26 #
> > > turning
> > > off
> > > sg_ses --dev-slot-num=9 --clear=3:4:1 /dev/sg26 #
> > > turning
> > > on
> > >
> > > …sets and clears the value of the 3:4:1 bit, where the bit is
> > > defined
> > > by the JBOD's manufacturer datasheet. The 3:4:1 specifically is
> > > defined
> > > by "AIC" manufacturer. That means the command as is unlikely to
> > > work on
> > > a different hardware.
> >
> > I never do this before, I'll try.
> > >
> > > Well, while on it, do you have any thoughts why just using a
> > > `echo
> > > 1 >
> > > /sys/block/sdX/device/delete` doesn't reproduce it? Does perhaps
> > > kernel
> > > not emulate device disappearance too well?
> >
> > echo 1 > delete just delete the disk from kernel, and scsi/dm-raid
> > will
> > know that this disk is deleted. However, the disk will stay in
> > kernel
> > for the other way, dm-raid does not aware that underlying disks are
> > problematic and IO will still be generated and issued.
> >
> > Thanks,
> > Kuai
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: Lockup of (raid5 or raid6) + vdo after taking out a disk under load
2024-07-31 14:14 ` Konstantin Kharlamov
@ 2024-07-31 20:41 ` Bryan Gurney
2024-08-01 14:46 ` Konstantin Kharlamov
2024-07-31 21:33 ` Matthew Sakai
1 sibling, 1 reply; 12+ messages in thread
From: Bryan Gurney @ 2024-07-31 20:41 UTC (permalink / raw)
To: Konstantin Kharlamov
Cc: Yu Kuai, Song Liu, linux-raid, linux-kernel, yangerkun,
yukuai (C),
dm-devel, Matthew Sakai
Hi Konstantin,
This sounds a lot like something that I encountered with md, back in
2019, on the old vdo-devel mailing list:
https://listman.redhat.com/archives/vdo-devel/2019-August/000171.html
Basically, I had a RAID-5 md array that was in the process of recovery:
$ cat /proc/mdstat
Personalities : [raid0] [raid6] [raid5] [raid4]
md0 : active raid5 sde[4] sdd[2] sdc[1] sdb[0]
2929890816 blocks super 1.2 level 5, 512k chunk, algorithm 2 [4/3] [UUU_]
[=>...................] recovery = 9.1% (89227836/976630272)
finish=85.1min speed=173727K/sec
bitmap: 0/8 pages [0KB], 65536KB chunk
Note that the speed of the recovery is 173,727 KB/sec, which is less
than the sync_speed_max value:
$ grep . /sys/block/md0/md/sync_speed*
/sys/block/md0/md/sync_speed:171052
/sys/block/md0/md/sync_speed_max:200000 (system)
/sys/block/md0/md/sync_speed_min:1000 (system)
...And when I decreased "sync_speed_max" to "65536", I stopped seeing
hung task timeouts.
There's a similar setting in dm-raid: the "--maxrecoveryrate" option
of lvchange. So, to set the maximum recovery rate to 64 MiB per
second per device, this would be the command, for an example VG/LV of
"p_r5/testdmraid5"
# lvchange --maxrecoveryrate 64M p_r5/testdmraid5
(Older hard disk drives may not have a sequential read / write speed
of more than 100 MiB/sec; this meant that md's default of 200 MiB/sec
was "too fast", and would result in the recovery I/O starving the VDO
volume from being able to service I/O.)
The current value of max_recovery_rate for dm-raid can be displayed
with "lvs -a -o +raid_max_recovery_rate".
By reducing the maximum recovery rate for the dm-raid RAID-5 logical
volume, does this result in the hung task timeouts for the
"dm-vdo0-bioQ*" to not appear, and for the fio job to continue
writing?
Thanks,
Bryan
On Wed, Jul 31, 2024 at 10:21 AM Konstantin Kharlamov
<Hi-Angel@yandex.ru> wrote:
>
> CC'ing VDO maintainers, because the problem is only reproducible with
> VDO, so potentially they might have some ideas.
>
> On Mon, 2024-07-22 at 20:56 +0300, Konstantin Kharlamov wrote:
> > Hi, sorry for the delay, I had to give away the nodes and we had a
> > week
> > of teambuilding and company party, so for the past week I only
> > managed
> > to hack away stripping debug symbols, get another node and set it up.
> >
> > Experiments below are based off of vanilla 6.9.8 kernel *without*
> > your
> > patch.
> >
> > On Mon, 2024-07-15 at 09:56 +0800, Yu Kuai wrote:
> > > Line number will be helpful.
> >
> > So, after tinkering with building scripts I managed to build modules
> > with debug symbols (not the kernel itself but should be good enough),
> > but for some reason kernel doesn't show line numbers in stacktraces.
> > No
> > idea what could be causing it, so I had to decode line numbers
> > manually, below is an output where I inserted line numbers for
> > raid456
> > manually after decoding them with `gdb`.
> >
> > […]
> > [ 1677.293366] <TASK>
> > [ 1677.293661] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
> > [ 1677.293972] ? _raw_spin_unlock_irq+0x10/0x30
> > [ 1677.294276] ? _raw_spin_unlock_irq+0xa/0x30
> > [ 1677.294586] raid5d at drivers/md/raid5.c:6572
> > [ 1677.294910] md_thread+0xc1/0x170
> > [ 1677.295228] ? __pfx_autoremove_wake_function+0x10/0x10
> > [ 1677.295545] ? __pfx_md_thread+0x10/0x10
> > [ 1677.295870] kthread+0xff/0x130
> > [ 1677.296189] ? __pfx_kthread+0x10/0x10
> > [ 1677.296498] ret_from_fork+0x30/0x50
> > [ 1677.296810] ? __pfx_kthread+0x10/0x10
> > [ 1677.297112] ret_from_fork_asm+0x1a/0x30
> > [ 1677.297424] </TASK>
> > […]
> > [ 1705.296253] <TASK>
> > [ 1705.296554] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
> > [ 1705.296864] ? _raw_spin_unlock_irq+0x10/0x30
> > [ 1705.297172] ? _raw_spin_unlock_irq+0xa/0x30
> > [ 1677.294586] raid5d at drivers/md/raid5.c:6597
> > [ 1705.297794] md_thread+0xc1/0x170
> > [ 1705.298099] ? __pfx_autoremove_wake_function+0x10/0x10
> > [ 1705.298409] ? __pfx_md_thread+0x10/0x10
> > [ 1705.298714] kthread+0xff/0x130
> > [ 1705.299022] ? __pfx_kthread+0x10/0x10
> > [ 1705.299333] ret_from_fork+0x30/0x50
> > [ 1705.299641] ? __pfx_kthread+0x10/0x10
> > [ 1705.299947] ret_from_fork_asm+0x1a/0x30
> > [ 1705.300257] </TASK>
> > […]
> > [ 1733.296255] <TASK>
> > [ 1733.296556] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
> > [ 1733.296862] ? _raw_spin_unlock_irq+0x10/0x30
> > [ 1733.297170] ? _raw_spin_unlock_irq+0xa/0x30
> > [ 1677.294586] raid5d at drivers/md/raid5.c:6572
> > [ 1733.297792] md_thread+0xc1/0x170
> > [ 1733.298096] ? __pfx_autoremove_wake_function+0x10/0x10
> > [ 1733.298403] ? __pfx_md_thread+0x10/0x10
> > [ 1733.298711] kthread+0xff/0x130
> > [ 1733.299018] ? __pfx_kthread+0x10/0x10
> > [ 1733.299330] ret_from_fork+0x30/0x50
> > [ 1733.299637] ? __pfx_kthread+0x10/0x10
> > [ 1733.299943] ret_from_fork_asm+0x1a/0x30
> > [ 1733.300251] </TASK>
> >
> > > Meanwhile, can you check if the underlying
> > > disks has IO while raid5 stuck, by /sys/block/[device]/inflight.
> >
> > The two devices that are left after the 3rd one is removed has these
> > numbers that don't change with time:
> >
> > [Mon Jul 22 20:18:06 @ ~]:> for d in dm-19 dm-17; do echo -n $d;
> > cat
> > /sys/block/$d/inflight; done
> > dm-19 9 1
> > dm-17 11 2
> > [Mon Jul 22 20:18:11 @ ~]:> for d in dm-19 dm-17; do echo -n $d;
> > cat
> > /sys/block/$d/inflight; done
> > dm-19 9 1
> > dm-17 11 2
> >
> > They also don't change after I return the disk back (which is to be
> > expected I guess, given that the lockup doesn't go away).
> >
> > > >
> > > > > At first, can the problem reporduce with raid1/raid10? If not,
> > > > > this
> > > > > is
> > > > > probably a raid5 bug.
> > > >
> > > > This is not reproducible with raid1 (i.e. no lockups for raid1),
> > > > I
> > > > tested that. I didn't test raid10, if you want I can try (but
> > > > probably
> > > > only after the weekend, because today I was asked to give the
> > > > nodes
> > > > away, for the weekend at least, to someone else).
> > >
> > > Yes, please try raid10 as well. For now I'll say this is a raid5
> > > problem.
> >
> > Tested: raid10 works just fine, i.e. no lockup and fio continues
> > having non-zero IOPS.
> >
> > > > > The best will be that if I can reporduce this problem myself.
> > > > > The problem is that I don't understand the step 4: turning off
> > > > > jbod
> > > > > slot's power, is this only possible for a real machine, or can
> > > > > I
> > > > > do
> > > > > this in my VM?
> > > >
> > > > Well, let's say that if it is possible, I don't know a way to do
> > > > that.
> > > > The `sg_ses` commands that I used
> > > >
> > > > sg_ses --dev-slot-num=9 --set=3:4:1 /dev/sg26 #
> > > > turning
> > > > off
> > > > sg_ses --dev-slot-num=9 --clear=3:4:1 /dev/sg26 #
> > > > turning
> > > > on
> > > >
> > > > …sets and clears the value of the 3:4:1 bit, where the bit is
> > > > defined
> > > > by the JBOD's manufacturer datasheet. The 3:4:1 specifically is
> > > > defined
> > > > by "AIC" manufacturer. That means the command as is unlikely to
> > > > work on
> > > > a different hardware.
> > >
> > > I never do this before, I'll try.
> > > >
> > > > Well, while on it, do you have any thoughts why just using a
> > > > `echo
> > > > 1 >
> > > > /sys/block/sdX/device/delete` doesn't reproduce it? Does perhaps
> > > > kernel
> > > > not emulate device disappearance too well?
> > >
> > > echo 1 > delete just delete the disk from kernel, and scsi/dm-raid
> > > will
> > > know that this disk is deleted. However, the disk will stay in
> > > kernel
> > > for the other way, dm-raid does not aware that underlying disks are
> > > problematic and IO will still be generated and issued.
> > >
> > > Thanks,
> > > Kuai
>
>
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: Lockup of (raid5 or raid6) + vdo after taking out a disk under load
2024-07-31 14:14 ` Konstantin Kharlamov
2024-07-31 20:41 ` Bryan Gurney
@ 2024-07-31 21:33 ` Matthew Sakai
1 sibling, 0 replies; 12+ messages in thread
From: Matthew Sakai @ 2024-07-31 21:33 UTC (permalink / raw)
To: Konstantin Kharlamov, Yu Kuai, Song Liu, linux-raid,
linux-kernel, yangerkun, yukuai (C)
Cc: dm-devel
On 7/31/24 10:14, Konstantin Kharlamov wrote:
> CC'ing VDO maintainers, because the problem is only reproducible with
> VDO, so potentially they might have some ideas.
I don't see anything that implicates VDO directly. The blocked VDO
threads (with the test patch) seem to be stuck in raid5_make_request()
so it seems like the raid itself is not handling requests in a timely
manner.
There is one potentially useful detail, however: VDO mostly submits 4K
bios. The large number of smaller bios may be exacerbating an issue in
the raid5.
Matt
> On Mon, 2024-07-22 at 20:56 +0300, Konstantin Kharlamov wrote:
>> Hi, sorry for the delay, I had to give away the nodes and we had a
>> week
>> of teambuilding and company party, so for the past week I only
>> managed
>> to hack away stripping debug symbols, get another node and set it up.
>>
>> Experiments below are based off of vanilla 6.9.8 kernel *without*
>> your
>> patch.
>>
>> On Mon, 2024-07-15 at 09:56 +0800, Yu Kuai wrote:
>>> Line number will be helpful.
>>
>> So, after tinkering with building scripts I managed to build modules
>> with debug symbols (not the kernel itself but should be good enough),
>> but for some reason kernel doesn't show line numbers in stacktraces.
>> No
>> idea what could be causing it, so I had to decode line numbers
>> manually, below is an output where I inserted line numbers for
>> raid456
>> manually after decoding them with `gdb`.
>>
>> […]
>> [ 1677.293366] <TASK>
>> [ 1677.293661] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
>> [ 1677.293972] ? _raw_spin_unlock_irq+0x10/0x30
>> [ 1677.294276] ? _raw_spin_unlock_irq+0xa/0x30
>> [ 1677.294586] raid5d at drivers/md/raid5.c:6572
>> [ 1677.294910] md_thread+0xc1/0x170
>> [ 1677.295228] ? __pfx_autoremove_wake_function+0x10/0x10
>> [ 1677.295545] ? __pfx_md_thread+0x10/0x10
>> [ 1677.295870] kthread+0xff/0x130
>> [ 1677.296189] ? __pfx_kthread+0x10/0x10
>> [ 1677.296498] ret_from_fork+0x30/0x50
>> [ 1677.296810] ? __pfx_kthread+0x10/0x10
>> [ 1677.297112] ret_from_fork_asm+0x1a/0x30
>> [ 1677.297424] </TASK>
>> […]
>> [ 1705.296253] <TASK>
>> [ 1705.296554] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
>> [ 1705.296864] ? _raw_spin_unlock_irq+0x10/0x30
>> [ 1705.297172] ? _raw_spin_unlock_irq+0xa/0x30
>> [ 1677.294586] raid5d at drivers/md/raid5.c:6597
>> [ 1705.297794] md_thread+0xc1/0x170
>> [ 1705.298099] ? __pfx_autoremove_wake_function+0x10/0x10
>> [ 1705.298409] ? __pfx_md_thread+0x10/0x10
>> [ 1705.298714] kthread+0xff/0x130
>> [ 1705.299022] ? __pfx_kthread+0x10/0x10
>> [ 1705.299333] ret_from_fork+0x30/0x50
>> [ 1705.299641] ? __pfx_kthread+0x10/0x10
>> [ 1705.299947] ret_from_fork_asm+0x1a/0x30
>> [ 1705.300257] </TASK>
>> […]
>> [ 1733.296255] <TASK>
>> [ 1733.296556] ? asm_sysvec_apic_timer_interrupt+0x16/0x20
>> [ 1733.296862] ? _raw_spin_unlock_irq+0x10/0x30
>> [ 1733.297170] ? _raw_spin_unlock_irq+0xa/0x30
>> [ 1677.294586] raid5d at drivers/md/raid5.c:6572
>> [ 1733.297792] md_thread+0xc1/0x170
>> [ 1733.298096] ? __pfx_autoremove_wake_function+0x10/0x10
>> [ 1733.298403] ? __pfx_md_thread+0x10/0x10
>> [ 1733.298711] kthread+0xff/0x130
>> [ 1733.299018] ? __pfx_kthread+0x10/0x10
>> [ 1733.299330] ret_from_fork+0x30/0x50
>> [ 1733.299637] ? __pfx_kthread+0x10/0x10
>> [ 1733.299943] ret_from_fork_asm+0x1a/0x30
>> [ 1733.300251] </TASK>
>>
>>> Meanwhile, can you check if the underlying
>>> disks has IO while raid5 stuck, by /sys/block/[device]/inflight.
>>
>> The two devices that are left after the 3rd one is removed has these
>> numbers that don't change with time:
>>
>> [Mon Jul 22 20:18:06 @ ~]:> for d in dm-19 dm-17; do echo -n $d;
>> cat
>> /sys/block/$d/inflight; done
>> dm-19 9 1
>> dm-17 11 2
>> [Mon Jul 22 20:18:11 @ ~]:> for d in dm-19 dm-17; do echo -n $d;
>> cat
>> /sys/block/$d/inflight; done
>> dm-19 9 1
>> dm-17 11 2
>>
>> They also don't change after I return the disk back (which is to be
>> expected I guess, given that the lockup doesn't go away).
>>
>>>>
>>>>> At first, can the problem reporduce with raid1/raid10? If not,
>>>>> this
>>>>> is
>>>>> probably a raid5 bug.
>>>>
>>>> This is not reproducible with raid1 (i.e. no lockups for raid1),
>>>> I
>>>> tested that. I didn't test raid10, if you want I can try (but
>>>> probably
>>>> only after the weekend, because today I was asked to give the
>>>> nodes
>>>> away, for the weekend at least, to someone else).
>>>
>>> Yes, please try raid10 as well. For now I'll say this is a raid5
>>> problem.
>>
>> Tested: raid10 works just fine, i.e. no lockup and fio continues
>> having non-zero IOPS.
>>
>>>>> The best will be that if I can reporduce this problem myself.
>>>>> The problem is that I don't understand the step 4: turning off
>>>>> jbod
>>>>> slot's power, is this only possible for a real machine, or can
>>>>> I
>>>>> do
>>>>> this in my VM?
>>>>
>>>> Well, let's say that if it is possible, I don't know a way to do
>>>> that.
>>>> The `sg_ses` commands that I used
>>>>
>>>> sg_ses --dev-slot-num=9 --set=3:4:1 /dev/sg26 #
>>>> turning
>>>> off
>>>> sg_ses --dev-slot-num=9 --clear=3:4:1 /dev/sg26 #
>>>> turning
>>>> on
>>>>
>>>> …sets and clears the value of the 3:4:1 bit, where the bit is
>>>> defined
>>>> by the JBOD's manufacturer datasheet. The 3:4:1 specifically is
>>>> defined
>>>> by "AIC" manufacturer. That means the command as is unlikely to
>>>> work on
>>>> a different hardware.
>>>
>>> I never do this before, I'll try.
>>>>
>>>> Well, while on it, do you have any thoughts why just using a
>>>> `echo
>>>> 1 >
>>>> /sys/block/sdX/device/delete` doesn't reproduce it? Does perhaps
>>>> kernel
>>>> not emulate device disappearance too well?
>>>
>>> echo 1 > delete just delete the disk from kernel, and scsi/dm-raid
>>> will
>>> know that this disk is deleted. However, the disk will stay in
>>> kernel
>>> for the other way, dm-raid does not aware that underlying disks are
>>> problematic and IO will still be generated and issued.
>>>
>>> Thanks,
>>> Kuai
>
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: Lockup of (raid5 or raid6) + vdo after taking out a disk under load
2024-07-31 20:41 ` Bryan Gurney
@ 2024-08-01 14:46 ` Konstantin Kharlamov
0 siblings, 0 replies; 12+ messages in thread
From: Konstantin Kharlamov @ 2024-08-01 14:46 UTC (permalink / raw)
To: Bryan Gurney
Cc: Yu Kuai, Song Liu, linux-raid, linux-kernel, yangerkun,
yukuai (C),
dm-devel, Matthew Sakai
On Wed, 2024-07-31 at 16:41 -0400, Bryan Gurney wrote:
> Hi Konstantin,
>
> This sounds a lot like something that I encountered with md, back in
> 2019, on the old vdo-devel mailing list:
>
> https://listman.redhat.com/archives/vdo-devel/2019-August/000171.html
>
> Basically, I had a RAID-5 md array that was in the process of
> recovery:
>
> $ cat /proc/mdstat
> Personalities : [raid0] [raid6] [raid5] [raid4]
> md0 : active raid5 sde[4] sdd[2] sdc[1] sdb[0]
> 2929890816 blocks super 1.2 level 5, 512k chunk, algorithm 2
> [4/3] [UUU_]
> [=>...................] recovery = 9.1% (89227836/976630272)
> finish=85.1min speed=173727K/sec
> bitmap: 0/8 pages [0KB], 65536KB chunk
>
> Note that the speed of the recovery is 173,727 KB/sec, which is less
> than the sync_speed_max value:
>
> $ grep . /sys/block/md0/md/sync_speed*
> /sys/block/md0/md/sync_speed:171052
> /sys/block/md0/md/sync_speed_max:200000 (system)
> /sys/block/md0/md/sync_speed_min:1000 (system)
>
> ...And when I decreased "sync_speed_max" to "65536", I stopped seeing
> hung task timeouts.
>
> There's a similar setting in dm-raid: the "--maxrecoveryrate" option
> of lvchange. So, to set the maximum recovery rate to 64 MiB per
> second per device, this would be the command, for an example VG/LV of
> "p_r5/testdmraid5"
>
> # lvchange --maxrecoveryrate 64M p_r5/testdmraid5
>
> (Older hard disk drives may not have a sequential read / write speed
> of more than 100 MiB/sec; this meant that md's default of 200 MiB/sec
> was "too fast", and would result in the recovery I/O starving the VDO
> volume from being able to service I/O.)
>
> The current value of max_recovery_rate for dm-raid can be displayed
> with "lvs -a -o +raid_max_recovery_rate".
>
> By reducing the maximum recovery rate for the dm-raid RAID-5 logical
> volume, does this result in the hung task timeouts for the
> "dm-vdo0-bioQ*" to not appear, and for the fio job to continue
> writing?
Thank you, so, I'm trying this out, and it doesn't seem to be working that well
(unless perhaps something changed in the userspace LVM since the 2.03.11 I am
using?).
So, after having executed the original steps-to-reproduce I have these two volumes:
$ lvs
LV VG Attr LSize Pool Origin Data% Meta% Move Log Cpy%Sync Convert
deco_vol p_r5 vwi-XXv-X- 100.00g vdo_internal_deco_vol
vdo_internal_deco_vol p_r5 dwi-XX--X- 20.00g
Executing the suggested lvchange command does nothing on them:
$ lvchange --maxrecoveryrate 64M p_r5/deco_vol
Command on LV p_r5/deco_vol uses options that require LV types raid .
Command not permitted on LV p_r5/deco_vol.
$ lvchange --maxrecoveryrate 64M p_r5/vdo_internal_deco_vol
Command on LV p_r5/vdo_internal_deco_vol uses options that require LV types raid .
Command not permitted on LV p_r5/vdo_internal_deco_vol.
Also, executing a `lvs -a -o +raid_max_recovery_rate` shows emptiness in place of
that field. However, this command shows various internal volumes:
$ lvs -a -o +raid_max_recovery_rate
LV VG Attr LSize Pool Origin Data% Meta% Move Log Cpy%Sync Convert MaxSync
deco_vol p_r5 vwi-XXv-X- 100.00g vdo_internal_deco_vol
vdo_internal_deco_vol p_r5 dwi-XX--X- 20.00g
[vdo_internal_deco_vol_vdata] p_r5 rwi-aor--- 20.00g 100.00
[vdo_internal_deco_vol_vdata_rimage_0] p_r5 iwi-aor--- 10.00g
[vdo_internal_deco_vol_vdata_rimage_1] p_r5 iwi-aor--- 10.00g
[vdo_internal_deco_vol_vdata_rimage_2] p_r5 iwi-aor--- 10.00g
[vdo_internal_deco_vol_vdata_rmeta_0] p_r5 ewi-aor--- 4.00m
[vdo_internal_deco_vol_vdata_rmeta_1] p_r5 ewi-aor--- 4.00m
[vdo_internal_deco_vol_vdata_rmeta_2] p_r5 ewi-aor--- 4.00m
So I tried executing the command on them:
$ lvchange --maxrecoveryrate 64M p_r5/{vdo_internal_deco_vol_vdata,vdo_internal_deco_vol_vdata_rimage_0,vdo_internal_deco_vol_vdata_rimage_1,vdo_internal_deco_vol_vdata_rimage_2,vdo_internal_deco_vol_vdata_rmeta_0,vdo_internal_deco_vol_vdata_rmeta_1,vdo_internal_deco_vol_vdata_rmeta_2}
Command on LV p_r5/vdo_internal_deco_vol_vdata_rimage_0 uses options that require LV types raid .
Command not permitted on LV p_r5/vdo_internal_deco_vol_vdata_rimage_0.
Command on LV p_r5/vdo_internal_deco_vol_vdata_rmeta_0 uses options that require LV types raid .
Command not permitted on LV p_r5/vdo_internal_deco_vol_vdata_rmeta_0.
Command on LV p_r5/vdo_internal_deco_vol_vdata_rimage_1 uses options that require LV types raid .
Command not permitted on LV p_r5/vdo_internal_deco_vol_vdata_rimage_1.
Command on LV p_r5/vdo_internal_deco_vol_vdata_rmeta_1 uses options that require LV types raid .
Command not permitted on LV p_r5/vdo_internal_deco_vol_vdata_rmeta_1.
Command on LV p_r5/vdo_internal_deco_vol_vdata_rimage_2 uses options that require LV types raid .
Command not permitted on LV p_r5/vdo_internal_deco_vol_vdata_rimage_2.
Command on LV p_r5/vdo_internal_deco_vol_vdata_rmeta_2 uses options that require LV types raid .
Command not permitted on LV p_r5/vdo_internal_deco_vol_vdata_rmeta_2.
Logical volume p_r5/vdo_internal_deco_vol_vdata changed.
This resulted in exactly one volume having changed its speed: the `[vdo_internal_deco_vol_vdata]`.
With that done, I tried removing a disk while there's load, and it results in same
old lockup reports:
-----------------------
So to sum up: the lvchange command only managed to change speed on a single internal
volume, but that didn't make the lockup go away.
^ permalink raw reply [flat|nested] 12+ messages in thread
end of thread, other threads:[~2024-08-01 14:46 UTC | newest]
Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2024-07-12 6:53 Lockup of (raid5 or raid6) + vdo after taking out a disk under load Konstantin Kharlamov
2024-07-12 8:35 ` Yu Kuai
2024-07-12 12:11 ` Konstantin Kharlamov
2024-07-13 11:06 ` Yu Kuai
2024-07-13 13:50 ` Konstantin Kharlamov
2024-07-15 1:56 ` Yu Kuai
2024-07-22 17:56 ` Konstantin Kharlamov
2024-07-23 14:34 ` Konstantin Kharlamov
2024-07-31 14:14 ` Konstantin Kharlamov
2024-07-31 20:41 ` Bryan Gurney
2024-08-01 14:46 ` Konstantin Kharlamov
2024-07-31 21:33 ` Matthew Sakai
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox
all inboxes | Powered by JetHome®