Re: [PERFORM] duration logging setting in 7.4
On Mon, Nov 17, 2003 at 09:37:07PM -0500, Bruce Momjian wrote: > Ryszard Lach wrote: > > > > Hi. > > > > I'm trying to set run-time environment in pgsql7.4 so, that it prints > > all statements with duration time, but I can't understand why setting > > log_min_duration_statement to '0' causes printing to syslog plenty of > > lines ending with 'duration: statement:', i.e. without any statement > > string (except expected ones). Can anybody help me? > > Can you show us some of the log file? If I do: > Sure. Nov 18 10:05:20 postgres[1348]: [318-1] LOG: duration: 0.297 ms statement: Nov 18 10:05:20 postgres[1311]: [5477-1] LOG: duration: 0.617 ms statement: Nov 18 10:05:20 postgres[1312]: [5134-1] LOG: duration: 0.477 ms statement: Nov 18 10:05:20 postgres[1349]: [318-1] LOG: duration: 0.215 ms statement: Nov 18 10:05:20 postgres[1313]: [5449-1] LOG: duration: 0.512 ms statement: Nov 18 10:05:20 postgres[1314]: [5534-1] LOG: duration: 0.420 ms statement: Nov 18 10:05:20 postgres[1330]: [772-1] LOG: duration: 1.386 ms statement: SELECT * FROM mytablemius WHERE id = 0; Nov 18 10:05:20 postgres[1315]: [5757-1] LOG: duration: 0.417 ms statement: Nov 18 10:05:20 postgres[1316]: [5885-1] LOG: duration: 0.315 ms statement: Nov 18 10:05:20 postgres[1317]: [5914-1] LOG: duration: 0.301 ms statement: Nov 18 10:05:20 postgres[1318]: [5990-1] LOG: duration: 0.293 ms statement: Nov 18 10:05:20 postgres[1319]: [6009-1] LOG: duration: 0.211 ms statement: Nov 18 10:05:20 postgres[1320]: [6039-1] LOG: duration: 0.188 ms statement: this is with setting log_duration = false log_statement = false log_min_duration_statement = 0 The amount of lines containing statement string is nearly the same ase before upgrade (from 7.3), all other lines are extra. I don't know if this can be a reason, this is on a pretty busy machine (ca. 100 selects/second, but loadavg lower then 0.9), I'm logging postgres through syslog. Richard. -- "First they ignore you. Then they laugh at you. Then they fight you. Then you win." - Mohandas Gandhi. ---(end of broadcast)--- TIP 9: the planner will ignore your desire to choose an index scan if your joining column's datatypes do not match
[PERFORM] Join on incompatible types
> "scott" == scott marlowe <[EMAIL PROTECTED]> writes:
[...]
scott> Note here:
scott> Merge Join (cost=1788.68..4735.71 rows=1 width=85) (actual
scott> time=597.540..1340.526 rows=20153 loops=1) Merge Cond:
scott> ("outer".id = "inner".id)
scott> This estimate is WAY off. Are both of those fields indexed
scott> and analyzed? Have you tried upping the statistics target on
scott> those two fields? I assume they are compatible types.
Should I understand that a join on incompatible types (such as integer
and varchar) may lead to bad performances ?
--
Laurent Martelli
[EMAIL PROTECTED]Java Aspect Components
http://www.aopsys.com/ http://jac.aopsys.com
---(end of broadcast)---
TIP 1: subscribe and unsubscribe commands go to [EMAIL PROTECTED]
Re: [PERFORM] Join on incompatible types
Laurent Martelli wrote:
"scott" == scott marlowe <[EMAIL PROTECTED]> writes:
[...]
scott> Note here:
scott> Merge Join (cost=1788.68..4735.71 rows=1 width=85) (actual
scott> time=597.540..1340.526 rows=20153 loops=1) Merge Cond:
scott> ("outer".id = "inner".id)
scott> This estimate is WAY off. Are both of those fields indexed
scott> and analyzed? Have you tried upping the statistics target on
scott> those two fields? I assume they are compatible types.
Should I understand that a join on incompatible types (such as integer
and varchar) may lead to bad performances ?
Conversely, you should enforce strict type compatibility in comparisons for
getting any good plans..:-)
Shridhar
---(end of broadcast)---
TIP 8: explain analyze is your friend
Re: [PERFORM] duration logging setting in 7.4
Wow, that is strange. If you don't use syslog, do you see the proper output? If you turn on log_statement, do you see the statements? --- Ryszard Lach wrote: > On Mon, Nov 17, 2003 at 09:37:07PM -0500, Bruce Momjian wrote: > > Ryszard Lach wrote: > > > > > > Hi. > > > > > > I'm trying to set run-time environment in pgsql7.4 so, that it prints > > > all statements with duration time, but I can't understand why setting > > > log_min_duration_statement to '0' causes printing to syslog plenty of > > > lines ending with 'duration: statement:', i.e. without any statement > > > string (except expected ones). Can anybody help me? > > > > Can you show us some of the log file? If I do: > > > > Sure. > > Nov 18 10:05:20 postgres[1348]: [318-1] LOG: duration: 0.297 ms statement: > Nov 18 10:05:20 postgres[1311]: [5477-1] LOG: duration: 0.617 ms statement: > Nov 18 10:05:20 postgres[1312]: [5134-1] LOG: duration: 0.477 ms statement: > Nov 18 10:05:20 postgres[1349]: [318-1] LOG: duration: 0.215 ms statement: > Nov 18 10:05:20 postgres[1313]: [5449-1] LOG: duration: 0.512 ms statement: > Nov 18 10:05:20 postgres[1314]: [5534-1] LOG: duration: 0.420 ms statement: > Nov 18 10:05:20 postgres[1330]: [772-1] LOG: duration: 1.386 ms statement: SELECT > * FROM mytablemius WHERE id = 0; > Nov 18 10:05:20 postgres[1315]: [5757-1] LOG: duration: 0.417 ms statement: > Nov 18 10:05:20 postgres[1316]: [5885-1] LOG: duration: 0.315 ms statement: > Nov 18 10:05:20 postgres[1317]: [5914-1] LOG: duration: 0.301 ms statement: > Nov 18 10:05:20 postgres[1318]: [5990-1] LOG: duration: 0.293 ms statement: > Nov 18 10:05:20 postgres[1319]: [6009-1] LOG: duration: 0.211 ms statement: > Nov 18 10:05:20 postgres[1320]: [6039-1] LOG: duration: 0.188 ms statement: > > > this is with setting > > log_duration = false > log_statement = false > log_min_duration_statement = 0 > > The amount of lines containing statement string is nearly the same ase before > upgrade (from 7.3), all other lines are extra. > > I don't know if this can be a reason, this is on a pretty busy machine (ca. 100 > selects/second, but loadavg lower then 0.9), I'm logging postgres through syslog. > > Richard. > > -- > "First they ignore you. Then they laugh at you. Then they > fight you. Then you win." - Mohandas Gandhi. > -- Bruce Momjian| http://candle.pha.pa.us [EMAIL PROTECTED] | (610) 359-1001 + If your life is a hard drive, | 13 Roberts Road + Christ can be your backup.| Newtown Square, Pennsylvania 19073 ---(end of broadcast)--- TIP 2: you can get off all lists at once with the unregister command (send "unregister YourEmailAddressHere" to [EMAIL PROTECTED])
Re: [PERFORM] Join on incompatible types
> "Shridhar" == Shridhar Daithankar <[EMAIL PROTECTED]> writes:
Shridhar> Laurent Martelli wrote:
[...]
>> Should I understand that a join on incompatible types (such as
>> integer and varchar) may lead to bad performances ?
Shridhar> Conversely, you should enforce strict type compatibility
Shridhar> in comparisons for getting any good plans..:-)
Ha ha, now I understand why a query of mine was so sluggish.
Is there a chance I could achieve the good perfs without having he
same types ? I've tried a CAST in the query, but it's even a little
worse than without it. However, using a view to cast integers into
varchar gives acceptable results (see at the end).
I'm using Postgresql 7.3.4.
iprofil-jac=# EXPLAIN ANALYZE SELECT * from classes where exists (select value from
lists where lists.id='16' and lists.value=classes.id);
QUERY PLAN
Seq Scan on classes (cost=0.00..5480289.75 rows=9610 width=25) (actual
time=31.68..7321.56 rows=146 loops=1)
Filter: (subplan)
SubPlan
-> Index Scan using lists_id on lists (cost=0.00..285.12 rows=1 width=8)
(actual time=0.38..0.38 rows=0 loops=19220)
Index Cond: (id = 16)
Filter: ((value)::text = ($0)::text)
Total runtime: 7321.72 msec
iprofil-jac=# EXPLAIN ANALYZE SELECT * from classes2 where exists (select value from
lists where lists.id='16' and lists.value=classes2.id);
QUERY PLAN
-
Seq Scan on classes2 (cost=0.00..5923.87 rows=500 width=64) (actual
time=0.76..148.20 rows=146 loops=1)
Filter: (subplan)
SubPlan
-> Index Scan using lists_value on lists (cost=0.00..5.90 rows=1 width=8)
(actual time=0.01..0.01 rows=0 loops=19220)
Index Cond: ((id = 16) AND (value = $0))
Total runtime: 148.34 msec
--
-- Tables classes and classes2 are populated with the same data, they
-- only differ on the type of the "id" column.
--
iprofil-jac=# \d classes
Table "public.classes"
Colonne | Type| Modifications
-+---+---
id | integer | not null
classid | character varying |
Index: classes_pkey primary key btree (id)
iprofil-jac=# \d classes2
Table "public.classes2"
Colonne | Type| Modifications
-+---+---
id | character varying | not null
classid | character varying |
Index: classes2_pkey primary key btree (id)
iprofil-jac=# \d lists
Table "public.lists"
Colonne | Type| Modifications
-+---+---
id | integer | not null
index | integer | not null
value | character varying |
Index: lists_index unique btree (id, "index"),
lists_id btree (id),
lists_value btree (id, value)
--
-- IT'S EVEN BETTER WITH A JOIN
--
iprofil-jac=# EXPLAIN ANALYZE SELECT * from lists join classes on
classes.id=lists.value where lists.id='16';
QUERY PLAN
---
Nested Loop (cost=0.00..90905.88 rows=298 width=41) (actual time=53.93..9327.87
rows=146 loops=1)
Join Filter: (("inner".id)::text = ("outer".value)::text)
-> Seq Scan on lists (cost=0.00..263.43 rows=146 width=16) (actual
time=8.38..9.70 rows=146 loops=1)
Filter: (id = 16)
-> Seq Scan on classes (cost=0.00..333.20 rows=19220 width=25) (actual
time=0.00..28.45 rows=19220 loops=146)
Total runtime: 9328.35 msec
iprofil-jac=# EXPLAIN ANALYZE SELECT * from lists join classes2 on
classes2.id=lists.value where lists.id='16';
QUERY PLAN
--
Merge Join (cost=268.67..324.09 rows=16 width=80) (actual time=9.59..65.55 rows=146
loops=1)
Merge Cond: ("outer".id = "inner".value)
-> Index Scan using classes2_pkey on classes2 (cost=0.00..52.00 rows=1000
width=64) (actual time=0.03..40.83 rows=18778 loops=1)
-> Sort (cost=268.67..269.03 rows=146 width=16) (actual time=9.50..9.56 rows=146
loops=1)
Sort Key: lists.value
-> Seq Scan on lists (cost=0.00..263.43 rows=146 width=16) (actual
time=8.83..9.17 rows=146 loops=1)
[PERFORM] More detail on settings for pgavd?
Shridhar, I was looking at the -V/-v and -A/-a settings in pgavd, and really don't understand how the calculation works. According to the readme, if I set -v to 1000 and -V to 2 (the defaults) for a table with 10,000 rows, pgavd would only vacuum after 21,000 rows had been updated. This seems wrong. Can you clear this up a little? I'd like to tweak these settings but can't without being better aquainted with the calculation. Also, you may want to reverse your default ratio for Vacuum/analyze frequency. True, analyze is a less expensive operation than Vacuum, but it's also needed less often -- only when the *distribution* of data changes.I've seen databases where the optimal vacuum/analyze frequency was every 10 min/once per day. -- -Josh Berkus Aglio Database Solutions San Francisco ---(end of broadcast)--- TIP 7: don't forget to increase your free space map settings
[PERFORM] High Processor consumption
I am running RH 7.3 running Apache 1.3.27-2 and PostgreSQL 7.2.3-5.73. When having 100+ users connected to my server I notice that postmaster consumes up wards of 90% of the processor and I hardly am higher than 10% idle. I did notice that when I kill apache and postmaster that my idle processor percentage goes to 95% or higher. I am looking on ways that I can find what connections are making the database processes run so high. If this could also tell which program is accessing it, it would be helpful. I have look through the documents on performance tuning postgresql and have adjusted my memory with little effect. I have even routed all traffic away from the Apache server so no load is on apache. I do have C programs that run and access the database. Any help will be greatly appreciated. Thanks in advance, Ben ---(end of broadcast)--- TIP 9: the planner will ignore your desire to choose an index scan if your joining column's datatypes do not match
[PERFORM] problem with select count(*) ..
Ever Since i upgraded to 7.4RC2 i am facing problem with select count(*) . In 7.3 the problem was not there select count(*) from data_bank.profiles used to return almost instantly , but in 7.4 explain analyze SELECT count(*) from data_bank.profiles; QUERY PLAN --- Aggregate (cost=48361.30..48361.30 rows=1 width=0) (actual time=23456.870..23456.871 rows=1 loops=1) -> Seq Scan on profiles (cost=0.00..47431.84 rows=371784 width=0) (actual time=12174.999..23262.823 rows=123928 loops=1) Total runtime: 23458.460 ms (3 rows) tradein_clients=# If i dump and reload the performance improves and it takes < 1 sec. This is what i have been doing since the upgrade. But its not a solution. The Vacuum full is at the end of a loading batch SQL file which makes lot of insert , deletes and updates. Regds Mallah. VACUUM FULL VERBOSE ANALYZE data_bank.profiles; INFO: vacuuming "data_bank.profiles" INFO: "profiles": found 430524 removable, 371784 nonremovable row versions in 43714 pages INFO: index "profiles_pincode" now contains 371784 row versions in 3419 pages INFO: index "profiles_city" now contains 371784 row versions in 3471 pages INFO: index "profiles_branch" now contains 371784 row versions in 2237 pages INFO: index "profiles_area_code" now contains 371784 row versions in 2611 pages INFO: index "profiles_source" now contains 371784 row versions in 3165 pages INFO: index "co_name_index_idx" now contains 371325 row versions in 3933 pages INFO: index "address_index_idx" now contains 371490 row versions in 4883 pages INFO: index "profiles_exp_cat" now contains 154836 row versions in 2181 pages INFO: index "profiles_imp_cat" now contains 73678 row versions in 1043 pages INFO: index "profiles_manu_cat" now contains 87124 row versions in 1201 pages INFO: index "profiles_serv_cat" now contains 19340 row versions in 269 pages INFO: index "profiles_pid" now contains 371784 row versions in 817 pages INFO: index "profiles_pending_branch_id" now contains 0 row versions in 1 pages INFO: "profiles": moved 0 row versions, truncated 43714 to 43714 pages INFO: vacuuming "pg_toast.pg_toast_67748379" INFO: "pg_toast_67748379": found 0 removable, 74 nonremovable row versions in 17 pages INFO: index "pg_toast_67748379_index" now contains 74 row versions in 2 pages INFO: "pg_toast_67748379": moved 1 row versions, truncated 17 to 17 pages INFO: index "pg_toast_67748379_index" now contains 74 row versions in 2 pages INFO: analyzing "data_bank.profiles" INFO: "profiles": 43714 pages, 3000 rows sampled, 3634 estimated total rows VACUUM Time: 1001525.19 ms ---(end of broadcast)--- TIP 3: if posting/reading through Usenet, please send an appropriate subscribe-nomail command to [EMAIL PROTECTED] so that your message can get through to the mailing list cleanly
Re: [PERFORM] More detail on settings for pgavd?
Josh Berkus wrote: Shridhar, I was looking at the -V/-v and -A/-a settings in pgavd, and really don't understand how the calculation works. According to the readme, if I set -v to 1000 and -V to 2 (the defaults) for a table with 10,000 rows, pgavd would only vacuum after 21,000 rows had been updated. This seems wrong. Can you clear this up a little? I'd like to tweak these settings but can't without being better aquainted with the calculation. Also, you may want to reverse your default ratio for Vacuum/analyze frequency. True, analyze is a less expensive operation than Vacuum, but it's also needed less often -- only when the *distribution* of data changes.I've seen databases where the optimal vacuum/analyze frequency was every 10 min/once per day. Will look into it. Give me a day or so. I am planning couple of other patches as well. May be over week end. Is this urgent? Shridhar ---(end of broadcast)--- TIP 4: Don't 'kill -9' the postmaster
Re: [PERFORM] High Processor consumption
Benjamin Bostow wrote: I am running RH 7.3 running Apache 1.3.27-2 and PostgreSQL 7.2.3-5.73. When having 100+ users connected to my server I notice that postmaster consumes up wards of 90% of the processor and I hardly am higher than 10% idle. I did notice that when I kill apache and postmaster that my idle processor percentage goes to 95% or higher. I am looking on ways that I can find what connections are making the database processes run so high. If this could also tell which program is accessing it, it would be helpful. I have look through the documents on performance tuning postgresql and have adjusted my memory with little effect. I have even routed all traffic away from the Apache server so no load is on apache. I do have C programs that run and access the database. Any help will be greatly appreciated. Routinely the CPU load for postgresql translates to too much low shared buffers setting for requirement. What are your postgresql.conf tunings? Could you please post them? Shridhar ---(end of broadcast)--- TIP 6: Have you searched our list archives? http://archives.postgresql.org
