Backuptask crashed when uploading to OVH Object Storage

[d19dotca]

I seem to be having the same issue (more or less) as Backuptask crashed thread.

Feb 05 20:50:20 box:backupupload v8 heap : used 73474192 total: 119877632 max: 4128627946
Feb 05 20:50:29 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 7560M@9MBps (box)"}
Feb 05 20:50:39 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 7662M@9MBps (box)"}
Feb 05 20:50:49 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 7765M@9MBps (box)"}
Feb 05 20:50:50 box:shell backup-snapshot/box (stdout): 2021-02-06T04:50:50.937Z box:backupupload process: rss: 1415004160 heapTotal: 122597376 heapUsed: 78836216 external: 656077307
Feb 05 20:50:50 box:backupupload v8 heap : used 78839584 total: 122597376 max: 4128627946
Feb 05 20:50:59 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 7866M@9MBps (box)"}
Feb 05 20:51:09 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 7974M@9MBps (box)"}
Feb 05 20:51:19 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 8076M@9MBps (box)"}
Feb 05 20:51:20 box:shell backup-snapshot/box (stdout): 2021-02-06T04:51:20.934Z box:backupupload process: rss: 1418588160 heapTotal: 126947328 heapUsed: 80527528 external: 981186043
Feb 05 20:51:20 box:shell backup-snapshot/box (stdout): 2021-02-06T04:51:20.934Z box:backupupload v8 heap : used 80530896 total: 126947328 max: 4128627946
Feb 05 20:51:29 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 8176M@9MBps (box)"}
Feb 05 20:51:39 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 8217M@9MBps (box)"}
Feb 05 20:51:49 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 8319M@9MBps (box)"}
Feb 05 20:51:50 box:shell backup-snapshot/box (stdout): 2021-02-06T04:51:50.933Z box:backupupload process: rss: 2455207936 heapTotal: 96661504 heapUsed: 72144744 external: 1787061677
Feb 05 20:51:50 box:backupupload v8 heap : used 72148112 total: 96661504 max: 4128627946
Feb 05 20:51:59 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 8424M@9MBps (box)"}
Feb 05 20:52:09 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 8518M@9MBps (box)"}
Feb 05 20:52:19 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 8621M@9MBps (box)"}
Feb 05 20:52:20 box:shell backup-snapshot/box (stdout): 2021-02-06T04:52:20.934Z box:backupupload process: rss: 1390559232 heapTotal: 114487296 heapUsed: 67759312 external: 499310587
Feb 05 20:52:20 box:backupupload v8 heap : used 67762680 total: 114487296 max: 4128627946
Feb 05 20:52:29 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 8717M@9MBps (box)"}
Feb 05 20:52:39 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 8813M@9MBps (box)"}
Feb 05 20:52:49 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 8914M@9MBps (box)"}
Feb 05 20:52:50 box:shell backup-snapshot/box (stdout): 2021-02-06T04:52:50.933Z box:backupupload process: rss: 1393696768 heapTotal: 117731328 heapUsed: 71638168 external: 789711867
Feb 05 20:52:50 box:backupupload v8 heap : used 71641536 total: 117731328 max: 4128627946
Feb 05 20:52:59 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 9023M@9MBps (box)"}
Feb 05 20:53:09 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 9125M@9MBps (box)"}
Feb 05 20:53:21 box:shell backup-snapshot/box (stdout): 2021-02-06T04:53:21.605Z box:backupupload process: rss: 2484719616 heapTotal: 89088000 heapUsed: 68641152 external: 2145967299
Feb 05 20:53:21 box:backupupload v8 heap : used 68644520 total: 89088000 max: 4128627946
Feb 05 20:53:21 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 9207M@9MBps (box)"}
Feb 05 20:53:31 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 9268M@9MBps (box)"}
Feb 05 20:53:41 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 9358M@9MBps (box)"}
Feb 05 20:53:51 box:shell backup-snapshot/box (stdout): 2021-02-06T04:53:51.606Z box:backupupload process: rss: 1392267264 heapTotal: 104415232 heapUsed: 55043424 external: 1337131954
Feb 05 20:53:51 box:backupupload v8 heap : used 55041336 total: 104415232 max: 4128627946
Feb 05 20:53:51 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 9455M@9MBps (box)"}
Feb 05 20:54:01 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 9564M@9MBps (box)"}
Feb 05 20:54:11 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 9667M@9MBps (box)"}
Feb 05 20:54:21 box:shell backup-snapshot/box (stdout): 2021-02-06T04:54:21.606Z box:backupupload process: rss: 1395830784 heapTotal: 107036672 heapUsed: 67273960 external: 635874811
Feb 05 20:54:21 box:backupupload v8 heap : used 67277328 total: 107036672 max: 4128627946
Feb 05 20:54:21 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 9776M@9MBps (box)"}
Feb 05 20:54:31 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 9864M@9MBps (box)"}
Feb 05 20:54:41 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 9957M@9MBps (box)"}
Feb 05 20:54:51 box:shell backup-snapshot/box (stdout): 2021-02-06T04:54:51.607Z box:backupupload process: rss: 1398034432 heapTotal: 109146112 heapUsed: 64747712 external: 925264891
Feb 05 20:54:51 box:backupupload v8 heap : used 64751080 total: 109146112 max: 4128627946
Feb 05 20:54:51 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 10057M@9MBps (box)"}
Feb 05 20:55:01 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 10157M@9MBps (box)"}
Feb 05 20:55:13 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 10230M@9MBps (box)"}
Feb 05 20:55:21 box:shell backup-snapshot/box (stdout): 2021-02-06T04:55:21.606Z box:backupupload process: rss: 2438123520 heapTotal: 75431936 heapUsed: 47143792 external: 2119090935
Feb 05 20:55:21 box:shell backup-snapshot/box (stdout): 2021-02-06T04:55:21.606Z box:backupupload v8 heap : used 47147160 total: 75431936 max: 4128627946
Feb 05 20:55:23 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 10303M@9MBps (box)"}
Feb 05 20:55:33 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 10398M@9MBps (box)"}
Feb 05 20:55:43 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 10502M@9MBps (box)"}
Feb 05 20:55:51 box:shell backup-snapshot/box (stdout): 2021-02-06T04:55:51.607Z box:backupupload process: rss: 2449010688 heapTotal: 93257728 heapUsed: 45112256 external: 2213315659
Feb 05 20:55:51 box:shell backup-snapshot/box (stdout): 2021-02-06T04:55:51.607Z box:backupupload v8 heap : used 45115624 total: 93257728 max: 4128627946
Feb 05 20:55:53 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 10590M@9MBps (box)"}
Feb 05 20:56:03 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 10676M@9MBps (box)"}
Feb 05 20:56:13 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 10777M@9MBps (box)"}
Feb 05 20:56:21 box:shell backup-snapshot/box (stdout): 2021-02-06T04:56:21.608Z box:backupupload process: rss: 2557865984 heapTotal: 94322688 heapUsed: 46055320 external: 2335666597
Feb 05 20:56:21 box:backupupload v8 heap : used 46058688 total: 94322688 max: 4128627946
Feb 05 20:56:23 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 10871M@9MBps (box)"}
Feb 05 20:56:33 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 10960M@9MBps (box)"}
Feb 05 20:56:43 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 11052M@9MBps (box)"}
Feb 05 20:56:51 box:shell backup-snapshot/box (stdout): 2021-02-06T04:56:51.608Z box:backupupload process: rss: 2707828736 heapTotal: 96149504 heapUsed: 47722872 external: 2428885015
Feb 05 20:56:51 box:backupupload v8 heap : used 47726240 total: 96149504 max: 4128627946
Feb 05 20:56:53 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 11164M@9MBps (box)"}
Feb 05 20:57:06 box:tasks 8247: {"percent":97.66666666666663,"message":"Uploading backup 11253M@9MBps (box)"}
Feb 05 20:57:18 box:shell backup-snapshot/box code: null, signal: SIGKILL
Feb 05 20:57:18 box:taskworker Task took 2001.989 seconds
Feb 05 20:57:18 box:tasks setCompleted - 8247: {"result":null,"error":{"stack":"BoxError: Backuptask crashed\n at /home/yellowtent/box/src/backups.js:872:29\n at f (/home/yellowtent/box/node_modules/once/once.js:25:25)\n at ChildProcess.<anonymous> (/home/yellowtent/box/src/shell.js:69:9)\n at ChildProcess.emit (events.js:198:13)\n at ChildProcess.EventEmitter.emit (domain.js:448:20)\n at Process.ChildProcess._handle.onexit (internal/child_process.js:248:12)","name":"BoxError","reason":"Internal Error","details":{},"message":"Backuptask crashed"}}
Feb 05 20:57:18 box:tasks 8247: {"percent":100,"result":null,"error":{"stack":"BoxError: Backuptask crashed\n at /home/yellowtent/box/src/backups.js:872:29\n at f (/home/yellowtent/box/node_modules/once/once.js:25:25)\n at ChildProcess.<anonymous> (/home/yellowtent/box/src/shell.js:69:9)\n at ChildProcess.emit (events.js:198:13)\n at ChildProcess.EventEmitter.emit (domain.js:448:20)\n at Process.ChildProcess._handle.onexit (internal/child_process.js:248:12)","name":"BoxError","reason":"Internal Error","details":{},"message":"Backuptask crashed"}}

It is always near the last bit of the upload for the Box backup part with all the emails and such. I've tried it twice now repeatedly but both times it failed the same way at nearly the same place (the second attempt was less though judging by the size as it made it to around 9000M instead of 11253 MB.

Here's the configuration of my backup set (this is a new setup, trying to upload to this Object Storage backend so I can try migrating to a new OVH instance from my current VPS provider (LunaNode)):

Note that I've tried a bunch of different configurations in memory limit, upload part size, concurrency levels for various items, and even rsync and tgz format. Issue seems to occur no matter what method is used.

Thoughts?

[girish]

@d19dotca said in Backuptask crashed when uploading to OVH Object Storage:

Feb 05 20:57:18 box:shell backup-snapshot/box code: null, signal: SIGKILL

Usually, this means the process ran out of memory. Can you try reducing the concurrency to say 100 and also reduce part size to say 100M ? Because it's going to upload 100 files in parallel and each of 100M, that's almost 10GB memory worst case with these numbers. So, you can even reduce it further to be 80 files in parallel with 50M part size (usually individual files are way less than 50M so part size can be quite small in rsync mode)

[d19dotca]

@girish sure I’ll try that then. I have tried a few different configurations with those numbers, one of them was just the defaults which still didn’t work at the time. I’ll try with your latest suggestion though and see if that helps. Thanks for the quick response.

[d19dotca]

@girish said in Backuptask crashed when uploading to OVH Object Storage:

reducing the concurrency to say 100 and also reduce part size to say 100M ? Because it's going to upload 100 files in parallel and each of 100M

Just curious… the GUI says “up to 3 parts are uploaded in parallel” for part size… but seems like you’re saying it’s actually whatever the value of upload concurrency is, right? Have I misunderstood… where does the “up to 3” come into play for part size?

[nebulon]

@d19dotca the concurrency is how many files are uploaded in parallel, however each file can be broken up in parts for uploading and those parts (per file) can also be uploaded in parallel (up to 3 parts)

[d19dotca]

@nebulon Ah okay, I think I understand. Does that mean then that we don't really need enough memory for 3x<part size>, so much as 3x(<upload_part_size>x<upload_concurrency>) for rsync setups, right, or did I totally misunderstand?

I guess what's throwing me off a bit is the UI saying "Up to 3 parts are uploaded in parallel and requires as much memory", but that's not entirely true then is it, is it fair to say that it's more important to have enough memory for 3x(<upload_part_size>x<upload_concurrency>), given what I think I understood from Girish earlier on the upload concurrency and upload part size?

In other words, if I had part size set to 512 MB and upload concurrency set to 10, then this means I need memory of 5120 MB at the very least, right, and that's then multiplied by three or is it only the 512 MB multiplied by upload concurrency and nothing about "3"? Sorry, I think I just need the math laid out a bit to better understand this so I am not pushing the server past what it has in order to avoid the backup task running out of memory.

[girish]

@d19dotca said in Backuptask crashed when uploading to OVH Object Storage:

@nebulon Ah okay, I think I understand. Does that mean then that we don't really need enough memory for 3x<part size>, so much as 3x(<upload_part_size>x<upload_concurrency>) for rsync setups, right, or did I totally misunderstand?

If a file is big (i.e > than the upload part size), we still need 3x<part size> for rsync. So, let's say you have a 5GB file, then we still need 3GB RAM (since upload part size in your screenshot is 1GB). Plus in addition, we need to memory for uploading 200 files in parallel as well. And if those 200 files contain more 5GB files, then you need add it all up. It gets complicated very quickly!