Extrordinarily Poor Performance....
I am running Postgresql 7.1 on a dedicated Redhat 7.0 box with 512meg ram
and an IDE hard drive.
All day long queries that usually seem to execute instantaneously have been
taking up to 10 second to run! I generally have about 6 postmasters
running, utilizing anywhere from 1% to 96% CPU utilization. Another server
running Apache and PHP is performing all the queries. I am not using
persistant connections. I vaccum daily, usually has little to no impact on
the server. The database is roughly 60 megs, there are no usually wide
tables... the is one table (user tracking) that has about 200,000 rows. It
is indexed.
We are running a proprietary e-commerce package. Right now I am getting
roughly one query per second.
Any input would be helpful! If you need additional info let me know.
BTW, Thanks to Lamar for some great tips today!
Here is the status from pg_ctl:
/usr/local/pgsql/bin/postmaster '-d2' '-N' '48' '-B' '10000' '-i' '-D'
'/usr/local/pgsql/data'
Here is a sample from the log:
DEBUG: ProcessQuery
DEBUG: CommitTransactionCommand
DEBUG: StartTransactionCommand
DEBUG: query: SELECT sale_price FROM ec_sale_prices WHERE sale_begins <=
CURRENT_TIMESTAMP AND sale_ends >= CURRENT_TIMESTAMP AND p
roduct_id = 137
DEBUG: ProcessQuery
DEBUG: CommitTransactionCommand
DEBUG: proc_exit(0)
DEBUG: shmem_exit(0)
DEBUG: exit(0)
/usr/local/pgsql/bin/postmaster: reaping dead processes...
/usr/local/pgsql/bin/postmaster: CleanupProc: pid 958 exited with status 0
/usr/local/pgsql/bin/postmaster: ServerLoop: handling reading 5
/usr/local/pgsql/bin/postmaster: ServerLoop: handling reading 5
/usr/local/pgsql/bin/postmaster: ServerLoop: handling writing 5
/usr/local/pgsql/bin/postmaster: BackendStartup: pid 959 user postgres db
pa_commerce socket 5
/usr/local/pgsql/bin/postmaster child[959]: starting with (postgres -d2
-v131072 -p pa_commerce )
FindExec: found "/usr/local/pgsql/bin/postgres" using argv[0]
DEBUG: connection: host=216.239.233.44 user=postgres database=pa_commerce
DEBUG: InitPostgres
DEBUG: StartTransactionCommand
DEBUG: query: SELECT web_user_id FROM pa_web_users WHERE session_id =
'34978ae91facc5fc9abb8e21db609b4c'
DEBUG: ProcessQuery
DEBUG: CommitTransactionCommand
DEBUG: StartTransactionCommand
DEBUG: query: SELECT web_user_id FROM pa_partner_user_map WHERE
web_user_id = 221256
DEBUG: ProcessQuery
DEBUG: CommitTransactionCommand
DEBUG: StartTransactionCommand
DEBUG: query: UPDATE pa_partner_user_map SET last_visited =
CURRENT_TIMESTAMP, partner_id = 'OmdxViUZtwA-*HFh50XeaHBc70n42b4iXA' WH
ERE web_user_id = 221256
DEBUG: ProcessQuery
DEBUG: CommitTransactionCommand
DEBUG: StartTransactionCommand
DEBUG: query: SELECT order_id FROM pa_orders WHERE web_user_id = 221256
AND order_state = 'in_basket'
DEBUG: ProcessQuery
DEBUG: CommitTransactionCommand
DEBUG: proc_exit(0)
DEBUG: shmem_exit(0)
DEBUG: exit(0)
/usr/local/pgsql/bin/postmaster: ServerLoop: handling reading 5
/usr/local/pgsql/bin/postmaster: ServerLoop: handling reading 5
/usr/local/pgsql/bin/postmaster: ServerLoop: handling writing 5
/usr/local/pgsql/bin/postmaster: BackendStartup: pid 960 user postgres db
pa_commerce socket 5
/usr/local/pgsql/bin/postmaster: reaping dead processes...
/usr/local/pgsql/bin/postmaster: CleanupProc: pid 959 exited with status 0
/usr/local/pgsql/bin/postmaster child[960]: starting with (postgres -d2
-v131072 -p pa_commerce )
FindExec: found "/usr/local/pgsql/bin/postgres" using argv[0]
Import Notes
Reply to msg id not found: 200105032318.f43NIDg08058@candle.pha.pa.usReference msg id not found: 9AC41B8C4781464695BB013F106FCA31D2BD23@nasdaq.ms.ensim.com
!! I haven't ran VACUUM ANALYZE since last night. Just ran it -
performance has improved significantly. I think I am going to have to run
it hourly during this high traffic time. Postmasters are still utilizing
about 100% of the CPU. Is this normal? I am considering increasing the
shmmax again.
Thanks for the help Mitch!
-r
At 09:11 PM 5/3/01 -0400, Mitch Vincent wrote:
Show quoted text
persistant connections. I vaccum daily, usually has little to no impact
on
You VACUUM ANALYZE too, don't you?
-Mitch
---
Incoming mail is certified Virus Free.
Checked by AVG anti-virus system (http://www.grisoft.com).
Version: 6.0.251 / Virus Database: 124 - Release Date: 4/26/01
Import Notes
Reply to msg id not found: 007a01c0d4371ec0de601251000a@windowsReference msg id not found: 9AC41B8C4781464695BB013F106FCA31D2BD23@nasdaq.ms.ensim.com
Here is some output from top...
9:20pm up 40 min, 1 user, load average: 3.77, 3.12, 3.74
41 processes: 36 sleeping, 5 running, 0 zombie, 0 stopped
CPU states: 99.2% user, 0.7% system, 0.0% nice, 0.0% idle
Mem: 515664K av, 303712K used, 211952K free, 37476K shrd, 39552K buff
Swap: 514068K av, 0K used, 514068K free 158980K cached
PID USER PRI NI SIZE RSS SHARE STAT %CPU %MEM TIME COMMAND
1657 postgres 20 0 6820 6820 5712 R 33.4 1.3 0:12 postmaster
1671 postgres 20 0 6576 6576 5468 R 33.4 1.2 0:08 postmaster
1650 postgres 19 0 6952 6952 5848 R 32.6 1.3 0:16 postmaster
1444 postgres 0 0 1044 1044 844 R 0.5 0.2 0:02 top
1 root 0 0 540 540 476 S 0.0 0.1 0:06 init
2 root 0 0 0 0 0 SW 0.0 0.0 0:02 kflushd
3 root 0 0 0 0 0 SW 0.0 0.0 0:04 kupdate
4 root 0 0 0 0 0 SW 0.0 0.0 0:00 kpiod
5 root 0 0 0 0 0 SW 0.0 0.0 0:00 kswapd
6 root -20 -20 0 0 0 SW< 0.0 0.0 0:00 mdrecoveryd
373 root 0 0 836 836 700 S 0.0 0.1 0:00 syslogd
383 root 0 0 852 852 472 S 0.0 0.1 0:00 klogd
398 rpc 0 0 580 580 492 S 0.0 0.1 0:00 portmap
414 root 0 0 0 0 0 SW 0.0 0.0 0:00 lockd
415 root 0 0 0 0 0 SW 0.0 0.0 0:00 rpciod
425 rpcuser 0 0 832 832 720 S 0.0 0.1 0:00 rpc.statd
477 nobody 0 0 720 720 612 S 0.0 0.1 0:00 identd
484 nobody 0 0 720 720 612 S 0.0 0.1 0:00 identd
485 nobody 0 0 720 720 612 S 0.0 0.1 0:00 identd
488 nobody 0 0 720 720 612 S 0.0 0.1 0:00 identd
489 nobody 0 0 720 720 612 S 0.0 0.1 0:00 identd
496 daemon 0 0 580 580 504 S 0.0 0.1 0:00 atd
511 root 0 0 1040 1040 828 S 0.0 0.2 0:00 xinetd
520 root 0 0 1196 1196 1060 S 0.0 0.2 0:00 sshd
533 root 0 0 2008 2008 1652 R 0.0 0.3 0:00 sshd
542 lp 0 0 1112 1112 948 S 0.0 0.2 0:00 lpd
579 root 0 0 512 512 448 S 0.0 0.0 0:00 gpm
594 root 0 0 720 720 616 S 0.0 0.1 0:00 crond
679 xfs 0 0 4496 4496 808 S 0.0 0.8 0:00 xfs
704 ryan 0 0 1328 1328 1036 S 0.0 0.2 0:00 bash
752 postgres 0 0 2492 2492 2360 S 0.0 0.4 0:01 postmaster
778 root 0 0 444 444 380 S 0.0 0.0 0:00 mingetty
779 root 0 0 444 444 380 S 0.0 0.0 0:00 mingetty
780 root 0 0 444 444 380 S 0.0 0.0 0:00 mingetty
781 root 0 0 444 444 380 S 0.0 0.0 0:00 mingetty
782 root 0 0 444 444 380 S 0.0 0.0 0:00 mingetty
783 root 0 0 444 444 380 S 0.0 0.0 0:00 mingetty
1279 root 0 0 1060 1060 856 S 0.0 0.2 0:00 su
1280 root 0 0 1388 1388 1076 S 0.0 0.2 0:00 bash
1369 root 0 0 1020 1020 828 S 0.0 0.1 0:00 su
1370 postgres 0 0 1308 1308 1028 S 0.0 0.2 0:00 bash
I hope you have those postmasters listening on different ports.
Here is some output from top...
9:20pm up 40 min, 1 user, load average: 3.77, 3.12, 3.74
41 processes: 36 sleeping, 5 running, 0 zombie, 0 stopped
CPU states: 99.2% user, 0.7% system, 0.0% nice, 0.0% idle
Mem: 515664K av, 303712K used, 211952K free, 37476K shrd, 39552K buff
Swap: 514068K av, 0K used, 514068K free 158980K cachedPID USER PRI NI SIZE RSS SHARE STAT %CPU %MEM TIME COMMAND
1657 postgres 20 0 6820 6820 5712 R 33.4 1.3 0:12 postmaster
1671 postgres 20 0 6576 6576 5468 R 33.4 1.2 0:08 postmaster
1650 postgres 19 0 6952 6952 5848 R 32.6 1.3 0:16 postmaster
1444 postgres 0 0 1044 1044 844 R 0.5 0.2 0:02 top
1 root 0 0 540 540 476 S 0.0 0.1 0:06 init
2 root 0 0 0 0 0 SW 0.0 0.0 0:02 kflushd
3 root 0 0 0 0 0 SW 0.0 0.0 0:04 kupdate
4 root 0 0 0 0 0 SW 0.0 0.0 0:00 kpiod
5 root 0 0 0 0 0 SW 0.0 0.0 0:00 kswapd
6 root -20 -20 0 0 0 SW< 0.0 0.0 0:00 mdrecoveryd
373 root 0 0 836 836 700 S 0.0 0.1 0:00 syslogd
383 root 0 0 852 852 472 S 0.0 0.1 0:00 klogd
398 rpc 0 0 580 580 492 S 0.0 0.1 0:00 portmap
414 root 0 0 0 0 0 SW 0.0 0.0 0:00 lockd
415 root 0 0 0 0 0 SW 0.0 0.0 0:00 rpciod
425 rpcuser 0 0 832 832 720 S 0.0 0.1 0:00 rpc.statd
477 nobody 0 0 720 720 612 S 0.0 0.1 0:00 identd
484 nobody 0 0 720 720 612 S 0.0 0.1 0:00 identd
485 nobody 0 0 720 720 612 S 0.0 0.1 0:00 identd
488 nobody 0 0 720 720 612 S 0.0 0.1 0:00 identd
489 nobody 0 0 720 720 612 S 0.0 0.1 0:00 identd
496 daemon 0 0 580 580 504 S 0.0 0.1 0:00 atd
511 root 0 0 1040 1040 828 S 0.0 0.2 0:00 xinetd
520 root 0 0 1196 1196 1060 S 0.0 0.2 0:00 sshd
533 root 0 0 2008 2008 1652 R 0.0 0.3 0:00 sshd
542 lp 0 0 1112 1112 948 S 0.0 0.2 0:00 lpd
579 root 0 0 512 512 448 S 0.0 0.0 0:00 gpm
594 root 0 0 720 720 616 S 0.0 0.1 0:00 crond
679 xfs 0 0 4496 4496 808 S 0.0 0.8 0:00 xfs
704 ryan 0 0 1328 1328 1036 S 0.0 0.2 0:00 bash
752 postgres 0 0 2492 2492 2360 S 0.0 0.4 0:01 postmaster
778 root 0 0 444 444 380 S 0.0 0.0 0:00 mingetty
779 root 0 0 444 444 380 S 0.0 0.0 0:00 mingetty
780 root 0 0 444 444 380 S 0.0 0.0 0:00 mingetty
781 root 0 0 444 444 380 S 0.0 0.0 0:00 mingetty
782 root 0 0 444 444 380 S 0.0 0.0 0:00 mingetty
783 root 0 0 444 444 380 S 0.0 0.0 0:00 mingetty
1279 root 0 0 1060 1060 856 S 0.0 0.2 0:00 su
1280 root 0 0 1388 1388 1076 S 0.0 0.2 0:00 bash
1369 root 0 0 1020 1020 828 S 0.0 0.1 0:00 su
1370 postgres 0 0 1308 1308 1028 S 0.0 0.2 0:00 bash
---
Outgoing mail is certified Virus Free.
Checked by AVG anti-virus system (http://www.grisoft.com).
Version: 6.0.251 / Virus Database: 124 - Release Date: 4/26/01
---------------------------(end of broadcast)---------------------------
TIP 5: Have you checked our extensive FAQ?
--
Bruce Momjian | http://candle.pha.pa.us
pgman@candle.pha.pa.us | (610) 853-3000
+ If your life is a hard drive, | 830 Blythe Avenue
+ Christ can be your backup. | Drexel Hill, Pennsylvania 19026
Thus spake Ryan Mahoney
!! I haven't ran VACUUM ANALYZE since last night. Just ran it -
performance has improved significantly. I think I am going to have to run
it hourly during this high traffic time. Postmasters are still utilizing
about 100% of the CPU. Is this normal? I am considering increasing the
shmmax again.
Although it isn't supposed to be necessary, I find that I have to dump and
reload once in a while to keep performance hight.
--
D'Arcy J.M. Cain <darcy@{druid|vex}.net> | Democracy is three wolves
http://www.druid.net/darcy/ | and a sheep voting on
+1 416 425 1212 (DoD#0082) (eNTP) | what's for dinner.