Supper Gluu enroll fails

By: Jelle Ruesink user 25 Sep 2017 at 9:54 a.m. CDT

7 Responses
Jelle Ruesink gravatar
Hi There, I'm trying to enroll SuperGluu with Gluu 3.1.0. At first login, i scan the QR code. My phone gives mu the option to accept. Then i get the error "Failed to get Fido U2F metadata" on my phone. In the oxauth.log the following error occurs: ``` 2017-09-25 16:46:11,585 ERROR [qtp1020391880-11] [oxauth.ws.rs.fido.u2f.U2fRegistrationWS] (U2fRegistrationWS.java:131) - Exception happened org.xdi.oxauth.model.fido.u2f.exception.BadInputException: session_id or enrollment_code is mandatory at org.xdi.oxauth.ws.rs.fido.u2f.U2fRegistrationWS.startRegistration(U2fRegistrationWS.java:100) [classes/:?] at org.xdi.oxauth.ws.rs.fido.u2f.U2fRegistrationWS$Proxy$_$$_WeldClientProxy.startRegistration(Unknown Source) [classes/:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_112] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_112] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_112] at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_112] at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:140) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:295) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:249) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:236) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:402) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:209) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:228) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [servlet-api-3.1.jar:3.1.0] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:845) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1772) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:193) [websocket-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.ocpsoft.rewrite.servlet.RewriteFilter.doFilter(RewriteFilter.java:226) [rewrite-servlet-3.4.1.Final.jar:3.4.1.Final] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.gluu.oxserver.filters.AbstractCorsFilter.handleNonCORS(AbstractCorsFilter.java:343) [oxcore-server-3.1.0.Final.jar:?] at org.gluu.oxserver.filters.AbstractCorsFilter.doFilter(AbstractCorsFilter.java:120) [oxcore-server-3.1.0.Final.jar:?] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.xdi.oxauth.audit.debug.ServletLoggingFilter.doFilter(ServletLoggingFilter.java:55) [classes/:?] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1751) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [jetty-security-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.Server.handle(Server.java:534) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283) [jetty-io-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110) [jetty-io-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [jetty-io-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112] ``` Same setup with gluu 3.0.2 is working without any problems. Any ideas? Regards, Jelle
CentOS 7.0
closed

Answers

By Jose Gonzalez staff 25 Sep 2017 at 3:56 p.m. CDT

Copy
Jose Gonzalez gravatar
Hi Jelle, To better assist you, can you confirm the following?: * You cannot authenticate using supergluu, not even enroll the device. I mean, in the "keys" tab of the app, a new entry is not being added Additionally, can you provide us with the log in TRACE level please?. To change oxauth's log level enter to the admin web interface (oxTrust) and go to `Organization` > `Json configuration` > `oxAuth configuration` and under **loggingLevel** set it to TRACE. Wait for a couple of minutes for the server to pick the change. Then do your attempt. Regards

By Jelle Ruesink user 26 Sep 2017 at 2:12 a.m. CDT

Copy
Jelle Ruesink gravatar
Hello, Thanks for your answer. Indead i cannot add my phone to my account. I enable supergluu as admin. Then I log in as a standard user and scan the QR code. The phone is trying to enroll, but gives the error "Failed to get Fido U2F metadata (Android). IOS Gives "2 Step: Authentication failed" ``` 2017-09-26 08:50:04,719 DEBUG [oxAuthScheduler_Worker-3] [org.xdi.service.timer.TimerJob] (TimerJob.java:34) - Fire timer event [org.xdi.oxauth.service.cdi.event.AuthConfigurationEvent] with qualifiers [@org.xdi.service.cdi.event.Scheduled()] 2017-09-26 08:50:04,719 DEBUG [oxAuthScheduler_Worker-3] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:62) - Bound request ended 2017-09-26 08:50:04,720 TRACE [Thread-5509] [org.xdi.oxauth.service.AppInitializer] (AppInitializer.java:256) - Attempting to use ldapEntryManager: org.gluu.site.ldap.OperationsFacade@7cff1930 2017-09-26 08:50:05,371 TRACE [qtp1020391880-19] [org.xdi.oxauth.auth.AuthenticationFilter] (AuthenticationFilter.java:88) - Get request to: 'https://my.gluuserver.com/oxauth/restv1/authorize' 2017-09-26 08:50:05,374 DEBUG [qtp1020391880-19] [xdi.oxauth.authorize.ws.rs.AuthorizeRestWebServiceImpl] (AuthorizeRestWebServiceImpl.java:159) - Attempting to request authorization: responseType = code id_token, clientId = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840, scope = openid profile email user_name, redirectUri = https://my.gluuserver.com/identity/authentication/authcode, nonce = f06c8e1c-b277-4db6-a53d-7b347838e261, state = null, request = null, isSecure = true, requestSessionId = null, sessionId = null 2017-09-26 08:50:05,375 DEBUG [qtp1020391880-19] [xdi.oxauth.authorize.ws.rs.AuthorizeRestWebServiceImpl] (AuthorizeRestWebServiceImpl.java:165) - Attempting to request authorization: acrValues = super_gluu, amrValues = null, originHeaders = null, codeChallenge = null, codeChallengeMethod = null 2017-09-26 08:50:05,375 TRACE [qtp1020391880-19] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,387 DEBUG [qtp1020391880-19] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:05,387 DEBUG [qtp1020391880-19] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:39) - Checking scopes policy for: openid profile email user_name 2017-09-26 08:50:05,388 DEBUG [qtp1020391880-19] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:59) - Granted scopes: [openid, user_name, profile, email] 2017-09-26 08:50:05,388 TRACE [qtp1020391880-19] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,388 DEBUG [qtp1020391880-19] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:05,389 DEBUG [qtp1020391880-19] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:76) - Validating redirection URI: clientIdentifier = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840, redirectionUri = https://my.gluuserver.com/identity/authentication/authcode, found = 5 2017-09-26 08:50:05,389 DEBUG [qtp1020391880-19] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://my.gluuserver.com/identity/scim/auth == https://my.gluuserver.com/identity/authentication/authcode 2017-09-26 08:50:05,389 DEBUG [qtp1020391880-19] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://my.gluuserver.com/identity/authentication/authcode == https://my.gluuserver.com/identity/authentication/authcode 2017-09-26 08:50:05,415 TRACE [qtp1020391880-10] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,416 DEBUG [qtp1020391880-10] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:05,417 TRACE [qtp1020391880-10] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:400) - Generated new session, id = '31657df0-0147-4f1f-9ec1-e8153f314baa', state = 'unauthenticated', asJwt = 'false', persisted = 'false' 2017-09-26 08:50:05,417 TRACE [qtp1020391880-10] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:456) - sessionIdAttributes: org.xdi.oxauth.model.common.SessionIdAccessMap@76490fb5 2017-09-26 08:50:05,418 TRACE [qtp1020391880-10] [xdi.oxauth.authorize.ws.rs.AuthorizeAction] (AuthorizeAction.java:258) - Session '31657df0-0147-4f1f-9ec1-e8153f314baa' persisted to LDAP 2017-09-26 08:50:05,437 DEBUG [qtp1020391880-14] [org.xdi.service.ExternalResourceHandler] (ExternalResourceHandler.java:68) - Found overriden resource: /login.xhtml 2017-09-26 08:50:05,438 DEBUG [qtp1020391880-14] [org.xdi.service.ExternalResourceHandler] (ExternalResourceHandler.java:68) - Found overriden resource: /login.xhtml 2017-09-26 08:50:05,439 DEBUG [qtp1020391880-14] [org.xdi.service.ExternalResourceHandler] (ExternalResourceHandler.java:68) - Found overriden resource: /login.xhtml 2017-09-26 08:50:05,440 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:05,440 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:05,441 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:05,441 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:05,441 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:05,442 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:05,442 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:05,442 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:05,443 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:05,443 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:05,444 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:05,444 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:05,445 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:05,445 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:05,445 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:05,475 DEBUG [qtp1020391880-14] [org.xdi.service.ExternalResourceHandler] (ExternalResourceHandler.java:68) - Found overriden resource: /login.xhtml 2017-09-26 08:50:05,484 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,484 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:05,485 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,485 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:05,494 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,495 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:05,495 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,495 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:05,496 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,496 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:05,497 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,497 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:05,498 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,498 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:05,499 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,499 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:05,506 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:05,507 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:05,507 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:05,508 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:05,508 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:05,508 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:05,509 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:05,509 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:05,509 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:05,510 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:05,510 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:05,510 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:05,511 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:05,511 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:05,511 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:05,519 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:05,519 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:05,520 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:05,520 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:05,520 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:05,521 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:05,523 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,530 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:05,531 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:05,531 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:12,767 DEBUG [qtp1020391880-11] [org.xdi.service.ExternalResourceHandler] (ExternalResourceHandler.java:68) - Found overriden resource: /login.xhtml 2017-09-26 08:50:12,768 DEBUG [qtp1020391880-11] [org.xdi.service.ExternalResourceHandler] (ExternalResourceHandler.java:68) - Found overriden resource: /login.xhtml 2017-09-26 08:50:12,781 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:12,782 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:12,782 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:12,784 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:12,784 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:12,785 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:12,796 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:12,796 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:12,797 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:12,798 TRACE [qtp1020391880-11] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:131) - Authenticating ... (interactive: true, skipPassword: false, credentials.username: jelle) 2017-09-26 08:50:12,799 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:12,799 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:12,799 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:12,810 DEBUG [qtp1020391880-11] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:136) - Authenticating user with LDAP: username: 'jelle', credentials: '639892882' 2017-09-26 08:50:12,810 DEBUG [qtp1020391880-11] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:260) - Attempting to find userDN by primary key: 'SAMAccountname' and key value: 'jelle', credentials: '639892882' 2017-09-26 08:50:12,811 DEBUG [qtp1020391880-11] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:349) - Getting user information from LDAP: attributeName = 'SAMAccountname', attributeValue = 'jelle' 2017-09-26 08:50:12,811 DEBUG [qtp1020391880-11] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:363) - Searching user by attributes: '[Attribute [name=SAMAccountname, values=[jelle]]]', baseDn: 'OU=XXXXXX,DC=YYYYYY,DC=local' 2017-09-26 08:50:12,845 DEBUG [qtp1020391880-11] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:365) - Found '1' entries 2017-09-26 08:50:12,866 DEBUG [qtp1020391880-11] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:282) - Attempting to authenticate userDN: CN=jelle Ruesink,OU=GPO Test OU,OU=Gebruikers,OU=XXXXXX,DC=YYYYYY,DC=local 2017-09-26 08:50:12,879 DEBUG [qtp1020391880-11] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:284) - User authenticated: CN=jelle Ruesink,OU=GPO Test OU,OU=Gebruikers,OU=XXXXXX,DC=YYYYYY,DC=local 2017-09-26 08:50:12,880 DEBUG [qtp1020391880-11] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:286) - Attempting to find userDN by local primary key: uid 2017-09-26 08:50:12,880 DEBUG [qtp1020391880-11] [org.xdi.oxauth.service.UserService] (UserService.java:182) - Getting user information from LDAP: attributeName = 'uid', attributeValue = 'jelle' 2017-09-26 08:50:12,892 DEBUG [qtp1020391880-11] [org.xdi.oxauth.service.UserService] (UserService.java:193) - Found '1' entries 2017-09-26 08:50:12,909 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:296) - authenticate_external: credentials: '639892882', credentials.userName: 'jelle', authenticatedUser.userId: 'jelle' 2017-09-26 08:50:12,910 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:12,910 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:12,910 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:12,911 DEBUG [qtp1020391880-11] [org.xdi.oxauth.service.UserService] (UserService.java:84) - Getting user information from LDAP: userId = jelle 2017-09-26 08:50:12,923 DEBUG [qtp1020391880-11] [org.xdi.oxauth.service.UserService] (UserService.java:93) - Found 1 entries for user id = jelle 2017-09-26 08:50:12,929 DEBUG [qtp1020391880-11] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:251) - Authentication result for user 'jelle'. auth_step: '1', result: 'true', credentials: '639892882' 2017-09-26 08:50:12,929 TRACE [qtp1020391880-11] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:258) - According to API version script supports steps overriding 2017-09-26 08:50:12,930 DEBUG [qtp1020391880-11] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:261) - Get next step from script: '2' 2017-09-26 08:50:12,934 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:12,935 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:12,935 TRACE [qtp1020391880-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:12,936 TRACE [qtp1020391880-11] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:327) - Redirect to page: '/auth/super-gluu/login.xhtml' 2017-09-26 08:50:12,937 TRACE [qtp1020391880-11] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:149) - Authentication successfully for 'jelle' 2017-09-26 08:50:12,954 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:12,954 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:12,955 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:12,973 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:12,973 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:12,973 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:12,974 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.UserService] (UserService.java:84) - Getting user information from LDAP: userId = jelle 2017-09-26 08:50:12,991 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.UserService] (UserService.java:93) - Found 1 entries for user id = jelle 2017-09-26 08:50:12,992 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:13,071 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:13,072 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:13,073 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:13,073 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:13,075 TRACE [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:195) - Get client from cache by Dn 'inum=@!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840,ou=clients,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu' 2017-09-26 08:50:13,075 DEBUG [qtp1020391880-14] [org.xdi.oxauth.service.ClientService] (ClientService.java:137) - Found 1 entries for client id = @!52E4.5193.C518.98D4!0001!6552.A9E5!0008!E863.3840 2017-09-26 08:50:13,497 TRACE [qtp1020391880-12] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:13,498 DEBUG [qtp1020391880-12] [xdi.oxauth.session.ws.rs.CheckSessionStatusRestWebServiceImpl] (CheckSessionStatusRestWebServiceImpl.java:67) - Found session 'session_id' cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:13,498 TRACE [qtp1020391880-12] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:13,498 TRACE [qtp1020391880-12] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:13,505 DEBUG [qtp1020391880-12] [xdi.oxauth.session.ws.rs.CheckSessionStatusRestWebServiceImpl] (CheckSessionStatusRestWebServiceImpl.java:83) - Check session status response: '{"state":"unauthenticated","custom_state":"","auth_time":1506408605417}' 2017-09-26 08:50:18,532 TRACE [qtp1020391880-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:18,532 DEBUG [qtp1020391880-15] [xdi.oxauth.session.ws.rs.CheckSessionStatusRestWebServiceImpl] (CheckSessionStatusRestWebServiceImpl.java:67) - Found session 'session_id' cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:18,532 TRACE [qtp1020391880-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:18,533 TRACE [qtp1020391880-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:18,534 DEBUG [qtp1020391880-15] [xdi.oxauth.session.ws.rs.CheckSessionStatusRestWebServiceImpl] (CheckSessionStatusRestWebServiceImpl.java:83) - Check session status response: '{"state":"unauthenticated","custom_state":"","auth_time":1506408605417}' 2017-09-26 08:50:22,557 TRACE [qtp1020391880-17] [oxauth.ws.rs.fido.u2f.U2fConfigurationWS] (U2fConfigurationWS.java:65) - FIDO U2F configuration: { "version" : "2.0", "issuer" : "https://my.gluuserver.com", "registration_endpoint" : "https://my.gluuserver.com/oxauth/restv1/fido/u2f/registration", "authentication_endpoint" : "https://my.gluuserver.com/oxauth/restv1/fido/u2f/authentication" } 2017-09-26 08:50:22,580 DEBUG [qtp1020391880-17] [oxauth.ws.rs.fido.u2f.U2fRegistrationWS] (U2fRegistrationWS.java:79) - Startig registration with username 'jelle' for appId 'https://my.gluuserver.com/identity/authentication/authcode'. session_id 'null', enrollment_code 'null' 2017-09-26 08:50:22,581 ERROR [qtp1020391880-17] [oxauth.ws.rs.fido.u2f.U2fRegistrationWS] (U2fRegistrationWS.java:131) - Exception happened org.xdi.oxauth.model.fido.u2f.exception.BadInputException: session_id or enrollment_code is mandatory at org.xdi.oxauth.ws.rs.fido.u2f.U2fRegistrationWS.startRegistration(U2fRegistrationWS.java:100) [classes/:?] at org.xdi.oxauth.ws.rs.fido.u2f.U2fRegistrationWS$Proxy$_$$_WeldClientProxy.startRegistration(Unknown Source) [classes/:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_112] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_112] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_112] at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_112] at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:140) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:295) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:249) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:236) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:402) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:209) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:228) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51) [resteasy-jaxrs-3.0.21.Final.jar:3.0.21.Final] at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [servlet-api-3.1.jar:3.1.0] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:845) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1772) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:193) [websocket-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.ocpsoft.rewrite.servlet.RewriteFilter.doFilter(RewriteFilter.java:226) [rewrite-servlet-3.4.1.Final.jar:3.4.1.Final] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.gluu.oxserver.filters.AbstractCorsFilter.handleNonCORS(AbstractCorsFilter.java:343) [oxcore-server-3.1.0.Final.jar:?] at org.gluu.oxserver.filters.AbstractCorsFilter.doFilter(AbstractCorsFilter.java:120) [oxcore-server-3.1.0.Final.jar:?] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.xdi.oxauth.audit.debug.ServletLoggingFilter.doFilter(ServletLoggingFilter.java:55) [classes/:?] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1751) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [jetty-security-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.Server.handle(Server.java:534) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283) [jetty-io-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110) [jetty-io-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [jetty-io-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112] 2017-09-26 08:50:22,583 DEBUG [qtp1020391880-17] [org.xdi.oxauth.model.error.ErrorResponseFactory] (ErrorResponseFactory.java:70) - Looking for the error with id: server_error 2017-09-26 08:50:22,584 DEBUG [qtp1020391880-17] [org.xdi.oxauth.model.error.ErrorResponseFactory] (ErrorResponseFactory.java:75) - Found error, id: server_error 2017-09-26 08:50:23,557 TRACE [qtp1020391880-12] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:223) - Found session_id cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:23,557 DEBUG [qtp1020391880-12] [xdi.oxauth.session.ws.rs.CheckSessionStatusRestWebServiceImpl] (CheckSessionStatusRestWebServiceImpl.java:67) - Found session 'session_id' cookie: '31657df0-0147-4f1f-9ec1-e8153f314baa' 2017-09-26 08:50:23,558 TRACE [qtp1020391880-12] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:600) - Try to get session by id: 31657df0-0147-4f1f-9ec1-e8153f314baa ... 2017-09-26 08:50:23,558 TRACE [qtp1020391880-12] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:602) - Session dn: oxAuthSessionId=31657df0-0147-4f1f-9ec1-e8153f314baa,ou=session,o=@!52E4.5193.C518.98D4!0001!6552.A9E5,o=gluu 2017-09-26 08:50:23,559 DEBUG [qtp1020391880-12] [xdi.oxauth.session.ws.rs.CheckSessionStatusRestWebServiceImpl] (CheckSessionStatusRestWebServiceImpl.java:83) - Check session status response: '{"state":"unauthenticated","custom_state":"","auth_time":1506408605417}' 2017-09-26 08:50:23,720 DEBUG [oxAuthScheduler_Worker-4] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:52) - Bound request started 2017-09-26 08:50:23,720 DEBUG [oxAuthScheduler_Worker-4] [org.xdi.service.timer.TimerJob] (TimerJob.java:34) - Fire timer event [org.xdi.service.cdi.event.UpdateScriptEvent] with qualifiers [@org.xdi.service.cdi.event.Scheduled()] 2017-09-26 08:50:23,749 DEBUG [oxAuthScheduler_Worker-4] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:62) - Bound request ended ``` Regards, Jelle

By Jose Gonzalez staff 26 Sep 2017 at 7:01 a.m. CDT

Copy
Jose Gonzalez gravatar
Thanks for the extra info. You are facing this problem (that stems from the `session_id` being 'null') because current super gluu does not support a newer feature added in the FIDO service implementation for 3.1.0. We had planned releasing Gluu Server 3.1.0 and updating super gluu in the mobile markets at the same time, however, the release of the newer app is delayed for some inconvenience in the publishing process at stores. We are striving for having supergluu update delivered ASAP. It should not take more than one week. I will let you know once it's ready. We apologize for the inconvenience this may cause you. Regards.

By Jelle Ruesink user 26 Sep 2017 at 7:14 a.m. CDT

Copy
Jelle Ruesink gravatar
Hi Jose, Thanks for your reply. Will the new version also be based on the oxpush3 client? https://github.com/GluuFederation/oxPush3 I've tried compiling the android app, and i am facing the same issue with that code. Ore is the new code not committed yet? Regards, Jelle

By Jose Gonzalez staff 26 Sep 2017 at 2:14 p.m. CDT

Copy
Jose Gonzalez gravatar
Jelle, Changes in public oxPush3 repo will be available once supergluu is released.

By Jose Gonzalez staff 11 Oct 2017 at 9:15 a.m. CDT

Copy
Jose Gonzalez gravatar
Jelle, The new version of supergluu is now available at stores. We are sorry for the inconvenience this delay has caused in your organization. oxPush3 repo is in process of update. Kind regards, Jose.

By Jelle Ruesink user 01 Nov 2017 at 9:23 a.m. CDT

Copy
Jelle Ruesink gravatar
Hi Jose, I still see old code on Github regarding oxpush. Is it possible to put the new code in the repository? Kind regards

Post an answer