NPE when requesting authorization with acr param

[qbert2k]

I am getting a NPE with a certification test, to reproduce it:

1. Go to https://op.certification.openid.net:60877/
2. Look for test (OP-Req-acr_values)
3. Run it and check the log of ce-dev3

2017-09-19 21:50:34,863 INFO [qtp370869802-20] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:127) - Acr is changed. Session acr: basic(level: 100), current acr: basic auth_ldap_server(level: null)
2017-09-19 21:50:34,868 ERROR [qtp370869802-20] [xdi.oxauth.authorize.ws.rs.AuthorizeRestWebServiceImpl] (AuthorizeRestWebServiceImpl.java:643) - null
java.lang.NullPointerException: null
at org.xdi.oxauth.service.SessionIdService.assertAuthenticatedSessionCorrespondsToNewRequest(SessionIdService.java:129) ~[classes/:?]
at org.xdi.oxauth.authorize.ws.rs.AuthorizeRestWebServiceImpl.requestAuthorization(AuthorizeRestWebServiceImpl.java:191) [classes/:?]
at org.xdi.oxauth.authorize.ws.rs.AuthorizeRestWebServiceImpl.requestAuthorizationGet(AuthorizeRestWebServiceImpl.java:124) [classes/:?]
at org.xdi.oxauth.authorize.ws.rs.AuthorizeRestWebServiceImpl$Proxy$_$$_WeldClientProxy.requestAuthorizationGet(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.xdi.oxauth.auth.AuthenticationFilter.processSessionAuth(AuthenticationFilter.java:157) [classes/:?]
at org.xdi.oxauth.auth.AuthenticationFilter.doFilter(AuthenticationFilter.java:135) [classes/:?]
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.1-SNAPSHOT.jar:?]
at org.gluu.oxserver.filters.AbstractCorsFilter.doFilter(AbstractCorsFilter.java:120) [oxcore-server-3.1.1-SNAPSHOT.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]

[yuriyz]

@qbert2k I wonder why we got failure here. Is it somehow related to your latest session_state changes?

[jgomer2001]

@qbert2k I think I have seen this one before (one month ago)... when you are starting with an acr, and then switch to another whose level value is lower than the value of the former. Isn't that behaviour correct?

[qbert2k]

Thanks for your feedback, I am debugging it.