[OPENAM-15668] AM withholds NullPointerException during authentication - troubleshooting difficult Created: 12/Nov/19  Updated: 18/Nov/19

Status: Open
Project: OpenAM
Component/s: authentication
Affects Version/s: 13.5.0, 13.5.1, 13.5.2, 14.0.0, 14.1.0, 14.1.1, 14.5.0, 14.5.1, 5.5.1, 14.1.1.1, 14.1.1.2, 14.1.1.3, 6.0.0, 6.0.0.1, 6.0.0.2, 6.0.0.3, 6.0.0.4, 14.1.1.4, 6.0.0.5, 14.1.1.5, 14.1.2.2, 6.5.0, 6.0.0.6, 6.5.0.1, 6.0.0.7, 14.1.2.3, 6.5.1, 6.5.0.2, 14.1.2.4, 6.5.2, 6.5.2.1, 6.5.2.2, 14.1.2.5, 14.1.2.11
Fix Version/s: None

Type: Bug Priority: Major
Reporter: Bernhard Thalmayr Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: EDISON
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Relates
relates to OPENAM-15669 NullPointerException in IdCachedServi... Open
relates to OPENAM-15670 DeviceIdSave auth module initializati... Resolved
Rank: 1|hzzfh3:
Support Ticket IDs:

 Description   

Bug description

During authentication AM withholds NullPointerExceptions. This makes troubleshooting very hard or even impossible

How to reproduce the issue

  1. Configure AM
  2. Configure the below mentioned auth-chain in some sub-realm
  3. Perform service based authentication
AuthnChain
[name=Certificate] [flag=OPTIONAL] [options=]
[name=DeviceMatch] [flag=SUFFICIENT] [options=]
[name=OTP] [flag=OPTIONAL] [options=]
[name=DeviceSave] [flag=SUFFICIENT] [options=]
[name=LDAP] [flag=REQUISITE] [options=]
[name=DeviceMatch] [flag=SUFFICIENT] [options=]
[name=OTP] [flag=REQUIRED] [options=]
[name=DeviceSave] [flag=REQUIRED] [options=]
Expected behaviour
NullPointerException in com.sun.identity.idm.server.IdCachedServicesImpl.search should be seen in logs
Current behaviour
No NPE shows up in any log, user has to provide credentials for LDAP auth twice.
[~/AM-Deployments/am6006/am/debug]$grep Null *
[~/AM-Deployments/am6006/am/debug]$
actual exception
java.lang.NullPointerException
	at com.sun.identity.idm.server.IdCachedServicesImpl.search(IdCachedServicesImpl.java:574)
	at com.sun.identity.idm.AMIdentityRepository.searchIdentities(AMIdentityRepository.java:380)
	at com.sun.identity.idm.AMIdentityRepository.searchIdentities(AMIdentityRepository.java:312)
	at com.sun.identity.idm.IdUtils.getIdentity(IdUtils.java:510)
	at org.forgerock.openam.authentication.modules.deviceprint.DeviceIdSave.init(DeviceIdSave.java:78)
	at com.sun.identity.authentication.spi.AMLoginModule.initialize(AMLoginModule.java:996)
	at sun.reflect.GeneratedMethodAccessor81.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.identity.authentication.jaas.LoginContext.invoke(LoginContext.java:210)
	at com.sun.identity.authentication.jaas.LoginContext.login(LoginContext.java:127)
	at com.sun.identity.authentication.service.AMLoginContext.runLogin(AMLoginContext.java:511)
	at com.sun.identity.authentication.server.AuthContextLocal.submitRequirements(AuthContextLocal.java:586)
	at org.forgerock.openam.core.rest.authn.core.wrappers.AuthContextLocalWrapper.submitRequirements(AuthContextLocalWrapper.java:108)
	at org.forgerock.openam.core.rest.authn.core.LoginProcess.next(LoginProcess.java:168)
	at org.forgerock.openam.core.rest.authn.RestAuthenticationHandler.processAuthentication(RestAuthenticationHandler.java:415)
	at org.forgerock.openam.core.rest.authn.RestAuthenticationHandler.processAuthentication(RestAuthenticationHandler.java:416)
	at org.forgerock.openam.core.rest.authn.RestAuthenticationHandler.authenticate(RestAuthenticationHandler.java:209)
	at org.forgerock.openam.core.rest.authn.http.AuthenticationServiceV1.authenticate(AuthenticationServiceV1.java:163)
	at sun.reflect.GeneratedMethodAccessor83.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.forgerock.openam.http.annotations.AnnotatedMethod.invoke(AnnotatedMethod.java:76)
	at org.forgerock.openam.http.annotations.Endpoints$1.handle(Endpoints.java:64)
	at org.forgerock.http.routing.Router.handle(Router.java:100)
	at org.forgerock.openam.audit.AbstractHttpAccessAuditFilter.filter(AbstractHttpAccessAuditFilter.java:59)
	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
	at org.forgerock.http.routing.Router.handle(Router.java:100)
	at org.forgerock.openam.rest.RealmContextFilter.filter(RealmContextFilter.java:80)
	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
	at org.forgerock.http.routing.Router.handle(Router.java:100)
	at org.forgerock.http.routing.Router.handle(Router.java:100)
	at org.forgerock.openam.rest.RealmRoutingFactory$ChfRealmRouter.handle(RealmRoutingFactory.java:140)
	at org.forgerock.http.routing.Router.handle(Router.java:100)
	at org.forgerock.openam.rest.RealmRoutingFactory$ChfRealmRouter.handle(RealmRoutingFactory.java:140)
	at org.forgerock.http.handler.Handlers$UndescribedAsDescribableHandler.handle(Handlers.java:179)
	at org.forgerock.openam.rest.RealmRoutingFactory$HostnameFilter.filter(RealmRoutingFactory.java:117)
	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
	at org.forgerock.http.routing.Router.handle(Router.java:100)
	at org.forgerock.http.routing.Router.handle(Router.java:100)
	at org.forgerock.openam.rest.CsrfFilter.filter(CsrfFilter.java:95)
	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
	at org.forgerock.http.routing.ResourceApiVersionRoutingFilter.filter(ResourceApiVersionRoutingFilter.java:59)
	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
	at org.forgerock.caf.authentication.framework.AuthenticationFramework.grantAccess(AuthenticationFramework.java:188)
	at org.forgerock.caf.authentication.framework.AuthenticationFramework.lambda$onValidateRequestSuccess$1(AuthenticationFramework.java:181)
	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:252)
	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:241)
	at org.forgerock.caf.authentication.framework.AuthenticationFramework.validateRequest(AuthenticationFramework.java:144)
	at org.forgerock.caf.authentication.framework.AuthenticationFramework.processMessage(AuthenticationFramework.java:134)
	at org.forgerock.caf.authentication.framework.AuthenticationFilter.filter(AuthenticationFilter.java:84)
	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
	at org.forgerock.openam.http.GuiceHandler.handle(GuiceHandler.java:51)
	at org.forgerock.openam.http.HttpRoute$6.handle(HttpRoute.java:206)
	at org.forgerock.http.routing.Router.handle(Router.java:100)
	at org.forgerock.openam.dpro.session.ProofOfPossessionTokenFilter.filter(ProofOfPossessionTokenFilter.java:88)
	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
	at org.forgerock.http.swagger.OpenApiRequestFilter.filter(OpenApiRequestFilter.java:63)
	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
	at org.forgerock.openam.http.ApiDescriptorFilter.filter(ApiDescriptorFilter.java:139)
	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
	at org.forgerock.openam.http.OpenAMHttpApplication$1.filter(OpenAMHttpApplication.java:74)
	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
	at org.forgerock.http.filter.TransactionIdInboundFilter.filter(TransactionIdInboundFilter.java:75)
	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
	at org.forgerock.http.servlet.HttpFrameworkServlet.service(HttpFrameworkServlet.java:254)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.forgerock.openam.rest.ProtocolVersionFilter.doFilter(ProtocolVersionFilter.java:65)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.forgerock.openam.validation.ResponseValidationFilter.doFilter(ResponseValidationFilter.java:59)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.forgerock.openam.headers.SetHeadersFilter.doFilter(SetHeadersFilter.java:80)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at com.sun.identity.setup.AMSetupFilter.doFilter(AMSetupFilter.java:115)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.forgerock.openam.audit.context.AuditContextFilter.doFilter(AuditContextFilter.java:46)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:494)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:651)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:412)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:754)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1385)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)

Code analysis

com.sun.identity.authentication.jaas.LoginContext.java
...
  private void invoke(String methodName) throws LoginException {
...
            } catch (InvocationTargetException ite) {

                if (ite.getTargetException() instanceof Error) {
                    if (debug.messageEnabled()) {
                        debug.message("LoginContext.invoke(): Handling expected java.lang.Error");
                    }
                    throw (Error)ite.getTargetException();
                }
...


 Comments   
Comment by Andy Hall [ 13/Nov/19 ]

Bernhard Thalmayr  Confused - where did the exception above come from if we don't log one?

 

Generated at Thu Apr 22 20:26:42 UTC 2021 using Jira 8.16.0#816000-sha1:a455b91378454416b49bbc88d03e653cb9815ed5.