From 43af829d46eb9d4ea87635974f4ae9a4237651d2 Mon Sep 17 00:00:00 2001 From: Bill Zissimopoulos Date: Mon, 16 May 2022 21:40:01 +0100 Subject: [PATCH] sys,dll,inc: FSP_IOCTL_TRANSACT --- build/VStudio/winfsp_dll.vcxproj | 3 +- build/VStudio/winfsp_dll.vcxproj.filters | 5 +- inc/winfsp/fsctl.h | 6 + src/dll/debug.c | 881 +--------------------- src/dll/debuglog.c | 890 +++++++++++++++++++++++ src/dll/fsctl.c | 7 +- src/dll/library.h | 9 + src/sys/devctl.c | 24 + src/sys/volume.c | 28 +- 9 files changed, 977 insertions(+), 876 deletions(-) create mode 100644 src/dll/debuglog.c diff --git a/build/VStudio/winfsp_dll.vcxproj b/build/VStudio/winfsp_dll.vcxproj index 3148b26a..cf77883c 100644 --- a/build/VStudio/winfsp_dll.vcxproj +++ b/build/VStudio/winfsp_dll.vcxproj @@ -48,6 +48,7 @@ + @@ -64,7 +65,7 @@ - + diff --git a/build/VStudio/winfsp_dll.vcxproj.filters b/build/VStudio/winfsp_dll.vcxproj.filters index bfd29ef4..6299aaca 100644 --- a/build/VStudio/winfsp_dll.vcxproj.filters +++ b/build/VStudio/winfsp_dll.vcxproj.filters @@ -94,7 +94,7 @@ Source - + Source @@ -172,6 +172,9 @@ Source + + Source + diff --git a/inc/winfsp/fsctl.h b/inc/winfsp/fsctl.h index e1c7a0b2..ef970587 100644 --- a/inc/winfsp/fsctl.h +++ b/inc/winfsp/fsctl.h @@ -97,8 +97,12 @@ extern const __declspec(selectany) GUID FspFsvrtDeviceClassGuid = CTL_CODE(FILE_DEVICE_FILE_SYSTEM, 0x800 + 'L', METHOD_BUFFERED, FILE_ANY_ACCESS) #define FSP_FSCTL_TRANSACT \ CTL_CODE(FILE_DEVICE_FILE_SYSTEM, 0x800 + 'T', METHOD_BUFFERED, FILE_ANY_ACCESS) +#define FSP_IOCTL_TRANSACT \ + CTL_CODE(0x8000 | ('F'<<8) | 'W', 0x800 + 'T', METHOD_BUFFERED, FILE_ANY_ACCESS) #define FSP_FSCTL_TRANSACT_BATCH \ CTL_CODE(FILE_DEVICE_FILE_SYSTEM, 0x800 + 't', METHOD_OUT_DIRECT, FILE_ANY_ACCESS) +#define FSP_IOCTL_TRANSACT_BATCH \ + CTL_CODE(0x8000 | ('F'<<8) | 'W', 0x800 + 't', METHOD_BUFFERED, FILE_ANY_ACCESS) #define FSP_FSCTL_STOP \ CTL_CODE(FILE_DEVICE_FILE_SYSTEM, 0x800 + 'S', METHOD_BUFFERED, FILE_ANY_ACCESS) #define FSP_FSCTL_STOP0 \ @@ -109,6 +113,8 @@ extern const __declspec(selectany) GUID FspFsvrtDeviceClassGuid = /* fsctl internal device codes (usable only in-kernel) */ #define FSP_FSCTL_TRANSACT_INTERNAL \ CTL_CODE(FILE_DEVICE_FILE_SYSTEM, 0x800 + 'I', METHOD_NEITHER, FILE_ANY_ACCESS) +#define FSP_IOCTL_TRANSACT_INTERNAL \ + CTL_CODE(0x8000 | ('F'<<8) | 'W', 0x800 + 'I', METHOD_BUFFERED, FILE_ANY_ACCESS) /* fsvol device codes */ #define FSP_FSCTL_QUERY_WINFSP \ diff --git a/src/dll/debug.c b/src/dll/debug.c index 2f59475e..5a2cadad 100644 --- a/src/dll/debug.c +++ b/src/dll/debug.c @@ -20,871 +20,22 @@ */ #include -#include -#include -static HANDLE FspDebugLogHandle = INVALID_HANDLE_VALUE; - -FSP_API VOID FspDebugLogSetHandle(HANDLE Handle) +#if !defined(NDEBUG) +ULONG DebugRandom(VOID) { - FspDebugLogHandle = Handle; -} - -FSP_API VOID FspDebugLog(const char *format, ...) -{ - char buf[1024]; - /* DbgPrint has a 512 byte limit, but wvsprintf is only safe with a 1024 byte buffer */ - va_list ap; - va_start(ap, format); - wvsprintfA(buf, format, ap); - va_end(ap); - buf[sizeof buf - 1] = '\0'; - if (INVALID_HANDLE_VALUE != FspDebugLogHandle) - { - DWORD bytes; - WriteFile(FspDebugLogHandle, buf, lstrlenA(buf), &bytes, 0); - } - else - OutputDebugStringA(buf); -} - -FSP_API VOID FspDebugLogSD(const char *format, PSECURITY_DESCRIPTOR SecurityDescriptor) -{ - char *Sddl; - - if (0 == SecurityDescriptor) - FspDebugLog(format, "null security descriptor"); - else if (ConvertSecurityDescriptorToStringSecurityDescriptorA(SecurityDescriptor, - SDDL_REVISION_1, - OWNER_SECURITY_INFORMATION | GROUP_SECURITY_INFORMATION | - DACL_SECURITY_INFORMATION | SACL_SECURITY_INFORMATION, - &Sddl, 0)) - { - FspDebugLog(format, Sddl); - LocalFree(Sddl); - } - else - FspDebugLog(format, "invalid security descriptor"); -} - -FSP_API VOID FspDebugLogSid(const char *format, PSID Sid) -{ - char *S; - - if (0 == Sid) - FspDebugLog(format, "null SID"); - else if (ConvertSidToStringSidA(Sid, &S)) - { - FspDebugLog(format, S); - LocalFree(S); - } - else - FspDebugLog(format, "invalid SID"); -} - -FSP_API VOID FspDebugLogFT(const char *format, PFILETIME FileTime) -{ - SYSTEMTIME SystemTime; - char buf[32]; - - if (FileTimeToSystemTime(FileTime, &SystemTime)) - { - wsprintfA(buf, "%04hu-%02hu-%02huT%02hu:%02hu:%02hu.%03huZ", - SystemTime.wYear, SystemTime.wMonth, SystemTime.wDay, - SystemTime.wHour, SystemTime.wMinute, SystemTime.wSecond, - SystemTime.wMilliseconds); - FspDebugLog(format, buf); - } - else - FspDebugLog(format, "invalid file time"); -} - -#define MAKE_UINT32_PAIR(v) \ - ((PLARGE_INTEGER)&(v))->HighPart, ((PLARGE_INTEGER)&(v))->LowPart - -static const char *FspDebugLogDispositionString(UINT32 CreateOptions) -{ - switch ((CreateOptions >> 24) & 0xff) - { - case FILE_CREATE: - return "FILE_CREATE"; - case FILE_OPEN: - return "FILE_OPEN"; - case FILE_OPEN_IF: - return "FILE_OPEN_IF"; - case FILE_OVERWRITE: - return "FILE_OVERWRITE"; - case FILE_SUPERSEDE: - return "FILE_SUPERSEDE"; - case FILE_OVERWRITE_IF: - return "FILE_OVERWRITE_IF"; - default: - return "INVALID"; - } -} - -static const char *FspDebugLogUserContextString(UINT64 UserContext, UINT64 UserContext2, char *Buf) -{ - wsprintfA(Buf, 0 == UserContext2 ? "%p" : "%p:%p", (PVOID)UserContext, (PVOID)UserContext2); - - return Buf; -} - -static const char *FspDebugLogFileTimeString(UINT64 FileTime, char *Buf) -{ - SYSTEMTIME SystemTime; - - if (0 == FileTime) - lstrcpyA(Buf, "0"); - else if (FileTimeToSystemTime((PFILETIME)&FileTime, &SystemTime)) - { - wsprintfA(Buf, "%04hu-%02hu-%02huT%02hu:%02hu:%02hu.%03huZ", - SystemTime.wYear, SystemTime.wMonth, SystemTime.wDay, - SystemTime.wHour, SystemTime.wMinute, SystemTime.wSecond, - SystemTime.wMilliseconds); - } - else - lstrcpyA(Buf, "INVALID"); - - return Buf; -} - -static const char *FspDebugLogFileInfoString(FSP_FSCTL_FILE_INFO *FileInfo, char *Buf) -{ - char CreationTimeBuf[32], LastAccessTimeBuf[32], LastWriteTimeBuf[32], ChangeTimeBuf[32]; - - wsprintfA(Buf, - "{" - "FileAttributes=%lx, " - "ReparseTag=%lx, " - "AllocationSize=%lx:%lx, " - "FileSize=%lx:%lx, " - "CreationTime=%s, " - "LastAccessTime=%s, " - "LastWriteTime=%s, " - "ChangeTime=%s, " - "IndexNumber=%lx:%lx" - "}", - FileInfo->FileAttributes, - FileInfo->ReparseTag, - MAKE_UINT32_PAIR(FileInfo->AllocationSize), - MAKE_UINT32_PAIR(FileInfo->FileSize), - FspDebugLogFileTimeString(FileInfo->CreationTime, CreationTimeBuf), - FspDebugLogFileTimeString(FileInfo->LastAccessTime, LastAccessTimeBuf), - FspDebugLogFileTimeString(FileInfo->LastWriteTime, LastWriteTimeBuf), - FspDebugLogFileTimeString(FileInfo->ChangeTime, ChangeTimeBuf), - MAKE_UINT32_PAIR(FileInfo->IndexNumber)); - - return Buf; -} - -static const char *FspDebugLogVolumeInfoString(FSP_FSCTL_VOLUME_INFO *VolumeInfo, char *Buf) -{ - wsprintfA(Buf, - "{" - "TotalSize=%lx:%lx, " - "FreeSize=%lx:%lx, " - "VolumeLabel=\"%.32S\"" - "}", - MAKE_UINT32_PAIR(VolumeInfo->TotalSize), - MAKE_UINT32_PAIR(VolumeInfo->FreeSize), - &VolumeInfo->VolumeLabel); - - return Buf; -} - -static const char *FspDebugLogWideCharBufferString(PVOID WideCharBuf, ULONG Length, char *Buf) -{ - WCHAR TempWideCharBuf[64 + 1]; - - if (Length > sizeof TempWideCharBuf - sizeof(WCHAR)) - Length = sizeof TempWideCharBuf - sizeof(WCHAR); - - memcpy(TempWideCharBuf, WideCharBuf, Length); - TempWideCharBuf[Length / sizeof(WCHAR)] = L'\0'; - - wsprintfA(Buf, "%.64S", TempWideCharBuf); - - return Buf; -} - -static const char *FspDebugLogReparseDataString(PVOID ReparseData0, char *Buf) -{ - union - { - PREPARSE_DATA_BUFFER D; - PREPARSE_GUID_DATA_BUFFER G; - } ReparseData; - char SubstituteName[64 + 1], PrintName[64 + 1]; - - ReparseData.D = ReparseData0; - if (0 == ReparseData.D->ReparseDataLength) - wsprintfA(Buf, - "{" - "ReparseTag=%#lx, " - "ReparseDataLength=%hu" - "}", - ReparseData.D->ReparseTag, ReparseData.D->ReparseDataLength); - else if (IO_REPARSE_TAG_MOUNT_POINT == ReparseData.D->ReparseTag) - wsprintfA(Buf, - "{" - "ReparseTag=IO_REPARSE_TAG_MOUNT_POINT, " - "SubstituteName=\"%s\", " - "PrintName=\"%s\"" - "}", - FspDebugLogWideCharBufferString( - ReparseData.D->MountPointReparseBuffer.PathBuffer + - ReparseData.D->MountPointReparseBuffer.SubstituteNameOffset / sizeof(WCHAR), - ReparseData.D->MountPointReparseBuffer.SubstituteNameLength, - SubstituteName), - FspDebugLogWideCharBufferString( - ReparseData.D->MountPointReparseBuffer.PathBuffer + - ReparseData.D->MountPointReparseBuffer.PrintNameOffset / sizeof(WCHAR), - ReparseData.D->MountPointReparseBuffer.PrintNameLength, - PrintName)); - else if (IO_REPARSE_TAG_SYMLINK == ReparseData.D->ReparseTag) - wsprintfA(Buf, - "{" - "ReparseTag=IO_REPARSE_TAG_SYMLINK, " - "SubstituteName=\"%s\", " - "PrintName=\"%s\", " - "Flags=%u" - "}", - FspDebugLogWideCharBufferString( - ReparseData.D->SymbolicLinkReparseBuffer.PathBuffer + - ReparseData.D->SymbolicLinkReparseBuffer.SubstituteNameOffset / sizeof(WCHAR), - ReparseData.D->SymbolicLinkReparseBuffer.SubstituteNameLength, - SubstituteName), - FspDebugLogWideCharBufferString( - ReparseData.D->SymbolicLinkReparseBuffer.PathBuffer + - ReparseData.D->SymbolicLinkReparseBuffer.PrintNameOffset / sizeof(WCHAR), - ReparseData.D->SymbolicLinkReparseBuffer.PrintNameLength, - PrintName), - ReparseData.D->SymbolicLinkReparseBuffer.Flags); - else if (IsReparseTagMicrosoft(ReparseData.D->ReparseTag)) - wsprintfA(Buf, - "{" - "ReparseTag=%#lx, " - "ReparseDataLength=%hu" - "}", - ReparseData.D->ReparseTag, ReparseData.D->ReparseDataLength); - else -#define Guid ReparseData.G->ReparseGuid - wsprintfA(Buf, - "{" - "ReparseTag=%#lx, " - "ReparseDataLength=%hu, " - "ReparseGuid={%08lX-%04X-%04X-%02X%02X-%02X%02X%02X%02X%02X%02X}" - "}", - ReparseData.G->ReparseTag, ReparseData.G->ReparseDataLength, - Guid.Data1, Guid.Data2, Guid.Data3, - Guid.Data4[0], Guid.Data4[1], Guid.Data4[2], Guid.Data4[3], - Guid.Data4[4], Guid.Data4[5], Guid.Data4[6], Guid.Data4[7]); -#undef Guid - - return Buf; -} - -static VOID FspDebugLogRequestVoid(FSP_FSCTL_TRANSACT_REQ *Request, const char *Name) -{ - FspDebugLog("%S[TID=%04lx]: %p: >>%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, Name); -} - -static VOID FspDebugLogResponseStatus(FSP_FSCTL_TRANSACT_RSP *Response, const char *Name) -{ - FspDebugLog("%S[TID=%04lx]: %p: <<%s IoStatus=%lx[%ld]\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Response->Hint, Name, - Response->IoStatus.Status, Response->IoStatus.Information); -} - -FSP_API VOID FspDebugLogRequest(FSP_FSCTL_TRANSACT_REQ *Request) -{ - char UserContextBuf[40]; - char CreationTimeBuf[32], LastAccessTimeBuf[32], LastWriteTimeBuf[32]; - char InfoBuf[256]; - char *Sddl = 0; - - switch (Request->Kind) - { - case FspFsctlTransactReservedKind: - FspDebugLogRequestVoid(Request, "RESERVED"); - break; - case FspFsctlTransactCreateKind: - if (0 != Request->Req.Create.SecurityDescriptor.Offset) - ConvertSecurityDescriptorToStringSecurityDescriptorA( - Request->Buffer + Request->Req.Create.SecurityDescriptor.Offset, - SDDL_REVISION_1, - OWNER_SECURITY_INFORMATION | GROUP_SECURITY_INFORMATION | - DACL_SECURITY_INFORMATION | SACL_SECURITY_INFORMATION, - &Sddl, 0); - FspDebugLog("%S[TID=%04lx]: %p: >>Create [%c%c%c%c%c%c] \"%S\", " - "%s, CreateOptions=%lx, FileAttributes=%lx, Security=%s%s%s, " - "AllocationSize=%lx:%lx, " - "AccessToken=%p[PID=%lx], DesiredAccess=%lx, GrantedAccess=%lx, " - "ShareAccess=%lx\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->Req.Create.UserMode ? 'U' : 'K', - Request->Req.Create.HasTraversePrivilege ? 'T' : '-', - Request->Req.Create.HasBackupPrivilege ? 'B' : '-', - Request->Req.Create.HasRestorePrivilege ? 'R' : '-', - Request->Req.Create.OpenTargetDirectory ? 'D' : '-', - Request->Req.Create.CaseSensitive ? 'C' : '-', - (PWSTR)Request->Buffer, - FspDebugLogDispositionString(Request->Req.Create.CreateOptions), - Request->Req.Create.CreateOptions & 0xffffff, - Request->Req.Create.FileAttributes, - Sddl ? "\"" : "", - Sddl ? Sddl : "NULL", - Sddl ? "\"" : "", - MAKE_UINT32_PAIR(Request->Req.Create.AllocationSize), - FSP_FSCTL_TRANSACT_REQ_TOKEN_HANDLE(Request->Req.Create.AccessToken), - FSP_FSCTL_TRANSACT_REQ_TOKEN_PID(Request->Req.Create.AccessToken), - Request->Req.Create.DesiredAccess, - Request->Req.Create.GrantedAccess, - Request->Req.Create.ShareAccess); - LocalFree(Sddl); - break; - case FspFsctlTransactOverwriteKind: - FspDebugLog("%S[TID=%04lx]: %p: >>Overwrite%s %s%S%s%s, " - "FileAttributes=%lx\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->Req.Overwrite.Supersede ? " [Supersede]" : "", - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.Overwrite.UserContext, Request->Req.Overwrite.UserContext2, - UserContextBuf), - Request->Req.Overwrite.FileAttributes); - break; - case FspFsctlTransactCleanupKind: - FspDebugLog("%S[TID=%04lx]: %p: >>Cleanup%s %s%S%s%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->Req.Cleanup.Delete ? " [Delete]" : "", - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.Cleanup.UserContext, Request->Req.Cleanup.UserContext2, - UserContextBuf)); - break; - case FspFsctlTransactCloseKind: - FspDebugLog("%S[TID=%04lx]: %p: >>Close %s%S%s%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.Close.UserContext, Request->Req.Close.UserContext2, - UserContextBuf)); - break; - case FspFsctlTransactReadKind: - FspDebugLog("%S[TID=%04lx]: %p: >>Read %s%S%s%s, " - "Address=%p, Offset=%lx:%lx, Length=%ld, Key=%lx\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.Read.UserContext, Request->Req.Read.UserContext2, - UserContextBuf), - (PVOID)Request->Req.Read.Address, - MAKE_UINT32_PAIR(Request->Req.Read.Offset), - Request->Req.Read.Length, - Request->Req.Read.Key); - break; - case FspFsctlTransactWriteKind: - FspDebugLog("%S[TID=%04lx]: %p: >>Write%s %s%S%s%s, " - "Address=%p, Offset=%lx:%lx, Length=%ld, Key=%lx\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->Req.Write.ConstrainedIo ? " [C]" : "", - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.Write.UserContext, Request->Req.Write.UserContext2, - UserContextBuf), - (PVOID)Request->Req.Write.Address, - MAKE_UINT32_PAIR(Request->Req.Write.Offset), - Request->Req.Write.Length, - Request->Req.Write.Key); - break; - case FspFsctlTransactQueryInformationKind: - FspDebugLog("%S[TID=%04lx]: %p: >>QueryInformation %s%S%s%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.QueryInformation.UserContext, Request->Req.QueryInformation.UserContext2, - UserContextBuf)); - break; - case FspFsctlTransactSetInformationKind: - switch (Request->Req.SetInformation.FileInformationClass) - { - case 4/*FileBasicInformation*/: - FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [Basic] %s%S%s%s, " - "FileAttributes=%lx, CreationTime=%s, LastAccessTime=%s, LastWriteTime=%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, - UserContextBuf), - Request->Req.SetInformation.Info.Basic.FileAttributes, - FspDebugLogFileTimeString(Request->Req.SetInformation.Info.Basic.CreationTime, - CreationTimeBuf), - FspDebugLogFileTimeString(Request->Req.SetInformation.Info.Basic.LastAccessTime, - LastAccessTimeBuf), - FspDebugLogFileTimeString(Request->Req.SetInformation.Info.Basic.LastWriteTime, - LastWriteTimeBuf)); - break; - case 19/*FileAllocationInformation*/: - FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [Allocation] %s%S%s%s, " - "AllocationSize=%lx:%lx\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, - UserContextBuf), - MAKE_UINT32_PAIR(Request->Req.SetInformation.Info.Allocation.AllocationSize)); - break; - case 20/*FileEndOfFileInformation*/: - FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [EndOfFile] %s%S%s%s, " - "FileSize = %lx:%lx\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, - UserContextBuf), - MAKE_UINT32_PAIR(Request->Req.SetInformation.Info.EndOfFile.FileSize)); - break; - case 13/*FileDispositionInformation*/: - FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [Disposition] %s%S%s%s, " - "%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, - UserContextBuf), - Request->Req.SetInformation.Info.Disposition.Delete ? "Delete" : "Undelete"); - break; - case 64/*FileDispositionInformationEx*/: - FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [DispositionEx] %s%S%s%s, " - "Flags=%lx\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, - UserContextBuf), - Request->Req.SetInformation.Info.DispositionEx.Flags); - break; - case 10/*FileRenameInformation*/: - FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [Rename] %s%S%s%s, " - "NewFileName=\"%S\", AccessToken=%p[PID=%lx]\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, - UserContextBuf), - (PWSTR)(Request->Buffer + Request->Req.SetInformation.Info.Rename.NewFileName.Offset), - FSP_FSCTL_TRANSACT_REQ_TOKEN_HANDLE(Request->Req.SetInformation.Info.Rename.AccessToken), - FSP_FSCTL_TRANSACT_REQ_TOKEN_PID(Request->Req.SetInformation.Info.Rename.AccessToken)); - break; - case 65/*FileRenameInformationEx*/: - FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [RenameEx] %s%S%s%s, " - "NewFileName=\"%S\", AccessToken=%p[PID=%lx], Flags=%lx\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, - UserContextBuf), - (PWSTR)(Request->Buffer + Request->Req.SetInformation.Info.Rename.NewFileName.Offset), - FSP_FSCTL_TRANSACT_REQ_TOKEN_HANDLE(Request->Req.SetInformation.Info.Rename.AccessToken), - FSP_FSCTL_TRANSACT_REQ_TOKEN_PID(Request->Req.SetInformation.Info.Rename.AccessToken), - Request->Req.SetInformation.Info.RenameEx.Flags); - break; - default: - FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [INVALID] %s%S%s%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, - UserContextBuf)); - break; - } - break; - case FspFsctlTransactQueryEaKind: - FspDebugLogRequestVoid(Request, "QUERYEA"); - break; - case FspFsctlTransactSetEaKind: - FspDebugLogRequestVoid(Request, "SETEA"); - break; - case FspFsctlTransactFlushBuffersKind: - FspDebugLog("%S[TID=%04lx]: %p: >>FlushBuffers %s%S%s%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.FlushBuffers.UserContext, Request->Req.FlushBuffers.UserContext2, - UserContextBuf)); - break; - case FspFsctlTransactQueryVolumeInformationKind: - FspDebugLogRequestVoid(Request, "QueryVolumeInformation"); - break; - case FspFsctlTransactSetVolumeInformationKind: - switch (Request->Req.SetVolumeInformation.FsInformationClass) - { - case 2/*FileFsLabelInformation*/: - FspDebugLog("%S[TID=%04lx]: %p: >>SetVolumeInformation [FsLabel] " - "Label=\"%S\"\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - (PWSTR)Request->Buffer); - break; - default: - FspDebugLog("%S[TID=%04lx]: %p: >>SetVolumeInformation [INVALID]\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint); - break; - } - break; - case FspFsctlTransactQueryDirectoryKind: - FspDebugLog("%S[TID=%04lx]: %p: >>QueryDirectory %s%S%s%s, " - "Address=%p, Length=%ld, Pattern=%s%S%s, Marker=%s%S%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.QueryDirectory.UserContext, Request->Req.QueryDirectory.UserContext2, - UserContextBuf), - (PVOID)Request->Req.QueryDirectory.Address, - Request->Req.QueryDirectory.Length, - Request->Req.QueryDirectory.Pattern.Size ? "\"" : "", - Request->Req.QueryDirectory.Pattern.Size ? - (PWSTR)(Request->Buffer + Request->Req.QueryDirectory.Pattern.Offset) : L"NULL", - Request->Req.QueryDirectory.Pattern.Size ? "\"" : "", - Request->Req.QueryDirectory.Marker.Size ? "\"" : "", - Request->Req.QueryDirectory.Marker.Size ? - (PWSTR)(Request->Buffer + Request->Req.QueryDirectory.Marker.Offset) : L"NULL", - Request->Req.QueryDirectory.Marker.Size ? "\"" : ""); - break; - case FspFsctlTransactFileSystemControlKind: - switch (Request->Req.FileSystemControl.FsControlCode) - { - case FSCTL_GET_REPARSE_POINT: - FspDebugLog("%S[TID=%04lx]: %p: >>FileSystemControl [FSCTL_GET_REPARSE_POINT] %s%S%s%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.FileSystemControl.UserContext, Request->Req.FileSystemControl.UserContext2, - UserContextBuf)); - break; - case FSCTL_SET_REPARSE_POINT: - case FSCTL_DELETE_REPARSE_POINT: - FspDebugLog("%S[TID=%04lx]: %p: >>FileSystemControl [%s] %s%S%s%s " - "ReparseData=%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - FSCTL_SET_REPARSE_POINT == Request->Req.FileSystemControl.FsControlCode ? - "FSCTL_SET_REPARSE_POINT" : "FSCTL_DELETE_REPARSE_POINT", - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.FileSystemControl.UserContext, Request->Req.FileSystemControl.UserContext2, - UserContextBuf), - FspDebugLogReparseDataString(Request->Buffer + Request->Req.FileSystemControl.Buffer.Offset, - InfoBuf)); - break; - default: - FspDebugLog("%S[TID=%04lx]: %p: >>FileSystemControl [INVALID] %s%S%s%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.FileSystemControl.UserContext, Request->Req.FileSystemControl.UserContext2, - UserContextBuf)); - break; - } - break; - case FspFsctlTransactDeviceControlKind: - FspDebugLogRequestVoid(Request, "DEVICECONTROL"); - break; - case FspFsctlTransactShutdownKind: - FspDebugLogRequestVoid(Request, "SHUTDOWN"); - break; - case FspFsctlTransactLockControlKind: - FspDebugLogRequestVoid(Request, "LOCKCONTROL"); - break; - case FspFsctlTransactQuerySecurityKind: - FspDebugLog("%S[TID=%04lx]: %p: >>QuerySecurity %s%S%s%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.QuerySecurity.UserContext, Request->Req.QuerySecurity.UserContext2, - UserContextBuf)); - break; - case FspFsctlTransactSetSecurityKind: - if (0 != Request->Req.SetSecurity.SecurityDescriptor.Size) - ConvertSecurityDescriptorToStringSecurityDescriptorA( - Request->Buffer + Request->Req.SetSecurity.SecurityDescriptor.Offset, - SDDL_REVISION_1, - OWNER_SECURITY_INFORMATION | GROUP_SECURITY_INFORMATION | - DACL_SECURITY_INFORMATION | SACL_SECURITY_INFORMATION, - &Sddl, 0); - FspDebugLog("%S[TID=%04lx]: %p: >>SetSecurity %s%S%s%s, " - "SecurityInformation=%lx, Security=%s%s%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.SetSecurity.UserContext, Request->Req.SetSecurity.UserContext2, - UserContextBuf), - Request->Req.SetSecurity.SecurityInformation, - Sddl ? "\"" : "", - Sddl ? Sddl : "NULL", - Sddl ? "\"" : ""); - LocalFree(Sddl); - break; - case FspFsctlTransactQueryStreamInformationKind: - FspDebugLog("%S[TID=%04lx]: %p: >>QueryStreamInformation %s%S%s%s\n", - FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, - Request->FileName.Size ? "\"" : "", - Request->FileName.Size ? (PWSTR)Request->Buffer : L"", - Request->FileName.Size ? "\", " : "", - FspDebugLogUserContextString( - Request->Req.QueryStreamInformation.UserContext, Request->Req.QueryStreamInformation.UserContext2, - UserContextBuf)); - break; - default: - FspDebugLogRequestVoid(Request, "INVALID"); - break; - } -} - -FSP_API VOID FspDebugLogResponse(FSP_FSCTL_TRANSACT_RSP *Response) -{ - if (STATUS_PENDING == Response->IoStatus.Status) - return; - - char UserContextBuf[40]; - char InfoBuf[256]; - char *Sddl = 0; - - switch (Response->Kind) - { - case FspFsctlTransactReservedKind: - FspDebugLogResponseStatus(Response, "RESERVED"); - break; - case FspFsctlTransactCreateKind: - if (!NT_SUCCESS(Response->IoStatus.Status)) - FspDebugLogResponseStatus(Response, "Create"); - else if (STATUS_REPARSE == Response->IoStatus.Status) - { - if (0/*IO_REPARSE*/ == Response->IoStatus.Information) - FspDebugLog("%S[TID=%04lx]: %p: <Hint, - Response->IoStatus.Status, Response->IoStatus.Information, - FspDebugLogWideCharBufferString( - Response->Buffer + Response->Rsp.Create.Reparse.Buffer.Offset, - Response->Rsp.Create.Reparse.Buffer.Size, - InfoBuf)); - else if (1/*IO_REMOUNT*/ == Response->IoStatus.Information) - FspDebugLogResponseStatus(Response, "Create"); - else - FspDebugLog("%S[TID=%04lx]: %p: <Hint, - Response->IoStatus.Status, Response->IoStatus.Information, - FspDebugLogReparseDataString( - Response->Buffer + Response->Rsp.Create.Reparse.Buffer.Offset, - InfoBuf)); - } - else - FspDebugLog("%S[TID=%04lx]: %p: <Hint, - Response->IoStatus.Status, Response->IoStatus.Information, - FspDebugLogUserContextString( - Response->Rsp.Create.Opened.UserContext, Response->Rsp.Create.Opened.UserContext2, - UserContextBuf), - Response->Rsp.Create.Opened.GrantedAccess, - FspDebugLogFileInfoString(&Response->Rsp.Create.Opened.FileInfo, InfoBuf)); - break; - case FspFsctlTransactOverwriteKind: - if (!NT_SUCCESS(Response->IoStatus.Status)) - FspDebugLogResponseStatus(Response, "Overwrite"); - else - FspDebugLog("%S[TID=%04lx]: %p: <Hint, - Response->IoStatus.Status, Response->IoStatus.Information, - FspDebugLogFileInfoString(&Response->Rsp.Overwrite.FileInfo, InfoBuf)); - break; - case FspFsctlTransactCleanupKind: - FspDebugLogResponseStatus(Response, "Cleanup"); - break; - case FspFsctlTransactCloseKind: - FspDebugLogResponseStatus(Response, "Close"); - break; - case FspFsctlTransactReadKind: - FspDebugLogResponseStatus(Response, "Read"); - break; - case FspFsctlTransactWriteKind: - if (!NT_SUCCESS(Response->IoStatus.Status)) - FspDebugLogResponseStatus(Response, "Write"); - else - FspDebugLog("%S[TID=%04lx]: %p: <Hint, - Response->IoStatus.Status, Response->IoStatus.Information, - FspDebugLogFileInfoString(&Response->Rsp.Write.FileInfo, InfoBuf)); - break; - case FspFsctlTransactQueryInformationKind: - if (!NT_SUCCESS(Response->IoStatus.Status)) - FspDebugLogResponseStatus(Response, "QueryInformation"); - else - FspDebugLog("%S[TID=%04lx]: %p: <Hint, - Response->IoStatus.Status, Response->IoStatus.Information, - FspDebugLogFileInfoString(&Response->Rsp.QueryInformation.FileInfo, InfoBuf)); - break; - case FspFsctlTransactSetInformationKind: - if (!NT_SUCCESS(Response->IoStatus.Status)) - FspDebugLogResponseStatus(Response, "SetInformation"); - else - FspDebugLog("%S[TID=%04lx]: %p: <Hint, - Response->IoStatus.Status, Response->IoStatus.Information, - FspDebugLogFileInfoString(&Response->Rsp.SetInformation.FileInfo, InfoBuf)); - break; - case FspFsctlTransactQueryEaKind: - FspDebugLogResponseStatus(Response, "QUERYEA"); - break; - case FspFsctlTransactSetEaKind: - FspDebugLogResponseStatus(Response, "SETEA"); - break; - case FspFsctlTransactFlushBuffersKind: - FspDebugLogResponseStatus(Response, "FlushBuffers"); - break; - case FspFsctlTransactQueryVolumeInformationKind: - if (!NT_SUCCESS(Response->IoStatus.Status)) - FspDebugLogResponseStatus(Response, "QueryVolumeInformation"); - else - FspDebugLog("%S[TID=%04lx]: %p: <Hint, - Response->IoStatus.Status, Response->IoStatus.Information, - FspDebugLogVolumeInfoString(&Response->Rsp.QueryVolumeInformation.VolumeInfo, InfoBuf)); - break; - case FspFsctlTransactSetVolumeInformationKind: - if (!NT_SUCCESS(Response->IoStatus.Status)) - FspDebugLogResponseStatus(Response, "SetVolumeInformation"); - else - FspDebugLog("%S[TID=%04lx]: %p: <Hint, - Response->IoStatus.Status, Response->IoStatus.Information, - FspDebugLogVolumeInfoString(&Response->Rsp.SetVolumeInformation.VolumeInfo, InfoBuf)); - break; - case FspFsctlTransactQueryDirectoryKind: - FspDebugLogResponseStatus(Response, "QueryDirectory"); - break; - case FspFsctlTransactFileSystemControlKind: - if (!NT_SUCCESS(Response->IoStatus.Status) || - 0 == Response->Rsp.FileSystemControl.Buffer.Size) - FspDebugLogResponseStatus(Response, "FileSystemControl"); - else - FspDebugLog("%S[TID=%04lx]: %p: <Hint, - Response->IoStatus.Status, Response->IoStatus.Information, - FspDebugLogReparseDataString(Response->Buffer + Response->Rsp.FileSystemControl.Buffer.Offset, - InfoBuf)); - break; - case FspFsctlTransactDeviceControlKind: - FspDebugLogResponseStatus(Response, "DEVICECONTROL"); - break; - case FspFsctlTransactShutdownKind: - FspDebugLogResponseStatus(Response, "SHUTDOWN"); - break; - case FspFsctlTransactLockControlKind: - FspDebugLogResponseStatus(Response, "LOCKCONTROL"); - break; - case FspFsctlTransactQuerySecurityKind: - if (!NT_SUCCESS(Response->IoStatus.Status)) - FspDebugLogResponseStatus(Response, "QuerySecurity"); - else - { - if (0 != Response->Rsp.QuerySecurity.SecurityDescriptor.Size) - ConvertSecurityDescriptorToStringSecurityDescriptorA( - Response->Buffer + Response->Rsp.QuerySecurity.SecurityDescriptor.Offset, - SDDL_REVISION_1, - OWNER_SECURITY_INFORMATION | GROUP_SECURITY_INFORMATION | - DACL_SECURITY_INFORMATION | SACL_SECURITY_INFORMATION, - &Sddl, 0); - FspDebugLog("%S[TID=%04lx]: %p: <Hint, - Response->IoStatus.Status, Response->IoStatus.Information, - Sddl ? "\"" : "", - Sddl ? Sddl : "NULL", - Sddl ? "\"" : ""); - LocalFree(Sddl); - } - break; - case FspFsctlTransactSetSecurityKind: - if (!NT_SUCCESS(Response->IoStatus.Status)) - FspDebugLogResponseStatus(Response, "SetSecurity"); - else - { - if (0 != Response->Rsp.SetSecurity.SecurityDescriptor.Size) - ConvertSecurityDescriptorToStringSecurityDescriptorA( - Response->Buffer + Response->Rsp.SetSecurity.SecurityDescriptor.Offset, - SDDL_REVISION_1, - OWNER_SECURITY_INFORMATION | GROUP_SECURITY_INFORMATION | - DACL_SECURITY_INFORMATION | SACL_SECURITY_INFORMATION, - &Sddl, 0); - FspDebugLog("%S[TID=%04lx]: %p: <Hint, - Response->IoStatus.Status, Response->IoStatus.Information, - Sddl ? "\"" : "", - Sddl ? Sddl : "NULL", - Sddl ? "\"" : ""); - LocalFree(Sddl); - } - break; - case FspFsctlTransactQueryStreamInformationKind: - FspDebugLogResponseStatus(Response, "QueryStreamInformation"); - break; - default: - FspDebugLogResponseStatus(Response, "INVALID"); - break; - } + static SRWLOCK SlimLock = SRWLOCK_INIT; + static ULONG Seed = 1; + ULONG Result; + + AcquireSRWLockExclusive(&SlimLock); + + /* see ucrt sources */ + Seed = Seed * 214013 + 2531011; + Result = (Seed >> 16) & 0x7fff; + + ReleaseSRWLockExclusive(&SlimLock); + + return Result; } +#endif diff --git a/src/dll/debuglog.c b/src/dll/debuglog.c new file mode 100644 index 00000000..ba8bf45f --- /dev/null +++ b/src/dll/debuglog.c @@ -0,0 +1,890 @@ +/** + * @file dll/debuglog.c + * + * @copyright 2015-2022 Bill Zissimopoulos + */ +/* + * This file is part of WinFsp. + * + * You can redistribute it and/or modify it under the terms of the GNU + * General Public License version 3 as published by the Free Software + * Foundation. + * + * Licensees holding a valid commercial license may use this software + * in accordance with the commercial license agreement provided in + * conjunction with the software. The terms and conditions of any such + * commercial license agreement shall govern, supersede, and render + * ineffective any application of the GPLv3 license to this software, + * notwithstanding of any reference thereto in the software or + * associated repository. + */ + +#include +#include +#include + +static HANDLE FspDebugLogHandle = INVALID_HANDLE_VALUE; + +FSP_API VOID FspDebugLogSetHandle(HANDLE Handle) +{ + FspDebugLogHandle = Handle; +} + +FSP_API VOID FspDebugLog(const char *format, ...) +{ + char buf[1024]; + /* DbgPrint has a 512 byte limit, but wvsprintf is only safe with a 1024 byte buffer */ + va_list ap; + va_start(ap, format); + wvsprintfA(buf, format, ap); + va_end(ap); + buf[sizeof buf - 1] = '\0'; + if (INVALID_HANDLE_VALUE != FspDebugLogHandle) + { + DWORD bytes; + WriteFile(FspDebugLogHandle, buf, lstrlenA(buf), &bytes, 0); + } + else + OutputDebugStringA(buf); +} + +FSP_API VOID FspDebugLogSD(const char *format, PSECURITY_DESCRIPTOR SecurityDescriptor) +{ + char *Sddl; + + if (0 == SecurityDescriptor) + FspDebugLog(format, "null security descriptor"); + else if (ConvertSecurityDescriptorToStringSecurityDescriptorA(SecurityDescriptor, + SDDL_REVISION_1, + OWNER_SECURITY_INFORMATION | GROUP_SECURITY_INFORMATION | + DACL_SECURITY_INFORMATION | SACL_SECURITY_INFORMATION, + &Sddl, 0)) + { + FspDebugLog(format, Sddl); + LocalFree(Sddl); + } + else + FspDebugLog(format, "invalid security descriptor"); +} + +FSP_API VOID FspDebugLogSid(const char *format, PSID Sid) +{ + char *S; + + if (0 == Sid) + FspDebugLog(format, "null SID"); + else if (ConvertSidToStringSidA(Sid, &S)) + { + FspDebugLog(format, S); + LocalFree(S); + } + else + FspDebugLog(format, "invalid SID"); +} + +FSP_API VOID FspDebugLogFT(const char *format, PFILETIME FileTime) +{ + SYSTEMTIME SystemTime; + char buf[32]; + + if (FileTimeToSystemTime(FileTime, &SystemTime)) + { + wsprintfA(buf, "%04hu-%02hu-%02huT%02hu:%02hu:%02hu.%03huZ", + SystemTime.wYear, SystemTime.wMonth, SystemTime.wDay, + SystemTime.wHour, SystemTime.wMinute, SystemTime.wSecond, + SystemTime.wMilliseconds); + FspDebugLog(format, buf); + } + else + FspDebugLog(format, "invalid file time"); +} + +#define MAKE_UINT32_PAIR(v) \ + ((PLARGE_INTEGER)&(v))->HighPart, ((PLARGE_INTEGER)&(v))->LowPart + +static const char *FspDebugLogDispositionString(UINT32 CreateOptions) +{ + switch ((CreateOptions >> 24) & 0xff) + { + case FILE_CREATE: + return "FILE_CREATE"; + case FILE_OPEN: + return "FILE_OPEN"; + case FILE_OPEN_IF: + return "FILE_OPEN_IF"; + case FILE_OVERWRITE: + return "FILE_OVERWRITE"; + case FILE_SUPERSEDE: + return "FILE_SUPERSEDE"; + case FILE_OVERWRITE_IF: + return "FILE_OVERWRITE_IF"; + default: + return "INVALID"; + } +} + +static const char *FspDebugLogUserContextString(UINT64 UserContext, UINT64 UserContext2, char *Buf) +{ + wsprintfA(Buf, 0 == UserContext2 ? "%p" : "%p:%p", (PVOID)UserContext, (PVOID)UserContext2); + + return Buf; +} + +static const char *FspDebugLogFileTimeString(UINT64 FileTime, char *Buf) +{ + SYSTEMTIME SystemTime; + + if (0 == FileTime) + lstrcpyA(Buf, "0"); + else if (FileTimeToSystemTime((PFILETIME)&FileTime, &SystemTime)) + { + wsprintfA(Buf, "%04hu-%02hu-%02huT%02hu:%02hu:%02hu.%03huZ", + SystemTime.wYear, SystemTime.wMonth, SystemTime.wDay, + SystemTime.wHour, SystemTime.wMinute, SystemTime.wSecond, + SystemTime.wMilliseconds); + } + else + lstrcpyA(Buf, "INVALID"); + + return Buf; +} + +static const char *FspDebugLogFileInfoString(FSP_FSCTL_FILE_INFO *FileInfo, char *Buf) +{ + char CreationTimeBuf[32], LastAccessTimeBuf[32], LastWriteTimeBuf[32], ChangeTimeBuf[32]; + + wsprintfA(Buf, + "{" + "FileAttributes=%lx, " + "ReparseTag=%lx, " + "AllocationSize=%lx:%lx, " + "FileSize=%lx:%lx, " + "CreationTime=%s, " + "LastAccessTime=%s, " + "LastWriteTime=%s, " + "ChangeTime=%s, " + "IndexNumber=%lx:%lx" + "}", + FileInfo->FileAttributes, + FileInfo->ReparseTag, + MAKE_UINT32_PAIR(FileInfo->AllocationSize), + MAKE_UINT32_PAIR(FileInfo->FileSize), + FspDebugLogFileTimeString(FileInfo->CreationTime, CreationTimeBuf), + FspDebugLogFileTimeString(FileInfo->LastAccessTime, LastAccessTimeBuf), + FspDebugLogFileTimeString(FileInfo->LastWriteTime, LastWriteTimeBuf), + FspDebugLogFileTimeString(FileInfo->ChangeTime, ChangeTimeBuf), + MAKE_UINT32_PAIR(FileInfo->IndexNumber)); + + return Buf; +} + +static const char *FspDebugLogVolumeInfoString(FSP_FSCTL_VOLUME_INFO *VolumeInfo, char *Buf) +{ + wsprintfA(Buf, + "{" + "TotalSize=%lx:%lx, " + "FreeSize=%lx:%lx, " + "VolumeLabel=\"%.32S\"" + "}", + MAKE_UINT32_PAIR(VolumeInfo->TotalSize), + MAKE_UINT32_PAIR(VolumeInfo->FreeSize), + &VolumeInfo->VolumeLabel); + + return Buf; +} + +static const char *FspDebugLogWideCharBufferString(PVOID WideCharBuf, ULONG Length, char *Buf) +{ + WCHAR TempWideCharBuf[64 + 1]; + + if (Length > sizeof TempWideCharBuf - sizeof(WCHAR)) + Length = sizeof TempWideCharBuf - sizeof(WCHAR); + + memcpy(TempWideCharBuf, WideCharBuf, Length); + TempWideCharBuf[Length / sizeof(WCHAR)] = L'\0'; + + wsprintfA(Buf, "%.64S", TempWideCharBuf); + + return Buf; +} + +static const char *FspDebugLogReparseDataString(PVOID ReparseData0, char *Buf) +{ + union + { + PREPARSE_DATA_BUFFER D; + PREPARSE_GUID_DATA_BUFFER G; + } ReparseData; + char SubstituteName[64 + 1], PrintName[64 + 1]; + + ReparseData.D = ReparseData0; + if (0 == ReparseData.D->ReparseDataLength) + wsprintfA(Buf, + "{" + "ReparseTag=%#lx, " + "ReparseDataLength=%hu" + "}", + ReparseData.D->ReparseTag, ReparseData.D->ReparseDataLength); + else if (IO_REPARSE_TAG_MOUNT_POINT == ReparseData.D->ReparseTag) + wsprintfA(Buf, + "{" + "ReparseTag=IO_REPARSE_TAG_MOUNT_POINT, " + "SubstituteName=\"%s\", " + "PrintName=\"%s\"" + "}", + FspDebugLogWideCharBufferString( + ReparseData.D->MountPointReparseBuffer.PathBuffer + + ReparseData.D->MountPointReparseBuffer.SubstituteNameOffset / sizeof(WCHAR), + ReparseData.D->MountPointReparseBuffer.SubstituteNameLength, + SubstituteName), + FspDebugLogWideCharBufferString( + ReparseData.D->MountPointReparseBuffer.PathBuffer + + ReparseData.D->MountPointReparseBuffer.PrintNameOffset / sizeof(WCHAR), + ReparseData.D->MountPointReparseBuffer.PrintNameLength, + PrintName)); + else if (IO_REPARSE_TAG_SYMLINK == ReparseData.D->ReparseTag) + wsprintfA(Buf, + "{" + "ReparseTag=IO_REPARSE_TAG_SYMLINK, " + "SubstituteName=\"%s\", " + "PrintName=\"%s\", " + "Flags=%u" + "}", + FspDebugLogWideCharBufferString( + ReparseData.D->SymbolicLinkReparseBuffer.PathBuffer + + ReparseData.D->SymbolicLinkReparseBuffer.SubstituteNameOffset / sizeof(WCHAR), + ReparseData.D->SymbolicLinkReparseBuffer.SubstituteNameLength, + SubstituteName), + FspDebugLogWideCharBufferString( + ReparseData.D->SymbolicLinkReparseBuffer.PathBuffer + + ReparseData.D->SymbolicLinkReparseBuffer.PrintNameOffset / sizeof(WCHAR), + ReparseData.D->SymbolicLinkReparseBuffer.PrintNameLength, + PrintName), + ReparseData.D->SymbolicLinkReparseBuffer.Flags); + else if (IsReparseTagMicrosoft(ReparseData.D->ReparseTag)) + wsprintfA(Buf, + "{" + "ReparseTag=%#lx, " + "ReparseDataLength=%hu" + "}", + ReparseData.D->ReparseTag, ReparseData.D->ReparseDataLength); + else +#define Guid ReparseData.G->ReparseGuid + wsprintfA(Buf, + "{" + "ReparseTag=%#lx, " + "ReparseDataLength=%hu, " + "ReparseGuid={%08lX-%04X-%04X-%02X%02X-%02X%02X%02X%02X%02X%02X}" + "}", + ReparseData.G->ReparseTag, ReparseData.G->ReparseDataLength, + Guid.Data1, Guid.Data2, Guid.Data3, + Guid.Data4[0], Guid.Data4[1], Guid.Data4[2], Guid.Data4[3], + Guid.Data4[4], Guid.Data4[5], Guid.Data4[6], Guid.Data4[7]); +#undef Guid + + return Buf; +} + +static VOID FspDebugLogRequestVoid(FSP_FSCTL_TRANSACT_REQ *Request, const char *Name) +{ + FspDebugLog("%S[TID=%04lx]: %p: >>%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, Name); +} + +static VOID FspDebugLogResponseStatus(FSP_FSCTL_TRANSACT_RSP *Response, const char *Name) +{ + FspDebugLog("%S[TID=%04lx]: %p: <<%s IoStatus=%lx[%ld]\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Response->Hint, Name, + Response->IoStatus.Status, Response->IoStatus.Information); +} + +FSP_API VOID FspDebugLogRequest(FSP_FSCTL_TRANSACT_REQ *Request) +{ + char UserContextBuf[40]; + char CreationTimeBuf[32], LastAccessTimeBuf[32], LastWriteTimeBuf[32]; + char InfoBuf[256]; + char *Sddl = 0; + + switch (Request->Kind) + { + case FspFsctlTransactReservedKind: + FspDebugLogRequestVoid(Request, "RESERVED"); + break; + case FspFsctlTransactCreateKind: + if (0 != Request->Req.Create.SecurityDescriptor.Offset) + ConvertSecurityDescriptorToStringSecurityDescriptorA( + Request->Buffer + Request->Req.Create.SecurityDescriptor.Offset, + SDDL_REVISION_1, + OWNER_SECURITY_INFORMATION | GROUP_SECURITY_INFORMATION | + DACL_SECURITY_INFORMATION | SACL_SECURITY_INFORMATION, + &Sddl, 0); + FspDebugLog("%S[TID=%04lx]: %p: >>Create [%c%c%c%c%c%c] \"%S\", " + "%s, CreateOptions=%lx, FileAttributes=%lx, Security=%s%s%s, " + "AllocationSize=%lx:%lx, " + "AccessToken=%p[PID=%lx], DesiredAccess=%lx, GrantedAccess=%lx, " + "ShareAccess=%lx\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->Req.Create.UserMode ? 'U' : 'K', + Request->Req.Create.HasTraversePrivilege ? 'T' : '-', + Request->Req.Create.HasBackupPrivilege ? 'B' : '-', + Request->Req.Create.HasRestorePrivilege ? 'R' : '-', + Request->Req.Create.OpenTargetDirectory ? 'D' : '-', + Request->Req.Create.CaseSensitive ? 'C' : '-', + (PWSTR)Request->Buffer, + FspDebugLogDispositionString(Request->Req.Create.CreateOptions), + Request->Req.Create.CreateOptions & 0xffffff, + Request->Req.Create.FileAttributes, + Sddl ? "\"" : "", + Sddl ? Sddl : "NULL", + Sddl ? "\"" : "", + MAKE_UINT32_PAIR(Request->Req.Create.AllocationSize), + FSP_FSCTL_TRANSACT_REQ_TOKEN_HANDLE(Request->Req.Create.AccessToken), + FSP_FSCTL_TRANSACT_REQ_TOKEN_PID(Request->Req.Create.AccessToken), + Request->Req.Create.DesiredAccess, + Request->Req.Create.GrantedAccess, + Request->Req.Create.ShareAccess); + LocalFree(Sddl); + break; + case FspFsctlTransactOverwriteKind: + FspDebugLog("%S[TID=%04lx]: %p: >>Overwrite%s %s%S%s%s, " + "FileAttributes=%lx\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->Req.Overwrite.Supersede ? " [Supersede]" : "", + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.Overwrite.UserContext, Request->Req.Overwrite.UserContext2, + UserContextBuf), + Request->Req.Overwrite.FileAttributes); + break; + case FspFsctlTransactCleanupKind: + FspDebugLog("%S[TID=%04lx]: %p: >>Cleanup%s %s%S%s%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->Req.Cleanup.Delete ? " [Delete]" : "", + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.Cleanup.UserContext, Request->Req.Cleanup.UserContext2, + UserContextBuf)); + break; + case FspFsctlTransactCloseKind: + FspDebugLog("%S[TID=%04lx]: %p: >>Close %s%S%s%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.Close.UserContext, Request->Req.Close.UserContext2, + UserContextBuf)); + break; + case FspFsctlTransactReadKind: + FspDebugLog("%S[TID=%04lx]: %p: >>Read %s%S%s%s, " + "Address=%p, Offset=%lx:%lx, Length=%ld, Key=%lx\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.Read.UserContext, Request->Req.Read.UserContext2, + UserContextBuf), + (PVOID)Request->Req.Read.Address, + MAKE_UINT32_PAIR(Request->Req.Read.Offset), + Request->Req.Read.Length, + Request->Req.Read.Key); + break; + case FspFsctlTransactWriteKind: + FspDebugLog("%S[TID=%04lx]: %p: >>Write%s %s%S%s%s, " + "Address=%p, Offset=%lx:%lx, Length=%ld, Key=%lx\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->Req.Write.ConstrainedIo ? " [C]" : "", + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.Write.UserContext, Request->Req.Write.UserContext2, + UserContextBuf), + (PVOID)Request->Req.Write.Address, + MAKE_UINT32_PAIR(Request->Req.Write.Offset), + Request->Req.Write.Length, + Request->Req.Write.Key); + break; + case FspFsctlTransactQueryInformationKind: + FspDebugLog("%S[TID=%04lx]: %p: >>QueryInformation %s%S%s%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.QueryInformation.UserContext, Request->Req.QueryInformation.UserContext2, + UserContextBuf)); + break; + case FspFsctlTransactSetInformationKind: + switch (Request->Req.SetInformation.FileInformationClass) + { + case 4/*FileBasicInformation*/: + FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [Basic] %s%S%s%s, " + "FileAttributes=%lx, CreationTime=%s, LastAccessTime=%s, LastWriteTime=%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, + UserContextBuf), + Request->Req.SetInformation.Info.Basic.FileAttributes, + FspDebugLogFileTimeString(Request->Req.SetInformation.Info.Basic.CreationTime, + CreationTimeBuf), + FspDebugLogFileTimeString(Request->Req.SetInformation.Info.Basic.LastAccessTime, + LastAccessTimeBuf), + FspDebugLogFileTimeString(Request->Req.SetInformation.Info.Basic.LastWriteTime, + LastWriteTimeBuf)); + break; + case 19/*FileAllocationInformation*/: + FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [Allocation] %s%S%s%s, " + "AllocationSize=%lx:%lx\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, + UserContextBuf), + MAKE_UINT32_PAIR(Request->Req.SetInformation.Info.Allocation.AllocationSize)); + break; + case 20/*FileEndOfFileInformation*/: + FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [EndOfFile] %s%S%s%s, " + "FileSize = %lx:%lx\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, + UserContextBuf), + MAKE_UINT32_PAIR(Request->Req.SetInformation.Info.EndOfFile.FileSize)); + break; + case 13/*FileDispositionInformation*/: + FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [Disposition] %s%S%s%s, " + "%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, + UserContextBuf), + Request->Req.SetInformation.Info.Disposition.Delete ? "Delete" : "Undelete"); + break; + case 64/*FileDispositionInformationEx*/: + FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [DispositionEx] %s%S%s%s, " + "Flags=%lx\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, + UserContextBuf), + Request->Req.SetInformation.Info.DispositionEx.Flags); + break; + case 10/*FileRenameInformation*/: + FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [Rename] %s%S%s%s, " + "NewFileName=\"%S\", AccessToken=%p[PID=%lx]\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, + UserContextBuf), + (PWSTR)(Request->Buffer + Request->Req.SetInformation.Info.Rename.NewFileName.Offset), + FSP_FSCTL_TRANSACT_REQ_TOKEN_HANDLE(Request->Req.SetInformation.Info.Rename.AccessToken), + FSP_FSCTL_TRANSACT_REQ_TOKEN_PID(Request->Req.SetInformation.Info.Rename.AccessToken)); + break; + case 65/*FileRenameInformationEx*/: + FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [RenameEx] %s%S%s%s, " + "NewFileName=\"%S\", AccessToken=%p[PID=%lx], Flags=%lx\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, + UserContextBuf), + (PWSTR)(Request->Buffer + Request->Req.SetInformation.Info.Rename.NewFileName.Offset), + FSP_FSCTL_TRANSACT_REQ_TOKEN_HANDLE(Request->Req.SetInformation.Info.Rename.AccessToken), + FSP_FSCTL_TRANSACT_REQ_TOKEN_PID(Request->Req.SetInformation.Info.Rename.AccessToken), + Request->Req.SetInformation.Info.RenameEx.Flags); + break; + default: + FspDebugLog("%S[TID=%04lx]: %p: >>SetInformation [INVALID] %s%S%s%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.SetInformation.UserContext, Request->Req.SetInformation.UserContext2, + UserContextBuf)); + break; + } + break; + case FspFsctlTransactQueryEaKind: + FspDebugLogRequestVoid(Request, "QUERYEA"); + break; + case FspFsctlTransactSetEaKind: + FspDebugLogRequestVoid(Request, "SETEA"); + break; + case FspFsctlTransactFlushBuffersKind: + FspDebugLog("%S[TID=%04lx]: %p: >>FlushBuffers %s%S%s%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.FlushBuffers.UserContext, Request->Req.FlushBuffers.UserContext2, + UserContextBuf)); + break; + case FspFsctlTransactQueryVolumeInformationKind: + FspDebugLogRequestVoid(Request, "QueryVolumeInformation"); + break; + case FspFsctlTransactSetVolumeInformationKind: + switch (Request->Req.SetVolumeInformation.FsInformationClass) + { + case 2/*FileFsLabelInformation*/: + FspDebugLog("%S[TID=%04lx]: %p: >>SetVolumeInformation [FsLabel] " + "Label=\"%S\"\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + (PWSTR)Request->Buffer); + break; + default: + FspDebugLog("%S[TID=%04lx]: %p: >>SetVolumeInformation [INVALID]\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint); + break; + } + break; + case FspFsctlTransactQueryDirectoryKind: + FspDebugLog("%S[TID=%04lx]: %p: >>QueryDirectory %s%S%s%s, " + "Address=%p, Length=%ld, Pattern=%s%S%s, Marker=%s%S%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.QueryDirectory.UserContext, Request->Req.QueryDirectory.UserContext2, + UserContextBuf), + (PVOID)Request->Req.QueryDirectory.Address, + Request->Req.QueryDirectory.Length, + Request->Req.QueryDirectory.Pattern.Size ? "\"" : "", + Request->Req.QueryDirectory.Pattern.Size ? + (PWSTR)(Request->Buffer + Request->Req.QueryDirectory.Pattern.Offset) : L"NULL", + Request->Req.QueryDirectory.Pattern.Size ? "\"" : "", + Request->Req.QueryDirectory.Marker.Size ? "\"" : "", + Request->Req.QueryDirectory.Marker.Size ? + (PWSTR)(Request->Buffer + Request->Req.QueryDirectory.Marker.Offset) : L"NULL", + Request->Req.QueryDirectory.Marker.Size ? "\"" : ""); + break; + case FspFsctlTransactFileSystemControlKind: + switch (Request->Req.FileSystemControl.FsControlCode) + { + case FSCTL_GET_REPARSE_POINT: + FspDebugLog("%S[TID=%04lx]: %p: >>FileSystemControl [FSCTL_GET_REPARSE_POINT] %s%S%s%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.FileSystemControl.UserContext, Request->Req.FileSystemControl.UserContext2, + UserContextBuf)); + break; + case FSCTL_SET_REPARSE_POINT: + case FSCTL_DELETE_REPARSE_POINT: + FspDebugLog("%S[TID=%04lx]: %p: >>FileSystemControl [%s] %s%S%s%s " + "ReparseData=%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + FSCTL_SET_REPARSE_POINT == Request->Req.FileSystemControl.FsControlCode ? + "FSCTL_SET_REPARSE_POINT" : "FSCTL_DELETE_REPARSE_POINT", + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.FileSystemControl.UserContext, Request->Req.FileSystemControl.UserContext2, + UserContextBuf), + FspDebugLogReparseDataString(Request->Buffer + Request->Req.FileSystemControl.Buffer.Offset, + InfoBuf)); + break; + default: + FspDebugLog("%S[TID=%04lx]: %p: >>FileSystemControl [INVALID] %s%S%s%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.FileSystemControl.UserContext, Request->Req.FileSystemControl.UserContext2, + UserContextBuf)); + break; + } + break; + case FspFsctlTransactDeviceControlKind: + FspDebugLogRequestVoid(Request, "DEVICECONTROL"); + break; + case FspFsctlTransactShutdownKind: + FspDebugLogRequestVoid(Request, "SHUTDOWN"); + break; + case FspFsctlTransactLockControlKind: + FspDebugLogRequestVoid(Request, "LOCKCONTROL"); + break; + case FspFsctlTransactQuerySecurityKind: + FspDebugLog("%S[TID=%04lx]: %p: >>QuerySecurity %s%S%s%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.QuerySecurity.UserContext, Request->Req.QuerySecurity.UserContext2, + UserContextBuf)); + break; + case FspFsctlTransactSetSecurityKind: + if (0 != Request->Req.SetSecurity.SecurityDescriptor.Size) + ConvertSecurityDescriptorToStringSecurityDescriptorA( + Request->Buffer + Request->Req.SetSecurity.SecurityDescriptor.Offset, + SDDL_REVISION_1, + OWNER_SECURITY_INFORMATION | GROUP_SECURITY_INFORMATION | + DACL_SECURITY_INFORMATION | SACL_SECURITY_INFORMATION, + &Sddl, 0); + FspDebugLog("%S[TID=%04lx]: %p: >>SetSecurity %s%S%s%s, " + "SecurityInformation=%lx, Security=%s%s%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.SetSecurity.UserContext, Request->Req.SetSecurity.UserContext2, + UserContextBuf), + Request->Req.SetSecurity.SecurityInformation, + Sddl ? "\"" : "", + Sddl ? Sddl : "NULL", + Sddl ? "\"" : ""); + LocalFree(Sddl); + break; + case FspFsctlTransactQueryStreamInformationKind: + FspDebugLog("%S[TID=%04lx]: %p: >>QueryStreamInformation %s%S%s%s\n", + FspDiagIdent(), GetCurrentThreadId(), (PVOID)Request->Hint, + Request->FileName.Size ? "\"" : "", + Request->FileName.Size ? (PWSTR)Request->Buffer : L"", + Request->FileName.Size ? "\", " : "", + FspDebugLogUserContextString( + Request->Req.QueryStreamInformation.UserContext, Request->Req.QueryStreamInformation.UserContext2, + UserContextBuf)); + break; + default: + FspDebugLogRequestVoid(Request, "INVALID"); + break; + } +} + +FSP_API VOID FspDebugLogResponse(FSP_FSCTL_TRANSACT_RSP *Response) +{ + if (STATUS_PENDING == Response->IoStatus.Status) + return; + + char UserContextBuf[40]; + char InfoBuf[256]; + char *Sddl = 0; + + switch (Response->Kind) + { + case FspFsctlTransactReservedKind: + FspDebugLogResponseStatus(Response, "RESERVED"); + break; + case FspFsctlTransactCreateKind: + if (!NT_SUCCESS(Response->IoStatus.Status)) + FspDebugLogResponseStatus(Response, "Create"); + else if (STATUS_REPARSE == Response->IoStatus.Status) + { + if (0/*IO_REPARSE*/ == Response->IoStatus.Information) + FspDebugLog("%S[TID=%04lx]: %p: <Hint, + Response->IoStatus.Status, Response->IoStatus.Information, + FspDebugLogWideCharBufferString( + Response->Buffer + Response->Rsp.Create.Reparse.Buffer.Offset, + Response->Rsp.Create.Reparse.Buffer.Size, + InfoBuf)); + else if (1/*IO_REMOUNT*/ == Response->IoStatus.Information) + FspDebugLogResponseStatus(Response, "Create"); + else + FspDebugLog("%S[TID=%04lx]: %p: <Hint, + Response->IoStatus.Status, Response->IoStatus.Information, + FspDebugLogReparseDataString( + Response->Buffer + Response->Rsp.Create.Reparse.Buffer.Offset, + InfoBuf)); + } + else + FspDebugLog("%S[TID=%04lx]: %p: <Hint, + Response->IoStatus.Status, Response->IoStatus.Information, + FspDebugLogUserContextString( + Response->Rsp.Create.Opened.UserContext, Response->Rsp.Create.Opened.UserContext2, + UserContextBuf), + Response->Rsp.Create.Opened.GrantedAccess, + FspDebugLogFileInfoString(&Response->Rsp.Create.Opened.FileInfo, InfoBuf)); + break; + case FspFsctlTransactOverwriteKind: + if (!NT_SUCCESS(Response->IoStatus.Status)) + FspDebugLogResponseStatus(Response, "Overwrite"); + else + FspDebugLog("%S[TID=%04lx]: %p: <Hint, + Response->IoStatus.Status, Response->IoStatus.Information, + FspDebugLogFileInfoString(&Response->Rsp.Overwrite.FileInfo, InfoBuf)); + break; + case FspFsctlTransactCleanupKind: + FspDebugLogResponseStatus(Response, "Cleanup"); + break; + case FspFsctlTransactCloseKind: + FspDebugLogResponseStatus(Response, "Close"); + break; + case FspFsctlTransactReadKind: + FspDebugLogResponseStatus(Response, "Read"); + break; + case FspFsctlTransactWriteKind: + if (!NT_SUCCESS(Response->IoStatus.Status)) + FspDebugLogResponseStatus(Response, "Write"); + else + FspDebugLog("%S[TID=%04lx]: %p: <Hint, + Response->IoStatus.Status, Response->IoStatus.Information, + FspDebugLogFileInfoString(&Response->Rsp.Write.FileInfo, InfoBuf)); + break; + case FspFsctlTransactQueryInformationKind: + if (!NT_SUCCESS(Response->IoStatus.Status)) + FspDebugLogResponseStatus(Response, "QueryInformation"); + else + FspDebugLog("%S[TID=%04lx]: %p: <Hint, + Response->IoStatus.Status, Response->IoStatus.Information, + FspDebugLogFileInfoString(&Response->Rsp.QueryInformation.FileInfo, InfoBuf)); + break; + case FspFsctlTransactSetInformationKind: + if (!NT_SUCCESS(Response->IoStatus.Status)) + FspDebugLogResponseStatus(Response, "SetInformation"); + else + FspDebugLog("%S[TID=%04lx]: %p: <Hint, + Response->IoStatus.Status, Response->IoStatus.Information, + FspDebugLogFileInfoString(&Response->Rsp.SetInformation.FileInfo, InfoBuf)); + break; + case FspFsctlTransactQueryEaKind: + FspDebugLogResponseStatus(Response, "QUERYEA"); + break; + case FspFsctlTransactSetEaKind: + FspDebugLogResponseStatus(Response, "SETEA"); + break; + case FspFsctlTransactFlushBuffersKind: + FspDebugLogResponseStatus(Response, "FlushBuffers"); + break; + case FspFsctlTransactQueryVolumeInformationKind: + if (!NT_SUCCESS(Response->IoStatus.Status)) + FspDebugLogResponseStatus(Response, "QueryVolumeInformation"); + else + FspDebugLog("%S[TID=%04lx]: %p: <Hint, + Response->IoStatus.Status, Response->IoStatus.Information, + FspDebugLogVolumeInfoString(&Response->Rsp.QueryVolumeInformation.VolumeInfo, InfoBuf)); + break; + case FspFsctlTransactSetVolumeInformationKind: + if (!NT_SUCCESS(Response->IoStatus.Status)) + FspDebugLogResponseStatus(Response, "SetVolumeInformation"); + else + FspDebugLog("%S[TID=%04lx]: %p: <Hint, + Response->IoStatus.Status, Response->IoStatus.Information, + FspDebugLogVolumeInfoString(&Response->Rsp.SetVolumeInformation.VolumeInfo, InfoBuf)); + break; + case FspFsctlTransactQueryDirectoryKind: + FspDebugLogResponseStatus(Response, "QueryDirectory"); + break; + case FspFsctlTransactFileSystemControlKind: + if (!NT_SUCCESS(Response->IoStatus.Status) || + 0 == Response->Rsp.FileSystemControl.Buffer.Size) + FspDebugLogResponseStatus(Response, "FileSystemControl"); + else + FspDebugLog("%S[TID=%04lx]: %p: <Hint, + Response->IoStatus.Status, Response->IoStatus.Information, + FspDebugLogReparseDataString(Response->Buffer + Response->Rsp.FileSystemControl.Buffer.Offset, + InfoBuf)); + break; + case FspFsctlTransactDeviceControlKind: + FspDebugLogResponseStatus(Response, "DEVICECONTROL"); + break; + case FspFsctlTransactShutdownKind: + FspDebugLogResponseStatus(Response, "SHUTDOWN"); + break; + case FspFsctlTransactLockControlKind: + FspDebugLogResponseStatus(Response, "LOCKCONTROL"); + break; + case FspFsctlTransactQuerySecurityKind: + if (!NT_SUCCESS(Response->IoStatus.Status)) + FspDebugLogResponseStatus(Response, "QuerySecurity"); + else + { + if (0 != Response->Rsp.QuerySecurity.SecurityDescriptor.Size) + ConvertSecurityDescriptorToStringSecurityDescriptorA( + Response->Buffer + Response->Rsp.QuerySecurity.SecurityDescriptor.Offset, + SDDL_REVISION_1, + OWNER_SECURITY_INFORMATION | GROUP_SECURITY_INFORMATION | + DACL_SECURITY_INFORMATION | SACL_SECURITY_INFORMATION, + &Sddl, 0); + FspDebugLog("%S[TID=%04lx]: %p: <Hint, + Response->IoStatus.Status, Response->IoStatus.Information, + Sddl ? "\"" : "", + Sddl ? Sddl : "NULL", + Sddl ? "\"" : ""); + LocalFree(Sddl); + } + break; + case FspFsctlTransactSetSecurityKind: + if (!NT_SUCCESS(Response->IoStatus.Status)) + FspDebugLogResponseStatus(Response, "SetSecurity"); + else + { + if (0 != Response->Rsp.SetSecurity.SecurityDescriptor.Size) + ConvertSecurityDescriptorToStringSecurityDescriptorA( + Response->Buffer + Response->Rsp.SetSecurity.SecurityDescriptor.Offset, + SDDL_REVISION_1, + OWNER_SECURITY_INFORMATION | GROUP_SECURITY_INFORMATION | + DACL_SECURITY_INFORMATION | SACL_SECURITY_INFORMATION, + &Sddl, 0); + FspDebugLog("%S[TID=%04lx]: %p: <Hint, + Response->IoStatus.Status, Response->IoStatus.Information, + Sddl ? "\"" : "", + Sddl ? Sddl : "NULL", + Sddl ? "\"" : ""); + LocalFree(Sddl); + } + break; + case FspFsctlTransactQueryStreamInformationKind: + FspDebugLogResponseStatus(Response, "QueryStreamInformation"); + break; + default: + FspDebugLogResponseStatus(Response, "INVALID"); + break; + } +} diff --git a/src/dll/fsctl.c b/src/dll/fsctl.c index b44d061b..2cb8930e 100644 --- a/src/dll/fsctl.c +++ b/src/dll/fsctl.c @@ -127,6 +127,7 @@ FSP_API NTSTATUS FspFsctlTransact(HANDLE VolumeHandle, BOOLEAN Batch) { NTSTATUS Result = STATUS_SUCCESS; + DWORD ControlCode; DWORD Bytes = 0; if (0 != PRequestBufSize) @@ -135,8 +136,12 @@ FSP_API NTSTATUS FspFsctlTransact(HANDLE VolumeHandle, *PRequestBufSize = 0; } + ControlCode = Batch ? + (DEBUGTEST(50) ? FSP_IOCTL_TRANSACT_BATCH : FSP_FSCTL_TRANSACT_BATCH) : + (DEBUGTEST(50) ? FSP_IOCTL_TRANSACT : FSP_FSCTL_TRANSACT); + if (!DeviceIoControl(VolumeHandle, - Batch ? FSP_FSCTL_TRANSACT_BATCH : FSP_FSCTL_TRANSACT, + ControlCode, ResponseBuf, (DWORD)ResponseBufSize, RequestBuf, Bytes, &Bytes, 0)) { diff --git a/src/dll/library.h b/src/dll/library.h index 7c83f676..38df10b6 100644 --- a/src/dll/library.h +++ b/src/dll/library.h @@ -46,6 +46,15 @@ #define DEBUGLOGSID(fmt, Sid) ((void)0) #endif +/* DEBUGTEST */ +#if !defined(NDEBUG) +ULONG DebugRandom(VOID); +#define DEBUGTEST(Percent) \ + (DebugRandom() <= (Percent) * 0x7fff / 100) +#else +#define DEBUGTEST(Percent) (TRUE) +#endif + VOID FspWksidFinalize(BOOLEAN Dynamic); VOID FspPosixFinalize(BOOLEAN Dynamic); VOID FspEventLogFinalize(BOOLEAN Dynamic); diff --git a/src/sys/devctl.c b/src/sys/devctl.c index ec8fc5bf..fc9e6b9d 100644 --- a/src/sys/devctl.c +++ b/src/sys/devctl.c @@ -21,6 +21,8 @@ #include +static NTSTATUS FspFsctlDeviceControl( + PDEVICE_OBJECT DeviceObject, PIRP Irp, PIO_STACK_LOCATION IrpSp); static NTSTATUS FspFsvrtDeviceControl( PDEVICE_OBJECT DeviceObject, PIRP Irp, PIO_STACK_LOCATION IrpSp); static BOOLEAN FspFsvrtDeviceControlStorageQuery( @@ -33,6 +35,7 @@ static FSP_IOP_REQUEST_FINI FspFsvolDeviceControlRequestFini; FSP_DRIVER_DISPATCH FspDeviceControl; #ifdef ALLOC_PRAGMA +#pragma alloc_text(PAGE, FspFsctlDeviceControl) #pragma alloc_text(PAGE, FspFsvrtDeviceControl) #pragma alloc_text(PAGE, FspFsvrtDeviceControlStorageQuery) #pragma alloc_text(PAGE, FspFsvolDeviceControl) @@ -46,6 +49,25 @@ enum RequestFileNode = 0, }; +static NTSTATUS FspFsctlDeviceControl( + PDEVICE_OBJECT FsctlDeviceObject, PIRP Irp, PIO_STACK_LOCATION IrpSp) +{ + PAGED_CODE(); + + NTSTATUS Result = STATUS_INVALID_DEVICE_REQUEST; + switch (IrpSp->Parameters.DeviceIoControl.IoControlCode) + { + case FSP_IOCTL_TRANSACT: + case FSP_IOCTL_TRANSACT_BATCH: + case FSP_IOCTL_TRANSACT_INTERNAL: + if (0 != IrpSp->FileObject->FsContext2) + Result = FspVolumeTransact(FsctlDeviceObject, Irp, IrpSp); + break; + } + + return Result; +} + static NTSTATUS FspFsvrtDeviceControl( PDEVICE_OBJECT FsvrtDeviceObject, PIRP Irp, PIO_STACK_LOCATION IrpSp) { @@ -258,6 +280,8 @@ NTSTATUS FspDeviceControl( FSP_RETURN(Result = FspFsvolDeviceControl(DeviceObject, Irp, IrpSp)); case FspFsvrtDeviceExtensionKind: FSP_RETURN(Result = FspFsvrtDeviceControl(DeviceObject, Irp, IrpSp)); + case FspFsctlDeviceExtensionKind: + FSP_RETURN(Result = FspFsctlDeviceControl(DeviceObject, Irp, IrpSp)); default: FSP_RETURN(Result = STATUS_INVALID_DEVICE_REQUEST); } diff --git a/src/sys/volume.c b/src/sys/volume.c index 3b105bda..5f4045d3 100644 --- a/src/sys/volume.c +++ b/src/sys/volume.c @@ -764,12 +764,24 @@ NTSTATUS FspVolumeTransact( { PAGED_CODE(); - ASSERT(IRP_MJ_FILE_SYSTEM_CONTROL == IrpSp->MajorFunction); - ASSERT(IRP_MN_USER_FS_REQUEST == IrpSp->MinorFunction); ASSERT( - FSP_FSCTL_TRANSACT == IrpSp->Parameters.FileSystemControl.FsControlCode || - FSP_FSCTL_TRANSACT_BATCH == IrpSp->Parameters.FileSystemControl.FsControlCode || - FSP_FSCTL_TRANSACT_INTERNAL == IrpSp->Parameters.FileSystemControl.FsControlCode); + ( + IRP_MJ_FILE_SYSTEM_CONTROL == IrpSp->MajorFunction && + IRP_MN_USER_FS_REQUEST == IrpSp->MinorFunction && + ( + FSP_FSCTL_TRANSACT == IrpSp->Parameters.FileSystemControl.FsControlCode || + FSP_FSCTL_TRANSACT_BATCH == IrpSp->Parameters.FileSystemControl.FsControlCode || + FSP_FSCTL_TRANSACT_INTERNAL == IrpSp->Parameters.FileSystemControl.FsControlCode + ) + ) || + ( + IRP_MJ_DEVICE_CONTROL == IrpSp->MajorFunction && + ( + FSP_IOCTL_TRANSACT == IrpSp->Parameters.FileSystemControl.FsControlCode || + FSP_IOCTL_TRANSACT_BATCH == IrpSp->Parameters.FileSystemControl.FsControlCode || + FSP_IOCTL_TRANSACT_INTERNAL == IrpSp->Parameters.FileSystemControl.FsControlCode + ) + )); ASSERT(0 != IrpSp->FileObject->FsContext2); /* check parameters */ @@ -779,7 +791,7 @@ NTSTATUS FspVolumeTransact( ULONG OutputBufferLength = IrpSp->Parameters.FileSystemControl.OutputBufferLength; PVOID InputBuffer = 0; PVOID OutputBuffer = 0; - if (FSP_FSCTL_TRANSACT_INTERNAL == ControlCode) + if (0x800 + 'I' /*FSP_xxCTL_TRANSACT_INTERNAL*/ == ((ControlCode >> 2) & 0xfff)) { InputBuffer = IrpSp->Parameters.FileSystemControl.Type3InputBuffer; if (KernelMode != Irp->RequestorMode) @@ -796,9 +808,9 @@ NTSTATUS FspVolumeTransact( FSP_FSCTL_DEFAULT_ALIGN_UP(sizeof(FSP_FSCTL_TRANSACT_RSP)) > InputBufferLength) return STATUS_INVALID_PARAMETER; if (0 != OutputBufferLength && - ((FSP_FSCTL_TRANSACT == ControlCode && + ((0x800 + 'T' /*FSP_xxCTL_TRANSACT*/ == ((ControlCode >> 2) & 0xfff) && FSP_FSCTL_TRANSACT_BUFFER_SIZEMIN > OutputBufferLength) || - (FSP_FSCTL_TRANSACT_BATCH == ControlCode && + (0x800 + 't' /*FSP_xxCTL_TRANSACT_BATCH*/ == ((ControlCode >> 2) & 0xfff) && FSP_FSCTL_TRANSACT_BATCH_BUFFER_SIZEMIN > OutputBufferLength))) return STATUS_BUFFER_TOO_SMALL; }