YoutubeDL-Material icon indicating copy to clipboard operation
YoutubeDL-Material copied to clipboard

[BUG]Container crashing on startup

Open jonathanm-ur opened this issue 2 years ago • 3 comments

When a large number of downloads are queued, the container crashes, restarts, crashes, restarts, ad nauseum.

To Reproduce Subscribe to an active channel, set downloads to a specific period, let run for a while. Noticed no new content being downloaded for any subscriptions, not just added channel. Attempted to clear the backlog by pausing ALL subscriptions and playlists.

Now any attempt to run the container results in repeated crashing when any of the queued downloads are started.

FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory 1: 0xb09980 node::Abort() [node /app/app.js] 2: 0xa1c235 node::FatalError(char const*, char const*) [node /app/app.js] 3: 0xcf784e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node /app/app.js] 4: 0xcf7bc7 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node /app/app.js] 5: 0xeaf465 [node /app/app.js] 6: 0xebf12d v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [node /app/app.js] 7: 0xec1e2e v8::internal::Heap::AllocateRawWithRetryOrFailSlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [node /app/app.js] 8: 0xe830a2 v8::internal::Factory::AllocateRaw(int, v8::internal::AllocationType, v8::internal::AllocationAlignment) [node /app/app.js] 9: 0xe7b6b4 v8::internal::FactoryBase<v8::internal::Factory>::AllocateRawWithImmortalMap(int, v8::internal::AllocationType, v8::internal::Map, v8::internal::AllocationAlignment) [node /app/app.js] 10: 0xe7d3c0 v8::internal::FactoryBase<v8::internal::Factory>::NewRawOneByteString(int, v8::internal::AllocationType) [node /app/app.js] 11: 0xe851fd v8::internal::Factory::NewStringFromUtf8(v8::base::Vector<char const> const&, v8::internal::AllocationType) [node /app/app.js] 12: 0xd06415 v8::String::NewFromUtf8(v8::Isolate*, char const*, v8::NewStringType, int) [node /app/app.js] 13: 0xbf5139 [node /app/app.js] 14: 0xae3eb5 [node /app/app.js] 15: 0x15856cc [node /app/app.js] 2022-08-08T10:28:34: PM2 log: App [YoutubeDL-Material:0] exited with code [0] via signal [SIGABRT] 2022-08-08T10:28:34: PM2 log: App [YoutubeDL-Material:0] starting in -fork mode- 2022-08-08T10:28:34: PM2 log: App [YoutubeDL-Material:0] online 2022-08-08T14:28:36.049Z INFO: Config items set using ENV variables. 2022-08-08T14:28:37.460Z INFO: YoutubeDL-Material v4.3 started on PORT 17442 2022-08-08T14:28:44.570Z VERBOSE: Disabling checking downloads as none are available. 2022-08-08T14:28:46.992Z VERBOSE: Disabling checking downloads as none are available. 2022-08-08T14:28:48.600Z VERBOSE: Disabling checking downloads as none are available. 2022-08-08T14:28:49.093Z VERBOSE: Disabling checking downloads as none are available. <--- Last few GCs ---> [479:0x49d9800] 1470854 ms: Scavenge 4031.0 (4119.1) -> 4030.5 (4129.6) MB, 11.8 / 0.0 ms (average mu = 0.387, current mu = 0.361) allocation failure [479:0x49d9800] 1470906 ms: Scavenge 4037.2 (4129.6) -> 4036.1 (4130.6) MB, 14.4 / 0.0 ms (average mu = 0.387, current mu = 0.361) allocation failure [479:0x49d9800] 1471471 ms: Scavenge 4038.2 (4130.6) -> 4037.3 (4151.3) MB, 553.7 / 0.0 ms (average mu = 0.387, current mu = 0.361) allocation failure <--- JS stacktrace ---> FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory 1: 0xb09980 node::Abort() [node /app/app.js] 2: 0xa1c235 node::FatalError(char const*, char const*) [node /app/app.js] 3: 0xcf784e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node /app/app.js] 4: 0xcf7bc7 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node /app/app.js] 5: 0xeaf465 [node /app/app.js] 6: 0xebf12d v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [node /app/app.js] 7: 0xec1e2e v8::internal::Heap::AllocateRawWithRetryOrFailSlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [node /app/app.js] 8: 0xe830a2 v8::internal::Factory::AllocateRaw(int, v8::internal::AllocationType, v8::internal::AllocationAlignment) [node /app/app.js] 9: 0xe7b6b4 v8::internal::FactoryBase<v8::internal::Factory>::AllocateRawWithImmortalMap(int, v8::internal::AllocationType, v8::internal::Map, v8::internal::AllocationAlignment) [node /app/app.js] 10: 0xe7d3c0 v8::internal::FactoryBase<v8::internal::Factory>::NewRawOneByteString(int, v8::internal::AllocationType) [node /app/app.js] 11: 0xe851fd v8::internal::Factory::NewStringFromUtf8(v8::base::Vector<char const> const&, v8::internal::AllocationType) [node /app/app.js] 12: 0xd06415 v8::String::NewFromUtf8(v8::Isolate*, char const*, v8::NewStringType, int) [node /app/app.js] 13: 0xbf5139 [node /app/app.js] 14: 0xae3eb5 [node /app/app.js] 15: 0x15856cc [node /app/app.js] 2022-08-08T10:53:05: PM2 log: App [YoutubeDL-Material:0] exited with code [0] via signal [SIGABRT] 2022-08-08T10:53:05: PM2 log: App [YoutubeDL-Material:0] starting in -fork mode- 2022-08-08T10:53:05: PM2 log: App [YoutubeDL-Material:0] online 2022-08-08T14:53:07.776Z INFO: Config items set using ENV variables. 2022-08-08T14:53:09.137Z INFO: YoutubeDL-Material v4.3 started on PORT 17442 2022-08-08T14:53:15.771Z VERBOSE: Disabling checking downloads as none are available. 2022-08-08T14:53:18.153Z VERBOSE: Disabling checking downloads as none are available. 2022-08-08T14:53:19.677Z VERBOSE: Disabling checking downloads as none are available. 2022-08-08T14:53:20.276Z VERBOSE: Disabling checking downloads as none are available.

Expected behavior Orderly download of queued list.

Environment Installed version: v4.3 -

You are up to date.

Installation type: docker Docker tag: nightly Commit hash: 9c0a77c Build date: 2022-08-02

jonathanm-ur avatar Aug 08 '22 15:08 jonathanm-ur

Having exactly the same issue here on nightly. It was fine until I added a several channels to be downloaded. Problem still exists even when rolling the docker back to the June 27th v4.2 2dc6813 build

Goolashe avatar Aug 14 '22 02:08 Goolashe

New to YoutubeDL-Material and debugging my crash loop at startup, so me three.

BillSobel avatar Sep 20 '22 00:09 BillSobel

The problem seems to be some routine is bringing in gigabytes of information on to the stack. So at startup I see the memory usage of node grow and grow until it crashes. It is almost like the downloaded video files are being read into the stack and not freed fast enough. I can't think of what else would be gigs and gigs of data....

BillSobel avatar Sep 20 '22 01:09 BillSobel

I'd like to note for anyone else still having this issue, I've tried the "fix" listed in issue 697 and it does not work. I haven't been able to get YTDLM to not boot loop, and I'm not sure what a fix would be other than to just wipe all data, which is admittedly undesirable.

Goolashe avatar Sep 27 '22 03:09 Goolashe

@Goolashe you need to delete the pending downloads in your DB. Once removed it will start back up until too many downloads get queued. The queue code winds up launching way too many workers and that is what eats up memory. I debugged it and put in a ticket with the problem.

BillSobel avatar Sep 27 '22 17:09 BillSobel

@Goolashe and everyone else with this problem. The fix worked for me in a modified form. If you're running into the issue while having free physical ram (in my case I had ~10GB free on my server) you can use the fix, but set it to 10GB instead of limiting it to two as suggested in 697. So "NODE_OPTIONS: --max_old_space_size=10240" has worked for me so far. Under Settings -> Downloads I now have a download queue of over 2k videos and it seems to be working so far. Before adding this fix the container would boot-loop after around 250 videos in queue.

RizeCrime avatar Oct 31 '22 09:10 RizeCrime

@RizeCrime I have actually set that variable to give it 16GB for some time now and it crashes at just above 12GB with out of memory errors, despite still having plenty more memory available (both in actual system memory and what's given to it with the variable). It seems to possibly be some sort of memory leak related to checking for new downloads for subscriptions (despite not even needing to download anything in those checks).

I haven't been able to do much troubleshooting lately, admittedly. Thanks for the response as it lets me know my problem is something more weird. I might try purging the subscription list and slowly adding things back to better see where it routinely blows up. The debug level of logging isn't helping narrow it down much so far.

Goolashe avatar Oct 31 '22 10:10 Goolashe

@Goolashe Yeah so... that solution didn't hold long. I've been testing it over night since yesterday and it worked when I wrote my last comment. Now it crashes when trying to download a playlist. But it doesn't end up boot-looping, just crashes once and reboots. After that it checks my subscriptions at a glacial pace and I haven't seen what happens when it gets back to that playlist again. My download queue is now at ~11k tho, which previously caused it to boot-loop ad infinitum.

Purging my subscriptions and adding them back slowly is what I've been trying for the last two days now but (at least for me) it doesn't help at all. When I add a channel with even a medium amount of videos (~100) it collects all the info about the videos, adds them in the "queued_downloads" table in mongodb and then simply doesn't download most of them. It will get to 20-30 videos and then stop while leaving the queue full of videos. When I then add another channel (or playlist) it behaves just as you've described - it will start checking info for all the new downloads, fill up ram but not reach either the system or node_options limit and then crash.

Edit: here's a log preceeding the crash: 2022-10-31T12:18:39.041Z VERBOSE: Subscription: getting videos for subscription DankPods with args: --dump-json,-o,"subscriptions/channels/DankPods/%(upload_date)s_%(title)s.%(ext)s",-ciw,--write-info-json,--print-json,-f,bestvideo[ext=mp4]+bestaudio[ext=m4a]/mp4,--write-thumbnail,--no-clean-info-json 2022-10-31T12:22:53.718Z VERBOSE: Subscription: finished check for DankPods 2022-10-31T12:22:55.823Z DEBUG: Inserted doc into download_queue 2022-10-31T12:22:55.835Z DEBUG: Inserted doc into download_queue 2022-10-31T12:22:55.848Z DEBUG: Inserted doc into download_queue 2022-10-31T12:22:55.859Z DEBUG: Inserted doc into download_queue 2022-10-31T12:23:02.484Z VERBOSE: Collecting info for download a1826fd4-b717-4a07-9200-bf32341c31f3 2022-10-31T12:23:02.493Z VERBOSE: yt-dlp args being used: -o,subscriptions/channels/DankPods/%(upload_date)s_%(title)s.%(ext)s,--write-info-json,-f,bestvideo+bestaudio,--merge-output-format,mp4,--write-thumbnail,--no-clean-info-json,-j,--no-simulate 2022-10-31T12:23:05.535Z VERBOSE: Downloading a1826fd4-b717-4a07-9200-bf32341c31f3 2022-10-31T12:23:08.159Z DEBUG: Video download delay: 2.62 seconds. 2022-10-31T12:23:08.640Z DEBUG: Inserted doc into files with filter: {"path":"subscriptions/channels/DankPods/20220623_The MP3 Pen..mp4"} 2022-10-31T12:23:15.297Z VERBOSE: Collecting info for download 58caf4e3-2b9b-4568-8c7a-6582bc4ab391 2022-10-31T12:23:16.050Z VERBOSE: yt-dlp args being used: -o,subscriptions/channels/DankPods/%(upload_date)s_%(title)s.%(ext)s,--write-info-json,-f,bestvideo+bestaudio,--merge-output-format,mp4,--write-thumbnail,--no-clean-info-json,-j,--no-simulate 2022-10-31T12:23:19.293Z VERBOSE: Collecting info for download 58caf4e3-2b9b-4568-8c7a-6582bc4ab391 2022-10-31T12:23:21.079Z VERBOSE: yt-dlp args being used: -o,subscriptions/channels/DankPods/%(upload_date)s_%(title)s.%(ext)s,--write-info-json,-f,bestvideo+bestaudio,--merge-output-format,mp4,--write-thumbnail,--no-clean-info-json,-j,--no-simulate 2022-10-31T12:23:42.945Z VERBOSE: Downloading 58caf4e3-2b9b-4568-8c7a-6582bc4ab391 2022-10-31T12:23:48.382Z VERBOSE: Downloading 58caf4e3-2b9b-4568-8c7a-6582bc4ab391 2022-10-31T12:23:52.700Z DEBUG: Video download delay: 2.507 seconds. 2022-10-31T12:24:01.383Z DEBUG: Video download delay: 4.127 seconds. 2022-10-31T12:24:16.214Z DEBUG: Inserted doc into files with filter: {"path":"subscriptions/channels/DankPods/20220616_The iDuck..mp4"} 2022-10-31T12:24:34.014Z DEBUG: Inserted doc into files with filter: {"path":"subscriptions/channels/DankPods/20220616_The iDuck..mp4"} 2022-10-31T12:25:18.117Z VERBOSE: Collecting info for download 9818e293-4513-440f-bd24-c7503ded40bd 2022-10-31T12:25:43.093Z VERBOSE: Collecting info for download 9818e293-4513-440f-bd24-c7503ded40bd 2022-10-31T12:26:10.540Z VERBOSE: yt-dlp args being used: -o,subscriptions/channels/DankPods/%(upload_date)s_%(title)s.%(ext)s,--write-info-json,-f,bestvideo+bestaudio,--merge-output-format,mp4,--write-thumbnail,--no-clean-info-json,-j,--no-simulate 2022-10-31T12:26:43.087Z VERBOSE: Collecting info for download 9818e293-4513-440f-bd24-c7503ded40bd 2022-10-31T12:26:53.686Z VERBOSE: yt-dlp args being used: -o,subscriptions/channels/DankPods/%(upload_date)s_%(title)s.%(ext)s,--write-info-json,-f,bestvideo+bestaudio,--merge-output-format,mp4,--write-thumbnail,--no-clean-info-json,-j,--no-simulate 2022-10-31T12:27:42.839Z VERBOSE: Collecting info for download 9818e293-4513-440f-bd24-c7503ded40bd 2022-10-31T12:28:41.350Z INFO: Config items set using ENV variables. 2022-10-31T12:28:41.723Z INFO: YoutubeDL-Material v4.3 started on PORT 17442

RizeCrime avatar Oct 31 '22 12:10 RizeCrime

I put in a bugs on this pointing to where the problem is, with large playlists the number of downloaders explode.

https://github.com/Tzahi12345/YoutubeDL-Material/issues/758 and https://github.com/Tzahi12345/YoutubeDL-Material/issues/755

BillSobel avatar Oct 31 '22 18:10 BillSobel