Announcement

Collapse
No announcement yet.

Logmsg "Script xxx is currently running..."

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

  • Logmsg "Script xxx is currently running..."

    I have a very small .vb script that optionally updates virtual max & min devices every time a temperature device changes. I have 10 devices, each one triggers the same script with different parameters. The trigger is on device changes, Some temps are accurate to a 0.1 so changes potentially could happen fairly often. Wait for script to finish and Allow only a single instance are both cleared. There are no global variables that would preclude concurrent execution. With these settings it should just create an instance with each temp change with no interference, but I frequently get the message "Script xxx.vb is currently running, waiting for it complete before its run again". It is only a notice, but it is cluttering up the log file. Any ideas why I'm getting this or is this a reportable bug?

  • #2
    So there are 10 events that run the same script?
    None of the events have a box checked to wait or run only one instance?
    I'm suspicious that HS thinks one of those boxes is checked on at least one of the events. Is there any way for you to tell if it is only some of the device changes that lead to the log entry or if they all do?
    Mike____________________________________________________________ __________________
    HS3 Pro Edition 3.0.0.548

    HW: Stargate | NX8e | CAV6.6 | Squeezebox | PCS | WGL 800RF, Rain8Net+ | RFXCOM | QSE100D | Vantage Pro | Green-Eye | X10: XTB-232, -IIR | Edgeport/8 | Way2Call | Ecobee3

    Comment


    • #3
      I thought the same thing - I checked each event and they all have both boxes cleared. I had already turned logging on each event to test the second part of your question, but all it did was prove the Observer Effect - the failure ceased to occur. I'm suspicious that HS3 isn't honoring the lack of the single instance flag but I want to see if anyone has a different thought.

      Comment


      • #4
        Originally posted by GPrade View Post
        I had already turned logging on each event to test the second part of your question, but all it did was prove the Observer Effect - the failure ceased to occur.
        So the error is intermittent? Or it just doesn't occur if you log the events? Maybe the extra time to log the event is preventing a collision of some sort. Have you tried adding a short "cannot rerun for..." to each event?
        Is there any chance the CPU of your HS system is a limiting factor?
        Mike____________________________________________________________ __________________
        HS3 Pro Edition 3.0.0.548

        HW: Stargate | NX8e | CAV6.6 | Squeezebox | PCS | WGL 800RF, Rain8Net+ | RFXCOM | QSE100D | Vantage Pro | Green-Eye | X10: XTB-232, -IIR | Edgeport/8 | Way2Call | Ecobee3

        Comment


        • #5
          The error is definitely intermittent - it occurs more frequently in the pm when temps are elevating rapidly. The error finally did occur once I turned the event logging flag on for the events - just not as frequently. I don't want to set the "cannot rerun for..." flag - the script is so small it should run quickly and it could occur in bursts and I don't want to miss an event. The script is essentially 3 device gets and possibly one put. The cpu shouldn't be a factor - its a dedicated gen 7 i5 quad core with 16GB and I rarely see the CPU in double digits; I don't see latency in any processing.

          Comment


          • #6
            When you see the 'already running' message and the event logging is on, is it associated with a specific device? There's always the possibility that one (or a few) of the events were not recorded correctly and "think" the single execution flag is on for the script. If a particular device is associated with the message, then rebuilding that event from scratch might be worth a try.

            There's also the possibility that It is an HS overhead issue in the event engine that is independent of processing power and script execution. I know that there is something that takes significant time in the event trigger subsystem because condition changes are very slow to be recognized relative to free running event triggers.
            Mike____________________________________________________________ __________________
            HS3 Pro Edition 3.0.0.548

            HW: Stargate | NX8e | CAV6.6 | Squeezebox | PCS | WGL 800RF, Rain8Net+ | RFXCOM | QSE100D | Vantage Pro | Green-Eye | X10: XTB-232, -IIR | Edgeport/8 | Way2Call | Ecobee3

            Comment


            • #7
              It's a small sample size (3) but it does appear that the attic temperature sensor is the primary suspect. I verified (again) the flags and they appear correct. However, the attic is probably also the most active since it really shoots up in the afternoon and it has a resolution of .1. I'll try deleting/adding that event.

              Your second paragraph is a bit concerning. I've been a HS user almost since the beginning and I view one of the major strengths of HS is the event driven nature based on changes to the environment as opposed to polling. Even worst case, I shouldn't be over taxing the event processing capabilities. That would be a concern given the small size of my system (~650 devices, ~150 events).

              Comment


              • #8
                I'm just speculating, so may be way off, but I'm wondering if there is a latency after a script is called before it can be called again. Normally, if it is run from only one event, the timing / sequencing algorithms accommodate it seamlessly, but if 10 events call the same script - all at high frequency, and for extended sequences, the algorithm gets overwhelmed. That's not fact or knowledge based, just a supposition based on my impression of HST's approach to stress testing their system.

                I still think a miss configured event is the more likely explanation, though.
                Mike____________________________________________________________ __________________
                HS3 Pro Edition 3.0.0.548

                HW: Stargate | NX8e | CAV6.6 | Squeezebox | PCS | WGL 800RF, Rain8Net+ | RFXCOM | QSE100D | Vantage Pro | Green-Eye | X10: XTB-232, -IIR | Edgeport/8 | Way2Call | Ecobee3

                Comment


                • #9
                  That’s not the perfect solution. But a workaround, if nothing works..would be to have multiple copies of the script. I mean, 1 copy per event.

                  Comment


                  • #10
                    Michael, I tried rebuilding the events from scratch instead of copying them and ensuring the Allow only one instance... flag was cleared. I also put some precise timestamps at the start and end to get a better idea of the issue. I think I better understand what's going on, so this is just to close out the issue.

                    The script is only 6 lines long with 3-4 HS API calls (3 device gets, 0 or 1 puts) and 2 log writes. From walking through the HS log, assuming log output is serialized, it's not the events that HS is complaining about, it is the script itself. I assumed that each event would create a new instance of the script, but apparently HS only appears to allow one copy of a script to run at any given instant. This would imply Matt's suggestion would solve the problem, but in reality just ignoring the warning also works without having to corrupt good programming practice.

                    Thanks all for the suggestions.

                    Comment


                    • #11
                      Thanks for the wrap-up. As you note, the warnings in the log appear to be just an irrelevant nuisance, but I'm still puzzled. I'm pretty sure there are documented cases where HS runs more than one copy of a script simultaneously. If, in fact, it is restricting execution to just one copy, then the option to prevent multiple copies running is misleading at best. It just seems to me there's more here. In any case I think input from HS Support would be instructive.

                      FWIW, Jon00 has a System Monitor application that will track, among other metrics, scripts running over time. It might be instructive to see what it reveals.
                      Mike____________________________________________________________ __________________
                      HS3 Pro Edition 3.0.0.548

                      HW: Stargate | NX8e | CAV6.6 | Squeezebox | PCS | WGL 800RF, Rain8Net+ | RFXCOM | QSE100D | Vantage Pro | Green-Eye | X10: XTB-232, -IIR | Edgeport/8 | Way2Call | Ecobee3

                      Comment


                      • #12
                        I not only don't think the messages are relevant; I do think they are confusing. First, I think you made the same assumption I initially did - the event flag limits one event invocation at a time; the message is saying only one script can run at a time. The implication is that HS loads my script once then single threads things through it. However, from the trace messages I print, it's obvious that multiple invocations of my script are in fact running at the same time, usually without the message being issued. I think this is one of those times we are all left scratching our heads about what HS is really doing internally.

                        I have several of Jon00's tools - I'll try this one because I am curious. But probably just end up befuddled....

                        Thanks again for the discussion.

                        Comment


                        • #13
                          I run multiple copies of the same script on a regular basis and never see that warning except for those instances where I have set to not allow that. You can see the currently running scripts by using the hs.ScriptsRunning command. I actually run that command once a second and write the output to a virtual device so that I can easily see what scripts are running. HS does have a limit as to how many total scripts can run at the same time (I believe it is 20) and I don't know if that's configurable.
                          HS 3.0.0.548: 1970 Devices 1149 Events
                          Z-Wave 3.0.1.262: 123 Nodes on one Z-Net

                          Comment

                          Working...
                          X