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.

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

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

Open
Daninet opened this issue Nov 17, 2024 · 8 comments
Labels
bug Something isn't working

Comments

@Daninet
Copy link

Daninet commented Nov 17, 2024

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 Daninet added the bug Something isn't working label Nov 17, 2024
@Daninet
Copy link
Author

Daninet commented Nov 17, 2024

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)
        

@garethgeorge
Copy link
Owner

garethgeorge commented Nov 18, 2024

Thanks for reporting this, I think we'll get a version bump to at least 1.68.2-r0
next time I publish a patch release https://pkgs.alpinelinux.org/package/edge/community/x86_64/rclone .

I'm expecting to run a patch release sometime either this week or early next, once I get a few more PRs in.

@nesalkiN
Copy link

nesalkiN commented Nov 19, 2024

Nice, thanks.

Is it possible to add and run start.sh (or something like that), that gets executed at container start?
I use rclone selfupdate in the container until upgrade.

@nesalkiN
Copy link

nesalkiN commented Nov 26, 2024

rclone still old verion in new release. :)

(also, no favicon for backrest or something on my side?)

@ovizii
Copy link

ovizii commented Dec 2, 2024

Thankfully I found this thread before I panicked and started debugging on my end 😂

@garethgeorge
Copy link
Owner

Thanks for calling out the missed upgrade -- I'm pretty surprised that the alpine package isn't using the latest version when running the docker build. If anyone sees an obvious issue with how rclone is being installed please let me know. The build script is running apk with --no-cache already so it should be getting the latest version.

I'll spent a bit of time looking at this before pushing out the next release.

@Daninet
Copy link
Author

Daninet commented Dec 6, 2024

I see that the Dockerfile has "FROM alpine:latest" that tracks the latest stable distro version that doesn't necessarily include the latest version from the packages. You would need to switch to "alpine:edge" to track those.
But this is not necessary anymore, because yesterday ,they released Alpine 3.21.0 which contains a new rclone version (1.68.2).
Old version package: link
New version package: link

@florianehmke
Copy link

I can confirm that updating fixes the problem. I was also affected by this, glad I don't have to look for another solution :).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

5 participants