Bisync performance difference R2 vs B2

tommodev · June 30, 2023, 4:36am

What is the problem you are having with rclone?

Observing a performance difference between Rclone bisync operation with the same payload (5.1GB of Bare Git Repos and Zotero Database). Does not appear to be bandwidth related (single large files under copy or sync ops have similar up/down between R2 and B2), appears to be calculations or diffing activity. Crypt is being used on both R2 and B2.

Not sure if expected difference in B2 vs R2 / S3 API so starting with post then will roll to GH issue if warranted.

bisync and bisync --resync operations for B2 are reasonably fast (approx 30s to 1m for bisync, 1-2 mins for --resync). However under R2 bisync takes 2-3 mins and bisync --resync takes up to 1hr to complete.

Looking at ~/<user>/.cache/rclone/bisync I can see it's populating the path1 and path2 entries, but even under -vv the --resync process doesn't offer a lot of information re: what is taking up the bulk of the runtime.

Noted in Docs that S3 is currently "first class" for bisync, however R2 and B2 might not be.

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

❯ rclone version
rclone v1.62.2
- os/version: ubuntu 23.04 (64 bit)
- os/kernel: 6.2.0-23-generic (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.20.2
- go/linking: dynamic
- go/tags: none

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

Cloudflare R2 with APAC region hinting
Backblaze B2 in US-WEST region

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

rclone bisync -vvv --progress r2-sync-crypt:sync/appdata /tmp/appdata

rclone bisync --resync -vvv --progress r2-sync-crypt:sync/appdata /tmp/appdata

The rclone config contents with secrets removed.

[b2-sync]
type = b2
account = xxx
key = xxx

[b2-sync-crypt]
type = crypt
remote = b2-sync:ws-sync
password = xxx
password2 = xxx

[r2-sync]
type = s3
provider = Cloudflare
access_key_id = xxx
secret_access_key = xxx
endpoint = https://xxx.r2.cloudflarestorage.com
acl = private
region = auto

[r2-sync-crypt]
type = crypt
remote = r2-sync:ws-sync
password = xxx
password2 = xxx

A log from the command with the `-vv` flag

b2-sync:

<7>DEBUG : rclone: Version "v1.62.2" starting with parameters ["rclone" "bisync" "-vv" "--progress" "/media/data/appdata" "b2-sync-crypt:sync/appdata"]
<7>DEBUG : rclone: systemd logging support activated
<7>DEBUG : Creating backend with remote "/media/data/appdata"
<7>DEBUG : Using config file from "/home/xxx/.config/rclone/rclone.conf"
<7>DEBUG : Creating backend with remote "b2-sync-crypt:sync/appdata"
<7>DEBUG : Creating backend with remote "b2-sync:ws-sync/int7gu1o361ro2ndsbil1dusak/cqgkblormbra8ijk66n1tineok"
<7>DEBUG : Couldn't decode error response: EOF
<5>NOTICE: bisync is EXPERIMENTAL. Don't use in production!
2023-06-30 13:47:44 DEBUG : Lock file created: /home/xxx/.cache/rclone/bisync/media_data_appdata..b2-sync-crypt_sync_appdata.lck
2023-06-30 13:47:44 INFO  : Synching Path1 "/media/data/appdata/" with Path2 "b2-sync-crypt:sync/appdata/"
2023-06-30 13:47:44 INFO  : Path1 checking for diffs
2023-06-30 13:48:16 INFO  : Path2 checking for diffs
2023-06-30 13:48:22 INFO  : No changes found
2023-06-30 13:48:22 INFO  : Updating listings
2023-06-30 13:48:22 INFO  : Validating listings for Path1 "/media/data/appdata/" vs Path2 "b2-sync-crypt:sync/appdata/"
2023-06-30 13:48:23 DEBUG : Lock file removed: /home/xxx/.cache/rclone/bisync/media_data_appdata..b2-sync-crypt_sync_appdata.lck
2023-06-30 13:48:23 INFO  : Bisync successful
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:        40.5s
<6>INFO  :
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:        40.5s

<7>DEBUG : 6 go routines active

b2-resync:

<7>DEBUG : rclone: Version "v1.62.2" starting with parameters ["rclone" "bisync" "-vv" "/media/data/appdata" "b2-sync-crypt:sync/appdata"]
<7>DEBUG : rclone: systemd logging support activated
<7>DEBUG : Creating backend with remote "/media/data/appdata"
<7>DEBUG : Using config file from "/home/xxx/.config/rclone/rclone.conf"
<7>DEBUG : Creating backend with remote "b2-sync-crypt:sync/appdata"
<7>DEBUG : Creating backend with remote "b2-sync:ws-sync/int7gu1o361ro2ndsbil1dusak/cqgkblormbra8ijk66n1tineok"
<7>DEBUG : Couldn't decode error response: EOF
<5>NOTICE: bisync is EXPERIMENTAL. Don't use in production!
<7>DEBUG : Lock file created: /home/xxx/.cache/rclone/bisync/media_data_appdata..b2-sync-crypt_sync_appdata.lck
<6>INFO  : Synching Path1 "/media/data/appdata/" with Path2 "b2-sync-crypt:sync/appdata/"
<6>INFO  : Path1 checking for diffs
<6>INFO  : Path2 checking for diffs
<6>INFO  : No changes found
<6>INFO  : Updating listings
<6>INFO  : Validating listings for Path1 "/media/data/appdata/" vs Path2 "b2-sync-crypt:sync/appdata/"
<7>DEBUG : Lock file removed: /home/xxx/.cache/rclone/bisync/media_data_appdata..b2-sync-crypt_sync_appdata.lck
<6>INFO  : Bisync successful
<6>INFO  :
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:        48.8s

<7>DEBUG : 6 go routines active

r2-resync:

<7>DEBUG : rclone: Version "v1.62.2" starting with parameters ["rclone" "bisync" "--resync" "-vv" "r2-sync-crypt:sync/appdata" "/tmp/appdata"]
<7>DEBUG : rclone: systemd logging support activated
<7>DEBUG : Creating backend with remote "r2-sync-crypt:sync/appdata"
<7>DEBUG : Using config file from "/home/tommo/.config/rclone/rclone.conf"
<7>DEBUG : Creating backend with remote "r2-sync:ws-sync/int7gu1o361ro2ndsbil1dusak/cqgkblormbra8ijk66n1tineok"
<7>DEBUG : Resolving service "s3" region "auto"
<7>DEBUG : Creating backend with remote "/tmp/appdata"
<5>NOTICE: bisync is EXPERIMENTAL. Don't use in production!
<7>DEBUG : Lock file created: /home/tommo/.cache/rclone/bisync/r2-sync-crypt_sync_appdata..tmp_appdata.lck
<6>INFO  : Synching Path1 "r2-sync-crypt:sync/appdata/" with Path2 "/tmp/appdata/"
<6>INFO  : Copying unique Path2 files to Path1
<6>INFO  :
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:       1m0.5s

<6>INFO  :
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:       2m0.5s

<6>INFO  :
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:       3m0.5s

<6>INFO  :
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:       4m0.5s

<Continues up to ~1HR>

ncw · June 30, 2023, 4:52pm

Try running with -vv --dump headers and that will show HTTP transactions which might give a clue what is going on.

tommodev · June 30, 2023, 11:35pm

Thank you! Ok couple of steps, setting up on a new box for testing.

Initial R2 setup and resync

Copied the R2 remote to local and ran bisync --resync, the checks finished at approx. 30 min mark then process continued to run until 1hr. Paste below:

datbox:/dat/appdata# rclone bisync --resync --progress /dat/appdata r2-sync-crypt:sync/appdata
2023/06/30 22:09:58 NOTICE: bisync is EXPERIMENTAL. Don't use in production!
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Checks:              6446 / 6446, 100%
Elapsed time:     51m38.4s

Exec R2 bisync w/ dump headers

Running bisync with --dump headers:

Around the 5min mark:

2023-06-30 23:07:03 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-06-30 23:07:03 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-06-30 23:07:03 DEBUG : HTTP RESPONSE (req 0xc000e1a900)
2023-06-30 23:07:03 DEBUG : HTTP/1.1 200 OK
Content-Length: 27740
Accept-Ranges: bytes
Cf-Ray: 7dfa10313fe2555d-SYD
Connection: keep-alive
Content-Type: application/octet-stream
Date: Fri, 30 Jun 2023 23:07:03 GMT
Etag: "dca46fd11e22bd5deee68018eef18b9c"
Last-Modified: Fri, 30 Jun 2023 20:50:33 GMT
Server: cloudflare
X-Amz-Meta-Mtime: 1688101188.184
2023-06-30 23:07:03 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-06-30 23:07:03 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-06-30 23:07:03 DEBUG : HTTP REQUEST (req 0xc000e1ae00)
2023-06-30 23:07:03 DEBUG : HEAD /ws-sync/int7gu1o361ro2ndsbil1dusak/cqgkblormbra8ijk66n1tineok/2qkeq15j6dpk1opqveujhm1q6s/d370t409g0380u45ql
5audrb30/1lgehvr88iom3uitqgvlrr4328/37o4euhthumd8djt5fuh2a8l4c/so2r1av74qmg49hqpq4q0oedoo/d9o6ubgqqe1c36pgq6l5ccertcfq361nbgsohi7flem2ahqhhch
0/tl81rj2u9tqgtvlp6ava84qud0/filr0gkth8amhljstnk0va674g HTTP/1.1
Host: 055e6090bf0ab1be7931f97f933cf9a4.r2.cloudflarestorage.com
User-Agent: rclone/
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20230630T230703Z
2023-06-30 23:07:03 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-06-30 23:07:03 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-06-30 23:07:03 DEBUG : HTTP RESPONSE (req 0xc000e1ae00)
2023-06-30 23:07:03 DEBUG : HTTP/1.1 200 OK
Content-Length: 865
Accept-Ranges: bytes
Cf-Ray: 7dfa1032a868555d-SYD
Connection: keep-alive
Content-Type: application/octet-stream
Date: Fri, 30 Jun 2023 23:07:03 GMT
Etag: "7b2a800d3d80ec44ffa452a826a6c1b0"
Last-Modified: Fri, 30 Jun 2023 20:50:32 GMT
Server: cloudflare
X-Amz-Meta-Mtime: 1688101188.02
2023-06-30 23:07:03 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

Plugging away at the 20min mark

2023-06-30 23:21:57 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-06-30 23:21:57 DEBUG : HTTP REQUEST (req 0xc00099f700)
2023-06-30 23:21:57 DEBUG : HEAD /ws-sync/int7gu1o361ro2ndsbil1dusak/cqgkblormbra8ijk66n1tineok/4bpmepn7q4m5hsrvdtsheafcf8/hj1jkoi9m3epmfe88p
njvc9kl8/qs5fng7k0uap69upak4onl1h5s/45n5u1u8t7ccq24klir6pjiri8/vihta69org1am93qnlg5l0ucjs HTTP/1.1
Host: 055e6090bf0ab1be7931f97f933cf9a4.r2.cloudflarestorage.com
User-Agent: rclone/
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20230630T232157Z
2023-06-30 23:21:57 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

Finished at 23min

X-Amz-Meta-Mtime: 1688101736.375
2023-06-30 23:26:37 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-06-30 23:26:37 INFO  : No changes found
2023-06-30 23:26:37 INFO  : Updating listings
2023-06-30 23:26:37 INFO  : Validating listings for Path1 "/dat/appdata/" vs Path2 "r2-sync-crypt:sync/appdata/"
2023-06-30 23:26:37 DEBUG : Lock file removed: /root/.cache/rclone/bisync/dat_appdata..r2-sync-crypt_sync_appdata.lck
2023-06-30 23:26:37 INFO  : Bisync successful
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:     23m40.8s
2023/06/30 23:26:37 INFO  :
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Elapsed time:     23m40.8s

2023/06/30 23:26:37 DEBUG : 6 go routines active

R2 Bisync resync w/ dump headers

Kicks off the same way as Sync while it's enumerating over the R2 bucket.

The checks seem to finish about halfway through the run but there's a constant run of HEAD across files in the bucket across the entire ~50min run?

2023-06-30 23:29:13 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-06-30 23:29:13 DEBUG : HTTP REQUEST (req 0xc001450000)
2023-06-30 23:29:13 DEBUG : HEAD /ws-sync/int7gu1o361ro2ndsbil1dusak/cqgkblormbra8ijk66n1tineok/2qkeq15j6dpk1opqveujhm1q6s/d370t409g0380u45ql
5audrb30/1lgehvr88iom3uitqgvlrr4328/37o4euhthumd8djt5fuh2a8l4c/6jngge515kuehjkjqnub3dt7q0/gmnhakm4bbodpsrvle4f6diif5n3uo4jdieg61mppabblu9ruep
0 HTTP/1.1
Host: 055e6090bf0ab1be7931f97f933cf9a4.r2.cloudflarestorage.com
User-Agent: rclone/
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20230630T232913Z
2023-06-30 23:29:13 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

15 minute mark

2023-06-30 23:43:49 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-06-30 23:43:49 DEBUG : HTTP REQUEST (req 0xc00094e200)
2023-06-30 23:43:49 DEBUG : HEAD /ws-sync/int7gu1o361ro2ndsbil1dusak/cqgkblormbra8ijk66n1tineok/4bpmepn7q4m5hsrvdtsheafcf8/hj1jkoi9
m3epmfe88pnjvc9kl8/gktk35negh0ca4oim4c74gviu0/8l9i2l1fic9mbjkbl59jvgvelo/gb34m0hf6oq70kr0dhto3qe570 HTTP/1.1
Host: 055e6090bf0ab1be7931f97f933cf9a4.r2.cloudflarestorage.com
User-Agent: rclone/
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20230630T234349Z
2023-06-30 23:43:49 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-06-30 23:43:49 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-06-30 23:43:49 DEBUG : HTTP RESPONSE (req 0xc00094e200)
2023-06-30 23:43:49 DEBUG : HTTP/1.1 200 OK
Content-Length: 603528
Accept-Ranges: bytes
Cf-Ray: 7dfa460d4f28a96b-SYD
Connection: keep-alive
Content-Type: application/octet-stream
Date: Fri, 30 Jun 2023 23:43:49 GMT
Etag: "15aaeeb7ba9d10786e419df3a544d179"
Last-Modified: Fri, 30 Jun 2023 22:01:31 GMT
Server: cloudflare
X-Amz-Meta-Mtime: 1670014473
2023-06-30 23:43:49 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

Hit the checks around the 25 min mark

2023-06-30 23:52:54 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-06-30 23:52:54 DEBUG : <my filename>: Size and modification time th
e same (differ by 0s, within tolerance 1ns)
2023-06-30 23:52:54 DEBUG : <my filename 2>: Unchanged skipping
2023-06-30 23:52:54 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-06-30 23:52:54 DEBUG : HTTP REQUEST (req 0xc0016c9e00)
2023-06-30 23:52:54 DEBUG : HEAD /ws-sync/int7gu1o361ro2ndsbil1dusak/cqgkblormbra8ijk66n1tineok/2qkeq15j6dpk1opqveujhm1q6s/e77urer1
pi0bvosqtbu319aak0/1lgehvr88iom3uitqgvlrr4328/6c4enarev1ov4u5na7puig0jmki0m5n571lutuo8b2u7o0go6nq0/6gn2ei7tfqej95j74hpsqi6qk8/6m7i4
egt6bm5hrb1qlc656st70/qfkf2hebl6skpmjvosuvfi8oak HTTP/1.1
Host: 055e6090bf0ab1be7931f97f933cf9a4.r2.cloudflarestorage.com
User-Agent: rclone/
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20230630T235254Z
2023-06-30 23:52:54 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

28 mins - checks seem to have finished but its still plugging away at the API

2023-06-30 23:56:28 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-06-30 23:56:28 DEBUG : HTTP REQUEST (req 0xc0012e6b00)
2023-06-30 23:56:28 DEBUG : HEAD /ws-sync/int7gu1o361ro2ndsbil1dusak/cqgkblormbra8ijk66n1tineok/2qkeq15j6dpk1opqveujhm1q6s/d370t409
g0380u45ql5audrb30/1lgehvr88iom3uitqgvlrr4328/37o4euhthumd8djt5fuh2a8l4c/6uggmlqplu4bbis68sq6ev1324/u7t0o24gapf45emp8vsu3h7l08/i26p
cjsbmc9degvk555t9ige9g/kf1s0rpk6f0r0qjflfbo0v4c5o HTTP/1.1
Host: 055e6090bf0ab1be7931f97f933cf9a4.r2.cloudflarestorage.com
User-Agent: rclone/
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20230630T235628Z
2023-06-30 23:56:28 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

aaaand done at ~50mins again

2023-07-01 00:19:40 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-07-01 00:19:40 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-07-01 00:19:40 DEBUG : HTTP RESPONSE (req 0xc000a46500)
2023-07-01 00:19:40 DEBUG : HTTP/1.1 200 OK
Content-Length: 16131578
Accept-Ranges: bytes
Cf-Ray: 7dfa7a934e5adfbd-SYD
Connection: keep-alive
Content-Type: application/octet-stream
Date: Sat, 01 Jul 2023 00:19:40 GMT
Etag: "049aad7a0ea29cc13203abbad2bb8d5a"
Last-Modified: Fri, 30 Jun 2023 20:47:54 GMT
Server: cloudflare
X-Amz-Meta-Mtime: 1688101736.375
2023-07-01 00:19:40 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-07-01 00:19:40 DEBUG : Lock file removed: /root/.cache/rclone/bisync/dat_appdata..r2-sync-crypt_sync_appdata.lck
2023-07-01 00:19:40 INFO  : Bisync successful
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Checks:              6446 / 6446, 100%
Elapsed time:     51m24.8s
2023/07/01 00:19:40 INFO  :
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Checks:              6446 / 6446, 100%
Elapsed time:     51m24.8s

B2 Bisync w/ dump headers

Snippet from the b2 sync using rclone bisync --progress -vv --dump headers /media/data/appdata b2-sync-crypt:sync/appdata. Took approx ~40 secs to execute

2023-07-01 09:11:41 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-07-01 09:11:42 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-07-01 09:11:42 DEBUG : HTTP RESPONSE (req 0xc0009d8000)
2023-07-01 09:11:42 DEBUG : HTTP/1.1 200
Content-Length: 841089
Cache-Control: max-age=0, no-cache, no-store
Content-Type: application/json;charset=UTF-8
Date: Fri, 30 Jun 2023 23:11:41 GMT
2023-07-01 09:11:42 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-07-01 09:11:42 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-07-01 09:11:42 DEBUG : HTTP REQUEST (req 0xc000734000)
2023-07-01 09:11:42 DEBUG : POST /b2api/v1/b2_list_file_names HTTP/1.1
Host: api004.backblazeb2.com
User-Agent: rclone/v1.62.2
Content-Length: 359
Authorization: XXXX
Content-Type: application/json
Accept-Encoding: gzip
2023-07-01 09:11:42 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-07-01 09:11:42 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-07-01 09:11:42 DEBUG : HTTP RESPONSE (req 0xc000734000)
2023-07-01 09:11:42 DEBUG : HTTP/1.1 200
Content-Length: 726659
Cache-Control: max-age=0, no-cache, no-store
Content-Type: application/json;charset=UTF-8
Date: Fri, 30 Jun 2023 23:11:41 GMT
2023-07-01 09:11:42 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

B2 Bisync resync w/ dump headers

As above for --resync.

rclone bisync --resync --progress -vv --dump headers /media/data/appdata b2-sync-crypt:sync/appdata

Snippet during sync, ran for approx 3min

2023-07-01 09:18:41 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-07-01 09:18:41 DEBUG : HTTP REQUEST (req 0xc000c06400)
2023-07-01 09:18:41 DEBUG : POST /b2api/v1/b2_list_file_names HTTP/1.1
Host: api004.backblazeb2.com
User-Agent: rclone/v1.62.2
Content-Length: 430
Authorization: XXXX
Content-Type: application/json
Accept-Encoding: gzip
2023-07-01 09:18:41 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-07-01 09:18:41 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-07-01 09:18:41 DEBUG : HTTP RESPONSE (req 0xc0004c9e00)
2023-07-01 09:18:41 DEBUG : HTTP/1.1 200
Content-Length: 2294
Cache-Control: max-age=0, no-cache, no-store
Content-Type: application/json;charset=UTF-8
Date: Fri, 30 Jun 2023 23:18:41 GMT
2023-07-01 09:18:41 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-07-01 09:18:41 DEBUG : data-stores/zotero/storage/ZUGFD6DT/.zotero-ft-cache: Size and modification time the same (differ by 0s, within tolerance 1ms)
2023-07-01 09:18:41 DEBUG : data-stores/zotero/storage/ZUGFD6DT/.zotero-ft-cache: Unchanged skipping
2023-07-01 09:18:41 DEBUG : data-stores/zotero/storage/ZUGFD6DT/.zotero-ft-info: Size and modification time the same (differ by 0s, within tolerance 1ms)
2023-07-01 09:18:41 DEBUG : data-stores/zotero/storage/ZUGFD6DT/.zotero-ft-info: Unchanged skipping
2023-07-01 09:18:41 DEBUG : data-stores/zotero/storage/ZUGFD6DT/Lencioni Team Effectiveness.pdf: Size and modification time the same (differ by 0s, within tolerance 1ms)
2023-07-01 09:18:41 DEBUG : data-stores/zotero/storage/ZUGFD6DT/Lencioni Team Effectiveness.pdf: Unchanged skipping
2023-07-01 09:18:41 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-07-01 09:18:41 DEBUG : HTTP RESPONSE (req 0xc0006ee300)
2023-07-01 09:18:41 DEBUG : HTTP/1.1 200
Content-Length: 1619
Cache-Control: max-age=0, no-cache, no-store
Content-Type: application/json;charset=UTF-8
Date: Fri, 30 Jun 2023 23:18:41 GMT
2023-07-01 09:18:41 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

End of log:

2023-07-01 09:19:05 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-07-01 09:19:06 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-07-01 09:19:06 DEBUG : HTTP RESPONSE (req 0xc0004c8000)
2023-07-01 09:19:06 DEBUG : HTTP/1.1 200
Content-Length: 341277
Cache-Control: max-age=0, no-cache, no-store
Content-Type: application/json;charset=UTF-8
Date: Fri, 30 Jun 2023 23:19:06 GMT
2023-07-01 09:19:06 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-07-01 09:19:07 DEBUG : Lock file removed: /home/tommo/.cache/rclone/bisync/media_data_appdata..b2-sync-crypt_sync_appdata.lck
2023-07-01 09:19:07 INFO  : Bisync successful
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Checks:              6445 / 6445, 100%
Elapsed time:      2m44.4s
<6>INFO  :
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Checks:              6445 / 6445, 100%
Elapsed time:      2m44.4s

<7>DEBUG : 6 go routines active

system · July 30, 2023, 11:35pm

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