Announcement

Collapse
No announcement yet.

Event Execution Delay Measurement Script discussion

Collapse
X
 
  • Filter
  • Time
  • Show
Clear All
new posts

  • #76
    Yes the event is recurring every 2 minutes and the script para is "main","2".
    On the old PC with HS running now, it is usually .06 to .09 and sometimes up to 2.0 or so.
    I can't believe HS on this larger, faster, newer PC would be in the 53 range.
    It is so much faster in executing scripts, turning lights on/off, picking up motion detectors ect ect.
    That's the main reason I am switching over to this PC. Even the status page is lighting fast.

    Thanks,
    Tim

    ps ini file

    Code:
    [Configuration]
    TrackingDevice = S35
    GraphingDevice = 
    Jon00GraphNum  = 
    
    LogWrngThrshld = 0
    LogWrngSamples = 2
    SpkWrngThrshld = 10
    SpkWrngSamples = 5
    SpeakMessage   = Homeseer event execution is seriously delayed. Immediate intervention may be required.
    RunScptThrshld = 0
    RunScptSamples = 10
    ScriptToRun    = Event Delay Actions.vb
    RebootThrshold = 0
    RebootSamples  = 1
    UseTextInGraph = True
    IncludeDelta   = True
    IncludeMinMax  = True
    IncludeTOD     = True
    IncludeEvents  = True
    IncludeScripts = True
    
    [Data]
    LastRunTime =5/27/2013 9:32:53 AM
    LastDelay =53.046
    MinDelay  =21.265
    MaxDelay  =53.109
    MaxDelayTOD =5/27/2013 12:16 AM
    ExSamples =283

    from the old PC -
    Code:
    5/27/2013 9:34:15 AM ~!~EventDelay~!~Current delay: 0.283 seconds [Delta: -0.469 Min: 0 Max: 17.359 @ 5/18/2013 7:00 AM] Last Event: EventDelayMeasurment.  Scripts running: Event Delay Measurement.vb
    FB Page - https://www.facebook.com/pages/Capt-Tim/209398425902188

    HSTouch Layouts - https://www.facebook.com/media/set/?...5902188&type=3

    No, Im from Iowa. I only work in outer space. Captain Kirk

    Comment


    • #77
      Here is how it started out -

      Code:
      5/26/2013 11:05:05 PM ~!~Event~!~Running script in background: Event Delay Measurement.vb("Main","2")
      5/26/2013 11:05:05 PM ~!~Warning~!~Events delayed: Current delay: 43865.375 seconds [Delta: 43865.297 Min: 0.062 Max: 43865.375 @ 5/26/2013 11:05 PM] Last Event: EventDelayMsrmnt.  Scripts running: Event Delay Measurement.vb
      5/26/2013 11:05:22 PM ~!~Device Control~!~Device:  SystemInfo EventDelayTime (S35) ON
      5/26/2013 11:05:26 PM ~!~Device Control~!~Device:  SystemInfo EventDelayTime (S35) OFF
      5/26/2013 11:06:21 PM ~!~Event~!~Event Trigger "EventDelayMsrmnt"
      5/26/2013 11:06:21 PM ~!~Event~!~Running script in background: Event Delay Measurement.vb("Main","2")
      5/26/2013 11:07:05 PM ~!~Event~!~Event Trigger "EventDelayMsrmnt"
      5/26/2013 11:07:05 PM ~!~Event~!~Running script in background: Event Delay Measurement.vb("Main","2")
      5/26/2013 11:07:05 PM ~!~Warning~!~Events delayed: Current delay: 65.062 seconds [Delta: 103.125 Min: 0 Max: 43865.375 @ 5/26/2013 11:05 PM] Last Event: EventDelayMsrmnt.  Scripts running: Event Delay Measurement.vb
      5/26/2013 11:09:05 PM ~!~Event~!~Event Trigger "EventDelayMsrmnt"
      5/26/2013 11:09:05 PM ~!~Event~!~Running script in background: Event Delay Measurement.vb("Main","2")
      5/26/2013 11:09:05 PM ~!~Warning~!~Events delayed: Current delay: 65.062 seconds [Delta: 0 Min: 0 Max: 43865.375 @ 5/26/2013 11:05 PM] Last Event: EventDelayMsrmnt.  Scripts running: Event Delay Measurement.vb
      5/26/2013 11:09:57 PM ~!~Event~!~Event Trigger "WeatherWarnings"
      Thanks,
      Tim
      FB Page - https://www.facebook.com/pages/Capt-Tim/209398425902188

      HSTouch Layouts - https://www.facebook.com/media/set/?...5902188&type=3

      No, Im from Iowa. I only work in outer space. Captain Kirk

      Comment


      • #78
        Post your config file and a screen shot of your event schedule, trigger and action.

        From your log:
        I see the event sometimes running every minute, not every two. This will cause the calculation to be incorrect if you specify a different parameter in the event action. The parameter absolutely must match the trigger frequency.
        I see too the event is never being triggered on the minute (Seconds = 0). This is essential, otherwise you will get delays reported as it's exactly that time difference the script is measuring.


        And again, there's no reason not to run this on a one minute schedule at least until you've gotten things working properly.

        The speed of a machine has little to do with how Homeseer behaves.

        I was wrong about Priority and Allow one inscance to run. These should be unchecked. However, you do need to check "Reference to the Hour" under the trigger tab.
        I'm adding a debug routine to provide a little more information to the log in these cases. Should be ready shortly.
        Last edited by Wadenut; May 27th, 2013, 11:53 AM.
        Real courage is not securing your Wi-Fi network.

        Comment


        • #79
          I changed the event-trigger every 1 minute-referance to the hour-running the script with ("Main","1").

          Now I am getting 0.079 as a reading
          Much better!
          Thank you,
          Tim
          FB Page - https://www.facebook.com/pages/Capt-Tim/209398425902188

          HSTouch Layouts - https://www.facebook.com/media/set/?...5902188&type=3

          No, Im from Iowa. I only work in outer space. Captain Kirk

          Comment


          • #80
            Good.
            Nonetheless, 1.12.2 is identical in every way to 1.12.1 except it adds a completely optional parameter to the "Configuration" section of the INI. If present, and set to TRUE, "DEBUG" will produce a single informational log entry on each execution of the script.
            If you DO feel the need to upgrade from 1.12.1, don't replace your INI file. Just add the Debug parameter if you wish.

            Just for the record, I've been using the same copy as has been uploaded, since last August, without issues on two installations of HS. Any time a delay has been reported, it's been real.
            Real courage is not securing your Wi-Fi network.

            Comment


            • #81
              I would like to change what the device string shows.
              As it is, this is what it shows in the device string.

              Code:
              0.312 seconds [Delta: 0.156 Min: 0.059 Max: 35.422 @ 7/31/2013 2:11 PM]
              But this shows in the log

              Code:
              Current delay: 0.203 seconds [Delta: 0.094 Min: 0.059 Max: 35.422 @ 7/31/2013 2:11 PM] Last Event: UpdateWthrXmlCond.  Scripts running: Event Delay Measurement.vb
              I would like the device string to show what shows up in the log.
              It looks like this is the right section, but I am not 100% sure.

              Code:
              LogString = "Current delay: " & DVString 
                  If UseEvents Then LogString = LogString + " Last Event: " + LastEvent 
                  If UseScripts Then LogString = LogString + ".  Scripts running: " + RunningScripts 
                  If TrackDV <> "" Then
                      hs.SetDeviceString(TrackDV,"<font color=" & DVColor & ">" & DVString & "</font>")
                      hs.SetDeviceValue(TrackDV,CInt(DelayTime * 1000))
                  End If
              Thanks,
              Tim
              FB Page - https://www.facebook.com/pages/Capt-Tim/209398425902188

              HSTouch Layouts - https://www.facebook.com/media/set/?...5902188&type=3

              No, Im from Iowa. I only work in outer space. Captain Kirk

              Comment


              • #82
                Never mind, I got it.

                Tim
                FB Page - https://www.facebook.com/pages/Capt-Tim/209398425902188

                HSTouch Layouts - https://www.facebook.com/media/set/?...5902188&type=3

                No, Im from Iowa. I only work in outer space. Captain Kirk

                Comment


                • #83
                  HS3 version posted.
                  Real courage is not securing your Wi-Fi network.

                  Comment


                  • #84
                    Anyone seen this?
                    Just noticed it today.

                    Thanks,
                    Tim
                    Attached Files
                    FB Page - https://www.facebook.com/pages/Capt-Tim/209398425902188

                    HSTouch Layouts - https://www.facebook.com/media/set/?...5902188&type=3

                    No, Im from Iowa. I only work in outer space. Captain Kirk

                    Comment


                    • #85
                      Originally posted by fungun View Post
                      Anyone seen this?
                      Just noticed it today.

                      Thanks,
                      Tim
                      Looks like you've got some delay there. The list is a list of running scripts, which in this case means you have many copies running for some reason, and likely causing the delay in the first place.
                      In the event, you ought to have "allow only one to run" (not sure of the exact wording there; it's under advanced in the Action section). There's nothing in the script that would cause it to hang that I'm even remotely aware of... ie. no loops of any sort. It's actually quite linear.... In, measure, report, out.
                      Real courage is not securing your Wi-Fi network.

                      Comment


                      • #86
                        The delays vary, usually under 1 second. (I was tasking it for testing)
                        Once I noticed the repeating same script running, I watched it for over a hour.
                        The delays varied but not the "Scripts running' part of the device string.
                        I restarted HS and all is good now. It reports other events / scripts that are running instead of just itself running repeatedly.

                        Tim
                        FB Page - https://www.facebook.com/pages/Capt-Tim/209398425902188

                        HSTouch Layouts - https://www.facebook.com/media/set/?...5902188&type=3

                        No, Im from Iowa. I only work in outer space. Captain Kirk

                        Comment


                        • #87
                          Originally posted by fungun View Post
                          The delays vary, usually under 1 second. (I was tasking it for testing)
                          Once I noticed the repeating same script running, I watched it for over a hour.
                          The delays varied but not the "Scripts running' part of the device string.
                          I restarted HS and all is good now. It reports other events / scripts that are running instead of just itself running repeatedly.

                          Tim
                          As I recall, there's a setting in the INI which determines the threshold where reporting will start. Below that, it just runs quietly. Here, I normally see delays of about 60ms which would just be the time it takes for HS to trigger the event and start the script. The first thing it does is take a snap of the current time. After that, it reads the INI, does the math, sets the device string, reports and exits.
                          Real courage is not securing your Wi-Fi network.

                          Comment


                          • #88
                            Here is some logging before and after my restart.
                            I will also attach my ini file for you.

                            Thanks,
                            Tim

                            Code:
                            2/16/2015 3:31:00 PM ~!~EventDelay~!~Current delay: 0.064 seconds [Delta: 0 Min: 0.064 Max: 0.705 @ 2/16/2015 3:27 PM] Last Event: EventDelayMsrmnt.  Scripts running: Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb,Event Delay Measurement.vb
                            2/16/2015 3:31:09 PM ~!~Event~!~Event Trigger "MaxUptime"
                            
                            RESTART
                            
                            2/16/2015 3:57:02 PM ~!~EventDelay~!~Current delay: 1.314 seconds [Delta: 0.953 Min: 0.08 Max: 1.314 @ 2/16/2015 3:57 PM] Last Event: EventDelayMsrmnt.  Scripts running: Jon00RCCNM_Monitor.vben,Event Delay Measurement.vb
                            
                            2/16/2015 4:00:00 PM ~!~EventDelay~!~Current delay: 0.267 seconds [Delta: 0.109 Min: 0.08 Max: 1.314 @ 2/16/2015 3:57 PM] Last Event: EventDelayMsrmnt.  Scripts running: Event Delay Measurement.vb,2StockQuotesTicker.txt

                            Code:
                            [Configuration]
                            TrackingDevice = S35
                            GraphingDevice = 
                            Jon00GraphNum  = 
                            
                            LogWrngThrshld = 0
                            LogWrngSamples = 2
                            SpkWrngThrshld = 10
                            SpkWrngSamples = 5
                            SpeakMessage   = Homeseer event execution is seriously delayed. Immediate intervention may be required.
                            RunScptThrshld = 0
                            RunScptSamples = 10
                            ScriptToRun    = 
                            RebootThrshold = 0
                            RebootSamples  = 1
                            UseTextInGraph = True
                            IncludeDelta   = True
                            IncludeMinMax  = True
                            IncludeTOD     = True
                            IncludeEvents  = True
                            IncludeScripts = True
                            
                            [Data]
                            LastRunTime =2/16/2015 4:29:00 PM
                            LastDelay =0.095
                            MinDelay  =0.08
                            MaxDelay  =0.314
                            MaxDelayTOD =2/16/2015 4:21 PM
                            ExSamples =0
                            FB Page - https://www.facebook.com/pages/Capt-Tim/209398425902188

                            HSTouch Layouts - https://www.facebook.com/media/set/?...5902188&type=3

                            No, Im from Iowa. I only work in outer space. Captain Kirk

                            Comment


                            • #89
                              It didn't cause your problem but I'd change LogWrngThrshld to something more than 0. I don't remember whether or not a setting of 0 turns off the warning. although it probably should next time I do anything with the script. Somewhere between 0.5 and 1.5 wouldn't be unreasonable. The next setting is the number of samples outside this limit before you'll get a warning.
                              Real courage is not securing your Wi-Fi network.

                              Comment


                              • #90
                                It's almost like the device string wasn't getting updated, just added to it.

                                Thanks,
                                Tim
                                FB Page - https://www.facebook.com/pages/Capt-Tim/209398425902188

                                HSTouch Layouts - https://www.facebook.com/media/set/?...5902188&type=3

                                No, Im from Iowa. I only work in outer space. Captain Kirk

                                Comment

                                Working...
                                X