Agh. Webservices app goes AWOL.
am 08.11.2007 13:03:36 von mrmooseheadHi, an unashamed beg for help here.
Have a C# webservices app that serves XMLDocuments back to a c#
service at regular intervals.
Authentication is on a login, get ticketid, store clientinfo object in
static cache, return ticketid to client in SOAPHeader.
Subsequent calls to other bits of the webservice pass in a SOAPHeader
with the ticketid in - we check it is authenticated from the cache and
bob's your uncle. (Static cache array is locked whilst accessing) -
the client app requests this page every minute or so. The request
takes about 700ms to process.
Has been working fine, but introduced some new procecssing in the
generation of the return XML that seems to be causing some issues.
it runs for 20 hours or so fine, but then goes awry - returns an error
saying not authenticated - that's fine, we reauthenticate, get another
ticket, then call the webmethod - but says swe aren't authenticated,
so we reuthenticate, get ticket, then call etc etc. for 10 attempts,
at which point the client gives up, returns -1 to environment. Service
restarts after a couple of minnutes but the cycle now continues.
Stopping and starting WWW publishing service makes no difference - it
just won't work now.
In the system event log just before the failures start is an entry it
hasn't appeared until this time):
A worker process with process id of '4508' serving application pool
'DefaultAppPool' has requested a recycle because the worker process
reached its allowed processing time limit.
>From this point, everything goes wrong.
Last time the only way I could get it to work again was to physically
replace all the DLLs.
I have tried to use iisstate to glean some more information on what's
happening, but that looks like an arcane science to me - here it is,
if it helps. (There are other things running on the server as well,
but triedd to make sure that the thing that is failing was set off at
same time as state trace)
Any information, clues, solutions you can give me would be greatly
appreciated.
Regards,
M
***********************
Starting new log output
IISState version 3.3.1
Thu Nov 08 11:37:37 2007
OS = Windows 2003 Server
Executable: inetinfo.exe
PID = 1780
Note: Thread times are formatted as HH:MM:SS.ms
***********************
Thread ID: 0
System Thread ID: 6f8
Kernel Time: 0:0:0.15
User Time: 0:0:0.0
Thread Type: Other
# ChildEBP RetAddr
00 0006f99c 7c821b84 ntdll!KiFastSystemCallRet
01 0006f9a0 77e4189f ntdll!NtReadFile+0xc
02 0006fa08 77f795ab kernel32!ReadFile+0x16c
03 0006fa34 77f7943c ADVAPI32!ScGetPipeInput+0x2a
04 0006faa8 77fb2ec9 ADVAPI32!ScDispatcherLoop+0x51
05 0006fcec 010027be ADVAPI32!StartServiceCtrlDispatcherA+0x93
06 0006fe1c 01002969 inetinfo!StartDispatchTable+0x277
07 0006ff44 0100339d inetinfo!main+0x117
08 0006ffc0 77e523e5 inetinfo!mainCRTStartup+0x12f
09 0006fff0 00000000 kernel32!BaseProcessStart+0x23
Thread ID: 1
System Thread ID: 6fc
Kernel Time: 0:0:0.0
User Time: 0:0:0.0
Thread Status: Thread is in a WAIT state.
Thread Type: Other
# ChildEBP RetAddr
00 007efe14 7c822124 ntdll!KiFastSystemCallRet
01 007efe18 77e6bad8 ntdll!NtWaitForSingleObject+0xc
02 007efe88 77e6ba42 kernel32!WaitForSingleObjectEx+0xac
03 007efe9c 01002ebf kernel32!WaitForSingleObject+0x12
04 007effb8 77e6608b inetinfo!W3SVCThreadEntry+0x3d
05 007effec 00000000 kernel32!BaseThreadStart+0x34
Thread ID: 2
System Thread ID: 700
Kernel Time: 0:0:0.46
User Time: 0:0:0.62
Thread Status: Thread is in a WAIT state.
Thread Type: Other
# ChildEBP RetAddr
00 0082fcb8 7c822124 ntdll!KiFastSystemCallRet
01 0082fcbc 77e6bad8 ntdll!NtWaitForSingleObject+0xc
02 0082fd2c 77e6ba42 kernel32!WaitForSingleObjectEx+0xac
03 0082fd40 649f26a4 kernel32!WaitForSingleObject+0x12
04 0082fd68 010024b3 iisadmin!ServiceEntry+0x28a
05 0082ffa4 77f79348 inetinfo!InetinfoStartService+0x2cc
06 0082ffb8 77e6608b ADVAPI32!ScSvcctrlThreadA+0x21
07 0082ffec 00000000 kernel32!BaseThreadStart+0x34
Thread ID: 3
System Thread ID: 760
Kernel Time: 0:0:0.78
User Time: 0:0:0.0
Thread Type: Other
# ChildEBP RetAddr
00 00bfff9c 7c821364 ntdll!KiFastSystemCallRet
01 00bfffa0 7c81fe26 ntdll!NtDelayExecution+0xc
02 00bfffb8 77e6608b ntdll!RtlpTimerThread+0x47
03 00bfffec 00000000 kernel32!BaseThreadStart+0x34
Thread ID: 4
System Thread ID: 774
Kernel Time: 0:0:0.0
User Time: 0:0:0.46
Thread Status: Thread is in a WAIT state.
Thread Type: Other
# ChildEBP RetAddr
00 00d0feac 7c822114 ntdll!KiFastSystemCallRet
01 00d0feb0 77e67143 ntdll!NtWaitForMultipleObjects+0xc
02 00d0ff58 77e6109d kernel32!WaitForMultipleObjectsEx+0x11a
03 00d0ff74 56f951ef kernel32!WaitForMultipleObjects+0x18
04 00d0ffa0 56f96a06 COADMIN!NOTIFY_CONTEXT::GetNextContext+0x67
05 00d0ffb8 77e6608b COADMIN!NOTIFY_CONTEXT::NotifyThreadProc+0x5f
06 00d0ffec 00000000 kernel32!BaseThreadStart+0x34
Thread ID: 5
System Thread ID: 3d8
Kernel Time: 0:0:0.46
User Time: 0:0:0.31
Thread Status: Thread is in a WAIT state.
Thread Type: Other
# ChildEBP RetAddr
00 0158fbb8 7c822114 ntdll!KiFastSystemCallRet
01 0158fbbc 77e67143 ntdll!NtWaitForMultipleObjects+0xc
02 0158fc64 7739cd38 kernel32!WaitForMultipleObjectsEx+0x11a
03 0158fcc0 7738e3b1 USER32!RealMsgWaitForMultipleObjectsEx+0x141
04 0158fcdc 6c7d63d5 USER32!MsgWaitForMultipleObjects+0x1f
05 0158fd28 6930e66a INFOCOMM!IIS_SERVICE::StartServiceOperation+0x231
06 0158fd68 010024b3 ftpsvc2!ServiceEntry+0xae
07 0158ffa4 77f79348 inetinfo!InetinfoStartService+0x2cc
08 0158ffb8 77e6608b ADVAPI32!ScSvcctrlThreadA+0x21
09 0158ffec 00000000 kernel32!BaseThreadStart+0x34
Thread ID: 6
System Thread ID: 804
Kernel Time: 0:0:0.0
User Time: 0:0:0.0
Thread Type: HTTP Listener
# ChildEBP RetAddr
00 017bff50 7c821bf4 ntdll!KiFastSystemCallRet
01 017bff54 77e66142 ntdll!NtRemoveIoCompletion+0xc
02 017bff80 63ec7235 kernel32!GetQueuedCompletionStatus+0x29
03 017bffb4 7c81a8e0 ISATQ!AtqPoolThread+0x40
Thread ID: 7
System Thread ID: 808
Kernel Time: 0:0:0.0
User Time: 0:0:0.0
Thread Type: HTTP Listener
# ChildEBP RetAddr
00 017fff50 7c821bf4 ntdll!KiFastSystemCallRet
01 017fff54 77e66142 ntdll!NtRemoveIoCompletion+0xc
02 017fff80 63ec7235 kernel32!GetQueuedCompletionStatus+0x29
03 017fffb4 7c81a8e0 ISATQ!AtqPoolThread+0x40
Thread ID: 8
System Thread ID: 810
Kernel Time: 0:0:0.0
User Time: 0:0:0.0
Thread Type: Possible ASP page. Possible DCOM activity
Executing Page: ASP.dll symbols not found. Unable to locate ASP page.
Continuing with other analysis.
No remote call being made
# ChildEBP RetAddr
00 019ffe18 7c821c54 ntdll!KiFastSystemCallRet
01 019ffe1c 77c7538c ntdll!ZwReplyWaitReceivePortEx+0xc
02 019fff84 77c5778f RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0x198
03 019fff8c 77c5f7dd RPCRT4!RecvLotsaCallsWrapper+0xd
04 019fffac 77c5de88 RPCRT4!BaseCachedThreadRoutine+0x9d
05 019fffb8 77e6608b RPCRT4!ThreadStartRoutine+0x1b
06 019fffec 00000000 kernel32!BaseThreadStart+0x34
Thread ID: 9
System Thread ID: 818
Kernel Time: 0:0:0.15
User Time: 0:0:0.0
Thread Status: Thread is in a WAIT state.
Thread Type: Other
# ChildEBP RetAddr
00 01a7fcec 7c822114 ntdll!KiFastSystemCallRet
01 01a7fcf0 7c83acfd ntdll!NtWaitForMultipleObjects+0xc
02 01a7ffb8 77e6608b ntdll!RtlpWaitThread+0x161
03 01a7ffec 00000000 kernel32!BaseThreadStart+0x34
Thread ID: 10
System Thread ID: 820
Kernel Time: 0:0:8.859
User Time: 0:0:30.812
Thread Type: Possible ASP page. Possible DCOM activity
Executing Page: ASP.dll symbols not found. Unable to locate ASP page.
Continuing with other analysis.
No remote call being made
# ChildEBP RetAddr
00 01bbfe18 7c821c54 ntdll!KiFastSystemCallRet
01 01bbfe1c 77c7538c ntdll!ZwReplyWaitReceivePortEx+0xc
02 01bbff84 77c5778f RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0x198
03 01bbff8c 77c5f7dd RPCRT4!RecvLotsaCallsWrapper+0xd
04 01bbffac 77c5de88 RPCRT4!BaseCachedThreadRoutine+0x9d
05 01bbffb8 77e6608b RPCRT4!ThreadStartRoutine+0x1b
06 01bbffec 00000000 kernel32!BaseThreadStart+0x34
Thread ID: 11
System Thread ID: 83c
Kernel Time: 0:0:0.46
User Time: 0:0:0.62
Thread Status: Thread is in a WAIT state.
Thread Type: Other
# ChildEBP RetAddr
00 01bffec4 7c822114 ntdll!KiFastSystemCallRet
01 01bffec8 77e67143 ntdll!NtWaitForMultipleObjects+0xc
02 01bfff70 69308dc4 kernel32!WaitForMultipleObjectsEx+0x11a
03 01bfffb8 77e6608b ftpsvc2!PASV_ACCEPT_CONTEXT::AcceptThreadFunc
+0x33
04 01bfffec 00000000 kernel32!BaseThreadStart+0x34
Thread ID: 12
System Thread ID: 84c
Kernel Time: 0:0:0.0
User Time: 0:0:0.0
Thread Status: Thread is in a WAIT state.
Thread Type: HTTP Listener
# ChildEBP RetAddr
00 01c8fe0c 7c822124 ntdll!KiFastSystemCallRet
01 01c8fe10 71b23a09 ntdll!NtWaitForSingleObject+0xc
02 01c8fe4c 71b23a52 mswsock!SockWaitForSingleObject+0x19d
03 01c8ff3c 71c0470c mswsock!WSPSelect+0x380
04 01c8ff8c 63ec4696 WS2_32!select+0xb9
05 01c8ffb4 63ec4700 ISATQ!ATQ_BMON_SET::BmonThreadFunc+0x22
06 01c8ffb8 77e6608b ISATQ!BmonThreadFunc+0x9
07 63ec4700 8b575600 kernel32!BaseThreadStart+0x34
WARNING: Frame IP not in any known module. Following frames may be
wrong.
08 04c2c033 00000000 0x8b575600
Thread ID: 13
System Thread ID: 15cc
Kernel Time: 0:0:0.0
User Time: 0:0:0.0
Thread Type: Possible ASP page. Possible DCOM activity
Executing Page: ASP.dll symbols not found. Unable to locate ASP page.
Continuing with other analysis.
No remote call being made
# ChildEBP RetAddr
00 00bbfeac 7c821bf4 ntdll!KiFastSystemCallRet
01 00bbfeb0 77e66142 ntdll!NtRemoveIoCompletion+0xc
02 00bbfedc 77c604c3 kernel32!GetQueuedCompletionStatus+0x29
03 00bbff18 77c60655 RPCRT4!COMMON_ProcessCalls+0xa1
04 00bbff84 77c5f9f1 RPCRT4!LOADABLE_TRANSPORT::ProcessIOEvents+0x117
05 00bbff8c 77c5f7dd RPCRT4!ProcessIOEventsWrapper+0xd
06 00bbffac 77c5de88 RPCRT4!BaseCachedThreadRoutine+0x9d
07 00bbffb8 77e6608b RPCRT4!ThreadStartRoutine+0x1b
08 00bbffec 00000000 kernel32!BaseThreadStart+0x34
Thread ID: 14
System Thread ID: 3e0
Kernel Time: 0:0:0.15
User Time: 0:0:0.78
Thread Type: Possible ASP page. Possible DCOM activity
Executing Page: ASP.dll symbols not found. Unable to locate ASP page.
Continuing with other analysis.
No remote call being made
# ChildEBP RetAddr
00 00c3fe18 7c821c54 ntdll!KiFastSystemCallRet
01 00c3fe1c 77c7538c ntdll!ZwReplyWaitReceivePortEx+0xc
02 00c3ff84 77c5778f RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0x198
03 00c3ff8c 77c5f7dd RPCRT4!RecvLotsaCallsWrapper+0xd
04 00c3ffac 77c5de88 RPCRT4!BaseCachedThreadRoutine+0x9d
05 00c3ffb8 77e6608b RPCRT4!ThreadStartRoutine+0x1b
06 00c3ffec 00000000 kernel32!BaseThreadStart+0x34
Thread ID: 15
System Thread ID: 1624
Kernel Time: 0:0:0.0
User Time: 0:0:0.0
Thread Type: Other
# ChildEBP RetAddr
00 016fff70 7c821bf4 ntdll!KiFastSystemCallRet
01 016fff74 7c83ad75 ntdll!NtRemoveIoCompletion+0xc
02 016fffb8 77e6608b ntdll!RtlpWorkerThread+0x3d
03 016fffec 00000000 kernel32!BaseThreadStart+0x34
Thread ID: 16
System Thread ID: 105c
Kernel Time: 0:0:0.0
User Time: 0:0:0.0
Thread Type: Other
# ChildEBP RetAddr
00 0150ff70 7c821bf4 ntdll!KiFastSystemCallRet
01 0150ff74 7c83ad75 ntdll!NtRemoveIoCompletion+0xc
02 0150ffb8 77e6608b ntdll!RtlpWorkerThread+0x3d
03 0150ffec 00000000 kernel32!BaseThreadStart+0x34
Closing open log file C:\iisstate\output\IISState-1780.log
Opened log file 'C:\iisstate\output\IISState-1780.log'