Your browser was unable to load all of the resources. They may have been blocked by your firewall, proxy or browser configuration.
Press Ctrl+F5 or Ctrl+Shift+R to have your browser try again.

More detailed information needed in Server Log #3345

mmuszyns ·
Hi,

Our Server Log gets a lot of messages, many of them are quite the same. Log rotate happens every 10-12 hours, so it's a bit of an issue to find specific error messages from, let's say, last Monday.

I'm trying to fix as many errors as possible by analyzing each error type that appears in Server Log. However, it's very problematic because error messages don't provide me with information about configuration or user that threw an exception. Is it possible to add such details to Server Log?
  • replies 4
  • views 4233
  • stars 0
robinshen ADMIN ·
Can you cite an example of that exception? Or let me know how to get it reproduced.
mmuszyns ·
Sure, few examples. But first I'd like to emphasize: we know how to fix 99% of these issues, we just don't know how to efficiently find occurences of scripts causing these errors. More than 10 people can edit settings, there are c.a. 1000 users and few thousands of build configurations. Running `grep` on XML files from backups is not very efficient.

1. Configuration path would be useful:

2015-10-12 14:16:35,324 [pool-1-thread-29030] WARN com.pmease.quickbuild.plugin.notifier.email.EmailNotifier - Can not send email notification to user 'xyz': email not specified.

2015-10-12 14:17:18,148 [pool-1-thread-29097] WARN com.pmease.quickbuild.DefaultBuildEngine - Committer email can not be found in repository, trying to lookup email of user 'John Doe' from authenticators...

2015-10-12 14:17:18,152 [pool-1-thread-29097] WARN com.pmease.quickbuild.DefaultBuildEngine - Can not find mapped QuickBuild user 'Rafal Korszun', trying to lookup email of committer 'Jane Doe' from repository...

2. Configuration name would be useful:

2015-10-12 14:17:12,171 [pool-1-thread-29049] ERROR com.pmease.quickbuild.DefaultBuildEngine - Error processing build request.
java.lang.RuntimeException: Failed to evaluate below expression:
groovy:
vars.get("VER_BUILD").increase();
newlabel = "MANUAL_UNIT_TESTS_" + vars.getValue("BRANCH_NAME").replace('/', '-') + "_1.0.0." + vars.get("VER_BUILD");
newlabel
at com.pmease.quickbuild.util.ExceptionUtils.wrapException(ExceptionUtils.java:87)
at com.pmease.quickbuild.DefaultScriptEngine.evaluate(DefaultScriptEngine.java:94)
at com.pmease.quickbuild.DefaultScriptEngine.interpolate(DefaultScriptEngine.java:105)
at com.pmease.quickbuild.DefaultScriptEngine$Interpolator.intercept(DefaultScriptEngine.java:281)
at com.pmease.quickbuild.setting.configuration.version.UseSpecifiedVersion$$EnhancerByCGLIB$$93b7860c.getVersion(<generated>)
at com.pmease.quickbuild.setting.configuration.version.UseSpecifiedVersion.getNext(UseSpecifiedVersion.java:49)
at com.pmease.quickbuild.setting.configuration.version.UseSpecifiedVersion$$EnhancerByCGLIB$$93b7860c.CGLIB$getNext$2(<generated>)
at com.pmease.quickbuild.setting.configuration.version.UseSpecifiedVersion$$EnhancerByCGLIB$$93b7860c$$FastClassByCGLIB$$41bb741a.invoke(<generated>)
at net.sf.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:215)
at com.pmease.quickbuild.DefaultScriptEngine$Interpolator.intercept(DefaultScriptEngine.java:273)
at com.pmease.quickbuild.setting.configuration.version.UseSpecifiedVersion$$EnhancerByCGLIB$$93b7860c.getNext(<generated>)
at com.pmease.quickbuild.model.Configuration.getNextVersion(Configuration.java:567)
at sun.reflect.GeneratedMethodAccessor194.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java:197)
at com.pmease.quickbuild.model.Configuration_$$_javassist_28.getNextVersion(Configuration_$$_javassist_28.java)
at com.pmease.quickbuild.DefaultBuildEngine.newVersion(DefaultBuildEngine.java:240)
at com.pmease.quickbuild.DefaultBuildEngine.process(DefaultBuildEngine.java:348)
at com.pmease.quickbuild.DefaultBuildEngine.access$000(DefaultBuildEngine.java:131)
at com.pmease.quickbuild.DefaultBuildEngine$2.run(DefaultBuildEngine.java:1076)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:450)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:314)
at java.util.concurrent.FutureTask.run(FutureTask.java:149)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:767)
Caused by: com.pmease.quickbuild.QuickbuildException: java.lang.NullPointerException: Cannot invoke method replace() on null object
at org.codehaus.groovy.runtime.NullObject.invokeMethod(NullObject.java:77)
at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.call(PogoMetaClassSite.java:45)
at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:42)
at org.codehaus.groovy.runtime.callsite.NullCallSite.call(NullCallSite.java:32)
at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:42)
at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:108)
at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:120)
at script14446522321402004857862.run(script14446522321402004857862.groovy:3)
at com.pmease.quickbuild.plugin.basis.BasisPlugin$28.evaluate(BasisPlugin.java:347)
at com.pmease.quickbuild.DefaultScriptEngine.evaluate(DefaultScriptEngine.java:81)
at com.pmease.quickbuild.DefaultScriptEngine.interpolate(DefaultScriptEngine.java:105)
at com.pmease.quickbuild.DefaultScriptEngine$Interpolator.intercept(DefaultScriptEngine.java:281)
at com.pmease.quickbuild.setting.configuration.version.UseSpecifiedVersion$$EnhancerByCGLIB$$93b7860c.getVersion(<generated>)
at com.pmease.quickbuild.setting.configuration.version.UseSpecifiedVersion.getNext(UseSpecifiedVersion.java:49)
at com.pmease.quickbuild.setting.configuration.version.UseSpecifiedVersion$$EnhancerByCGLIB$$93b7860c.CGLIB$getNext$2(<generated>)
at com.pmease.quickbuild.setting.configuration.version.UseSpecifiedVersion$$EnhancerByCGLIB$$93b7860c$$FastClassByCGLIB$$41bb741a.invoke(<generated>)
at net.sf.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:215)
at com.pmease.quickbuild.DefaultScriptEngine$Interpolator.intercept(DefaultScriptEngine.java:273)
at com.pmease.quickbuild.setting.configuration.version.UseSpecifiedVersion$$EnhancerByCGLIB$$93b7860c.getNext(<generated>)
at com.pmease.quickbuild.model.Configuration.getNextVersion(Configuration.java:567)
at sun.reflect.GeneratedMethodAccessor194.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java:197)
at com.pmease.quickbuild.model.Configuration_$$_javassist_28.getNextVersion(Configuration_$$_javassist_28.java)
at com.pmease.quickbuild.DefaultBuildEngine.newVersion(DefaultBuildEngine.java:240)
at com.pmease.quickbuild.DefaultBuildEngine.process(DefaultBuildEngine.java:348)
at com.pmease.quickbuild.DefaultBuildEngine.access$000(DefaultBuildEngine.java:131)
at com.pmease.quickbuild.DefaultBuildEngine$2.run(DefaultBuildEngine.java:1076)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:450)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:314)
at java.util.concurrent.FutureTask.run(FutureTask.java:149)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:767)
at com.pmease.quickbuild.plugin.basis.BasisPlugin$28.evaluate(BasisPlugin.java:371)
at com.pmease.quickbuild.DefaultScriptEngine.evaluate(DefaultScriptEngine.java:81)
... 25 more

4, Again, user or configuration path would be useful:

2015-10-12 14:17:29,896 [qtp1183270535-9615283] WARN org.eclipse.jetty.servlet.ServletHandler - /rest/notifications
java.lang.IllegalArgumentException: The validated string is empty
at org.apache.commons.lang.Validate.notEmpty(Validate.java:382)
at com.pmease.quickbuild.security.SecurityHelper.authenticate(SecurityHelper.java:363)
at com.pmease.quickbuild.security.SecurityHelper.authenticate(SecurityHelper.java:603)
at com.pmease.quickbuild.rest.RestServlet.service(RestServlet.java:40)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
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:1037)
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.headerComplete(AbstractHttpConnection.java:926)
at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:988)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:635)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
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.server.ssl.SslSocketConnector$SslConnectorEndPoint.run(SslSocketConnector.java:670)
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(Thread.java:767)

5. This one is different, because I don't know the cause of this error. But I think that this one happens sporadically, so it's not crucial in this thread.

2015-10-12 14:23:36,912 [qtp1183270535-9496080] ERROR com.pmease.quickbuild.web.WicketConfig - Error handling wicket request.
org.apache.wicket.WicketRuntimeException: Method onLinkClicked of interface org.apache.wicket.markup.html.link.ILinkListener targeted at [ [Component id = deleteConfiguration]] on component [ [Component id = deleteConfiguration]] threw an exception
at org.apache.wicket.RequestListenerInterface.internalInvoke(RequestListenerInterface.java:282)
at org.apache.wicket.RequestListenerInterface.invoke(RequestListenerInterface.java:220)
at org.apache.wicket.request.handler.ListenerInterfaceRequestHandler.invokeListener(ListenerInterfaceRequestHandler.java:179)
at org.apache.wicket.request.handler.ListenerInterfaceRequestHandler.respond(ListenerInterfaceRequestHandler.java:165)
at org.apache.wicket.request.cycle.RequestCycle$HandlerExecutor.respond(RequestCycle.java:719)
at org.apache.wicket.request.RequestHandlerStack.execute(RequestHandlerStack.java:63)
at org.apache.wicket.request.cycle.RequestCycle.processRequest(RequestCycle.java:210)
at org.apache.wicket.request.cycle.RequestCycle.processRequestAndDetach(RequestCycle.java:253)
at org.apache.wicket.protocol.http.WicketFilter.processRequest(WicketFilter.java:162)
at org.apache.wicket.protocol.http.WicketServlet.doGet(WicketServlet.java:137)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:734)
at com.pmease.quickbuild.web.MainServlet.service(MainServlet.java:124)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
at org.eclipse.equinox.http.helper.FilterServletAdaptor$FilterChainImpl.doFilter(FilterServletAdaptor.java:56)
at org.eclipse.jetty.servlets.UserAgentFilter.doFilter(UserAgentFilter.java:82)
at org.eclipse.jetty.servlets.GzipFilter.doFilter(GzipFilter.java:243)
at org.eclipse.equinox.http.helper.FilterServletAdaptor.service(FilterServletAdaptor.java:37)
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:1037)
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.headerComplete(AbstractHttpConnection.java:926)
at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:988)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:635)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
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.server.ssl.SslSocketConnector$SslConnectorEndPoint.run(SslSocketConnector.java:670)
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(Thread.java:767)
Caused by: java.lang.reflect.InvocationTargetException
at sun.reflect.GeneratedMethodAccessor276.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at org.apache.wicket.RequestListenerInterface.internalInvoke(RequestListenerInterface.java:272)
... 42 more
Caused by: org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:85)
at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:70)
at org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:47)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2707)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2911)
at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:97)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:273)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:265)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:189)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1216)
at com.pmease.quickbuild.entitymanager.impl.DefaultConfigurationManager.delete(DefaultConfigurationManager.java:246)
at com.pmease.quickbuild.entitymanager.impl.DefaultConfigurationManager.delete(DefaultConfigurationManager.java:167)
at com.pmease.quickbuild.entitymanager.impl.DefaultConfigurationManager.delete(DefaultConfigurationManager.java:167)
at com.pmease.quickbuild.entitymanager.impl.DefaultConfigurationManager.delete(DefaultConfigurationManager.java:73)
at com.pmease.quickbuild.web.page.configuration.ConfigurationPage$6.onClick(ConfigurationPage.java:253)
at org.apache.wicket.markup.html.link.Link.onLinkClicked(Link.java:187)
... 46 more
robinshen ADMIN ·
Thanks for info. I filed below issue to address this:
http://track.pmease.com/browse/QB-2557
mmuszyns ·
Thank you Robin!