The previous lesson closed with a promise: CicloUrbana is in production and it deploys itself, and from here on we are going to watch it run and make it run fast. This is the first step, and it is worth starting by clearing up a misunderstanding: performance tuning is not a matter of applying tricks. It is not adding a cache, pushing the connection pool up to 100 or switching garbage collector because an article said it was faster. Those are all levers, and with no method behind them they are three different ways of moving a number at random.

The method is short and skips no steps: measure, find the bottleneck, fix one single thing, measure again. This lesson walks the whole of it over the Ribalta network. We will see why average latency lies and what to look at instead, how to establish a baseline with a load test that reproduces the morning peak, two laws that tell you where the effort is worth spending, and then the prioritised tour of the places where the time actually goes: the database first —the N+1 and the indexes—, then the connection pool, the JVM, threads and the network. We will finish with a complete case: an endpoint that takes 2.4 seconds at p95 and ends up taking 90 milliseconds.

Contents

  1. The method: never optimise without measuring
  2. Targets: SLI, SLO and why the average lies
  3. The baseline: the load test
  4. A k6 script for Ribalta's morning peak
  5. Reading the test results
  6. Two practical laws: Little and Amdahl
  7. Where the time goes in a Spring Boot application
  8. The database (I): spotting the N+1
  9. The database (II): indexes and EXPLAIN ANALYZE
  10. The database (III): pagination, projections and batching
  11. HikariCP: sizing the pool sensibly
  12. The JVM: memory, collector and pauses
  13. Threads: Tomcat, the pool and virtual threads
  14. The network: compression and response size
  15. Profiling: async-profiler, JFR and dumps
  16. Worked example: the stations endpoint
  17. Common Mistakes and Tips
  18. Exercises

  1. The method: never optimise without measuring

There is a line from Donald Knuth that everyone quotes by halves. The full version reads: "programmers waste enormous amounts of time thinking about, or worrying about, the speed of noncritical parts of their programs, and these attempts at efficiency actually have a strong negative impact when debugging and maintenance are considered. We should forget about small efficiencies, say about 97 % of the time: premature optimization is the root of all evil. Yet we should not pass up our opportunities in that critical 3 %."

What matters is the ending: there is a critical 3 % and it has to be found. The mistake is not optimising, it is optimising blind. And intuition about where that 3 % lives is notoriously bad: almost every developer bets on their own Java code, when in an application like CicloUrbana the time is nearly always spent waiting on the database or on a remote service.

The working cycle is this:

flowchart LR
    A[Define the target<br/>measurable SLO] --> B[Measure the baseline<br/>load test]
    B --> C[Locate the bottleneck<br/>profiling and traces]
    C --> D[Fix ONE thing]
    D --> E[Measure again]
    E --> F{Is the target<br/>met?}
    F -->|No| C
    F -->|Yes| G[Stop and document]

Three rules govern that cycle. One change at a time: if you touch the pool, the cache and the index all at once and things improve, you do not know which one helped or which one is making something else worse —and in CicloUrbana that discipline is cheap, because every change is an automatic deployment (08-05)—. Stop when the target is met: with no stopping criterion the tuning never ends and ends up adding complexity nobody needs; "fast" is not a target, "p95 under 300 ms with 200 concurrent users" is. And measure where it matters: a System.currentTimeMillis() around a method on your laptop, with an empty database and no concurrency, says nothing about Ribalta at eight in the morning.

  1. Targets: SLI, SLO and why the average lies

Before measuring you have to decide what is measured and what value is acceptable:

Term What it is Example in CicloUrbana
SLI (indicator) The specific metric being observed Latency of POST /api/v1/rentals
SLO (objective) The internal target for that SLI p95 < 300 ms and p99 < 800 ms for 99 % of the month
SLA (agreement) The contractual commitment, with a penalty The council requires 99.5 % monthly availability

The choice of statistic is not a detail: it is the single most important decision in the whole chapter. Suppose 1,000 requests to the rental-start endpoint during a Ribalta morning peak:

Group Requests Latency
Station cached, all well 900 40 ms
Station with many bikes 80 300 ms
Coincides with a nightly batch lock 20 3,000 ms

The average is (900×40 + 80×300 + 20×3000) / 1000 = 120 ms. An excellent number you can take into a meeting without blushing. Now the percentiles: with the 1,000 latencies sorted, position 950 (p95) falls in the 300 ms group, and position 990 (p99) falls in the 3,000 ms group.

p50 = 40 ms · average = 120 ms · p95 = 300 ms · p99 = 3,000 ms

The same data tells two opposite stories. And the one that matters is the second: 20 out of every 1,000 citizens wait three seconds staring at their phone in front of a bike. In a morning peak with 12,000 rentals, that is 240 people every morning. The average hid them because it averages over a long-tailed distribution, which is exactly the shape every real latency distribution has.

Four practical rules. The average is never the SLO: at most it serves to detect a gross regression. p95 describes the typical bad experience and p99 or p99.9 the worst one, and the more critical the service, the further right you have to look. Percentiles do not average: the mean of the p95s of three instances is not the p95 of the whole, something with very concrete technical consequences that we will see in 09-03 with histograms. And latency and availability are looked at together, because an endpoint that returns 500 in 5 ms has a magnificent p99.

  1. The baseline: the load test

Without a baseline there is no improvement, only a feeling of improvement. A load test subjects the application to controlled, reproducible traffic, so that before and after can be compared with the same pattern.

k6 JMeter
Scenarios JavaScript, in the repository XML, usually through a GUI
Learning curve Low for anyone who programs Medium; many concepts of its own
Generator resources Very low (Go, coroutines) High (one thread per virtual user)
Version control Natural: it is code Hard: the .jmx does not review well
CI integration Excellent, official image Possible, heavier
Protocols HTTP, gRPC, WebSocket Very many (JDBC, JMS, LDAP...)
Reports Console, JSON, Prometheus output GUI and HTML reports
When to pick it The default in CicloUrbana Exotic protocols or already-trained teams

We choose k6: the scenario lives next to the code, it runs in the 08-05 pipeline and it does not need a powerful machine to generate 500 virtual users. Three warnings before the script: do not test against production without agreeing it first —you test against pre (07-02) and with realistically sized data, because a database with 12 stations and 30 rentals reveals nothing—; the generator must not be the bottleneck, so if k6 runs on the same laptop as the application you are measuring the laptop; and warm the JVM up, because the first few seconds are interpreted code and a cold pool, and they are discarded.

  1. A k6 script for Ribalta's morning peak

The scenario reproduces what happens between 7:45 and 9:15 in Ribalta: lots of people check nearby stations, some of them start a rental and, a few minutes later, finish it.

import http from 'k6/http';
import { check, sleep, group } from 'k6';
import { Trend, Rate } from 'k6/metrics';

const startLatency = new Trend('rental_start_ms');
const failedRentals = new Rate('failed_rentals');

const BASE = __ENV.BASE_URL || 'https://pre.ciclourbana.ribalta.example';
const STATIONS = [1, 2, 3, 4];

export const options = {
  stages: [
    { duration: '1m',  target: 50  },   // ramp-up: warm the JVM and the pool
    { duration: '3m',  target: 200 },   // climb to the morning peak
    { duration: '5m',  target: 200 },   // plateau: this is where we really measure
    { duration: '1m',  target: 0   },   // orderly ramp-down
  ],
  thresholds: {
    'http_req_failed':   ['rate<0.01'],                 // fewer than 1 % errors
    'http_req_duration': ['p(95)<300', 'p(99)<800'],    // the SLO from section 2
    'rental_start_ms': ['p(95)<400'],
  },
};

export function setup() {                    // once only, shared token
  const res = http.post(`${BASE}/api/v1/auth/login`,
      JSON.stringify({ email: '[email protected]', password: __ENV.PASSWORD }),
      { headers: { 'Content-Type': 'application/json' } });
  return { token: res.json('token') };
}

export default function (data) {
  const headers = { headers: { 'Authorization': `Bearer ${data.token}`,
                               'Content-Type': 'application/json' } };
  const station = STATIONS[Math.floor(Math.random() * STATIONS.length)];

  group('browse stations', () => {
    const res = http.get(`${BASE}/api/v1/stations?page=0&size=20`, headers);
    check(res, { 'stations 200': (r) => r.status === 200 });
    sleep(Math.random() * 2 + 1);          // the citizen looks at the map
  });

  group('start and finish a rental', () => {
    const start = http.post(`${BASE}/api/v1/rentals`,
        JSON.stringify({ originStationId: station, fareType: 'STANDARD' }), headers);
    startLatency.add(start.timings.duration);
    const created = check(start, { 'rental 201': (r) => r.status === 201 });
    failedRentals.add(!created);
    if (!created) return;

    sleep(3);                               // simulated journey
    const finish = http.patch(`${BASE}/api/v1/rentals/${start.json('id')}/finish`,
        JSON.stringify({ destinationStationId: station }), headers);
    check(finish, { 'finish 200': (r) => r.status === 200 });
  });
}

What each piece does and why. stages defines the shape of the load, and the initial ramp is not a courtesy: without it you are measuring the JVM interpreting bytecode and HikariCP opening connections, not the steady state —the plateau is the only part whose numbers are worth anything—. thresholds turns the SLO into a failure condition: if it is not met, k6 exits with a non-zero code and the 08-05 pipeline goes red, so performance stops being an opinion and becomes a test. setup() runs once and shares the token with every virtual user, so you do not measure the cost of login on every iteration. sleep() is essential: with no pauses you are not simulating 200 citizens, you are simulating an attack; think time is what makes the scenario's concurrency resemble the real thing. And your own metrics (Trend, Rate) separate the business SLO —starting a rental— from the aggregate over all requests.

It runs like this:

k6 run --env BASE_URL=https://pre.ciclourbana.ribalta.example \
       --env PASSWORD="$LOAD_PASSWORD" \
       --out json=baseline-results.json peak-hour-load.js

  1. Reading the test results

     http_req_duration..............: avg=214ms min=11ms med=98ms max=4.8s p(90)=402ms p(95)=1.19s
       { expected_response:true }...: avg=201ms min=11ms med=95ms max=4.8s p(90)=380ms p(95)=1.11s
     http_req_failed................: 0.71%  432 out of 60731
     http_reqs......................: 60731  112.4/s
     iterations.....................: 15182  28.1/s
     vus............................: 200    min=1 max=200
     rental_start_ms................: avg=486ms med=210ms p(95)=2.41s
     ✓ stations 200
     ✗ rental 201  99.29% ✓ 15074 ✗ 108

     ✗ http_req_duration: p(95)<300  ->  p(95)=1.19s

How to read it, in order. Did any threshold fail? Yes: the overall p95 is 1.19 s against the SLO's 300 ms, so the test has done its job. Are there errors? 0.71 %, below the 1 % threshold, but it is not noise and you have to look at what kind they are: a 500 is a failure, whereas a 409 may be the partial unique index from 04-08 rejecting a second rental from the same user, which is correct. Average versus percentiles? avg=214ms against p(95)=1.19s and max=4.8s: the long tail from section 2, exactly. Which specific operation? rental_start_ms has a p95 of 2.41 s with a median of 210 ms, so the problem is not spread out: it is in one place and only under load —an operation with a good median and a p95 ten times worse is almost always waiting on a shared resource: a pool connection, a row lock or a GC pause—. Does it scale? 112 requests per second with 200 virtual users; if doubling the users does not raise throughput but does raise latency, you have hit saturation and there is a limited resource behind it.

That is the baseline. It is stored in the repository with the date and the deployed version, because the only honest way to claim "this is faster" is to compare against it.

  1. Two practical laws: Little and Amdahl

Little's law relates three quantities in any stable system:

L = λ × W
concurrency = throughput × latency

With the numbers from the test: λ = 112 req/s, W = 0.214 s on average, so L = 24 requests inside the system at once. That number is gold:

  • If there are 24 concurrent requests and the HikariCP pool has 10 connections, requests are waiting for a connection. There is the candidate.
  • If Tomcat has 200 threads and only 24 are in use, raising the thread count fixes nothing. It is the most common mistake in tuning by intuition.
  • The other way round: if the target is 300 requests per second with 200 ms of latency, you will need to sustain L = 60 simultaneous requests. The law tells you the requirement before you test.

Amdahl's law says how much the whole can improve by speeding up one part:

maximum_speedup = 1 / ((1 - P) + P / S)

where P is the fraction of time taken by the optimised part and S how much it is sped up. Two CicloUrbana cases:

What is optimised P S Overall speedup
The SQL queries, which are 70 % of the time 0.70 10× 2.7×
JSON serialisation, which is 5 % 0.05 10× 1.05×
The queries, removed entirely with a cache 0.70 ∞ 3.3× (the ceiling)

The reading is devastating: making serialisation ten times faster improves the whole by 5 %. Half a week's work for a gain nobody can see. That is why the first step is always to work out how the time is split, and why the table in the next section is ordered.

  1. Where the time goes in a Spring Boot application

Typical split in a management application like CicloUrbana, in the order in which you should look:

Order Source Usual share Characteristic symptom Tool
1 Database: N+1, missing index, heavy query 40-80 % Latency grows with the volume of data SQL log, query counter, EXPLAIN ANALYZE
2 Resource waits: connection pool, locks 0-40 % under load Good median, dreadful p99 hikaricp.connections.* (09-03), pg_locks
3 External network: payment gateway (07-06) 0-30 % Constant latency, insensitive to volume Traces (09-06), client metrics
4 Serialisation and response size 5-15 % High CPU, megabyte responses CPU profiling
5 GC and memory 1-10 % Periodic spikes, everything pausing at once -Xlog:gc, jvm.gc.pause
6 Your own Java code 1-10 % One specific method burns in the flame graph async-profiler, JFR

The practical conclusion: always start with the database and work down the list. And do not move to the next level until you have exhausted the previous one, because the order reflects Amdahl's law applied to the average case.

  1. The database (I): spotting the N+1

We revisit the problem from 04-04 with an operational formulation: the number of queries in an endpoint must be constant, not proportional to the number of results. First, seeing it. In dev it is enough to switch the SQL on:

spring:
  jpa.properties.hibernate:
    format_sql: true
    generate_statistics: true          # per-session summary at the end
logging.level:
  org.hibernate.SQL: DEBUG
  org.hibernate.orm.jdbc.bind: TRACE   # the parameters, in Hibernate 6

The generate_statistics summary is the key piece of data:

Session Metrics { 201 JDBC statements executed;
                  1876453200 nanoseconds spent executing 201 JDBC statements; }

201 statements to list 200 stations. No further diagnosis needed.

Reading the SQL by hand does not scale: as soon as the endpoint gets complex, nobody counts lines. The solution is a per-request query counter, with datasource-proxy:

<dependency>
    <groupId>net.ttddyy</groupId>
    <artifactId>datasource-proxy</artifactId>
    <version>1.10</version>
</dependency>

You wrap the DataSource in a BeanPostProcessor annotated with @Profile({"dev","test"}) —never in production, because it intercepts every query— returning ProxyDataSourceBuilder.create(ds).name("ciclourbana").countQuery().logSlowQueryBySlf4j(200, MILLISECONDS).build(): countQuery() accumulates the count per thread and logSlowQueryBySlf4j warns about queries taking more than 200 ms. On top of that, a filter writes at the end of every request how many queries were executed —and since the TraceFilter from 03-06 has already put the traceId in the MDC, the line is directly correlatable with the rest of the log:

@Component
@Profile({"dev", "test"})
public class QueryCounterFilter extends OncePerRequestFilter {

    @Override
    protected void doFilterInternal(HttpServletRequest req, HttpServletResponse res,
                                    FilterChain chain) throws ServletException, IOException {
        QueryCountHolder.clear();
        long t0 = System.nanoTime();
        try {
            chain.doFilter(req, res);
        } finally {
            QueryCount counter = QueryCountHolder.get("ciclourbana");
            long ms = (System.nanoTime() - t0) / 1_000_000;
            if (counter != null && counter.getTotal() > 10) {
                log.warn("{} {} -> {} queries in {} ms",
                        req.getMethod(), req.getRequestURI(), counter.getTotal(), ms);
            }
            QueryCountHolder.clear();     // just like MDC.remove(): the thread is reused
        }
    }
}

With this, an endpoint that degrades warns you by itself the moment somebody slips a getBikes() inside a loop. And the technique reaches all the way into the tests: in a @DataJpaTest (06-04) you can assert assertThat(counter.getTotal()).isEqualTo(1), turning "there is no N+1" into a genuine regression test.

The fix we already know from 04-04 and 04-06: @EntityGraph(attributePaths = "bikes") or JOIN FETCH when the entities are needed, @BatchSize when the collection is paginated, and —often the best— a projection that makes the database do the counting and brings back no entities at all.

  1. The database (II): indexes and EXPLAIN ANALYZE

An index is an auxiliary structure that avoids reading the whole table. The question is not "should I add an index?" but "which columns do my real queries filter and sort by?". And the answer comes from PostgreSQL, not from intuition.

The citizen's history query:

EXPLAIN (ANALYZE, BUFFERS)
SELECT r.id, r.started_at, r.ended_at, r.total_amount
FROM rentals r
WHERE r.user_id = 4711 AND r.status = 'FINISHED'
ORDER BY r.started_at DESC
LIMIT 20;

Before touching anything, with 3.2 million rows:

Limit  (cost=98234.11..98234.16 rows=20) (actual time=812.443..812.451 rows=20 loops=1)
  ->  Sort  (cost=98234.11..98301.44 rows=26932) (actual time=812.441..812.445 rows=20)
        Sort Key: started_at DESC
        Sort Method: top-N heapsort  Memory: 27kB
        ->  Seq Scan on rentals r  (cost=0.00..97517.00) (actual time=0.031..798.220)
              Filter: ((user_id = 4711) AND ((status)::text = 'FINISHED'::text))
              Rows Removed by Filter: 3172896
              Buffers: shared hit=1204 read=61313
Execution Time: 812.478 ms

How to read it, from the inside out:

Line What it means
Seq Scan It reads the entire table. The principal offence.
Rows Removed by Filter: 3172896 It read 3.2 million rows only to discard them. The clearest sign of a missing index.
cost= vs actual time= Planner estimate vs reality. If they diverge a lot, statistics are missing: ANALYZE rentals.
Buffers: read=61313 Blocks read from disk (8 KB each): ~480 MB moved to return 20 rows.
Sort Method: top-N heapsort Sorts in memory; if it said external merge Disk, it would be sorting on disk.
Execution Time The number that matters.

idx_rentals_user from 04-08 already existed, but the planner discards it: with 27,000 rentals for that user, jumping from the index to the table 27,000 times costs it more than sweeping the table. The solution is a composite index covering the filter and the ordering:

CREATE INDEX CONCURRENTLY idx_rentals_history
    ON rentals (user_id, status, started_at DESC);
Limit  (cost=0.56..12.83 rows=20) (actual time=0.041..0.061 rows=20 loops=1)
  ->  Index Scan using idx_rentals_history on rentals r
        Index Cond: ((user_id = 4711) AND ((status)::text = 'FINISHED'::text))
        Buffers: shared hit=24
Execution Time: 0.084 ms

From 812 ms to 0.08 ms: almost ten thousand times. There is no Java-code optimisation that can come close to that, and that is the argument of the whole lesson.

The column order in a composite index is not arbitrary. The rule, in this order: equality columns first (user_id, status), then the range or ordering ones (started_at DESC). An index on (user_id, status, started_at) serves queries by user_id, by user_id + status and by all three; it does not serve a query by status alone. That is the leftmost-prefix principle, and it explains why one well-designed index usually makes two or three others unnecessary.

Partial indexes. When only a subset matters:

-- Only open rentals: a few dozen against millions
CREATE INDEX idx_rentals_in_progress ON rentals (origin_station_id)
    WHERE ended_at IS NULL;

It takes kilobytes instead of hundreds of megabytes and it is the same mechanism as uk_rentals_user_in_progress from 04-08.

The cost of over-indexing. An index is not free: it takes space, every INSERT, UPDATE and DELETE has to update it, and it makes the planner's job harder. A table with twelve indexes can take three times as long to write to. To find out which ones are surplus:

SELECT relname, indexrelname, idx_scan, pg_size_pretty(pg_relation_size(indexrelid))
FROM pg_stat_user_indexes WHERE idx_scan = 0 ORDER BY pg_relation_size(indexrelid) DESC;

idx_scan = 0 after weeks in production means that index is pure cost. And to find the expensive queries, the pg_stat_statements extension sorted by total_exec_time answers the question "which query is consuming 40 % of the database time".

  1. The database (III): pagination, projections and batching

The large OFFSET. Pageable generates LIMIT 20 OFFSET 200000, and PostgreSQL has to produce and discard 200,000 rows before returning 20. Page 1 flies; page 10,000 takes seconds. For deep listings —the full rental history, an export— you use keyset pagination:

// Instead of: findAll(PageRequest.of(page, 20))
@Query("""
       select r from Rental r
       where r.user.id = :userId
         and (r.startedAt < :lastStartedAt or (r.startedAt = :lastStartedAt and r.id < :lastId))
       order by r.startedAt desc, r.id desc
       """)
List<Rental> nextPage(Long userId, Instant lastStartedAt, Long lastId,
                      Limit limit);

The client sends the last row it saw instead of a page number. The query uses the index to position itself rather than to count, and the cost is constant at any depth. Its limits: it does not allow jumping to page 500 or showing the total —and that count(*) in every Page is, very often, more expensive than the data query: which is why Slice exists, avoiding it.

Projections versus entities (04-06). Loading the full entity brings back every column, creates managed objects in the persistence context and forces Hibernate to do dirty checking on each one at commit time:

Entity Projection
Columns read All of them Only the declared ones
Managed objects Yes, with memory and checking cost No
Risk of LazyInitializationException Yes No
When to use it When you are going to modify When you are only going to display

CicloUrbana's rule: read-only endpoints return projections. It is simultaneously faster and safer.

readOnly and batching. @Transactional(readOnly = true) (04-07) makes Hibernate use FlushMode.MANUAL and skip keeping the original state for comparison: less memory and less CPU on every read. And for the nightly importer's bulk writes:

spring:
  jpa:
    properties:
      hibernate:
        jdbc.batch_size: 50          # groups 50 statements per round trip
        order_inserts: true          # groups them by table so they can be batched
        order_updates: true
        batch_versioned_data: true   # needed with @Version (04-03)

Inserting 10,000 rows goes from 10,000 network round trips to 200. One requirement: the identifier generator cannot be IDENTITY, because it forces each INSERT to be executed separately in order to learn the key; that is why CicloUrbana has used sequences with allocationSize = 50 since 04-03.

  1. HikariCP: sizing the pool sensibly

Intuition says "more connections, more throughput". It is false, and the reason is that a busy connection is a CPU core and a disk on the database working. When there are more active connections than real capacity, the database server spends its time context-switching and contending for locks: throughput falls and latency rises.

The formula HikariCP itself documents:

connections = (db_server_cores × 2) + effective_disks

CicloUrbana's PostgreSQL instance has 4 cores and network SSD storage (1 effective "disk"): 4 × 2 + 1 = 9, rounded up to 10. Yes, ten connections serve 112 requests per second: by Little's law, if a query takes 5 ms, each connection can handle 200 queries per second.

spring:
  datasource:
    hikari:
      maximum-pool-size: 10
      minimum-idle: 10             # fixed: avoids the latency of opening under load
      connection-timeout: 3000     # fail fast, do not queue indefinitely
      max-lifetime: 1800000        # below the server-side timeout
      leak-detection-threshold: 20000
      pool-name: ciclourbana-pool

Four details with consequences. minimum-idle equal to maximum-pool-size: an elastic pool saves a few irrelevant resources and adds the latency of a TCP handshake plus authentication exactly when the peak arrives. connection-timeout: 3000: if there is no connection within 3 seconds an exception is thrown, whereas a value of 30 s turns a degradation into a queue that ends up consuming Tomcat's 200 threads —that is how a database problem brings down the entire application—. leak-detection-threshold warns about a connection held for more than 20 s, the classic symptom of an HTTP call inside a transaction. And max-lifetime must be lower than the server-side close time, or the pool will hand out dead connections.

Detecting the wait is what decides whether the pool is badly sized. The hikaricp.connections.pending metric (09-03) measures how many threads are waiting and hikaricp.connections.acquire how long they take. If pending is persistently above zero there are two possible causes and only one of them is fixed by raising the pool: if the queries are slow or the transactions enormously long, fix that and not the pool; if the database has capacity to spare and the concurrency is real, raise the pool moderately and measure again.

  1. The JVM: memory, collector and pauses

Memory in a container (07-04). The modern JVM detects cgroup limits, but by default it reserves only 25 % of the available memory for the heap. In a 1 GB container that is 256 MB, and the rest is wasted:

ENV JAVA_TOOL_OPTIONS="-XX:MaxRAMPercentage=75 -XX:InitialRAMPercentage=50 \
    -XX:+ExitOnOutOfMemoryError -Xlog:gc*:file=/tmp/gc.log:time,uptime:filecount=5,filesize=10M"

The 75 % —not 100 %— leaves room for what is not heap: metaspace, thread stacks, direct buffers and the JVM itself. If the heap takes up the container's whole limit, the process dies with OOMKilled (code 137) without leaving so much as an exception, and Kubernetes' restartPolicy restarts it in a loop. +ExitOnOutOfMemoryError is preferable to limping along: an instance out of memory responds badly and keeps receiving traffic; dead, the 07-01 probe takes it out of the load balancer.

Choosing a collector:

G1 (default) ZGC (-XX:+UseZGC) Parallel
Goal Balance Minimum latency Maximum throughput
Typical pauses 10-200 ms < 1 ms, with huge heaps Hundreds of ms
Recommended heap 2-32 GB 8 GB - several TB < 4 GB
CPU and memory cost Moderate ~10-15 % more of both Low
When to use it CicloUrbana today If pauses are what set your p99 Nightly batches, not APIs

The real criterion: do not change collector until you have confirmed, in the GC logs, that pauses explain your p99. With a 2 GB heap and G1, CicloUrbana's pauses are 15-40 ms; the p95 of 1.19 s does not come from there.

Reading the GC logs:

[12.481s][info][gc] GC(38) Pause Young (Normal) (G1 Evacuation Pause) 1204M->318M(2048M) 22.418ms
[41.902s][info][gc] GC(72) Pause Full (System.gc()) 1902M->1841M(2048M) 1842.771ms

What to look at. The notation 1204M->318M(2048M) is before → after (total): it reclaimed 886 MB, so it is healthy. By contrast 1902M->1841M reclaimed 61 MB out of 1.9 GB, that is, the memory no longer comes down —a leak or an insufficient heap—, which is exactly the symptom anticipated at the close of 08-05. The 1.8 s Pause Full stops all threads and a single one is enough to explain a disastrous p99; if they repeat, an OutOfMemoryError is on its way. And the frequency matters as much as the duration: short young pauses every few seconds are normal, but every 200 ms means garbage is being generated by the fistful, almost always by loading entities nobody needs —section 10 again—.

  1. Threads: Tomcat, the pool and virtual threads

server:
  tomcat:
    threads:
      max: 200            # threads that serve requests
      min-spare: 20
    accept-count: 100     # operating-system queue when all 200 are busy
    max-connections: 8192 # connections accepted simultaneously
    connection-timeout: 20s

The relationship between the two pools is the source of an expensive misunderstanding. With 200 Tomcat threads and 10 HikariCP connections, up to 190 threads can be blocked waiting for a connection. That is not a design flaw: it is a deliberate funnel that protects the database. What is a flaw is not bounding the wait —hence the connection-timeout: 3000 from section 11—.

And raising threads.max to 800 almost never helps: if the bottleneck is the 10 connections, the 600 new threads only add 600 stacks of 1 MB and more context switching. Little's law tells you how many threads you really need: threads ≈ λ × W; with 112 req/s and 214 ms, about 24.

Virtual threads (07-03), on Java 21 and Spring Boot 3.2+:

spring.threads.virtual.enabled: true

Each request is served on a virtual thread which, when it blocks on I/O, releases the platform thread instead of occupying it. For an application like CicloUrbana —blocking and with a lot of database waiting— it is the cheapest way to sustain high concurrency without a reactive stack. With two warnings we have already seen: synchronized around a blocking operation pins the virtual thread and cancels the benefit, and ThreadLocals —the TraceFilter's MDC, the SecurityContext— still work, but there is no longer a bounded pool limiting concurrency: the limit becomes the connection pool, so its connection-timeout matters even more.

  1. The network: compression and response size

The time the citizen perceives includes the transfer. A listing of 200 stations in JSON is around 180 KB; over a Ribalta mobile network, half a second on its own.

server.compression:
  enabled: true
  mime-types: application/json,application/problem+json,text/html,text/plain
  min-response-size: 1KB          # compressing 200 bytes costs more than it saves

With JSON, gzip cuts between 70 % and 90 % because the format repeats the keys in every element: 180 KB becomes around 20 KB. The cost is server CPU; if there is a proxy or an ALB in front (08-03), it is often better for it to do the compressing.

But the best compression is not sending the data at all. This is where the DTOs from 03-05 stop being a design matter and become performance: StationResponse publishes six fields instead of dumping the entity with its auditing, its version and its collection of bikes. Fewer serialised bytes, less CPU, less network and less memory. Three rules: always paginate listings (never a findAll() without a Pageable), do not nest whole collections in the response —link to a subresource—, and use ETag (03-03) so that a client that already has the data receives a two-hundred-byte 304 Not Modified.

  1. Profiling: async-profiler, JFR and dumps

When the database is already clean and the time still goes somewhere, it is time to profile.

Tool What it gives Cost When
async-profiler CPU, allocations, locks, with a flame graph ~1 % One-off investigation, even in prod
JFR Continuous recording of JVM events ~1 % Leave it always on in prod
/actuator/threaddump A snapshot of every thread and its state None Application hung or slow right now
/actuator/heapdump A full heap dump High: it pauses the JVM Suspected leak; handle with care
# async-profiler: 30 seconds of CPU in a flame graph
./profiler.sh -d 30 -e cpu -f /tmp/profile.html $(pgrep -f ciclourbana.jar)

# Permanent JFR, with an on-demand dump
java -XX:StartFlightRecording=disk=true,maxsize=200M,settings=profile -jar app.jar
jcmd $(pgrep -f ciclourbana.jar) JFR.dump name=1 filename=/tmp/ciclourbana.jfr

How to read a flame graph. The horizontal axis is not time: it is the proportion of samples. Each bar is a method and above it are the methods it calls. You read it from the bottom up looking for wide plateaus: a wide bar means that method was on the stack in many samples. If the plateau is right at the top, that method is burning CPU itself; if it is wide but with towers on top, the cost is in what it calls. In CicloUrbana, a typical profile shows a wide plateau under PgConnection.execSQLQuery —waiting on the database, which is what you would expect— and, if something is wrong in the code, an unexpected tower under ObjectMapper.writeValue or under an entity equals.

And the most profitable use of /actuator/threaddump: with the application running slowly, you download it and count the threads by state. Fifty http-nio-8080-exec-* threads WAITING on HikariPool.getConnection is a closed diagnosis, with no need to profile anything.

  1. Worked example: the stations endpoint

Symptom. GET /api/v1/stations?page=0&size=20 has a p95 of 2.4 s in the load test. The median is 210 ms.

Step 1 — measure. The QueryCounterFilter from section 8 writes this in the pre log:

WARN [7f3a91c2] GET /api/v1/stations -> 43 queries in 2380 ms

43 queries for 20 stations: 1 + 20 + 20 + 2. The pattern is unmistakable.

Step 2 — locate. The code:

@Transactional(readOnly = true)
public PageResponse<StationResponse> list(Pageable pageable) {
    return PageResponse.of(stationRepository.findAll(pageable)
            .map(s -> new StationResponse(
                    s.getId(), s.getName(), s.getAddress(),
                    s.getBikes().size(),                        // lazy query (20)
                    countAvailable(s.getId()))));               // another query (20)
}

Two chained N+1s. And countAvailable runs select count(*) from bikes where station_id = ? and status = 'AVAILABLE', whose EXPLAIN ANALYZE reveals a Seq Scan: idx_bikes_status exists, but on its own it does not filter well.

Step 3 — fix. Two changes, one per cause. A projection that makes the database do the counting in a single query:

public interface StationRepository extends JpaRepository<Station, Long> {

    @Query("""
           select s.id as id, s.name as name, s.address as address,
                  size(s.bikes) as total,
                  (select count(b) from Bike b
                    where b.station = s and b.status = 'AVAILABLE') as available
           from Station s where s.active = true
           """)
    Page<StationSummary> pagedSummary(Pageable pageable);
}

And the composite index that supports that subquery:

-- V13__index_bikes_station_status.sql
CREATE INDEX CONCURRENTLY idx_bikes_station_status
    ON bikes (station_id, status);

Equality first, and with both filter columns the index covers the query: PostgreSQL counts without touching the table.

Step 4 — measure again. Same k6 test, same machine, same data:

Metric Before After Factor
Queries per request 43 1 43×
p50 210 ms 28 ms 7.5×
p95 2,410 ms 91 ms 26×
p99 3,980 ms 148 ms 27×
Throughput (req/s) 112 604 5.4×
Waiting connections (peak) 37 0 —
Bytes per response 184 KB 21 KB 8.7× (projection + gzip)

Four observations are worth more than the numbers. Not a single cache or machine was added: unnecessary work was removed. pending dropped to zero on its own, which proves the pool was not badly sized but held hostage by surplus queries —raising it to 50 would have hidden the problem and punished the database—. p95 improved more than the median (26× against 7.5×), which is typical when the cause was waiting on a shared resource. And the SLO from section 2 —p95 < 300 ms— is met, so we stop.

This was the easy case: there was wasted work. When there is none left and the query is minimal and indexed, but it is repeated a thousand times a minute with the same result, the next lever is a different one: not running it. That is caching, and it is the next lesson.

Common Mistakes and Tips

Optimising with no baseline and using the average as a target. Without an earlier number, "it is faster" is an impression: store the k6 result with the date and the version in the repository. And the average hides exactly the worst-treated users, so the SLO is written in p95 and p99.

Changing several things at once. If you improve the index, raise the pool and enable compression in the same deployment, you will not know which one helped nor be able to revert the one that is surplus.

Raising the connection pool as a first measure. It nearly always makes things worse: it moves the congestion from your application to the database, where it is harder to see and affects everybody.

Measuring on your laptop with toy data. A Seq Scan over 40 rows is instantaneous. Performance problems are problems of volume and concurrency, and they reproduce in pre with realistic data.

Leaving org.hibernate.SQL: DEBUG or datasource-proxy on in production. Both add cost per query and fill the disk: they go under @Profile({"dev","test"}), and if you need to see SQL in production you raise the level at runtime with /actuator/loggers (07-01) and lower it afterwards.

Confusing a Full GC with "we need more memory". Sometimes yes; very often it is that entities nobody needs are being loaded. Look at section 10 first.

Tip: put a query limit per request in the tests, with an assertThat(counter.getTotal()).isLessThanOrEqualTo(3) in a @DataJpaTest: it is the only way to stop an N+1 coming back in three months' time. Run the load test in the nightly pipeline too, because with thresholds a regression is detected the day it is introduced and not the day the council calls. And EXPLAIN ANALYZE before creating an index, with a review of pg_stat_user_indexes every quarter to drop the ones nobody uses.

Exercises

Exercise 1: diagnosing from the signals

After a deployment, CicloUrbana's operations team observes: p50 of POST /api/v1/rentals = 45 ms (unchanged), p99 = 4.2 s (previously 300 ms), application CPU at 20 %, database CPU at 25 %, hikaricp.connections.pending spiking to 60, no Full GC at all, and the query-counter log saying "3 queries in 4,100 ms". Formulate the most likely hypothesis, say what you would check to confirm it and what you would not do.

Exercise 2: index and EXPLAIN

The council's dashboard runs this query every minute and it takes 1.8 s:

SELECT origin_station_id, count(*) FROM rentals
WHERE started_at >= now() - interval '1 hour' AND status = 'IN_PROGRESS'
GROUP BY origin_station_id;

EXPLAIN ANALYZE shows Seq Scan on rentals with Rows Removed by Filter: 3198412. Propose the index, justify the column order, decide whether it should be partial and estimate the effect.

Exercise 3: sizing with Little's law

CicloUrbana has to sustain 400 requests per second with p95 < 250 ms. The measured average latency is 180 ms, of which 120 ms are database (two queries of 60 ms). The PostgreSQL server has 8 cores and SSD. Work out the required concurrency, size the HikariCP pool and the Tomcat threads, and say whether the system can meet the target or where it will break first.

Solutions

Solution 1.

Hypothesis: waiting for a pool connection, not application slowness. The signals fit one by one: an untouched median indicates the fast path has not changed; a p99 through the roof with low CPU on both sides rules out compute saturation; pending spiking to 60 says literally that 60 threads are waiting for a connection; "3 queries in 4,100 ms" is the exact signature —few queries, a lot of time—, because the time is not spent running SQL but waiting to be able to run it; and the absence of Full GC rules out memory pauses.

Most likely cause: something is holding connections longer than it should. The two usual suspects: an HTTP call inside a transaction —very likely here, because the deployment touched charging and the 07-06 gateway can take seconds— or a transaction stretched out by work that does not need the database.

How to confirm it: with /actuator/threaddump during a spike, looking for http-nio-* threads WAITING on HikariPool.getConnection and —above all— threads that already hold a connection and are blocked on a gateway socket; by enabling leak-detection-threshold: 20000, whose stack trace points at the guilty method; by looking at the Resilience4j metrics (07-06), because if the gateway's latency rose at the same time the diagnosis is closed; and by watching hikaricp.connections.usage, which measures how long each connection is held.

What I would NOT do: raise maximum-pool-size. With database CPU at 25 % the problem is not lack of capacity, and more connections held by remote calls only prolongs the agony. Nor would I raise the Tomcat threads: it would create more threads to wait for the same thing. The fix is to move the gateway call outside the transaction —commit first and charge afterwards, in the AFTER_COMMIT of 07-03— and to check that connection-timeout is measured in seconds, not thirty of them.

Solution 2.

CREATE INDEX CONCURRENTLY idx_rentals_started_status
    ON rentals (status, started_at, origin_station_id);

Column order: status first because it is the equality predicate; started_at next because it is a range one —a range column in an index "consumes" the rest for any future equalities, so it goes after all the equalities—; and origin_station_id last so that the index covers the query: PostgreSQL can group by reading the index alone (Index Only Scan) without visiting the table.

Partial? Yes, and it is the best decision in the exercise:

CREATE INDEX CONCURRENTLY idx_rentals_in_progress_started
    ON rentals (started_at, origin_station_id) WHERE status = 'IN_PROGRESS';

IN_PROGRESS rentals number a few hundred out of 3.2 million. The partial index takes kilobytes instead of ~150 MB, is maintained almost for free on every write and, since every indexed row already satisfies the status filter, the planner only has to walk the last hour's range.

Estimated effect: from a Seq Scan over 3.2 million rows (~1.8 s) to walking a few hundred contiguous index entries: under 5 ms, two or three orders of magnitude. Mandatory verification: repeat EXPLAIN (ANALYZE, BUFFERS) and check that Index Scan/Index Only Scan appears, that Rows Removed by Filter disappears and that Buffers: read drops to a few dozen. And CONCURRENTLY because the table is in production: without it, the CREATE INDEX blocks writes for the whole build (04-08).

Solution 3.

Required concurrency (Little): L = λ × W = 400 × 0.180 = 72 simultaneous requests inside the system.

Connection pool: the formula gives 8 × 2 + 1 = 17, rounded to 20. Does it hold? Each request occupies a connection for 120 ms; one connection serves 1 / 0.120 = 8.3 requests per second; 20 connections give 20 × 8.3 = 166 req/s. It does not reach 400: this is where it breaks first.

What to do, in order. First, reduce the database time per request, which is the right lever: two 60 ms queries to start a rental is an enormous amount and with the right indexes they drop to 5 ms, so that with W_db = 10 ms one connection serves 100 req/s and 20 connections give 2,000 req/s, five times the target. Only if capacity is still missing after optimising, scale horizontally (08-04): three instances with 20 connections each are 60 connections against the database, close to the sensible limit for 8 cores, and the next step would be read replicas. What would be a mistake is raising the pool to 80: 80 active connections over 8 cores multiply the context switching and the lock contention, aggregate throughput falls and p95 rises.

Tomcat threads: with L = 72, the default 200 are more than enough; threads.max: 200 and accept-count: 100 are correct. With virtual threads enabled, the effective limit becomes the connection pool, which reinforces the conclusion: the target is met by optimising the queries, not by enlarging pools.

Resulting latency: with the queries at 10 ms, W ≈ 70 ms and L = 400 × 0.07 = 28. Well below the 250 ms p95 SLO, with room for variability.

Conclusion

CicloUrbana is no longer tuned by intuition. You have a method that skips no steps —define the target, measure the baseline, locate the bottleneck, fix one thing, measure again— and you know why the average lies and why the SLO is written in p95 and p99, with the 20 citizens in every 1,000 that the average was hiding. You know how to set up a k6 load test that reproduces Ribalta's morning peak, with a ramp, a plateau and thresholds that turn the 08-05 pipeline red, and how to read its output in the right order: thresholds, errors, percentiles versus average, specific operation and saturation. Little's law tells you how much concurrency there really is inside the system and, with it, whether a pool is properly sized; Amdahl's tells you that optimising serialisation by 900 % improves the total by 5 %, and that is why the tour is ordered.

You have done that whole tour. The database first: spotting the 04-04 N+1 with generate_statistics and with a per-request query counter that warns you by itself, and fixing it with @EntityGraph, JOIN FETCH or —better— a projection; reading an EXPLAIN ANALYZE telling Seq Scan from Index Scan and knowing what Rows Removed by Filter and Buffers mean; designing composite indexes with the equalities in front and the ordering behind, partial indexes that take kilobytes, and dropping the ones nobody uses. Then keyset pagination against the large OFFSET, projections against entities, readOnly and Hibernate batching. Then HikariCP, with the formula and the explanation of why a large pool makes things worse, and pending as the signal that tells "not enough pool" from "too many queries". And finally the JVM —MaxRAMPercentage, G1 against ZGC, reading -Xlog:gc and recognising memory that goes up and never comes down—, Tomcat's threads and their relationship with the pool, the virtual threads of 07-03 as an alternative, compression and profiling with async-profiler, JFR and the dumps from 07-01.

The worked example sums up the whole lesson: an endpoint with a p95 of 2.4 s, 43 queries per request and a Seq Scan, which after removing work —a projection and an index— responds in 91 ms and multiplies throughput by five, with no extra machine and no cache. That order matters: unnecessary work is eliminated first. But when the work is already minimal and even so it is repeated a thousand times a minute to return the very same thing —Ribalta's station catalogue, which changes once a month and is queried a hundred times a second—, one different lever remains: not running it. The next lesson, Caching with Spring Cache, develops it in full: which data deserves a cache and which does not, @Cacheable and its traps, Caffeine and Redis, and the genuinely hard part, which is invalidation.

Spring Boot Course

Module 1: Introduction to Spring Boot

Module 2: Spring Boot Core Concepts

Module 3: Building RESTful Web Services

Module 4: Data Access with Spring Boot

Module 5: Security in Spring Boot

Module 6: Testing in Spring Boot

Module 7: Advanced Spring Boot Features

Module 8: Deploying Spring Boot Applications

Module 9: Performance and Monitoring

Module 10: Best Practices and Tips

© Copyright 2026. All rights reserved