Slow performance after adding second client

Support
1

Hi!
I’ve used kopia-cli for a couple of months as a backup solution for my primary server now. The backend is a remote webdav server (Nextcloud). Everything ran fine until I connected to the same repo with another client (Raspberry Pi 3).
At first I had trouble establishing the connection at all but even after I did, all commands took minutes as opposed to seconds.

I tried backing up a small config file from the Raspberry Pi host which ended up taking > 20 minutes. Here is the cli log entry for it:

2024-02-22T13:24:47.438586Z DEBUG kopia/cli build version v0.15.0, available v
2024-02-22T13:24:47.439301Z DEBUG kopia/cli no updated version available
2024-02-22T13:24:47.440485Z DEBUG passwordpersist password for /home/benedikt/.config/kopia/repository.config retrieved from password file
2024-02-22T13:24:48.974256Z DEBUG kopia/repo throttling limits from connection info	{"limits":{}}
2024-02-22T13:24:48.984344Z DEBUG cache finished initial cache scan	{"cache":"contents","duration":"834.272µs","totalRetainedSize":0,"tooRecentBytes":0,"tooRecentCount":0,"maxSizeBytes":5242880000,"limitBytes":0,"inUsePercent":0}
2024-02-22T13:24:48.992418Z DEBUG cache finished initial cache scan	{"cache":"metadata","duration":"5.704959ms","totalRetainedSize":2943626,"tooRecentBytes":2943626,"tooRecentCount":2,"maxSizeBytes":5242880000,"limitBytes":0,"inUsePercent":0}
2024-02-22T13:24:49.006152Z DEBUG cache finished initial cache scan	{"cache":"index-blobs","duration":"11.316687ms","totalRetainedSize":6901320,"tooRecentBytes":6901320,"tooRecentCount":35,"maxSizeBytes":5242880000,"limitBytes":0,"inUsePercent":0}
2024-02-22T13:24:49.010955Z DEBUG kopia/repo [STORAGE] concurrency level reached	{"maxConcurrency":1}
2024-02-22T13:24:49.032018Z DEBUG kopia/repo [STORAGE] concurrency level reached	{"maxConcurrency":2}
2024-02-22T13:24:49.032171Z DEBUG kopia/repo [STORAGE] concurrency level reached	{"maxConcurrency":3}
2024-02-22T13:24:49.033912Z DEBUG kopia/repo [STORAGE] concurrency level reached	{"maxConcurrency":4}
2024-02-22T13:25:41.266667Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xw","resultCount":1,"error":null,"duration":"52.255465916s"}
2024-02-22T13:25:41.288987Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xe","resultCount":2,"error":null,"duration":"52.254885915s"}
2024-02-22T13:26:07.121433Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xr","resultCount":2,"error":null,"duration":"1m18.089206124s"}
2024-02-22T13:29:06.465650Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xs","resultCount":12,"error":null,"duration":"4m17.433376199s"}
2024-02-22T13:29:57.814005Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xn10_","resultCount":0,"error":null,"duration":"51.339715118s"}
2024-02-22T13:30:23.458763Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xn8_","resultCount":20,"error":null,"duration":"1m16.984765249s"}
2024-02-22T13:30:23.460985Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xn9_","resultCount":14,"error":null,"duration":"1m16.985842074s"}
2024-02-22T13:30:23.764868Z INFO kopia/cli Snapshotting benedikt@mirror:/home/benedikt/MagicMirror/config/config.js ...
2024-02-22T13:30:23.776435Z DEBUG uploader uploading	{"source":"benedikt@mirror:/home/benedikt/MagicMirror/config/config.js","previousManifests":0,"parallel":4}
2024-02-22T13:32:56.765065Z DEBUG kopia/repo [STORAGE] PutBlob	{"blobID":"scdfaf7fe25e2e9f48e61c24a51c714ce-s7e444db238b9308b125","length":204,"error":null,"duration":"2m32.907361121s"}
2024-02-22T13:32:56.825261Z DEBUG kopia/snapshot/policy   keeping 2024-02-22 14:30:23.776739481 +0100 CET retention: [daily-1,weekly-1] pins: []
2024-02-22T13:32:56.825551Z INFO kopia/cli Created snapshot with root 529a4978fec29e6ecc5c6822ce987e49 and ID bcc2cf651468d12e2c60a95290a4f6ec in 2m32s
2024-02-22T13:34:39.567923Z DEBUG kopia/repo [STORAGE] PutBlob	{"blobID":"pbee5f84b4a51502c11b59b8bea698180-s7e444db238b9308b125","length":4298,"error":null,"duration":"1m42.735062285s"}
2024-02-22T13:35:05.198324Z DEBUG kopia/repo [STORAGE] GetBlob	{"blobID":"kopia.repository","offset":0,"length":-1,"outputLength":1101,"error":null,"duration":"25.626014256s"}
2024-02-22T13:35:30.842511Z DEBUG kopia/repo [STORAGE] GetBlob	{"blobID":"kopia.blobcfg","offset":0,"length":-1,"outputLength":30,"error":null,"duration":"25.632590513s"}
2024-02-22T13:37:14.071636Z DEBUG kopia/repo [STORAGE] PutBlob	{"blobID":"q30ce8d77f38d9938b7f38eb39ad1fbee-s7e444db238b9308b125","length":4298,"error":null,"duration":"1m43.218862559s"}
2024-02-22T13:38:05.425565Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xw","resultCount":1,"error":null,"duration":"51.348599165s"}
2024-02-22T13:38:05.438047Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xe","resultCount":2,"error":null,"duration":"51.362171951s"}
2024-02-22T13:38:31.124906Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xr","resultCount":2,"error":null,"duration":"1m17.048892905s"}
2024-02-22T13:41:30.735448Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xs","resultCount":12,"error":null,"duration":"4m16.659412756s"}
2024-02-22T13:42:22.106122Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xn10_","resultCount":0,"error":null,"duration":"51.366962381s"}
2024-02-22T13:42:47.750684Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xn8_","resultCount":20,"error":null,"duration":"1m17.01184053s"}
2024-02-22T13:42:47.767944Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xn9_","resultCount":14,"error":null,"duration":"1m17.029135093s"}
2024-02-22T13:44:04.804995Z DEBUG kopia/repo [STORAGE] PutBlob	{"blobID":"xn9_77908e46b927c76229686310d2c2a00f-s7e444db238b9308b125-c1","length":243,"error":null,"duration":"1m17.036005508s"}
2024-02-22T13:44:56.220571Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xw","resultCount":1,"error":null,"duration":"51.411345778s"}
2024-02-22T13:44:56.244567Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xe","resultCount":2,"error":null,"duration":"51.435100145s"}
2024-02-22T13:45:21.907992Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xr","resultCount":2,"error":null,"duration":"1m17.097113733s"}
2024-02-22T13:48:21.245273Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xs","resultCount":12,"error":null,"duration":"4m16.433021446s"}
2024-02-22T13:49:12.631374Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xn10_","resultCount":0,"error":null,"duration":"51.383754664s"}
2024-02-22T13:49:38.218150Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xn8_","resultCount":20,"error":null,"duration":"1m16.970639042s"}
2024-02-22T13:49:38.237602Z DEBUG kopia/repo [STORAGE] ListBlobs	{"prefix":"xn9_","resultCount":15,"error":null,"duration":"1m16.990013974s"}
2024-02-22T13:50:04.613641Z DEBUG kopia/repo [STORAGE] DeleteBlob	{"blobID":"scdfaf7fe25e2e9f48e61c24a51c714ce-s7e444db238b9308b125","error":null,"duration":"26.374801608s"}
2024-02-22T13:50:30.250553Z DEBUG kopia/repo [STORAGE] GetBlob	{"blobID":"q30ce8d77f38d9938b7f38eb39ad1fbee-s7e444db238b9308b125","offset":0,"length":-1,"outputLength":4298,"error":null,"duration":"25.63296769s"}
2024-02-22T13:51:21.879993Z DEBUG kopia/repo [STORAGE] PutBlob	{"blobID":"_log_20240222142448_426f_1708608289_1708609830_1_73622aa96ea7532266fbd0dd43ebdbe8","length":2466,"error":null,"duration":"51.611825807s"}
2024-02-22T13:51:21.880306Z DEBUG kopia/repo [STORAGE] Close	{"error":null,"duration":"1.511µs"}

Weirdly, commands that ran quickly on my primary server (kopia snapshot list for example) now also take minutes.
Any pointers or help would be appreciated!

2

Kopia operations are relatively computationally heavy - encryption, compression etc. Raspberry Pi 3 does everything in software - unlike most modern computers its CPU does not have any instructions to accelerate it. It has only changed recently with release of RPi 5. So unfortunately I am afraid that kopia slowness is expected on such small and old computer (it was first released in 2016).

3

Ok then, but why has kopia slowed down on my main server that much? It used to be fine. I don’t see why connecting another client would have that much of an impact on the first client.

4

I doubt one has anything to do with another. “Connecting” another client does not have any stateful consequences. It is just some other IP writing/reading sometimes to your cloud storage. So most likely issue is either Nextcloud or your original machine setup. Something changed. Maybe timing coincidence only.

Otherwise you could just “disconnect” RPi - and all should work like before.