scheduling icon indicating copy to clipboard operation
scheduling copied to clipboard
verified publisher icon ow2-proactive

"You should log on first" error, when using proactive-client after a scheduler restart

Open fviale opened this issue 10 years ago • 4 comments

It does not occur each time but occurs quite often. When trying to use the proactive-client command to submit job after a scheduler restart, the following error occurs :

[2015-12-08 18:50:43,259 WARN o.e.j.s.ServletHandler] /rest/scheduler/status org.jboss.resteasy.spi.UnhandledException: org.ow2.proactive_grid_cloud_portal.scheduler.exception.NotConnectedRestException: You are not connected to the scheduler, you should log on first at org.jboss.resteasy.core.ExceptionHandler.handleApplicationException(ExceptionHandler.java:76) at org.jboss.resteasy.core.ExceptionHandler.handleException(ExceptionHandler.java:212) at org.jboss.resteasy.core.SynchronousDispatcher.writeException(SynchronousDispatcher.java:165) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:392) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:199) at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:221) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51) at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:808) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:587) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:52) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) at org.eclipse.jetty.server.Server.handle(Server.java:499) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257) at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555) at java.lang.Thread.run(Thread.java:745) Caused by: org.ow2.proactive_grid_cloud_portal.scheduler.exception.NotConnectedRestException: You are not connected to the scheduler, you should log on first at org.ow2.proactive_grid_cloud_portal.scheduler.SchedulerStateRest.checkAccess(SchedulerStateRest.java:1944) at org.ow2.proactive_grid_cloud_portal.scheduler.SchedulerStateRest.getSchedulerStatus(SchedulerStateRest.java:2646) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:139) at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:295) at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:249) at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:236) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:376) ... 24 more

Retrying does not solve the problem. Only restarting the scheduler again, and I need often 3-4 restarts before it passes.

fviale avatar Dec 08 '15 17:12 fviale

The issue seems related to the fact that the workflow-catalog connects to the scheduler and, maybe concurrently, an other connection is made using the proactive-client CLI. Both Workflow-catalog and CLI use the same user. By changing the username, the issue seems to disappear.

fviale avatar Dec 09 '15 14:12 fviale

The scheduler server dump stack does not show any special hanged stack

stack.txt

fviale avatar Dec 17 '15 13:12 fviale

Even if I try to print the job list with a command like the following I get the same problem:

[root@frrdski02d ~]# /opt/proactive/default/bin/proactive-client -lj -X -u https://frrdski02d.rd.loreal:9900/rest -X -ca /opt/proactive/default/config/web/truststore.ts -cap activeeon
An error occurred while retrieving job list:
Error Message: HTTP 500 Internal Server Error
Stack Track: javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error
        at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.handleErrorStatus(ClientInvocation.java:189)
        at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.extractResult(ClientInvocation.java:154)
        at org.jboss.resteasy.client.jaxrs.internal.proxy.extractors.BodyEntityExtractor.extractEntity(BodyEntityExtractor.java:58)
        at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invoke(ClientInvoker.java:104)
        at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientProxy.invoke(ClientProxy.java:62)
        at com.sun.proxy.$Proxy30.revisionAndjobsinfo(Unknown Source)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:497)
        at org.ow2.proactive_grid_cloud_portal.scheduler.client.SchedulerRestClient$RestClientExceptionHandler.invoke(SchedulerRestClient.java:488)
        at com.sun.proxy.$Proxy30.revisionAndjobsinfo(Unknown Source)
        at org.ow2.proactive_grid_cloud_portal.cli.cmd.sched.ListJobCommand.printJobsList(ListJobCommand.java:138)
        at org.ow2.proactive_grid_cloud_portal.cli.cmd.sched.ListJobCommand.execute(ListJobCommand.java:100)
        at org.ow2.proactive_grid_cloud_portal.cli.EntryPoint.executeCommandList(EntryPoint.java:156)
        at org.ow2.proactive_grid_cloud_portal.cli.EntryPoint.run(EntryPoint.java:119)
        at org.ow2.proactive_grid_cloud_portal.cli.CommonEntryPoint.main(CommonEntryPoint.java:51)

The Scheduler logs shows the same stack trace as described above:

[2015-12-17 15:17:35,156 WARN          o.e.j.s.ServletHandler] /rest/scheduler/revisionjobsinfo
org.jboss.resteasy.spi.UnhandledException: org.ow2.proactive_grid_cloud_portal.scheduler.exception.NotConnectedRestException: You are not connected to the scheduler,              you should log on first
        at org.jboss.resteasy.core.ExceptionHandler.handleApplicationException(ExceptionHandler.java:76)
        at org.jboss.resteasy.core.ExceptionHandler.handleException(ExceptionHandler.java:212)
        at org.jboss.resteasy.core.SynchronousDispatcher.writeException(SynchronousDispatcher.java:149)
        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:372)
        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:179)
        at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:220)
        at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
        at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:770)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:684)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:503)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:557)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1086)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:429)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1020)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
        at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:52)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
        at org.eclipse.jetty.server.Server.handle(Server.java:370)
        at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:494)
        at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:971)
        at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:1033)
        at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:644)
        at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
        at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
        at org.eclipse.jetty.io.nio.SslConnection.handle(SslConnection.java:196)
        at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:696)
        at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:53)
        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:745)
Caused by: org.ow2.proactive_grid_cloud_portal.scheduler.exception.NotConnectedRestException: You are not connected to the scheduler, you should log on first
        at org.ow2.proactive_grid_cloud_portal.scheduler.SchedulerStateRest.checkAccess(SchedulerStateRest.java:1335)
        at org.ow2.proactive_grid_cloud_portal.scheduler.SchedulerStateRest.revisionAndjobsinfo(SchedulerStateRest.java:291)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:497)
        at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:137)
        at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:280)
        at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:234)
        at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:221)
        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:356)
        ... 30 more

fviale avatar Dec 17 '15 13:12 fviale

The workaround was to regenerate the session id using the rest API. and then to use this id in the command line.

laurentpellegrino avatar Feb 01 '16 14:02 laurentpellegrino