EPG fails to load with PMS v1.11.1.4760 (JSON parse error)

@ChuckPA

Not sure if this log (com.plexapp.system.log) helps, but I’m no longer getting this error since the EPG refresh started working. It’s from the same timeframe as the previous log (Plex Media Server.log) I attached.

2018-02-06 16:17:00,391 (7f1557a23700) : DEBUG (runtime:717) - Handling request GET /system/agents/update?mediaType=2&force=1&guid=com%2Egracenote%2Eonconnect%3A%2F%2Fshow%2F12515355&id=5450
2018-02-06 16:17:00,396 (7f1557a23700) : DEBUG (runtime:814) - Found route matching /system/agents/update
2018-02-06 16:17:00,450 (7f1557a23700) : CRITICAL (agentservice:364) - Exception in update request handler (most recent call last):
File “/volume1/@appstore/Plex Media Server/Resources/Plug-ins-58bcb2957/System.bundle/Contents/Code/agentservice.py”, line 297, in update
version = self.agent_get_version(libraryAgent or identifier, ‘Artist’ if media_type == ‘Album’ else media_type)
File “/volume1/@appstore/Plex Media Server/Resources/Plug-ins-58bcb2957/System.bundle/Contents/Code/agentservice.py”, line 1172, in agent_get_version
for agent in self.agent_info[identifier]:
File “/volume1/@appstore/Plex Media Server/Resources/Plug-ins-58bcb2957/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/code/sandbox.py”, line 108, in
getitem = lambda x, y: x.getitem(y),
KeyError: ‘com.gracenote.onconnect’

2018-02-06 16:17:00,454 (7f1557a23700) : DEBUG (runtime:924) - Response: [200] InitiateUpdateResponse, 942 bytes

I chatted with Tim a short while ago. He has an idea about how to capture the information he needs. I think he’ll be posting here as soon as he decides and implements whatever he’s thinking.

It’s back again;
Channel 52 is the lowest numbered channel in my Plex DVR channel lineup.
Not sure why it made it to 58% this time before failing.

Feb 11, 2018 17:24:38.096 [0x7f6324911700] DEBUG - Activity: updated activity fa69261e-5045-4c4f-94b8-dbd422018d6b - completed 58% - Refreshing EPG

Feb 11, 2018 17:24:38.116 [0x7f6324911700] ERROR - EPG: JSON parse error. Data from request is [{“stationId”:“26046”,“callSign”:“TVLANDP”,“channel”:“052”,“preferredImage”:{“uri”:“http://plex.tmsimg.com/sources/generic/generic_sources_h9.png"},“airings”:[{“startTime”:“2018-02-19T00:00Z”,“endTime”:“2018-02-19T00:30Z”,“duration”:30,“qualifiers”:[“CC”,“Stereo”],“channels”:[“052”],“stationId”:“26046”,“ratings”:[{“body”:"USA Parental Rating”,“code”:“TVPG”}],“program”:{“tmsId”:“EP004596600108”,“rootId”:“2566006”,“seriesId”:“184735”,“subType”:“Series”,“title”:“Reba”,“episodeTitle”:“Issues”,“releaseYear”:2005,“releaseDate”:“2005-12-09”,“origAirDate”:“2005-12-09”,“titleLang”:“en”,“descriptionLang”:“en”,“entityType”:“Episode”,“genres”:[“Sitcom”],“longDescription”:“After observing their constant bickering in the office, Reba and Van’s boss (Stanley Kamel) insists they see the company’s occupational therapist (Richard Kind).”,“shortDescription”:“Reba and Van’s boss insists they see the company’s occupational therapist.”,“episodeNum”:10,“seasonNum”:5,“topCast”:[“Reba McEntire”,“Christopher Rich”,“Joanna Garcia”],“directors”:[“Robbie Countryman”],“ratings”:[{“body”:“Canadian Parental Rating”,“code”:“PG”},{“body”:“USA Parental Rating”,“code”:“TVPG”}],“preferredImage”:{“width”:“960”,“height”:“1440”,“uri”:“http://plex.tmsimg.com/assets/p184735_i_v8_ab.jpg",“category”:“Iconic”,“primary”:“true”,“tier”:“Series”}}},{“startTime”:“2018-02-19T00:30Z”,“endTime”:“2018-02-19T01:00Z”,“duration”:30,“qualifiers”:[“CC”,“Stereo”],“channels”:[“052”],“stationId”:“26046”,“ratings”:[{“body”:"USA Parental Rating”,“code”:“TVPG”}],“program”:{“tmsId”:“EP004596600109”,“rootId”:“2566007”,“seriesId”:“184735”,“subType”:“Series”,“title”:“Reba”,“episodeTitle”:“Brock’s Got Stones”,“releaseYear”:2006,“releaseDate”:“2006-01-13”,“origAirDate”:“2006-01-13”,“titleLang”:“en”,“descriptionLang”:“en”,“entityType”:“Episode”,“genres”:[“Sitcom”],“longDescription”:“Reba must care for Brock, who has kidney stones while Barbra Jean is away; Cheyenne helps at the homeless shelter.”,“shortDescription”:“Reba must care for Brock, who has kidney stones while Barbra Jean is away.”,“episodeNum”:11,“seasonNum”:5,“topCast”:[“Reba McEntire”,“Christopher Rich”,“Joanna Garcia”],“directors”:[“Mimi Deaton”],“ratings”:[{“body”:“Canadian Parental Rating”,“code”:“G”},{“body”:“The R\u00e9gie du cin\u00e9ma”,“code”:“G”},{“body”:“USA Parental Rating”,“code”:“TVG”}],“preferredImage”:{“width”:“960”,“height”:“1440”,“uri”:“http://plex.tmsimg.com/assets/p184735_i_v8_ab.jpg",“category”:“Iconic”,“primary”:“true”,“tier”:“Series”}}},{“startTime”:“2018-02-19T01:00Z”,“endTime”:“2018-02-19T01:30Z”,“duration”:30,“qualifiers”:[“CC”,“Stereo”],“channels”:[“052”],“stationId”:“26046”,“ratings”:[{“body”:"USA Parental Rating”,“code”:“TVPG”}],“program”:{“tmsId”:“EP004596600110”,“rootId”:“2566008”,“seriesId”:“184735”,“subType”:“Series”,“title”:“Reba”,“episodeTitle”:“Parenting With Puppets”,“releaseYear”:2006,“releaseDate”:“2006-01-20”,“origAirDate”:“2006-01-20”,“titleLang”:“en”,“descriptionLang”:“en”,“entityType”:“Episode”,“genres”:[“Sitcom”],“longDescription”:“Reba does not approve of Barbra Jean’s method of disciplining Henry; Brock and Van are mistaken for a gay couple when they go to a day spa.”,“shortDescription”:“Reba does not approve of Barbra Jean’s method of disciplining Henry.”,“episodeNum”:12,“seasonNum”:5,“topCast”:[“Reba McEntire”,“Christopher Rich”,“Joanna Garcia”],“directors”:[“Will Mackenzie”],“ratings”:[{“body”:“Canadian Parental Rating”,“code”:“PG”},{“body”:“USA Parental Rating”,“code”:“TVPG”}],“preferredImage”:{“width”:“960”,“height”:“1440”,“uri”:“http://plex.tmsimg.com/assets/p184735_i_v8_ab.jpg",“category”:“Iconic”,“primary”:“true”,“tier”:“Series”}}},{“startTime”:“2018-02-19T01:30Z”,“endTime”:“2018-02-19T02:00Z”,“duration”:30,“qualifiers”:[“CC”,“Stereo”],“channels”:[“052”],“stationId”:“26046”,“ratings”:[{“body”:"USA Parental Rating”,“code”:“TVPG”}],“program”:{“tmsId”:“EP004596600111”,“rootId”:“2566009”,“seriesId”:“184735”,“subType”:“Series”,“title”:“Reba”,“episodeTitle”:“Don’t Mess With Taxes”,“releaseYear”:2006,“releaseDate”:“2006-01-27”,“origAirDate”

Feb 11, 2018 17:24:38.138 [0x7f6324911700] WARN - EPG[onconnect]: Failed to load EPG.

Feb 11, 2018 17:24:38.138 [0x7f6324911700] DEBUG - Database: Shutting down.

Feb 11, 2018 17:24:38.615 [0x7f6324911700] DEBUG - EPG[onconnect]: Total time to load EPG was 1473.8 (HTTP details cached 99.4%, CloudFlare grid cached: 0.0%, 0 HTTP errors)

Feb 11, 2018 17:24:38.615 [0x7f6324911700] DEBUG - Activity: Ended activity fa69261e-5045-4c4f-94b8-dbd422018d6b.

It was nice while it lasted…The working EPG refresh that is.

Went back to v1.9.7.4460. At least that one works for me.

Plex is aware of the issue and working on a fix.
See thread forums.plex.tv/discussion/308148/bug-epg-high-cpu-usage#latest

Any clue as to how long before it is fixed? My script works, but it sux that at 1am every morning my server has to go down for a second to begin the update process…

Kind of weird, but mine seems to have fixed itself, I just tested, one odd thing is it jumped from 0% to 3%, which it had never done before, but it seems to be functioning, leaving my script in place for now, but I will continue to test it and let you know my results.

Spoke too soon, it is not pulling all the EPG data, TV Shows that were there to record are now missing, I am considering a different solution now, because TV is a way of life in my house of 6, and this is not working the way it is supposed to be.

@Havok115 said:
Spoke too soon, it is not pulling all the EPG data, TV Shows that were there to record are now missing, I am considering a different solution now, because TV is a way of life in my house of 6, and this is not working the way it is supposed to be.

Log files please (Full set) ?

There is a known issue they are working on with EPG data. I do not yet have any details regarding their progress

I did not have verbose logging on I don’t think, and I managed to get it fixed by deleteing the Plug-ins directory, and do a few more updates, and finally it worked, but here are my logs for what it is worth.

Please verify

  1. DEBUG = enabled
  2. VERBOSE = disabled

Verified I did not have it turned on…

I have had nothing but problems with EPG for weeks now, so as soon as I realize I have issues again, I will turn on debug and run a refresh, and send the logs, won’t be long.

@Havok115 said:
Verified I did not have it turned on…

I have had nothing but problems with EPG for weeks now, so as soon as I realize I have issues again, I will turn on debug and run a refresh, and send the logs, won’t be long.

Please see my above post.

@ChuckPA said:

@Havok115 said:
Verified I did not have it turned on…

I have had nothing but problems with EPG for weeks now, so as soon as I realize I have issues again, I will turn on debug and run a refresh, and send the logs, won’t be long.

Please see my above post.

Chuck, Thank you for responding, it has been very frustrating trying to get this working again, and of course since I deleted my Plugins Directory and let it refresh, after the first failure it has worked perfectly. I don’t think it is fixed permanently, because of the nature of the problem, however, since I posted, there has been 0 problems refreshing, if and when it happens again I will for sure enable verbose and debug logging and send the logs to this thread.

I love Plex, it has bugs, and we are dealing with them, and some of them are pretty bad, missing daily shows, and the like, but this thing has saved me a bundle on my costs of Television, and I really don’t want to go elsewhere, because this is the best concept on the Net as far as I am concerned. So please keep up the good work, and I am quite Tech savvy myself being an Engineer for a Cloud Based Application provider myself. If there is anything I can do to assist in your processes I would be happy to help make Plex the best one stop shop for everyone’s needs.

I will post as soon as I have issues again, but of course the minute I start complaining, everything starts working, it was almost as if my server knew you were getting involved and decided to behave itself…

Okay so I have noticed that my epg refresh is working to 100%, but it is not getting every show in my recording list. Last night two new airings were on, and they are shows I wanted to record, there were no conflicts, and yet they did not record, or show up in the recording schedule at all. I have enabled debug and verbose and ran an EPG refresh. I am attaching my logs below. I am running the latest Plex Media Server in 64bit Fedora.

@ChuckPA said:

@Havok115 said:
Verified I did not have it turned on…

I have had nothing but problems with EPG for weeks now, so as soon as I realize I have issues again, I will turn on debug and run a refresh, and send the logs, won’t be long.

Please see my above post.

See above…

@ChuckPA mentioned having verbose disabled in his last post. Verbose logging adds too much information to the logs often to the point of making it extremely difficult to find information. A Plex Employee will ask if/when they need verbose logging enabled.

Yeah he did, lemme run it again without verbose, dunno what I was thinking…

Okay with Debug, no Verbose…

Your logs only go back to 3/18 today at 10:57 so no way to see what shows you missed the other day. With Debug logging on now if you get any other missed shows this week please post again with logs pulled from right after missed recordings. I see log entries for upcoming scheduled recordings. For example:

Mar 18, 2018 15:05:22.700 [0x7fc47e3f9700] DEBUG - DVR:Grabber: Scheduling 'Judge Judy - E158 - Episode 158' for timed grab at 2018-03-30 16:30:00 (in 1041878 seconds)
Mar 18, 2018 15:05:22.700 [0x7fc47e3f9700] DEBUG - DVR:Schedule: Attempting to schedule the item 'Judge Judy - E159 - Episode 159'.
Mar 18, 2018 15:05:22.700 [0x7fc47e3f9700] DEBUG - DVR:Schedule: Trying airing at 2018-03-30 16:00:00 on channel 189.
Mar 18, 2018 15:05:22.700 [0x7fc47e3f9700] DEBUG - DVR:Schedule: Device 0 tuner 1 scheduled recording between 2018-03-30 16:00:00 and 2018-03-30 16:30:00 on channel 189.
Mar 18, 2018 15:05:22.701 [0x7fc47e3f9700] DEBUG - DVR:Grabber: Scheduling 'Judge Judy - E159 - Episode 159' for timed grab at 2018-03-30 16:00:00 (in 1040078 seconds)
Mar 18, 2018 15:05:22.703 [0x7fc47e3f9700] DEBUG - DVR:Schedule: Attempting to schedule the item 'Roseanne - E1 - Twenty Years to Life; Dress to Impress'.
Mar 18, 2018 15:05:22.703 [0x7fc47e3f9700] DEBUG - DVR:Schedule: Trying airing at 2018-03-27 19:00:00 on channel 187.
Mar 18, 2018 15:05:22.703 [0x7fc47e3f9700] DEBUG - DVR:Schedule: Device 0 tuner 0 scheduled recording between 2018-03-27 19:00:00 and 2018-03-27 20:00:00 on channel 187.
Mar 18, 2018 15:05:22.703 [0x7fc47e3f9700] DEBUG - DVR:Grabber: Scheduling 'Roseanne - E1 - Twenty Years to Life; Dress to Impress' for timed grab at 2018-03-27 19:00:00 (in 791678 seconds)