Thread: Logging/Debugging
Hi, I went through the man pages for postmaster, as well as "pg_ctl --help" for options to log a date/time stamp in the "serverlog" but could not find it. It was also not clear to me what debug levels are available (other than 1) and what they log. How would I go about this? Thank you Tielman J de Villiers BondNet (Pty) Ltd
About 25% of the time while running my nightly maintenance script, which deletes and the copies in a large amount of new data, then vacuums and recreates indexes, the vacuum command will hang. When I wake up in the morning, everything is hosed and I have 6000 complaint emails. boohoo. :) This behavior started a few weeks ago when I upgraded from 7.0 to 7.1.3. Looking at the process list (ps -x on Readhat Linux 6.2) shows the following, 4168 ? S 1:11 postgres: postgres ucc 207.132.206.57 idle in transaction 5754 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5755 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5756 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5757 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5758 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5759 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5791 ? S 0:01 postgres: postgres ucc 207.132.206.57 VACUUM waiting 5794 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5796 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5797 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5798 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5799 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5800 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5801 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5802 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting 5803 ? S 0:00 postgres: postgres ucc 207.132.206.65 idle waiting etc... If I kill pid 4168, the idle in transaction process, then the vacuum and all the other waiting processes will proceed fine. Any clues to what could be hanging or how I could get more information from postmaster about what transaction is hanging? Thanks, Rich
It looks like you've got a transaction which is staying open while holding a lock. I'm not sure why it'd be different between versions. If you turn up the debugging level and turn on at least log_pid you should be able to see what statements the process from that pid has executed. > If I kill pid 4168, the idle in transaction process, then the vacuum and all > the other waiting processes will proceed fine. Any clues to what could be > hanging or how I could get more information from postmaster about what > transaction is hanging?
Colm Thank you very much. This in postgresql.conf gives me exactly what I wanted: log_connections = true log_timestamp = true log_pid = true debug_level = 2 debug_print_query = true THOUGH I would prefer a further option to only display the query/date/pid/db_name (the rest are completely "lost' for an entry level user like me) Logging the above information helps me to check when certain web pages take exceptional strain, and when/if I should cache them to relive the strain ... Tielman J de Villiers BondNet Pty Ltd -----Original Message----- From: Colm McCartan [mailto:colmm@owl.co.uk] Sent: Monday, December 10, 2001 11:23 AM To: Tielman J de Villiers Subject: Re: [GENERAL] Logging/Debugging Tielman J de Villiers wrote: > Hi, > > I went through the man pages for postmaster, as well as "pg_ctl > --help" for options to log a date/time stamp in the "serverlog" but > could not find it. It was also not clear to me what debug levels are > available (other than 1) and what they log. How would I go about this? Tielman, you'll find lots of basic information on this in the idocs at: http://www.postgresql.org/idocs/index.php?runtime-config.html However, I too would like a little more detail as to what each of the debugging levels signifies - does anyone have any more detailed info? Thanks, colm
"Rich Ryan" <rich@usedcars.com> writes:
> If I kill pid 4168, the idle in transaction process, then the vacuum and all
> the other waiting processes will proceed fine.
You've got a client that is sitting with an open transaction block ---
ie, BEGIN, do something, go to sleep without issuing COMMIT/ROLLBACK.
In 7.1 the "do something" could just be a SELECT; that's still
sufficient to block VACUUM. I think that 7.0 might have been a little
laxer about that, and would not hold a lock for a SELECT-only
transaction.
regards, tom lane
Hi, <history> Sometime back my app had some probs with postgres 7.1.2- the app did a lot of updates, and somehow after weeks the backend exited when I did a select on a table. I truncated the table and updated to 7.1.3 (did not pg_dump). I'm trying to see if the problem recurs in 7.1.3. </history> Recently I vacummed the database (the postmasters were using a lot of cpu). No vacuum analyze, just plain psql, vacuum. The disk usage before vacuuming was 95MB. After dropped to 45MB. Then I noticed the postmaster for a particular table still using lots of cpu 45-80%. Another postmaster on the same database, using different table was using a lot less cpu. I vacuumed again, this time the troublesome table specifically. Then the disk usage dropped to 9MB. And the postmaster cpu usage went down. I did not restart the app or postgres. Is it normal to require two vacuums for it to be effective? AFAIK I was connected to the correct database when vacuuming. Should I have pg_dumped and reloaded? Regards, Link.