1

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

9
  • Go through the steps in the [stackoverflow.com/tags/postgresql-performance/info](Info) link on the postgresql-performance tag, and paste the info into your question. Commented Mar 10, 2017 at 16:47
  • @Andrew Medvedev, if it turns out to be an issue with knex, and not your query/database, there's always either direct query execution via knex, or just go for pg-promise ;) Commented Mar 10, 2017 at 17:13
  • You must show the EXPLAIN (ANALYZE, BUFFERS) output for the query if you want people to help you optimize it. Commented Mar 11, 2017 at 5:38
  • Added extra info. Thanks to @Mike and Laurenz Albe Commented Mar 11, 2017 at 9:22
  • Since query planning takes such a long time, such queries should be executed as prepared statements ;) Anyway, seems like your database problem, if it needs almost a second to plan the execution. Commented Mar 11, 2017 at 11:24

0

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.