Re: [PERFORM] VACUUMs take twice as long across all nodes
Hi :) [pg_dump from a Slony replica] That's not the problem. The problem is that when you restore the dump of the slave, you'll have garbage. Slony fools with the catalogs on the replicas. (And you might as well throw away the dumpfiles from the replicas that you have. They won't work when you restore them.) This is interesting, but I don't understand.. We've done a full restore from one of these pg_dump backups before now and it worked just great. Sure I had to DROP SCHEMA _replication CASCADE to clear out all the slony-specific triggers etc., but the new-master ran fine, as did firing up new replication to the other nodes :) Was I just lucky? Cheers, Gavin. ---(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] 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
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
[PERFORM] VACUUMs take twice as long across all nodes
Hullo, here's one of those dreadful touchy-feely hand-waving problems. Our 5-node 8.1.3 Slony system has just started taking /much/ longer to VACUUM ANALYZE.. The data set has not increased more than usual (nightly backups stand at 1.3GB, growing by 10MB per day), and no configuration has changed on the machines. Nodes 2 and 3 take only the tables necessary to run our search (10 out of the full 130) and are much lighter (only 7GB on disk cf. 30GB for the full master) , yet the nightly VACUUM FULL has jumped from 2 hours to 4 in the space of one day! Like I say, no config changes, no reboots / postmaster restarts, no extra processes, and every machine has a comfortable overhead of free page slots + relations. From a few days ago: 2006-10-20 03:04:29 UTC INFO: Allocation: found 786856 removable, 4933448 nonremovable row versions in 53461 pages 2006-10-20 03:04:29 UTC DETAIL: 0 dead row versions cannot be removed yet. 2006-10-20 03:07:32 UTC INFO: index allocation_pkey now contains 4933448 row versions in 93918 pages 2006-10-20 03:07:32 UTC DETAIL: 786856 index row versions were removed. 2006-10-20 03:14:21 UTC INFO: index ix_date now contains 4933448 row versions in 74455 pages 2006-10-20 03:14:21 UTC DETAIL: 786856 index row versions were removed. 2006-10-20 03:22:32 UTC INFO: index ix_dateprice now contains 4933448 row versions in 81313 pages 2006-10-20 03:22:32 UTC DETAIL: 786856 index row versions were removed. 2006-10-20 03:24:41 UTC INFO: index ix_dateroom now contains 4933448 row versions in 44610 pages 2006-10-20 03:24:41 UTC DETAIL: 786856 index row versions were removed. 2006-10-20 03:27:52 UTC INFO: index ix_room now contains 4933448 row versions in 35415 pages 2006-10-20 03:27:52 UTC DETAIL: 786856 index row versions were removed. 2006-10-20 03:31:43 UTC INFO: Allocation: moved 348324 row versions, truncated 53461 to 46107 pages 2006-10-20 03:31:43 UTC DETAIL: CPU 4.72s/17.63u sec elapsed 230.81 sec. From last night: 2006-10-26 01:00:30 UTC INFO: vacuuming public.Allocation 2006-10-26 01:00:36 UTC INFO: Allocation: found 774057 removable, 4979938 nonremovable row versions in 53777 pages 2006-10-26 01:00:36 UTC DETAIL: 0 dead row versions cannot be removed yet. 2006-10-26 01:06:18 UTC INFO: index allocation_pkey now contains 4979938 row versions in 100800 pages 2006-10-26 01:06:18 UTC DETAIL: 774057 index row versions were removed. 2006-10-26 01:19:22 UTC INFO: index ix_date now contains 4979938 row versions in 81630 pages 2006-10-26 01:19:22 UTC DETAIL: 774057 index row versions were removed. 2006-10-26 01:35:17 UTC INFO: index ix_dateprice now contains 4979938 row versions in 87750 pages 2006-10-26 01:35:17 UTC DETAIL: 774057 index row versions were removed. 2006-10-26 01:41:27 UTC INFO: index ix_dateroom now contains 4979938 row versions in 46320 pages 2006-10-26 01:41:27 UTC DETAIL: 774057 index row versions were removed. 2006-10-26 01:48:18 UTC INFO: index ix_room now contains 4979938 row versions in 36513 pages 2006-10-26 01:48:18 UTC DETAIL: 774057 index row versions were removed. 2006-10-26 01:56:35 UTC INFO: Allocation: moved 322744 row versions, truncated 53777 to 46542 pages 2006-10-26 01:56:35 UTC DETAIL: CPU 4.21s/15.90u sec elapsed 496.30 sec. As you can see, the amount of system + user time for these runs are comparable, but the amount of real time has more than doubled. This isn't even a case for making the cost-based delay vacuum more aggressive because I already have vacuum_cost_delay = 0 on all machines to make the vacuum run as quickly as possible. Any ideas warmly received! :) 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] VACUUMs take twice as long across all nodes
On Thu, 26 Oct 2006 10:47:21 -0400 Tom Lane [EMAIL PROTECTED] wrote: Gavin Hamill [EMAIL PROTECTED] writes: Nodes 2 and 3 take only the tables necessary to run our search (10 out of the full 130) and are much lighter (only 7GB on disk cf. 30GB for the full master) , yet the nightly VACUUM FULL has jumped from 2 hours to 4 in the space of one day! I guess the most useful question to ask is why are you doing VACUUM FULL? Plain VACUUM should be considerably faster, and for the level of row turnover shown by your log, there doesn't seem to be a reason to use FULL. I do FULL on the 'light' clients simply because 'I can'. The example posted was a poor choice - the other tables have a larger churn. Anyway, once it starts, the load balancer takes it out of rotation so no love is lost. The same behaviour is shown on the 'heavy' clients (master + 2 slaves) which take all tables - although I cannot afford to VACUUM FULL on there, the usual VACUUM ANALYZE has begun to take vastly more time since yesterday than in the many previous months we've been using pg. Cheers, Gavin. ---(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 Thu, 26 Oct 2006 14:17:29 -0500 Jim C. Nasby [EMAIL PROTECTED] wrote: Are you sure that there's nothing else happening on the machine that could affect the vacuum times? Like, say a backup? Or perhaps updates coming in from Slony that didn't used to be there? 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. Plus, I have fairly verbose logging, and it's not showing anything out of the ordinary. Like I said, it's one of those awful hypothesis/hand-waving problems :) Cheers, Gavin. ---(end of broadcast)--- TIP 2: Don't 'kill -9' the postmaster
Re: [PERFORM] scaling up postgres
On Tue, 13 Jun 2006 14:28:49 -0500 Scott Marlowe [EMAIL PROTECTED] wrote: Search the performance archives for the last 4 or 5 months for PPC / pseries machines. You'll find a very long thread about the disappointing performance the tester got with a rather expensive P Series machine. And his happy ending of testing on an Opteron machine. Amen, brother :) We hoped throwing a silly pSeries 650 would solve all our problems. Boy were we wrong... a world of pain... Don't go there - just buy an Opteron system - if you're talking about IBM big iron, a decent Opteron will cost you about as much as a couple of compilers and an on-site visit from IBM... Cheers, Gavin. ---(end of broadcast)--- TIP 3: Have you checked our extensive FAQ? http://www.postgresql.org/docs/faq
Re: [PERFORM] Large (8M) cache vs. dual-core CPUs
On Tue, 25 Apr 2006 14:14:35 -0400 Bill Moran [EMAIL PROTECTED] wrote: Does anyone in the PostgreSQL community have any experience with large caches or dual-core pentiums that could make any recommendations? Heh :) You're in the position I was in about a year ago - we naturally replaced our old Dell 2650 with £14k of Dell 6850 Quad Xeon with 8M cache, and TBH the performance is woeful :/ Having gone through Postgres consultancy, been through IBM 8-way POWER4 hardware, discovered a bit of a shortcoming in PG on N-way hardware (where N is large) [1] , I have been able to try out a dual-dual-core Opteron machine, and it flies. In fact, it flies so well that we ordered one that day. So, in short £3k's worth of dual-opteron beat the living daylights out of our Xeon monster. I can't praise the Opteron enough, and I've always been a firm Intel pedant - the HyperTransport stuff must really be doing wonders. I typically see 500ms searches on it instead of 1000-2000ms on the Xeon) As it stands, I've had to borrow this Opteron so much (and send live searches across the net to the remote box) because otherwise we simply don't have enough CPU power to run the website (!) Cheers, Gavin. [1] Simon Riggs + Tom Lane are currently involved in optimisation work for this - it turns out our extremely read-heavy load pattern reveals some buffer locking issues in PG. ---(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] IBM pSeries - overrated bucket of crud?
Hi again :) This is a follow-up to the mega thread which made a Friday night more interesting [1] - the summary is various people thought there was some issue with shared memory access on AIX. I then installed Debian (kernel 2.6.11) on the 8-CPU p650 (native - no LPAR) and saw just as woeful performance. Now I've had a chance to try a 2-CPU dualcore Opteron box, and it *FLIES* - the 4-way machine sits churning through our heavy 'hotelsearch' function at ~400ms per call. Basically, this pSeries box is available until Monday lunchtime if any pg devel wants to pop in, run tests, mess around since I am convinced that the hardware itself cannot be this poor - it has to be some failing of pg when mixed with our dataset / load pattern. e.g. If I run 'ab -n 200 -c 4 -k http://localhost/test.php [2] with pg_connect pointed at the pSeries, it turns in search times of ~3500ms with loadavg of 4. The same test with pg_connect pointed at the dual-Opteron turns in ~300ms searches, with loadavg of 3.5 .. something is very very wrong with the pSeries setup :) If I crank up the heat and run apachebench with 10 hammering clients instead of 4, the differences become even more stark.. pSeries: 5000-15000ms, loadavg 9.. Opteron ~3000ms, loadavg 8. 90% of queries on the Opteron conclude in under 4000ms, which maxes out at 6.5 searches per second. The pSeries manages 0.9 searches per second. (!) Databases on both machines have seen a VACUUM FULL and VACUUM ANALYZE before testing, and have near-identical postgresql.conf's. (the pSeries has twice the RAM) This post is not intended to be whining that 'pg is crap on pSeries!' - I'm trying to make a resource available (albeit for a short time) to help fix a problem that will doubtless affect others in future - for certain we're never going midrange again! :O Cheers, Gavin. [1] http://archives.postgresql.org/pgsql-performance/2006-04/msg00143.php [2] Trivial script which does a pg_connect, runs a random hotelsearch and exits. ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
Re: [PERFORM] Slow query - possible bug?
Tom Lane wrote: Gavin Hamill [EMAIL PROTECTED] writes: If I replace the (allocation0_.Date between '2006-06-09 00:00:00.00' and '2006-06-09 00:00:00.00') with allocation0_.Date ='2006-04-09 00:00:00.00' then the query comes back in a few milliseconds (as I'd expect :) Could we see EXPLAIN ANALYZE for * both forms of the date condition, with the roomid condition; * both forms of the date condition, WITHOUT the roomid condition; * just the roomid condition I'm thinking the planner is misestimating something, but it's hard to tell what without breaking it down. Of course. In each case, I have changed the date by two weeks to try and minimise the effect of any query caching. The base query is explain analyse select allocation0_.ID as y1_, allocation0_.RoomID as y2_, allocation0_.StatusID as y4_, allocation0_.Price as y3_, allocation0_.Number as y5_, allocation0_.Date as y6_ from Allocation allocation0_ where now both forms of the Date condition a) (allocation0_.Date between '2006-04-25 00:00:00.00' and '2006-04-25 00:00:00.00')and(allocation0_.RoomID in(211800)); QUERY PLAN --- Index Scan using ix_date on Allocation allocation0_ (cost=0.00..4.77 rows=1 width=34) (actual time=3253.340..48040.396 rows=1 loops=1) Index Cond: ((Date = '2006-04-25'::date) AND (Date = '2006-04-25'::date)) Filter: (RoomID = 211800) Total runtime: 48040.451 ms (ouch!) b) (allocation0_.Date= '2006-05-10 00:00:00.00'::date)and(allocation0_.RoomID in(211800)); QUERY PLAN Index Scan using ix_dateroom on Allocation allocation0_ (cost=0.00..5.01 rows=1 width=34) (actual time=0.033..0.035 rows=1 loops=1) Index Cond: ((RoomID = 211800) AND (Date = '2006-05-10'::date)) Total runtime: 0.075 ms (whoosh!) And now without the RoomID condition: a) (allocation0_.Date between '2006-06-10 00:00:00.00' and '2006-06-10 00:00:00.00'); QUERY PLAN --- Index Scan using ix_date on Allocation allocation0_ (cost=0.00..4.77 rows=1 width=34) (actual time=0.035..6706.467 rows=34220 loops=1) Index Cond: ((Date = '2006-06-10'::date) AND (Date = '2006-06-10'::date)) Total runtime: 6728.743 ms b) (allocation0_.Date= '2006-05-25 00:00:00.00'::date); QUERY PLAN -- Bitmap Heap Scan on Allocation allocation0_ (cost=87.46..25017.67 rows=13845 width=34) (actual time=207.674..9702.656 rows=34241 loops=1) Recheck Cond: (Date = '2006-05-25'::date) - Bitmap Index Scan on ix_date (cost=0.00..87.46 rows=13845 width=0) (actual time=185.086..185.086 rows=42705 loops=1) Index Cond: (Date = '2006-05-25'::date) Total runtime: 9725.470 ms Wow, I'm not really sure what that tells me... Cheers, Gavin. ---(end of broadcast)--- TIP 6: explain analyze is your friend
Re: [PERFORM] Slow query - possible bug?
On Tue, 18 Apr 2006 13:31:48 -0400 Tom Lane [EMAIL PROTECTED] wrote: There should be a fix for this by the time PG 8.2 comes out, but in the meantime you might find that it helps to write the range check in a way that doesn't have identical bounds, eg date = '2006-06-10'::date AND date '2006-06-11'::date OK coolies - we've already had a code release for this (and other stuff) planned for tomorrow morning checking on the client side if a single date has been chosen, then do an equality test on that... otherwise leave the between in place - seems to work like a charm, and hopefully it'll mean we don't have a loadavg of 15 on our main pg server tomorrow (!) :)) Basically, as long as I know it's a pg issue rather than something daft I've done (or not done) then I'm happy enough. Cheers, Gavin. ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
Re: [PERFORM] Slow query - possible bug?
On Tue, 18 Apr 2006 15:51:44 -0400 Tom Lane [EMAIL PROTECTED] wrote: Fair enough, no reason to replace one workaround with another. But would you try it on your test case, just to verify the diagnosis? Yup I can confirm it from testing earlier today - as soon as the two dates are non-equal, an index scan is correctly selected and returns results in just a few milliseconds: laterooms=# explain analyse select allocation0_.ID as y1_, allocation0_.RoomID as y2_, allocation0_.StatusID as y4_, allocation0_.Price as y3_, allocation0_.Number as y5_, allocation0_.Date as y6_ from Allocation allocation0_ where (allocation0_.Date between '2006-04-25 00:00:00.00' and '2006-04-26 00:00:00.00')and(allocation0_.RoomID in(211800)); QUERY PLAN --- Index Scan using ix_dateroom on Allocation allocation0_ (cost=0.00..14.02 rows=4 width=34) (actual time=16.799..21.804 rows=2 loops=1) Index Cond: ((RoomID = 211800) AND (Date = '2006-04-25'::date) AND (Date = '2006-04-26'::date)) Total runtime: 21.910 ms which I ran first, versus the identical-date equivalent which turned in a whopping... Index Scan using ix_date on Allocation allocation0_ (cost=0.00..4.77 rows=1 width=34) (actual time=6874.272..69541.064 rows=1 loops=1) Index Cond: ((Date = '2006-04-25'::date) AND (Date = '2006-04-25'::date)) Filter: (RoomID = 211800) Total runtime: 69541.113 ms (4 rows) Cheers, Gavin. ---(end of broadcast)--- TIP 3: Have you checked our extensive FAQ? http://www.postgresql.org/docs/faq
[PERFORM] Slow query - possible bug?
laterooms=# explain analyze select allocation0_.ID as y1_,
allocation0_.RoomID as y2_, allocation0_.StatusID as y4_,
allocation0_.Price as y3_, allocation0_.Number as y5_,
allocation0_.Date as y6_ from Allocation allocation0_ where
(allocation0_.Date between '2006-06-09 00:00:00.00' and
'2006-06-09 00:00:00.00')and(allocation0_.RoomID in(4300591));
QUERY PLAN
--
Index Scan using ix_date on Allocation allocation0_ (cost=0.00..4.77
rows=1 width=34) (actual time=1411.325..1689.860 rows=1 loops=1)
Index Cond: ((Date = '2006-06-09'::date) AND (Date =
'2006-06-09'::date))
Filter: (RoomID = 4300591)
Total runtime: 1689.917 ms
(4 rows)
Yep, the two dates are identical - yep I would change the client
software to do where Date = '2006-06-09 00:00:00.00' if I could...
However, it's clear to see why this simple query is taking so long - the
plan is selecting /all/ dates after 2006-06-09 and /all/ dates before
then, and only returning the union of the two - a large waste of effort,
surely?
VACUUM ANALYZE hasn't improved matters... the schema for the table is
ID int8 NOT NULL DEFAULT
nextval(('public.allocation_id_seq'::text)::regclass),
RoomID int4,
Price numeric(10,2),
StatusID int4,
Number int4,
Date date,
and there are indexes kept for 'RoomID' and 'Date' in this 4.3-million
row table.
Is this a bug or a hidden feature in pg 8.1.3 ? :)
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] Slow query - possible bug?
chris smith wrote: 1.6secs isn't too bad on 4.3mill rows... How many entries are there for that date range? 1.7 secs /is/ good - it typically takes 5 or 6 seconds, which isn't so good. My question is 'why does the planner choose such a bizarre range request when both elements of the 'between' are identical? :)' If I replace the (allocation0_.Date between '2006-06-09 00:00:00.00' and '2006-06-09 00:00:00.00') with allocation0_.Date ='2006-04-09 00:00:00.00' then the query comes back in a few milliseconds (as I'd expect :) - and yup I've been using different dates for each test to avoid the query being cached. For ref, there are typically 35000 rows per date :) Cheers, Gavin. ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
Re: [PERFORM] pg 8.1.3, AIX, huge box, painfully slow.
Tom Lane wrote: Gavin Hamill [EMAIL PROTECTED] writes: would a simple #define LWLOCK_PADDED_SIZE 128 be sufficient? Yeah, that's fine. OK I tried that but noticed no real improvement... in the interim I've installed Debian on the pSeries (using http://debian.gonicus.de/debian/dists/sarge/main/disks-powerpc/current/pseries/install.txt ) and using a simple load-test script - it picks a 'hotelsearch' select at random from a big file and just does a pg_query on that via PHP... Using apachebench with 10 clients gave a loadavg of about 10 after a few minutes, and the logs showed typical query times of 8 seconds. Again, no disk activity, normal context-switching, just full-out CPU usage... We're improving the quality + efficiency of the hotelsearch function all the time (Simon will certainly be able to vouch for its complexity) - am really uncertain what to do next tho! :/ Cheers, Gavin. ---(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] pg 8.1.3, AIX, huge box, painfully slow.
Simon Riggs wrote: pSeries cache lines are 128 bytes wide, so I'd go straight to 128. Hello :) OK, that line of code is: #define LWLOCK_PADDED_SIZE (sizeof(LWLock) = 16 ? 16 : 32) What should I change this to? I don't understand the syntax of the = 16 ? : stuff... would a simple #define LWLOCK_PADDED_SIZE 128 be sufficient? If you're renting all 8 CPUs, I'd drop to 4 and try that instead. With 8 CPUs the contention will vary according to what each CPU is doing at any one time - when they all hit the contention spot, things will get worse. We have a physical machine installed in our rack at the data centre, rather than renting a virtual partition of a real machine... I'm not sure how to enable/disable CPUs even with the help of 'smitty' :) The pSeries has good CPUs and great caching, so I'd expect contention to be somewhat more apparent as a bottleneck. Yep, I expected 32MB of 'L3' cache would yield impressive results :) 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] pg 8.1.3, AIX, huge box, painfully slow.
Bing-bong, passenger announcement.. the panic train is now pulling into platform 8.1.3. Bing-bong. =) OK, having moved from our quad-xeon to an 8-CPU IBM pSeries 650 (8x1.45GHz POWER4 instead of 4 x 3GHz Xeon), our query times have shot up and our website is next to unusable. The IBM is not swapping (not with 16GB of RAM!), disk i/o is low, but there must be something critically wrong for this monster to be performing so badly.. There is little IO (maybe 500KB/sec), but the CPUs are often at 100% usage. VACUUM VERBOSE ANALYZE shows me 4 page slots are needed to track all free space. I have 16 page slots configured, and this machine is dedicated to pg. The thing that really winds me up about this, is that aside from all the normal 'my postgres is slow l0lz!' troubleshooting is the previous machine (Debian sarge on four 3GHz Xeons) is using 8.1.3 also, with an inferior I/O subsystem, and it churns through the workload very merrily, only reaching a full loadavg of 4 at peak times, and running our main 'hotelsearch' function in ~1000ms.. This IBM on the other hand is often taking 5-10 seconds to do the same thing - although just by watching the logs it's clear to see the workload coming in waves, and then calming down again. (this correlation is matched by watching the load-balancer's logs as it takes unresponsive webservers out of the cluster) Here's the differences (I've removed obvious things like file/socket paths) in select name,setting from pg_catalog.pg_settings between the two: --- cayenne 2006-04-07 18:43:48.0 +0100 # quad xeon +++ jalapeno2006-04-07 18:44:08.0 +0100 # ibm 650 - effective_cache_size| 32 + effective_cache_size| 64 - integer_datetimes | on + integer_datetimes | off - maintenance_work_mem| 262144 + maintenance_work_mem| 1048576 - max_connections | 150 + max_connections | 100 - max_fsm_pages | 66000 + max_fsm_pages | 16 - max_stack_depth | 2048 + max_stack_depth | 16384 - tcp_keepalives_count| 0 - tcp_keepalives_idle | 0 - tcp_keepalives_interval | 0 - temp_buffers| 1000 - TimeZone| GB + tcp_keepalives_count| 8 + tcp_keepalives_idle | 7200 + tcp_keepalives_interval | 75 + temp_buffers| 4000 + TimeZone| GMT0BST,M3.5.0,M10.5.0 - wal_sync_method | fdatasync - work_mem| 4096 + wal_sync_method | open_datasync + work_mem| 16384 So, jalapeno really should have much more room to move. shared_buffers is 6 on both machines. I'm reaching the end of my tether here - our search functions are just so extensive and my pg knowledge is so small that it's overwhelming to try and step through it to find any bottlenecks :( Just to reiterate, it all runs great on cayenne since we trimmed a lot of the fat out of the search, and I can't understand why the IBM box isn't absolutely throwing queries out the door :) 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] pg 8.1.3, AIX, huge box, painfully slow.
On Fri, 07 Apr 2006 14:41:39 -0400 Tom Lane [EMAIL PROTECTED] wrote: Gavin Hamill [EMAIL PROTECTED] writes: OK, having moved from our quad-xeon to an 8-CPU IBM pSeries 650 (8x1.45GHz POWER4 instead of 4 x 3GHz Xeon), our query times have shot up and our website is next to unusable. The IBM is not swapping (not with 16GB of RAM!), disk i/o is low, but there must be something critically wrong for this monster to be performing so badly.. Have you vacuumed/analyzed since reloading your data? Absolutely - a VACUUM FULL was the first thing I did, and have VACUUM ANALYZE VERBOSE'd a couple of times since. I have plenty of overhead to keep the entire free space map in RAM. Compare some EXPLAIN ANALYZE outputs for identical queries on the two machines, that usually helps figure out what's wrong. If only :) Since 90% of the db work is the 'hotelsearch' function (which is 350 lines-worth that I'm not permitted to share :(( ), an EXPLAIN ANALYZE reveals practically nothing: # jalapeno (IBM) laterooms=# EXPLAIN ANALYZE select * from hotelsearch(12.48333::numeric, 41.9::numeric, 5::int4, '2006-04-13'::date, 5::int4, NULL::int4, 1::int4, NULL::int4, NULL::int4, TRUE::bool, FALSE::bool, FALSE::bool, 1::int2, 'GBP'::text, 'Roma'::text, 7::int4, NULL::int4, NULL::int4) limit 500; QUERY PLAN --- Limit (cost=0.00..6.25 rows=500 width=1587) (actual time=2922.282..2922.908 rows=255 loops=1) - Function Scan on hotelsearch (cost=0.00..12.50 rows=1000 width=1587) (actual time=2922.277..2922.494 rows=255 loops=1) Total runtime: 2923.296 ms (3 rows) # cayenne (xeon) laterooms=# EXPLAIN ANALYZE select * from hotelsearch(12.48333::numeric, 41.9::numeric, 5::int4, '2006-04-13'::date, 5::int4, NULL::int4, 1::int4, NULL::int4, NULL::int4, TRUE::bool, FALSE::bool, FALSE::bool, 1::int2, 'GBP'::text, 'Roma'::text, 7::int4, NULL::int4, NULL::int4) limit 500; QUERY PLAN --- Limit (cost=0.00..6.25 rows=500 width=1587) (actual time=1929.483..1930.103 rows=255 loops=1) - Function Scan on hotelsearch (cost=0.00..12.50 rows=1000 width=1587) (actual time=1929.479..1929.693 rows=255 loops=1) Total runtime: 1930.506 ms (3 rows) The 'LIMIT 500' is a red herring since the function body will get all data, so reducing the LIMIT in the call to hotelsearch doesn't reduce the amount of work being done. The killer in it all is tail'ing the postgres log (which I have set only to log queries at 1000ms or up) is things will be returning at 1000-2000ms.. then suddenly shoot up to 8000ms.. and if I try a few of those 8000ms queries on the xeon box, they exec in ~1500ms.. and if I try them again a few moments later on the ibm, they'll also exec in maybe ~2500ms. This is one hell of a moving target and I can't help but think I'm just missing something that's right in front of my nose, too close to see. Cheers, Gavin. ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings
Re: [PERFORM] pg 8.1.3, AIX, huge box, painfully slow.
On Fri, 07 Apr 2006 13:54:21 -0500 Scott Marlowe [EMAIL PROTECTED] wrote: Are the same queries getting the same basic execution plan on both boxes? Turn on logging for slow queries, and explain analyze them on both machines to see if they are. See reply to Tom Lane :) I'd put the old 4 way Xeon back in production and do some serious testing of this pSeries machine. IBM should be willing to help you, I hope. They probably would if this had been bought new - as it is, we have rented the machine for a month from a 2nd-user dealer to see if it's capable of taking the load. I'm now glad we did this. My guess is that this is an OS issue. Maybe there are AIX tweaks that will get it up to the same or higher level of performance as your four way xeon. Maybe there aren't. The pSeries isn't much older than our Xeon machine, and I expected the performance level to be exemplary out of the box.. we've enabled the 64-bit kernel+userspace, and compiled pg for 64-bitness with the gcc flags as reccommended by Senica Cunningham on this very list.. Myself, I'd throw a spare drive in for the OS, put some flavor of linux on it Terrifying given I know nothing about the pSeries boot system, but at this stage I'm game for nearly anything. http://www.asaservers.com/system_dept.asp?dept_id=SD-002 Multi-Opteron was the other thing we considered but decided to give 'Big Iron' UNIX a whirl... Cheers, Gavin. ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings
Re: [PERFORM] pg 8.1.3, AIX, huge box, painfully slow.
On Fri, 7 Apr 2006 16:16:02 -0400 D'Arcy J.M. Cain darcy@druid.net wrote: We also had problems with a high end AIX system and we got no help from IBM. They expected you to put Oracle on and if you used anything else you were on your own. Urk, I thought IBM were supposedly Linux sycophants thesedays... We had exactly the same issue. We expected to get an order of magnitude improvement and instead the app bogged down. That's kind of encouraging, I suppose - that it might not be something mind-bogglingly stupid I'm doing. It also got worse over time. We had to reboot every night to get anything out of it. Needless to say, they got their system back. nod That's Seneca. Oops - meant to check the spelling before I sent that =) We found that our money was better spent on multiple servers running NetBSD with a home grown multi-master replication system. Need more power? Just add more servers. Aye, I originally suggested multiple servers, but was talked round to one giant db so that our devels didn't have to rewrite code to deal with read/write + read-only db handles... Cheers, Gavin. ---(end of broadcast)--- TIP 4: Have you searched our list archives? http://archives.postgresql.org
Re: [PERFORM] pg 8.1.3, AIX, huge box, painfully slow.
On Fri, 07 Apr 2006 15:24:18 -0500 Scott Marlowe [EMAIL PROTECTED] wrote: See reply to Tom Lane :) I didn't see one go by yet... Could be sitting in the queue. If it's not arrived by now - EXPLAIN ANALYZE doesn't tell me anything :) Let us know if changing the fsync setting helps. Hopefully that's all the problem is. fsync's already off - yes a bit scary, but our I/O is only about 500KB/sec writing.. the whole db fits in RAM / kernel disk cache, and I'd rather have performance than security at this exact moment.. Off on a tangent. If the aggregate memory bandwidth of the pSeries is no greater than you Xeon you might not see a big improvement if you were memory bound before. If you were CPU bound, you may or may not see an improvement. I did look into the specs of the system, and the memory bw on the pSeries was /much/ greater than the Xeon - it's one of the things that really pushed me towards it in the end. I forget the figures, but it was 3 or 4 times greater. Can you describe the disc subsystems in the two machines for us? What kind of read / write load you have? It could be the older box was running on IDE drives with fake fsync responses which would lie, be fast, but not reliable in case of a power outage. Again, I'm confident that I/O's not the killer here.. the Xeon is a Dell 6850- hardware RAID1.. SCSI drives. Multi-Opteron was the other thing we considered but decided to give 'Big Iron' UNIX a whirl... It still might be a good choice, if it's a simple misconfiguration issue. But man, those new multiple core opterons can make some impressive machines for very little money. So I see - we could buy two quad-opterons for the cost of renting this pSeries for a month Cheers, Gavin. ---(end of broadcast)--- TIP 3: Have you checked our extensive FAQ? http://www.postgresql.org/docs/faq
Re: [PERFORM] pg 8.1.3, AIX, huge box, painfully slow.
On Fri, 07 Apr 2006 16:06:02 -0400 Tom Lane [EMAIL PROTECTED] wrote: The pSeries isn't much older than our Xeon machine, and I expected the performance level to be exemplary out of the box.. I'm fairly surprised too. One thing I note from your comparison of settings is that the default WAL sync method is different on the two operating systems. We're very read-focussed.. there's update activity, sure, but the IO is only pushing about 500KByte/sec on average, usually much less. I also have fsync switched off - yes dangerous, but I just want to eliminate IO completely as a contributing factor. Does AIX have anything comparable to oprofile or dtrace? I've used neither on Linux, but a quick google showed up a few articles along the lines of 'in theory it shouldn't be hard to port to AIX' but nothing concrete. My guess is IBM sell a tool to do this. Hell, the C++ compiler is £1200... (hence our use of GCC 4.1 to compile pg) Failing a low-level profiler, there should at least be something comparable to strace --- you should try watching some of the backends with strace and see what their behavior is when the performance goes south. Lots of delaying select()s or semop()s would be a red flag. There's truss installed which seems to do the same as strace on Linux... and here's a wildly non-scientific glance.. I watched the 'topas' output (top for AIX) , identified a PID that was doing a lot of work, then attached truss to that pid. In addition to lots of send (), recv() and lseek()s... about once a minute I saw hundreds of calls to __semop() interspersed with _select(), followed by tons of lseek() +kread()+__semop() and then I can see the kwrite() to the pg logfile 246170: kwrite(2, L O G : d u, 8)= 8 etc. Cheers, Gavin. ---(end of broadcast)--- TIP 6: explain analyze is your friend
Re: [PERFORM] pg 8.1.3, AIX, huge box, painfully slow.
On Fri, 07 Apr 2006 17:56:49 -0400 Tom Lane [EMAIL PROTECTED] wrote: This is not good. Did the semop storms coincide with visible slowdown? (I'd assume so, but you didn't actually say...) If I'd been able to tell, then I'd tell you =) I'll have another go... Yes, there's a definate correlation here.. I attached truss to the main postmaster.. $ truss -Ff -p 340344 21 | grep semop here's a snippet 278774: __semop(15728650, 0x0FFF7E80, 1)= 0 155712: __semop(15728650, 0x0FFF5920, 1)= 0 278774: __semop(15728649, 0x0FFF6F10, 1) 114914: __semop(15728649, 0x0FFF6A40, 1)= 0 = 0 114914: __semop(15728650, 0x0FFF61E0, 1) 155712: __semop(15728650, 0x0FFF6850, 1)= 0 = 0 155712: __semop(15728650, 0x0FFF6890, 1)= 0 1 55712: __semop(15728650, 0x0FFF5920, 1) 278774: __semop(15728650, 0x0FFF6F10, 1) 155712: __semop(15728650, 0x0FFF6850, 1)= 0 = 0 278774: __semop(15728649, 0x0FFF7E40, 1) 114914: __semop(15728649, 0x0FFF6A80, 1)= 0 = 0 278774: __semop(15728650, 0x0FFF7E80, 1) And when I saw a flood of semop's for any particular PID, a second later in the 'topas' process list would show that PID at a 100% CPU ... Most intriguing :) Cheers, Gavin. ---(end of broadcast)--- TIP 6: explain analyze is your friend
Re: [PERFORM] pg 8.1.3, AIX, huge box, painfully slow.
On Fri, 07 Apr 2006 18:52:20 -0400 Tom Lane [EMAIL PROTECTED] wrote: Are you in a position to try your workload using PG CVS tip? There's a nontrivial possibility that we've already fixed this --- a couple months ago I did some work to reduce contention in the lock manager: Well, there's a question. At the moment it's still live - but I'll need to swap back to the Xeon machine since I can't afford to have a Saturday with the db firing on three cylinders (out of eight :) At that point you're welcome to twiddle, compile, throw anything you want at it. If it helps us as much as the greater pg world, then that's perfect. This is unfortunately not going to help you as far as getting that machine into production now (unless you're brave enough to run CVS tip as production, which I certainly am not). .. if the problem can actually be boiled down to the locking/threading issues, surely it should be straightforward to backport those changes to 8.1.3 mainline? I'm afraid you're most likely going to have to ship that pSeries back at the end of the month, but while you've got it it'd be awfully nice if we could use it as a testbed ... We have it for the next 2 weeks, and whilst I can't guarantee access for all that time, you're welcome to hammer away at it over this weekend if that's any help? Mail me privately and I'll sort out login details if this is interesting. Cheers, Gavin. ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings
Re: [PERFORM] pg 8.1.3, AIX, huge box, painfully slow.
On Fri, 07 Apr 2006 15:56:52 -0700 Luke Lonergan [EMAIL PROTECTED] wrote: Seems like you're hitting a very small target in RAM with these semop calls. I wonder what part of the code is doing this - Tom would know better how to trace it, but the equivalent of oprofile output would be nice. I'm happy to test whatever I can, but I simply don't know enough AIX to be able to tell whether a similar kernel-level profiler is available/possible. The other thing that I'd like to see is an evaluation of the memory access latency of this machine from Register to RAM. I couldn't find a benchmarking tool that was UNIX friendly out there, maybe I'll write one real quick. I suspect this machine has a heinous latency and a storm of semops to the same spot of RAM might be a far worse performance problem on this machine than on others... Well, as I said to Tom, the machine is available for running tests on :) If it helps us, and helps pg become more AIX friendly, then I'm all for whatever needs done... Cheers, Gavin. ---(end of broadcast)--- TIP 2: Don't 'kill -9' the postmaster
[PERFORM] CREATE INDEX rather sluggish
Hullo, I have pg 8.1.3 on an 8-CPU AIX 5.3 box with 16GB of RAM, and I'm
finding that it's taking an age to CREATE INDEX on a large table:
Column | Type | Modifiers
++-
ID | integer| not null default
nextval(('public.keyword_id_seq'::text)::regclass)
Text | character varying(200) |
Longitude | numeric(16,5) |
Latitude | numeric(16,5) |
AreaID | integer|
SearchCount| integer| not null default 0
Radius | integer|
LanguageID | integer|
KeywordType| character varying(20) |
LowerText | character varying(200) |
NumberOfHotels | integer|
CountryID | integer|
FriendlyText | character varying(200) |
Indexes:
2006-03-29 21:39:38 BST LOG: duration: 41411.625 ms statement: CREATE INDEX ix_keyword_areaid ON
Keyword USING btree (AreaID);
2006-03-29 21:42:46 BST LOG: duration: 188550.644 ms statement: CREATE INDEX ix_keyword_lonlat ON
Keyword USING btree (Longitude, Latitude);
2006-03-29 21:46:41 BST LOG: duration: 234864.571 ms statement: CREATE INDEX ix_keyword_lowertext
ON Keyword USING btree (LowerText);
2006-03-29 21:52:32 BST LOG: duration: 350757.565 ms statement: CREATE INDEX ix_keyword_type ON
Keyword USING btree (KeywordType);
The table has just under six million rows - should it really be taking
nearly six minutes to add an index? These log snippets were taking
during a pg_restore on a newly created db, so there should be no issues
with the table needing vacuuming.
What parameters in the postgresql.conf are pertinent here? I have
shared_buffers 12
work_mem 16384
maintenance_work_mem = 262144
for starters... any advice would be warmly welcomed!
Cheers,
Gavin.
---(end of broadcast)---
TIP 5: don't forget to increase your free space map settings
Re: [PERFORM] CREATE INDEX rather sluggish
Tom Lane wrote: Gavin Hamill [EMAIL PROTECTED] writes: The table has just under six million rows - should it really be taking nearly six minutes to add an index? Try running it with trace_sort enabled to get more info about where the time is going. We've been doing some considerable work on the sorting code in the last couple months, so 8.2 should be better, but I'd like to verify that you're not seeing something we don't know about. OKies, I dropped the db, created again so it's all clean, ran pg_restore again with trace_sort on - here's the output from one of the larger CREATE INDEXes: 2006-03-30 16:48:53 BST LOG: begin index sort: unique = f, workMem = 262144, randomAccess = f 2006-03-30 16:49:04 BST LOG: switching to external sort: CPU 0.88s/9.99u sec elapsed 10.90 sec 2006-03-30 16:49:44 BST LOG: autovacuum: processing database postgres 2006-03-30 16:50:38 BST LOG: performsort starting: CPU 1.69s/102.73u sec elapsed 104.58 sec 2006-03-30 16:50:44 BST LOG: autovacuum: processing database laterooms 2006-03-30 16:51:44 BST LOG: autovacuum: processing database postgres 2006-03-30 16:52:23 BST LOG: finished writing run 1: CPU 2.40s/206.53u sec elapsed 209.30 sec 2006-03-30 16:52:39 BST LOG: finished writing final run 2: CPU 2.51s/222.98u sec elapsed 225.89 sec 2006-03-30 16:52:40 BST LOG: performsort done (except final merge): CPU 2.59s/223.99u sec elapsed 226.98 sec 2006-03-30 16:52:44 BST LOG: autovacuum: processing database laterooms 2006-03-30 16:52:53 BST LOG: external sort ended, 21292 disk blocks used: CPU 3.65s/233.10u sec elapsed 239.35 sec 2006-03-30 16:52:53 BST LOG: duration: 239381.535 ms statement: CREATE INDEX ix_keyword_lowertext ON Keyword USING btree (LowerText); During all this, there's been about 900KB/sec of disk activity. The disks are RAID1 and will happily sustain 50MB/sec with minimal system overhead. I'm guessing then that an external sort means disk-based... maintenance_work_mem = 262144 Fooling with this might affect the results some. OK will tinker with that - it's not a massive problem since I hope I never have to do a pg_restore once the live server is running fulltime :) Right - I bumped maintenance_work_mem up to 1GB, tried dropping the index and recreating, and sure enough it's an internal sort now, chopping 10% off the time taken: 2006-03-30 21:15:57 BST LOG: begin index sort: unique = f, workMem = 1048576, randomAccess = f 2006-03-30 21:16:03 BST LOG: autovacuum: processing database laterooms 2006-03-30 21:16:12 BST LOG: performsort starting: CPU 1.20s/13.85u sec elapsed 15.07 sec 2006-03-30 21:17:03 BST LOG: autovacuum: processing database laterooms 2006-03-30 21:18:03 BST LOG: autovacuum: processing database laterooms 2006-03-30 21:19:03 BST LOG: autovacuum: processing database laterooms 2006-03-30 21:19:28 BST LOG: performsort done: CPU 1.20s/210.34u sec elapsed 211.69 sec 2006-03-30 21:19:36 BST LOG: internal sort ended, 336538 KB used: CPU 2.06s/212.61u sec elapsed 218.80 sec 2006-03-30 21:19:36 BST LOG: duration: 218847.055 ms statement: CREATE INDEX ix_keyword_lowertext on Keyword USING btree (LowerText); If that's reasonable performance from 8.1, then that's fine - I just didn't want to be inadvertantly running way under average :) Cheers, Gavin. ---(end of broadcast)--- TIP 6: explain analyze is your friend
