Message-ID: <4D3F86D9.9080200@agliodbs.com>
Date: Tue, 25 Jan 2011 18:28:41 -0800
From: Josh Berkus <josh@agliodbs.com>
User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.5; en-US;
	rv:1.9.1b3pre) Gecko/20090223 Thunderbird/3.0b2
MIME-Version: 1.0
To: Tom Lane <tgl@sss.pgh.pa.us>
CC: pgsql-bugs@postgresql.org
Subject: Re: Multicolun index creation never completes on 9.0.1/solaris
References: <4D3F2D10.1020905@agliodbs.com> <21735.1295990515@sss.pgh.pa.us>
In-Reply-To: <21735.1295990515@sss.pgh.pa.us>
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 7bit


> trace_sort would be interesting.

This is it so far:

LOG:  begin index sort: unique = f, workMem = 1048576, randomAccess = f
STATEMENT:  create index "write_log_accounttime_idx" on write_log
(account_id, event_time);
LOG:  switching to external sort with 3745 tapes: CPU 9.06s/6.65u sec
elapsed 21.68 sec
STATEMENT:  create index "write_log_accounttime_idx" on write_log
(account_id, event_time);
LOG:  finished writing run 1 to tape 0: CPU 33.39s/149.02u sec elapsed
190.11 sec

LOG:  finished writing run 2 to tape 1: CPU 62.72s/371.06u sec elapsed
443.16 sec

LOG:  finished writing run 3 to tape 2: CPU 91.04s/599.43u sec elapsed
701.37 sec

LOG:  finished writing run 4 to tape 3: CPU 120.95s/823.59u sec elapsed
956.67 sec

If it's going to take 3 minutes each to write each of 3745 tapes, that
means completing in around 9 days.

I wanted to see what this looks like with a single-column index, so I
did one on event_time, which was even *worse*:

LOG:  begin index sort: unique = f, workMem = 1048576, randomAccess = f
STATEMENT:  create index "write_log_time_idx" on write_log (event_time);

LOG:  switching to external sort with 3745 tapes: CPU 14.45s/10.87u sec
elapsed 26.19 sec

LOG:  finished writing run 1 to tape 0: CPU 135.32s/302.18u sec elapsed
447.44 sec

... run 2 didn't complete in even 1/2 hour.

So the problem isn't multicolumn indexes, it's indexes on a table this
large in general (a VARCHR index wasn't much faster to build).  I'd
guess that the PK index finished only because the table might have been
in that rough physical order.

For whatever reason, tape sort is being extra slow on this build on
Solaris10; did we change anything between 8.4 and 9.0?  Or is this
possibly the build I used?

I'll try to run a sort_trace on an 8.4.4 copy of the database.

Oh, FWIW, the rough number of rows in the table:
1 486 530 000

-- 
                                  -- Josh Berkus
                                     PostgreSQL Experts Inc.
                                     http://www.pgexperts.com