Bug 182570 - [zfs] [patch] ZFS panic in receive
Summary: [zfs] [patch] ZFS panic in receive
Status: Closed FIXED
Alias: None
Product: Base System
Classification: Unclassified
Component: kern (show other bugs)
Version: Unspecified
Hardware: Any Any
: Normal Affects Only Me
Assignee: Andriy Gapon
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2013-10-02 12:50 UTC by Keith White
Modified: 2013-12-24 07:25 UTC (History)
0 users

See Also:


Attachments
file.diff (989 bytes, patch)
2013-10-02 12:50 UTC, Keith White
no flags Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Keith White 2013-10-02 12:50:03 UTC
[previously sent to freebsd-current]

I get the following reproducible panic when doing a zfs send -R | zfs recv
of a well churned file system (snapshots of the ports tree before and
after libiconv update) running a recent current:

panic: solaris assert: dn->dn_maxblkid == 0 &&
(BP_IS_HOLE(&dn->dn_phys->dn_blkptr[0]) || dnode_block_freed(dn, 0)),
file:
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dnode.c,
line: 598

coredump available.


# zfs list -t snapshot -r tank/ports
NAME                  USED  AVAIL  REFER  MOUNTPOINT
tank/ports@20130915  72.5M      -  3.64G  -
tank/ports@20130917      0      -  3.65G  -
tank/ports@20130918      0      -  3.65G  -
tank/ports@20130921  88.6M      -  3.66G  -
tank/ports@20130928   352K      -  3.66G  -

# zpool list -v
NAME             SIZE  ALLOC   FREE    CAP  DEDUP  HEALTH  ALTROOT
m_tank          1.81T   831G  1.00T    44%  1.00x  ONLINE  -
  ada4.nop.eli  1.81T   831G  1.00T         -
tank             928G   831G  96.9G    89%  1.00x  ONLINE  -
  ada3.nop.eli   928G   831G  96.9G         -

# zfs send -vR tank/ports@20130928 | zfs recv -vF m_tank/xports
.. panic eventually ...

# cd /boot/kernel; kgdb kernel /var/crash/vmcore.last
..
(kgdb) up
#5  0xffffffff81d09735 in dnode_reallocate (dn=0xfffff8006dde3000,
ot=DMU_OT_PLAIN_FILE_CONTENTS, blocksize=1024, bonustype=DMU_OT_SA,
bonuslen=168, tx=0xfffff8006d7a2600)
    at
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dnode.c:596


596                     ASSERT(dn->dn_maxblkid == 0 &&

(kgdb) p dn->dn_maxblkid
$1 = 2

So, no question about why the ASSERT failed.

Sorry, debugging this is *way* beyond me.  Any hints, patches to try?

Fix: This will just avoid the panic, the received filesystem is not complete.  The "zfs recv" now terminates with "internal error: File too large":

How-To-Repeat: on a zpool called "tank" with non-existent tank/nobj and tank/xobj:

#!/bin/sh

zfs create tank/nobj
zfs snapshot tank/nobj@0
__MAKECONF=/dev/null SRCCONF=/dev/null MAKEOBJDIRPREFIX=/tank/nobj make -j6 buildkernel
zfs snapshot tank/nobj@1
find /tank/nobj -name '.h' -print | xargs rm
zfs snapshot tank/nobj@2
rm -rf /tank/nobj/*
zfs snapshot tank/nobj@3
__MAKECONF=/dev/null SRCCONF=/dev/null MAKEOBJDIRPREFIX=/tank/nobj make -j6 buildkernel
zfs snapshot tank/nobj@4
rm -rf /tank/nobj/*
zfs snapshot tank/nobj@5

zfs send -vR tank/nobj@5 | zfs recv -vF tank/xobj
Comment 1 Keith White 2013-10-02 18:52:04 UTC
On Wed, 2 Oct 2013, FreeBSD-gnats-submit@FreeBSD.org wrote:

> Thank you very much for your problem report.
> It has the internal identification `kern/182570'.
> The individual assigned to look at your
> report is: freebsd-bugs.
>
> You can access the state of your problem report at any time
> via this link:
>
> http://www.freebsd.org/cgi/query-pr.cgi?pr=182570
>
>> Category:       kern
>> Responsible:    freebsd-bugs
>> Synopsis:       ZFS panic in receive
>> Arrival-Date:   Wed Oct 02 11:50:03 UTC 2013

Addendum:  The "how to repeat" section has an earlier version.  More success (err, repeatable failure) with this:

=== cut here ===
#!/bin/sh

zfs create tank/nobj
zfs snapshot tank/nobj@0
__MAKECONF=/dev/null SRCCONF=/dev/null MAKEOBJDIRPREFIX=/tank/nobj make -j6 buildkernel
zfs snapshot tank/nobj@1
#find /tank/nobj -name '.h' -print | xargs rm
zfs snapshot tank/nobj@2
#rm -rf /tank/nobj/*
zfs snapshot tank/nobj@3
__MAKECONF=/dev/null SRCCONF=/dev/null MAKEOBJDIRPREFIX=/tank/nobj make -j6 buildkernel
zfs snapshot tank/nobj@4
#rm -rf /tank/nobj/*
zfs snapshot tank/nobj@5

zfs send -vR tank/nobj@5 | zfs recv -vF tank/xobj

=== cut here ===

Missing from the report is a kernel backtrace:

=== cut here ===
# kgdb /boot/kernel/kernel /var/crash/vmcore.last
GNU gdb 6.1.1 [FreeBSD]
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "amd64-marcel-freebsd"...

Unread portion of the kernel message buffer:
panic: solaris assert: dn->dn_maxblkid == 0 && (BP_IS_HOLE(&dn->dn_phys->dn_blkptr[0]) || dnode_block_freed(dn, 0)), file: /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dnode.c, line: 598
cpuid = 1
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe00992b3280
kdb_backtrace() at kdb_backtrace+0x39/frame 0xfffffe00992b3330
vpanic() at vpanic+0x126/frame 0xfffffe00992b3370
panic() at panic+0x43/frame 0xfffffe00992b33d0
assfail() at assfail+0x22/frame 0xfffffe00992b33e0
dnode_reallocate() at dnode_reallocate+0x225/frame 0xfffffe00992b3430
dmu_object_reclaim() at dmu_object_reclaim+0x123/frame 0xfffffe00992b3480
dmu_recv_stream() at dmu_recv_stream+0xd79/frame 0xfffffe00992b36b0
zfs_ioc_recv() at zfs_ioc_recv+0x96c/frame 0xfffffe00992b3920
zfsdev_ioctl() at zfsdev_ioctl+0x54a/frame 0xfffffe00992b39c0
devfs_ioctl_f() at devfs_ioctl_f+0xf0/frame 0xfffffe00992b3a20
kern_ioctl() at kern_ioctl+0x2ca/frame 0xfffffe00992b3a90
sys_ioctl() at sys_ioctl+0x11f/frame 0xfffffe00992b3ae0
amd64_syscall() at amd64_syscall+0x265/frame 0xfffffe00992b3bf0
Xfast_syscall() at Xfast_syscall+0xfb/frame 0xfffffe00992b3bf0
--- syscall (54, FreeBSD ELF64, sys_ioctl), rip = 0x8019dc9ca, rsp = 0x7fffffff5ad8, rbp = 0x7fffffff5b60 ---
KDB: enter: panic
Uptime: 37m10s
Dumping 874 out of 2023 MB:

...

#0  doadump (textdump=1) at pcpu.h:218
218     pcpu.h: No such file or directory.
         in pcpu.h
(kgdb) where
#0  doadump (textdump=1) at pcpu.h:218
#1  0xffffffff808b7217 in kern_reboot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:447
#2  0xffffffff808b7725 in vpanic (fmt=<value optimized out>, ap=<value optimized out>) at /usr/src/sys/kern/kern_shutdown.c:754
#3  0xffffffff808b7773 in panic (fmt=<value optimized out>) at /usr/src/sys/kern/kern_shutdown.c:683
#4  0xffffffff81e52222 in assfail (a=<value optimized out>, f=<value optimized out>, l=<value optimized out>) at /usr/src/sys/modules/opensolaris/../../cddl/compat/opensolaris/kern/opensolaris_cmn_err.c:81
#5  0xffffffff81d09735 in dnode_reallocate (dn=0xfffff8006dde3000, ot=DMU_OT_PLAIN_FILE_CONTENTS, blocksize=1024, bonustype=DMU_OT_SA, bonuslen=168, tx=0xfffff8006d7a2600)
     at /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dnode.c:596
#6  0xffffffff81cff463 in dmu_object_reclaim (os=<value optimized out>, object=<value optimized out>, ot=DMU_OT_PLAIN_FILE_CONTENTS, blocksize=1024, bonustype=DMU_OT_SA, bonuslen=168)
     at /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_object.c:155
#7  0xffffffff81cfd849 in dmu_recv_stream (drc=0xfffffe00992b3728, fp=<value optimized out>, voffp=0xfffffe00992b3718, cleanup_fd=8, action_handlep=<value optimized out>)
     at /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_send.c:1231
#8  0xffffffff81d8b1fc in zfs_ioc_recv (zc=0xfffffe00372e1000) at /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_ioctl.c:4102
#9  0xffffffff81d864ea in zfsdev_ioctl (dev=<value optimized out>, zcmd=<value optimized out>, arg=<value optimized out>, flag=<value optimized out>, td=<value optimized out>)
     at /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_ioctl.c:5960
#10 0xffffffff807af840 in devfs_ioctl_f (fp=0xfffff800052e1460, com=3222821403, data=0xfffff8006ff1faa0, cred=<value optimized out>, td=0xfffff8003f7ba920) at /usr/src/sys/fs/devfs/devfs_vnops.c:757
#11 0xffffffff8090e94a in kern_ioctl (td=0xfffff8003f7ba920, fd=<value optimized out>, com=0) at file.h:319
#12 0xffffffff8090e62f in sys_ioctl (td=0xfffff8003f7ba920, uap=0xfffffe00992b3b80) at /usr/src/sys/kern/sys_generic.c:698
#13 0xffffffff80caee35 in amd64_syscall (td=0xfffff8003f7ba920, traced=0) at subr_syscall.c:134
#14 0xffffffff80c961ab in Xfast_syscall () at /usr/src/sys/amd64/amd64/exception.S:391
#15 0x00000008019dc9ca in ?? ()
Previous frame inner to this frame (corrupt stack?)
Current language:  auto; currently minimal

=== cut here ===


...keith
Comment 2 Keith White 2013-10-04 12:56:24 UTC
The following suggestion from Andrej Gapon fixes the problem for me:

> ...
> To me this looks very similar to a problem discovered and fixed in illumos some
> time ago.  Please check if the following change improves the situation for you.
>
> https://github.com/avg-I/freebsd/commit/a7e7dece215bc5d00077e9c7f4db34d9e5c30659
>
> Raw:
> https://github.com/avg-I/freebsd/commit/a7e7dece215bc5d00077e9c7f4db34d9e5c30659.patch
> ...

Once the patch is applied, "svn diff" gives:

Index: sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu.c
===================================================================
--- sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu.c	(revision 255986)
+++ sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu.c	(working copy)
@@ -677,6 +677,16 @@
   	if (err != 0)
   		return (err);
   	err = dmu_free_long_range_impl(os, dn, offset, length);
+
+	/*
+	 * It is important to zero out the maxblkid when freeing the entire
+	 * file, so that (a) subsequent calls to dmu_free_long_range_impl()
+	 * will take the fast path, and (b) dnode_reallocate() can verify
+	 * that the entire file has been freed.
+	 */
+	if (offset == 0 && length == DMU_OBJECT_END)
+		dn->dn_maxblkid = 0;
+
   	dnode_rele(dn, FTAG);
   	return (err);
   }
Index: sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_tx.c
===================================================================
--- sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_tx.c	(revision 255986)
+++ sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_tx.c	(working copy)
@@ -616,7 +616,7 @@
   	 */
   	if (dn->dn_datablkshift == 0) {
   		if (off != 0 || len < dn->dn_datablksz)
-			dmu_tx_count_write(txh, off, len);
+			dmu_tx_count_write(txh, 0, dn->dn_datablksz);
   	} else {
   		/* first block will be modified if it is not aligned */
   		if (!IS_P2ALIGNED(off, 1 << dn->dn_datablkshift))
Comment 3 Mark Linimon freebsd_committer freebsd_triage 2013-10-04 15:49:34 UTC
Responsible Changed
From-To: freebsd-bugs->freebsd-fs

Over to maintainer(s).
Comment 4 dfilter service freebsd_committer freebsd_triage 2013-10-10 10:53:54 UTC
Author: avg
Date: Thu Oct 10 09:53:46 2013
New Revision: 256259
URL: http://svnweb.freebsd.org/changeset/base/256259

Log:
  MFV r255257: 4082 zfs receive gets EFBIG from dmu_tx_hold_free()
  
    illumos change 14172:be36a38bac3d:
    illumos ZFS issues:
      4082 zfs receive gets EFBIG from dmu_tx_hold_free()
  
  Please note that this change is slightly different from r255257, because
  it is merged out of order with other (larger) upstream changes.
  
  PR:		kern/182570
  Reported by:	Keith White <kwhite@site.uottawa.ca>
  Tested by:	Keith White <kwhite@site.uottawa.ca>
  Approved by:	re (glebius)
  MFC after:	1 week
  X-MFC after:	r254753

Modified:
  head/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu.c
  head/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_tx.c
Directory Properties:
  head/sys/cddl/contrib/opensolaris/   (props changed)

Modified: head/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu.c
==============================================================================
--- head/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu.c	Thu Oct 10 09:43:15 2013	(r256258)
+++ head/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu.c	Thu Oct 10 09:53:46 2013	(r256259)
@@ -677,6 +677,16 @@ dmu_free_long_range(objset_t *os, uint64
 	if (err != 0)
 		return (err);
 	err = dmu_free_long_range_impl(os, dn, offset, length);
+
+	/*
+	 * It is important to zero out the maxblkid when freeing the entire
+	 * file, so that (a) subsequent calls to dmu_free_long_range_impl()
+	 * will take the fast path, and (b) dnode_reallocate() can verify
+	 * that the entire file has been freed.
+	 */
+	if (offset == 0 && length == DMU_OBJECT_END)
+		dn->dn_maxblkid = 0;
+
 	dnode_rele(dn, FTAG);
 	return (err);
 }

Modified: head/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_tx.c
==============================================================================
--- head/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_tx.c	Thu Oct 10 09:43:15 2013	(r256258)
+++ head/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_tx.c	Thu Oct 10 09:53:46 2013	(r256259)
@@ -616,7 +616,7 @@ dmu_tx_hold_free(dmu_tx_t *tx, uint64_t 
 	 */
 	if (dn->dn_datablkshift == 0) {
 		if (off != 0 || len < dn->dn_datablksz)
-			dmu_tx_count_write(txh, off, len);
+			dmu_tx_count_write(txh, 0, dn->dn_datablksz);
 	} else {
 		/* first block will be modified if it is not aligned */
 		if (!IS_P2ALIGNED(off, 1 << dn->dn_datablkshift))
_______________________________________________
svn-src-all@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/svn-src-all
To unsubscribe, send any mail to "svn-src-all-unsubscribe@freebsd.org"
Comment 5 Xin LI freebsd_committer freebsd_triage 2013-12-24 07:25:24 UTC
State Changed
From-To: open->closed

Mark as closed -- fix was committed by avg@. 


Comment 6 Xin LI freebsd_committer freebsd_triage 2013-12-24 07:25:24 UTC
Responsible Changed
From-To: freebsd-fs->avg

Assign.