restic: Write operations fail when talking to Synology NAS over SFTP

Output of restic version

Today’s tip of trunk

$ ./restic version
debug enabled
restic 0.2.0 (v0.2.0-176-g2635152)
compiled at 2016-08-28 16:09:23 with go1.6

Expected behavior

This is a follow up to issue #592 trying to get SFTP happy with the various errors from talking to my weird Synology NAS.

Basic read operations worked, but they had a problem with locking so I guess it was a problem writing.

So here I tried to create a new test repository.

Actual behavior

$ DEBUG_LOG=/tmp/restic-debug.log ./restic -r sftp:p4:test1 init
debug log file /tmp/restic-debug.log
debug enabled
panic: runtime error: index out of range

goroutine 1 [running]:
panic(0x9d8480, 0xc820010150)
    /usr/local/go/src/runtime/panic.go:464 +0x3e6
restic/debug.Log(0xaaa2d0, 0xa, 0x0, 0x0, 0x0, 0x0, 0x0)
    /tmp/restic-build-165477600/src/restic/debug/debug.go:149 +0xa19
restic/backend/sftp.(*SFTP).Close(0xc820131110, 0x0, 0x0)
    /tmp/restic-build-165477600/src/restic/backend/sftp/sftp.go:526 +0x6a
restic/backend/sftp.Create(0x7ffd7680f490, 0x5, 0xa95640, 0x3, 0xc82000af80, 0x3, 0x4, 0x3, 0x0, 0x0)
    /tmp/restic-build-165477600/src/restic/backend/sftp/sftp.go:182 +0x511
restic/backend/sftp.CreateWithConfig(0x0, 0x0, 0x7ffd7680f48d, 0x2, 0x7ffd7680f490, 0x5, 0x1, 0x0, 0x0)
    /tmp/restic-build-165477600/src/restic/backend/sftp/sftp.go:195 +0x222
main.create(0x7ffd7680f488, 0xd, 0x0, 0x0, 0x0, 0x0)
    /tmp/restic-build-165477600/src/cmds/restic/global.go:320 +0x9ae
main.CmdInit.Execute(0xd87960, 0xc820130870, 0x0, 0x3, 0x0, 0x0)
    /tmp/restic-build-165477600/src/cmds/restic/cmd_init.go:18 +0x169
main.(*CmdInit).Execute(0xc82002a088, 0xc820130870, 0x0, 0x3, 0x0, 0x0)
    <autogenerated>:32 +0xb9
github.com/jessevdk/go-flags.(*Parser).ParseArgs(0xc820014960, 0xc82000a3d0, 0x3, 0x3, 0x0, 0x0, 0x0, 0x0, 0x0)
    /tmp/restic-build-165477600/src/github.com/jessevdk/go-flags/parser.go:278 +0x8dd
github.com/jessevdk/go-flags.(*Parser).Parse(0xc820014960, 0x0, 0x0, 0x0, 0x0, 0x0)
    /tmp/restic-build-165477600/src/github.com/jessevdk/go-flags/parser.go:154 +0x9b
main.main()
    /tmp/restic-build-165477600/src/cmds/restic/main.go:32 +0x1ca

debug log:

2016/08/28 16:19:50 0.000 [    restic]   1 main.go:30 main []string{"./restic", "-r", "sftp:p4:test1", "init"}
2016/08/28 16:19:50 0.000 [      open]   1 global.go:308 parsing location sftp:p4:test1
2016/08/28 16:19:50 0.000 [      open]   1 global.go:319 create sftp repository at sftp.Config{User:"", Host:"p4", Dir:"test1"}
2016/08/28 16:19:50 0.000 [sftp.CreateWithConfig]   1 sftp.go:194 config { p4 test1}
2016/08/28 16:19:50 0.000 [          sftp.Create]   1 sftp.go:162 ssh [p4 -s sftp]

The directory does appear to exist on the disk with reasonable permissions, but it never asked me about a password.

wscott@p4:~$ ls -l test1
total 24
drwx------ 2 wscott users 4096 Aug 28 16:19 data
drwx------ 2 wscott users 4096 Aug 28 16:19 index
drwx------ 2 wscott users 4096 Aug 28 16:19 keys
drwx------ 2 wscott users 4096 Aug 28 16:19 locks
drwx------ 2 wscott users 4096 Aug 28 16:19 snapshots
drwx------ 2 wscott users 4096 Aug 28 16:19 tmp
wscott@p4:~$ ls -lR test1
test1:
total 24
drwx------ 2 wscott users 4096 Aug 28 16:19 data
drwx------ 2 wscott users 4096 Aug 28 16:19 index
drwx------ 2 wscott users 4096 Aug 28 16:19 keys
drwx------ 2 wscott users 4096 Aug 28 16:19 locks
drwx------ 2 wscott users 4096 Aug 28 16:19 snapshots
drwx------ 2 wscott users 4096 Aug 28 16:19 tmp

test1/data:
total 0

test1/index:
total 0

test1/keys:
total 0

test1/locks:
total 0

test1/snapshots:
total 0

test1/tmp:
total 0

It might again be the Synology to blame but again we are missing some error handling.