Bug 198242 - [zfs] L2ARC degraded. Checksum errors, I/O errors
Summary: [zfs] L2ARC degraded. Checksum errors, I/O errors
Status: Closed FIXED
Alias: None
Product: Base System
Classification: Unclassified
Component: kern (show other bugs)
Version: 10.1-RELEASE
Hardware: amd64 Any
: --- Affects Some People
Assignee: Andriy Gapon
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2015-03-03 19:03 UTC by Kenneth
Modified: 2016-07-26 11:58 UTC (History)
10 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Kenneth 2015-03-03 19:03:35 UTC
When the L2ARC has filled up I/O errors and Bad checksums appears.

The zpool status is ok.

The device is an Intel S3700 100GB SSD.
Partitioned and attached as a 8G log and a 80G cache device.
The L2ARC size is reported as 161GiB, compression is used and the problem
appears when the size is in the 80G range.
I have seen more problems with this, here is one:
https://bugs.freenas.org/issues/5347

[root@tornet10 /home/kenneth]# zfs-stats -L

------------------------------------------------------------------------
ZFS Subsystem Report                            Tue Mar  3 19:54:46 2015
------------------------------------------------------------------------

L2 ARC Summary: (DEGRADED)
        Passed Headroom:                        59.87m
        Tried Lock Failures:                    7.87m
        IO In Progress:                         14.35k
        Low Memory Aborts:                      22
        Free on Write:                          27.64k
        Writes While Full:                      8.35k
        R/W Clashes:                            109
        Bad Checksums:                          14.49k
        IO Errors:                              12.88k
        SPA Mismatch:                           990.88k

L2 ARC Size: (Adaptive)                         161.27  GiB
        Header Size:                    0.28%   456.38  MiB

L2 ARC Evicts:
        Lock Retries:                           145
        Upon Reading:                           0

L2 ARC Breakdown:                               9.21m
        Hit Ratio:                      11.06%  1.02m
        Miss Ratio:                     88.94%  8.19m
        Feeds:                                  2.54m

L2 ARC Buffer:
        Bytes Scanned:                          6.54    PiB
        Buffer Iterations:                      2.54m
        List Iterations:                        162.35m
        NULL List Iterations:                   344.58k

L2 ARC Writes:
        Writes Sent:                    100.00% 94.06k

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

[root@tornet10 /home/kenneth]#  sysctl -a | grep l2
kern.cam.ctl2cam.max_sense: 252
kern.features.linuxulator_v4l2: 1
vfs.zfs.l2arc_write_max: 33554432
vfs.zfs.l2arc_write_boost: 67108864
vfs.zfs.l2arc_headroom: 2
vfs.zfs.l2arc_feed_secs: 1
vfs.zfs.l2arc_feed_min_ms: 200
vfs.zfs.l2arc_noprefetch: 1
vfs.zfs.l2arc_feed_again: 1
vfs.zfs.l2arc_norw: 1
vfs.zfs.l2c_only_size: 163026834432
vfs.cache.numfullpathfail2: 0
kstat.zfs.misc.arcstats.evict_l2_cached: 693505577984
kstat.zfs.misc.arcstats.evict_l2_eligible: 98812823040
kstat.zfs.misc.arcstats.evict_l2_ineligible: 31591627776
kstat.zfs.misc.arcstats.l2_hits: 1019407
kstat.zfs.misc.arcstats.l2_misses: 8195111
kstat.zfs.misc.arcstats.l2_feeds: 2538329
kstat.zfs.misc.arcstats.l2_rw_clash: 109
kstat.zfs.misc.arcstats.l2_read_bytes: 15623280128
kstat.zfs.misc.arcstats.l2_write_bytes: 357188632064
kstat.zfs.misc.arcstats.l2_writes_sent: 94115
kstat.zfs.misc.arcstats.l2_writes_done: 94115
kstat.zfs.misc.arcstats.l2_writes_error: 0
kstat.zfs.misc.arcstats.l2_writes_hdr_miss: 321
kstat.zfs.misc.arcstats.l2_evict_lock_retry: 145
kstat.zfs.misc.arcstats.l2_evict_reading: 0
kstat.zfs.misc.arcstats.l2_free_on_write: 27644
kstat.zfs.misc.arcstats.l2_abort_lowmem: 22
kstat.zfs.misc.arcstats.l2_cksum_bad: 14495
kstat.zfs.misc.arcstats.l2_io_error: 12877
kstat.zfs.misc.arcstats.l2_size: 173169375232
kstat.zfs.misc.arcstats.l2_asize: 168640780800
kstat.zfs.misc.arcstats.l2_hdr_size: 478502856
kstat.zfs.misc.arcstats.l2_compress_successes: 1057448
kstat.zfs.misc.arcstats.l2_compress_zeros: 0
kstat.zfs.misc.arcstats.l2_compress_failures: 892255
kstat.zfs.misc.arcstats.l2_write_trylock_fail: 7866025
kstat.zfs.misc.arcstats.l2_write_passed_headroom: 59875065
kstat.zfs.misc.arcstats.l2_write_spa_mismatch: 990877
kstat.zfs.misc.arcstats.l2_write_in_l2: 142755184565
kstat.zfs.misc.arcstats.l2_write_io_in_progress: 14352
kstat.zfs.misc.arcstats.l2_write_not_cacheable: 117559529322
kstat.zfs.misc.arcstats.l2_write_full: 8352
kstat.zfs.misc.arcstats.l2_write_buffer_iter: 2538329
kstat.zfs.misc.arcstats.l2_write_pios: 94115
kstat.zfs.misc.arcstats.l2_write_buffer_bytes_scanned: 7359951087932928
kstat.zfs.misc.arcstats.l2_write_buffer_list_iter: 162354237
kstat.zfs.misc.arcstats.l2_write_buffer_list_null_iter: 344583

[root@tornet10 /home/kenneth]# zpool status
  pool: tank
 state: ONLINE
  scan: scrub repaired 0 in 4h45m with 0 errors on Mon Feb 23 07:47:02 2015
config:

        NAME                                              STATE     READ WRITE CKSUM
        tank                                              ONLINE       0     0     0
          raidz2-0                                        ONLINE       0     0     0
            diskid/DISK-S2H7J9BZC03819%20%20%20%20%20%20  ONLINE       0     0     0
            diskid/DISK-S2H7J9BZC03822%20%20%20%20%20%20  ONLINE       0     0     0
            diskid/DISK-S2H7J9BZC03825%20%20%20%20%20%20  ONLINE       0     0     0
            diskid/DISK-S2H7J9BZC03831%20%20%20%20%20%20  ONLINE       0     0     0
            diskid/DISK-S2H7J9BZC03833%20%20%20%20%20%20  ONLINE       0     0     0
            diskid/DISK-S2H7J9BZC03834%20%20%20%20%20%20  ONLINE       0     0     0
            diskid/DISK-S2H7J9BZC03656%20%20%20%20%20%20  ONLINE       0     0     0
            diskid/DISK-S2H7J9DZC00545%20%20%20%20%20%20  ONLINE       0     0     0
        logs
          gpt/log                                         ONLINE       0     0     0
        cache
          gpt/cache                                       ONLINE       0     0     0

errors: No known data errors

[root@tornet10 /home/kenneth]# uname -v
FreeBSD 10.1-RELEASE #0 r274401: Tue Nov 11 21:02:49 UTC 2014     root@releng1.nyi.freebsd.org:/usr/obj/usr/src/sys/GENERIC
Comment 1 Kenneth 2015-03-06 07:28:45 UTC
The bug also appears with the same type of Intel 3700 100GB SSD on another system where the whole disk is attached as only L2ARC.
It looks like the L2ARC is filled up to its physicall size and then the fill is stuck there for some hour. Then suddenly the fill rises above the physical size and the bad checksum and I/O errors shows up.
Comment 2 Kenneth 2015-03-07 13:19:27 UTC
I found another Bug Report that looks like the same problem:
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=195746
Comment 3 Robert Schulze 2015-03-09 09:08:11 UTC
We have the same behaviour here, with an Intel SSDSA2M080G2GC as L2ARC. 
In the past, this led to serious performance degradation and a crash of the system. The behaviour is better since 10.1, but not fixed entirely.

with kind regards,
Robert Schulze
Comment 4 Lehel Bernadt 2015-03-17 09:18:26 UTC
I'm having the same problem. L2ARC is on a Samsung 840 PRO SSD.

------------------------------------------------------------------------
ZFS Subsystem Report                            Tue Mar 17 10:12:30 2015
------------------------------------------------------------------------

L2 ARC Summary: (DEGRADED)
        Passed Headroom:                        79.34m
        Tried Lock Failures:                    8.06m
        IO In Progress:                         934
        Low Memory Aborts:                      33
        Free on Write:                          2.38k
        Writes While Full:                      8.99k
        R/W Clashes:                            243
        Bad Checksums:                          5.83m
        IO Errors:                              768.49k
        SPA Mismatch:                           21.27b

L2 ARC Size: (Adaptive)                         76.25   GiB
        Header Size:                    0.26%   200.69  MiB

L2 ARC Evicts:
        Lock Retries:                           11
        Upon Reading:                           0

L2 ARC Breakdown:                               35.31m
        Hit Ratio:                      31.74%  11.21m
        Miss Ratio:                     68.26%  24.11m
        Feeds:                                  1.59m

L2 ARC Buffer:
        Bytes Scanned:                          1.36    PiB
        Buffer Iterations:                      1.59m
        List Iterations:                        101.39m
        NULL List Iterations:                   994.41k

L2 ARC Writes:
        Writes Sent:                    100.00% 40.13k

------------------------------------------------------------------------
Comment 5 Lacey Powers 2015-04-26 03:26:06 UTC
This bug, and the related bug:

https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=195746

looks like they were fixed in Illumos as of a few days ago.

https://www.illumos.org/issues/5701
Comment 6 gkontos 2015-04-26 10:26:11 UTC
When can we expect this to 10.1-STABLE?

Thanks
Comment 8 gkontos 2015-06-09 15:22:49 UTC
Thanks Andiry, the link appears to be broken though.
Comment 9 Karli Sjöberg 2015-06-09 15:32:39 UTC
I took a look at it before leaving work but now it's gone?!
Comment 10 Andriy Gapon freebsd_committer freebsd_triage 2015-06-09 17:57:43 UTC
Please try this one instead: https://reviews.freebsd.org/D2764?download=true
Comment 11 Justin O'Connor 2015-06-11 20:28:11 UTC
Thanks Andriy. Looks like the patch is for stable/10. Will upgrade a box from release to stable for testing.

1 issue (svn co stable/10 today)-
Hunk #10 failed at 5324.
1 out of 10 hunks failed while patching sys/cddl/contrib/opensolaris/uts/common/fs/zfs/arc.c
done

Patched anyways and found the other lines by hand -
diff arc.c arc.c.orig
...
5327,5328c5305,5306
< ARCSTAT_INCR(arcstat_l2_asize, stats_size);
< vdev_space_update(dev->l2ad_vdev, stats_size, 0, 0);
> ARCSTAT_INCR(arcstat_l2_asize, write_asize);
> vdev_space_update(dev->l2ad_vdev, write_psize, 0, 0);

Cheers
Comment 12 gkontos 2015-06-20 10:11:00 UTC
Looks ok here after 2 weeks of testing.
Comment 13 commit-hook freebsd_committer freebsd_triage 2015-08-24 08:11:27 UTC
A commit references this bug:

Author: avg
Date: Mon Aug 24 08:10:53 UTC 2015
New revision: 287099
URL: https://svnweb.freebsd.org/changeset/base/287099

Log:
  account for ashift when gathering buffers to be written to l2arc device

  The change that introduced the L2ARC compression support also introduced
  a bug where the on-disk size of the selected buffers could end up larger
  than the target size if the ashift is greater than 9.  This was because
  the buffer selection could did not take into account the fact that
  on-disk size could be larger than the in-memory buffer size due to
  the alignment requirements.

  At the moment b_asize is a misnomer as it does not always represent the
  allocated size: if a buffer is compressed, then the compressed size is
  properly rounded (on FreeBSD), but if the compression fails or it is not
  applied, then the original size is kept and it could be smaller than what
  ashift requires.

  For the same reasons arcstat_l2_asize and the reported used space
  on the cache device could be smaller than the actual allocated size
  if ashift > 9.  That problem is not fixed by this change.

  This change only ensures that l2ad_hand is not advanced by more
  than target_sz.  Otherwise we would overwrite active (unevicted)
  L2ARC buffers.  That problem is manifested as growing l2_cksum_bad
  and l2_io_error counters.

  This change also changes 'p' prefix to 'a' prefix in a few places
  where variables represent allocated rather than physical size.

  The resolved problem could also result in the reported allocated size
  being greater than the cache device's capacity, because of the
  overwritten buffers (more than one buffer claiming the same disk
  space).

  This change is already in ZFS-on-Linux:
  zfsonlinux/zfs@ef56b0780c80ebb0b1e637b8b8c79530a8ab3201

  PR:		198242
  PR:		195746 (possibly related)
  Reviewed by:	mahrens (https://reviews.csiden.org/r/229/)
  Tested by:	gkontos@aicom.gr (most recently)
  MFC after:	15 days
  X-MFC note:	patch does not apply as is at the moment
  Relnotes:	yes
  Sponsored by:	ClusterHQ
  Differential Revision:	https://reviews.freebsd.org/D2764
  Reviewed by:	noone (@FreeBSD.org)

Changes:
  head/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/arc.c
Comment 14 Andriy Gapon freebsd_committer freebsd_triage 2015-09-11 13:28:49 UTC
Should be fixed now.
Comment 15 braddeicide 2016-07-26 11:17:59 UTC
I am now facing this issue on 10.3-RELEASE-p5 on a Samsung SSD 950 Pro (nvme).

I'm using the same device for logs and it appears to be functioning fine (I know not best practice)

#zfs-stats -L
------------------------------------------------------------------------
ZFS Subsystem Report                            Tue Jul 26 20:54:51 2016
------------------------------------------------------------------------

L2 ARC Summary: (DEGRADED)
        Passed Headroom:                        1.05m
        Tried Lock Failures:                    1.68m
        IO In Progress:                         268
        Low Memory Aborts:                      114
        Free on Write:                          647.02k
        Writes While Full:                      1.42m
        R/W Clashes:                            2
        Bad Checksums:                          0
        IO Errors:                              0
        SPA Mismatch:                           1.38k

L2 ARC Size: (Adaptive)                         298.83  MiB
        Header Size:                    0.00%   0

L2 ARC Evicts:
        Lock Retries:                           37
        Upon Reading:                           0

L2 ARC Breakdown:                               44.69m
        Hit Ratio:                      5.07%   2.27m
        Miss Ratio:                     94.93%  42.43m
        Feeds:                                  1.70m

L2 ARC Buffer:
        Bytes Scanned:                          114.97  TiB
        Buffer Iterations:                      1.70m
        List Iterations:                        3.13m
        NULL List Iterations:                   58.42k

L2 ARC Writes:
        Writes Sent:                    100.00% 1.54m

# sysctl -a | grep l2
kern.cam.ctl2cam.max_sense: 252
vfs.zfs.l2c_only_size: 0
vfs.zfs.l2arc_norw: 1
vfs.zfs.l2arc_feed_again: 1
vfs.zfs.l2arc_noprefetch: 0
vfs.zfs.l2arc_feed_min_ms: 200
vfs.zfs.l2arc_feed_secs: 1
vfs.zfs.l2arc_headroom: 2
vfs.zfs.l2arc_write_boost: 52428800
vfs.zfs.l2arc_write_max: 26214400
vfs.cache.numfullpathfail2: 0
kstat.zfs.misc.arcstats.l2_write_buffer_list_null_iter: 58416
kstat.zfs.misc.arcstats.l2_write_buffer_list_iter: 3128016
kstat.zfs.misc.arcstats.l2_write_buffer_bytes_scanned: 126433859595264
kstat.zfs.misc.arcstats.l2_write_pios: 1543758
kstat.zfs.misc.arcstats.l2_write_buffer_iter: 1705468
kstat.zfs.misc.arcstats.l2_write_full: 1424118
kstat.zfs.misc.arcstats.l2_write_not_cacheable: 1229880739
kstat.zfs.misc.arcstats.l2_write_io_in_progress: 268
kstat.zfs.misc.arcstats.l2_write_in_l2: 4397896253
kstat.zfs.misc.arcstats.l2_write_spa_mismatch: 1379
kstat.zfs.misc.arcstats.l2_write_passed_headroom: 1047813
kstat.zfs.misc.arcstats.l2_write_trylock_fail: 1676946
-> kstat.zfs.misc.arcstats.l2_compress_failures: 143662342
kstat.zfs.misc.arcstats.l2_compress_zeros: 11159
kstat.zfs.misc.arcstats.l2_compress_successes: 1038776676
kstat.zfs.misc.arcstats.l2_hdr_size: 0
kstat.zfs.misc.arcstats.l2_asize: 152834048
kstat.zfs.misc.arcstats.l2_size: 338656768
kstat.zfs.misc.arcstats.l2_io_error: 0
kstat.zfs.misc.arcstats.l2_cksum_bad: 0
kstat.zfs.misc.arcstats.l2_abort_lowmem: 114
kstat.zfs.misc.arcstats.l2_cdata_free_on_write: 4449
kstat.zfs.misc.arcstats.l2_free_on_write: 647030
kstat.zfs.misc.arcstats.l2_evict_l1cached: 3164010
kstat.zfs.misc.arcstats.l2_evict_reading: 0
kstat.zfs.misc.arcstats.l2_evict_lock_retry: 37
kstat.zfs.misc.arcstats.l2_writes_lock_retry: 2181
-> kstat.zfs.misc.arcstats.l2_writes_error: 1499766
kstat.zfs.misc.arcstats.l2_writes_done: 1543758
kstat.zfs.misc.arcstats.l2_writes_sent: 1543758
kstat.zfs.misc.arcstats.l2_write_bytes: 17569594126336
kstat.zfs.misc.arcstats.l2_read_bytes: 59325997056
kstat.zfs.misc.arcstats.l2_rw_clash: 2
kstat.zfs.misc.arcstats.l2_feeds: 1705468
kstat.zfs.misc.arcstats.l2_misses: 42457839
kstat.zfs.misc.arcstats.l2_hits: 2265463
kstat.zfs.misc.arcstats.evict_l2_skip: 712
kstat.zfs.misc.arcstats.evict_l2_ineligible: 214781087744
kstat.zfs.misc.arcstats.evict_l2_eligible: 1461307185152
kstat.zfs.misc.arcstats.evict_l2_cached: 250679670784


# zpool status
  pool: zpool1
 state: ONLINE
status: One or more devices has experienced an unrecoverable error.  An
        attempt was made to correct the error.  Applications are unaffected.
action: Determine if the device needs to be replaced, and clear the errors
        using 'zpool clear' or replace the device with 'zpool replace'.
   see: http://illumos.org/msg/ZFS-8000-9P
  scan: scrub repaired 0 in 30h28m with 0 errors on Wed Jul 20 04:06:39 2016
config:

        NAME           STATE     READ WRITE CKSUM
        zpool1         ONLINE       0     0     0
          mirror-0     ONLINE       0     0     0
            da0p2.eli  ONLINE       0     0     0
            da1p2.eli  ONLINE       0     0     0
          mirror-1     ONLINE       0     0     0
            da2p2.eli  ONLINE       0     0     0
            da3p2.eli  ONLINE       0     0     0
          mirror-3     ONLINE       0     0     0
            da6p2.eli  ONLINE       0     0     0
            da7p2.eli  ONLINE       0     0     0
          mirror-4     ONLINE       0     0     0
            da4p2.eli  ONLINE       0     0     0
            da5p2.eli  ONLINE       0     0     0
        logs
          nvd0p2.eli   ONLINE       0     0     0
        cache
          nvd0p3.eli   ONLINE       0 1.21G     0

errors: No known data errors

When I remove and re-add the device it works for a while, but then gets in the state seen below where its capacity is entirely free.

# zpool iostat -v
                  capacity     operations    bandwidth
pool           alloc   free   read  write   read  write
-------------  -----  -----  -----  -----  -----  -----
zpool1         11.6T  2.91T    625    186  11.6M  3.58M
  mirror       2.70T   945G    137     51  2.76M   727K
    da0p2.eli      -      -     39     15  2.78M   730K
    da1p2.eli      -      -     39     15  2.78M   730K
  mirror       2.86T   784G    183     34  2.86M   515K
    da2p2.eli      -      -     43     12  2.89M   517K
    da3p2.eli      -      -     43     11  2.89M   517K
  mirror       3.23T   406G    217     28  3.17M   452K
    da6p2.eli      -      -     54     10  3.27M   455K
    da7p2.eli      -      -     53     10  3.27M   455K
  mirror       2.80T   846G     87     45  2.80M   691K
    da4p2.eli      -      -     31     13  2.80M   694K
    da5p2.eli      -      -     31     13  2.80M   694K
logs               -      -      -      -      -      -
  nvd0p2.eli   14.1M  6.92G      0     34      0  1.60M
cache              -      -      -      -      -      -
  nvd0p3.eli    146M   450G    126    263  1.05M  12.7M
-------------  -----  -----  -----  -----  -----  -----

Let me know if you'd rather I start a new ticket.
Comment 16 Andriy Gapon freebsd_committer freebsd_triage 2016-07-26 11:27:10 UTC
(In reply to braddeicide from comment #15)
I don't see any checksum or I/O errors in the stats that you reported.
Comment 17 braddeicide 2016-07-26 11:58:43 UTC
Ah, different issue, I'll raise a separate ticket, thanks.