rainmanwy / robotframework-SikuliLibrary

Sikuli Robot Framework Library provide keywords for Robot Framework to test UI through Sikuli.
Apache License 2.0
147 stars 61 forks source link

Error on Java during the library initialization #183

Closed FortCWB closed 1 year ago

FortCWB commented 1 year ago

I'm facing an issue in several machines, but in others it works smoothly. When I run the test case, in some machines the test gets stuck on the terminal and in others it runs as it should. I'm basically trying to have an official VM for running tests but I'm ending up on "works on my machine" issue.

Versions of robot, python and java are all the same (but also tried older versions on those machines that are having java crashed).

I also tried with mode=NEW, but no success (even though I'm gonna use NEW from now on)

Even the basic example of this page documentation ends up on the same error/crash.

Do you guys have any ideia of what's happening?

OS: Windows 10 Python: 3.11 Robot: 6.00 Java: 1.8.0_171 Sikuli Library: robotframework-sikulilibrary-2.0.3

Lib logs:

15:42:07.029 [main] INFO  org.eclipse.jetty.util.log - Logging initialized @494ms to org.robotframework.remoteserver.logging.Jetty2Log4J
15:42:07.107 [main] INFO  org.eclipse.jetty.server.Server - jetty-9.4.31.v20200723; built: 2020-07-23T17:57:36.812Z; git: 450ba27947e13e66baa8cd1ce7e85a4461cacc1d; jvm 1.8.0_171-b11
15:42:07.169 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@5a63f509{/,null,AVAILABLE}
15:42:07.263 [main] INFO  org.eclipse.jetty.server.AbstractConnector - Started ServerConnector@49e202ad{HTTP/1.1, (http/1.1)}{0.0.0.0:52952}
15:42:07.263 [main] INFO  org.eclipse.jetty.server.Server - Started @730ms
2022-12-06 15:42:10
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.171-b11 mixed mode):

"DestroyJavaVM" #20 prio=5 os_prio=0 tid=0x000000000243d800 nid=0xf88 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"qtp802581203-19" #19 prio=5 os_prio=0 tid=0x000000001f11d800 nid=0x16bc waiting on condition [0x000000002047e000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x000000076c701e18> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(Unknown Source)
    at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:382)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.idleJobPoll(QueuedThreadPool.java:875)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:925)
    at java.lang.Thread.run(Unknown Source)

"qtp802581203-18" #18 prio=5 os_prio=0 tid=0x000000001f11c800 nid=0x1730 waiting on condition [0x000000002037e000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x000000076c701e18> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(Unknown Source)
    at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:382)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.idleJobPoll(QueuedThreadPool.java:875)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:925)
    at java.lang.Thread.run(Unknown Source)

"qtp802581203-17" #17 prio=5 os_prio=0 tid=0x000000001f11c000 nid=0x1c50 waiting on condition [0x000000002027e000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x000000076c701e18> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(Unknown Source)
    at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:382)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.idleJobPoll(QueuedThreadPool.java:875)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:925)
    at java.lang.Thread.run(Unknown Source)

"qtp802581203-16-acceptor-0@7577f124-ServerConnector@49e202ad{HTTP/1.1, (http/1.1)}{0.0.0.0:52952}" #16 prio=3 os_prio=-1 tid=0x000000001f11b000 nid=0x18b0 runnable [0x000000002017e000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
    at sun.nio.ch.ServerSocketChannelImpl.accept(Unknown Source)
    at sun.nio.ch.ServerSocketChannelImpl.accept(Unknown Source)
    - locked <0x000000076d0507a0> (a java.lang.Object)
    at org.eclipse.jetty.server.ServerConnector.accept(ServerConnector.java:388)
    at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:702)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
    at java.lang.Thread.run(Unknown Source)

"qtp802581203-15" #15 prio=5 os_prio=0 tid=0x000000001f076800 nid=0x464 runnable [0x000000002007e000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
    at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(Unknown Source)
    at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(Unknown Source)
    at sun.nio.ch.WindowsSelectorImpl.doSelect(Unknown Source)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(Unknown Source)
    - locked <0x000000076d1b1430> (a sun.nio.ch.Util$3)
    - locked <0x000000076d1b1420> (a java.util.Collections$UnmodifiableSet)
    - locked <0x000000076d1b12d0> (a sun.nio.ch.WindowsSelectorImpl)
    at sun.nio.ch.SelectorImpl.select(Unknown Source)
    at sun.nio.ch.SelectorImpl.select(Unknown Source)
    at org.eclipse.jetty.io.ManagedSelector.nioSelect(ManagedSelector.java:149)
    at org.eclipse.jetty.io.ManagedSelector.select(ManagedSelector.java:156)
    at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.select(ManagedSelector.java:572)
    at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:509)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produceTask(EatWhatYouKill.java:360)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:184)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:135)
    at org.eclipse.jetty.io.ManagedSelector$$Lambda$28/745962066.run(Unknown Source)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
    at java.lang.Thread.run(Unknown Source)

"qtp802581203-14" #14 prio=5 os_prio=0 tid=0x000000001f076000 nid=0x10dc runnable [0x000000001ff7e000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
    at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(Unknown Source)
    at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(Unknown Source)
    at sun.nio.ch.WindowsSelectorImpl.doSelect(Unknown Source)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(Unknown Source)
    - locked <0x000000076d1ad6e0> (a sun.nio.ch.Util$3)
    - locked <0x000000076d1ad6d0> (a java.util.Collections$UnmodifiableSet)
    - locked <0x000000076d1ad580> (a sun.nio.ch.WindowsSelectorImpl)
    at sun.nio.ch.SelectorImpl.select(Unknown Source)
    at sun.nio.ch.SelectorImpl.select(Unknown Source)
    at org.eclipse.jetty.io.ManagedSelector.nioSelect(ManagedSelector.java:149)
    at org.eclipse.jetty.io.ManagedSelector.select(ManagedSelector.java:156)
    at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.select(ManagedSelector.java:572)
    at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:509)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produceTask(EatWhatYouKill.java:360)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:184)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:135)
    at org.eclipse.jetty.io.ManagedSelector$$Lambda$28/745962066.run(Unknown Source)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
    at java.lang.Thread.run(Unknown Source)

"qtp802581203-13" #13 prio=5 os_prio=0 tid=0x000000001f12e800 nid=0x20b0 runnable [0x000000001fe7e000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
    at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(Unknown Source)
    at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(Unknown Source)
    at sun.nio.ch.WindowsSelectorImpl.doSelect(Unknown Source)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(Unknown Source)
    - locked <0x000000076d1a9990> (a sun.nio.ch.Util$3)
    - locked <0x000000076d1a9980> (a java.util.Collections$UnmodifiableSet)
    - locked <0x000000076d1a9830> (a sun.nio.ch.WindowsSelectorImpl)
    at sun.nio.ch.SelectorImpl.select(Unknown Source)
    at sun.nio.ch.SelectorImpl.select(Unknown Source)
    at org.eclipse.jetty.io.ManagedSelector.nioSelect(ManagedSelector.java:149)
    at org.eclipse.jetty.io.ManagedSelector.select(ManagedSelector.java:156)
    at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.select(ManagedSelector.java:572)
    at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:509)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produceTask(EatWhatYouKill.java:360)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:184)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:135)
    at org.eclipse.jetty.io.ManagedSelector$$Lambda$28/745962066.run(Unknown Source)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
    at java.lang.Thread.run(Unknown Source)

"qtp802581203-12" #12 prio=5 os_prio=0 tid=0x000000001f10f800 nid=0x19f0 runnable [0x000000001fd7e000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
    at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(Unknown Source)
    at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(Unknown Source)
    at sun.nio.ch.WindowsSelectorImpl.doSelect(Unknown Source)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(Unknown Source)
    - locked <0x000000076d081330> (a sun.nio.ch.Util$3)
    - locked <0x000000076d0812a8> (a java.util.Collections$UnmodifiableSet)
    - locked <0x000000076d080ea8> (a sun.nio.ch.WindowsSelectorImpl)
    at sun.nio.ch.SelectorImpl.select(Unknown Source)
    at sun.nio.ch.SelectorImpl.select(Unknown Source)
    at org.eclipse.jetty.io.ManagedSelector.nioSelect(ManagedSelector.java:149)
    at org.eclipse.jetty.io.ManagedSelector.select(ManagedSelector.java:156)
    at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.select(ManagedSelector.java:572)
    at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:509)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produceTask(EatWhatYouKill.java:360)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:184)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:135)
    at org.eclipse.jetty.io.ManagedSelector$$Lambda$28/745962066.run(Unknown Source)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
    at java.lang.Thread.run(Unknown Source)

"Service Thread" #10 daemon prio=9 os_prio=0 tid=0x000000001e01d800 nid=0x1278 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread3" #9 daemon prio=9 os_prio=2 tid=0x000000001df87000 nid=0x50c waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread2" #8 daemon prio=9 os_prio=2 tid=0x000000001df82000 nid=0x1130 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #7 daemon prio=9 os_prio=2 tid=0x000000001df80000 nid=0x21f0 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #6 daemon prio=9 os_prio=2 tid=0x000000001df77000 nid=0x2344 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000000001df76000 nid=0x1e54 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x000000001df7f800 nid=0x1c78 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x000000001df70800 nid=0x17e8 in Object.wait() [0x000000001e44e000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x000000076b388ed0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(Unknown Source)
    - locked <0x000000076b388ed0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(Unknown Source)
    at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source)

"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x0000000002639000 nid=0xb1c in Object.wait() [0x000000001df4f000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x000000076b386bf8> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Unknown Source)
    at java.lang.ref.Reference.tryHandlePending(Unknown Source)
    - locked <0x000000076b386bf8> (a java.lang.ref.Reference$Lock)
    at java.lang.ref.Reference$ReferenceHandler.run(Unknown Source)

"VM Thread" os_prio=2 tid=0x000000001c068800 nid=0x1b04 runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x0000000002557000 nid=0x16e4 runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x0000000002559000 nid=0x19e8 runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x000000000255a800 nid=0x16d0 runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x000000000255d000 nid=0x2230 runnable 

"GC task thread#4 (ParallelGC)" os_prio=0 tid=0x000000000255e000 nid=0x1a20 runnable 

"GC task thread#5 (ParallelGC)" os_prio=0 tid=0x000000000255f000 nid=0x16ac runnable 

"GC task thread#6 (ParallelGC)" os_prio=0 tid=0x0000000002563800 nid=0x1d98 runnable 

"GC task thread#7 (ParallelGC)" os_prio=0 tid=0x0000000002564800 nid=0x23fc runnable 

"VM Periodic Task Thread" os_prio=2 tid=0x000000001e030800 nid=0x548 waiting on condition 

JNI global references: 421

Heap
 PSYoungGen      total 76288K, used 36744K [0x000000076b380000, 0x0000000770880000, 0x00000007c0000000)
  eden space 65536K, 56% used [0x000000076b380000,0x000000076d762120,0x000000076f380000)
  from space 10752K, 0% used [0x000000076fe00000,0x000000076fe00000,0x0000000770880000)
  to   space 10752K, 0% used [0x000000076f380000,0x000000076f380000,0x000000076fe00000)
 ParOldGen       total 175104K, used 0K [0x00000006c1a00000, 0x00000006cc500000, 0x000000076b380000)
  object space 175104K, 0% used [0x00000006c1a00000,0x00000006c1a00000,0x00000006cc500000)
 Metaspace       used 13660K, capacity 13928K, committed 14208K, reserved 1060864K
  class space    used 1773K, capacity 1887K, committed 1920K, reserved 1048576K
rainmanwy commented 1 year ago

Hi, @FortCWB could you check the link "https://github.com/rainmanwy/robotframework-SikuliLibrary#start-server-manually"

you could start the java process manually.

do all these VMs have same configuration?

FortCWB commented 1 year ago

Hi, @rainmanwy !!

Yes, it worked! Thank you I'm going to use this as a workaround until I find another machine that "accepts" the tradicional mode + NEW (and thank you for adding this option to the lib).

Here is what I did, in case someone else gets the same issue:

Console terminal command I used:

PS C:\Users\xyz\AppData\Local\Programs\Python\Python39\Lib\site-packages\SikuliLibrary\lib> java -jar SikuliLibrary.jar  12345  .\sikuli_captured\

WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance.
06:52:35.698 [main] INFO  org.eclipse.jetty.util.log - Logging initialized @952ms to org.robotframework.remoteserver.logging.Jetty2Log4J
06:52:35.806 [main] INFO  org.eclipse.jetty.server.Server - jetty-9.4.31.v20200723; built: 2020-07-23T17:57:36.812Z; git: 450ba27947e13e66baa8cd1ce7e85a4461cacc1d; jvm 11.0.16.1+1-LTS-1
06:52:35.868 [main] INFO  org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@146dfe6{/,null,AVAILABLE}
06:52:36.024 [main] INFO  org.eclipse.jetty.server.AbstractConnector - Started ServerConnector@769a1df5{HTTP/1.1, (http/1.1)}{0.0.0.0:12345}
06:52:36.024 [main] INFO  org.eclipse.jetty.server.Server - Started @1294ms
PS C:\Users\xyz\AppData\Local\Programs\Python\Python39\Lib\site-packages\SikuliLibrary\lib> 

Basic test to validate the workaround:

*** Settings ***
Test Setup        Add Needed Image Path
#Test Teardown     Stop Remote Server
#Library           SikuliLibrary
Library        Remote        http://127.0.0.1:12345/

*** Variables ***
${IMAGE_DIR}      ${CURDIR}\\img

*** Test Cases ***
Click In Example
    Click language button

*** Keywords ***
Add Needed Image Path
    Add Image Path    ${IMAGE_DIR}

Click language button
    Click             Capture.png

Notice: uncomment lines 3 and 4 and comment line 5 is enough to get the error.

It's necessary to add "Library Remote http://ip:port/" to each file that uses Sikuli keywords. As far as I understand, the keywords come from the running server itself.