panic: VERIFY3(dev->l2ad_hand <= dev->l2ad_evict) failed

[grahamperrin]

System information

Type	Version/Name
Distribution Name	FreeBSD
Distribution Version	14.0-CURRENT
Kernel Version	1400089
Architecture	amd64
OpenZFS Version	2.1.99-FreeBSD_gad0a55461

% zfs version
zfs-2.1.99-FreeBSD_gad0a55461
zfs-kmod-2.1.99-FreeBSD_gad0a55461
% uname -aKU
FreeBSD mowa219-gjp4-8570p-freebsd 14.0-CURRENT FreeBSD 14.0-CURRENT #41 main-n263189-c2c9ac88c2bb-dirty: Sat May 27 16:55:26 BST 2023     grahamperrin@mowa219-gjp4-8570p-freebsd:/usr/obj/usr/src/amd64.amd64/sys/GENERIC-NODEBUG amd64 1400089 1400089
% freebsd-version -kru
14.0-CURRENT
14.0-CURRENT
14.0-CURRENT
% 

In context, chronological order:

1. d38c815 (2023-05-09)
2. https://cgit.freebsd.org/src/commit/?id=c0a83fe074a375c66ca669bfe1f128fe12b9f377 (2023-05-23) zfs: merge ad0a55461
3. https://cgit.freebsd.org/src/log/?qt=range&q=c2c9ac88c2bb | freebsd/freebsd-src@c2c9ac8 (2023-05-26) – that is, the c2c9ac88c2bb above in output from uname -aKU.

Describe the problem you're observing

Frequent panics with a GENERIC 14.0-CURRENT kernel. No panic with GENERIC-NODEBUG.

From the original report at https://lists.freebsd.org/archives/freebsd-current/2023-May/003736.html:

… The first panic occurred during installworld, uptime five minutes.

The second was in single user mode, when I took the third of three L2ARC devices online, uptime twenty-two minutes.

The third panic was whilst using Plasma, without the device that featured in the second panic, uptime twenty-three minutes.

The result of a probe at 07:49 UTC: https://bsd-hardware.info/?probe=65376d6b42

Describe how to reproduce the problem

I nearly always use the GENERIC-NODEBUG kernel with 14.0-CURRENT.

I'm not sure about reproducibility, however five panics with GENERIC, in a fifteen-hour period, make me wonder whether:

1. there's a bug; and/or
2. the panics are symptomatic of a hardware issue.

I use three simple USB flash drives for L2ARC, which might be unusual, however the performance gains are great.

Include any warning/errors/backtraces from the system logs

https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=271772 includes four backtraces from five panics.

Additional information available on request.

---

This upstream report is at the suggestion of @PMT:libera.chat in Matrix/Element.

(I looked at #14828 before writing to the freebsd-current list. PMT looked at the same PR.)

L2ARC overview

% lsblk
DEVICE         MAJ:MIN SIZE TYPE                                          LABEL MOUNT
ada0             0:123 932G GPT                                               - -
  ada0p1         0:125 260M efi                                    gpt/efiboot0 -
  <FREE>         -:-   1.0M -                                                 - -
  ada0p2         0:127  16G freebsd-swap                              gpt/swap0 SWAP
  ada0p2.eli     2:59   16G freebsd-swap                                      - SWAP
  ada0p3         0:129 915G freebsd-zfs                                gpt/zfs0 <ZFS>
  ada0p3.eli     0:136 915G -                                                 - -
  <FREE>         -:-   708K -                                                 - -
da0              0:154 7.2G GPT                                               - -
  <FREE>         -:-   1.0M -                                                 - -
  da0p1          0:155 7.2G freebsd-zfs                       gpt/cache3-august <ZFS>
  <FREE>         -:-   1.0M -                                                 - -
da1              0:219 932G GPT                                               - -
  <FREE>         -:-   1.0M -                                                 - -
  da1p1          0:220 932G freebsd-zfs                           gpt/Transcend <ZFS>
  <FREE>         -:-   712K -                                                 - -
da2              0:221  14G GPT                                               - -
  <FREE>         -:-   1.0M -                                                 - -
  da2p1          0:224  14G freebsd-zfs                       gpt/cache2-august <ZFS>
  <FREE>         -:-   1.0M -                                                 - -
da3              0:222  14G GPT                                               - -
  <FREE>         -:-   1.0M -                                                 - -
  da3p1          0:225  14G freebsd-zfs                        gpt/cache-august <ZFS>
  <FREE>         -:-   1.0M -                                                 - -
% geom disk list da3
Geom name: da3
Providers:
1. Name: da3
   Mediasize: 15552479232 (14G)
   Sectorsize: 512
   Mode: r1w1e3
   descr: Kingston DataTraveler 3.0
   lunname: KingstonDataTraveler 3.01.01
   lunid: KingstonDataTraveler 3.01.01
   ident: 60A44C426697AF20F000167F
   rotationrate: unknown
   fwsectors: 63
   fwheads: 255

% geom disk list da2
Geom name: da2
Providers:
1. Name: da2
   Mediasize: 15502147584 (14G)
   Sectorsize: 512
   Mode: r1w1e3
   descr: Kingston DataTraveler 3.0
   lunname: PHISON  USB3
   lunid: 2000acde48234567
   ident: 08606E6B6446BFB138159554
   rotationrate: unknown
   fwsectors: 63
   fwheads: 255

% geom disk list da0
Geom name: da0
Providers:
1. Name: da0
   Mediasize: 7755268096 (7.2G)
   Sectorsize: 512
   Mode: r1w1e3
   descr: Kingston DataTraveler 2.0
   ident: 60A44C4253CABDA03B46026A
   rotationrate: unknown
   fwsectors: 63
   fwheads: 255

% zpool status -x
all pools are healthy
% zpool iostat -v 3
                       capacity     operations     bandwidth 
pool                 alloc   free   read  write   read  write
-------------------  -----  -----  -----  -----  -----  -----
august                763G   149G      5     52  60.5K  1.17M
  ada0p3.eli          763G   149G      5     52  60.5K  1.17M
cache                    -      -      -      -      -      -
  gpt/cache2-august  10.3G  4.14G     16      0   416K   119K
  gpt/cache-august   10.4G  4.08G     17      0   415K   119K
  gpt/cache3-august  3.28G  3.94G     13      0   278K   117K
-------------------  -----  -----  -----  -----  -----  -----
                       capacity     operations     bandwidth 
pool                 alloc   free   read  write   read  write
-------------------  -----  -----  -----  -----  -----  -----
august                763G   149G     55     66   388K  1.48M
  ada0p3.eli          763G   149G     55     66   388K  1.48M
cache                    -      -      -      -      -      -
  gpt/cache2-august  10.3G  4.14G     47      1   366K  42.7K
  gpt/cache-august   10.4G  4.09G     42      1   267K   162K
  gpt/cache3-august  3.28G  3.94G     31      1   240K  79.2K
-------------------  -----  -----  -----  -----  -----  -----
                       capacity     operations     bandwidth 
pool                 alloc   free   read  write   read  write
-------------------  -----  -----  -----  -----  -----  -----
august                763G   149G     22    160   338K  3.92M
  ada0p3.eli          763G   149G     22    160   338K  3.92M
cache                    -      -      -      -      -      -
  gpt/cache2-august  10.3G  4.14G     19      1   199K   234K
  gpt/cache-august   10.4G  4.09G     14      1   131K   294K
  gpt/cache3-august  3.28G  3.94G     14      1   161K   156K
-------------------  -----  -----  -----  -----  -----  -----
^C
% 

[gamanakis]

We recently merged d38c815 fixing a related bug (PR #14828, issue #13899). Do you know if 2.1.99-FreeBSD_gad0a55461(version reported here) contained this commit?

edit: I saw the chronological order provided above, but cannot tell if the fix was included or not.

[gamanakis]

Will take another look at the logic here.

[gamanakis]

Ok, I see the bug, will file a PR soon.

[grahamperrin]

Thanks for the speedy response!

#14936 (comment)

… cannot tell if the fix was included or not.

Yes, it was included at the c2c9ac88c2bb point in time:

• lines 8201–8211 and beyond in https://github.com/freebsd/freebsd-src/blob/c2c9ac88c2bb62423ae91beeee4083b596922adc/sys/contrib/openzfs/module/zfs/arc.c#L8201-L8211 | https://cgit.freebsd.org/src/tree/sys/contrib/openzfs/module/zfs/arc.c?id=c2c9ac88c2bb62423ae91beeee4083b596922adc#n8201.

[rincebrain]

I regret to say that this assert just fired here on this branch which includes bcd5321. @gamanakis

e:

[ 7461.663013] VERIFY3(dev->l2ad_hand <= dev->l2ad_evict) failed (151148032 <= 151147008)
[ 7461.676633] PANIC at arc.c:9456:l2arc_write_buffers()
[ 7461.684178] Showing stack for process 32154
[ 7461.691238] CPU: 1 PID: 32154 Comm: l2arc_feed Kdump: loaded Tainted: P           OE  ------------   3.10.0-1160.90.1.el7.x86_64 #1
[ 7461.707257] Hardware name: Amazon EC2 m5d.large/, BIOS 1.0 10/16/2017
[ 7461.715242] Call Trace:
[ 7461.720362]  [<ffffffffbb3b1bec>] dump_stack+0x19/0x1f
[ 7461.726871]  [<ffffffffc04b965b>] spl_dumpstack+0x2b/0x40 [spl]
[ 7461.733836]  [<ffffffffc04b9739>] spl_panic+0xc9/0x110 [spl]
[ 7461.740605]  [<ffffffffc04c1c34>] ? taskq_dispatch_ent+0x74/0x1f0 [spl]
[ 7461.748012]  [<ffffffffc0720450>] ? zio_taskq_member.constprop.0+0x80/0x80 [zfs]
[ 7461.759495]  [<ffffffffc0675c1c>] ? spa_taskq_dispatch_ent+0x6c/0xe0 [zfs]
[ 7461.767062]  [<ffffffffc071e042>] ? zio_taskq_dispatch+0xc2/0x170 [zfs]
[ 7461.774406]  [<ffffffffc065cde9>] ? do_raw_spin_unlock+0x9/0x10 [zfs]
[ 7461.781725]  [<ffffffffc065cdf9>] ? __raw_spin_unlock+0x9/0x10 [zfs]
[ 7461.788949]  [<ffffffffc05a6592>] l2arc_write_buffers+0x882/0xc50 [zfs]
[ 7461.796494]  [<ffffffffc05a7fa2>] l2arc_feed_thread+0x2e2/0x470 [zfs]
[ 7461.803790]  [<ffffffffc05a7cc0>] ? l2arc_remove_vdev+0x330/0x330 [zfs]
[ 7461.811133]  [<ffffffffc04c2bec>] thread_generic_wrapper+0x7c/0xb0 [spl]
[ 7461.818532]  [<ffffffffc04c2b70>] ? spin_lock_irq+0x10/0x10 [spl]
[ 7461.825913]  [<ffffffffbaccb621>] kthread+0xd1/0xe0
[ 7461.832386]  [<ffffffffbaccb550>] ? insert_kthread_work+0x40/0x40
[ 7461.839399]  [<ffffffffbb3c51f7>] ret_from_fork_nospec_begin+0x21/0x21
[ 7461.846676]  [<ffffffffbaccb550>] ? insert_kthread_work+0x40/0x40

[gamanakis]

thanks for reporting this, will take another look

[glebius]

I have got panic with FreeBSD CURRENT 4e8d558c9d1, this includes openzfs/zfs up to feff9df:

--- trap 0x9, rip = 0xffffffff803ab4f9, rsp = 0xfffffe02622c27e0, rbp = 0xfffffe02622c2820 ---
buf_hash_find() at buf_hash_find+0xb9/frame 0xfffffe02622c2820
arc_read() at arc_read+0x1de/frame 0xfffffe02622c28d0
dbuf_issue_final_prefetch() at dbuf_issue_final_prefetch+0x110/frame 0xfffffe02622c2910
dbuf_prefetch_impl() at dbuf_prefetch_impl+0x3d0/frame 0xfffffe02622c2a30
dbuf_prefetch() at dbuf_prefetch+0x18/frame 0xfffffe02622c2a50
dmu_prefetch() at dmu_prefetch+0x171/frame 0xfffffe02622c2a90
zfs_freebsd_readdir() at zfs_freebsd_readdir+0x4a8/frame 0xfffffe02622c2cc0
VOP_READDIR_APV() at VOP_READDIR_APV+0x1f/frame 0xfffffe02622c2ce0
kern_getdirentries() at kern_getdirentries+0x186/frame 0xfffffe02622c2dd0
sys_getdirentries() at sys_getdirentries+0x29/frame 0xfffffe02622c2e00
amd64_syscall() at amd64_syscall+0x100/frame 0xfffffe02622c2f30
fast_syscall_common() at fast_syscall_common+0xf8/frame 0xfffffe02622c2f30

(kgdb)  frame 8
#8  0xffffffff803aa22e in arc_read (pio=0xfffff80ed3d939c0, spa=0xfffffe022e4e3000, bp=0xfffffe02622c2920, 
    done=0xffffffff803c9ea0 <dbuf_issue_final_prefetch_done>, private=private@entry=0xfffff8019145fa80, priority=ZIO_PRIORITY_SYNC_READ, 
    zio_flags=<optimized out>, arc_flags=0xfffffe02622c2904, zb=0xfffff8019145fa88) at /usr/src/FreeBSD/sys/contrib/openzfs/module/zfs/arc.c:5710
5710                    hdr = buf_hash_find(guid, bp, &hash_lock);
(kgdb) p hash_lock
$1 = (kmutex_t *) 0x0
(kgdb) p &hash_lock
$2 = (kmutex_t **) 0xfffffe02622c2878
(kgdb) p guid
$3 = 10764490942119040405
(kgdb) p bp
$4 = (const blkptr_t *) 0xfffffe02622c2920
(kgdb) p *bp
$5 = {blk_dva = {{dva_word = {16, 2955990064}}, {dva_word = {16, 5653526320}}, {dva_word = {0, 0}}}, blk_prop = 9226194547628245023, blk_pad = {
    0, 0}, blk_phys_birth = 0, blk_birth = 24013652, blk_fill = 32, blk_cksum = {zc_word = {840181217790, 582227756846574, 216841723804020208, 
      1739683392500561293}}}

[glebius]

I will try to reproduce with INVARIANTS.

[grahamperrin]

@glebius #14936 (comment) at a glance, that's not related to this issue (or L2ARC) …

[glebius]

I think it is related. The non-INVARIANT panic I had before looked pretty much the same.