ANCM: _ASSERT(... *phWaitHandle == NULL) failure

[jhkimnew]

1. Put a sleep time with 10 seconds and configure startupTimeLimit with 5
2. Send a request

EXPECTED:

No assertion failure

ACTUAL:

Assertion failure happens from the line of "_ASSERT(... *phWaitHandle == NULL)".

Attached the call stack below

0:008> kn
# Child-SP          RetAddr           Call Site
00 000000d6`527fc7e0 00007ffa`21ee2291 aspnetcorerh!SERVER_PROCESS::RegisterProcessWait+0x7f [d:\gitroot\iisintegration\src\requesthandler\outofprocess\serverprocess.cxx @ 1937] 
01 000000d6`527fc830 00007ffa`21ee2ab5 aspnetcorerh!SERVER_PROCESS::PostStartCheck+0x1a1 [d:\gitroot\iisintegration\src\requesthandler\outofprocess\serverprocess.cxx @ 684] 
02 000000d6`527fc920 00007ffa`21edf5a3 aspnetcorerh!SERVER_PROCESS::StartProcess+0x425 [d:\gitroot\iisintegration\src\requesthandler\outofprocess\serverprocess.cxx @ 975] 
03 000000d6`527fcd70 00007ffa`21eddcef aspnetcorerh!PROCESS_MANAGER::GetProcess+0x6a3 [d:\gitroot\iisintegration\src\requesthandler\outofprocess\processmanager.cxx @ 240] 
04 000000d6`527fd120 00007ffa`21ed66ec aspnetcorerh!OUT_OF_PROCESS_APPLICATION::GetProcess+0x3f [d:\gitroot\iisintegration\src\requesthandler\outofprocess\outprocessapplication.cpp @ 54] 
05 000000d6`527fd150 00007ffa`23c589e3 aspnetcorerh!FORWARDING_HANDLER::OnExecuteRequestHandler+0x25c [d:\gitroot\iisintegration\src\requesthandler\outofprocess\forwardinghandler.cpp @ 122] 
06 000000d6`527ff430 00007ffa`308f3224 aspnetcore!ASPNET_CORE_PROXY_MODULE::OnExecuteRequestHandler+0x343 [d:\gitroot\iisintegration\src\aspnetcore\src\proxymodule.cxx @ 168] 
07 000000d6`527ff790 00007ffa`308f46e8 iiscore+0x3224
08 000000d6`527ff7d0 00007ffa`308fc006 iiscore+0x46e8
09 000000d6`527ff8e0 00007ffa`308f6ce2 iiscore+0xc006
0a 000000d6`527ff940 00007ffa`308fc293 iiscore+0x6ce2
0b 000000d6`527ffc50 00007ffa`34941349 iiscore+0xc293
0c 000000d6`527ffc90 00007ffa`36402092 w3dt!UlAtqFreeContext+0x119
0d 000000d6`527ffcf0 00007ffa`36401ff3 W3TP!THREAD_POOL::BindIoCompletionCallback+0x192
0e 000000d6`527ffd40 00007ffa`36401f7e W3TP!THREAD_POOL::BindIoCompletionCallback+0xf3
0f 000000d6`527ffd80 00007ffa`342f1d54 W3TP!THREAD_POOL::BindIoCompletionCallback+0x7e
10 000000d6`527ffdc0 00007ffa`3ba413d2 vfbasics+0x11d54
11 000000d6`527ffe00 00007ffa`3de75444 KERNEL32!BaseThreadInitThunk+0x22
12 000000d6`527ffe30 00000000`00000000 ntdll!RtlUserThreadStart+0x34

Eventually, I got this exception error

(4f4.eac): Access violation - code c0000005 (!!! second chance !!!)
aspnetcorerh!SERVER_PROCESS::HandleProcessExit+0x6f:
00007ffa`21ee4e2f f00fb10a        lock cmpxchg dword ptr [rdx],ecx ds:000000d6`5c2e5e38=????????
0:009> kn
 # Child-SP          RetAddr           Call Site
00 000000d6`5387f1e0 00007ffa`21ee4ca6 aspnetcorerh!SERVER_PROCESS::HandleProcessExit+0x6f [d:\gitroot\iisintegration\src\requesthandler\outofprocess\serverprocess.cxx @ 1976] 
01 000000d6`5387f270 00007ffa`342ecfdb aspnetcorerh!SERVER_PROCESS::ProcessHandleCallback+0x36 [d:\gitroot\iisintegration\src\requesthandler\outofprocess\serverprocess.cxx @ 1926] 
02 000000d6`5387f2b0 00007ffa`3de7d79b vfbasics+0xcfdb
03 000000d6`5387f330 00007ffa`3de798da ntdll!RtlDetectHeapLeaks+0xdb
04 000000d6`5387f390 00007ffa`3de98d51 ntdll!LdrInitializeThunk+0xa2a
05 000000d6`5387f3d0 00007ffa`3ba413d2 ntdll!RtlFreeUnicodeString+0x1c51
06 000000d6`5387f7b0 00007ffa`3de75444 KERNEL32!BaseThreadInitThunk+0x22
07 000000d6`5387f7e0 00000000`00000000 ntdll!RtlUserThreadStart+0x34

[jhkimnew]

The assertion failure can be fixed with reinitializing m_hProcessWaitHandle with NULL value on the StartProcess() as the following:

HRESULT
SERVER_PROCESS::StartProcess(
    VOID
)
{
…

    while (dwRetryCount > 0)
    {
        m_hProcessWaitHandle = NULL;

However, after fixing the assertion failure issue, when I retried the same scenario, I ran into this AV.
Please take a look at this AV issue as well.

Attached the stack of the AV.

Application "\??\c:\program files\dotnet\dotnet.exe" found in cache
Application "\??\c:\program files\dotnet\dotnet.exe" found in cache
(e84.1920): Access violation - code c0000005 (first chance)
First chance exceptions are reported before any exception handling.
This exception may be expected and handled.
*** WARNING: Unable to verify checksum for C:\Windows\system32\inetsrv\aspnetcorerh.dll
aspnetcorerh!SERVER_PROCESS::HandleProcessExit+0x6f:
00007ffa`212e4e3f f00fb10a        lock cmpxchg dword ptr [rdx],ecx ds:00000009`2e12fe38=????????
WARNING: Unable to find source file with matching checksum.  Found 'c:\temp\requesthandler\outofprocess\serverprocess.cxx' with mismatch!
0:009> kn
# Child-SP          RetAddr           Call Site
00 00000009`2568f850 00007ffa`212e4cb6 aspnetcorerh!SERVER_PROCESS::HandleProcessExit+0x6f [d:\gitroot\iisintegration\src\requesthandler\outofprocess\serverprocess.cxx @ 1978] 
*** ERROR: Module load completed but symbols could not be loaded for C:\Windows\SYSTEM32\vfbasics.dll
01 00000009`2568f8e0 00007ffa`24a5cfdb aspnetcorerh!SERVER_PROCESS::ProcessHandleCallback+0x36 [d:\gitroot\iisintegration\src\requesthandler\outofprocess\serverprocess.cxx @ 1928] 
02 00000009`2568f920 00007ffa`3de7d79b vfbasics+0xcfdb
03 00000009`2568f9a0 00007ffa`3de798da ntdll!RtlDetectHeapLeaks+0xdb
04 00000009`2568fa00 00007ffa`3de98d51 ntdll!LdrInitializeThunk+0xa2a
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for C:\Windows\system32\KERNEL32.DLL - 
05 00000009`2568fa40 00007ffa`3ba413d2 ntdll!RtlFreeUnicodeString+0x1c51
06 00000009`2568fe20 00007ffa`3de75444 KERNEL32!BaseThreadInitThunk+0x22
07 00000009`2568fe50 00000000`00000000 ntdll!RtlUserThreadStart+0x34
0:009> dv
           this = 0x00000009`2e12fd20
    dwProcessId = 0
             hr = 0x00000000
         fReady = 0n0
0:009> dx -r1 ((aspnetcorerh!SERVER_PROCESS *)0x92e12fd20)
((aspnetcorerh!SERVER_PROCESS *)0x92e12fd20)                 : 0x92e12fd20 [Type: SERVER_PROCESS *]
    [+0x008] m_pForwarderConnection : Unable to read memory at Address 0x92e12fd28
    [+0x010] m_fStdoutLogEnabled : Unable to read memory at Address 0x92e12fd30
    [+0x014] m_fWindowsAuthEnabled : Unable to read memory at Address 0x92e12fd34
    [+0x018] m_fBasicAuthEnabled : Unable to read memory at Address 0x92e12fd38
    [+0x01c] m_fAnonymousAuthEnabled : Unable to read memory at Address 0x92e12fd3c
    [+0x020] m_Timer          [Type: STTIMER]
    [+0x038] m_socket         : Unable to read memory at Address 0x92e12fd58
    [+0x040] m_struLogFile    [Type: STRU]
    [+0x058] m_struFullLogFile [Type: STRU]
    [+0x070] m_ProcessPath    [Type: STRU]
    [+0x088] m_Arguments      [Type: STRU]
    [+0x0a0] m_struAppVirtualPath [Type: STRU]
    [+0x0b8] m_struAppFullPath [Type: STRU]
    [+0x0d0] m_struPhysicalPath [Type: STRU]
    [+0x0e8] m_struPort       [Type: STRU]
    [+0x100] m_struCommandLine [Type: STRU]
    [+0x118] m_lStopping      : Unable to read memory at Address 0x92e12fe38
    [+0x11c] m_fReady         : Unable to read memory at Address 0x92e12fe3c
    [+0x120] m_cRefs          : Unable to read memory at Address 0x92e12fe40
    [+0x124] m_dwPort         : Unable to read memory at Address 0x92e12fe44
    [+0x128] m_dwStartupTimeLimitInMS : Unable to read memory at Address 0x92e12fe48
    [+0x12c] m_dwShutdownTimeLimitInMS : Unable to read memory at Address 0x92e12fe4c
    [+0x130] m_cChildProcess  : Unable to read memory at Address 0x92e12fe50
    [+0x134] m_dwChildProcessIds [Type: unsigned long [16]]
    [+0x174] m_dwProcessId    : Unable to read memory at Address 0x92e12fe94
    [+0x178] m_dwListeningProcessId : Unable to read memory at Address 0x92e12fe98
    [+0x180] m_straGuid       [Type: STRA]
    [+0x198] m_hJobObject     : Unable to read memory at Address 0x92e12feb8
    [+0x1a0] m_hStdoutHandle  : Unable to read memory at Address 0x92e12fec0
    [+0x1a8] m_hProcessHandle : Unable to read memory at Address 0x92e12fec8
    [+0x1b0] m_hListeningProcessHandle : Unable to read memory at Address 0x92e12fed0
    [+0x1b8] m_hProcessWaitHandle : Unable to read memory at Address 0x92e12fed8
    [+0x1c0] m_hShutdownHandle : Unable to read memory at Address 0x92e12fee0
    [+0x1c8] m_hChildProcessHandles [Type: void * [16]]
    [+0x248] m_hChildProcessWaitHandles [Type: void * [16]]
    [+0x2c8] m_pProcessManager : Unable to read memory at Address 0x92e12ffe8
    [+0x2d0] m_pEnvironmentVarTable : Unable to read memory at Address 0x92e12fff0

[shirhatti]

@pan-wang Can you confirm and close?

[jhkimnew]

This issue is already fixed. I don't see any AV with the repro scenario.