Page 1 of 1

More "Server Error 500"

Posted: Fri Feb 08, 2019 10:49 am
by adam1991
Woke up this AM to another Server Error 500 result from the overnight task. Ran it manually, all is well.

I realize Gary will probably program around this to try the task again in an effort to keep the user from seeing this if at all possible, but I'm getting the willys here. Call whatever names you like, but old folks like me have been around the block too long not to see the bad potential in all of this SD stuff happening lately.

I remember back when the Ceton card was announced, long before it was released; I spent that couple of years paying attention and making plans for the inevitable end of analog cable service, which tied in with the end of ReplayTV. When the Ceton card came out, I jumped hard and went right to 7MC.

Here we are...8?...years later, and guide service is beginning to be wonky across the board. First Rovi, now SD.

Always be aware, and never stop planning for the future.

Re: More "Server Error 500"

Posted: Fri Feb 08, 2019 2:42 pm
by garyan2
If you download the latest version (released last night), you will find that the Server Error 500 may no longer be an issue for updates. EPG123 will still report them in the log file, but it will try the request 3 times before declaring an en error and failing.

I think the difference in outlook between you and I is that these errors aren't a sign of the end, but simply that the servers need some attention. The hints we get to that needed action starts with the time discontinuities and evidently the 500 errors. Other indicators would be slow updates and response times. Talking with SD the last few days, it is probable they will schedule a server downtime this weekend to do some house cleaning and maintenance. What we are experiencing is a check engine light and is fully correctable. There is no change in physics that renders our method of updating the guide to be useless.

What is needed though, is when we start seeing issues, or the check engine light, we report them to Schedules Direct. I can only verify an issue exists right along with every other user, but Schedules Direct can actually take action to correct/repair the problem.

Note: SD servers are in the AWS server farms ... they aren't going anywhere and they are fully supported by Amazon which isn't going anywhere for a very long time.

Re: More "Server Error 500"

Posted: Fri Feb 08, 2019 6:13 pm
by adam1991
garyan2 wrote: Fri Feb 08, 2019 2:42 pmI think the difference in outlook between you and I is that these errors aren't a sign of the end, but simply that the servers need some attention. The hints we get to that needed action starts with the time discontinuities and evidently the 500 errors. Other indicators would be slow updates and response times. Talking with SD the last few days, it is probable they will schedule a server downtime this weekend to do some house cleaning and maintenance. What we are experiencing is a check engine light and is fully correctable. There is no change in physics that renders our method of updating the guide to be useless.
I won't disagree with you one bit, but...trust, but verify. We'll see how they respond. That'll tell.
What is needed though, is when we start seeing issues, or the check engine light, we report them to Schedules Direct. I can only verify an issue exists right along with every other user, but Schedules Direct can actually take action to correct/repair the problem.

Note: SD servers are in the AWS server farms ... they aren't going anywhere and they are fully supported by Amazon which isn't going anywhere for a very long time.
pardon me if I don't put that level of faith into any of it.

Re: More "Server Error 500"

Posted: Sat Feb 09, 2019 4:34 am
by garyan2
SD took the servers offline for maintenance at 0400Z. Should be back up at 0800Z. We'll see if you have any Server 500 errors tomorrow?

Re: More "Server Error 500"

Posted: Sat Feb 09, 2019 3:16 pm
by adam1991
I updated to 1.2.11 last night, to take advantage of the three tries and you're out feature.

0800Z is 3am EST. That's when my scheduled task is set to run. I expected to wake up this morning to a red icon, thinking that the servers wouldn't necessarily be up at 3am; I was going to let it slide until tonight's overnight run and see what happens.

Instead, I woke up to a green icon, with today's date on it, WITH a plus sign on it indicating there's a new version. ???

Code: Select all

[2/9/2019 3:00:01 AM] ===============================================================================
[2/9/2019 3:00:01 AM]  Beginning epg123 update execution. version 1.2.11.0
[2/9/2019 3:00:01 AM] ===============================================================================
[2/9/2019 3:00:01 AM] [ INFO] Beginning EPG123 update execution. 2019-02-09 08:00:01Z
[2/9/2019 3:00:01 AM] [ INFO] DaysToDownload: 21 , TheTVDBNumbers : True , PrefixEpisodeTitle: False , PrefixEpisodeDescription : True , AppendEpisodeDesc: True , OADOverride : True , TMDbCoverArt: True , IncludeSDLogos : False , AutoAddNew: True , CreateXmltv: False , ModernMediaUiPlusSupport: False
[2/9/2019 3:00:04 AM] [ERROR] Failed token request. code: 3000 , message: Server offline for maintenance. , datetime: 2019-02-09T08:00:04Z
[2/9/2019 3:00:04 AM] [ERROR] Failed to retrieve token from Schedules Direct. message: Failed token request. code: 3000 , message: Server offline for maintenance. , datetime: 2019-02-09T08:00:04Z
[2/9/2019 3:00:04 AM] [ INFO] epg123 update execution time was 00:00:03.3400047.
[2/9/2019 3:00:09 AM] ===============================================================================
[2/9/2019 3:00:09 AM]  Beginning epg123 client execution. version 1.2.11.0
[2/9/2019 3:00:09 AM] ===============================================================================
[2/9/2019 3:00:09 AM] [ INFO] Beginning epg123 client execution. 2019-02-09 08:00:09Z
[2/9/2019 3:00:09 AM] [ INFO] Import: True , Match: True , NoLogo: False , Force: False , ShowProgress: False
[2/9/2019 3:00:10 AM] Entering importMxfFile() for file "c:\epg123\output\epg123.mxf"
[2/9/2019 3:00:26 AM] [ INFO] Successfully imported .mxf file into Media Center database. Exit code: 0
[2/9/2019 3:00:26 AM] Exiting importMxfFile(). SUCCESS.
[2/9/2019 3:00:26 AM] [ INFO] Completed the automatch of lineup stations to tuner channels.
[2/9/2019 3:00:26 AM] [ INFO] Completed lineup refresh.
[2/9/2019 3:00:26 AM] Entering runWmcTask(ReindexSearchRoot)
[2/9/2019 3:00:26 AM] [ INFO] SUCCESS: Attempted to run the scheduled task "Microsoft\Windows\Media Center\ReindexSearchRoot".
[2/9/2019 3:00:26 AM] [ INFO] Successfully started the ReindexSearchRoot task. Exit code: 0
[2/9/2019 3:00:26 AM] Exiting runWmcTask(ReindexSearchRoot). SUCCESS.
[2/9/2019 3:00:26 AM] Entering runWmcTask(PvrScheduleTask)
[2/9/2019 3:00:26 AM] [ INFO] SUCCESS: Attempted to run the scheduled task "Microsoft\Windows\Media Center\PvrScheduleTask".
[2/9/2019 3:00:27 AM] [ INFO] Successfully started the PvrScheduleTask task. Exit code: 0
[2/9/2019 3:00:27 AM] Exiting runWmcTask(PvrScheduleTask). SUCCESS.
[2/9/2019 3:00:27 AM] [ INFO] Completed EPG123 client execution.
[2/9/2019 3:00:27 AM] [ INFO] EPG123 client execution time was 00:00:17.4990412.
The update was not succesful, nor is there a new version available.

Inquiring minds and all that.

Thanks.

Re: More "Server Error 500"

Posted: Sat Feb 09, 2019 3:24 pm
by garyan2
Looks like the server was still down for maintenance, so your update did not complete. Since it did not complete, the icon was not updated either. If you take a look, it will have yesterdays date on it rather than todays.

Re: More "Server Error 500"

Posted: Sat Feb 09, 2019 4:04 pm
by adam1991
No, it had today's date on it. 2/9. No question. Still does.

Re: More "Server Error 500"

Posted: Sat Feb 09, 2019 4:13 pm
by garyan2
Oh yeah... the client creates the image, and an "update available" status is determined by the contents of the mxf file. Since the mxf file was not updated today it still has yesterdays run which was with the old version. The client will look for "Available" in the displayName attribute as below.

Code: Select all

<Providers>
  <Provider id="provider1" name="EPG123" displayName="Electronic Program Guide in 1-2-3 v1.2.10 (v1.2.11 Available)" copyright="© 2019 GaRyan2. Portions of content provided by Gracenote." status="1" />
</Providers>

Re: More "Server Error 500"

Posted: Sat Feb 09, 2019 4:49 pm
by adam1991
That makes sense.

But previous runs which got "Server Error 500" came up with a red icon. For example:

Code: Select all

[2/7/2019 3:00:00 AM] ===============================================================================
[2/7/2019 3:00:00 AM]  Beginning epg123 update execution. version 1.2.5.20
[2/7/2019 3:00:00 AM] ===============================================================================
[2/7/2019 3:00:00 AM] [ INFO] Beginning EPG123 update execution. 2019-02-07 08:00:00Z
[2/7/2019 3:00:00 AM] [ INFO] DaysToDownload: 21 , TheTVDBNumbers : True , PrefixEpisodeTitle: False , PrefixEpisodeDescription : True , AppendEpisodeDesc: True , OADOverride : True , TMDbCoverArt: True , IncludeSDLogos : False , AutoAddNew: True , CreateXmltv: False , ModernMediaUiPlusSupport: False
[2/7/2019 3:00:04 AM] [ INFO] Token request successful. serverID: 20141201.web.1
[2/7/2019 3:00:05 AM] [ INFO] Status request successful. account expires: 2019-10-28T13:33:26Z , lineups: 1/4 , lastDataUpdate: 2019-02-07T05:36:00Z
[2/7/2019 3:00:05 AM] [ INFO] system status: Online , message: No known issues.
[2/7/2019 3:00:06 AM] [ INFO] epg123 is not up to date. Latest version is 1.2.10 and can be downloaded from http://epg123.garyan2.net.
[2/7/2019 3:00:07 AM] [ INFO] Successfully retrieved TMDb configurations.
[2/7/2019 3:00:08 AM] [ INFO] Successfully requested listing of client lineups from Schedules Direct.
[2/7/2019 3:00:08 AM] Entering buildLineupServices() for 1 lineups.
[2/7/2019 3:00:09 AM] [ INFO] Successfully retrieved the station mapping for lineup USA-OTA-43214.
[2/7/2019 3:00:09 AM] Exiting buildLineupServices(). SUCCESS.
[2/7/2019 3:00:09 AM] Entering getAllScheduleEntryMd5s() for 21 days on 18 stations.
[2/7/2019 3:00:24 AM] [ INFO] Successfully retrieved Md5s for 18 station's daily schedules.
[2/7/2019 3:00:26 AM] [ INFO] Successfully retrieved 18 station's daily schedules.
[2/7/2019 3:00:28 AM] [ INFO] Found 185 cached daily schedules.
[2/7/2019 3:00:28 AM] [ INFO] Downloaded 155 daily schedules.
[2/7/2019 3:00:31 AM] [ INFO] Processed 340 daily schedules for 18 stations.
[2/7/2019 3:00:31 AM] Exiting getAllScheduleEntryMd5s(). SUCCESS.
[2/7/2019 3:00:31 AM] Entering buildAllProgramEntries() for 7117 programs.
[2/7/2019 3:01:10 AM] [ INFO] Found 6406 cached program descriptions.
[2/7/2019 3:01:29 AM] [ERROR] SD API WebException Thrown. Message: The remote server returned an error: (500) Internal Server Error. , Status: ProtocolError
[2/7/2019 3:01:29 AM] [ERROR] Did not receive a response from Schedules Direct for 711 program descriptions.
[2/7/2019 3:01:29 AM] Problem occurred during buildProgramEntries(). Exiting.
[2/7/2019 3:01:29 AM] [ERROR] Failed to create MXF file. Exiting.
[2/7/2019 3:01:29 AM] [ INFO] epg123 update execution time was 00:01:28.7262234.
[2/7/2019 3:01:29 AM] ===============================================================================
[2/7/2019 3:01:29 AM]  Beginning epg123 client execution. version 1.2.5.0
[2/7/2019 3:01:29 AM] ===============================================================================
[2/7/2019 3:01:29 AM] [ INFO] Beginning epg123 client execution. 2019-02-07 08:01:29Z
[2/7/2019 3:01:29 AM] [ INFO] Import: True , Match: True , NoLogo: False , Force: False , ShowProgress: False
[2/7/2019 3:01:30 AM] Entering importMxfFile() for file "C:\epg123\output\epg123.mxf"
[2/7/2019 3:01:45 AM] [ INFO] Successfully imported .mxf file into Media Center database. Exit code: 0
[2/7/2019 3:01:45 AM] Exiting importMxfFile(). SUCCESS.
[2/7/2019 3:01:45 AM] [ INFO] Completed the automatch of lineup stations to tuner channels.
[2/7/2019 3:01:45 AM] [ INFO] Completed lineup refresh.
[2/7/2019 3:01:45 AM] Entering runWmcTask(ReindexSearchRoot)
[2/7/2019 3:01:45 AM] [ INFO] SUCCESS: Attempted to run the scheduled task "Microsoft\Windows\Media Center\ReindexSearchRoot".
[2/7/2019 3:01:45 AM] [ INFO] Successfully started the ReindexSearchRoot task. Exit code: 0
[2/7/2019 3:01:45 AM] Exiting runWmcTask(ReindexSearchRoot). SUCCESS.
[2/7/2019 3:01:45 AM] Entering runWmcTask(PvrScheduleTask)
[2/7/2019 3:01:46 AM] [ INFO] SUCCESS: Attempted to run the scheduled task "Microsoft\Windows\Media Center\PvrScheduleTask".
[2/7/2019 3:01:46 AM] [ INFO] Successfully started the PvrScheduleTask task. Exit code: 0
[2/7/2019 3:01:46 AM] Exiting runWmcTask(PvrScheduleTask). SUCCESS.
[2/7/2019 3:01:46 AM] [ INFO] Completed EPG123 client execution.
[2/7/2019 3:01:46 AM] [ INFO] EPG123 client execution time was 00:00:16.1500226.
It looks like last night's failed token request still got me a green icon, while on 2/7 the update process got a valid token request which was then followed by a server error--and that generates a red icon.

Shouldn't any failure of the update process, including a failed token request and subsequent abort of the update process, generate a red icon?

Re: More "Server Error 500"

Posted: Sat Feb 09, 2019 5:31 pm
by garyan2
Yes, but no. Like I said, the client generates the icon and the only thing it has to go by is the MXF file itself. Inside the MXF file are indicators for an available update and a status from the builder (epg123.exe). Then there is the file date/timestamp. If an error occurs such that the MXF file creation is aborted, then the MXF file in the output will be untouched and will be from the previous update.

To get an error (red) icon...
1. MXF file needs to be greater than 24 hours old, OR
2. an error occurred during import / automatch (epg123Client.exe)

To get a warning (yellow) icon...
1. MXF file must be less than 24 hours old, AND
2. MXF status indicator must be 47825 (0xBAD1)

Because you did a manual update yesterday out-of-schedule, the file was less than 24 hours old and didn't get recognized as an error for logo purposes. Note that the error is still logged in the Event Log... just the logo does not reflect any problems with the aborting of the epg123.exe update run.

Re: More "Server Error 500"

Posted: Sun Feb 10, 2019 3:41 pm
by StinkyImp
garyan2 wrote: Sat Feb 09, 2019 5:31 pm To get an error (red) icon...
1. MXF file needs to be greater than 24 hours old, OR...
I open and close WMC multiple times per day. I always make it a habit to look at the generated icon and the date stamp to make sure it's current.

On the 8th and the 9th my icon was green and the icon date was for the (then) current day.

Code: Select all

EPG123 Log Parser (and Report Generator)
Report Created on 02/10/2019 at 08:31:33
================================================================
     1 [2/8/2019 12:18:20 AM] [ERROR] The MXF file imported is 24.01 hours old.
     2 [2/9/2019 12:15:46 AM] [ERROR] The MXF file imported is 47.96 hours old.

===== QUERY INFORMATION (Custom) ===============================
File Name:		OK_TO_DELETE_Merged Log.txt
Search String:		The MXF file imported
Date Range:		02/01/2019 thru 02/10/2019
Total results found:	2
Query time:		13 seconds

===== GENERAL INFORMATION ======================================
Total lines processed:	10835
Logfile timespan:	9/29/2018 thru 2/10/2019
EPG123 version 1.2.7.0

Should my icon have been red on at least one of those days?

Re: More "Server Error 500"

Posted: Sun Feb 10, 2019 4:07 pm
by garyan2
StinkyImp wrote: Sun Feb 10, 2019 3:41 pmShould my icon have been red on at least one of those days?
Yes, they both should have been red. I'm not seeing anything in my code that hints it could be anything else.

I'll keep looking.

EDIT: I was looking at the current version, not v1.2.7, but I don't believe there were any changes between then and now. I'll look at the source for 1.2.7 later.