Uploaded image for project: 'OpenICF'
  1. OpenICF
  2. OPENICF-1223

LDAP Connector: AD/AD LDS query id with sortKeys called after query id with invalid cookie returns code 500

    Details

      Description

      Found in regression tests where query with sortKeys returns HTTP 500 when called right after query with invalid pagedResultsCookie.

      Steps to reproduce

      1. Install IDM
      2. Setup AD/AD LDS and create 10 users
      3. Setup ICF provisioner to be able to connect to AD/AD LDS
      4. Start IDM with extended ICF logging for LDAP (conf/logging.properties)
        org.identityconnectors.ldap.level = FINER
        
      5. Run query with invalid cookie
        curl --header "X-OpenIDM-Username: openidm-admin" --header "X-OpenIDM-Password: openidm-admin"  --request GET "http://localhost:8080/openidm/system/ldap/account/?_queryId=query-all-ids&_sortKeys=description&_pageSize=5&_pagedResultsCookie=invalid"
        

        Response HTTP 500 as expected

      6. Run query any with sortkeys
        curl --header "X-OpenIDM-Username: openidm-admin" --header "X-OpenIDM-Password: openidm-admin"  --request GET "http://localhost:8080/openidm/system/ldap/account?_queryId=query-all-ids&_sortKeys=description"
        

        Returns HTTP 500 but we are expecting to get HTTP 200 and retrieved results
        IDM log contains HTTP 500 and LDAP error

        [285] Dec 03, 2019 12:19:40.547 PM org.identityconnectors.ldap.LdapConnector executeQuery
        FINE: Simple Paged Search Strategy used for search operation	Method: getSearchStrategy
        [285] Dec 03, 2019 12:19:40.547 PM org.identityconnectors.ldap.search.LdapInternalSearch execute
        FINE: Searching in [OU=RobotTests2019_12_03_12_18_33,DC=testing] with filter (&(objectClass=top)(objectClass=person)(objectClass=organizationalPerson)(objectClass=user)) and SearchControls: {returningAttributes=[ms-DS-UserAccountAutoLocked, msDS-User-Account-Control-Computed, msDS-UserAccountDisabled, msDS-UserPasswordExpired, objectGUID, userAccountControl], scope=SUBTREE}	Method: doSearch
        [163] Dec 03, 2019 12:19:40.610 PM org.forgerock.openidm.servlet.internal.ResourceFilters$3 lambda$handleRequestWithLogging$8
        WARNING: Resource exception: 500 Internal Server Error: "Operation QUERY failed with ConnectorException on system object"
        org.forgerock.json.resource.InternalServerErrorException: Operation QUERY failed with ConnectorException on system object
        	at org.forgerock.openidm.provisioner.openicf.impl.ExceptionHelper.adaptConnectorException(ExceptionHelper.java:152)
        	at org.forgerock.openidm.provisioner.openicf.impl.ObjectClassResourceProvider.handleQuery(ObjectClassResourceProvider.java:520)
        	at org.forgerock.openidm.provisioner.openicf.impl.ObjectClassRequestHandler.handleQuery(ObjectClassRequestHandler.java:132)
        	at org.forgerock.json.resource.Router.handleQuery(Router.java:317)
        	at org.forgerock.json.resource.FilterChain$Cursor.handleQuery(FilterChain.java:94)
        	at org.forgerock.json.resource.ResourceApiVersionRoutingFilter.filterQuery(ResourceApiVersionRoutingFilter.java:71)
        	at org.forgerock.json.resource.FilterChain$Cursor.handleQuery(FilterChain.java:92)
        	at org.forgerock.json.resource.FilterChain.handleQuery(FilterChain.java:249)
        	at org.forgerock.json.resource.Router.handleQuery(Router.java:317)
        	at org.forgerock.json.resource.FilterChain$Cursor.handleQuery(FilterChain.java:94)
        	at org.forgerock.json.resource.Filters$ConditionalFilter.filterQuery(Filters.java:84)
        	at org.forgerock.json.resource.Filters$ConditionalFilter.filterQuery(Filters.java:82)
        	at org.forgerock.json.resource.FilterChain$Cursor.handleQuery(FilterChain.java:92)
        	at org.forgerock.json.resource.Filters$ConditionalFilter.filterQuery(Filters.java:84)
        	at org.forgerock.json.resource.FilterChain$Cursor.handleQuery(FilterChain.java:92)
        	at org.forgerock.openidm.authz.DelegatedAdminFilter.lambda$filterQuery$6(DelegatedAdminFilter.java:278)
        	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:263)
        	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:227)
        	at org.forgerock.openidm.authz.DelegatedAdminFilter.filterRequest(DelegatedAdminFilter.java:297)
        	at org.forgerock.openidm.authz.DelegatedAdminFilter.filterQuery(DelegatedAdminFilter.java:277)
        	at org.forgerock.json.resource.Filters$ConditionalFilter.filterQuery(Filters.java:82)
        	at org.forgerock.json.resource.FilterChain$Cursor.handleQuery(FilterChain.java:92)
        	at org.forgerock.openidm.audit.filter.AuditFilter.lambda$filterQuery$4(AuditFilter.java:139)
        	at org.forgerock.openidm.audit.filter.AuditFilter.logAuditAccessEntry(AuditFilter.java:171)
        	at org.forgerock.openidm.audit.filter.AuditFilter.filterQuery(AuditFilter.java:139)
        	at org.forgerock.openidm.router.filter.MutableFilterDecorator.filterQuery(MutableFilterDecorator.java:90)
        	at org.forgerock.json.resource.Filters$ConditionalFilter.filterQuery(Filters.java:82)
        	at org.forgerock.json.resource.FilterChain$Cursor.handleQuery(FilterChain.java:92)
        	at org.forgerock.openidm.servlet.internal.ResourceFilters$3.lambda$filterQuery$4(ResourceFilters.java:194)
        	at org.forgerock.openidm.servlet.internal.ResourceFilters$3.handleRequestWithLogging(ResourceFilters.java:222)
        	at org.forgerock.openidm.servlet.internal.ResourceFilters$3.filterQuery(ResourceFilters.java:194)
        	at org.forgerock.json.resource.FilterChain$Cursor.handleQuery(FilterChain.java:92)
        	at org.forgerock.openidm.filter.QueryIdToQueryFilterTransformFilter.lambda$filterQuery$3(QueryIdToQueryFilterTransformFilter.java:199)
        	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:263)
        	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:227)
        	at org.forgerock.openidm.filter.QueryIdToQueryFilterTransformFilter.filterQuery(QueryIdToQueryFilterTransformFilter.java:199)
        	at org.forgerock.json.resource.FilterChain$Cursor.handleQuery(FilterChain.java:92)
        	at org.forgerock.openidm.router.filter.PassthroughFilter.filterQuery(PassthroughFilter.java:66)
        	at org.forgerock.openidm.router.filter.MutableFilterDecorator.filterQuery(MutableFilterDecorator.java:90)
        	at org.forgerock.openidm.router.filter.MutableFilterDecorator.filterQuery(MutableFilterDecorator.java:90)
        	at org.forgerock.json.resource.FilterChain$Cursor.handleQuery(FilterChain.java:92)
        	at org.forgerock.openidm.router.filter.PassthroughFilter.filterQuery(PassthroughFilter.java:66)
        	at org.forgerock.openidm.router.filter.MutableFilterDecorator.filterQuery(MutableFilterDecorator.java:90)
        	at org.forgerock.json.resource.Filters$ConditionalFilter.filterQuery(Filters.java:82)
        	at org.forgerock.json.resource.FilterChain$Cursor.handleQuery(FilterChain.java:92)
        	at org.forgerock.openidm.servlet.internal.ResourceFilters$2.filterQuery(ResourceFilters.java:119)
        	at org.forgerock.json.resource.Filters$ConditionalFilter.filterQuery(Filters.java:82)
        	at org.forgerock.json.resource.FilterChain$Cursor.handleQuery(FilterChain.java:92)
        	at org.forgerock.json.resource.FilterChain.handleQuery(FilterChain.java:249)
        	at org.forgerock.json.resource.InternalConnection.queryAsync(InternalConnection.java:74)
        	at org.forgerock.json.resource.AbstractConnectionWrapper.queryAsync(AbstractConnectionWrapper.java:185)
        	at org.forgerock.openidm.servlet.internal.ServletConnectionFactory$InternalConnectionWrapper.lambda$queryAsync$13(ServletConnectionFactory.java:335)
        	at org.forgerock.openidm.metrics.MetricsCollector.time(MetricsCollector.java:112)
        	at org.forgerock.openidm.servlet.internal.ServletConnectionFactory$InternalConnectionWrapper.time(ServletConnectionFactory.java:257)
        	at org.forgerock.openidm.servlet.internal.ServletConnectionFactory$InternalConnectionWrapper.queryAsync(ServletConnectionFactory.java:334)
        	at org.forgerock.json.resource.http.RequestRunner.visitQueryRequest(RequestRunner.java:214)
        	at org.forgerock.json.resource.http.RequestRunner.visitQueryRequest(RequestRunner.java:85)
        	at org.forgerock.json.resource.Requests$QueryRequestImpl.accept(Requests.java:444)
        	at org.forgerock.json.resource.http.RequestRunner.handleResult(RequestRunner.java:137)
        	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:263)
        	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:252)
        	at org.forgerock.json.resource.http.HttpAdapter.doRequest(HttpAdapter.java:744)
        	at org.forgerock.json.resource.http.HttpAdapter.doQuery(HttpAdapter.java:503)
        	at org.forgerock.json.resource.http.HttpAdapter.handle(HttpAdapter.java:312)
        	at org.forgerock.http.handler.Handlers$HandlerDescribableAsDescribableHandler.handle(Handlers.java:146)
        	at org.forgerock.http.filter.OptionsFilter.filter(OptionsFilter.java:69)
        	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.openidm.auth.ProfileEnhancementCheckFilter.filter(ProfileEnhancementCheckFilter.java:145)
        	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
        	at org.forgerock.openidm.auth.LoginCountFilter.filter(LoginCountFilter.java:75)
        	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:263)
        	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:252)
        	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:85)
        	at org.forgerock.openidm.auth.AuthFilterWrapper.filter(AuthFilterWrapper.java:85)
        	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.filter.TransactionIdInboundFilter.filter(TransactionIdInboundFilter.java:86)
        	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
        	at org.forgerock.http.servlet.HttpFrameworkServlet.service(HttpFrameworkServlet.java:264)
        	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
        	at org.eclipse.jetty.servlet.ServletHolder$NotAsyncServlet.service(ServletHolder.java:1392)
        	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:760)
        	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1617)
        	at org.forgerock.openidm.jetty.LargePayloadServletFilter.doFilter(LargePayloadServletFilter.java:64)
        	at sun.reflect.GeneratedMethodAccessor102.invoke(Unknown Source)
        	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        	at java.lang.reflect.Method.invoke(Method.java:498)
        	at org.forgerock.openidm.servletregistration.impl.ServletRegistrationSingleton$FilterProxy.invoke(ServletRegistrationSingleton.java:327)
        	at com.sun.proxy.$Proxy73.doFilter(Unknown Source)
        	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)
        	at org.eclipse.jetty.servlets.CrossOriginFilter.handle(CrossOriginFilter.java:310)
        	at org.eclipse.jetty.servlets.CrossOriginFilter.doFilter(CrossOriginFilter.java:264)
        	at sun.reflect.GeneratedMethodAccessor102.invoke(Unknown Source)
        	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        	at java.lang.reflect.Method.invoke(Method.java:498)
        	at org.forgerock.openidm.servletregistration.impl.ServletRegistrationSingleton$FilterProxy.invoke(ServletRegistrationSingleton.java:327)
        	at com.sun.proxy.$Proxy71.doFilter(Unknown Source)
        	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)
        	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:545)
        	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71)
        	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
        	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:536)
        	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
        	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
        	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1592)
        	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
        	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1296)
        	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:290)
        	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
        	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:485)
        	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1562)
        	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
        	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1211)
        	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
        	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80)
        	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:767)
        	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
        	at org.eclipse.jetty.server.Server.handle(Server.java:500)
        	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:386)
        	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:562)
        	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:378)
        	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:270)
        	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
        	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
        	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
        	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
        	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
        	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
        	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
        	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:388)
        	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
        	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
        	at java.lang.Thread.run(Thread.java:748)
        Caused by: org.identityconnectors.framework.common.exceptions.ConnectorException: javax.naming.CommunicationException: [LDAP: error code 2 - 00000057: LdapErr: DSID-0C0907C5, comment: Error processing control, data 0, v1db1#]; remaining name 'OU=RobotTests2019_12_03_12_18_33,DC=testing'
        	at org.identityconnectors.ldap.search.LdapInternalSearch.execute(LdapInternalSearch.java:87)
        	at org.identityconnectors.ldap.search.LdapSearch.execute(LdapSearch.java:159)
        	at org.identityconnectors.ldap.search.LdapSearch.execute(LdapSearch.java:144)
        	at org.identityconnectors.ldap.LdapConnector.executeQuery(LdapConnector.java:215)
        	at org.identityconnectors.ldap.LdapConnector.executeQuery(LdapConnector.java:1)
        	at org.identityconnectors.framework.impl.api.local.operations.SearchImpl.rawSearch(SearchImpl.java:162)
        	at org.identityconnectors.framework.impl.api.local.operations.SearchImpl.search(SearchImpl.java:118)
        	at sun.reflect.GeneratedMethodAccessor103.invoke(Unknown Source)
        	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        	at java.lang.reflect.Method.invoke(Method.java:498)
        	at org.identityconnectors.framework.impl.api.local.operations.ConnectorAPIOperationRunnerProxy.invoke(ConnectorAPIOperationRunnerProxy.java:104)
        	at com.sun.proxy.$Proxy76.search(Unknown Source)
        	at sun.reflect.GeneratedMethodAccessor103.invoke(Unknown Source)
        	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        	at java.lang.reflect.Method.invoke(Method.java:498)
        	at org.identityconnectors.framework.impl.api.local.operations.ThreadClassLoaderManagerProxy.invoke(ThreadClassLoaderManagerProxy.java:96)
        	at com.sun.proxy.$Proxy76.search(Unknown Source)
        	at sun.reflect.GeneratedMethodAccessor103.invoke(Unknown Source)
        	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        	at java.lang.reflect.Method.invoke(Method.java:498)
        	at org.identityconnectors.framework.impl.api.BufferedResultsProxy$BufferedResultsHandler.run(BufferedResultsProxy.java:157)
        Caused by: javax.naming.CommunicationException: [LDAP: error code 2 - 00000057: LdapErr: DSID-0C0907C5, comment: Error processing control, data 0, v1db1#]; remaining name 'OU=RobotTests2019_12_03_12_18_33,DC=testing'
        	at com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3202)
        	at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:3100)
        	at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2891)
        	at com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1846)
        	at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1769)
        	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_search(ComponentDirContext.java:392)
        	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:358)
        	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:341)
        	at javax.naming.directory.InitialDirContext.search(InitialDirContext.java:267)
        	at org.identityconnectors.ldap.search.SimplePagedSearchStrategy.doSearch(SimplePagedSearchStrategy.java:91)
        	at org.identityconnectors.ldap.search.LdapInternalSearch.execute(LdapInternalSearch.java:71)
        	... 20 more
        

      Please see the attached IDM log

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                gael Gael Allioux
                Reporter:
                son.nguyen Son Nguyen
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: