Closed rkrten closed 3 years ago
rkrten
commented
5 years ago Jonathon's patch https://github.com/zfsonlinux/zfs/commit/e5db31349484e5e859c7a942eb15b98d68ce5b4d has solved the problem for me; I was able to complete a scrub in the usual 6 hours, with no exceptional dp_sync_taskq activity. I did this twice just to make sure :-)
rkrten
commented
5 years ago I spoke too soon :-( The issue, while better, still remains.
Here's a latest top, again demonstrating the dp_sync_taskq problem:
top - 16:07:09 up 8:33, 1 user, load average: 2.38, 2.55, 2.50
Tasks: 415 total, 1 running, 341 sleeping, 0 stopped, 1 zombie
%Cpu(s): 3.6 us, 4.4 sy, 0.0 ni, 80.5 id, 11.2 wa, 0.0 hi, 0.4 si, 0.0 st
KiB Mem : 16323184 total, 4531884 free, 7944208 used, 3847092 buff/cache
KiB Swap: 0 total, 0 free, 0 used. 6953072 avail Mem
...
1089 root 39 19 0 0 0 S 0.0 0.0 18:44.30 `- dp_sync_taskq
1090 root 39 19 0 0 0 S 0.0 0.0 18:15.41 `- dp_sync_taskq
1091 root 39 19 0 0 0 D 57.1 0.0 18:54.27 `- dp_sync_taskq
1092 root 39 19 0 0 0 S 0.0 0.0 19:08.11 `- dp_sync_taskq
1093 root 39 19 0 0 0 S 0.0 0.0 17:44.40 `- dp_sync_taskq
1094 root 39 19 0 0 0 S 0.0 0.0 19:46.78 `- dp_sync_taskqThe problem is weird; when there is other filesystem activity (e.g., an rsync), the scrub proceeds at a good pace — the scanned and issued rates are in the 350-500 MB/s range. But once the filesystem goes idle, the performance of the scrub drops off, and the CPU utilization of dq_sync_taskq increases to the 50-75% range.
# zpool status
pool: main
state: ONLINE
scan: scrub in progress since Sun Jul 28 07:36:33 2019
5.75T scanned at 358M/s, 4.67T issued at 290M/s, 6.89T total
0B repaired, 67.77% done, 0 days 02:13:34 to go
config:
NAME STATE READ WRITE CKSUM
main ONLINE 0 0 0
raidz1-0 ONLINE 0 0 0
ata-WDC_WD40EZRZ-00GXCB0_WD-WCC7K1TVP9P2 ONLINE 0 0 0
ata-WDC_WD40EZRZ-00GXCB0_WD-WCC7K7KD384P ONLINE 0 0 0
ata-WDC_WD40EZRZ-00GXCB0_WD-WCC7K4SFJS7U ONLINE 0 0 0
errors: No known data errors# zpool status
pool: main
state: ONLINE
scan: scrub in progress since Sun Jul 28 07:36:33 2019
5.85T scanned at 254M/s, 5.75T issued at 249M/s, 6.89T total
0B repaired, 83.51% done, 0 days 01:19:32 to go
config:
NAME STATE READ WRITE CKSUM
main ONLINE 0 0 0
raidz1-0 ONLINE 0 0 0
ata-WDC_WD40EZRZ-00GXCB0_WD-WCC7K1TVP9P2 ONLINE 0 0 0
ata-WDC_WD40EZRZ-00GXCB0_WD-WCC7K7KD384P ONLINE 0 0 0
ata-WDC_WD40EZRZ-00GXCB0_WD-WCC7K4SFJS7U ONLINE 0 0 0
errors: No known data errors# zpool status
pool: main
state: ONLINE
scan: scrub in progress since Sun Jul 28 07:36:33 2019
5.85T scanned at 200M/s, 5.85T issued at 200M/s, 6.89T total
0B repaired, 84.95% done, 0 days 01:30:25 to go
config:
NAME STATE READ WRITE CKSUM
main ONLINE 0 0 0
raidz1-0 ONLINE 0 0 0
ata-WDC_WD40EZRZ-00GXCB0_WD-WCC7K1TVP9P2 ONLINE 0 0 0
ata-WDC_WD40EZRZ-00GXCB0_WD-WCC7K7KD384P ONLINE 0 0 0
ata-WDC_WD40EZRZ-00GXCB0_WD-WCC7K4SFJS7U ONLINE 0 0 0
errors: No known data errorsNotice that almost two hours later, the estimated completion is later by about 10 minutes and the speed has dropped by 50MB/s.
The interesting thing about the type of filesystem activity required to boost the speed is that it doesn't have to be with the ZFS filesystem. What I mean is, my ZFS is mounted at /main, and I was doing lots of filesystem activity between a DVD drive and the network filesystem NFS on a different machine. That's why I closed this bug, figuring "unrelated" filesystem activity wouldn't affect ZFS performance, and hence thinking that the ZFS problem had been fixed.
Do let me know what else I can provide.
rkrten
commented
5 years ago Jonathon suggested I run haveged in the background to see if entropy was being exhausted. I did, but there was no difference in zpool scrub speed.
rkrten
commented
5 years ago Upgraded from AMD FX8320 to AMD 3900X (a serious boost in performance, overall) but no change in speed. In fact, it may have gotten worse; at one point I was down to several hundred bytes per second on the issued speed.
rkrten
commented
5 years ago I updated a second machine to AMD 3900X and encrypted ZFS (4 x 6T RAIDZ1 configuration; the one described above is 3 x 4T RAIDZ1). This machine completes the scrub in just a little over FIVE hours, as opposed to SEVENTEEN previously! The second machine is a server, so it has more filesystem activity than the slow machine above. Just another datapoint :-) The slow machine continues to be slow...
rkrten
commented
4 years ago Same thing on the latest Ubuntu 19.10 beta; eventually, after about half an hour, it slowed down to kilobytes/second.
peterdey
commented
4 years ago I'm seeing the same issue here.
CPU: 2x Xeon L5640 4x 4TB WD Red in raidz1
Ubuntu 19.10 Kernel 5.3.0-24-generic ZFS version 0.8.1-1ubuntu14.2
Moved from LUKS encryption underneath to ZFS encrypted raidz1 on the bare drives.
Scrub used to finish in around 8 hours (depending on system usage). Currently still ongoing for over 18 hours now. dp_sync_taskq is still very active, and has accumulated a 6h15m of runtime.
stale[bot]
commented
3 years ago This issue has been automatically marked as "stale" because it has not had any activity for a while. It will be closed in 90 days if no further activity occurs. Thank you for your contributions.
System information
Describe the problem you're observing
zpool scrubon encrypted pool takes days; previously the same same scrub on unencrypted pool took about 6 hours (pool info below). I tried withecho 1 >/sys/module/zfs/parameters/zfs_scan_legacyas well, (in progress) but that too is taking a long time. Also noticed thatdp_sync_taskq(distributed over 6 threads) takes 50-75% CPU for significant periods of time; this was on an otherwise idle system.Describe how to reproduce the problem
Nothing special, just:
Include any warning/errors/backtraces from the system logs
Various logs for the "new" scrub (i.e.,
zfs_scan_legacyset to zero) that took several days to complete, on a relatively modern 3+GHz AMD64 8320 8-core processor) are below.zpool status
zpool statusgives:The previous version of ZFS on a non-encrypted partition would have been finished by now, whereas this one was less than 1% done with sub-megabyte-per-second data rates.
dp_sync_taskq consuming CPU
I noticed that
topshowsdp_sync_taskqtaking up a lot of CPU time:Which particular thread of
dp_sync_taskqtakes up the CPU time alternates, as you can tell by the distribution of the "TIME+" column values.zfs get all
zpool get all
Happy to supply any other info needed or run diags.