search

garethgeorge / backrest

Backrest is a web UI and orchestrator for restic backup.
GNU General Public License v3.0
1.67k stars 47 forks source link

Rclone / OneDrive integration is unstable with rclone v1.66. Consider updating. #563

Open Daninet opened 2 hours ago

Daninet commented 2 hours ago

Hi devs! First of all, thank you for this awesome project!

I've ran into an issue with the latest Backrest v1.6.1 docker image. It has rclone v1.66.0 installed that has a randomly occurring bug in restic <-> rclone communication.

The error message looks like this:

command: /bin/restic-0.17.1 check -o sftp.args=-oBatchMode=yes
using temporary cache in /tmp/restic-check-cache-3523010399
create exclusive lock for repository
Load(<key/924efb6bc1>, 0, 0) failed: <key/924efb6bc1> does not exist
Load(<key/924efb6bc1>, 0, 0) failed: <key/924efb6bc1> does not exist
Fatal: <key/924efb6bc1> does not exist

The "924efb6bc1" file is there, just there is a communication error between restic and rclone.

It seems that the bug was fixed in rclone v1.67.0. Updating the rclone version in docker image fixes the issue on my computer. Please consider updating the docker image.

Thank you!

Daninet commented 2 hours ago

If anybody interested, here is the relevant part from restic debug log:


2024/11/17 20:45:46 rest/rest.go:398    rest.(*Backend).listv2  1       parsing API v2 response
2024/11/17 20:45:46 repository/key.go:145       repository.SearchKey.func1      1       trying key "924efb6bc1fb5cdce82fdb99ed549786c616addc3f608a070ce308a8495349ff"
2024/11/17 20:45:46 logger/log.go:45    logger.(*Backend).Load  1       Load(<key/924efb6bc1>, length 0, offset 0)
2024/11/17 20:45:46 sema/semaphore.go:27        sema.semaphore.GetToken 1       acquired token
2024/11/17 20:45:46 debug/round_tripper.go:93   debug.loggingRoundTripper.RoundTrip     1       ------------  HTTP REQUEST -----------
GET /keys/924efb6bc1fb5cdce82fdb99ed549786c616addc3f608a070ce308a8495349ff HTTP/1.1
Host: localhost
User-Agent: Go-http-client/1.1
Accept: application/vnd.x.restic.rest.v2
Range: bytes=0-

2024/11/17 20:45:47 debug/round_tripper.go:110  debug.loggingRoundTripper.RoundTrip     1       ------------  HTTP RESPONSE ----------
HTTP/2.0 404 Not Found
Content-Length: 454
Accept-Ranges: bytes
Content-Range: bytes 0-453/454
Content-Type: text/plain; charset=utf-8
Date: Sun, 17 Nov 2024 18:45:47 GMT
Last-Modified: Sun, 17 Nov 2024 12:44:43 GMT
Server: rclone/v1.66.0-DEV
X-Content-Type-Options: nosniff

2024/11/17 20:45:47 debug/round_tripper.go:46   debug.(*eofDetectReader).Close  1       body not drained, 0 bytes not read, error: unexpected EOF: Close()
github.com/restic/restic/internal/debug.(*eofDetectReader).Close
        /restic/internal/debug/round_tripper.go:46
github.com/restic/restic/internal/backend/rest.drainAndClose
        /restic/internal/backend/rest/rest.go:78
github.com/restic/restic/internal/backend/rest.(*Backend).openReader
        /restic/internal/backend/rest/rest.go:246
github.com/restic/restic/internal/backend/rest.(*Backend).Load
        /restic/internal/backend/rest/rest.go:199
github.com/restic/restic/internal/backend/sema.(*connectionLimitedBackend).Load
        /restic/internal/backend/sema/backend.go:95
github.com/restic/restic/internal/backend/logger.(*Backend).Load
        /restic/internal/backend/logger/log.go:46
github.com/restic/restic/internal/backend/retry.(*Backend).Load.func1
        /restic/internal/backend/retry/backend_retry.go:209
github.com/restic/restic/internal/backend/retry.(*Backend).retry.func1
        /restic/internal/backend/retry/backend_retry.go:132
github.com/restic/restic/internal/backend/retry.retryNotifyErrorWithSuccess.func1
        /restic/internal/backend/retry/backend_retry.go:53
github.com/cenkalti/backoff/v4.RetryNotifyWithTimer.Operation.withEmptyData.func1
        /home/build/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:18
github.com/cenkalti/backoff/v4.doRetryNotify[...]
        /home/build/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:88
github.com/cenkalti/backoff/v4.RetryNotifyWithTimer
        /home/build/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:61
github.com/cenkalti/backoff/v4.RetryNotify
        /home/build/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:49
github.com/restic/restic/internal/backend/retry.retryNotifyErrorWithSuccess
        /restic/internal/backend/retry/backend_retry.go:62
github.com/restic/restic/internal/backend/retry.(*Backend).retry
        /restic/internal/backend/retry/backend_retry.go:130
github.com/restic/restic/internal/backend/retry.(*Backend).Load
        /restic/internal/backend/retry/backend_retry.go:207
github.com/restic/restic/internal/repository.loadRaw
        /restic/internal/repository/raw.go:46
github.com/restic/restic/internal/repository.(*Repository).LoadRaw
        /restic/internal/repository/raw.go:19
github.com/restic/restic/internal/repository.LoadKey
        /restic/internal/repository/key.go:181
github.com/restic/restic/internal/repository.OpenKey
        /restic/internal/repository/key.go:66
github.com/restic/restic/internal/repository.SearchKey.func1
        /restic/internal/repository/key.go:146
github.com/restic/restic/internal/repository.SearchKey.(*Repository).List.func2
        /restic/internal/repository/repository.go:827
github.com/restic/restic/internal/backend/retry.(*Backend).List.func1.1
        /restic/internal/backend/retry/backend_retry.go:265
github.com/restic/restic/internal/backend/rest.(*Backend).listv2
        /restic/internal/backend/rest/rest.go:419
github.com/restic/restic/internal/backend/rest.(*Backend).List
        /restic/internal/backend/rest/rest.go:349
github.com/restic/restic/internal/backend/logger.(*Backend).List
        /restic/internal/backend/logger/log.go:60
github.com/restic/restic/internal/backend/retry.(*Backend).List.func1
        /restic/internal/backend/retry/backend_retry.go:259
github.com/restic/restic/internal/backend/retry.(*Backend).retry.func1
        /restic/internal/backend/retry/backend_retry.go:132
github.com/restic/restic/internal/backend/retry.retryNotifyErrorWithSuccess.func1
        /restic/internal/backend/retry/backend_retry.go:53
github.com/cenkalti/backoff/v4.RetryNotifyWithTimer.Operation.withEmptyData.func1
        /home/build/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:18
github.com/cenkalti/backoff/v4.doRetryNotify[...]
        /home/build/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:88
github.com/cenkalti/backoff/v4.RetryNotifyWithTimer
        /home/build/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.3.0/retry.go:61
2024/11/17 20:45:47 logger/log.go:47    logger.(*Backend).Load  1         load err <key/924efb6bc1> does not exist
2024/11/17 20:45:47 restic/global.go:254        main.Warnf      1       Load(<key/924efb6bc1>, 0, 0) failed: <key/924efb6bc1> does not exist
2024/11/17 20:45:47 logger/log.go:45    logger.(*Backend).Load  1       Load(<key/924efb6bc1>, length 0, offset 0)