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.