Progam slowing down - MouseDown: extended delay --- too many observe events???

Asked by Shekhar on 2017-12-02

Hi,

I am using sikuli for automating a game. The full code is pretty long but the part that moves / clicks mouse is as follows:-

class click_thread(threading.Thread):
    def __init__(self, reg_to_click):
        threading.Thread.__init__(self)
        self.reg_to_click = reg_to_click
    def run(self):
        click_lock.acquire()
        click_func(self.reg_to_click)
        click_lock.release()

def click_func(reg_to_click):
    while True:
        if auto_mouse == 'go':
            Settings.MoveMouseDelay = 0.1
            Settings.DelayBeforeMouseDown = 0.1
            Settings.ClickDelay = 0.1
            click(reg_to_click.getCenter())
            mouseMove(0,50)
            break
        else:
            print((time.asctime(time.localtime(time.time()))),"click func recd call - waiting 1s")
            wait(1)

click_lock = threading.Lock()

# auto_mouse is a global variable I use to 'pause' mouse actions if reqd by reassigning it from elsewhere

I am using threading to take care of mouse actions. Other functions in the code create a thread instance whenever they need the mouse to click something on the screen in the following way:-

            click_thread_instance = click_thread(reg_to_click)
            click_thread_instance.start()
            click_thread_instance.join()

The program slows down as it runs, resulting in a lot of 'timeouts' in the game i use it on. When i check logs, the most frequent entry seems to be 'MouseDown: extended delay'. I have tried running it both from IDE and the command line. It appears to make no difference to this problem. Any idea what might be causing this and what can be done to rectify it?

My env:-
OS:- Microsoft Windows 10 Home, 64-bit
Java:- Version 8, Update 151, build 1.8.0_151-b12
Sikuli: 1.1.1

Thanks in Advance.
Shekhar

Question information

Language:
English Edit question
Status:
Solved
For:
Sikuli Edit question
Assignee:
No assignee Edit question
Solved by:
RaiMan
Solved:
2018-01-05
Last query:
2018-01-05
Last reply:
2018-01-05
Shekhar (shekharpr10015) said : #1

I tried to carry out the clicks via a function instead of using multi threading to see if it makes any difference:-

 def click_func(reg_to_click):
  while True:
   if auto_mouse == 'go':
    Settings.MoveMouseDelay = 0.1
    Settings.DelayBeforeMouseDown = 0.1
    Settings.ClickDelay = 0.1
    click(reg_to_click.getCenter())
    mouseMove(0,50)
    break
   else:
    print((time.asctime(time.localtime(time.time()))),"click func recd call - waiting 1s")
    wait(1)

All other functions in the script now call this function to get any clicking done. I am still experiencing the script slowing down gradually. Below are the latest logs:-

[debug] MouseDown: extended delay: 1026
[debug] MouseDown: extended delay: 1176
[debug] MouseDown: extended delay: 1493
[debug] MouseDown: extended delay: 1584
[debug] MouseDown: extended delay: 1658
[debug] MouseDown: extended delay: 3077
[debug] MouseDown: extended delay: 3248
[debug] MouseDown: extended delay: 3394
[debug] MouseDown: extended delay: 5769
[debug] MouseUp: extended delay: 1083
[debug] MouseUp: extended delay: 1094
[debug] MouseUp: extended delay: 1159
[debug] MouseUp: extended delay: 1263
[debug] MouseUp: extended delay: 1394
[debug] MouseUp: extended delay: 2123

Any advise / suggestions would be much appreciated on how to solve this problem.

Thanks

RaiMan (raimund-hocke) said : #2

--- None of these settings make really sense:
            Settings.MoveMouseDelay = 0.1 # 0 would be the value, to switch of the mouse move animation
            Settings.DelayBeforeMouseDown = 0.1 # only relevant for dragDrop, no effect with click
            Settings.ClickDelay = 0.1 # time between down and up for click, standard is 0 which normally works.

--- click using a thread:
not needed with SikuliX 1.1.1+, since internally mouse actions are globally synchronized

--- extended delay
Internally SikuliX uses the Java AWT Robot class to handle mouse actions (Button up/down and move). All higher level mouse actions are composed based on these Robot features.
The error message comes up, when inside the Robot a feature like ButtonDown does not come back after a maximum delay (standard 1 second). This extended delay is not created by any SikuliX feature, but is completely in the layer between the Robot and the system mouse handling.

Since you are automating a game, it might well be, that the game engine is aware of the fact that the mouse actions are non-human and hence interferes the mouse handling with some delay, which seems probable looking at the continuous increase of the delay.

You might try, to implement your central click function using mouseDown() and mouseUp() with surrounding and intermediate short waits, that are randomly generated. This may help, to avoid being detected as a non-human.

I've got a similar problem with even bigger delays.
Java 8 too, but Mac OS X.
Not game, but the new iOS simulator came with XCode9.
Can't find any information apart from this thread.

RaiMan (raimund-hocke) said : #5

@Windows
might be related: bug 1730645

@Mac
might be related: bug 1739534

Shekhar (shekharpr10015) said : #6

Hi,

Regarding my issue, after a lot of trial and error, it turned out to be not because of the game client detecting the clicks as non human (because the problem kept occurring even when i tried to run the game on one computer and tried controlling it with another computer with this sikuli script remote accessing it).

The issue turned out to be because i had too many observer events registered which were consuming too much of system's resources. Knocking off a few observer events and reducing the Settings.ObserveScanRate solved my problem.

I figured this out by writing a simple script with only the clicking function (there were no mousedown / mouseup delays happening here) and kept adding one feature/function of my original script at a time to this until the mousedown / mouseup delays started happening.

@ https://launchpad.net/~podolyan-roman - Try this and see if it solves your problem too

Best RaiMan (raimund-hocke) said : #7

@Shekar
Thanks for feedback.

Yes too many observer events in parallel can slowdown, since the needed search actions internally are done one after the other in a row in the interval given by the observe scan rate.

But this is only true for the events registered with the same Region object: this is usually the case, if you register all events against the SCREEN object (using undotted onXXX...()).

each Region.observeInBackground is done in a seperate thread, so the observes for different region objects are done in parallel.

So with this trick you can run the events of one region in parallel, by registering the single events to a copy of the base region:
reg1 = someRegion
reg1.onAppear...
reg1.observeInBackground()
reg2 = Region(reg1) # a new Region object of the same region
reg2.onAppear...
reg2.observeInBackground()
...

Shekhar (shekharpr10015) said : #8

Thanks RaiMan, that solved my question.

Shekhar (shekharpr10015) said : #9

Thanks for the tip @RaiMan. I my script, all my observe events were for different regions (and explicitly defined regions at that, not SCREEN). So even though these were running as separate threads and being processed in parallel, they were still resulting in mouseup / mousedown delays. Perhaps its because of limitations of my computer? So, number of observer events & observe scan rate is a possible factor effecting mouseup / mousedown delays.

Anyways, sharing it so that my experience may help others. Thanks for your tip on creating duplicate regions to observe for different images in same region - i can already think of some uses of it in my automation :-)

RaiMan (raimund-hocke) said : #10

@Shekar
Thanks for feedback.

I think I have to go deeper into that, to find out, what might be the possible reasons for the fact, that multiple observes affect the SikuliX mouse behavior.

@RaiMan
> use this to start the IDE from a command line:
> java -jar /Applications/SikuliX.app/Contents/Java/sikulix.jar

Thanks a lot, seems working!

RaiMan (raimund-hocke) said : #12

@Roman
Thanks for confirming.
All the best.