Re: CREATE INDEX rather sluggish - Mailing list pgsql-performance

Tom Lane wrote:

>Gavin Hamill <gdh@laterooms.com> 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.