Weird exit message: snapshot saved, context canceled, exit code 1

Hi, I am running restic with sftp backend.
On large folder sets (500MB) it sometimes produces this error: context canceled.
However snapshot is being saved. Same thing I caught on S3 backend.
Basically I need exit code 0 to make sure it worked fine, for monitoring purposes.
Thank you.

restic 0.9.2 (v0.9.2-42-gd708d60) compiled with go1.9.4 on linux/amd64
+ restic.debug -r sftp:pathos.tanatos.org@pavel.wsynth.net:/home/pathos.tanatos.org/restic backup --files-from ./files --exclude-file ./excludes -v -v
debug enabled
open repository
lock repository
load index files
using parent snapshot 1e8be23c
start scan on [/var /home/fuck/btsync/encdroid.encdroid /usr/local /etc /opt /root]
start backup on [/var /home/fuck/btsync/encdroid.encdroid /usr/local /etc /opt /root]
modified  /etc/openvpn/openvpn-status.log, saved in 0.130s (427 B added)


Files:           0 new,     1 changed, 38165 unmodified
Dirs:            0 new,     0 changed,     4 unmodified
Data Blobs:      1 new
Tree Blobs:      1 new
Added to the repo: 2.487 KiB

processed 38166 files, 0 B in 0:55
snapshot f761efdb saved
context canceled

real	0m55.627s
user	0m39.956s
sys	0m2.012s
+ local EXIT_CODE=1

Debug log: https://pathos.tanatos.org/restic-debug.log ( 40MB)

P.S. purging ~/.cache/restic/ helps sometimes to get rid of context cancelled

Huh, that’s odd (and a bug). When restic backup runs, there are several processes running in the background. For example, the process which uploads intermediate index files. The message you see (“Context Cancelled”) means one of the background processes was told to terminate. This by itself isn’t a huge deal, but if it was requested to finish, it should exit gracefully. Apparently, the error (“Context Cancelled”) was passed up to the main function, which saw the error and exited with an error code.

I skimmed over the debug log but couldn’t see anything relevant, hm. You could try applying the following patch and see if we get a stack trace:

diff --git a/cmd/restic/main.go b/cmd/restic/main.go
index 01a902b1..53087465 100644
--- a/cmd/restic/main.go
+++ b/cmd/restic/main.go
@@ -88,8 +88,8 @@ func main() {
        switch {
        case restic.IsAlreadyLocked(errors.Cause(err)):
                fmt.Fprintf(os.Stderr, "%v\nthe `unlock` command can be used to remove stale locks\n", err)
-       case errors.IsFatal(errors.Cause(err)):
-               fmt.Fprintf(os.Stderr, "%v\n", err)
+       // case errors.IsFatal(errors.Cause(err)):
+       //      fmt.Fprintf(os.Stderr, "%v\n", err)
        case err != nil:
                fmt.Fprintf(os.Stderr, "%+v\n", err)

If you have the time, it’d be great if you could open an issue on the GitHub issue tracker. This is a bug and we need to track finding the cause :slight_smile:

It was indeed a bug, I’ve described the details here:

It’s resolved in https://github.com/restic/restic/pull/1991

1 Like