sikuli-driver team mailing list archive

Thread
Date
Re: [Question #230237]: [1.0 ]Sometimes "wait" hangs in sikuli 1.0

To: sikuli-driver@xxxxxxxxxxxxxxxxxxx
From: "Assi.NET" <question230237@xxxxxxxxxxxxxxxxxxxxx>
Date: Wed, 25 Nov 2020 18:01:10 -0000
Reply-to: question230237@xxxxxxxxxxxxxxxxxxxxx
Sender: bounces@xxxxxxxxxxxxx
Question #230237 on Sikuli changed:
https://answers.launchpad.net/sikuli/+question/230237

Assi.NET posted a new comment:
Hi, Raiman,

Fortunately, TestMechanic helped me to find out this post and also try
to help me with my issue.

Unfortunately, 7 years later I hit a similar problem with version 2.0.4. I have never experienced such an issue with 1.1.3 version for years. I do a few days of experiments, described below
I have a test set where I run it simultaneously on 1.1.3 and 2.0.4 via Jenkins (so 2 different jobs, the same code base, windows 10 machines, the same Java Version 11 LTS  - just different Sikuli versions)

After 200 builds I don't have any hangs with 1.1.3, but about 20% hangs
with 2.0.4.

I'm using unittest and HTMLTestRunner

################################
################################
Few hangs appear here:

        click(Sport_UI.position_Statistics_Right_Result_1)
        sleep(1)
        all_remove_bet_buttons = list(findAll(Sport_UI.betslip_button_RemoveItem))
        assert len(all_remove_bet_buttons) == 2

################################
################################
Another Here - this is from output:
03:06:01 [log] CLICK on L[1737,99]@S(0) (609 msec)
03:06:01 [log] ( Ctrl )  TYPE "a"
03:06:03 [log] ( Ctrl )  TYPE "c"
03:06:04 [log] CLICK on L[1737,99]@S(0) (43 msec)
03:13:40 Build timed out (after 12 minutes). Marking the build as aborted.


################################
################################
Here is a few hangs with "-d 3" option of the Sikuli:
18:16:11 [debug] Region: wait: icon_User.png appeared (M[1871,81 33x37]@S(0) S:1.00 T:1737,99 [373 msec])
18:16:11 [debug] CLICK on L[1737,99]@S(0) (569 msec)
18:16:11 [debug] ( Ctrl )  TYPE "a"
18:16:11 [debug] Region: ( Ctrl )  TYPE "a"
18:16:13 [debug] ( Ctrl )  TYPE "c"
18:16:13 [debug] Region: ( Ctrl )  TYPE "c"
18:16:14 [debug] Region: wait: waiting 3.0 secs for icon_User.png to appear in R[0,0 1920x1080]@S(0)
18:16:14 [debug] Finder2: makeMat: INT_RGB (33x37)
18:16:14 [debug] Finder2: makeMat: 3BYTE_BGR (33x37)
18:16:14 [debug] Finder2: doFindImage: start (stdDev: 211.3592 mean: 440.961507)
18:16:14 [debug] Finder2: doFindImage: in original: %-27.0082 (?99) 0 msec 
18:16:14 [debug] Finder2: doFindImage: end 0 msec
18:16:14 [debug] Region: checkLastSeen: not there
18:16:14 [debug] Finder2: makeMat: INT_RGB (1920x1080)
18:16:14 [debug] Finder2: makeMat: 3BYTE_BGR (33x37)
18:16:14 [debug] Finder2: doFindImage: start (stdDev: 211.3592 mean: 440.961507)
18:16:14 [debug] Finder2: doFindImage: in original: %99.9987 (?70) 295 msec 
18:16:14 [debug] Finder2: doFindImage: end 295 msec
18:16:14 [debug] Region: wait: icon_User.png appeared (M[1871,81 33x37]@S(0) S:1.00 T:1737,99 [382 msec])
18:16:14 [debug] CLICK on L[1737,99]@S(0) (32 msec)
18:24:14 Build timed out (after 12 minutes). Marking the build as aborted.
18:24:14 New run name is '#147-sport_bet_tests-UAT-win10x64-2'
18:24:14 Build was aborted
18:24:14 [htmlpublisher] Archiving HTML reports...
18:24:14 [htmlpublisher] Archiving at BUILD level c:\ui-tests\results\jenkins to C:\_J\jobs\Sikuli_204\builds\147\htmlreports\HTMLReport
18:24:14 ^CTraceback (most recent call last):
18:24:14   File "runner.py", line 210, in <module>
18:24:14     os.system(command)
18:24:14 KeyboardInterrupt
18:24:14 [717566 debug] RunTime:***** final cleanup at System.exit() *****
18:24:14 Terminate batch job (Y/N)? 
18:24:14 The batch file cannot be found.
18:24:14 [717646 debug] FileManager: deleteFileOrFolder:
18:24:14 C:\Users\egttest\AppData\Local\Temp\Sikulix_1459735496
18:24:16 Recording test results
18:24:16 [Checks API] No suitable checks publisher found.
18:24:16 Finished: ABORTED


################################
################################
16:20:36 [debug] Region: wait: button_Statistics.png appeared (M[874,371 28x27]@S(0) S:1.00 C:888,384 [407 msec])
16:20:36 [debug] Region: wait: waiting 3.0 secs for button_Statistics.png to appear in R[0,0 1920x1080]@S(0)
16:20:36 [debug] Finder2: makeMat: INT_RGB (28x27)
16:20:36 [debug] Finder2: makeMat: 3BYTE_BGR (28x27)
16:20:36 [debug] Finder2: doFindImage: start (stdDev: 126.5751 mean: 271.599206)
16:20:36 [debug] Finder2: doFindImage: in original: %7.4645 (?99) 1 msec 
16:20:36 [debug] Finder2: doFindImage: end 1 msec
16:20:36 [debug] Region: checkLastSeen: not there
16:20:36 [debug] Finder2: makeMat: INT_RGB (1920x1080)
16:20:36 [debug] Finder2: makeMat: 3BYTE_BGR (28x27)
16:20:36 [debug] Finder2: doFindImage: start (stdDev: 126.5751 mean: 271.599206)
16:20:36 [debug] Finder2: doFindImage: in original: %99.9994 (?70) 282 msec 
16:20:36 [debug] Finder2: doFindImage: end 282 msec
16:20:36 [debug] Region: wait: button_Statistics.png appeared (M[874,371 28x27]@S(0) S:1.00 T:1068,384 [397 msec])
16:20:37 [debug] CLICK on L[1068,384]@S(0) (532 msec)
16:20:38 [debug] Region: findAll: waiting 3.0 secs for (multiple) betslip_button_RemoveItem.png to appear in R[0,0 1920x1080]@S(0)
16:20:38 [debug] Finder2: makeMat: INT_RGB (1920x1080)
16:20:38 [debug] Finder2: makeMat: 3BYTE_BGR (29x22)
16:20:38 [debug] Finder2: doFindImage: start (stdDev: 91.0381 mean: 640.631661)
16:20:38 [debug] Finder2: doFindImage: in original: %99.9724 (?85) 297 msec 
16:20:38 [debug] Finder2: doFindImage: end 297 msec
16:20:38 [debug] Region: findAll: betslip_button_RemoveItem.png has appeared
16:20:38 PASS: test_520_SPORT_Add_Both_Teams_Score (__main__.SportBetTests)
16:20:38 
16:20:38 TEST STARTED: test_550_SPORT_Place_Bet_Combined (__main__.SportBetTests)
16:27:58 Build timed out (after 12 minutes). Marking the build as aborted.
16:27:58 New run name is '#133-sport_bet_tests-UAT-win10x64-2'
16:27:59 Build was aborted
16:27:59 [htmlpublisher] Archiving HTML reports...
16:27:59 [htmlpublisher] Archiving at BUILD level c:\ui-tests\results\jenkins to C:\_J\jobs\Sikuli_204\builds\133\htmlreports\HTMLReport
16:27:59 ^CTraceback (most recent call last):
16:27:59   File "runner.py", line 210, in <module>
16:27:59     os.system(command)
16:27:59 KeyboardInterrupt
16:27:59 [717533 debug] RunTime:***** final cleanup at System.exit() *****
16:27:59 Terminate batch job (Y/N)? 
16:27:59 The batch file cannot be found.
16:27:59 [717622 debug] FileManager: deleteFileOrFolder:
16:27:59 C:\Users\egttest\AppData\Local\Temp\Sikulix_1734820930
16:27:59 [debug] RunTime:***** final cleanup at System.exit() *****
16:27:59 [debug] HotkeyManager: reset: removed all SikuliX hotkeys.
16:27:59 [debug] HotkeyController: stopping hotkey provider
16:28:00 [debug] FileManager: deleteFileOrFolder:
16:28:00 C:\Users\egttest\AppData\Local\Temp\Sikulix_2096708501
16:28:00 Recording test results
16:28:00 [Checks API] No suitable checks publisher found.
16:28:00 Finished: ABORTED

#####################################
#####################################
Here is how the execution starts
#####################################
14:59:44 java -jar c:\ui-tests\sikuli\sikulix-2.0.4.jar -r c:\ui-tests\tests\sport_bet_tests.sikuli -v -d 3
14:59:44 'fake' is not recognized as an internal or external command,
14:59:44 operable program or batch file.
14:59:44 [DEBUG]startUp: IDE: Running: C:\ui-tests\sikuli\sikulix-2.0.4.jar
14:59:44 [DEBUG]startUp: IDE: AppData: C:\Users\egttest\AppData\Roaming\Sikulix
14:59:44 [DEBUG]startUp: IDE: starting with classpath: c:\ui-tests\sikuli\sikulix-2.0.4.jar ...
14:59:44 [DEBUG]startUp: IDE: no extensions.txt nor valid content
14:59:44 [DEBUG]startUp: IDE: adding extension file: C:\Users\egttest\AppData\Roaming\Sikulix\Extensions\jython-standalone-2.7.1.jar
14:59:44 [258 debug] RunTime:temp folder ok: C:\Users\egttest\AppData\Local\Temp\Sikulix_202313442
14:59:44 Options: *** options dump
14:59:44 Options: testing = 
14:59:44 Options: OptionsFile = C:\Users\egttest\AppData\Roaming\Sikulix\SikulixStore\SikulixOptions.txt
14:59:44 Options: *** options dump end
14:59:44 ***** show environment for 2.0.4-2020-03-14_08:01 API
14:59:44 user.home: C:\Users\egttest
14:59:44 user.dir (work dir): c:\ui-tests
14:59:44 user.name: egttest
14:59:44 java.io.tmpdir: C:\Users\egttest\AppData\Local\Temp
14:59:44 running 64Bit(amd64) on w (10.0) from a jar
14:59:44 java 11 version 11 vm 11.0.8+10-LTS class 55.0 arch 64
14:59:44 app data folder: C:\Users\egttest\AppData\Roaming\Sikulix
14:59:44 executing jar: C:\ui-tests\sikuli\sikulix-2.0.4.jar
14:59:44 *** classpath dump sikulix
14:59:44   0: c:\ui-tests\sikuli\sikulix-2.0.4.jar
14:59:44 *** classpath dump end
14:59:44 ***** show environment end
14:59:44 [DEBUG]startUp: IDE: *********************** leaving start
14:59:45 [51 debug] Sikulix: starting IDE
14:59:45 [75 debug] RunTime:temp folder ok: C:\Users\egttest\AppData\Local\Temp\Sikulix_557388382
14:59:45 Options: *** options dump
14:59:45 Options: testing = 
14:59:45 Options: OptionsFile = C:\Users\egttest\AppData\Roaming\Sikulix\SikulixStore\SikulixOptions.txt
14:59:45 Options: *** options dump end
14:59:45 ***** show environment for 2.0.4-2020-03-14_08:01 API
14:59:45 user.home: C:\Users\egttest
14:59:45 user.dir (work dir): c:\ui-tests
14:59:45 user.name: egttest
14:59:45 java.io.tmpdir: C:\Users\egttest\AppData\Local\Temp
14:59:45 running 64Bit(amd64) on w (10.0) from a jar
14:59:45 java 11 version 11 vm 11.0.8+10-LTS class 55.0 arch 64
14:59:45 app data folder: C:\Users\egttest\AppData\Roaming\Sikulix
14:59:45 executing jar: C:\ui-tests\sikuli\sikulix-2.0.4.jar
14:59:45 *** classpath dump sikulix
14:59:45   0: C:\ui-tests\sikuli\sikulix-2.0.4.jar
14:59:45   1: C:\Users\egttest\AppData\Roaming\Sikulix\Extensions\jython-standalone-2.7.1.jar
14:59:45   2: c:\ui-tests\sikuli\sikulix-2.0.4.jar
14:59:45 *** classpath dump end
14:59:45 ***** show environment end
14:59:46 [960 debug] Runner: added: NetworkRunner [] NET
14:59:46 [960 debug] Runner: added: Sikulix [] directory/sikulix
14:59:46 [961 debug] Runner: added: PowerShell [ps1] text/powershell
14:59:46 [971 debug] Runner: added: Jython [py] text/jython
14:59:46 [972 debug] Runner: added: Text [txt] text/text
14:59:46 [1313 debug] Runner: added: JavaScript [js] text/javascript
14:59:46 [1316 debug] Runner: init: class org.sikuli.script.runners.AbstractLocalFileScriptRunner: warning: not possible
14:59:46 [1317 debug] Runner: added: PackedSikulix [zip] application/zip
14:59:46 [1317 debug] Runner: added: SikulixJar [jar] text/jar
14:59:46 [1318 debug] Runner: added: PackedSikulix [skl] text/skl
14:59:46 [1330 debug] HotkeyManager: add Abort Hotkey: ALT+SHIFT C (67, 9)
14:59:46 [1445 debug] Runner: runscript: running script: c:\ui-tests\tests\sport_bet_tests.sikuli\sport_bet_tests.py
14:59:46 [1447 debug] JythonRunner: starting initialization
14:59:46 [1450 debug] RunTime:resourceLocation: (class org.sikuli.script.support.RunTime) /Lib/sikuli
14:59:46 [1450 debug] RunTime:resourceList: having jar: jar:file:/C:/ui-tests/sikuli/sikulix-2.0.4.jar!/Lib/sikuli
14:59:47 [2895 debug] RunTime:files exported: 7 from: Lib/sikuli to:
14:59:47  C:\Users\egttest\AppData\Roaming\Sikulix\Lib\sikuli
14:59:51 [6031 debug] Jython: added as Jython::sys.path[0]:
14:59:51 C:\Users\egttest\AppData\Roaming\Sikulix\Lib\site-packages
14:59:51 [6033 debug] Jython: ***** sys.path
14:59:51  0: C:\Users\egttest\AppData\Roaming\Sikulix\Lib\site-packages
14:59:51  1: C:\Users\egttest\AppData\Roaming\Sikulix\Lib
14:59:51  2: C:\Users\egttest\AppData\Roaming\Sikulix\Extensions\Lib
14:59:51  3: C:\Users\egttest\AppData\Roaming\Sikulix\Extensions\jython-standalone-2.7.1.jar\Lib
14:59:51 [6045 debug] JythonRunner: ready: version 2.7.1 
14:59:51 [debug] Jython: SikulixForJython: init: starting
14:59:51 [debug] Jython: added as Jython::sys.path[0]:
14:59:51 C:\Users\egttest\AppData\Roaming\Sikulix\Lib\site-packages
14:59:51 [debug] Jython: SikulixForJython: init: success
14:59:51 [debug] Jython: sikuli: Sikuli: starting init
14:59:52 [debug] Screen: initScreens: starting
14:59:52 [debug] Screen: Accessing: GraphicsEnvironment.getLocalGraphicsEnvironment()
14:59:52 [debug] Screen: Accessing: GraphicsEnvironment.getLocalGraphicsEnvironment().getScreenDevices()
14:59:52 [debug] Screen: ScreenDevice 0 has (0,0) --- will be primary Screen(0)
14:59:52 [debug] Screen: Monitor 0: (0, 0) 1920 x 1080
14:59:52 [debug] Mouse: init start
14:59:52 [debug] Mouse: init end
14:59:52 [debug] Screen: initScreens: ending
14:59:52 [debug] Jython: use as default region: R[0,0 1920x1080]@S(0)
14:59:52 [debug] Image: BufferedImage: (1920, 1080)
14:59:52 [debug] Jython: sikuli: Sikuli: ending init
14:59:52 [debug] Jython: use as default region: R[0,0 1920x1080]@S(0)
14:59:53 [debug] Image: BufferedImage: (1920, 1080)
14:59:53 [debug] ImagePath: new BundlePath: C:\ui-tests\tests\sport_bet_tests.sikuli
14:59:53 [debug] FileManager: normalizeAbsolute: file: C:\ui-tests\tests\_libs.sikuli
14:59:53 [debug] FileManager: normalizeAbsolute: file: C:\ui-tests\tests\_libs.sikuli
14:59:53 [debug] ImagePath: add: /C:\ui-tests\tests\_libs.sikuli/
14:59:53 [debug] FileManager: normalizeAbsolute: file: C:\ui-tests\tests\_uimap.sikuli
14:59:53 [debug] FileManager: normalizeAbsolute: file: C:\ui-tests\tests\_uimap.sikuli
14:59:53 [debug] ImagePath: add: /C:\ui-tests\tests\_uimap.sikuli/
14:59:53 [debug] RunTime:loadlib: trying opencv_java342
14:59:53 [debug] RunTime:addToWindowsSystemPath: added to systempath:
14:59:53 C:\Users\egttest\AppData\Roaming\Sikulix\SikulixLibs
14:59:53 [debug] RunTime:libsExport: folder exists: C:\Users\egttest\AppData\Roaming\Sikulix\SikulixLibs (2.0.4 - 202003140801)
14:59:53 [debug] RunTime:loadLib: opencv_java342.dll (success)
14:59:53 [debug] Image: loaded: input_Name.png (file:C:\ui-tests\tests\_uimap.sikuli\input_Name.png)
14:59:53 [debug] Image: cached: input_Name.png (3 KB) (# 1 KB 3 -- 0 % of 64 MB)
14:59:53 [debug] Image: loaded: input_Email_reg.png (file:C:\ui-tests\tests\_uimap.sikuli\input_Email_reg.png)


I hope this will help to figure out what the problem

Regards,
Ivomir

-- 
You received this question notification because your team Sikuli Drivers
is an answer contact for Sikuli.