Uploaded image for project: 'OpenIDM'
  1. OpenIDM
  2. OPENIDM-15075

Response time from query relationship endpoint increased significantly after 718a0fdf29

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Critical
    • Resolution: Fixed
    • Affects Version/s: 7.0.0
    • Fix Version/s: 7.0.0
    • Component/s: None
    • Environment:
      IDM commit 718a0fdf29 runs on a CentOS7, MySQL as repo, Java 11,
    • Target Version/s:
    • Verified Version/s:
    • Story Points:
      2
    • Sprint:
      2020.09 - IDM

      Description

      The test preload 30K managed users with roles(10 roles with one assignment each), then sends 1000 queries on the relationship endpoint managed/user/username/roles?_queryFilter=true&_fields=_ref/ with concurrency 20.

      before the commit 718a0fdf29(OPENIDM-11601) , the 1000 queries can finish in about 900 seconds:

      2020-06-26 19:47:05 900s elapsed 
      ---- Requests ------------------------------------------------------------------ > 
      Global (OK=1000 KO=0 ) > Read Get Request (OK=1000 KO=0 )
      ---- Global Information --------------------------------------------------------> request count                                       1000 (OK=1000   KO=0     )
      > min response time                                   2494 (OK=2494   KO=-     )
      > max response time                                  22816 (OK=22816  KO=-     )
      > mean response time                                 17484 (OK=17484  KO=-     )
      ...
      > mean requests/sec                                  1.121 

      After 718a0fdf29, the test either fails with Gatling OOME(with 8g heap) or with a longer response times:

      ================================================================================
      2020-06-26 18:55:34                                        1084s elapsed
      ---- Requests ------------------------------------------------------------------
      > Global                                                   (OK=470    KO=0     )
      > Read Get Request                                         (OK=470    KO=0     )---- ManUsers Read Get ---------------------------------------------------------
      [--------------------------------------------------------------------------]  0%
                waiting: 0      / active: 20     / done: 0
      ================================================================================18:55:33.991 [WARN ] i.g.h.e.GatlingHttpListener - Request 'Read Get Request' failed for user 6
      io.gatling.http.client.impl.RequestTimeoutException: Request timeout to fourme.internal.forgerock.com/172.16.204.17:8081 after 60000 ms
      18:55:33.990 [WARN ] i.g.h.e.GatlingHttpListener - Request 'Read Get Request' failed for user 12
      ...
      io.gatling.http.client.impl.RequestTimeoutException: Request timeout to fourme.internal.forgerock.com/172.16.204.17:8081 after 60000 ms
      18:55:34.005 [WARN ] i.g.h.e.GatlingHttpListener - Request 'Read Get Request' failed for user 8
      java.lang.OutOfMemoryError: Java heap space
              at java.util.Arrays.copyOfRange(Arrays.java:3664)
              ...

      only 470 queries are done in 1084 seconds. It's half as fast as earlier.

      later checked the response size of the query on one user,

      before 718a0fdf29, the size is about 121M, with 718a0fdf29, the size is about 434M that should explain why Gatling OOME as 20 active users are doing the query.

      checked the response content:
      Before 718a0fdf29, the response has members like:

      "members": [
                      {
                          "_id": "A-A-15234",
                          "_ref": "managed/user/A-A-15234",
                          "_refProperties": {
                              "_id": "d354843d-d43f-42b7-adf2-9959f9c854b4",
                              "_rev": "0"
                          },
                          "_refResourceCollection": "managed/user",
                          "_refResourceId": "A-A-15234",
                          "_rev": "0",
                          "accountStatus": "active",
                          "city": "city1",
                          "country": "usa",
                          "description": "Managed User",
                          "displayName": "Auabuhyr.Apibac",
                          "effectiveAssignments": [
                              {
                                  "_id": "assignment0",
                                  "_rev": "0",
                                  "attributes": [
                                      {
                                          "name": "ldapGroups",
                                          "value": [
                                              "cn=App0,dc=example,dc=com"
                                          ]
                                      }
                                  ],
                                  "description": "assignment description",
                                  "mapping": "managedUser_managedUser",
                                  "name": "ldap"
                              }
                          ],
                          "effectiveRoles": [
                              {
                                  "_ref": "managed/role/role39"
                              },
                              {
                                  "_ref": "managed/role/role40"
                              },
                              {
                                  "_ref": "managed/role/role41"
                              },
                              {
                                  "_ref": "managed/role/role42"
                              },
                              {
                                  "_ref": "managed/role/role43"
                              },

      with the commit:

      "members": [
                      {
                          "_id": "W-C-2",
                          "_ref": "managed/user/W-C-2",
                          "_refProperties": {
                              "_id": "79cb7654-981f-4a2f-ac4a-98a6edb08d72",
                              "_rev": "0"
                          },
                          "_refResourceCollection": "managed/user",
                          "_refResourceId": "W-C-2",
                          "_rev": "0",
                          "accountStatus": "active",
                          "city": "city1",
                          "country": "usa",
                          "description": "Managed User",
                          "displayName": "Cdnfjbkx.Wongrd",
                          "effectiveAssignments": [
                              {
                                  "_id": "assignment0",
                                  "_rev": "0",
                                  "attributes": [
                                      {
                                          "name": "ldapGroups",
                                          "value": [
                                              "cn=App0,dc=example,dc=com"
                                          ]
                                      }
                                  ],
                                  "description": "assignment description",
                                  "mapping": "managedUser_managedUser",
                                  "name": "ldap"
                              },
                              {
                                  "_id": "assignment0",
                                  "_rev": "0",
                                  "attributes": [
                                      {
                                          "name": "ldapGroups",
                                          "value": [
                                              "cn=App0,dc=example,dc=com"
                                          ]
                                      }
                                  ],
                                  "description": "assignment description",
                                  "mapping": "managedUser_managedUser",
                                  "name": "ldap"
                              },
      ...
      {
                                  "_id": "assignment0",
                                  "_rev": "0",
                                  "attributes": [
                                      {
                                          "name": "ldapGroups",
                                          "value": [
                                              "cn=App0,dc=example,dc=com"
                                          ]
                                      }
                                  ],
                                  "description": "assignment description",
                                  "mapping": "managedUser_managedUser",
                                  "name": "ldap"
                              }
                          ],
                          "effectiveRoles": [
                              {
                                  "_ref": "managed/role/role33",
                                  "_refResourceCollection": "managed/role",
                                  "_refResourceId": "role33"
                              },
                              {
                                  "_ref": "managed/role/role34",
                                  "_refResourceCollection": "managed/role",
                                  "_refResourceId": "role34"
                              },
      ...

      One main difference is that the same assignment are repeated included in the response from the commit.

      To reproduce, use the pyforge config attached and run test and see the symptom:

       ./run-pybot.py -v -c perf -s relationship.QueryRelationShipEndpoint -t IDM_Query_Relationship_Endpoint_Fields_RefStar OpenIDM

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                dhogan Dirk Hogan
                Reporter:
                Tinghua.Xu Tinghua.Xu [X] (Inactive)
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: