sys: fsp_debug: greatly simplify debugging support

This commit is contained in:
Bill Zissimopoulos 2016-04-10 23:45:09 -07:00
parent adb6819de1
commit 9b81c03ccc
12 changed files with 90 additions and 77 deletions

View File

@ -429,7 +429,7 @@ NTSTATUS FspFsvolCreatePrepare(
FileObject = FspIopRequestContext(Request, RequestFileObject);
/* lock the FileNode for overwriting */
Success = DEBUGTEST(90, TRUE) && FspFileNodeTryAcquireExclusive(FileNode, Full);
Success = DEBUGTEST(90) && FspFileNodeTryAcquireExclusive(FileNode, Full);
if (!Success)
{
FspIopRetryPrepareIrp(Irp, &Result);
@ -706,7 +706,7 @@ static NTSTATUS FspFsvolCreateTryOpen(PIRP Irp, const FSP_FSCTL_TRANSACT_RSP *Re
FSP_FSCTL_TRANSACT_REQ *Request = FspIrpRequest(Irp);
BOOLEAN Success;
Success = DEBUGTEST(90, TRUE) && FspFileNodeTryAcquireExclusive(FileNode, Main);
Success = DEBUGTEST(90) && FspFileNodeTryAcquireExclusive(FileNode, Main);
if (!Success)
{
/* repost the IRP to retry later */

View File

@ -296,4 +296,19 @@ ULONG DebugRandom(VOID)
return Result;
}
VOID FspDebugLogIrp(const char *func, PIRP Irp, NTSTATUS Result)
{
PIO_STACK_LOCATION IrpSp = IoGetCurrentIrpStackLocation(Irp);
DbgPrint("[%d] " DRIVER_NAME "!%s: IRP=%p, %s%c, %s%s, IoStatus=%s[%lld]\n",
KeGetCurrentIrql(),
func,
Irp,
DeviceExtensionKindSym(FspDeviceExtension(IrpSp->DeviceObject)->Kind),
Irp->RequestorMode == KernelMode ? 'K' : 'U',
IrpMajorFunctionSym(IrpSp->MajorFunction),
IrpMinorFunctionSym(IrpSp->MajorFunction, IrpSp->MinorFunction),
NtStatusSym(Result),
(LONGLONG)Irp->IoStatus.Information);
}
#endif

View File

@ -395,7 +395,7 @@ static NTSTATUS FspFsvolQueryDirectoryRetry(
(ULONG)(UINT_PTR)FspIopRequestContext(Request, RequestSystemBufferLength) : 0;
/* try to acquire the FileNode exclusive; Full because we may need to send a Request */
Success = DEBUGTEST(90, TRUE) &&
Success = DEBUGTEST(90) &&
FspFileNodeTryAcquireExclusiveF(FileNode, FspFileNodeAcquireFull, CanWait);
if (!Success)
{
@ -798,7 +798,7 @@ NTSTATUS FspFsvolDirectoryControlComplete(
(ULONG)(UINT_PTR)FspIopRequestContext(Request, RequestDirInfoChangeNumber);
/* acquire FileNode exclusive Full (because we may need to go back to user-mode) */
Success = DEBUGTEST(90, TRUE) && FspFileNodeTryAcquireExclusive(FileNode, Full);
Success = DEBUGTEST(90) && FspFileNodeTryAcquireExclusive(FileNode, Full);
if (!Success)
{
FspIopRetryCompleteIrp(Irp, Response, &Result);

View File

@ -31,7 +31,7 @@ DRIVER_UNLOAD FspUnload;
NTSTATUS DriverEntry(
PDRIVER_OBJECT DriverObject, PUNICODE_STRING RegistryPath)
{
FSP_ENTER();
FSP_ENTER_DRV();
FspDriverMultiVersionInitialize();
@ -158,7 +158,7 @@ NTSTATUS DriverEntry(
IoRegisterFileSystem(FspFsctlDiskDeviceObject);
#pragma prefast(suppress:28175, "We are in DriverEntry: ok to access DriverName")
FSP_LEAVE("DriverName=\"%wZ\", RegistryPath=\"%wZ\"",
FSP_LEAVE_DRV("DriverName=\"%wZ\", RegistryPath=\"%wZ\"",
&DriverObject->DriverName, RegistryPath);
}

View File

@ -35,63 +35,84 @@
#define FSP_ALLOC_EXTERNAL_TAG 'XpsF'
#define FSP_IO_INCREMENT IO_NETWORK_INCREMENT
/* debug */
#if DBG
enum
{
fsp_debug_bp_generic = 0x00000001, /* generic breakpoint switch */
fsp_debug_bp_drvrld = 0x00000002, /* DriverEntry/Unload breakpoint switch */
fsp_debug_bp_ioentr = 0x00000004, /* I/O entry breakpoint switch */
fsp_debug_bp_ioprep = 0x00000008, /* I/O prepare breakpoint switch */
fsp_debug_bp_iocmpl = 0x00000010, /* I/O complete breakpoint switch */
fsp_debug_bp_iocall = 0x00000020, /* I/O callback breakpoint switch */
fsp_debug_bp_iorecu = 0x00000040, /* I/O recursive breakpoint switch */
fsp_debug_dt = 0x01000000, /* DEBUGTEST switch */
fsp_debug_dp = 0x10000000, /* DbgPrint switch */
};
extern __declspec(selectany) int fsp_debug =
fsp_debug_bp_drvrld | fsp_debug_dt;
const char *NtStatusSym(NTSTATUS Status);
const char *IrpMajorFunctionSym(UCHAR MajorFunction);
const char *IrpMinorFunctionSym(UCHAR MajorFunction, UCHAR MinorFunction);
const char *IoctlCodeSym(ULONG ControlCode);
const char *FileInformationClassSym(FILE_INFORMATION_CLASS FileInformationClass);
const char *FsInformationClassSym(FS_INFORMATION_CLASS FsInformationClass);
const char *DeviceExtensionKindSym(UINT32 Kind);
ULONG DebugRandom(VOID);
VOID FspDebugLogIrp(const char *func, PIRP Irp, NTSTATUS Result);
#endif
/* DbgPrint */
#if DBG
extern __declspec(selectany) int fsp_dp = 1;
#define DbgPrint(...) ((void)(fsp_dp ? DbgPrint(__VA_ARGS__) : 0))
#else
#define DbgPrint(...) \
((void)((fsp_debug & fsp_debug_dp) ? DbgPrint(__VA_ARGS__) : 0))
#endif
/* DEBUGLOG */
#if DBG
#define DEBUGLOG(fmt, ...) \
DbgPrint("[%d] " DRIVER_NAME "!" __FUNCTION__ ": " fmt "\n", KeGetCurrentIrql(), __VA_ARGS__)
#else
#define DEBUGLOG(fmt, ...) ((void)0)
#endif
/* DEBUGLOGIRP */
#if DBG
#define DEBUGLOGIRP(Irp, Result) FspDebugLogIrp(__FUNCTION__, Irp, Result)
#else
#define DEBUGLOG(fmt, ...) ((void)0)
#define DEBUGLOGIRP(Irp, Result) ((void)0)
#endif
/* DEBUGBREAK */
#if DBG
extern __declspec(selectany) int fsp_bp = 1; /* generic breakpoint switch */
extern __declspec(selectany) int fsp_bp_crit = 1; /* critical error breakpoint */
extern __declspec(selectany) int fsp_bp_ioentr = 1; /* I/O entry breakpoint switch */
extern __declspec(selectany) int fsp_bp_ioprep = 1; /* I/O prepare breakpoint switch */
extern __declspec(selectany) int fsp_bp_iocmpl = 1; /* I/O complete breakpoint switch */
extern __declspec(selectany) int fsp_bp_iocall = 1; /* I/O callback breakpoint switch */
extern __declspec(selectany) int fsp_bp_iorecu = 1; /* I/O recursive breakpoint switch */
#define DEBUGBREAK_CRIT() \
do \
{ \
static int bp = 1; \
if (bp && !KD_DEBUGGER_NOT_PRESENT)\
DbgBreakPoint(); \
} while (0,0)
#define DEBUGBREAK() \
do \
{ \
static int bp = 1; \
if (bp && fsp_bp && !KD_DEBUGGER_NOT_PRESENT)\
if (bp && (fsp_debug & fsp_debug_bp_generic) && !KD_DEBUGGER_NOT_PRESENT)\
DbgBreakPoint(); \
} while (0,0)
#define DEBUGBREAK_EX(category) \
do \
{ \
static int bp = 1; \
if (bp && fsp_bp && fsp_bp_ ## category && !KD_DEBUGGER_NOT_PRESENT)\
if (bp && (fsp_debug & fsp_debug_bp_ ## category) && !KD_DEBUGGER_NOT_PRESENT)\
DbgBreakPoint(); \
} while (0,0)
#else
#define DEBUGBREAK_CRIT() do {} while (0,0)
#define DEBUGBREAK() do {} while (0,0)
#define DEBUGBREAK_EX(category) do {} while (0,0)
#endif
/* DEBUGTEST */
#if DBG
extern __declspec(selectany) int fsp_dt = 1;
#define DEBUGTEST(Percent, Default) \
(!fsp_dt || DebugRandom() <= (Percent) * 0x7fff / 100 ? (Default) : !(Default))
#define DEBUGTEST(Percent) \
(0 == (fsp_debug & fsp_debug_dt) || DebugRandom() <= (Percent) * 0x7fff / 100)
#else
#define DEBUGTEST(Percent, Default) (Default)
#define DEBUGTEST(Percent) (TRUE)
#endif
/* FSP_ENTER/FSP_LEAVE */
@ -137,6 +158,10 @@ extern __declspec(selectany) int fsp_dt = 1;
NTSTATUS Result = STATUS_SUCCESS; FSP_ENTER_(iocall, __VA_ARGS__)
#define FSP_LEAVE(fmt, ...) \
FSP_LEAVE_(FSP_DEBUGLOG_(fmt, " = %s", __VA_ARGS__, NtStatusSym(Result))); return Result
#define FSP_ENTER_DRV(...) \
NTSTATUS Result = STATUS_SUCCESS; FSP_ENTER_(drvrld, __VA_ARGS__)
#define FSP_LEAVE_DRV(fmt, ...) \
FSP_LEAVE_(FSP_DEBUGLOG_(fmt, " = %s", __VA_ARGS__, NtStatusSym(Result))); return Result
#define FSP_ENTER_MJ(...) \
NTSTATUS Result = STATUS_SUCCESS; \
PIO_STACK_LOCATION IrpSp = IoGetCurrentIrpStackLocation(Irp);\
@ -973,43 +998,6 @@ NTSTATUS FspFileDescResetDirectoryPattern(FSP_FILE_DESC *FileDesc,
#define FspFileNodeDereferenceDirInfo(P) FspMetaCacheDereferenceItemBuffer(P)
#define FspFileNodeUnlockAll(N,F,P) FsRtlFastUnlockAll(&(N)->FileLock, F, P, N)
/* debug */
#if DBG
const char *NtStatusSym(NTSTATUS Status);
const char *IrpMajorFunctionSym(UCHAR MajorFunction);
const char *IrpMinorFunctionSym(UCHAR MajorFunction, UCHAR MinorFunction);
const char *IoctlCodeSym(ULONG ControlCode);
const char *FileInformationClassSym(FILE_INFORMATION_CLASS FileInformationClass);
const char *FsInformationClassSym(FS_INFORMATION_CLASS FsInformationClass);
const char *DeviceExtensionKindSym(UINT32 Kind);
ULONG DebugRandom(VOID);
static inline
VOID FspDebugLogIrp(const char *func, PIRP Irp, NTSTATUS Result)
{
PIO_STACK_LOCATION IrpSp = IoGetCurrentIrpStackLocation(Irp);
DbgPrint("[%d] " DRIVER_NAME "!%s: IRP=%p, %s%c, %s%s, IoStatus=%s[%lld]\n",
KeGetCurrentIrql(),
func,
Irp,
DeviceExtensionKindSym(FspDeviceExtension(IrpSp->DeviceObject)->Kind),
Irp->RequestorMode == KernelMode ? 'K' : 'U',
IrpMajorFunctionSym(IrpSp->MajorFunction),
IrpMinorFunctionSym(IrpSp->MajorFunction, IrpSp->MinorFunction),
NtStatusSym(Result),
(LONGLONG)Irp->IoStatus.Information);
}
#endif
/* extern */
extern PDRIVER_OBJECT FspDriverObject;
extern PDEVICE_OBJECT FspFsctlDiskDeviceObject;
extern PDEVICE_OBJECT FspFsctlNetDeviceObject;
extern FAST_IO_DISPATCH FspFastIoDispatch;
extern CACHE_MANAGER_CALLBACKS FspCacheManagerCallbacks;
extern FSP_IOPREP_DISPATCH *FspIopPrepareFunction[];
extern FSP_IOCMPL_DISPATCH *FspIopCompleteFunction[];
extern WCHAR FspFileDescDirectoryPatternMatchAll[];
/* multiversion support */
typedef
NTKERNELAPI
@ -1021,6 +1009,16 @@ FSP_MV_CcCoherencyFlushAndPurgeCache(
_Out_ PIO_STATUS_BLOCK IoStatus,
_In_opt_ ULONG Flags
);
/* extern */
extern PDRIVER_OBJECT FspDriverObject;
extern PDEVICE_OBJECT FspFsctlDiskDeviceObject;
extern PDEVICE_OBJECT FspFsctlNetDeviceObject;
extern FAST_IO_DISPATCH FspFastIoDispatch;
extern CACHE_MANAGER_CALLBACKS FspCacheManagerCallbacks;
extern FSP_IOPREP_DISPATCH *FspIopPrepareFunction[];
extern FSP_IOCMPL_DISPATCH *FspIopCompleteFunction[];
extern WCHAR FspFileDescDirectoryPatternMatchAll[];
extern FSP_MV_CcCoherencyFlushAndPurgeCache *FspMvCcCoherencyFlushAndPurgeCache;
#endif

View File

@ -774,7 +774,7 @@ VOID FspFileNodeSetFileInfo(FSP_FILE_NODE *FileNode, PFILE_OBJECT CcFileObject,
if (!NT_SUCCESS(Result))
{
DEBUGLOG("FspCcSetFileSizes error: %s", NtStatusSym(Result));
DEBUGBREAK_EX(crit);
DEBUGBREAK_CRIT();
CcUninitializeCacheMap(CcFileObject, 0, 0);
}
}

View File

@ -497,7 +497,7 @@ NTSTATUS FspFsvolQueryInformationComplete(
FspFileNodeReleaseOwner(FileNode, Full, Request);
}
Success = DEBUGTEST(90, TRUE) && FspFileNodeTryAcquireExclusive(FileNode, Main);
Success = DEBUGTEST(90) && FspFileNodeTryAcquireExclusive(FileNode, Main);
if (!Success)
{
FspIopRetryCompleteIrp(Irp, Response, &Result);

View File

@ -33,7 +33,7 @@ static NTSTATUS FspFsvolLockControlRetry(
BOOLEAN Success;
/* try to acquire the FileNode shared Main */
Success = DEBUGTEST(90, TRUE) &&
Success = DEBUGTEST(90) &&
FspFileNodeTryAcquireSharedF(FileNode, FspFileNodeAcquireMain, CanWait);
if (!Success)
return FspWqRepostIrpWorkItem(Irp, FspFsvolLockControlRetry, 0);

View File

@ -103,7 +103,7 @@ static NTSTATUS FspFsvolReadCached(
BOOLEAN Success;
/* try to acquire the FileNode Main shared */
Success = DEBUGTEST(90, TRUE) &&
Success = DEBUGTEST(90) &&
FspFileNodeTryAcquireSharedF(FileNode, FspFileNodeAcquireMain, CanWait);
if (!Success)
return FspWqRepostIrpWorkItem(Irp, FspFsvolReadCached, 0);
@ -232,7 +232,7 @@ static NTSTATUS FspFsvolReadNonCached(
return Result;
/* acquire FileNode exclusive Full */
Success = DEBUGTEST(90, TRUE) &&
Success = DEBUGTEST(90) &&
FspFileNodeTryAcquireExclusiveF(FileNode, FspFileNodeAcquireFull, CanWait);
if (!Success)
return FspWqRepostIrpWorkItem(Irp, FspFsvolReadNonCached, 0);
@ -371,7 +371,7 @@ NTSTATUS FspFsvolReadComplete(
InfoChangeNumber =
(ULONG)(UINT_PTR)FspIopRequestContext(Request, RequestInfoChangeNumber);
Success = DEBUGTEST(90, TRUE) && FspFileNodeTryAcquireExclusive(FileNode, Main);
Success = DEBUGTEST(90) && FspFileNodeTryAcquireExclusive(FileNode, Main);
if (!Success)
{
FspIopRetryCompleteIrp(Irp, Response, &Result);

View File

@ -141,7 +141,7 @@ NTSTATUS FspFsvolQuerySecurityComplete(
FspFileNodeReleaseOwner(FileNode, Full, Request);
}
Success = DEBUGTEST(90, TRUE) && FspFileNodeTryAcquireExclusive(FileNode, Main);
Success = DEBUGTEST(90) && FspFileNodeTryAcquireExclusive(FileNode, Main);
if (!Success)
{
FspIopRetryCompleteIrp(Irp, Response, &Result);

View File

@ -128,7 +128,7 @@ PVOID FspAllocatePoolMustSucceed(POOL_TYPE PoolType, SIZE_T Size, ULONG Tag)
for (ULONG i = 0, n = sizeof(Delays) / sizeof(Delays[0]);; i++)
{
Result = DEBUGTEST(95, TRUE) ? ExAllocatePoolWithTag(PoolType, Size, Tag) : 0;
Result = DEBUGTEST(95) ? ExAllocatePoolWithTag(PoolType, Size, Tag) : 0;
if (0 != Result)
return Result;
@ -146,7 +146,7 @@ PVOID FspAllocateIrpMustSucceed(CCHAR StackSize)
for (ULONG i = 0, n = sizeof(Delays) / sizeof(Delays[0]);; i++)
{
Result = DEBUGTEST(95, TRUE) ? IoAllocateIrp(StackSize, FALSE) : 0;
Result = DEBUGTEST(95) ? IoAllocateIrp(StackSize, FALSE) : 0;
if (0 != Result)
return Result;

View File

@ -109,7 +109,7 @@ static NTSTATUS FspFsvolWriteCached(
BOOLEAN Success;
/* should we defer the write? */
Success = DEBUGTEST(90, TRUE) && CcCanIWrite(FileObject, WriteLength, CanWait, Retrying);
Success = DEBUGTEST(90) && CcCanIWrite(FileObject, WriteLength, CanWait, Retrying);
if (!Success)
{
Result = FspWqCreateIrpWorkItem(Irp, FspFsvolWriteCached, 0);
@ -125,7 +125,7 @@ static NTSTATUS FspFsvolWriteCached(
}
/* try to acquire the FileNode Main exclusive */
Success = DEBUGTEST(90, TRUE) &&
Success = DEBUGTEST(90) &&
FspFileNodeTryAcquireExclusiveF(FileNode, FspFileNodeAcquireMain, CanWait);
if (!Success)
return FspWqRepostIrpWorkItem(Irp, FspFsvolWriteCached, 0);
@ -298,7 +298,7 @@ static NTSTATUS FspFsvolWriteNonCached(
return Result;
/* acquire FileNode exclusive Full */
Success = DEBUGTEST(90, TRUE) &&
Success = DEBUGTEST(90) &&
FspFileNodeTryAcquireExclusiveF(FileNode, FspFileNodeAcquireFull, CanWait);
if (!Success)
return FspWqRepostIrpWorkItem(Irp, FspFsvolWriteNonCached, 0);