"Failed to set Modification time: Copy source too big" BackBlaze

Help and Support
1

While running a rclone copy job to back up files on a FreeNAS 11.1-U6 system to a BackBlaze account, I get this error warning:

...<snip>...
2019/10/17 10:51:05 ERROR : 0_Masters_All_Finished_Projects/The Treasure 4401/AE/MOV/THE_TREASURE_V01_101419.mov: Failed to set modification time: Copy source too big: 13225566937 (400 bad_request)
2019/10/17 10:51:45 INFO  : 
Transferred:       14.396G / 14.396 GBytes, 100%, 9.431 MBytes/s, ETA 0s
Errors:                 1 (retrying may help)
Checks:            776931 / 776931, 100%
Transferred:            1 / 1, 100%
Elapsed time:       26m3s

2019/10/17 10:52:02 INFO  : B2 bucket DawnSign-0001 path FreeNAS: Waiting for checks to finish
2019/10/17 10:52:02 INFO  : B2 bucket DawnSign-0001 path FreeNAS: Waiting for transfers to finish
2019/10/17 10:52:02 ERROR : B2 bucket DawnSign-0001 path FreeNAS: not deleting files as there were IO errors
2019/10/17 10:52:02 ERROR : B2 bucket DawnSign-0001 path FreeNAS: not deleting directories as there were IO errors
2019/10/17 10:52:02 ERROR : Attempt 2/3 failed with 2 errors and: not deleting files as there were IO errors
2019/10/17 10:52:45 INFO  : 
Transferred:       14.396G / 14.396 GBytes, 100%, 9.428 MBytes/s, ETA 0s
Errors:                 0
Checks:            890329 / 890329, 100%
Transferred:            1 / 1, 100%
Elapsed time:     26m3.6s

2019/10/17 10:53:45 INFO  : 
Transferred:       14.396G / 14.396 GBytes, 100%, 9.428 MBytes/s, ETA 0s
Errors:                 0
Checks:            890329 / 890329, 100%
Transferred:            1 / 1, 100%
Elapsed time:     26m3.6s

2019/10/17 10:54:45 INFO  : 
Transferred:       14.396G / 14.396 GBytes, 100%, 9.428 MBytes/s, ETA 0s
Errors:                 0
Checks:            890329 / 890329, 100%
Transferred:            1 / 1, 100%
Elapsed time:     26m3.6s

2019/10/17 10:55:45 INFO  : 
Transferred:       14.396G / 14.396 GBytes, 100%, 9.381 MBytes/s, ETA 0s
Errors:                 0
Checks:            958445 / 958446, 100%
Transferred:            1 / 1, 100%
Elapsed time:    26m11.4s
Checking:
 * 0_Masters_All_Finished…REASURE_V01_101419.mov: checking

2019/10/17 10:56:09 INFO  : B2 bucket DawnSign-0001 path FreeNAS: Waiting for checks to finish
2019/10/17 10:56:45 INFO  : 
Transferred:       14.396G / 14.396 GBytes, 100%, 9.036 MBytes/s, ETA 0s
Errors:                 0
Checks:           1335483 / 1335484, 100%
Transferred:            1 / 1, 100%
Elapsed time:    27m11.4s
Checking:
 * 0_Masters_All_Finished…REASURE_V01_101419.mov: checking

2019/10/17 10:57:17 ERROR : 0_Masters_All_Finished_Projects/The Treasure 4401/AE/MOV/THE_TREASURE_V01_101419.mov: Failed to set modification time: Copy source too big: 13225566937 (400 bad_request)
2019/10/17 10:57:17 INFO  : B2 bucket DawnSign-0001 path FreeNAS: Waiting for transfers to finish
2019/10/17 10:57:17 ERROR : B2 bucket DawnSign-0001 path FreeNAS: not deleting files as there were IO errors
2019/10/17 10:57:17 ERROR : B2 bucket DawnSign-0001 path FreeNAS: not deleting directories as there were IO errors
2019/10/17 10:57:17 ERROR : Attempt 3/3 failed with 2 errors and: not deleting files as there were IO errors
2019/10/17 10:57:17 Failed to sync with 2 errors: last error was: not deleting files as there were IO errors

I see that the file has been uploaded but it appears that the modification time is not updated. Then the rclone job aborts.

Script to run rclone as follows:

#!/bin/sh

src=/mnt/storage
dest=b2-backup:DawnSign-0001
fold=FreeNAS
log_level=INFO
log_time=`date "+%Y%m%d_%H:%M"`
log_path=/var/log
#log_file=/var/log/rclone.log
log_file=${log_path}/rclone-${log_time}.log
min_age=15m
#b2_chunk_size=190M
#b2_chunk_size=96M
b2_chunk_size=48M
transfers=20


/usr/local/bin/rclone sync \
    --copy-links \
    --b2-hard-delete \
    --fast-list \
    --exclude .DS_Store \
    --exclude-if-present .ignore \
    --min-age ${min_age} \
    --b2-chunk-size ${b2_chunk_size} \
    --transfers ${transfers} \
    --log-level ${log_level} \
    --log-file ${log_file} \
     ${src} ${dest}/${fold} $@
rc=$?

if [ $rc != 0 ]; then
#    echo "An error occurred. Please check the logs." | /usr/bin/mail -s "rclone backup error" ${email}
    touch /root/bin/B2-error-${log_time}.txt
    cat /root/bin/B2-error.txt > /root/bin/B2-error-${log_time}.txt
    cat ${log_file} >> /root/bin/B2-error-${log_time}.txt 
    cat /root/bin/B2-error-${log_time}.txt | /usr/local/bin/mini_sendmail -fadmin@example.com -smail.example.com ${email}

else
#    echo "Backup succeeded" | /usr/bin/mail -s "rclone backup success" ${email}
    touch /root/bin/B2-success-${log_time}.txt
    cat /root/bin/B2-success.txt > /root/bin/B2-success-${log_time}.txt
    cat ${log_file} >> /root/bin/B2-success-${log_time}.txt 
    cat /root/bin/B2-success-${log_time}.txt | /usr/local/bin/mini_sendmail -fadmin@example.com -smail.example.com ${email}
fi

I have two other rclone copy jobs quite identical to this one on another system and neither of them are failing. Granted that the files being copied there are much smaller than those on this system. I have another large file on this system which is 21GB (bigger than the one listed in the log listed above) and is also failing to update the modified time.

root@rclone:~/bin # rclone version
rclone v1.49.4

  • os/arch: freebsd/amd64
  • go version: go1.13.1

I've adjusted the chunk_size to no avail. Is this a known issue?

~Doug

2

You may be affected by this:
https://www.backblaze.com/b2/docs/large_files.html

There seems to be a 5GB max size on the backend for B2.
You might need to use the upcoming "chunker" backend (already in latest beta I think?) to work around this in a transparent manner - it basically saves very big files as multiple parts.
https://tip.rclone.org/chunker/

If you could do a test with uploading a file a bit smaller than 5GB, and one a bit larger than 5GB then this should confirm if this is the problem we are looking at...

@ncw Please do double-check me on this Nick because I won't want to mis-teach people :slight_smile:

3

I have installed the beta version of rclone and created a new remote overlay utilizing the same bucket. I am currently running the rclone sync. So far it appears to be working. All the files over 5GB appear to have been successfully uploaded.

I'm going to let it run overnight and report back any further issues.

Thank you!

~Doug

4

Did you actually check to verify the issue before you jumped to the conclusion? ... I would recommend that so we don't end up barking up the wrong tree.

Do note that the backend is in beta, so there may be bugs still. I'm sure NCW will appreciate any feedback on anything that needs fixing though. When it has made it in the beta builds it generally means that it's for the most part working as intended though and is unlikely to misbehave too badly.

5

Yes, as part of the test per your request, I found that any files exceeding 5GB failed to get uploaded. Actually the first file does get uploaded but its metadata wasn't being updated correctly. Any subsequent files exceeding 5GB failed to get uploaded. The clunker feature seems to have solved this particular issue.

Thanks!
~Doug

6

It is a relatively recent addition to b2 the ability to copy files. This is used to set modification times of files by rclone.

Rclone can upload large files bigger than GB just fine to b2, but it looks like there is a bug setting the modification times of these files.

Can you please make a new issue on github so we can fix that - thanks!

7

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.