Re: Monitoring PostgreSQL Process

If you're not logged in as a superuser, you won't be able to see other
user's queries. Try to login as a superuser (ei, postgres or whatever
you superuser account is).

Sincerely,

--
Husam

________________________________

From: aaron(dot)bono(at)gmail(dot)com [mailto:aaron(dot)bono(at)gmail(dot)com] On Behalf Of
Aaron Bono
Sent: Wednesday, November 22, 2006 1:46 PM
To: Tomeh, Husam
Cc: pgsql-admin(at)postgresql(dot)org
Subject: Re: [ADMIN] Monitoring PostgreSQL Process

On 11/22/06, Tomeh, Husam <htomeh(at)firstam(dot)com> wrote:

This indicates that some stats parameters are not enabled in
your "postgresql.conf" file. In particular, make sure that
"stats_command_string" parameter is turned ON so that pg_stat_activity
can report back the actual SQL statement.

Right, as I mentioned, I had stats_command_string turned off but turned
it on. What I expected to find is that the <command string not enabled>
would remain until another query was run by that process. But since
these processes are eating up so many CPU cycles, I thought they would
show something other than <command string not enabled> pretty quickly.
Since they did not show something new, why are they using so much of the
CPU? Could the be caught in some kind of massive , seemingly endless
query?

In fact 30961 and 2830 are still not showing anything new and 30960 and
30306 show Idle most of the time.

I know the application is causing the problem, I am just trying to
figure out what part of the application is taking postgres so much.

Thanks,
Aaron

________________________________

From: aaron(dot)bono(at)gmail(dot)com [mailto:aaron(dot)bono(at)gmail(dot)com] On
Behalf Of Aaron Bono
Sent: Wednesday, November 22, 2006 1:14 PM
To: Tomeh, Husam
Cc: pgsql-admin(at)postgresql(dot)org
Subject: Re: [ADMIN] Monitoring PostgreSQL Process



On 11/22/06, Tomeh, Husam <htomeh(at)firstam(dot)com> wrote:

You may query the system view, pg_stat_activity to check
out the current SQL statements running. To track down executed SQL
statements into a physical log file, you may want to enable statement
logging. For more details on that, check out:
http://www.postgresql.org/docs/8.1/static/runtime-config-logging.html

Once you capture your SQL statement, you can run
"explain" on it to check out its execution plan.

So I went out to the server and selected on pg_stat_activity and
found that stats_command_string had been turned off. I turned it on and
gave postgres a reload command. Then I selected on pg_stat_activity
again and got this:

my_db=# select * from pg_stat_activity where procpid in (30960,
30961, 877, 30306, 2830);
datid | datname | procpid | usesysid | usename |
current_query | query_start |
backend_start | client_addr | client_port

-------+----------------------+---------+----------+----------+---------
---------------------+-------------------------------+------------------
-------------+-------------+-------------
29246 | my_db | 30960 | 24114 | usr1 | <command string not
enabled> | | 2006-11-20 07:20:
24.068052-06 | 127.0.0.1 | xxxxx
29246 | my_db | 30961 | 24114 | usr1 | <command string not
enabled> | | 2006-11-20 07:20:24.072152-06
| 127.0.0.1 | xxxxx
29246 | my_db | 877 | 24114 | usr1 | <IDLE>
| 2006-11-22 15:04:42.230017-06 | 2006-11-20 08:20:35.765786-06 |
127.0.0.1 | xxxxx
29246 | my_db | 2830 | 24114 | usr1 | <command string not
enabled> | | 2006-11-22 10:45:09.528452-06
| 127.0.0.1 | xxxxx
29246 | my_db | 30306 | 24113 | usr2 | <BIND>
| 2006-11-22 15:04:42.408911-06 | 2006-11-22 07:43:08.825445-06 |
127.0.0.1 | xxxxx
(5 rows)

I cleared out the client ports.

The funny thing is that process ID's 30960, 30961 and 2830 are
using a lot of the CPU but according to pg_stat_activity the <command
string not enabled> has not been updated. Doesn't this suggest that
those processes are NOT running anything on the database, or at least
anything new?

Here is what I get from "ps axuf":

postgres 25635 0.0 0.2 34864 5592 ? S Oct01 0:02
/usr/bin/postmaster -p 5432 -D /var/lib/pgsql/data
postgres 25637 0.0 0.0 11220 768 ? S Oct01 1:07
\_ postgres: logger process
postgres 25639 0.0 0.8 35100 17624 ? S Oct01 5:03
\_ postgres: writer process
postgres 25640 0.0 0.0 12220 1568 ? S Oct01 0:50
\_ postgres: stats buffer process
postgres 25641 0.0 0.0 11908 1224 ? S Oct01 1:03
| \_ postgres: stats collector process
postgres 30950 2.2 1.1 38728 23000 ? S Nov20 74:23
\_ postgres: user3 my_db 127.0.0.1(xxx) idle
postgres 30951 2.1 1.1 38752 23328 ? S Nov20 70:22
\_ postgres: user3 my_db 127.0.0.1(xxx) idle
postgres 30960 21.3 1.1 39840 24740 ? S Nov20 715:38
\_ postgres: user1 my_db 127.0.0.1(xxx) idle
postgres 30961 17.2 1.1 39496 24356 ? S Nov20 578:08
\_ postgres: user1 my_db 127.0.0.1(xxx) idle
postgres 30962 9.5 1.1 39864 24588 ? R Nov20 320:22
\_ postgres: user1 my_db 127.0.0.1(xxx) PARSE
postgres 31068 0.0 0.2 36584 4940 ? S Nov20 0:00
\_ postgres: user1 my_test_db 127.0.0.1(xxx) idle
postgres 31069 0.6 0.9 36724 20268 ? S Nov20 22:09
\_ postgres: user1 my_test_db 127.0.0.1(xxx) idle
postgres 31070 0.0 0.2 35792 4548 ? S Nov20 0:00
\_ postgres: user1 my_test_db 127.0.0.1(xxx) idle
postgres 31199 1.8 1.1 39320 23708 ? S Nov20 62:14
\_ postgres: user2 my_db 127.0.0.1(xxx) idle
postgres 31359 0.6 1.0 37092 21308 ? S Nov20 21:11
\_ postgres: user2 my_test_db 127.0.0.1(xxx) idle
postgres 31361 0.0 0.2 36720 5000 ? S Nov20 0:00
\_ postgres: user2 my_test_db 127.0.0.1(xxx) idle
postgres 31362 1.5 1.0 38132 21384 ? S Nov20 53:26
\_ postgres: user2 my_test_db 127.0.0.1(xxx) idle
postgres 32030 5.1 1.1 39816 24740 ? S Nov20 171:42
\_ postgres: user2 my_db 127.0.0.1(xxx) idle
postgres 877 14.6 1.1 39812 24676 ? S Nov20 481:37
\_ postgres: user1 my_db 127.0.0.1(xxx) idle
postgres 3008 4.9 1.1 39404 24460 ? S Nov20 158:17
\_ postgres: user2 my_db 127.0.0.1(xxx) idle in transaction
postgres 3009 1.7 1.1 39012 23804 ? S Nov20 56:44
\_ postgres: user2 my_db 127.0.0.1(xxx) idle in transaction
postgres 17186 1.2 1.1 38804 23204 ? S Nov20 31:19
\_ postgres: user3 my_db 127.0.0.1 (xxx) idle
postgres 19966 2.7 1.1 38596 23056 ? S Nov21 25:08
\_ postgres: user3 my_db 127.0.0.1(xxx) idle
postgres 30306 19.4 1.1 39448 23908 ? S 07:43 86:45
\_ postgres: user2 my_db 127.0.0.1 (xxx) idle
postgres 2830 15.4 1.0 38992 22068 ? S 10:45 40:40
\_ postgres: user1 my_db 127.0.0.1(xxx) idle

Anyone have any clue why these processes are eating up so much
CPU time?

Thanks,
Aaron

--

==================================================================
Aaron Bono
Aranya Software Technologies, Inc.
http://www.aranya.com
http://codeelixir.com

==================================================================

**********************************************************************
This message contains confidential information intended only for
the use of the addressee(s) named above and may contain information that
is legally privileged. If you are not the addressee, or the person
responsible for delivering it to the addressee, you are hereby notified
that reading, disseminating, distributing or copying this message is
strictly prohibited. If you have received this message by mistake,
please immediately notify us by replying to the message and delete the
original message immediately thereafter.

Thank you.

FADLD Tag

**********************************************************************

--
==================================================================
Aaron Bono
Aranya Software Technologies, Inc.
http://www.aranya.com
http://codeelixir.com
==================================================================