Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

PANIC / zfs receive hanging #11648

Closed
jtyocum opened this issue Feb 24, 2021 · 17 comments
Closed

PANIC / zfs receive hanging #11648

jtyocum opened this issue Feb 24, 2021 · 17 comments
Labels
Status: Triage Needed New issue which needs to be triaged Type: Defect Incorrect behavior (e.g. crash, hang)

Comments

@jtyocum
Copy link

jtyocum commented Feb 24, 2021

System information

Type Version/Name
Distribution Name CentOS
Distribution Version 8.3
Linux Kernel 4.18.0-240.1.1.el8_3.x86_64
Architecture x86_64
ZFS Version 0.8.6-1
SPL Version 0.8.6-1

Describe the problem you're observing

zfs receive randomly hangs when receiving file system snapshots from another system. Once it hangs, the receive stops writing to disk until the SSH process that was used to send the snapshot is killed.

Below is the syntax of the receive command we're using:

zfs receive -Fduv tank

Describe how to reproduce the problem

Problem occurs randomly. Not sure how to trigger it.

Additional details, the ZFS pool that is doing the receiving "tank", contains both file systems receiving snapshots (replication), along with active / in use file systems.

Include any warning/errors/backtraces from the system logs

[4995815.674524] VERIFY3(insert_inode_locked(ip) == 0) failed (-16 == 0)
[4995815.674568] PANIC at zfs_znode.c:611:zfs_znode_alloc()
[4995815.674591] Showing stack for process 4036656
[4995815.674594] CPU: 6 PID: 4036656 Comm: z_unlinked_drai Kdump: loaded Tainted: P           OE    --------- -  - 4.18.0-240.1.1.el8_3.x86_64 #1
[4995815.674595] Hardware name: Supermicro Super Server/X11DPH-T, BIOS 3.2 10/22/2019
[4995815.674595] Call Trace:
[4995815.674606]  dump_stack+0x5c/0x80
[4995815.674618]  spl_panic+0xd3/0xfb [spl]
[4995815.674677]  ? dbuf_dirty+0x396/0x8a0 [zfs]
[4995815.674681]  ? _cond_resched+0x15/0x30
[4995815.674683]  ? _cond_resched+0x15/0x30
[4995815.674684]  ? mutex_lock+0xe/0x30
[4995815.674726]  ? dmu_buf_replace_user+0x5d/0x80 [zfs]
[4995815.674729]  ? iput+0x76/0x200
[4995815.674731]  ? insert_inode_locked+0x1d1/0x1e0
[4995815.674785]  zfs_znode_alloc+0x653/0x6b0 [zfs]
[4995815.674842]  zfs_zget+0x1a0/0x240 [zfs]
[4995815.674896]  zfs_unlinked_drain_task+0x6e/0xf0 [zfs]
[4995815.674900]  ? __switch_to_asm+0x41/0x70
[4995815.674901]  ? __switch_to_asm+0x35/0x70
[4995815.674902]  ? __switch_to_asm+0x41/0x70
[4995815.674903]  ? __switch_to_asm+0x35/0x70
[4995815.674904]  ? __switch_to_asm+0x41/0x70
[4995815.674905]  ? __switch_to_asm+0x35/0x70
[4995815.674905]  ? __switch_to_asm+0x41/0x70
[4995815.674906]  ? __switch_to_asm+0x35/0x70
[4995815.674907]  ? __switch_to_asm+0x41/0x70
[4995815.674908]  ? __switch_to_asm+0x35/0x70
[4995815.674909]  ? __switch_to_asm+0x41/0x70
[4995815.674912]  ? __switch_to+0x7a/0x3f0
[4995815.674914]  ? __schedule+0x2ae/0x700
[4995815.674917]  ? __wake_up_common_lock+0x89/0xc0
[4995815.674919]  ? remove_wait_queue+0x20/0x60
[4995815.674925]  taskq_thread+0x2e5/0x530 [spl]
[4995815.674929]  ? wake_up_q+0x80/0x80
[4995815.674935]  ? taskq_thread_spawn+0x50/0x50 [spl]
[4995815.674937]  kthread+0x112/0x130
[4995815.674939]  ? kthread_flush_work_fn+0x10/0x10
[4995815.674940]  ret_from_fork+0x1f/0x40
@jtyocum jtyocum added Status: Triage Needed New issue which needs to be triaged Type: Defect Incorrect behavior (e.g. crash, hang) labels Feb 24, 2021
@jtyocum
Copy link
Author

jtyocum commented Feb 24, 2021

Possibly related? #9741

@andybalholm
Copy link

I'm getting the same panic with zfs-2.0.0-rc5 on Linux 3.10.0.

@beren12
Copy link
Contributor

beren12 commented Mar 30, 2021

that is very old now, try with a current release

@andybalholm
Copy link

@beren12 That is the newest package that seems to be available for CentOS 7. I've built 2.0.4 from source now. We'll see how that works.

@andybalholm
Copy link

@beren12 It's still happening with 2.0.4.

@pgdh
Copy link

pgdh commented Apr 7, 2021

Same here on Ubuntu 20.04.2 LTS ...

[2509290.655791] VERIFY3(insert_inode_locked(ip) == 0) failed (-16 == 0)
[2509290.655891] PANIC at zfs_znode.c:611:zfs_znode_alloc()
[2509290.655950] Showing stack for process 3553743
[2509290.655956] CPU: 18 PID: 3553743 Comm: z_unlinked_drai Tainted: P           OE     5.4.0-66-generic #74-Ubuntu
[2509290.655958] Hardware name: Dell Inc. PowerEdge R630/02C2CP, BIOS 2.12.1 12/04/2020
[2509290.655960] Call Trace:
[2509290.655973]  dump_stack+0x6d/0x9a
[2509290.655994]  spl_dumpstack+0x29/0x2b [spl]
[2509290.656009]  spl_panic+0xd4/0x102 [spl]
[2509290.656160]  ? zrl_add_impl+0xa0/0xb0 [zfs]
[2509290.656294]  ? atomic_dec_return+0x9/0x10 [zfs]
[2509290.656373]  ? do_raw_spin_unlock+0x9/0x10 [zfs]
[2509290.656451]  ? __raw_spin_unlock+0x9/0x10 [zfs]
[2509290.656532]  ? dmu_buf_replace_user+0x75/0xa0 [zfs]
[2509290.656661]  ? atomic_cmpxchg+0x16/0x30 [zfs]
[2509290.656790]  ? atomic_sub_return.constprop.0+0xd/0x20 [zfs]
[2509290.656795]  ? iput+0x7d/0x210
[2509290.656799]  ? insert_inode_locked+0x1d5/0x1e0
[2509290.656929]  zfs_znode_alloc+0x54a/0x570 [zfs]
[2509290.657062]  zfs_zget+0x24a/0x290 [zfs]
[2509290.657188]  zfs_unlinked_drain_task+0x74/0x100 [zfs]
[2509290.657196]  ? __switch_to_asm+0x34/0x70
[2509290.657200]  ? __switch_to_asm+0x40/0x70
[2509290.657204]  ? __switch_to_asm+0x34/0x70
[2509290.657208]  ? __switch_to_asm+0x40/0x70
[2509290.657212]  ? __switch_to_asm+0x34/0x70
[2509290.657216]  ? __switch_to_asm+0x40/0x70
[2509290.657220]  ? __switch_to_asm+0x34/0x70
[2509290.657224]  ? __switch_to_asm+0x40/0x70
[2509290.657231]  ? __switch_to+0x7f/0x470
[2509290.657236]  ? __switch_to_asm+0x40/0x70
[2509290.657240]  ? __switch_to_asm+0x34/0x70
[2509290.657244]  ? __schedule+0x2eb/0x740
[2509290.657250]  ? __wake_up_common_lock+0x8a/0xc0
[2509290.657265]  ? __list_add+0x17/0x40 [spl]
[2509290.657277]  ? list_add+0xc/0x10 [spl]
[2509290.657289]  taskq_thread+0x245/0x430 [spl]
[2509290.657295]  ? wake_up_q+0x70/0x70
[2509290.657301]  kthread+0x104/0x140
[2509290.657313]  ? task_done+0x90/0x90 [spl]
[2509290.657316]  ? kthread_park+0x90/0x90
[2509290.657321]  ret_from_fork+0x35/0x40

This occurred while sending about 25TB across three filesystems with about 125 snapshots across each from one pool to another on the same host ...

zfs send -c -I ${FIRST:?} ${LAST:?} |
pv -prb -f |
zfs receive -F ${RECV:?}

Interestingly, the zfs send continues, while the zfs recieve freezes (so where all that data is going is a bit of a mystery).

root@hqs7:~# uname -a
Linux hqs7 5.4.0-66-generic #74-Ubuntu SMP Wed Jan 27 22:54:38 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
root@hqs7:~# cat /etc/os-release
NAME="Ubuntu"
VERSION="20.04.2 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.2 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal
root@hqs7:~# zpool version
zfs-0.8.3-1ubuntu12.6
zfs-kmod-0.8.3-1ubuntu12.6
root@hqs7:~#

[EDIT: the following was requested]

root@hqs7:~# zpool status
  pool: hqs7p1
 state: ONLINE
  scan: scrub repaired 0B in 0 days 16:09:04 with 0 errors on Thu Apr  1 16:09:05 2021
config:

	NAME                                 STATE     READ WRITE CKSUM
	hqs7p1                               ONLINE       0     0     0
	  mirror-0                           ONLINE       0     0     0
	    dm-uuid-mpath-35000c500cb4e3393  ONLINE       0     0     0
	    dm-uuid-mpath-35000c500cb40dc77  ONLINE       0     0     0
	  mirror-1                           ONLINE       0     0     0
	    dm-uuid-mpath-35000c500cb2d671b  ONLINE       0     0     0
	    dm-uuid-mpath-35000c500cb4ca703  ONLINE       0     0     0
	  mirror-2                           ONLINE       0     0     0
	    dm-uuid-mpath-35000c500cb392b9b  ONLINE       0     0     0
	    dm-uuid-mpath-35000c500cb4c7977  ONLINE       0     0     0

errors: No known data errors

  pool: hqs7p2
 state: ONLINE
  scan: none requested
config:

	NAME                                 STATE     READ WRITE CKSUM
	hqs7p2                               ONLINE       0     0     0
	  mirror-0                           ONLINE       0     0     0
	    dm-uuid-mpath-35000c500cb4e1f4b  ONLINE       0     0     0
	    dm-uuid-mpath-35000c500cb4e304f  ONLINE       0     0     0
	  mirror-1                           ONLINE       0     0     0
	    dm-uuid-mpath-35000c500cb50e95f  ONLINE       0     0     0
	    dm-uuid-mpath-35000c500cb51f44b  ONLINE       0     0     0
	  mirror-2                           ONLINE       0     0     0
	    dm-uuid-mpath-35000c500cb4f6407  ONLINE       0     0     0
	    dm-uuid-mpath-35000c500cb0dda97  ONLINE       0     0     0

errors: No known data errors
root@hqs7:~#

@bghira
Copy link

bghira commented Apr 7, 2021

i don't see any pool layout details for any of the affected users. can you share the output of zpool status?

@andybalholm
Copy link

Here is mine:

  pool: vault
 state: ONLINE
status: Some supported and requested features are not enabled on the pool.
        The pool can still be used, but some features are unavailable.
action: Enable all features using 'zpool upgrade'. Once this is done,
        the pool may no longer be accessible by software that does not support
        the features. See zpool-features(5) for details.
  scan: scrub repaired 0B in 02:54:08 with 0 errors on Sun Jan 24 23:23:53 2021
config:

        NAME                                         STATE     READ WRITE CKSUM
        vault                                        ONLINE       0     0     0
          ata-WDC_WD1002FAEX-00Y9A0_WD-WCAW35081458  ONLINE       0     0     0

errors: No known data errors

@jtyocum
Copy link
Author

jtyocum commented Apr 7, 2021

Here's mine:

  pool: tank
 state: ONLINE
  scan: scrub repaired 0B in 0 days 06:29:52 with 0 errors on Wed Dec 16 15:42:42 2020
config:

	NAME                                                        STATE     READ WRITE CKSUM
	tank                                                        ONLINE       0     0     0
	  raidz2-0                                                  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy0-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy1-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy2-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy3-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy4-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy5-lun-0   ONLINE       0     0     0
	  raidz2-1                                                  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy6-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy7-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy8-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy9-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy10-lun-0  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy11-lun-0  ONLINE       0     0     0
	  raidz2-2                                                  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy28-lun-0  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy29-lun-0  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy30-lun-0  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy31-lun-0  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy32-lun-0  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy33-lun-0  ONLINE       0     0     0
	  raidz2-3                                                  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy34-lun-0  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy35-lun-0  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy36-lun-0  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy37-lun-0  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy38-lun-0  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x500304802097dbff-phy39-lun-0  ONLINE       0     0     0
	  raidz2-4                                                  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x5003048020a4267f-phy0-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x5003048020a4267f-phy1-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x5003048020a4267f-phy2-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x5003048020a4267f-phy3-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x5003048020a4267f-phy4-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x5003048020a4267f-phy5-lun-0   ONLINE       0     0     0
	  raidz2-5                                                  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x5003048020a4267f-phy6-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x5003048020a4267f-phy7-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x5003048020a4267f-phy8-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x5003048020a4267f-phy9-lun-0   ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x5003048020a4267f-phy10-lun-0  ONLINE       0     0     0
	    pci-0000:3d:00.0-sas-exp0x5003048020a4267f-phy11-lun-0  ONLINE       0     0     0
	logs	
	  mirror-6                                                  ONLINE       0     0     0
	    pci-0000:3b:00.0-nvme-1                                 ONLINE       0     0     0
	    pci-0000:3c:00.0-nvme-1                                 ONLINE       0     0     0

errors: No known data errors

@andybalholm
Copy link

I rebuilt zfs from git master (583e320), and I'm still having the problem.

@pgdh
Copy link

pgdh commented May 28, 2021

I've upgraded a server from our ZFS farm to Ubuntu 21.04 and see the same panic and subsequent hang ...

[Thu May 27 12:55:25 2021] VERIFY3(insert_inode_locked(ip) == 0) failed (-16 == 0)
[Thu May 27 12:55:25 2021] PANIC at zfs_znode.c:616:zfs_znode_alloc()
[Thu May 27 12:55:25 2021] Showing stack for process 2376
[Thu May 27 12:55:25 2021] CPU: 6 PID: 2376 Comm: z_unlinked_drai Tainted: P           O      5.11.0-16-generic #17-Ubuntu
[Thu May 27 12:55:25 2021] Hardware name: Dell Inc. PowerEdge R630/02C2CP, BIOS 2.12.1 12/04/2020
[Thu May 27 12:55:25 2021] Call Trace:
[Thu May 27 12:55:25 2021]  show_stack+0x52/0x58
[Thu May 27 12:55:25 2021]  dump_stack+0x70/0x8b
[Thu May 27 12:55:25 2021]  spl_dumpstack+0x29/0x2b [spl]
[Thu May 27 12:55:25 2021]  spl_panic+0xd4/0xfc [spl]
[Thu May 27 12:55:25 2021]  ? spl_kmem_cache_alloc+0x3b/0x100 [spl]
[Thu May 27 12:55:25 2021]  ? _cond_resched+0x1a/0x50
[Thu May 27 12:55:25 2021]  ? do_raw_spin_unlock+0x9/0x10 [zfs]
[Thu May 27 12:55:25 2021]  ? __raw_spin_unlock+0x9/0x10 [zfs]
[Thu May 27 12:55:25 2021]  ? dmu_buf_replace_user+0x65/0x80 [zfs]
[Thu May 27 12:55:25 2021]  ? iput.part.0+0x5f/0xb0
[Thu May 27 12:55:25 2021]  ? insert_inode_locked+0x1fa/0x210
[Thu May 27 12:55:25 2021]  zfs_znode_alloc+0x53e/0x560 [zfs]
[Thu May 27 12:55:25 2021]  zfs_zget+0x237/0x280 [zfs]
[Thu May 27 12:55:25 2021]  zfs_unlinked_drain_task+0x74/0x100 [zfs]
[Thu May 27 12:55:25 2021]  ? __update_idle_core+0x9b/0xb0
[Thu May 27 12:55:25 2021]  ? __switch_to+0x11d/0x3f0
[Thu May 27 12:55:25 2021]  ? __switch_to_asm+0x36/0x70
[Thu May 27 12:55:25 2021]  ? __schedule+0x245/0x670
[Thu May 27 12:55:25 2021]  ? __list_add+0x17/0x40 [spl]
[Thu May 27 12:55:25 2021]  ? list_add+0xc/0x10 [spl]
[Thu May 27 12:55:25 2021]  taskq_thread+0x236/0x420 [spl]
[Thu May 27 12:55:25 2021]  ? wake_up_q+0xa0/0xa0
[Thu May 27 12:55:25 2021]  kthread+0x12f/0x150
[Thu May 27 12:55:25 2021]  ? param_set_taskq_kick+0xf0/0xf0 [spl]
[Thu May 27 12:55:25 2021]  ? __kthread_bind_mask+0x70/0x70
[Thu May 27 12:55:25 2021]  ret_from_fork+0x22/0x30
[Thu May 27 12:57:59 2021] INFO: task z_unlinked_drai:2376 blocked for more than 120 seconds.
[Thu May 27 12:57:59 2021]       Tainted: P           O      5.11.0-16-generic #17-Ubuntu
[Thu May 27 12:57:59 2021] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Thu May 27 12:57:59 2021] task:z_unlinked_drai state:D stack:    0 pid: 2376 ppid:     2 flags:0x00004000
[Thu May 27 12:57:59 2021] Call Trace:
[Thu May 27 12:57:59 2021]  __schedule+0x23d/0x670
[Thu May 27 12:57:59 2021]  schedule+0x4f/0xc0
[Thu May 27 12:57:59 2021]  spl_panic+0xfa/0xfc [spl]
[Thu May 27 12:57:59 2021]  ? spl_kmem_cache_alloc+0x3b/0x100 [spl]
[Thu May 27 12:57:59 2021]  ? _cond_resched+0x1a/0x50
[Thu May 27 12:57:59 2021]  ? do_raw_spin_unlock+0x9/0x10 [zfs]
[Thu May 27 12:57:59 2021]  ? __raw_spin_unlock+0x9/0x10 [zfs]
[Thu May 27 12:57:59 2021]  ? dmu_buf_replace_user+0x65/0x80 [zfs]
[Thu May 27 12:57:59 2021]  ? iput.part.0+0x5f/0xb0
[Thu May 27 12:57:59 2021]  ? insert_inode_locked+0x1fa/0x210
[Thu May 27 12:57:59 2021]  zfs_znode_alloc+0x53e/0x560 [zfs]
[Thu May 27 12:57:59 2021]  zfs_zget+0x237/0x280 [zfs]
[Thu May 27 12:57:59 2021]  zfs_unlinked_drain_task+0x74/0x100 [zfs]
[Thu May 27 12:57:59 2021]  ? __update_idle_core+0x9b/0xb0
[Thu May 27 12:57:59 2021]  ? __switch_to+0x11d/0x3f0
[Thu May 27 12:57:59 2021]  ? __switch_to_asm+0x36/0x70
[Thu May 27 12:57:59 2021]  ? __schedule+0x245/0x670
[Thu May 27 12:57:59 2021]  ? __list_add+0x17/0x40 [spl]
[Thu May 27 12:57:59 2021]  ? list_add+0xc/0x10 [spl]
[Thu May 27 12:57:59 2021]  taskq_thread+0x236/0x420 [spl]
[Thu May 27 12:57:59 2021]  ? wake_up_q+0xa0/0xa0
[Thu May 27 12:57:59 2021]  kthread+0x12f/0x150
[Thu May 27 12:57:59 2021]  ? param_set_taskq_kick+0xf0/0xf0 [spl]
[Thu May 27 12:57:59 2021]  ? __kthread_bind_mask+0x70/0x70
[Thu May 27 12:57:59 2021]  ret_from_fork+0x22/0x30

We see this panic daily during zfs receives from elsewhere in our ZFS farm.

The zfs send / receive incantation we're using is ...

zfs send -I tank0/DAT1@auto-20210524112633 tank1/DAT1@auto-20210528050201 | ssh backup1 zfs recv -F tank1/DAT1

Note: these are backup servers so we have primarycache=metadata throughout.

root@backup1:~# uname -a
Linux backup1 5.11.0-16-generic #17-Ubuntu SMP Wed Apr 14 20:12:43 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
root@backup1:~# zfs version
zfs-2.0.2-1ubuntu5
zfs-kmod-2.0.2-1ubuntu5
root@backup1:~# zpool get all tank1
NAME     PROPERTY                       VALUE                          SOURCE
tank1  size                           102T                           -
tank1  capacity                       89%                            -
tank1  altroot                        -                              default
tank1  health                         ONLINE                         -
tank1  guid                           4608309948481903554            -
tank1  version                        -                              default
tank1  bootfs                         -                              default
tank1  delegation                     on                             default
tank1  autoreplace                    off                            default
tank1  cachefile                      -                              default
tank1  failmode                       wait                           default
tank1  listsnapshots                  off                            default
tank1  autoexpand                     off                            default
tank1  dedupratio                     1.00x                          -
tank1  free                           10.8T                          -
tank1  allocated                      91.0T                          -
tank1  readonly                       off                            -
tank1  ashift                         12                             local
tank1  comment                        -                              default
tank1  expandsize                     -                              -
tank1  freeing                        0                              -
tank1  fragmentation                  21%                            -
tank1  leaked                         0                              -
tank1  multihost                      off                            default
tank1  checkpoint                     -                              -
tank1  load_guid                      10726547910070845016           -
tank1  autotrim                       off                            default
tank1  feature@async_destroy          enabled                        local
tank1  feature@empty_bpobj            active                         local
tank1  feature@lz4_compress           active                         local
tank1  feature@multi_vdev_crash_dump  enabled                        local
tank1  feature@spacemap_histogram     active                         local
tank1  feature@enabled_txg            active                         local
tank1  feature@hole_birth             active                         local
tank1  feature@extensible_dataset     active                         local
tank1  feature@embedded_data          active                         local
tank1  feature@bookmarks              enabled                        local
tank1  feature@filesystem_limits      enabled                        local
tank1  feature@large_blocks           enabled                        local
tank1  feature@large_dnode            enabled                        local
tank1  feature@sha512                 enabled                        local
tank1  feature@skein                  enabled                        local
tank1  feature@edonr                  enabled                        local
tank1  feature@userobj_accounting     active                         local
tank1  feature@encryption             enabled                        local
tank1  feature@project_quota          active                         local
tank1  feature@device_removal         enabled                        local
tank1  feature@obsolete_counts        enabled                        local
tank1  feature@zpool_checkpoint       enabled                        local
tank1  feature@spacemap_v2            active                         local
tank1  feature@allocation_classes     enabled                        local
tank1  feature@resilver_defer         enabled                        local
tank1  feature@bookmark_v2            enabled                        local
tank1  feature@redaction_bookmarks    disabled                       local
tank1  feature@redacted_datasets      disabled                       local
tank1  feature@bookmark_written       disabled                       local
tank1  feature@log_spacemap           disabled                       local
tank1  feature@livelist               disabled                       local
tank1  feature@device_rebuild         disabled                       local
tank1  feature@zstd_compress          disabled                       local
root@backup1:~# zfs get all tank1
NAME     PROPERTY              VALUE                  SOURCE
tank1  type                  filesystem             -
tank1  creation              Wed Apr 21 11:58 2021  -
tank1  used                  91.0T                  -
tank1  available             7.62T                  -
tank1  referenced            216K                   -
tank1  compressratio         1.74x                  -
tank1  mounted               yes                    -
tank1  quota                 none                   default
tank1  reservation           none                   default
tank1  recordsize            128K                   default
tank1  mountpoint            /tank1                 default
tank1  sharenfs              off                    default
tank1  checksum              on                     default
tank1  compression           off                    default
tank1  atime                 on                     default
tank1  devices               on                     default
tank1  exec                  on                     default
tank1  setuid                on                     default
tank1  readonly              off                    default
tank1  zoned                 off                    default
tank1  snapdir               hidden                 default
tank1  aclmode               discard                default
tank1  aclinherit            restricted             default
tank1  createtxg             1                      -
tank1  canmount              on                     default
tank1  xattr                 on                     default
tank1  copies                1                      default
tank1  version               5                      -
tank1  utf8only              off                    -
tank1  normalization         none                   -
tank1  casesensitivity       sensitive              -
tank1  vscan                 off                    default
tank1  nbmand                off                    default
tank1  sharesmb              off                    default
tank1  refquota              none                   default
tank1  refreservation        none                   default
tank1  guid                  6361132405610378149    -
tank1  primarycache          metadata               local
tank1  secondarycache        all                    default
tank1  usedbysnapshots       0B                     -
tank1  usedbydataset         216K                   -
tank1  usedbychildren        91.0T                  -
tank1  usedbyrefreservation  0B                     -
tank1  logbias               latency                default
tank1  objsetid              54                     -
tank1  dedup                 off                    default
tank1  mlslabel              none                   default
tank1  sync                  standard               default
tank1  dnodesize             legacy                 default
tank1  refcompressratio      1.00x                  -
tank1  written               216K                   -
tank1  logicalused           158T                   -
tank1  logicalreferenced     100K                   -
tank1  volmode               default                default
tank1  filesystem_limit      none                   default
tank1  snapshot_limit        none                   default
tank1  filesystem_count      none                   default
tank1  snapshot_count        none                   default
tank1  snapdev               hidden                 default
tank1  acltype               off                    default
tank1  context               none                   default
tank1  fscontext             none                   default
tank1  defcontext            none                   default
tank1  rootcontext           none                   default
tank1  relatime              off                    default
tank1  redundant_metadata    all                    default
tank1  overlay               on                     default
tank1  encryption            off                    default
tank1  keylocation           none                   default
tank1  keyformat             none                   default
tank1  pbkdf2iters           0                      default
tank1  special_small_blocks  0                      default
root@backup1:~# zpool status
  pool: tank1
 state: ONLINE
status: Some supported features are not enabled on the pool. The pool can
        still be used, but some features are unavailable.
action: Enable all features using 'zpool upgrade'. Once this is done,
        the pool may no longer be accessible by software that does not support
        the features. See zpool-features(5) for details.
config:

        NAME                        STATE     READ WRITE CKSUM
        tank1                     ONLINE       0     0     0
          mirror-0                  ONLINE       0     0     0
            scsi-35000c500cbf33e27  ONLINE       0     0     0
            scsi-35000c500cbf501eb  ONLINE       0     0     0
          mirror-1                  ONLINE       0     0     0
            scsi-35000c500cbf4fcef  ONLINE       0     0     0
            scsi-35000c500cbee50e7  ONLINE       0     0     0
          mirror-2                  ONLINE       0     0     0
            scsi-35000c500cbf01ceb  ONLINE       0     0     0
            scsi-35000c500cbf09e23  ONLINE       0     0     0
          mirror-3                  ONLINE       0     0     0
            scsi-35000c500cbef981f  ONLINE       0     0     0
            scsi-35000c500cbf0c79b  ONLINE       0     0     0
          mirror-4                  ONLINE       0     0     0
            scsi-35000c500cbef7ffb  ONLINE       0     0     0
            scsi-35000c500cbf0e753  ONLINE       0     0     0
          mirror-5                  ONLINE       0     0     0
            scsi-35000c500cbeff5b3  ONLINE       0     0     0
            scsi-35000c500cbf0647f  ONLINE       0     0     0
          mirror-6                  ONLINE       0     0     0
            scsi-35000c500cbf150cb  ONLINE       0     0     0
            scsi-35000c500cbeff343  ONLINE       0     0     0
          mirror-7                  ONLINE       0     0     0
            scsi-35000c500cbef366b  ONLINE       0     0     0
            scsi-35000c500cbf0e61f  ONLINE       0     0     0

errors: No known data errors
root@backup1:~#

@PaulZ-98
Copy link
Contributor

PaulZ-98 commented Jun 3, 2021

Provided root cause information and reproducer in #9741

PaulZ-98 added a commit to datto/zfs that referenced this issue Jun 9, 2021
In zfs_znode_alloc we always hash inodes.  If the
znode is unlinked, we do not need to hash it.  This
fixes the problem where zfs_suspend_fs is doing zrele
(iput) in an async fashion, and zfs_resume_fs unlinked
drain processing will try to hash an inode that could
still be hashed, resulting in a panic.

Fixes: openzfs#9741
Fixes: openzfs#11223
Fixes: openzfs#11648

Signed-off-by: Paul Zuchowski <pzuchowski@datto.com>
PaulZ-98 added a commit to datto/zfs that referenced this issue Jun 9, 2021
In zfs_znode_alloc we always hash inodes.  If the
znode is unlinked, we do not need to hash it.  This
fixes the problem where zfs_suspend_fs is doing zrele
(iput) in an async fashion, and zfs_resume_fs unlinked
drain processing will try to hash an inode that could
still be hashed, resulting in a panic.

Fixes: openzfs#9741
Fixes: openzfs#11223
Fixes: openzfs#11648

Signed-off-by: Paul Zuchowski <pzuchowski@datto.com>
tonyhutter pushed a commit to tonyhutter/zfs that referenced this issue Jun 15, 2021
In zfs_znode_alloc we always hash inodes.  If the
znode is unlinked, we do not need to hash it.  This
fixes the problem where zfs_suspend_fs is doing zrele
(iput) in an async fashion, and zfs_resume_fs unlinked
drain processing will try to hash an inode that could
still be hashed, resulting in a panic.

Reviewed-by: Brian Behlendorf <behlendorf1@llnl.gov>
Reviewed-by: Alan Somers <asomers@gmail.com>
Signed-off-by: Paul Zuchowski <pzuchowski@datto.com>
Closes openzfs#9741
Closes openzfs#11223
Closes openzfs#11648
Closes openzfs#12210
behlendorf pushed a commit that referenced this issue Jun 16, 2021
In zfs_znode_alloc we always hash inodes.  If the
znode is unlinked, we do not need to hash it.  This
fixes the problem where zfs_suspend_fs is doing zrele
(iput) in an async fashion, and zfs_resume_fs unlinked
drain processing will try to hash an inode that could
still be hashed, resulting in a panic.

Reviewed-by: Brian Behlendorf <behlendorf1@llnl.gov>
Reviewed-by: Alan Somers <asomers@gmail.com>
Signed-off-by: Paul Zuchowski <pzuchowski@datto.com>
Closes #9741
Closes #11223
Closes #11648
Closes #12210
tonyhutter pushed a commit to tonyhutter/zfs that referenced this issue Jun 16, 2021
In zfs_znode_alloc we always hash inodes.  If the
znode is unlinked, we do not need to hash it.  This
fixes the problem where zfs_suspend_fs is doing zrele
(iput) in an async fashion, and zfs_resume_fs unlinked
drain processing will try to hash an inode that could
still be hashed, resulting in a panic.

Reviewed-by: Brian Behlendorf <behlendorf1@llnl.gov>
Reviewed-by: Alan Somers <asomers@gmail.com>
Signed-off-by: Paul Zuchowski <pzuchowski@datto.com>
Closes openzfs#9741
Closes openzfs#11223
Closes openzfs#11648
Closes openzfs#12210
tonyhutter pushed a commit to tonyhutter/zfs that referenced this issue Jun 17, 2021
In zfs_znode_alloc we always hash inodes.  If the
znode is unlinked, we do not need to hash it.  This
fixes the problem where zfs_suspend_fs is doing zrele
(iput) in an async fashion, and zfs_resume_fs unlinked
drain processing will try to hash an inode that could
still be hashed, resulting in a panic.

Reviewed-by: Brian Behlendorf <behlendorf1@llnl.gov>
Reviewed-by: Alan Somers <asomers@gmail.com>
Signed-off-by: Paul Zuchowski <pzuchowski@datto.com>
Closes openzfs#9741
Closes openzfs#11223
Closes openzfs#11648
Closes openzfs#12210
@andybalholm
Copy link

I'm still getting the kernel panics even after the fix.

@PaulZ-98
Copy link
Contributor

I'm still getting the kernel panics even after the fix.

Can you post stack traces of your panic?

@andybalholm
Copy link

Yes:

2021-06-21T10:01:05.781542-07:00 system kernel: VERIFY3(insert_inode_locked(ip) == 0) failed (-16 == 0)
2021-06-21T10:01:05.781586-07:00 system kernel: PANIC at zfs_znode.c:612:zfs_znode_alloc()
2021-06-21T10:01:05.781602-07:00 system kernel: Showing stack for process 750
2021-06-21T10:01:05.781618-07:00 system kernel: CPU: 1 PID: 750 Comm: z_unlinked_drai Tainted: P           OE  ------------   3.10.0-1160.25.1.el7.x86_64 #1
2021-06-21T10:01:05.781634-07:00 system kernel: Hardware name: Micro-Star International Co., Ltd. MS-7C75/Z490-A PRO (MS-7C75), BIOS 2.10 05/21/2020
2021-06-21T10:01:05.781647-07:00 system kernel: Call Trace:
2021-06-21T10:01:05.781661-07:00 system kernel: [<ffffffffae98311a>] dump_stack+0x19/0x1b
2021-06-21T10:01:05.781674-07:00 system kernel: [<ffffffffc053fc5b>] spl_dumpstack+0x2b/0x30 [spl]
2021-06-21T10:01:05.781687-07:00 system kernel: [<ffffffffc053fd29>] spl_panic+0xc9/0x110 [spl]
2021-06-21T10:01:05.781700-07:00 system kernel: [<ffffffffae987192>] ? mutex_lock+0x12/0x2f
2021-06-21T10:01:05.781713-07:00 system kernel: [<ffffffffc06fc528>] ? dmu_buf_replace_user+0x68/0x90 [zfs]
2021-06-21T10:01:05.781726-07:00 system kernel: [<ffffffffae46c76b>] ? iput+0x3b/0x190
2021-06-21T10:01:05.781738-07:00 system kernel: [<ffffffffae46d0ec>] ? insert_inode_locked+0x1bc/0x1d0
2021-06-21T10:01:05.781754-07:00 system kernel: [<ffffffffc0819687>] zfs_znode_alloc+0x6b7/0x6c0 [zfs]
2021-06-21T10:01:05.781766-07:00 system kernel: [<ffffffffc081bef5>] zfs_zget+0x1c5/0x270 [zfs]
2021-06-21T10:01:05.781779-07:00 system kernel: [<ffffffffc0806f6e>] zfs_unlinked_drain_task+0x9e/0x110 [zfs]
2021-06-21T10:01:05.781792-07:00 system kernel: [<ffffffffae22b59e>] ? __switch_to+0xce/0x580
2021-06-21T10:01:05.781805-07:00 system kernel: [<ffffffffae988a77>] ? __schedule+0x3c7/0x870
2021-06-21T10:01:05.781817-07:00 system kernel: [<ffffffffae2d2b90>] ? task_rq_unlock+0x20/0x20
2021-06-21T10:01:05.781830-07:00 system kernel: [<ffffffffae5a616d>] ? list_del+0xd/0x30
2021-06-21T10:01:05.781843-07:00 system kernel: [<ffffffffae2c6a81>] ? remove_wait_queue+0x31/0x40
2021-06-21T10:01:05.781856-07:00 system kernel: [<ffffffffc05454f6>] taskq_thread+0x2c6/0x520 [spl]
2021-06-21T10:01:05.781870-07:00 system kernel: [<ffffffffae2dadf0>] ? wake_up_state+0x20/0x20
2021-06-21T10:01:05.781884-07:00 system kernel: [<ffffffffc0545230>] ? taskq_thread_spawn+0x60/0x60 [spl]
2021-06-21T10:01:05.781897-07:00 system kernel: [<ffffffffae2c5da1>] kthread+0xd1/0xe0
2021-06-21T10:01:05.781910-07:00 system kernel: [<ffffffffae2c5cd0>] ? insert_kthread_work+0x40/0x40
2021-06-21T10:01:05.781923-07:00 system kernel: [<ffffffffae995ddd>] ret_from_fork_nospec_begin+0x7/0x21
2021-06-21T10:01:05.781935-07:00 system kernel: [<ffffffffae2c5cd0>] ? insert_kthread_work+0x40/0x40

@PaulZ-98
Copy link
Contributor

Are you certain you're running with the fix? The insert_inode_locked() call is at line 618 of zfs_znode.c but this trace says line 612. Or maybe you have back-ported the fix and that's why the line numbers differ?

@andybalholm
Copy link

I built ZFS from commit afa7b34. The modification time of the installed module looks like it was from that build. But I didn't do make clean or anything; I just pulled and checked out the commit with the fix…

What should I do to ensure I'm actually running the correct version?

tonyhutter pushed a commit that referenced this issue Jun 23, 2021
In zfs_znode_alloc we always hash inodes.  If the
znode is unlinked, we do not need to hash it.  This
fixes the problem where zfs_suspend_fs is doing zrele
(iput) in an async fashion, and zfs_resume_fs unlinked
drain processing will try to hash an inode that could
still be hashed, resulting in a panic.

Reviewed-by: Brian Behlendorf <behlendorf1@llnl.gov>
Reviewed-by: Alan Somers <asomers@gmail.com>
Signed-off-by: Paul Zuchowski <pzuchowski@datto.com>
Closes #9741
Closes #11223
Closes #11648
Closes #12210
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Status: Triage Needed New issue which needs to be triaged Type: Defect Incorrect behavior (e.g. crash, hang)
Projects
None yet
Development

No branches or pull requests

6 participants