Hi, I am using kopia 0.8.4 on debian buster, installed from the official apt repo.
I followed the “getting started” guide. First backing up about 17 GB to a filesystem location, which worked well and was done in a few minutes.
- Then I created a new repo on azure and tried to back up the same data to azure.
- For about 4-5 minutes, kopia is uploading. (At about 250kB/sec - checked with
nethogs. This is the maximum of my DSL line. So it should have uploaded about 60-80MB during that time.) - Then kopia will just hang and do nothing, saying
\ 5 hashing, 469 hashed (146.1 MB), 0 cached (0 B), uploaded 89.5 MB, estimating...
Also, when I check the azure container, there will be only a few very small m, n, q and s files and the kopia.maintenance and kopia.repository file (in total not even 1 MB) - no p files as I would have expected.
I let it run for a few hours, but nothing more happens except periodic log entries.
In the CLI logs, I get the following every 15 minutes:
2021-06-10 03:37:24.772 D [logger.go:254] Refresh started
2021-06-10 03:37:24.936 D [logger.go:254] [STORAGE] ListBlobs("m")=<nil> returned 1 items and took 163.865716ms
2021-06-10 03:37:24.936 D [logger.go:254] saving 1 blobs with prefix m to cache
2021-06-10 03:37:24.937 D [logger.go:254] listed 1 index blobs with prefix m from source
2021-06-10 03:37:24.965 D [logger.go:254] [STORAGE] ListBlobs("n")=<nil> returned 15 items and took 192.626712ms
2021-06-10 03:37:24.965 D [logger.go:254] saving 15 blobs with prefix n to cache
2021-06-10 03:37:24.965 D [logger.go:254] listed 15 index blobs with prefix n from source
2021-06-10 03:37:24.966 D [logger.go:254] updating timestamp on /root/.cache/kopia/5ae779b3ab5f55e1/metadata/m0/6e405322107908baa838d4111897460.f to 2021-06-10 03
2021-06-10 03:37:24.967 D [logger.go:254] Refresh completed in 194.82891ms and updated=false
2021-06-10 03:38:21.993 D [logger.go:254] finished sweeping content cache in 47.493µs and retained 0/5242880000 bytes (0 %)
2021-06-10 03:38:22.148 D [logger.go:254] finished sweeping metadata cache in 1.154196ms and retained 54796/5242880000 bytes (0 %)
2021-06-10 03:39:21.994 D [logger.go:254] finished sweeping content cache in 145.819µs and retained 0/5242880000 bytes (0 %)
...
In the content log, there are also periodic entries, but they are not really helpful to me:
2021-06-10 06:07:27.1575454 active-index-blobs[3] = {{nf62dd7a8e117faf833c97c89bbabb979-sad189e92bdf539f3105 159 2021-06-09 22:34:40 +0000 GMT} []}
2021-06-10 06:07:27.1575772 active-index-blobs[4] = {{n8cb88bfaf5a420f8e3c8ccbf70c5ed18 742 2021-06-09 22:30:31 +0000 GMT} []}
2021-06-10 06:07:27.1575982 active-index-blobs[5] = {{ne5f079e8c2899551d18c55e1dbb812cf-sd08e1335261a98b8105 159 2021-06-09 22:34:30 +0000 GMT} []}
2021-06-10 06:07:27.1576334 index-already-cached n6dedb3415cc8e4d3430a5424f35e72bb-s9f667e27b153763f105
2021-06-10 06:07:27.1576573 index-already-cached nc75cd78b9deb8cab470ebe2480d7362a-s723726755c3a5244105
2021-06-10 06:07:27.1576780 index-already-cached n5a82c08f64af251bf33c42fa99fcded0-s5b0d10f857846d55105
2021-06-10 06:07:27.1576983 index-already-cached nf62dd7a8e117faf833c97c89bbabb979-sad189e92bdf539f3105
2021-06-10 06:07:27.1577180 index-already-cached n8cb88bfaf5a420f8e3c8ccbf70c5ed18
2021-06-10 06:07:27.1577431 index-already-cached ne5f079e8c2899551d18c55e1dbb812cf-sd08e1335261a98b8105
2021-06-10 06:22:27.3566823 found-index-blobs[0] = {n6dedb3415cc8e4d3430a5424f35e72bb-s9f667e27b153763f105 159 2021-06-09 22:31:39 +0000 GMT}
2021-06-10 06:22:27.3567503 found-index-blobs[1] = {nc75cd78b9deb8cab470ebe2480d7362a-s723726755c3a5244105 159 2021-06-09 22:39:19 +0000 GMT}
...
Can somebody help me what to do or how to debug?