Re: [PERFORM] User concurrency thresholding: where do I look?
Jignesh K. Shah wrote: > Top Wait time seems to come from the following code path for > ProcArrayLock: > > Lock IdMode Count > ProcArrayLock Exclusive 21 > > Lock Id Combined Time (ns) > ProcArrayLock 5255937500 > > Lock Id Combined Time (ns) > > > postgres`LWLockAcquire+0x1f0 > postgres`CommitTransaction+0x104 Yeah, ProcArrayLock is pretty contended. I think it would be kinda neat if we could split it up in partitions. This lock is quite particular though. -- Alvaro Herrerahttp://www.CommandPrompt.com/ PostgreSQL Replication, Consulting, Custom Development, 24x7 support ---(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] User concurrency thresholding: where do I look?
Yes I can try to breakup the Shared and exclusive time.. Also yes I use commit delays =10, it helps out a lot in reducing IO load.. I will try out the patch soon. -Jignesh Simon Riggs wrote: On Thu, 2007-07-26 at 17:17 -0400, Jignesh K. Shah wrote: Lock Id Combined Time (ns) XidGenLock194966200 WALInsertLock517955000 CLogControlLock679665100 WALWriteLock 2838716200 ProcArrayLock 44181002600 Is this the time the lock is held for or the time that we wait for that lock? It would be good to see the break down of time separately for shared and exclusive. Can we have a table like this: LockId,LockMode,SumTimeLockHeld,SumTimeLockWait Top Wait time seems to come from the following code path for ProcArrayLock: Lock IdMode Count ProcArrayLock Exclusive 21 Lock Id Combined Time (ns) ProcArrayLock 5255937500 Lock Id Combined Time (ns) postgres`LWLockAcquire+0x1f0 postgres`CommitTransaction+0x104 postgres`CommitTransactionCommand+0xbc postgres`finish_xact_command+0x78 Well thats pretty weird. That code path clearly only happens once per transaction and ought to be fast. The other code paths that take ProcArrayLock like TransactionIdIsInProgress() and GetSnapshotData() ought to spend more time holding the lock. Presumably you are running with a fair number of SERIALIZABLE transactions? Are you running with commit_delay > 0? Its possible that the call to CountActiveBackends() is causing pinging of the procarray by other backends while we're trying to read it during CommitTransaction(). If so, try the attached patch. ---(end of broadcast)--- TIP 7: You can help support the PostgreSQL project by donating at http://www.postgresql.org/about/donate
Re: [PERFORM] disk filling up
On 7/26/07, Joshua D. Drake <[EMAIL PROTECTED]> wrote: > Brandon Shalton wrote: > > Hello all, > > > > My hard disk is filling up in the /base directory to where it has > > consumed all 200gig of that drive. > > > > All the posts that i see keep saying move to a bigger drive, but at some > > point a bigger drive would just get consumed. > > > > How can i keep the disk from filling up other than get like a half TB > > setup just to hold the ./base/* folder > > 1. Don't have two hundred gig of data. > 2. Sounds more like you don't have 200G of data and you aren't vacuuming > enough. third (but unlikely) possibility is there are various dropped tables, etc which need to be deleted but there are stale postgresql processes holding on to the fd. This would only happen following a postmaster crash or some other bizarre scenario, but i've seen it on production box. symptoms are du and df reporting different numbers. solutions is easy: reboot or stop postmaster and kill all postgresql processes (or, if you are brave, do it with dbms running and nail all processes not following postmaster, do a ps axf [on linux] to see them). merlin ---(end of broadcast)--- TIP 7: You can help support the PostgreSQL project by donating at http://www.postgresql.org/about/donate
Re: [PERFORM] User concurrency thresholding: where do I look?
On Thu, 2007-07-26 at 17:17 -0400, Jignesh K. Shah wrote: > Lock Id Combined Time (ns) > XidGenLock194966200 >WALInsertLock517955000 > CLogControlLock679665100 > WALWriteLock 2838716200 >ProcArrayLock 44181002600 Is this the time the lock is held for or the time that we wait for that lock? It would be good to see the break down of time separately for shared and exclusive. Can we have a table like this: LockId,LockMode,SumTimeLockHeld,SumTimeLockWait > Top Wait time seems to come from the following code path for > ProcArrayLock: > > Lock IdMode Count >ProcArrayLock Exclusive 21 > > Lock Id Combined Time (ns) >ProcArrayLock 5255937500 > > Lock Id Combined Time (ns) > > > postgres`LWLockAcquire+0x1f0 > postgres`CommitTransaction+0x104 > postgres`CommitTransactionCommand+0xbc > postgres`finish_xact_command+0x78 Well thats pretty weird. That code path clearly only happens once per transaction and ought to be fast. The other code paths that take ProcArrayLock like TransactionIdIsInProgress() and GetSnapshotData() ought to spend more time holding the lock. Presumably you are running with a fair number of SERIALIZABLE transactions? Are you running with commit_delay > 0? Its possible that the call to CountActiveBackends() is causing pinging of the procarray by other backends while we're trying to read it during CommitTransaction(). If so, try the attached patch. -- Simon Riggs EnterpriseDB http://www.enterprisedb.com Index: src/backend/access/transam/xact.c === RCS file: /projects/cvsroot/pgsql/src/backend/access/transam/xact.c,v retrieving revision 1.245 diff -c -r1.245 xact.c *** src/backend/access/transam/xact.c 7 Jun 2007 21:45:58 - 1.245 --- src/backend/access/transam/xact.c 27 Jul 2007 09:09:08 - *** *** 820,827 * are fewer than CommitSiblings other backends with active * transactions. */ ! if (CommitDelay > 0 && enableFsync && ! CountActiveBackends() >= CommitSiblings) pg_usleep(CommitDelay); XLogFlush(recptr); --- 820,826 * are fewer than CommitSiblings other backends with active * transactions. */ ! if (CommitDelay > 0 && enableFsync) pg_usleep(CommitDelay); XLogFlush(recptr); ---(end of broadcast)--- TIP 2: Don't 'kill -9' the postmaster
Re: [PERFORM] User concurrency thresholding: where do I look?
On Fri, 2007-07-27 at 04:58 -0400, Alvaro Herrera wrote: > Jignesh K. Shah wrote: > > > Top Wait time seems to come from the following code path for > > ProcArrayLock: > > > > Lock IdMode Count > > ProcArrayLock Exclusive 21 > > > > Lock Id Combined Time (ns) > > ProcArrayLock 5255937500 > > > > Lock Id Combined Time (ns) > > > > > > postgres`LWLockAcquire+0x1f0 > > postgres`CommitTransaction+0x104 > > Yeah, ProcArrayLock is pretty contended. I think it would be kinda neat > if we could split it up in partitions. This lock is quite particular > though. Maybe, if we did we should set the partitions according to numbers of users, so lower numbers of users are all in one partition. -- Simon Riggs EnterpriseDB http://www.enterprisedb.com ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
[PERFORM] Slow query with backwards index scan
Dear list, I am having problems selecting the 10 most recent rows from a large table (4.5M rows), sorted by a date column of that table. The large table has a column user_id which either should match a given user_id, or should match the column contact_id in a correlated table where the user_id of that correlated table must match the given user_id. The user_id values in the large table are distributed in such a way that in the majority of cases for a given user_id 10 matching rows can be found very early when looking at the table sorted by the date - propably within the first 1%. Sometimes the given user_id however would match any rows only very far towards the end of the sorted large table, or not at all. The query works fine for the common cases when matching rows are found early in the sorted large table, like this: testdb=# EXPLAIN ANALYZE SELECT * FROM large_table lt LEFT JOIN relationships r ON lt.user_id=r.contact_id WHERE r.user_id = 5 OR lt.user_id = 5 ORDER BY lt.created_at DESC LIMIT 10; QUERY PLAN -- Limit (cost=0.00..33809.31 rows=10 width=646) (actual time=0.088..69.448 rows=10 loops=1) -> Nested Loop Left Join (cost=0.00..156983372.66 rows=46432 width=646) (actual time=0.082..69.393 rows=10 loops=1) Filter: ((r.user_id = 5) OR (lt.user_id = 5)) -> Index Scan Backward using large_created_at_index on large_table lt (cost=0.00..914814.94 rows=4382838 width=622) (actual time=0.028..0.067 rows=13 loops=1) -> Index Scan using relationships_contact_id_index on relationships r (cost=0.00..35.33 rows=16 width=24) (actual time=0.017..2.722 rows=775 loops=13) Index Cond: (lt.user_id = r.contact_id) Total runtime: 69.640 ms but for the following user_id there are 3M rows in the large table which are more recent then the 10th matching one. The query then does not perform so well: testdb=# EXPLAIN ANALYZE SELECT * FROM large_table lt LEFT JOIN relationships r ON lt.user_id=r.contact_id WHERE r.user_id = 12345 OR lt.user_id = 12345 ORDER BY lt.created_at DESC LIMIT 10; QUERY PLAN --- Limit (cost=0.00..33809.31 rows=10 width=646) (actual time=203454.353..425978.718 rows=10 loops=1) -> Nested Loop Left Join (cost=0.00..156983372.66 rows=46432 width=646) (actual time=203454.347..425978.662 rows=10 loops=1) Filter: ((r.user_id = 12345) OR (lt.user_id = 12345)) -> Index Scan Backward using large_created_at_index on large_table lt (cost=0.00..914814.94 rows=4382838 width=622) (actual time=0.031..78386.769 rows=3017547 loops=1) -> Index Scan using relationships_contact_id_index on relationships r (cost=0.00..35.33 rows=16 width=24) (actual time=0.006..0.060 rows=18 loops=3017547) Index Cond: (lt.user_id = r.contact_id) Total runtime: 425978.903 ms When split it up into the two following queries it performs much better for that user_id. Since the results of the two could be combined into the desired result, I'm assuming it could also be done efficiently within one query, if only a better plan would be used. testdb=# EXPLAIN ANALYZE SELECT * FROM large_table lt WHERE lt.user_id = 12345 ORDER BY lt.created_at DESC LIMIT 10; QUERY PLAN - Limit (cost=0.00..33.57 rows=10 width=622) (actual time=64.030..71.720 rows=10 loops=1) -> Index Scan Backward using large_user_id_created_at_index on large_table lt (cost=0.00..7243.59 rows=2158 width=622) (actual time=64.023..71.662 rows=10 loops=1) Index Cond: (user_id = 12345) Total runtime: 71.826 ms testdb=# EXPLAIN ANALYZE SELECT * FROM large_table lt WHERE user_id IN (SELECT contact_id FROM relationships WHERE user_id=12345) ORDER BY created_at DESC LIMIT 10; QUERY PLAN --
Re: [PERFORM] Slow query with backwards index scan
Tilmann Singer skrev: > The query works fine for the common cases when matching rows are found > early in the sorted large table, like this: > > testdb=# EXPLAIN ANALYZE > SELECT * FROM large_table lt > LEFT JOIN relationships r ON lt.user_id=r.contact_id > WHERE r.user_id = 5 OR lt.user_id = 5 > ORDER BY lt.created_at DESC LIMIT 10; > > QUERY PLAN > but for the following user_id there are 3M rows in the large table > which are more recent then the 10th matching one. The query then does > not perform so well: > > > testdb=# EXPLAIN ANALYZE > SELECT * FROM large_table lt > LEFT JOIN relationships r ON lt.user_id=r.contact_id > WHERE r.user_id = 12345 OR lt.user_id = 12345 > ORDER BY lt.created_at DESC LIMIT 10; > > QUERY PLAN > When split it up into the two following queries it performs much > better for that user_id. Since the results of the two could be > combined into the desired result, I'm assuming it could also be done > efficiently within one query, if only a better plan would be used. > > > testdb=# EXPLAIN ANALYZE > SELECT * FROM large_table lt > WHERE lt.user_id = 12345 > ORDER BY lt.created_at DESC LIMIT 10; > > QUERY PLAN > testdb=# EXPLAIN ANALYZE > SELECT * FROM large_table lt > WHERE user_id IN (SELECT contact_id FROM relationships WHERE user_id=12345) > ORDER BY created_at DESC LIMIT 10; > > QUERY PLAN > I'm not very experienced reading query plans and don't know how to go > about this from here - is it theoretically possible to have a query > that performs well with the given data in both cases or is there a > conceptual problem? How does the "obvious" UNION query do - ie: SELECT * FROM ( SELECT * FROM large_table lt WHERE lt.user_id = 12345 UNION SELECT * FROM large_table lt WHERE user_id IN (SELECT contact_id FROM relationships WHERE user_id=12345) ) q ORDER BY created_at DESC LIMIT 10; ? How about SELECT * FROM large_table lt WHERE lt.user_id = 12345 OR user_id IN (SELECT contact_id FROM relationships WHERE user_id=12345) ORDER BY created_at DESC LIMIT 10; ? I am missing a unique constraint on (user_id, contact_id) - otherwise the subselect is not equivalent to the join. Probably you also should have foreign key constraints on relationships.user_id and relationships.contact_id. These are unlikely to affect performance though, in my experience. It might be good to know whether contact_id = user_id is possible - since this would rule out the possibility of a row satisfying both branches of the union. Nis ---(end of broadcast)--- TIP 3: Have you checked our extensive FAQ? http://www.postgresql.org/docs/faq
Re: [PERFORM] How to use a trigger to write rows to a remote server
On 7/18/07, Michael Dengler <[EMAIL PROTECTED]> wrote: > Hmm..I was hoping to avoid personal insults > > Anyway, Nuts or not...what I am attempting is to simply have row from one > table inserted into another servers DB I don't see it as replication > because: I think you took Tom's comments the wrong way. He is suggesting you are nuts to attempt trigger based data transfer to remote server when there are two clearly better options, slony and dblink. You took as a personal insult which was just some frank (and frankly good) advice... Slony is in fact the _solution_ to the problem of transferring data between servers with triggers. If your tables are well designed and you are reasonably proficient with stored procedures, and you requirements of transfer are very specific and not extremely time sensitive, a poll based system over dblink is also a good solution. > a) The destination table will have a trigger that modifies the arriving data > to fit its table scheme. > b) It is not critical that the data be synchronous (ie a lost row on the > destination DB is not a big deal) > c) I see as more of a provision of data to the destination DB NOT A > REPLICATION OF DATA. based on this you may want to rig dblink/poll. 3rd option is pitr shipping to warm standby, depending on your requirements. > Essentially the remote server just wants to know when some record arrives at > the source server and wants to know some of the info contained in the new > record. > > And yes it may be that I know little about the myriad of problems involved > with replication...but I do know how to carry on a civil, adult > conversationmaybe we can have a knowledge exchange. now that's a bit dramatic :-) merlin ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
Re: [PERFORM] User concurrency thresholding: where do I look?
I tried CLOG Buffers 32 and the performance is as good as 64 bit.. (I havent tried 16 yet though.. ) I am going to try your second patch now.. Also here is the breakup by Mode. The combined time is the total time it waits for all counts. Lock IdMode Count ProcArrayLock Shared 1 CLogControlLock Exclusive 4 CLogControlLock Shared 4 XidGenLock Shared 4 XidGenLock Exclusive 7 WALInsertLock Exclusive 21 WALWriteLock Exclusive 62 ProcArrayLock Exclusive 79 Lock IdModeCombined Time (ns) CLogControlLockExclusive 325200 CLogControlLock Shared 4509200 XidGenLockExclusive 11839600 ProcArrayLock Shared 40506600 XidGenLock Shared119013700 WALInsertLockExclusive148063100 WALWriteLockExclusive347052100 ProcArrayLockExclusive 1054780600 Here is another one at higher user count 1600: bash-3.00# ./4_lwlock_waits.d 9208 Lock IdMode Count CLogControlLock Exclusive 1 CLogControlLock Shared 2 XidGenLock Shared 7 WALInsertLock Exclusive 12 WALWriteLock Exclusive 50 ProcArrayLock Exclusive 82 Lock IdMode Combined Time (ns) CLogControlLockExclusive27300 XidGenLock Shared 14689300 CLogControlLock Shared 72664900 WALInsertLockExclusive101431300 WALWriteLockExclusive534357400 ProcArrayLockExclusive 4110350300 Now I will try with your second patch. Regards, Jignesh Simon Riggs wrote: On Thu, 2007-07-26 at 17:17 -0400, Jignesh K. Shah wrote: Lock Id Combined Time (ns) XidGenLock194966200 WALInsertLock517955000 CLogControlLock679665100 WALWriteLock 2838716200 ProcArrayLock 44181002600 Is this the time the lock is held for or the time that we wait for that lock? It would be good to see the break down of time separately for shared and exclusive. Can we have a table like this: LockId,LockMode,SumTimeLockHeld,SumTimeLockWait Top Wait time seems to come from the following code path for ProcArrayLock: Lock IdMode Count ProcArrayLock Exclusive 21 Lock Id Combined Time (ns) ProcArrayLock 5255937500 Lock Id Combined Time (ns) postgres`LWLockAcquire+0x1f0 postgres`CommitTransaction+0x104 postgres`CommitTransactionCommand+0xbc postgres`finish_xact_command+0x78 Well thats pretty weird. That code path clearly only happens once per transaction and ought to be fast. The other code paths that take ProcArrayLock like TransactionIdIsInProgress() and GetSnapshotData() ought to spend more time holding the lock. Presumably you are running with a fair number of SERIALIZABLE transactions? Are you running with commit_delay > 0? Its possible that the call to CountActiveBackends() is causing pinging of the procarray by other backends while we're trying to read it during CommitTransaction(). If so, try the attached patch. Index: src/backend/access/transam/xact.c === RCS file: /projects/cvsroot/pgsql/src/backend/access/transam/xact.c,v retrieving revision 1.245 diff -c -r1.245 xact.c *** src/backend/access/transam/xact.c 7 Jun 2007 21:45:58 - 1.245 --- src/backend/access/transam/xact.c 27 Jul 2007 09:09:08 - *** *** 820,827 * are fewer than CommitSiblings other backends with active * transactions. */ ! if (CommitDelay > 0 && enableFsync && ! CountActiveBackends() >= CommitSiblings) pg_usleep(CommitDelay); XLogFlush(recptr); --- 820,826 * are fewer than CommitSiblings other backends with active * transactions. */ ! if (CommitDelay > 0 && enableFsync) pg_usleep(CommitDelay); XLogFlush(recptr);
Re: [PERFORM] User concurrency thresholding: where do I look?
Using CLOG Buffers 32 and the commit sibling check patch I still see a drop at 1200-1300 users.. bash-3.00# ./4_lwlock_waits.d 18250 Lock IdMode Count XidGenLock Shared 1 CLogControlLock Shared 2 ProcArrayLock Shared 2 XidGenLock Exclusive 4 CLogControlLock Exclusive 15 WALInsertLock Exclusive 18 WALWriteLock Exclusive 38 ProcArrayLock Exclusive 77 Lock IdMode Combined Time (ns) XidGenLock Shared88700 WALInsertLock Exclusive 69556000 ProcArrayLock Shared 95656800 XidGenLock Exclusive139634100 CLogControlLock Exclusive148822200 CLogControlLock Shared16163 WALWriteLock Exclusive332781800 ProcArrayLock Exclusive 5688265500 bash-3.00# ./4_lwlock_waits.d 18599 Lock IdMode Count ProcArrayLock Shared 2 XidGenLock Exclusive 3 XidGenLock Shared 4 CLogControlLock Shared 5 WALInsertLock Exclusive 10 CLogControlLock Exclusive 21 WALWriteLock Exclusive 28 ProcArrayLock Exclusive 54 Lock IdMode Combined Time (ns) XidGenLock Exclusive 5688800 WALInsertLock Exclusive 11424700 CLogControlLock Shared 55589100 ProcArrayLock Shared135220400 WALWriteLock Exclusive177906900 XidGenLock Shared524146500 CLogControlLock Exclusive524563900 ProcArrayLock Exclusive 5828744500 bash-3.00# bash-3.00# ./6_lwlock_stack.d 4 18599 Lock IdMode Count ProcArrayLock Shared 1 ProcArrayLock Exclusive 52 Lock IdMode Combined Time (ns) ProcArrayLock Shared 41428300 ProcArrayLock Exclusive 3858386500 Lock Id Combined Time (ns) postgres`LWLockAcquire+0x1f0 postgres`GetSnapshotData+0x120 postgres`GetTransactionSnapshot+0x80 postgres`PortalStart+0x198 postgres`exec_bind_message+0x84c postgres`PostgresMain+0x17f8 postgres`BackendRun+0x2f8 postgres`ServerLoop+0x680 postgres`PostmasterMain+0xda8 postgres`main+0x3d0 postgres`_start+0x17c Shared 41428300 postgres`LWLockAcquire+0x1f0 postgres`CommitTransaction+0x104 postgres`CommitTransactionCommand+0xbc postgres`finish_xact_command+0x78 postgres`exec_execute_message+0x42c postgres`PostgresMain+0x1838 postgres`BackendRun+0x2f8 postgres`ServerLoop+0x680 postgres`PostmasterMain+0xda8 postgres`main+0x3d0 postgres`_start+0x17c Exclusive3858386500 -Jignesh ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings
[PERFORM] Vacuum looping?
Postgres 8.2.4. We have a large table, let's call it "foo", whereby an automated process periodically inserts many (hundreds of thousands or millions) rows into it at a time. It's essentially INSERT INTO foo SELECT FROM WHERE . Recently, for whatever reason, the query started to run out of memory. This happened on the order of 50 times before it was noticed and the process was stopped. (Admittedly, more investigation needs to go into the OOM problem... ) Now autovacuum promptly kicked in trying to clean up this mess, however it couldn't keep up at the rate that dead tuples were being generated. I'm not sure if it got into a weird state. After a few days, long after the inserting process was stopped, we decided to abort the vacuum (which we weren't convinced was doing anything), then start a manual vacuum with a higher vacuum_cost_limit to get things cleaned up quicker. After 28 hours, here was the output of vacuum verbose: # VACUUM VERBOSE foo; INFO: vacuuming "public.foo" INFO: scanned index "foo_pkey" to remove 44739062 row versions DETAIL: CPU 5.74s/26.09u sec elapsed 529.57 sec. INFO: scanned index "foo_1" to remove 44739062 row versions DETAIL: CPU 760.09s/619.83u sec elapsed 56929.54 sec. INFO: scanned index "foo_2" to remove 44739062 row versions DETAIL: CPU 49.35s/99.57u sec elapsed 4410.74 sec. INFO: "foo": removed 44739062 row versions in 508399 pages DETAIL: CPU 47.35s/12.88u sec elapsed 3985.92 sec. INFO: scanned index "foo_pkey" to remove 32534234 row versions DETAIL: CPU 22.05s/32.51u sec elapsed 2259.05 sec. The vacuum then just sat there. What I can't understand is why it went back for a second pass of the pkey index? There was nothing writing to the table once the vacuum began. Is this behaviour expected? Are these times reasonable for a vacuum (on a busy system, mind you)? We have since aborted the vacuum and truncated the table. We're now working on the root OOM problem, which is easier said than done... Steve
