Missing reports, logs, requests in 5.10.1


#1

After updating to 5.10.1, I occasionally get reports missing. For example, when running this Test Suite Collection, that consists of 5 Test Suites, TS-0001 is executed and only 1 of 3 Test Cases runs. The other two didn’t even run, for an unknown reason. Console log shows 0/3 passed, however only 1 is passed. See screenshot:

2019-01-11_11-36-47

Failed test cases were supposed to be retried, like the TS-0003 is retried (notice “Re-run 1” in the screenshot).

I also have set up a reporting system that sends a message via a POST request after the test suite. The messages haven’t been sent (or better, I cannot find any trace of them being sent) for the two failed Test Suites (TS-0001 and TS-0005). This is not normal behavior, the POST messages are sent regardless of PASS/FAIL/ERROR.

TC 1/3 of the TS-0001 finished execution at 8:12:48 and was supposed to continue with TC 2 of the TS-0001, but this never happens, instead it jumps to TS-0002. Here is the log around that time:

!SESSION 2019-01-11 08:12:26.638 -----------------------------------------------
eclipse.buildId=unknown
java.version=1.8.0_181
java.vendor=Oracle Corporation
BootLoader constants: OS=win32, ARCH=x86_64, WS=win32, NL=en_US
Framework arguments: -runMode=console -projectPath=C:\ccccc.prj -statusDelay=3 -retry=3 -retryFailedTestCases=true -testSuiteCollectionPath=Test Suites/TSC-0001-xxxx
Command-line arguments: -os win32 -ws win32 -arch x86_64 -data config -runMode=console -consoleLog -projectPath=C:\ccccc.prj -statusDelay=3 -retry=3 -retryFailedTestCases=true -testSuiteCollectionPath=Test Suites/TSC-0001-xxxx


!ENTRY org.eclipse.core.resources 2 10035 2019-01-11 08:12:29.178
!MESSAGE The workspace exited with unsaved changes in the previous session; refreshing workspace to recover changes.
SLF4J: Failed to load class “org.slf4j.impl.StaticLoggerBinder”.
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
Warning: NLS unused message: HAND_INSTANT_BROWSERS_DIA_MESSAGE in: com.kms.katalon.composer.webui.recorder.constants.composerWebuiRecorderMessages
Warning: NLS unused message: HAND_INSTANT_BROWSERS_DIA_TITLE in: com.kms.katalon.composer.webui.recorder.constants.composerWebuiRecorderMessages
Warning: NLS unused message: HAND_INSTANT_BROWSERS_DIA_TOOGLE_MESSAGE in: com.kms.katalon.composer.webui.recorder.constants.composerWebuiRecorderMessages
Warning: NLS unused message: INSTANT_BROWSER_PREFIX in: com.kms.katalon.composer.webui.recorder.constants.composerWebuiRecorderMessages
Warning: NLS unused message: Key in: com.kms.katalon.composer.webui.recorder.constants.composerWebuiRecorderMessages
Warning: NLS unused message: MENU_ITEM_INSTANT_BROWSERS in: com.kms.katalon.composer.webui.recorder.constants.composerWebuiRecorderMessages
Warning: NLS unused message: PREF_LBL_INSTANT_BROWSER_DO_NOT_SHOW_WARNING_DIALOG in: com.kms.katalon.composer.webui.recorder.constants.composerWebuiRecorderMessages
Warning: NLS unused message: PREF_LBL_INSTANT_BROWSER_PORT in: com.kms.katalon.composer.webui.recorder.constants.composerWebuiRecorderMessages
org.eclipse.jetty.server.Server@4799876c - STARTED
+= qtp484146607{STARTED,8<=11<=200,i=1,q=0} - STARTED
| ± 119 qtp484146607-119 RUNNABLE @ sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
| ± 118 qtp484146607-118-acceptor-0@6972329b-ServerConnector@10167e4b{HTTP/1.1,[http/1.1]}{0.0.0.0:50000} RUNNABLE @ sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) prio=3
| ± 115 qtp484146607-115 RUNNABLE @ sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
| ± 121 qtp484146607-121 RUNNABLE @ sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
| ± 124 qtp484146607-124 RUNNABLE @ sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
| ± 114 qtp484146607-114 RUNNABLE @ sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
| ± 116 qtp484146607-116 RUNNABLE @ sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
| ± 120 qtp484146607-120 RUNNABLE @ sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
| ± 117 qtp484146607-117 RUNNABLE @ sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
| ± 125 qtp484146607-125-acceptor-0@bfa1054-ServerConnector@5dcf5d{HTTP/1.1,[http/1.1]}{0.0.0.0:50001} RUNNABLE @ sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) prio=3
| ± 126 qtp484146607-126 TIMED_WAITING @ sun.misc.Unsafe.park(Native Method) IDLE
+= ServerConnector@10167e4b{HTTP/1.1,[http/1.1]}{0.0.0.0:50000} - STARTED
| +~ org.eclipse.jetty.server.Server@4799876c - STARTED
| +~ qtp484146607{STARTED,8<=11<=200,i=1,q=0} - STARTED
| += org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@6dba0b95 - STARTED
| ± org.eclipse.jetty.io.ArrayByteBufferPool@5c6fd25b
| += HttpConnectionFactory@487f436c[HTTP/1.1] - STARTED
| | ± HttpConfiguration@6f423aeb{32768/8192,8192/8192,https://:0,[]}
| += org.eclipse.jetty.server.ServerConnector$ServerConnectorManager@22e3c56f - STARTED
| | += org.eclipse.jetty.io.ManagedSelector@4c77d2f4 id=0 keys=0 selected=0 id=0
| | | ± sun.nio.ch.WindowsSelectorImpl@43de729f keys=0
| | += org.eclipse.jetty.io.ManagedSelector@6640469e id=1 keys=0 selected=0 id=1
| | | ± sun.nio.ch.WindowsSelectorImpl@69be3d38 keys=0
| | += org.eclipse.jetty.io.ManagedSelector@b6a5fe0 id=2 keys=0 selected=0 id=2
| | | ± sun.nio.ch.WindowsSelectorImpl@38459908 keys=0
| | += org.eclipse.jetty.io.ManagedSelector@3f582fe id=3 keys=0 selected=0 id=3
| | ± sun.nio.ch.WindowsSelectorImpl@7e381729 keys=0
| ± sun.nio.ch.ServerSocketChannelImpl[/0:0:0:0:0:0:0:0:50000]
| ± qtp484146607-118-acceptor-0@6972329b-ServerConnector@10167e4b{HTTP/1.1,[http/1.1]}{0.0.0.0:50000}
+= ServerConnector@5dcf5d{HTTP/1.1,[http/1.1]}{0.0.0.0:50001} - STARTED
| +~ org.eclipse.jetty.server.Server@4799876c - STARTED
| +~ qtp484146607{STARTED,8<=13<=200,i=3,q=0} - STARTED
| += org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@3c29bd0a - STARTED
| ± org.eclipse.jetty.io.ArrayByteBufferPool@846bb36
| += HttpConnectionFactory@566bcf17[HTTP/1.1] - STARTED
| | ± HttpConfiguration@3dd1d67c{32768/8192,8192/8192,https://:0,[]}
| += org.eclipse.jetty.server.ServerConnector$ServerConnectorManager@3b97fe74 - STARTED
| | += org.eclipse.jetty.io.ManagedSelector@3fc28a48 id=0 keys=0 selected=0 id=0
| | | ± sun.nio.ch.WindowsSelectorImpl@2812a73d keys=0
| | += org.eclipse.jetty.io.ManagedSelector@5d218973 id=1 keys=0 selected=0 id=1
| | | ± sun.nio.ch.WindowsSelectorImpl@aadef17 keys=0
| | += org.eclipse.jetty.io.ManagedSelector@585f49b4 id=2 keys=0 selected=0 id=2
| | | ± sun.nio.ch.WindowsSelectorImpl@5d115921 keys=0
| | += org.eclipse.jetty.io.ManagedSelector@20c15ece id=3 keys=0 selected=0 id=3
| | ± sun.nio.ch.WindowsSelectorImpl@797f6c3a keys=0
| ± sun.nio.ch.ServerSocketChannelImpl[/0:0:0:0:0:0:0:0:50001]
| ± qtp484146607-125-acceptor-0@bfa1054-ServerConnector@5dcf5d{HTTP/1.1,[http/1.1]}{0.0.0.0:50001}
+= o.e.j.s.ServletContextHandler@7484b207{/,null,AVAILABLE} - STARTED
| += org.eclipse.jetty.server.session.SessionHandler@559afe49 - STARTED
| | += org.eclipse.jetty.server.session.HashSessionManager@24c5374 - STARTED
| | | += org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@1a6a6bfb - STARTED
| | | | ± sun.misc.Unsafe.park(Native Method)
| | | | ± java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
| | | | ± java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
| | | | ± java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
| | | | ± java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
| | | | ± java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
| | | | ± java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
| | | | ± java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
| | | | ± java.lang.Thread.run(Thread.java:748)
| | | +~ org.eclipse.jetty.server.session.HashSessionIdManager@3be66e4c - STARTED
| | += org.eclipse.jetty.servlet.ServletHandler@2cf4fee4 - STARTED
| | += Jetty_WebSocketUpgradeFilter - STARTED
| | | ± contextAttributeKey=org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter
| | | ± pathmap=PathMappings[size=1]
| | | ± MappedResource[pathSpec=UriTemplatePathSpec["/",pathDepth=1,group=EXACT],resource=org.eclipse.jetty.websocket.jsr356.server.JsrCreator[metadata=AnnotatedServerEndpointMetadata[endpoint=@javax.websocket.server.ServerEndpoint(encoders=[], configurator=class javax.websocket.server.ServerEndpointConfig$Configurator, decoders=[], subprotocols=[], value=/),config=AnnotatedServerEndpointConfig[endpointClass=class com.kms.katalon.composer.webui.recorder.websocket.RecorderAddonSocket,path=/,decoders=[],encoders=[],subprotocols=[],extensions=[]]]]]
| | ± [/*]/[]==1=>Jetty_WebSocketUpgradeFilter
| | += org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-3dd53cf9@669c0a59==org.eclipse.jetty.servlet.ServletHandler$Default404Servlet,-1,true - STARTED
| | ± [/]=>org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-3dd53cf9
| += org.eclipse.jetty.websocket.jsr356.server.ServerContainer@1a2bb9c6 - STARTED
| | += org.eclipse.jetty.websocket.client.WebSocketClient@21f87466 - STARTED
| | += org.eclipse.jetty.websocket.server.WebSocketServerFactory@5003757 - STARTED
| | += org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@59363501 - STARTED
| | ± org.eclipse.jetty.io.MappedByteBufferPool@1398ada7
| | += WebSocketSession[websocket=JsrAnnotatedEventDriver[websocket=com.kms.katalon.composer.webui.recorder.websocket.RecorderAddonSocket@80babe4],behavior=SERVER,connection=WebSocketServerConnection@18A3A1{endp=SelectChannelEndPoint@7aa28ae4{/0:0:0:0:0:0:0:1:63760<->50000,Open,in,out,FI,-,1341/300000,WebSocketServerConnection@18a3a1}{io=1/1,kio=1,kro=1},ios=IOState@37e1d09a[OPEN,in,out],f=Flusher[queueSize=0,aggregateSize=0,failure=null],g=Generator[SERVER,validating],p=Parser@ca906f0[ExtensionStack,s=START,c=0,len=77,f=null]},remote=WebSocketRemoteEndpoint@7d7e3494[batching=true],incoming=JsrAnnotatedEventDriver[websocket=com.kms.katalon.composer.webui.recorder.websocket.RecorderAddonSocket@80babe4],outgoing=ExtensionStack[queueSize=0,extensions=[],incoming=org.eclipse.jetty.websocket.jsr356.JsrSession,outgoing=org.eclipse.jetty.websocket.server.WebSocketServerConnection]] - STARTED
| | ± incomingHandler : JsrAnnotatedEventDriver[websocket=com.kms.katalon.composer.webui.recorder.websocket.RecorderAddonSocket@80babe4]
| | ± outgoingHandler : ExtensionStack[queueSize=0,extensions=[],incoming=org.eclipse.jetty.websocket.jsr356.JsrSession,outgoing=org.eclipse.jetty.websocket.server.WebSocketServerConnection] - STARTED
| | ± Stack
| | ± Network : WebSocketServerConnection@18A3A1{endp=SelectChannelEndPoint@7aa28ae4{/0:0:0:0:0:0:0:1:63760<->50000,Open,in,out,FI,-,1487/300000,WebSocketServerConnection@18a3a1}{io=1/1,kio=1,kro=1},ios=IOState@37e1d09a[OPEN,in,out],f=Flusher[queueSize=0,aggregateSize=0,failure=null],g=Generator[SERVER,validating],p=Parser@ca906f0[ExtensionStack,s=START,c=0,len=77,f=null]}
| | ± Websocket: WebSocketSession[websocket=JsrAnnotatedEventDriver[websocket=com.kms.katalon.composer.webui.recorder.websocket.RecorderAddonSocket@80babe4],behavior=SERVER,connection=WebSocketServerConnection@18A3A1{endp=SelectChannelEndPoint@7aa28ae4{/0:0:0:0:0:0:0:1:63760<->50000,Open,in,out,FI,-,1513/300000,WebSocketServerConnection@18a3a1}{io=1/1,kio=1,kro=1},ios=IOState@37e1d09a[OPEN,in,out],f=Flusher[queueSize=0,aggregateSize=0,failure=null],g=Generator[SERVER,validating],p=Parser@ca906f0[ExtensionStack,s=START,c=0,len=77,f=null]},remote=WebSocketRemoteEndpoint@7d7e3494[batching=true],incoming=JsrAnnotatedEventDriver[websocket=com.kms.katalon.composer.webui.recorder.websocket.RecorderAddonSocket@80babe4],outgoing=ExtensionStack[queueSize=0,extensions=[],incoming=org.eclipse.jetty.websocket.jsr356.JsrSession,outgoing=org.eclipse.jetty.websocket.server.WebSocketServerConnection]]
| |
| +> No ClassLoader
| +> Handler attributes o.e.j.s.ServletContextHandler@7484b207{/,null,AVAILABLE}
| | ± org.eclipse.jetty.server.Executor=qtp484146607{STARTED,8<=13<=200,i=3,q=0}
| | ± org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter=WebSocketUpgradeFilter[factory=org.eclipse.jetty.websocket.server.WebSocketServerFactory@5003757,pathmap=PathMappings[size=1]]
| | ± javax.websocket.server.ServerContainer=org.eclipse.jetty.websocket.jsr356.server.ServerContainer@1a2bb9c6
| +> Context attributes o.e.j.s.ServletContextHandler@7484b207{/,null,AVAILABLE}
| | ± org.eclipse.jetty.util.DecoratedObjectFactory=org.eclipse.jetty.util.DecoratedObjectFactory[decorators=1]
| +> Initparams o.e.j.s.ServletContextHandler@7484b207{/,null,AVAILABLE}
+= org.eclipse.jetty.server.session.HashSessionIdManager@3be66e4c - STARTED
|
+> org.eclipse.osgi.internal.loader.EquinoxClassLoader@4f9f2c62[org.eclipse.jetty.server:9.3.9.v20160517(id=268)]
± org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1@551435b5
Warning: NLS unused message: HAND_INSTANT_BROWSERS_DIA_MESSAGE in: com.kms.katalon.objectspy.constants.objectspyMessages
Warning: NLS unused message: HAND_INSTANT_BROWSERS_DIA_TITLE in: com.kms.katalon.objectspy.constants.objectspyMessages
Warning: NLS unused message: INSTANT_BROWSER_PREFIX in: com.kms.katalon.objectspy.constants.objectspyMessages
Warning: NLS unused message: MENU_ITEM_INSTANT_BROWSERS in: com.kms.katalon.objectspy.constants.objectspyMessages
Warning: NLS unused message: PREF_LBL_INSTANT_BROWSER_PORT in: com.kms.katalon.objectspy.constants.objectspyMessages
Warning: NLS unused message: PREF_LBL_INSTANT_BROWSER_PORT_DO_NOT_SHOW_WARNING_DIALOG in: com.kms.katalon.objectspy.constants.objectspyMessages
Warning: NLS missing message: DIA_MSG_SELECT_ALL_BTN in: com.kms.katalon.objectspy.constants.objectspyMessages
Warning: NLS missing message: DIA_MSG_DE_SELECT_ALL_BTN in: com.kms.katalon.objectspy.constants.objectspyMessages
Jan 11, 2019 9:01:21 AM org.openqa.selenium.remote.ProtocolHandshake createSession
INFO: Detected dialect: OSS


#2

Adding from the JUnit_Report.xml:


#3

@duyluong @huynguyen Please take a look.


#4

Hi @Mate_Mrse,

At TS-0001 Chrome (headless), the status show 0/3 that means there were 3 test cases in the test suite and 0 test case was completed. Therefore, the first executed test case has not completed yet.

Please investigate, or send us log files (.log) in report folder 20190111_081243 of TS-0001 Chrome (headless) to address the issue.

Thanks.


#5

Sorry guys. This is my mistake. I found the cause of incomplete tests - there was some text pasted in the test script that couldn’t compile. :woozy_face:


#6

Thank you for the update - if anything goes wrong again don’t hesitate to inform us :smiley:.


#7