How Thread Count, Random Delays, and Logging Skew QPS Measurements

Background

This article extends a previous study of performance‑test error sources by quantifying how thread count, random request latency, and synchronous logging affect the accuracy of QPS (queries per second) measurements.

Baseline Test Script

A minimal Groovy program creates a static Vector<Long> costs to store per‑request durations, a CountDownLatch for thread synchronization, and runs thread = 20 threads each performing times = 50 iterations with a fixed sleep(0.1) delay.

package com.funtester.groovy
import com.funtester.frame.SourceCode
import com.funtester.utils.Time
import java.util.concurrent.CountDownLatch
import java.util.concurrent.atomic.AtomicInteger

class FunTester extends SourceCode {
    static Vector<Long> costs = new Vector<>()
    static CountDownLatch countDownLatch
    private static final int thread = 20
    private static final int times = 50
    private static final AtomicInteger excutetimes = new AtomicInteger()

    static void main(String[] args) {
        countDownLatch = new CountDownLatch(thread)
        long s = Time.getTimeStamp()
        thread.times { new FunTest().start() }
        countDownLatch.await()
        long e = Time.getTimeStamp()
        double rt = costs.stream().mapToLong(Long::longValue).average().orElse(0)
        double qpsAvg = thread * 1000.0 / rt
        double qpsTot = excutetimes.get() * 1000.0 / (e - s)
        double deviation = SourceCode.getPercent(Math.abs(qpsAvg - qpsTot) * 100 / Math.max(qpsAvg, qpsTot))
        output("Average‑time QPS:" + qpsAvg)
        output("Total‑time QPS:" + qpsTot)
        output("Error:" + deviation)
    }

    private static class FunTest extends Thread {
        @Override
        void run() {
            times.times {
                long start = Time.getTimeStamp()
                sleep(0.1)
                long end = Time.getTimeStamp()
                excutetimes.getAndIncrement()
                costs.add(end - start)
            }
            countDownLatch.countDown()
        }
    }
}

Running the baseline (20 threads × 50 iterations) produces:

Average‑time QPS: 193.41
Total‑time QPS: 189.54
Error: 2%

Introducing Random Delays

To simulate non‑uniform request latency, the run() method is changed to:

@Override
void run() {
    times.times {
        long start = Time.getTimeStamp()
        sleep(0.1 + getRandomDouble() / 3)
        long end = Time.getTimeStamp()
        excutetimes.getAndIncrement()
        costs.add(end - start)
    }
    countDownLatch.countDown()
}

Results show that random latency increases QPS error, especially with more threads:

20 threads × 50 iterations → QPS ≈ 75.8 / 70.3, error ≈ 7.33%

40 threads × 50 iterations → QPS ≈ 148.3 / 130.3, error ≈ 12.11%

Increasing the iteration count mitigates the error (e.g., 20 threads × 100 iterations → error ≈ 6.78%), confirming the statistical principle that larger sample sizes converge toward the true mean.

Controlling Early Termination

A static boolean flag KEY forces all threads to stop simultaneously. The loop checks the flag and breaks when it becomes true, then sets the flag after the loop.

@Override
void run() {
    for (int i = 0; i < times; i++) {
        long start = Time.getTimeStamp()
        sleep(0.1 + getRandomDouble() / 3)
        long end = Time.getTimeStamp()
        excutetimes.getAndIncrement()
        costs.add(end - start)
        if (KEY) break
    }
    KEY = true
    countDownLatch.countDown()
}

With 40 threads × 50 iterations the error drops to ~2.78% and QPS rises slightly, demonstrating that synchronising thread termination reduces measurement variance.

Impact of Synchronous Logging

Synchronous Log4j2 logging (10 log statements per iteration) is added inside the request loop:

@Override
void run() {
    times.times {
        long start = Time.getTimeStamp()
        sleep(0.1)
        10.times { logger.info(text) }
        long end = Time.getTimeStamp()
        excutetimes.getAndIncrement()
        costs.add(end - start)
    }
    countDownLatch.countDown()
}

Measured results:

20 threads × 50 iterations → QPS ≈ 186.36 / 182.52, error ≈ 2.06% (baseline error ≈ 2%)

40 threads × 50 iterations → QPS ≈ 347.37 / 339.33, error ≈ 2.31% (baseline error ≈ 1%)

40 threads × 100 iterations → QPS ≈ 364.38 / 352.86, error ≈ 3.16% (baseline error ≈ 1%)

Even modest synchronous logging can degrade QPS by up to 10% and increase measurement error, especially as concurrency grows.

Conclusions

Random request latency amplifies QPS error; the effect worsens with higher thread counts.

Increasing the number of request repetitions reduces error, confirming statistical convergence.

Synchronous logging introduces noticeable overhead; minimizing or disabling log output during performance runs is advisable.

For baseline measurements, use a deterministic request model (fixed sleep) and treat logging impact as a separate factor.