Emby Removing and Readding Dozens of series for unknown reason

[dicion 3]

Hello, this started yesterday at ~9:30AM. Emby removed, and then completely readded about 2 dozen series, some that have been there, untouched, working fine for 6+ months.

It happened again this morning at ~9:30AM. About 2 dozen Different series were affected.

I do recognize the fact that this was almost exactly 24 hours apart, and I'm trying to find the root cause, and understand that it may not be Emby's fault, and hopefully the logs can point me/us to the actual cause.

The timing seems to align with my 'download subtitles' task in Emby.

Here's some excerpts of the logs that starts the removal and readdition of each series:

 

2023-02-08 09:33:31.854 Error App: Error reading existng nfo
	*** Error Report ***
	Version: 4.7.11.0
	Command line: C:\Users\rt\AppData\Roaming\Emby-Server\system\EmbyServer.dll
	Operating system: Microsoft Windows 10.0.19044
	Framework: .NET 6.0.10
	OS/Process: x64/x64
	Runtime: C:/Users/rt/AppData/Roaming/Emby-Server/system/System.Private.CoreLib.dll
	Processor count: 16
	Data path: C:\Users\rt\AppData\Roaming\Emby-Server\programdata
	Application path: C:\Users\rt\AppData\Roaming\Emby-Server\system
	System.Xml.XmlException: System.Xml.XmlException: Data at the root level is invalid. Line 83, position 1.
	   at System.Xml.XmlTextReaderImpl.Throw(Exception e)
	   at System.Xml.XmlTextReaderImpl.ParseRootLevelWhitespace()
	   at System.Xml.XmlTextReaderImpl.ParseDocumentContent()
	   at NfoMetadata.Savers.BaseNfoSaver.AddCustomTags(String path, List`1 xmlTagsUsed, XmlWriter writer, ILogger logger, IFileSystem fileSystem)
	   at NfoMetadata.Savers.BaseNfoSaver.Save(BaseItem item, LibraryOptions libraryOptions, Stream stream, String xmlPath)
	Source: System.Private.Xml
	TargetSite: Void Throw(System.Exception)

It then drops everything, re-ffprobes them, and rescans and puts them back in.

Here's another example

2023-02-08 09:33:58.453 Error App: Error reading existng nfo
	*** Error Report ***
	Version: 4.7.11.0
	Command line: C:\Users\rt\AppData\Roaming\Emby-Server\system\EmbyServer.dll
	Operating system: Microsoft Windows 10.0.19044
	Framework: .NET 6.0.10
	OS/Process: x64/x64
	Runtime: C:/Users/rt/AppData/Roaming/Emby-Server/system/System.Private.CoreLib.dll
	Processor count: 16
	Data path: C:\Users\rt\AppData\Roaming\Emby-Server\programdata
	Application path: C:\Users\rt\AppData\Roaming\Emby-Server\system
	System.Xml.XmlException: System.Xml.XmlException: Data at the root level is invalid. Line 48, position 1.
	   at System.Xml.XmlTextReaderImpl.Throw(Exception e)
	   at System.Xml.XmlTextReaderImpl.ParseRootLevelWhitespace()
	   at System.Xml.XmlTextReaderImpl.ParseDocumentContent()
	   at NfoMetadata.Savers.BaseNfoSaver.AddCustomTags(String path, List`1 xmlTagsUsed, XmlWriter writer, ILogger logger, IFileSystem fileSystem)
	   at NfoMetadata.Savers.BaseNfoSaver.Save(BaseItem item, LibraryOptions libraryOptions, Stream stream, String xmlPath)
	Source: System.Private.Xml
	TargetSite: Void Throw(System.Exception)

And another 

2023-02-08 09:35:42.568 Error App: Error reading existng nfo
	*** Error Report ***
	Version: 4.7.11.0
	Command line: C:\Users\rt\AppData\Roaming\Emby-Server\system\EmbyServer.dll
	Operating system: Microsoft Windows 10.0.19044
	Framework: .NET 6.0.10
	OS/Process: x64/x64
	Runtime: C:/Users/rt/AppData/Roaming/Emby-Server/system/System.Private.CoreLib.dll
	Processor count: 16
	Data path: C:\Users\rt\AppData\Roaming\Emby-Server\programdata
	Application path: C:\Users\rt\AppData\Roaming\Emby-Server\system
	System.Xml.XmlException: System.Xml.XmlException: Data at the root level is invalid. Line 50, position 1.
	   at System.Xml.XmlTextReaderImpl.Throw(Exception e)
	   at System.Xml.XmlTextReaderImpl.ParseRootLevelWhitespace()
	   at System.Xml.XmlTextReaderImpl.ParseDocumentContent()
	   at NfoMetadata.Savers.BaseNfoSaver.AddCustomTags(String path, List`1 xmlTagsUsed, XmlWriter writer, ILogger logger, IFileSystem fileSystem)
	   at NfoMetadata.Savers.BaseNfoSaver.Save(BaseItem item, LibraryOptions libraryOptions, Stream stream, String xmlPath)
	Source: System.Private.Xml
	TargetSite: Void Throw(System.Exception)
	

 

I see that they are all variations of "Data at the root level is invalid." errors. What I don't know is what that means specifically. Again, these are series that have been in place for 6+ Months without anything changing. I didn't change any metadata myself. However, they are not LOCKED from changes.

 

In the logs, preceding each of these, I also saw this:

2023-02-08 09:31:24.240 Info HttpClient: GET https://api4.thetvdb.com/v4/series/73630/extended?meta=translations
2023-02-08 09:31:24.670 Info HttpClient: POST https://api.opensubtitles.org/xml-rpc
2023-02-08 09:31:24.735 Info HttpClient: GET https://api.themoviedb.org/3/tv/44?api_key=x_secret1_x&append_to_response=alternative_titles,reviews,credits,images,keywords,external_ids,videos,content_ratings&language=en&include_image_language=en,null
2023-02-08 09:31:25.211 Info HttpClient: GET https://private.omdbapi.com?apikey=x_secret2_x&i=tt0222518&plot=short&tomatoes=true&r=json
2023-02-08 09:31:25.810 Info HttpClient: GET https://webservice.fanart.tv/v3/tv/73630?api_key=x_secret3_x
2023-02-08 09:31:25.895 Info HttpClient: POST https://api.opensubtitles.org/xml-rpc
2023-02-08 09:31:26.498 Info HttpClient: POST https://api.opensubtitles.org/xml-rpc
2023-02-08 09:31:26.659 Error App: Error reading existng nfo

I looked into the Show IDs in these url's, and they Are the shows that are immediately being nuked afterwards.

My theory is that for some reason, metadata or other information is being pulled/scraped from these databases, perhaps while downloading subtitles, and it's breaking the XML somehow, causing a complete nuke and rescan? Has anyone else seen this? Is there any way to check the XML format of the nfo file before/after the update so I can see what, specifically, broke it? Does emby keep a backup anywhere?

Basically, I'm just looking to see if there are others experiencing this, and if there is any known solution other than locking all my series from metadata changes.

Did one of the major DB's have some formatting/output change that breaks rescans starting yesterday? Etc. Is it a systemic problem due to a third party change that needs to be adapted/adjusted for. That sort of thing.

Attached is the whole log for more details. Look around 09:31:24.240 for the start.

embyserver.txt

Edited February 8, 2023 by dicion

[ebr 16187]

Hi.  Those XML errors are not the problem.  Here is your issue:

	System.IO.IOException: System.IO.IOException: The specified network name is no longer available. : '\\192.168.50.8\mainshare\mediashare\TVShows\Star Trek (1966)'

Has something in your network changed? Maybe that IP address?  You may want to use a name there instead of address.

[dicion 3]

Edit: Deleted. Yes, this does appear to be the cause, looking into more. Thanks.

 

Edit2: Specifically, when my Synology NAS performs Data scrubbing at night, it's dropping SMB connections left and right, hundreds of times. I need to look into why it's doing that and stop it if possible. Thanks for pointing that out.

Edited February 8, 2023 by dicion

[dicion 3]

Just for anyone searching in the future that may have this issue.

If you're using a Synology NAS, other people have reported that having the 'Raid Resync Speed Limits' on 'Run Faster' can cause performance issues during resync and scrubbing operations. Mine was indeed, on 'go fast' mode. The dialog looks like this:

https://i.imgur.com/E2Irpkx.png

It's recommended to change it to 'Lower the impact' so it doesn't affect services while running. I have done this and await to see if this fixes my issue. Unfortunately, I'm going to have to wait a month or more until the next time scrubbing happens.

Admins: Maybe this is something that can fit in some FAQ somewhere with regard to using external NAS devices or network shares. That Emby is very aggressive with maintaining SMB connections when using network shares and anything that causes those to blip or drop can cause issues, and to recommend setting this setting properly on Synology NAS units, as they are one of the most popular ones used by home users. Your call

Edited February 8, 2023 by dicion

[Luke 42083]

1 hour ago, dicion said:

Just for anyone searching in the future that may have this issue.

If you're using a Synology NAS, other people have reported that having the 'Raid Resync Speed Limits' on 'Run Faster' can cause performance issues during resync and scrubbing operations. Mine was indeed, on 'go fast' mode. The dialog looks like this:

https://i.imgur.com/E2Irpkx.png

It's recommended to change it to 'Lower the impact' so it doesn't affect services while running. I have done this and await to see if this fixes my issue. Unfortunately, I'm going to have to wait a month or more until the next time scrubbing happens.

Admins: Maybe this is something that can fit in some FAQ somewhere with regard to using external NAS devices or network shares. That Emby is very aggressive with maintaining SMB connections when using network shares and anything that causes those to blip or drop can cause issues, and to recommend setting this setting properly on Synology NAS units, as they are one of the most popular ones used by home users. Your call

Thanks for the feedback.

[Happy2Play 9783]

44 minutes ago, Luke said:

Thanks for the feedback.

Doesn't this fall under all the other topics of Emby dumping library when there are issues?

Shouldn't Emby maintain all library links while there is a assign library path and only dump when configured library is removed as access should be irrelevant?

Edited February 8, 2023 by Happy2Play

[Luke 42083]

11 minutes ago, Happy2Play said:

Doesn't this fall under all the other topics of Emby dumping library when there are issues?

Shouldn't Emby maintain all library links while there is a assign library path and only dump when configured library is removed as access should be irrelevant?

It sounds like it, yes. This should be improved a bit in the 4.8 release.