Script becomes way slower after a msgbox - (Moved)

[jchd]

@water good to know. You win your certificate of non-contamination.

[water]

My Windows machine is a company notebook. I fear OS update and contamination will happen quite soon

[argumentum]

; Win10 Ent. N 2016 LTSB - v. 1607
;~ _Sleep(1000)
;~ First loop is         0.68% faster after Sleep()
;~ Subsequent loops are  0.01% faster after Sleep()
;~ Complete run is       1.37% faster after Sleep()
;~ Total time running: 2148.59787 ms.

;~ Sleep(1000)
;~ First loop is         1.59% faster after Sleep()
;~ Subsequent loops are  0.01% faster after Sleep()
;~ Complete run is       0.92% faster after Sleep()
;~ Total time running: 2137.90848 ms.

 

[Jon]

My AutoIt Dev machine is 1809 and I get the issue. x10 slowdown for me. I need simple scripts for tests as ConsoleWrite/complex scripts, etc is no good when running through the debugger - too many libraries and stuff included, so this shows it.

;MsgBox(4096, "Comment me out", "")
Local $hTimer = TimerInit()
For $i = 1 to 5000000
Next
Local $fDiff = TimerDiff($hTimer)
MsgBox(4096, "Time Difference", $fDiff)

I've got a horrible feeling this is due to AutoIt not having a high dpi manifest as just showing a messagebox doesn't trigger any special code paths,  but that will be easy enough to remove to test. But I'm unable to change that from the release version as the GUI functions would be completely broken.

Complete tangent but I recently upgraded my work laptop to a Dell XPS 15 with i7 and 32GB ram. Windows 10 and Office is DOG slow. It's a joke how slow excel is. High DPI on windows is a catastrophe. I wish they'd implemented it like the mac does where the application doesn't need to do much, whereas on windows you have to recode the entire app.

But maybe it won't be that.... 

[Jon]

Ok I've not programmed for a while but this makes no sense. If I run AutoIt3.exe directly then the script runs the same speed with/without a MsgBox. If I run it through scite then there is a massive speed difference. Doubly weird. The fast version in scite is way faster than the standalone versions. How...why...wut?

[Jon]

It's something to do with the /ErrorStdOut line that scite uses but isn't used normally. It's making the script run much faster. So rather than this being an issue with the script slowing down it's actually the script running at "normal" speed and for some reason in the past /ErrorStdOut was making it very fast. But since 1809 that difference is removed, but only if the GUI is triggered. How bizarre.

Edit: Ignore that. It's just that running AutoIt3.exe standalone and seeing the "Load Script" dialog triggered the behaviour is what confused me in the debugger.

[Exit]

Local $msg, $Timer
For $j = 1 To 2
    $Timer = TimerInit()
    For $i = 1 To 5000000
    Next
    $Timer = TimerDiff($Timer)
    $msg &= $Timer & @LF
    MsgBox(0, "", $msg, 2-$j)
Next

 

[Musashi]

As far as possible, we have discussed this problem in the German forum as well.
I have no idea if this may help, but the renowned (and obviously tenacious ) user named Chesstiger wrote a contribution that might be interesting : https://autoit.de/thread/86867-msgbox-verlangsamt-den-skriptablauf-unter-win-10/?postID=699054#post699054

Unfortunately the text is in German, but it should be no problem to translate it using Google or even better https://www.deepl.com/translator

The User Mars has reported, that even a script compiled years ago suffers from this problem.

Of course, these are only circumstantial evidence, but who knows, maybe someone will find a useful clue there.

EDIT : Chesstiger told me that he has an account here under the same name, i.e. @chesstiger . I just want to mention this so that the right person is appreciated for their work .

Edited April 29, 2020 by Musashi

[Jon]

I've narrowed this down to the Win32 PeekMessage function. This is called every script line to check for user quit / gui messages. The function runs fine until ANY GUI element is made visible. As soon as that happens PeekMessage takes 10 times longer to return. It's almost certainly a bug/design change in Windows 1809+.

Edit: I just did a google translate on that German thread and PeekMessage mentioned there too.

[jchd]

If I understand you correctly this primitive is closely related to the message pump.  Strange that PeekMessage is recommended to speed up msg intercept for demanding games!

EDIT: do you experience an avalanche of messages to examine by PeekMessage  in v1809+ vs. only few with earlier versions of the OS?

Edited April 27, 2020 by jchd

[Jon]

Seems just to be taking longer per call rather than more messages. I changed the code to not even try and process the messages and just check a single message per script line (the minimum it will ever be) and it was just as slow.  I even disabled dispatching the messages with no difference. 
I think the only solution would be to completely change the message loop so it runs on it’s own thread which will be painful. I’m not sure why I didn’t do it that way from the start as I do that in c# all the time. Probably noob. 

[Nine]

@Jon  I wanna thank you for being here and update us.  This thread is like watching a "Mission Impossible",  It is hardly possible to solve this issue, but in the end, it will be a brilliant success.  

[jchd]

Don't feel guilty about the changes MS introduced midterm in W10, some 15+ years after your original decision back around 2003 (it was circa XP SP1 at this time)
I whish you get the ability to bissect now thru future releases of Windows 2025, that would get you a huge pile of money.

 

BTW did you test the strange slowdown on the first run of a loop after a Sleep()?
Post is here and fix 2 posts below:
https://www.autoitscript.com/forum/topic/202270-script-becomes-way-slower-after-a-msgbox-moved/?do=findComment&comment=1452672

Most probably no relationship with the GUIs thing but still strange.

 

[Musashi]

11 minutes ago, Nine said:

@Jon : I wanna thank you for being here and update us.  This thread is like watching a "Mission Impossible",  It is hardly possible to solve this issue, but in the end, it will be a brilliant success.  

@Jon : I gladly agree with this statement, and would also like to express my thanks (not only by clicking the LIKE button). There are too many people anyway who complain about what is missing instead of being happy about what is there.

[Jon]

Can I get some tests done on this for anyone who want to help?

https://www.autoitscript.com/autoit3/files/beta/autoit/win10slow/

The problem is that win32 PeekMessage becomes crazy slow after any gui element is shown after Win10 1809. Depending how a program is written this will be affecting lots of other software... Looks like a proper bug to me but no doubt it will be around for years.

The proper fix is a ground-up rewrite scenario where the message pump and UI is on one thread, and the script code runs on another. I had a look a retrofitting this into AutoIt but it would likely break lots of GUI scripts so although I may tinker in the background I don't think its feasible. The CreateWindowEx/SetWindowLongPtr functions (amongst others) and PeekMessage/message pump have to run on the same thread so it's complicated as for lots of user code where GUIs are created you've have to get one thread to create windows in another thread. A lot of DllCall type code (winapi library) would likely blow up.

As a filthy dirty hack what I'm trying to to throttle calls to PeekMessage. In AutoIt we check for new message each "cycle" which is in between each script line and during Sleep/WinWait type functions. If you throttle this to every ~64 calls then the slow down becomes small.

I tried using GetQueueStatus instead of this nasty throttle hack to check if there is a message waiting prior to calling PeekMessage but GetQueueStatus was even slower (what's the point??). GetInputState (checks for input related messages waiting) seems quick so I've used that. 

In the test exes above I have throttled it super hard to help with bug finding AutoIt functions that are hit by the throttling, so the current code only runs PeekMessage in the following cases:

• GetInputState indicates user input (user is moving mouse and interacting with a GUI)
• Throttle count is 2048 (to help bug finding, will trim this back if this workaround is viable)
• GuiSetState has just been executed
• GuiGetMsg has just been executed

 

 

[UEZ]

I get following result on Win10 x64 1903 using this code:

AutoItSetOption('GUIOnEventMode', 1)
$start = TimerInit()
$x = 0
For $i = 1 To 5000000
    $x += 1
Next
ConsoleWrite('@@ Debug(' & @ScriptLineNumber & ') : TimerDiff($start) = ' & TimerDiff($start) & @CRLF) ;### Debug Console
ConsoleWrite(@AutoItVersion & @CRLF)

W/o AutoItSetOption:

@@ Debug(7) : TimerDiff($start) = 799.4219
3.3.14.5

W/ AutoItSetOption:

@@ Debug(7) : TimerDiff($start) = 2190.8238
3.3.14.5

 

W/o AutoItSetOption:

@@ Debug(7) : TimerDiff($start) = 713.472
3.3.15.1

W/ AutoItSetOption:

@@ Debug(7) : TimerDiff($start) = 2208.2213
3.3.15.1

 

Problem still exists.

[Nine]

Running this code :

#include <Constants.au3>

$start = TimerInit()
$x = 0
For $i = 1 To 5000000
    $x += 1
Next
ConsoleWrite('@@ Debug(' & @ScriptLineNumber & ') : TimerDiff($start) = ' & TimerDiff($start) & @CRLF)
MsgBox ($MB_SYSTEMMODAL,"","Test")

$start = TimerInit()
$x = 0
For $i = 1 To 5000000
    $x += 1
Next
ConsoleWrite('@@ Debug(' & @ScriptLineNumber & ') : TimerDiff($start) = ' & TimerDiff($start) & @CRLF)

Working perfectly !  Congrats @Jon.  Same speed before and after msgbox.

I'll make further test...

[jchd]

@Jon works like a charm:

Before setting AutoIt hidden window to @SW_SHOW
@@ Debug(167) : TimerDiff($start) = 243.218  GUIOnEventMode = 1
@@ Debug(172) : TimerDiff($start) = 228.974  GUIOnEventMode = 1
@@ Debug(177) : TimerDiff($start) = 233.470  GUIOnEventMode = 1
@@ Debug(167) : TimerDiff($start) = 79.8592  GUIOnEventMode = 0
@@ Debug(172) : TimerDiff($start) = 78.5932  GUIOnEventMode = 0
@@ Debug(177) : TimerDiff($start) = 79.9705  GUIOnEventMode = 0

After setting AutoIt hidden window to @SW_SHOW
@@ Debug(191) : TimerDiff($start) = 281.677  GUIOnEventMode = 1
@@ Debug(196) : TimerDiff($start) = 239.198  GUIOnEventMode = 1
@@ Debug(201) : TimerDiff($start) = 232.640  GUIOnEventMode = 1
@@ Debug(191) : TimerDiff($start) = 78.1924  GUIOnEventMode = 0
@@ Debug(196) : TimerDiff($start) = 84.5815  GUIOnEventMode = 0
@@ Debug(201) : TimerDiff($start) = 77.9786  GUIOnEventMode = 0

 

[jchd]

Strangely if AutoItSetOption is reversed (testing 1 before 0) the first loop is slightly slower, but it's almost nothing.

Before setting AutoIt hidden window to @SW_SHOW
@@ Debug(168) : TimerDiff($start) = 78.6547  GUIOnEventMode = 0
@@ Debug(173) : TimerDiff($start) = 76.8702  GUIOnEventMode = 0
@@ Debug(178) : TimerDiff($start) = 77.1078  GUIOnEventMode = 0
@@ Debug(168) : TimerDiff($start) = 233.426  GUIOnEventMode = 1
@@ Debug(173) : TimerDiff($start) = 229.788  GUIOnEventMode = 1
@@ Debug(178) : TimerDiff($start) = 222.427  GUIOnEventMode = 1

After setting AutoIt hidden window to @SW_SHOW
@@ Debug(193) : TimerDiff($start) = 116.367  GUIOnEventMode = 0  <==
@@ Debug(198) : TimerDiff($start) = 79.4645  GUIOnEventMode = 0
@@ Debug(203) : TimerDiff($start) = 80.9340  GUIOnEventMode = 0
@@ Debug(193) : TimerDiff($start) = 224.905  GUIOnEventMode = 1
@@ Debug(198) : TimerDiff($start) = 224.905  GUIOnEventMode = 1
@@ Debug(203) : TimerDiff($start) = 221.863  GUIOnEventMode = 1

Code used for testing:

expandcollapse popup

ConsoleWrite("Before setting AutoIt hidden window to @SW_SHOW" & @LF)
;~ For $n = 1 To 0 Step -1
For $n = 0 To 1
    AutoItSetOption('GUIOnEventMode', $n)
    $x = 0
    $start = TimerInit()
    For $i = 1 To 500000
        $x += 1
    Next
    ConsoleWrite('@@ Debug(' & @ScriptLineNumber & ') : TimerDiff($start) = ' & TimerDiff($start) & @TAB & ' GUIOnEventMode = ' & $n & @CRLF) ;### Debug Console
    $start = TimerInit()
    For $i = 1 To 500000
        $x += 1
    Next
    ConsoleWrite('@@ Debug(' & @ScriptLineNumber & ') : TimerDiff($start) = ' & TimerDiff($start) & @TAB & ' GUIOnEventMode = ' & $n & @CRLF) ;### Debug Console
    $start = TimerInit()
    For $i = 1 To 500000
        $x += 1
    Next
    ConsoleWrite('@@ Debug(' & @ScriptLineNumber & ') : TimerDiff($start) = ' & TimerDiff($start) & @TAB & ' GUIOnEventMode = ' & $n & @CRLF) ;### Debug Console
Next

; Show the AutoIt3 hidden window
WinSetState(AutoItWinGetTitle(), "", @SW_SHOW)

ConsoleWrite(@LF & "After setting AutoIt hidden window to @SW_SHOW" & @LF)
;~ For $n = 1 To 0 Step -1
For $n = 0 To 1
    AutoItSetOption('GUIOnEventMode', $n)
    $x = 0
    $start = TimerInit()
    For $i = 1 To 500000
        $x += 1
    Next
    ConsoleWrite('@@ Debug(' & @ScriptLineNumber & ') : TimerDiff($start) = ' & TimerDiff($start) & @TAB & ' GUIOnEventMode = ' & $n & @CRLF) ;### Debug Console
    $start = TimerInit()
    For $i = 1 To 500000
        $x += 1
    Next
    ConsoleWrite('@@ Debug(' & @ScriptLineNumber & ') : TimerDiff($start) = ' & TimerDiff($start) & @TAB & ' GUIOnEventMode = ' & $n & @CRLF) ;### Debug Console
    $start = TimerInit()
    For $i = 1 To 500000
        $x += 1
    Next
    ConsoleWrite('@@ Debug(' & @ScriptLineNumber & ') : TimerDiff($start) = ' & TimerDiff($start) & @TAB & ' GUIOnEventMode = ' & $n & @CRLF) ;### Debug Console
Next

 

Edited May 1, 2020 by jchd

[Nine]

#Region ;**** Directives created by AutoIt3Wrapper_GUI ****
#AutoIt3Wrapper_UseX64=y
#EndRegion ;**** Directives created by AutoIt3Wrapper_GUI ****
#include <Constants.au3>

$start = TimerInit()
$x = 0
For $i = 1 To 5000000
    $x += 1
Next
ConsoleWrite('@@ Debug(' & @ScriptLineNumber & ') : TimerDiff($start) = ' & TimerDiff($start) & @CRLF)

AutoItSetOption('GUIOnEventMode', 1)
GUICreate ("Test")
GUISetState ()
Sleep (1000)

$start = TimerInit()
$x = 0
For $i = 1 To 5000000
    $x += 1
Next
ConsoleWrite('@@ Debug(' & @ScriptLineNumber & ') : TimerDiff($start) = ' & TimerDiff($start) & @CRLF)

x64 :

@@ Debug(11) : TimerDiff($start) = 622.2217
@@ Debug(23) : TimerDiff($start) = 1841.9612

x86 :

@@ Debug(11) : TimerDiff($start) = 673.3123
@@ Debug(23) : TimerDiff($start) = 2004.7148
 

With eventmode set to 0, same speed.