By: Lukasz Golinski named 20 Jun 2022 at 4:41 a.m. CDT

11 Responses
Lukasz Golinski gravatar
## Expected behavior Querying scim user devices by keyhandle should not make opendj unresponsive. ## Actual behavior We have found an issue during querying fido devices by keyhandle using scim-client. When the user is created and no devices are registered and we perform a get query on the following enpoint: /scim/v2/FidoDevices we noticed that that scim service throws an LdapSearchException mentioning that the base entry does not exist. This is probably expected, but any further get queries to /scim/v2/FidoDevices are timed out. It seems like opendj is unresponsive. In the logs I attach exception being logged by scim component. We use scim-client version 4.2.3.Final ## Minimized example 1. Create a user 2. Search device by keyhandle 3. Search device by keyhandle (this query is timed out and at this point ldap is unresponsive)

By Thomas Gasmyr Mougang staff 20 Jun 2022 at 5:40 a.m. CDT

Thomas Gasmyr Mougang gravatar
Hello Lukasz, Can you provide the full log file?

By Thomas Gasmyr Mougang staff 21 Jun 2022 at 11:18 a.m. CDT

Thomas Gasmyr Mougang gravatar
We are not able to replicate this issue. Our suggestion is this: As you are using Gluu server 4.4.0, can you use scim-client 4.4.0 instead of 4.2.3?

By Lukasz Golinski named 24 Jun 2022 at 4:49 a.m. CDT

Lukasz Golinski gravatar
I did some additional tests. The outcome is that actually ldap is working fine, but further scim service queries takes more than 20 seconds to complete. Here is a simplified scenario: ``` public void test() { log.info("test"); for (int i = 0; i < 4; i++) { long startTime = System.currentTimeMillis(); log.info("Iteration: " + i); ClientSideService client = ScimClientFactory.getClient(...); try { String inum = "dd539fac-088d-4923-826e-9d1449c75528"; // This user should exist without any registered devices String query = "urn:ietf:params:scim:schemas:core:2.0:FidoDevice:deviceKeyHandle eq \"somekeyhandle\""; Integer startIndex = 1; Integer count = 200; String sortBy = "meta.created"; String order = "descending"; log.info("Performing ClientSideService query"); Response response = client.searchDevices(inum, query, 1, 200, sortBy, order, (String) null, (String) null); log.info("Success"); } catch (Exception e) { log.error("Unable to fetch"); } finally { long endTime = System.currentTimeMillis(); long duration = (endTime - startTime); log.info("Lasted: " + duration); client.close(); } } } ``` I also attach the logs of the scim service and the above simplified application. I also confirm that ldap is working properly... during running above test querying ldap via ldapsearch works as expected.

By Lukasz Golinski named 24 Jun 2022 at 5:15 a.m. CDT

Lukasz Golinski gravatar
Tested with following versions of scim-client: 4.2.3.Final 4.3.0.Final 4.4.0-SNAPSHOT The problem occurs using all above libraries.

By Thomas Gasmyr Mougang staff 27 Jun 2022 at 5:52 a.m. CDT

Thomas Gasmyr Mougang gravatar
Hi Lukasz, Everything looks good when i execute that example. Here is the output: ``` =====================TEST======= Iteration: 0 2022-06-27 11:39:01.736 INFO 14444 --- [nio-8080-exec-1] o.g.u.security.SecurityProviderUtility : Adding Bouncy Castle Provider 2022-06-27 11:39:02.336 INFO 14444 --- [nio-8080-exec-1] o.g.u.security.SecurityProviderUtility : Provider 'BC' with version 1.7 is added Performing ClientSideService query Success Lasted: 4152 2022-06-27 11:39:05.898 INFO 14444 --- [nio-8080-exec-1] gluu.scim2.client.TestModeScimClient : Closing RestEasy client Iteration: 1 Performing ClientSideService query Success Lasted: 380 2022-06-27 11:39:06.280 INFO 14444 --- [nio-8080-exec-1] gluu.scim2.client.TestModeScimClient : Closing RestEasy client Iteration: 2 Performing ClientSideService query Success Lasted: 205 2022-06-27 11:39:06.486 INFO 14444 --- [nio-8080-exec-1] gluu.scim2.client.TestModeScimClient : Closing RestEasy client Iteration: 3 Performing ClientSideService query Success Lasted: 498 2022-06-27 11:39:06.984 INFO 14444 --- [nio-8080-exec-1] gluu.scim2.client.TestModeScimClient : Closing RestEasy client ``` As you can see the first request took 4152, the next one 380 then 205. So no performance issue after the first request.

By Thomas Gasmyr Mougang staff 27 Jun 2022 at 6:02 a.m. CDT

Thomas Gasmyr Mougang gravatar
Here the result is way better from the previous one due to the reuse of the client connexion. ``` =====================TEST======= 2022-06-27 11:58:57.869 INFO 21360 --- [nio-8080-exec-1] o.g.u.security.SecurityProviderUtility : Adding Bouncy Castle Provider 2022-06-27 11:58:58.621 INFO 21360 --- [nio-8080-exec-1] o.g.u.security.SecurityProviderUtility : Provider 'BC' with version 1.7 is added Iteration: 0 Performing ClientSideService query Success Lasted: 237 Iteration: 1 Performing ClientSideService query Success Lasted: 146 Iteration: 2 Performing ClientSideService query Success Lasted: 122 Iteration: 3 Performing ClientSideService query Success Lasted: 70 2022-06-27 11:59:01.203 INFO 21360 --- [nio-8080-exec-1] gluu.scim2.client.TestModeScimClient : Closing RestEasy client ``` I think you should reuse the client connexion as much as possible.

By Lukasz Golinski named 27 Jun 2022 at 8:39 a.m. CDT

Lukasz Golinski gravatar
Hello Thomas, We actually do reuse the connection in our production code. I was thinking that it might be the cause of the issue we experience, but it seems it is not. Do you confirm that you ran the test **against a user inum that do not have any registered devices** and that you see the following LDAP exception in the scim logs? > Caused by: com.unboundid.ldap.sdk.LDAPSearchException: The search base entry 'ou=fido,inum=dd539fac-088d-4923-826e-9d1449c75528,ou=people,o=gluu' does not exist > Best regards, Lukasz Golinski

By Thomas Gasmyr Mougang staff 28 Jun 2022 at 4:02 a.m. CDT

Thomas Gasmyr Mougang gravatar
Yes, i'm getting the same error: ``` Caused by: com.unboundid.ldap.sdk.LDAPSearchException: The search base entry 'ou=fido,inum=7f84ad59-cfd4-4730-b5da-64361440c120,ou=people,o=gluu' does not exist at com.unboundid.ldap.sdk.LDAPConnection.search(LDAPConnection.java:3966) ~[unboundid-ldapsdk-6.0.4.jar:6.0.4] at org.gluu.persist.ldap.operation.impl.LdapOperationServiceImpl.nextSearchResult(LdapOperationServiceImpl.java:515) ~[gluu-orm-ldap-4.4.0.Final.jar:?] ``` That user exist in LDAP but doesn't have a fido devices registered.

By Lukasz Golinski named 04 Jul 2022 at 9:25 a.m. CDT

Lukasz Golinski gravatar
Hi Thomas, Do you have any idea regarding what configuration may cause such behavior? This problem occurs on all of our kubernetes environments. Today I tested changing the scim component and opendj component image to "base gluu" image, but it didn't reslve the problem. I also noticed that after scim pod restart this problem happen after 10th query. Best regards, Lukasz Golinski

By Lukasz Golinski named 04 Jul 2022 at 9:30 a.m. CDT

Lukasz Golinski gravatar
Looking at the gluu.ldap.properties.tmpl it would indicate that the maxConnection pool is exhausted.

By Lukasz Golinski named 04 Jul 2022 at 10:03 a.m. CDT

Lukasz Golinski gravatar
I can confirm that changing the maxConnection property in scim component to 15 changed the initial number of queries without failure to 15.