[dm-devel] dmzone trigger problem with zone reclaim
yangerkun
yangerkun at huawei.com
Fri Jul 6 09:20:21 UTC 2018
Hi,
Nowdays, i am trying dm-zoned+f2fs to use SMR block device. But, there
is a problem that i can not distinguish it is problem of block device or
the software.
The steps and phenomena of recurrence are as follows:
1.dmzadm --format /dev/sdf
2.echo "0 `blockdev --getsize /dev/sdf` zoned /dev/sdf" | dmsetup create
dmz-`basename /dev/sdf`
3.mkfs.f2fs /dev/mapper/dmz-sdf
Then, dm-zoned will reclaim some rnd zone, and the problem will trigger
as follow:
dmz_reclaim
->dmz_reclaim_rnd_data
->dmz_reclaim_copy
->dmz_reclaim_align_wp
->blkdev_issue_zeroout
The return error is EIO:
[ 4536.178190] sas: Enter sas_scsi_recover_host busy: 2 failed: 2
[ 4536.184040] sas: trying to find task 0x00000000b423196b
[ 4536.189268] sas: sas_scsi_find_task: aborting task 0x00000000b423196b
[ 4536.249110] sas: sas_scsi_find_task: task 0x00000000b423196b is done
[ 4536.255464] sas: sas_eh_handle_sas_errors: task 0x00000000b423196b is
done
[ 4536.262345] sas: ata6: end_device-0:0:8: cmd error handler
[ 4536.267864] sas: ata1: end_device-0:0:0: dev error handler
[ 4536.267871] sas: ata2: end_device-0:0:1: dev error handler
[ 4536.267879] sas: ata3: end_device-0:0:3: dev error handler
[ 4536.267895] sas: ata4: end_device-0:0:4: dev error handler
[ 4536.267905] sas: ata5: end_device-0:0:5: dev error handler
[ 4536.267915] sas: ata6: end_device-0:0:8: dev error handler
[ 4536.267919] ata6.00: sense data available but port frozen
[ 4536.267921] ata6.00: sense data available but port frozen
[ 4536.267925] ata6.00: exception Emask 0x1 SAct 0x60 SErr 0x0 action
0x6 frozen
[ 4536.267930] ata6.00: failed command: WRITE FPDMA QUEUED
[ 4536.267934] ata6.00: cmd 61/00:00:00:08:87/04:00:03:00:00/40 tag 5
ncq dma 524288 out
res 43/04:00:00:00:00/00:00:00:00:00/00 Emask 0x5 (timeout)
[ 4536.267936] ata6.00: status: { DRDY SENSE ERR }
[ 4536.267937] ata6.00: error: { ABRT }
[ 4536.267939] ata6.00: failed command: WRITE FPDMA QUEUED
[ 4536.267943] ata6.00: cmd 61/00:00:00:0c:87/04:00:03:00:00/40 tag 6
ncq dma 524288 out
res 43/04:00:00:00:00/00:00:00:00:00/00 Emask 0x1 (device error)
[ 4536.267945] ata6.00: status: { DRDY SENSE ERR }
[ 4536.267946] ata6.00: error: { ABRT }
[ 4536.267948] ata6: hard resetting link
[ 4536.274454] sas: broadcast received: 0
[ 4536.383437] sas: REVALIDATION DEFERRED on port 0, pid:18191
[ 4536.389010] sas: broadcast received: 0
[ 4536.392752] sas: broadcast received: 0
[ 4536.396494] sas: broadcast received: 0
[ 4536.400236] sas: broadcast received: 0
[ 4536.403977] sas: broadcast received: 0
[ 4536.407718] sas: broadcast received: 0
[ 4536.411460] sas: broadcast received: 0
[ 4536.415202] sas: broadcast received: 0
[ 4536.418944] sas: broadcast received: 0
[ 4536.422685] sas: broadcast received: 0
[ 4536.426427] sas: broadcast received: 0
[ 4536.430168] sas: broadcast received: 0
[ 4536.433904] sas: broadcast received: 0
[ 4536.437646] sas: broadcast received: 0
[ 4536.441388] sas: broadcast received: 0
[ 4538.459884] ata6.00: NCQ Send/Recv Log not supported
[ 4538.466881] ata6.00: NCQ Send/Recv Log not supported
[ 4538.472894] ata6.00: configured for UDMA/133
[ 4538.477179] ata6: EH complete
[ 4538.480194] sas: --- Exit sas_scsi_recover_host: busy: 0 failed: 2
tries: 1
[ 4538.480198] sas: broadcast received: 0
[ 4538.490924] sas: REVALIDATING DOMAIN on port 0, pid:17922
[ 4538.497366] sas: Expander phy change count has changed
[ 4538.503341] sas: ex 500e004aaaaaaa1f phy8 originated BROADCAST(CHANGE)
[ 4538.510109] sas: ex 500e004aaaaaaa1f phy 0x8 broadcast flutter
[ 4538.517490] sas: done REVALIDATING DOMAIN on port 0, pid:17922, res 0x0
[ 4551.682209] sas: Enter sas_scsi_recover_host busy: 2 failed: 2
[ 4551.688047] sas: trying to find task 0x0000000046927847
[ 4551.693280] sas: sas_scsi_find_task: aborting task 0x0000000046927847
[ 4551.752529] sas: sas_scsi_find_task: task 0x0000000046927847 is done
[ 4551.758880] sas: sas_eh_handle_sas_errors: task 0x0000000046927847 is
done
[ 4551.765758] sas: ata6: end_device-0:0:8: cmd error handler
[ 4551.771271] sas: ata1: end_device-0:0:0: dev error handler
[ 4551.771279] sas: ata2: end_device-0:0:1: dev error handler
[ 4551.771287] sas: ata3: end_device-0:0:3: dev error handler
[ 4551.771294] sas: ata4: end_device-0:0:4: dev error handler
[ 4551.771297] sas: ata5: end_device-0:0:5: dev error handler
[ 4551.771301] sas: ata6: end_device-0:0:8: dev error handler
[ 4551.771306] ata6.00: sense data available but port frozen
[ 4551.771307] ata6.00: sense data available but port frozen
[ 4551.771310] ata6.00: exception Emask 0x1 SAct 0x300 SErr 0x0 action
0x6 frozen
[ 4551.771313] ata6.00: failed command: WRITE FPDMA QUEUED
[ 4551.771317] ata6.00: cmd 61/00:00:00:0c:87/04:00:03:00:00/40 tag 8
ncq dma 524288 out
res 43/04:00:00:0c:87/00:04:03:00:00/40 Emask 0x5 (timeout)
[ 4551.771318] ata6.00: status: { DRDY SENSE ERR }
[ 4551.771320] ata6.00: error: { ABRT }
[ 4551.771321] ata6.00: failed command: WRITE FPDMA QUEUED
[ 4551.771325] ata6.00: cmd 61/00:00:00:08:87/04:00:03:00:00/40 tag 9
ncq dma 524288 out
res 43/04:00:00:0c:87/00:04:03:00:00/40 Emask 0x1 (device error)
[ 4551.771327] ata6.00: status: { DRDY SENSE ERR }
[ 4551.771328] ata6.00: error: { ABRT }
[ 4551.771330] ata6: hard resetting link
[ 4551.774432] sas: broadcast received: 0
[ 4551.774438] sas: REVALIDATION DEFERRED on port 0, pid:15800
[ 4551.774466] sas: broadcast received: 0
[ 4551.774494] sas: broadcast received: 0
[ 4551.774522] sas: broadcast received: 0
[ 4551.774551] sas: broadcast received: 0
[ 4551.774579] sas: broadcast received: 0
[ 4551.774608] sas: broadcast received: 0
[ 4551.774637] sas: broadcast received: 0
[ 4551.854272] sas: broadcast received: 0
[ 4551.922385] sas: broadcast received: 0
[ 4551.926121] sas: broadcast received: 0
[ 4551.929864] sas: broadcast received: 0
[ 4551.933606] sas: broadcast received: 0
[ 4551.937348] sas: broadcast received: 0
[ 4551.941089] sas: broadcast received: 0
[ 4551.944831] sas: broadcast received: 0
[ 4553.947340] ata6.00: NCQ Send/Recv Log not supported
[ 4553.954438] ata6.00: NCQ Send/Recv Log not supported
[ 4553.960445] ata6.00: configured for UDMA/133
[ 4553.964727] ata6: EH complete
[ 4553.967723] sas: --- Exit sas_scsi_recover_host: busy: 0 failed: 2
tries: 1
[ 4553.967726] sas: broadcast received: 0
[ 4553.967735] sas: REVALIDATING DOMAIN on port 0, pid:18193
[ 4553.984913] sas: Expander phy change count has changed
[ 4553.990947] sas: ex 500e004aaaaaaa1f phy8 originated BROADCAST(CHANGE)
[ 4553.997680] sas: ex 500e004aaaaaaa1f phy 0x8 broadcast flutter
[ 4554.005030] sas: done REVALIDATING DOMAIN on port 0, pid:18193, res 0x0
[ 4566.678209] sas: Enter sas_scsi_recover_host busy: 2 failed: 2
[ 4566.684047] sas: trying to find task 0x0000000046927847
[ 4566.689274] sas: sas_scsi_find_task: aborting task 0x0000000046927847
[ 4566.748663] sas: sas_scsi_find_task: task 0x0000000046927847 is done
[ 4566.755015] sas: sas_eh_handle_sas_errors: task 0x0000000046927847 is
done
[ 4566.761896] sas: ata6: end_device-0:0:8: cmd error handler
[ 4566.767409] sas: ata1: end_device-0:0:0: dev error handler
[ 4566.767416] sas: ata2: end_device-0:0:1: dev error handler
[ 4566.767422] sas: ata3: end_device-0:0:3: dev error handler
[ 4566.767430] sas: ata4: end_device-0:0:4: dev error handler
[ 4566.767432] sas: ata5: end_device-0:0:5: dev error handler
[ 4566.767435] sas: ata6: end_device-0:0:8: dev error handler
[ 4566.767440] ata6.00: sense data available but port frozen
[ 4566.767442] ata6.00: sense data available but port frozen
[ 4566.767444] ata6.00: exception Emask 0x1 SAct 0x1800 SErr 0x0 action
0x6 frozen
[ 4566.767447] ata6.00: failed command: WRITE FPDMA QUEUED
[ 4566.767451] ata6.00: cmd 61/00:00:00:08:87/04:00:03:00:00/40 tag 11
ncq dma 524288 out
res 43/04:00:00:08:87/00:04:03:00:00/40 Emask 0x5 (timeout)
[ 4566.767452] ata6.00: status: { DRDY SENSE ERR }
[ 4566.767454] ata6.00: error: { ABRT }
[ 4566.767455] ata6.00: failed command: WRITE FPDMA QUEUED
[ 4566.767459] ata6.00: cmd 61/00:00:00:0c:87/04:00:03:00:00/40 tag 12
ncq dma 524288 out
res 43/04:00:00:08:87/00:04:03:00:00/40 Emask 0x1 (device error)
[ 4566.767460] ata6.00: status: { DRDY SENSE ERR }
[ 4566.767461] ata6.00: error: { ABRT }
[ 4566.767464] ata6: hard resetting link
[ 4566.775447] sas: broadcast received: 0
[ 4566.883322] sas: REVALIDATION DEFERRED on port 0, pid:18238
[ 4566.888893] sas: broadcast received: 0
[ 4566.892634] sas: broadcast received: 0
[ 4566.896376] sas: broadcast received: 0
[ 4566.900118] sas: broadcast received: 0
[ 4566.903859] sas: broadcast received: 0
[ 4566.907601] sas: broadcast received: 0
[ 4566.911343] sas: broadcast received: 0
[ 4566.915084] sas: broadcast received: 0
[ 4566.918826] sas: broadcast received: 0
[ 4566.922567] sas: broadcast received: 0
[ 4566.926308] sas: broadcast received: 0
[ 4566.930044] sas: broadcast received: 0
[ 4566.933786] sas: broadcast received: 0
[ 4566.937527] sas: broadcast received: 0
[ 4566.941268] sas: broadcast received: 0
[ 4568.955383] ata6.00: NCQ Send/Recv Log not supported
[ 4568.963034] ata6.00: NCQ Send/Recv Log not supported
[ 4568.969047] ata6.00: configured for UDMA/133
[ 4568.973333] ata6: EH complete
[ 4568.976328] sas: --- Exit sas_scsi_recover_host: busy: 0 failed: 2
tries: 1
[ 4568.976332] sas: broadcast received: 0
[ 4568.987038] sas: REVALIDATING DOMAIN on port 0, pid:17922
[ 4568.993476] sas: Expander phy change count has changed
[ 4568.999504] sas: ex 500e004aaaaaaa1f phy8 originated BROADCAST(CHANGE)
[ 4569.006254] sas: ex 500e004aaaaaaa1f phy 0x8 broadcast flutter
[ 4569.013597] sas: done REVALIDATING DOMAIN on port 0, pid:17922, res 0x0
[ 4581.930193] sas: Enter sas_scsi_recover_host busy: 2 failed: 2
[ 4581.936034] sas: trying to find task 0x0000000046927847
[ 4581.941261] sas: sas_scsi_find_task: aborting task 0x0000000046927847
[ 4582.001409] sas: sas_scsi_find_task: task 0x0000000046927847 is done
[ 4582.007762] sas: sas_eh_handle_sas_errors: task 0x0000000046927847 is
done
[ 4582.014640] sas: ata6: end_device-0:0:8: cmd error handler
[ 4582.020152] sas: ata1: end_device-0:0:0: dev error handler
[ 4582.020158] sas: ata2: end_device-0:0:1: dev error handler
[ 4582.020166] sas: ata3: end_device-0:0:3: dev error handler
[ 4582.020171] sas: ata4: end_device-0:0:4: dev error handler
[ 4582.020178] sas: ata5: end_device-0:0:5: dev error handler
[ 4582.020179] sas: ata6: end_device-0:0:8: dev error handler
[ 4582.020184] ata6.00: sense data available but port frozen
[ 4582.020185] ata6.00: sense data available but port frozen
[ 4582.020187] ata6.00: NCQ disabled due to excessive errors
[ 4582.020188] ata6.00: exception Emask 0x1 SAct 0xc000 SErr 0x0 action
0x6 frozen
[ 4582.020190] ata6.00: failed command: WRITE FPDMA QUEUED
[ 4582.020194] ata6.00: cmd 61/00:00:00:0c:87/04:00:03:00:00/40 tag 14
ncq dma 524288 out
res 43/04:00:00:0c:87/00:04:03:00:00/40 Emask 0x5 (timeout)
[ 4582.020195] ata6.00: status: { DRDY SENSE ERR }
[ 4582.020196] ata6.00: error: { ABRT }
[ 4582.020198] ata6.00: failed command: WRITE FPDMA QUEUED
[ 4582.020201] ata6.00: cmd 61/00:00:00:08:87/04:00:03:00:00/40 tag 15
ncq dma 524288 out
res 43/04:00:00:0c:87/00:04:03:00:00/40 Emask 0x1 (device error)
[ 4582.020203] ata6.00: status: { DRDY SENSE ERR }
[ 4582.020204] ata6.00: error: { ABRT }
[ 4582.020206] ata6: hard resetting link
[ 4582.025469] sas: broadcast received: 0
[ 4582.025476] sas: REVALIDATION DEFERRED on port 0, pid:18191
[ 4582.025505] sas: broadcast received: 0
[ 4582.025533] sas: broadcast received: 0
[ 4582.025561] sas: broadcast received: 0
[ 4582.025590] sas: broadcast received: 0
[ 4582.025619] sas: broadcast received: 0
[ 4582.025649] sas: broadcast received: 0
[ 4582.169474] sas: broadcast received: 0
[ 4582.173225] sas: broadcast received: 0
[ 4582.176968] sas: broadcast received: 0
[ 4582.180710] sas: broadcast received: 0
[ 4582.184452] sas: broadcast received: 0
[ 4582.188194] sas: broadcast received: 0
[ 4582.191937] sas: broadcast received: 0
[ 4582.195678] sas: broadcast received: 0
[ 4582.199420] sas: broadcast received: 0
[ 4584.187387] ata6.00: NCQ Send/Recv Log not supported
[ 4584.194424] ata6.00: NCQ Send/Recv Log not supported
[ 4584.200434] ata6.00: configured for UDMA/133
[ 4584.204718] ata6: EH complete
[ 4584.207714] sas: --- Exit sas_scsi_recover_host: busy: 0 failed: 2
tries: 1
[ 4584.207719] sas: broadcast received: 0
[ 4584.218446] sas: REVALIDATING DOMAIN on port 0, pid:15800
[ 4584.224907] sas: Expander phy change count has changed
[ 4584.230935] sas: ex 500e004aaaaaaa1f phy8 originated BROADCAST(CHANGE)
[ 4584.237667] sas: ex 500e004aaaaaaa1f phy 0x8 broadcast flutter
[ 4584.242183] sas: Enter sas_scsi_recover_host busy: 1 failed: 1
[ 4584.245029] sas: done REVALIDATING DOMAIN on port 0, pid:15800, res 0x0
[ 4584.249321] sas: ata6: end_device-0:0:8: cmd error handler
[ 4584.261444] sas: ata1: end_device-0:0:0: dev error handler
[ 4584.261450] sas: ata2: end_device-0:0:1: dev error handler
[ 4584.261455] sas: ata3: end_device-0:0:3: dev error handler
[ 4584.261461] sas: ata4: end_device-0:0:4: dev error handler
[ 4584.261465] sas: ata5: end_device-0:0:5: dev error handler
[ 4584.261467] sas: ata6: end_device-0:0:8: dev error handler
[ 4584.266971] sd 0:0:5:0: [sdf] tag#0 UNKNOWN(0x2003) Result:
hostbyte=0x00 driverbyte=0x08
[ 4584.302489] sd 0:0:5:0: [sdf] tag#0 Sense Key : 0x5 [current]
[ 4584.308318] sd 0:0:5:0: [sdf] tag#0 ASC=0x21 ASCQ=0x4
[ 4584.313453] sd 0:0:5:0: [sdf] tag#0 CDB: opcode=0x8a 8a 00 00 00 00
00 03 87 08 00 00 00 04 00 00 00
[ 4584.322579] print_req_error: I/O error, dev sdf, sector 59181056
[ 4584.328614] sas: --- Exit sas_scsi_recover_host: busy: 0 failed: 1
tries: 1
[ 4584.358188] sas: Enter sas_scsi_recover_host busy: 1 failed: 1
[ 4584.364022] sas: ata6: end_device-0:0:8: cmd error handler
[ 4584.369532] sas: ata1: end_device-0:0:0: dev error handler
[ 4584.369539] sas: ata2: end_device-0:0:1: dev error handler
[ 4584.369558] sas: ata3: end_device-0:0:3: dev error handler
[ 4584.369564] sas: ata4: end_device-0:0:4: dev error handler
[ 4584.369573] sas: ata5: end_device-0:0:5: dev error handler
[ 4584.369621] sas: ata6: end_device-0:0:8: dev error handler
[ 4584.369856] sd 0:0:5:0: [sdf] tag#0 UNKNOWN(0x2003) Result:
hostbyte=0x00 driverbyte=0x08
[ 4584.369859] sd 0:0:5:0: [sdf] tag#0 Sense Key : 0x5 [current]
[ 4584.369861] sd 0:0:5:0: [sdf] tag#0 ASC=0x21 ASCQ=0x4
[ 4584.369864] sd 0:0:5:0: [sdf] tag#0 CDB: opcode=0x8a 8a 00 00 00 00
00 03 87 0c 00 00 00 04 00 00 00
[ 4584.369865] print_req_error: I/O error, dev sdf, sector 59182080
[ 4584.436640] sas: --- Exit sas_scsi_recover_host: busy: 0 failed: 1
tries: 1
[ 4584.680697] device-mapper: zoned reclaim: (sdf): Align zone 112 wp 0
to 57856 (wp+57856) blocks failed -5
With another way, just go through 1 and 2, and then use dd to do flush
data into block device. The rnd zone size is 23GB, use dd to do write in
this area won't trigger error, but while try to write the first sector
in seq zone, it will trigger problem as follow.
[ 4779.730183] sas: Enter sas_scsi_recover_host busy: 1 failed: 1
[ 4779.736031] sas: ata6: end_device-0:0:8: cmd error handler
[ 4779.741546] sas: ata1: end_device-0:0:0: dev error handler
[ 4779.741550] sas: ata2: end_device-0:0:1: dev error handler
[ 4779.741575] sas: ata3: end_device-0:0:3: dev error handler
[ 4779.741585] sas: ata4: end_device-0:0:4: dev error handler
[ 4779.741593] sas: ata5: end_device-0:0:5: dev error handler
[ 4779.741598] sas: ata6: end_device-0:0:8: dev error handler
[ 4779.741859] sd 0:0:5:0: [sdf] tag#0 UNKNOWN(0x2003) Result:
hostbyte=0x00 driverbyte=0x08
[ 4779.741863] sd 0:0:5:0: [sdf] tag#0 Sense Key : 0x5 [current]
[ 4779.741865] sd 0:0:5:0: [sdf] tag#0 ASC=0x21 ASCQ=0x4
[ 4779.741868] sd 0:0:5:0: [sdf] tag#0 CDB: opcode=0x8a 8a 00 00 00 00
00 03 00 00 00 00 00 00 01 00 00
[ 4779.741870] print_req_error: I/O error, dev sdf, sector 50331648
[ 4779.808664] sas: --- Exit sas_scsi_recover_host: busy: 0 failed: 1
tries: 1
Since there is only one device, i cannot contrast the appearance with
other SMR block device. Can you help me?
More information about the dm-devel
mailing list