Backblaze B2 stuck on "open repository"

alexwms · March 20, 2020, 1:36pm

For the past couple of months I was successfully able to run backups using restic to Backblaze B2. Yesterday when I tried to perform a backup, the terminal command gave me no output. So, I ran the command in verbose mode and the only output I got was open repository. I also back up to a local external drive and this is still operating normally. My issue may be the same as No output when backing up to Backblaze B2. After running pkill -6 restic, I get the following output:

open repository
SIGABRT: abort
PC=0x45d1f3 m=0 sigcode=0

goroutine 33 [syscall]:
runtime.notetsleepg(0x14bdcc0, 0x12a039bbc, 0x1)
	/usr/local/go/src/runtime/lock_futex.go:227 +0x34 fp=0xc00036a760 sp=0xc00036a730 pc=0x40aba4
runtime.timerproc(0x14bdca0)
	/usr/local/go/src/runtime/time.go:311 +0x2f1 fp=0xc00036a7d8 sp=0xc00036a760 pc=0x44c0c1
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc00036a7e0 sp=0xc00036a7d8 pc=0x45b2c1
created by runtime.(*timersBucket).addtimerLocked
	/usr/local/go/src/runtime/time.go:169 +0x10e

goroutine 1 [select]:
github.com/kurin/blazer/b2.withBackoff(0xf20fe0, 0xc00022e9c0, 0xf2cb00, 0xc0003f4090, 0xc00057c6c8, 0x0, 0x0)
	/restic/vendor/github.com/kurin/blazer/b2/backend.go:757 +0x177
github.com/kurin/blazer/b2.(*beBucket).downloadFileByName(0xc00014c7a0, 0xf20fe0, 0xc00022e9c0, 0xdca1b6, 0x6, 0x0, 0x1, 0xc00057c7c0, 0x40e7fb, 0xc0003f4088, ...)
	/restic/vendor/github.com/kurin/blazer/b2/backend.go:446 +0xf8
github.com/kurin/blazer/b2.(*Bucket).getObject(0xc0000a7200, 0xf20fe0, 0xc00022e9c0, 0xdca1b6, 0x6, 0xc82500, 0xc0002257d0, 0xc00057c800)
	/restic/vendor/github.com/kurin/blazer/b2/b2.go:616 +0x80
github.com/kurin/blazer/b2.(*Object).ensure(0xc00057c9a0, 0xf20fe0, 0xc00022e9c0, 0x20, 0x20)
	/restic/vendor/github.com/kurin/blazer/b2/b2.go:563 +0x72
github.com/kurin/blazer/b2.(*Object).Attrs(0xc00057c9a0, 0xf20fe0, 0xc00022e9c0, 0x0, 0x0, 0xdca1b6)
	/restic/vendor/github.com/kurin/blazer/b2/b2.go:443 +0x5d
github.com/restic/restic/internal/backend/b2.(*b2Backend).Stat(0xc000230400, 0xf20fe0, 0xc00022e9c0, 0xdca1b6, 0x6, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/restic/internal/backend/b2/b2.go:223 +0x179
main.open(0x7fff03b7910e, 0x13, 0x7fff03b7910e, 0x13, 0x0, 0x0, 0x7fff03b79156, 0x10, 0x0, 0x0, ...)
	/restic/cmd/restic/global.go:650 +0x533
main.OpenRepository(0x7fff03b7910e, 0x13, 0x0, 0x0, 0x7fff03b79156, 0x10, 0x0, 0x0, 0x0, 0x2, ...)
	/restic/cmd/restic/global.go:358 +0x96
main.runBackup(0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xc000222460, ...)
	/restic/cmd/restic/cmd_backup.go:413 +0x2da
main.glob..func2(0x14ab4e0, 0xc0003d0960, 0x4, 0xa, 0x0, 0x0)
	/restic/cmd/restic/cmd_backup.go:63 +0x1bf
github.com/spf13/cobra.(*Command).execute(0x14ab4e0, 0xc0003d0820, 0xa, 0xa, 0x14ab4e0, 0xc0003d0820)
	/restic/vendor/github.com/spf13/cobra/command.go:762 +0x460
github.com/spf13/cobra.(*Command).ExecuteC(0x14adfa0, 0xc000365eb0, 0x42d511, 0xe0fd98)
	/restic/vendor/github.com/spf13/cobra/command.go:852 +0x2ea
github.com/spf13/cobra.(*Command).Execute(...)
	/restic/vendor/github.com/spf13/cobra/command.go:800
main.main()
	/restic/cmd/restic/main.go:86 +0x3f

goroutine 6 [syscall]:
os/signal.signal_recv(0x0)
	/usr/local/go/src/runtime/sigqueue.go:147 +0x9c
os/signal.loop()
	/usr/local/go/src/os/signal/signal_unix.go:23 +0x22
created by os/signal.init.0
	/usr/local/go/src/os/signal/signal_unix.go:29 +0x41

goroutine 7 [chan receive]:
github.com/restic/restic/internal/restic.init.0.func1.1()
	/restic/internal/restic/lock.go:257 +0xb3
created by github.com/restic/restic/internal/restic.init.0.func1
	/restic/internal/restic/lock.go:254 +0x35

goroutine 17 [chan receive]:
github.com/restic/restic/internal/restic.init.2.func1(0xc00003a1e0)
	/restic/internal/restic/progress_unix.go:17 +0x63
created by github.com/restic/restic/internal/restic.init.2
	/restic/internal/restic/progress_unix.go:16 +0xab

goroutine 34 [select]:
go.opencensus.io/stats/view.(*worker).start(0xc000246690)
	/restic/vendor/go.opencensus.io/stats/view/worker.go:154 +0x100
created by go.opencensus.io/stats/view.init.0
	/restic/vendor/go.opencensus.io/stats/view/worker.go:32 +0x57

goroutine 35 [chan receive]:
main.CleanupHandler(0xc00021e720)
	/restic/cmd/restic/cleanup.go:62 +0x5d
created by main.init.0
	/restic/cmd/restic/cleanup.go:24 +0x67

goroutine 50 [select]:
github.com/restic/restic/internal/ui/termstatus.(*Terminal).run(0xc00012aa80, 0xf20fe0, 0xc00022ecc0)
	/restic/internal/ui/termstatus/status.go:98 +0x16e
github.com/restic/restic/internal/ui/termstatus.(*Terminal).Run(0xc00012aa80, 0xf20fe0, 0xc00022ecc0)
	/restic/internal/ui/termstatus/status.go:83 +0x7d
main.glob..func2.1(0x0, 0xcba900)
	/restic/cmd/restic/cmd_backup.go:61 +0x6d
gopkg.in/tomb%2ev2.(*Tomb).run(0xc0003f2000, 0xc0002285a0)
	/restic/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x2b
created by gopkg.in/tomb%2ev2.(*Tomb).Go
	/restic/vendor/gopkg.in/tomb.v2/tomb.go:159 +0xc7

rax    0xfffffffffffffffc
rbx    0x3b9873bc
rcx    0x45d1f3
rdx    0x0
rdi    0x14bdcc0
rsi    0x80
rbp    0xc00036a6e8
rsp    0xc00036a6a0
r8     0x0
r9     0x0
r10    0xc00036a6d8
r11    0x202
r12    0x1054c2ff967
r13    0x1
r14    0x1054c2ff967
r15    0x10
rip    0x45d1f3
rflags 0x202
cs     0x33
fs     0x0
gs     0x0

OS information:
Distributor ID: Ubuntu Description: Ubuntu 18.04 LTS (beaver-three-eyed-raven X92.1) Release: 18.04 Codename: bionic

I am running restic version 0.9.6 installed via snap.

Any help would be greatly appreciated!

rawtaz · March 20, 2020, 2:17pm

If this started happening out of the blue, something must have changed, and it’s not restic. The goal would be to isolate, identify and verify what has changed.

Thoughts:

What changed? OS upgrade/update? Network? ISP? Backblaze? Version of restic?
Contact Backblaze and ask them what they changed (assuming nothing else like your computer, network, ISP changed)?
Try rclone to see if the same problem persists (ideally coordinating this with the other chap who had the same/similar problem, if that hasn’t been done yet)?

MichaelEischer · March 20, 2020, 9:48pm

The stack traces look very similar to the one from the other forum topic, when comparing from downloadFileByName downwards.

The withBackoff function retries the request in an endless loop as long as backblaze tells it to try again later. At least that’s what should happen.

Taking a closer look at what’s happening would require a debug log of restic. The latter means building restic yourself, in case you’re willing to give it a try. There’s a relatively short description on how to create a debug build of restic at https://github.com/restic/restic/blob/master/CONTRIBUTING.md#reporting-bugs . If you need further explanations, feel free to ask.

From the debug log, the last “HTTP REQUEST” and “HTTP RESONSE” pair should suffice for debugging. Note: The debug log contains the backblaze auth token, account id, … in plaintext. Make sure to mask them before posting a log excerpt.

alexwms · March 20, 2020, 10:09pm

I am going to first do a debug build and post the results here. It may take me a little while to make progress. Things are a little hectic right now with work. Thanks for your responses.

alexwms · April 4, 2020, 12:23am

I tried running my backup script a week later and everything worked just fine. It seems like it must have been a temporary network issue or issue with Backblaze. Thanks for your advice.