Duplicacy killed during copy

Bug
#1

Please describe what you are doing to trigger the bug:

I am running duplicacy copy -from digitalocean -to google-drive on my Digitalocean droplet with 1 GB of memory.

Please describe what you expect to happen (but doesn’t):

I expect the process to finish successfully.

Please describe what actually happens (the wrong behaviour):

The process gets killed after processing 10 - 40 chunks, after hitting 400 MB of memory.

My Repository has 151 chunks, 5 revisions, an a total size of 800 MB. All other operation, including backup and restore, performs normally, although I also get the same error when running duplicacy benchmark -storage digitalocean.

#2

Are these numbers correct? This is a very small repository and copy shouldn’t use that much memory. Can you post the log from a check job?

#3

Yes they are correct, that’s why I was asking. Here is the output of check

Listing all chunks
1 snapshots and 11 revisions
Total chunk size is 575,005K in 192 chunks
All chunks referenced by snapshot website at revision 9 exist
All chunks referenced by snapshot website at revision 10 exist
All chunks referenced by snapshot website at revision 11 exist
All chunks referenced by snapshot website at revision 12 exist
All chunks referenced by snapshot website at revision 13 exist
All chunks referenced by snapshot website at revision 14 exist
All chunks referenced by snapshot website at revision 15 exist
All chunks referenced by snapshot website at revision 16 exist
All chunks referenced by snapshot website at revision 17 exist
All chunks referenced by snapshot website at revision 18 exist
All chunks referenced by snapshot website at revision 19 exist

    snap | rev |                          | files |    bytes | chunks |    bytes | uniq |    bytes | new |    bytes |
 website |   9 | @ 2021-05-24 13:57       | 14348 | 720,400K |    161 | 544,424K |    0 |        0 | 161 | 544,424K |
 website |  10 | @ 2021-05-24 14:02       | 14348 | 720,400K |    161 | 544,424K |    0 |        0 |   0 |        0 |
 website |  11 | @ 2021-05-24 14:08       | 14348 | 720,400K |    161 | 544,424K |    0 |        0 |   0 |        0 |
 website |  12 | @ 2021-05-24 14:51       | 14366 | 722,174K |    162 | 547,654K |    3 |   1,444K |   4 |   4,673K |
 website |  13 | @ 2021-05-24 14:51       | 14366 | 722,172K |    163 | 549,910K |    4 |   3,700K |   4 |   3,700K |
 website |  14 | @ 2021-05-24 14:54       | 14366 | 722,172K |    163 | 549,909K |    3 |   3,697K |   4 |   3,698K |
 website |  15 | @ 2021-05-24 14:54       | 14366 | 722,172K |    163 | 549,909K |    3 |   3,697K |   3 |   3,697K |
 website |  16 | @ 2021-05-24 14:56       | 14366 | 722,172K |    164 | 549,910K |    5 |   3,700K |   5 |   3,700K |
 website |  17 | @ 2021-05-24 15:20       | 14366 | 722,173K |    163 | 549,913K |    4 |   3,702K |   4 |   3,702K |
 website |  18 | @ 2021-05-24 18:29       | 14365 | 722,053K |    163 | 549,915K |    3 |   3,703K |   4 |   3,704K |
 website |  19 | @ 2021-05-24 18:32       | 14365 | 722,053K |    163 | 549,916K |    3 |   3,704K |   3 |   3,704K |
 website | all |                          |       |          |    192 | 575,005K |  192 | 575,005K |     |          |
#4

Any news on this one. I am still running into issues here when using this commands:

duplicacy copy -from digitalocean -to google-drive
duplicacy copy -from digitalocean -to sftp-drive

After analyzing and before copying the chunks it starts at 25 MB memory usage. And then it constantly climbs up to 350 MB, at which point it is killed. This looks like a leak to me. The problem doesn’t happen during a backup using this command, even for a initial backup:

duplicacy backup -storage digitalocean

I looked a bit in the source, but wasn’t able to see anything obvious. Also I am not versed in golang, not to mention memory management in this language. Maybe someone with more experience could have a look.

Any ideas or workarounds?

This is my repository:

Files: 28262 total, 721,399K bytes; 28262 new, 721,399K bytes
File chunks: 146 total, 721,399K bytes; 146 new, 721,399K bytes, 537,430K bytes uploaded
Metadata chunks: 5 total, 10,062K bytes; 5 new, 10,062K bytes, 3,077K bytes uploaded
All chunks: 151 total, 731,461K bytes; 151 new, 731,461K bytes, 540,507K bytes uploaded

And in the case of copy, which operates only on compressed chunks, this means a total working size of 540 MB and 151 files.

#6

How many revisions are you copying?

#7

In this case just 1-2 revision. One was an initial backup. The other one was 5 months old and had 20 revisions already copied and needed 1 more to be copied with about 80 chunks.

It typically crashed after copying about 20 chunks, when reaching 350 MB memory. Although once it crashed only after 60 chunks. So it seems that the garbage collection has some influence here.

At the end it still got it done, after starting it like 8 times. Then all 150 chunks where copied, 20 chunks at a time.

#8

I added a new global option, -print-memory-usage, that prints out memory usage stats every second: Add a global option to print memory usage · gilbertchen/duplicacy@68b6049 · GitHub

Here is sample output:

duplicacy  -s LIST_SKIP -s COPY_PROGRESS -log -print-memory-usage copy -to second 
2021-10-15 20:57:44.623 INFO MEMORY_STATS Currently allocated: 1.96M, total allocated: 1.96M, system memory: 68.31M, number of GCs: 0
2021-10-15 20:57:44.629 INFO STORAGE_SET Source storage set to /tmp/duplicacy_test/storage
2021-10-15 20:57:44.632 INFO STORAGE_SET Destination storage set to /tmp/duplicacy_test/storage2
2021-10-15 20:57:44.761 INFO SNAPSHOT_COPY Chunks to copy: 400, to skip: 0, total: 400
2021-10-15 20:57:45.634 INFO MEMORY_STATS Currently allocated: 1.43M, total allocated: 33.34M, system memory: 68.69M, number of GCs: 14
2021-10-15 20:57:46.639 INFO MEMORY_STATS Currently allocated: 3.19M, total allocated: 62.51M, system memory: 68.69M, number of GCs: 26
2021-10-15 20:57:47.644 INFO MEMORY_STATS Currently allocated: 1.44M, total allocated: 90.52M, system memory: 68.69M, number of GCs: 39
2021-10-15 20:57:48.650 INFO MEMORY_STATS Currently allocated: 3.14M, total allocated: 119.68M, system memory: 68.94M, number of GCs: 52
2021-10-15 20:57:49.652 INFO MEMORY_STATS Currently allocated: 2.59M, total allocated: 147.69M, system memory: 68.94M, number of GCs: 64
2021-10-15 20:57:50.657 INFO MEMORY_STATS Currently allocated: 1.48M, total allocated: 176.84M, system memory: 68.94M, number of GCs: 77
2021-10-15 20:57:51.662 INFO MEMORY_STATS Currently allocated: 2.62M, total allocated: 209.98M, system memory: 69.19M, number of GCs: 91
2021-10-15 20:57:52.667 INFO MEMORY_STATS Currently allocated: 1.95M, total allocated: 236.77M, system memory: 69.19M, number of GCs: 103

If you need a pre-built binary, please let me know the OS/platform that you’re running.

1 Like
#9

I have some first results. I compiled the new commit and ran it with the same command as before. The memory doesn’t seem to rise much. So that seems fixed. On the other hand on my sftp backend the copy rate went from 1.50 MB/s down to 140 kB/s. That’s not good. Any ideas why?

The original version was 2.7.2 downloaded from here: Releases · gilbertchen/duplicacy · GitHub

#10

I compiled now version tag 2.7.2 from github. Here the memory increase like before, while copy speed is slow and around 160 kB/s. Any ideas? I am using go 1.17.2 on Ubuntu 20.04. I download all the standard dependencies and rolled back swift to 1.0.50 as described here.

Also in this version the garbage collection seems to work, as it went down from 200 MB to 150 MB after copying 20 chunks. Any ideas how to get back the copy speeds, or what the memory problem could be?