Running Watij based tests on build agent cause build to stall

I have a build that runs a functional test that makes use of Watij. This test runs correctly when run by hand as part of a Maven build kicked of from the command line. However, when this test is run by a build agent the build stalls. Is there anyway to make Watij based tests run?

Many thanks,
Leon

10 comments

Hello,

Try to view thread dump when test hangs next time (there is a "View thread
dump" link in the build results page).

--
Pavel Sher
Software Developer
JetBrains, Inc.
http://www.jetbrains.com
"Develop with pleasure!"



"Leon Davis" <no_reply@jetbrains.com> wrote in message
news:12162527.1201463864467.JavaMail.itn@is.intellij.net...
>I have a build that runs a functional test that makes use of Watij. This
>test runs correctly when run by hand as part of a Maven build kicked of
>from the command line. However, when this test is run by a build agent the
>build stalls. Is there anyway to make Watij based tests run?
>

Many thanks,
Leon



0

I have pasted the Thread dump output for the part of the build that I think represents where Watij is being run. I dont know if I am interpretting the output correctly, but I notice the following:
java.lang.Thread.State: BLOCKED (on object monitor) (Near the very end of the thread dump)

It appears as though Watij is stuck. What should I do?

Many thanks,
Leon

"C:\Program Files\Java\jdk1.6.0_04\jre\bin\java" -jar C:\temp\TeamCity\BuildAgent\temp\buildTmp\surefirebooter35963.jar C:\temp\TeamCity\BuildAgent\temp\buildTmp\surefire35961tmp C:\temp\TeamCity\BuildAgent\temp\buildTmp\surefire35962tmp

2008-02-04 23:46:10
Full thread dump Java HotSpot(TM) Client VM (10.0-b19 mixed mode, sharing):

"Thread-2" prio=6 tid=0x03282c00 nid=0x220 waiting on condition
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at com.jniwrapper.win32.ie.x.run(SourceFile:109)

"BrowserEventLoop" daemon prio=6 tid=0x03294800 nid=0x344 runnable
java.lang.Thread.State: RUNNABLE
at com.jniwrapper.Function.invokeVirtualFunc(Native Method)
at com.jniwrapper.FunctionCall.a(SourceFile:130)
at com.jniwrapper.FunctionCall.callVirtual(SourceFile:57)
at com.jniwrapper.win32.com.impl.IUnknownImpl.invokeVirtualMethod(SourceFile:659)
at com.jniwrapper.win32.com.impl.IUnknownImpl.invokeStandardVirtualMethod(SourceFile:721)
at com.jniwrapper.win32.mshtml.impl.IHTMLFormElementImpl.submit(SourceFile:279)
at com.jniwrapper.win32.ie.dom.C.run(SourceFile:102)
at com.jniwrapper.win32.MessageLoopThread.doInvokeAndWait(MessageLoopThread.java:193)
at com.jniwrapper.win32.ie.dom.Y.submit(SourceFile:98)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.jniwrapper.win32.ie.dom.j.run(SourceFile:592)
at com.jniwrapper.win32.MessageLoopThread$ThreadSynchronizedAction.run(MessageLoopThread.java:569)
at com.jniwrapper.win32.MessageLoopThread$LoopThread.run(MessageLoopThread.java:511)
- locked ]]> (a [Z)

"com.jniwrapper.NativeResourceCollector" daemon prio=6 tid=0x03292c00 nid=0xc08 in Object.wait()
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116) - locked <0x22ec5598>]]> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
at com.jniwrapper.a.run(SourceFile:134)

"Low Memory Detector" daemon prio=6 tid=0x02abec00 nid=0x15fc runnable
java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=10 tid=0x02ab9000 nid=0x17d4 waiting on condition
java.lang.Thread.State: RUNNABLE

"Attach Listener" daemon prio=10 tid=0x02ab8000 nid=0x15a8 waiting on condition
java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x02ab7000 nid=0xd98 runnable
java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=8 tid=0x02aaf400 nid=0xba0 in Object.wait()
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116) - locked <0x22dbfbc8>]]> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x02aae400 nid=0x1198 in Object.wait()
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:485) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116) - locked <0x22dbfc50>]]> (a java.lang.ref.Reference$Lock)

"main" prio=6 tid=0x00386800 nid=0x824 waiting for monitor entry
java.lang.Thread.State: BLOCKED (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on (a [Z) at java.lang.Object.wait(Object.java:443) at com.jniwrapper.win32.MessageLoopThread.doInvokeAndWait(MessageLoopThread.java:222) - locked <0x22f01f10>]]> (a [Z)
at com.jniwrapper.win32.ie.dom.A.invoke(SourceFile:604)
at $Proxy10.submit(Unknown Source)
at watij.runtime.ie.IEForm.submit(IEForm.java:14)
at com.ladsons.sitelad.sitecd.functional.CreateSiteFunctionalTest.setup(CreateSiteFunctionalTest.java:34)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.internal.runners.BeforeAndAfterRunner.invokeMethod(BeforeAndAfterRunner.java:74)
at org.junit.internal.runners.BeforeAndAfterRunner.runBefores(BeforeAndAfterRunner.java:50)
at org.junit.internal.runners.BeforeAndAfterRunner.runProtected(BeforeAndAfterRunner.java:33)
at org.junit.internal.runners.TestMethodRunner.runMethod(TestMethodRunner.java:75)
at org.junit.internal.runners.TestMethodRunner.run(TestMethodRunner.java:45)
at org.junit.internal.runners.TestClassMethodsRunner.invokeTestMethod(TestClassMethodsRunner.java:66)
at org.junit.internal.runners.TestClassMethodsRunner.run(TestClassMethodsRunner.java:35)
at org.junit.internal.runners.TestClassRunner$1.runUnprotected(TestClassRunner.java:42)
at org.junit.internal.runners.BeforeAndAfterRunner.runProtected(BeforeAndAfterRunner.java:34)
at org.junit.internal.runners.TestClassRunner.run(TestClassRunner.java:52)
at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:62)
at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:140)
at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:127)
at org.apache.maven.surefire.Surefire.run(Surefire.java:177)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:334)
at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:980)

"VM Thread" prio=10 tid=0x02aad000 nid=0x17a8 runnable

"VM Periodic Task Thread" prio=10 tid=0x02ac8800 nid=0xce4 waiting on condition

JNI global references: 634

0

Leon,

Thread dump does not have TeamCity code at all...

Could you please try to run the same command (exact command used to run the build can be found in the agent logs), on the same agent, under the same user that TeamCity agent is run under?

--
Best regards,

Yegor Yarko
Project Manager
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"

0

Hello,

Have you tried to run this build when agent started from the agent.bat file?

--
Pavel Sher
Software Developer
JetBrains, Inc.
http://www.jetbrains.com
"Develop with pleasure!"



"Leon Davis" <no_reply@jetbrains.com> wrote in message
news:9719054.1202169492769.JavaMail.itn@is.intellij.net...
>I have pasted the Thread dump output for the part of the build that I think
>represents where Watij is being run. I dont know if I am interpretting the
>output correctly, but I notice the following:

java.lang.Thread.State: BLOCKED (on object monitor) (Near the very
end of the thread dump)

>

It appears as though Watij is stuck. What should I do?

>

Many thanks,
Leon

>

"C:\Program Files\Java\jdk1.6.0_04\jre\bin\java" -jar
C:\temp\TeamCity\BuildAgent\temp\buildTmp\surefirebooter35963.jar
C:\temp\TeamCity\BuildAgent\temp\buildTmp\surefire35961tmp
C:\temp\TeamCity\BuildAgent\temp\buildTmp\surefire35962tmp

>

2008-02-04 23:46:10
Full thread dump Java HotSpot(TM) Client VM (10.0-b19 mixed mode,
sharing):

>

"Thread-2" prio=6 tid=0x03282c00 nid=0x220 waiting on condition

java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at com.jniwrapper.win32.ie.x.run(SourceFile:109)

>

"BrowserEventLoop" daemon prio=6 tid=0x03294800 nid=0x344 runnable

java.lang.Thread.State: RUNNABLE
at com.jniwrapper.Function.invokeVirtualFunc(Native Method)
at com.jniwrapper.FunctionCall.a(SourceFile:130)
at com.jniwrapper.FunctionCall.callVirtual(SourceFile:57)
at
com.jniwrapper.win32.com.impl.IUnknownImpl.invokeVirtualMethod(SourceFile:659)
at
com.jniwrapper.win32.com.impl.IUnknownImpl.invokeStandardVirtualMethod(SourceFile:721)
at
com.jniwrapper.win32.mshtml.impl.IHTMLFormElementImpl.submit(SourceFile:279)
at com.jniwrapper.win32.ie.dom.C.run(SourceFile:102)
at
com.jniwrapper.win32.MessageLoopThread.doInvokeAndWait(MessageLoopThread.java:193)
at com.jniwrapper.win32.ie.dom.Y.submit(SourceFile:98)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.jniwrapper.win32.ie.dom.j.run(SourceFile:592)
at
com.jniwrapper.win32.MessageLoopThread$ThreadSynchronizedAction.run(MessageLoopThread.java:569)
at
com.jniwrapper.win32.MessageLoopThread$LoopThread.run(MessageLoopThread.java:511)
- locked <0x22f01f10> (a [Z)

>

"com.jniwrapper.NativeResourceCollector" daemon prio=6 tid=0x03292c00
nid=0xc08 in Object.wait()
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22ec5598> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
- locked <0x22ec5598> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
at com.jniwrapper.a.run(SourceFile:134)

>

"Low Memory Detector" daemon prio=6 tid=0x02abec00 nid=0x15fc runnable

java.lang.Thread.State: RUNNABLE

>

"CompilerThread0" daemon prio=10 tid=0x02ab9000 nid=0x17d4 waiting on
condition
java.lang.Thread.State: RUNNABLE

>

"Attach Listener" daemon prio=10 tid=0x02ab8000 nid=0x15a8 waiting on
condition
java.lang.Thread.State: RUNNABLE

>

"Signal Dispatcher" daemon prio=10 tid=0x02ab7000 nid=0xd98 runnable

java.lang.Thread.State: RUNNABLE

>

"Finalizer" daemon prio=8 tid=0x02aaf400 nid=0xba0 in Object.wait()

java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22dbfbc8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
- locked <0x22dbfbc8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

>

"Reference Handler" daemon prio=10 tid=0x02aae400 nid=0x1198 in
Object.wait()
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22dbfc50> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:485)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
- locked <0x22dbfc50> (a java.lang.ref.Reference$Lock)

>

"main" prio=6 tid=0x00386800 nid=0x824 waiting for monitor entry

java.lang.Thread.State: BLOCKED (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22f01f10> (a [Z)
at java.lang.Object.wait(Object.java:443)
at
com.jniwrapper.win32.MessageLoopThread.doInvokeAndWait(MessageLoopThread.java:222)
- locked <0x22f01f10> (a [Z)
at com.jniwrapper.win32.ie.dom.A.invoke(SourceFile:604)
at $Proxy10.submit(Unknown Source)
at watij.runtime.ie.IEForm.submit(IEForm.java:14)
at
com.ladsons.sitelad.sitecd.functional.CreateSiteFunctionalTest.setup(CreateSiteFunctionalTest.java:34)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.junit.internal.runners.BeforeAndAfterRunner.invokeMethod(BeforeAndAfterRunner.java:74)
at
org.junit.internal.runners.BeforeAndAfterRunner.runBefores(BeforeAndAfterRunner.java:50)
at
org.junit.internal.runners.BeforeAndAfterRunner.runProtected(BeforeAndAfterRunner.java:33)
at
org.junit.internal.runners.TestMethodRunner.runMethod(TestMethodRunner.java:75)
at
org.junit.internal.runners.TestMethodRunner.run(TestMethodRunner.java:45)
at
org.junit.internal.runners.TestClassMethodsRunner.invokeTestMethod(TestClassMethodsRunner.java:66)
at
org.junit.internal.runners.TestClassMethodsRunner.run(TestClassMethodsRunner.java:35)
at
org.junit.internal.runners.TestClassRunner$1.runUnprotected(TestClassRunner.java:42)
at
org.junit.internal.runners.BeforeAndAfterRunner.runProtected(BeforeAndAfterRunner.java:34)
at org.junit.internal.runners.TestClassRunner.run(TestClassRunner.java:52)
at
org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:62)
at
org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:140)
at
org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:127)
at org.apache.maven.surefire.Surefire.run(Surefire.java:177)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:334)
at
org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:980)

>

"VM Thread" prio=10 tid=0x02aad000 nid=0x17a8 runnable

>

"VM Periodic Task Thread" prio=10 tid=0x02ac8800 nid=0xce4 waiting on
condition

>

JNI global references: 634



0

Added this message before seeing that I could reply directly to another users message, Cant see a delete option...

Message was edited by:
Leon Davis

0

Hi,
When running the build agent from the command line as administrator on the box teamcity is running on the Watij tests complete (Windows server 2003 SBS). I am therefore guessing that I have a problem with rights the user has the build agent is running under. This user is the currently the Local System user. This was chosen by default when I installed the agent using the Java Webstart method.

Should I create a new user for the agent to be run under? What is it specifically that the Local System user might not have that stops these tests from running and that I should therefore make sure another user does have?

When looking at the logs in C:\Program Files\TeamCity\BuildAgent\logs, I do not see anything that says what is wrong with the Local System user.

teamcity-agent.log:
This appears show the same information as I would see if running the Maven build myself from the command line. When it gets the Watij test the logs stops as the agent is currenly stalled.

launcher.log + wrapper.log appear to say the same thing: The successful starting of the agent. Is there another log that I should be looking in?

Many thanks for all your help,
Leon

0

Leon,

The problem can be both in user and the fact that the agent is started as Windows service.

As we are not running Watij tests ourselves, we cannot advice on the specific problem resolution.

You can try running the TeamCity agent service as Administrator to see what if this helps.

Most probably, however, you will need to run the agent from the user session and not as a service.

As the problem seem to lie in Watij itself, I am not sure any TeamCity logs can help you much. All the relevant information should be present in the build log and teamcity-agent.log

--
Best regards,

Yegor Yarko
Project Manager
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"

0

Hello Leon,

Could you please try toturn on checkbox "Allow service to interact with
desktop" and run build again? This checkbox is on the Log On tab in the
service configuration.

--
Pavel Sher
Software Developer
JetBrains, Inc.
http://www.jetbrains.com
"Develop with pleasure!"



"Leon Davis" <no_reply@jetbrains.com> wrote in message
news:32356861.1202426302006.JavaMail.itn@is.intellij.net...

Hi,
When running the build agent from the command line as administrator on the
box teamcity is running on the Watij tests complete (Windows server 2003
SBS). I am therefore guessing that I have a problem with rights the user
has the build agent is running under. This user is the currently the Local
System user. This was chosen by default when I installed the agent using
the Java Webstart method.

>

Should I create a new user for the agent to be run under? What is it
specifically that the Local System user might not have that stops these
tests from running and that I should therefore make sure another user does
have?

>

When looking at the logs in C:\Program Files\TeamCity\BuildAgent\logs, I
do not see anything that says what is wrong with the Local System user.

>

teamcity-agent.log:
This appears show the same information as I would see if running the Maven
build myself from the command line. When it gets the Watij test the logs
stops as the agent is currenly stalled.

>

launcher.log + wrapper.log appear to say the same thing: The successful
starting of the agent. Is there another log that I should be looking in?

>

Many thanks for all your help,
Leon



0

Hi Paul,

Good news, when running the build agent service as Administrator it all works fine :)

I have tried creating a basic separate user (teamcityBuildAgent) to run this service but it suffers the same problems as the Local System user, i.e. the tests stall. This means that administrator has some specific rights required by a user to run Watij tests as a service. I completely understand that this is a Watij issue and will raise the question the relevant forum (unless anyone has any ideas? :) ).

It is however good to know that Watij tests can be run on a server running TeamCity.

When I find out how to get a standard user to run the build agent as a service I will add it to this post and mark this question as answered

Many thanks,
Leon

0

Just as an info:

From what I know, a windows-service running under the system account doesn't have network access.
Only services running under normal user account's can access network.

As watij uses the network I'd assume that's the cause.

0

Please sign in to leave a comment.