SOLVED Failed Local Replication on 11.3

[Jerami1981]

I am running 11.3 Release. I am attempting to replicate pool A (PhotoLibrary) to pool B (freenasty). Both pools are local to each other. Pool A is on the striped SSDs, and pool B is on the HDDs. I get the following error message when the replication takes place. "Replication "PhotoLibrary - freenasty" failed: cannot unmount '/var/db/system': Device busy warning:cannot send 'PhotoLibrary@auto-2020-02-02_00-00': signal received.

This is my first attempt at using replication, so it is possible I have something configured incorrectly. I used the replication wizard, and also double checked myself against the guide listed for 11.3 and everything seems to be in order.

System harware:
SuperMicro MBD-X11SPI-TF-O
Intel Xeon Silver 4110 Skylake 8-Core BX806734110
64 GB 2133 ECC Ram
HBA x2 LSI 9305 12 Gb/s
Mellanox MNPA19-XTR 10G

Pool A
Samsung 860 1TB x3 Striped

Pool B
RaidZ2
Vdev#1 x6 10TB WD
Vdev#2 x6 8TB WD & SG
Vdev#3 x6 4TB WD & SG
Vdev#4 x6 4TB WD & SG

 

[Jerami1981]

Still trying to figure this out. I came across some reading that sounds similar to my error, and possibly my use case.

"In FreeNAS, it is possible to replicate an entire volume recursively, s.t. the user doesn't have to create individual replication tasks for each dataset. However, this will not work out of the box, if the user wants to replicate the first FreeNAS volume to another first FreeNAS volume on a remote FreeNAS installation. By first FreeNAS volume i mean the first one you have created, or, in other words, the one in which FreeNAS has created the .system dataset.

What happens in this case, is that FreeNAS will create snapshots of the .system dataset as well, and will try to send that to the remote server's first FreeNAS volume. The remote system will try to unmount .system, and will fail."

I only have one dataset per pool. I am trying to replicate from one pool to the other pool. Is this simply not supported due to my file structure?

 

[Jerami1981]

I have managed to get the errors to stop, and now see a message under notifications that says Replication from A to B was successful. I am currently doing a snap shot on even days of the month, and replication on odd days. I have been error free for about 6 days now. Is there a way to validate the snapshots are actually replicating to the backup location? I am worried it is still not working, as when i look at the Replication task, under the Last Snapshot tab, it says No snapshots sent yet.

 

[irTwit]

Is there a way to validate the snapshots are actually replicating to the backup location? I am worried it is still not working, as when i look at the Replication task, under the Last Snapshot tab, it says No snapshots sent yet.

I'm also replicating between local pools. My replication tasks are showing Finished with the last snapshot name. You can look under the Storage>Snapshots page and look for the snapshots on the destination pool.

 

[Jerami1981]

attached are what I see on my replication task, periodic snapshot task, and then my storage/snapshots list. So snapshots are definitely being created, but nothing is being moved/replicated, and there are no errors. It’s probably something simple, but at this point I am at a loss for what it is.

 

[irTwit]

In your replication task page the "Last Snapshot" column should have the name of the last snapshot replicated. It doesn't' look like they are replicating. You can also turn on "Debug" logging in the replication task then run it manually to see if there any clues there.

Also, is the data in the "freenasty" pool only a backup the "PhotoLibrary"pool? If so, I would get rid of the periodic snapshot task for "freenasty".

 

[Jerami1981]

I will turn on debugging and see what comes from that. **Edit** it appears I still had debugging on from when I started troubleshooting this. However, these logs mean about as much as the original errors meant.

Freenasty is my primary storage pool for everything. In the same chassis, I have a small pool of ssds that i work off of for photography, that i would like to replicate to the freenasty pool on the same device, which then rsyncs a full backup to another server.

 

[Jerami1981]

Here are my configs for my replication, and snapshots. I have both snapshots take place one day, and the replication on the next. That seemed to get rid of the error I had originally. Maybe something in here isn’t set right?

 

[irTwit]

I would try manually creating a dataset under freenasty (ex. freenasty/photolibrary), and set that as your replication destination.

 

[Jerami1981]

I now have a dataset within Freenasty, called photolibrary, and pointed the replication task towards that. It errors out if i don't have Replicate Scratch selected. If i do select from scratch, it does not error, but also does not show anything replicated.

Code:

Error: Target dataset 'freenasty/Photolibrary' does not have snapshots but has data (180048 bytes used) and replication from scratch is not allowed. Refusing to overwrite existing data.

Logs :
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.1.async_exec.83] Running ['zfs', 'get', '-H', '-p', 'type', 'PhotoLibrary']
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.1.async_exec.83] Success: 'PhotoLibrary\ttype\tfilesystem\t-\n'
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.10.async_exec.84] Running ['zfs', 'get', '-H', '-p', 'type', 'freenasty/Photolibrary']
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.10.async_exec.84] Success: 'freenasty/Photolibrary\ttype\tfilesystem\t-\n'
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.1.async_exec.85] Running ['zfs', 'list', '-t', 'filesystem,volume', '-H', '-o', 'name', '-s', 'name', '-r', 'PhotoLibrary']
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.1.async_exec.85] Success: 'PhotoLibrary\n'
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.1.async_exec.86] Running ['zfs', 'list', '-t', 'snapshot', '-H', '-o', 'name', '-s', 'name', '-r', 'PhotoLibrary']
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.1.async_exec.86] Success: 'PhotoLibrary@auto-2020-04-04_0....Library@auto-2020-04-16_00-00\n'
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.10.async_exec.87] Running ['zfs', 'list', '-t', 'filesystem,volume', '-H', '-o', 'name,readonly', '-s', 'name', '-r', 'freenasty/Photolibrary']
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.10.async_exec.87] Success: 'freenasty/Photolibrary\toff\n'
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.10.async_exec.88] Running ['zfs', 'list', '-t', 'snapshot', '-H', '-o', 'name', '-s', 'name', '-r', 'freenasty/Photolibrary']
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.10.async_exec.88] Success: ''
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.10.async_exec.89] Running ['zfs', 'get', '-H', '-p', 'receive_resume_token', 'freenasty/Photolibrary']
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.10.async_exec.89] Success: 'freenasty/Photolibrary\treceive_resume_token\t-\t-\n'
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.10.async_exec.90] Running ['zfs', 'get', '-H', '-p', 'type,referenced,used', 'freenasty/Photolibrary']
[2020/04/16 18:44:40] DEBUG    [replication_task__task_5] [zettarepl.transport.local.shell.10.async_exec.90] Success: 'freenasty/Photolibrary\ttype\tfi....ty/Photolibrary\tused\t180048\t-\n'
[2020/04/16 18:44:40] ERROR    [replication_task__task_5] [zettarepl.replication.run] For task 'task_5' non-recoverable replication error ReplicationError("Target dataset 'freenasty/Photolibrary' does not have snapshots but has data (180048 bytes used) and replication from scratch is not allowed. Refusing to overwrite existing data.")

 

[irTwit]

I'm out of ideas. I had lots of trouble moving from the old SSH replication method to the LOCAL method.

If its any help this is how mine is set up. I use non-recursive snapshots and replications. Due to the way I layer my snapshot lifetimes I found it easier to use a set replication schedule vs. tying it to the snapshot task directly.

 

[Jerami1981]

So i have noticed it appears you have two datasets at the root of your storage. Where as, i have one main pool/dataset, and am trying to replicate to a sub, empty dataset. I wonder if that is why it will not work. I tried setting up a new rep task from scratch and matched yours, other than the dataset being its own pool, and it failed due to the dataset not being empty again.

 

[Jerami1981]

I added 2 drives in a mirror and made a new dataset on them, and still can't get the replication to work. If i select Replication from scratch, it finishes instantly, but sends no snapshots. If I uncheck scratch, the job fails saying there is data on the pool and won't overwrite it.

 

[Apollo]

Pool B (Freenasty) cannot have any recursive snapshot tasks of the pool if it is to receive snapshot from replication.

 

[Jerami1981]

I have removed all snapshots, and removed the recursive setting from the snapshot tasks. I have now pointed the replication task back to the Freenasty pool, and will update when things have run their course over the next couple of days. Thanks for the info!

 

[Jerami1981]

My snapshot task finished this morning, so i manually started my replication task. This is the log from that. It says Finished, but still shows no snapshots sent.

Code:

[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.1.async_exec.286] Running ['zfs', 'get', '-H', '-p', 'type', 'PhotoLibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.1.async_exec.286] Success: 'PhotoLibrary\ttype\tfilesystem\t-\n'
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.287] Running ['zfs', 'get', '-H', '-p', 'type', 'freenasty/Photolibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.287] Success: 'freenasty/Photolibrary\ttype\tfilesystem\t-\n'
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.1.async_exec.288] Running ['zfs', 'list', '-t', 'filesystem,volume', '-H', '-o', 'name', '-s', 'name', '-d', '1', 'PhotoLibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.1.async_exec.288] Success: 'PhotoLibrary\n'
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.1.async_exec.289] Running ['zfs', 'list', '-t', 'snapshot', '-H', '-o', 'name', '-s', 'name', '-d', '1', 'PhotoLibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.1.async_exec.289] Success: 'PhotoLibrary@auto-2020-04-26_00-00\n'
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.290] Running ['zfs', 'list', '-t', 'filesystem,volume', '-H', '-o', 'name,readonly', '-s', 'name', '-d', '1', 'freenasty/Photolibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.290] Success: 'freenasty/Photolibrary\toff\n'
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.291] Running ['zfs', 'list', '-t', 'snapshot', '-H', '-o', 'name', '-s', 'name', '-d', '1', 'freenasty/Photolibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.291] Success: ''
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.292] Running ['zfs', 'get', '-H', '-p', 'receive_resume_token', 'freenasty/Photolibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.292] Success: 'freenasty/Photolibrary\treceive_resume_token\t-\t-\n'
[2020/04/26 12:29:48] INFO     [replication_task__task_7] [zettarepl.replication.run] No snapshots to send for replication task 'task_7' on dataset 'PhotoLibrary'

 

[Apollo]

My snapshot task finished this morning, so i manually started my replication task. This is the log from that. It says Finished, but still shows no snapshots sent.

Code:

[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.1.async_exec.286] Running ['zfs', 'get', '-H', '-p', 'type', 'PhotoLibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.1.async_exec.286] Success: 'PhotoLibrary\ttype\tfilesystem\t-\n'
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.287] Running ['zfs', 'get', '-H', '-p', 'type', 'freenasty/Photolibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.287] Success: 'freenasty/Photolibrary\ttype\tfilesystem\t-\n'
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.1.async_exec.288] Running ['zfs', 'list', '-t', 'filesystem,volume', '-H', '-o', 'name', '-s', 'name', '-d', '1', 'PhotoLibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.1.async_exec.288] Success: 'PhotoLibrary\n'
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.1.async_exec.289] Running ['zfs', 'list', '-t', 'snapshot', '-H', '-o', 'name', '-s', 'name', '-d', '1', 'PhotoLibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.1.async_exec.289] Success: 'PhotoLibrary@auto-2020-04-26_00-00\n'
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.290] Running ['zfs', 'list', '-t', 'filesystem,volume', '-H', '-o', 'name,readonly', '-s', 'name', '-d', '1', 'freenasty/Photolibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.290] Success: 'freenasty/Photolibrary\toff\n'
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.291] Running ['zfs', 'list', '-t', 'snapshot', '-H', '-o', 'name', '-s', 'name', '-d', '1', 'freenasty/Photolibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.291] Success: ''
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.292] Running ['zfs', 'get', '-H', '-p', 'receive_resume_token', 'freenasty/Photolibrary']
[2020/04/26 12:29:48] DEBUG    [replication_task__task_7] [zettarepl.transport.local.shell.36.async_exec.292] Success: 'freenasty/Photolibrary\treceive_resume_token\t-\t-\n'
[2020/04/26 12:29:48] INFO     [replication_task__task_7] [zettarepl.replication.run] No snapshots to send for replication task 'task_7' on dataset 'PhotoLibrary'

Not sure what the problem is.
I went through your post and read the logs in more details and noticed replication is using Tokens to allow resuming where replication is left at when replication is interrupted for any reasons.

I haven't done any GUI driven replication, but I did play with token once or twice when it was first introduced to freenas/ZFS. I haven't made use of it since, but I would seem to remember, the token must be destroyed in order to get replication to work again, but I could be wrong here.

What I would try, is to always enable replication and if I am correct, only new scheduled snapshot task will trigger replication.
Replication task isn't run at will so, unless you have a limited window to transfer the snapshots, I would allow replication to take place as soon as possible.
Try to set your snapshot task to occur every day with a 5 minutes interval. This way you should be able to see some activity fairly quickly.

 

[Jerami1981]

Ok, so I removed all snapshots again. This time I only configured the for the photo library to start out with, and everything seems to be working. Posting my relevant config pages in case that helps anyone else out down the road.

A big thanks to everyone who contributed and gave me some different things to try out