Re: Idle processes chewing up CPU? - Mailing list pgsql-general

Hi Craig,

Sorry, I had the stack trace so I thought it was enough. I'll make sure the
debug environment is set up and post the full stack traces again.

-Brendan


-----Original Message-----
From: Craig Ringer [mailto:craig@postnewspapers.com.au]
Sent: Wednesday, 5 August 2009 4:35 PM
To: Brendan Hill
Cc: 'Tom Lane'; pgsql-general@postgresql.org
Subject: RE: [GENERAL] Idle processes chewing up CPU?

On Wed, 2009-08-05 at 15:26 +1000, Brendan Hill wrote:

> I copied a few of the stack traces (at the end of this email), it kept
> changing each time I looked.

Yep, that's to be expected. If the process is busy, unless it's in a
_REALLY_ simple infinite loop, it'll be looping through some non-trivial
sequence of function calls. Thus, most stack traces will be different.

Unfortunately, you don't appear to have set up your debugging
environment, so your stack traces aren't annotated with any sort of
symbolic information that might tell the reader what's actually
happening. The numeric offsets can be converted to symbolic names if you
know the _EXACT_ version of the module (eg "hal.dll") in question, but
you haven't provided that, and even if you did it's a pain to do.

If you did set your symbol path, might you have an overzealous software
firewall that's interfering with requests to the symbol server. Make
sure that HTTP (port 80) access to msdl.microsoft.com for windbg.exe and
procexp.exe is unimpeded, or download the symbol bundle for your OS
(warning: huge download) from
http://www.microsoft.com/whdc/devtools/debugging/symbolpkg.mspx .

Because your symbol path doesn't appear to be configured there's no
guarantee the symbols for postgres.exe are right either, and more
importantly there's no "depth" to the trace; it doesn't show the call
path within postgres / libeay32 / etc .

Take this trace, for example.

ntkrnlpa.exe+0x8dafe
ntkrnlpa.exe+0x29a82
ntkrnlpa.exe+0x33198
hal.dll+0x6199
hal.dll+0x63d9
hal.dll+0x6577
hal.dll+0x3902
postgres.exe!process_implied_equality+0x18d50e

process_implied_equality(...) from backend/optimizer/plan/initsplan.c is
deep in the query planner, and is "currently used only when an
EquivalenceClass is found to contain pseudoconstants".

It's not going to be calling into hal.dll - not, at least, without a
fairly long call chain between it and hal.dll . So we can't trust that
postgres was even in the "process_implied_equality" function when it
called into hal.dll and if it was we don't have any idea how it got
there. The call trace is basically useless.

(New section added to wiki article for this:
http://wiki.postgresql.org/wiki/Getting_a_stack_trace_of_a_running_PostgreSQ
L_backend_on_Windows#How_to_make_sure_a_stack_trace_is_useful
)


A stack trace that includes symbols for the kernel / HAL calls should
look something like this:

ntkrnlpa.exe!KiSwapContext+0x2f
ntkrnlpa.exe!KiSwapThread+0x8a
ntkrnlpa.exe!KeWaitForSingleObject+0x1c2
ntkrnlpa.exe!KiSuspendThread+0x18
ntkrnlpa.exe!KiDeliverApc+0x124
ntkrnlpa.exe!KiSwapThread+0xa8
ntkrnlpa.exe!KeWaitForMultipleObjects+0x284
ntkrnlpa.exe!NtWaitForMultipleObjects+0x297
ntkrnlpa.exe!KiFastCallEntry+0xfc
ntdll.dll!KiFastSystemCallRet
ntdll.dll!ZwWaitForMultipleObjects+0xc
kernel32.dll!WaitForMultipleObjectsEx+0x12c
postgres.exe!pgwin32_waitforsinglesocket+0x1f0
postgres.exe!pgwin32_recv+0x90
postgres.exe!secure_read+0x17d
postgres.exe!pq_recvbuf+0x71
postgres.exe!pq_getbyte+0x15
postgres.exe!SocketBackend+0x6
postgres.exe!PostgresMain+0xbe8
postgres.exe!BackendRun+0x204
postgres.exe!SubPostmasterMain+0x224
postgres.exe!main+0x177
postgres.exe!__tmainCRTStartup+0x10f
kernel32.dll!BaseProcessStart+0x23


See how it has "ModuleNames!SymbolicNames+offsets" instead of just
"ModuleNames+offsets" ?




--
Craig Ringer