Solving WFP callout kernel CRASH drivers issue- is FwpsCompleteOperation0() a Sleeping function - HE

Hi Guys,

I am developing a WFP kernel driver which basically filters the required
packets. I see a kernel crash and details are bloe.
It looks to be as a locking issue.

*pseudo code
*TimerObject gClearRulesTimer;
*init.c*

*driver_entry()
*{
/* Register callouts/ add callouts/ register filters */
…*

IMP: *callout.calloutKey = OUT_CONNECT_CALLOUT_V4 ;
callout.classifyFn = EvtOutboundConnect ;
status = FwpsCalloutRegister0(pDeviceObject, &callout, NULL) ;
if( !NT_SUCCESS(status) )
{
KdPrint((“Error: Failed to register outbound IP connect callout.
0x%x\n”, status)) ;
goto errorexit ;
}
/* init couple of "KeInitializeTimer"s */
*IMP: *KeInitializeTimer(&gClearRulesTimer.timer) ;

}

/*connect callout */
VOID NTAPI EvtOutboundConnect(IN const FWPS_INCOMING_VALUES0 *pFixedValues,
IN const FWPS_INCOMING_METADATA_VALUES0
*pMetaValues,
IN OUT VOID *pLayerData,
IN const FWPS_FILTER0 *pFilter,
IN UINT64 flowContext,
OUT FWPS_CLASSIFY_OUT0 *pClassifyOut)
{

LOCK(&gDriverMutex, &irql) ; *callout_connect.c @ 79*

UNLOCK(&gDriverMutex, &irql) ;
}

/* periodically invoked timer function */
VOID ClearPendingRules(IN PKDPC dpc,
IN PVOID deferredContext,
IN PVOID systemArgument1,
IN PVOID systemArgument2)
{

LOCK(&gDriverMutex, &irql) ;

if( pRule->hCompletionContext != NULL )
FwpsCompleteOperation0(pRule->hCompletionContext,
pRule->pCompletionArgument) ; <- Windbg points to this line at
the bottom of trace
** else *rule.c @ 391
*
pRule->pfnCompletionFunc(pRule) ;

UNLOCK(&gDriverMutex, &irql) ;
}

Stack trace:
kd> kb
ChildEBP RetAddr Args to Child
82729448 8265eb73 0002625a 00000000 0000b000 nt!KeAccumulateTicks+0x316
82729488 8265ea20 82a15749 00000000 00000000 nt!KeUpdateRunTime+0x145
827294e4 8265e223 00000002 00000002 000000d1 nt!KeUpdateSystemTime+0x613
827294e4 82a15749 00000002 00000002 000000d1
nt!KeUpdateSystemTimeAssist+0x13
82729568 8c5b0fa3 857d6998 00000000 00000000
hal!KeAcquireSpinLockRaiseToSynch+0x39
827295bc 86d62106 82729940 84c7f8e0 00000000
waclient!EvtOutboundConnect+0x1d3
[c:\windows_driver_devel\access_point\src\modules\as_server\src\platform\proxyclient_win32\drv_vista\callout_connect.c
@ 79]
827295e0 86d4b96a 00000000 8c5b0dd0 82729940
NETIO!ProcessNonBufferedCallout+0x23
8272963c 86d4bb99 00000030 82729940 84c7f8e0 NETIO!ProcessCallout+0x184
827296b0 86d4b0fe 00000030 82729940 84c7f8e0 NETIO!ArbitrateAndEnforce+0xae
827297c0 86e7277e 00000030 82729940 84c7f8e0 NETIO!KfdClassify+0x1c7
827297f0 86e6abb3 82729940 84c7f8e0 00000000 tcpip!WfpAleClassify+0x3a
8272995c 86e68fc0 8405ec98 00000020 86f0c360
tcpip!WfpAlepReauthorizeOutboundConnection+0x888
827299fc 86ee8d99 00000030 00000002 00000006
tcpip!WfpAleReauthorizeOutboundConnection+0x101
82729a94 86ee8246 83f075c8 00000000 8c5b8bfa
tcpip!WfpAlepAuthorizeConnectCompletion+0x68
82729b00 8c5b4f79 83f075c8 00000000 82729bb8
tcpip!WfpAleCompleteOperation+0x146
82729b38 8265d95d 8c5bbce8 8c5bbd80 ebca4228
waclient!ClearPendingRules+0x2c9
[c:\windows_driver_devel\access_point\src\modules\as_server\src\platform\proxyclient_win32\drv_vista\rule.c
@ 391]
82729b7c 8265d901 8272cd20 82729ca8 00000001 nt!KiProcessTimerDpcTable+0x50
82729c68 8265d7be 8272cd20 82729ca8 00000000
nt!KiProcessExpiredTimerList+0x101
82729cdc 8265b96e 0000adb3 857db920 82736280 nt!KiTimerExpiration+0x25c
82729d20 8265b798 00000000 0000000e 00000000 nt!KiRetireDpcList+0xcb

I can provide more information if needed.

Thanks.
Mukund Jampala

What is the output of

!analyze -v

?

d

Sent from my phone with no t9, all spilling mistakes are not intentional.


From: mukund nani
Sent: Monday, October 19, 2009 6:45 PM
To: Kernel Debugging Interest List
Subject: [windbg] Solving WFP callout kernel CRASH drivers issue- is FwpsCompleteOperation0() a Sleeping function - HELP

Hi Guys,

I am developing a WFP kernel driver which basically filters the required packets. I see a kernel crash and details are bloe.
It looks to be as a locking issue.

pseudo code
TimerObject gClearRulesTimer;
init.c

driver_entry()
{
/* Register callouts/ add callouts/ register filters /


IMP: callout.calloutKey = OUT_CONNECT_CALLOUT_V4 ;
callout.classifyFn = EvtOutboundConnect ;
status = FwpsCalloutRegister0(pDeviceObject, &callout, NULL) ;
if( !NT_SUCCESS(status) )
{
KdPrint((“Error: Failed to register outbound IP connect callout. 0x%x\n”, status)) ;
goto errorexit ;
}
/
init couple of "KeInitializeTimer"s */
IMP: KeInitializeTimer(&gClearRulesTimer.timer) ;


}

/*connect callout */
VOID NTAPI EvtOutboundConnect(IN const FWPS_INCOMING_VALUES0 *pFixedValues,
IN const FWPS_INCOMING_METADATA_VALUES0 *pMetaValues,
IN OUT VOID *pLayerData,
IN const FWPS_FILTER0 *pFilter,
IN UINT64 flowContext,
OUT FWPS_CLASSIFY_OUT0 pClassifyOut)
{

LOCK(&gDriverMutex, &irql) ; callout_connect.c @ 79

UNLOCK(&gDriverMutex, &irql) ;
}

/
periodically invoked timer function */
VOID ClearPendingRules(IN PKDPC dpc,
IN PVOID deferredContext,
IN PVOID systemArgument1,
IN PVOID systemArgument2)
{

LOCK(&gDriverMutex, &irql) ;

if( pRule->hCompletionContext != NULL )
FwpsCompleteOperation0(pRule->hCompletionContext, pRule->pCompletionArgument) ; <- Windbg points to this line at the bottom of trace
else rule.c @ 391
pRule->pfnCompletionFunc(pRule) ;

UNLOCK(&gDriverMutex, &irql) ;
}

Stack trace:
kd> kb
ChildEBP RetAddr Args to Child
82729448 8265eb73 0002625a 00000000 0000b000 nt!KeAccumulateTicks+0x316
82729488 8265ea20 82a15749 00000000 00000000 nt!KeUpdateRunTime+0x145
827294e4 8265e223 00000002 00000002 000000d1 nt!KeUpdateSystemTime+0x613
827294e4 82a15749 00000002 00000002 000000d1 nt!KeUpdateSystemTimeAssist+0x13
82729568 8c5b0fa3 857d6998 00000000 00000000 hal!KeAcquireSpinLockRaiseToSynch+0x39
827295bc 86d62106 82729940 84c7f8e0 00000000 waclient!EvtOutboundConnect+0x1d3 [c:\windows_driver_devel\access_point\src\modules\as_server\src\platform\proxyclient_win32\drv_vista\callout_connect.c @ 79]
827295e0 86d4b96a 00000000 8c5b0dd0 82729940 NETIO!ProcessNonBufferedCallout+0x23
8272963c 86d4bb99 00000030 82729940 84c7f8e0 NETIO!ProcessCallout+0x184
827296b0 86d4b0fe 00000030 82729940 84c7f8e0 NETIO!ArbitrateAndEnforce+0xae
827297c0 86e7277e 00000030 82729940 84c7f8e0 NETIO!KfdClassify+0x1c7
827297f0 86e6abb3 82729940 84c7f8e0 00000000 tcpip!WfpAleClassify+0x3a
8272995c 86e68fc0 8405ec98 00000020 86f0c360 tcpip!WfpAlepReauthorizeOutboundConnection+0x888
827299fc 86ee8d99 00000030 00000002 00000006 tcpip!WfpAleReauthorizeOutboundConnection+0x101
82729a94 86ee8246 83f075c8 00000000 8c5b8bfa tcpip!WfpAlepAuthorizeConnectCompletion+0x68
82729b00 8c5b4f79 83f075c8 00000000 82729bb8 tcpip!WfpAleCompleteOperation+0x146
82729b38 8265d95d 8c5bbce8 8c5bbd80 ebca4228 waclient!ClearPendingRules+0x2c9 [c:\windows_driver_devel\access_point\src\modules\as_server\src\platform\proxyclient_win32\drv_vista\rule.c @ 391]
82729b7c 8265d901 8272cd20 82729ca8 00000001 nt!KiProcessTimerDpcTable+0x50
82729c68 8265d7be 8272cd20 82729ca8 00000000 nt!KiProcessExpiredTimerList+0x101
82729cdc 8265b96e 0000adb3 857db920 82736280 nt!KiTimerExpiration+0x25c
82729d20 8265b798 00000000 0000000e 00000000 nt!KiRetireDpcList+0xcb

I can provide more information if needed.

Thanks.
Mukund Jampala

— WINDBG is sponsored by OSR For our schedule of WDF, WDM, debugging and other seminars visit: http://www.osr.com/seminars To unsubscribe, visit the List Server section of OSR Online at http://www.osronline.com/page.cfm?name=ListServer

kd> !Analyze -v
*******************************************************************************
*
*
* Bugcheck
Analysis *
*
*
*******************************************************************************

Unknown bugcheck code (0)
Unknown bugcheck description
Arguments:
Arg1: 00000000
Arg2: 00000000
Arg3: 00000000
Arg4: 00000000

Debugging Details:

ERROR: Could Not Find Target OS Version. Please Update GetFunctionForOSVer
to include target OS Version

DBGHELP: mssmbios - public symbols

c:\symbols\websymbols\mssmbios.pdb\29553BB44DF44D07B86E342EAEECBC8A1\mssmbios.pdb
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe -
mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe -
mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe -
mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe -
mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe -
mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe -
mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe -
mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe -
mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe -
mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe -
mismatched
DBGHELP: c:\symbols\websymbols\halmacpi.dll\49EE8A2E37000\halmacpi.dll -
mismatched
DBGHELP: c:\symbols\websymbols\NETIO.SYS\49EE8A8D3e000\NETIO.SYS -
mismatched
DBGHELP: c:\symbols\websymbols\NETIO.SYS\49EE8A8D3e000\NETIO.SYS -
mismatched
DBGHELP: c:\symbols\websymbols\NETIO.SYS\49EE8A8D3e000\NETIO.SYS -
mismatched
DBGHELP: c:\symbols\websymbols\NETIO.SYS\49EE8A8D3e000\NETIO.SYS -
mismatched
DBGHELP: c:\symbols\websymbols\tcpip.sys\49EE8AB7145000\tcpip.sys -
mismatched
DBGHELP: c:\symbols\websymbols\tcpip.sys\49EE8AB7145000\tcpip.sys -
mismatched
DBGHELP: c:\symbols\websymbols\tcpip.sys\49EE8AB7145000\tcpip.sys -
mismatched
DBGHELP: c:\symbols\websymbols\tcpip.sys\49EE8AB7145000\tcpip.sys -
mismatched
DBGHELP: c:\symbols\websymbols\tcpip.sys\49EE8AB7145000\tcpip.sys -
mismatched
DBGHELP: c:\symbols\websymbols\tcpip.sys\49EE8AB7145000\tcpip.sys -
mismatched
SYMSRV: c:\symbols\websymbols\waclient.sys\4ADE21AF14000\waclient.sys not
found
SYMSRV:
http://msdl.microsoft.com/download/symbols/waclient.sys/4ADE21AF14000/waclient.sysnot
found
DBGHELP:
C:\Users\root\Desktop\Notes\Driver_windbg_analysys_info\src-0\objchk_wlh_x86\i386\waclient.sys

  • OK

PROCESS_NAME: System

FAULTING_IP:
nt!KeAccumulateTicks+316
82674651 cd2c int 2Ch

EXCEPTION_RECORD: ffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 82674651 (nt!KeAccumulateTicks+0x00000316)
ExceptionCode: c0000420 (Assertion failure)
ExceptionFlags: 00000000
NumberParameters: 0
Assertion: *** DPC execution time exceeds system limit
This is NOT a break in update time
This is a BUG in a DPC routine
Perform a stack trace to find the culprit
The time out limit will be doubled on continuation
Use gh to continue!!

ERROR_CODE: (NTSTATUS) 0xc0000420 -

EXCEPTION_CODE: (NTSTATUS) 0xc0000420 -

DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT

BUGCHECK_STR: 0x0

CURRENT_IRQL: 1c

LAST_CONTROL_TRANSFER: from 82673b73 to 82674651

STACK_TEXT:
8273e448 82673b73 00002626 00000000 00081700 nt!KeAccumulateTicks+0x316
8273e488 82673a20 82a2a749 00000000 00000000 nt!KeUpdateRunTime+0x145
8273e4e4 82673223 00000002 00000002 000000d1 nt!KeUpdateSystemTime+0x613
8273e4e4 82a2a749 00000002 00000002 000000d1
nt!KeUpdateSystemTimeAssist+0x13
8273e568 8feebfb3 850634c8 00000000 00000000
hal!KeAcquireSpinLockRaiseToSynch+0x39
8273e5bc 86d56106 8273e940 84c7fbe0 00000000
waclient!EvtOutboundConnect+0x1d3
[c:\users\root\desktop\notes\driver_windbg_analysys_info\src-0\callout_connect.c
@ 79]
8273e5e0 86d3f96a 00000000 8feebde0 8273e940
NETIO!ProcessNonBufferedCallout+0x23
8273e63c 86d3fb99 00000030 8273e940 84c7fbe0 NETIO!ProcessCallout+0x184
8273e6b0 86d3f0fe 00000030 8273e940 84c7fbe0 NETIO!ArbitrateAndEnforce+0xae
8273e7c0 86e8077e 00000030 8273e940 84c7fbe0 NETIO!KfdClassify+0x1c7
8273e7f0 86e78bb3 8273e940 84c7fbe0 00000000 tcpip!WfpAleClassify+0x3a
8273e95c 86e76fc0 8419c628 00000020 86f1a360
tcpip!WfpAlepReauthorizeOutboundConnection+0x888
8273e9fc 86ef6d99 00000030 00000002 00000006
tcpip!WfpAleReauthorizeOutboundConnection+0x101
8273ea94 86ef6246 859798d0 00000000 8fef3ac4
tcpip!WfpAlepAuthorizeConnectCompletion+0x68
8273eb00 8feeffb7 859798d0 00000000 8273eba0
tcpip!WfpAleCompleteOperation+0x146
8273eb38 8267295d 8fef6ce8 8fef6d80 2b35f969
waclient!ClearPendingRules+0x2c7
[c:\users\root\desktop\notes\driver_windbg_analysys_info\src-0\rule.c @ 387]
8273eb7c 82672901 82741d20 8273eca8 00000001 nt!KiProcessTimerDpcTable+0x50
8273ec68 826727be 82741d20 8273eca8 00000000
nt!KiProcessExpiredTimerList+0x101
8273ecdc 8267096e 0008152b 85740b68 8274b280 nt!KiTimerExpiration+0x25c
8273ed20 82670798 00000000 0000000e 00000000 nt!KiRetireDpcList+0xcb
8273ed24 00000000 0000000e 00000000 00000000 nt!KiIdleLoop+0x38

STACK_COMMAND: kb

FOLLOWUP_IP:
waclient!EvtOutboundConnect+1d3
[c:\users\root\desktop\notes\driver_windbg_analysys_info\src-0\callout_connect.c
@ 79]
8feebfb3 8845f7 mov byte ptr [ebp-9],al

FAULTING_SOURCE_CODE:
75: }
76:
77: pClassifyOut->actionType = FWP_ACTION_BLOCK ;
78:
> 79: LOCK(&gDriverMutex, &irql) ;
80:
81: if( (protocol != PROTOCOL_TCP && protocol != PROTOCOL_UDP) ||
82: addressType == NlatAnycast ||
83: addressType == NlatBroadcast ||
84: addressType == NlatMulticast ||

SYMBOL_STACK_INDEX: 5

SYMBOL_NAME: waclient!EvtOutboundConnect+1d3

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: waclient

IMAGE_NAME: waclient.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 4ade21af

FAILURE_BUCKET_ID: 0x0_waclient!EvtOutboundConnect+1d3

BUCKET_ID: 0x0_waclient!EvtOutboundConnect+1d3

Followup: MachineOwner
---------

On Mon, Oct 19, 2009 at 8:02 PM, Doron Holan wrote:

> What is the output of
>
> !analyze -v
>
> ?
>
> d
>
> Sent from my phone with no t9, all spilling mistakes are not intentional.
>
> ------------------------------
> From: mukund nani
> Sent: Monday, October 19, 2009 6:45 PM
> To: Kernel Debugging Interest List
> Subject: [windbg] Solving WFP callout kernel CRASH drivers issue- is
> FwpsCompleteOperation0() a Sleeping function - HELP
>
> Hi Guys,
>
> I am developing a WFP kernel driver which basically filters the required
> packets. I see a kernel crash and details are bloe.
> It looks to be as a locking issue.
>
>
> *pseudo code
> *TimerObject gClearRulesTimer;
> init.c
>
> *driver_entry()
> {
> /
Register callouts/ add callouts/ register filters /
> .......

>
> IMP: callout.calloutKey = OUT_CONNECT_CALLOUT_V4 ;
> callout.classifyFn = EvtOutboundConnect ;
> status = FwpsCalloutRegister0(pDeviceObject, &callout, NULL) ;
> if( !NT_SUCCESS(status) )
> {
> KdPrint(("Error: Failed to register outbound IP connect callout.
> 0x%x\n", status)) ;
> goto errorexit ;
> }
> /
init couple of "KeInitializeTimer"s */
> *IMP: *KeInitializeTimer(&gClearRulesTimer.timer) ;
> .......
>
> }
>
> /*connect callout */
> VOID NTAPI EvtOutboundConnect(IN const FWPS_INCOMING_VALUES0 *pFixedValues,
> IN const FWPS_INCOMING_METADATA_VALUES0
> *pMetaValues,
> IN OUT VOID *pLayerData,
> IN const FWPS_FILTER0 *pFilter,
> IN UINT64 flowContext,
> OUT FWPS_CLASSIFY_OUT0 pClassifyOut)
> {
> .......
> LOCK(&gDriverMutex, &irql) ; callout_connect.c @ 79
> ......
> UNLOCK(&gDriverMutex, &irql) ;
> }
>
>
> /
periodically invoked timer function */
> VOID ClearPendingRules(IN PKDPC dpc,
> IN PVOID deferredContext,
> IN PVOID systemArgument1,
> IN PVOID systemArgument2)
> {
> ..........
> LOCK(&gDriverMutex, &irql) ;
> ..........
> if( pRule->hCompletionContext != NULL )
> FwpsCompleteOperation0(pRule->hCompletionContext,
> pRule->pCompletionArgument) ; <- Windbg points to this line at
> the bottom of trace
> ** else rule.c @
> 391

> pRule->pfnCompletionFunc(pRule) ;
> ..........
> UNLOCK(&gDriverMutex, &irql) ;
> }
>
>
> Stack trace:
> kd> kb
> ChildEBP RetAddr Args to Child
> 82729448 8265eb73 0002625a 00000000 0000b000 nt!KeAccumulateTicks+0x316
> 82729488 8265ea20 82a15749 00000000 00000000 nt!KeUpdateRunTime+0x145
> 827294e4 8265e223 00000002 00000002 000000d1 nt!KeUpdateSystemTime+0x613
> 827294e4 82a15749 00000002 00000002 000000d1
> nt!KeUpdateSystemTimeAssist+0x13
> 82729568 8c5b0fa3 857d6998 00000000 00000000
> hal!KeAcquireSpinLockRaiseToSynch+0x39
> 827295bc 86d62106 82729940 84c7f8e0 00000000
> waclient!EvtOutboundConnect+0x1d3
> [c:\windows_driver_devel\access_point\src\modules\as_server\src\platform\proxyclient_win32\drv_vista\callout_connect.c
> @ 79]
> 827295e0 86d4b96a 00000000 8c5b0dd0 82729940
> NETIO!ProcessNonBufferedCallout+0x23
> 8272963c 86d4bb99 00000030 82729940 84c7f8e0 NETIO!ProcessCallout+0x184
> 827296b0 86d4b0fe 00000030 82729940 84c7f8e0 NETIO!ArbitrateAndEnforce+0xae
> 827297c0 86e7277e 00000030 82729940 84c7f8e0 NETIO!KfdClassify+0x1c7
> 827297f0 86e6abb3 82729940 84c7f8e0 00000000 tcpip!WfpAleClassify+0x3a
> 8272995c 86e68fc0 8405ec98 00000020 86f0c360
> tcpip!WfpAlepReauthorizeOutboundConnection+0x888
> 827299fc 86ee8d99 00000030 00000002 00000006
> tcpip!WfpAleReauthorizeOutboundConnection+0x101
> 82729a94 86ee8246 83f075c8 00000000 8c5b8bfa
> tcpip!WfpAlepAuthorizeConnectCompletion+0x68
> 82729b00 8c5b4f79 83f075c8 00000000 82729bb8
> tcpip!WfpAleCompleteOperation+0x146
> 82729b38 8265d95d 8c5bbce8 8c5bbd80 ebca4228
> waclient!ClearPendingRules+0x2c9
> [c:\windows_driver_devel\access_point\src\modules\as_server\src\platform\proxyclient_win32\drv_vista\rule.c
> @ 391]
> 82729b7c 8265d901 8272cd20 82729ca8 00000001 nt!KiProcessTimerDpcTable+0x50
> 82729c68 8265d7be 8272cd20 82729ca8 00000000
> nt!KiProcessExpiredTimerList+0x101
> 82729cdc 8265b96e 0000adb3 857db920 82736280 nt!KiTimerExpiration+0x25c
> 82729d20 8265b798 00000000 0000000e 00000000 nt!KiRetireDpcList+0xcb
>
> I can provide more information if needed.
>
> Thanks.
> Mukund Jampala
>
> --- WINDBG is sponsored by OSR For our schedule of WDF, WDM, debugging and
> other seminars visit: OSR Seminars – OSR To unsubscribe, visit
> the List Server section of OSR Online at
> ListServer/Forum
>
> ---
> WINDBG is sponsored by OSR
>
> For our schedule of WDF, WDM, debugging and other seminars visit:
> OSR Seminars – OSR
>
> To unsubscribe, visit the List Server section of OSR Online at
> ListServer/Forum
>

Something tells me that you have a symbol problem.

You appear to be using the correct symbol server path (http://msdl.microsoft.com/download/symbols), but windbg is also reporting mismatched symbols, which is definitely not a good thing.

Try this and post the results, where you can replace ‘c:\symbols’ with any local path in which you would like to cache the symbols that get download from the msft symbol server.

.symopt+ 0x80000000
.sympath srv*c:\symbols*http://msdl.microsoft.com/download/symbols
.reload -f -n
lml

mm

My guess is that you are spending too much time in this particular DPC. Is the code before the LOCK a loop?

From: xxxxx@lists.osr.com [mailto:xxxxx@lists.osr.com] On Behalf Of mukund nani
Sent: Tuesday, October 20, 2009 4:22 PM
To: Kernel Debugging Interest List
Subject: Re: [windbg] Solving WFP callout kernel CRASH drivers issue- is FwpsCompleteOperation0() a Sleeping function - HELP

kd> !Analyze -v
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************

Unknown bugcheck code (0)
Unknown bugcheck description
Arguments:
Arg1: 00000000
Arg2: 00000000
Arg3: 00000000
Arg4: 00000000

Debugging Details:

ERROR: Could Not Find Target OS Version. Please Update GetFunctionForOSVer to include target OS Version

DBGHELP: mssmbios - public symbols
c:\symbols\websymbols\mssmbios.pdb\29553BB44DF44D07B86E342EAEECBC8A1\mssmbios.pdb
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe - mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe - mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe - mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe - mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe - mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe - mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe - mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe - mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe - mismatched
DBGHELP: c:\symbols\websymbols\ntkrpamp.exe\49EE8B4E40f000\ntkrpamp.exe - mismatched
DBGHELP: c:\symbols\websymbols\halmacpi.dll\49EE8A2E37000\halmacpi.dll - mismatched
DBGHELP: c:\symbols\websymbols\NETIO.SYS\49EE8A8D3e000\NETIO.SYS - mismatched
DBGHELP: c:\symbols\websymbols\NETIO.SYS\49EE8A8D3e000\NETIO.SYS - mismatched
DBGHELP: c:\symbols\websymbols\NETIO.SYS\49EE8A8D3e000\NETIO.SYS - mismatched
DBGHELP: c:\symbols\websymbols\NETIO.SYS\49EE8A8D3e000\NETIO.SYS - mismatched
DBGHELP: c:\symbols\websymbols\tcpip.sys\49EE8AB7145000\tcpip.sys - mismatched
DBGHELP: c:\symbols\websymbols\tcpip.sys\49EE8AB7145000\tcpip.sys - mismatched
DBGHELP: c:\symbols\websymbols\tcpip.sys\49EE8AB7145000\tcpip.sys - mismatched
DBGHELP: c:\symbols\websymbols\tcpip.sys\49EE8AB7145000\tcpip.sys - mismatched
DBGHELP: c:\symbols\websymbols\tcpip.sys\49EE8AB7145000\tcpip.sys - mismatched
DBGHELP: c:\symbols\websymbols\tcpip.sys\49EE8AB7145000\tcpip.sys - mismatched
SYMSRV: c:\symbols\websymbols\waclient.sys\4ADE21AF14000\waclient.sys not found
SYMSRV: http://msdl.microsoft.com/download/symbols/waclient.sys/4ADE21AF14000/waclient.sys not found
DBGHELP: C:\Users\root\Desktop\Notes\Driver_windbg_analysys_info\src-0\objchk_wlh_x86\i386\waclient.sys - OK

PROCESS_NAME: System

FAULTING_IP:
nt!KeAccumulateTicks+316
82674651 cd2c int 2Ch

EXCEPTION_RECORD: ffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 82674651 (nt!KeAccumulateTicks+0x00000316)
ExceptionCode: c0000420 (Assertion failure)
ExceptionFlags: 00000000
NumberParameters: 0
Assertion: *** DPC execution time exceeds system limit
This is NOT a break in update time
This is a BUG in a DPC routine
Perform a stack trace to find the culprit
The time out limit will be doubled on continuation
Use gh to continue!!

ERROR_CODE: (NTSTATUS) 0xc0000420 -

EXCEPTION_CODE: (NTSTATUS) 0xc0000420 -

DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT

BUGCHECK_STR: 0x0

CURRENT_IRQL: 1c

LAST_CONTROL_TRANSFER: from 82673b73 to 82674651

STACK_TEXT:
8273e448 82673b73 00002626 00000000 00081700 nt!KeAccumulateTicks+0x316
8273e488 82673a20 82a2a749 00000000 00000000 nt!KeUpdateRunTime+0x145
8273e4e4 82673223 00000002 00000002 000000d1 nt!KeUpdateSystemTime+0x613
8273e4e4 82a2a749 00000002 00000002 000000d1 nt!KeUpdateSystemTimeAssist+0x13
8273e568 8feebfb3 850634c8 00000000 00000000 hal!KeAcquireSpinLockRaiseToSynch+0x39
8273e5bc 86d56106 8273e940 84c7fbe0 00000000 waclient!EvtOutboundConnect+0x1d3 [c:\users\root\desktop\notes\driver_windbg_analysys_info\src-0\callout_connect.c @ 79]
8273e5e0 86d3f96a 00000000 8feebde0 8273e940 NETIO!ProcessNonBufferedCallout+0x23
8273e63c 86d3fb99 00000030 8273e940 84c7fbe0 NETIO!ProcessCallout+0x184
8273e6b0 86d3f0fe 00000030 8273e940 84c7fbe0 NETIO!ArbitrateAndEnforce+0xae
8273e7c0 86e8077e 00000030 8273e940 84c7fbe0 NETIO!KfdClassify+0x1c7
8273e7f0 86e78bb3 8273e940 84c7fbe0 00000000 tcpip!WfpAleClassify+0x3a
8273e95c 86e76fc0 8419c628 00000020 86f1a360 tcpip!WfpAlepReauthorizeOutboundConnection+0x888
8273e9fc 86ef6d99 00000030 00000002 00000006 tcpip!WfpAleReauthorizeOutboundConnection+0x101
8273ea94 86ef6246 859798d0 00000000 8fef3ac4 tcpip!WfpAlepAuthorizeConnectCompletion+0x68
8273eb00 8feeffb7 859798d0 00000000 8273eba0 tcpip!WfpAleCompleteOperation+0x146
8273eb38 8267295d 8fef6ce8 8fef6d80 2b35f969 waclient!ClearPendingRules+0x2c7 [c:\users\root\desktop\notes\driver_windbg_analysys_info\src-0\rule.c @ 387]
8273eb7c 82672901 82741d20 8273eca8 00000001 nt!KiProcessTimerDpcTable+0x50
8273ec68 826727be 82741d20 8273eca8 00000000 nt!KiProcessExpiredTimerList+0x101
8273ecdc 8267096e 0008152b 85740b68 8274b280 nt!KiTimerExpiration+0x25c
8273ed20 82670798 00000000 0000000e 00000000 nt!KiRetireDpcList+0xcb
8273ed24 00000000 0000000e 00000000 00000000 nt!KiIdleLoop+0x38

STACK_COMMAND: kb

FOLLOWUP_IP:
waclient!EvtOutboundConnect+1d3 [c:\users\root\desktop\notes\driver_windbg_analysys_info\src-0\callout_connect.c @ 79]
8feebfb3 8845f7 mov byte ptr [ebp-9],al

FAULTING_SOURCE_CODE:
75: }
76:
77: pClassifyOut->actionType = FWP_ACTION_BLOCK ;
78:
> 79: LOCK(&gDriverMutex, &irql) ;
80:
81: if( (protocol != PROTOCOL_TCP && protocol != PROTOCOL_UDP) ||
82: addressType == NlatAnycast ||
83: addressType == NlatBroadcast ||
84: addressType == NlatMulticast ||

SYMBOL_STACK_INDEX: 5

SYMBOL_NAME: waclient!EvtOutboundConnect+1d3

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: waclient

IMAGE_NAME: waclient.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 4ade21af

FAILURE_BUCKET_ID: 0x0_waclient!EvtOutboundConnect+1d3

BUCKET_ID: 0x0_waclient!EvtOutboundConnect+1d3

Followup: MachineOwner
---------

On Mon, Oct 19, 2009 at 8:02 PM, Doron Holan > wrote:
What is the output of

!analyze -v

?

d

Sent from my phone with no t9, all spilling mistakes are not intentional.
________________________________
From: mukund nani >
Sent: Monday, October 19, 2009 6:45 PM
To: Kernel Debugging Interest List >
Subject: [windbg] Solving WFP callout kernel CRASH drivers issue- is FwpsCompleteOperation0() a Sleeping function - HELP
Hi Guys,

I am developing a WFP kernel driver which basically filters the required packets. I see a kernel crash and details are bloe.
It looks to be as a locking issue.

pseudo code
TimerObject gClearRulesTimer;
init.c

driver_entry()
{
/* Register callouts/ add callouts/ register filters /
.......

IMP: callout.calloutKey = OUT_CONNECT_CALLOUT_V4 ;
callout.classifyFn = EvtOutboundConnect ;
status = FwpsCalloutRegister0(pDeviceObject, &callout, NULL) ;
if( !NT_SUCCESS(status) )
{
KdPrint(("Error: Failed to register outbound IP connect callout. 0x%x\n", status)) ;
goto errorexit ;
}
/
init couple of "KeInitializeTimer"s */
IMP: KeInitializeTimer(&gClearRulesTimer.timer) ;
.......

}

/*connect callout */
VOID NTAPI EvtOutboundConnect(IN const FWPS_INCOMING_VALUES0 *pFixedValues,
IN const FWPS_INCOMING_METADATA_VALUES0 *pMetaValues,
IN OUT VOID *pLayerData,
IN const FWPS_FILTER0 *pFilter,
IN UINT64 flowContext,
OUT FWPS_CLASSIFY_OUT0 pClassifyOut)
{
.......
LOCK(&gDriverMutex, &irql) ; callout_connect.c @ 79
......
UNLOCK(&gDriverMutex, &irql) ;
}

/
periodically invoked timer function */
VOID ClearPendingRules(IN PKDPC dpc,
IN PVOID deferredContext,
IN PVOID systemArgument1,
IN PVOID systemArgument2)
{
..........
LOCK(&gDriverMutex, &irql) ;
..........
if( pRule->hCompletionContext != NULL )
FwpsCompleteOperation0(pRule->hCompletionContext, pRule->pCompletionArgument) ; <- Windbg points to this line at the bottom of trace
else rule.c @ 391
pRule->pfnCompletionFunc(pRule) ;
..........
UNLOCK(&gDriverMutex, &irql) ;
}

Stack trace:
kd> kb
ChildEBP RetAddr Args to Child
82729448 8265eb73 0002625a 00000000 0000b000 nt!KeAccumulateTicks+0x316
82729488 8265ea20 82a15749 00000000 00000000 nt!KeUpdateRunTime+0x145
827294e4 8265e223 00000002 00000002 000000d1 nt!KeUpdateSystemTime+0x613
827294e4 82a15749 00000002 00000002 000000d1 nt!KeUpdateSystemTimeAssist+0x13
82729568 8c5b0fa3 857d6998 00000000 00000000 hal!KeAcquireSpinLockRaiseToSynch+0x39
827295bc 86d62106 82729940 84c7f8e0 00000000 waclient!EvtOutboundConnect+0x1d3 [c:\windows_driver_devel\access_point\src\modules\as_server\src\platform\proxyclient_win32\drv_vista\callout_connect.c @ 79]
827295e0 86d4b96a 00000000 8c5b0dd0 82729940 NETIO!ProcessNonBufferedCallout+0x23
8272963c 86d4bb99 00000030 82729940 84c7f8e0 NETIO!ProcessCallout+0x184
827296b0 86d4b0fe 00000030 82729940 84c7f8e0 NETIO!ArbitrateAndEnforce+0xae
827297c0 86e7277e 00000030 82729940 84c7f8e0 NETIO!KfdClassify+0x1c7
827297f0 86e6abb3 82729940 84c7f8e0 00000000 tcpip!WfpAleClassify+0x3a
8272995c 86e68fc0 8405ec98 00000020 86f0c360 tcpip!WfpAlepReauthorizeOutboundConnection+0x888
827299fc 86ee8d99 00000030 00000002 00000006 tcpip!WfpAleReauthorizeOutboundConnection+0x101
82729a94 86ee8246 83f075c8 00000000 8c5b8bfa tcpip!WfpAlepAuthorizeConnectCompletion+0x68
82729b00 8c5b4f79 83f075c8 00000000 82729bb8 tcpip!WfpAleCompleteOperation+0x146
82729b38 8265d95d 8c5bbce8 8c5bbd80 ebca4228 waclient!ClearPendingRules+0x2c9 [c:\windows_driver_devel\access_point\src\modules\as_server\src\platform\proxyclient_win32\drv_vista\rule.c @ 391]
82729b7c 8265d901 8272cd20 82729ca8 00000001 nt!KiProcessTimerDpcTable+0x50
82729c68 8265d7be 8272cd20 82729ca8 00000000 nt!KiProcessExpiredTimerList+0x101
82729cdc 8265b96e 0000adb3 857db920 82736280 nt!KiTimerExpiration+0x25c
82729d20 8265b798 00000000 0000000e 00000000 nt!KiRetireDpcList+0xcb

I can provide more information if needed.

Thanks.
Mukund Jampala
--- WINDBG is sponsored by OSR For our schedule of WDF, WDM, debugging and other seminars visit: OSR Seminars – OSR To unsubscribe, visit the List Server section of OSR Online at ListServer/Forum

---
WINDBG is sponsored by OSR

For our schedule of WDF, WDM, debugging and other seminars visit:
OSR Seminars – OSR

To unsubscribe, visit the List Server section of OSR Online at ListServer/Forum

--- WINDBG is sponsored by OSR For our schedule of WDF, WDM, debugging and other seminars visit: OSR Seminars – OSR To unsubscribe, visit the List Server section of OSR Online at ListServer/Forum