Second Days Schedule Update Run Time

An evolving, supported alternative to Rovi
Forum rules
★ Download the latest EPG123 here: https://garyan2.github.io/ <> Setup guide here: https://garyan2.github.io/install.html
Post Reply
glorp

Posts: 369
Joined: Sun Sep 23, 2012 2:54 pm
Location:

HTPC Specs: Show details

Second Days Schedule Update Run Time

#1

Post by glorp » Wed Mar 16, 2016 3:51 pm

Starting a thread so this doesn't get mixed in with all the other setup questions.

Question:

Yesterday after I installed EPG123 on 2 existing MCs it ran the initial schedule dl and update. Took a total of ~7 minutes for each to complete.

Code: Select all

03/15/2016 02:04:54 PM] [STATS] epg123 execution time was 00:06:46.2640626.
Today I had one of those two new machines update now via the scheduled task. It took ~36 minutes to complete the second run. I was actually getting nervous and had an itchy "kill" finger on the task but decided to ride it out for at least an hour and it finished normally. Was doing major disk access the whole time. Here's a snipped portion of the log, full run starts @ exactly 0800 but not much interesting in all those steps:

Code: Select all

[3/16/2016 8:00:04 AM] Entering getAllScheduleEntryMd5s() for 14 days on 520 stations.
[3/16/2016 8:01:31 AM] [ INFO] Successfully retrieved Md5s for 520 station's daily schedules.
[3/16/2016 8:03:16 AM] [ INFO] Successfully retrieved 520 station's daily schedules.
[3/16/2016 8:07:54 AM] Entering buildAllProgramEntries() for 38499 programs.
[3/16/2016 8:31:06 AM] [ INFO] Successfully retrieved 2737 programs metadata.
[3/16/2016 8:31:23 AM] Exiting buildAllProgramEntries(). SUCCESS.
...
[3/16/2016 8:31:32 AM] [STATS] Generated .mxf file contains 520 services, 8409 series, 38499 programs, and 55720 people with 11311 image links.
[3/16/2016 8:33:02 AM] [ INFO] Successfully imported .mxf file into Media Center. Exit code: 0
[3/16/2016 8:33:02 AM] [ INFO] Successfully started the ReindexSearchRoot task. Exit code: 0
[3/16/2016 8:36:18 AM] [ INFO] 4657 files deleted from the cache directory during cleanup.
[3/16/2016 8:36:18 AM] [STATS] epg123 execution time was 00:36:17.3399930.
So, normal to take that long? Guide data are present and I confirmed another days worth added at end after everything quit so it did its update. One thing I did on these two MCs that was different was to simply deactivate all the unused channels 1-10000 using Guide Tool rather than deleting channels 1000-10000 like I did on the first machine.

webminster

Posts: 657
Joined: Tue Dec 20, 2011 11:05 pm
Location:

HTPC Specs: Show details

#2

Post by webminster » Thu Mar 17, 2016 1:39 am

Mine (0.7.6 on a laptop with SSD) is running a lot longer tonight for some unknown reason. 38 minutes in and hasn't replaced yesterdays mxf file yet. Don't know why.

Code: Select all

[3/16/2016 7:01:03 PM] [ INFO] Token request successful. serverID: 20141201.web.2
[3/16/2016 7:01:03 PM] [ERROR] epg123 is not recognized as an approved app from Schedules Direct. code: 1005 , message: Did not recognize the submitted client. , datetime: 2016-03-17T01:00:46Z
[3/16/2016 7:01:04 PM] [ INFO] Successfully requested listing of client lineups from Schedules Direct.
[3/16/2016 7:01:04 PM] [ INFO] Successfully retrieved the station mapping for lineup USA-CO05459-X.
[3/16/2016 7:01:05 PM] Entering getAllScheduleEntryMd5s() for 18 days on 513 stations.
[3/16/2016 7:01:54 PM] [ INFO] Successfully retrieved Md5s for 513 station's daily schedules.
[3/16/2016 7:02:35 PM] [ INFO] Successfully retrieved 513 station's daily schedules.
[3/16/2016 7:13:14 PM] Entering buildAllProgramEntries() for 44722 programs.
[3/16/2016 7:41:01 PM] [ INFO] Successfully retrieved 3234 programs metadata.
[3/16/2016 7:41:52 PM] Exiting buildAllProgramEntries(). SUCCESS.
[3/16/2016 7:41:52 PM] Entering getAllMoviePosters() for 5174 movies.
[3/16/2016 7:41:55 PM] [ INFO] Successfully retrieved artwork info for 171 programs.
-Alan

rkulagow

Posts: 246
Joined: Sun Jul 19, 2015 1:04 am
Location: Schedules Direct

HTPC Specs: Show details

#3

Post by rkulagow » Thu Mar 17, 2016 2:47 am

Did the run complete?

If yes, and you run it again right now (it's 9:46P in Chicago), does it still take a long time? I'm watching the servers to see if I can determine if this is a one-off for your particular situation, or a systemic issue.

webminster

Posts: 657
Joined: Tue Dec 20, 2011 11:05 pm
Location:

HTPC Specs: Show details

#4

Post by webminster » Thu Mar 17, 2016 3:18 am

Yes. it did complete in about 48 minutes all told.
Just ran from a command prompt, it ran mostly out of cache and ran in a couple of minutes.

Didn't observe any Internet issues locally around the time...

edit: running again by triggering the task, is running very slow. Must be the i/o or other priorities running under task scheduler that is making it run so slowly...
Last edited by webminster on Thu Mar 17, 2016 3:27 am, edited 1 time in total.
-Alan

glorp

Posts: 369
Joined: Sun Sep 23, 2012 2:54 pm
Location:

HTPC Specs: Show details

#5

Post by glorp » Thu Mar 17, 2016 3:22 am

IDK if it will help but today my first run on one WMC occurred at 0730 (Pacific) and took ~4.5 minutes. The second WMC installed yesterday updated at 0800 and that's the log from ^above; took ~36 minutes. At 1043 I installed a third copy on a server and started the first data pull run which took ~4 minutes. AFAIK, you still have tracing turned on for my account. All three of those use exactly the same lineup configuration.

User avatar
garyan2

Posts: 7438
Joined: Fri Nov 27, 2015 7:23 pm
Location:

HTPC Specs: Show details

#6

Post by garyan2 » Thu Mar 17, 2016 3:24 am

Sorry, didn't see this thread created.

Upon entering the buildAllProgramEntries() procedure, epg123 steps through the previous steps downloaded md5s to determine what is in cache, and what needs to be downloaded. So glorp's machine was checking 38499 program md5s with the files in the cache; if the file existed it was read into epg123 and processed. If the file didn't exist, it was queued for download to be saved in the cache and processed (which was 2737 programs). This process hits the hard drive pretty hard to import all the cached files and write the new program files. The huge disparity between the initial setup and the update could point to poor read performance of your hard drive and possibly slow internet connection...but that is just a possibility. I have a couple questions ... did you change any parameters of the scheduled task? did you use epg123 to create the task? Was the task run right after a login/boot where the hard drive would be totally thrashed with windows startup/login activities as well?

Right now, all I can offer is both your experiences are unexpected...especially on a SSD.
- Gary
Keeping WMC alive beyond January 2020. https://garyan2.github.io

User avatar
garyan2

Posts: 7438
Joined: Fri Nov 27, 2015 7:23 pm
Location:

HTPC Specs: Show details

#7

Post by garyan2 » Thu Mar 17, 2016 3:28 am

webminster wrote:Yes. it did complete in about 48 minutes all told.
Just ran from a command prompt, it ran mostly out of cache and ran in a couple of minutes.

Didn't observe any Internet issues locally around the time...
That's a good data point. Could you run the Task to see if there is any notable difference?

EDIT: looks like you just did...like minds :)
- Gary
Keeping WMC alive beyond January 2020. https://garyan2.github.io

glorp

Posts: 369
Joined: Sun Sep 23, 2012 2:54 pm
Location:

HTPC Specs: Show details

#8

Post by glorp » Thu Mar 17, 2016 3:36 am

garyan2 wrote:Sorry, didn't see this thread created.

Upon entering the buildAllProgramEntries() procedure, epg123 steps through the previous steps downloaded md5s to determine what is in cache, and what needs to be downloaded. So glorp's machine was checking 38499 program md5s with the files in the cache; if the file existed it was read into epg123 and processed. If the file didn't exist, it was queued for download to be saved in the cache and processed (which was 2737 programs). This process hits the hard drive pretty hard to import all the cached files and write the new program files. The huge disparity between the initial setup and the update could point to poor read performance of your hard drive and possibly slow internet connection...but that is just a possibility. I have a couple questions ... did you change any parameters of the scheduled task? did you use epg123 to create the task? Was the task run right after a login/boot where the hard drive would be totally thrashed with windows startup/login activities as well?

Right now, all I can offer is both your experiences are unexpected...especially on a SSD.
All of my caches are on spinners. I'm not sure I know what you mean about changing task parameters. Yes, if you mean did I allow epg123 to create it but then I modified some things manually; primarily I change it to run under NETWORK SERVICE account and I also set some of the max run time settings. Internet speeds should not be an issue and per my earlier comment would seem unlikely since I had a run on a different machine 30 minutes earlier whose update was very fast.

After thinking about it all day I have/had a theory about what was maybe happening but then webminster posted and I became less convinced about it. Basically I realized I had Search Indexing enabled for the drive and subdirectory on the newest installation machine that took so long. After about 20 minutes of processing this AM I finally gave in to being patient and started up Process Monitor and noticed that all the disk access was coming from epg123 and Also SearchIndexer. I later suspected that perhaps Windows Search was trying to keep up with all the changes happening in the cache, plus I also keep the index files themselves for Windows Search on that same spinner so it may have been epg123 + search reading for indexing + search writing for indexing all at the same time. I have removed the EPG123 program/cache directory from the indexed files and we'll see tomorrow I guess.

User avatar
garyan2

Posts: 7438
Joined: Fri Nov 27, 2015 7:23 pm
Location:

HTPC Specs: Show details

#9

Post by garyan2 » Thu Mar 17, 2016 3:41 am

glorp wrote:
garyan2 wrote:Sorry, didn't see this thread created.

Upon entering the buildAllProgramEntries() procedure, epg123 steps through the previous steps downloaded md5s to determine what is in cache, and what needs to be downloaded. So glorp's machine was checking 38499 program md5s with the files in the cache; if the file existed it was read into epg123 and processed. If the file didn't exist, it was queued for download to be saved in the cache and processed (which was 2737 programs). This process hits the hard drive pretty hard to import all the cached files and write the new program files. The huge disparity between the initial setup and the update could point to poor read performance of your hard drive and possibly slow internet connection...but that is just a possibility. I have a couple questions ... did you change any parameters of the scheduled task? did you use epg123 to create the task? Was the task run right after a login/boot where the hard drive would be totally thrashed with windows startup/login activities as well?

Right now, all I can offer is both your experiences are unexpected...especially on a SSD.
All of my caches are on spinners. I'm not sure I know what you mean about changing task parameters. Yes, if you mean did I allow epg123 to create it but then I modified some things manually; primarily I change it to run under NETWORK SERVICE account and I also set some of the max run time settings. Internet speeds should not be an issue and per my earlier comment would seem unlikely since I had a run on a different machine 30 minutes earlier whose update was very fast.

After thinking about it all day I have/had a theory about what was maybe happening but then webminster posted and I became less convinced about it. Basically I realized I had Search Indexing enabled for the drive and subdirectory on the newest installation machine that took so long. After about 20 minutes of processing this AM I finally gave in to being patient and started up Process Monitor and noticed that all the disk access was coming from epg123 and Also SearchIndexer. I later suspected that perhaps Windows Search was trying to keep up with all the changes happening in the cache, plus I also keep the index files themselves for Windows Search on that same spinner so it may have been epg123 + search reading for indexing + search writing for indexing all at the same time. I have removed the EPG123 program/cache directory from the indexed files and we'll see tomorrow I guess.
Yah, we have noticed that windows SearchIndexer will be active during the cache scanning/building/modifying. I hadn't thought about excluding the directory from search ... very interested if that makes a difference and will include that in the guide if it pans out.
- Gary
Keeping WMC alive beyond January 2020. https://garyan2.github.io

webminster

Posts: 657
Joined: Tue Dec 20, 2011 11:05 pm
Location:

HTPC Specs: Show details

#10

Post by webminster » Thu Mar 17, 2016 3:44 am

Probably a bad idea, but got the run time on non-initial runs down from 48 minutes to maybe 5... by changing the task (I/O) priority. Creating tasks in the GUI sets priority 7 (below normal), I exported the task, changed to 5, and re-imported. Can't change the priority in the GUI. may run it too hot, not sure yet. Just experimenting.

edit: as far as having changed the task... the task is set to run as SYSTEM, logged in or not, highest privileges.
Interesting point re: indexing - I'll disable that on that folder/subfolders and see what happens.

edit 2: from a first pass, doesn't look much like turning off indexing on the epg123 folder and subfolders made much if any difference. I deleted the existing task and recreated it, and disabled the indexing, and still runs a lot slower than if you run it in a shell. Or, if you change the task priority.
-Alan

User avatar
garyan2

Posts: 7438
Joined: Fri Nov 27, 2015 7:23 pm
Location:

HTPC Specs: Show details

#11

Post by garyan2 » Thu Mar 17, 2016 4:44 am

All right, looking for some suggestions here ... come on, I can't know everything!

If we bump the priority of the task, which appears to be likely, should we also define an idle condition to run? What is the best approach? Personally, I run my task at 0400, so I don't really care how long it takes. I will also say I don't have this issue on my scheduled task runs so don't know if I'll be able to recreate that here to experiment with.
- Gary
Keeping WMC alive beyond January 2020. https://garyan2.github.io

webminster

Posts: 657
Joined: Tue Dec 20, 2011 11:05 pm
Location:

HTPC Specs: Show details

#12

Post by webminster » Thu Mar 17, 2016 4:48 am

I'm still running some tests, so I don't have concrete suggestions yet. And I'm basically with you, once I pull the trigger on this "production", It'll probably run at 2 or 4 am, and if it takes an hour I'll sleep through it and not care. Not sure it's worth burning any extra CPU in that case by bumping the priority. This is all on my test laptop with an SSD, not my main HTPC (which is a more powerful box), so not sure I'll know until I gather the balls to hack it.
-Alan

glorp

Posts: 369
Joined: Sun Sep 23, 2012 2:54 pm
Location:

HTPC Specs: Show details

#13

Post by glorp » Thu Mar 17, 2016 3:45 pm

Some details:

I have EPG123 installed and running on 3 different machines right now. Each is scheduled to run off a scheduled task created by EPG123 but tasks modified some by me mainly to run in a different security context. All 3 tasks have been modified identically though. Each machine;s task is scheduled to run at a different time within a 3 hour window. All 3 have done at least one previous download so caches are populated. All 3 are currently configured with the same EPG123 options however one is running on the server (for my ultimate whole home set up) so is not configured to do the mxf load/reindex. Same single SD lineup on each with 14 day data pulls configured updating only once per day so today's updates would have been 24 hours from the last ones as I didn't run any of them in-between scheduled task starts. All three have EPG123 and the cache on spinners, non-boot drives although the server's directory is actually on a DrivePool drive.

The EPG123 run times to get to the "Entering WriteMXF" step are:

Code: Select all

Machine                 Task Start Time                 Run Time to WriteMXF
Server                     0530                              06:12
First (New) HTPC           0730                              00:47  (that's right, 47 seconds)
Old HTPC                   0800                              08:40  (this is the one that took ~36 minutes yesterday)
The main differences in the machines are the age and configuration of hardware/resources. The "Old HTPC" has only 4 gig memory, older drives in use for several years whereas the others are either brand new with 8 gig (New HTPC) or 16 gig, about a year-old drives (Server)). I watched the Old HTPC closely with Resource Monitor while it was doing it's thing. In addition to epg123.exe using a lot of disk i/o so still was SearchIndexer (yes, I had indeed excluded the epg123 directory from indexing) and also at times it appeared the swap files were being read/written to [C:\pagefile.sys and D:\pagefil.sys]. Memory use never went above 46% committed according to ResMon however.

I don't think ~10 minutes for an update is unreasonable and like what's been said already, it would occur during periods where the machine is not expected to be in use. It's just that these update times vary so wildly from day to day and machine to machine for what should be exactly the same schedule update on each that it seems like something isn't quite right.

IownFIVEechos

Posts: 696
Joined: Fri Jul 12, 2013 2:29 pm
Location:

HTPC Specs: Show details

#14

Post by IownFIVEechos » Thu Mar 17, 2016 4:01 pm

^^^
How about the network settings. Are they all using the same DNS? I would clear your DNS cache. Perhaps one machine is hitting a slower server? Just a thought with having no knowledge of the way the files are retrieved. Best of luck.

glorp

Posts: 369
Joined: Sun Sep 23, 2012 2:54 pm
Location:

HTPC Specs: Show details

#15

Post by glorp » Thu Mar 17, 2016 4:14 pm

Hmm. "Server" is the DNS provider for all including itself. Server forward-resolves to Google, OpenDNS and typically maintains a cached entry for SD. All have 1-gig network interfaces to the same switch and router.

User avatar
STC

Posts: 6808
Joined: Mon Jun 06, 2011 4:58 pm
Location:

HTPC Specs: Show details

#16

Post by STC » Thu Mar 17, 2016 4:34 pm

And you're already connected to SD. No more routing of IP required.
By the Community, for the Community. 100% Commercial Free.

Want decent guide data back? Check out EPG123

User avatar
STC

Posts: 6808
Joined: Mon Jun 06, 2011 4:58 pm
Location:

HTPC Specs: Show details

#17

Post by STC » Thu Mar 17, 2016 5:45 pm

FWIW I just checked the log.

On the 16th 3:20am EST it took 09.27 which is unusually long. I average 2-3 minutes.
By the Community, for the Community. 100% Commercial Free.

Want decent guide data back? Check out EPG123

User avatar
garyan2

Posts: 7438
Joined: Fri Nov 27, 2015 7:23 pm
Location:

HTPC Specs: Show details

#18

Post by garyan2 » Sun Mar 20, 2016 7:20 am

Here are the values for the task priority...epg123 is currently 7. I'm going to change it to 6 to be a low normal priority as opposed to a below normal task.
Attachments
TaskPriority.PNG
- Gary
Keeping WMC alive beyond January 2020. https://garyan2.github.io

glorp

Posts: 369
Joined: Sun Sep 23, 2012 2:54 pm
Location:

HTPC Specs: Show details

#19

Post by glorp » Sun Mar 20, 2016 4:18 pm

garyan2 wrote:Here are the values for the task priority...epg123 is currently 7. I'm going to change it to 6 to be a low normal priority as opposed to a below normal task.
I changed one a few days ago to priority 4 from the original 7. It really didn't seem to make much difference. However I no longer see times that are as long as first reported here for any of them either. What's odd is that 3 different machines each doing exactly the same update within a couple of hours of each other still take quite different times. In fact the most "powerful" computer (CPU/memory size-wise) takes ~18 minutes each day, over and over while the others are down in the 1-4 minutes range. As long as it's fairly predictable it's not a big deal in the long run. I just want to be able to coordinate the update finishing on the server with the MXF load on client machines eventually.

Post Reply