On Feb 17, 2016, at 7:57 AM, Josh Fisher <jfisher AT pvct DOT com> wrote:

On 2/16/2016 6:59 PM, Dan Langille wrote:

On Feb 16, 2016, at 3:21 PM, Dan Langille <dan AT langille DOT org> wrote:

I can scp a 5GB Volume from one system to another in about 90 seconds.

Why does that take the SD 8-10 minutes to do the same?

The two systems are on the same 1Gb/s network.  We are copying from HDD local to SSD remote.

I'm running a copy job, from disk on one SD to tape on another SD.  Data spooling is enabled.

The full job can be seen here https://gist.github.com/dlangille/210fd8a8c3418f9004f6 :

15-Feb 13:32 crey-sd JobId 231187: Forward spacing Volume "FullAuto-3531" to file:block 0:216.
15-Feb 13:41 crey-sd JobId 231187: End of Volume at file 1 on device "vDrive-0" (/usr/local/bacula/volumes), Volume "FullAuto-3531"
15-Feb 13:41 crey-sd JobId 231187: Ready to read from volume "FullAuto-3534" on file device "vDrive-0" (/usr/local/bacula/volumes).
15-Feb 13:41 crey-sd JobId 231187: Forward spacing Volume "FullAuto-3534" to file:block 0:216.
15-Feb 13:51 crey-sd JobId 231187: End of Volume at file 1 on device "vDrive-0" (/usr/local/bacula/volumes), Volume "FullAuto-3534"
15-Feb 13:51 crey-sd JobId 231187: Ready to read from volume "FullAuto-3582" on file device "vDrive-0" (/usr/local/bacula/volumes).
15-Feb 13:51 crey-sd JobId 231187: Forward spacing Volume "FullAuto-3582" to file:block 0:216.
15-Feb 13:59 crey-sd JobId 231187: End of Volume at file 1 on device "vDrive-0" (/usr/local/bacula/volumes), Volume "FullAuto-3582"
15-Feb 13:59 crey-sd JobId 231187: Ready to read from volume "FullAuto-3594" on file device "vDrive-0" (/usr/local/bacula/volumes).
15-Feb 13:59 crey-sd JobId 231187: Forward spacing Volume "FullAuto-3594" to file:block 0:218.

Each volume is 5G and it's taking the SD nearly three times longer than scp to transfer.

As a test, I scp'd over all the volumes for one job and timed it:

real    167m15.956s

user    117m51.006s

sys     23m56.653s

FWIW, these copies were done while a ZFS scrub was underway, so if anything, the potential throughput is higher.

The job above, took nearly 11 hours.  Something is up.

I tried another test run, just now, but cancelled it after the first two Volumes were read; it was going at about the same rate as the full job mentioned above.

What might account for this vast difference?

You mention that data spooling is enabled, but what about attribute spooling? There are a lot of records being added to the catalog for a Copy job.