YouTube-Agent.bundle icon indicating copy to clipboard operation
YouTube-Agent.bundle copied to clipboard

Not generating metadata at all, getting timeout

Open garbled1 opened this issue 2 years ago • 7 comments

For some reason, it stopped generating metadata recently. I figured I upgraded plex too far, or just needed to update the code. Updated ASS and YT agent, and now it's just not working at all.

After mucking with it for awhile, I now get this problem whenever I refresh metadata, or fix a match:

2022-07-16 11:40:21,241 (7f24a8f86b38) :  DEBUG (runtime:924) - Response: [200] str, 103363 bytes
2022-07-16 11:40:32,603 (7f24a8152b38) :  CRITICAL (agentservice:786) - Exception notifying the media server (most recent call last):
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-a806c5905/System.bundle/Contents/Code/agentservice.py", line 784, in notify_thread
    HTTP.Request(url, cacheTime=0, immediate=True, data=xml)
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-a806c5905/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/networkkit.py", line 194, in Request
    method=method,
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-a806c5905/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/networkkit.py", line 67, in _http_request
    req = self._core.networking.http_request(url, *args, **kwargs)
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-a806c5905/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py", line 346, in http_request
    return HTTPRequest(self._core, url, data, h, url_cache, encoding, errors, timeout, immediate, sleep, opener, follow_redirects, method)
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-a806c5905/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py", line 118, in __init__
    self.load()
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-a806c5905/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py", line 158, in load
    f = self._opener.open(req, timeout=self._timeout)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 429, in open
    response = self._open(req, data)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 447, in _open
    '_open', req)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 407, in _call_chain
    result = func(*args)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 1228, in http_open
    return self.do_open(httplib.HTTPConnection, req)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 1201, in do_open
    r = h.getresponse(buffering=True)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/httplib.py", line 1148, in getresponse
    response.begin()
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/httplib.py", line 448, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/httplib.py", line 404, in _read_status
    line = self.fp.readline(_MAXLINE + 1)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/socket.py", line 480, in readline
    data = self._sock.recv(self._rbufsize)
timeout: timed out

Not sure I understand why this is failing, as the youtube log seems to find all the metadata just fine.

com.plexapp.agents.youtube.log com.plexapp.system.log

garbled1 avatar Jul 16 '22 18:07 garbled1

None of the python code giving errors are part of the YouTube agent... Corrupted Plex database? Recent Plex update breaking everything?

ZeroQI avatar Jul 16 '22 19:07 ZeroQI

Indeed no agent errors in agent logs. Look like Plex issue, maybe its database is corrupted and needs fixing

ZeroQI avatar Jul 16 '22 19:07 ZeroQI

I think this is what concerns me, even if I do a single refresh metadata:

2022-07-16 14:51:15,627 (7f24a8e46b38) :  DEBUG (runtime:717) - Handling request GET /system/agents/update?mediaType=4&force=1&respectTags=0&parentGUID=com%2Eplexapp%2Eagents%2Eyoutube%3A%2F%2Fyoutube%7CUCSFaYYQzNMLo2U6rSNLpghg%7CTorbjorn_Ahman%20%5BUCSFaYYQzNMLo2U6rSNLpghg%5D%2F2022%3Flang%3Dxn&parentID=121166&guid=com%2Eplexapp%2Eagents%2Eyoutube%3A%2F%2Fyoutube%7CUCSFaYYQzNMLo2U6rSNLpghg%7CTorbjorn_Ahman%20%5BUCSFaYYQzNMLo2U6rSNLpghg%5D%2F2022%2F2022-04-29%3Flang%3Dxn&id=125616
2022-07-16 14:51:15,633 (7f24a8e46b38) :  DEBUG (runtime:814) - Found route matching /system/agents/update
2022-07-16 14:51:15,636 (7f24a8e46b38) :  DEBUG (networking:143) - Requesting 'http://127.0.0.1:32400/:/plugins'
2022-07-16 14:51:15,645 (7f24a8e46b38) :  DEBUG (agentservice:330) - Adding com.plexapp.agents.youtube://youtube|UCSFaYYQzNMLo2U6rSNLpghg|Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/2022/2022-04-29?lang=xn to the update list
2022-07-16 14:51:15,648 (7f24a9a51b38) :  DEBUG (agentservice:404) - Acquiring GUID mutex for com.plexapp.agents.youtube://youtube|UCSFaYYQzNMLo2U6rSNLpghg|Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/2022/2022-04-29?lang=xn (125616) (count is now 1)
2022-07-16 14:51:15,651 (7f24a9a51b38) :  DEBUG (agentservice:406) - Acquired GUID mutex for com.plexapp.agents.youtube://youtube|UCSFaYYQzNMLo2U6rSNLpghg|Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/2022/2022-04-29?lang=xn (125616)
2022-07-16 14:51:15,654 (7f24a8e46b38) :  DEBUG (runtime:924) - Response: [200] InitiateUpdateResponse, 161 bytes
2022-07-16 14:51:15,655 (7f24a9a51b38) :  INFO (agentservice:408) - Preparing metadata for TV_Show in com.plexapp.agents.youtube (youtube|UCSFaYYQzNMLo2U6rSNLpghg|Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg])
2022-07-16 14:51:15,660 (7f24a8e46b38) :  DEBUG (networking:143) - Requesting 'http://127.0.0.1:32400/:/metadata/processing?id=125616'
2022-07-16 14:51:15,662 (7f24a9a51b38) :  DEBUG (runtime:1117) - Created a thread named 'notify_processing'
2022-07-16 14:51:15,683 (7f24a9a51b38) :  DEBUG (networking:143) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.agents.youtube/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNgoxMjU2MTZzNApkYmlkaTAKczcKdmVyc2lvbnMxMTYKY29tLnBsZXhhcHAuYWdlbnRzLnlvdXR1YmU6Ly95b3V0dWJlfFVDU0ZhWVlRek5NTG8yVTZyU05McGdoZ3xUb3Jiam9ybl9BaG1hbiBbVUNTRmFZWVF6Tk1MbzJVNnJTTkxwZ2hnXS8yMDIyP2xhbmc9eG5zMTAKcGFyZW50R1VJRHM2CjEyMTE2NnM4CnBhcmVudElEczcKVFZfU2hvd3MxMAptZWRpYV90eXBlczEyNwpjb20ucGxleGFwcC5hZ2VudHMueW91dHViZTovL3lvdXR1YmV8VUNTRmFZWVF6Tk1MbzJVNnJTTkxwZ2hnfFRvcmJqb3JuX0FobWFuIFtVQ1NGYVlZUXpOTUxvMlU2clNOTHBnaGddLzIwMjIvMjAyMi0wNC0yOT9sYW5nPXhuczQKZ3VpZHM3NAp5b3V0dWJlfFVDU0ZhWVlRek5NTG8yVTZyU05McGdoZ3xUb3Jiam9ybl9BaG1hbiBbVUNTRmFZWVF6Tk1MbzJVNnJTTkxwZ2hnXXMyCmlkcjAK'
2022-07-16 14:51:18,191 (7f24a9a51b38) :  DEBUG (model:32) - Loading model with GUID com.plexapp.agents.youtube://youtube|UCSFaYYQzNMLo2U6rSNLpghg|Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/2022/2022-04-29?lang=xn
2022-07-16 14:51:18,193 (7f24a9a51b38) :  DEBUG (model:234) - Deserializing from /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/TV Shows/5/0bf3d04351e271e6800204e665dbe82d3d30d6f.bundle/Contents/com.plexapp.agents.youtube/Info.xml
2022-07-16 14:51:18,340 (7f24a9a51b38) :  DEBUG (networking:143) - Requesting 'http://127.0.0.1:32400/library/metadata/125616/tree'
2022-07-16 14:51:18,381 (7f24a9a51b38) :  DEBUG (sandbox:19) - >>> Agent order: ['com.plexapp.agents.youtube']
2022-07-16 14:51:18,382 (7f24a9a51b38) :  DEBUG (agentservice:677) - Combining subtitles for media bundle at '/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Media/localhost/6/535f37c900d7f94f7a200dc3b19770d6a1854c5.bundle'
2022-07-16 14:51:18,385 (7f24a9a51b38) :  DEBUG (sandbox:19) - >>> No file found at path /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Media/localhost/6/535f37c900d7f94f7a200dc3b19770d6a1854c5.bundle/Contents/Subtitle Contributions/com.plexapp.agents.youtube.xml
2022-07-16 14:51:18,385 (7f24a9a51b38) :  DEBUG (sandbox:19) - >>> Creating combined XML file from {}
2022-07-16 14:51:18,386 (7f24a9a51b38) :  DEBUG (sandbox:19) - Combined XML data: <?xml version='1.0' encoding='utf8'?>
<Subtitles/>

2022-07-16 14:51:18,387 (7f24a9a51b38) :  INFO (agentservice:586) - Metadata preparation for com.plexapp.agents.youtube://youtube|UCSFaYYQzNMLo2U6rSNLpghg|Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/2022/2022-04-29?lang=xn complete
2022-07-16 14:51:18,388 (7f24a8e46b38) :  INFO (agentservice:767) - Bundle with guid com.plexapp.agents.youtube://youtube|UCSFaYYQzNMLo2U6rSNLpghg|Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/2022/2022-04-29?lang=xn has been updated - notifying the media server
2022-07-16 14:51:18,389 (7f24a9a51b38) :  DEBUG (runtime:1117) - Created a thread named 'notify_thread'
2022-07-16 14:51:18,392 (7f24a9a51b38) :  DEBUG (agentservice:625) - Removing com.plexapp.agents.youtube://youtube|UCSFaYYQzNMLo2U6rSNLpghg|Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/2022/2022-04-29?lang=xn from the update list
2022-07-16 14:51:18,393 (7f24a9a51b38) :  DEBUG (agentservice:638) - Releasing GUID mutex for com.plexapp.agents.youtube://youtube|UCSFaYYQzNMLo2U6rSNLpghg|Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/2022/2022-04-29?lang=xn
2022-07-16 14:51:18,393 (7f24a9a51b38) :  DEBUG (agentservice:644) - We're done with the mutex for com.plexapp.agents.youtube://youtube|UCSFaYYQzNMLo2U6rSNLpghg|Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/2022/2022-04-29?lang=xn
2022-07-16 14:51:18,398 (7f24a8e46b38) :  DEBUG (networking:143) - Requesting 'http://127.0.0.1:32400/:/metadata/notify?guid=com.plexapp.agents.youtube%3A%2F%2Fyoutube%7CUCSFaYYQzNMLo2U6rSNLpghg%7CTorbjorn_Ahman+%5BUCSFaYYQzNMLo2U6rSNLpghg%5D%2F2022%2F2022-04-29%3Flang%3Dxn&path=TV+Shows%2F5%2F0bf3d04351e271e6800204e665dbe82d3d30d6f.bundle&force=1&queueSize=0&id=125616&success=1&async=1'

and


2022-07-16 14:51:15,692 (7f92303c4b38) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.youtube/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNgoxMjU2MTZzNApkYmlkaTAKczcKdmVyc2lvbnMxMTYKY29tLnBsZXhhcHAuYWdlbnRzLnlvdXR1YmU6Ly95b3V0dWJlfFVDU0ZhWVlRek5NTG8yVTZyU05McGdoZ3xUb3Jiam9ybl9BaG1hbiBbVUNTRmFZWVF6Tk1MbzJVNnJTTkxwZ2hnXS8yMDIyP2xhbmc9eG5zMTAKcGFyZW50R1VJRHM2CjEyMTE2NnM4CnBhcmVudElEczcKVFZfU2hvd3MxMAptZWRpYV90eXBlczEyNwpjb20ucGxleGFwcC5hZ2VudHMueW91dHViZTovL3lvdXR1YmV8VUNTRmFZWVF6Tk1MbzJVNnJTTkxwZ2hnfFRvcmJqb3JuX0FobWFuIFtVQ1NGYVlZUXpOTUxvMlU2clNOTHBnaGddLzIwMjIvMjAyMi0wNC0yOT9sYW5nPXhuczQKZ3VpZHM3NAp5b3V0dWJlfFVDU0ZhWVlRek5NTG8yVTZyU05McGdoZ3xUb3Jiam9ybl9BaG1hbiBbVUNTRmFZWVF6Tk1MbzJVNnJTTkxwZ2hnXXMyCmlkcjAK
2022-07-16 14:51:15,695 (7f92303c4b38) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2022-07-16 14:51:15,699 (7f92303c4b38) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.youtube/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNgoxMjU2MTZzNApkYmlkaTAKczcKdmVyc2lvbnMxMTYKY29tLnBsZXhhcHAuYWdlbnRzLnlvdXR1YmU6Ly95b3V0dWJlfFVDU0ZhWVlRek5NTG8yVTZyU05McGdoZ3xUb3Jiam9ybl9BaG1hbiBbVUNTRmFZWVF6Tk1MbzJVNnJTTkxwZ2hnXS8yMDIyP2xhbmc9eG5zMTAKcGFyZW50R1VJRHM2CjEyMTE2NnM4CnBhcmVudElEczcKVFZfU2hvd3MxMAptZWRpYV90eXBlczEyNwpjb20ucGxleGFwcC5hZ2VudHMueW91dHViZTovL3lvdXR1YmV8VUNTRmFZWVF6Tk1MbzJVNnJTTkxwZ2hnfFRvcmJqb3JuX0FobWFuIFtVQ1NGYVlZUXpOTUxvMlU2clNOTHBnaGddLzIwMjIvMjAyMi0wNC0yOT9sYW5nPXhuczQKZ3VpZHM3NAp5b3V0dWJlfFVDU0ZhWVlRek5NTG8yVTZyU05McGdoZ3xUb3Jiam9ybl9BaG1hbiBbVUNTRmFZWVF6Tk1MbzJVNnJTTkxwZ2hnXXMyCmlkcjAK
2022-07-16 14:51:15,702 (7f92303c4b38) :  DEBUG (model:32) - Loading model with GUID com.plexapp.agents.youtube://youtube|UCSFaYYQzNMLo2U6rSNLpghg|Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/2022/2022-04-29?lang=xn
2022-07-16 14:51:15,727 (7f92303c4b38) :  ERROR (model:205) - Cannot read model from /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/TV Shows/5/0bf3d04351e271e6800204e665dbe82d3d30d6f.bundle/Contents/com.plexapp.agents.youtube
2022-07-16 14:51:15,729 (7f92303c4b38) :  DEBUG (networking:143) - Requesting 'http://127.0.0.1:32400/library/metadata/125616/tree'
2022-07-16 14:51:15,794 (7f92303c4b38) :  INFO (__init__:192) - === update(lang=xn, force=True, movie=False) ===
2022-07-16 14:51:15,795 (7f92303c4b38) :  INFO (__init__:39) - /var/lib/plexmediaserver/alcyone/video/Misc/Youtube/Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/20220430 - Blacksmithing_off_grid_with_the_EcoFlow_Delta_MAX [7xW_T9fcdio].mp4
2022-07-16 14:51:15,796 (7f92303c4b38) :  INFO (__init__:204) - =============================================================================================================================================================
2022-07-16 14:51:15,797 (7f92303c4b38) :  INFO (__init__:287) - [ ] library:    "YouTube"
2022-07-16 14:51:15,798 (7f92303c4b38) :  INFO (__init__:288) - [ ] root:       "/var/lib/plexmediaserver/alcyone/video/Misc/Youtube"
2022-07-16 14:51:15,798 (7f92303c4b38) :  INFO (__init__:289) - [ ] path:       "Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]"
2022-07-16 14:51:15,799 (7f92303c4b38) :  INFO (__init__:290) - [ ] dir:        "/var/lib/plexmediaserver/alcyone/video/Misc/Youtube/Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]"
2022-07-16 14:51:15,799 (7f92303c4b38) :  INFO (__init__:295) - [ ] series_root_folder: "/var/lib/plexmediaserver/alcyone/video/Misc/Youtube/Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]"
2022-07-16 14:51:15,894 (7f92303c4b38) :  INFO (__init__:298) - [ ] subfolder_count:    "0"
2022-07-16 14:51:15,895 (7f92303c4b38) :  INFO (__init__:318) - Grouping folder not found or single folder, root: /var/lib/plexmediaserver/alcyone/video/Misc/Youtube, path: Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg], Grouping folder: Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg], subdirs: 0, reverse_path: [u'Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]']
2022-07-16 14:51:15,896 (7f92303c4b38) :  DEBUG (__init__:70) - Loaded token from youtube-token.txt file
2022-07-16 14:51:15,919 (7f92303c4b38) :  DEBUG (networking:138) - Fetching 'https://www.googleapis.com/youtube/v3/channels?part=snippet%2CcontentDetails%2Cstatistics%2CbrandingSettings&id=UCSFaYYQzNMLo2U6rSNLpghg&key=AIzaSyChKknePGNaCIb3Qn4nkjMCYofbKwsF_o0' from the HTTP cache
2022-07-16 14:51:15,938 (7f92303c4b38) :  INFO (__init__:352) - [ ] title:        "Torbjorn_Ahman ", metadata.title: "Torbjorn_Ahman "
2022-07-16 14:51:15,939 (7f92303c4b38) :  INFO (__init__:362) - [ ] country: SE
2022-07-16 14:51:15,939 (7f92303c4b38) :  INFO (__init__:414) - [X] art:       https://yt3.ggpht.com/jJNyePUrPCfd79WWEhXue7CZb9OeVckCIhQo4Sml0H5D76IrqfF7Vi1h3arH06dBXSmxLhZcK3k=s1920
2022-07-16 14:51:15,950 (7f92303c4b38) :  DEBUG (networking:143) - Requesting 'https://yt3.ggpht.com/jJNyePUrPCfd79WWEhXue7CZb9OeVckCIhQo4Sml0H5D76IrqfF7Vi1h3arH06dBXSmxLhZcK3k=s1920'
2022-07-16 14:51:16,753 (7f92303c4b38) :  DEBUG (networking:175) - Not caching 'https://yt3.ggpht.com/jJNyePUrPCfd79WWEhXue7CZb9OeVckCIhQo4Sml0H5D76IrqfF7Vi1h3arH06dBXSmxLhZcK3k=s1920' (content type 'image/jpeg' not cacheable in Agent plug-ins)
2022-07-16 14:51:16,755 (7f92303c4b38) :  INFO (__init__:416) - [X] banners:   https://yt3.ggpht.com/jJNyePUrPCfd79WWEhXue7CZb9OeVckCIhQo4Sml0H5D76IrqfF7Vi1h3arH06dBXSmxLhZcK3k=s1920
2022-07-16 14:51:16,767 (7f92303c4b38) :  DEBUG (networking:143) - Requesting 'https://yt3.ggpht.com/jJNyePUrPCfd79WWEhXue7CZb9OeVckCIhQo4Sml0H5D76IrqfF7Vi1h3arH06dBXSmxLhZcK3k=s1920'
2022-07-16 14:51:17,534 (7f92303c4b38) :  DEBUG (networking:175) - Not caching 'https://yt3.ggpht.com/jJNyePUrPCfd79WWEhXue7CZb9OeVckCIhQo4Sml0H5D76IrqfF7Vi1h3arH06dBXSmxLhZcK3k=s1920' (content type 'image/jpeg' not cacheable in Agent plug-ins)
2022-07-16 14:51:17,534 (7f92303c4b38) :  INFO (__init__:421) - [X] posters:   https://yt3.ggpht.com/ytc/AKedOLQKkOSrgn4KlYaj8gk-0bln42Xm076BkERhQM2Y=s240-c-k-c0x00ffffff-no-rj
2022-07-16 14:51:17,546 (7f92303c4b38) :  DEBUG (networking:143) - Requesting 'https://yt3.ggpht.com/ytc/AKedOLQKkOSrgn4KlYaj8gk-0bln42Xm076BkERhQM2Y=s240-c-k-c0x00ffffff-no-rj'
2022-07-16 14:51:17,852 (7f92303c4b38) :  DEBUG (networking:175) - Not caching 'https://yt3.ggpht.com/ytc/AKedOLQKkOSrgn4KlYaj8gk-0bln42Xm076BkERhQM2Y=s240-c-k-c0x00ffffff-no-rj' (content type 'image/jpeg' not cacheable in Agent plug-ins)
2022-07-16 14:51:17,855 (7f92303c4b38) :  INFO (__init__:430) - [ ] role:        Torbjörn Åhman
2022-07-16 14:51:17,855 (7f92303c4b38) :  INFO (__init__:443) - =============================================================================================================================================================
2022-07-16 14:51:17,856 (7f92303c4b38) :  INFO (__init__:444) - Season: 2022
2022-07-16 14:51:17,858 (7f92303c4b38) :  INFO (__init__:450) - metadata.seasons[2022].episodes[2022-04-30] "20220430 - Blacksmithing_off_grid_with_the_EcoFlow_Delta_MAX [7xW_T9fcdio].mp4"
2022-07-16 14:51:17,859 (7f92303c4b38) :  INFO (__init__:469) - populate_episode_metadata_from_info_json() - series_root_folder: /var/lib/plexmediaserver/alcyone/video/Misc/Youtube/Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg], filename: 20220430 - Blacksmithing_off_grid_with_the_EcoFlow_Delta_MAX [7xW_T9fcdio].mp4
2022-07-16 14:51:17,859 (7f92303c4b38) :  INFO (__init__:470) - Searching for "20220430 - Blacksmithing_off_grid_with_the_EcoFlow_Delta_MAX [7xW_T9fcdio].info.json". Searching in "/var/lib/plexmediaserver/alcyone/video/Misc/Youtube/Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]".
2022-07-16 14:51:17,879 (7f92303c4b38) :  INFO (__init__:472) - Directory /var/lib/plexmediaserver/alcyone/video/Misc/Youtube/Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg] contains 334 files
2022-07-16 14:51:17,956 (7f92303c4b38) :  INFO (__init__:478) - Attempting to read metadata from /var/lib/plexmediaserver/alcyone/video/Misc/Youtube/Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/20220430 - Blacksmithing_off_grid_with_the_EcoFlow_Delta_MAX [7xW_T9fcdio].info.json
2022-07-16 14:51:17,957 (7f92303c4b38) :  INFO (__init__:480) - # videoId [7xW_T9fcdio] not in Playlist/channel item list so loading json_video_details
2022-07-16 14:51:17,957 (7f92303c4b38) :  INFO (__init__:481) - [?] link:     "https://www.youtube.com/watch?v=7xW_T9fcdio"
2022-07-16 14:51:17,958 (7f92303c4b38) :  INFO (__init__:97) - img_load() - series_root_folder: /var/lib/plexmediaserver/alcyone/video/Misc/Youtube/Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg], filename: 20220430 - Blacksmithing_off_grid_with_the_EcoFlow_Delta_MAX [7xW_T9fcdio].mp4
2022-07-16 14:51:17,989 (7f92303c4b38) :  INFO (__init__:100) - local thumbnail found for file /var/lib/plexmediaserver/alcyone/video/Misc/Youtube/Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/20220430 - Blacksmithing_off_grid_with_the_EcoFlow_Delta_MAX [7xW_T9fcdio].png
2022-07-16 14:51:18,091 (7f92303c4b38) :  INFO (__init__:487) - [ ] thumbs:   "/var/lib/plexmediaserver/alcyone/video/Misc/Youtube/Torbjorn_Ahman [UCSFaYYQzNMLo2U6rSNLpghg]/20220430 - Blacksmithing_off_grid_with_the_EcoFlow_Delta_MAX [7xW_T9fcdio].png"
2022-07-16 14:51:18,093 (7f92303c4b38) :  INFO (__init__:491) - [ ] title:    "Blacksmithing off grid with the EcoFlow Delta MAX"
2022-07-16 14:51:18,094 (7f92303c4b38) :  INFO (__init__:492) - [ ] summary:  "In this video I show a simple project to demonstrate how a battery pack/power station can be used in your shop when you suddenly don't have grid power. . Thanks to EcoFlow for sponsoring this video! Visit EcoFlow’s site here https://bit.ly/3vqfYtl to check out the Delta MAX unit.. . #EcoFlow #PortableGenerator #PortablePowerStation #SolarGenerator #SolarPanels. . Check out my recommended tools/gear:. https://www.amazon.com/shop/torbjornahman. . If you like my videos you can support me at:. https://www.patreon.com/torbjornahman. . For more info:. https://www.facebook.com/torbjornahmanblacksmith. https://www.instagram.com/torbjornahman. http://www.torbjornahman.se"
2022-07-16 14:51:18,097 (7f92303c4b38) :  INFO (__init__:493) - [ ] date:     "20220430"
2022-07-16 14:51:18,098 (7f92303c4b38) :  INFO (__init__:494) - [ ] duration: "894"
2022-07-16 14:51:18,099 (7f92303c4b38) :  INFO (__init__:505) - [ ] genres:   "[]"
2022-07-16 14:51:18,099 (7f92303c4b38) :  INFO (__init__:545) - === End Of Agent Call, errors after that are Plex related ===================================================================================================
2022-07-16 14:51:18,181 (7f92303c4b38) :  DEBUG (model:229) - Serializing to /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/TV Shows/5/0bf3d04351e271e6800204e665dbe82d3d30d6f.bundle/Contents/com.plexapp.agents.youtube/Info.xml
2022-07-16 14:51:18,185 (7f92303c4b38) :  DEBUG (runtime:88) - Sending packed state data (107 bytes)
2022-07-16 14:51:18,185 (7f92303c4b38) :  DEBUG (runtime:924) - Response: [200] str, 16 bytes
root@musica:/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Logs/PMS Plugin Logs# 

Everything there looks good, but it doesn't update the actual metadata at all. No errors even.

garbled1 avatar Jul 16 '22 21:07 garbled1

Correct. It look like a Plex issue https://support.plex.tv/articles/repair-a-corrupted-database/

ZeroQI avatar Jul 17 '22 07:07 ZeroQI

I've attempted repair of my db, which seems to have done nothing, and found no errors. I also tried to build a new library by copying one Channel's worth of files into a new dir, and loading that. I get basically the same issue. What I did notice, is I see this error:

2022-07-30 12:40:51,235 (7fa358b0eb38) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.system/resourceHashes
2022-07-30 12:40:51,237 (7fa358b0eb38) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.system/resourceHashes
2022-07-30 12:40:51,237 (7fa358b0eb38) :  DEBUG (networking:143) - Requesting 'http://resources-cdn.plexapp.com/hashes.json'
2022-07-30 12:40:53,060 (7fa358b0eb38) :  ERROR (networking:196) - Error opening URL 'http://resources-cdn.plexapp.com/hashes.json'
2022-07-30 12:40:53,063 (7fa358b0eb38) :  CRITICAL (runtime:1299) - Exception getting hosted resource hashes (most recent call last):
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-a806c5905/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/runtime.py", line 1291, in get_resource_hashes
    json = self._core.networking.http_request("http://resources-cdn.plexapp.com/hashes.json", timeout=5).content
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-a806c5905/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py", line 242, in content
    return self.__str__()
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-a806c5905/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py", line 220, in __str__
    self.load()
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-a806c5905/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py", line 158, in load
    f = self._opener.open(req, timeout=self._timeout)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 435, in open
    response = meth(req, response)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 548, in http_response
    'http', request, response, code, msg, hdrs)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 473, in error
    return self._call_chain(*args)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 407, in _call_chain
    result = func(*args)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 556, in http_error_default
    raise HTTPError(req.get_full_url(), code, msg, hdrs, fp)
HTTPError: HTTP Error 403: Forbidden

2022-07-30 12:40:53,064 (7fa358b0eb38) :  DEBUG (runtime:88) - Sending packed state data (99 bytes)

I'm not sure what is going on there.. maybe my whole plex install is just buggered?

garbled1 avatar Jul 30 '22 20:07 garbled1

None of these errors point to the YouTube agent code but Plex code itself... It couldn't open a Plex Jason file from the Plex code itself...

Error opening URL 'http://resources-cdn.plexapp.com/hashes.json'

Cannot assist there I am afraid Either your install is corrupted and you are the only one impacted, OR Plex made an update causing this issue for all...

ZeroQI avatar Jul 31 '22 01:07 ZeroQI

I am having the same issue. When using YouTubeSeries agent the channel is found and channel (tv show) information is set but none of the videos metadata are actually updated. No errors in the logs and in the com.plexapp.agents.youtube.log it says the metadata is being set, shows correct information for each video. Repaired my data base and tried with a completely fresh install of plex, ASS, and Youtube agent. And video metadata is still never set. When using YouTubeMovies the metadata is set properly though. com.plexapp.agents.youtube.log com.plexapp.system.log

gageirwin avatar Oct 10 '22 09:10 gageirwin

@Gage-Irwin The error is seen in all logs, even forHAma when the agent run, gather meta, do not crash and plex fail to update it. SInce the agent code doesn't fail, not a YouTube agent issue, but a plex issue, likelly corrupted plex database

ZeroQI avatar Jan 16 '23 20:01 ZeroQI

@Gage-Irwin The error is seen in all logs, even forHAma when the agent run, gather meta, do not crash and plex fail to update it. SInce the agent code doesn't fail, not a YouTube agent issue, but a plex issue, likelly corrupted plex database

I don't think it is a corrupted plex database because I even created a new server just for testing this and still had the same issues. One server was a linux docker container and the other was on windows both had the same issue. I even looked at the plex agent docs and tried making my own simple agent and I would still get the issue of logs saying metadata was changed but it wasn't except strangely one or two random videos. I kind of gave up as it seems to be just an issue with plex itself.

gageirwin avatar Jan 17 '23 06:01 gageirwin

For any future reference (those finding this issue through search engines). I think ZeroQI is kind of correct. Your database is probably not completely corrupt, but is rather in need to applying optimization (especially if you add a lot of videos at the same time).

Can be found under plex settings -> Manage -> Troubleshooting -> Optimize database

asabla avatar Jan 19 '23 21:01 asabla