Biscync: panic: page 33 already freed

saltysyncs · September 18, 2024, 8:09am

What is the problem you are having with rclone?

Bisync results in error panic: page 33 already freed and hangs.

Run the command 'rclone version' and share the full output of the command.

rclone v1.68.0
- os/version: ubuntu 22.04 (64 bit)
- os/kernel: 5.15.0-121-generic (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.23.1
- go/linking: static
- go/tags: none

Which cloud storage system are you using? (eg Google Drive)

IDrive

The command you were trying to run (eg `rclone copy /tmp remote:tmp`)

First occurred resuming from hibernate during a run without --recover but log below is from using --resync instead:

rclone bisync "idrive-sync-hasher:/" "/home/salty/sync/" --check-access --fast-list --verbose --filter-from=/home/salty/.config/rclone/filters --links --compare size,modtime,checksum --log-file="$temp_log" --error-on-no-transfer --conflict-resolve newer --resilient --resync

Please run 'rclone config redacted' and share the full output. If you get command not found, please make sure to update rclone.

[idrive-sync]
type = s3
provider = IDrive
access_key_id = XXX
secret_access_key = XXX
acl = private
endpoint = x3k6.ie.idrivee2-50.com
bucket_acl = private
no_check_bucket = true
server_side_encryption = aws:kms

[idrive-sync-crypt]
type = crypt
remote = idrive-sync:sync
password = XXX
password2 = XXX
filename_encoding = base32768

[idrive-sync-hasher]
type = hasher
remote = idrive-sync-crypt:
hashes = md5
max_age = 3M
auto_size = 107374182400

A log from the command that you were trying to run with the `-vv` flag

2024/09/18 08:36:19 INFO  : Hasher is EXPERIMENTAL!
2024/09/18 08:36:19 NOTICE: bisync is IN BETA. Don't use in production!
2024/09/18 08:36:19 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": true,
	"HashType1": 1,
	"HashType2": 1,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2024/09/18 08:36:19 INFO  : Synching Path1 "idrive-sync-hasher:/" with Path2 "local{b6816}:/home/daire/sync/"
2024/09/18 08:36:19 INFO  : Copying Path2 files to Path1
2024/09/18 08:36:19 INFO  : Checking access health
2024/09/18 08:36:49 INFO  : Found 1 matching "RCLONE_TEST" files on both paths
2024/09/18 08:36:49 INFO  : - Path2    Resync is copying files to         - Path1
2024/09/18 08:37:19 INFO  : 
Transferred:   	          0 B / 0 B, -, 0 B/s, ETA -
Checks:                 2 / 2, 100%
Elapsed time:       1m0.0s

2024/09/18 08:38:19 INFO  : 
Transferred:   	          0 B / 0 B, -, 0 B/s, ETA -
Checks:              1309 / 2503, 52%
Elapsed time:       2m0.0s
Checking:
 * code/FinanceToolkit/Fi…nceToolkit-env/bin/ttx: checking
 * Education/mod1234/li…/java/client/Main.java: checking
 *                           code/gflows/LICENSE: checking
 *                          code/gflows/Procfile: checking
 *                         code/gflows/README.md: checking
 *                            code/gflows/app.py: checking
 * Education/mod1234/li…sses/client/Main.class: checking
 * Education/FYP/softhsm-…retest.vcxproj.filters: checking

panic: page 33 already freed

goroutine 15 [running]:
go.etcd.io/bbolt.(*freelist).free(0xc004134f00, 0x4a01f, 0x7fcb01d6c000)
	go.etcd.io/bbolt@v1.3.10/freelist.go:175 +0x2b4
go.etcd.io/bbolt.(*node).spill(0xc006ac9f10)
	go.etcd.io/bbolt@v1.3.10/node.go:363 +0x192
go.etcd.io/bbolt.(*node).spill(0xc006ac9ea0)
	go.etcd.io/bbolt@v1.3.10/node.go:350 +0x9e
go.etcd.io/bbolt.(*node).spill(0xc006ac9e30)
	go.etcd.io/bbolt@v1.3.10/node.go:350 +0x9e
go.etcd.io/bbolt.(*node).spill(0xc006ac9dc0)
	go.etcd.io/bbolt@v1.3.10/node.go:350 +0x9e
go.etcd.io/bbolt.(*node).spill(0xc006ac9d50)
	go.etcd.io/bbolt@v1.3.10/node.go:350 +0x9e
go.etcd.io/bbolt.(*Bucket).spill(0xc00096e440)
	go.etcd.io/bbolt@v1.3.10/bucket.go:592 +0x365
go.etcd.io/bbolt.(*Bucket).spill(0xc006dda478)
	go.etcd.io/bbolt@v1.3.10/bucket.go:559 +0x105
go.etcd.io/bbolt.(*Tx).Commit(0xc006dda460)
	go.etcd.io/bbolt@v1.3.10/tx.go:163 +0xf9
go.etcd.io/bbolt.(*DB).Update(0xc0000b6100?, 0xc007eb1e78)
	go.etcd.io/bbolt@v1.3.10/db.go:893 +0xca
github.com/rclone/rclone/lib/kv.(*DB).execute(0xc0000b6100, {0x2a61d10, 0x3e49a60}, {0x2a3ad60, 0xc006df0660}, 0x1)
	github.com/rclone/rclone/lib/kv/bolt.go:264 +0xa5
github.com/rclone/rclone/lib/kv.(*request).handle(0xc00096e3c0, {0x2a61d10?, 0x3e49a60?}, 0xc0000b6100)
	github.com/rclone/rclone/lib/kv/bolt.go:254 +0x1ee
github.com/rclone/rclone/lib/kv.(*DB).loop(0xc0000b6100)
	github.com/rclone/rclone/lib/kv/bolt.go:197 +0xf9
created by github.com/rclone/rclone/lib/kv.Start in goroutine 1
	github.com/rclone/rclone/lib/kv/bolt.go:108 +0x67b

How can I resolve this please?

nielash · September 18, 2024, 9:02am

This looks like an upstream bug in the bbolt package, which provides the database used by hasher. It looks like they are aware of it and have made some recent improvements:

github.com/etcd-io/bbolt

Refactor freelist management & add more dedicated tests

opened 02:43PM - 08 Jul 24 UTC

ahrtr

area/freelist

## Backgroud There are some long standing data corruption issues, which indicat…e that there might be potential bug(s) in freelist management. - https://github.com/etcd-io/bbolt/issues/778 - https://github.com/etcd-io/bbolt/issues/402 - https://github.com/etcd-io/bbolt/issues/705 - ... I am not satisfied with the bbolt freelist management for a long time. It's hard to understand and also tightly coupled with bbolt. I have been thinking to refactor it to improve the understandability & testability. ## Refactor The high level idea is to - simplify the implementation to improve **understandability**; - and introduce interface and decouple it with the bbolt TXN workflow to improve **testability**. What we have done and are going to do: - [x] https://github.com/etcd-io/bbolt/pull/777 - [x] https://github.com/etcd-io/bbolt/pull/783 - [x] https://github.com/etcd-io/bbolt/pull/775 - [x] https://github.com/etcd-io/bbolt/pull/788 - [x] https://github.com/etcd-io/bbolt/pull/792 - [ ] Simplify & update the logic related to the pending released free pages, refer to [doc](https://docs.google.com/spreadsheets/d/1T7ORCbv3mguq1hQoZkUg0XEzuUXFrNFFj1sUfQysZ2k/edit?gid=0#gid=0) We also need to continue to refactor & simplify the interface from user (bbolt) perspective, in other words, we should have a clear understanding on how the interface will & should be used by bbolt. The motivation is to improve testablity. The freelist management is the most sensitive & important part. So let's do it step by step. ## Test Any unit tests are welcome. But more importantly, we should add dedicated **randomized** test case to simulate **concurrent** (multiple) read TXNs and (single) writing TXN. - We need to record all the requests or operations sent to the freelist module; - We need to set up a list of expected behavior or invariable properties, and verify all the invariable properties are not broken during the test.

^I'm guessing this is what caused it in your case, as it appears to be related to database operations that get interrupted uncleanly, resulting in db corruption.

I wonder if updating the bbolt package to the latest version might help, given their recent fixes? I'm not sure if it will, but it might be worth a try.

Otherwise, I'm not sure if there is a solution other than resetting your hasher db

ncw · September 18, 2024, 12:55pm

Is there an fsck or repair for bolt DBs?

nielash · September 18, 2024, 1:46pm

Looks like maybe?

github.com/etcd-io/bbolt

Unexpected power down, bbolt db “failed to get all reachable pages”

opened 05:51AM - 07 Aug 22 UTC

closed 11:30AM - 30 Dec 22 UTC

superbool

After unexpected power down，my etcd can't restart。It seems that the bbolt db fil…e damaged，here is the fail log and the full db file： ``` panic: freepages: failed to get all reachable pages (page 8314893338927566090: out of bounds: 6258) goroutine 133 [running]: go.etcd.io/bbolt.(*DB).freepages.func2(0xc00047c420) /go/pkg/mod/go.etcd.io/bbolt@v1.3.6/db.go:1056 +0xe9 created by go.etcd.io/bbolt.(*DB).freepages /go/pkg/mod/go.etcd.io/bbolt@v1.3.6/db.go:1054 +0x1cd ``` https://github.com/superbool/test-bbolt/blob/99156f5928a5381779d50fa618f2de060b84d110/db Is there any possible repair the db file?

github.com/etcd-io/bbolt

bbolt CLI surgery commands

opened 11:27AM - 30 Dec 22 UTC

closed 12:48PM - 23 Oct 23 UTC

ptabor

help wanted area/bbolt-cli

After https://github.com/etcd-io/bbolt/pull/361 is submitted it would be good to… expose additional bbolt file 'surgery' commands: 1. `bbolt surgery revert-meta-page. db.inputFile db.outputFile` - should execute https://github.com/etcd-io/bbolt/blob/d13096eccc8deb93488897990957a8ac82df8ada/internal/surgeon/surgeon.go#L41 2. `bbolt surgery copy-page db.inputFile db.outputFile 17 14` - should execute https://github.com/etcd-io/bbolt/blob/d13096eccc8deb93488897990957a8ac82df8ada/internal/surgeon/surgeon.go#L10 3 `bbolt surgery write-empty-branch-page db.inputFile db.outputFile 17` - should execute a new command that overwites given page with an empty node. Follow up to: https://github.com/etcd-io/bbolt/issues/335

I am not very familiar with it, though.

darthShadow · September 18, 2024, 4:31pm

I wonder if it's worth trying to switch to sqlite instead. We now have CGo-free implementations of sqlite and they have pretty good performance.

saltysyncs · September 18, 2024, 5:47pm

If I rclone backend drop idrive-sync-hasher:/ will it just rebuild next time I run my bisync command or must I setup the hasher again as I did originally?

nielash · September 19, 2024, 6:53am

I think that should be enough, but I'm not 100% sure (it may be that the db is too corrupted to even get that far). If that doesn't work, what you may need to do is go into the cache directory (usually ~/.cache/rclone/kv/) and delete the corrupt hasher.bolt file.

Either way, yes, it should regenerate the sum cache next time, and you shouldn't have to mess with the config. You can also manually force it to refresh by running rclone hashsum MD5 --download idrive-sync-hasher:

ncw · September 19, 2024, 10:41am

Those tools look really low level, for use by bbolt experts only and are not at all the bbolt repair tool that users could actually use

That is a possibility... The repair tools are certainly better for sqlite. I wonder how the speed of sqlite compares against bbolt?

darthShadow · September 19, 2024, 12:59pm

In general and from previous such migrations, it should be equivalent to bbolt for reads (if not faster) and definitely faster for writes.

Shifting to sqlite will also allow other programs to interact with the DB directly bypassing rclone and will also allow multiple rclone processes to run simultaneously using the same DB, which is not possible with BoltDB.

There are some performance numbers available in these PRs, but I’m not sure how relevant they are:

bolt on master:
    lnd_payment_test.go:348: 	Benchmark info: Elapsed time:  41.977280583s
    lnd_payment_test.go:349: 	Benchmark info: TPS:  11.506224159637577

the branch as is:
    lnd_payment_test.go:348: 	Benchmark info: Elapsed time:  26.357677917s
    lnd_payment_test.go:349: 	Benchmark info: TPS:  18.324831251104936

synchronous=normal + fullfsync=true:
    lnd_payment_test.go:348: 	Benchmark info: Elapsed time:  1.956410833s
    lnd_payment_test.go:349: 	Benchmark info: TPS:  246.8806611847257

github.com/etcd-io/etcd

[WIP] (proof-of-concept) sqlite port of etcd

etcd-io:main ← logicalhan:sqlite

opened 01:33AM - 31 Jul 23 UTC

logicalhan

+2203 -560

[DO NOT MERGE] This is just a demonstrative PR, demonstrating the proof-of-conce…pt of: - extracting out bolt and putting it behind an interface - implementing the interface using bolt - implementing the interface using sqlite If you want to run etcd using sqlite, please apply [this patch](https://gist.github.com/logicalhan/e3a3c98024f0bdc998614295cf5d90aa) and run: - `make` - `rm -rf default.etcd` - `./bin/etcd` You can benchmark the performance of etcd using etcdctl by running `./bin/etcdctl check perf`. Note that this implementation of etcd-on-sqlite uses a pure golang version of sqlite, which is roughly half as fast as the full blown C implementation. Even so, the etcdctl performance tests suggest that the full golang version of sqlite seems roughly on par with bolt (if not a tad bit faster). For speed, we may want to consider using `github.com/mattn/go-sqlite3`, which compiles with CGO. However, this does break all of our build scripts and github actions since we presume that etcd can be compiled with CGO disabled. All github actions (unmodified) [are passing](https://github.com/logicalhan/etcd/actions?page=2).

Note that this implementation of etcd-on-sqlite uses a pure golang version of sqlite, which is roughly half as fast as the full blown C implementation. Even so, the etcdctl performance tests suggest that the full golang version of sqlite seems roughly on par with bolt (if not a tad bit faster).

That said, I doubt such numbers would matter for most rclone uses since we would be bottlenecked mostly by disk or network I/O.

ncw · September 19, 2024, 2:29pm

I've been keeping an eye on the modernc sqlite port for a long time now! It seems to be very good now with the benchmarks only 16% slower than the C version.

Once possible problem is the platform support which doesn't include all the platforms rclone supports.

I made a prototype for VFS2 which used bbolt for directory metadata and file metadata storage, but I'd much rather use sqlite for that...

darthShadow · September 20, 2024, 5:59am

It may be possible to use the WASM version for those platforms not supported by the modernc version. Theoretically, WASM should work on every platform.

This is the WASM version: GitHub - ncruces/go-sqlite3: Go bindings to SQLite using wazero

which uses: GitHub - tetratelabs/wazero: wazero: the zero dependency WebAssembly runtime for Go developers

Per their docs regarding the compiler:

It has zero dependencies, and doesn't rely on CGO.

This is done without host-specific dependencies.

system · October 1, 2024, 8:01am

This topic was automatically closed 3 days after the last reply. New replies are no longer allowed.

What is the problem you are having with rclone?

Run the command 'rclone version' and share the full output of the command.

Which cloud storage system are you using? (eg Google Drive)

The command you were trying to run (eg rclone copy /tmp remote:tmp)

Please run 'rclone config redacted' and share the full output. If you get command not found, please make sure to update rclone.

A log from the command that you were trying to run with the -vv flag

The command you were trying to run (eg `rclone copy /tmp remote:tmp`)

A log from the command that you were trying to run with the `-vv` flag