syncoid trying to send an older snapshot than the incremental point when using a bookmark

[Davis-A]

I've never used syncoid till today (and never used sanoid) and thought i'd give it a try.

I tried sending from my main server to another device on my network, previously i've done it manually by taking a dedicated snapshot to send, sending it, then bookmarking the dedicated snapshot on the sender (then deleting the snapshot). Today when trying out syncoid for the first time i got this:

andrew@bsd-nas ~> syncoid trinity/share/stuff root@relay:usb-zpool/stuff
Password:
Sending incremental trinity/share/stuff#'send-snapshot3' ... 2023-05-11_06.10.00--6m (~ UNKNOWN):
warning: cannot send 'trinity/share/stuff@2023-05-11_06.10.00--6m': not an earlier snapshot from the same fs
0.00 B 0:00:00 [0.00 B/s] [<=>                                                                                                                                                             ]cannot receive: failed to read from stream
CRITICAL ERROR: sudo zfs send  -i 'trinity/share/stuff'#'send-snapshot3' 'trinity/share/stuff'@'2023-05-11_06.10.00--6m' | pv -p -t -e -r -b -s 0 | lzop  | mbuffer  -q -s 128k -m 16M 2>/dev/null | ssh     -S /tmp/syncoid-root@relay-1699244576 root@relay ' mbuffer  -q -s 128k -m 16M 2>/dev/null | lzop -dfc |  zfs receive  -s -F '"'"'usb-zpool/stuff'"'"' 2>&1' failed: 256 at /usr/local/bin/syncoid line 745.

Lets look at that bookmark vs the snapshot

andrew@bsd-nas ~> zfs get creation,createtxg trinity/share/stuff'#'send-snapshot3
NAME                                PROPERTY   VALUE                  SOURCE
trinity/share/stuff#send-snapshot3  creation   Sat Jul 22  6:18 2023  -
trinity/share/stuff#send-snapshot3  createtxg  761679                 -                -

andrew@bsd-nas ~> zfs get creation,createtxg trinity/share/stuff@2023-05-11_06.10.00--6m
NAME                                         PROPERTY   VALUE                  SOURCE
trinity/share/stuff@2023-05-11_06.10.00--6m  creation   Thu May 11  6:10 2023  -
trinity/share/stuff@2023-05-11_06.10.00--6m  createtxg  688707                 -

The bookmark was created on a later transaction than the snapshot. syncoid has correctly identified that it needs to incrementally send from #send-snapshot3. The problem is it's trying to send a snapshot from a transaction earlier than the bookmark so zfs send is bailing out. I was able to solve this problem today by using --no-stream so it would send from the bookmark to the latest snapshot in only one send. But it was still surprising.

Here's a script which reproduces it from scratch:

truncate -s 16GB /root/send.img
truncate -s 16GB /root/receive.img

zpool create -o ashift=12 -O atime=off send /root/send.img
zpool create -o ashift=12 -O atime=off receive /root/receive.img
zfs create send/example

echo aaa > /send/example/a.txt
zfs snapshot send/example@a
echo bbb > /send/example/b.txt
zfs snapshot send/example@b

zfs send send/example@b | zfs receive receive/example
zfs bookmark send/example@b '#b'
zfs destroy send/example@b

echo ccc > /send/example/c.txt
zfs snapshot send/example@c

# will fail!
syncoid send/example receive/example

[Davis-A]

I started trying to debug this and i'm now not sure if my recreation script is reflective of whatever i hit. Yes, my recreation example hits it but that's because if you run the above commands in a script then snapshot a has the same creation time as bookmark b

# if intermediate snapshots are needed we need to find the next oldest snapshot,
# do an replication to it and replicate as always from oldest to newest
# because bookmark sends doesn't support intermediates directly
foreach my $snap ( sort { $snaps{'source'}{$a}{'creation'}<=>$snaps{'source'}{$b}{'creation'} } keys %{ $snaps{'source'} }) {
	if ($snaps{'source'}{$snap}{'creation'} >= $bookmarkcreation) {
		$nextsnapshot = $snap;
		last;
	}
}

So this piece of code doesn't handle the case of a snapshot and later bookmark being created at the same timestamp.... But that's not really reflective of what i encountered at the start of my bug report where their creations were months apart.

If i get time tomorrow i'll return back to my original setup and see what additional information i can figure out