"run" command takes at least .5 second and makes the macro unstoppable while it executes

Hi again,

I observed this even earlier but RL happened a couple of times I forgot to file this issue. But I digress.

This is originally a 2 (two) part issue, tested on 9.1.3:

  1. “run” commands always takes at least half a second to “execute”, regardless of !replayspeed.
  2. You cannot stop a macro while a “run” command is “executing”.
    This is made more pronounced if !replayspeed is set to something faster than MEDIUM (i.e., FAST and nodisplay) because you are more likely to press the button while it is “executing”
  3. [NEW] “nodisplay” controls disappears.
    Observed in 9.1.5. 9.1.3 does not exhibit this problem.

Is there anything we can do to work around this?

To demonstrate:
Please create 3 macros: “Main”, “A”, and “B”. Run Main.
Your primary objective is to stop the macro manually by clicking the “Stop” button.

Word of Caution: Once you try this, you will have difficulty in stopping the macro :smiling_imp:

B

{
  "Name": "B",
  "CreationDate": "2024-4-12",
  "Commands": []
}

A

{
  "Name": "A",
  "CreationDate": "2024-4-12",
  "Commands": [
    {
      "Command": "run",
      "Target": "B",
      "Value": "",
      "Description": ""
    }
  ]
}

Main

{
  "Name": "Main",
  "CreationDate": "2024-4-12",
  "Commands": [
    {
      "Command": "times",
      "Target": "37",
      "Value": "",
      "Description": ""
    },
    {
      "Command": "store",
      "Target": "nodisplay",
      "Value": "!REPLAYSPEED",
      "Description": ""
    },
    {
      "Command": "run",
      "Target": "A",
      "Value": "",
      "Description": ""
    },
    {
      "Command": "end",
      "Target": "",
      "Value": "",
      "Description": ""
    }
  ]
}

Regarding the .5 seconds I mentioned in the title, it is not a guess.

I checked logs from a Windows+Edge+9.1.3 and a Linux+Chrome+9.1.5 setups and it consistently shows a .5 seconds delay between the Executing: | run | and the next line. I used 7 instead of 37 to make testing quick.

[status] Playing macro Main
2024-04-12T16:26:10.443Z - [info] Executing:  | times | 7 |  | 
2024-04-12T16:26:10.470Z - [info] Executing:  | store | nodisplay | !REPLAYSPEED | 
2024-04-12T16:26:10.494Z - [info] Executing:  | run | A |  | 
2024-04-12T16:26:10.999Z - [status] Running 'A', called by 'Main'
2024-04-12T16:26:11.057Z - [status] Playing macro A
2024-04-12T16:26:11.067Z - [info] Executing:  | run | B |  | 
2024-04-12T16:26:11.571Z - [status] Running 'B', called by 'Main' > 'A'
2024-04-12T16:26:11.627Z - [status] Playing macro B
2024-04-12T16:26:11.638Z - [status] Finished running 'B', returning to 'Main' > 'A'
2024-04-12T16:26:11.693Z - [status] Playing macro A
2024-04-12T16:26:11.703Z - [status] Finished running 'A', returning to 'Main'
2024-04-12T16:26:11.757Z - [status] Playing macro Main
2024-04-12T16:26:11.767Z - [info] Executing:  | end |  |  |

Compare the timestamps between these two executions of the “run” command.

[status] Playing macro Main
2024-04-12T16:26:10.494Z - [info] Executing:  | run | A |  | 
2024-04-12T16:26:10.999Z - [status] Running 'A', called by 'Main'
...
2024-04-12T16:26:11.067Z - [info] Executing:  | run | B |  | 
2024-04-12T16:26:11.571Z - [status] Running 'B', called by 'Main' > 'A'

As a bonus, there also appears to be some kind of regularity with the delay between the [status] Running and the [status] Playing macro which is around 60 milliseconds or 0.06 seconds. I am not sure why those take as if there are 2 commands in between the run and the first command in the next macro but I guess it is what it is. Also, at this point, that 60 msec is almost inconsequential by comparison to the 500 msec which is almost ten-fold as slow.

With this issue, you can basically replace a "pause | 500 | " command with a simple run command to an empty macro. It would not be an accurate 500 msec but it guarantees that it will wait at least 500 msec and even prevents the user from manually stopping the macro while it “pauses”.

Hi,

I think this is a very interesting topic you are referencing here to. I noticed also that a “run” command takes always a half second to execute. So at times I am conflicted to use more run commands to modularize my scripts to keep them cleaner and easier to read or to have them faster by using using less run commands.

The thing is, even a half second sounds so little, it really can sum up in loops. If you have a loop that executes a “run” command 60 times, you have already the running a half minute of additional run time.

However as long as I can remember of all the previous version, the “run” command always delayed the execute of a script by 30 seconds. And I think it makes sense, because loading a new script context from the the hard drive into the browsers memory will take some time. So there is nothing that concerns me, It’s just finding a balance of when it is useful to use the “run” command and when not.

I agree on your points, especially on that tiny 0.5 seconds building up as you continue to call other macros. That is the reason why I noticed this behavior is because “run” commands took a huge chunk of my macro’s execution time that is not funny anymore.

The “makes the macro unstoppable” just followed through when I started investigating further. The third point just happens to be there when I crafted the test macro and Chrome just updated UIV to V9.1.5; I made a separate report on that.

I’ve reported this because the 0.5 seconds delay is so consistent in two machines with different operating systems, hardware, and has no xmodules installed that the only logical reasonable explaination left is that it must be artificial (i.e., setTimeout(...,500)).

However, even if it is being delayed 30 seconds on previous versions, 0.5 seconds is still way too much to spend on “loading a new script context from the the hard drive into the browsers memory” especially considering that newer machines are still getting faster and solid state drives are getting more use in the wide populace.

The purpose of my report is hopefully the UI.Vision developers could make it run as fast (or reasonably fast) as any other “normal” non-waiting commands like “store”.

For now, I restructured my macros so that they call ‘run’ less often which help recover most of that loss.

Thanks.

Hello, thanks to both of you for pointing out this issue. I confirmed it and we will look into it.

My test was two macro calling each other via RUN:

Thanks again for the useful test case => The 0.5s delay is fixed in V9.1.9