Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Bug]: OOM When trying to download all episodes from a large podcast #3601

Closed
mikiher opened this issue Nov 10, 2024 · 5 comments · Fixed by #3604
Closed

[Bug]: OOM When trying to download all episodes from a large podcast #3601

mikiher opened this issue Nov 10, 2024 · 5 comments · Fixed by #3604
Labels
bug Something isn't working

Comments

@mikiher
Copy link
Contributor

mikiher commented Nov 10, 2024

What happened?

I'm opening this to capture this bug opened on audiobookshelf-windows, as I don't believe this is a Windows-specific bug.

I was able to reproduce it both on the official audiobookshelf-windows 2.16.2 as well on dev server built from latest source, on Windows 11.

What did you expect to happen?

Expecting server not to crash

Steps to reproduce the issue

  1. Create a Podcasts library in an empty folder
  2. Go the Library's Add page
  3. Search for "stuff you should know"
  4. Select the first result ("Stuff You Should Know" by "iHeartPodcasts")
  5. Click Submit
  6. Click the Find Episodes button (magnifying glass)
  7. Check Select all episodes
  8. Click Download 2437 episodes

Server crash on OOM

Audiobookshelf version

v2.16.2

How are you running audiobookshelf?

Built from source

What OS is your Audiobookshelf server hosted from?

Windows

If the issue is being seen in the UI, what browsers are you seeing the problem on?

None

Logs

[2024-11-10 17:52:41.422] INFO: [Watcher] Initializing watcher for "Podcasts".
[2024-11-10 17:52:41.422] DEBUG: [Watcher] Init watcher for library folder path "F:/Podcasts3"
[2024-11-10 17:52:41.424] INFO: [Watcher] "Podcasts" Ready
[2024-11-10 17:53:05.786] DEBUG: [ApiCacheManager] count: 0 size: 0
[2024-11-10 17:53:05.789] DEBUG: Loaded filterdata in 0.00s
[2024-11-10 17:53:05.790] DEBUG: [ApiCacheManager] Cache miss: {"user":"root","url":"/libraries/2f9b22d3-3d6e-4134-9f95-42d975198612?include=filterdata"}
[2024-11-10 17:53:05.810] DEBUG: [ApiCacheManager] count: 1 size: 1059
[2024-11-10 17:53:05.811] DEBUG: [ApiCacheManager] Cache hit: {"user":"root","url":"/libraries/2f9b22d3-3d6e-4134-9f95-42d975198612?include=filterdata"}
[2024-11-10 17:53:05.868] DEBUG: [ApiCacheManager] count: 1 size: 1059
[2024-11-10 17:53:05.873] DEBUG: Loaded 0 of 0 items for "Continue Listening/Reading" in 0.00s
[2024-11-10 17:53:05.877] DEBUG: Loaded 0 of 0 episodes for "Newest Episodes" in 0.00s
[2024-11-10 17:53:05.881] DEBUG: Loaded 0 of 0 items for "Recently Added" in 0.00s
[2024-11-10 17:53:05.885] DEBUG: Loaded 0 of 0 items for "Listen/Read Again" in 0.00s
[2024-11-10 17:53:05.885] DEBUG: Loaded 0 personalized shelves in 0.01s
[2024-11-10 17:53:05.885] DEBUG: [ApiCacheManager] Cache miss: {"user":"root","url":"/libraries/2f9b22d3-3d6e-4134-9f95-42d975198612/personalized?include=rssfeed,numEpisodesIncomplete,share"}
[2024-11-10 17:53:05.885] DEBUG: [ApiCacheManager] Caching with 1800000 ms TTL
[2024-11-10 17:53:07.697] DEBUG: [ApiCacheManager] count: 2 size: 1302
[2024-11-10 17:53:07.697] DEBUG: [ApiCacheManager] Cache hit: {"user":"root","url":"/libraries/2f9b22d3-3d6e-4134-9f95-42d975198612?include=filterdata"}
[2024-11-10 17:53:07.750] DEBUG: [ApiCacheManager] count: 2 size: 1302
[2024-11-10 17:53:07.752] DEBUG: [ApiCacheManager] Cache miss: {"user":"root","url":"/libraries/2f9b22d3-3d6e-4134-9f95-42d975198612/podcast-titles"}
[2024-11-10 17:54:04.427] DEBUG: [iTunes] Searching for podcast with term "stuff you should know"
[2024-11-10 17:54:04.514] DEBUG: [iTunes] Podcast search for "stuff you should know" returned 31 results
[2024-11-10 17:54:11.896] DEBUG: [podcastUtils] getPodcastFeed for "https://www.omnycontent.com/d/playlist/e73c998e-6e60-432f-8610-ae210140c5b1/a91018a4-ea4f-4130-bf55-ae270180c327/44710ecc-10bb-48d1-93c7-ae270180c33e/podcast.rss"
[2024-11-10 17:54:12.510] DEBUG: [podcastUtils] getPodcastFeed for "https://www.omnycontent.com/d/playlist/e73c998e-6e60-432f-8610-ae210140c5b1/a91018a4-ea4f-4130-bf55-ae270180c327/44710ecc-10bb-48d1-93c7-ae270180c33e/podcast.rss" success - parsing xml
[2024-11-10 17:55:49.654] DEBUG: [fileUtils] Downloading file to F:/Podcasts3/Stuff You Should Know/cover
[2024-11-10 17:55:49.714] INFO: [CoverManager] Downloaded libraryItem cover "F:/Podcasts3/Stuff You Should Know/cover.jpg" from url "https://is1-ssl.mzstatic.com/image/thumb/Podcasts126/v4/17/a1/ce/17a1ce39-f248-8750-351a-0201206df213/mza_6600839420822557618.jpg/600x600bb.jpg" for "Stuff You Should Know"
[2024-11-10 17:55:49.715] DEBUG: [LibraryItem] Success saving abmetadata to "F:\VS Code Worksapces\audiobookshelf-local\audiobookshelf\metadata\items\77f96e6e-ca32-44e7-956c-08cf18f3a298\metadata.json"
[2024-11-10 17:55:49.735] DEBUG: [ApiCacheManager] libraryItem.afterCreate: Clearing cache
[2024-11-10 17:55:49.740] DEBUG: [ApiCacheManager] podcast.afterCreate: Clearing cache
[2024-11-10 17:55:49.867] DEBUG: [FfmpegHelpers] Resize Image Cmd: ffmpeg -i F:/Podcasts3/Stuff You Should Know/cover.jpg -y -vf scale=400:-1 F:\VS Code Worksapces\audiobookshelf-local\audiobookshelf\metadata\cache\covers\77f96e6e-ca32-44e7-956c-08cf18f3a298_400.webp
[2024-11-10 17:55:49.926] DEBUG: [FfmpegHelpers] Image resized Successfully
[2024-11-10 17:59:10.690] DEBUG: [podcastUtils] getPodcastFeed for "https://www.omnycontent.com/d/playlist/e73c998e-6e60-432f-8610-ae210140c5b1/a91018a4-ea4f-4130-bf55-ae270180c327/44710ecc-10bb-48d1-93c7-ae270180c33e/podcast.rss"
[2024-11-10 17:59:11.286] DEBUG: [podcastUtils] getPodcastFeed for "https://www.omnycontent.com/d/playlist/e73c998e-6e60-432f-8610-ae210140c5b1/a91018a4-ea4f-4130-bf55-ae270180c327/44710ecc-10bb-48d1-93c7-ae270180c33e/podcast.rss" success - parsing xml

<--- Last few GCs --->

[59600:00000201AFD58790]   634233 ms: Mark-Compact 3672.1 (4128.4) -> 3667.1 (4142.7) MB, 44.05 / 0.00 ms  (average mu = 0.970, current mu = 0.868) allocation failure; scavenge might not succeed
[59600:00000201AFD58790]   634346 ms: Mark-Compact 3682.8 (4142.7) -> 3679.1 (4156.2) MB, 102.03 / 0.00 ms  (average mu = 0.884, current mu = 0.098) allocation failure; scavenge might not succeed


<--- JS stacktrace --->

FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory
----- Native stack trace -----

 1: 00007FF7EDEC6E7B node::SetCppgcReference+16075
 2: 00007FF7EDE3D996 v8::base::CPU::num_virtual_address_bits+79190
 3: 00007FF7EDE3FBA5 v8::base::CPU::num_virtual_address_bits+87909
 4: 00007FF7EE8AD9E1 v8::Isolate::ReportExternalAllocationLimitReached+65
 5: 00007FF7EE897178 v8::Function::Experimental_IsNopFunction+1336
 6: 00007FF7EE6F8AA0 v8::Platform::SystemClockTimeMillis+659328
 7: 00007FF7EE6F5B28 v8::Platform::SystemClockTimeMillis+647176
 8: 00007FF7EE70AE3A v8::Platform::SystemClockTimeMillis+733978
 9: 00007FF7EE70B6B7 v8::Platform::SystemClockTimeMillis+736151
10: 00007FF7EE7142EE v8::Platform::SystemClockTimeMillis+772046
11: 00007FF7EE724E3A v8::Platform::SystemClockTimeMillis+840474
12: 00007FF7EE729908 v8::Platform::SystemClockTimeMillis+859624
13: 00007FF7EE38FB0B v8::internal::Version::GetString+89803
14: 00007FF7EE610B7C v8::ObjectTemplate::IsImmutableProto+192316
15: 00007FF7EE61214C v8::ObjectTemplate::IsImmutableProto+197900
16: 00007FF7EE6143F7 v8::ObjectTemplate::IsImmutableProto+206775
17: 00007FF7EE61764E v8::base::time_internal::TimeBase<v8::base::TimeTicks>::operator!=+9694
18: 00007FF7EE6135E7 v8::ObjectTemplate::IsImmutableProto+203175
19: 00007FF7EE6143F7 v8::ObjectTemplate::IsImmutableProto+206775
20: 00007FF7EE614C42 v8::ObjectTemplate::IsImmutableProto+208898
21: 00007FF7EE617252 v8::base::time_internal::TimeBase<v8::base::TimeTicks>::operator!=+8674
22: 00007FF7EE83D83A v8::SharedValueConveyor::SharedValueConveyor+258874
23: 00007FF7EE95EEAE v8::PropertyDescriptor::writable+676878
24: 00007FF76ED73C66

Additional Notes

Following the server process memory usage on Task Manager, I can confirm it quickly goes up to ~4Gb before it crashes.

@nichwall
Copy link
Contributor

Related to #3338

@advplyr
Copy link
Owner

advplyr commented Nov 11, 2024

Doing a search in issues that specific podcast has caused a few OOM crashes. Here is one #2075 (comment)

I did a quick test and the issue is that the download queue in PodcastManager is storing large objects (PodcastEpisodeDownload which contains the PodcastEpisode).
OOM when adding episode 2260 to the queue.

image

We can fix this by refactoring the queue so that it only stores the fields from the RSS feed that are sent in by the request, and construct the PodcastEpisode when the download starts for that episode. This might make the PodcastEpisodeDownload class unnecessary.

@mikiher
Copy link
Contributor Author

mikiher commented Nov 11, 2024

I also checked, and I think that is not the actual issue.

I think the actual issue is emitting episode_download_queue_updated with the value of this.getDownloadQueueDetails() every time we queue a download.

I believe this causes creation of O(n^2) large objects in quick succession, before they're even sent over the socket, which causes the crash.

If you remove this emit call, or put it after the loop that queues all the downloads, the OOM issue is gone.

@advplyr
Copy link
Owner

advplyr commented Nov 11, 2024

Yep removing that it only takes up ~250MB of heap. The socket event should definitely not be sending the entire queue.

Copy link

Fixed in v2.17.0.

@github-actions github-actions bot removed the awaiting release Issue is resolved and will be in the next release label Nov 17, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants