Event Execution Delay Measurement Script discussion

[Wadenut]

Pete, Try turning the graph itself on/off. Let me know if this works. I plan to incorporate Jon's suggestion into the posted version. It'll be optional as will the separate device be. I want to make this as versatile as possible, and useful to the non-scripters out there.

[Pete]

Greg,

Originally only removed the variable but left the DIM statement for the variable in the script.

Changed the graph from a "status" to a "virtual" device and turned it on. While doing this I noticed some extreme delays. Before this and since my last post I didn't see anything over 65 Ms.

Seeing the following in the logs:

9/10/2012 1:46:11 PM Event Running script in background: wunwebcamupload.vb
9/10/2012 1:46:11 PM Warning Events seem to be delayed. Last Event: WadeNut Test. Current delay: 11.703 seconds [Delta: 11.703]. Scripts running: wunwebcamupload.vb,Event Delay Check.vb
9/10/2012 1:48:39 PM Event Event Trigger "WeatherXML Check Alerts"
9/10/2012 1:48:39 PM Event Running script and waiting: weatheralerts.vb
9/10/2012 1:49:01 PM Device Control Device: Virtual - Performance Event Execution Delay (Y98) ON
9/10/2012 1:49:14 PM Warning Events seem to be delayed. Last Event: WadeNut Test. Current delay: 74.859 seconds [Delta: 74.859]. Scripts running: Event Delay Check.vb

Note that the delays in the log above didn't show up on the graph of the delays. Should I remove the Y98 execution delay variable dim statement in your script?

[Pete]

When I changed the graph to "off" I saw another delay.

9/10/2012 2:00:16 PM Warning Events seem to be delayed. Last Event: WadeNut Test. Current delay: 16.812 seconds [Delta: 16.812]. Scripts running: Event Delay Check.vb
9/10/2012 2:00:41 PM Device Control Device: Virtual - Performance Event Execution Delay (Y98) OFF
9/10/2012 2:00:57 PM Device Control Device: Virtual - Performance Event Execution Delay (Y98) ON
9/10/2012 2:00:59 PM Device Control Device: Virtual - Performance Event Execution Delay (Y98) OFF

After a couple of minutes I turned it on again. No delays in the logs this time.

[Wadenut]

No idea why turning a device on/off might cause an event delay.
I doubt a Dim statement being present for an unused variable will make any difference.
I have noticed a slightly longer delay initially after I modify the script. It's probably due to the fact HS is reading the file from the disk.

Now, coincidentally I hope, I've been seeing some sporadic 17 second delays this afternoon as well. Haven't nailed down a cause.
So far, I'm putting it down to running a rather CPU intensive task on my laptop (remote from HS) while IE is open to the Homeseer /Stat page which auto refreshes every five minutes.

[Pete]

I noticed that my every 10 minute delay is now gone. I am seeing log entries of delays and they are scattered which is what I was hoping to see such that I can pinpoint the causes. The warning log entry from your script is now showing me an event each time where as before it was not.

I turned it off twice; then turned it once and saw no delays this time after doing this.

9/10/2012 2:46:12 PM Event Running script in background: wunwebcamupload.vb
9/10/2012 2:46:13 PM Warning Events seem to be delayed. Last Event: WadeNut Test. Current delay: 12.843 seconds [Delta: 12.843]. Scripts running: wunwebcamupload.vb,Event Delay Check.vb 9/10/2012 2:59:39 PM Event Event Trigger "MCS Graphs Snapshot"
9/10/2012 2:59:39 PM Event Running script in background: mcs-graph.vb
9/10/2012 3:00:00 PM Event Event Trigger "Goes13IR Capture"
9/10/2012 3:00:00 PM Event Event Trigger "Time and Temp"
9/10/2012 3:00:00 PM Event Running script in background: Jon00HTML2Image.vben("Main","7")
9/10/2012 3:00:00 PM Event Running script and waiting: speaktimeandtemp-1.vbs
9/10/2012 3:00:16 PM Warning Events seem to be delayed. Last Event: WadeNut Test. Current delay: 16.593 seconds [Delta: 16.593]. Scripts running: mcs-graph.vb,Event Delay Check.vb
9/10/2012 3:03:04 PM Event Event Trigger "WUN WeatherCam Upload"
9/10/2012 3:03:04 PM Event Running script in background: wunwebcamupload.vb
9/10/2012 3:03:04 PM Event Event Trigger "WeatherXML Check Alerts"
9/10/2012 3:03:04 PM Event Running script and waiting: weatheralerts.vb
9/10/2012 3:03:04 PM Warning Events seem to be delayed. Last Event: WadeNut Test. Current delay: 64.359 seconds [Delta: 64.359]. Scripts running: wunwebcamupload.vb,Jon00RCCNM_A.vben,Event Delay Check.vb
9/10/2012 3:16:12 PM Event Event Trigger "WUN WeatherCam Upload"
9/10/2012 3:16:12 PM Event Running script in background: wunwebcamupload.vb
9/10/2012 3:16:13 PM Warning Events seem to be delayed. Last Event: WadeNut Test. Current delay: 13 seconds [Delta: 13]. Scripts running: Event Delay Check.vb,wunwebcamupload.vb

Noticed too this morning during/after events quit running one TS client with a message that it was using the wrong version of HSTouch server. That said that client was not connected this morning. I installed a second HSTouch client in the family room a couple of days ago to watch a bit.

[Wadenut]

Mine is still occurring... Every 12 minutes like clockwork. The only thing I do at 12 minute intervals is the Weather Underground upload. I chose 12 minutes to reduce coincidence with other activity. I'll try 11 (prime), but I doubt it's going to help this.

[Pete]

My only original guess relating to the every 10 minutes was the Cumulus plugin downloads from my web site. I am still using the not updated plugin (X2) and not seeing that now which doesn't make any sense to me. I have delays already set up for some of the Jon00HTML2Image.vben downloads; nothing more than 5-10 seconds though.

[Pete]

Most of the delays have been less than 20 seconds. I had one about two hours ago which was 42 seconds and that one isn't showing up on the graph. Max on the graph is one for 22 seconds.

[Wadenut]

Most of my timed events occur on the minute, I changed the WUN upload to 11 minutes 30 seconds and haven't had a delay since.
What this seems to show is that hs.GetURL hangs HS until it either receives a response, or times out.
I seem to remember having had the same type of problem with my Environment Canada Weather script originally, and I took steps to avoid problems. Must take another look at that when I have some time.

[Pete]

I never used seconds for the running of events. Will give it a try.

[Pete]

I configured the weather events using minutes/seconds around the last post time. Looking over the logs see only one delay of 18 seconds in the last hour.

Going to switch the event running to every minute to see what happens.

[Wadenut]

I have a new version of the delay script. I'll post it today once I've completed testing and updated the doc. (v1.08)
This will enable the option to present data in a device string as before, and as well (or instead) directly to a Jon00 Graph.
I thought this the best compromise as two sets of data can optionally be made available simultaneously (eg. short term and long term) as required tracked in separate graphs.

Jon: I had to write the delay value to the 'internal' graph DeviceValue in order for the Delta to be calculated properly when only the graph option is selected.

This version has a number of new options as well.

[jon00]

I'll wait in anticipation then! The virtual graphing update with session average (which you requested) is now available.

[Pete]

Two changes last night here: one was to utilize seconds on my reoccurring events (75% or so) and one to run "dah script" every 1 minute instead of every 2 minutes.

Noticed only 4 delays over 1 second from about midnight to 5 AM. One occurring during the backup time (0430c). It was about 11 seconds. Previous it was around 0200c for around same @ 11 seconds. HD capture/upload is 3-4 MP upload to web server.

9/11/2012 1:26:05 AM Event Event Trigger "WeatherCam2 North CaptureHD-Cumulus"
9/11/2012 1:26:05 AM Event Running script and waiting: Capture-Save-House NorthHD.vb
9/11/2012 1:26:05 AM Event Running script and waiting: WCamHDtoCCUpload.vb
9/11/2012 1:26:11 AM Warning Events seem to be delayed. Last Event: WadeNut Test. Current delay: 11.953 seconds [Delta: 11.953]. Scripts running: Event Delay Check.vb
9/11/2012 1:41:05 AM Event Event Trigger "WeatherCam2 North CaptureHD-Cumulus"
9/11/2012 1:41:05 AM Event Running script and waiting: Capture-Save-House NorthHD.vb
9/11/2012 1:41:05 AM Event Running script and waiting: WCamHDtoCCUpload.vb
9/11/2012 1:41:11 AM Warning Events seem to be delayed. Last Event: WadeNut Test. Current delay: 11.796 seconds [Delta: 11.796]. Scripts running: Event Delay Check.vb
9/11/2012 4:16:05 AM Event Event Trigger "WeatherCam2 North CaptureHD-Cumulus"
9/11/2012 4:16:05 AM Event Running script and waiting: Capture-Save-House NorthHD.vb
9/11/2012 4:16:05 AM Event Running script and waiting: WCamHDtoCCUpload.vb
9/11/2012 4:16:11 AM Event Event Trigger "Goes13IR Capture"
9/11/2012 4:16:11 AM Event Running script in background: Jon00HTML2Image.vben("Main","7")
9/11/2012 4:16:11 AM Event Event Trigger "WeatherXML Check Alerts"
9/11/2012 4:16:11 AM Event Running script and waiting: weatheralerts.vb
9/11/2012 4:16:11 AM Warning Events seem to be delayed. Last Event: WadeNut Test. Current delay: 11.921 seconds [Delta: 11.921]. Scripts running: Event Delay Check.vb
9/11/2012 4:31:05 AM Event Event Trigger "WeatherCam2 North CaptureHD-Cumulus"
9/11/2012 4:31:05 AM Event Running script and waiting: Capture-Save-House NorthHD.vb
9/11/2012 4:31:05 AM Event Running script and waiting: WCamHDtoCCUpload.vb
9/11/2012 4:31:11 AM Warning Events seem to be delayed. Last Event: WadeNut Test. Current delay: 11.656 seconds [Delta: 11.656]. Scripts running: Jon00RCCNM_A.vben,Event Delay Check.vb
9/11/2012 4:31:14 AM Event Event Trigger "Goes13IR Capture"
9/11/2012 4:31:14 AM Event Running script in background: Jon00HTML2Image.vben("Main","7")

[Wadenut]

I'll wait in anticipation then! The virtual graphing update with session average (which you requested) is now available.

I think you'll like this. The only thing I've decided not to do is create the Delay Measurement device. It wouldn't be difficult to do but would mean several lines of code which normally would only execute once. The script will exit with an error if the device does not exist.

Just have to re-write the doc now.

I'll get the vd update later. Thanks.
By "session average", do you mean the number of samples taken during the period defined by "DelayCount=" ?. That was sort of what I had in mind, although an overall session average is good too.