Re: Hash join on int takes 8..114 seconds

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.

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
2 root 34 19 0 0 0 S 0.0 0.0 0:00.01 ksoftirqd/0
3 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 events/0
4 root 10 -5 0 0 0 S 0.0 0.0 0:00.42 khelper
5 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 kthread
7 root 10 -5 0 0 0 S 0.0 0.0 2:03.91 kblockd/0
8 root 20 -5 0 0 0 S 0.0 0.0 0:00.00 kacpid
115 root 13 -5 0 0 0 S 0.0 0.0 0:00.00 aio/0
114 root 15 0 0 0 0 S 0.0 0.0 8:49.67 kswapd0
116 root 10 -5 0 0 0 S 0.0 0.0 0:10.32 xfslogd/0
117 root 10 -5 0 0 0 S 0.0 0.0 0:39.96 xfsdatad/0
706 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 kseriod
723 root 13 -5 0 0 0 S 0.0 0.0 0:00.00 kpsmoused
738 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 ata/0
740 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_0
741 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_1
742 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_2
743 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_3
762 root 10 -5 0 0 0 S 0.0 0.0 0:17.54 xfsbufd
763 root 10 -5 0 0 0 S 0.0 0.0 0:00.68 xfssyncd
963 root 16 -4 1712 528 336 S 0.0 0.0 0:00.24 udevd
6677 root 15 0 1728 572 400 S 0.0 0.0 0:04.99 syslog-ng
7128 postgres 16 0 140m 10m 9900 S 0.0 0.5 0:05.60 postmaster

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
2 root 34 19 0 0 0 S 0.0 0.0 0:00.01 ksoftirqd/0
3 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 events/0
4 root 10 -5 0 0 0 S 0.0 0.0 0:00.42 khelper
5 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 kthread
7 root 10 -5 0 0 0 S 0.0 0.0 2:03.97 kblockd/0
8 root 20 -5 0 0 0 S 0.0 0.0 0:00.00 kacpid
115 root 13 -5 0 0 0 S 0.0 0.0 0:00.00 aio/0
114 root 15 0 0 0 0 S 0.0 0.0 8:49.79 kswapd0
116 root 10 -5 0 0 0 S 0.0 0.0 0:10.32 xfslogd/0
117 root 10 -5 0 0 0 S 0.0 0.0 0:39.96 xfsdatad/0
706 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 kseriod
723 root 13 -5 0 0 0 S 0.0 0.0 0:00.00 kpsmoused
738 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 ata/0
740 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_0
741 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_1
742 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_2
743 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_3
762 root 10 -5 0 0 0 S 0.0 0.0 0:17.54 xfsbufd
763 root 10 -5 0 0 0 S 0.0 0.0 0:00.68 xfssyncd
963 root 16 -4 1712 528 336 S 0.0 0.0 0:00.24 udevd
6677 root 15 0 1728 572 400 S 0.0 0.0 0:04.99 syslog-ng

Andrus.