Re: [PERFORM] Query taking too long. Problem reading explain output.
Henrik <[EMAIL PROTECTED]> writes:
> Here is the query if needed.
> explain analyze SELECT file_name FROM tbl_file_structure JOIN
> tbl_file ON pk_file_id = fk_file_id JOIN tbl_structure ON
> pk_structure_id = fk_structure_id JOIN tbl_archive ON pk_archive_id
> =fk_archive_id JOIN tbl_share ON pk_share_id =fk_share_id JOIN
> tbl_computer ON pk_computer_id = fk_computer_id JOIN tbl_filetype ON
> pk_filetype_id = fk_filetype_id LEFT OUTER JOIN tbl_job ON
> tbl_archive.fk_job_id = pk_job_id LEFT OUTER JOIN tbl_job_group ON
> tbl_job.fk_job_group_id = pk_job_group_id WHERE LOWER(file_name) LIKE
> LOWER('index.php%') AND (computer_name = 'SOLARIS2') AND
> (fk_archive_id = 56) AND archive_complete = true AND (job_group_type
> = 'B' OR job_group_type IS NULL) GROUP BY file_name, file_ctime,
> structure_path, pk_computer_id, filetype_icon, computer_name,
> share_name, share_path;
[ counts the JOINs... ] Try raising join_collapse_limit. I think the
planner may be neglecting to consider the join order you need.
regards, tom lane
---(end of broadcast)---
TIP 6: explain analyze is your friend
Re: [PERFORM] Query taking too long. Problem reading explain output.
On Wed, Oct 03, 2007 at 10:03:53AM +0200, Henrik wrote: > I have a little query that takes too long and what I can see in the > explain output is a seq scan on my biggest table ( tbl_file_structure) > which I can't explain why. Here's where almost all of the time is taken: > Hash Join (cost=8605.68..410913.87 rows=19028 width=40) (actual > time=22.810..16196.414 rows=17926 loops=1) > Hash Cond: (tbl_file_structure.fk_file_id = tbl_file.pk_file_id) > -> Seq Scan on tbl_file_structure (cost=0.00..319157.94 rows=16591994 > width=16) (actual time=0.016..7979.083 rows=16591994 loops=1) > -> Hash (cost=8573.62..8573.62 rows=2565 width=40) (actual > time=22.529..22.529 rows=2221 loops=1) > -> Bitmap Heap Scan on tbl_file (cost=74.93..8573.62 rows=2565 > width=40) (actual time=1.597..20.691 rows=2221 loops=1) > Filter: (lower((file_name)::text) ~~ 'index.php%'::text) > -> Bitmap Index Scan on tbl_file_idx (cost=0.00..74.28 > rows=2565 width=0) (actual time=1.118..1.118 rows=2221 loops=1) > Index Cond: ((lower((file_name)::text) ~>=~ > 'index.php'::character varying) AND (lower((file_name)::text) ~<~ > 'index.phq'::character varying)) Does tbl_file_structure have an index on fk_file_id? If so then what's the EXPLAIN ANALYZE output if you set enable_seqscan to off? I don't recommend disabling sequential scans permanently but doing so can be useful when investigating why the planner thinks one plan will be faster than another. What are your settings for random_page_cost, effective_cache_size, work_mem, and shared_buffers? If you're using the default random_page_cost of 4 then what's the EXPLAIN ANALYZE output if you reduce it to 3 or 2 (after setting enable_seqscan back to on)? -- Michael Fuhr ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
[PERFORM] Query taking too long. Problem reading explain output.
Hello list, I have a little query that takes too long and what I can see in the explain output is a seq scan on my biggest table ( tbl_file_structure) which I can't explain why. Here is the output. I hope this is formatted correctly. If not, let me know and I'll paste it somewhere. Postgres version is 8.2.4 running on a Linux system with 2GB RAM and a Core 2 Duo processor. HashAggregate (cost=418833.59..418833.63 rows=4 width=127) (actual time=16331.326..16331.449 rows=160 loops=1) -> Hash Left Join (cost=16290.37..418833.51 rows=4 width=127) (actual time=4386.574..16330.727 rows=160 loops=1) Hash Cond: (tbl_job.fk_job_group_id = tbl_job_group.pk_job_group_id) Filter: ((tbl_job_group.job_group_type = 'B'::bpchar) OR (tbl_job_group.job_group_type IS NULL)) -> Merge Join (cost=16285.22..418828.08 rows=17 width=135) (actual time=4386.474..16330.253 rows=160 loops=1) Merge Cond: (tbl_computer.pk_computer_id = tbl_share.fk_computer_id) -> Nested Loop (cost=16268.52..418810.55 rows=216 width=122) (actual time=4386.324..16329.638 rows=160 loops=1) -> Index Scan using tbl_computer_pkey on tbl_computer (cost=0.00..12.48 rows=1 width=20) (actual time=0.013..0.024 rows=1 loops=1) Filter: ((computer_name)::text = 'SOLARIS2'::text) -> Hash Join (cost=16268.52..418795.91 rows=216 width=102) (actual time=4386.307..16329.425 rows=160 loops=1) Hash Cond: (tbl_file.fk_filetype_id = tbl_filetype.pk_filetype_id) -> Hash Join (cost=16267.03..418791.44 rows=216 width=100) (actual time=4386.268..16329.119 rows=160 loops=1) Hash Cond: (tbl_file_structure.fk_structure_id = tbl_structure.pk_structure_id) -> Hash Join (cost=8605.68..410913.87 rows=19028 width=40) (actual time=22.810..16196.414 rows=17926 loops=1) Hash Cond: (tbl_file_structure.fk_file_id = tbl_file.pk_file_id) -> Seq Scan on tbl_file_structure (cost=0.00..319157.94 rows=16591994 width=16) (actual time=0.016..7979.083 rows=16591994 loops=1) -> Hash (cost=8573.62..8573.62 rows=2565 width=40) (actual time=22.529..22.529 rows=2221 loops=1) -> Bitmap Heap Scan on tbl_file (cost=74.93..8573.62 rows=2565 width=40) (actual time=1.597..20.691 rows=2221 loops=1) Filter: (lower ((file_name)::text) ~~ 'index.php%'::text) -> Bitmap Index Scan on tbl_file_idx (cost=0.00..74.28 rows=2565 width=0) (actual time=1.118..1.118 rows=2221 loops=1) Index Cond: ((lower((file_name)::text) ~>=~ 'index.php'::character varying) AND (lower((file_name)::text) ~<~ 'index.phq'::character varying)) -> Hash (cost=7487.57..7487.57 rows=13902 width=76) (actual time=100.905..100.905 rows=24571 loops=1) -> Index Scan using tbl_structure_idx3 on tbl_structure (cost=0.00..7487.57 rows=13902 width=76) (actual time=0.055..79.301 rows=24571 loops=1) Index Cond: (fk_archive_id = 56) -> Hash (cost=1.22..1.22 rows=22 width=18) (actual time=0.032..0.032 rows=22 loops=1) -> Seq Scan on tbl_filetype (cost=0.00..1.22 rows=22 width=18) (actual time=0.004..0.016 rows=22 loops=1) -> Sort (cost=16.70..16.70 rows=1 width=37) (actual time=0.144..0.239 rows=1 loops=1) Sort Key: tbl_share.fk_computer_id -> Nested Loop (cost=4.26..16.69 rows=1 width=37) (actual time=0.072..0.115 rows=1 loops=1) Join Filter: (tbl_share.pk_share_id = tbl_archive.fk_share_id) -> Nested Loop Left Join (cost=4.26..15.42 rows=1 width=24) (actual time=0.055..0.097 rows=1 loops=1) Join Filter: (tbl_archive.fk_job_id = tbl_job.pk_job_id) -> Bitmap Heap Scan on tbl_archive (cost=4.26..8.27 rows=1 width=24) (actual time=0.033..0.033 rows=1 loops=1) Recheck Cond: (56 = pk_archive_id) Filter: archive_complete -> Bitmap Index Scan on tbl_archive_pkey (cost=0.00..4.26 rows=1 width=0) (actual time=0.026..0.026 rows=1 loops=1) Index Cond: (56 = pk_archive_id) -> Seq Scan on tbl_job (cost=0.00..6.51 rows=5
Re: [PERFORM] Newbie question about degraded performance on delete statement. (SOLVED)
Hello, thanks to the added info available running the explain plan through pgsl (instead of using pgAdmin) I was able to realize that an (implicitly created) trigger was the culprit of the slowdown I was suffering. Adding an index on the foreign key the trigger was monitoring solved the issue. THANKS EVERYBODY for your kind attention. Best regards, Giulio Cesare On 10/3/07, Giulio Cesare Solaroli <[EMAIL PROTECTED]> wrote: > Hello Gregory, > > On 10/3/07, Greg Williamson <[EMAIL PROTECTED]> wrote: > > Giulio Cesare Solaroli wrote: > > > Hello everybody, > > > > > > I have just joined the list, as I am experiencing a degradation on > > > performances on my PostgreSQL instance, and I was looking for some > > > insights on how to fix/avoid it. > > > > > > What I have observed are impossibly high time on delete statements on > > > some tables. > > > > > > The delete statement is very simple: > > > delete from table where pk = ? > > > > > > The explain query report a single index scan on the primary key index, > > > as expected. > > > > > > I have run vacuum using the pgAdmin tool, but to no avail. > > > > > > I have also dropped and recreated the indexes, again without any benefit. > > > > > Make sure you run ANALYZE on the table in question after changes to make > > sure the stats are up to date. > > I have run Analyze (always through the pgAdmin interface), and it did > not provide any benefits. > > > > > I have later created a copy of the table using the "create table > > > table_copy as select * from table" syntax. > > > > > > Matching the configuration of the original table also on the copy > > > (indexes and constraints), I was able to delete the raws from the new > > > table with regular performances, from 20 to 100 times faster than > > > deleting from the original table. > > > > > > > > As another poster indicated, this sounds like foreign constraints where > > the postmaster process has to make sure there are no child references in > > dependent tables; if you are lacking proper indexing on those tables a > > sequential scan would be involved. > > > > Posting the DDL for the table in question and anything that might refer > > to it with an FK relationship would help the list help you. > > clipperz_connection=> \d clipperz.rcrvrs >Table "clipperz.rcrvrs" > Column| Type | Modifiers > --+--+--- > id_rcrvrs| integer | not null > id_rcr | integer | not null > id_prvrcrvrs | integer | > reference| character varying(1000) | not null > header | text | not null > data | text | not null > version | character varying(100) | not null > creation_date| timestamp with time zone | not null > access_date | timestamp with time zone | not null > update_date | timestamp with time zone | not null > previous_version_key | text | not null > Indexes: > "rcrvrs_pkey" PRIMARY KEY, btree (id_rcrvrs) > "unique_rcrvrs_referecnce" UNIQUE, btree (id_rcr, reference) > Foreign-key constraints: > "rcrvrs_id_prvrcrvrs_fkey" FOREIGN KEY (id_prvrcrvrs) REFERENCES > rcrvrs(id_rcrvrs) > "rcrvrs_id_rcr_fkey" FOREIGN KEY (id_rcr) REFERENCES rcr(id_rcr) > DEFERRABLE INITIALLY DEFERRED > > Is this a complete listing of all the DDL involved in defining the > table, or is there something possibly missing here? > > > > > Try running the query with EXPLAIN ANALYZE ... to see what the planner > > says. Put this in a transaction and roll it back if you want to leave > > the data unchanged, e.g. > > BEGIN; > > EXPLAIN ANALYZE DELETE FROM foo WHERE pk = 1234; -- or whatever values > > you'd be using > > ROLLBACK; > > I have already tried the explain plan, but only using the pgAdmin > interface; running it from psql shows some more data that looks very > promising: > > > Index Scan using rcrvrs_pkey on rcrvrs (cost=0.00..3.68 rows=1 > width=6) (actual time=2.643..2.643 rows=1 loops=1) >Index Cond: (id_rcrvrs = 15434) > Trigger for constraint rcrvrs_id_prvrcrvrs_fkey: time=875.992 calls=1 > Total runtime: 878.641 ms > (4 rows) > > The trigger stuff was not shown on the pgAdmin interface. > > I will try to add an index on the foreign key field (id_prvrcrvrs) to > see if this improves performances of the incriminated query. > > Thanks for the kind attention. > > Best regards, > > > Giulio Cesare > ---(end of broadcast)--- TIP 2: Don't 'kill -9' the postmaster
