Re: [PERFORM] VACUUMs take twice as long across all nodes
On Thu, 26 Oct 2006 18:09:37 -0400 Andrew Sullivan [EMAIL PROTECTED] wrote: On Thu, Oct 26, 2006 at 09:35:56PM +0100, Gavin Hamill wrote: I'm absolutely certain. The backups run from only one slave, given that it is a full copy of node 1. Our overnight traffic has not increased any, and the nightly backups show that the overall size of the DB has not increased more than usual growth. A couple things from your posts: 1.Don't do VACUUM FULL, please. It takes longer, and blocks other things while it's going on, which might mean you're having table bloat in various slony-related tables. I know it takes longer, I know it blocks. It's never been a problem 2.Are your slony logs showing increased time too? Are your targets getting further behind? Nope, the slaves are keeping up just great - once the vacuums are finished, all machines are running at about 50%-75% of full load in duty. 3.Your backups from the slave aren't done with pg_dump, right? Em, they are indeed. I assumed that MVCC would ensure I got a consistent snapshot from the instant when pg_dump began. Am I wrong? But I suspect Slony has a role here, too. I'd look carefully at the slony tables -- especially the sl_log and pg_listen things, which both are implicated. Slony is an easy target to point the finger at, so I tried a little test. I took one of the 'light' slaves (only 10 tables..), stopped its slon daemon, removed it from the load-balancer, and restarted postgres so there were no active connections. With the removal of both replication overhead and normal queries from clients, the machine should be completely clear to run at full tilt. Then I launched a 'vacuum verbose' and I was able to see exactly the same poor speeds as before, even with vacuum_cost_delay = 0 as it was previously... 2006-10-27 08:37:12 UTC INFO: vacuuming public.Allocation 2006-10-27 08:37:21 UTC INFO: Allocation: found 56449 removable, 4989360 nonremovable row versions in 47158 pages 2006-10-27 08:37:21 UTC DETAIL: 0 dead row versions cannot be removed yet. Nonremovable row versions range from 64 to 72 bytes long. There were 1 unused item pointers. Total free space (including removable row versions) is 5960056 bytes. 13 pages are or will become empty, including 0 at the end of the table. 5258 pages containing 4282736 free bytes are potential move destinations. CPU 0.16s/0.07u sec elapsed 9.55 sec. 2006-10-27 08:44:25 UTC INFO: index allocation_pkey now contains 4989360 row versions in 102198 pages 2006-10-27 08:44:25 UTC DETAIL: 56449 index row versions were removed. 1371 index pages have been deleted, 1371 are currently reusable. CPU 1.02s/0.38u sec elapsed 423.22 sec. If I've read this correctly, then on an otherwise idle system, it has taken seven minutes to perform 1.4 seconds-worth of actual work. Surely that's nonsense? That would suggest that the issue is poor IO; vmstat 5 output during this run wasn't ripping performance - maybe averaging 3MB/sec in and out. I know the peak IO on this machine is rather much better than that: joltpg2:/root# dd if=/dev/zero of=/tmp/t bs=1024k count=1000 1000+0 records in 1000+0 records out 1048576000 bytes (1.0 GB) copied, 8.02106 seconds, 131 MB/s The test system is one CPU's-worth (two cores) of a 4 x Opteron 880 machine split up by Xen, and I can confirm the IO on the other Xen partitions was minimal. I appreciate the time, help and advice people are offering, however I really don't think Slony is the culprit here. Cheers, Gavin. ---(end of broadcast)--- TIP 1: 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
[PERFORM] query produces 1 GB temp file
Hi, here is a query which produces over 1G temp file in pgsql_tmp. This is on pgsql 7.4.2, RHEL 3.0, XEON MP machine with 32GB RAM, 300MB sort_mem and 320MB shared_mem. Below is the query and results for EXPLAIN and EXPLAIN ANALYZE. All tables have been analyzed before. Can some please explain why the temp file is so huge? I understand there are a lot of rows. All relevant indices seem to be used. Thanks in advance, Dirk EXPLAIN SELECT DISTINCT ON (ft.val_9, ft.created, ft.flatid) ft.docstart, ft.flatobj, bi.oid, bi.en FROM bi, en, df AS ft, es WHERE bi.rc=130170467 AND bi.en=ft.en AND bi.co=117305223 AND bi.hide=FALSE AND ft.en=en.oid AND es.en=bi.en AND es.co=bi.co AND es.spec=122293729 AND (ft.val_2='DG' OR ft.val_2='SK') AND ft.docstart=1 ORDER BY ft.val_9 ASC, ft.created DESC LIMIT 1000 OFFSET 0; Limit (cost=8346.75..8346.78 rows=3 width=1361) - Unique (cost=8346.75..8346.78 rows=3 width=1361) - Sort (cost=8346.75..8346.76 rows=3 width=1361) Sort Key: ft.val_9, ft.created, ft.flatid - Nested Loop (cost=0.00..8346.73 rows=3 width=1361) - Nested Loop (cost=0.00..5757.17 rows=17 width=51) - Nested Loop (cost=0.00..5606.39 rows=30 width=42) - Index Scan using es_sc_index on es (cost=0.00..847.71 rows=301 width=8) Index Cond: ((spec = 122293729) AND (co = 117305223::oid)) - Index Scan using bi_env_index on bi (cost=0.00..15.80 rows=1 width=42) Index Cond: (outer.en = bi.en) Filter: ((rc = 130170467::oid) AND (co = 117305223::oid) AND (hide = false)) - Index Scan using en_oid_index on en (cost=0.00..5.01 rows=1 width=9) Index Cond: (outer.en = en.oid) - Index Scan using df_en on df ft (cost=0.00..151.71 rows=49 width=1322) Index Cond: (outer.en = ft.en) Filter: (((val_2 = 'DG'::text) OR (val_2 = 'SK'::text)) AND (docstart = 1)) (17 rows) -- EXPLAIN ANALYZE gives: Limit (cost=8346.75..8346.78 rows=3 width=1361) (actual time=75357.465..75679.964 rows=1000 loops=1) - Unique (cost=8346.75..8346.78 rows=3 width=1361) (actual time=75357.459..75675.371 rows=1000 loops=1) - Sort (cost=8346.75..8346.76 rows=3 width=1361) (actual time=75357.448..75499.263 rows=22439 loops=1) Sort Key: ft.val_9, ft.created, ft.flatid - Nested Loop (cost=0.00..8346.73 rows=3 width=1361) (actual time=34.104..18016.005 rows=703677 loops=1) - Nested Loop (cost=0.00..5757.17 rows=17 width=51) (actual time=0.467..3216.342 rows=48563 loops=1) - Nested Loop (cost=0.00..5606.39 rows=30 width=42) (actual time=0.381..1677.014 rows=48563 loops=1) - Index Scan using es_sc_index on es (cost=0.00..847.71 rows=301 width=8) (actual time=0.184..46.519 rows=5863 loops=1) Index Cond: ((spec = 122293729) AND (co = 117305223::oid)) - Index Scan using bi_env_index on bi (cost=0.00..15.80 rows=1 width=42) (actual time=0.052..0.218 rows=8 loops=5863) Index Cond: (outer.en = bi.en) Filter: ((rc = 130170467::oid) AND (co = 117305223::oid) AND (hide = false)) - Index Scan using en_oid_index on en (cost=0.00..5.01 rows=1 width=9) (actual time=0.015..0.019 rows=1 loops=48563) Index Cond: (outer.en = en.oid) - Index Scan using df_en on df ft (cost=0.00..151.71 rows=49 width=1322) (actual time=0.038..0.148 rows=14 loops=48563) Index Cond: (outer.en = ft.en) Filter: (((val_2 = 'DG'::text) OR (val_2 = 'SK'::text)) AND (docstart = 1)) Total runtime: 81782.052 ms (18 rows) ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings
[PERFORM] client crashes in PQfinish
Hello, My Server is crashed in PQfinish. Below is the core file details: =[1] DLRemHead(0x2b7780, 0xfb6bc008, 0x319670, 0xfb6bc008, 0x21c40, 0x3106f8), at 0xfded10e4 [2] DLFreeList(0x2b7780, 0x0, 0x417b48, 0xfdec5aa4, 0x21c18, 0x0), at 0xfded0c64 [3] freePGconn(0x371ea0, 0x0, 0x289f48, 0xfbfb61b8, 0x21c18, 0x0), at 0xfdec5ac0 [4] PQfinish(0x371ea0, 0x289ce8, 0x289ce8, 0xf9a0b65c, 0x20fa0, 0xfb0718dc), at 0xfdec5cc4 [5] abc(0x289ce0, 0xfafec000, 0xfb5b1d88, 0x0, 0xf9a0ba8c, 0x7), at 0xfb071aec Server is crashed at DLRemHead. This crash is not easily reproducible. Can anybody please tell me whether above problem is related to postgres or not? Thanks, Sonal
Re: [PERFORM] Regarding Bitmap Scan
Thanks a lot for your help. Thanks, Soni On 10/17/06, Dawid Kuroczko [EMAIL PROTECTED] wrote: On 10/17/06, soni de [EMAIL PROTECTED] wrote: I didn't understand theBitmap Scan andthe sentence indexes will be dynamically converted to bitmaps in memory. What does mean by Bitmap Scan in database? Can anybody help us regarding above query? Assume you have a table:CREATE TABLE foo ( some_key int, some_time timestamp with time zone, some_data text);And two indexes:CREATE INDEX foo_key ON foo (some_key);CREATE INDEX foo_time ON foo (some_time); Now, you make a query:SELECT * from foo WHERE some_key 10 AND some_time '2006-10-01'::timestamptz;...originally planner would choose only one index to use -- and would use theone which it think its best. The 8.1 version does differently: It will scan foo_key index -- make a bitmap out of it,scan foo_time index -- make another bitmap out of it, binary AND these bitmaps,and will read the data from the table using such combined bitmap. It could as well use OR if you used OR in your query.Hence -- it can be faster, especially for large tables and selective queries.Regards, DAwid
Re: [PERFORM] query produces 1 GB temp file
On 2/5/05, Dirk Lutzebaeck [EMAIL PROTECTED] wrote: here is a query which produces over 1G temp file in pgsql_tmp. This is on pgsql 7.4.2, RHEL 3.0, XEON MP machine with 32GB RAM, 300MB sort_mem and 320MB shared_mem. Below is the query and results for EXPLAIN and EXPLAIN ANALYZE. All tables have been analyzed before. Can some please explain why the temp file is so huge? I understand there are a lot of rows. All relevant indices seem to be used. how much memory have you set aside for sorting? also, this query will likely run better in a more recent version of postgresql if thats possible. merlin ---(end of broadcast)--- TIP 3: Have you checked our extensive FAQ? http://www.postgresql.org/docs/faq
Re: [PERFORM] query produces 1 GB temp file
Merlin Moncure wrote: On 2/5/05, Dirk Lutzebaeck [EMAIL PROTECTED] wrote: snip Was the original message actually from 2/5/05? ---(end of broadcast)--- TIP 1: 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] query produces 1 GB temp file
While I can't explain why PostgreSQL would use that memory, I recommend looking into tweaking the work_mem parameter. This setting specifies how much memory PostgreSQL on certain temporary data structures (hash tables, sort vectors) until it starts using temporary files. Quoting the docs: work_mem (integer) Specifies the amount of memory to be used by internal sort operations and hash tables before switching to temporary disk files. The value is specified in kilobytes, and defaults to 1024 kilobytes (1 MB). Note that for a complex query, several sort or hash operations might be running in parallel; each one will be allowed to use as much memory as this value specifies before it starts to put data into temporary files. Also, several running sessions could be doing such operations concurrently. So the total memory used could be many times the value of work_mem; it is necessary to keep this fact in mind when choosing the value. Sort operations are used for ORDER BY, DISTINCT, and merge joins. Hash tables are used in hash joins, hash-based aggregation, and hash- based processing of IN subqueries. Alexander. On Feb 5, 2005, at 18:25 , Dirk Lutzebaeck wrote: Hi, here is a query which produces over 1G temp file in pgsql_tmp. This is on pgsql 7.4.2, RHEL 3.0, XEON MP machine with 32GB RAM, 300MB sort_mem and 320MB shared_mem. Below is the query and results for EXPLAIN and EXPLAIN ANALYZE. All tables have been analyzed before. Can some please explain why the temp file is so huge? I understand there are a lot of rows. All relevant indices seem to be used. Thanks in advance, Dirk EXPLAIN SELECT DISTINCT ON (ft.val_9, ft.created, ft.flatid) ft.docstart, ft.flatobj, bi.oid, bi.en FROM bi, en, df AS ft, es WHERE bi.rc=130170467 AND bi.en=ft.en AND bi.co=117305223 AND bi.hide=FALSE AND ft.en=en.oid AND es.en=bi.en AND es.co=bi.co AND es.spec=122293729 AND (ft.val_2='DG' OR ft.val_2='SK') AND ft.docstart=1 ORDER BY ft.val_9 ASC, ft.created DESC LIMIT 1000 OFFSET 0; Limit (cost=8346.75..8346.78 rows=3 width=1361) - Unique (cost=8346.75..8346.78 rows=3 width=1361) - Sort (cost=8346.75..8346.76 rows=3 width=1361) Sort Key: ft.val_9, ft.created, ft.flatid - Nested Loop (cost=0.00..8346.73 rows=3 width=1361) - Nested Loop (cost=0.00..5757.17 rows=17 width=51) - Nested Loop (cost=0.00..5606.39 rows=30 width=42) - Index Scan using es_sc_index on es (cost=0.00..847.71 rows=301 width=8) Index Cond: ((spec = 122293729) AND (co = 117305223::oid)) - Index Scan using bi_env_index on bi (cost=0.00..15.80 rows=1 width=42) Index Cond: (outer.en = bi.en) Filter: ((rc = 130170467::oid) AND (co = 117305223::oid) AND (hide = false)) - Index Scan using en_oid_index on en (cost=0.00..5.01 rows=1 width=9) Index Cond: (outer.en = en.oid) - Index Scan using df_en on df ft (cost=0.00..151.71 rows=49 width=1322) Index Cond: (outer.en = ft.en) Filter: (((val_2 = 'DG'::text) OR (val_2 = 'SK'::text)) AND (docstart = 1)) (17 rows) -- EXPLAIN ANALYZE gives: Limit (cost=8346.75..8346.78 rows=3 width=1361) (actual time=75357.465..75679.964 rows=1000 loops=1) - Unique (cost=8346.75..8346.78 rows=3 width=1361) (actual time=75357.459..75675.371 rows=1000 loops=1) - Sort (cost=8346.75..8346.76 rows=3 width=1361) (actual time=75357.448..75499.263 rows=22439 loops=1) Sort Key: ft.val_9, ft.created, ft.flatid - Nested Loop (cost=0.00..8346.73 rows=3 width=1361) (actual time=34.104..18016.005 rows=703677 loops=1) - Nested Loop (cost=0.00..5757.17 rows=17 width=51) (actual time=0.467..3216.342 rows=48563 loops=1) - Nested Loop (cost=0.00..5606.39 rows=30 width=42) (actual time=0.381..1677.014 rows=48563 loops=1) - Index Scan using es_sc_index on es (cost=0.00..847.71 rows=301 width=8) (actual time=0.184..46.519 rows=5863 loops=1) Index Cond: ((spec = 122293729) AND (co = 117305223::oid)) - Index Scan using bi_env_index on bi (cost=0.00..15.80 rows=1 width=42) (actual time=0.052..0.218 rows=8 loops=5863) Index Cond: (outer.en = bi.en) Filter: ((rc = 130170467::oid) AND (co = 117305223::oid) AND (hide = false)) - Index Scan using en_oid_index on en (cost=0.00..5.01 rows=1 width=9) (actual time=0.015..0.019 rows=1
Re: [PERFORM] query produces 1 GB temp file
Hi, I'm sorry but it look like my computer has resent older posts from me, sigh... Dirk Alexander Staubo wrote: While I can't explain why PostgreSQL would use that memory, I recommend looking into tweaking the work_mem parameter. This setting specifies how much memory PostgreSQL on certain temporary data structures (hash tables, sort vectors) until it starts using temporary files. Quoting the docs: work_mem (integer) Specifies the amount of memory to be used by internal sort operations and hash tables before switching to temporary disk files. The value is specified in kilobytes, and defaults to 1024 kilobytes (1 MB). Note that for a complex query, several sort or hash operations might be running in parallel; each one will be allowed to use as much memory as this value specifies before it starts to put data into temporary files. Also, several running sessions could be doing such operations concurrently. So the total memory used could be many times the value of work_mem; it is necessary to keep this fact in mind when choosing the value. Sort operations are used for ORDER BY, DISTINCT, and merge joins. Hash tables are used in hash joins, hash-based aggregation, and hash-based processing of IN subqueries. Alexander. On Feb 5, 2005, at 18:25 , Dirk Lutzebaeck wrote: Hi, here is a query which produces over 1G temp file in pgsql_tmp. This is on pgsql 7.4.2, RHEL 3.0, XEON MP machine with 32GB RAM, 300MB sort_mem and 320MB shared_mem. Below is the query and results for EXPLAIN and EXPLAIN ANALYZE. All tables have been analyzed before. Can some please explain why the temp file is so huge? I understand there are a lot of rows. All relevant indices seem to be used. Thanks in advance, Dirk EXPLAIN SELECT DISTINCT ON (ft.val_9, ft.created, ft.flatid) ft.docstart, ft.flatobj, bi.oid, bi.en FROM bi, en, df AS ft, es WHERE bi.rc=130170467 AND bi.en=ft.en AND bi.co=117305223 AND bi.hide=FALSE AND ft.en=en.oid AND es.en=bi.en AND es.co=bi.co AND es.spec=122293729 AND (ft.val_2='DG' OR ft.val_2='SK') AND ft.docstart=1 ORDER BY ft.val_9 ASC, ft.created DESC LIMIT 1000 OFFSET 0; Limit (cost=8346.75..8346.78 rows=3 width=1361) - Unique (cost=8346.75..8346.78 rows=3 width=1361) - Sort (cost=8346.75..8346.76 rows=3 width=1361) Sort Key: ft.val_9, ft.created, ft.flatid - Nested Loop (cost=0.00..8346.73 rows=3 width=1361) - Nested Loop (cost=0.00..5757.17 rows=17 width=51) - Nested Loop (cost=0.00..5606.39 rows=30 width=42) - Index Scan using es_sc_index on es (cost=0.00..847.71 rows=301 width=8) Index Cond: ((spec = 122293729) AND (co = 117305223::oid)) - Index Scan using bi_env_index on bi (cost=0.00..15.80 rows=1 width=42) Index Cond: ("outer".en = bi.en) Filter: ((rc = 130170467::oid) AND (co = 117305223::oid) AND (hide = false)) - Index Scan using en_oid_index on en (cost=0.00..5.01 rows=1 width=9) Index Cond: ("outer".en = en.oid) - Index Scan using df_en on df ft (cost=0.00..151.71 rows=49 width=1322) Index Cond: ("outer".en = ft.en) Filter: (((val_2 = 'DG'::text) OR (val_2 = 'SK'::text)) AND (docstart = 1)) (17 rows) -- EXPLAIN ANALYZE gives: Limit (cost=8346.75..8346.78 rows=3 width=1361) (actual time=75357.465..75679.964 rows=1000 loops=1) - Unique (cost=8346.75..8346.78 rows=3 width=1361) (actual time=75357.459..75675.371 rows=1000 loops=1) - Sort (cost=8346.75..8346.76 rows=3 width=1361) (actual time=75357.448..75499.263 rows=22439 loops=1) Sort Key: ft.val_9, ft.created, ft.flatid - Nested Loop (cost=0.00..8346.73 rows=3 width=1361) (actual time=34.104..18016.005 rows=703677 loops=1) - Nested Loop (cost=0.00..5757.17 rows=17 width=51) (actual time=0.467..3216.342 rows=48563 loops=1) - Nested Loop (cost=0.00..5606.39 rows=30 width=42) (actual time=0.381..1677.014 rows=48563 loops=1) - Index Scan using es_sc_index on es (cost=0.00..847.71 rows=301 width=8) (actual time=0.184..46.519 rows=5863 loops=1) Index Cond: ((spec = 122293729) AND (co = 117305223::oid)) - Index Scan using bi_env_index on bi (cost=0.00..15.80 rows=1 width=42) (actual time=0.052..0.218 rows=8 loops=5863) Index Cond: ("outer".en = bi.en) Filter: ((rc = 130170467::oid) AND (co = 117305223::oid) AND (hide = false)) - Index Scan using en_oid_index on en (cost=0.00..5.01 rows=1 width=9) (actual time=0.015..0.019 rows=1 loops=48563) Index Cond: ("outer".en = en.oid) - Index Scan using df_en on df ft (cost=0.00..151.71 rows=49 width=1322) (actual time=0.038..0.148 rows=14 loops=48563) Index Cond: ("outer".en = ft.en) Filter: (((val_2 = 'DG'::text) OR (val_2 = 'SK'::text)) AND (docstart = 1)) Total
Re: [PERFORM] query produces 1 GB temp file
He is probably using IPOT (IP Other Time) : http://kadreg.free.fr/ipot/ :-) (sorry only french page ) On Oct 27, 2006, at 16:33, Bricklen Anderson wrote:Merlin Moncure wrote: On 2/5/05, Dirk Lutzebaeck [EMAIL PROTECTED] wrote: snipWas the original message actually from 2/5/05?---(end of broadcast)---TIP 1: 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] query produces 1 GB temp file
On Sat, 2005-02-05 at 11:25, Dirk Lutzebaeck wrote: Hi, here is a query which produces over 1G temp file in pgsql_tmp. This is on pgsql 7.4.2, RHEL 3.0, XEON MP machine with 32GB RAM, 300MB sort_mem and 320MB shared_mem. First step, upgrade to the latest 7.4.x version. 7.4.2 is an OLD version of 7.4 I think the latest version is 7.4.13. Below is the query and results for EXPLAIN and EXPLAIN ANALYZE. All tables have been analyzed before. SNIP EXPLAIN ANALYZE gives: Limit (cost=8346.75..8346.78 rows=3 width=1361) (actual time=75357.465..75679.964 rows=1000 loops=1) - Unique (cost=8346.75..8346.78 rows=3 width=1361) (actual time=75357.459..75675.371 rows=1000 loops=1) - Sort (cost=8346.75..8346.76 rows=3 width=1361) (actual time=75357.448..75499.263 rows=22439 loops=1) Sort Key: ft.val_9, ft.created, ft.flatid - Nested Loop (cost=0.00..8346.73 rows=3 width=1361) (actual time=34.104..18016.005 rows=703677 loops=1) - Nested Loop (cost=0.00..5757.17 rows=17 width=51) (actual time=0.467..3216.342 rows=48563 loops=1) - Nested Loop (cost=0.00..5606.39 rows=30 width=42) (actual time=0.381..1677.014 rows=48563 loops=1) - Index Scan using es_sc_index on es (cost=0.00..847.71 rows=301 width=8) (actual time=0.184..46.519 rows=5863 loops=1) Index Cond: ((spec = 122293729) AND (co = 117305223::oid)) - Index Scan using bi_env_index on bi (cost=0.00..15.80 rows=1 width=42) (actual time=0.052..0.218 rows=8 loops=5863) Index Cond: (outer.en = bi.en) Filter: ((rc = 130170467::oid) AND (co = 117305223::oid) AND (hide = false)) - Index Scan using en_oid_index on en (cost=0.00..5.01 rows=1 width=9) (actual time=0.015..0.019 rows=1 loops=48563) Index Cond: (outer.en = en.oid) - Index Scan using df_en on df ft (cost=0.00..151.71 rows=49 width=1322) (actual time=0.038..0.148 rows=14 loops=48563) Index Cond: (outer.en = ft.en) Filter: (((val_2 = 'DG'::text) OR (val_2 = 'SK'::text)) AND (docstart = 1)) Total runtime: 81782.052 ms (18 rows) Why do you have an index scan on en_oid_index that thinks it will return 1 row when it returns 48563, and one on df_en that thinks it will return 49 and returns 48563 as well? Is this database analyzed often? Are oids even analyzed? I'd really recommend switching off of them as they complicate backups and restores. If analyze doesn't help, you can try brute forcing off nested loops for this query and see if that helps. nested loop is really slow for large numbers of rows. ---(end of broadcast)--- TIP 6: explain analyze is your friend
Re: [PERFORM] VACUUMs take twice as long across all nodes
Gavin Hamill [EMAIL PROTECTED] writes: 2006-10-27 08:37:12 UTC INFO: vacuuming public.Allocation 2006-10-27 08:37:21 UTC INFO: Allocation: found 56449 removable, 4989360 nonremovable row versions in 47158 pages 2006-10-27 08:37:21 UTC DETAIL: 0 dead row versions cannot be removed yet. Nonremovable row versions range from 64 to 72 bytes long. There were 1 unused item pointers. Total free space (including removable row versions) is 5960056 bytes. 13 pages are or will become empty, including 0 at the end of the table. 5258 pages containing 4282736 free bytes are potential move destinations. CPU 0.16s/0.07u sec elapsed 9.55 sec. 2006-10-27 08:44:25 UTC INFO: index allocation_pkey now contains 4989360 row versions in 102198 pages 2006-10-27 08:44:25 UTC DETAIL: 56449 index row versions were removed. 1371 index pages have been deleted, 1371 are currently reusable. CPU 1.02s/0.38u sec elapsed 423.22 sec. So the time is all in index vacuuming, eh? I think what's happening is that the physical order of the index is degrading over time, and so the vacuum scan takes longer due to more seeking. Can you afford to do a REINDEX? If this theory is correct that should drive the time back down. 8.2 has rewritten btree index vacuuming code that scans the index in physical not logical order, so this problem should largely go away in 8.2, but in existing releases I can't see much you can do about it except REINDEX when things get slow. regards, tom lane ---(end of broadcast)--- TIP 6: explain analyze is your friend
Re: [PERFORM] Best COPY Performance
I do have a dirty little secret, one which I wasn't completely aware of until a little while ago. Apparently, someone decided to install Oracle on the server, and use the SAN as the primary tablespace, so that might have something to do with the poor performance of the SAN. At least, I'm hoping that's what is involved. I'll be able to tell for sure when I can rerun the benchmarks on Monday without Oracle. Thank you all for all your help so far. I've learned a ton about Postgres (and life!) from both this thread and this list in general, and the support has been nothing less than spectacular. I'm hoping that the corporate Oracle machine won't shut down my pg projects. On total side note, if anyone knows how to best limit Oracle's impact on a system (i.e. memory usage, etc), I'd be interested. I hate shared DB servers. Thanks! ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings
Re: [PERFORM] Best COPY Performance
On 10/27/06, Worky Workerson [EMAIL PROTECTED] wrote: I'm hoping that the corporate Oracle machine won't shut down my pg projects. On total side note, if anyone knows how to best limit Oracle's impact on a system (i.e. memory usage, etc), I'd be interested. rm -rf /usr/local/oracle? merlin ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
Re: [PERFORM] Best COPY Performance
The read speed on your /data volume is awful to the point where you should consider it broken and find a fix. A quick comparison: the same number on a 16 drive internal SATA array with 7200 RPM disks gets 950 MB/s read, about 25 times faster for about 1/4 the price. I'm hoping that the poor performance is a result of Oracle doing random reads while I try and do the sequential read. If not (I'll test on Monday), I'll start looking other places. Any immediate suggestions? Can you provide about 10 seconds worth of vmstat 1 while running your COPY so we can get a global view of the I/O and CPU? Here it is, taken from a spot about halfway through a 'cat file | psql' load, with the Oracle-is-installed-and-running caveat: r b swpd free buffcache si so bibo in cs us sy id wa 1 0 345732 29328 770980 12947212 0 0 20 16552 1223 3677 12 2 85 1 1 0 345732 29840 770520 12946924 0 0 20 29244 1283 2955 11 2 85 1 1 0 345732 32144 770560 12944436 0 0 12 16436 1204 2936 11 2 86 1 1 0 345732 33744 770464 12942764 0 0 20 16460 1189 2005 10 2 86 1 2 0 345732 32656 770140 12943972 0 0 16 7068 1057 3434 13 2 85 0 1 0 345732 34832 770184 12941820 0 0 20 9368 1170 3120 11 2 86 1 1 0 345732 36528 770228 12939804 0 0 16 32668 1297 2109 11 2 85 1 1 0 345732 29304 770272 12946764 0 0 16 16428 1192 3105 12 2 85 1 1 0 345732 30840 770060 12945480 0 0 20 16456 1196 3151 12 2 84 1 1 0 345732 32760 769972 12943528 0 0 12 16460 1185 3103 11 2 86 1 ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings
Re: [PERFORM] VACUUMs take twice as long across all nodes
On Fri, 27 Oct 2006 14:07:43 -0400 Tom Lane [EMAIL PROTECTED] wrote: So the time is all in index vacuuming, eh? I think what's happening is that the physical order of the index is degrading over time, and so the vacuum scan takes longer due to more seeking. Can you afford to do a REINDEX? If this theory is correct that should drive the time back down. Tom, You wonderful, wonderful man. I tried a test reindex on Allocation, and noticed a vacuum had turbo-charged... then reindexed the whole db, did a vacuum, and lo! The whole db had turbo-charged :) When I say 'turbo-charged', I mean it. The vacuum times have dropped to 20% of what we were seeing even before it 'got much slower a couple of days ago.' It sucks that the new reindex code is only in 8.2, but now that I know this is an issue in 8.1 I can plan for it. Thanks so much :) Cheers, Gavin. ---(end of broadcast)--- TIP 1: 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] Best COPY Performance
Worky (that your real name? :-) On 10/27/06 12:08 PM, Worky Workerson [EMAIL PROTECTED] wrote: Here it is, taken from a spot about halfway through a 'cat file | psql' load, with the Oracle-is-installed-and-running caveat: r b swpd free buffcache si so bibo in cs us sy id wa 1 0 345732 29328 770980 12947212 0 0 20 16552 1223 3677 12 2 85 1 1 0 345732 29840 770520 12946924 0 0 20 29244 1283 2955 11 2 85 1 1 0 345732 32144 770560 12944436 0 0 12 16436 1204 2936 11 2 86 1 1 0 345732 33744 770464 12942764 0 0 20 16460 1189 2005 10 2 86 1 2 0 345732 32656 770140 12943972 0 0 16 7068 1057 3434 13 2 85 0 1 0 345732 34832 770184 12941820 0 0 20 9368 1170 3120 11 2 86 1 1 0 345732 36528 770228 12939804 0 0 16 32668 1297 2109 11 2 85 1 1 0 345732 29304 770272 12946764 0 0 16 16428 1192 3105 12 2 85 1 1 0 345732 30840 770060 12945480 0 0 20 16456 1196 3151 12 2 84 1 1 0 345732 32760 769972 12943528 0 0 12 16460 1185 3103 11 2 86 1 It doesn't look like there's anything else running - the runnable r is about 1. Your bo blocks output rate is about 16MB/s, so divide by 3 and you're about in range with your 5MB/s COPY rate. The interesting thing is that the I/O wait is pretty low. How many CPUs on the machine? Can you send the result of cat /proc/cpuinfo? Is your cat file | psql being done on the DBMS server or is it on the network? - Luke ---(end of broadcast)--- TIP 1: 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] Best COPY Performance
On 10/28/06, Luke Lonergan [EMAIL PROTECTED] wrote: Worky (that your real name? :-) On 10/27/06 12:08 PM, Worky Workerson [EMAIL PROTECTED] wrote: Here it is, taken from a spot about halfway through a 'cat file | psql' load, with the Oracle-is-installed-and-running caveat: r b swpd free buffcache si so bibo in cs us sy id wa 1 0 345732 29328 770980 12947212 0 0 20 16552 1223 3677 12 2 85 1 1 0 345732 29840 770520 12946924 0 0 20 29244 1283 2955 11 2 85 1 1 0 345732 32144 770560 12944436 0 0 12 16436 1204 2936 11 2 86 1 1 0 345732 33744 770464 12942764 0 0 20 16460 1189 2005 10 2 86 1 2 0 345732 32656 770140 12943972 0 0 16 7068 1057 3434 13 2 85 0 1 0 345732 34832 770184 12941820 0 0 20 9368 1170 3120 11 2 86 1 1 0 345732 36528 770228 12939804 0 0 16 32668 1297 2109 11 2 85 1 1 0 345732 29304 770272 12946764 0 0 16 16428 1192 3105 12 2 85 1 1 0 345732 30840 770060 12945480 0 0 20 16456 1196 3151 12 2 84 1 1 0 345732 32760 769972 12943528 0 0 12 16460 1185 3103 11 2 86 1 It doesn't look like there's anything else running - the runnable r is about 1. Your bo blocks output rate is about 16MB/s, so divide by 3 and you're about in range with your 5MB/s COPY rate. The interesting thing is that the I/O wait is pretty low. How many CPUs on the machine? Can you send the result of cat /proc/cpuinfo? Is your cat file | psql being done on the DBMS server or is it on the network? iirc, he is running quad opteron 885 (8 cores), so if my math is correct he can split up his process for an easy gain. merlin ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
Re: [PERFORM] Best COPY Performance
Worky (that your real name? :-) Nope, its Mike. worky.workerson is just the email that I use for work :) How many CPUs on the machine? Can you send the result of cat /proc/cpuinfo? Not at work at the moment, however I do have quad dual-core opterons, like Merlin mentioned. Is your cat file | psql being done on the DBMS server or is it on the network? Everything is currently being done on the same DB server. The data that is being loaded is on the same 2-disk RAID10 as the OS and WAL. ---(end of broadcast)--- TIP 9: In versions below 8.0, the planner will ignore your desire to choose an index scan if your joining column's datatypes do not match
Re: [PERFORM] Best COPY Performance
On 10/27/06, Merlin Moncure [EMAIL PROTECTED] wrote: r b swpd free buffcache si so bibo in cs us sy id wa 1 0 345732 29328 770980 12947212 0 0 20 16552 1223 3677 12 2 85 1 1 0 345732 29840 770520 12946924 0 0 20 29244 1283 2955 11 2 85 1 1 0 345732 32144 770560 12944436 0 0 12 16436 1204 2936 11 2 86 1 1 0 345732 33744 770464 12942764 0 0 20 16460 1189 2005 10 2 86 1 2 0 345732 32656 770140 12943972 0 0 16 7068 1057 3434 13 2 85 0 1 0 345732 34832 770184 12941820 0 0 20 9368 1170 3120 11 2 86 1 1 0 345732 36528 770228 12939804 0 0 16 32668 1297 2109 11 2 85 1 1 0 345732 29304 770272 12946764 0 0 16 16428 1192 3105 12 2 85 1 1 0 345732 30840 770060 12945480 0 0 20 16456 1196 3151 12 2 84 1 1 0 345732 32760 769972 12943528 0 0 12 16460 1185 3103 11 2 86 1 It doesn't look like there's anything else running - the runnable r is about 1. Your bo blocks output rate is about 16MB/s, so divide by 3 and you're about in range with your 5MB/s COPY rate. The interesting thing is that the I/O wait is pretty low. How many CPUs on the machine? Can you send the result of cat /proc/cpuinfo? iirc, he is running quad opteron 885 (8 cores), so if my math is correct he can split up his process for an easy gain. Are you saying that I should be able to issue multiple COPY commands because my I/O wait is low? I was under the impression that I am I/O bound, so multiple simeoultaneous loads would have a detrimental effect ... ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
Re: [PERFORM] Best COPY Performance
Worky, On 10/27/06 8:47 PM, Worky Workerson [EMAIL PROTECTED] wrote: 1 0 345732 29304 770272 12946764 0 0 16 16428 1192 3105 12 2 85 1 1 0 345732 30840 770060 12945480 0 0 20 16456 1196 3151 12 2 84 1 1 0 345732 32760 769972 12943528 0 0 12 16460 1185 3103 11 2 86 1 iirc, he is running quad opteron 885 (8 cores), so if my math is correct he can split up his process for an easy gain. Are you saying that I should be able to issue multiple COPY commands because my I/O wait is low? I was under the impression that I am I/O bound, so multiple simeoultaneous loads would have a detrimental effect ... The reason I asked how many CPUs was to make sense of the 12% usr CPU time in the above. That means you are CPU bound and are fully using one CPU. So you aren't being limited by the I/O in this case, it's the CPU. I agree with Merlin that you can speed things up by breaking the file up. Alternately you can use the OSS Bizgres java loader, which lets you specify the number of I/O threads with the -n option on a single file. OTOH, you should find that you will only double your COPY speed with this approach because your write speed as you previously found was limited to 30 MB/s. For now, you could simply split the file in two pieces and load two copies at once, then watch the same vmstat 1 for 10 seconds and look at your bo rate. If this does speed things up, you really should check out the Bizgres Java loader. The other thing to wonder about though is why you are so CPU bound at 5 MB/s. What version of Postgres is this? - Luke ---(end of broadcast)--- TIP 3: Have you checked our extensive FAQ? http://www.postgresql.org/docs/faq