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

Regression: Failed to handle certain number of concurrent requests since commits dd7967f6ef7

    Details

    • Target Version/s:
    • Verified Version/s:
    • Story Points:
      3
    • Sprint:
      2020.02 - IDM

      Description

      Our stress tests preload users by sending IDM concurrent creating managed users requests, the dispatch rate is 300 users/second and it has been working well. Since dd7967f6ef7 IDM failed to handle this number of concurrent requests and requests timed-out. IDM logged:

      SEVERE: INTERNAL_USER has thrown an error whilst attempting to authenticate the client
      org.forgerock.caf.authentication.api.AuthenticationException: Failed delegated authentication of openidm-admin on internal/user
              at org.forgerock.openidm.auth.impl.modules.DelegatedAuthModule.authenticate(DelegatedAuthModule.java:211)
              at org.forgerock.openidm.auth.impl.modules.DelegatedAuthModule.validateRequest(DelegatedAuthModule.java:148)
      ...
      Caused by: org.forgerock.json.resource.InternalServerErrorException: Querying failed: 368a1062-c698-4e9e-9c1a-52f1049e5521 - Connection is not available, request timed out after 30000ms.
              at org.forgerock.openidm.repo.jdbc.impl.JDBCRepoServiceHandleQuery.handle(JDBCRepoServiceHandleQuery.java:272)
              at org.forgerock.openidm.repo.jdbc.impl.JDBCRepoServiceHandleQuery.handleQuery(JDBCRepoServiceHandleQuery.java:182)
              at org.forgerock.openidm.repo.jdbc.impl.JDBCRepoService.lambda$handleQuery$8(JDBCRepoServic
      ...
      Caused by: java.sql.SQLTransientConnectionException: 368a1062-c698-4e9e-9c1a-52f1049e5521 - Connection is not available, request timed out after 30000ms.
              at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:583)
              at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:186)
              at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:145)
              at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:85)
              at org.forgerock.openidm.repo.jdbc.impl.JDBCRepoService.lambda$getConnection$11(JDBCRepoService.java:763)
              at org.forgerock.openidm.metrics.MetricsCollector.time(MetricsCollector.java:51)
              at org.forgerock.openidm.metrics.MetricsCollector.time(MetricsCollector.java:68)
              at org.forgerock.openidm.repo.jdbc.impl.JDBCRepoService.getConnection(JDBCRepoService.java:762)
              at org.forgerock.openidm.repo.jdbc.impl.JDBCRepoServiceHandleQuery.handle(JDBCRepoServiceHandleQuery.java:251)
              ... 213 more
      
      

      Note:
      1. Tried to reduce the dispatch rate from 300 to 200, the same issue still exists, then the requests can go through when the rate is 150 users/second.
      2. In the same test environment, the commit a26f177 worked well with 300 users/second dispatch rate.
      3. See the same symptom with Postgres as repo as well, still see the issue after dropped the dispatch rate to 50 users/second.
      4. The real test doesn't see regression on mean response times and throughput in user creations.

      attached are the idm logs and idm threads dump(jstack output) after the test

      To reproduce using pyforge:
      Adjust stress parameters as below:

      [Stress]
      num_users = 10
      duration = 60
      concurrency = 10
      max_throughput = -1
      test_duration = 300
      preload_users = 300
      preload_duration = 1
      test_concurrency = 30
      

      and run test as:

      run-pybot.py -v -n  -c perf -s simple_managed_user.ReadManUsers OpenIDM
      

        Attachments

        1. jstack.out
          304 kB
        2. openidm0.log.0
          4.00 MB

          Issue Links

            Activity

              People

              • Assignee:
                katie.gonzalez Katie Gonzalez
                Reporter:
                Tinghua.Xu Tinghua.Xu
              • Votes:
                0 Vote for this issue
                Watchers:
                1 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: