com.pmease.quickbuild.AccessDeniedException: Access denied #3690

montanaa · 7 years ago

Running a QuickBuild configuration (QuickBuild 6.1 running on Win 2012 R2) executing a step on another node (also Win 2012 R2) server results in the build hanging, the buildAgent console.log for the node contains tons of com.pmease.quickbuild.AccessDeniedException's:

2017-01-11 14:25:13,525 [qtp527655694-27] WARN org.eclipse.jetty.servlet.ServletHandler - /service/node
com.pmease.quickbuild.AccessDeniedException: Access denied for connection from '127.0.0.1'.
at com.pmease.quickbuild.security.SecurityHelper.checkAgentToken(SecurityHelper.java:757)
at com.pmease.quickbuild.grid.GridServlet.service(GridServlet.java:34)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:669)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1336)
at com.pmease.quickbuild.Quickbuild$DisableTraceFilter.doFilter(Quickbuild.java:1057)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:453)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1072)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:382)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1006)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:154)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
at org.eclipse.jetty.server.Server.handle(Server.java:365)
at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:485)
at org.eclipse.jetty.server.BlockingHttpConnection.handleRequest(BlockingHttpConnection.java:53)
at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:937)
at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:998)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:856)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)
at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:72)
at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:264)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
at java.lang.Thread.run(Unknown Source)

The build itself hangs until I kill the java process on the node.

The build log contains:
14:24:16,941 INFO - Executing pre-execute action...
14:24:16,941 INFO - Running step...
14:24:16,957 INFO - Checking step execute condition...
14:24:16,958 INFO - Step execute condition satisfied, executing...
14:24:17,086 INFO - Executing pre-execute action...
14:24:17,224 INFO - Running step...
14:24:17,238 INFO - Checking step execute condition...
14:24:17,238 INFO - Step execute condition satisfied, executing...
14:26:18,247 INFO - Executing post-execute action...

Hanging on "Executing post-execute action...", however there is no post-execute action for the step (i.e. Post-Execute Action = No Action).

replies 4
views 1273
stars 0

robinshen ADMIN · 7 years ago

Looks like the agent authorization token is out of sync with server. Can you please restart the agent to see if there are any errors printed in console?

montanaa · 7 years ago

1. Restarted the agent with no problems/errors...

C:\buildagent\bin>agent restart
wrapperm | Stopping the QuickBuild Build Agent service...
wrapperm | QuickBuild Build Agent service stopped.
wrapperm | Starting the QuickBuild Build Agent service...
wrapperm | QuickBuild Build Agent service started.

2. Verified the node was active via the QuickBuild Active Nodes dashboard.

3. Ran the configuration and got the same result, the build UI says 100% complete but does not complete (hangs). After a couple of minutes I killed the java process running on the agent machine (I've found this is necessary to stop the build otherwise it continues running).

4. Logs are below, FYI I believe the "Unable to find job '7c917c87-e54f-4d84-93ff-55faf6072a88' on node 'sdsvm902025:8811'" is a result of me killing the java process to stop the build.

full.log (from QuickBuild Web UI)...

06:39:40,805 INFO - Executing pre-execute action...
06:39:40,805 INFO - Running step...
06:39:40,825 INFO - Checking step execute condition...
06:39:40,826 INFO - Step execute condition satisfied, executing...
06:39:40,959 INFO - Executing pre-execute action...
06:39:40,991 INFO - Running step...
06:39:41,011 INFO - Checking step execute condition...
06:39:41,011 INFO - Step execute condition satisfied, executing...
06:42:42,220 INFO - Executing post-execute action...
06:42:42,220 ERROR - Step 'master>Build & Test All Platforms' is failed: Unable to find job '7c917c87-e54f-4d84-93ff-55faf6072a88' on node 'sdsvm902025:8811'.
06:42:42,335 INFO - Executing post-execute action...
06:42:42,335 ERROR - Step 'master' is failed: Composite step 'master' failed due to unsatisfied success condition.

console.log is full of com.pmease.quickbuild.AccessDeniedException: Access denied for connection from '127.0.0.1' exceptions ending with...

jvm 1 | 2017-01-12 06:42:41,040 WARN - /service/node
jvm 1 | com.pmease.quickbuild.AccessDeniedException: Access denied for connection from '127.0.0.1'.
jvm 1 | at com.pmease.quickbuild.security.SecurityHelper.checkAgentToken(SecurityHelper.java:757)
jvm 1 | at com.pmease.quickbuild.grid.GridServlet.service(GridServlet.java:34)
jvm 1 | at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:669)
jvm 1 | at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1336)
jvm 1 | at com.pmease.quickbuild.Quickbuild$DisableTraceFilter.doFilter(Quickbuild.java:1057)
jvm 1 | at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
jvm 1 | at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:453)
jvm 1 | at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
jvm 1 | at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1072)
jvm 1 | at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:382)
jvm 1 | at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
jvm 1 | at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1006)
jvm 1 | at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
jvm 1 | at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:154)
jvm 1 | at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
jvm 1 | at org.eclipse.jetty.server.Server.handle(Server.java:365)
jvm 1 | at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:485)
jvm 1 | at org.eclipse.jetty.server.BlockingHttpConnection.handleRequest(BlockingHttpConnection.java:53)
jvm 1 | at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:937)
jvm 1 | at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:998)
jvm 1 | at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:856)
jvm 1 | at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
jvm 1 | at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:72)
jvm 1 | at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:264)
jvm 1 | at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
jvm 1 | at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
jvm 1 | at java.lang.Thread.run(Unknown Source)
wrapper | JVM exited unexpectedly.
wrapper | Reloading Wrapper configuration...
wrapper | Launching a JVM...
jvm 2 | WrapperManager: Initializing...
jvm 2 | 2017-01-12 06:42:46,899 INFO - Cleaning cached plugin libraries...
jvm 2 | 2017-01-12 06:42:47,040 INFO - Cleaning temp directory...
jvm 2 | 2017-01-12 06:42:47,040 INFO - Benchmarking...
jvm 2 | 2017-01-12 06:42:49,086 INFO - Connecting to server 'http://9.30.9.82:8810'...
jvm 2 | 2017-01-12 06:42:49,165 INFO - Updating framework...
jvm 2 | 2017-01-12 06:42:49,165 INFO - Updating plugins...
jvm 2 | 2017-01-12 06:42:49,180 INFO - Updating plugins/com.pmease.quickbuild.libs...
jvm 2 | 2017-01-12 06:42:49,180 INFO - Updating plugins/site...
jvm 2 | 2017-01-12 06:42:49,180 INFO - Updating asset...
jvm 2 | 2017-01-12 06:42:49,180 INFO - Booting QuickBuild from 'C:\buildagent'...
jvm 2 | 2017-01-12 06:42:49,196 INFO - Starting framework...
jvm 2 | 2017-01-12 06:42:49,258 INFO - Caching plugin libraries...
jvm 2 | 2017-01-12 06:42:51,790 INFO - Starting QuickBuild agent...
jvm 2 | 2017-01-12 06:42:51,805 INFO - Initializing velocity...
jvm 2 | 2017-01-12 06:42:51,915 INFO - Starting plugins...

montanaa · 7 years ago

Any update on this - suggestions as how to resolve the issue?

robinshen ADMIN · 7 years ago

Please unauthorize the agent and re-authorize before running any build to see if it works. Also are there any other agents experiencing the issue? Is the agent installed on the same machine as build server?