Hi All,
I'm having issues with a set of fairly related queries in my
application. EXPLAIN ANALYZE is showing them all to be getting stuck
performing roughly the same operation:
-> Bitmap Heap Scan on logparser_entry
(cost=4119.06..21520.55 rows=68787 width=8) (actual
time=107.032..444.864 rows=16168 loops=1)
Recheck Cond: ((event_type)::text = ANY
('{Attack,"DoT Tick","Critical Attack"}'::text[]))
Filter: ((((target_relation)::text <> ALL
('{Other,N/A}'::text[])) OR (NOT (target_relation IS NOT NULL))) AND
(log_id = 2))
-> Bitmap Index Scan on
logparser_entry_event_type_like (cost=0.00..4101.86 rows=217733
width=0) (actual time=46.392..46.392 rows=237151 loops=1)
Index Cond: ((event_type)::text = ANY
('{Attack,"DoT Tick","Critical Attack"}'::text[]))
-> Hash (cost=196.49..196.49 rows=9749 width=23)
(actual time=19.606..19.606 rows=9749 loops=1)
All the queries are being generated by the Django ORM, so they are not
particularly well optimized pretty. I'd prefer to stay with the ORM
as a lot of the queries are highly variable depending on the request
parameters and so unless their are huge gains to be had by falling
back to raw SQL it will save me a lot of development time to stay with
the ORM.
The table in question (logparser_entry) currently has 815000 records
(but that only represents a very very small amount compared to what
the production server would have to handle, as this represents only 2
log objects when I would expect easily 100 or more logs to be uploaded
per day).
Nulls should be rare in the fields.
This was being run on an AWS High CPU medium instance. Obviously not
enoughfor a produciton system, but I would hope it would be more than
adequate for testing when I'm the only one using the app. I opted for
High CPU because the system doesn't seem to be IO bound even on a
micro instance (nearly 0 wait time according to top) and barely
touches the RAM even when tuned to be aggressive with memory usage.
At the same time it's running 100% cpu usage.
My server config:
Server Config
name |
current_setting
------------------------------+-------------------------------------------------------------------------------------------------------------------
version | PostgreSQL 8.4.8 on i686-pc-linux-gnu,
compiled by GCC gcc-4.4.real (Ubuntu/Linaro 4.4.4-14ubuntu5) 4.4.5,
32-bit
checkpoint_completion_target | 0.9
effective_cache_size | 1044MB
external_pid_file | /var/run/postgresql/8.4-main.pid
fsync | on
lc_collate | en_US.UTF-8
lc_ctype | en_US.UTF-8
listen_addresses | *
log_line_prefix | %t
log_min_duration_statement | 250ms
max_connections | 25
max_stack_depth | 2MB
port | 5432
random_page_cost | 4
server_encoding | UTF8
shared_buffers | 16MB
synchronous_commit | off
TimeZone | UTC
unix_socket_directory | /var/run/postgresql
work_mem | 250MB
(20 rows)
To try to make reading the queries easier I've attached a text file
with the queries and links to EXPLAIN ANALYZE outputs as well as
copied them below. I've tried a lot to tune these queries, but
nothing seems to work. The queries always spend a large amount of
time in the same place. Is there something I missing that could
improve these or even a way to rework my schema to speed things up.
Thanks,
John
SELECT "logparser_entry"."id" ,
"logparser_entry"."log_id" ,
"logparser_entry"."encounter_id" ,
"logparser_entry"."entry_order" ,
"logparser_entry"."timestamp" ,
"logparser_entry"."seconds_since_start" ,
"logparser_entry"."event_type" ,
"logparser_entry"."actor_id" ,
"logparser_entry"."actor_relation" ,
"logparser_entry"."target_id" ,
"logparser_entry"."target_relation" ,
"logparser_entry"."pet_owner_id" ,
"logparser_entry"."pet_owner_relation" ,
"logparser_entry"."pet_target_owner_id" ,
"logparser_entry"."pet_target_owner_relation",
"logparser_entry"."ability_id" ,
"logparser_entry"."effective_value" ,
"logparser_entry"."blocked" ,
"logparser_entry"."absorbed" ,
"logparser_entry"."overkill" ,
"logparser_entry"."overheal" ,
"logparser_entry"."total_value"
FROM "logparser_entry"
WHERE (
"logparser_entry"."log_id" = 2
AND NOT
(
(
"logparser_entry"."actor_relation"
IN (E'Other',
E'N/A')
AND "logparser_entry"."actor_relation"
IS NOT NULL
)
)
AND "logparser_entry"."event_type" IN (E'Attack' ,
E'DoT Tick',
E'Critical Attack')
)
ORDER BY "logparser_entry"."entry_order" ASC
LIMIT 1
http://explain.depesz.com/s/vEx
SELECT (ROUND(logparser_entry.seconds_since_start / 42)) AS "interval",
SUM("logparser_entry"."effective_value") AS
"effective_value__sum"
FROM "logparser_entry"
WHERE (
"logparser_entry"."log_id" = 2
AND NOT
(
(
"logparser_entry"."actor_relation"
IN (E'Other',
E'N/A')
AND "logparser_entry"."actor_relation"
IS NOT NULL
)
)
AND "logparser_entry"."event_type" IN (E'Attack' ,
E'DoT Tick',
E'Critical Attack')
)
GROUP BY (ROUND(logparser_entry.seconds_since_start / 42)),
ROUND(logparser_entry.seconds_since_start / 42)
ORDER BY "interval" ASC
http://explain.depesz.com/s/Rhb
SELECT (ROUND(logparser_entry.seconds_since_start / 45)) AS "interval",
SUM("logparser_entry"."effective_value") AS
"effective_value__sum"
FROM "logparser_entry"
WHERE (
"logparser_entry"."log_id" = 2
AND NOT
(
(
"logparser_entry"."target_relation" IN (E'Other',
E'N/A')
AND
"logparser_entry"."target_relation" IS NOT NULL
)
AND
(
"logparser_entry"."actor_relation"
IN (E'Other',
E'N/A')
AND "logparser_entry"."actor_relation"
IS NOT NULL
)
)
AND "logparser_entry"."event_type" IN (E'Heal',
E'Heal Critical')
)
GROUP BY (ROUND(logparser_entry.seconds_since_start / 45)),
ROUND(logparser_entry.seconds_since_start / 45)
ORDER BY "interval" ASC
http://explain.depesz.com/s/JUo
SELECT "units_ability"."ability_name",
"units_ability"."damage_type" ,
SUM("logparser_entry"."total_value") AS "total"
FROM "logparser_entry"
LEFT OUTER JOIN "units_ability"
ON (
"logparser_entry"."ability_id" = "units_ability"."id"
)
WHERE (
"logparser_entry"."log_id" = 2
AND NOT
(
(
"logparser_entry"."target_relation" IN (E'Other',
E'N/A')
AND
"logparser_entry"."target_relation" IS NOT NULL
)
)
AND "logparser_entry"."event_type" IN (E'Attack' ,
E'DoT Tick',
E'Critical Attack')
)
GROUP BY "units_ability"."ability_name",
"units_ability"."damage_type" ,
"units_ability"."ability_name",
"units_ability"."damage_type"
HAVING NOT
(
SUM("logparser_entry"."total_value") = 0
)
ORDER BY "total" DESC
http://explain.depesz.com/s/VZA
Table "public.logparser_entry"
Column | Type |
Modifiers
---------------------------+------------------------+--------------------------------------------------------------
id | integer | not null default
nextval('logparser_entry_id_seq'::regclass)
log_id | integer | not null
encounter_id | integer |
entry_order | integer | not null
timestamp | time without time zone | not null
seconds_since_start | integer | not null
event_type | character varying(64) | not null
actor_id | integer | not null
actor_relation | character varying(24) |
target_id | integer |
target_relation | character varying(24) |
pet_owner_id | integer |
pet_owner_relation | character varying(24) |
pet_target_owner_id | integer |
pet_target_owner_relation | character varying(32) |
ability_id | integer |
effective_value | integer | not null
blocked | integer | not null
absorbed | integer | not null
overkill | integer | not null
overheal | integer | not null
total_value | integer | not null
Indexes:
"logparser_entry_pkey" PRIMARY KEY, btree (id)
"logparser_entry_ability_id" btree (ability_id)
"logparser_entry_actor_id" btree (actor_id)
"logparser_entry_actor_relation" btree (actor_relation)
"logparser_entry_actor_relation_like" btree (actor_relation
varchar_pattern_ops)
"logparser_entry_encounter_id" btree (encounter_id)
"logparser_entry_event_type" btree (event_type)
"logparser_entry_event_type_like" btree (event_type varchar_pattern_ops)
"logparser_entry_log_id" btree (log_id)
"logparser_entry_pet_owner_id" btree (pet_owner_id)
"logparser_entry_pet_target_owner_id" btree (pet_target_owner_id)
"logparser_entry_target_id" btree (target_id)
"logparser_entry_target_relation" btree (target_relation)
"logparser_entry_target_relation_like" btree (target_relation
varchar_pattern_ops)
Foreign-key constraints:
"logparser_entry_ability_id_fkey" FOREIGN KEY (ability_id)
REFERENCES units_ability(id) DEFERRABLE INITIALLY DEFERRED
"logparser_entry_actor_id_fkey" FOREIGN KEY (actor_id) REFERENCES
units_unit(id) DEFERRABLE INITIALLY DEFERRED
"logparser_entry_encounter_id_fkey" FOREIGN KEY (encounter_id)
REFERENCES logparser_encounter(id) DEFERRABLE INITIALLY DEFERRED
"logparser_entry_log_id_fkey" FOREIGN KEY (log_id) REFERENCES
logparser_log(id) DEFERRABLE INITIALLY DEFERRED
"logparser_entry_pet_owner_id_fkey" FOREIGN KEY (pet_owner_id)
REFERENCES units_unit(id) DEFERRABLE INITIALLY DEFERRED
"logparser_entry_pet_target_owner_id_fkey" FOREIGN KEY
(pet_target_owner_id) REFERENCES units_unit(id) DEFERRABLE INITIALLY
DEFERRED
"logparser_entry_target_id_fkey" FOREIGN KEY (target_id)
REFERENCES units_unit(id) DEFERRABLE INITIALLY DEFERRED
Server Config
name |
current_setting
------------------------------+-------------------------------------------------------------------------------------------------------------------
version | PostgreSQL 8.4.8 on i686-pc-linux-gnu,
compiled by GCC gcc-4.4.real (Ubuntu/Linaro 4.4.4-14ubuntu5) 4.4.5,
32-bit
checkpoint_completion_target | 0.9
effective_cache_size | 1044MB
external_pid_file | /var/run/postgresql/8.4-main.pid
fsync | on
lc_collate | en_US.UTF-8
lc_ctype | en_US.UTF-8
listen_addresses | *
log_line_prefix | %t
log_min_duration_statement | 250ms
max_connections | 25
max_stack_depth | 2MB
port | 5432
random_page_cost | 4
server_encoding | UTF8
shared_buffers | 16MB
synchronous_commit | off
TimeZone | UTC
unix_socket_directory | /var/run/postgresql
work_mem | 250MB
(20 rows)
SELECT "logparser_entry"."id" ,
"logparser_entry"."log_id" ,
"logparser_entry"."encounter_id" ,
"logparser_entry"."entry_order" ,
"logparser_entry"."timestamp" ,
"logparser_entry"."seconds_since_start" ,
"logparser_entry"."event_type" ,
"logparser_entry"."actor_id" ,
"logparser_entry"."actor_relation" ,
"logparser_entry"."target_id" ,
"logparser_entry"."target_relation" ,
"logparser_entry"."pet_owner_id" ,
"logparser_entry"."pet_owner_relation" ,
"logparser_entry"."pet_target_owner_id" ,
"logparser_entry"."pet_target_owner_relation",
"logparser_entry"."ability_id" ,
"logparser_entry"."effective_value" ,
"logparser_entry"."blocked" ,
"logparser_entry"."absorbed" ,
"logparser_entry"."overkill" ,
"logparser_entry"."overheal" ,
"logparser_entry"."total_value"
FROM "logparser_entry"
WHERE (
"logparser_entry"."log_id" = 2
AND NOT
(
(
"logparser_entry"."actor_relation" IN (E'Other',
E'N/A')
AND "logparser_entry"."actor_relation" IS NOT NULL
)
)
AND "logparser_entry"."event_type" IN (E'Attack' ,
E'DoT Tick',
E'Critical Attack')
)
ORDER BY "logparser_entry"."entry_order" ASC
LIMIT 1
http://explain.depesz.com/s/vEx
SELECT (ROUND(logparser_entry.seconds_since_start / 42)) AS "interval",
SUM("logparser_entry"."effective_value") AS "effective_value__sum"
FROM "logparser_entry"
WHERE (
"logparser_entry"."log_id" = 2
AND NOT
(
(
"logparser_entry"."actor_relation" IN (E'Other',
E'N/A')
AND "logparser_entry"."actor_relation" IS NOT NULL
)
)
AND "logparser_entry"."event_type" IN (E'Attack' ,
E'DoT Tick',
E'Critical Attack')
)
GROUP BY (ROUND(logparser_entry.seconds_since_start / 42)),
ROUND(logparser_entry.seconds_since_start / 42)
ORDER BY "interval" ASC
http://explain.depesz.com/s/Rhb
SELECT (ROUND(logparser_entry.seconds_since_start / 45)) AS "interval",
SUM("logparser_entry"."effective_value") AS "effective_value__sum"
FROM "logparser_entry"
WHERE (
"logparser_entry"."log_id" = 2
AND NOT
(
(
"logparser_entry"."target_relation" IN (E'Other',
E'N/A')
AND "logparser_entry"."target_relation" IS NOT NULL
)
AND
(
"logparser_entry"."actor_relation" IN (E'Other',
E'N/A')
AND "logparser_entry"."actor_relation" IS NOT NULL
)
)
AND "logparser_entry"."event_type" IN (E'Heal',
E'Heal Critical')
)
GROUP BY (ROUND(logparser_entry.seconds_since_start / 45)),
ROUND(logparser_entry.seconds_since_start / 45)
ORDER BY "interval" ASC
http://explain.depesz.com/s/JUo
SELECT "units_ability"."ability_name",
"units_ability"."damage_type" ,
SUM("logparser_entry"."total_value") AS "total"
FROM "logparser_entry"
LEFT OUTER JOIN "units_ability"
ON (
"logparser_entry"."ability_id" = "units_ability"."id"
)
WHERE (
"logparser_entry"."log_id" = 2
AND NOT
(
(
"logparser_entry"."target_relation" IN (E'Other',
E'N/A')
AND "logparser_entry"."target_relation" IS NOT NULL
)
)
AND "logparser_entry"."event_type" IN (E'Attack' ,
E'DoT Tick',
E'Critical Attack')
)
GROUP BY "units_ability"."ability_name",
"units_ability"."damage_type" ,
"units_ability"."ability_name",
"units_ability"."damage_type"
HAVING NOT
(
SUM("logparser_entry"."total_value") = 0
)
ORDER BY "total" DESC
http://explain.depesz.com/s/VZA
Table "public.logparser_entry"
Column | Type | Modifiers
---------------------------+------------------------+--------------------------------------------------------------
id | integer | not null default nextval('logparser_entry_id_seq'::regclass)
log_id | integer | not null
encounter_id | integer |
entry_order | integer | not null
timestamp | time without time zone | not null
seconds_since_start | integer | not null
event_type | character varying(64) | not null
actor_id | integer | not null
actor_relation | character varying(24) |
target_id | integer |
target_relation | character varying(24) |
pet_owner_id | integer |
pet_owner_relation | character varying(24) |
pet_target_owner_id | integer |
pet_target_owner_relation | character varying(32) |
ability_id | integer |
effective_value | integer | not null
blocked | integer | not null
absorbed | integer | not null
overkill | integer | not null
overheal | integer | not null
total_value | integer | not null
Indexes:
"logparser_entry_pkey" PRIMARY KEY, btree (id)
"logparser_entry_ability_id" btree (ability_id)
"logparser_entry_actor_id" btree (actor_id)
"logparser_entry_actor_relation" btree (actor_relation)
"logparser_entry_actor_relation_like" btree (actor_relation varchar_pattern_ops)
"logparser_entry_encounter_id" btree (encounter_id)
"logparser_entry_event_type" btree (event_type)
"logparser_entry_event_type_like" btree (event_type varchar_pattern_ops)
"logparser_entry_log_id" btree (log_id)
"logparser_entry_pet_owner_id" btree (pet_owner_id)
"logparser_entry_pet_target_owner_id" btree (pet_target_owner_id)
"logparser_entry_target_id" btree (target_id)
"logparser_entry_target_relation" btree (target_relation)
"logparser_entry_target_relation_like" btree (target_relation varchar_pattern_ops)
Foreign-key constraints:
"logparser_entry_ability_id_fkey" FOREIGN KEY (ability_id) REFERENCES units_ability(id) DEFERRABLE INITIALLY DEFERRED
"logparser_entry_actor_id_fkey" FOREIGN KEY (actor_id) REFERENCES units_unit(id) DEFERRABLE INITIALLY DEFERRED
"logparser_entry_encounter_id_fkey" FOREIGN KEY (encounter_id) REFERENCES logparser_encounter(id) DEFERRABLE INITIALLY DEFERRED
"logparser_entry_log_id_fkey" FOREIGN KEY (log_id) REFERENCES logparser_log(id) DEFERRABLE INITIALLY DEFERRED
"logparser_entry_pet_owner_id_fkey" FOREIGN KEY (pet_owner_id) REFERENCES units_unit(id) DEFERRABLE INITIALLY DEFERRED
"logparser_entry_pet_target_owner_id_fkey" FOREIGN KEY (pet_target_owner_id) REFERENCES units_unit(id) DEFERRABLE INITIALLY DEFERRED
"logparser_entry_target_id_fkey" FOREIGN KEY (target_id) REFERENCES units_unit(id) DEFERRABLE INITIALLY DEFERRED
--
Sent via pgsql-performance mailing list (pgsql-performance@xxxxxxxxxxxxxx)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
