Metadata download unreliable

Server Version#: 1.16.5.1554

Brief history of the issue; Metadata will not download. Had this or related issues for a while now., Metadata download is unreliable and intermittent.

Items appear to match correctly, but metadata doesn’t download. No particular reason, progress indicator spins and spins but nothing ever happens. Sometimes information will update without posters or art. Sometimes, everything does download but only after a zillion “refresh metadata” over a 24 hour period.

It appears to be dependent on time of day too. I’m in the UK, it’s more likely to fail later in the day. Past about 9pm you can forget about it which for me suggests a loading issue on a server. Interestingly, manually browsing to the sources of information appears to be successful (i.e, imdb, tvdb.org etc… all up with correct information being shown in a browser.)

Had an issue getting a file to even match (2005 animated film “Robots”) so turned on debugging. Eventually was able to fix through removing the item, cleaning the database, deleting bundles and emptying trash and then re-adding. Item now matches but stuck with same metadata downloading issue. Since I have the debugging turned on thought I’d dig deeper.

Here’s the weird thing for me. in the com.plexapp.agents.imdb.log file, there are entries like “2019-08-31 19:36:22,806 (ea4) : DEBUG (networking:198) - Not caching ‘http://image.tmdb.org/t/p/w154/vYy0Afpj571fVYmw4tLHHRd6Fhy.jpg’ (content type ‘image/jpeg’ not cacheable in Agent plug-ins)”

Now http://image.tmdb.org/t/p/w154/vYy0Afpj571fVYmw4tLHHRd6Fhy.jpg is a real file I can browse to… it’s a movie poster for this movie Robots. There are a few of these links, all to posters and artwork. So the weird thing is, it DOES appear to be requesting and downloading the artwork, posters and I would assume any other metadata… it just doesn’t ever actually appear. Weirdly, while trying to fix the “matching” issue with this file I matched it to a different film and metadata DID (eventually) download.

Since the symptoms are the same as any other time I’ve had this issue, I’m going to guess it’s the same. Metadata and posters do EVENTUALLY download at some random time and this might eventually be the same. because it does work eventually I’m ruling out permissions. I can browse the resources in a browser so I’m ruling our network access and I can see those entries in the Plex log file so I know the Plex server is attempting to download the right stuff.

Issue has persisted for some time and over multiple versions of PMS. Since the problem eventually, randomly goes away for each item it seems like something that should be fixable, but I can’t see what. Log files are attached (I hope)

Plex Media Server Logs_2019-08-31_19-42-40.zip (561.8 KB)

Oh boy! Your log report 3500 errors and 1100 warnings.
From not connecting to xxx, slow queries, unable to load nvcuda.dll.
I would start by clearing cache. Exit PMS first
https://support.plex.tv/articles/202967376-clearing-plugin-channel-agent-http-caches/

Then check HW transcoding. If you don’t have/use it then disable(uncheck) in settings.
Setting>Transcoder>Use hardware acceleration when available.

Also, try and optimize your database

OK, thanks for taking a look. I’d done some of that but following your suggestion I took the opportunity to disable the “use hardware acceleration” optio, and also clean up a bunch of other things.

I would say that the checkbox implies hw acceleration will only work if available. Since there is no hw acceleration available (at all, it’s running on a generic VGA driver) then the checkbox implies that hw acceleration won’t be attempted. If it isn’t, then how is it looking for things and throwing errors. Looks like the wording on the checkbox should be changed to “Use HW acceleration regardless of whether it’s available or not and throw a bunch of errors if it isn’t.”

So, with HW acceleration disabled, i disabled PMS, removed a bunch of old plugins and agents. I then restarted PMS and re-optimised the Database and deleted bundles from the troubleshooting page. I then re-shut down PMS, cleared the cache AND removed the logs file to help narrow the logs to only current issues. I have not restarted PMS and attempted to download metadata on the offending item. No change, so again the (now much smaller) logs are attached.

Plex Media Server Logs_2019-09-01_21-43-00.zip (34.3 KB)

I know… An oversight I guess…

Your new logs

Sep 01, 2019 21:32:50.877 [3040] ERROR - QueryParser: Invalid field 'onlyTransient' found, ignoring.
Sep 01, 2019 21:32:50.877 [3040] ERROR - QueryParser: Invalid field 'onlyTransient' found, ignoring.
Sep 01, 2019 21:32:50.892 [3040] ERROR - QueryParser: Invalid field 'onlyTransient' found, ignoring.
Sep 01, 2019 21:32:50.892 [3040] ERROR - QueryParser: Invalid field 'onlyTransient' found, ignoring.
Sep 01, 2019 21:32:50.908 [3040] ERROR - QueryParser: Invalid field 'onlyTransient' found, ignoring.
Sep 01, 2019 21:32:55.884 [3596] ERROR - [PlexRelay] kex protocol error: type 7 seq 11
Sep 01, 2019 21:32:59.722 [3708] ERROR - Error issuing curl_easy_perform(handle): 7
Sep 01, 2019 21:33:00.237 [2584] ERROR - Unknown metadata type: 
Sep 01, 2019 21:33:00.283 [1552] ERROR - Unknown metadata type: 
Sep 01, 2019 21:33:00.471 [3360] ERROR - EventSource: Retrying in 15 seconds.
Sep 01, 2019 21:33:04.901 [3264] ERROR - Error issuing curl_easy_perform(handle): 28
Sep 01, 2019 21:33:04.901 [2648] ERROR - Error issuing curl_easy_perform(handle): 28
Sep 01, 2019 21:33:05.073 [2008] ERROR - Unknown metadata type: 
Sep 01, 2019 21:33:11.422 [2008] ERROR - Unknown metadata type: 
Sep 01, 2019 21:33:15.821 [3088] ERROR - EventSource: Retrying in 30 seconds.
Sep 01, 2019 21:33:46.194 [3360] ERROR - EventSource: Retrying in 60 seconds.
Sep 01, 2019 21:34:46.535 [3088] ERROR - EventSource: Retrying in 120 seconds.
Sep 01, 2019 21:36:46.905 [3088] ERROR - EventSource: Retrying in 240 seconds.
Sep 01, 2019 21:40:47.395 [3360] ERROR - EventSource: Retrying in 480 seconds.

I’d like to know what Unknown metadata type: means.
Got a warning

Sep 01, 2019 21:32:59.722 [3708] WARN - HTTP error requesting GET https://176-25-219-223.9c9d8feda5594867989cd2775618ec71.plex.direct:18235/identity (0, No error) (Failed to connect to 176-25-219-223.9c9d8feda5594867989cd2775618ec71.plex.direct port 18235: Connection refused)

Seems like its having connecting issues.

I saw that but I haven’t the foggiest idea why though. Everything is working otherwise including remote access, so I’m unsure what the URL “https://176-25-219-223.9c9d8feda5594867989cd2775618ec71.plex.direct:18235” is or why it might be failing. It certainly doesn’t work in a browser

Some more weirdness, in the file com.plexapp.agents.imdb there is whole section of errors which look very much like this “fixed” error shown in this bug tracker from 2013; Metadata request timeouts while syncing should be handled gracefully · Issue #55 · trakt/Plex-Trakt-Scrobbler · GitHub

Also there are still entries at the end of that file like this…

2019-09-01 21:39:55,759 (9a4) : DEBUG (networking:198) - Not caching ‘http://image.tmdb.org/t/p/w300/4WdWgRuyTFJDo8LWrOs4k1gfuBH.jpg’ (content type ‘image/jpeg’ not cacheable in Agent plug-ins)

If you look at the URL in a browser, it’s artwork and backgrounds for this film… so it appears it IS getting some metadata. I’m baffled if I know what it’s doing with it though, it certainly isn’t appearing where it should.

Right, update. If I use my phone’s 4G to connect to that .direct URL, it will connect. If I use my network, it will not. I’ve switched to both OpenDNS servers and Google Server for DNS with no luck. Looks like my ISP is just filtering out connections to .direct URL’s at this time. Weird cause it’s SKY in the UK, one of the biggest ISP’s.

Annoyingly, this is a kinda known issue, see this post here… Explanation, in technical detail, about how to avoid relaying? - #8 by OttoKerner and yet despite knowing that ISP’s aren’t happy with .direct URL’s plex seems unable to pony up the 10 quid or so to change URL to something less troublesome.

I will continue to investigate and search for a workaround.

OK. At some point in the last few minutes, the metadata updated. I don’t think the plex.direct thing was the issue ( think that’s used to communicate directly with the clients), but I’m not sure. Only change between working to not working seems to be changing from Google DNS to OpenDNS. I will see what happens when I finish ripping and uploading my next batch.

Either way, I think you’ve convinced me to beef up the server hardware!

Worth a try:
Disable support for IPv6

Interestingly I did do that too but forgot. I’m please to report that with NewPlaza’s advice and a bit of a clean I just transferred a new batch of files in and they all got matched and downloaded rapidly. Hope that’s the last of that issue…

What I have found that worked for me was to unmatch the artist, the match again. That has fixed all of the issues I have been having with cover art. It is a fix as you go sorta thing, but much more manageable than adding cover art to individual discs when adding many cds in a rip party.