Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

restic trying to get lock file that no longer exists #4515

Closed
awannabeengineer opened this issue Oct 13, 2023 · 0 comments · Fixed by #4520
Closed

restic trying to get lock file that no longer exists #4515

awannabeengineer opened this issue Oct 13, 2023 · 0 comments · Fixed by #4520

Comments

@awannabeengineer
Copy link
Contributor

Output of restic version

Two devices
wbe-pc: restic 0.16.0 compiled with go1.20.8 on linux/amd64
wbe-tp: restic 0.16.0 compiled with go1.20.8 on linux/amd64

How did you run restic exactly?

same commands were run on both devices

#!/bin/bash
export RESTIC_DEBUG=true
export DEBUG_LOG=restic-debug.log
/path/to/restic backup --password-file=/path/to/pass.txt --repo=rclone:r2:my-repo --verbose=2 /path/to/src
/path/to/restic forget --keep-daily=3 --keep-hourly=5 --keep-monthly=4 --keep-tag=forever --keep-weekly=4 --password-file=/path/to/pass.txt --path=/path/to/src --repo=rclone:r2:my-repo --verbose=2

What backend/server/service did you use to store the repository?

Cloudflare R2 configured with rclone

Expected behavior

Expected all restic commands on both devices to either acquire lock and complete or fail.

Actual behavior

restic continues retrying to load a lock file that no longer exists.

Steps to reproduce the behavior

I am able to reproduce the problem by running the above commands in "how did you run restic" section.
But this problem will not happen every time.

Do you have any idea what may have caused this?

A lock file that exists when restic calls GET /locks/ but is deleted before restic calls /locks/lock-id.
Logs and trace are attached at the end.

Some relevant parts of the logs are included here.

Part 1: wbe-pc saves lock/f813ae713d, does backup, deletes lock

Part 1 log 
2023/10/13 13:53:49 logger/log.go:59	logger.(*Backend).List	24	List(lock)
2023/10/13 13:53:49 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	24	------------  HTTP REQUEST -----------
GET /locks/ HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Accept-Encoding: gzip


2023/10/13 13:53:49 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	24	------------  HTTP RESPONSE ----------
HTTP/2.0 200 OK
Content-Length: 3
Accept-Ranges: bytes
Content-Type: application/vnd.x.restic.rest.v2
Date: Fri, 13 Oct 2023 18:53:49 GMT
Server: rclone/1.64.0


2023/10/13 13:53:49 rest/rest.go:384	rest.(*Backend).listv2	24	parsing API v2 response
2023/10/13 13:53:49 logger/log.go:61	logger.(*Backend).List	24	  list err <nil>
2023/10/13 13:53:49 restic/json.go:25	restic.SaveJSONUnpacked	1	save new blob lock
2023/10/13 13:53:49 logger/log.go:30	logger.(*Backend).Save	1	Save(<lock/f813ae713d>, 178)
2023/10/13 13:53:49 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	1	------------  HTTP REQUEST -----------
POST /locks/f813ae713de99d0a726541f99405657c639c9f53da53075891718a4c8e2c860a HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Content-Length: 178
Accept: application/vnd.x.restic.rest.v2
Content-Type: application/octet-stream
Accept-Encoding: gzip


2023/10/13 13:53:49 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	1	------------  HTTP RESPONSE ----------
HTTP/2.0 200 OK
Content-Length: 0
Accept-Ranges: bytes
Date: Fri, 13 Oct 2023 18:53:49 GMT
Server: rclone/1.64.0


2023/10/13 13:53:49 logger/log.go:32	logger.(*Backend).Save	1	  save err <nil>
2023/10/13 13:53:49 repository/repository.go:505	repository.(*Repository).SaveUnpacked	1	blob <lock/f813ae713d> saved
2023/10/13 13:53:49 logger/log.go:59	logger.(*Backend).List	43	List(lock)
2023/10/13 13:53:49 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	43	------------  HTTP REQUEST -----------
GET /locks/ HTTP/1.1
Host: lcalhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Accept-Encoding: gzip


2023/10/13 13:53:49 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	43	------------  HTTP RESPONSE ----------
HTTP/2.0 200 OK
Content-Length: 89
Accept-Ranges: bytes
Content-Type: application/vnd.x.restic.rest.v2
Date: Fri, 13 Oct 2023 18:53:49 GMT
Server: rclone/1.64.0


2023/10/13 13:53:49 rest/rest.go:384	rest.(*Backend).listv2	43	parsing API v2 response
2023/10/13 13:53:49 logger/log.go:61	logger.(*Backend).List	43	  list err <nil>
2023/10/13 13:53:49 restic/parallel.go:44	restic.ParallelList.func2	45	worker got file lock/f813ae71
2023/10/13 13:53:49 restic/lock.go:104	main.lockRepository	1	create lock 0xc0000f3880 (exclusive false)
2023/10/13 13:53:49 restic/lock.go:135	main.refreshLocks	49	start
2023/10/13 13:53:49 logger/log.go:59	logger.(*Backend).List	147	List(snapshot)
2023/10/13 13:53:49 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	147	------------  HTTP REQUEST -----------
GET /snapshots/ HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Accept-Encoding: gzip


2023/10/13 13:53:50 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	147	------------  HTTP RESPONSE ----------
HTTP/2.0 200 OK
Content-Length: 3917
Accept-Ranges: bytes
Content-Type: application/vnd.x.restic.rest.v2
Date: Fri, 13 Oct 2023 18:53:50 GMT
Server: rclone/1.64.0

2023/10/13 13:53:50 logger/log.go:32	logger.(*Backend).Save	1	  save err <nil>
2023/10/13 13:53:50 cache/file.go:82	cache.(*Cache).Save	1	Save to cache: <snapshot/e8898dcb11>
2023/10/13 13:53:50 repository/repository.go:505	repository.(*Repository).SaveUnpacked	1	blob <snapshot/e8898dcb11> saved
2023/10/13 13:53:50 restic/lock.go:158	main.refreshLocks	49	terminate
2023/10/13 13:53:50 restic/lock.go:146	main.refreshLocks.func1	49	unlocking repository with lock PID 941753 on wbe-pc by wbe (UID 1000, GID 1000)
lock was created at 2023-10-13 13:53:49 (1.605789258s ago)
storage ID f813ae71
2023/10/13 13:53:50 restic/lock.go:222	main.monitorLockRefresh	146	terminate expiry monitoring
2023/10/13 13:53:50 cache/backend.go:37	cache.(*Backend).Remove	49	cache Remove(<lock/f813ae713d>)
2023/10/13 13:53:50 logger/log.go:38	logger.(*Backend).Remove	49	Remove(<lock/f813ae713d>)
2023/10/13 13:53:50 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	49	------------  HTTP REQUEST -----------
DELETE /locks/f813ae713de99d0a726541f99405657c639c9f53da53075891718a4c8e2c860a HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Accept-Encoding: gzip


2023/10/13 13:53:50 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	49	------------  HTTP RESPONSE ----------
HTTP/2.0 200 OK
Accept-Ranges: bytes
Date: Fri, 13 Oct 2023 18:53:50 GMT
Server: rclone/1.64.0
Content-Length: 0


2023/10/13 13:53:50 logger/log.go:40	logger.(*Backend).Remove	49	  remove err <nil>
2023/10/13 13:53:50 restic/lock.go:300	main.unlockAll	1	unlocking 0 locks
2023/10/13 13:53:50 restic/cleanup.go:87	main.Exit	1	exiting with status code 0

Part 2: wbe-tp saves lock/e623a33a, sees lock/f813ae713d when listing locks, but can not access it when calling GET /lock/lock-id
since it has already been deleted by wbe-pc.

Part 2 log 
2023/10/13 13:53:49 logger/log.go:59	logger.(*Backend).List	75	List(lock)
2023/10/13 13:53:49 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	75	------------  HTTP REQUEST -----------
GET /locks/ HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Accept-Encoding: gzip


2023/10/13 13:53:49 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	75	------------  HTTP RESPONSE ----------
HTTP/2.0 200 OK
Content-Length: 89
Accept-Ranges: bytes
Content-Type: application/vnd.x.restic.rest.v2
Date: Fri, 13 Oct 2023 18:53:49 GMT
Server: rclone/1.64.0


2023/10/13 13:53:49 rest/rest.go:384	rest.(*Backend).listv2	75	parsing API v2 response
2023/10/13 13:53:49 logger/log.go:61	logger.(*Backend).List	75	  list err <nil>
2023/10/13 13:53:49 restic/parallel.go:44	restic.ParallelList.func2	80	worker got file lock/f813ae71
2023/10/13 13:53:49 repository/repository.go:176	repository.(*Repository).LoadUnpacked	80	load lock with id f813ae713de99d0a726541f99405657c639c9f53da53075891718a4c8e2c860a
2023/10/13 13:53:49 cache/file.go:38	cache.(*Cache).load	80	Load(<lock/f813ae713d>, 0, 0) from cache
2023/10/13 13:53:49 cache/backend.go:172	cache.(*Backend).Load	80	error loading <lock/f813ae713d> from cache: cannot be cached
2023/10/13 13:53:49 cache/backend.go:176	cache.(*Backend).Load	80	Load(<lock/f813ae713d>, 0, 0): delegating to backend
2023/10/13 13:53:49 logger/log.go:45	logger.(*Backend).Load	80	Load(<lock/f813ae713d>, length 0, offset 0)
2023/10/13 13:53:49 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	80	------------  HTTP REQUEST -----------
GET /locks/f813ae713de99d0a726541f99405657c639c9f53da53075891718a4c8e2c860a HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Range: bytes=0-


2023/10/13 13:53:50 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	80	------------  HTTP RESPONSE ----------
HTTP/2.0 206 Partial Content
Content-Length: 178
Accept-Ranges: bytes
Content-Range: bytes 0-177/178
Content-Type: application/octet-stream
Date: Fri, 13 Oct 2023 18:53:50 GMT
Server: rclone/1.64.0


2023/10/13 13:53:50 logger/log.go:47	logger.(*Backend).Load	80	  load err <nil>
2023/10/13 13:53:50 restic/json.go:25	restic.SaveJSONUnpacked	1	save new blob lock
2023/10/13 13:53:50 logger/log.go:30	logger.(*Backend).Save	1	Save(<lock/e623a33abd>, 179)
2023/10/13 13:53:50 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	1	------------  HTTP REQUEST -----------
POST /locks/e623a33abd60eba1e5d0fbc28fe815cb7deaa3efca33552590ede9974453ffee HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Content-Length: 179
Accept: application/vnd.x.restic.rest.v2
Content-Type: application/octet-stream
Accept-Encoding: gzip


2023/10/13 13:53:50 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	1	------------  HTTP RESPONSE ----------
HTTP/2.0 200 OK
Content-Length: 0
Accept-Ranges: bytes
Date: Fri, 13 Oct 2023 18:53:50 GMT
Server: rclone/1.64.0


2023/10/13 13:53:50 logger/log.go:32	logger.(*Backend).Save	1	  save err <nil>
2023/10/13 13:53:50 repository/repository.go:505	repository.(*Repository).SaveUnpacked	1	blob <lock/e623a33abd> saved
2023/10/13 13:53:50 logger/log.go:59	logger.(*Backend).List	57	List(lock)
2023/10/13 13:53:50 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	57	------------  HTTP REQUEST -----------
GET /locks/ HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Accept-Encoding: gzip


2023/10/13 13:53:50 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	57	------------  HTTP RESPONSE ----------
HTTP/2.0 200 OK
Content-Length: 176
Accept-Ranges: bytes
Content-Type: application/vnd.x.restic.rest.v2
Date: Fri, 13 Oct 2023 18:53:50 GMT
Server: rclone/1.64.0


2023/10/13 13:53:50 rest/rest.go:384	rest.(*Backend).listv2	57	parsing API v2 response
2023/10/13 13:53:50 logger/log.go:61	logger.(*Backend).List	57	  list err <nil>
2023/10/13 13:53:50 restic/parallel.go:44	restic.ParallelList.func2	62	worker got file lock/e623a33a
2023/10/13 13:53:50 restic/parallel.go:44	restic.ParallelList.func2	60	worker got file lock/f813ae71
2023/10/13 13:53:50 repository/repository.go:176	repository.(*Repository).LoadUnpacked	60	load lock with id f813ae713de99d0a726541f99405657c639c9f53da53075891718a4c8e2c860a
2023/10/13 13:53:50 cache/file.go:38	cache.(*Cache).load	60	Load(<lock/f813ae713d>, 0, 0) from cache
2023/10/13 13:53:50 cache/backend.go:172	cache.(*Backend).Load	60	error loading <lock/f813ae713d> from cache: cannot be cached
2023/10/13 13:53:50 cache/backend.go:176	cache.(*Backend).Load	60	Load(<lock/f813ae713d>, 0, 0): delegating to backend
2023/10/13 13:53:50 logger/log.go:45	logger.(*Backend).Load	60	Load(<lock/f813ae713d>, length 0, offset 0)
2023/10/13 13:53:50 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	60	------------  HTTP REQUEST -----------
GET /locks/f813ae713de99d0a726541f99405657c639c9f53da53075891718a4c8e2c860a HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Range: bytes=0-


2023/10/13 13:54:31 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	60	------------  HTTP RESPONSE ----------
HTTP/2.0 404 Not Found
Content-Length: 178
Accept-Ranges: bytes
Content-Range: bytes 0-177/178
Content-Type: text/plain; charset=utf-8
Date: Fri, 13 Oct 2023 18:54:31 GMT
Server: rclone/1.64.0
X-Content-Type-Options: nosniff


2023/10/13 13:54:31 debug/round_tripper.go:46	debug.(*eofDetectReader).Close	60	body not drained, 10 bytes not read, error: unexpected EOF, body: "Not Found\n": Close()
github.com/restic/restic/internal/debug.(*eofDetectReader).Close
 github.com/restic/restic/internal/debug/round_tripper.go:46
github.com/restic/restic/internal/backend/rest.(*Backend).openReader
 github.com/restic/restic/internal/backend/rest/rest.go:228
github.com/restic/restic/internal/backend/rest.(*Backend).Load
 github.com/restic/restic/internal/backend/rest/rest.go:176
github.com/restic/restic/internal/backend/sema.(*connectionLimitedBackend).Load
 github.com/restic/restic/internal/backend/sema/backend.go:95
github.com/restic/restic/internal/backend/logger.(*Backend).Load
 github.com/restic/restic/internal/backend/logger/log.go:46
github.com/restic/restic/internal/backend/retry.(*Backend).Load.func1
 github.com/restic/restic/internal/backend/retry/backend_retry.go:131
github.com/restic/restic/internal/backend/retry.retryNotifyErrorWithSuccess.func1
 github.com/restic/restic/internal/backend/retry/backend_retry.go:47
github.com/cenkalti/backoff/v4.RetryNotifyWithTimer.func1
 github.com/cenkalti/backoff/[email protected]/retry.go:18
github.com/cenkalti/backoff/v4.doRetryNotify[...]
 github.com/cenkalti/backoff/[email protected]/retry.go:88
github.com/cenkalti/backoff/v4.RetryNotifyWithTimer
 github.com/cenkalti/backoff/[email protected]/retry.go:61
github.com/cenkalti/backoff/v4.RetryNotify
 github.com/cenkalti/backoff/[email protected]/retry.go:49
github.com/restic/restic/internal/backend/retry.retryNotifyErrorWithSuccess
 github.com/restic/restic/internal/backend/retry/backend_retry.go:55
github.com/restic/restic/internal/backend/retry.(*Backend).retry
 github.com/restic/restic/internal/backend/retry/backend_retry.go:77
github.com/restic/restic/internal/backend/retry.(*Backend).Load
 github.com/restic/restic/internal/backend/retry/backend_retry.go:129
github.com/restic/restic/internal/cache.(*Backend).Load
 github.com/restic/restic/internal/cache/backend.go:177
github.com/restic/restic/internal/repository.(*Repository).LoadUnpacked
 github.com/restic/restic/internal/repository/repository.go:189
github.com/restic/restic/internal/restic.LoadJSONUnpacked
 github.com/restic/restic/internal/restic/json.go:14
github.com/restic/restic/internal/restic.LoadLock
 github.com/restic/restic/internal/restic/lock.go:371
github.com/restic/restic/internal/restic.ForAllLocks.func1
 github.com/restic/restic/internal/restic/lock.go:433
github.com/restic/restic/internal/restic.ParallelList.func2
 github.com/restic/restic/internal/restic/parallel.go:45
golang.org/x/sync/errgroup.(*Group).Go.func1
 golang.org/x/[email protected]/errgroup/errgroup.go:75
runtime.goexit
 runtime/asm_amd64.s:1598
2023/10/13 13:54:31 logger/log.go:47	logger.(*Backend).Load	60	  load err <lock/f813ae713d> does not exist
2023/10/13 13:54:31 restic/global.go:288	main.Warnf	60	Load(<lock/f813ae713d>, 0, 0) returned error, retrying after 625.752961ms: <lock/f813ae713d> does not exist

Part 3: wbe-pc starts second restic command but since wbe-tp has not removed lock/e623a33a, the command will eventually fail out.

Part 3 log 
2023/10/13 13:53:52 logger/log.go:59	logger.(*Backend).List	30	List(lock)
2023/10/13 13:53:52 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	30	------------  HTTP REQUEST -----------
GET /locks/ HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Accept-Encoding: gzip


2023/10/13 13:53:52 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	30	------------  HTTP RESPONSE ----------
HTTP/2.0 200 OK
Content-Length: 89
Accept-Ranges: bytes
Content-Type: application/vnd.x.restic.rest.v2
Date: Fri, 13 Oct 2023 18:53:52 GMT
Server: rclone/1.64.0


2023/10/13 13:53:52 rest/rest.go:384	rest.(*Backend).listv2	30	parsing API v2 response
2023/10/13 13:53:52 logger/log.go:61	logger.(*Backend).List	30	  list err <nil>
2023/10/13 13:53:52 restic/parallel.go:44	restic.ParallelList.func2	31	worker got file lock/e623a33a
2023/10/13 13:53:52 repository/repository.go:176	repository.(*Repository).LoadUnpacked	31	load lock with id e623a33abd60eba1e5d0fbc28fe815cb7deaa3efca33552590ede9974453ffee
2023/10/13 13:53:52 cache/file.go:38	cache.(*Cache).load	31	Load(<lock/e623a33abd>, 0, 0) from cache
2023/10/13 13:53:52 cache/backend.go:172	cache.(*Backend).Load	31	error loading <lock/e623a33abd> from cache: cannot be cached
2023/10/13 13:53:52 cache/backend.go:176	cache.(*Backend).Load	31	Load(<lock/e623a33abd>, 0, 0): delegating to backend
2023/10/13 13:53:52 logger/log.go:45	logger.(*Backend).Load	31	Load(<lock/e623a33abd>, length 0, offset 0)
2023/10/13 13:53:52 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	31	------------  HTTP REQUEST -----------
GET /locks/e623a33abd60eba1e5d0fbc28fe815cb7deaa3efca33552590ede9974453ffee HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Range: bytes=0-


2023/10/13 13:53:52 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	31	------------  HTTP RESPONSE ----------
HTTP/2.0 206 Partial Content
Content-Length: 179
Accept-Ranges: bytes
Content-Range: bytes 0-178/179
Content-Type: application/octet-stream
Date: Fri, 13 Oct 2023 18:53:52 GMT
Server: rclone/1.64.0


2023/10/13 13:53:52 logger/log.go:47	logger.(*Backend).Load	31	  load err <nil>
2023/10/13 13:53:52 restic/lock.go:79	main.lockRepository	1	repo already locked, retrying in 0s
2023/10/13 13:53:52 restic/lock.go:86	main.lockRepository	1	repo already locked, timeout expired
2023/10/13 13:53:52 logger/log.go:59	logger.(*Backend).List	85	List(lock)
2023/10/13 13:53:52 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	85	------------  HTTP REQUEST -----------
GET /locks/ HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Accept-Encoding: gzip


2023/10/13 13:53:52 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	85	------------  HTTP RESPONSE ----------
HTTP/2.0 200 OK
Content-Length: 89
Accept-Ranges: bytes
Content-Type: application/vnd.x.restic.rest.v2
Date: Fri, 13 Oct 2023 18:53:52 GMT
Server: rclone/1.64.0


2023/10/13 13:53:52 rest/rest.go:384	rest.(*Backend).listv2	85	parsing API v2 response
2023/10/13 13:53:52 logger/log.go:61	logger.(*Backend).List	85	  list err <nil>
2023/10/13 13:53:52 restic/parallel.go:44	restic.ParallelList.func2	90	worker got file lock/e623a33a
2023/10/13 13:53:52 repository/repository.go:176	repository.(*Repository).LoadUnpacked	90	load lock with id e623a33abd60eba1e5d0fbc28fe815cb7deaa3efca33552590ede9974453ffee
2023/10/13 13:53:52 cache/file.go:38	cache.(*Cache).load	90	Load(<lock/e623a33abd>, 0, 0) from cache
2023/10/13 13:53:52 cache/backend.go:172	cache.(*Backend).Load	90	error loading <lock/e623a33abd> from cache: cannot be cached
2023/10/13 13:53:52 cache/backend.go:176	cache.(*Backend).Load	90	Load(<lock/e623a33abd>, 0, 0): delegating to backend
2023/10/13 13:53:52 logger/log.go:45	logger.(*Backend).Load	90	Load(<lock/e623a33abd>, length 0, offset 0)
2023/10/13 13:53:52 debug/round_tripper.go:93	debug.loggingRoundTripper.RoundTrip	90	------------  HTTP REQUEST -----------
GET /locks/e623a33abd60eba1e5d0fbc28fe815cb7deaa3efca33552590ede9974453ffee HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Range: bytes=0-


2023/10/13 13:53:53 debug/round_tripper.go:110	debug.loggingRoundTripper.RoundTrip	90	------------  HTTP RESPONSE ----------
HTTP/2.0 206 Partial Content
Content-Length: 179
Accept-Ranges: bytes
Content-Range: bytes 0-178/179
Content-Type: application/octet-stream
Date: Fri, 13 Oct 2023 18:53:53 GMT
Server: rclone/1.64.0


2023/10/13 13:53:53 logger/log.go:47	logger.(*Backend).Load	90	  load err <nil>
2023/10/13 13:53:53 restic/lock.go:300	main.unlockAll	1	unlocking 0 locks
2023/10/13 13:53:53 restic/cleanup.go:87	main.Exit	1	exiting with status code 1

Do you have an idea how to solve the issue?

I think this problem might be addressed if there is no retry when Load() fails with noExistError.
I might be overlooking other factors. I would appericiate if anyone could tell me if this makes sense or point me in the right direction.

Did restic help you today? Did it make you happy in any way?

Despite this cahllenge, restic is what got me to try and setup proper backups on all my devices again. Overall, it has been way more fun than frustration compared to other solutions I've tried in the past. Thank you.

Logs

restic-trace.txt
restic-debug-wbe-tp.log
restic-debug-wbe-pc.log
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

retry: Do not retry Load() if file does not exist awannabeengineer/restic
1 participant
@awannabeengineer