Dear sirs. I have an issue which I am at a loss to solve. Because of the behaviour I am not certain that this is a “slow query” problem, so I send my question here. My question regards a query using deep subqueries. EXPLAIN gives a maximum cost of about 2.000 (details below), but the query runs "forever" (at least 3 hours). It takes 100% CPU on the machine while running. It is expected to produce 0 rows. I have auto-vacuum enabled, but have also manually VACUUM:ed and ANALYZE:d the database. I am using "PostgreSQL 9.4.9 on x86_64-apple-darwin14.5.0, compiled by Apple LLVM version 7.0.2 (clang-700.1.81), 64-bit)". The query has worked as expected before, but stopped working. See below for query, EXPLAIN-output, definition of all tables, the table's sizes, and a gdb backtrace of the "hung" process. I apologize for the SQL, which is horribly ugly. It is in part automatically generated, and therefore looks like ****. I have tried to format it in an as-readable-form as possible. I have manually executed the innermost subquery ("SELECT n.account, ..."), and it produces 1 row in negligible time.The next levels out ("SELECT s3.nid, ...", "SELECT s4.nid, ..." and "SELECT i.assignment, ...") all produce 0 rows and run fine. I have run "CREATE TABLE tmptbl AS SELECT i.assignment, ...", running the topmost subquery and all its subqueries. They produce 0 rows in negligible time. If I replace the subquery with a select from that temporary table, "SELECT s6.nid AS orgunit, i.tags_point AS tags_point FROM tmptbl, ...", that query runs fine, producing 0 rows in notime. It is only when I use the complete query that it hangs - the individual parts all run. A "select * from pg_stat_activity where waiting='t'” while the query is running produces 0 rows. I also think that locking problems are unlikely, since the query works if I split it in two and use a table to store intermediate output (which is 0 rows, BTW). Unless an inner query can hang on a lock held by an outer one. The EXPLAIN (since it does not terminate I cannot run EXPLAIN ANALYZE): https://explain.depesz.com/s/Ex2z See below for all the ugly details. Thank you in advance, for all and any help.
/Viktor
SELECT s6.nid AS orgunit, i.tags_point AS tags_point FROM (SELECT i.assignment AS assignment, i.tags_point AS tags_point FROM (SELECT s4.nid AS assignment, i.tags_point AS tags_point FROM (SELECT s3.nid AS person, i.tags_point AS tags_point FROM (SELECT n.account AS account, tp.point AS tags_point FROM "pdb4_ad"."account_name" n, UNNEST(ARRAY[0]) AS injected_points, tags_point tp WHERE injected_points = tp.point AND int8range(n._r_from, n._r_to) @> tp.rev AND (n._value = '__bootstrap__') AND tsrange(n._start, n._stop) @> tp.time ) i, tags_point AS tp, "pdb4_ad"."account" AS s1, "pdb4_ad"."identifies" AS s2, "pdb4_person"."person" AS s3 WHERE i.tags_point = tp.point AND i.account = s1.nid AND s1.nid = s2."account" AND s2."person" = s3.nid AND INT8RANGE(s1._r_from, s1._r_to) @> tp.rev AND TSRANGE(s1._start, s1._stop) @> tp.time AND INT8RANGE(s2._r_from, s2._r_to) @> tp.rev AND TSRANGE(s2._start, s2._stop) @> tp.time AND INT8RANGE(s3._r_from, s3._r_to) @> tp.rev AND TSRANGE(s3._start, s3._stop) @> tp.time ) i, tags_point AS tp, "pdb4_person"."person" AS s1, "pdb4_org"."assignment" AS s2, "pdb4_org"."assignment_active" AS s3, "pdb4_org"."assignment" AS s4 WHERE i.tags_point = tp.point AND i.person = s1.nid AND s1.nid = s2."person" AND s2.nid = s3."assignment" AND s3."assignment" = s4.nid AND INT8RANGE(s1._r_from, s1._r_to) @> tp.rev AND TSRANGE(s1._start, s1._stop) @> tp.time AND INT8RANGE(s2._r_from, s2._r_to) @> tp.rev AND TSRANGE(s2._start, s2._stop) @> tp.time AND INT8RANGE(s3._r_from, s3._r_to) @> tp.rev AND TSRANGE(s3._start, s3._stop) @> tp.time AND INT8RANGE(s4._r_from, s4._r_to) @> tp.rev AND TSRANGE(s4._start, s4._stop) @> tp.time ) i, tags_point AS tp, "pdb4_org"."assignment" AS s1, "pdb4_org"."role" AS s2, "pdb4_org"."role_name" AS s3 WHERE i.tags_point = tp.point AND i.assignment = s1.nid AND s1."role" = s2.nid AND s2."name" = s3.nid AND INT8RANGE(s1._r_from, s1._r_to) @> tp.rev AND TSRANGE(s1._start, s1._stop) @> tp.time AND INT8RANGE(s2._r_from, s2._r_to) @> tp.rev AND TSRANGE(s2._start, s2._stop) @> tp.time AND INT8RANGE(s3._r_from, s3._r_to) @> tp.rev AND TSRANGE(s3._start, s3._stop) @> tp.time AND s3._value = 'pdb-reggare' ) i, tags_point AS tp, "pdb4_org"."assignment" AS s1, "pdb4_org"."orgunit" AS s2, "pdb4_org"."orgunit_path" AS s3, "pdb4_org"."orgunit_path_validity" AS s4, "pdb4_org"."orgunit_path" AS s5, "pdb4_org"."orgunit" AS s6 WHERE i.tags_point = tp.point AND i.assignment = s1.nid AND s1."orgunit" = s2.nid AND s2.nid = s3."end" AND s3.nid = s4."path" AND s4."path" = s5.nid AND s5."start" = s6.nid AND INT8RANGE(s1._r_from, s1._r_to) @> tp.rev AND TSRANGE(s1._start, s1._stop) @> tp.time AND INT8RANGE(s2._r_from, s2._r_to) @> tp.rev AND TSRANGE(s2._start, s2._stop) @> tp.time AND INT8RANGE(s3._r_from, s3._r_to) @> tp.rev AND TSRANGE(s3._start, s3._stop) @> tp.time AND INT8RANGE(s4._r_from, s4._r_to) @> tp.rev AND TSRANGE(s4._start, s4._stop) @> tp.time AND INT8RANGE(s5._r_from, s5._r_to) @> tp.rev AND TSRANGE(s5._start, s5._stop) @> tp.time AND INT8RANGE(s6._r_from, s6._r_to) @> tp.rev AND TSRANGE(s6._start, s6._stop) @> tp.time A backtrace of the postgres process executing the query: #0 0x000000010739fdb7 in ExecQual () #1 0x00000001073a0c9f in ExecScan () #2 0x000000010739a5b6 in ExecProcNode () #3 0x00000001073af88b in ExecNestLoop () #4 0x000000010739a645 in ExecProcNode () #5 0x00000001073af88b in ExecNestLoop () #6 0x000000010739a645 in ExecProcNode () #7 0x00000001073af88b in ExecNestLoop () #8 0x000000010739a645 in ExecProcNode () #9 0x00000001073af88b in ExecNestLoop () #10 0x000000010739a645 in ExecProcNode () #11 0x00000001073af88b in ExecNestLoop () #12 0x000000010739a645 in ExecProcNode () #13 0x00000001073af88b in ExecNestLoop () #14 0x000000010739a645 in ExecProcNode () #15 0x00000001073af88b in ExecNestLoop () #16 0x000000010739a645 in ExecProcNode () #17 0x00000001073af88b in ExecNestLoop () #18 0x000000010739a645 in ExecProcNode () #19 0x00000001073af88b in ExecNestLoop () #20 0x000000010739a645 in ExecProcNode () #21 0x00000001073af88b in ExecNestLoop () #22 0x000000010739a645 in ExecProcNode () #23 0x00000001073af88b in ExecNestLoop () #24 0x000000010739a645 in ExecProcNode () #25 0x00000001073af88b in ExecNestLoop () #26 0x000000010739a645 in ExecProcNode () #27 0x00000001073af88b in ExecNestLoop () #28 0x000000010739a645 in ExecProcNode () #29 0x00000001073af88b in ExecNestLoop () #30 0x000000010739a645 in ExecProcNode () #31 0x00000001073af88b in ExecNestLoop () #32 0x000000010739a645 in ExecProcNode () #33 0x00000001073af88b in ExecNestLoop () #34 0x000000010739a645 in ExecProcNode () #35 0x00000001073af88b in ExecNestLoop () #36 0x000000010739a645 in ExecProcNode () #37 0x00000001073af88b in ExecNestLoop () #38 0x000000010739a645 in ExecProcNode () #39 0x00000001073af929 in ExecNestLoop () #40 0x000000010739a645 in ExecProcNode () #41 0x000000010739816f in standard_ExecutorRun () #42 0x0000000107475b59 in PortalRunSelect () #43 0x000000010747574f in PortalRun () #44 0x0000000107473c83 in PostgresMain () #45 0x0000000107422a01 in PostmasterMain () #46 0x00000001073c8326 in main () Description of all tables used in the query: pdb4=> \d tags_point; Table "public.tags_point" Column | Type | Modifiers --------+-----------------------------+----------- point | integer | not null rev | bigint | not null time | timestamp without time zone | not null pdb4=> \d "pdb4_ad"."account_name" Table "pdb4_ad.account_name" Column | Type | Modifiers ---------+-----------------------------+----------- _r_from | bigint | not null _value | text | not null nid | bigint | not null _stop | timestamp without time zone | not null _start | timestamp without time zone | not null _r_to | bigint | account | bigint | Indexes: "account_name__r_from_idx" btree (_r_from) "account_name__r_to_idx" btree (_r_to) "account_name__start_idx" btree (_start) "account_name__stop_idx" btree (_stop) "account_name_account_idx" btree (account) "account_name_nid_idx" btree (nid) Foreign-key constraints: "account_name_account_fkey" FOREIGN KEY (account) REFERENCES pdb4_ad.account__id(nid) "account_name_nid_fkey" FOREIGN KEY (nid) REFERENCES pdb4_ad.account_name__id(nid) Triggers: pdb4_ad_trg__account_name_insert_id BEFORE INSERT ON pdb4_ad.account_name FOR EACH ROW EXECUTE PROCEDURE pdb4_ad.account_name__insert_trigger() pdb4=> \d "pdb4_ad"."identifies" Table "pdb4_ad.identifies" Column | Type | Modifiers ---------+-----------------------------+----------- _r_from | bigint | not null nid | bigint | not null _stop | timestamp without time zone | not null _start | timestamp without time zone | not null _r_to | bigint | person | bigint | account | bigint | Indexes: "identifies__r_from_idx" btree (_r_from) "identifies__r_to_idx" btree (_r_to) "identifies__start_idx" btree (_start) "identifies__stop_idx" btree (_stop) "identifies_account_idx" btree (account) "identifies_nid_idx" btree (nid) "identifies_person_idx" btree (person) Foreign-key constraints: "identifies_account_fkey" FOREIGN KEY (account) REFERENCES pdb4_ad.account__id(nid) "identifies_nid_fkey" FOREIGN KEY (nid) REFERENCES pdb4_ad.identifies__id(nid) "identifies_person_fkey" FOREIGN KEY (person) REFERENCES pdb4_person.person__id(nid) Triggers: pdb4_ad_trg__identifies_insert_id BEFORE INSERT ON pdb4_ad.identifies FOR EACH ROW EXECUTE PROCEDURE pdb4_ad.identifies__insert_trigger() pdb4=> \d "pdb4_person"."person" Table "pdb4_person.person" Column | Type | Modifiers ---------+-----------------------------+----------- _r_from | bigint | not null nid | bigint | not null name | bigint | _stop | timestamp without time zone | not null _start | timestamp without time zone | not null _r_to | bigint | Indexes: "person__r_from_idx" btree (_r_from) "person__r_to_idx" btree (_r_to) "person__start_idx" btree (_start) "person__stop_idx" btree (_stop) "person_name_idx" btree (name) "person_nid_idx" btree (nid) Foreign-key constraints: "person_name_fkey" FOREIGN KEY (name) REFERENCES pdb4_person.person_name__id(nid) "person_nid_fkey" FOREIGN KEY (nid) REFERENCES pdb4_person.person__id(nid) Triggers: pdb4_person_trg__person_insert_id BEFORE INSERT ON pdb4_person.person FOR EACH ROW EXECUTE PROCEDURE pdb4_person.person__insert_trigger() pdb4=> \d "pdb4_person"."person" Table "pdb4_person.person" Column | Type | Modifiers ---------+-----------------------------+----------- _r_from | bigint | not null nid | bigint | not null name | bigint | _stop | timestamp without time zone | not null _start | timestamp without time zone | not null _r_to | bigint | Indexes: "person__r_from_idx" btree (_r_from) "person__r_to_idx" btree (_r_to) "person__start_idx" btree (_start) "person__stop_idx" btree (_stop) "person_name_idx" btree (name) "person_nid_idx" btree (nid) Foreign-key constraints: "person_name_fkey" FOREIGN KEY (name) REFERENCES pdb4_person.person_name__id(nid) "person_nid_fkey" FOREIGN KEY (nid) REFERENCES pdb4_person.person__id(nid) Triggers: pdb4_person_trg__person_insert_id BEFORE INSERT ON pdb4_person.person FOR EACH ROW EXECUTE PROCEDURE pdb4_person.person__insert_trigger() pdb4=> \d "pdb4_org"."assignment" Table "pdb4_org.assignment" Column | Type | Modifiers ----------+-----------------------------+----------- _r_from | bigint | not null orgunit | bigint | nid | bigint | not null person | bigint | _stop | timestamp without time zone | not null _start | timestamp without time zone | not null _r_to | bigint | role | bigint | owned_by | bigint | Indexes: "assignment__r_from_idx" btree (_r_from) "assignment__r_to_idx" btree (_r_to) "assignment__start_idx" btree (_start) "assignment__stop_idx" btree (_stop) "assignment_nid_idx" btree (nid) "assignment_orgunit_idx" btree (orgunit) "assignment_owned_by_idx" btree (owned_by) "assignment_person_idx" btree (person) "assignment_role_idx" btree (role) Foreign-key constraints: "assignment_nid_fkey" FOREIGN KEY (nid) REFERENCES pdb4_org.assignment__id(nid) "assignment_orgunit_fkey" FOREIGN KEY (orgunit) REFERENCES pdb4_org.orgunit__id(nid) "assignment_owned_by_fkey" FOREIGN KEY (owned_by) REFERENCES pdb4_ad.service__id(nid) "assignment_person_fkey" FOREIGN KEY (person) REFERENCES pdb4_person.person__id(nid) "assignment_role_fkey" FOREIGN KEY (role) REFERENCES pdb4_org.role__id(nid) Triggers: pdb4_org_trg__assignment_insert_id BEFORE INSERT ON pdb4_org.assignment FOR EACH ROW EXECUTE PROCEDURE pdb4_org.assignment__insert_trigger() pdb4=> \d "pdb4_org"."assignment_active" Table "pdb4_org.assignment_active" Column | Type | Modifiers ------------+-----------------------------+----------- _r_from | bigint | not null nid | bigint | not null _stop | timestamp without time zone | not null _start | timestamp without time zone | not null _r_to | bigint | assignment | bigint | Indexes: "assignment_active__r_from_idx" btree (_r_from) "assignment_active__r_to_idx" btree (_r_to) "assignment_active__start_idx" btree (_start) "assignment_active__stop_idx" btree (_stop) "assignment_active_assignment_idx" btree (assignment) "assignment_active_nid_idx" btree (nid) Foreign-key constraints: "assignment_active_assignment_fkey" FOREIGN KEY (assignment) REFERENCES pdb4_org.assignment__id(nid) "assignment_active_nid_fkey" FOREIGN KEY (nid) REFERENCES pdb4_org.assignment_active__id(nid) Triggers: pdb4_org_trg__assignment_active_insert_id BEFORE INSERT ON pdb4_org.assignment_active FOR EACH ROW EXECUTE PROCEDURE pdb4_org.assignment_active__insert_trigger() pdb4=> \d "pdb4_org"."role" Table "pdb4_org.role" Column | Type | Modifiers ---------+-----------------------------+----------- _r_from | bigint | not null nid | bigint | not null name | bigint | _stop | timestamp without time zone | not null _start | timestamp without time zone | not null _r_to | bigint | Indexes: "role__r_from_idx" btree (_r_from) "role__r_to_idx" btree (_r_to) "role__start_idx" btree (_start) "role__stop_idx" btree (_stop) "role_name_idx" btree (name) "role_nid_idx" btree (nid) Foreign-key constraints: "role_name_fkey" FOREIGN KEY (name) REFERENCES pdb4_org.role_name__id(nid) "role_nid_fkey" FOREIGN KEY (nid) REFERENCES pdb4_org.role__id(nid) Triggers: pdb4_org_trg__role_insert_id BEFORE INSERT ON pdb4_org.role FOR EACH ROW EXECUTE PROCEDURE pdb4_org.role__insert_trigger() pdb4=> \d "pdb4_org"."role_name" Table "pdb4_org.role_name" Column | Type | Modifiers ---------+-----------------------------+----------- _r_from | bigint | not null _value | text | not null nid | bigint | not null _stop | timestamp without time zone | not null _start | timestamp without time zone | not null _r_to | bigint | Indexes: "role_name__r_from_idx" btree (_r_from) "role_name__r_to_idx" btree (_r_to) "role_name__start_idx" btree (_start) "role_name__stop_idx" btree (_stop) "role_name_nid_idx" btree (nid) Foreign-key constraints: "role_name_nid_fkey" FOREIGN KEY (nid) REFERENCES pdb4_org.role_name__id(nid) Triggers: pdb4_org_trg__role_name_insert_id BEFORE INSERT ON pdb4_org.role_name FOR EACH ROW EXECUTE PROCEDURE pdb4_org.role_name__insert_trigger() pdb4=> \d "pdb4_org"."orgunit" Table "pdb4_org.orgunit" Column | Type | Modifiers ---------+-----------------------------+----------- _r_from | bigint | not null nid | bigint | not null name | bigint | _stop | timestamp without time zone | not null _start | timestamp without time zone | not null _r_to | bigint | Indexes: "orgunit__r_from_idx" btree (_r_from) "orgunit__r_to_idx" btree (_r_to) "orgunit__start_idx" btree (_start) "orgunit__stop_idx" btree (_stop) "orgunit_name_idx" btree (name) "orgunit_nid_idx" btree (nid) Foreign-key constraints: "orgunit_name_fkey" FOREIGN KEY (name) REFERENCES pdb4_org.orgunit_name__id(nid) "orgunit_nid_fkey" FOREIGN KEY (nid) REFERENCES pdb4_org.orgunit__id(nid) Triggers: pdb4_org_trg__orgunit_insert_id BEFORE INSERT ON pdb4_org.orgunit FOR EACH ROW EXECUTE PROCEDURE pdb4_org.orgunit__insert_trigger() pdb4=> \d "pdb4_org"."orgunit_path" Table "pdb4_org.orgunit_path" Column | Type | Modifiers ---------+-----------------------------+----------- type | bigint | _r_from | bigint | not null _value | integer | not null nid | bigint | not null end | bigint | _stop | timestamp without time zone | not null _start | timestamp without time zone | not null _r_to | bigint | start | bigint | Indexes: "orgunit_path__r_from_idx" btree (_r_from) "orgunit_path__r_to_idx" btree (_r_to) "orgunit_path__start_idx" btree (_start) "orgunit_path__stop_idx" btree (_stop) "orgunit_path_end_idx" btree ("end") "orgunit_path_nid_idx" btree (nid) "orgunit_path_start_idx" btree (start) "orgunit_path_type_idx" btree (type) Foreign-key constraints: "orgunit_path_end_fkey" FOREIGN KEY ("end") REFERENCES pdb4_org.orgunit__id(nid) "orgunit_path_nid_fkey" FOREIGN KEY (nid) REFERENCES pdb4_org.orgunit_path__id(nid) "orgunit_path_start_fkey" FOREIGN KEY (start) REFERENCES pdb4_org.orgunit__id(nid) "orgunit_path_type_fkey" FOREIGN KEY (type) REFERENCES pdb4_org.orgunit_link_type__id(nid) Triggers: pdb4_org_trg__orgunit_path_insert_id BEFORE INSERT ON pdb4_org.orgunit_path FOR EACH ROW EXECUTE PROCEDURE pdb4_org.orgunit_path__insert_trigger() pdb4=> \d "pdb4_org"."orgunit_path_validity" Table "pdb4_org.orgunit_path_validity" Column | Type | Modifiers ---------+-----------------------------+----------- path | bigint | _r_from | bigint | not null nid | bigint | not null _stop | timestamp without time zone | not null _start | timestamp without time zone | not null _r_to | bigint | Indexes: "orgunit_path_validity__r_from_idx" btree (_r_from) "orgunit_path_validity__r_to_idx" btree (_r_to) "orgunit_path_validity__start_idx" btree (_start) "orgunit_path_validity__stop_idx" btree (_stop) "orgunit_path_validity_nid_idx" btree (nid) "orgunit_path_validity_path_idx" btree (path) Foreign-key constraints: "orgunit_path_validity_nid_fkey" FOREIGN KEY (nid) REFERENCES pdb4_org.orgunit_path_validity__id(nid) "orgunit_path_validity_path_fkey" FOREIGN KEY (path) REFERENCES pdb4_org.orgunit_path__id(nid) Triggers: pdb4_org_trg__orgunit_path_validity_insert_id BEFORE INSERT ON pdb4_org.orgunit_path_validity FOR EACH ROW EXECUTE PROCEDURE pdb4_org.orgunit_path_validity__insert_trigger() And the size of each table: pdb4=> select count(*) from tags_point; count ------- 1 (1 row) pdb4=> select count(*) from "pdb4_ad"."account_name"; count -------- 115054 (1 row) pdb4=> select count(*) from "pdb4_ad"."identifies"; count -------- 112211 (1 row) pdb4=> select count(*) from "pdb4_person"."person"; count -------- 112211 (1 row) pdb4=> select count(*) from "pdb4_org"."assignment"; count ------- 0 (1 row) pdb4=> select count(*) from "pdb4_org"."assignment_active"; count ------- 0 (1 row) pdb4=> select count(*) from "pdb4_org"."role"; count ------- 8 (1 row) pdb4=> select count(*) from "pdb4_org"."role_name"; count ------- 8 (1 row) pdb4=> select count(*) from "pdb4_org"."orgunit"; count ------- 282 (1 row) pdb4=> select count(*) from "pdb4_org"."orgunit_path"; count ------- 464 (1 row) pdb4=> select count(*) from "pdb4_org"."orgunit_path_validity"; count ------- 464 (1 row) |