Bernd Wipf
23-Aug-2005, 08:00 PM
Hi all,
We are having some problems when using EurekaLog within an IntraWeb
application in ISAPI mode, resulting in occasional access violations within
the IIS helper process W3WP.exe, followed by a "session not found" message
displayed in the browser because of the crash.
We tried an analysis with "iisstate", which gave us the following stack dump
for the offending thread:
==========
Thread ID: 4
System Thread ID: 1b9c
Kernel Time: 0:0:0.0
User Time: 0:0:0.46
Thread Type: HTTP Compression Thread
# ChildEBP RetAddr
WARNING: Stack unwind information not available. Following frames may be
wrong.
00 00c9fdf4 025f1d1a AVWebJournal+0x2b4b: System.Move+0x0013 from map file
01 00c9fe04 5a322991 0x25f1d1a
02 00c9fe24 5a3968ff w3isapi!ProcessIsapiRequest+0x214
03 00c9fe58 5a3967e0 w3core!W3_ISAPI_HANDLER::IsapiDoWork+0x3fd
04 00c9fe78 5a396764 w3core!W3_ISAPI_HANDLER::DoWork+0xb0
05 00c9fe98 5a3966f4 w3core!W3_HANDLER::MainDoWork+0x16e
06 00c9fea8 5a3966ae w3core!W3_CONTEXT::ExecuteCurrentHandler+0x53
07 00c9fec4 5a396648 w3core!W3_CONTEXT::ExecuteHandler+0x51
08 00c9feec 5a392264 w3core!W3_STATE_HANDLE_REQUEST::DoWork+0x9a
09 00c9ff10 5a3965ea w3core!W3_MAIN_CONTEXT::DoWork+0xa6
0a 00c9ff2c 5a36169f w3core!W3_MAIN_CONTEXT::OnNewRequest+0x55
0b 00c9ff38 5a361650 w3dt!UL_NATIVE_REQUEST::DoStateProcess+0x48
0c 00c9ff48 5a3616ca w3dt!UL_NATIVE_REQUEST::DoWork+0x7f
0d 00c9ff5c 5a3024de w3dt!OverlappedCompletionRoutine+0x1a
0e 00c9ff8c 5a3026bc W3TP!THREAD_POOL_DATA::ThreadPoolThread+0x73
0f 00c9ffa0 5a301db9 W3TP!THREAD_POOL_DATA::ThreadPoolThread+0x24
10 00c9ffb8 77e66063 W3TP!THREAD_MANAGER::ThreadManagerThread+0x39
11 00c9ffec 00000000 kernel32!BaseThreadStart+0x34
==========
We tried some further analysis with WinDbg, using the minidump that "MS
Error Reporting" temporarily generates before sending the report to
Microsoft, and took a closer look on what is going on at address 0x25f1d1a.
Our findings:
- Dynamic code near 0x25f1d1a calls EHook.InternalUnhookProc
- InternalUnhookProc calls EHook.WriteMem
- WriteMem then calls System.Move with obviously bad parameters, causing the
access violation.
The code near 0x25f1d1a is actually code that calls following procedures in
succession, probably in order to temporarily disable a procedure hook:
- EHook.InternalUnhookProc
- OurWebApp!HttpExtensionProc
- EHook.InternalHookProc
The problem can be reproduced with a quite high chance by sending many
parallel requests to download auxiliary files using URL's of the form
"http://ourServer/ourAppDir/OurWebApp.dll/files/something.gif" after
recycling the corresponding application pool. Quite often the problem does
not show up, and once a dozen request or more have been successfully
processed the problem will no longer show up.
Deactivating EurekaLog does solve the problem.
Are we doing something wrong, or did we hit a bug? To me this looks like a
threading problem with the code that temporarily disables a procedure hook.
Our configuration:
Windows Server 2003 SP1
IIS 6, with current security patches
Delphi Version 7.0 (not 7.01 or 7.1)
IntaWeb 7.2.41
EurekaLog 5.0.2
Bernd Wipf
EDS Information Business GmbH
Zurich, Switzerland
We are having some problems when using EurekaLog within an IntraWeb
application in ISAPI mode, resulting in occasional access violations within
the IIS helper process W3WP.exe, followed by a "session not found" message
displayed in the browser because of the crash.
We tried an analysis with "iisstate", which gave us the following stack dump
for the offending thread:
==========
Thread ID: 4
System Thread ID: 1b9c
Kernel Time: 0:0:0.0
User Time: 0:0:0.46
Thread Type: HTTP Compression Thread
# ChildEBP RetAddr
WARNING: Stack unwind information not available. Following frames may be
wrong.
00 00c9fdf4 025f1d1a AVWebJournal+0x2b4b: System.Move+0x0013 from map file
01 00c9fe04 5a322991 0x25f1d1a
02 00c9fe24 5a3968ff w3isapi!ProcessIsapiRequest+0x214
03 00c9fe58 5a3967e0 w3core!W3_ISAPI_HANDLER::IsapiDoWork+0x3fd
04 00c9fe78 5a396764 w3core!W3_ISAPI_HANDLER::DoWork+0xb0
05 00c9fe98 5a3966f4 w3core!W3_HANDLER::MainDoWork+0x16e
06 00c9fea8 5a3966ae w3core!W3_CONTEXT::ExecuteCurrentHandler+0x53
07 00c9fec4 5a396648 w3core!W3_CONTEXT::ExecuteHandler+0x51
08 00c9feec 5a392264 w3core!W3_STATE_HANDLE_REQUEST::DoWork+0x9a
09 00c9ff10 5a3965ea w3core!W3_MAIN_CONTEXT::DoWork+0xa6
0a 00c9ff2c 5a36169f w3core!W3_MAIN_CONTEXT::OnNewRequest+0x55
0b 00c9ff38 5a361650 w3dt!UL_NATIVE_REQUEST::DoStateProcess+0x48
0c 00c9ff48 5a3616ca w3dt!UL_NATIVE_REQUEST::DoWork+0x7f
0d 00c9ff5c 5a3024de w3dt!OverlappedCompletionRoutine+0x1a
0e 00c9ff8c 5a3026bc W3TP!THREAD_POOL_DATA::ThreadPoolThread+0x73
0f 00c9ffa0 5a301db9 W3TP!THREAD_POOL_DATA::ThreadPoolThread+0x24
10 00c9ffb8 77e66063 W3TP!THREAD_MANAGER::ThreadManagerThread+0x39
11 00c9ffec 00000000 kernel32!BaseThreadStart+0x34
==========
We tried some further analysis with WinDbg, using the minidump that "MS
Error Reporting" temporarily generates before sending the report to
Microsoft, and took a closer look on what is going on at address 0x25f1d1a.
Our findings:
- Dynamic code near 0x25f1d1a calls EHook.InternalUnhookProc
- InternalUnhookProc calls EHook.WriteMem
- WriteMem then calls System.Move with obviously bad parameters, causing the
access violation.
The code near 0x25f1d1a is actually code that calls following procedures in
succession, probably in order to temporarily disable a procedure hook:
- EHook.InternalUnhookProc
- OurWebApp!HttpExtensionProc
- EHook.InternalHookProc
The problem can be reproduced with a quite high chance by sending many
parallel requests to download auxiliary files using URL's of the form
"http://ourServer/ourAppDir/OurWebApp.dll/files/something.gif" after
recycling the corresponding application pool. Quite often the problem does
not show up, and once a dozen request or more have been successfully
processed the problem will no longer show up.
Deactivating EurekaLog does solve the problem.
Are we doing something wrong, or did we hit a bug? To me this looks like a
threading problem with the code that temporarily disables a procedure hook.
Our configuration:
Windows Server 2003 SP1
IIS 6, with current security patches
Delphi Version 7.0 (not 7.01 or 7.1)
IntaWeb 7.2.41
EurekaLog 5.0.2
Bernd Wipf
EDS Information Business GmbH
Zurich, Switzerland