Why My 500/s Throughput Goal Dropped to 50/s: A Deep Dive into Java Backend Bottlenecks

1. Analysis Process

Identifying the "slow" cause

Temporarily ignore the high CPU usage.

The average response time was too high, indicating blocking. The focus was on locks (synchronization, distributed, DB) and time‑consuming operations (network calls, SQL).

Locks (synchronization, distributed, database)

Time‑consuming operations (network latency, SQL)

Added timing probes:

Log a warning if interface response exceeds 500 ms.

Log a warning if internal remote call exceeds 200 ms.

Log a warning if Redis access exceeds 10 ms.

Log a warning if SQL execution exceeds 100 ms.

After enabling these probes, a slow SQL statement was found:

<!-- Mainly similar to inventory decrement, each type has only a few rows (one per type) -->
update table set field = field - 1 where type = 1 and filed > 1;

The statement caused lock contention, accounting for over 80 % of the request latency. The quick fix was to execute it asynchronously, which roughly doubled the throughput and reduced the maximum response time from 5 s to 2 s, and the 95th percentile from 4 s to 1 s.

Continuing to locate the "slow" cause

Further log inspection showed noticeable gaps between certain INFO entries, suggesting thread switches, excessive logging (500 MB of logs in 5 minutes), or Stop‑The‑World pauses.

Thread switching due to too many threads.

Excessive log printing.

Potential STW pauses.

Actions taken:

Raised log level to DEBUG (modest improvement).

Split work using @Async with a controlled thread pool (core threads limited to 50); throughput rose to ~200 req/s.

Increased JVM heap from 512 MB to 4 GB; YGC frequency dropped from 4 /s to 2 /s, with no noticeable throughput gain.

Locating the high CPU usage cause

CPU usage remained high even after reducing thread count. Thread dump analysis showed no single thread consuming excessive CPU; most threads hovered around 10 %.

The stack trace revealed frequent calls to BeanUtils.getBean(RedisMaster.class), which triggered createBean on a prototype‑scoped RedisMaster bean. Since the Redis client (Jedis) is not thread‑safe, each request instantiated the bean ~10 times, causing massive bean‑creation overhead.

// BeanUtils is a Hutool utility equivalent to @Autowired
RedisTool redisTool = BeanUtils.getBean(RedisMaster.class);

Replacing the prototype bean with a direct new instance eliminated the overhead.

Additional timing instrumentation (using System.currentTimeMillis() or Hutool’s StopWatch) was also identified as a non‑trivial cost under high concurrency.

long start = System.currentTimeMillis();
// ...
long end = System.currentTimeMillis();
long runTime = end - start;

StopWatch watch = new StopWatch();
watch.start();
// ...
watch.stop();
System.out.println(watch.getTotalTimeMillis());

2. Summary

The resolution was successful but required a trial‑and‑error approach over four days, highlighting gaps in performance‑optimization knowledge.

MySQL tuning: buffer pool, change buffer, redo log size, etc.

Code changes: async execution, thread‑pool tuning, Tomcat configuration, Druid connection‑pool adjustments.

JVM tuning: memory size, garbage‑collector selection.

Further learning is needed to develop systematic troubleshooting strategies rather than ad‑hoc experimentation.

Useful Commands

Check process CPU: top -Hp <pid> Inspect JVM GC: jstat -gc <pid> 2000 Dump stack traces:

jstack -l <pid> >> stack.log

TODO

Deep‑dive into why createBean incurs such a heavy performance penalty and under what conditions Spring’s prototype scope is appropriate.