Nooby Q: Should this take five hours? And counting?

On Sat, Apr 18, 2009 at 4:11 PM, Kenneth Tilton <kentilton@gmail.com> wrote:

ie, 5hrs and counting, no clue how long it intends to run, but methinks this
is insane even if it is 10^7 records, mebbe half a dozen dups per value (a
product-id usually around 8-chars long):

CREATE INDEX web_source_items_by_item_id_strip
              ON web_source_items
              USING btree (item_id_strip);

Am I unreasonably impatient?

I see pg getting just a few % CPU on a heavily ram/core-endowed Sun box with
nothing else going on. Mebbe they installed pg on a compact flash? DVD-RW?
/usr/local/something, prolly not.

What does vmstat 1 60 say during the index build? Specifically the
cpu columns for user, system, wa?

Scott Marlowe wrote:

On Sat, Apr 18, 2009 at 4:11 PM, Kenneth Tilton <kentilton@gmail.com>

wrote:

ie, 5hrs and counting, no clue how long it intends to run, but

methinks this

is insane even if it is 10^7 records, mebbe half a dozen dups per

value (a

product-id usually around 8-chars long):

CREATE INDEX web_source_items_by_item_id_strip
ON web_source_items
USING btree (item_id_strip);

Am I unreasonably impatient?

I see pg getting just a few % CPU on a heavily ram/core-endowed Sun

box with

nothing else going on. Mebbe they installed pg on a compact flash?

DVD-RW?

/usr/local/something, prolly not.

What does vmstat 1 60 say during the index build? Specifically the
cpu columns for user, system, wa?

uh-oh, Unix noob too, and unfortunately someone has jumped on with a
CPU-intensive task pegging one of the cores at 100%, so these numbers
prolly do not help, but here goes:

procs -----------memory---------- ---swap-- -----io---- --system--
-----cpu------
r b swpd free buff cache si so bi bo in cs us sy
id wa st
1 1 2076312 1503204 182152 30669308 49 69 260 299 3 3
28 2 63 7 0
1 1 2076312 1502900 182152 30669656 0 0 192 2260 1198 332
25 1 50 24 0
1 1 2076312 1503024 182152 30669656 0 0 0 704 1181 282
25 1 50 25 0
1 3 2076312 1502904 182156 30669740 0 0 104 2780 1224 422
25 0 48 26 0
1 3 2076312 1502896 182156 30669740 0 0 0 1552 1173 309
25 0 50 25 0
1 1 2076312 1502140 182172 30669976 0 0 120 312 1222 396
26 1 48 25 0
1 1 2076312 1501724 182180 30670408 0 0 496 3996 1161 450
26 1 50 24 0
1 1 2076312 1501304 182200 30670960 0 0 428 2892 1203 438
26 1 50 24 0
1 2 2076312 1501064 182200 30671400 0 0 236 3456 1168 434
26 1 49 24 0
1 2 2076312 1501064 182200 30671360 0 0 0 1620 1225 357
25 0 50 25 0
1 1 2076312 1501064 182200 30671360 0 0 0 292 1205 339
25 1 49 25 0
1 1 2076312 1500652 182220 30671776 0 0 416 1740 1186 410
25 1 50 24 0
1 2 2076312 1500472 182224 30671992 0 0 208 3560 1177 399
25 1 49 24 0

I'll sample again if I get a window, but these jobs tend to run for hours.

thx,

kt

On Sat, Apr 18, 2009 at 6:32 PM, Kenneth Tilton <kentilton@gmail.com> wrote:

Scott Marlowe wrote:

On Sat, Apr 18, 2009 at 4:11 PM, Kenneth Tilton <kentilton@gmail.com>
wrote:

ie, 5hrs and counting, no clue how long it intends to run, but methinks
this
is insane even if it is 10^7 records, mebbe half a dozen dups per value
(a
product-id usually around 8-chars long):

CREATE INDEX web_source_items_by_item_id_strip
              ON web_source_items
              USING btree (item_id_strip);

Am I unreasonably impatient?

I see pg getting just a few % CPU on a heavily ram/core-endowed Sun box
with
nothing else going on. Mebbe they installed pg on a compact flash?
DVD-RW?
/usr/local/something, prolly not.

What does vmstat 1 60 say during the index build?  Specifically the
cpu columns for user, system, wa?

uh-oh, Unix noob too, and unfortunately someone has jumped on with a
CPU-intensive task pegging one of the cores at 100%, so these numbers prolly
do not help, but here goes:

procs -----------memory---------- ---swap-- -----io---- --system--
-----cpu------
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id
wa st
 1  1 2076312 1503204 182152 30669308   49   69   260   299    3    3 28  2
63  7  0
 1  1 2076312 1502900 182152 30669656    0    0   192  2260 1198  332 25  1
50 24  0
 1  1 2076312 1503024 182152 30669656    0    0     0   704 1181  282 25  1
50 25  0
 1  3 2076312 1502904 182156 30669740    0    0   104  2780 1224  422 25  0
48 26  0
 1  3 2076312 1502896 182156 30669740    0    0     0  1552 1173  309 25  0

I'll sample again if I get a window, but these jobs tend to run for hours.

I'm gonna take a guess about a few things:
1: You've got a lot of memory in that machine, try cranking up
work_mem for this query to see if that helps
2: You've got a slow disk subsystem, if you're already seeing 25%
IOWait with only ~2 to 3 megs a second being written.

While having enough memory for everything to fit in it makes for fast
reads, it doesn't do a lot to help with writes.

MG>take a look at the man page for vmstat

Martin Gainty
______________________________________________
Disclaimer and Confidentiality/Verzicht und Vertraulichkeitanmerkung / Note de déni et de confidentialité
This message is confidential. If you should not be the intended receiver, then we ask politely to report. Each unauthorized forwarding or manufacturing of a copy is inadmissible. This message serves only for the exchange of information and has no legal binding effect. Due to the easy manipulation of emails we cannot take responsibility over the the contents.

Date: Sat, 18 Apr 2009 18:55:59 -0600
Subject: Re: [GENERAL] Nooby Q: Should this take five hours? And counting?
From: scott.marlowe@gmail.com
To: kentilton@gmail.com
CC: pgsql-general@postgresql.org

On Sat, Apr 18, 2009 at 6:32 PM, Kenneth Tilton <kentilton@gmail.com> wrote:

Scott Marlowe wrote:

On Sat, Apr 18, 2009 at 4:11 PM, Kenneth Tilton <kentilton@gmail.com>
wrote:

ie, 5hrs and counting, no clue how long it intends to run, but methinks
this
is insane even if it is 10^7 records, mebbe half a dozen dups per value
(a
product-id usually around 8-chars long):

CREATE INDEX web_source_items_by_item_id_strip
ON web_source_items
USING btree (item_id_strip);

Am I unreasonably impatient?

I see pg getting just a few % CPU on a heavily ram/core-endowed Sun box
with
nothing else going on. Mebbe they installed pg on a compact flash?
DVD-RW?
/usr/local/something, prolly not.

What does vmstat 1 60 say during the index build? Specifically the
cpu columns for user, system, wa?

uh-oh, Unix noob too, and unfortunately someone has jumped on with a
CPU-intensive task pegging one of the cores at 100%, so these numbers prolly
do not help, but here goes:

procs -----------memory---------- ---swap-- -----io---- --system--
-----cpu------

FIELD DESCRIPTION FOR VM MODE Procs
r: The number of processes waiting for run time.
b: The number of processes in uninterruptible sleep.

Memory
swpd: the amount of virtual memory used.
free: the amount of idle memory.
buff: the amount of memory used as buffers.
cache: the amount of memory used as cache.
inact: the amount of inactive memory. (-a option)
active: the amount of active memory. (-a option)

Swap
si: Amount of memory swapped in from disk (/s).
so: Amount of memory swapped to disk (/s).

IO
bi: Blocks received from a block device (blocks/s).
bo: Blocks sent to a block device (blocks/s).

System
in: The number of interrupts per second, including the clock.
cs: The number of context switches per second.

CPU
These are percentages of total CPU time.
us: Time spent running non-kernel code. (user time, including nice time)
sy: Time spent running kernel code. (system time)
id: Time spent idle. Prior to Linux 2.5.41, this includes IO-wait time.
wa: Time spent waiting for IO. Prior to Linux 2.5.41, shown as zero.

r b swpd free buff cache si so bi bo in cs us sy id
wa st
1 1 2076312 1503204 182152 30669308 49 69 260 299 3 3 28 2
63 7 0
1 1 2076312 1502900 182152 30669656 0 0 192 2260 1198 332 25 1
50 24 0
1 1 2076312 1503024 182152 30669656 0 0 0 704 1181 282 25 1
50 25 0
1 3 2076312 1502904 182156 30669740 0 0 104 2780 1224 422 25 0
48 26 0
1 3 2076312 1502896 182156 30669740 0 0 0 1552 1173 309 25 0

I'll sample again if I get a window, but these jobs tend to run for hours.

I'm gonna take a guess about a few things:
1: You've got a lot of memory in that machine, try cranking up
work_mem for this query to see if that helps
2: You've got a slow disk subsystem, if you're already seeing 25%
IOWait with only ~2 to 3 megs a second being written.

While having enough memory for everything to fit in it makes for fast
reads, it doesn't do a lot to help with writes.

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

_________________________________________________________________
Rediscover Hotmail®: Now available on your iPhone or BlackBerry
http://windowslive.com/RediscoverHotmail?ocid=TXT_TAGLM_WL_HM_Rediscover_Mobile2_042009

Scott Marlowe wrote:

On Sat, Apr 18, 2009 at 6:32 PM, Kenneth Tilton <kentilton@gmail.com> wrote:

Scott Marlowe wrote:

On Sat, Apr 18, 2009 at 4:11 PM, Kenneth Tilton <kentilton@gmail.com>
wrote:

ie, 5hrs and counting, no clue how long it intends to run, but methinks
this
is insane even if it is 10^7 records, mebbe half a dozen dups per value
(a
product-id usually around 8-chars long):

CREATE INDEX web_source_items_by_item_id_strip
ON web_source_items
USING btree (item_id_strip);

Am I unreasonably impatient?

I see pg getting just a few % CPU on a heavily ram/core-endowed Sun box
with
nothing else going on. Mebbe they installed pg on a compact flash?
DVD-RW?
/usr/local/something, prolly not.

What does vmstat 1 60 say during the index build? Specifically the
cpu columns for user, system, wa?

uh-oh, Unix noob too, and unfortunately someone has jumped on with a
CPU-intensive task pegging one of the cores at 100%, so these numbers prolly
do not help, but here goes:

procs -----------memory---------- ---swap-- -----io---- --system--
-----cpu------
r b swpd free buff cache si so bi bo in cs us sy id
wa st
1 1 2076312 1503204 182152 30669308 49 69 260 299 3 3 28 2
63 7 0
1 1 2076312 1502900 182152 30669656 0 0 192 2260 1198 332 25 1
50 24 0
1 1 2076312 1503024 182152 30669656 0 0 0 704 1181 282 25 1
50 25 0
1 3 2076312 1502904 182156 30669740 0 0 104 2780 1224 422 25 0
48 26 0
1 3 2076312 1502896 182156 30669740 0 0 0 1552 1173 309 25 0

I'll sample again if I get a window, but these jobs tend to run for hours.

I'm gonna take a guess about a few things:
1: You've got a lot of memory in that machine, try cranking up
work_mem for this query to see if that helps

A bit. I killed the indexing and jacked work_mem up to 500mb, indexing
then finished in 7 min 25s.

Yer a genius!

2: You've got a slow disk subsystem, if you're already seeing 25%
IOWait with only ~2 to 3 megs a second being written.

This has been passed along to management for consideration.

Thx a ton,

ken

On Sat, Apr 18, 2009 at 6:32 PM, Kenneth Tilton <kentilton@gmail.com> wrote:

Scott Marlowe wrote:

On Sat, Apr 18, 2009 at 4:11 PM, Kenneth Tilton <kentilton@gmail.com>
wrote:

ie, 5hrs and counting, no clue how long it intends to run, but methinks
this
is insane even if it is 10^7 records, mebbe half a dozen dups per value
(a
product-id usually around 8-chars long):

CREATE INDEX web_source_items_by_item_id_strip
              ON web_source_items
              USING btree (item_id_strip);

Am I unreasonably impatient?

I see pg getting just a few % CPU on a heavily ram/core-endowed Sun box
with
nothing else going on. Mebbe they installed pg on a compact flash?
DVD-RW?
/usr/local/something, prolly not.

What does vmstat 1 60 say during the index build?  Specifically the
cpu columns for user, system, wa?

uh-oh, Unix noob too, and unfortunately someone has jumped on with a
CPU-intensive task pegging one of the cores at 100%, so these numbers prolly
do not help, but here goes:

procs -----------memory---------- ---swap-- -----io---- --system--
-----cpu------
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id
wa st
 1  1 2076312 1503204 182152 30669308   49   69   260   299    3    3 28  2
63  7  0
 1  1 2076312 1502900 182152 30669656    0    0   192  2260 1198  332 25  1
50 24  0
 1  1 2076312 1503024 182152 30669656    0    0     0   704 1181  282 25  1
50 25  0
 1  3 2076312 1502904 182156 30669740    0    0   104  2780 1224  422 25  0
48 26  0

Looking at these numbers, it seems you've got 4 cores, 1 is running
100% user, 2 are sitting idle, and 1 is 100% io wait. I'm guessing
the 100% iowait is the postgres backend running your query.

Kenneth Tilton <kentilton@gmail.com> writes:

A bit. I killed the indexing and jacked work_mem up to 500mb, indexing then
finished in 7 min 25s.

Yer a genius!

FWIW creating indexes using maintenance_work_mem. I would not expect changing
work_mem to really help much. That's, uh, curious.

2: You've got a slow disk subsystem, if you're already seeing 25%
IOWait with only ~2 to 3 megs a second being written.

This has been passed along to management for consideration.

Depends. If it's all random i/o then 8-12MB/s is about right for 4-6 drives.
If there's any sequential i/o mixed in then yeah, it's pretty poor.

--
Gregory Stark
EnterpriseDB http://www.enterprisedb.com
Ask me about EnterpriseDB's On-Demand Production Tuning