Uploaded image for project: 'Okapi'
  1. Okapi
  2. OKAPI-866

Okapi uses excessive memory or OOM for bulk instance id download

    XMLWordPrintable

Details

    • Standard Bug Write-Up Format
    • CP: sprint 91, CP: sprint 92
    • Core: Platform

    Description

      Overview:
      While testing Okapi 3.1.1 with bulk instance id download, noticed that Okapi uses excessive memory usage. If the memory is setting a bit low like 1g, it will get OOM error.

      Steps to Reproduce:

      1. Use Okapi 3.1.1 (set -Xmx to 1g for example) with latest modules code
      2. Use nightly perf data set. It has about 2.7m instance records
      3. Make API call to /instance-bulk/ids?limit=2147483647&query=(keyword="") sortby title*
      4. Check Okapi log

      Expected Results:
      No error in the log

      Actual Results:
      OOM error

      20:49:53 INFO  ProxyContext         465546/instance-bulk REQ 140.234.253.9:21737 supertenant GET /instance-bulk/ids  mod-authtoken-2.6.0-SNAPSHOT.73 mod-inventory-storage-19.3.0-SNAPSHOT.440
      20:49:53 INFO  ProxyContext         465546/instance-bulk;355490/users REQ 172.31.6.98:39356 supertenant GET /users/8cef003e-a9bd-409f-8ea4-8d395b55e415  mod-authtoken-2.6.0-SNAPSHOT.73 mod-users-17.1.0-SNAPSHOT.136
      20:49:53 INFO  ProxyContext         465546/instance-bulk;355490/users RES 202 15719us mod-authtoken-2.6.0-SNAPSHOT.73 http://172.31.6.98:9201/users/8cef003e-a9bd-409f-8ea4-8d395b55e415
      20:49:53 INFO  ProxyContext         465546/instance-bulk;355490/users RES 200 12436us mod-users-17.1.0-SNAPSHOT.136 http://172.31.6.98:9227/users/8cef003e-a9bd-409f-8ea4-8d395b55e415
      20:49:53 INFO  ProxyContext         465546/instance-bulk;975356/perms REQ 172.31.6.98:39358 supertenant GET /perms/users  mod-authtoken-2.6.0-SNAPSHOT.73 mod-permissions-5.12.0-SNAPSHOT.82
      20:49:53 INFO  ProxyContext         465546/instance-bulk;975356/perms RES 202 5139us mod-authtoken-2.6.0-SNAPSHOT.73 http://172.31.6.98:9201/perms/users?query=userId==8cef003e-a9bd-409f-8ea4-8d395b55e415
      20:49:53 INFO  ProxyContext         465546/instance-bulk;975356/perms RES 200 17055us mod-permissions-5.12.0-SNAPSHOT.82 http://172.31.6.98:9220/perms/users?query=userId==8cef003e-a9bd-409f-8ea4-8d395b55e415
      20:49:53 INFO  ProxyContext         465546/instance-bulk;150874/perms REQ 172.31.6.98:39358 supertenant GET /perms/users/be69019d-fdb4-421d-ab14-9ad4c2c7ec56/permissions  mod-authtoken-2.6.0-SNAPSHOT.73 mod-permissions-5.12.0-SNAPSHOT.82
      20:49:53 INFO  ProxyContext         465546/instance-bulk;150874/perms RES 202 3804us mod-authtoken-2.6.0-SNAPSHOT.73 http://172.31.6.98:9201/perms/users/be69019d-fdb4-421d-ab14-9ad4c2c7ec56/permissions?expanded=true
      20:49:53 INFO  ProxyContext         465546/instance-bulk;150874/perms RES 200 23457us mod-permissions-5.12.0-SNAPSHOT.82 http://172.31.6.98:9220/perms/users/be69019d-fdb4-421d-ab14-9ad4c2c7ec56/permissions?expanded=true
      20:49:53 INFO  ProxyContext         465546/instance-bulk RES 202 183318us mod-authtoken-2.6.0-SNAPSHOT.73 http://172.31.6.98:9201/instance-bulk/ids?limit=2147483647&query=%28keyword=%22%2A%22%29%20sortby%20title
      20:50:45 INFO  ProxyContext         465546/instance-bulk RES 200 51941389us mod-inventory-storage-19.3.0-SNAPSHOT.440 http://172.31.6.98:9213/instance-bulk/ids?limit=2147483647&query=%28keyword=%22%2A%22%29%20sortby%20title
      20:52:44 WARN  ?                    Thread Thread[vert.x-eventloop-thread-1,5,main] has been blocked for 2493 ms, time limit is 2000 ms
      20:53:04 INFO  jFactory$Log4jLogger [172.17.0.2]:5701 [dev] [3.12.2] processors=2, physical.memory.total=7.5G, physical.memory.free=5.4G, swap.space.total=0, swap.space.free=0, heap.memory.used=720.9M, heap.memory.free=189.6M, heap.memory.total=910.5M, heap.memory.max=910.5M, heap.memory.used/total=79.17%, heap.memory.used/max=79.17%, minor.gc.count=0, minor.gc.time=0ms, major.gc.count=0, major.gc.time=0ms, load.process=56.61%, load.system=53.50%, load.systemAverage=0.88, thread.count=62, thread.peakCount=63, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=582, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=0, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
      20:53:16 WARN  ?                    Thread Thread[vert.x-eventloop-thread-1,5,main] has been blocked for 2704 ms, time limit is 2000 ms
      20:53:24 INFO  jFactory$Log4jLogger [172.17.0.2]:5701 [dev] [3.12.2] processors=2, physical.memory.total=7.5G, physical.memory.free=5.3G, swap.space.total=0, swap.space.free=0, heap.memory.used=792.5M, heap.memory.free=118.0M, heap.memory.total=910.5M, heap.memory.max=910.5M, heap.memory.used/total=87.03%, heap.memory.used/max=87.03%, minor.gc.count=0, minor.gc.time=0ms, major.gc.count=0, major.gc.time=0ms, load.process=87.23%, load.system=86.38%, load.systemAverage=1.20, thread.count=63, thread.peakCount=63, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=582, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=0, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
      20:53:29 WARN  ?                    Thread Thread[vert.x-eventloop-thread-1,5,main] has been blocked for 2279 ms, time limit is 2000 ms
      20:53:32 WARN  ?                    Thread Thread[vert.x-eventloop-thread-1,5,main] has been blocked for 2965 ms, time limit is 2000 ms
      20:53:34 WARN  ?                    Thread Thread[vert.x-eventloop-thread-1,5,main] has been blocked for 2252 ms, time limit is 2000 ms
      Exception in thread "vertx-blocked-thread-checker" java.lang.OutOfMemoryError: GC overhead limit exceeded
      java.lang.OutOfMemoryError: GC overhead limit exceeded
      20:57:14 WARN  jFactory$Log4jLogger [172.17.0.2]:5701 [dev] [3.12.2] BroadcastOperationControlTask delayed 175872 ms
      java.lang.OutOfMemoryError: GC overhead limit exceeded
      java.lang.OutOfMemoryError: GC overhead limit exceeded
      java.lang.OutOfMemoryError: GC overhead limit exceeded
      

      TestRail: Results

        Attachments

          Issue Links

            Activity

              People

                adam Adam Dickmeiss
                hji Hongwei Ji
                Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                  Created:
                  Updated:
                  Resolved:

                  TestRail: Runs

                    TestRail: Cases