Skip site navigation (1) Skip section navigation (2)

Re: postgres.exe 100% CPU but no I/O

From: Robert Schnabel <schnabelr(at)missouri(dot)edu>
To: Guido Barosio <gbarosio(at)gmail(dot)com>
Cc: pgsql-novice(at)postgresql(dot)org
Subject: Re: postgres.exe 100% CPU but no I/O
Date: 2009-01-27 00:21:23
Message-ID: 497E5383.1000206@missouri.edu (view raw or flat)
Thread:
Lists: pgsql-novice
Thanks for giving me a place to start.  I set log_min_duration_statement 
= 0 and log_min_messages = debug5.  Below is the log entry for the first 
2 minutes after I restarted the server.  This repeats exactly every 60 
seconds.  As I said in the original post, there is no disk I/O being 
performed, just 100% CPU load.  Any suggestions as to what may be 
causing this or where to look next?  I'm a novice, hence posting to the 
novice list, so just saying RTFM! :) doesn't do the novice much good 
when they've already done that and just needs some pointers to isolate a 
problem.  I apologize for the long log but I'm not sure exactly what is 
relevant and what is not.

Bob

-- 

*************************************************
Robert Schnabel
Research Assistant Professor
University of Missouri-Columbia
Animal Sciences Unit, Rm.162
920 East Campus Drive
Columbia, MO 65211-5300
Phone: 573-884-4106
Fax:   573-882-6827
http://animalgenomics.missouri.edu

"Don't speak unless you can improve the silence"
-various sources
*************************************************



2009-01-26 07:14:07 LOG:  database system was shut down at 2009-01-26 
07:13:02
2009-01-26 07:14:07 DEBUG:  mapped win32 error code 2 to 2
2009-01-26 07:14:07 DEBUG:  mapped win32 error code 2 to 2
2009-01-26 07:14:07 DEBUG:  mapped win32 error code 2 to 2
2009-01-26 07:14:07 LOG:  checkpoint record is at 160/932590C8
2009-01-26 07:14:07 LOG:  redo record is at 160/932590C8; undo record is 
at 0/0; shutdown TRUE
2009-01-26 07:14:07 LOG:  next transaction ID: 0/370293; next OID: 25596
2009-01-26 07:14:07 LOG:  next MultiXactId: 1; next MultiXactOffset: 0
2009-01-26 07:14:07 LOG:  database system is ready
2009-01-26 07:14:07 DEBUG:  mapped win32 error code 80 to 17
2009-01-26 07:14:07 DEBUG:  transaction ID wrap limit is 2147484173, 
limited by database "postgres"
2009-01-26 07:14:07 DEBUG:  mapped win32 error code 80 to 17
2009-01-26 07:14:07 DEBUG:  mapped win32 error code 80 to 17
2009-01-26 07:14:07 DEBUG:  proc_exit(0)
2009-01-26 07:14:07 DEBUG:  shmem_exit(0)
2009-01-26 07:14:07 DEBUG:  exit(0)
2009-01-26 07:14:07 DEBUG:  reaping dead processes
2009-01-26 07:14:07 DEBUG:  waiting on 2 children
2009-01-26 07:14:07 DEBUG:  waiting on 3 children
2009-01-26 07:14:07 DEBUG:  StartTransaction
2009-01-26 07:14:07 DEBUG:  name: unnamed; blockState:       DEFAULT; 
state: INPROGR, xid/subid/cid: 370293/1/0, nestlvl: 1, children: <>
2009-01-26 07:14:07 DEBUG:  mapped win32 error code 2 to 2
2009-01-26 07:14:07 DEBUG:  CommitTransaction
2009-01-26 07:14:07 DEBUG:  name: unnamed; blockState:       STARTED; 
state: INPROGR, xid/subid/cid: 370293/1/0, nestlvl: 1, children: <>
2009-01-26 07:14:07 DEBUG:  autovacuum: processing database "postgres"
2009-01-26 07:14:07 DEBUG:  StartTransaction
2009-01-26 07:14:07 DEBUG:  name: unnamed; blockState:       DEFAULT; 
state: INPROGR, xid/subid/cid: 370294/1/0, nestlvl: 1, children: <>
2009-01-26 07:14:07 DEBUG:  pg_authid: vac: 0 (threshold 500), anl: 0 
(threshold 250)
2009-01-26 07:14:07 DEBUG:  pg_statistic: vac: 0 (threshold 560), anl: 0 
(threshold 280)
2009-01-26 07:14:07 DEBUG:  pg_type: vac: 0 (threshold 548), anl: 0 
(threshold 274)
2009-01-26 07:14:07 DEBUG:  pg_attribute: vac: 0 (threshold 826), anl: 0 
(threshold 413)
2009-01-26 07:14:07 DEBUG:  pg_proc: vac: 0 (threshold 886), anl: 0 
(threshold 443)
2009-01-26 07:14:07 DEBUG:  pg_class: vac: 0 (threshold 541), anl: 0 
(threshold 270)
2009-01-26 07:14:07 DEBUG:  pg_autovacuum: vac: 0 (threshold 500), anl: 
0 (threshold 250)
2009-01-26 07:14:07 DEBUG:  pg_inherits: vac: 0 (threshold 500), anl: 0 
(threshold 250)
2009-01-26 07:14:07 DEBUG:  pg_index: vac: 0 (threshold 515), anl: 0 
(threshold 258)
2009-01-26 07:14:07 DEBUG:  pg_operator: vac: 0 (threshold 633), anl: 0 
(threshold 317)
2009-01-26 07:14:07 DEBUG:  pg_opclass: vac: 0 (threshold 520), anl: 0 
(threshold 260)
2009-01-26 07:14:07 DEBUG:  pg_am: vac: 0 (threshold 501), anl: 0 
(threshold 250)
2009-01-26 07:14:07 DEBUG:  pg_amop: vac: 0 (threshold 589), anl: 0 
(threshold 295)
2009-01-26 07:14:07 DEBUG:  pg_amproc: vac: 0 (threshold 545), anl: 0 
(threshold 272)
2009-01-26 07:14:07 DEBUG:  pg_language: vac: 0 (threshold 501), anl: 0 
(threshold 250)
2009-01-26 07:14:07 DEBUG:  pg_aggregate: vac: 0 (threshold 523), anl: 0 
(threshold 261)
2009-01-26 07:14:07 DEBUG:  pg_rewrite: vac: 0 (threshold 515), anl: 0 
(threshold 257)
2009-01-26 07:14:07 DEBUG:  pg_trigger: vac: 0 (threshold 501), anl: 0 
(threshold 250)
2009-01-26 07:14:07 DEBUG:  pg_cast: vac: 0 (threshold 551), anl: 0 
(threshold 276)
2009-01-26 07:14:07 DEBUG:  pg_namespace: vac: 0 (threshold 501), anl: 0 
(threshold 251)
2009-01-26 07:14:07 DEBUG:  pg_conversion: vac: 0 (threshold 525), anl: 
0 (threshold 262)
2009-01-26 07:14:07 DEBUG:  pg_tablespace: vac: 0 (threshold 500), anl: 
0 (threshold 250)
2009-01-26 07:14:07 DEBUG:  pg_shdepend: vac: 0 (threshold 500), anl: 0 
(threshold 250)
2009-01-26 07:14:07 DEBUG:  pg_shdescription: vac: 0 (threshold 500), 
anl: 0 (threshold 250)
2009-01-26 07:14:07 DEBUG:  pg_database: vac: 0 (threshold 500), anl: 0 
(threshold 250)
2009-01-26 07:14:07 DEBUG:  pg_auth_members: vac: 0 (threshold 500), 
anl: 0 (threshold 250)
2009-01-26 07:14:07 DEBUG:  CommitTransaction
2009-01-26 07:14:07 DEBUG:  name: unnamed; blockState:       STARTED; 
state: INPROGR, xid/subid/cid: 370294/1/0, nestlvl: 1, children: <>
2009-01-26 07:14:07 DEBUG:  proc_exit(0)
2009-01-26 07:14:07 DEBUG:  shmem_exit(0)
2009-01-26 07:14:07 DEBUG:  exit(0)
2009-01-26 07:14:07 DEBUG:  reaping dead processes
2009-01-26 07:14:07 DEBUG:  waiting on 4 children
2009-01-26 07:14:07 DEBUG:  waiting on 3 children
2009-01-26 07:14:07 DEBUG:  forked new backend, pid=4220 socket=568
2009-01-26 07:14:07 DEBUG:  proc_exit(0)
2009-01-26 07:14:07 DEBUG:  shmem_exit(0)
2009-01-26 07:14:07 DEBUG:  exit(0)
2009-01-26 07:14:07 DEBUG:  reaping dead processes
2009-01-26 07:14:07 DEBUG:  waiting on 4 children
2009-01-26 07:14:07 DEBUG:  server process (PID 4220) exited with exit 
code 0
2009-01-26 07:14:07 DEBUG:  waiting on 3 children
2009-01-26 07:15:07 DEBUG:  StartTransaction
2009-01-26 07:15:07 DEBUG:  name: unnamed; blockState:       DEFAULT; 
state: INPROGR, xid/subid/cid: 370295/1/0, nestlvl: 1, children: <>
2009-01-26 07:15:07 DEBUG:  CommitTransaction
2009-01-26 07:15:07 DEBUG:  name: unnamed; blockState:       STARTED; 
state: INPROGR, xid/subid/cid: 370295/1/0, nestlvl: 1, children: <>
2009-01-26 07:15:07 DEBUG:  autovacuum: processing database "postgres"
2009-01-26 07:15:07 DEBUG:  StartTransaction
2009-01-26 07:15:07 DEBUG:  name: unnamed; blockState:       DEFAULT; 
state: INPROGR, xid/subid/cid: 370296/1/0, nestlvl: 1, children: <>
2009-01-26 07:15:07 DEBUG:  pg_authid: vac: 0 (threshold 500), anl: 0 
(threshold 250)
2009-01-26 07:15:07 DEBUG:  pg_statistic: vac: 0 (threshold 560), anl: 0 
(threshold 280)
2009-01-26 07:15:07 DEBUG:  pg_type: vac: 0 (threshold 548), anl: 0 
(threshold 274)
2009-01-26 07:15:07 DEBUG:  pg_attribute: vac: 0 (threshold 826), anl: 0 
(threshold 413)
2009-01-26 07:15:07 DEBUG:  pg_proc: vac: 0 (threshold 886), anl: 0 
(threshold 443)
2009-01-26 07:15:07 DEBUG:  pg_class: vac: 0 (threshold 541), anl: 0 
(threshold 270)
2009-01-26 07:15:07 DEBUG:  pg_autovacuum: vac: 0 (threshold 500), anl: 
0 (threshold 250)
2009-01-26 07:15:07 DEBUG:  pg_inherits: vac: 0 (threshold 500), anl: 0 
(threshold 250)
2009-01-26 07:15:07 DEBUG:  pg_index: vac: 0 (threshold 515), anl: 0 
(threshold 258)
2009-01-26 07:15:07 DEBUG:  pg_operator: vac: 0 (threshold 633), anl: 0 
(threshold 317)
2009-01-26 07:15:07 DEBUG:  pg_opclass: vac: 0 (threshold 520), anl: 0 
(threshold 260)
2009-01-26 07:15:07 DEBUG:  pg_am: vac: 0 (threshold 501), anl: 0 
(threshold 250)
2009-01-26 07:15:07 DEBUG:  pg_amop: vac: 0 (threshold 589), anl: 0 
(threshold 295)
2009-01-26 07:15:07 DEBUG:  pg_amproc: vac: 0 (threshold 545), anl: 0 
(threshold 272)
2009-01-26 07:15:07 DEBUG:  pg_language: vac: 0 (threshold 501), anl: 0 
(threshold 250)
2009-01-26 07:15:07 DEBUG:  pg_aggregate: vac: 0 (threshold 523), anl: 0 
(threshold 261)
2009-01-26 07:15:07 DEBUG:  pg_rewrite: vac: 0 (threshold 515), anl: 0 
(threshold 257)
2009-01-26 07:15:07 DEBUG:  pg_trigger: vac: 0 (threshold 501), anl: 0 
(threshold 250)
2009-01-26 07:15:07 DEBUG:  pg_cast: vac: 0 (threshold 551), anl: 0 
(threshold 276)
2009-01-26 07:15:07 DEBUG:  pg_namespace: vac: 0 (threshold 501), anl: 0 
(threshold 251)
2009-01-26 07:15:07 DEBUG:  pg_conversion: vac: 0 (threshold 525), anl: 
0 (threshold 262)
2009-01-26 07:15:07 DEBUG:  pg_tablespace: vac: 0 (threshold 500), anl: 
0 (threshold 250)
2009-01-26 07:15:07 DEBUG:  pg_shdepend: vac: 0 (threshold 500), anl: 0 
(threshold 250)
2009-01-26 07:15:07 DEBUG:  pg_shdescription: vac: 0 (threshold 500), 
anl: 0 (threshold 250)
2009-01-26 07:15:07 DEBUG:  pg_database: vac: 0 (threshold 500), anl: 0 
(threshold 250)
2009-01-26 07:15:07 DEBUG:  pg_auth_members: vac: 0 (threshold 500), 
anl: 0 (threshold 250)
2009-01-26 07:15:07 DEBUG:  CommitTransaction
2009-01-26 07:15:07 DEBUG:  name: unnamed; blockState:       STARTED; 
state: INPROGR, xid/subid/cid: 370296/1/0, nestlvl: 1, children: <>
2009-01-26 07:15:07 DEBUG:  proc_exit(0)
2009-01-26 07:15:07 DEBUG:  shmem_exit(0)
2009-01-26 07:15:07 DEBUG:  exit(0)
2009-01-26 07:15:08 DEBUG:  reaping dead processes
2009-01-26 07:15:08 DEBUG:  waiting on 4 children
2009-01-26 07:15:08 DEBUG:  waiting on 3 children

Guido Barosio wrote:
> Robert,
>
>    As a first attempt, set log_min_duration_statement to 0 in your
> configuration file and restart the service, do not forget to tail your
> log file in order to understand what is going on. There are other
> parameter that will help you identify potential problems, all of them
> related with log_*. RTFM! :)
>
>   Another tip, Process Explorer, a tool for Windows that shows all
> the stuff running in windows such as the Linux 'ps' program but with a
> fancy UI. It's a freeware tool, so try it. It should present you  the
> PID of the offending process; this PID plus some SQL magic and the
> pg_stat_* tables will let you know what's going on.
>
> 2 cents
> gb.-

In response to

pgsql-novice by date

Next:From: LukasDate: 2009-01-27 10:10:34
Subject: Re: IN vs =
Previous:From: Tom LaneDate: 2009-01-26 21:33:25
Subject: Re: IN vs =

Privacy Policy | About PostgreSQL
Copyright © 1996-2014 The PostgreSQL Global Development Group