pgstat wait timeout - Mailing list pgsql-bugs

From Robert Schnabel
Subject pgstat wait timeout
Date
Msg-id 4A54B7A9.8070601@missouri.edu
Whole thread Raw
Responses Re: pgstat wait timeout  (Tom Lane <tgl@sss.pgh.pa.us>)
List pgsql-bugs
I've been having an issue for about 5 months now and after upgrading to
8.4 did not fix it I figured I'd try this list.  I tried the perform
list a while back but no bites.

My system: Windows XP64 SP2, dual Opteron 2218, 12G ram, PostgreSQL
8.4.  I am the only person using the postgres server and I only have one
db.  Yesterday I dumped from 8.3.7, installed 8.4 and restored my db to
8.4.  Everything works fine except the problem that I've had since about
January.  I didn't have this problem until I upgraded to 8.3.6 (I
think).  It did the same thing with 8.3.7.  Here is what's happening...

 From a fresh server restart I have one process that will run one
processor 100% essentially forever.  (I've let it go for about a week
just to see if it would ever stop and it didn't).  Attached is a text
dump from ProcessExplorer.  I have highlighted the relevant lines with
****.  Also attached is the current postgresql log after a server
restart.  You can see from the log that about every 70 seconds there is
an entry "WARNING:  pgstat wait timeout".  This will go on forever.
 From the ProcessExplorer file, the offending process is 2384.  From
within ProcessExplorer, if I suspend 2384 the log entries do not cease.
>From within ProcessExplorer, if I attach the debugger it will
immediately terminate the process and then restart with a new process
id.  For the last 5 months since I noticed the problem I have resorted
to using ProcessExplorer to suspend the process, thus freeing up a CPU,
and just let the log files get cluttered.  I assume this is a bug??  Any
help would be greatly appreciated.

Bob

2009-07-08 09:36:46 CDTLOG:  database system was shut down at 2009-07-08 09:36:17 CDT
2009-07-08 09:36:46 CDTLOG:  database system is ready to accept connections
2009-07-08 09:36:46 CDTLOG:  autovacuum launcher started
2009-07-08 09:37:54 CDTWARNING:  pgstat wait timeout
2009-07-08 09:39:02 CDTWARNING:  pgstat wait timeout
2009-07-08 09:40:10 CDTWARNING:  pgstat wait timeout
2009-07-08 09:41:18 CDTWARNING:  pgstat wait timeout
2009-07-08 09:42:26 CDTWARNING:  pgstat wait timeout
2009-07-08 09:43:34 CDTWARNING:  pgstat wait timeout
2009-07-08 09:44:42 CDTWARNING:  pgstat wait timeout
2009-07-08 09:45:50 CDTWARNING:  pgstat wait timeout
2009-07-08 09:46:58 CDTWARNING:  pgstat wait timeout
2009-07-08 09:48:06 CDTWARNING:  pgstat wait timeout
2009-07-08 09:49:14 CDTWARNING:  pgstat wait timeout
2009-07-08 09:50:22 CDTWARNING:  pgstat wait timeout
2009-07-08 09:51:30 CDTWARNING:  pgstat wait timeout
2009-07-08 09:52:38 CDTWARNING:  pgstat wait timeout
Process    PID    CPU    I/O Read Bytes    I/O Write Bytes    Virtual Size    Private Bytes    Description    Image
Type
System Idle Process    0    74.24    0    0    0 K    0 K        64-bit
 Interrupts    n/a        0    0    0 K    0 K    Hardware Interrupts    64-bit
 DPCs    n/a        0    0    0 K    0 K    Deferred Procedure Calls    64-bit
 System    4        218,393,621    10,932,220,446    2,432 K    44 K        64-bit
  smss.exe    384        20,985,656    74,760    4,584 K    232 K    Windows NT Session Manager    64-bit
   csrss.exe    444        375,627,261    0    65,360 K    3,036 K    Client Server Runtime Process    64-bit
   winlogon.exe    476        106,686,679    17,121,929    123,908 K    14,340 K    Windows NT Logon Application
64-bit
    services.exe    524        131,355,967    603,742,217    345,956 K    9,136 K    Services and Controller app
64-bit
     ati2evxx.exe    720        1,325,656    30,068    54,868 K    3,588 K    ATI External Event Utility EXE Module
64-bit
     svchost.exe    756        1,270,175    4,172    34,516 K    1,820 K    Generic Host Process for Win32 Services
64-bit
      wmiprvse.exe    2896        2,567,620    36,166    44,404 K    4,284 K    WMI    64-bit
     svchost.exe    808        6,992,228    180    41,388 K    3,424 K    Generic Host Process for Win32 Services
64-bit
     svchost.exe    860        6,779,745,807    2,788,840,736    586,720 K    33,952 K    Generic Host Process for
Win32Services    64-bit 
     svchost.exe    908        1,401,852    20    76,460 K    7,568 K    Generic Host Process for Win32 Services
64-bit
     svchost.exe    956        13,674,280    441,651,836    76,032 K    5,616 K    Generic Host Process for Win32
Services   64-bit 
     ccSetMgr.exe    1052        5,569,680    1,171,440    45,940 K    4,844 K    Symantec Settings Manager Service
32-bit
     ccEvtMgr.exe    1108        635,388    1,124    49,640 K    5,556 K    Symantec Event Manager Service    32-bit
     spoolsv.exe    1308        69,642,369    42,404,956    84,644 K    8,592 K    Spooler SubSystem App    64-bit
     svchost.exe    1428        263,500    11,568    54,848 K    3,376 K    Generic Host Process for Win32 Services
64-bit
     StorServ.exe    1472        388,457,885    521,622,223    1,299,740 K    236,988 K    Adaptec Storage Manager
Service   64-bit 
     AppleMobileDeviceService.exe    1524        752,192    12    30,128 K    2,904 K    Apple Mobile Device Service
32-bit
     mDNSResponder.exe    1564        729,122    12    40,352 K    2,504 K    Bonjour Service    32-bit
     DefWatch.exe    1584        832,800,561    728    68,256 K    2,772 K    Virus Definition Daemon    32-bit
     svchost.exe    1688        9,075,388    23,454,760    26,732 K    1,408 K    Generic Host Process for Win32
Services   64-bit 
     inetinfo.exe    1764        2,349,668    595,418    95,440 K    9,196 K    Internet Information Services    64-bit
     LS_Service.exe    1840        14,710,593    3,517,615    333,780 K    59,928 K    Aligner License Server Service
32-bit 
     NMSAccessU.exe    1880        54    12    30,016 K    1,064 K        32-bit
     ShadowProtectSvc.exe    2072        0    0    22,116 K    1,844 K    ShadowProtect Backup Agent    32-bit
      ShadowProtectSvc.exe    2112        146,098,131    17,339,642    75,940 K    10,220 K    ShadowProtect Backup
Agent   32-bit 
     svchost.exe    2300        563,790    1,820    46,532 K    5,164 K    Generic Host Process for Win32 Services
64-bit
     ImageManager.exe    2364        3,267,195    424    233,200 K    19,084 K    ShadowProtect ImageManager Service
32-bit
     Rtvscan.exe    2464        64,432,426,259    7,861,117,858    262,292 K    63,084 K    Symantec AntiVirus
32-bit
     ups.exe    2516        10,167,434    1,832,256    21,464 K    1,200 K    UPS Service    64-bit
     vsnapvss.exe    2636        448,714    460,764    26,512 K    1,476 K    StorageCraft Volume Snapshot VSS Provider
  32-bit 
     nSvcAppFlt.exe    2724        676,544    332    79,148 K    5,052 K    app_filter Module    64-bit
     nSvcIp.exe    2788        278    332    82,068 K    4,932 K    NVIDIA Corporation    64-bit
     alg.exe    1400        38,675    38,735    31,152 K    2,232 K    Application Layer Gateway Service    64-bit
     iPodService.exe    3020        192,562    476    47,540 K    3,532 K    iPodService Module    32-bit
     DkService.exe    4464        463,237,733,929    1,097,297,675    226,108 K    32,952 K    Diskeeper Service
64-bit
     pg_ctl.exe    5828        64,269    136    57,956 K    3,028 K    pg_ctl - starts/stops/restarts the PostgreSQL
server   32-bit 
      postgres.exe    5476        146,072    1,353    321,084 K    5,760 K    PostgreSQL Server    32-bit
       postgres.exe    2168        113,608    222    50,484 K    4,240 K    PostgreSQL Server    32-bit
**************************************************************************************************************
       postgres.exe    2384    25.00    114,053    69    46,968 K    4,904 K    PostgreSQL Server    32-bit
**************************************************************************************************************
       postgres.exe    2936        113,366    0    316,192 K    5,560 K    PostgreSQL Server    32-bit
       postgres.exe    6080        113,366    0    316,192 K    5,560 K    PostgreSQL Server    32-bit
       postgres.exe    6092        113,598    66    316,192 K    5,584 K    PostgreSQL Server    32-bit
    lsass.exe    536        399,803,814    427,394,628    56,644 K    7,112 K    LSA Shell    64-bit
    ati2evxx.exe    1040        200,932    3,648    62,416 K    4,352 K    ATI External Event Utility EXE Module
64-bit
explorer.exe    4000        418,832,000    116,507,626    246,788 K    39,412 K    Windows Explorer    64-bit
 RTHDCPL.EXE    3048        7,350,834    587,365    104,828 K    26,352 K    Realtek HD Audio Control Panel    32-bit
 atiptaxx.exe    2804        1,312,476    638,596    67,656 K    4,700 K    ATI Desktop Control Panel    64-bit
 ctfmon.exe    3164        468,124    160    52,780 K    1,356 K    CTF Loader    64-bit
  ctfmon.exe    3544        123,068    116    40,952 K    756 K    CTF Loader    32-bit
 taskmgr.exe    2876        1,352,248    1,236    64,660 K    2,868 K    Windows TaskManager    64-bit
 cmd.exe    3472        11,683    0    36,332 K    2,080 K    Windows Command Processor    64-bit
  bash.exe    4304        20,080    0    22,680 K    1,780 K        32-bit
   bash.exe    5092        380,743    91,018    451,204 K    3,216 K        32-bit
 cmd.exe    4264        11,165    0    36,332 K    2,080 K    Windows Command Processor    64-bit
  bash.exe    2580        18,756    0    340,632 K    10,680 K        32-bit
   bash.exe    1940        390,899    102,498    451,204 K    3,280 K        32-bit
 cmd.exe    4724        10,913    0    36,332 K    2,080 K    Windows Command Processor    64-bit
  bash.exe    4548        18,756    0    20,376 K    1,716 K        32-bit
   bash.exe    4028        132,747    78,882    451,204 K    3,216 K        32-bit
 cmd.exe    2432        10,913    0    36,332 K    2,080 K    Windows Command Processor    64-bit
  bash.exe    3212        18,666    0    20,376 K    1,716 K        32-bit
   bash.exe    3108        104,613    50,838    451,204 K    3,216 K        32-bit
 cmd.exe    4656        9,533    0    36,332 K    2,080 K    Windows Command Processor    64-bit
  bash.exe    4196        18,364    0    22,680 K    1,780 K        32-bit
   bash.exe    4460        220,181    111,190    451,204 K    3,216 K        32-bit
 explorer.exe    5056        12,197,091,858    12,167,473,174    127,600 K    14,368 K    Windows Explorer    64-bit
  EXCEL.EXE    1328        29,437,550    78,190,827    276,820 K    70,352 K    Microsoft Office Excel    32-bit
  MSACCESS.EXE    4568        162,201,634    10,354,462    276,104 K    37,212 K    Microsoft Office Access    32-bit
 firefox.exe    1352        83,485,220    66,711,513    184,028 K    75,892 K    Firefox    32-bit
 thunderbird.exe    4836        50,227,717    323,547    171,924 K    49,312 K    Mozilla Thunderbird    32-bit
 procexp.exe    3804        317,442    879,368    57,044 K    2,008 K    Sysinternals Process Explorer    32-bit
  procexp64.exe    804    0.76    462,208    13,969    139,320 K    22,424 K    Sysinternals Process Explorer    64-bit
hpwuSchd2.exe    2688        1,142,465    232    56,484 K    1,996 K    Hewlett-Packard Product Assistant    32-bit
WDBtnMgr.exe    608        105,786,020    3,024    121,928 K    16,824 K        32-bit
ccApp.exe    3468        1,449,300    464    61,236 K    4,804 K    Symantec User Session    32-bit
VPTray.exe    2868        2,004,507    812    84,776 K    4,792 K    Symantec AntiVirus    32-bit
iTunesHelper.exe    1896        182,536    348    61,968 K    3,632 K    iTunesHelper Module    32-bit
jusched.exe    3724        967,598    5,515    62,984 K    2,808 K    Java(TM) Platform SE binary    32-bit
acrotray.exe    3816        600,052    116    56,640 K    2,376 K    AcroTray    32-bit
cmd.exe    2172        450,073    0    36,328 K    2,044 K    Windows Command Processor    64-bit
ssh.exe    1988        9,974,054    9,666,324    451,568 K    4,392 K        32-bit
sftp.exe    4516        6,778,399,946    6,745,827,371    506,852 K    8,380 K        32-bit
ssh.exe    4376        268,039,407    6,796,074,016    454,960 K    5,664 K        32-bit
ssh.exe    516        809,154    775,556    451,568 K    4,076 K        32-bit
ssh.exe    3464        1,191,872    1,158,332    451,568 K    4,328 K        32-bit
ssh.exe    832        1,017,376    983,836    451,568 K    4,328 K        32-bit
WZQKPICK.EXE    1796        184    232    54,668 K    1,784 K    WinZip Executable    32-bit
splwow64.exe    1772        22,774    320    66,356 K    2,024 K    Thunking Spooler APIS from 32 to 64 Process
64-bit
realsched.exe    5696        13,916    1,605    61,104 K    2,168 K    RealNetworks Scheduler    32-bit

Process: postgres.exe Pid: 2384

Type    Name
Desktop    \Default
Directory    \BaseNamedObjects
Directory    \KnownDlls32
Directory    \KnownDlls32
Directory    \KnownDlls
**************************************************************************************************************
Event    \BaseNamedObjects\pgident(2384): postgres: stats collector process
**************************************************************************************************************
File    \Device\NamedPipe\Win32Pipes.00001564.00000002
File    \Device\Afd
File    \Device\Udp
File    \Device\Afd
File    \Device\KsecDD
File    D:\Program Files\PostgreSQL\8.4\data
File    \Device\WMIDataDevice
File    \Device\WMIDataDevice
File    C:\WINDOWS\WinSxS\x86_Microsoft.VC80.CRT_1fc8b3b9a1e18e3b_8.0.50727.3053_x-ww_b80fa8ca
File    C:\WINDOWS\WinSxS\x86_Microsoft.VC80.CRT_1fc8b3b9a1e18e3b_8.0.50727.3053_x-ww_b80fa8ca
File    C:\WINDOWS\WinSxS\x86_Microsoft.VC80.CRT_1fc8b3b9a1e18e3b_8.0.50727.3053_x-ww_b80fa8ca
File    D:\Program Files\PostgreSQL\8.4\data
File    \Device\NamedPipe\pgsignal_2384
File    \Device\Afd
Key    HKLM\SYSTEM\ControlSet001\Control\Nls\Language Groups
Key    HKLM\SYSTEM\ControlSet001\Control\Nls\Locale\Alternate Sorts
Key    HKLM\SYSTEM\ControlSet001\Control\Nls\Locale
Key    HKLM\SYSTEM\ControlSet001\Services\WinSock2\Parameters\NameSpace_Catalog5
Key    HKLM\SYSTEM\ControlSet001\Services\WinSock2\Parameters\Protocol_Catalog9
Key    HKLM
Key    HKLM\SOFTWARE\Wow6432Node\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\DllNXOptions
Key    HKLM\SOFTWARE\Wow6432Node\Microsoft\Windows NT\CurrentVersion\Image File Execution Options
KeyedEvent    \KernelObjects\CritSecOutOfMemoryEvent
KeyedEvent    \KernelObjects\CritSecOutOfMemoryEvent
Process    postgres.exe(5476)
Process    postgres.exe(2384)
Section    \BaseNamedObjects\Global/PostgreSQL:D:/Program Files/PostgreSQL/8.4/data
Thread    postgres.exe(2384): 5304
Thread    postgres.exe(2384): 2420
Thread    postgres.exe(2384): 2420
WindowStation    \Windows\WindowStations\Service-0x2-4f0855fa$

pgsql-bugs by date:

Previous
From: Dave Page
Date:
Subject: Re: Unknown winsock error 10061
Next
From: Dave Page
Date:
Subject: Re: Unknown winsock error 10061