Message-ID: <49254877.6090700@archonet.com>
Date: Thu, 20 Nov 2008 11:22:31 +0000
From: Richard Huxton <dev@archonet.com>
User-Agent: Thunderbird 2.0.0.18 (X11/20081105)
MIME-Version: 1.0
To: Andrus <kobruleht2@hot.ee>
CC: pgsql-performance@postgresql.org
Subject: Re: Hash join on int takes 8..114 seconds
References: <gg1sv3$27fr$1@news.hub.org> <49253FE1.3070706@archonet.com>
	<0205611B528C4C2CBA99AFC64E57D6E8@andrusnotebook>
In-Reply-To: <0205611B528C4C2CBA99AFC64E57D6E8@andrusnotebook>
Content-Type: text/plain; charset=windows-1257
Content-Transfer-Encoding: 7bit

Andrus wrote:
> Richard,
> 
>> At a quick glance, the plans look the same to me. The overall costs are
>> certainly identical. That means whatever is affecting the query times it
>> isn't the query plan.
>>
>> So - what other activity is happening on this machine? Either other
>> queries are taking up noticeable resources, or some other process is (it
>> might be disk activity from checkpointing, logging some other
>> application).
> 
> Thank you.
> This is dedicated server running only PostgreSql which serves approx 6
> point of sales at this time.
> 
> Maybe those other clients make queries which invalidate lot of data
> loaded into server cache.
> In next time server must read it again from disk which causes those
> perfomance differences.

In addition to "top" below, you'll probably find "vmstat 5" useful.

> top output is currently:
> 
> top - 13:13:10 up 22 days, 18:25,  1 user,  load average: 0.19, 0.12, 0.19
> Tasks:  53 total,   2 running,  51 sleeping,   0 stopped,   0 zombie
> Cpu(s): 13.7% us,  2.0% sy,  0.0% ni, 78.3% id,  6.0% wa,  0.0% hi, 
> 0.0% si
> Mem:   2075828k total,  2022808k used,    53020k free,        0k buffers
> Swap:  3911816k total,       88k used,  3911728k free,  1908536k cached
> 
>  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
> 5382 postgres  15   0  144m  43m  40m S 15.0  2.2   0:00.45 postmaster
> 5358 postgres  15   0  152m  87m  75m S  0.3  4.3   0:00.97 postmaster
>    1 root      16   0  1480  508  444 S  0.0  0.0   0:01.35 init

Looks pretty quiet.

> in few seconds later:
> 
> top - 13:14:01 up 22 days, 18:26,  1 user,  load average: 1.72, 0.53, 0.32
> Tasks:  52 total,   2 running,  50 sleeping,   0 stopped,   0 zombie
> Cpu(s):  5.3% us,  3.0% sy,  0.0% ni,  0.0% id, 91.0% wa,  0.0% hi, 
> 0.7% si
> Mem:   2075828k total,  2022692k used,    53136k free,        0k buffers
> Swap:  3911816k total,       88k used,  3911728k free,  1905028k cached
> 
>  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
> 1179 postgres  18   0  155m 136m 122m D  6.7  6.7   1:32.52 postmaster
> 4748 postgres  15   0  145m 126m 122m D  1.3  6.2   0:14.38 postmaster
> 5358 postgres  16   0  160m  98m  81m D  0.7  4.9   0:01.21 postmaster
>    1 root      16   0  1480  508  444 S  0.0  0.0   0:01.35 init

Here you're stuck waiting for disks (91.0% wa). Check out vmstat and
iostat to see what's happening.

-- 
  Richard Huxton
  Archonet Ltd