zfs send -R core dumps ?
Chris Samuel
I'm trying to get out of a pickle when I did "zfs add" instead of
"zfs attach" and ended up adding a new drive as a stripe rather
than a mirror. :-(
I thought I'd follow what was done here:
http://opensolaris.org/jive/message.jspa?messageID=204770#204770
like this:
# zfs snapshot -r Backups@today
# zfs send -R Backups/etc@20080324-1552 | zfs recv -n -v -F -d Oops
cannot receive: failed to read from stream
If I try and send the snapshot to a file I get a core dump!
# zfs send -R Backups@today > /srv/backup/ZFS
Segmentation fault (core dumped)
gdb tells me:
(gdb) run send -R Backups@today > /srv/backup/ZFS
Starting program: /usr/local/sbin/zfs send -R Backups@today > /srv/backup/ZFS
[Thread debugging using libthread_db enabled]
[New Thread 0x7f472f279b20 (LWP 18582)]
Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7f472f279b20 (LWP 18582)]
0x00000000004219c6 in zfs_prop_readonly (prop=<value optimized out>)
at lib/libzfscommon/zfs_prop.c:375
375 return (zfs_prop_table[prop].pd_attr == PROP_READONLY ||
and the backtrace is:
(gdb) bt
#0 0x00000000004219c6 in zfs_prop_readonly (prop=<value optimized out>)
at lib/libzfscommon/zfs_prop.c:375
#1 0x000000000041c3e4 in send_iterate_fs (zhp=0x1f17480, arg=0x7fff3729cb20)
at lib/libzfs/libzfs_sendrecv.c:229
#2 0x000000000041ccaf in gather_nvlist (hdl=<value optimized out>,
fsname=<value optimized out>, fromsnap=0x0, tosnap=0x7fff3729fa38 "today",
nvlp=0x7fff3729cbe8, avlp=0x7fff3729cbe0)
at lib/libzfs/libzfs_sendrecv.c:330
#3 0x00000000004201b4 in zfs_send (zhp=0x1f14fd0, fromsnap=0x0,
tosnap=0x7fff3729fa38 "today", replicate=B_TRUE, doall=B_TRUE,
fromorigin=B_FALSE, verbose=B_FALSE, outfd=1)
at lib/libzfs/libzfs_sendrecv.c:704
#4 0x00000000004066ca in zfs_do_send (argc=<value optimized out>,
argv=0x7fff3729ead0) at cmd/zfs/zfs_main.c:2346
#5 0x000000000040593c in main (argc=4, argv=0x7fff3729eab8)
at cmd/zfs/zfs_main.c:4064
Build information:
Distro: KUbuntu Hardy Heron beta (8.04) (64-bit)
ZFS/FUSE: Current mercurial trunk.
GCC info:
Target: x86_64-linux-gnu
Configured
with: ../src/configure -v --enable-languages=c,c++,fortran,objc,obj-c++,treelang --prefix=/usr --enable-shared --with-system-zlib --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --enable-nls --with-gxx-include-dir=/usr/include/c++/4.2 --program-suffix=-4.2 --enable-clocale=gnu --enable-libstdcxx-debug --enable-objc-gc --enable-mpfr --enable-checking=release --build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu
Thread model: posix
gcc version 4.2.3 (Ubuntu 4.2.3-2ubuntu6)
I'll also log a bug about it.
cheers,
Chris
--
Chris Samuel : http://www.csamuel.org/ : Melbourne, VIC
This email may come with a PGP signature as a file. Do not panic.
For more info see: http://en.wikipedia.org/wiki/OpenPGP
Chris Samuel
> Thanks for reporting.
Not a problem - been out for a bit so haven't gotten around to lodging
a proper bug report. I can report that the same thing happens when
compiled with debug=2 to disable optimisation.
I do appear to be able to send a snapshot on its own (no -R flag)
without it crashing, it's only when I try and do a recursive send
it's a problem.
I've attached the output of "zfs list" in case that gives any clues.
> Would you mind giving the changeset ID?
> $ hg log | head
changeset: 330:02d648b1676c
tag: tip
parent: 328:f9497d34cff0
parent: 329:c7ef0056ea08
user: Ricardo Correia <rcor...@wizy.org>
date: Thu Mar 06 19:59:39 2008 +0000
summary: Fix compilation issues due to onnv_85 update.
I did an hg pull just in case and it told me there was nothing to do,
so it's still the current tip of trunk.
I've attached a full backtrace (8K) and I've noticed that four calls
down the stack in zfs_send() errbuff has something that says:
errbuf = "cannot
send 'Backups'\000\000\000<D0><D4>[\001", '\0' <repeats 12
times>, "\020<A5>S\234<FF>\177\000\000\001\000\000\000\000\000\000\000<F3>
<A4>S\234<FF>\177\000\000\030\000\000\0000\000\000\000p<A6>S\234<FF>\177\000\000<B0><A5>S\234<FF>\177\000\000<D8>\221<C7>\223<F0>\177\000\000\000\000\000\000\000\000\000\000<A0>\231<C7>\000\000\000\000\000
<DF>[\001\000\000\000\000\017", '\0' <repeats 11
times>, "<F8><FF><FF><FF><FF><FF><FF><FF>\000\000\000\000<F8><FF><FF><FF>\000\000\000\000@<D5>[\001\000\000\000\000<FF><FF><FF><FF>\000\000\000\000\r\2062\224<F0>\177\000\000\a\000\000\000\000\000\000\000@<AA>Q\224<F0>\177\000\000\001\000\000\000\000\000\000\000\006\000\000"...
but looking at the code in ./lib/libzfs/libzfs_sendrecv.c that appears
to be set up immediately the function is entered, presumably just in
case something does go wrong later.. :-)
Eric Anopolsky
Ok, prop=4294967295 is being used as an index into the zfs_prop_table
array, which is causing the segmentation fault. That value of prop came
from the zfs_name_to_prop function, which got it from the
zprop_name_to_prop function, which ends with the following line:
return (prop == ZPROP_CONT ? ZPROP_INVAL : prop);
ZPROP_INVAL is defined elsewhere to be -1, which is 4294967295 in this
case. The associated propname was "createtxg", but I'm not familiar with
this part of the code so I don't know if that should be a valid propname
or not.
However, returning ZPROP_INVAL almost certainly indicates an error
condition, and nothing is checking for that, so there's a bug that needs
to be fixed no matter what else may be wrong. At the very least, it
should die gracefully rather than segfaulting.
It's getting late. I'll look at this more tomorrow.
Cheers,
Eric
Chris Samuel
Hello Eric,
> ZPROP_INVAL is defined elsewhere to be -1, which is 4294967295 in
> this case. The associated propname was "createtxg", but I'm not
> familiar with this part of the code so I don't know if that should
> be a valid propname or not.
It appears to be meant to be a hidden property, ZFS_PROP_CREATETXG,
which is something to do with the absolute ordering of snapshots.
In ./src/lib/libzfs/libzfs_sendrecv.c it says:
/*
* Sort them according to creation time. We use the hidden
* CREATETXG property to get an absolute ordering of snapshots.
*/
lcreate = zfs_prop_get_int(l, ZFS_PROP_CREATETXG);
rcreate = zfs_prop_get_int(r, ZFS_PROP_CREATETXG);
I don't think this is the same as the creation times you can get by
doing "zfs get creation" as in ./src/lib/libzfscommon/include/sys/fs/zfs.h
there is both a ZFS_PROP_CREATION and ZFS_PROP_CREATETXG,
with the latter bearing the comment: /* not exposed to the user */
> However, returning ZPROP_INVAL almost certainly indicates an error
> condition, and nothing is checking for that, so there's a bug that
> needs to be fixed no matter what else may be wrong. At the very
> least, it should die gracefully rather than segfaulting.
Indeed!
> It's getting late. I'll look at this more tomorrow.
Thanks so much, very much appreciated!
If it helps I've logged the bug here:
https://developer.berlios.de/bugs/?func=detailbug&bug_id=13494&group_id=6836
Chris Samuel
> ZPROP_INVAL is defined elsewhere to be -1, which is 4294967295 in
> this case. The associated propname was "createtxg", but I'm not
> familiar with this part of the code so I don't know if that should
> be a valid propname or not.
Inserting some debugging fprintf()'s into function that eventually
gets called to match requested properties against the definitive list,
propname_match(), I can confirm that it doesn't find it in the list.
It's not because it's a hidden property because my check prints:
# Comparing iscsioptions to createtxg
and iscsioptions is set after createtxg here in zfs_prop.c:
/* hidden properties */
register_hidden(ZFS_PROP_CREATETXG, "createtxg", PROP_TYPE_NUMBER,
PROP_READONLY, ZFS_TYPE_DATASET, NULL);
register_hidden(ZFS_PROP_NUMCLONES, "numclones", PROP_TYPE_NUMBER,
PROP_READONLY, ZFS_TYPE_SNAPSHOT, NULL);
register_hidden(ZFS_PROP_NAME, "name", PROP_TYPE_STRING,
PROP_READONLY, ZFS_TYPE_DATASET, "NAME");
register_hidden(ZFS_PROP_ISCSIOPTIONS, "iscsioptions", PROP_TYPE_STRING,
PROP_INHERIT, ZFS_TYPE_VOLUME, "ISCSIOPTIONS");
Interestingly numclones doesn't appear in the list either, but name
and iscsioptions do.
The odd thing is that this all (to me) looks like it's in the upstream
OpenSolaris code, so I can't see how they wouldn't have the same
problem too (unless I'm missing something).
Chris Samuel
> register_hidden(ZFS_PROP_CREATETXG, "createtxg",
> PROP_TYPE_NUMBER, PROP_READONLY, ZFS_TYPE_DATASET, NULL);
The fix *appears* to be to change that last NULL element (the column
name I believe) to be "CREATETXG" (diff attached).
I'm still waiting for the snapshot to finish dumping (it's a 30GB file
system) so I can check that zfs recv can parse the dump and then it's
a question of restoring it to a test FS.
This is definitely in the OpenSolaris code:
http://src.opensolaris.org/source/xref/onnv/onnv-gate/usr/src/common/zfs/zfs_prop.c
so I still can't understand why this hasn't tripped them up.
The secondary bug is that send_iterate_prop() doesn't check that
zfs_name_to_prop() has returned ZPROP_INVAL and even if it did it's
a void function so it can't really return an error condition to
send_iterate_fs() (not that it's looking for errors either).
Worth punting back upstream to see what the Sun folks say ?
Chris Samuel
> I'm still waiting for the snapshot to finish dumping (it's a 30GB
> file system) so I can check that zfs recv can parse the dump and
> then it's a question of restoring it to a test FS.
No such luck:
root@quad:~# cat /srv/backup/ZFS | zfs recv -nvFd Oops
malloc: using debugging hooks
malloc: using debugging hooks
would receive full stream of Backups@today into Oops@today
would receive full stream of Backups/home@20070119-2352 into
Oops/home@20070119-2352
zfs: lib/libzfs/libzfs_sendrecv.c:1482: recv_skip: Assertion
`!"invalid record type"' failed.
Aborted (core dumped)
:-(
Chris Samuel
> I'm still waiting for the snapshot to finish dumping (it's a 30GB
> file system) so I can check that zfs recv can parse the dump and
> then it's a question of restoring it to a test FS.
OK - so that didn't work, but interestingly enough it appears to work
if I dump a ZFS filesystem rather than a pool.
# zfs send -R 'Backups/etc@today' > /srv/backup/ZFS-etc
# cat /srv/backup/ZFS-etc | zfs recv -vnFd Oops
would receive full stream of Backups/etc@20070119-2352 into Oops/etc@20070119-2352
would receive incremental stream of Backups/etc@20070120-2346 into Oops/etc@20070120-2346
would receive incremental stream of Backups/etc@20070121-2138 into Oops/etc@20070121-2138
would receive incremental stream of Backups/etc@20070123-2335 into Oops/etc@20070123-2335
would receive incremental stream of Backups/etc@20070125-0038 into Oops/etc@20070125-0038
would receive incremental stream of Backups/etc@20070125-1410 into Oops/etc@20070125-1410
would receive incremental stream of Backups/etc@20070131-2320 into Oops/etc@20070131-2320
would receive incremental stream of Backups/etc@20070212-2202 into Oops/etc@20070212-2202
would receive incremental stream of Backups/etc@20070216-2301 into Oops/etc@20070216-2301
would receive incremental stream of Backups/etc@20070218-1707 into Oops/etc@20070218-1707
would receive incremental stream of Backups/etc@20070305-2256 into Oops/etc@20070305-2256
would receive incremental stream of Backups/etc@20070316-1950 into Oops/etc@20070316-1950
would receive incremental stream of Backups/etc@20070316-2225 into Oops/etc@20070316-2225
would receive incremental stream of Backups/etc@20070324-1810 into Oops/etc@20070324-1810
would receive incremental stream of Backups/etc@20070518-2007 into Oops/etc@20070518-2007
would receive incremental stream of Backups/etc@20070603-1435 into Oops/etc@20070603-1435
would receive incremental stream of Backups/etc@20070620-2345 into Oops/etc@20070620-2345
would receive incremental stream of Backups/etc@20070702-2130 into Oops/etc@20070702-2130
would receive incremental stream of Backups/etc@20070714-1517 into Oops/etc@20070714-1517
would receive incremental stream of Backups/etc@20070723-2048 into Oops/etc@20070723-2048
would receive incremental stream of Backups/etc@20070814-2341 into Oops/etc@20070814-2341
would receive incremental stream of Backups/etc@20071025-2316 into Oops/etc@20071025-2316
would receive incremental stream of Backups/etc@20080324-1552 into Oops/etc@20080324-1552
would receive incremental stream of Backups/etc@today into Oops/etc@today
and doing it for real says:
# cat /srv/backup/ZFS-etc | zfs recv -vFd Oops
receiving full stream of Backups/etc@20070119-2352 into Oops/etc@20070119-2352
received 14.0MB stream in 1 seconds (14.0MB/sec)
receiving incremental stream of Backups/etc@20070120-2346 into Oops/etc@20070120-2346
received 297KB stream in 1 seconds (297KB/sec)
receiving incremental stream of Backups/etc@20070121-2138 into Oops/etc@20070121-2138
received 208KB stream in 1 seconds (208KB/sec)
receiving incremental stream of Backups/etc@20070123-2335 into Oops/etc@20070123-2335
received 424KB stream in 1 seconds (424KB/sec)
receiving incremental stream of Backups/etc@20070125-0038 into Oops/etc@20070125-0038
received 473KB stream in 1 seconds (473KB/sec)
receiving incremental stream of Backups/etc@20070125-1410 into Oops/etc@20070125-1410
received 133KB stream in 1 seconds (133KB/sec)
receiving incremental stream of Backups/etc@20070131-2320 into Oops/etc@20070131-2320
received 1.52MB stream in 1 seconds (1.52MB/sec)
receiving incremental stream of Backups/etc@20070212-2202 into Oops/etc@20070212-2202
received 879KB stream in 1 seconds (879KB/sec)
receiving incremental stream of Backups/etc@20070216-2301 into Oops/etc@20070216-2301
received 760KB stream in 1 seconds (760KB/sec)
receiving incremental stream of Backups/etc@20070218-1707 into Oops/etc@20070218-1707
received 349KB stream in 1 seconds (349KB/sec)
receiving incremental stream of Backups/etc@20070305-2256 into Oops/etc@20070305-2256
received 1.58MB stream in 1 seconds (1.58MB/sec)
receiving incremental stream of Backups/etc@20070316-1950 into Oops/etc@20070316-1950
received 638KB stream in 1 seconds (638KB/sec)
receiving incremental stream of Backups/etc@20070316-2225 into Oops/etc@20070316-2225
received 103KB stream in 1 seconds (103KB/sec)
receiving incremental stream of Backups/etc@20070324-1810 into Oops/etc@20070324-1810
received 847KB stream in 1 seconds (847KB/sec)
receiving incremental stream of Backups/etc@20070518-2007 into Oops/etc@20070518-2007
received 5.21MB stream in 2 seconds (2.60MB/sec)
receiving incremental stream of Backups/etc@20070603-1435 into Oops/etc@20070603-1435
received 1.26MB stream in 1 seconds (1.26MB/sec)
receiving incremental stream of Backups/etc@20070620-2345 into Oops/etc@20070620-2345
received 1.15MB stream in 1 seconds (1.15MB/sec)
receiving incremental stream of Backups/etc@20070702-2130 into Oops/etc@20070702-2130
received 753KB stream in 1 seconds (753KB/sec)
receiving incremental stream of Backups/etc@20070714-1517 into Oops/etc@20070714-1517
received 922KB stream in 1 seconds (922KB/sec)
receiving incremental stream of Backups/etc@20070723-2048 into Oops/etc@20070723-2048
received 610KB stream in 1 seconds (610KB/sec)
receiving incremental stream of Backups/etc@20070814-2341 into Oops/etc@20070814-2341
received 1.71MB stream in 2 seconds (875KB/sec)
receiving incremental stream of Backups/etc@20071025-2316 into Oops/etc@20071025-2316
received 6.73MB stream in 3 seconds (2.24MB/sec)
receiving incremental stream of Backups/etc@20080324-1552 into Oops/etc@20080324-1552
received 8.29MB stream in 2 seconds (4.15MB/sec)
receiving incremental stream of Backups/etc@today into Oops/etc@today
received 312B stream in 1 seconds (312B/sec)
UliM
On Mar 31, 12:34 pm, Chris Samuel <ch...@csamuel.org> wrote:
> On Sun, 30 Mar 2008, Chris Samuel wrote:
> > I'm still waiting for the snapshot to finish dumping (it's a 30GB
> > file system) so I can check that zfs recv can parse the dump and
> > then it's a question of restoring it to a test FS.
>
> OK - so that didn't work, but interestingly enough it appears to work
> if I dump a ZFS filesystem rather than a pool.
matter if I do "zfs send -R striped@bee >bla" or "zfs send -R striped/
bla@bee >bla".
zfs receive also works although when dumping the whole zpool i have to
destroy a file system for receiving (e.g. zfs create striped/
toreceive ; zfs receive -dF striped/toreceive <bla)
> 1KDownload