Kind of been stumped with this lately, new movies are not having metadata attached/updated, but my TV show library does.
If anyone more knowledgeable about where to look in the logs would take a look, I would appreciate it.
Things I have tried:
Any input would be greatly appreciated.
Your logs are in ‘Verbose’ mode. They are almost unusable because of this.
See the notice to the right -->
Have you ever started Plex Server ‘As Administrator’ ? (you should never)
Did you install a new anti virus/personal firewall/privacy guard etc pp?
Which anti virus is in use?
Thank you for the reply!
No new AV/Firewall has been installed.
I only run Windows Defender on this machine since day one.
I do not run as admin.
I have attached the non-verbose logs.
After disabling IPv6 support within Plex , did you restart the Plex server?
Is this a Windows Server edition?
Are Windows updates activated?
I don’t see any attempts to match a movie in your logs within the last 2 days.
Please go to the video that doesn’t get any metadata and copy its Plex XML info and paste it into here (please enclose the XML with triple backticks ` above and below it).
Then perform the Plex Dance with the movie, wait 3 minutes, then grab fresh logs and post them again please.
I have restarted the machine several times since disabling IPv6 within Plex.
Windows 10 Pro 64 Bit.
Windows Updates are activated.
XML info for one of the files that will not update metadata:
<MediaContainer size="1" allowSync="1" identifier="com.plexapp.plugins.library" librarySectionID="1" librarySectionTitle="Movies" librarySectionUUID="cc3d7986-1311-4bf7-b97e-2e0348a92d70" mediaTagPrefix="/system/bundle/media/flags/" mediaTagVersion="1510645826">
<Video ratingKey="82573" key="/library/metadata/82573" guid="com.plexapp.agents.imdb://tt0338348?lang=en" librarySectionID="1" librarySectionKey="/library/sections/1" type="movie" title="The Polar Express" titleSort="Polar Express" summary="" thumb="/library/metadata/82573/thumb/1512106474" art="/library/metadata/82573/art/1512106474" duration="5996693" addedAt="1512106466" updatedAt="1512106474">
<Media videoResolution="720" id="389865" duration="5996693" bitrate="968" width="1280" height="528" aspectRatio="2.35" audioChannels="2" audioCodec="aac" videoCodec="h264" container="mp4" videoFrameRate="24p" optimizedForStreaming="0" audioProfile="lc" has64bitOffsets="0" videoProfile="main">
<Part accessible="1" exists="1" id="391732" key="/library/parts/391732/1512106270/file.mp4" duration="5996693" file="D:\Movies\The Polar Express (2004).mp4" size="725691631" audioProfile="lc" container="mp4" has64bitOffsets="0" optimizedForStreaming="0" videoProfile="main">
<Stream id="764359" streamType="1" default="1" codec="h264" index="0" bitrate="803" bitDepth="8" chromaSubsampling="4:2:0" colorRange="tv" colorSpace="bt709" frameRate="23.975" hasScalingMatrix="0" height="528" level="31" profile="main" refFrames="4" streamIdentifier="1" width="1280" />
<Stream id="764360" streamType="2" selected="1" default="1" codec="aac" index="1" channels="2" bitrate="165" audioChannelLayout="stereo" profile="lc" samplingRate="48000" streamIdentifier="2" />
</Part>
</Media>
<Extras size="0">
</Extras>
</Video>
</MediaContainer>
The thumbnail preview for the movie just sits with the animated spinning tag icon on it in perpetuity. Waited 10 minutes before downloading new logs.
I have the same problem new movie don’t get new data
same problem here with windows 10 Pro 64 Bit and 1.10.0.4523
The update request in your server produces an error or times out.
2017-12-02 08:59:22,404 (2158) : ERROR (networking:219) - Error opening URL 'http://127.0.0.1:32400/:/plugins/com.plexapp.agents.imdb/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKZW5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNQo4MjU3NHM0CmRiaWRpMApzNwp2ZXJzaW9ubnMxMApwYXJlbnRHVUlEbnM4CnBhcmVudElEczUKTW92aWVzMTAKbWVkaWFfdHlwZXM0Mwpjb20ucGxleGFwcC5hZ2VudHMuaW1kYjovL3R0MDMzODM0OD9sYW5nPWVuczQKZ3VpZHM5CnR0MDMzODM0OHMyCmlkcjAK'
2017-12-02 08:59:22,405 (2158) : CRITICAL (core:579) - Exception in update for com.plexapp.agents.imdb://tt0338348?lang=en (most recent call last):
File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-a39b25852\System.bundle\Contents\Code\agentservice.py", line 407, in update_task
self.agent_update_metadata(identifier, media_type, guid, id, lang, dbid, parentGUID, force, version, parentID, periodic)
File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-a39b25852\System.bundle\Contents\Code\agentservice.py", line 1236, in agent_update_metadata
kwargs=kwargs
File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-a39b25852\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\components\messaging.py", line 86, in call_external_function
packed_result = self._core.networking.http_request(url, cacheTime=0, timeout=None, immediate=True).content
File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-a39b25852\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\components
etworking.py", line 370, in http_request
return HTTPRequest(self._core, url, data, h, url_cache, encoding, errors, timeout, immediate, sleep, opener, follow_redirects, method)
File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-a39b25852\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\components
etworking.py", line 141, in __init__
self.load()
File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-a39b25852\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\components
etworking.py", line 181, in load
f = self._opener.open(req, timeout=self._timeout)
File "C:\Program Files (x86)\Plex\Plex Media Server\python27.zip\urllib2.py", line 435, in open
response = meth(req, response)
File "C:\Program Files (x86)\Plex\Plex Media Server\python27.zip\urllib2.py", line 548, in http_response
'http', request, response, code, msg, hdrs)
File "C:\Program Files (x86)\Plex\Plex Media Server\python27.zip\urllib2.py", line 473, in error
return self._call_chain(*args)
File "C:\Program Files (x86)\Plex\Plex Media Server\python27.zip\urllib2.py", line 407, in _call_chain
result = func(*args)
File "C:\Program Files (x86)\Plex\Plex Media Server\python27.zip\urllib2.py", line 556, in http_error_default
raise HTTPError(req.get_full_url(), code, msg, hdrs, fp)
HTTPError: HTTP Error 500: Internal Server Error
I think I need help with this one.
@sa2000 could you take a look?
Same Probleme
Win 10 family
plex server 1.10.0.4523
@OttoKerner said:
I think I need help with this one.
@sa2000 could you take a look?
There seem to be slow processing of requests to fetch images -
2017-12-02 08:49:22,703 (1938) : DEBUG (networking:166) - Requesting 'http://image.tmdb.org/t/p/w300/mXPoxiRny3VPH0iXJWXlyTq1mjo.jpg'
2017-12-02 08:51:02,921 (1938) : DEBUG (networking:198) - Not caching 'http://image.tmdb.org/t/p/w300/mXPoxiRny3VPH0iXJWXlyTq1mjo.jpg' (content type 'image/jpeg' not cacheable in Agent plug-ins)
2017-12-02 08:51:03,003 (1938) : DEBUG (networking:166) - Requesting 'http://image.tmdb.org/t/p/w300/v7aFwIIgUk5I38IhygcOYYhJbO6.jpg'
2017-12-02 08:52:43,168 (1938) : DEBUG (networking:198) - Not caching 'http://image.tmdb.org/t/p/w300/v7aFwIIgUk5I38IhygcOYYhJbO6.jpg' (content type 'image/jpeg' not cacheable in Agent plug-ins)
2017-12-02 08:52:43,226 (1938) : DEBUG (networking:166) - Requesting 'http://image.tmdb.org/t/p/w300/hGHCwdqgvJiOa8Np5tmp9Bb4WN6.jpg'
2017-12-02 08:54:24,855 (1938) : DEBUG (networking:198) - Not caching 'http://image.tmdb.org/t/p/w300/hGHCwdqgvJiOa8Np5tmp9Bb4WN6.jpg' (content type 'image/jpeg' not cacheable in Agent plug-ins)
2017-12-02 08:54:24,901 (1938) : DEBUG (networking:166) - Requesting 'http://image.tmdb.org/t/p/w300/gd2LTTrtkWOA3SYk6UPKZsr7uAr.jpg'
2017-12-02 08:56:05,661 (1938) : DEBUG (networking:198) - Not caching 'http://image.tmdb.org/t/p/w300/gd2LTTrtkWOA3SYk6UPKZsr7uAr.jpg' (content type 'image/jpeg' not cacheable in Agent plug-ins)
2017-12-02 08:56:05,716 (1938) : DEBUG (networking:166) - Requesting 'http://image.tmdb.org/t/p/w300/AcXCaPRB037DZoZZ2cJzRSxrNBP.jpg'
2017-12-02 08:57:45,993 (1938) : DEBUG (networking:198) - Not caching 'http://image.tmdb.org/t/p/w300/AcXCaPRB037DZoZZ2cJzRSxrNBP.jpg' (content type 'image/jpeg' not cacheable in Agent plug-ins)
2017-12-02 08:57:46,058 (1938) : DEBUG (networking:166) - Requesting 'http://image.tmdb.org/t/p/w300/3AuJ43BY8pCQHKTTGE9lWmRbEjU.jpg'
2017-12-02 09:00:15,351 (1938) : DEBUG (networking:198) - Not caching 'http://image.tmdb.org/t/p/w300/3AuJ43BY8pCQHKTTGE9lWmRbEjU.jpg' (content type 'image/jpeg' not cacheable in Agent plug-ins)
Each request seems to take 100 seconds to complete. Either something is slowing the responses or we are missing notifications
It is all http and https so can capture with wireshark easily and compare times to logs
Suggest first is to try these url’s in browser on the server and see if the images come back immediately
If they do, then need to look into using wireshark and then comparing times of when the requests go out and images come back from image.tmdb.org with what gets logged in the com.plexapp.agents.imdb.log file
Those image links load instantly using Chrome on the machine running the Plex server.
Began capturing packets with Wireshark right before adding Dunkirk to Movies folder. Got two 200 codes for jpegs received right away, and continued to let it run until Plex notified me it was done processing Dunkirk 9 minutes later. No metadata was added to the entry in Plex. I hope some of the attached files might help.
Exported captured frames as XML, and an HTTP export.
Bump if anyone else would mind taking a look.
Sorry - will have a look at your captured info later today
The wireshark captures do not give me absolute date/time to allow me to match to log entries in the plex logs
Do you still have the actual wireshark pcap file?
I need to know what times these were
<packet>
<section>21201</section>
<section>186.661994</section>
<section>10.0.1.37</section>
<section>104.16.57.155</section>
<section>HTTP</section>
<section>307</section>
<section>GET /t/p/w300/4yjJNAgXBmzxpS6sogj4ftwd270.jpg HTTP/1.1 </section>
</packet>
<packet>
<section>21227</section>
<section>186.726171</section>
<section>104.16.57.155</section>
<section>10.0.1.37</section>
<section>HTTP</section>
<section>462</section>
<section>HTTP/1.1 200 OK (JPEG JFIF image)</section>
</packet>
I noticed this error - I am not sure if it is relevant
mkdir(name, mode)
WindowsError: [Error 5] Access is denied: u'\\\\?\\C:\\Users\\Sean\\AppData\\Local\\Plex Media Server\\Metadata\\Movies\\8\\bbccbee97bfbad9a9fbb9deb3d49cc19ffb7e03.bundle\\Contents\\com.plexapp.agents.imdb\\art'
It is creating a directory and failing
The path was C:\Users\Sean\AppData\Local\Plex Media Server\Metadata\Movies\8\bbccbee97bfbad9a9fbb9deb3d49cc19ffb7e03.bundle\Contents\com.plexapp.agents.imdb\art
can you check permissions for the user account Plex Media Server runs in. Also disk space
Anything special about the filesystem ? Is it NTFS ?
Any symbolic links used?
I’m also having the same issue. Seems that recently, my agent setting were automatically changed.
Movies is set to Personal Media. However, I am unable to change the setting. There is no save button and it just reverts when I leave settings. All new movies are unable to get metadata.
Thanks again for taking a look.
D:\ drive is a parity Windows Storage Spaces disk, with four 3TB WD Reds.I no longer have the pcap for the original Wireshark capture, so I will complete another one.
Here is a quick synopsis of my capture:
2:57 Start Wireshark capture and add mother! (2017).mkv to Movies directory.
2:58 Plex notices file change and adds it to recently added movies list.
3:05? (post deleted so I’m not positive on time) I force refresh metadata on mother!.
3:10? Plex notifies processing complete on mother!, end Wireshark capture.
Attached in the .zip are Plex Server Logs, Wireshark pcap file, and a screenshot of Plex home.
Notice in the screenshot that after a few days, some of the movies have had their metadata attached, while others which were added at the same time (Cocoon) have not, and still have a spinning tag icon on them.
@sdownes said:
Thanks again for taking a look.
- A single user account on the system, with administrator privileges.
- Normal NTFS formatting for the C:\ drive, with ~170GB of free space available on the SSD.
D:\drive is a parity Windows Storage Spaces disk, with four 3TB WD Reds.- No symbolic links used beyond what Windows may use in Storage Spaces virtual disk.
I no longer have the pcap for the original Wireshark capture, so I will complete another one.
Here is a quick synopsis of my capture:
2:57 Start Wireshark capture and add mother! (2017).mkv to Movies directory.
2:58 Plex notices file change and adds it to recently added movies list.
3:05? (post deleted so I’m not positive on time) I force refresh metadata on mother!.
3:10? Plex notifies processing complete on mother!, end Wireshark capture.Attached in the .zip are Plex Server Logs, Wireshark pcap file, and a screenshot of Plex home.
Notice in the screenshot that after a few days, some of the movies have had their metadata attached, while others which were added at the same time (Cocoon) have not, and still have a spinning tag icon on them.
Many Thanks - Good evidence.
So the delay is on transmitting the request out
It shows the request not going out till 100 seconds later
2017-12-09 02:58:44,469 (19d0) : DEBUG (networking:166) - Requesting 'http://image.tmdb.org/t/p/w300/uuQpQ8VDOtVL2IO4y2pR58odkS5.jpg'
and captured in wireshark
1 2017-12-09 09:00:24.577753 0.000000 HTTP 10.0.1.37 63911 104.16.59.155 80 GET /t/p/w300/uuQpQ8VDOtVL2IO4y2pR58odkS5.jpg HTTP/1.1 369
The time showing as 09:00:24.577753 is because of my timezone - it is actually 03:00:24.577753
I will continue to look into this
What you could establish is if there was a lot of queued requests at the time - so repeat with another movie. But before adding the movie check with wireshark to see if there are a lot of queued requests being sent
I have done a test with a dummy file named mother! (2017).mkv in a test library to see what we can get in terms of more diagnostics
In my test - first image.tmdb.org jpg request
2017-12-09 17:22:36,269 (3cdc) : DEBUG (networking:166) - Requesting 'http://image.tmdb.org/t/p/w300/uuQpQ8VDOtVL2IO4y2pR58odkS5.jpg'
125 2017-12-09 17:22:36,628 (3cdc) : DEBUG (networking:198) - Not caching 'http://image.tmdb.org/t/p/w300/uuQpQ8VDOtVL2IO4y2pR58odkS5.jpg' (content type 'image/jpeg' not cacheable in Agent plug-ins)
Matching wireshark
143689 2017-12-09 17:22:36.588664 265.301957 HTTP 192.168.0.152 53262 104.16.61.155 80 GET /t/p/w300/uuQpQ8VDOtVL2IO4y2pR58odkS5.jpg HTTP/1.1 307
Just a 320ms delay compared to your 100 second delay
As you are now very good at getting the perfect diagnostics, I would like to take it one step deeper - just to see what was happening on your system in the 100 seconds
I am thinking of adding to wireshark and the logs, SysInternals Process Monitor
The procmon capture would record when the request goes out - in my case it was captured like this
147625 17:22:36.5885248 PlexScriptHost.exe 5724 0 TCP Connect AML-SA-LT\plex AML-SA-LT:53262 -> 104.16.61.155:http SUCCESS Length: 0, mss: 1460, sackopt: 1, tsopt: 0, wsopt: 1, rcvwin: 65700, rcvwinscale: 8, sndwinscale: 10, seqnum: 0, connid: 0 09/12/2017 17:22:36
147626 17:22:36.6164412 PlexScriptHost.exe 5724 0 TCP Send AML-SA-LT\plex AML-SA-LT:53262 -> 104.16.61.155:http SUCCESS Length: 253, startime: 378742, endtime: 378745, seqnum: 0, connid: 0 09/12/2017 17:22:36
So download procmon and run it as admin - do not start running it until you are ready.
Launch wireshark and add this filter display in the filter bar http.host contains "image.tmdb.org"
So suggest a test library and just one movie added and start procmon capture and wireshark just before you add the path folder to the test library to pick the movie file you place there.
As soon as you see a GET /t/p/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx entry in wireshark, stop procmon capture andn stop wireshark capture
Save procmon without filtering into PML file (clear all filters before saving all as PML)
Save wireshark without filtering as pcap file (Clear the display filter and let that change complete - then save all captured packets)
Zip both and upload in your dropbox or other personal space and send me link by private message
and attach the logs that go with it
