Обсуждение: statistics collector process is thrashing my cpu

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?

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?

Thanks,

Will T

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

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

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