Heavy RAM usage (41GB) related to Open Subtitles?

[solidsnakex37 42]

I noticed this morning that Emby was using 41GB of RAM which is not common. I checked the logs and the only errors I could find were the following, also attached the server log from when this occurred. 

In unraid I checked what process was consuming all that memory and it was this, which matched the error in the emby server log

2023-11-01 00:05:09.847 Error SubtitleManager: Error downloading subtitles from Open Subtitles
	*** Error Report ***
	Version: 4.7.14.0
	Command line: /system/EmbyServer.dll -programdata /config -ffdetect /bin/ffdetect -ffmpeg /bin/ffmpeg -ffprobe /bin/ffprobe -restartexitcode 3
	Operating system: Linux version 6.1.49-Unraid (root@Develop-612) (gcc (GCC) 12.2.0, GNU ld version 2.40-slack151) #1 SMP PREEMPT_DYNAMIC Wed Aug 30 09:42:35 PDT 2023
	Framework: .NET 6.0.20
	OS/Process: x64/x64
	Runtime: system/System.Private.CoreLib.dll
	Processor count: 32
	Data path: /config
	Application path: /system
	System.Exception: System.Exception: Exception of type 'System.Exception' was thrown.
	   at OpenSubtitles.OpenSubtitleDownloader.ValidateResponseXml(String xml)
	   at OpenSubtitles.OpenSubtitleDownloader.Login(CancellationToken cancellationToken)
	   at OpenSubtitles.OpenSubtitleDownloader.Search(SubtitleSearchRequest request, CancellationToken cancellationToken)
	   at Emby.Providers.Subtitles.SubtitleManager.SearchSubtitles(SubtitleSearchRequest request, CancellationToken cancellationToken)
	Source: OpenSubtitles
	TargetSite: Void ValidateResponseXml(System.String)

Not sure what the above error indicates? I checked that I wasn't banned on open subs using https://www.opensubtitles.org/addons/show_my_ip.php

Also using the link above, it says I haven't downloaded any subs at all  in the last 24 hours, so I am more confused on what caused the memory usage to climb, unless it's a memory leak? 

 

Edited November 1, 2023 by solidsnakex37
Logs aren't anonymized

[solidsnakex37 42]

I posted the logs but removed them, noticed that even though I have the Anonymize Log Contents enabled, it still showed my hostname to my server which I won't want to advertise 

[solidsnakex37 42]

2023-11-01 00:07:17.110 Error SubtitleManager: Error downloading subtitles from Open Subtitles
	*** Error Report ***
	Version: 4.7.14.0
	Command line: /system/EmbyServer.dll -programdata /config -ffdetect /bin/ffdetect -ffmpeg /bin/ffmpeg -ffprobe /bin/ffprobe -restartexitcode 3
	Operating system: Linux version 6.1.49-Unraid (root@Develop-612) (gcc (GCC) 12.2.0, GNU ld version 2.40-slack151) #1 SMP PREEMPT_DYNAMIC Wed Aug 30 09:42:35 PDT 2023
	Framework: .NET 6.0.20
	OS/Process: x64/x64
	Runtime: system/System.Private.CoreLib.dll
	Processor count: 32
	Data path: /config
	Application path: /system
	System.Xml.XmlException: System.Xml.XmlException: Data at the root level is invalid. Line 1, position 1.
	   at System.Xml.XmlTextReaderImpl.Throw(Exception e)
	   at System.Xml.XmlTextReaderImpl.Throw(String res, String arg)
	   at System.Xml.XmlTextReaderImpl.ParseRootLevelWhitespace()
	   at System.Xml.XmlTextReaderImpl.ParseDocumentContent()
	   at OpenSubtitles.OpenSubtitleDownloader.ParseXmlResponse(String xml)
	   at OpenSubtitles.OpenSubtitleDownloader.SearchSubtitlesAsync(OpenSubtitleQuery[] queries, CancellationToken cancellationToken)
	   at OpenSubtitles.OpenSubtitleDownloader.Search(SubtitleSearchRequest request, CancellationToken cancellationToken)
	   at Emby.Providers.Subtitles.SubtitleManager.SearchSubtitles(SubtitleSearchRequest request, CancellationToken cancellationToken)
	Source: System.Private.Xml
	TargetSite: Void Throw(System.Exception)
	

This one seems different, adds more info to the exception "Data at the root level is invalid"

[Luke 37094]

HI, please attach the complete emby server log file. Thanks.

[solidsnakex37 42]

39 minutes ago, Luke said:

HI, please attach the complete emby server log file. Thanks.

Hey Luke! I just sent it over in a PM, thanks for taking a look!

[Luke 37094]

HI, please try removing these plugins:

	Episode Refresh 1.0.0.1
	Playback Reporting 2.0.1.0
	Samsung Smart Things 1.0.0.4

Then restart the server and see how things compare. Thanks.

[solidsnakex37 42]

On 11/2/2023 at 11:20 PM, Luke said:

HI, please try removing these plugins:

	Episode Refresh 1.0.0.1
	Playback Reporting 2.0.1.0
	Samsung Smart Things 1.0.0.4

Then restart the server and see how things compare. Thanks.

Hey Luke, 

I've removed all of the above plugins as requested, though today I am seeing that large spike in RAM usage again. The other day it was as high as 40GB, right now I am seeing it again at 20GB. 

I've sent you the latest server logs, sorry I would post here but I am finding that the logs have IPs of my current users and the hostname of my server (I wish this would be redacted in the anonymize logs setting). 

Thanks again for your help with this, Happy Thanksgiving! 

[solidsnakex37 42]

Something else I just noticed, I am seeing ffmpeg-remux log files? I've been using Emby for at least a year, I don't think i've ever come across a remux log? I've only ever seen transcode logs, wanted to mention this in case this may be a factor in the high RAM usage. 



Though, everything should be going to /tmp which I have mapped to a cache drive in Unraid. 

Edited November 23, 2023 by solidsnakex37
added more info

[solidsnakex37 42]

Usage just went from 20GB to 32GB so it seems to fluctuate. I tried restarting the Emby server through the UI (Admin Dashboard) but that RAM usage remained? Seems like the restart option in Emby isn't a full restart. 

If I restart the Emby Server container, this resets RAM usage. 

I personally don't mind if Emby uses a good amount of RAM, the issue is just when it runs off and causes my whole server to freeze up. Last week it went up to 40GB and maxed out my system memory and my Unraid UI become unresponsive. I could still get into Emby so I shutdown the Emby server from there. 

[jaycedk 383]

/tmp is a ram drive in unraid.

My guess is that you are using that as your transcoding drive.

Try to use something else, just as an test.

And report back.

[solidsnakex37 42]

45 minutes ago, jaycedk said:

/tmp is a ram drive in unraid.

My guess is that you are using that as your transcoding drive.

Try to use something else, just as an test.

And report back.

Well I have /tmp mapped to a transcode share, do you mean change the container mapping to something like /temp as well as in Emby? 

[jaycedk 383]

Hmm might have miss read that, sorry about that.

 

[solidsnakex37 42]

9 minutes ago, jaycedk said:

Hmm might have miss read that, sorry about that.

 

No worries! I wondered about that though, I posted a pic of my container mapping and the emby mapping just incase. Though it doesn't seem to increase when transcodes are happening, sometimes I don't see any transcodes or playback activities and the jobs don't appear to be running anything at least the UI isn't reporting it. 

[solidsnakex37 42]

I found that when the high RAM usage was occurring, there are loads of intro detection processes taking place. Though, no tasks appear to be running in the dashboard, despite this process running. 

It looks like this was resolved in the latest beta version of Emby server. 

• Fix Intro Detection scheduled task not being visible

Listed under 4.8.0.63 Beta 
https://github.com/MediaBrowser/Emby.Releases/releases

I believe this is my issue which is fixed. I can't wait for the next stable release of Emby Server. So many improvements. I might have to play around with the Beta release! 

[solidsnakex37 42]

I am having this issue again, Emby container is consuming large amounts of RAM and causing my entire array to be unresponsive.

If you look at my netdata chart, Emby consumed a total of 48GB of RAM. Every 30 minutes in the chart, it continued to consume around 8GB of RAM. 

I've attached the server log from around this time stamp. 

I am running the latest version now, 4.8.1.0 in Docker. 

This has happened 3 times over the last 48 hours and took me a bit to figure out this was Emby again. 

The log was large, so I just cut out the parts prior to the graph increasing and left the startup details. The logs cover about 20 min before the RAM spike.

If you want the full log, it's 15MB 80,000 lines, but I can provide it. (just been an issue in the past).

Graph below is from 19:39-23:05 where it drops (thankfully, the container seemed to have crashed or something and not my whole server this time). 

embyserver-63843897600.txt

Edited February 19 by solidsnakex37
correction

[Lessaj 61]

I'm not sure if this is causing it but something I see here is it looks like a lot of your NFO files under cinema have an invalid structure. This one for example is Atlantis: The Lost Empire. You can try to look at the NFO and see if the date on it has changed recently, could try to throw it into an XML validator to see if there's something missing. Can also maybe delete the NFO and refresh metadata on this item and see if it has a error after?

2024-02-18 20:57:26.874 Info LibraryMonitor: cinema (/media/movies/cinema) will be refreshed.
2024-02-18 20:57:27.210 Info HttpClient: GET https://api4.thetvdb.com/v4/movies/768/extended?meta=translations
2024-02-18 20:57:27.339 Info HttpClient: GET https://api.themoviedb.org/3/movie/10865?api_key=x_secret9_x&append_to_response=alternative_titles,reviews,casts,releases,images,keywords,trailers&language=en-US&include_image_language=en-US,en,null,en
2024-02-18 20:57:27.535 Error App: Error reading existng nfo
	System.Xml.XmlException: System.Xml.XmlException: Data at the root level is invalid. Line 176, position 1.

 

[solidsnakex37 42]

3 minutes ago, Lessaj said:

I'm not sure if this is causing it but something I see here is it looks like a lot of your NFO files under cinema have an invalid structure. This one for example is Atlantis: The Lost Empire. You can try to look at the NFO and see if the date on it has changed recently, could try to throw it into an XML validator to see if there's something missing. Can also maybe delete the NFO and refresh metadata on this item and see if it has a error after?

2024-02-18 20:57:26.874 Info LibraryMonitor: cinema (/media/movies/cinema) will be refreshed.
2024-02-18 20:57:27.210 Info HttpClient: GET https://api4.thetvdb.com/v4/movies/768/extended?meta=translations
2024-02-18 20:57:27.339 Info HttpClient: GET https://api.themoviedb.org/3/movie/10865?api_key=x_secret9_x&append_to_response=alternative_titles,reviews,casts,releases,images,keywords,trailers&language=en-US&include_image_language=en-US,en,null,en
2024-02-18 20:57:27.535 Error App: Error reading existng nfo
	System.Xml.XmlException: System.Xml.XmlException: Data at the root level is invalid. Line 176, position 1.

 

That is strange, looking at the .nfo file, Line 176 is <micodec>dts</micodec>

If I run it through a XML validator, it's not finding any errors. 


Atlantis The Lost Empire (2001) [imdbid-tt0230011] - [Remux-1080p][DTS-HD MA 5.1][AVC]-FraMeSToR.nfo

[Lessaj 61]

Was this NFO recently updated? Could be a red herring error if it just replaces the NFO. I'm also seeing a lot of RTM refreshes for cinema folder, if you have anything in this root folder that kept changing that might cause that. Ideally there should only be folders under this folder. Otherwise beyond that it's mostly showing subtitle download attempts.

[solidsnakex37 42]

 

Just now, Lessaj said:

Otherwise beyond that it's mostly showing subtitle download attempts.

So 2 out of the 3 times this occurred over the weekend, my entire server had to be rebooted. This last event (last night, in the graph above), I was able to get into my server and open Emby after a few attempts, it dropped to 15GB usage and things came back up, the only task I saw running in the dashboard was Download Subtitles. There was no library scan or anything else. I had suspected before when this first occurred it was an issue downloading subtitles, but I can't prove it. 

That .nfo file was modified around 8:57 (20:57), at least that's the date modified on the file. 

In my server log file I attached, there are 1255 hits for Error Reports over that 4 hour period, which is a lot. They seem to vary between: 

Error SubtitleManager: Error searching for subtitles on Open Subtitles
Error App: Error sending web socket message Sessions
Error App: Error reading existng nfo
Error Trakt: Exception handled sending status update
Error Notifications: Error sending notification

I am going to kick off the download subtitles task and see if I can replicate the behavior and see

 

[solidsnakex37 42]

I haven't been able to replicate it manually, however I just got an alert that Emby is consuming over 35GB of memory again. There are no tasks running on the dashboard. No streams running. I've attached the server log, and screenshot below showing the same incremental increase over a 2 hour period. 

 

 

embyserver (4).txt

[Luke 37094]

Hi, please try removing these plugins:

2024-02-23 14:23:01.360 Info App: Loading Emby.Bulky, Version=1.0.20.0, Culture=neutral, PublicKeyToken=null from /config/plugins/Emby.Bulky.dll
2024-02-23 14:23:01.360 Info App: Loading Emby.Plugins.AniSearch, Version=1.0.1.0, Culture=neutral, PublicKeyToken=null from /config/plugins/Emby.Plugins.AniSearch.dll
2024-02-23 14:23:01.360 Info App: Loading MediaBrowser.Plugins.Anime, Version=1.5.6.0, Culture=neutral, PublicKeyToken=null from /config/plugins/MediaBrowser.Plugins.Anime.dll
2024-02-23 14:23:01.360 Info App: Loading playback_reporting, Version=2.1.0.5, Culture=neutral, PublicKeyToken=null from /config/plugins/playback_reporting.dll

Then restart the server and see how things compare.

[solidsnakex37 42]

8 minutes ago, Luke said:

Hi, please try removing these plugins:

2024-02-23 14:23:01.360 Info App: Loading Emby.Bulky, Version=1.0.20.0, Culture=neutral, PublicKeyToken=null from /config/plugins/Emby.Bulky.dll
2024-02-23 14:23:01.360 Info App: Loading Emby.Plugins.AniSearch, Version=1.0.1.0, Culture=neutral, PublicKeyToken=null from /config/plugins/Emby.Plugins.AniSearch.dll
2024-02-23 14:23:01.360 Info App: Loading MediaBrowser.Plugins.Anime, Version=1.5.6.0, Culture=neutral, PublicKeyToken=null from /config/plugins/MediaBrowser.Plugins.Anime.dll
2024-02-23 14:23:01.360 Info App: Loading playback_reporting, Version=2.1.0.5, Culture=neutral, PublicKeyToken=null from /config/plugins/playback_reporting.dll

Then restart the server and see how things compare.

Removed the following and will keep monitoring further: 

Bulky 1.0.20.0
AniSearch 1.0.1.0
Anime 1.5.6.0
Playback Reporting 2.1.0.5

[solidsnakex37 42]

The plugins above are still removed, however I am seeing the same behavior again today. The blue is the Emby container, this is over the last 6 hours. 

Current status: 
No scans are showing in the dashboard
Only direct streams are currently in progress
Current RAM usage is 34GB
Current logs attached 

embyserver (15).txt

[solidsnakex37 42]

I continued to monitor it and around an hour or two after my post above, it climbed to around 62GB+ of usage, then just dropped back to normal RAM usage. 

[Luke 37094]

Hi, that's interesting. Thanks for the update.