Where do the waiting transactions accumulate?

[hkayabilisim]

I've successfully installed TeaStore and done some benchmark tests using HTTP-Load-Generator; no problems. However, I came accross a peculiar case where I couldn't understand the mechanism of accumulated transactions.

In the following scenario, I've delibaretly decreased the capacity of teastore-webui to the extend that TeaStore is still functional but successfull transactions are generally lower than the Load Intensity. In my tests, Director does not report Failed or Dropped transactions. But I assume that the transactions should start accumulate and I should observe some failed or dropped transactions after some time. But I couldn't find evidence (number of increasing threads, increasing memory etc) of this accumulation. In other words: where exactly are those "waiting" transactions are waiting? I checked "netstat -pantul": the number of connections is always 128. I checked the stack trace of java process in the generator: it stays fixed around 1000. The number of threads ("ps -eLf") of the generator is also not increasing.

Director output
java -jar httploadgenerator.jar director --ip 10.27.44.100 --load constantLoad_100tps.csv --lua teastore_browse.lua Here is the output.

Jan 03, 2022 10:03:35 AM tools.descartes.dlim.httploadgenerator.runner.Director executeDirector
WARNING: No power measurements
Jan 03, 2022 10:03:35 AM tools.descartes.dlim.httploadgenerator.runner.Director executeDirector
INFO: Load Generator Thread Count set to 128
Jan 03, 2022 10:03:35 AM tools.descartes.dlim.httploadgenerator.runner.Director executeDirector
INFO: URL connection timout set to 0 ms
Jan 03, 2022 10:03:35 AM tools.descartes.dlim.httploadgenerator.runner.Director executeDirector
INFO: Using Lua Script: teastore_browse.lua
Jan 03, 2022 10:03:35 AM tools.descartes.dlim.httploadgenerator.runner.Director process
INFO: Read 86401 Arrival Rate Tuples
Load Generator sent: ok
Jan 03, 2022 10:03:35 AM tools.descartes.dlim.httploadgenerator.runner.Director process
INFO: Arrival Rates sent to Load Generator(s).
Load Generator sent: ok
Jan 03, 2022 10:03:35 AM tools.descartes.dlim.httploadgenerator.runner.Director process
INFO: Thread Count sent to Load Generator(s): 128
Load Generator sent: ok
Load Generator sent: ok
Jan 03, 2022 10:03:35 AM tools.descartes.dlim.httploadgenerator.runner.Director process
INFO: Contents of script sent to Load Generator: teastore_browse.lua
Jan 03, 2022 10:03:35 AM tools.descartes.dlim.httploadgenerator.runner.Director process
INFO: Starting Load Generation
Beginning Run @1641193415722(03.01.2022;10:03:35722)
Target Time = 0.5; Load Intensity = 100.0; #Success = 14; #Failed = 0; #Dropped = 0
Target Time = 1.5; Load Intensity = 100.0; #Success = 184; #Failed = 0; #Dropped = 0
Target Time = 2.5; Load Intensity = 100.0; #Success = 101; #Failed = 0; #Dropped = 0
Target Time = 3.5; Load Intensity = 100.0; #Success = 81; #Failed = 0; #Dropped = 0
Target Time = 4.5; Load Intensity = 100.0; #Success = 67; #Failed = 0; #Dropped = 0
Target Time = 5.5; Load Intensity = 100.0; #Success = 55; #Failed = 0; #Dropped = 0
Target Time = 6.5; Load Intensity = 100.0; #Success = 26; #Failed = 0; #Dropped = 0
 ...
Target Time = 6586.5; Load Intensity = 100.0; #Success = 80; #Failed = 0; #Dropped = 0
Target Time = 6587.5; Load Intensity = 100.0; #Success = 113; #Failed = 0; #Dropped = 0
Target Time = 6588.5; Load Intensity = 100.0; #Success = 91; #Failed = 0; #Dropped = 0
Target Time = 6589.5; Load Intensity = 100.0; #Success = 62; #Failed = 0; #Dropped = 0
Target Time = 6590.5; Load Intensity = 100.0; #Success = 99; #Failed = 0; #Dropped = 0
Target Time = 6591.5; Load Intensity = 100.0; #Success = 75; #Failed = 0; #Dropped = 0
Target Time = 6592.5; Load Intensity = 100.0; #Success = 95; #Failed = 0; #Dropped = 0
Target Time = 6593.5; Load Intensity = 100.0; #Success = 101; #Failed = 0; #Dropped = 0
Target Time = 6594.5; Load Intensity = 100.0; #Success = 87; #Failed = 0; #Dropped = 0
Target Time = 6595.5; Load Intensity = 100.0; #Success = 80; #Failed = 0; #Dropped = 0
Target Time = 6596.5; Load Intensity = 100.0; #Success = 107; #Failed = 0; #Dropped = 0

Director output (visualized)
I've also visualized the previous output. "Waiting" refers to the cumulated sum of (load intensity-success-failed-dropped). As you see the successfull transactions oscillate around 100 but it is generally below zero. There is no failed or dropped transactions reported. So there should be some transactions waiting somewhere. And this "waiting" transactions are increasing linearly with time.

Director Side

Generator Side
java -jar httploadgenerator.jar loadgenerator

constantLoad_100tps.csv

0.5,100
1.5,100
2.5,100
3.5,100
...
86397.5,100
86398.5,100
86399.5,100
86400.5,100

teastore_browse.lua
I've only changed prefix = "http://teastore.apps.company/tools.descartes.teastore.webui/"

teastore-webui deployment
Here is the output of oc get deployment/teastore-webui -o yaml:
Please note that I deliberately set CATALINA_OPTS=-Xmx300M, replicas=1, and cpu limit to 500m to reduce the capacity of the teastore-webui container.

apiVersion: apps/v1
kind: Deployment
metadata:
  annotations:
    deployment.kubernetes.io/revision: "719"
    kubectl.kubernetes.io/last-applied-configuration: |
      {"apiVersion":"apps/v1","kind":"Deployment","metadata":{"annotations":{},"name":"teastore-webui","namespace":"teastore"},"spec":{"replicas":2,"selector":{"matchLabels":{"app":"teastore","run":"teastore-webui"}},"template":{"metadata":{"labels":{"app":"teastore","run":"teastore-webui"}},"spec":{"containers":[{"env":[{"name":"USE_POD_IP","value":"true"},{"name":"REGISTRY_HOST","value":"teastore-registry"},{"name":"RABBITMQ_HOST","value":"teastore-kieker-rabbitmq"},{"name":"CATALINA_OPTS","value":"-Xmx500M"}],"image":"default-route-openshift-image-registry.apps.company/teastore/teastore-webui","name":"teastore-webui","ports":[{"containerPort":8080}],"resources":{"limits":{"cpu":"500m"}}}]}}}}
  creationTimestamp: "2021-07-25T17:54:56Z"
  generation: 796
  name: teastore-webui
  namespace: teastore
  resourceVersion: "65487249"
  selfLink: /apis/apps/v1/namespaces/teastore/deployments/teastore-webui
  uid: d8fa2d7d-673e-4e79-91ec-f7739c2a6a0a
spec:
  progressDeadlineSeconds: 600
  replicas: 1
  revisionHistoryLimit: 10
  selector:
    matchLabels:
      app: teastore
      run: teastore-webui
  strategy:
    rollingUpdate:
      maxSurge: 25%
      maxUnavailable: 25%
    type: RollingUpdate
  template:
    metadata:
      creationTimestamp: null
      labels:
        app: teastore
        run: teastore-webui
    spec:
      containers:
      - env:
        - name: USE_POD_IP
          value: "true"
        - name: REGISTRY_HOST
          value: teastore-registry
        - name: RABBITMQ_HOST
          value: teastore-kieker-rabbitmq
        - name: CATALINA_OPTS
          value: -Xmx300M
        image: default-route-openshift-image-registry.apps.company/teastore/teastore-webui
        imagePullPolicy: Always
        name: teastore-webui
        ports:
        - containerPort: 8080
          protocol: TCP
        resources:
          limits:
            cpu: 500m
        terminationMessagePath: /dev/termination-log
        terminationMessagePolicy: File
      dnsPolicy: ClusterFirst
      restartPolicy: Always
      schedulerName: default-scheduler
      securityContext: {}
      terminationGracePeriodSeconds: 30
status:
  availableReplicas: 1
  conditions:
  - lastTransitionTime: "2021-12-04T20:43:55Z"
    lastUpdateTime: "2021-12-04T20:43:55Z"
    message: Deployment has minimum availability.
    reason: MinimumReplicasAvailable
    status: "True"
    type: Available
  - lastTransitionTime: "2021-07-25T17:54:56Z"
    lastUpdateTime: "2021-12-04T21:00:15Z"
    message: ReplicaSet "teastore-webui-6b5b98b79f" has successfully progressed.
    reason: NewReplicaSetAvailable
    status: "True"
    type: Progressing
  observedGeneration: 796
  readyReplicas: 1
  replicas: 1
  updatedReplicas: 1`

Versions

• OpenShift 4.7 with CoreOS