statistics collector process is thrashing my cpu

William Temperley wrote:

Dear All

Sometimes postgres.exe will thrash one of the cores and won't stop
until I kill the process. I know it's the statistics collector as I
get this message when I kill the process:
"statistics collector process (PID 172) exited with exit code 1"
Nothing other than this app is accessing my PG server.

I'm developing a web mapping application which retrieves point data
via multiple statements like this:

select xmlelement(name "amr:mapFeatureType",
xmlattributes(featuretype as name),xmlagg(
xmlelement(name "amr:mapFeature",
xmlforest(y(the_geom) as "amr:latitude", x(the_geom) as
"amr:longitude", lable as "amr:description"))
))
from (select featuretype, the_geom, lable from poi
WHERE the_geom && setsrid(
'BOX3D(-5.625 52.482780222078205,0
55.7765730186677)'::box3d, 4326)
and featureclass = 'layer3'
limit 15) as ss
group by ss.featuretype

I don't even know why this process would run anyway, as I haven't
updated the database for weeks (it's only a dummy dataset).

I'm also getting hundreds of these messages in a few hours work:
2008-05-08 09:22:56 BST LOG: loaded library
"$libdir/plugins/plugin_debugger.dll"
2008-05-08 09:22:56 BST LOG: loaded library
"$libdir/plugins/plugin_debugger.dll"
Why would it load it twice within the same second?

You get one of those everytime you start a new backend.

Select version() - "PostgreSQL 8.3.1, compiled by Visual C++ build
1400" Machine - XP sp2, core 2 duo 7250 laptop

The only non 'out of the box' setting I've changed in postgresql.conf
is: log_statement = 'all'

Any ideas why this might be happening, and how I can stop it?

It'd be interesting to know what the stats collector is actually doing.
Could you, using Process Explorer or a debugger, get a stack trace from
that process while it's in the trashing state?

//Magnus

Any ideas why this might be happening, and how I can stop it?

It'd be interesting to know what the stats collector is actually doing.
Could you, using Process Explorer or a debugger, get a stack trace from
that process while it's in the trashing state?

//Magnus

Certainly, but I'll have to wait 'til it does it again, it doesn't
happen all the time.
What would you like to know from Process Explorer?

Will T

William Temperley wrote:

Any ideas why this might be happening, and how I can stop it?

It'd be interesting to know what the stats collector is actually
doing. Could you, using Process Explorer or a debugger, get a stack
trace from that process while it's in the trashing state?

//Magnus

Certainly, but I'll have to wait 'til it does it again, it doesn't
happen all the time.
What would you like to know from Process Explorer?

Get the backtrace from hung process. Find the process in the list, open
it. Go to the tab "Threads", find the thread that's using a lot of CPU
(or at least has a lot of ocntext switchs), and click the Stack button.
That should give you a window with a backtrace.

//Magnus

On Thu, May 8, 2008 at 6:14 PM, Magnus Hagander <magnus@hagander.net> wrote:

William Temperley wrote:

Any ideas why this might be happening, and how I can stop it?

It'd be interesting to know what the stats collector is actually
doing. Could you, using Process Explorer or a debugger, get a stack
trace from that process while it's in the trashing state?

//Magnus

Certainly, but I'll have to wait 'til it does it again, it doesn't
happen all the time.
What would you like to know from Process Explorer?

Get the backtrace from hung process. Find the process in the list, open
it. Go to the tab "Threads", find the thread that's using a lot of CPU
(or at least has a lot of ocntext switchs), and click the Stack button.
That should give you a window with a backtrace.

//Magnus

Ok, got the little blighter. Below are 4 stack traces taken at random times.
Doesn't seem to be doing much I/O (16 reads and 167 other in 3 hours).
The memory usage seems to be static (3.7MB) even with high database
usage (vacuum, read, update).

ntoskrnl.exe+0x584d
ntoskrnl.exe!MmCreateMdl+0x28a
hal.dll+0x2ef2
ntoskrnl.exe!IoCheckFunctionAccess+0x1d8a6
ntoskrnl.exe!RtlFindUnicodePrefix+0x29
ntoskrnl.exe!MmPrefetchPages+0xc59
ntoskrnl.exe!ZwSetSystemInformation+0x23
ntdll.dll!KiFastSystemCallRet
mswsock.dll+0x6e2d
mswsock.dll+0x6039
WS2_32.dll!WSAAddressToStringW+0x1c9
WS2_32.dll!WSAAddressToStringW+0x113
WS2_32.dll!WSAEventSelect+0x2f
postgres.exe!RemoveTSConfiguration+0x151837
postgres.exe!RemoveTSConfiguration+0x15a586

ntoskrnl.exe!ZwAssignProcessToJobObject+0x15
ntoskrnl.exe!MmCreateMdl+0x28a
hal.dll!HalClearSoftwareInterrupt+0x342
hal.dll!HalRequestSoftwareInterrupt+0x3c
ntoskrnl.exe!SeCaptureSecurityDescriptor+0x41e
ntoskrnl.exe!ZwSetSystemInformation+0x23
ntdll.dll!KiFastSystemCallRet
postgres.exe!RemoveTSConfiguration+0x151788
postgres.exe!RemoveTSConfiguration+0x15a586

ntoskrnl.exe!ZwAssignProcessToJobObject+0x15
ntoskrnl.exe!MmCreateMdl+0x28a
hal.dll!HalClearSoftwareInterrupt+0x342
ntoskrnl.exe!IoCheckFunctionAccess+0x1d8a6
ntoskrnl.exe!RtlFindUnicodePrefix+0x29
ntoskrnl.exe!MmPrefetchPages+0xc59
ntoskrnl.exe!ZwSetSystemInformation+0x23
ntdll.dll!KiFastSystemCallRet
mswsock.dll+0x6e2d
mswsock.dll+0x6039
WS2_32.dll!WSAAddressToStringW+0x1c9
WS2_32.dll!WSAAddressToStringW+0x113
WS2_32.dll!WSAEventSelect+0x2f
postgres.exe!RemoveTSConfiguration+0x151837
postgres.exe!RemoveTSConfiguration+0x15a586

ntoskrnl.exe!ZwAssignProcessToJobObject+0x15
ntoskrnl.exe!MmCreateMdl+0x28a
hal.dll!HalClearSoftwareInterrupt+0x342
mswsock.dll+0x5f38
mswsock.dll+0x6e75
mswsock.dll+0x6e2d
mswsock.dll+0x6039
WS2_32.dll!WSAAddressToStringW+0x1c9
WS2_32.dll!WSAAddressToStringW+0x113
WS2_32.dll!WSAEventSelect+0x2f
postgres.exe!RemoveTSConfiguration+0x151837
postgres.exe!RemoveTSConfiguration+0x15a586

Hope that means more to you than me,

Will

William Temperley wrote:

On Thu, May 8, 2008 at 6:14 PM, Magnus Hagander <magnus@hagander.net>
wrote:

William Temperley wrote:

Any ideas why this might be happening, and how I can stop it?

It'd be interesting to know what the stats collector is actually
doing. Could you, using Process Explorer or a debugger, get a
stack trace from that process while it's in the trashing state?

//Magnus

Certainly, but I'll have to wait 'til it does it again, it doesn't
happen all the time.
What would you like to know from Process Explorer?

Get the backtrace from hung process. Find the process in the list,
open it. Go to the tab "Threads", find the thread that's using a
lot of CPU (or at least has a lot of ocntext switchs), and click
the Stack button. That should give you a window with a backtrace.

//Magnus

Ok, got the little blighter. Below are 4 stack traces taken at random
times. Doesn't seem to be doing much I/O (16 reads and 167 other in 3
hours). The memory usage seems to be static (3.7MB) even with high
database usage (vacuum, read, update).

Hmm. They all show the same function, but it's not a function being
used in the stats collector. I think I missed a step in the
instructions - you need to download the symbols for the server (make
sure you get the same version!) and configure process explorer to use
those (IIRC, it can use detached symbols), then do the same things
again. Sorry for missing that in the first instructions!

//Magus

On Fri, May 9, 2008 at 2:55 PM, Magnus Hagander <magnus@hagander.net> wrote:

William Temperley wrote:

On Thu, May 8, 2008 at 6:14 PM, Magnus Hagander <magnus@hagander.net>
wrote:

William Temperley wrote:

Any ideas why this might be happening, and how I can stop it?

It'd be interesting to know what the stats collector is actually
doing. Could you, using Process Explorer or a debugger, get a
stack trace from that process while it's in the trashing state?

//Magnus

Certainly, but I'll have to wait 'til it does it again, it doesn't
happen all the time.
What would you like to know from Process Explorer?

Get the backtrace from hung process. Find the process in the list,
open it. Go to the tab "Threads", find the thread that's using a
lot of CPU (or at least has a lot of ocntext switchs), and click
the Stack button. That should give you a window with a backtrace.

//Magnus

Ok, got the little blighter. Below are 4 stack traces taken at random
times. Doesn't seem to be doing much I/O (16 reads and 167 other in 3
hours). The memory usage seems to be static (3.7MB) even with high
database usage (vacuum, read, update).

Hmm. They all show the same function, but it's not a function being
used in the stats collector. I think I missed a step in the
instructions - you need to download the symbols for the server (make
sure you get the same version!) and configure process explorer to use
those (IIRC, it can use detached symbols), then do the same things
again. Sorry for missing that in the first instructions!

//Magus

Hi Magnus,

Sorry I didn't reply earlier (away on holiday). I can't seem to get the
symbols to work -
I can't find any way to attach symbols in process explorer, however windows
debugger can. I've done this:
1. Downloaded the symbols (8.3.1!)
2. Set the path for windows debugger to find them
3. Atttached to the process (offending PID found from process explorer)

Then I get this message:

Microsoft (R) Windows Debugger Version 6.9.0003.113 X86
Copyright (c) Microsoft Corporation. All rights reserved.

*** wait with pending attach
Symbol search path is: C:\Temp\pgsymbols
Executable search path is:
ModLoad: 00400000 007da000 C:\Program
Files\PostgreSQL\8.3\bin\postgres.exe
...........Lots more modload lines .....
(eb4.3e4): Break instruction exception - code 80000003 (first chance)
eax=7ffd4000 ebx=00000001 ecx=00000002 edx=00000003 esi=00000004
edi=00000005
eip=7c901230 esp=0235ffcc ebp=0235fff4 iopl=0 nv up ei pl zr na pe
nc
cs=001b ss=0023 ds=0023 es=0023 fs=0038 gs=0000
efl=00000246
*** ERROR: Symbol file could not be found. Defaulted to export symbols for
C:\WINDOWS\system32\ntdll.dll -
ntdll!DbgBreakPoint:
7c901230 cc int 3

Any ideas?

Will

William Temperley wrote:

On Fri, May 9, 2008 at 2:55 PM, Magnus Hagander <magnus@hagander.net>
wrote:

William Temperley wrote:

On Thu, May 8, 2008 at 6:14 PM, Magnus Hagander
<magnus@hagander.net> wrote:

William Temperley wrote:

Any ideas why this might be happening, and how I can stop
it?

It'd be interesting to know what the stats collector is
actually doing. Could you, using Process Explorer or a
debugger, get a stack trace from that process while it's in
the trashing state?

//Magnus

Certainly, but I'll have to wait 'til it does it again, it
doesn't happen all the time.
What would you like to know from Process Explorer?

Get the backtrace from hung process. Find the process in the
list, open it. Go to the tab "Threads", find the thread that's
using a lot of CPU (or at least has a lot of ocntext switchs),
and click the Stack button. That should give you a window with
a backtrace.

//Magnus

Ok, got the little blighter. Below are 4 stack traces taken at
random times. Doesn't seem to be doing much I/O (16 reads and 167
other in 3 hours). The memory usage seems to be static (3.7MB)
even with high database usage (vacuum, read, update).

Hmm. They all show the same function, but it's not a function being
used in the stats collector. I think I missed a step in the
instructions - you need to download the symbols for the server (make
sure you get the same version!) and configure process explorer to
use those (IIRC, it can use detached symbols), then do the same
things again. Sorry for missing that in the first instructions!

//Magus

Hi Magnus,

Sorry I didn't reply earlier (away on holiday). I can't seem to get
the symbols to work -
I can't find any way to attach symbols in process explorer, however
windows debugger can. I've done this:
1. Downloaded the symbols (8.3.1!)
2. Set the path for windows debugger to find them
3. Atttached to the process (offending PID found from process
explorer)

Then I get this message:

Microsoft (R) Windows Debugger Version 6.9.0003.113 X86
Copyright (c) Microsoft Corporation. All rights reserved.

*** wait with pending attach
Symbol search path is: C:\Temp\pgsymbols
Executable search path is:
ModLoad: 00400000 007da000 C:\Program
Files\PostgreSQL\8.3\bin\postgres.exe
...........Lots more modload lines .....
(eb4.3e4): Break instruction exception - code 80000003 (first chance)
eax=7ffd4000 ebx=00000001 ecx=00000002 edx=00000003 esi=00000004
edi=00000005
eip=7c901230 esp=0235ffcc ebp=0235fff4 iopl=0 nv up ei pl zr
na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=0038 gs=0000
efl=00000246
*** ERROR: Symbol file could not be found. Defaulted to export
symbols for C:\WINDOWS\system32\ntdll.dll -
ntdll!DbgBreakPoint:
7c901230 cc int 3

Any ideas?

Actually, that does not mean it's broken. It just says it can't find
symbols for where it was - but if this was in ntdll, that's fine. If
you bring up the full stacktrace at this point, does it contain proper
data?

//Magnus

William Temperley wrote:

On Fri, May 9, 2008 at 2:55 PM, Magnus Hagander <magnus@hagander.net>
wrote:

William Temperley wrote:

On Thu, May 8, 2008 at 6:14 PM, Magnus Hagander
<magnus@hagander.net> wrote:

William Temperley wrote:

Any ideas why this might be happening, and how I can stop
it?

It'd be interesting to know what the stats collector is
actually doing. Could you, using Process Explorer or a
debugger, get a stack trace from that process while it's in
the trashing state?

//Magnus

Certainly, but I'll have to wait 'til it does it again, it
doesn't happen all the time.
What would you like to know from Process Explorer?

Get the backtrace from hung process. Find the process in the
list, open it. Go to the tab "Threads", find the thread that's
using a lot of CPU (or at least has a lot of ocntext switchs),
and click the Stack button. That should give you a window with
a backtrace.

//Magnus

Ok, got the little blighter. Below are 4 stack traces taken at
random times. Doesn't seem to be doing much I/O (16 reads and 167
other in 3 hours). The memory usage seems to be static (3.7MB)
even with high database usage (vacuum, read, update).

Hmm. They all show the same function, but it's not a function being
used in the stats collector. I think I missed a step in the
instructions - you need to download the symbols for the server (make
sure you get the same version!) and configure process explorer to
use those (IIRC, it can use detached symbols), then do the same
things again. Sorry for missing that in the first instructions!

//Magus

Hi Magnus,

Sorry I didn't reply earlier (away on holiday). I can't seem to get
the symbols to work -
I can't find any way to attach symbols in process explorer, however
windows debugger can. I've done this:
1. Downloaded the symbols (8.3.1!)
2. Set the path for windows debugger to find them
3. Atttached to the process (offending PID found from process
explorer)

Then I get this message:

Microsoft (R) Windows Debugger Version 6.9.0003.113 X86
Copyright (c) Microsoft Corporation. All rights reserved.

*** wait with pending attach
Symbol search path is: C:\Temp\pgsymbols
Executable search path is:
ModLoad: 00400000 007da000 C:\Program
Files\PostgreSQL\8.3\bin\postgres.exe
...........Lots more modload lines .....
(eb4.3e4): Break instruction exception - code 80000003 (first chance)
eax=7ffd4000 ebx=00000001 ecx=00000002 edx=00000003 esi=00000004
edi=00000005
eip=7c901230 esp=0235ffcc ebp=0235fff4 iopl=0 nv up ei pl zr
na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=0038 gs=0000
efl=00000246
*** ERROR: Symbol file could not be found. Defaulted to export
symbols for C:\WINDOWS\system32\ntdll.dll -
ntdll!DbgBreakPoint:
7c901230 cc int 3

Any ideas?

Actually, that does not mean it's broken. It just says it can't find
symbols for where it was - but if this was in ntdll, that's fine. If
you bring up the full stacktrace at this point, does it contain proper
data?

//Magnus

Mystery solved, it was PCTools antivirus causing the problem.
It seems pctlsp.dll was interfering when the stats collector process -
Prolonged stepping into the hung process showed pctlsp.dll popping its head
up now and then, and absolutely no postgres code was run at all. It was all
happening within ntdll!LdrShutdownThread.

Uninstalling PCTools solved the problem and restored my faith in Postgres!

Will T

William Temperley wrote:

Actually, that does not mean it's broken. It just says it can't find
symbols for where it was - but if this was in ntdll, that's fine. If
you bring up the full stacktrace at this point, does it contain
proper data?

//Magnus

Mystery solved, it was PCTools antivirus causing the problem.
It seems pctlsp.dll was interfering when the stats collector process -
Prolonged stepping into the hung process showed pctlsp.dll popping
its head up now and then, and absolutely no postgres code was run at
all. It was all happening within ntdll!LdrShutdownThread.

Uninstalling PCTools solved the problem and restored my faith in
Postgres!

Ah, thanks for letting us know.

//Magnus