Thread: Almost infinite query -> Different Query Plan when changing where clause value
Almost infinite query -> Different Query Plan when changing where clause value
From
lionel duboeuf
Date:
Some informations:
The following problem has been detected on
Postgresql 8.3 and 8.4. on System linux or windows
Default AutoVacuum daemon working
One pg_dump every day
This happens sometimes and i don't see what can be the cause.
A manual Vacuum Analyse repair that problem.
Dear you all,
Hope someone would help me understand why only changing a where clause
value attribute will have a big impact on query plan and lead to almost
unending query.
regards
lionel
This is my query:
select element2_.element_seqnum as col_0_0_,
element1_.element_seqnum as col_1_0_,
link0_.link_rank_in_bunch as col_2_0_,
element2_.element_state as col_3_0_
from public.link link0_
inner join public.element element1_ on
link0_.element_target=element1_.element_seqnum
inner join public.user_element users3_ on
element1_.element_seqnum=users3_.element_seqnum
inner join public.user user4_ on users3_.user_seqnum=user4_.user_seqnum
inner join public.element_block blocks7_ on
element1_.element_seqnum=blocks7_.element_seqnum
inner join public.block block8_ on
blocks7_.block_seqnum=block8_.block_seqnum
inner join public.element element2_ on
link0_.element_source=element2_.element_seqnum
inner join public.user_element users5_ on
element2_.element_seqnum=users5_.element_seqnum
inner join public.user user6_ on
users5_.user_seqnum=user6_.user_seqnum
inner join public.element_block blocks9_ on
element2_.element_seqnum=blocks9_.element_seqnum
inner join public.block block10_ on
blocks9_.block_seqnum=block10_.block_seqnum
where block10_.block_seqnum=5
and block8_.block_seqnum=5
and user6_.user_seqnum=XX
and (link0_.link_sup_date is null)
and user4_.user_seqnum=XX
-------------------------------------------------------
This one works well: Query Plan for that user "2"
("user4_.user_seqnum=2" and "user6_.user_seqnum=2 ") will be:
Nested Loop (cost=36.33..5932.28 rows=1 width=16)
-> Nested Loop (cost=36.33..5926.38 rows=1 width=20)
-> Nested Loop (cost=36.33..5925.23 rows=1 width=24)
Join Filter: (link0_.element_source = blocks9_.element_seqnum)
-> Index Scan using fki_element_block_block on
element_block blocks9_ (cost=0.00..8.29 rows=1 width=8)
Index Cond: (block_seqnum = 5)
-> Nested Loop (cost=36.33..5916.64 rows=24 width=28)
-> Nested Loop (cost=36.33..5883.29 rows=4 width=40)
-> Seq Scan on "user" user4_ (cost=0.00..5.89
rows=1 width=4)
Filter: (user_seqnum = 2)
-> Nested Loop (cost=36.33..5877.36 rows=4
width=36)
-> Nested Loop (cost=36.33..5860.81
rows=4 width=28)
-> Nested Loop
(cost=36.33..5835.59 rows=6 width=20)
-> Nested Loop
(cost=0.00..17.76 rows=1 width=8)
-> Nested Loop
(cost=0.00..16.61 rows=1 width=12)
-> Index Scan
using fki_element_block_block on element_block blocks7_
(cost=0.00..8.29 rows=1 width=8)
Index Cond:
(block_seqnum = 5)
-> Index Scan
using pk_element on element element1_ (cost=0.00..8.31 rows=1 width=4)
Index Cond:
(element1_.element_seqnum = blocks7_.element_seqnum)
-> Seq Scan on block
block8_ (cost=0.00..1.14 rows=1 width=4)
Filter:
(block8_.block_seqnum = 5)
-> Bitmap Heap Scan on link
link0_ (cost=36.33..5792.21 rows=2050 width=12)
Recheck Cond:
(link0_.element_target = element1_.element_seqnum)
Filter:
(link0_.link_sup_date IS NULL)
-> Bitmap Index Scan
on element_target_fk (cost=0.00..35.82 rows=2050 width=0)
Index Cond:
(link0_.element_target = element1_.element_seqnum)
-> Index Scan using
pk_user_element on user_element users5_ (cost=0.00..4.19 rows=1 width=8)
Index Cond:
((users5_.user_seqnum = 2) AND (users5_.element_seqnum =
link0_.element_source))
-> Index Scan using pk_element on
element element2_ (cost=0.00..4.12 rows=1 width=8)
Index Cond:
(element2_.element_seqnum = link0_.element_source)
-> Index Scan using pk_user_element on user_element
users3_ (cost=0.00..8.33 rows=1 width=8)
Index Cond: ((users3_.user_seqnum = 2) AND
(users3_.element_seqnum = link0_.element_target))
-> Seq Scan on block block10_ (cost=0.00..1.14 rows=1 width=4)
Filter: (block10_.block_seqnum = 5)
-> Seq Scan on "user" user6_ (cost=0.00..5.89 rows=1 width=4)
Filter: (user6_.user_seqnum = 2)
*
This one is very very very long (was still in process 10 mins later with
100%cpu*): Query Plan for user "10" ("user4_.user_seqnum=10" and
"user6_.user_seqnum=10 ") will be:
QUERY PLAN
Nested Loop (cost=54.34..1490.62 rows=1 width=16)
-> Nested Loop (cost=54.34..1484.72 rows=1 width=20)
Join Filter: (link0_.element_source = blocks9_.element_seqnum)
-> Nested Loop (cost=54.34..1476.41 rows=1 width=32)
-> Nested Loop (cost=54.34..1475.26 rows=1 width=28)
-> Nested Loop (cost=54.34..1466.95 rows=1 width=36)
-> Nested Loop (cost=54.34..1461.05 rows=1
width=40)
-> Nested Loop (cost=54.34..1459.90
rows=1 width=44)
-> Nested Loop
(cost=54.34..1455.52 rows=1 width=36)
-> Nested Loop
(cost=13.15..1410.30 rows=1 width=24)
-> Nested Loop
(cost=0.00..16.63 rows=1 width=16)
-> Index Scan
using fki_element_block_block on element_block blocks7_
(cost=0.00..8.29 rows=1 width=8)
Index Cond:
(block_seqnum = 5)
-> Index Scan
using pk_user_element on user_element users3_ (cost=0.00..8.33 rows=1
width=8)
Index Cond:
((users3_.user_seqnum = 10) AND (users3_.element_seqnum =
blocks7_.element_seqnum))
-> Bitmap Heap Scan on
user_element users5_ (cost=13.15..1387.40 rows=627 width=8)
Recheck Cond:
(users5_.user_seqnum = 10)
-> Bitmap Index
Scan on fki_user_element_user (cost=0.00..12.99 rows=627 width=0)
Index Cond:
(users5_.user_seqnum = 10)
-> Bitmap Heap Scan on link
link0_ (cost=41.19..45.20 rows=1 width=12)
Recheck Cond:
((link0_.element_source = users5_.element_seqnum) AND
(link0_.element_target = users3_.element_seqnum))
Filter:
(link0_.link_sup_date IS NULL)
-> BitmapAnd
(cost=41.19..41.19 rows=1 width=0)
-> Bitmap Index
Scan on element_source_fk (cost=0.00..4.60 rows=21 width=0)
Index Cond:
(link0_.element_source = users5_.element_seqnum)
-> Bitmap Index
Scan on element_target_fk (cost=0.00..35.82 rows=2050 width=0)
Index Cond:
(link0_.element_target = users3_.element_seqnum)
-> Index Scan using pk_element on
element element2_ (cost=0.00..4.37 rows=1 width=8)
Index Cond:
(element2_.element_seqnum = link0_.element_source)
-> Seq Scan on block block8_
(cost=0.00..1.14 rows=1 width=4)
Filter: (block8_.block_seqnum = 5)
-> Seq Scan on "user" user4_ (cost=0.00..5.89
rows=1 width=4)
Filter: (user4_.user_seqnum = 10)
-> Index Scan using pk_element on element element1_
(cost=0.00..8.31 rows=1 width=4)
Index Cond: (element1_.element_seqnum =
link0_.element_target)
-> Seq Scan on block block10_ (cost=0.00..1.14 rows=1
width=4)
Filter: (block10_.block_seqnum = 5)
-> Index Scan using fki_element_block_block on element_block
blocks9_ (cost=0.00..8.29 rows=1 width=8)
Index Cond: (blocks9_.block_seqnum = 5)
-> Seq Scan on "user" user6_ (cost=0.00..5.89 rows=1 width=4)
Filter: (user6_.user_seqnum = 10)
_______________________________________________
Boozter-dev mailing list
Boozter-dev@boozter.com
http://ns355324.ovh.net/mailman/listinfo/boozter-dev
Re: Almost infinite query -> Different Query Plan when changing where clause value
From
"Kevin Grittner"
Date:
lionel duboeuf <lionel.duboeuf@boozter.com> wrote: > Some informations: > The following problem has been detected on > Postgresql 8.3 and 8.4. on System linux or windows > Default AutoVacuum daemon working > One pg_dump every day > This happens sometimes and i don't see what can be the cause. > A manual Vacuum Analyse repair that problem. It's good to know that the issue has been observed in more than one release or on more than one platform, but it's also useful to get a bit more information about one particular occurrence. Please read this: http://wiki.postgresql.org/wiki/SlowQueryQuestions In particular, knowing such things as your postgresql.conf settings, the disk configuration, how much RAM the machine has, etc. can allow us to provide more useful advice. Please run these as EXPLAIN ANALYZE (or at least whatever you can get to finish that way) instead of just EXPLAIN. If you can let the slow one run through EXPLAIN ANALYZE overnight or on a test machine so that it can complete, it will give us a lot more with which to work. Please attach wide output (like that from EXPLAIN) as a text attachment, to prevent wrapping which makes it hard to read. -Kevin
Re: Almost infinite query -> Different Query Plan when changing where clause value
From
lionel duboeuf
Date:
Thanks kevin for your answer. Here is some additionnal informations attached as files. regards. Lionel Kevin Grittner a écrit : > lionel duboeuf <lionel.duboeuf@boozter.com> wrote: > > >> Some informations: >> The following problem has been detected on >> Postgresql 8.3 and 8.4. on System linux or windows >> Default AutoVacuum daemon working >> One pg_dump every day >> This happens sometimes and i don't see what can be the cause. >> A manual Vacuum Analyse repair that problem. >> > > It's good to know that the issue has been observed in more than one > release or on more than one platform, but it's also useful to get a > bit more information about one particular occurrence. Please read > this: > > http://wiki.postgresql.org/wiki/SlowQueryQuestions > > In particular, knowing such things as your postgresql.conf settings, > the disk configuration, how much RAM the machine has, etc. can allow > us to provide more useful advice. > > Please run these as EXPLAIN ANALYZE (or at least whatever you can > get to finish that way) instead of just EXPLAIN. If you can let the > slow one run through EXPLAIN ANALYZE overnight or on a test machine > so that it can complete, it will give us a lot more with which to > work. Please attach wide output (like that from EXPLAIN) as a text > attachment, to prevent wrapping which makes it hard to read. > > -Kevin > processor : 0 vendor_id : GenuineIntel cpu family : 6 model : 15 model name : Intel(R) Core(TM)2 Duo CPU T7500 @ 2.20GHz stepping : 11 cpu MHz : 2201.000 cache size : 4096 KB physical id : 0 siblings : 2 core id : 0 cpu cores : 2 apicid : 0 initial apicid : 0 fdiv_bug : no hlt_bug : no f00f_bug : no coma_bug : no fpu : yes fpu_exception : yes cpuid level : 10 wp : yes flags : fpu vme de pse tsc msr pae mce cx8 apic mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ssht tm pbe nx lm constant_tsc arch_perfmon pebs bts pni dtes64 monitor ds_cpl vmx est tm2 ssse3 cx16 xtpr pdcm lahf_lm idatpr_shadow vnmi flexpriority bogomips : 4389.59 clflush size : 64 power management: processor : 1 vendor_id : GenuineIntel cpu family : 6 model : 15 model name : Intel(R) Core(TM)2 Duo CPU T7500 @ 2.20GHz stepping : 11 cpu MHz : 2201.000 cache size : 4096 KB physical id : 0 siblings : 2 core id : 1 cpu cores : 2 apicid : 1 initial apicid : 1 fdiv_bug : no hlt_bug : no f00f_bug : no coma_bug : no fpu : yes fpu_exception : yes cpuid level : 10 wp : yes flags : fpu vme de pse tsc msr pae mce cx8 apic mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ssht tm pbe nx lm constant_tsc arch_perfmon pebs bts pni dtes64 monitor ds_cpl vmx est tm2 ssse3 cx16 xtpr pdcm lahf_lm idatpr_shadow vnmi flexpriority bogomips : 4388.96 clflush size : 64 power management: QUERY PLAN Nested Loop (cost=58.71..1512.50 rows=1 width=16) (actual time=1.849..535681.136 rows=14 loops=1) -> Nested Loop (cost=58.71..1506.60 rows=1 width=20) (actual time=1.839..535680.377 rows=14 loops=1) Join Filter: (link0_.element_source = blocks9_.element_seqnum) -> Nested Loop (cost=58.71..1498.29 rows=1 width=32) (actual time=1.819..535337.910 rows=6534 loops=1) -> Nested Loop (cost=58.71..1497.14 rows=1 width=28) (actual time=1.811..535246.825 rows=6534 loops=1) -> Nested Loop (cost=58.71..1488.83 rows=1 width=36) (actual time=1.800..535160.718 rows=6534 loops=1) -> Nested Loop (cost=58.71..1484.40 rows=1 width=28) (actual time=1.772..535042.549 rows=6534loops=1) -> Nested Loop (cost=13.20..1434.87 rows=1 width=16) (actual time=1.398..8327.567 rows=122850loops=1) -> Nested Loop (cost=13.20..1428.97 rows=1 width=20) (actual time=1.387..1911.520rows=122850 loops=1) -> Nested Loop (cost=13.20..1427.83 rows=1 width=24) (actual time=1.374..517.662rows=122850 loops=1) -> Nested Loop (cost=0.00..16.63 rows=1 width=16) (actual time=0.085..0.409rows=15 loops=1) -> Index Scan using fki_element_block_block on element_block blocks7_ (cost=0.00..8.30 rows=1 width=8) (actual time=0.045..0.082 rows=15 loops=1) Index Cond: (block_seqnum = 5) -> Index Scan using pk_user_element on user_element users3_ (cost=0.00..8.33rows=1 width=8) (actual time=0.012..0.015 rows=1 loops=15) Index Cond: ((users3_.user_seqnum = 10) AND (users3_.element_seqnum= blocks7_.element_seqnum)) -> Bitmap Heap Scan on user_element users5_ (cost=13.20..1404.85 rows=634width=8) (actual time=1.091..12.478 rows=8190 loops=15) Recheck Cond: (users5_.user_seqnum = 10) -> Bitmap Index Scan on fki_user_element_user (cost=0.00..13.05rows=634 width=0) (actual time=1.062..1.062 rows=8194 loops=15) Index Cond: (users5_.user_seqnum = 10) -> Seq Scan on block block8_ (cost=0.00..1.14 rows=1 width=4) (actual time=0.004..0.005rows=1 loops=122850) Filter: (block8_.block_seqnum = 5) -> Seq Scan on "user" user4_ (cost=0.00..5.89 rows=1 width=4) (actual time=0.005..0.047rows=1 loops=122850) Filter: (user4_.user_seqnum = 10) -> Bitmap Heap Scan on link link0_ (cost=45.50..49.51 rows=1 width=12) (actual time=4.283..4.283rows=0 loops=122850) Recheck Cond: ((link0_.element_source = users5_.element_seqnum) AND (link0_.element_target= users3_.element_seqnum)) Filter: (link0_.link_sup_date IS NULL) -> BitmapAnd (cost=45.50..45.50 rows=1 width=0) (actual time=4.280..4.280 rows=0loops=122850) -> Bitmap Index Scan on element_source_fk (cost=0.00..4.61 rows=21 width=0)(actual time=0.007..0.007 rows=6 loops=122850) Index Cond: (link0_.element_source = users5_.element_seqnum) -> Bitmap Index Scan on element_target_fk (cost=0.00..40.12 rows=2089 width=0)(actual time=4.719..4.719 rows=33814 loops=110880) Index Cond: (link0_.element_target = users3_.element_seqnum) -> Index Scan using pk_element on element element2_ (cost=0.00..4.41 rows=1 width=8) (actualtime=0.009..0.011 rows=1 loops=6534) Index Cond: (element2_.element_seqnum = link0_.element_source) -> Index Scan using pk_element on element element1_ (cost=0.00..8.31 rows=1 width=4) (actual time=0.006..0.007rows=1 loops=6534) Index Cond: (element1_.element_seqnum = link0_.element_target) -> Seq Scan on block block10_ (cost=0.00..1.14 rows=1 width=4) (actual time=0.005..0.007 rows=1 loops=6534) Filter: (block10_.block_seqnum = 5) -> Index Scan using fki_element_block_block on element_block blocks9_ (cost=0.00..8.30 rows=1 width=8) (actualtime=0.007..0.030 rows=15 loops=6534) Index Cond: (blocks9_.block_seqnum = 5) -> Seq Scan on "user" user6_ (cost=0.00..5.89 rows=1 width=4) (actual time=0.006..0.048 rows=1 loops=14) Filter: (user6_.user_seqnum = 10) Total runtime: 535681.414 ms MemTotal: 3087448 kB MemFree: 2355500 kB Buffers: 22212 kB Cached: 396520 kB SwapCached: 0 kB Active: 387472 kB Inactive: 289388 kB Active(anon): 313808 kB Inactive(anon): 0 kB Active(file): 73664 kB Inactive(file): 289388 kB Unevictable: 0 kB Mlocked: 0 kB HighTotal: 2226696 kB HighFree: 1560912 kB LowTotal: 860752 kB LowFree: 794588 kB SwapTotal: 0 kB SwapFree: 0 kB Dirty: 6216 kB Writeback: 0 kB AnonPages: 258144 kB Mapped: 127688 kB Slab: 28196 kB SReclaimable: 14624 kB SUnreclaim: 13572 kB PageTables: 5272 kB NFS_Unstable: 0 kB Bounce: 0 kB WritebackTmp: 0 kB CommitLimit: 1543724 kB Committed_AS: 913152 kB VmallocTotal: 122880 kB VmallocUsed: 11192 kB VmallocChunk: 88472 kB HugePages_Total: 0 HugePages_Free: 0 HugePages_Rsvd: 0 HugePages_Surp: 0 Hugepagesize: 4096 kB DirectMap4k: 16376 kB DirectMap4M: 892928 kB # ----------------------------- # PostgreSQL configuration file # ----------------------------- # # This file consists of lines of the form: # # name = value # # (The "=" is optional.) Whitespace may be used. Comments are introduced with # "#" anywhere on a line. The complete list of parameter names and allowed # values can be found in the PostgreSQL documentation. # # The commented-out settings shown in this file represent the default values. # Re-commenting a setting is NOT sufficient to revert it to the default value; # you need to reload the server. # # This file is read on server startup and when the server receives a SIGHUP # signal. If you edit the file on a running system, you have to SIGHUP the # server for the changes to take effect, or use "pg_ctl reload". Some # parameters, which are marked below, require a server shutdown and restart to # take effect. # # Any parameter can also be given as a command-line option to the server, e.g., # "postgres -c log_connections=on". Some paramters can be changed at run time # with the "SET" SQL command. # # Memory units: kB = kilobytes MB = megabytes GB = gigabytes # Time units: ms = milliseconds s = seconds min = minutes h = hours d = days #------------------------------------------------------------------------------ # FILE LOCATIONS #------------------------------------------------------------------------------ # The default values of these variables are driven from the -D command-line # option or PGDATA environment variable, represented here as ConfigDir. data_directory = '/var/lib/postgresql/8.3/main' # use data in another directory # (change requires restart) hba_file = '/etc/postgresql/8.3/main/pg_hba.conf' # host-based authentication file # (change requires restart) ident_file = '/etc/postgresql/8.3/main/pg_ident.conf' # ident configuration file # (change requires restart) # If external_pid_file is not explicitly set, no extra PID file is written. external_pid_file = '/var/run/postgresql/8.3-main.pid' # write an extra PID file # (change requires restart) #------------------------------------------------------------------------------ # CONNECTIONS AND AUTHENTICATION #------------------------------------------------------------------------------ # - Connection Settings - #listen_addresses = 'localhost' # what IP address(es) to listen on; # comma-separated list of addresses; # defaults to 'localhost', '*' = all # (change requires restart) port = 5432 # (change requires restart) max_connections = 100 # (change requires restart) # Note: Increasing max_connections costs ~400 bytes of shared memory per # connection slot, plus lock space (see max_locks_per_transaction). You might # also need to raise shared_buffers to support more connections. #superuser_reserved_connections = 3 # (change requires restart) unix_socket_directory = '/var/run/postgresql' # (change requires restart) #unix_socket_group = '' # (change requires restart) #unix_socket_permissions = 0777 # begin with 0 to use octal notation # (change requires restart) #bonjour_name = '' # defaults to the computer name # (change requires restart) # - Security and Authentication - #authentication_timeout = 1min # 1s-600s ssl = true # (change requires restart) #ssl_ciphers = 'ALL:!ADH:!LOW:!EXP:!MD5:@STRENGTH' # allowed SSL ciphers # (change requires restart) #password_encryption = on #db_user_namespace = off # Kerberos and GSSAPI #krb_server_keyfile = '' # (change requires restart) #krb_srvname = 'postgres' # (change requires restart, Kerberos only) #krb_server_hostname = '' # empty string matches any keytab entry # (change requires restart, Kerberos only) #krb_caseins_users = off # (change requires restart) #krb_realm = '' # (change requires restart) # - TCP Keepalives - # see "man 7 tcp" for details #tcp_keepalives_idle = 0 # TCP_KEEPIDLE, in seconds; # 0 selects the system default #tcp_keepalives_interval = 0 # TCP_KEEPINTVL, in seconds; # 0 selects the system default #tcp_keepalives_count = 0 # TCP_KEEPCNT; # 0 selects the system default #------------------------------------------------------------------------------ # RESOURCE USAGE (except WAL) #------------------------------------------------------------------------------ # - Memory - shared_buffers = 24MB # min 128kB or max_connections*16kB # (change requires restart) #temp_buffers = 8MB # min 800kB #max_prepared_transactions = 5 # can be 0 or more # (change requires restart) # Note: Increasing max_prepared_transactions costs ~600 bytes of shared memory # per transaction slot, plus lock space (see max_locks_per_transaction). #work_mem = 1MB # min 64kB #maintenance_work_mem = 16MB # min 1MB #max_stack_depth = 2MB # min 100kB # - Free Space Map - max_fsm_pages = 153600 # min max_fsm_relations*16, 6 bytes each # (change requires restart) #max_fsm_relations = 1000 # min 100, ~70 bytes each # (change requires restart) # - Kernel Resource Usage - #max_files_per_process = 1000 # min 25 # (change requires restart) #shared_preload_libraries = '' # (change requires restart) # - Cost-Based Vacuum Delay - #vacuum_cost_delay = 0 # 0-1000 milliseconds #vacuum_cost_page_hit = 1 # 0-10000 credits #vacuum_cost_page_miss = 10 # 0-10000 credits #vacuum_cost_page_dirty = 20 # 0-10000 credits #vacuum_cost_limit = 200 # 1-10000 credits # - Background Writer - #bgwriter_delay = 200ms # 10-10000ms between rounds #bgwriter_lru_maxpages = 100 # 0-1000 max buffers written/round #bgwriter_lru_multiplier = 2.0 # 0-10.0 multipler on buffers scanned/round #------------------------------------------------------------------------------ # WRITE AHEAD LOG #------------------------------------------------------------------------------ # - Settings - #fsync = on # turns forced synchronization on or off #synchronous_commit = on # immediate fsync at commit #wal_sync_method = fsync # the default is the first option # supported by the operating system: # open_datasync # fdatasync # fsync # fsync_writethrough # open_sync #full_page_writes = on # recover from partial page writes #wal_buffers = 64kB # min 32kB # (change requires restart) #wal_writer_delay = 200ms # 1-10000 milliseconds #commit_delay = 0 # range 0-100000, in microseconds #commit_siblings = 5 # range 1-1000 # - Checkpoints - #checkpoint_segments = 3 # in logfile segments, min 1, 16MB each #checkpoint_timeout = 5min # range 30s-1h #checkpoint_completion_target = 0.5 # checkpoint target duration, 0.0 - 1.0 #checkpoint_warning = 30s # 0 is off # - Archiving - #archive_mode = off # allows archiving to be done # (change requires restart) #archive_command = '' # command to use to archive a logfile segment #archive_timeout = 0 # force a logfile segment switch after this # time; 0 is off #------------------------------------------------------------------------------ # QUERY TUNING #------------------------------------------------------------------------------ # - Planner Method Configuration - #enable_bitmapscan = on #enable_hashagg = on #enable_hashjoin = on #enable_indexscan = on #enable_mergejoin = on #enable_nestloop = on #enable_seqscan = on #enable_sort = on #enable_tidscan = on # - Planner Cost Constants - #seq_page_cost = 1.0 # measured on an arbitrary scale #random_page_cost = 4.0 # same scale as above #cpu_tuple_cost = 0.01 # same scale as above #cpu_index_tuple_cost = 0.005 # same scale as above #cpu_operator_cost = 0.0025 # same scale as above #effective_cache_size = 128MB # - Genetic Query Optimizer - #geqo = on #geqo_threshold = 12 #geqo_effort = 5 # range 1-10 #geqo_pool_size = 0 # selects default based on effort #geqo_generations = 0 # selects default based on effort #geqo_selection_bias = 2.0 # range 1.5-2.0 # - Other Planner Options - #default_statistics_target = 10 # range 1-1000 #constraint_exclusion = off #from_collapse_limit = 8 #join_collapse_limit = 8 # 1 disables collapsing of explicit # JOIN clauses #------------------------------------------------------------------------------ # ERROR REPORTING AND LOGGING #------------------------------------------------------------------------------ # - Where to Log - #log_destination = 'stderr' # Valid values are combinations of # stderr, csvlog, syslog and eventlog, # depending on platform. csvlog # requires logging_collector to be on. # This is used when logging to stderr: logging_collector = on # Enable capturing of stderr and csvlog # into log files. Required to be on for # csvlogs. # (change requires restart) # These are only used if logging_collector is on: log_directory = 'pg_log' # directory where log files are written, # can be absolute or relative to PGDATA #log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log' # log file name pattern, # can include strftime() escapes #log_truncate_on_rotation = off # If on, an existing log file of the # same name as the new log file will be # truncated rather than appended to. # But such truncation only occurs on # time-driven rotation, not on restarts # or size-driven rotation. Default is # off, meaning append to existing files # in all cases. #log_rotation_age = 1d # Automatic rotation of logfiles will # happen after that time. 0 to disable. #log_rotation_size = 10MB # Automatic rotation of logfiles will # happen after that much log output. # 0 to disable. # These are relevant when logging to syslog: #syslog_facility = 'LOCAL0' #syslog_ident = 'postgres' # - When to Log - #client_min_messages = notice # values in order of decreasing detail: # debug5 # debug4 # debug3 # debug2 # debug1 # log # notice # warning # error #log_min_messages = notice # values in order of decreasing detail: # debug5 # debug4 # debug3 # debug2 # debug1 # info # notice # warning # error # log # fatal # panic #log_error_verbosity = default # terse, default, or verbose messages log_min_error_statement = error # values in order of decreasing detail: # debug5 # debug4 # debug3 # debug2 # debug1 # info # notice # warning # error # log # fatal # panic (effectively off) log_min_duration_statement = 100 # -1 is disabled, 0 logs all statements # and their durations, > 0 logs only # statements running at least this time. #silent_mode = off # DO NOT USE without syslog or # logging_collector # (change requires restart) # - What to Log - #debug_print_parse = off #debug_print_rewritten = off #debug_print_plan = off #debug_pretty_print = off #log_checkpoints = off #log_connections = off #log_disconnections = off #log_duration = off #log_hostname = off log_line_prefix = '%t ' # special values: # %u = user name # %d = database name # %r = remote host and port # %h = remote host # %p = process ID # %t = timestamp without milliseconds # %m = timestamp with milliseconds # %i = command tag # %c = session ID # %l = session line number # %s = session start timestamp # %v = virtual transaction ID # %x = transaction ID (0 if none) # %q = stop here in non-session # processes # %% = '%' # e.g. '<%u%%%d> ' #log_lock_waits = off # log lock waits >= deadlock_timeout #log_statement = 'none' # none, ddl, mod, all #log_temp_files = -1 # log temporary files equal or larger # than specified size; # -1 disables, 0 logs all temp files #log_timezone = unknown # actually, defaults to TZ environment # setting #------------------------------------------------------------------------------ # RUNTIME STATISTICS #------------------------------------------------------------------------------ # - Query/Index Statistics Collector - #track_activities = on #track_counts = on #update_process_title = on # - Statistics Monitoring - #log_parser_stats = off #log_planner_stats = off #log_executor_stats = off #log_statement_stats = off #------------------------------------------------------------------------------ # AUTOVACUUM PARAMETERS #------------------------------------------------------------------------------ #autovacuum = on # Enable autovacuum subprocess? 'on' # requires track_counts to also be on. #log_autovacuum_min_duration = -1 # -1 disables, 0 logs all actions and # their durations, > 0 logs only # actions running at least that time. #autovacuum_max_workers = 3 # max number of autovacuum subprocesses #autovacuum_naptime = 1min # time between autovacuum runs #autovacuum_vacuum_threshold = 50 # min number of row updates before # vacuum #autovacuum_analyze_threshold = 50 # min number of row updates before # analyze #autovacuum_vacuum_scale_factor = 0.2 # fraction of table size before vacuum #autovacuum_analyze_scale_factor = 0.1 # fraction of table size before analyze #autovacuum_freeze_max_age = 200000000 # maximum XID age before forced vacuum # (change requires restart) #autovacuum_vacuum_cost_delay = 20 # default vacuum cost delay for # autovacuum, -1 means use # vacuum_cost_delay #autovacuum_vacuum_cost_limit = -1 # default vacuum cost limit for # autovacuum, -1 means use # vacuum_cost_limit #------------------------------------------------------------------------------ # CLIENT CONNECTION DEFAULTS #------------------------------------------------------------------------------ # - Statement Behavior - #search_path = '"$user",public' # schema names #default_tablespace = '' # a tablespace name, '' uses the default #temp_tablespaces = '' # a list of tablespace names, '' uses # only default tablespace #check_function_bodies = on #default_transaction_isolation = 'read committed' #default_transaction_read_only = off #session_replication_role = 'origin' #statement_timeout = 0 # 0 is disabled #vacuum_freeze_min_age = 100000000 #xmlbinary = 'base64' #xmloption = 'content' # - Locale and Formatting - datestyle = 'iso, dmy' #timezone = unknown # actually, defaults to TZ environment # setting #timezone_abbreviations = 'Default' # Select the set of available time zone # abbreviations. Currently, there are # Default # Australia # India # You can create your own file in # share/timezonesets/. #extra_float_digits = 0 # min -15, max 2 #client_encoding = sql_ascii # actually, defaults to database # encoding # These settings are initialized by initdb, but they can be changed. lc_messages = 'fr_FR.UTF-8' # locale for system error message # strings lc_monetary = 'fr_FR.UTF-8' # locale for monetary formatting lc_numeric = 'fr_FR.UTF-8' # locale for number formatting lc_time = 'fr_FR.UTF-8' # locale for time formatting # default configuration for text search default_text_search_config = 'pg_catalog.french' # - Other Defaults - #explain_pretty_print = on #dynamic_library_path = '$libdir' #local_preload_libraries = '' #------------------------------------------------------------------------------ # LOCK MANAGEMENT #------------------------------------------------------------------------------ #deadlock_timeout = 1s #max_locks_per_transaction = 64 # min 10 # (change requires restart) # Note: Each lock table slot uses ~270 bytes of shared memory, and there are # max_locks_per_transaction * (max_connections + max_prepared_transactions) # lock table slots. #------------------------------------------------------------------------------ # VERSION/PLATFORM COMPATIBILITY #------------------------------------------------------------------------------ # - Previous PostgreSQL Versions - #add_missing_from = off #array_nulls = on #backslash_quote = safe_encoding # on, off, or safe_encoding #default_with_oids = off #escape_string_warning = on #regex_flavor = advanced # advanced, extended, or basic #sql_inheritance = on #standard_conforming_strings = off #synchronize_seqscans = on # - Other Platforms and Clients - #transform_null_equals = off #------------------------------------------------------------------------------ # CUSTOMIZED OPTIONS #------------------------------------------------------------------------------ #custom_variable_classes = '' # list of custom variable class names
Re: Almost infinite query -> Different Query Plan when changing where clause value
From
"Kevin Grittner"
Date:
lionel duboeuf <lionel.duboeuf@boozter.com> wrote: > Thanks kevin for your answer. Here is some additionnal > informations attached as files. Could you supply an EXPLAIN ANALYZE of the fast plan as an attachment, for comparison? Anyway, it looks like at least one big problem is the bad estimate on how many rows will be generated by joining to the users5_ table: > (cost=13.20..1427.83 rows=1 width=24) > (actual time=1.374..517.662 rows=122850 loops=1) If it had expected 122850 rows to qualify for that join, it probably would have picked a different plan. I just reread your original email, and I'm not sure I understand what you meant regarding VACUUM ANALYZE. If you run that right beforehand, do you still get the slow plan for user 10? -Kevin
Re: Almost infinite query -> Different Query Plan when changing where clause value
From
lionel duboeuf
Date:
See as attachment the "correct" query plan for an other 'user'.
I confirm by executing manual "VACUUM ANALYZE" that the problem is solved.
But what i don't understand is that i would expect autovacuum to do the job.
Lionel
Kevin Grittner a écrit :
> lionel duboeuf <lionel.duboeuf@boozter.com> wrote:
>
>> Thanks kevin for your answer. Here is some additionnal
>> informations attached as files.
>>
>
> Could you supply an EXPLAIN ANALYZE of the fast plan as an
> attachment, for comparison?
>
> Anyway, it looks like at least one big problem is the bad estimate
> on how many rows will be generated by joining to the users5_ table:
>
>
>> (cost=13.20..1427.83 rows=1 width=24)
>> (actual time=1.374..517.662 rows=122850 loops=1)
>>
>
> If it had expected 122850 rows to qualify for that join, it probably
> would have picked a different plan.
>
> I just reread your original email, and I'm not sure I understand
> what you meant regarding VACUUM ANALYZE. If you run that right
> beforehand, do you still get the slow plan for user 10?
>
> -Kevin
QUERY PLAN
Nested Loop (cost=40145.11..87205.30 rows=1836 width=16) (actual time=4675.927..8731.066 rows=14 loops=1)
-> Seq Scan on "user" user6_ (cost=0.00..5.89 rows=1 width=4) (actual time=0.021..0.070 rows=1 loops=1)
Filter: (user_seqnum = 2)
-> Nested Loop (cost=40145.11..87181.05 rows=1836 width=20) (actual time=4675.899..8730.951 rows=14 loops=1)
-> Seq Scan on block block10_ (cost=0.00..1.14 rows=1 width=4) (actual time=0.005..0.013 rows=1 loops=1)
Filter: (block_seqnum = 5)
-> Hash Join (cost=40145.11..87161.55 rows=1836 width=24) (actual time=4675.889..8730.897 rows=14 loops=1)
Hash Cond: (link0_.element_source = blocks9_.element_seqnum)
-> Hash Join (cost=38355.16..84432.84 rows=81814 width=28) (actual time=1959.785..8659.972 rows=54481
loops=1)
Hash Cond: (link0_.element_source = element2_.element_seqnum)
-> Hash Join (cost=15293.09..59268.67 rows=100436 width=12) (actual time=213.249..6178.980
rows=357563loops=1)
Hash Cond: (link0_.element_target = element1_.element_seqnum)
-> Seq Scan on link link0_ (cost=0.00..36544.07 rows=1968922 width=12) (actual
time=0.017..2750.650rows=1968833 loops=1)
Filter: (link_sup_date IS NULL)
-> Hash (cost=15280.27..15280.27 rows=1025 width=12) (actual time=212.858..212.858 rows=15
loops=1)
-> Nested Loop (cost=2881.38..15280.27 rows=1025 width=12) (actual
time=9.566..212.823rows=15 loops=1)
-> Seq Scan on "user" user4_ (cost=0.00..5.89 rows=1 width=4) (actual
time=0.012..0.051rows=1 loops=1)
Filter: (user_seqnum = 2)
-> Nested Loop (cost=2881.38..15264.14 rows=1025 width=16) (actual
time=9.549..212.724rows=15 loops=1)
-> Seq Scan on block block8_ (cost=0.00..1.14 rows=1 width=4) (actual
time=0.004..0.009rows=1 loops=1)
Filter: (block_seqnum = 5)
-> Nested Loop (cost=2881.38..15252.75 rows=1025 width=20) (actual
time=9.540..212.673rows=15 loops=1)
-> Hash Join (cost=2881.38..6613.08 rows=1434 width=16) (actual
time=9.522..212.453rows=15 loops=1)
Hash Cond: (users3_.element_seqnum = blocks7_.element_seqnum)
-> Bitmap Heap Scan on user_element users3_
(cost=1091.43..4090.04rows=63889 width=8) (actual time=9.252..131.240 rows=60568 loops=1)
Recheck Cond: (user_seqnum = 2)
-> Bitmap Index Scan on fki_user_element_user
(cost=0.00..1075.46rows=63889 width=0) (actual time=9.017..9.017 rows=60568 loops=1)
Index Cond: (user_seqnum = 2)
-> Hash (cost=1705.72..1705.72 rows=6738 width=8) (actual
time=0.079..0.079rows=15 loops=1)
-> Bitmap Heap Scan on element_block blocks7_
(cost=116.50..1705.72rows=6738 width=8) (actual time=0.032..0.053 rows=15 loops=1)
Recheck Cond: (block_seqnum = 5)
-> Bitmap Index Scan on fki_element_block_block
(cost=0.00..114.81rows=6738 width=0) (actual time=0.025..0.025 rows=15 loops=1)
Index Cond: (block_seqnum = 5)
-> Index Scan using pk_element on element element1_
(cost=0.00..6.01rows=1 width=4) (actual time=0.007..0.008 rows=1 loops=15)
Index Cond: (element1_.element_seqnum = users3_.element_seqnum)
-> Hash (cost=21951.46..21951.46 rows=63889 width=16) (actual time=1746.309..1746.309 rows=60568
loops=1)
-> Hash Join (cost=15534.07..21951.46 rows=63889 width=16) (actual time=1277.246..1653.836
rows=60568loops=1)
Hash Cond: (users5_.element_seqnum = element2_.element_seqnum)
-> Bitmap Heap Scan on user_element users5_ (cost=1091.43..4090.04 rows=63889
width=8)(actual time=7.775..87.724 rows=60568 loops=1)
Recheck Cond: (user_seqnum = 2)
-> Bitmap Index Scan on fki_user_element_user (cost=0.00..1075.46 rows=63889
width=0)(actual time=7.565..7.565 rows=60568 loops=1)
Index Cond: (user_seqnum = 2)
-> Hash (cost=7552.95..7552.95 rows=419895 width=8) (actual time=1269.211..1269.211
rows=419895loops=1)
-> Seq Scan on element element2_ (cost=0.00..7552.95 rows=419895 width=8)
(actualtime=0.031..640.484 rows=419895 loops=1)
-> Hash (cost=1705.72..1705.72 rows=6738 width=8) (actual time=0.081..0.081 rows=15 loops=1)
-> Bitmap Heap Scan on element_block blocks9_ (cost=116.50..1705.72 rows=6738 width=8) (actual
time=0.034..0.058rows=15 loops=1)
Recheck Cond: (block_seqnum = 5)
-> Bitmap Index Scan on fki_element_block_block (cost=0.00..114.81 rows=6738 width=0)
(actualtime=0.028..0.028 rows=15 loops=1)
Index Cond: (block_seqnum = 5)
Total runtime: 8731.494 ms
Re: Almost infinite query -> Different Query Plan when changing where clause value
From
Scott Marlowe
Date:
On Mon, Feb 15, 2010 at 2:52 AM, lionel duboeuf <lionel.duboeuf@boozter.com> wrote: > See as attachment the "correct" query plan for an other 'user'. > I confirm by executing manual "VACUUM ANALYZE" that the problem is solved. > But what i don't understand is that i would expect autovacuum to do the job. There are two operations here. Vacuum, which reclaims lost space, and analyze which analyzes your data and stores histograms to be used when building queries, to determine how many rows are likely to be returned by each part of the plan. The autovac daemon runs both vacuums and analyzes, often independently of each other, when needed, based on threshold settings. By running autovac your db would get analyzed when necessary and would then have up to date statistics when queries were run after that.