Sir! Hello today. Although I don’t use the livetv feature, I was able to find some problems in your log files that will need to be addressed, as they aren’t common but likely fixable.
Your com.plexapp.system.log has a critical error every morning at 2:00 am when PlexMusic is interfacing with Gracenote. I’m not all that sure what’s happening yet, possibly network.
in com.plexapp.system.log
2019-10-08 02:00:41,348 (1bcc) : DEBUG (runtime:717) - Handling request GET /system/agents/update?mediaType=8&force=1&guid=com%2Eplexapp%2Eagents%2Eplexmusic%3A%2F%2Fgracenote%2Fartist%2F05E454AB2A19E806%3Flang%3Den&id=1489
2019-10-08 02:00:41,348 (1bcc) : DEBUG (runtime:814) - Found route matching /system/agents/update
2019-10-08 02:00:41,349 (1bcc) : DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins'
2019-10-08 02:00:41,352 (1bcc) : DEBUG (logkit:13) - Adding com.plexapp.agents.plexmusic://gracenote/artist/05E454AB2A19E806?lang=en to the update list
2019-10-08 02:00:41,354 (c30) : INFO (logkit:16) - Preparing metadata for Artist in com.plexapp.agents.plexmusic (gracenote/artist/05E454AB2A19E806)
2019-10-08 02:00:41,355 (c30) : DEBUG (runtime:1117) - Created a thread named 'notify_processing'
2019-10-08 02:00:41,355 (1bcc) : DEBUG (runtime:924) - Response: [200] InitiateUpdateResponse, 160 bytes
2019-10-08 02:00:41,355 (37c) : DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/metadata/processing?id=1489'
2019-10-08 02:00:41,355 (c30) : DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.agents.plexmusic/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKZW5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNAoxNDg5czQKZGJpZGkwCnM3CnZlcnNpb25uczEwCnBhcmVudEdVSURuczgKcGFyZW50SURzNgpBcnRpc3RzMTAKbWVkaWFfdHlwZXM3Mgpjb20ucGxleGFwcC5hZ2VudHMucGxleG11c2ljOi8vZ3JhY2Vub3RlL2FydGlzdC8wNUU0NTRBQjJBMTlFODA2P2xhbmc9ZW5zNApndWlkczMzCmdyYWNlbm90ZS9hcnRpc3QvMDVFNDU0QUIyQTE5RTgwNnMyCmlkcjAK'
2019-10-08 02:00:42,006 (1744) : DEBUG (runtime:717) - Handling request GET /system/agents/update?mediaType=2&force=1&guid=com%2Egracenote%2Eonconnect%3A%2F%2Fshow%2F15877021&id=251
2019-10-08 02:00:42,006 (1744) : DEBUG (runtime:814) - Found route matching /system/agents/update
2019-10-08 02:00:42,006 (1744) : CRITICAL (core:579) - Exception in update request handler (most recent call last):
File "D:\Plex\Plex Media Server\Resources\Plug-ins-d42cfa161\System.bundle\Contents\Code\agentservice.py", line 298, in update
version = self.agent_get_version(libraryAgent or identifier, 'Artist' if media_type == 'Album' else media_type)
File "D:\Plex\Plex Media Server\Resources\Plug-ins-d42cfa161\System.bundle\Contents\Code\agentservice.py", line 1184, in agent_get_version
for agent in self.agent_info[identifier]:
File "D:\Plex\Plex Media Server\Resources\Plug-ins-d42cfa161\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\sandbox.py", line 108, in <lambda>
_getitem_ = lambda x, y: x.__getitem__(y),
KeyError: 'com.gracenote.onconnect'
2019-10-08 02:00:42,007 (1744) : DEBUG (runtime:924) - Response: [200] InitiateUpdateResponse, 909 bytes
2019-10-08 02:00:42,013 (1b84) : DEBUG (runtime:717) - Handling request GET /system/agents/update?mediaType=2&force=1&guid=com%2Egracenote%2Eonconnect%3A%2F%2Fshow%2F16297251&id=1208
2019-10-08 02:00:42,013 (1b84) : DEBUG (runtime:814) - Found route matching /system/agents/update
2019-10-08 02:00:42,013 (1b84) : CRITICAL (core:579) - Exception in update request handler (most recent call last):
File "D:\Plex\Plex Media Server\Resources\Plug-ins-d42cfa161\System.bundle\Contents\Code\agentservice.py", line 298, in update
version = self.agent_get_version(libraryAgent or identifier, 'Artist' if media_type == 'Album' else media_type)
File "D:\Plex\Plex Media Server\Resources\Plug-ins-d42cfa161\System.bundle\Contents\Code\agentservice.py", line 1184, in agent_get_version
for agent in self.agent_info[identifier]:
File "D:\Plex\Plex Media Server\Resources\Plug-ins-d42cfa161\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\sandbox.py", line 108, in <lambda>
_getitem_ = lambda x, y: x.__getitem__(y),
KeyError: 'com.gracenote.onconnect'
2019-10-08 02:00:42,015 (1b84) : DEBUG (runtime:924) - Response: [200] InitiateUpdateResponse, 909 bytes
2019-10-08 02:00:42,733 (146c) : DEBUG (runtime:717) - Handling request GET /system/agents/update?mediaType=4&force=1&parentGUID=local%3A%2F%2F252&parentID=252&guid=com%2Egracenote%2Eonconnect%3A%2F%2Fepisode%2F15877021%2F2018-10-15&id=253&agent=com.plexapp.agents.localmedia&async=0
2019-10-08 02:00:42,733 (146c) : DEBUG (runtime:814) - Found route matching /system/agents/update
2019-10-08 02:00:42,733 (146c) : CRITICAL (core:579) - Exception in update request handler (most recent call last):
File "D:\Plex\Plex Media Server\Resources\Plug-ins-d42cfa161\System.bundle\Contents\Code\agentservice.py", line 298, in update
version = self.agent_get_version(libraryAgent or identifier, 'Artist' if media_type == 'Album' else media_type)
File "D:\Plex\Plex Media Server\Resources\Plug-ins-d42cfa161\System.bundle\Contents\Code\agentservice.py", line 1184, in agent_get_version
for agent in self.agent_info[identifier]:
File "D:\Plex\Plex Media Server\Resources\Plug-ins-d42cfa161\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\sandbox.py", line 108, in <lambda>
_getitem_ = lambda x, y: x.__getitem__(y),
KeyError: 'com.gracenote.onconnect'
Your Plex Media Server.log indicates a variety of potential problems, most of them also being network related. It constantly complains about a time problem, perhaps caused by another piece of hardware:
Oct 09, 2019 22:58:47.129 [2856] DEBUG - HTTP requesting GET https://epg.provider.plex.tv/grid?beginsAt%3C=1570838400&channel=5cab3c63ec158a001d32daea&endsAt%3E=1570665600&X-Plex-Api-Token=xxxxxxxxxxxxxxxxxxxx
Oct 09, 2019 22:58:47.223 [2856] DEBUG - HTTP 200 response from GET https://epg.provider.plex.tv/grid?beginsAt%3C=1570838400&channel=5cab3c63ec158a001d32daea&endsAt%3E=1570665600&X-Plex-Api-Token=xxxxxxxxxxxxxxxxxxxx
Oct 09, 2019 22:58:47.239 [2856] ERROR - [Time] Failed to convert '-157766400' from epoch.
Oct 09, 2019 22:58:47.239 [2856] ERROR - [Time] Failed to convert '-157766400' from epoch.
Oct 09, 2019 22:58:47.239 [2856] ERROR - [Time] Failed to convert '-441849600' from epoch.
Oct 09, 2019 22:58:47.255 [2856] ERROR - [Time] Failed to convert '-441849600' from epoch.
Also, Plex is sensitive to the presence of any VPN or ESET or other security software. It is sensitive to IPv6. It’s not worth trying to understand why when IPv4 works.
My suggestions:
- Go into PMS
Settings - Show Advanced - Network
- Disable IPv6 and network discovery (GDM) and Save Changes.
- Disable DLNA in
Settings - DLNA and Save Changes.
- Restart the PMS hardware.
- Give it 6min to initialize
- Grab new logs
Settings - Troubleshooting - Download Logs
We’ll need to also understand this misbehaving IP address, as the logs are also filled with this error (which is why I asked you to disable DLNA and GDM):
Oct 10, 2019 00:34:12.609 [2136] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://10.0.3.2:8080/upnp
Oct 10, 2019 00:34:12.609 [2136] DEBUG - HTTP requesting GET http://10.0.3.2:8080/upnp
Oct 10, 2019 00:34:12.609 [2136] DEBUG - HTTP 404 response from GET http://10.0.3.2:8080/upnp
Oct 10, 2019 00:34:12.609 [2136] ERROR - SSDP: Error parsing device schema for http://10.0.3.2:8080/upnp
So do you have any VPN or security software? Can we get some new logs with the changes I asked and a reboot? That would be great, thanks!
