I'm developing an server-side app for mobile game backed with postgresql and I'm using pg with Knex("pg": "6.1.2" and "knex": "0.12.6"). Not so long ago I faced a problem with select perfomance degradation. Latest Postgresql and v4.7.2 Node
I've benchmarked my app with 40 fictive ccu. So I measured time between Query
constructor and Query.prototype.handleReadyForQuery
and what i've got:
{"select count(*) from \"player_battles\" where (\"attacking_player\" = $1 or \"defending_player\" = $2) and attacking_player <> defending_player": [27, 74, 92, 156, 170, 203, 217, 230, 243, 251, 261, 269, 288, 303, 313, 328, 342, 352, 361, 384, 395, 407, 420, 428, 440, 448, 460, 471, 483, 494, 507, 515, 537, 538, 539, 30, 40, 60, 1564, 2273, 2287, 2291, 2320, 2327, 2346, 2354, 2370, 2380, 2388, 2402, 2411, 2419, 2429, 2436, 2444, 4014, 4412, 4421, 4421, 4422, 4423, 4423, 4424, 4425, 4426, 4427, 4427, 4428, 4429, 4429, 18, 35, 60, 78, 113, 125, 151, 161, 170, 178, 185, 197, 611, 1972, 1987, 1988, 1988, 1989, 1991, 1992, 1993, 1993, 1994, 1995, 1996, 1996, 1997, 1997, 1999, 1999, 2000, 2001, 2002, 2002, 2002]}
(Array of numbers are representing times to complete particular query ms)
4429ms, Carl! Unpleasant surprize.
Obviously the problem lies in unoptimized sql or bad indexing, but analyzing logs with pgBadger showed me that: https://gyazo.com/4855a0eceac8669ab5c21564a392b357
Any ideas?
Related Issue @ Github: https://github.com/brianc/node-postgres/issues/1243
Previous question: Knex with PostgreSQL select query extremely performance degradation on multiple parallel requests
UPD Here is screenshot of "General activity": https://gyazo.com/b2781069c87f88a2d4034345d58f91a3
UPD2
Example query
SELECT COUNT(*)
FROM "player_battles"
WHERE ("attacking_player" = $1
OR "defending_player" = $2)
AND attacking_player <> defending_player
(where $1 and $2 are 1
and 2
)
Target table ddl
CREATE TABLE public.player_battles
(
id integer NOT NULL DEFAULT nextval('player_battles_id_seq'::regclass),
attacking_player integer NOT NULL,
defending_player integer NOT NULL,
is_attacking_won boolean NOT NULL,
received_honor integer NOT NULL,
lost_honor integer NOT NULL,
gold_stolen bigint,
created_at bigint NOT NULL DEFAULT '0'::bigint,
attacking_level_atm integer NOT NULL DEFAULT 0,
defending_level_atm integer NOT NULL DEFAULT 0,
attacking_honor_atm integer NOT NULL DEFAULT 0,
defending_honor_atm integer NOT NULL DEFAULT 0,
no_winner boolean NOT NULL DEFAULT false,
auto_defeat boolean,
CONSTRAINT player_battles_pkey PRIMARY KEY (id),
CONSTRAINT player_battles_attacking_player_foreign FOREIGN KEY (attacking_player)
REFERENCES public.player_profile (id) MATCH SIMPLE
ON UPDATE NO ACTION
ON DELETE NO ACTION,
CONSTRAINT player_battles_defending_player_foreign FOREIGN KEY (defending_player)
REFERENCES public.player_profile (id) MATCH SIMPLE
ON UPDATE NO ACTION
ON DELETE NO ACTION
)
WITH (
OIDS = FALSE
)
TABLESPACE pg_default;
And indexes
CREATE INDEX player_battles_attacking_player_index
ON public.player_battles USING btree
(attacking_player)
TABLESPACE pg_default;
CREATE INDEX player_battles_created_at_index
ON public.player_battles USING btree
(created_at DESC)
TABLESPACE pg_default;
CREATE INDEX player_battles_defending_player_index
ON public.player_battles USING btree
(defending_player)
TABLESPACE pg_default;
EXPLAIN ANALYZE
Aggregate (cost=19.40..19.41 rows=1 width=8) (actual time=0.053..0.053 rows=1 loops=1)
-> Bitmap Heap Scan on player_battles (cost=8.33..19.39 rows=4 width=0) (actual time=0.030..0.047 rows=4 loops=1)
Recheck Cond: ((attacking_player = 1) OR (defending_player = 2))
Filter: (attacking_player <> defending_player)
Heap Blocks: exact=4
-> BitmapOr (cost=8.33..8.33 rows=4 width=0) (actual time=0.021..0.021 rows=0 loops=1)
-> Bitmap Index Scan on player_battles_attacking_player_index (cost=0.00..4.16 rows=2 width=0) (actual time=0.016..0.016 rows=2 loops=1)
Index Cond: (attacking_player = 1)
-> Bitmap Index Scan on player_battles_defending_player_index (cost=0.00..4.16 rows=2 width=0) (actual time=0.003..0.003 rows=2 loops=1)
Index Cond: (defending_player = 2)
Planning time: 0.907 ms
Execution time: 0.160 ms
Extra data
Just about 160 players and 310 rows in player_battles
, but num of rows does not correlate with the problem. System: DigitalOcean 2cpu/2gb ram. Output of pgBadger
and response times from node-postgres
: http://ge.tt/3DWk8Dj2
And my conf file may help: http://ge.tt/7cw69Dj2
EXPLAIN (ANALYZE, BUFFERS)
output for the query if you want people to help you optimize it.