Bug 211381

Comment 1 Andriy Gapon 2016-07-26 17:21:44 UTC

(In reply to braddeicide from comment #0)
I do not know why that third party script says that L2ARC is "degraded".
I do not see any of the OS tools reporting any degradation.

Comment 2 Andriy Gapon 2016-07-26 17:25:47 UTC

(In reply to Andriy Gapon from comment #1)
Actually, sorry, I now see that you have highlighted kstat.zfs.misc.arcstats.l2_writes_error counter.

Comment 3 Andriy Gapon 2016-07-26 17:34:20 UTC

It would be interesting to see what errors are reported by the following dtrace oneliner:

dtrace -n 'sdt:::l2arc-iodone /args[0]->io_error != 0/ { printf("io_error = %d", args[0]->io_error); }'

Yes I was suspicious of the script when I removed and readded the device and it worked for a while, but the script kept saying degraded.  How I can tell it's gone wrong again however is in zpool iostat -v when all data is dropped from the arc and capacity stays 100% free despite writes.

# dtrace -n 'sdt:::l2arc-iodone /args[0]->io_error != 0/ { printf("io_error = %d", args[0]->io_error); }'
dtrace: description 'sdt:::l2arc-iodone ' matched 1 probe
dtrace: buffer size lowered to 512k
CPU     ID                    FUNCTION:NAME
  0  57400                none:l2arc-iodone io_error = 22
  3  57400                none:l2arc-iodone io_error = 22
  1  57400                none:l2arc-iodone io_error = 22
  1  57400                none:l2arc-iodone io_error = 22
  1  57400                none:l2arc-iodone io_error = 22
  3  57400                none:l2arc-iodone io_error = 22
  3  57400                none:l2arc-iodone io_error = 22
  3  57400                none:l2arc-iodone io_error = 22
  1  57400                none:l2arc-iodone io_error = 22
  3  57400                none:l2arc-iodone io_error = 22
  0  57400                none:l2arc-iodone io_error = 22
  1  57400                none:l2arc-iodone io_error = 22
  0  57400                none:l2arc-iodone io_error = 22
  2  57400                none:l2arc-iodone io_error = 22

Comment 5 Andriy Gapon 2016-07-27 06:09:18 UTC

(In reply to braddeicide from comment #4)

22 is EINVAL, I wonder from where it comes.
Based on the device names it seems that GELI is involved here? Perhaps it could be some problem with it...

Anyway, could you please add printing of the following values to the dtrace script? args[0]->io_offset, args[0]->io_size

Also, diskinfo -v /dev/nvd0p3.eli
Thank you.

Comment 6 Andriy Gapon 2016-07-27 07:00:48 UTC

BTW, don't want to jump to conclusion but it's possible that r300039 might help.

Yes it's on a geli

dtrace -n 'sdt:::l2arc-iodone /args[0]->io_error != 0/ { printf("io_error = %d io_offset = %d io_size = %d", args[0]->io_error, args[0]->io_offset, args[0]->io_size); }'
dtrace: description 'sdt:::l2arc-iodone ' matched 1 probe
dtrace: buffer size lowered to 512k
CPU     ID                    FUNCTION:NAME
  2  57400                none:l2arc-iodone io_error = 22 io_offset = 0 io_size = 0
  1  57400                none:l2arc-iodone io_error = 22 io_offset = 0 io_size = 0
  0  57400                none:l2arc-iodone io_error = 22 io_offset = 0 io_size = 0
  1  57400                none:l2arc-iodone io_error = 22 io_offset = 0 io_size = 0
  0  57400                none:l2arc-iodone io_error = 22 io_offset = 0 io_size = 0
  1  57400                none:l2arc-iodone io_error = 22 io_offset = 0 io_size = 0
  0  57400                none:l2arc-iodone io_error = 22 io_offset = 0 io_size = 0
  1  57400                none:l2arc-iodone io_error = 22 io_offset = 0 io_size = 0
  2  57400                none:l2arc-iodone io_error = 22 io_offset = 0 io_size = 0
  0  57400                none:l2arc-iodone io_error = 22 io_offset = 0 io_size = 0

# diskinfo -v /dev/nvd0p3.eli
/dev/nvd0p3.eli
        4096            # sectorsize
        483117756416    # mediasize in bytes (450G)
        117948671       # mediasize in sectors
        0               # stripesize
        0               # stripeoffset
        7341            # Cylinders according to firmware.
        255             # Heads according to firmware.
        63              # Sectors according to firmware.
        S2GMNCAGA01093W # Disk ident.

Oh 4k, this device is pretty deadset on being 512

# diskinfo -v /dev/nvd0p3
/dev/nvd0p3
        512             # sectorsize
        483117760512    # mediasize in bytes (450G)
        943589376       # mediasize in sectors
        512             # stripesize
        0               # stripeoffset
        58735           # Cylinders according to firmware.
        255             # Heads according to firmware.
        63              # Sectors according to firmware.
        S2GMNCAGA01093W # Disk ident.

I dropped the cache and the dtrace errors stopped so that's the source alright. I detached the geli, attached the geli and added cache and they started again.
Dropped the cache, detached geli, added nvd0p3 as cache without geli and no errors and the cache started building.

                  capacity     operations    bandwidth
pool           alloc   free   read  write   read  write
cache              -      -      -      -      -      -
  nvd0p3        514M   449G      0      0      0      0

I recreated geli with 512 Sectorsize, reattached and so far no errors, but it worked the first time for a while too.  Cache is building, no dtrace errors yet, i'll watch.

# diskinfo -v /dev/nvd0p3.eli
/dev/nvd0p3.eli
        512             # sectorsize
        483117760000    # mediasize in bytes (450G)
        943589375       # mediasize in sectors
        0               # stripesize
        0               # stripeoffset
        58735           # Cylinders according to firmware.
        255             # Heads according to firmware.
        63              # Sectors according to firmware.
        S2GMNCAGA01093W # Disk ident.

re r300039, yeah looks useful
------------------------------------------------------------------------
r300039 | avg | 2016-05-17 18:43:50 +1000 (Tue, 17 May 2016) | 5 lines

MFC r297848: l2arc: make sure that all writes honor ashift of a cache device

Note: no MFC stable/9 because it has become quite out of date with head,
so the merge would be quite labourious and, thus, risky.

------------------------------------------------------------------------

Comment 8 Andriy Gapon 2016-07-28 08:24:12 UTC

(In reply to braddeicide from comment #7)
> io_error = 22 io_offset = 0 io_size = 0

This looks really strange.  I am not sure why L2ARC code would issue such zio-s.
Ah, it's actually a parent zio of all zio-s for individual buffers written in a pass.  If a single child zio fails, then the parent zio is marked as failed too.

Comment 9 Andriy Gapon 2016-07-28 08:30:43 UTC

And another one-liner:
dtrace -n 'fbt::g_io_deliver:entry /args[1] == EINVAL/ { printf("dest: %s, offset %d, length %d", stringof(args[0]->bio_to->name), args[0]->bio_offset, args[0]->bio_length); }'

This hasn't reoccurred since I changed the geli sector size to 512 to match the underlying device.

Would you like me to return to the failing configuration so we can find a better solution?

Comment 11 Andriy Gapon 2016-08-06 11:15:18 UTC

(In reply to braddeicide from comment #10)
If you could do that and then pick up and test r300039 that would be great!

Been running r300039 in previously problematic mismatched sector size configuration for a week, looks good.

# geli is 4k, underlying device is 512
diskinfo -v /dev/nvd0p3.eli | grep sectorsize
        4096            # sectorsize
diskinfo -v /dev/nvd0p3 | grep sectorsize
        512             # sectorsize

# zfs-stats
L2 ARC Summary: (HEALTHY)

# Cache is growing
pool           alloc   free   read  write   read  write
-------------  -----  -----  -----  -----  -----  -----
cache              -      -      -      -      -      -
  nvd0p3.eli    139G   311G      3      3  40.0K   427K

# guess compress_failures weren't a valid indicator
kstat.zfs.misc.arcstats.l2_compress_failures: 11644501
kstat.zfs.misc.arcstats.l2_writes_error: 0

Comment 13 Andriy Gapon 2016-08-15 13:30:19 UTC

(In reply to braddeicide from comment #12)
"Compress failure" only means that the compression didn't save any space and thus a buffer eligible for the compression was placed in L2ARC without it.

Comment 14 Andriy Gapon 2016-08-23 07:47:00 UTC

Assuming that the problem was fixed by https://svnweb.freebsd.org/base?view=revision&revision=297848