BSOD on WdfObjectGetTypedContextWorker

Hsin_Hui_Chiang · March 14, 2014, 7:12am

Dear All:
I’m porting a CANBUS driver from the SerialPort sample driver, and have the read/write operation work when I send data from one computer and receive from another one. But I get a BSOD after about 10 minutes and get the following message

========================WinDbg Message Start================
Microsoft (R) Windows Debugger Version 6.11.0001.404 AMD64
Copyright (c) Microsoft Corporation. All rights reserved.

Opened \.\com6
Waiting to reconnect…
Connected to Windows 7 7601 x86 compatible target at (Fri Mar 14 13:36:23.195 2014 (GMT+8)), ptr64 FALSE
Kernel Debugger connection established.
Symbol search path is: C:\WinDBG\EPM3112\symbolFile\bus\i386;C:\WinDBG\EPM3112\symbolFile\func\i386;C:\Symbols
Executable search path is: C:\WinDBG\EPM3112\symbolFile\bus\i386;C:\WinDBG\EPM3112\symbolFile\func\i386
Windows 7 Kernel Version 7601 (Service Pack 1) MP (2 procs) Free x86 compatible
Product: WinNt, suite: TerminalServer EmbeddedNT SingleUserTS
Built by: 7601.17514.x86fre.win7sp1_rtm.101119-1850
Machine Name:
Kernel base = 0x82c11000 PsLoadedModuleList = 0x82d515b0
Debug session time: Sat Mar 15 08:48:02.198 2014 (GMT+8)
System Uptime: 0 days 0:02:20.289
Break instruction exception - code 80000003 (first chance)
*******************************************************************************
* *
* You are seeing this message because you pressed either *
* CTRL+C (if you run kd.exe) or, *
* CTRL+BREAK (if you run WinDBG), *
* on your debugger machine’s keyboard. *
* *
* THIS IS NOT A BUG OR A SYSTEM CRASH *
* *
* If you did not intend to break into the debugger, press the “g” key, then *
* press the “Enter” key now. This message might immediately reappear. If it *
* does, press “g” and “Enter” again. *
* *
*******************************************************************************
nt!RtlpBreakWithStatusInstruction:
82c69d00 cc int 3
0: kd> g
Access violation - code c0000005 (!!! second chance !!!)
839cd018 8b700c mov esi,dword ptr [eax+0Ch]
0: kd> !analyze -v
Connected to Windows 7 7601 x86 compatible target at (Fri Mar 14 13:38:48.460 2014 (GMT+8)), ptr64 FALSE
Loading Kernel Symbols
…
…
…
Loading User Symbols
…
Loading unloaded module list
…*** ERROR: Symbol file could not be found. Defaulted to export symbols for ntdll.dll -

*** ERROR: Module load completed but symbols could not be loaded for Wdf01000.sys
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************

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

Debugging Details:

*** ERROR: Symbol file could not be found. Defaulted to export symbols for kernel32.dll -
*** ERROR: Symbol file could not be found. Defaulted to export symbols for mxdev.dll -
*** ERROR: Module load completed but symbols could not be loaded for mxcan_loop_test.exe

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

*************************************************************************
*** ***
*** ***
*** Your debugger is not using the correct symbols ***
*** ***
*** In order for this command to work properly, your symbol path ***
*** must point to .pdb files that have full type information. ***
*** ***
*** Certain .pdb files (such as the public OS symbols) do not ***
*** contain the required information. Contact the group that ***
*** provided you with these symbols if you need this command to ***
*** work. ***
*** ***
*** Type referenced: kernel32!pNlsUserInfo ***
*** ***
*************************************************************************
*************************************************************************
*** ***
*** ***
*** Your debugger is not using the correct symbols ***
*** ***
*** In order for this command to work properly, your symbol path ***
*** must point to .pdb files that have full type information. ***
*** ***
*** Certain .pdb files (such as the public OS symbols) do not ***
*** contain the required information. Contact the group that ***
*** provided you with these symbols if you need this command to ***
*** work. ***
*** ***
*** Type referenced: kernel32!pNlsUserInfo ***
*** ***
*************************************************************************

PROCESS_NAME: mxcan_loop_tes

FAULTING_IP:
Wdf01000+40018
839cd018 8b700c mov esi,dword ptr [eax+0Ch]

EXCEPTION_RECORD: ffffffff – (.exr 0xffffffffffffffff)
ExceptionAddress: 839cd018 (Wdf01000+0x00040018)
ExceptionCode: c0000005 (Access violation)
ExceptionFlags: 00000000
NumberParameters: 2
Parameter[0]: 00000000
Parameter[1]: 00000004
Attempt to read from address 00000004

ERROR_CODE: (NTSTATUS) 0xc0000005 - 0x%08lx

EXCEPTION_CODE: (NTSTATUS) 0xc0000005 - 0x%08lx

EXCEPTION_PARAMETER1: 00000000

EXCEPTION_PARAMETER2: 00000004

READ_ADDRESS: 00000004

FOLLOWUP_IP:
mxcport!WdfObjectGetTypedContextWorker+18 [c:\winddk\7600.16385.0\inc\wdf\kmdf\1.9\wdfobject.h @ 409]
903df5f8 5d pop ebp

BUGCHECK_STR: ACCESS_VIOLATION

DEFAULT_BUCKET_ID: NULL_CLASS_PTR_DEREFERENCE

CURRENT_IRQL: 0

LAST_CONTROL_TRANSFER: from 903df5f8 to 839cd018

STACK_TEXT:
WARNING: Stack unwind information not available. Following frames may be wrong.
a894da58 903df5f8 903ea014 a894da74 903df9d4 Wdf01000+0x40018
a894da64 903df9d4 00000000 903ea014 a894da90 mxcport!WdfObjectGetTypedContextWorker+0x18 [c:\winddk\7600.16385.0\inc\wdf\kmdf\1.9\wdfobject.h @ 409]
a894da74 903e35d1 00000000 00000003 903e7330 mxcport!MxCanGetRequestContext+0x14 [c:\winddk\7600.16385.0\embeddedstandard\expansioncard\epm-3112\wdf\epm_3112_kmdf_2014-03-13-09\2.src\driver\func\shared\toaster.h @ 810]
a894da90 903e2cc0 00000000 903e2090 00000000 mxcport!MxCanSetCancelRoutine+0x11 [c:\winddk\7600.16385.0\embeddedstandard\expansioncard\epm-3112\wdf\epm_3112_kmdf_2014-03-13-09\2.src\driver\func\featured\utils.c @ 160]
a894dad4 903e4092 879bd1d8 00000000 00000018 mxcport!MxCanStartRead+0x1b0 [c:\winddk\7600.16385.0\embeddedstandard\expansioncard\epm-3112\wdf\epm_3112_kmdf_2014-03-13-09\2.src\driver\func\featured\read.c @ 1063]
a894db04 903ebb11 879bd1d8 77bc3308 78641278 mxcport!MxCanStartOrQueue+0xc2 [c:\winddk\7600.16385.0\embeddedstandard\expansioncard\epm-3112\wdf\epm_3112_kmdf_2014-03-13-09\2.src\driver\func\featured\utils.c @ 820]
a894db94 839bc02a 78641698 77bc3308 00000014 mxcport!ToasterEvtIoRead+0x1e1 [c:\winddk\7600.16385.0\embeddedstandard\expansioncard\epm-3112\wdf\epm_3112_kmdf_2014-03-13-09\2.src\driver\func\featured\toaster.c @ 1086]
a894dbb0 839bd256 78641698 77bc3308 00000014 Wdf01000+0x2f02a
a894dbd8 839bf9ac 77bc3308 8843ccf0 879be960 Wdf01000+0x30256
a894dbf4 839c0a36 879be900 00000000 879bde30 Wdf01000+0x329ac
a894dc14 839c2824 8843ccf0 88688820 879bd6e0 Wdf01000+0x33a36
a894dc38 839b1a3f 88646df8 a894dc5c 82c40047 Wdf01000+0x35824
a894dc44 82c40047 879bd6e0 88646df8 88646df8 Wdf01000+0x24a3f
a894dc5c 82e169d5 88646df8 88646e8c 88688820 nt!IofCallDriver+0x63
a894dc7c 82e178bc 879bd6e0 88688820 00000001 nt!IopSynchronousServiceTail+0x1f8
a894dd08 82c4687a 879bd6e0 88646df8 00000000 nt!NtReadFile+0x644
a894dd08 76f970b4 879bd6e0 88646df8 00000000 nt!KiFastCallEntry+0x12a
00b4f2cc 76c8974f 00000040 00b4f36c 00000014 ntdll!KiFastSystemCallRet
00b4f314 1000751b 00000040 00b4f36c 00000014 kernel32!ReadFile+0x54
00b4f338 012c1170 00000040 00b4f36c 00000014 mxdev!mxcan_read+0x2b
00b4f33c 00000000 00b4f36c 00000014 00000000 mxcan_loop_test+0x1170

STACK_COMMAND: kb

FAULTING_SOURCE_CODE:
No source found for ‘c:\winddk\7600.16385.0\inc\wdf\kmdf\1.9\wdfobject.h’

SYMBOL_STACK_INDEX: 1

SYMBOL_NAME: mxcport!WdfObjectGetTypedContextWorker+18

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: mxcport

IMAGE_NAME: mxcport.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 5321657f

FAILURE_BUCKET_ID: ACCESS_VIOLATION_mxcport!WdfObjectGetTypedContextWorker+18

BUCKET_ID: ACCESS_VIOLATION_mxcport!WdfObjectGetTypedContextWorker+18

Followup: MachineOwner

========================Request Context Start================

The WinDbg says WdfObjectGetTypedContextWorker cause the access violation, but I have no idea on how to debug it, because it’s a wdf api. The only clue is I use self-defined request context, so I guess if the context causes the BSOD issue randomly

========================WinDbg Message End================
typedef struct _REQUEST_CONTEXT {
ULONG_PTR Information;
NTSTATUS Status;
ULONG Length;
PVOID RefCount;
PVOID SystemBuffer;
UCHAR MajorFunction;
PFN_WDF_REQUEST_CANCEL CancelRoutine;
BOOLEAN Cancelled;
PVOID Type3InputBuffer;
PFDO_DATA Extension; //PSERIAL_DEVICE_EXTENSION Extension;
ULONG IoctlCode;
BOOLEAN MarkCancelableOnResume;
} REQUEST_CONTEXT, *PREQUEST_CONTEXT;

WDF_DECLARE_CONTEXT_TYPE_WITH_NAME(REQUEST_CONTEXT, MxCanGetRequestContext)
========================Request Context End================

Thanks in advance

Peter_Viscarola_OSR · March 14, 2014, 8:43am

Do the two huge boxes with stars around them saying “your debugger is not using the correct symbols” not hint to you that your debugger is not using the correct symbols?

Fix the symbols, please… Then come back and talk with us.

Peter
OSR
@OSRDrivers

Hsin_Hui_Chiang · March 14, 2014, 10:36am

Thank you for reminding me of that. I will change to standard OS instead of embedded OS.

OSR_Community_User · March 14, 2014, 12:26pm

> Thank you for reminding me of that. I will change to standard OS instead

of embedded OS.

That’s the wrong solution. The correct solution is to get the right
symbols. The best way to do this is to learn how to set up to use the
Microsoft symbol server.
Joe

NTDEV is sponsored by OSR

Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev

OSR is HIRING!! See http://www.osr.com/careers

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

Hsin_Hui_Chiang · March 15, 2014, 11:17pm

Dear Joseph:
Thanks for your suggestion, I try to set symbol path to SRV*c:\Symbols*http://msdl.microsoft.com/download/symbols and reload the symbols but still get the same error

I have no idea how to solve it, I run windbg on my win7 SP1 64-bit notebook and have debugging symbols installed and my target device is Win7 SP1 32-bit computer.

Is there something I missed in my settings? Any idea is appreciated.

OSR_Community_User · March 16, 2014, 4:34am

> Dear Joseph:

Thanks for your suggestion, I try to set symbol path to
SRV*c:\Symbols*http://msdl.microsoft.com/download/symbols and reload
the symbols but still get the same error

Setting the symbol server doesn’t make the error itself go away; it just
means that when you do !analyze -v, you will get a meaningful dump.

Note also that if you have a driver of your own, you need to include its
symbol directory in the symbol search path.

I have no idea how to solve it, I run windbg on my win7 SP1 64-bit
notebook and have debugging symbols installed and my target device is Win7
SP1 32-bit computer.

Is there something I missed in my settings? Any idea is appreciated.

NTDEV is sponsored by OSR

Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev

OSR is HIRING!! See http://www.osr.com/careers

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

Alex_Grig · March 16, 2014, 5:51pm

>Note also that if you have a driver of your own, you need to include its
symbol directory in the symbol search path.

If your debugger host is the same as build machine, the .PDB will be picked from the build target folder.

Scott_Noone_OSR · March 17, 2014, 8:28am

You can safely ignore the missing symbol warnings if they are in reference
to kernel32!pNlsUserInfo, such as in your output:

*************************************************************************
…
*** Your debugger is not using the correct symbols
…
*** Type referenced: kernel32!pNlsUserInfo
***
*************************************************************************

This is a user mode thing that you don’t care about.

Your original dump was missing symbols for wdf01000.sys as well though,
which is bad. If you have a new crash with symbols for wdf01000 (!chksym
wdf01000), check the IFR with !wdfkd.wdflogdump to see if there’s anything
interesting. It looks to me like you’re calling an accessor method on a
destroyed object.

-scott
@OSRDrivers

wrote in message news:xxxxx@ntdev…

Note also that if you have a driver of your own, you need to include its
symbol directory in the symbol search path.

If your debugger host is the same as build machine, the .PDB will be picked
from the build target folder.

Hsin_Hui_Chiang · March 17, 2014, 9:37am

Dear All:
Thanks for your information.

Dear Scott:
I run the commands but sadly I don’t get something interesting.

====================Windbg Message Start============================
1: kd> !chksym

!chksym [symbol]

!chksym tests the validity of a module against a symbol file.
The module can be specified by either its name or base address.
If a symbol file is not specified, then the loaded symbol is tested.
Otherwise, if a pdb or dbg symbol file path is specified, it is tested
against the loaded module.

1: kd> !chksym wdf01000

Wdf01000.sys
Timestamp: 4A5BBF28
SizeOfImage: 71000
pdb: Wdf01000.pdb
pdb sig: A9E46808-F4F7-4817-8D30-71AA9EE76FB7
age: 1

Loaded pdb is c:\symbols\Wdf01000.pdb\A9E46808F4F748178D3071AA9EE76FB71\Wdf01000.pdb

Wdf01000.pdb
pdb sig: A9E46808-F4F7-4817-8D30-71AA9EE76FB7
age: 1

MATCH: Wdf01000.pdb and Wdf01000.sys

1: kd> !wdfkd.wdflogdump
error: Could not retrieve driver name parameter.
hint: Did you give the driver name parameter?
====================Windbg Message End============================

Doron_Holan · March 17, 2014, 10:23am

For wdfkd.wdflogdump to work, you need to have your driver symbols loaded and you need to specify your driver name on the command line

d

Bent from my phone

From: xxxxx@moxa.com mailto:xxxxx
Sent: ?3/?17/?2014 6:37 AM
To: Windows System Software Devs Interest Listmailto:xxxxx
Subject: RE:[ntdev] BSOD on WdfObjectGetTypedContextWorker

Dear All:
Thanks for your information.

Dear Scott:
I run the commands but sadly I don’t get something interesting.

====================Windbg Message Start============================
1: kd> !chksym

!chksym [symbol]

!chksym tests the validity of a module against a symbol file.
The module can be specified by either its name or base address.
If a symbol file is not specified, then the loaded symbol is tested.
Otherwise, if a pdb or dbg symbol file path is specified, it is tested
against the loaded module.

1: kd> !chksym wdf01000

Wdf01000.sys
Timestamp: 4A5BBF28
SizeOfImage: 71000
pdb: Wdf01000.pdb
pdb sig: A9E46808-F4F7-4817-8D30-71AA9EE76FB7
age: 1

Loaded pdb is c:\symbols\Wdf01000.pdb\A9E46808F4F748178D3071AA9EE76FB71\Wdf01000.pdb

Wdf01000.pdb
pdb sig: A9E46808-F4F7-4817-8D30-71AA9EE76FB7
age: 1

MATCH: Wdf01000.pdb and Wdf01000.sys

1: kd> !wdfkd.wdflogdump
error: Could not retrieve driver name parameter.
hint: Did you give the driver name parameter?
====================Windbg Message End============================

—
NTDEV is sponsored by OSR

Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev

OSR is HIRING!! See http://www.osr.com/careers

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</mailto:xxxxx></mailto:xxxxx>

Hsin_Hui_Chiang · March 18, 2014, 7:57am

Dear All:

I try the following command but i’m still unable to get the clue.

TMF file used for formatting log is: C:\WinDBG\i386\wdf01000.tmf
Log at 85e4b000
Gather log: Please wait, this may take a moment (reading 4032 bytes).
% read so far … 10, 20, 30, 40, 50, 60, 70, 80, 90, 100
There are 90 log entries
— start of log —
Unknown( 26): GUID=b08d780f-dac6-1796-1fec-bf92340e06bb (No Format Information found).
Unknown( 12): GUID=950bd909-4e9f-8c00-5d83-948120fba76d (No Format Information found).
Unknown( 12): GUID=950bd909-4e9f-8c00-5d83-948120fba76d (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 14): GUID=1c6af04a-8c20-a063-1976-7299d70a2744 (No Format Information found).
Unknown( 14): GUID=1c6af04a-8c20-a063-1976-7299d70a2744 (No Format Information found).
Unknown( 14): GUID=1c6af04a-8c20-a063-1976-7299d70a2744 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 14): GUID=31f474a8-23f3-c270-e156-7b455a6f635c (No Format Information found).
Unknown( 14): GUID=31f474a8-23f3-c270-e156-7b455a6f635c (No Format Information found).
Unknown( 14): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 20): GUID=0cb05f64-1305-ad9b-046c-8d30905d67c5 (No Format Information found).
Unknown( 15): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 14): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 20): GUID=0cb05f64-1305-ad9b-046c-8d30905d67c5 (No Format Information found).
Unknown( 15): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 15): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 15): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 14): GUID=31f474a8-23f3-c270-e156-7b455a6f635c (No Format Information found).
Unknown( 14): GUID=31f474a8-23f3-c270-e156-7b455a6f635c (No Format Information found).
Unknown( 14): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 14): GUID=31f474a8-23f3-c270-e156-7b455a6f635c (No Format Information found).
Unknown( 14): GUID=31f474a8-23f3-c270-e156-7b455a6f635c (No Format Information found).
Unknown( 17): GUID=d5bee12d-f3d5-3523-08d6-a905ce438286 (No Format Information found).
Unknown( 14): GUID=1c6af04a-8c20-a063-1976-7299d70a2744 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 26): GUID=b08d780f-dac6-1796-1fec-bf92340e06bb (No Format Information found).
Unknown( 12): GUID=950bd909-4e9f-8c00-5d83-948120fba76d (No Format Information found).
Unknown( 12): GUID=950bd909-4e9f-8c00-5d83-948120fba76d (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 14): GUID=1c6af04a-8c20-a063-1976-7299d70a2744 (No Format Information found).
Unknown( 14): GUID=1c6af04a-8c20-a063-1976-7299d70a2744 (No Format Information found).
Unknown( 14): GUID=1c6af04a-8c20-a063-1976-7299d70a2744 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 14): GUID=31f474a8-23f3-c270-e156-7b455a6f635c (No Format Information found).
Unknown( 14): GUID=31f474a8-23f3-c270-e156-7b455a6f635c (No Format Information found).
Unknown( 14): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 14): GUID=31f474a8-23f3-c270-e156-7b455a6f635c (No Format Information found).
Unknown( 14): GUID=31f474a8-23f3-c270-e156-7b455a6f635c (No Format Information found).
Unknown( 17): GUID=d5bee12d-f3d5-3523-08d6-a905ce438286 (No Format Information found).
Unknown( 14): GUID=1c6af04a-8c20-a063-1976-7299d70a2744 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 26): GUID=b08d780f-dac6-1796-1fec-bf92340e06bb (No Format Information found).
Unknown( 12): GUID=950bd909-4e9f-8c00-5d83-948120fba76d (No Format Information found).
Unknown( 12): GUID=950bd909-4e9f-8c00-5d83-948120fba76d (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 15): GUID=9fad61e3-68ff-f42e-15fe-7a3fb252225e (No Format Information found).
Unknown( 14): GUID=1c6af04a-8c20-a063-1976-7299d70a2744 (No Format Information found).
Unknown( 14): GUID=1c6af04a-8c20-a063-1976-7299d70a2744 (No Format Information found).
Unknown( 14): GUID=1c6af04a-8c20-a063-1976-7299d70a2744 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 14): GUID=31f474a8-23f3-c270-e156-7b455a6f635c (No Format Information found).
Unknown( 14): GUID=31f474a8-23f3-c270-e156-7b455a6f635c (No Format Information found).
Unknown( 14): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 20): GUID=0cb05f64-1305-ad9b-046c-8d30905d67c5 (No Format Information found).
Unknown( 15): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 14): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 20): GUID=0cb05f64-1305-ad9b-046c-8d30905d67c5 (No Format Information found).
Unknown( 15): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 15): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 15): GUID=d816b6e3-c6ba-363d-54b4-3533d1de16bb (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
Unknown( 16): GUID=a06c4939-ec03-9e2b-f095-211ff9a6d5e5 (No Format Information found).
---- end of log ----

Hsin_Hui_Chiang · March 25, 2014, 12:48pm

Dear All:
I temporarily skip this BSOD by storing the values in device extension instead of in request’s context
, but I encounter the another BSOD which stuck at WdfRequestMarkCancelable and this phenomenon happens after 20 minutes, so I’m not sure what’s wrong with my code.
And then I remove the cancel function and run the test again, and it passes the test over 8 hours.
Both read and write call WdfRequestMarkCancelable in EvtIoRead/EvtIoWrite function and call WdfRequestUnmarkCancelable in DPC routine, but the BSOD issue always happens in read operation and not in write operation.
Is there something I miss in my code to cause this issue? But why it happens after 20 minutes but not at start up?

Thanks in advance.

Tim_Roberts · March 25, 2014, 1:28pm

xxxxx@moxa.com wrote:

I temporarily skip this BSOD by storing the values in device extension instead of in request’s context, but I encounter the another BSOD which stuck at WdfRequestMarkCancelable and this phenomenon happens after 20 minutes, so I’m not sure what’s wrong with my code.

No doubt. Looking back on this thread, you’ve spent an awful lot of
time dealing with why you can’t get your symbols straight, and no time
at all on your code. In your original stack dump, it looked like you
were callimg MxCanSetCancelRoutine with a NULL IRP. That’s always going
to fail.

You haven’t shown us any code at all. You can’t expect us to offer help
without seeing what your code actually does.

Is there something I miss in my code to cause this issue?

Yes.

–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.

Hsin_Hui_Chiang · March 26, 2014, 1:55am

Dear Tim:
You are right, that’s my miss. The code of read operation to mark and unmark the request to be cancelable is as follows:

Thanks.

====================Start Read operation========================
VOID
ToasterEvtIoRead (
WDFQUEUE Queue,
WDFREQUEST Request,
size_t Length
)
{
…
status = WdfRequestRetrieveOutputBuffer (Request, Length, &extension->SystemBuffer, &bufLen);
if(!NT_SUCCESS(status) )
{
KdPrint((“ToasterEvtIoRead : WdfRequestRetrieveOutputBuffer fail, status = 0x%x\n”, status));
MxCanCompleteRequest(Request , status, 0);

return;
}
else
{
KdPrint((“ToasterEvtIoRead : WdfRequestRetrieveOutputBuffer Success, extension->SystemBuffer = %p\n”, extension->SystemBuffer));
}

ASSERT(bufLen == extension->Length);

// Well it looks like we actually have to do some
// work. Put the read on the queue so that we can
// process it when our previous reads are done.
//
MxCanStartOrQueue(extension, Request, extension->ReadQueue, &extension->CurrentReadRequest, MxCanStartRead);

return;
…
}

VOID
MxCanStartOrQueue(
IN PFDO_DATA Extension, //IN PSERIAL_DEVICE_EXTENSION Extension, //TODO:Need to change to IN PMXCAN_DEVICE_EXTENSION Extension
IN WDFREQUEST Request,
IN WDFQUEUE QueueToExamine,
IN WDFREQUEST *CurrentOpRequest,
IN PMXCAN_START_ROUTINE Starter
)
{

NTSTATUS status = STATUS_SUCCESS;
PREQUEST_CONTEXT reqContext;
WDF_REQUEST_PARAMETERS params;

WDF_REQUEST_PARAMETERS_INIT(&params);

WdfRequestGetParameters(
Request,
&params);

//
// If this is a write request then take the amount of characters
// to write and add it to the count of characters to write.
//

if (params.Type == WdfRequestTypeWrite) {

Extension->TotalCharsQueued += Extension->Length;

}

*CurrentOpRequest = Request;

Starter(Extension);

return;
}

VOID
MxCanStartRead(
IN PFDO_DATA Extension
)
{
MXCAN_UPDATE_CHAR updateChar;

WDFREQUEST newRequest;

BOOLEAN returnWithWhatsPresent;
BOOLEAN useTotalTimer = FALSE;
BOOLEAN useIntervalTimer = FALSE;

ULONG multiplierVal = 0;
ULONG constantVal = 0;
BOOLEAN result = FALSE;

LARGE_INTEGER totalTime = {0};

PREQUEST_CONTEXT reqContext;

KdPrint((“++Enter MxCanStartRead(%p)\n”, Extension));
updateChar.Extension = Extension;

Extension->ShortIntervalAmount.QuadPart = -1;
Extension->LongIntervalAmount.QuadPart = -10000000;
Extension->CutOverAmount.QuadPart = 200000000;
Extension->NumberNeededForRead = Extension->Length;

//
// We do this copy in the hope of getting most (if not
// all) of the characters out of the interrupt buffer.
//
// Note that we need to protect this operation with a
// spinlock since we don’t want a purge to hose us.
//
updateChar.CharsCopied = MxCanGetCharsFromIntBuffer(Extension);
KdPrint((“MxCanStartRead : updateChar.CharsCopied = %d\n”, updateChar.CharsCopied));
KdPrint((“MxCanStartRead : Extension->WdfInterrupt = %d\n”, Extension->WdfInterrupt));

/* Get current IRQL */
if (KeGetCurrentIrql() <= DISPATCH_LEVEL)
{
KdPrint((“MxCanStartRead : KeGetCurrentIrql() <= DISPATCH_LEVEL\n”));
}
else
{
KdPrint((“MxCanStartRead : KeGetCurrentIrql() > DISPATCH_LEVEL\n”));
}

//
// See if we have any cause to return immediately.
//
if ((!Extension->NumberNeededForRead))
{
KdPrint((“MxCanStartRead : Extension->NumberNeededForRead = 0\n”));
//
// We got all we needed for this read.
// Update the number of characters in the
// interrupt read buffer.
//
WdfInterruptSynchronize(
Extension->WdfInterrupt,
MxCanUpdateInterruptBuffer,
&updateChar
);

Extension->Status = STATUS_SUCCESS;
}
else
{
KdPrint((“MxCanStartRead : Extension->NumberNeededForRead = %d\n”, Extension->NumberNeededForRead));

//
// The request might go under control of the isr. It
// won’t hurt to initialize the reference count
// right now.
//
MXCAN_INIT_REFERENCE(Extension);

//
// We still need to get more characters for this read.
// synchronize with the isr so that we can update the
// number of characters and if necessary it will have the
// isr switch to copying into the users buffer.
//

WdfInterruptSynchronize(
Extension->WdfInterrupt,
MxCanUpdateAndSwitchToUser,
&updateChar
);

if (!updateChar.Completed)
{
KdPrint((“MxCanStartRead : !updateChar.Completed, prepare to set cancel routine\n”));
MxCanSetCancelRoutine(Extension, Extension->CurrentReadRequest, MxCanCancelCurrentRead); <------We set cancel routine here
}
}
KdPrint((“–Leave MxCanStartRead \n”));

return;

====================End Read Operation==========================

====================Start ISR Operation==========================
BOOLEAN
MxCanEvtChildIsr(
IN PVOID Context
)

{
WDFDEVICE device;
PFDO_DATA fdoData, pDevExt;
UCHAR buffer[sizeof(CANMSG)];
unsigned int interrupt = 0;
BOOLEAN ourOwnInerrupt = FALSE;
ULONG amountToWrite = sizeof(CANMSG);
PFDO_DATA Extension = NULL;
PREQUEST_CONTEXT reqContext = NULL;
HWPORT *pHwPort;

KdPrint((“++ Enter MxCanEvtChildIsr\n”));

/* Get child device stored in Context which bus driver passed in */
device = (WDFDEVICE) Context;

/* Get device extension from interrupt */
fdoData = ToasterFdoGetData(device);
pDevExt = fdoData;
Extension = fdoData;
pHwPort = Extension->pHwPort;

/* Get interrupts */
interrupt = hwport_get_interrupts(pDevExt->pHwPort);
KdPrint((“MxCanEvtChildIsr : interrupt = 0x%x\n”, interrupt));

if(interrupt & INTERRUPT_TYPE_RX)
{
KdPrint((“MxCanEvtChildIsr : INTERRUPT_TYPE_RX\n”));
ourOwnInerrupt = TRUE;

/* Read data from device */
hwport_read(pDevExt->pHwPort, (char *)&buffer, sizeof(buffer));

/* Store the data to interrupt buffer */
MxCanPutChar(pDevExt, (PUCHAR)buffer);

}

if(interrupt & INTERRUPT_TYPE_TX)
{
KdPrint((“MxCanEvtChildIsr : INTERRUPT_TYPE_TX\n”));
ourOwnInerrupt = TRUE;

/* Prepare amount to write */
amountToWrite = (sizeof(CANMSG) < Extension->WriteLength)? sizeof(CANMSG): Extension->WriteLength;
KdPrint((“MxCanEvtChildIsr : amountToWrite = %d\n”, amountToWrite));

/* Prepare buffer address to be sent */
Extension->HoldingEmpty = FALSE;
Extension->WriteCurrentChar += amountToWrite;
Extension->WriteLength -= amountToWrite;

KdPrint((“MxCanEvtChildIsr : Extension->WriteCurrentChar = %p\n”, Extension->WriteCurrentChar));
KdPrint((“MxCanEvtChildIsr : Extension->WriteLength = %d\n”, Extension->WriteLength));

KdPrint((“MxCanEvtChildIsr : Write all data, now we can complete the request\n”));

/* Assign the return length */
Extension->Information = Extension->Length;

/* Enqueue the TX DPC to complete the write request */
WdfDpcEnqueue(pDevExt->CompleteWriteDpc);
}

KdPrint((“-- Leave MxCanEvtChildIsr\n”));

return ourOwnInerrupt;
}

VOID
MxCanPutChar(
IN PFDO_DATA Extension,
IN PUCHAR CharsToPut
)
{
CANMSG *msg = NULL;
unsigned int i = 0;
PREQUEST_CONTEXT reqContext = NULL;

KdPrint((“+++MxCanPutChar\n”));
KdPrint((“MxCanPutChar : Extension->CharsInInterruptBuffer = %d\n”, Extension->CharsInInterruptBuffer));

//
// Check to see if we are copying into the
// users buffer or into the interrupt buffer.
//
// If we are copying into the user buffer
// then we know there is always room for one more.
// (We know this because if there wasn’t room
// then that read would have completed and we
// would be using the interrupt buffer.)
//
// If we are copying into the interrupt buffer
// then we will need to check if we have enough
// room.
//
KdPrint((“MxCanPutChar : Extension->ReadBufferBase = 0x%p\n”, Extension->ReadBufferBase));
KdPrint((“MxCanPutChar : Extension->InterruptReadBuffer = 0x%p\n”, Extension->InterruptReadBuffer));
if(Extension->ReadBufferBase != Extension->InterruptReadBuffer)
{
KdPrint((“MxCanPutChar : We are in user buffer\n”));
//
// Increment the following value so
// that the interval timer (if one exists
// for this read) can know that a character
// has been read.
//

//Extension->ReadByIsr++;
KdPrint((“MxCanPutChar : Extension->ReadByIsr(Before) = 0x%x\n”, Extension->ReadByIsr));
Extension->ReadByIsr+= sizeof(CANMSG);
KdPrint((“MxCanPutChar : Extension->ReadByIsr(After) = 0x%x\n”, Extension->ReadByIsr));

//
// We are in the user buffer. Place the
// character into the buffer. See if the
// read is complete.
//

/* Store the CAN message into user buffer */
RtlCopyMemory(Extension->CurrentCharSlot, CharsToPut, sizeof(CANMSG));

KdPrint((“Extension->CurrentCharSlot = %p\n”, Extension->CurrentCharSlot));
KdPrint((“Extension->LastCharSlot = %p\n”, Extension->LastCharSlot));*/

/* Accumulate the location of CurrentCharSlot */
Extension->CurrentCharSlot += (sizeof(CANMSG));
KdPrint((“Extension->CurrentCharSlot(Accumulate) = %p\n”, Extension->CurrentCharSlot));
KdPrint((“Extension->LastCharSlot = %p\n”, Extension->LastCharSlot));

if((Extension->CurrentCharSlot - 1) == Extension->LastCharSlot) {

KdPrint((“MxCanPutChar : We have fill up the user’s buffer\n”));

//
// We’ve filled up the users buffer.
// Switch back to the interrupt buffer
// and send off a DPC to Complete the read.
//
// It is inherent that when we were using
// a user buffer that the interrupt buffer
// was empty.
//

Extension->ReadBufferBase =
Extension->InterruptReadBuffer;
Extension->CurrentCharSlot =
Extension->InterruptReadBuffer;
Extension->FirstReadableChar =
Extension->InterruptReadBuffer;
Extension->LastCharSlot =
Extension->InterruptReadBuffer +
(Extension->BufferSize - 1);
Extension->CharsInInterruptBuffer = 0;

Extension->Information = Extension->Length;
Extension->Status = STATUS_SUCCESS;

MxCanInsertQueueDpc(
Extension->CompleteReadDpc <---- Go to MxCanCompleteRead function
);
}
}

KdPrint((“—MxCanPutChar\n”));
}

VOID
MxCanCompleteRead(
IN WDFDPC Dpc
)
{
PFDO_DATA fdoData = NULL;
PDEVICE_EXTENSION pDevExt = NULL;
PDEVICE_EXTENSION extension = NULL;

KdPrint((“+++ MxCanCompleteRead DPC\n”));

/* Get device extension */
fdoData = ToasterFdoGetData(WdfDpcGetParentObject(Dpc));
pDevExt = fdoData;
extension = pDevExt;

//
// We set this to indicate to the interval timer
// that the read has completed.
//
// Recall that the interval timer dpc can be lurking in some
// DPC queue.
//

extension->CountOnLastRead = MXCAN_COMPLETE_READ_COMPLETE;

MxCanTryToCompleteCurrent(
extension,
NULL,
STATUS_SUCCESS,
&extension->CurrentReadRequest,
MXCAN_REF_ISR
);

KdPrint((“— MxCanCompleteRead DPC\n”));
}

VOID
MxCanTryToCompleteCurrent(
IN PFDO_DATA Extension,
IN PFN_WDF_INTERRUPT_SYNCHRONIZE SynchRoutine OPTIONAL,
IN NTSTATUS StatusToUse,
IN WDFREQUEST *CurrentOpRequest,
IN LONG RefType
)
{
PREQUEST_CONTEXT reqContext;
WDFREQUEST newRequest;
WDFREQUEST oldRequest;

WDFFILEOBJECT fileObject; //Add by Epson 2014-03-18
PFDO_DATA extension; //Add by Epson 2014-03-18

KdPrint((“+++ MxCanTryToCompleteCurrent\n”));
/* Get WDFFILEOBJECT from request */ //Add by Epson 2014-03-18
fileObject = WdfRequestGetFileObject(*CurrentOpRequest);

/* Get device extension from WDFFILEOBJECT */
extension = ToasterFdoGetData(WdfFileObjectGetDevice(fileObject));

KdPrint((“MxCanTryToCompleteCurrent : *CurrentOpRequest = 0x%p\n”, *CurrentOpRequest));

if(RefType == MXCAN_REF_ISR) {
//
// We can decrement the reference to “remove” the fact
// that the caller no longer will be accessing this request.
//
MXCAN_CLEAR_REFERENCE(
extension,
RefType
);
}

if (SynchRoutine) {

WdfInterruptSynchronize(
Extension->WdfInterrupt,
SynchRoutine,
Extension
);
}

//
// Try to run down all other references to this request.
//

MxCanRundownIrpRefs(
CurrentOpRequest,
Extension,
RefType
);

if(StatusToUse == STATUS_CANCELLED) {
KdPrint((“MxCanTryToCompleteCurrent : StatusToUse == STATUS_CANCELLED\n”));
//
// This function is called from a cancelroutine. So mark
// the request as cancelled. We need to do this because
// we may not complete the request below if somebody
// else has a reference to it.
// This state variable was added to avoid calling
// WdfRequestMarkCancelable second time on a request that
// has cancelled but wasn’t completed in the cancel routine.
//
//reqContext->Cancelled = TRUE;
extension->Cancelled = TRUE; //Modify by Epson 2014-03-18
}

//
// See if the ref count is zero after trying to complete everybody else.
//

KdPrint((“MXCAN_REFERENCE_COUNT(extension) = %d\n”, MXCAN_REFERENCE_COUNT(extension)));

if (!MXCAN_REFERENCE_COUNT(extension)) {

//
// The ref count was zero so we should complete this
// request.
//
// The following call will also cause the current request to be
// completed.
//

extension->Status = StatusToUse;

if (StatusToUse == STATUS_CANCELLED) {

KdPrint((“MxCanTryToCompleteCurrent : StatusToUse == STATUS_CANCELLED\n”));
extension->Information = 0;
}

KdPrint((“MxCanTryToCompleteCurrent : We don’t have a new request, complete current request\n”));
oldRequest = *CurrentOpRequest;

KdPrint((“MxCanTryToCompleteCurrent : oldRequest = *CurrentOpRequest\n”));

//
// There was no get next routine. We will simply complete
// the request. We should make sure that we null out the
// pointer to the pointer to this request.
//

*CurrentOpRequest = NULL;

KdPrint((“extension->Information = %d\n”, extension->Information));

extension->Cancelled = FALSE;

MxCanCompleteRequest(oldRequest,
extension->Status,
extension->Information);
}
else {

}

KdPrint((“— MxCanTryToCompleteCurrent\n”));
}

VOID
MxCanRundownIrpRefs(
IN WDFREQUEST *CurrentOpRequest,
//IN WDFTIMER IntervalTimer OPTIONAL,
//IN WDFTIMER TotalTimer OPTIONAL,
IN PFDO_DATA PDevExt,
IN LONG RefType
)
{
PREQUEST_CONTEXT reqContext;
WDFREQUEST request = *CurrentOpRequest;

WDFFILEOBJECT fileObject;
PFDO_DATA extension;

//reqContext = MxCanGetRequestContext(request);

/* Get WDFFILEOBJECT from request */
fileObject = WdfRequestGetFileObject(request);

/* Get device extension from WDFFILEOBJECT */
extension = ToasterFdoGetData(WdfFileObjectGetDevice(fileObject));
if(RefType == MXCAN_REF_CANCEL) {
//
// Caller is a cancel routine. So just clear the reference.
//
MXCAN_CLEAR_REFERENCE( extension, MXCAN_REF_CANCEL );
extension->CancelRoutine = NULL;
}
else
{
//
// Try to clear the cancelable state.
//
MxCanClearCancelRoutine(request, TRUE); <–We clear cancel routine here
}
}
====================End ISR Operation==========================

Hsin_Hui_Chiang · March 26, 2014, 6:18am

VOID
MxCanSetCancelRoutine(
IN PFDO_DATA Extension,
IN WDFREQUEST Request,
IN PFN_WDF_REQUEST_CANCEL CancelRoutine)
{
WDFFILEOBJECT fileObject;
PFDO_DATA extension;
NTSTATUS status = STATUS_SUCCESS;
extension = Extension;

KdPrint((“+++ MxCanSetCancelRoutine \n”));
KdPrint((“MxCanSetCancelRoutine Request = %p\n”, Request));

if(Request!=NULL)
{
status = WdfRequestMarkCancelableEx(Request, CancelRoutine);
if(!NT_SUCCESS(status))
{
switch(status)
{
case STATUS_CANCELLED:
WdfRequestComplete (Request, status);
break;

case STATUS_INVALID_DEVICE_REQUEST:
WdfRequestComplete (Request, status);
break;

default:
WdfRequestComplete (Request, status);
break;
}
}
else
{

MXCAN_SET_REFERENCE(extension, MXCAN_REF_CANCEL);
extension->CancelRoutine = CancelRoutine;

}

}
KdPrint((“— MxCanSetCancelRoutine\n”));
return;
}

NTSTATUS
MxCanClearCancelRoutine(
IN WDFREQUEST Request,
IN BOOLEAN ClearReference
)
{
NTSTATUS status = STATUS_SUCCESS;
WDFFILEOBJECT fileObject;
PFDO_DATA extension;

/* Get WDFFILEOBJECT from request */
fileObject = WdfRequestGetFileObject(Request);

/* Get device extension from WDFFILEOBJECT */
extension = ToasterFdoGetData(WdfFileObjectGetDevice(fileObject));

KdPrint((“+++ MxCanClearCancelRoutine %p %x\n”, Request, ClearReference));

if(MXCAN_TEST_REFERENCE(extension, MXCAN_REF_CANCEL))
{
status = WdfRequestUnmarkCancelable(Request);
if (NT_SUCCESS(status)) {

KdPrint((“MxCanClearCancelRoutine : WdfRequestUnmarkCancelable success\n”));
extension->CancelRoutine = NULL;
if(ClearReference)
{
MXCAN_CLEAR_REFERENCE( extension, MXCAN_REF_CANCEL );
}
}
else {
KdPrint((“MxCanClearCancelRoutine : WdfRequestUnmarkCancelable fail\n”));
ASSERT(status == STATUS_CANCELLED);
}
}

KdPrint((“— MxCanClearCancelRoutine\n”));

return status;
}

Tim_Roberts · March 26, 2014, 1:25pm

xxxxx@moxa.com wrote:

Dear Tim:
You are right, that’s my miss. The code of read operation to mark and unmark the request to be cancelable is as follows:

One thing that you don’t show here is where you create your request
context and associate it with the WDFREQUEST. I see that
ToasterEvtIoRead gets the request and calls MxCanStartOrQueue. That
routine stores the request in extension->CurrentReadRequest and calls
MxCanStartRead. MxCanStartRead eventually calls MxCanSetCancelRoutine.
But in all that time, I don’t ever see you creating the request
context. If that were so, then of course an attempt to fetch the
context from the request in MxCanSetCancelRoutine is going to fail.

By the way, I see you passing WDFREQUEST* pointers here. That is almost
always a bad idea. All of the WDF object types are handles. They are
the size of a pointer, and should all be passed by value.

–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.

Hsin_Hui_Chiang · March 27, 2014, 3:12am

Dear Tim:
I initialize the request context in EvtDeviceAdd function, the code is as follows:
And thanks for your suggestion, I will try to avoid to use WDFREQUEST* pointer.

====================Code Start==========================
NTSTATUS
ToasterEvtDeviceAdd(
IN WDFDRIVER Driver,
IN PWDFDEVICE_INIT DeviceInit
)
/*++
Routine Description:

ToasterEvtDeviceAdd is called by the framework in response to AddDevice
call from the PnP manager. We create and initialize a device object to
represent a new instance of toaster device.

Arguments:

Driver - Handle to a framework driver object created in DriverEntry

DeviceInit - Pointer to a framework-allocated WDFDEVICE_INIT structure.

Return Value:

NTSTATUS

–*/
{
NTSTATUS status = STATUS_SUCCESS;
WDF_PNPPOWER_EVENT_CALLBACKS pnpPowerCallbacks;
WDF_OBJECT_ATTRIBUTES fdoAttributes;
WDF_OBJECT_ATTRIBUTES reqAttributes;
WDFDEVICE device;
WDF_FILEOBJECT_CONFIG fileConfig;
WDF_DEVICE_POWER_POLICY_IDLE_SETTINGS idleSettings;
WDF_DEVICE_POWER_POLICY_WAKE_SETTINGS wakeSettings;
WDF_POWER_POLICY_EVENT_CALLBACKS powerPolicyCallbacks;
WDF_IO_QUEUE_CONFIG queueConfig;
PFDO_DATA fdoData;
WDFQUEUE queue;
DECLARE_UNICODE_STRING_SIZE(win32DeviceName, MAX_ID_LEN); DECLARE_UNICODE_STRING_SIZE(ntDeviceName, MAX_ID_LEN);
WDF_INTERRUPT_CONFIG InterruptConfig;
WDFINTERRUPT Interrupt;
PDEVICE_EXTENSION pDevExt;
PDEVICE_OBJECT pDevObj;

UNREFERENCED_PARAMETER(Driver);

PAGED_CODE();

KdPrint((“ToasterEvtDeviceAdd called\n”));

/* Set request attributes*/
WDF_OBJECT_ATTRIBUTES_INIT_CONTEXT_TYPE(&reqAttributes, REQUEST_CONTEXT);
WdfDeviceInitSetRequestAttributes(DeviceInit, &reqAttributes); <– Set request context here

//
// Initialize the pnpPowerCallbacks structure. Callback events for PNP
// and Power are specified here. If you don’t supply any callbacks,
// the Framework will take appropriate default actions based on whether
// DeviceInit is initialized to be an FDO, a PDO or a filter device
// object.
//

WDF_PNPPOWER_EVENT_CALLBACKS_INIT(&pnpPowerCallbacks);

//
// Register PNP callbacks.
//
pnpPowerCallbacks.EvtDevicePrepareHardware = ToasterEvtDevicePrepareHardware;
pnpPowerCallbacks.EvtDeviceReleaseHardware = ToasterEvtDeviceReleaseHardware;
pnpPowerCallbacks.EvtDeviceSelfManagedIoInit = ToasterEvtDeviceSelfManagedIoInit;

//
// Register Power callbacks.
//
pnpPowerCallbacks.EvtDeviceD0Entry = ToasterEvtDeviceD0Entry;
pnpPowerCallbacks.EvtDeviceD0Exit = ToasterEvtDeviceD0Exit;

WdfDeviceInitSetPnpPowerEventCallbacks(DeviceInit, &pnpPowerCallbacks);
…

====================Code End==========================

And here is the structure definition
====================Structure Start==========================
typedef struct _REQUEST_CONTEXT {
ULONG_PTR Information;
NTSTATUS Status;
ULONG Length;
PVOID RefCount;
PVOID SystemBuffer;
UCHAR MajorFunction;
PFN_WDF_REQUEST_CANCEL CancelRoutine;
BOOLEAN Cancelled;
PVOID Type3InputBuffer;
ULONG IoctlCode;
BOOLEAN MarkCancelableOnResume;
} REQUEST_CONTEXT, *PREQUEST_CONTEXT;
====================Structure End==========================

Hsin_Hui_Chiang · March 27, 2014, 5:29am

Dear All:
I compare the code flow of read and write operation, and I found that in write operation MxCanSetCancelRoutine is called before calling WdfInterruptSynchronize but in read operation MxCanSetCancelRoutine is called after calling WdfInterruptSynchronize, so I change the sequence the same with write operation as following code, and then everything works fine.

I am curious about the root cause, does my code violate the WDF driver rules, so that I got the BSOD after setting the cancel routine? But why it happens after 20 mins?

====================Code Start==========================
KdPrint((“MxCanStartRead : Extension->NumberNeededForRead = %d\n”, Extension->NumberNeededForRead));

//
// The request might go under control of the isr. It
// won’t hurt to initialize the reference count
// right now.
//
MXCAN_INIT_REFERENCE(Extension);

MxCanSetCancelRoutine(Extension, Extension->CurrentReadRequest, MxCanCancelCurrentRead);

//
// We still need to get more characters for this read.
// synchronize with the isr so that we can update the
// number of characters and if necessary it will have the
// isr switch to copying into the users buffer.
//

WdfInterruptSynchronize(
Extension->WdfInterrupt,
MxCanUpdateAndSwitchToUser,
&updateChar
);
====================Code Stop==========================

Tim_Roberts · March 27, 2014, 12:41pm

xxxxx@moxa.com wrote:

Dear All:
I compare the code flow of read and write operation, and I found that in write operation MxCanSetCancelRoutine is called before calling WdfInterruptSynchronize but in read operation MxCanSetCancelRoutine is called after calling WdfInterruptSynchronize, so I change the sequence the same with write operation as following code, and then everything works fine.

I am curious about the root cause, does my code violate the WDF driver rules, so that I got the BSOD after setting the cancel routine? But why it happens after 20 mins?

Without stepping through the code line-by-line, there’s no way I could
answer this. Even with KMDF, the path to correct cancellation handling
is filled with potholes and detours. It’s way too easy to leave gaps
where things are vulnerable, and if the gap is small, it might take a
very long time to fall in.

–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.

OSR_Community_User · March 28, 2014, 3:28am

It was 1968. I was doing some kernel mods on IBM’s TSS/360. I ran across
some code that was truly a wonder to behold. Assembly code, of course,
but clean, elegant, well-commented with comments that made sense.

Then I got to the part where the shared memory cache was being updated.
Instead of the atomic TS (Test-and-Set, the 360’s equivalent of
InterlockedCompareAndExchange) instruction, there was a compare, a branch,
and a set. I pointed this out to my manager, who agreed it was wrong. We
initiated a formal bug report to IBM, and I replaced the offending
instruction. Suddenly, a set of inexplicable crashes, all of which
happened in the same place, went away. There had been one a week for
nearly a year. But that particular BSOD-equivalent (known as an
“OS-ABEND”) ceased. There was a one-instruction-cycle window, and we were
hitting it about once a week. I learned a very practical lesson about the
need for synchronization correctness: there is no such thing as “almost
right” or “probably right”. Unlike many real scenarios, synchronization
has only two states: “right” and “wrong”. Forty-six years later we are
still wrestling with these problems, which is a sad commentary on the
state of our tools and our programming maturity over that period of time.
joe

xxxxx@moxa.com wrote:
> Dear All:
> I compare the code flow of read and write operation, and I found
> that in write operation MxCanSetCancelRoutine is called before
> calling WdfInterruptSynchronize but in read operation
> MxCanSetCancelRoutine is called after calling
> WdfInterruptSynchronize, so I change the sequence the same with
> write operation as following code, and then everything works
> fine.
>
> I am curious about the root cause, does my code violate the WDF driver
> rules, so that I got the BSOD after setting the cancel routine? But why
> it happens after 20 mins?

Without stepping through the code line-by-line, there’s no way I could
answer this. Even with KMDF, the path to correct cancellation handling
is filled with potholes and detours. It’s way too easy to leave gaps
where things are vulnerable, and if the gap is small, it might take a
very long time to fall in.

–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.

NTDEV is sponsored by OSR

Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev

OSR is HIRING!! See http://www.osr.com/careers

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