Tom Lane wrote:
> I wrote:
>
>>Stefan Kaltenbrunner <stefan@kaltenbrunner.cc> writes:
>>
>>>samples % symbol name
>>>350318533 98.8618 mergepreread
>>>971822 0.2743 tuplesort_gettuple_common
>>>413674 0.1167 tuplesort_heap_siftup
>
>
>>I don't have enough memory to really reproduce this, but I've come close
>>enough that I believe I see what's happening. It's an artifact of the
>>code I added recently to prevent the SortTuple array from growing during
>>the merge phase, specifically the "mergeslotsfree" logic.
>
>
> I've committed a fix for this; if you're still interested, please
> retest.
This seems to have fixed the problem - mergepreread is gone from the
profile and the CREATE INDEX finished in about 2h 37 minutes:
LOG: begin index sort: unique = f, workMem = 8024000, randomAccess = f
LOG: switching to external sort with 28658 tapes: CPU 4.68s/11.67u sec
elapsed 16.36 sec
LOG: finished writing run 1 to tape 0: CPU 303.18s/3324.51u sec elapsed
3858.55 sec
LOG: performsort starting: CPU 611.37s/6829.75u sec elapsed 7830.90 sec
LOG: finished writing final run 2 to tape 1: CPU 614.15s/6928.92u sec
elapsed 7933.38 sec
LOG: performsort done (except 2-way final merge): CPU 615.26s/6940.77u
sec elapsed 7951.58 sec
LOG: external sort ended, 4398827 disk blocks used: CPU
827.45s/8519.86u sec elapsed 10046.31 sec
profile for this run looks like:
CPU: AMD64 processors, speed 2405.5 MHz (estimated)
Counted CPU_CLK_UNHALTED events (Cycles outside of halt state) with a
unit mask of 0x00 (No unit mask) count 100000
samples % symbol name
77645525 39.6040 comparetup_index
47024448 23.9854 btint4cmp
22508630 11.4808 tuplesort_heap_siftup
12657874 6.4563 LogicalTapeRead
4049912 2.0657 tuplesort_heap_insert
3025537 1.5432 tuplesort_gettuple_common
2922149 1.4905 AllocSetFree
2499669 1.2750 readtup_index
1725984 0.8804 AllocSetAlloc
1318344 0.6724 LWLockAcquire
1298245 0.6622 PageAddItem
1271657 0.6486 heapgettup
Stefan