Search code examples
postgresqlperformance-testingdatabase-performancepgbench

How to get P99 latency result using pgbench?


I am trying to use pgbench to perform a test on PolarDB for postgreSQL.

This is the command I used to perform the test.

pgbench -M prepared -r -c 16 -j 4 -T 30 -p 10001 -d pgbench -l

And this is the result

... ...
client 2 sending P0_10
client 2 receiving
client 2 receiving
client 14 receiving
transaction type: <builtin: TPC-B (sort of)>
scaling factor: 32
query mode: prepared
number of clients: 16
number of threads: 4
duration: 30 s
number of transactions actually processed: 49126
latency average = 9.772 ms
tps = 1637.313156 (including connections establishing)
tps = 1637.438330 (excluding connections establishing)
statement latencies in milliseconds:
         1.128  \set aid random(1, 100000 * :scale)
         0.068  \set bid random(1, 1 * :scale)
         0.040  \set tid random(1, 10 * :scale)
         0.041  \set delta random(-5000, 5000)
         0.104  BEGIN;
         3.815  UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
         0.590  SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
         1.188  UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
         1.440  UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
         0.327  INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
         0.481  END;

I wonder if there is a way to calculate P99 from the result, or there is some extra parameter I need provide to pgbench?


Solution

  • The -l caused it to write log files. You need to look in those log files for the latencies. For me that looks something like this:

    cat pgbench_log.107915*|wc
      36635  219810 1033548
    sort pgbench_log.107915* -k3rn|head -n 366|tail -n 1
    13 990 65184 0 195589 166574
    

    so about 65.184 ms was the 99% latency. I would question if that actually means anything, though. After all, the very last transaction had to wait nearly 30 seconds before it even got is turn on the server, so why wasn't its 'latency' 30 seconds? What about the transactions that never got their turn at all?