ZFS Reading on ZFS extremely slow

Probably after the FreeBSD upgrade from 12.2 to 13.0, the read performance on our 20 TB ZFS volume has decreased dramatically.

Read performance has dropped to about 20 MB/seconds maximum, which is not realistic.

The hard disks are HGST HUS726060ALE610 and should give us at least 120 MB/s or similar. But anyway, we hadn't problems like this for many years.

Does anyone have an idea about what is going on?

Thanks,
Thomas Mack

Edit:
Code:
  pool: zroot
 state: ONLINE
  scan: scrub canceled on Tue Feb  8 21:58:11 2022
config:

        NAME        STATE     READ WRITE CKSUM
        zroot       ONLINE       0     0     0
          raidz1-0  ONLINE       0     0     0
            ada0p3  ONLINE       0     0     0
            ada1p3  ONLINE       0     0     0
            ada2p3  ONLINE       0     0     0
            ada3p3  ONLINE       0     0     0

errors: No known data errors
 
I think its a openzfs regression, I have been doing my own tests, have found several bugs (that also exist in TrueNAS 12), they dont exist on ZFS in 12.x and some of them are performance regressions.

If I find a tunable to recover the performance I will reply here.
 
Do you, by any chance, restrict ARC size? If so, try to remove the restriction. One difference I found is that the version of OpenZFS included with FreeBSD 13+ relies much more on ARC, but at the same time frees ARC in memory pressure situations much more quickly, so chances are restrictions on the size aren't necessary any more.
 
… an idea about what is going on? …

Is any one dataset noticeably slower than others?

<https://github.com/jimsalterjrs/ioztat#readme> ▶ sysutils/py-ioztat ◀ <https://old.reddit.com/comments/s88xnf/-/>

Code:
% pwd
/usr/home/grahamperrin/dev/ioztat
% git pull
Already up to date.
% chmod 755 ./ioztat
% ./ioztat -z -i 3
                                    operations    throughput
dataset                             read  write   read  write
---------------------------------  -----  -----  -----  -----
Transcend/VirtualBox                   0      0  5.24K  5.71K
august/ROOT/n252997-b6724f7004c-c     44      6   130K  86.1K
august/VirtualBox                      0      0  20.2K  30.9K
august/usr/home                      225     29  5.42M   413K
august/usr/ports                       0      0     87    351
august/usr/src                        23      0   100K    266
august/var/log                         0      0      0     12
august/var/tmp                         0      0     14     50
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    102      1   332K  35.0K
august/usr/home                        0      0      0      0
august/usr/src                        70      0   343K     33
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c      9      0  26.0K      0
august/usr/home                        3      7  85.2K   107K
august/usr/src                        72      0   374K      0
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    327      3   618K  65.7K
august/usr/home                        2      5  64.2K  64.4K
august/usr/src                        52      0   245K     73
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    143      1   442K  27.2K
august/usr/home                        0      5  21.3K  85.5K
august/usr/src                        68      0   315K     34
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c     55      1   207K  25.5K
august/usr/home                        3      7  85.4K   107K
august/usr/src                        74      0   376K     27
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c     50      0   137K      0
august/usr/home                        0      0      0  2.45K
august/usr/src                        69      0   353K      0
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c      7      1  13.0K  39.5K
august/usr/home                    2.76K  2.72K  6.60M  4.66M
august/usr/src                        35      0   185K      0
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    171     41   617K  5.07M
august/usr/home                        3     28  68.1K   156K
august/usr/src                        71      0   332K     30
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    192     21   762K   269K
august/usr/home                        0      2  22.5K  43.7K
august/usr/src                        44      0   221K     28
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    137     98   354K  5.70M
august/usr/home                        5      7  92.8K   108K
august/usr/src                        68      0   321K     30
^C
% ./ioztat --version
ioztat 2.0.0-dev
%

Code:
% ./ioztat -z -i 3
                                    operations    throughput
dataset                             read  write   read  write
---------------------------------  -----  -----  -----  -----
Transcend/VirtualBox                   0      0  6.80K  5.57K
august/ROOT/n252997-b6724f7004c-c     49      7   142K  90.9K
august/VirtualBox                      0      0  22.1K  30.1K
august/usr/home                      225     29  5.39M   412K
august/usr/ports                       0      0     85    342
august/usr/src                        25      0   111K    267
august/var/log                         0      0      0     12
august/var/tmp                         0      0     13     49
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    388     95   683K   154K
august/VirtualBox                     55      0  3.45M      0
august/usr/home                        3     18  85.1K   111K
august/usr/src                       167     20   585K  1.47K
august/var/log                         0      0      0     43
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c     72     22  19.7K  61.2K
august/VirtualBox                     67      0  4.24M      0
august/usr/home                        1      7  4.04K  6.46K
august/usr/src                        43      7  39.1K    573
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c      9    262  1.62K  2.58M
august/VirtualBox                     43      0  2.69M      0
august/usr/home                        3     13  86.8K   110K
august/usr/src                         0      0      0     35
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    495    260  3.06M  4.70M
august/VirtualBox                     52      0  3.27M      0
august/usr/home                        3     12  85.3K   109K
august/usr/src                         0      1      0     89
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c      7    254  1.68K  2.49M
august/VirtualBox                    243      0  15.2M     44
august/usr/home                        0      5      0  2.35K
august/usr/src                        33      0   108K      0
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    410    193   670K  7.25M
august/VirtualBox                    227      0  14.2M      0
august/usr/home                        3     12  85.2K   110K
august/usr/src                        85     40   320K  3.46K
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    825    149  1.74M   183K
august/VirtualBox                    193      0  12.1M      0
august/usr/home                        5      6  14.8K  2.84K
august/usr/src                       171     29   584K  2.18K
august/var/log                         0      1      0     43
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    341     54   765K  84.7K
august/VirtualBox                    444      0  27.8M      0
august/usr/home                        0      5  3.99K  1.12K
august/usr/src                        64     10   283K    838
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    167     22   443K   335K
august/VirtualBox                    501      0  31.4M      0
august/usr/home                        6     13  89.6K   109K
august/usr/src                        53      5   228K    391
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c     84     21   193K   145K
august/VirtualBox                    310      0  19.4M      0
august/usr/home                        2      6     32  14.9K
august/usr/src                         8      3  31.0K    244
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    235     33   670K   273K
august/VirtualBox                    266      0  16.7M      0
august/usr/home                        3     12  85.3K   108K
august/usr/src                       141     10   639K    801
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    126     18   322K  65.5K
august/VirtualBox                    366      0  22.9M      0
august/usr/home                        2      5  35.1K  1.60K
august/usr/src                        11      3  50.2K    297
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    143     19   365K  67.3K
august/VirtualBox                    308      0  19.3M      0
august/usr/home                        5     12  91.6K   108K
august/usr/src                        14      3  64.0K    357
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    182     41   533K   329K
august/VirtualBox                    274      0  17.1M      0
august/usr/home                        4     12  64.1K  87.3K
august/usr/src                        92     10   434K    779
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    261     35   759K   132K
august/VirtualBox                    308      0  19.3M      0
august/usr/home                        0      5  21.3K  22.9K
august/usr/src                        86      7   476K    572
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    223     33   555K   151K
august/VirtualBox                    193     23  12.1M  4.91K
august/usr/home                        3     13  85.6K   109K
august/usr/src                        63      6   357K    486
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    237     32   617K   128K
august/VirtualBox                      5     29   341K   823K
august/usr/home                        2      5  4.18K  2.95K
august/usr/src                        61      6   363K    504
august/var/log                         0      1      0    108
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    116     18   272K  76.7K
august/VirtualBox                      1     33  12.0K  1.22M
august/usr/home                        6     13  90.7K   110K
august/usr/src                        29      3   173K    276
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    201     28   506K   133K
august/VirtualBox                      1      3  1.33M    306
august/usr/home                        8     12  98.4K   109K
august/usr/src                        55      5   312K    451
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    291     55   783K   480K
august/VirtualBox                      0  1.27K      0  75.8M
august/usr/home                        2      5  4.55K  1.69K
august/usr/src                        93      9   514K    744
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    195     26   611K   146K
august/VirtualBox                      0  1.19K      0  70.8M
august/usr/home                       15     17   116K   117K
august/usr/src                        60      6   315K    496
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    166     25   361K  68.7K
august/VirtualBox                      0  1.53K      0  91.7M
august/usr/home                        2      6  8.15K  9.60K
august/usr/src                        61      6   286K    534
---------------------------------  -----  -----  -----  -----
august/ROOT/n252997-b6724f7004c-c    172     48   414K   293K
august/VirtualBox                      0    946     47  38.0M
august/usr/home                        5     13  85.2K   109K
august/usr/src                        21      7  87.0K    631
---------------------------------  -----  -----  -----  -----
Transcend/VirtualBox                   6      0   106K      0
august/ROOT/n252997-b6724f7004c-c    260     17   733K   367K
august/VirtualBox                      6      1  1.63M    201
august/usr/home                        8      9  65.8K  33.9K
august/usr/src                        54      4   244K    405
august/var/log                         0      0      0     37
---------------------------------  -----  -----  -----  -----
Transcend/VirtualBox                  41      0  2.03M      0
august/ROOT/n252997-b6724f7004c-c    184     23   540K  74.1K
august/VirtualBox                     12      0   781K      0
august/usr/home                       10     10  65.4K  76.2K
august/usr/src                        12      5  48.7K    454
august/var/log                         0      0      0     57
---------------------------------  -----  -----  -----  -----
Transcend/VirtualBox                 116     53  6.72M  30.0K
august/ROOT/n252997-b6724f7004c-c    217     36  2.01M  75.2K
august/VirtualBox                      4      0   280K      0
august/usr/home                       16     15   403K   110K
august/usr/src                        88      8   360K    809
august/var/log                         0      1      0     99
---------------------------------  -----  -----  -----  -----
Transcend/VirtualBox                 110      0  6.88M      0
august/ROOT/n252997-b6724f7004c-c    335     47   899K   125K
august/usr/home                       80     21  2.28M   195K
august/usr/src                        82     11   354K  1.04K
---------------------------------  -----  -----  -----  -----
Transcend/VirtualBox                 166      0  10.4M      0
august/ROOT/n252997-b6724f7004c-c    331     32  1.04M   112K
august/usr/home                        7     15  97.4K   118K
august/usr/src                        26      6   118K    621
---------------------------------  -----  -----  -----  -----
Transcend/VirtualBox                 182      0  11.4M      0
august/ROOT/n252997-b6724f7004c-c    252     36   694K  77.2K
august/usr/home                        2      9  65.3K  37.6K
august/usr/src                        24      7   101K    710
---------------------------------  -----  -----  -----  -----
Transcend/VirtualBox                 205      0  12.9M     43
august/ROOT/n252997-b6724f7004c-c    348     39  1.21M   333K
august/usr/home                        0      8  21.3K  76.3K
august/usr/src                        40      7   180K    746
---------------------------------  -----  -----  -----  -----
Transcend/VirtualBox                 374      0  23.4M      0
august/ROOT/n252997-b6724f7004c-c    422     49  1.23M   148K
august/usr/home                        4     12  85.4K   109K
august/usr/src                        57     12   242K  1.02K
---------------------------------  -----  -----  -----  -----
Transcend/VirtualBox                 482      0  30.1M      0
august/ROOT/n252997-b6724f7004c-c    272     46   904K   419K
august/usr/home                        1      4  4.03K  1.60K
august/usr/src                        62     10   276K    886
---------------------------------  -----  -----  -----  -----
Transcend/VirtualBox                 397      0  24.9M      0
august/ROOT/n252997-b6724f7004c-c     93     10   249K  73.5K
august/usr/home                       16     13   312K   109K
august/usr/src                         7      2  36.7K    186
---------------------------------  -----  -----  -----  -----
^C
% zpool iostat -v 3
                         capacity     operations     bandwidth
pool                   alloc   free   read  write   read  write
---------------------  -----  -----  -----  -----  -----  -----
Transcend               379G  85.1G      0      0  27.4K  5.92K
  gpt/Transcend         379G  85.1G      0      0  27.4K  5.92K
cache                      -      -      -      -      -      -
  gpt/cache-transcend  14.3G   144M      0      0    742  3.31K
---------------------  -----  -----  -----  -----  -----  -----
august                  392G   520G      6     25   225K   859K
  ada0p3.eli            392G   520G      6     25   225K   859K
cache                      -      -      -      -      -      -
  gpt/cache-august     8.97G  19.8G      9      0   375K  39.5K
  gpt/duracell         7.26G  8.17G      8      0   349K  43.3K
---------------------  -----  -----  -----  -----  -----  -----
                         capacity     operations     bandwidth
pool                   alloc   free   read  write   read  write
---------------------  -----  -----  -----  -----  -----  -----
Transcend               379G  85.1G     62     33  4.27M  2.40M
  gpt/Transcend         379G  85.1G     62     33  4.27M  2.40M
cache                      -      -      -      -      -      -
  gpt/cache-transcend  14.3G   145M      4     25   269K  2.48M
---------------------  -----  -----  -----  -----  -----  -----
august                  392G   520G      8     38  34.6K   967K
  ada0p3.eli            392G   520G      8     38  34.6K   967K
cache                      -      -      -      -      -      -
  gpt/cache-august     8.97G  19.8G      1      1  25.3K  10.5K
  gpt/duracell         7.26G  8.17G      0      1  7.99K  22.8K
^C
% uname -aKU
FreeBSD mowa219-gjp4-8570p-freebsd 14.0-CURRENT FreeBSD 14.0-CURRENT #2 main-n252997-b6724f7004c-dirty: Mon Feb  7 10:54:28 GMT 2022     root@mowa219-gjp4-8570p-freebsd:/usr/obj/usr/src/amd64.amd64/sys/GENERIC-NODEBUG  amd64 1400051 1400051
%

In the second example, Transcend is a circa 2010 hard disk drive (StoreJet Transcend 25 Mobile) on USB. Reading at more than 30 M depending on workload, which is not stunning, but it's old USB.

Code:
% zpool list
NAME        SIZE  ALLOC   FREE  CKPOINT  EXPANDSZ   FRAG    CAP  DEDUP    HEALTH  ALTROOT
Transcend   464G   380G  84.1G        -         -    49%    81%  1.00x    ONLINE  -
august      912G   392G   520G        -         -    24%    42%  1.00x    ONLINE  -
% lsblk
DEVICE         MAJ:MIN SIZE TYPE                                          LABEL MOUNT
ada0             0:146 932G GPT                                               - -
  ada0p1         0:147 260M efi                                    gpt/efiboot0 -
  <FREE>         -:-   1.0M -                                                 - -
  ada0p2         0:150  16G freebsd-swap                              gpt/swap0 SWAP
  ada0p2.eli     1:242  16G freebsd-swap                                      - SWAP
  ada0p3         0:151 915G freebsd-zfs                                gpt/zfs0 <ZFS>
  ada0p3.eli     0:154 915G -                                                 - -
  <FREE>         -:-   708K -                                                 - -
da0              0:161  15G GPT                                               - -
  <FREE>         -:-   1.0M -                                                 - -
  da0p1          0:162  15G freebsd-zfs                            gpt/duracell <ZFS>
da1              0:184  29G GPT                                               - -
  da1p1          0:185  29G freebsd-zfs                        gpt/cache-august <ZFS>
da2              2:2   466G GPT                                               - -
  <FREE>         -:-   1.0M -                                                 - -
  da2p1          2:3   466G freebsd-zfs                           gpt/Transcend <ZFS>
da3              2:10   14G GPT                                               - -
  <FREE>         -:-   1.0M -                                                 - -
  da3p1          2:11   14G freebsd-zfs                     gpt/cache-transcend <ZFS>
% geom disk list da2
Geom name: da2
Providers:
1. Name: da2
   Mediasize: 500107862016 (466G)
   Sectorsize: 512
   Stripesize: 4096
   Stripeoffset: 0
   Mode: r1w1e3
   descr: StoreJet Transcend
   lunid: 5000000000000001
   ident: (null)
   rotationrate: unknown
   fwsectors: 63
   fwheads: 255

% geom disk list da3
Geom name: da3
Providers:
1. Name: da3
   Mediasize: 15518924800 (14G)
   Sectorsize: 512
   Mode: r1w1e3
   descr: Kingston DataTraveler 3.0
   lunname: KingstonDataTraveler 3.0
   lunid: KingstonDataTraveler 3.0
   ident: 60A44C3FACC93110B9970045
   rotationrate: 0
   fwsectors: 63
   fwheads: 255

%
 
So, no change in ARC size (min and max = 0).

Did some tests with a 10 GB file.

I copied this 10 GB file to all other datasets and wondered about the performance: the first copy took about 10 minutes == about 15 MB/s, the following copy actions took 3 to 4 minutes, which is about 50 MB/s.

I again copied this file after many other tests and activities, and it took more than 20 minutes to complete (8 MB/s), so this bad copy performance was repeatable, when it is the "first" copy action.

Then tested reading this file (time cat /..../10gb > /dev/null) and it took about 2 minutes on every datasets without much variation. This is about 85 MB/s - still not the read performance, I would expect.

ioztat didn't report any better values.

I started a scrub for testing and it started with almost 286MB/s for the first 18 GB and is now down to 92 MB/s at 270 GB. I even saw 58 MB/s at 102 GB.

So, performance is really not acceptable currently with zfs.
 
Will be difficult with more than 14 TB used on the remote server...

Ok, I already thought of such an option by migrating to a new server. But when performance doesn't improve, I would have to switch to ufs or to some Linux afterwards.


Btw.: There are 25 million files in one dataset. This shouldn't be a problem, I think, but maybe one might want to tune something here?
 
I remember I had this performance problem when I switch from FreeBSD 12.2 to FreeBSD 13.0.
The first thing I made is remove the limit for ARC size like said by Zirias and the second action is to recreate the pool and
restore it from file.
 
I would give 13-STABLE a spin as there have been several bumps of OpenZFS since 13.0 and since 13.1 is to be released relatively soon it would be nice to have any regression reported and fixed.
You might also want to pull up gstat to see if one disk gets hammered/bogged down during read operations.
 
Ok, gstat shows high load on the disks:

gstat.png

So, they are 100% busy, just with too many IOPS?

So it's not a problem with zfs and the update, obviously. The IOPS have increased dramatically?
 
This was with scrub active. Pausing scrub, the IOPS and %busy are down.

IOPS seem to be a problem. When cat'ing to /dev/null, IOPS rise to 500 or up to 800 per disk, which is even more than I expect to be possible.

Normally, I see around 200 IOPS, so why does a simple cat 10GB > /dev/null create so many more IOPS? Is this normal / can I do something to avoid this?
 
The rough rule of thumb is that disks can do about 150 IOps (in the range of 100 to 200) when doing random seeks. The actual number depends on the seek distance; if all the seeks are in a relatively narrow range, you can have more seeks, up to roughly 2x more (eventually limited by the track settling time, which is below 1ms, and the rotational latency, which depends on RPM of the disk). That's called short stroking the disk, and many file systems do that to some extent, by keeping the data for a single file relatively close.

But when doing sequential IO, the IOps becomes less meaningful. If doing large IOs truly sequentially, the limit is typically the head bandwidth, which is typically 100-200 MByte/s. The number of IOps now depends on the size of the IOs; with 1 MByte IOs, that's again the same 100-200 IOps, but if the file system issues smaller IOs, you can get more IOps at the same bandwidth.

So far, so good. Where it gets more interesting is queuing. To actually use these IOps, you need to send multiple IOs to the disk. For two reasons: When doing random seeks, the disk becomes more efficient if it can sort the IOs, and select which one to do next (perhaps out of submission = enqueuing order), which is usually much faster than doing them in the order submitted. When doing sequential IO, the next IO request should already be at the disk when the previous one finishes, so the disk doesn't lose the position on the platter.

The numbers you show from gstat seem confusing. Ignoring ada0, the other three disks seem to be doing ~550 IOps. The average bandwidth is about 8 MByte/s, which indicates an average IO size of about 16 KByte. That's surprisingly small. They seem to be averaging 4.5 ms per IO, and that should give you 220 IOps, not the 550 that gstat claims. But then, gstat also shows a queue depth of 3. And this is where I stop believing the gstat output: In the presence of queues (multiple IOs on the disk), it gets tricky to calculate performance statistics: the time it takes to do an IO is not the time from the start of this IO to its end, but (if another IO is already enqueued), the time from the end of the previous IO to the end of this one. I suspect that the IOps and MByte/s output is correct, and the ms/r output is wrong.

Suggestion: Also check iostat.

None of this helps making your file system faster, but measuring accurately is the first step that has to be done.
 
Thanks for the explanation. gstat was consistent, when scrub wasn't running and it matches iostat.

Normally I see around 5 MB/s [0.2 MB/s to 9 GB/s] read performance per disk just reading a 700 GB file.

Size per IO request remains in the area of 5 to 20 KB. This doesn't look good to me, as reading any zfs record of default 128 KB will create many IO requests.

Just now, it is extremly slow again, only reading this 700 GB file:

gstat2.png


iostat2.png
 
I have upgraded my ZFS server from FreeBSD 12 to 13.

My disks are down-market from HGST (a mix of old WD reds and newer Seagate EXOS).
My ARC is unconstrained. Memory is 16 GB. LZ4 compression is (mostly) on. De-duplication is off. Atime is off. See attached.
On a 7 x 3TB spindle RAID-Z3 pool, I get 2.5GB/sec sequential input on a synthetic benchmark (bonnie++).

So I don't think that the problem is generic.
 

Attachments

  • tank_propereties.txt
    4.2 KB · Views: 150
Ok, so my parameters look very similar. The installation on my current server is from december 2017, probably started with FreeBSD 11.1.

When looking into messages, I do see some errors on ada0 only, smartctl does not seem to see any problems, but I started an extended test now.

The errors are very low volume, so I don't know, if they are responsible for the problems. Complete list:

Code:
Dec 27 15:41:17 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Dec 27 15:41:17 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )

Jan  6 23:23:04 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Jan  6 23:23:04 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )

Feb  8 17:56:37 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb  8 17:56:37 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )

Feb 10 16:39:56 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 10 16:39:56 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 10 16:40:46 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 10 16:40:46 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )

Feb 12 22:03:21 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 11 22:03:21 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:20:53 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:20:53 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:20:58 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:20:58 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:21:45 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:21:45 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:21:51 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:21:51 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:21:55 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:21:55 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:22:21 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:22:21 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:22:25 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:22:25 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:22:30 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:22:30 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:22:35 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:22:35 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:22:40 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:22:40 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:23:01 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:23:01 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:23:19 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:23:19 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:23:54 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:23:54 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:23:59 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:23:59 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:24:03 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:24:03 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb 12 23:24:50 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb 12 23:24:50 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )

Anyway, it's not correct and maybe the disk has to be replaced.
...
Ok, I took ada0 offline for a test, but read performance remained at around 5 MB/s per disk.
 
The complete errors look like this:

Code:
Feb  8 17:56:36 www kernel: (ada0:ahcich2:0:0:0): READ_FPDMA_QUEUED. ACB: 60 58 38 0a f7 40 f1 01 00 00 00 00
Feb  8 17:56:37 www kernel: (ada0:ahcich2:0:0:0): CAM status: ATA Status Error
Feb  8 17:56:37 www kernel: (ada0:ahcich2:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Feb  8 17:56:37 www kernel: (ada0:ahcich2:0:0:0): RES: 41 40 38 0a f7 00 f1 01 00 58 00
Feb  8 17:56:37 www kernel: (ada0:ahcich2:0:0:0): Retrying command, 3 more tries remain
 
Those are uncorrectable errors, which could have a profound impact on performance.

If that were my server, I would order a spare disk. Maybe two.

But I would also make sure that the data cable to ada0 is properly seated at both ends.
 
...or just review SMART data and/or run a long SMART test :)
I have a rather old RAID-Z array that I can give a spin probably later today
 
Yes, I thought so. We rented this server, so no physical access possible.

Just tested with dd if=/dev/ada0 of=/dev/null bs=1M etc., and this shows ada0 to have lower and rather irregular performance rates than all the other disks.

Time to get it replaced.

Code:
root@www:~ # iostat -d 10
            ada0             ada1             ada2             ada3
 KB/t  tps  MB/s  KB/t  tps  MB/s  KB/t  tps  MB/s  KB/t  tps  MB/s
 34.3  157   5.3  33.1  153   4.9  33.3  157   5.1  32.7  152   4.9
  4.7  177   0.8   4.7  180   0.8   5.1  179   0.9   5.0  192   0.9
  4.8  158   0.7   4.8  170   0.8   5.3  159   0.8   5.1  165   0.8
  5.3  113   0.6   5.1  131   0.7   6.0  123   0.7   5.6  139   0.8
  6.4   50   0.3   6.5   46   0.3   7.7   52   0.4   7.9   46   0.4
  761  128  95.3   7.2   37   0.3   8.4   36   0.3   8.4   36   0.3
  458  118  52.8   6.8   63   0.4   7.2   69   0.5   7.1   67   0.5
  610  145  86.4   7.0   59   0.4   7.4   58   0.4   7.4   55   0.4
  626  138  84.1   6.5   53   0.3   7.4   56   0.4   7.6   55   0.4
  410  147  58.9   8.4   84   0.7   8.0   88   0.7   9.0   81   0.7
  506  146  72.1  12.1   64   0.8   9.8   74   0.7  11.4   59   0.7
  384  161  60.3   6.0   93   0.5   6.8  103   0.7   7.0   92   0.6
  354  192  66.4   6.0  134   0.8   6.5  132   0.8   6.1  130   0.8
  247  188  45.5   6.0  137   0.8   6.0  149   0.9   6.0  139   0.8
  416  209  84.8   6.2  122   0.7   6.0  127   0.7   6.1  122   0.7
  782  118  90.2   8.9   35   0.3  10.7   27   0.3   8.8   34   0.3
  777  173 130.9   9.6   34   0.3   8.9   43   0.4   9.5   36   0.3
  824  129 103.5   9.3   43   0.4  12.4   24   0.3   8.4   40   0.3
 10.0   42   0.4   790  116  89.5   7.9   41   0.3  10.5   25   0.3
 12.1   30   0.4   787  165 126.6  10.8   28   0.3   8.6   38   0.3
 11.5   31   0.3   812  188 148.8  10.6   30   0.3   8.8   37   0.3
 11.1   39   0.4   849  170 141.1   8.5   38   0.3  10.1   28   0.3
  9.8   35   0.3   793  176 136.4   9.4   32   0.3   8.3   39   0.3
 12.6   29   0.4   786  186 142.5  11.5   25   0.3   8.7   39   0.3
 12.7   29   0.4   780  174 132.9   9.7   26   0.2   8.2   39   0.3
 10.1   35   0.3   783  142 108.7   7.9   33   0.3   8.2   31   0.2
  9.9   45   0.4  11.5   31   0.3   683  117  78.2   9.3   29   0.3
  9.7   42   0.4  11.4   29   0.3   800  167 130.7   9.4   28   0.3
 12.5   28   0.3  10.0   38   0.4   876  184 157.0   8.3   38   0.3
 10.4   34   0.3   9.5   36   0.3   802  163 127.4   9.2   38   0.3
  9.6   34   0.3   9.9   30   0.3   804  168 132.0   9.9   30   0.3
 11.8   22   0.2   7.3   45   0.3   881  158 136.1   8.7   47   0.4
  7.8   37   0.3   9.2   29   0.3   801  170 132.7  10.7   31   0.3
  8.1   34   0.3   9.0   28   0.2   810  168 132.7  10.6   30   0.3
  7.3   38   0.3   9.4   29   0.3   9.9   40   0.4   647   77  48.6
  7.5   43   0.3  10.6   22   0.2   9.2   45   0.4   894  177 154.3
 10.4   26   0.3   8.4   37   0.3  12.0   31   0.4   802  175 136.7
  8.4   34   0.3   9.4   29   0.3  11.2   36   0.4   852  187 155.6
  8.1   37   0.3   9.8   33   0.3   9.2   40   0.4   841  182 149.6
  8.7   24   0.2   6.5   37   0.2   7.9   25   0.2   825  183 147.0
  6.7   33   0.2   7.2   27   0.2   6.9   33   0.2   848  161 133.2
  9.0   35   0.3   8.9   31   0.3   8.1   33   0.3   804  129 101.4
  7.9   35   0.3   8.5   28   0.2   7.8   33   0.3   8.6   29   0.2
^C  9.0   18   0.2   8.8   12   0.1   8.5   20   0.2   8.6   15   0.1
 
I got the first disk replaced. Unfortunately, the system doesn't boot.

I booted into a rescue system of FreeBSD 13.0 and then imported the pool and tried to make ada0 bootable:

Code:
gpart bootcode -b /boot/pmbr -p /boot/gptzfsboot -i 1 ada0

and exported it afterwards, but it didn't boot the original system.
I also tried without exporting, but it didn't boot either.

Don't know, what it actually does. Anyone knows more? I can ask for a console later to get access to BIOS and boot screen etc..

The system is four disks in raid-z1 configuration without any other disk. Just replacing the first disk should not affect the system, I thought. What can I do?
 
To interpret the iostat data, we would need to look at the co-incidental error messages. My guess is that the re-tries for the uncorrectable errors are probably slowing things down.

The uncorrectable errors may be fixable by automatic bad block forwarding if you re-write that block with the uncorrectable error at some stage. Sometimes this happens in routine activity, and nobody notices. Sometimes the bad block holds "long term" data, which is not likely to be re-written. So the uncorrectable error can persist.

Right now your RAID set is running like a dog. You have uncorrectable errors. Your disks have been in service for four years (probably all the same factory batch and likely to fail at the same time). Your RAID-Z1 set can only survive the loss of one disk. And you have one disk at significant risk.

A replacement disk costs a few hundred dollars. You should consider the risk to reward ratio. Are the data valuable? Does a few hundred dollars matter in the overall outcome? I'm suggesting that this is a business decision, not a technical one.

If I owned that disk, I would take it out of service, and replace it with a new drive, immediately. Then, if the cost of a disk matters, re-write the entire disk, which should hopefully forward the bad block. You could then confirm it's OK with (a lot of) SMART extended tests, re-initialise the label, and place it back into the spares pool, or dump it, depending on the outcome.

I keep at least one new spare (SMART-tested) disk for my RAID set at all times. Before acquiring a hot-swap cage, I used to run with a hot (spinning) spare.
 
We rented the server and I got the disk replaced very quick. There are indications that the replacement does not solve the problem, but currently I have this other problem of the system not booting.
 
Our posts crossed.

My ZFS zroots are all small, and on mirrors, with boot blocks on each disk. So I have no direct experience of your situation.

Knowing the status of the zroot pool is important. You need to know if it's seriously damaged.

You also need to verify that your service provider actually replaced ada0.

I'd boot from the rescue media. Have a look at zpool status zroot.

Is ada0 "OFFLINE"? Are all the other disks "ONLINE"? If not, stop, and re-consider.

Assuming ada0 has been replaced, you are going to need to put a gpt label on it. Assuming that they all disks all the same:
Code:
gpart show    # check the partitions, especially the freebsd-boot partition number -- assuming 1 below)
gpart destroy -F ada0
gpart backup ada1 | gpart restore -F ada0
gpart bootcode -b /boot/pmbr -p /boot/gptzfsboot -i 1 ada0

If it still won't boot from ada0, try switching to ada1 in the BIOS (ada1 might need bootcode installed).

If you do manage to boot, pause and prepare a plan for the re-silvering.

There's plenty of expertise on this list. They just need a chance to respond.
 
Back
Top