api: upgrade logging

Log runtime information to quickly check whether the values are sane
when analyzing error logs sent in by users.

Signed-off-by: Simon Rozman <simon@rozman.si>
This commit is contained in:
Simon Rozman 2021-02-02 13:12:45 +01:00
parent 542a281808
commit bc5cde8916
10 changed files with 431 additions and 177 deletions

View File

@ -75,7 +75,11 @@ static _Return_type_success_(return != NULL) SP_DRVINFO_DETAIL_DATA_W *GetAdapte
Free(DrvInfoDetailData); Free(DrvInfoDetailData);
if (LastError != ERROR_INSUFFICIENT_BUFFER) if (LastError != ERROR_INSUFFICIENT_BUFFER)
{ {
SetLastError(LOG_ERROR(L"Failed", LastError)); if (DevInfoData)
LOG_ERROR(LastError, L"Failed for adapter %u", DevInfoData->DevInst);
else
LOG_ERROR(LastError, L"Failed");
SetLastError(LastError);
return NULL; return NULL;
} }
} }
@ -99,7 +103,8 @@ static _Return_type_success_(return != NULL) void *GetDeviceRegistryProperty(
Free(Data); Free(Data);
if (LastError != ERROR_INSUFFICIENT_BUFFER) if (LastError != ERROR_INSUFFICIENT_BUFFER)
{ {
SetLastError(LOG_ERROR(L"Querying property failed", LastError)); SetLastError(
LOG_ERROR(LastError, L"Querying adapter %u property 0x%x failed", DevInfoData->DevInst, Property));
return NULL; return NULL;
} }
} }
@ -122,7 +127,11 @@ static _Return_type_success_(return != NULL)
LastError = GetLastError(); LastError = GetLastError();
break; break;
default: default:
LOG(WINTUN_LOG_ERR, L"Property is not a string"); LOG(WINTUN_LOG_ERR,
L"Adapter %u property 0x%x is not a string (type: %u)",
DevInfoData->DevInst,
Property,
ValueType);
LastError = ERROR_INVALID_DATATYPE; LastError = ERROR_INVALID_DATATYPE;
} }
Free(Buf); Free(Buf);
@ -147,7 +156,11 @@ static _Return_type_success_(return != NULL)
LastError = GetLastError(); LastError = GetLastError();
break; break;
default: default:
LOG(WINTUN_LOG_ERR, L"Property is not a string"); LOG(WINTUN_LOG_ERR,
L"Adapter %u property 0x%x is not a string (type: %u)",
DevInfoData->DevInst,
Property,
ValueType);
LastError = ERROR_INVALID_DATATYPE; LastError = ERROR_INVALID_DATATYPE;
} }
Free(Buf); Free(Buf);
@ -170,7 +183,7 @@ IsOurAdapter(_In_ HDEVINFO DevInfo, _In_ SP_DEVINFO_DATA *DevInfoData)
WCHAR *Hwids = GetDeviceRegistryMultiString(DevInfo, DevInfoData, SPDRP_HARDWAREID); WCHAR *Hwids = GetDeviceRegistryMultiString(DevInfo, DevInfoData, SPDRP_HARDWAREID);
if (!Hwids) if (!Hwids)
{ {
LOG_LAST_ERROR(L"Failed to get hardware ID"); LOG_LAST_ERROR(L"Failed to get adapter %u hardware ID", DevInfoData->DevInst);
return FALSE; return FALSE;
} }
BOOL IsOurs = IsOurHardwareID(Hwids); BOOL IsOurs = IsOurHardwareID(Hwids);
@ -190,7 +203,7 @@ static _Return_type_success_(return != NULL) WCHAR *GetDeviceObjectFileName(_In_
ERROR_GEN_FAILURE); ERROR_GEN_FAILURE);
if (LastError != ERROR_SUCCESS) if (LastError != ERROR_SUCCESS)
{ {
SetLastError(LOG_ERROR(L"Failed to query associated instances size", LastError)); SetLastError(LOG_ERROR(LastError, L"Failed to query adapter %s associated instances size", InstanceId));
return NULL; return NULL;
} }
WCHAR *Interfaces = Alloc(InterfacesLen * sizeof(WCHAR)); WCHAR *Interfaces = Alloc(InterfacesLen * sizeof(WCHAR));
@ -206,7 +219,7 @@ static _Return_type_success_(return != NULL) WCHAR *GetDeviceObjectFileName(_In_
ERROR_GEN_FAILURE); ERROR_GEN_FAILURE);
if (LastError != ERROR_SUCCESS) if (LastError != ERROR_SUCCESS)
{ {
LOG_ERROR(L"Failed to get associated instances", LastError); LOG_ERROR(LastError, L"Failed to get adapter %s associated instances", InstanceId);
Free(Interfaces); Free(Interfaces);
SetLastError(LastError); SetLastError(LastError);
return NULL; return NULL;
@ -227,9 +240,9 @@ static _Return_type_success_(return != INVALID_HANDLE_VALUE) HANDLE OpenDeviceOb
OPEN_EXISTING, OPEN_EXISTING,
0, 0,
NULL); NULL);
Free(Filename);
if (Handle == INVALID_HANDLE_VALUE) if (Handle == INVALID_HANDLE_VALUE)
LOG_LAST_ERROR(L"Failed to connect to adapter"); LOG_LAST_ERROR(L"Failed to connect to adapter %s associated instance %s", InstanceId, Filename);
Free(Filename);
return Handle; return Handle;
} }
@ -253,6 +266,7 @@ EnsureDeviceObject(_In_z_ const WCHAR *InstanceId)
Sleep(50); Sleep(50);
} }
Exists = FALSE; Exists = FALSE;
LOG_LAST_ERROR(L"Failed to connect to adapter %s associated instance %s", InstanceId, Filename);
out: out:
Free(Filename); Free(Filename);
return Exists; return Exists;
@ -268,7 +282,7 @@ static _Return_type_success_(return != FALSE) BOOL
if (SetupDiGetDeviceInstanceIdW(DevInfo, DevInfoData, NULL, 0, &RequiredBytes) || if (SetupDiGetDeviceInstanceIdW(DevInfo, DevInfoData, NULL, 0, &RequiredBytes) ||
(LastError = GetLastError()) != ERROR_INSUFFICIENT_BUFFER) (LastError = GetLastError()) != ERROR_INSUFFICIENT_BUFFER)
{ {
LOG_ERROR(L"Failed to query instance ID size", LastError); LOG_ERROR(LastError, L"Failed to query adapter %u instance ID size", DevInfoData->DevInst);
return FALSE; return FALSE;
} }
WCHAR *InstanceId = Zalloc(sizeof(*InstanceId) * RequiredBytes); WCHAR *InstanceId = Zalloc(sizeof(*InstanceId) * RequiredBytes);
@ -276,13 +290,13 @@ static _Return_type_success_(return != FALSE) BOOL
return FALSE; return FALSE;
if (!SetupDiGetDeviceInstanceIdW(DevInfo, DevInfoData, InstanceId, RequiredBytes, &RequiredBytes)) if (!SetupDiGetDeviceInstanceIdW(DevInfo, DevInfoData, InstanceId, RequiredBytes, &RequiredBytes))
{ {
LastError = LOG_LAST_ERROR(L"Failed to get instance ID"); LastError = LOG_LAST_ERROR(L"Failed to get adapter %u instance ID", DevInfoData->DevInst);
goto cleanupInstanceId; goto cleanupInstanceId;
} }
HANDLE NdisHandle = OpenDeviceObject(InstanceId); HANDLE NdisHandle = OpenDeviceObject(InstanceId);
if (NdisHandle == INVALID_HANDLE_VALUE) if (NdisHandle == INVALID_HANDLE_VALUE)
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get adapter object"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to get adapter %u object", DevInfoData->DevInst);
goto cleanupInstanceId; goto cleanupInstanceId;
} }
if (DeviceIoControl(NdisHandle, TUN_IOCTL_FORCE_CLOSE_HANDLES, NULL, 0, NULL, 0, &RequiredBytes, NULL)) if (DeviceIoControl(NdisHandle, TUN_IOCTL_FORCE_CLOSE_HANDLES, NULL, 0, NULL, 0, &RequiredBytes, NULL))
@ -293,7 +307,7 @@ static _Return_type_success_(return != FALSE) BOOL
else if (GetLastError() == ERROR_NOTHING_TO_TERMINATE) else if (GetLastError() == ERROR_NOTHING_TO_TERMINATE)
LastError = ERROR_SUCCESS; LastError = ERROR_SUCCESS;
else else
LastError = LOG_LAST_ERROR(L"Failed to perform ioctl"); LastError = LOG_LAST_ERROR(L"Failed to perform ioctl on adapter %u", DevInfoData->DevInst);
CloseHandle(NdisHandle); CloseHandle(NdisHandle);
cleanupInstanceId: cleanupInstanceId:
Free(InstanceId); Free(InstanceId);
@ -331,15 +345,15 @@ static _Return_type_success_(return != FALSE) BOOL
((Status & DN_HAS_PROBLEM) && ProblemCode == CM_PROB_DISABLED)) ((Status & DN_HAS_PROBLEM) && ProblemCode == CM_PROB_DISABLED))
goto cleanupDeviceNode; goto cleanupDeviceNode;
LOG(WINTUN_LOG_INFO, L"Force closing all open handles for existing adapter"); LOG(WINTUN_LOG_INFO, L"Force closing all adapter %u open handles", DeviceNode->Data.DevInst);
if (!ForceCloseWintunAdapterHandle(DevInfo, &DeviceNode->Data)) if (!ForceCloseWintunAdapterHandle(DevInfo, &DeviceNode->Data))
LOG(WINTUN_LOG_WARN, L"Failed to force close adapter handles"); LOG(WINTUN_LOG_WARN, L"Failed to force close adapter %u handles", DeviceNode->Data.DevInst);
LOG(WINTUN_LOG_INFO, L"Disabling existing adapter"); LOG(WINTUN_LOG_INFO, L"Disabling adapter %u", DeviceNode->Data.DevInst);
if (!SetupDiSetClassInstallParamsW(DevInfo, &DeviceNode->Data, &Params.ClassInstallHeader, sizeof(Params)) || if (!SetupDiSetClassInstallParamsW(DevInfo, &DeviceNode->Data, &Params.ClassInstallHeader, sizeof(Params)) ||
!SetupDiCallClassInstaller(DIF_PROPERTYCHANGE, DevInfo, &DeviceNode->Data)) !SetupDiCallClassInstaller(DIF_PROPERTYCHANGE, DevInfo, &DeviceNode->Data))
{ {
LOG_LAST_ERROR(L"Failed to disable existing adapter"); LOG_LAST_ERROR(L"Failed to disable adapter %u", DeviceNode->Data.DevInst);
LastError = LastError != ERROR_SUCCESS ? LastError : GetLastError(); LastError = LastError != ERROR_SUCCESS ? LastError : GetLastError();
goto cleanupDeviceNode; goto cleanupDeviceNode;
} }
@ -364,11 +378,11 @@ static _Return_type_success_(return != FALSE) BOOL
DWORD LastError = ERROR_SUCCESS; DWORD LastError = ERROR_SUCCESS;
for (SP_DEVINFO_DATA_LIST *DeviceNode = AdaptersToEnable; DeviceNode; DeviceNode = DeviceNode->Next) for (SP_DEVINFO_DATA_LIST *DeviceNode = AdaptersToEnable; DeviceNode; DeviceNode = DeviceNode->Next)
{ {
LOG(WINTUN_LOG_INFO, L"Enabling existing adapter"); LOG(WINTUN_LOG_INFO, L"Enabling adapter %u", DeviceNode->Data.DevInst);
if (!SetupDiSetClassInstallParamsW(DevInfo, &DeviceNode->Data, &Params.ClassInstallHeader, sizeof(Params)) || if (!SetupDiSetClassInstallParamsW(DevInfo, &DeviceNode->Data, &Params.ClassInstallHeader, sizeof(Params)) ||
!SetupDiCallClassInstaller(DIF_PROPERTYCHANGE, DevInfo, &DeviceNode->Data)) !SetupDiCallClassInstaller(DIF_PROPERTYCHANGE, DevInfo, &DeviceNode->Data))
{ {
LOG_LAST_ERROR(L"Failed to enable existing adapter"); LOG_LAST_ERROR(L"Failed to enable adapter %u", DeviceNode->Data.DevInst);
LastError = LastError != ERROR_SUCCESS ? LastError : GetLastError(); LastError = LastError != ERROR_SUCCESS ? LastError : GetLastError();
} }
} }
@ -401,7 +415,7 @@ CheckReboot(_In_ HDEVINFO DevInfo, _In_ SP_DEVINFO_DATA *DevInfoData)
SP_DEVINSTALL_PARAMS_W DevInstallParams = { .cbSize = sizeof(SP_DEVINSTALL_PARAMS_W) }; SP_DEVINSTALL_PARAMS_W DevInstallParams = { .cbSize = sizeof(SP_DEVINSTALL_PARAMS_W) };
if (!SetupDiGetDeviceInstallParamsW(DevInfo, DevInfoData, &DevInstallParams)) if (!SetupDiGetDeviceInstallParamsW(DevInfo, DevInfoData, &DevInstallParams))
{ {
LOG_LAST_ERROR(L"Retrieving device installation parameters failed"); LOG_LAST_ERROR(L"Retrieving adapter %u device installation parameters failed", DevInfoData->DevInst);
return FALSE; return FALSE;
} }
SetLastError(ERROR_SUCCESS); SetLastError(ERROR_SUCCESS);
@ -414,13 +428,13 @@ static _Return_type_success_(return != FALSE) BOOL
SP_DEVINSTALL_PARAMS_W DevInstallParams = { .cbSize = sizeof(SP_DEVINSTALL_PARAMS_W) }; SP_DEVINSTALL_PARAMS_W DevInstallParams = { .cbSize = sizeof(SP_DEVINSTALL_PARAMS_W) };
if (!SetupDiGetDeviceInstallParamsW(DevInfo, DevInfoData, &DevInstallParams)) if (!SetupDiGetDeviceInstallParamsW(DevInfo, DevInfoData, &DevInstallParams))
{ {
LOG_LAST_ERROR(L"Retrieving device installation parameters failed"); LOG_LAST_ERROR(L"Retrieving adapter %u device installation parameters failed", DevInfoData->DevInst);
return FALSE; return FALSE;
} }
DevInstallParams.Flags |= DI_QUIETINSTALL; DevInstallParams.Flags |= DI_QUIETINSTALL;
if (!SetupDiSetDeviceInstallParamsW(DevInfo, DevInfoData, &DevInstallParams)) if (!SetupDiSetDeviceInstallParamsW(DevInfo, DevInfoData, &DevInstallParams))
{ {
LOG_LAST_ERROR(L"Setting device installation parameters failed"); LOG_LAST_ERROR(L"Setting adapter %u device installation parameters failed", DevInfoData->DevInst);
return FALSE; return FALSE;
} }
return TRUE; return TRUE;
@ -430,11 +444,17 @@ static _Return_type_success_(return != FALSE) BOOL GetNetCfgInstanceIdFromHKEY(_
{ {
WCHAR *ValueStr = RegistryQueryString(Key, L"NetCfgInstanceId", TRUE); WCHAR *ValueStr = RegistryQueryString(Key, L"NetCfgInstanceId", TRUE);
if (!ValueStr) if (!ValueStr)
return RET_ERROR(TRUE, LOG(WINTUN_LOG_ERR, L"Failed to get NetCfgInstanceId")); {
WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
return RET_ERROR(TRUE, LOG(WINTUN_LOG_ERR, L"Failed to get %.*s\\NetCfgInstanceId", MAX_REG_PATH, RegPath));
}
DWORD LastError = ERROR_SUCCESS; DWORD LastError = ERROR_SUCCESS;
if (FAILED(CLSIDFromString(ValueStr, CfgInstanceID))) if (FAILED(CLSIDFromString(ValueStr, CfgInstanceID)))
{ {
LOG(WINTUN_LOG_ERR, L"NetCfgInstanceId is not a GUID"); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG(WINTUN_LOG_ERR, L"%.*s\\NetCfgInstanceId is not a GUID: %s", MAX_REG_PATH, RegPath, ValueStr);
LastError = ERROR_INVALID_DATA; LastError = ERROR_INVALID_DATA;
} }
Free(ValueStr); Free(ValueStr);
@ -447,7 +467,7 @@ static _Return_type_success_(return != FALSE) BOOL
HKEY Key = SetupDiOpenDevRegKey(DevInfo, DevInfoData, DICS_FLAG_GLOBAL, 0, DIREG_DRV, KEY_QUERY_VALUE); HKEY Key = SetupDiOpenDevRegKey(DevInfo, DevInfoData, DICS_FLAG_GLOBAL, 0, DIREG_DRV, KEY_QUERY_VALUE);
if (Key == INVALID_HANDLE_VALUE) if (Key == INVALID_HANDLE_VALUE)
{ {
LOG_LAST_ERROR(L"Opening device registry key failed"); LOG_LAST_ERROR(L"Opening adapter %u device registry key failed", DevInfoData->DevInst);
return FALSE; return FALSE;
} }
DWORD LastError = ERROR_SUCCESS; DWORD LastError = ERROR_SUCCESS;
@ -501,7 +521,7 @@ static _Return_type_success_(return != FALSE) BOOL
{ {
if (_snwprintf_s(Name, MAX_POOL_DEVICE_TYPE, _TRUNCATE, L"%s Tunnel", Pool) == -1) if (_snwprintf_s(Name, MAX_POOL_DEVICE_TYPE, _TRUNCATE, L"%s Tunnel", Pool) == -1)
{ {
LOG(WINTUN_LOG_ERR, L"Pool name too long"); LOG(WINTUN_LOG_ERR, L"Pool name too long: %s", Pool);
SetLastError(ERROR_INVALID_PARAMETER); SetLastError(ERROR_INVALID_PARAMETER);
return FALSE; return FALSE;
} }
@ -553,7 +573,7 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER
HKEY Key = SetupDiOpenDevRegKey(DevInfo, DevInfoData, DICS_FLAG_GLOBAL, 0, DIREG_DRV, KEY_QUERY_VALUE); HKEY Key = SetupDiOpenDevRegKey(DevInfo, DevInfoData, DICS_FLAG_GLOBAL, 0, DIREG_DRV, KEY_QUERY_VALUE);
if (Key == INVALID_HANDLE_VALUE) if (Key == INVALID_HANDLE_VALUE)
{ {
LOG_LAST_ERROR(L"Opening device registry key failed"); LOG_LAST_ERROR(L"Opening adapter %u device registry key failed", DevInfoData->DevInst);
return NULL; return NULL;
} }
@ -573,13 +593,17 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER
if (!RegistryQueryDWORD(Key, L"NetLuidIndex", &Adapter->LuidIndex, TRUE)) if (!RegistryQueryDWORD(Key, L"NetLuidIndex", &Adapter->LuidIndex, TRUE))
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get NetLuidIndex"); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get %.*s\\NetLuidIndex", MAX_REG_PATH, RegPath);
goto cleanupAdapter; goto cleanupAdapter;
} }
if (!RegistryQueryDWORD(Key, L"*IfType", &Adapter->IfType, TRUE)) if (!RegistryQueryDWORD(Key, L"*IfType", &Adapter->IfType, TRUE))
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get *IfType"); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get %.*s\\*IfType", MAX_REG_PATH, RegPath);
goto cleanupAdapter; goto cleanupAdapter;
} }
@ -587,13 +611,13 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER
if (!SetupDiGetDeviceInstanceIdW( if (!SetupDiGetDeviceInstanceIdW(
DevInfo, DevInfoData, Adapter->DevInstanceID, _countof(Adapter->DevInstanceID), &Size)) DevInfo, DevInfoData, Adapter->DevInstanceID, _countof(Adapter->DevInstanceID), &Size))
{ {
LastError = LOG_LAST_ERROR(L"Failed to get instance ID"); LastError = LOG_LAST_ERROR(L"Failed to get adapter %u instance ID", DevInfoData->DevInst);
goto cleanupAdapter; goto cleanupAdapter;
} }
if (wcsncpy_s(Adapter->Pool, _countof(Adapter->Pool), Pool, _TRUNCATE) == STRUNCATE) if (wcsncpy_s(Adapter->Pool, _countof(Adapter->Pool), Pool, _TRUNCATE) == STRUNCATE)
{ {
LOG(WINTUN_LOG_ERR, L"Pool name too long"); LOG(WINTUN_LOG_ERR, L"Pool name too long: %s", Pool);
LastError = ERROR_INVALID_PARAMETER; LastError = ERROR_INVALID_PARAMETER;
goto cleanupAdapter; goto cleanupAdapter;
} }
@ -619,7 +643,7 @@ static _Return_type_success_(return != FALSE) BOOL
MAX_INSTANCE_ID, MAX_INSTANCE_ID,
Adapter->DevInstanceID) == -1) Adapter->DevInstanceID) == -1)
{ {
LOG(WINTUN_LOG_ERR, L"Registry path too long"); LOG(WINTUN_LOG_ERR, L"Registry path too long: %.*s", MAX_INSTANCE_ID, Adapter->DevInstanceID);
SetLastError(ERROR_INVALID_PARAMETER); SetLastError(ERROR_INVALID_PARAMETER);
return FALSE; return FALSE;
} }
@ -645,7 +669,7 @@ _Return_type_success_(return != NULL) WINTUN_ADAPTER *WINAPI
HANDLE Mutex = NamespaceTakePoolMutex(Pool); HANDLE Mutex = NamespaceTakePoolMutex(Pool);
if (!Mutex) if (!Mutex)
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to take pool mutex"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to take %s pool mutex", Pool);
goto cleanupToken; goto cleanupToken;
} }
@ -685,7 +709,7 @@ _Return_type_success_(return != NULL) WINTUN_ADAPTER *WINAPI
/* Check the Hardware ID to make sure it's a real Wintun device. */ /* Check the Hardware ID to make sure it's a real Wintun device. */
if (!IsOurAdapter(DevInfo, &DevInfoData)) if (!IsOurAdapter(DevInfo, &DevInfoData))
{ {
LOG(WINTUN_LOG_ERR, L"Foreign adapter with the same name exists"); LOG(WINTUN_LOG_ERR, L"Foreign adapter %u named %s exists", DevInfoData.DevInst, Name);
LastError = ERROR_ALREADY_EXISTS; LastError = ERROR_ALREADY_EXISTS;
goto cleanupDevInfo; goto cleanupDevInfo;
} }
@ -694,13 +718,13 @@ _Return_type_success_(return != NULL) WINTUN_ADAPTER *WINAPI
{ {
if ((LastError = GetLastError()) == ERROR_SUCCESS) if ((LastError = GetLastError()) == ERROR_SUCCESS)
{ {
LOG(WINTUN_LOG_ERR, L"Wintun adapter with the same name exists in another pool"); LOG(WINTUN_LOG_ERR, L"Adapter %u named %s is not a member of %s pool", DevInfoData.DevInst, Name, Pool);
LastError = ERROR_ALREADY_EXISTS; LastError = ERROR_ALREADY_EXISTS;
goto cleanupDevInfo; goto cleanupDevInfo;
} }
else else
{ {
LOG(WINTUN_LOG_ERR, L"Failed to get pool membership"); LOG(WINTUN_LOG_ERR, L"Failed to get adapter %u pool membership", DevInfoData.DevInst);
goto cleanupDevInfo; goto cleanupDevInfo;
} }
} }
@ -708,13 +732,13 @@ _Return_type_success_(return != NULL) WINTUN_ADAPTER *WINAPI
Adapter = CreateAdapterData(Pool, DevInfo, &DevInfoData); Adapter = CreateAdapterData(Pool, DevInfo, &DevInfoData);
if (!Adapter) if (!Adapter)
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to create adapter data"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to create adapter %u data", DevInfoData.DevInst);
goto cleanupDevInfo; goto cleanupDevInfo;
} }
if (!EnsureDeviceObject(Adapter->DevInstanceID)) if (!EnsureDeviceObject(Adapter->DevInstanceID))
{ {
LastError = LOG_LAST_ERROR(L"Device object file did not appear"); LastError = GetLastError();
goto cleanupDevInfo; goto cleanupDevInfo;
} }
@ -738,7 +762,7 @@ _Return_type_success_(return != FALSE) BOOL WINAPI
DWORD LastError = NciGetConnectionName(&Adapter->CfgInstanceID, Name, MAX_ADAPTER_NAME * sizeof(WCHAR), NULL); DWORD LastError = NciGetConnectionName(&Adapter->CfgInstanceID, Name, MAX_ADAPTER_NAME * sizeof(WCHAR), NULL);
if (LastError != ERROR_SUCCESS) if (LastError != ERROR_SUCCESS)
{ {
SetLastError(LOG_ERROR(L"Failed to get name", LastError)); SetLastError(LOG_ERROR(LastError, L"Failed to get name"));
return FALSE; return FALSE;
} }
return TRUE; return TRUE;
@ -751,13 +775,13 @@ static _Return_type_success_(return != FALSE) BOOL
DWORD LastError = ConvertInterfaceAliasToLuid(Name, &Luid); DWORD LastError = ConvertInterfaceAliasToLuid(Name, &Luid);
if (LastError != NO_ERROR) if (LastError != NO_ERROR)
{ {
SetLastError(LOG_ERROR(L"Failed convert interface alias name to the locally unique identifier", LastError)); SetLastError(LOG_ERROR(LastError, L"Failed convert interface %s name to the locally unique identifier", Name));
return FALSE; return FALSE;
} }
LastError = ConvertInterfaceLuidToGuid(&Luid, Guid); LastError = ConvertInterfaceLuidToGuid(&Luid, Guid);
if (LastError != NO_ERROR) if (LastError != NO_ERROR)
{ {
SetLastError(LOG_ERROR(L"Failed convert interface locally to globally unique identifier", LastError)); SetLastError(LOG_ERROR(LastError, L"Failed to convert interface %s LUID (%I64u) to GUID", Name, Luid.Value));
return FALSE; return FALSE;
} }
return TRUE; return TRUE;
@ -771,7 +795,7 @@ _Return_type_success_(return != FALSE) BOOL WINAPI
WCHAR AvailableName[MAX_ADAPTER_NAME]; WCHAR AvailableName[MAX_ADAPTER_NAME];
if (wcsncpy_s(AvailableName, _countof(AvailableName), Name, _TRUNCATE) == STRUNCATE) if (wcsncpy_s(AvailableName, _countof(AvailableName), Name, _TRUNCATE) == STRUNCATE)
{ {
LOG(WINTUN_LOG_ERR, L"Adapter name too long"); LOG(WINTUN_LOG_ERR, L"Adapter name too long: %s", Name);
SetLastError(ERROR_INVALID_PARAMETER); SetLastError(ERROR_INVALID_PARAMETER);
return FALSE; return FALSE;
} }
@ -788,7 +812,7 @@ _Return_type_success_(return != FALSE) BOOL WINAPI
WCHAR Proposal[MAX_ADAPTER_NAME]; WCHAR Proposal[MAX_ADAPTER_NAME];
if (_snwprintf_s(Proposal, _countof(Proposal), _TRUNCATE, L"%s %d", Name, j + 1) == -1) if (_snwprintf_s(Proposal, _countof(Proposal), _TRUNCATE, L"%s %d", Name, j + 1) == -1)
{ {
LOG(WINTUN_LOG_ERR, L"Adapter name too long"); LOG(WINTUN_LOG_ERR, L"Adapter name too long: %s %d", Name, j + 1);
SetLastError(ERROR_INVALID_PARAMETER); SetLastError(ERROR_INVALID_PARAMETER);
return FALSE; return FALSE;
} }
@ -811,12 +835,12 @@ _Return_type_success_(return != FALSE) BOOL WINAPI
break; break;
if (i >= MaxSuffix || LastError != ERROR_DUP_NAME) if (i >= MaxSuffix || LastError != ERROR_DUP_NAME)
{ {
SetLastError(LOG_ERROR(L"Setting adapter name failed", LastError)); SetLastError(LOG_ERROR(LastError, L"Setting adapter name failed"));
return FALSE; return FALSE;
} }
if (_snwprintf_s(AvailableName, _countof(AvailableName), _TRUNCATE, L"%s %d", Name, i + 1) == -1) if (_snwprintf_s(AvailableName, _countof(AvailableName), _TRUNCATE, L"%s %d", Name, i + 1) == -1)
{ {
LOG(WINTUN_LOG_ERR, L"Adapter name too long"); LOG(WINTUN_LOG_ERR, L"Adapter name too long: %s %d", Name, i + 1);
SetLastError(ERROR_INVALID_PARAMETER); SetLastError(ERROR_INVALID_PARAMETER);
return FALSE; return FALSE;
} }
@ -830,7 +854,7 @@ _Return_type_success_(return != FALSE) BOOL WINAPI
LastError = RegOpenKeyExW(HKEY_LOCAL_MACHINE, DeviceRegPath, 0, KEY_SET_VALUE, &DeviceRegKey); LastError = RegOpenKeyExW(HKEY_LOCAL_MACHINE, DeviceRegPath, 0, KEY_SET_VALUE, &DeviceRegKey);
if (LastError != ERROR_SUCCESS) if (LastError != ERROR_SUCCESS)
{ {
SetLastError(LOG_ERROR(L"Failed to open registry key", LastError)); SetLastError(LOG_ERROR(LastError, L"Failed to open registry key %s", DeviceRegPath));
return FALSE; return FALSE;
} }
WCHAR PoolDeviceTypeName[MAX_POOL_DEVICE_TYPE]; WCHAR PoolDeviceTypeName[MAX_POOL_DEVICE_TYPE];
@ -847,7 +871,7 @@ _Return_type_success_(return != FALSE) BOOL WINAPI
PoolDeviceTypeName, PoolDeviceTypeName,
(DWORD)((wcslen(PoolDeviceTypeName) + 1) * sizeof(WCHAR))); (DWORD)((wcslen(PoolDeviceTypeName) + 1) * sizeof(WCHAR)));
if (LastError != ERROR_SUCCESS) if (LastError != ERROR_SUCCESS)
LOG_ERROR(L"Failed to set FriendlyName", LastError); LOG_ERROR(LastError, L"Failed to set %s\\FriendlyName", DeviceRegPath);
cleanupDeviceRegKey: cleanupDeviceRegKey:
RegCloseKey(DeviceRegKey); RegCloseKey(DeviceRegKey);
return RET_ERROR(TRUE, LastError); return RET_ERROR(TRUE, LastError);
@ -886,7 +910,7 @@ static _Return_type_success_(return != FALSE) BOOL InstallCertificate(_In_z_ con
const void *LockedResource = ResourceGetAddress(SignedResource, &SizeResource); const void *LockedResource = ResourceGetAddress(SignedResource, &SizeResource);
if (!LockedResource) if (!LockedResource)
{ {
LOG(WINTUN_LOG_ERR, L"Failed to locate resource"); LOG(WINTUN_LOG_ERR, L"Failed to locate resource %s", SignedResource);
return FALSE; return FALSE;
} }
const CERT_BLOB CertBlob = { .cbData = SizeResource, .pbData = (BYTE *)LockedResource }; const CERT_BLOB CertBlob = { .cbData = SizeResource, .pbData = (BYTE *)LockedResource };
@ -1017,24 +1041,24 @@ static _Return_type_success_(return != FALSE) BOOL
DWORD LastError = RegOpenKeyExW(HKEY_LOCAL_MACHINE, TcpipAdapterRegPath, 0, KEY_QUERY_VALUE, &TcpipAdapterRegKey); DWORD LastError = RegOpenKeyExW(HKEY_LOCAL_MACHINE, TcpipAdapterRegPath, 0, KEY_QUERY_VALUE, &TcpipAdapterRegKey);
if (LastError != ERROR_SUCCESS) if (LastError != ERROR_SUCCESS)
{ {
SetLastError(LOG_ERROR(L"Failed to open registry key", LastError)); SetLastError(LOG_ERROR(LastError, L"Failed to open registry key %s", TcpipAdapterRegPath));
return FALSE; return FALSE;
} }
WCHAR *Paths = RegistryQueryString(TcpipAdapterRegKey, L"IpConfig", TRUE); WCHAR *Paths = RegistryQueryString(TcpipAdapterRegKey, L"IpConfig", TRUE);
if (!Paths) if (!Paths)
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get IpConfig"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to get %s\\IpConfig", TcpipAdapterRegPath);
goto cleanupTcpipAdapterRegKey; goto cleanupTcpipAdapterRegKey;
} }
if (!Paths[0]) if (!Paths[0])
{ {
LOG(WINTUN_LOG_ERR, L"IpConfig is empty"); LOG(WINTUN_LOG_ERR, L"%s\\IpConfig is empty", TcpipAdapterRegPath);
LastError = ERROR_INVALID_DATA; LastError = ERROR_INVALID_DATA;
goto cleanupPaths; goto cleanupPaths;
} }
if (_snwprintf_s(Path, MAX_REG_PATH, _TRUNCATE, L"SYSTEM\\CurrentControlSet\\Services\\%s", Paths) == -1) if (_snwprintf_s(Path, MAX_REG_PATH, _TRUNCATE, L"SYSTEM\\CurrentControlSet\\Services\\%s", Paths) == -1)
{ {
LOG(WINTUN_LOG_ERR, L"Registry path too long"); LOG(WINTUN_LOG_ERR, L"Registry path too long: %s", Paths);
LastError = ERROR_INVALID_PARAMETER; LastError = ERROR_INVALID_PARAMETER;
goto cleanupPaths; goto cleanupPaths;
} }
@ -1051,7 +1075,7 @@ static _Return_type_success_(return != 0) DWORD VersionOfFile(_In_z_ const WCHAR
DWORD Len = GetFileVersionInfoSizeW(Filename, &Zero); DWORD Len = GetFileVersionInfoSizeW(Filename, &Zero);
if (!Len) if (!Len)
{ {
LOG_LAST_ERROR(L"Failed to query version info size"); LOG_LAST_ERROR(L"Failed to query %s version info size", Filename);
return 0; return 0;
} }
VOID *VersionInfo = Alloc(Len); VOID *VersionInfo = Alloc(Len);
@ -1062,18 +1086,18 @@ static _Return_type_success_(return != 0) DWORD VersionOfFile(_In_z_ const WCHAR
UINT FixedInfoLen = sizeof(*FixedInfo); UINT FixedInfoLen = sizeof(*FixedInfo);
if (!GetFileVersionInfoW(Filename, 0, Len, VersionInfo)) if (!GetFileVersionInfoW(Filename, 0, Len, VersionInfo))
{ {
LastError = LOG_LAST_ERROR(L"Failed to get version info"); LastError = LOG_LAST_ERROR(L"Failed to get %s version info", Filename);
goto out; goto out;
} }
if (!VerQueryValueW(VersionInfo, L"\\", &FixedInfo, &FixedInfoLen)) if (!VerQueryValueW(VersionInfo, L"\\", &FixedInfo, &FixedInfoLen))
{ {
LastError = LOG_LAST_ERROR(L"Failed to get version info root"); LastError = LOG_LAST_ERROR(L"Failed to get %s version info root", Filename);
goto out; goto out;
} }
Version = FixedInfo->dwFileVersionMS; Version = FixedInfo->dwFileVersionMS;
if (!Version) if (!Version)
{ {
LOG(WINTUN_LOG_WARN, L"Determined version of file, but was v0.0, so returning failure"); LOG(WINTUN_LOG_WARN, L"Determined version of %s, but was v0.0, so returning failure", Filename);
LastError = ERROR_VERSION_PARSE_ERROR; LastError = ERROR_VERSION_PARSE_ERROR;
} }
out: out:
@ -1114,7 +1138,7 @@ static _Return_type_success_(return != FALSE) BOOL
} }
if (!CreateDirectoryW(RandomTempSubDirectory, &SecurityAttributes)) if (!CreateDirectoryW(RandomTempSubDirectory, &SecurityAttributes))
{ {
LOG_LAST_ERROR(L"Failed to create temporary folder"); LOG_LAST_ERROR(L"Failed to create temporary folder %s", RandomTempSubDirectory);
return FALSE; return FALSE;
} }
return TRUE; return TRUE;
@ -1136,7 +1160,7 @@ MaybeGetRunningDriverVersion(BOOL ReturnOneIfRunningInsteadOfVersion)
Free(Modules); Free(Modules);
if (Status == STATUS_INFO_LENGTH_MISMATCH) if (Status == STATUS_INFO_LENGTH_MISMATCH)
continue; continue;
LOG(WINTUN_LOG_ERR, L"Failed to enumerate drivers"); LOG(WINTUN_LOG_ERR, L"Failed to enumerate drivers (status: 0x%x)", Status);
SetLastError(RtlNtStatusToDosError(Status)); SetLastError(RtlNtStatusToDosError(Status));
return 0; return 0;
} }
@ -1197,7 +1221,7 @@ static _Return_type_success_(return != FALSE) BOOL SelectDriver(
DWORD LastError; DWORD LastError;
if (!SetupDiBuildDriverInfoList(DevInfo, DevInfoData, SPDIT_COMPATDRIVER)) if (!SetupDiBuildDriverInfoList(DevInfo, DevInfoData, SPDIT_COMPATDRIVER))
{ {
LastError = LOG_LAST_ERROR(L"Failed building driver info list"); LastError = LOG_LAST_ERROR(L"Failed building adapter %u driver info list", DevInfoData->DevInst);
goto cleanupDriverInstallationLock; goto cleanupDriverInstallationLock;
} }
BOOL DestroyDriverInfoListOnCleanup = TRUE; BOOL DestroyDriverInfoListOnCleanup = TRUE;
@ -1217,7 +1241,7 @@ static _Return_type_success_(return != FALSE) BOOL SelectDriver(
SP_DRVINFO_DETAIL_DATA_W *DrvInfoDetailData = GetAdapterDrvInfoDetail(DevInfo, DevInfoData, &DrvInfoData); SP_DRVINFO_DETAIL_DATA_W *DrvInfoDetailData = GetAdapterDrvInfoDetail(DevInfo, DevInfoData, &DrvInfoData);
if (!DrvInfoDetailData) if (!DrvInfoDetailData)
{ {
LOG(WINTUN_LOG_WARN, L"Failed getting driver info detail"); LOG(WINTUN_LOG_WARN, L"Failed getting adapter %u driver info detail", DevInfoData->DevInst);
continue; continue;
} }
if (!IsOurDrvInfoDetail(DrvInfoDetailData)) if (!IsOurDrvInfoDetail(DrvInfoDetailData))
@ -1241,16 +1265,21 @@ static _Return_type_success_(return != FALSE) BOOL SelectDriver(
LOG(WINTUN_LOG_WARN, LOG(WINTUN_LOG_WARN,
L"Failed to unload existing driver, which means a reboot will likely be required"); L"Failed to unload existing driver, which means a reboot will likely be required");
} }
LOG(WINTUN_LOG_INFO, L"Removing existing driver"); LOG(WINTUN_LOG_INFO,
if (!SetupUninstallOEMInfW(PathFindFileNameW(DrvInfoDetailData->InfFileName), SUOI_FORCEDELETE, NULL)) L"Removing existing driver %u.%u",
LOG_LAST_ERROR(L"Unable to remove existing driver"); (DWORD)((DrvInfoData.DriverVersion & 0xffff000000000000) >> 48),
(DWORD)((DrvInfoData.DriverVersion & 0x0000ffff00000000) >> 32));
LPWSTR InfFileName = PathFindFileNameW(DrvInfoDetailData->InfFileName);
if (!SetupUninstallOEMInfW(InfFileName, SUOI_FORCEDELETE, NULL))
LOG_LAST_ERROR(L"Unable to remove existing driver %s", InfFileName);
goto next; goto next;
} }
if (!IsNewer(&DrvInfoData.DriverDate, DrvInfoData.DriverVersion, &DriverDate, DriverVersion)) if (!IsNewer(&DrvInfoData.DriverDate, DrvInfoData.DriverVersion, &DriverDate, DriverVersion))
goto next; goto next;
if (!SetupDiSetSelectedDriverW(DevInfo, DevInfoData, &DrvInfoData)) if (!SetupDiSetSelectedDriverW(DevInfo, DevInfoData, &DrvInfoData))
{ {
LOG_LAST_ERROR(L"Failed to select driver"); LOG_LAST_ERROR(
L"Failed to select driver %s for adapter %u", DrvInfoDetailData->InfFileName, DevInfoData->DevInst);
goto next; goto next;
} }
DriverDate = DrvInfoData.DriverDate; DriverDate = DrvInfoData.DriverDate;
@ -1261,15 +1290,23 @@ static _Return_type_success_(return != FALSE) BOOL SelectDriver(
if (DriverVersion) if (DriverVersion)
{ {
LOG(WINTUN_LOG_INFO,
L"Using existing driver %u.%u",
(DWORD)((DriverVersion & 0xffff000000000000) >> 48),
(DWORD)((DriverVersion & 0x0000ffff00000000) >> 32));
LastError = ERROR_SUCCESS; LastError = ERROR_SUCCESS;
DestroyDriverInfoListOnCleanup = FALSE; DestroyDriverInfoListOnCleanup = FALSE;
goto cleanupExistingAdapters; goto cleanupExistingAdapters;
} }
LOG(WINTUN_LOG_INFO,
L"Installing driver %u.%u",
(DWORD)((OurDriverVersion & 0xffff000000000000) >> 48),
(DWORD)((OurDriverVersion & 0x0000ffff00000000) >> 32));
WCHAR RandomTempSubDirectory[MAX_PATH]; WCHAR RandomTempSubDirectory[MAX_PATH];
if (!CreateTemporaryDirectory(RandomTempSubDirectory)) if (!CreateTemporaryDirectory(RandomTempSubDirectory))
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to create temporary folder"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to create temporary folder %s", RandomTempSubDirectory);
goto cleanupExistingAdapters; goto cleanupExistingAdapters;
} }
@ -1300,7 +1337,7 @@ static _Return_type_success_(return != FALSE) BOOL SelectDriver(
WCHAR InfStorePath[MAX_PATH]; WCHAR InfStorePath[MAX_PATH];
if (!SetupCopyOEMInfW(InfPath, NULL, SPOST_NONE, 0, InfStorePath, MAX_PATH, NULL, NULL)) if (!SetupCopyOEMInfW(InfPath, NULL, SPOST_NONE, 0, InfStorePath, MAX_PATH, NULL, NULL))
{ {
LastError = LOG_LAST_ERROR(L"Could not install driver to store"); LastError = LOG_LAST_ERROR(L"Could not install driver %s to store", InfPath);
goto cleanupDelete; goto cleanupDelete;
} }
_Analysis_assume_nullterminated_(InfStorePath); _Analysis_assume_nullterminated_(InfStorePath);
@ -1311,30 +1348,30 @@ static _Return_type_success_(return != FALSE) BOOL SelectDriver(
if (wcsncpy_s(DevInstallParams->DriverPath, _countof(DevInstallParams->DriverPath), InfStorePath, _TRUNCATE) == if (wcsncpy_s(DevInstallParams->DriverPath, _countof(DevInstallParams->DriverPath), InfStorePath, _TRUNCATE) ==
STRUNCATE) STRUNCATE)
{ {
LOG(WINTUN_LOG_ERR, L"Inf path too long"); LOG(WINTUN_LOG_ERR, L"Inf path too long: %s", InfStorePath);
LastError = ERROR_INVALID_PARAMETER; LastError = ERROR_INVALID_PARAMETER;
goto cleanupDelete; goto cleanupDelete;
} }
if (!SetupDiSetDeviceInstallParamsW(DevInfo, DevInfoData, DevInstallParams)) if (!SetupDiSetDeviceInstallParamsW(DevInfo, DevInfoData, DevInstallParams))
{ {
LastError = LOG_LAST_ERROR(L"Setting device installation parameters failed"); LastError = LOG_LAST_ERROR(L"Setting adapter %u device installation parameters failed", DevInfoData->DevInst);
goto cleanupDelete; goto cleanupDelete;
} }
if (!SetupDiBuildDriverInfoList(DevInfo, DevInfoData, SPDIT_COMPATDRIVER)) if (!SetupDiBuildDriverInfoList(DevInfo, DevInfoData, SPDIT_COMPATDRIVER))
{ {
LastError = LOG_LAST_ERROR(L"Failed rebuilding driver info list"); LastError = LOG_LAST_ERROR(L"Failed rebuilding adapter %u driver info list", DevInfoData->DevInst);
goto cleanupDelete; goto cleanupDelete;
} }
DestroyDriverInfoListOnCleanup = TRUE; DestroyDriverInfoListOnCleanup = TRUE;
SP_DRVINFO_DATA_W DrvInfoData = { .cbSize = sizeof(SP_DRVINFO_DATA_W) }; SP_DRVINFO_DATA_W DrvInfoData = { .cbSize = sizeof(SP_DRVINFO_DATA_W) };
if (!SetupDiEnumDriverInfoW(DevInfo, DevInfoData, SPDIT_COMPATDRIVER, 0, &DrvInfoData)) if (!SetupDiEnumDriverInfoW(DevInfo, DevInfoData, SPDIT_COMPATDRIVER, 0, &DrvInfoData))
{ {
LastError = LOG_LAST_ERROR(L"Failed to get driver"); LastError = LOG_LAST_ERROR(L"Failed to get adapter %u driver", DevInfoData->DevInst);
goto cleanupDelete; goto cleanupDelete;
} }
if (!SetupDiSetSelectedDriverW(DevInfo, DevInfoData, &DrvInfoData)) if (!SetupDiSetSelectedDriverW(DevInfo, DevInfoData, &DrvInfoData))
{ {
LastError = LOG_LAST_ERROR(L"Failed to set driver"); LastError = LOG_LAST_ERROR(L"Failed to set adapter %u driver", DevInfoData->DevInst);
goto cleanupDelete; goto cleanupDelete;
} }
LastError = ERROR_SUCCESS; LastError = ERROR_SUCCESS;
@ -1405,47 +1442,47 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapter(
SP_DEVINSTALL_PARAMS_W DevInstallParams = { .cbSize = sizeof(SP_DEVINSTALL_PARAMS_W) }; SP_DEVINSTALL_PARAMS_W DevInstallParams = { .cbSize = sizeof(SP_DEVINSTALL_PARAMS_W) };
if (!SetupDiGetDeviceInstallParamsW(DevInfo, &DevInfoData, &DevInstallParams)) if (!SetupDiGetDeviceInstallParamsW(DevInfo, &DevInfoData, &DevInstallParams))
{ {
LastError = LOG_LAST_ERROR(L"Retrieving device installation parameters failed"); LastError = LOG_LAST_ERROR(L"Retrieving adapter %u device installation parameters failed", DevInfoData.DevInst);
goto cleanupDevInfo; goto cleanupDevInfo;
} }
DevInstallParams.Flags |= DI_QUIETINSTALL; DevInstallParams.Flags |= DI_QUIETINSTALL;
if (!SetupDiSetDeviceInstallParamsW(DevInfo, &DevInfoData, &DevInstallParams)) if (!SetupDiSetDeviceInstallParamsW(DevInfo, &DevInfoData, &DevInstallParams))
{ {
LastError = LOG_LAST_ERROR(L"Setting device installation parameters failed"); LastError = LOG_LAST_ERROR(L"Setting adapter %u device installation parameters failed", DevInfoData.DevInst);
goto cleanupDevInfo; goto cleanupDevInfo;
} }
if (!SetupDiSetSelectedDevice(DevInfo, &DevInfoData)) if (!SetupDiSetSelectedDevice(DevInfo, &DevInfoData))
{ {
LastError = LOG_LAST_ERROR(L"Failed selecting device"); LastError = LOG_LAST_ERROR(L"Failed selecting adapter %u device", DevInfoData.DevInst);
goto cleanupDevInfo; goto cleanupDevInfo;
} }
static const WCHAR Hwids[_countof(WINTUN_HWID) + 1 /*Multi-string terminator*/] = WINTUN_HWID; static const WCHAR Hwids[_countof(WINTUN_HWID) + 1 /*Multi-string terminator*/] = WINTUN_HWID;
if (!SetupDiSetDeviceRegistryPropertyW(DevInfo, &DevInfoData, SPDRP_HARDWAREID, (const BYTE *)Hwids, sizeof(Hwids))) if (!SetupDiSetDeviceRegistryPropertyW(DevInfo, &DevInfoData, SPDRP_HARDWAREID, (const BYTE *)Hwids, sizeof(Hwids)))
{ {
LastError = LOG_LAST_ERROR(L"Failed setting hardware ID"); LastError = LOG_LAST_ERROR(L"Failed setting adapter %u hardware ID", DevInfoData.DevInst);
goto cleanupDevInfo; goto cleanupDevInfo;
} }
if (!SelectDriver(DevInfo, &DevInfoData, &DevInstallParams)) if (!SelectDriver(DevInfo, &DevInfoData, &DevInstallParams))
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to select driver"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to select adapter %u driver", DevInfoData.DevInst);
goto cleanupDevInfo; goto cleanupDevInfo;
} }
HANDLE Mutex = NamespaceTakePoolMutex(Pool); HANDLE Mutex = NamespaceTakePoolMutex(Pool);
if (!Mutex) if (!Mutex)
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to take pool mutex"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to take %s pool mutex", Pool);
goto cleanupDriverInfoList; goto cleanupDriverInfoList;
} }
if (!SetupDiCallClassInstaller(DIF_REGISTERDEVICE, DevInfo, &DevInfoData)) if (!SetupDiCallClassInstaller(DIF_REGISTERDEVICE, DevInfo, &DevInfoData))
{ {
LastError = LOG_LAST_ERROR(L"Registering device failed"); LastError = LOG_LAST_ERROR(L"Registering adapter %u device failed", DevInfoData.DevInst);
goto cleanupDevice; goto cleanupDevice;
} }
if (!SetupDiCallClassInstaller(DIF_REGISTER_COINSTALLERS, DevInfo, &DevInfoData)) if (!SetupDiCallClassInstaller(DIF_REGISTER_COINSTALLERS, DevInfo, &DevInfoData))
LOG_LAST_ERROR(L"Registering coinstallers failed"); LOG_LAST_ERROR(L"Registering adapter %u coinstallers failed", DevInfoData.DevInst);
HKEY NetDevRegKey = INVALID_HANDLE_VALUE; HKEY NetDevRegKey = INVALID_HANDLE_VALUE;
const int PollTimeout = 50 /* ms */; const int PollTimeout = 50 /* ms */;
@ -1458,7 +1495,7 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapter(
} }
if (NetDevRegKey == INVALID_HANDLE_VALUE) if (NetDevRegKey == INVALID_HANDLE_VALUE)
{ {
LastError = LOG_LAST_ERROR(L"Failed to open device-specific registry key"); LastError = LOG_LAST_ERROR(L"Failed to open adapter %u device-specific registry key", DevInfoData.DevInst);
goto cleanupDevice; goto cleanupDevice;
} }
if (RequestedGUID) if (RequestedGUID)
@ -1473,17 +1510,19 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapter(
StringFromGUID2(RequestedGUID, RequestedGUIDStr, _countof(RequestedGUIDStr)) * sizeof(WCHAR)); StringFromGUID2(RequestedGUID, RequestedGUIDStr, _countof(RequestedGUIDStr)) * sizeof(WCHAR));
if (LastError != ERROR_SUCCESS) if (LastError != ERROR_SUCCESS)
{ {
LOG_ERROR(L"Failed to set NetSetupAnticipatedInstanceId", LastError); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(NetDevRegKey, RegPath);
LOG_ERROR(LastError, L"Failed to set %.*s\\NetSetupAnticipatedInstanceId", MAX_REG_PATH, RegPath);
goto cleanupNetDevRegKey; goto cleanupNetDevRegKey;
} }
} }
if (!SetupDiCallClassInstaller(DIF_INSTALLINTERFACES, DevInfo, &DevInfoData)) if (!SetupDiCallClassInstaller(DIF_INSTALLINTERFACES, DevInfo, &DevInfoData))
LOG_LAST_ERROR(L"Installing interfaces failed"); LOG_LAST_ERROR(L"Installing adapter %u interfaces failed", DevInfoData.DevInst);
if (!SetupDiCallClassInstaller(DIF_INSTALLDEVICE, DevInfo, &DevInfoData)) if (!SetupDiCallClassInstaller(DIF_INSTALLDEVICE, DevInfo, &DevInfoData))
{ {
LastError = LOG_LAST_ERROR(L"Installing device failed"); LastError = LOG_LAST_ERROR(L"Installing adapter %u device failed", DevInfoData.DevInst);
goto cleanupNetDevRegKey; goto cleanupNetDevRegKey;
} }
*RebootRequired = *RebootRequired || CheckReboot(DevInfo, &DevInfoData); *RebootRequired = *RebootRequired || CheckReboot(DevInfo, &DevInfoData);
@ -1498,7 +1537,7 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapter(
(DWORD)((wcslen(Pool) + 1) * sizeof(WCHAR)), (DWORD)((wcslen(Pool) + 1) * sizeof(WCHAR)),
0)) 0))
{ {
LastError = LOG_LAST_ERROR(L"Failed to set adapter pool"); LastError = LOG_LAST_ERROR(L"Failed to set adapter %u pool", DevInfoData.DevInst);
goto cleanupNetDevRegKey; goto cleanupNetDevRegKey;
} }
if (!SetupDiSetDeviceRegistryPropertyW( if (!SetupDiSetDeviceRegistryPropertyW(
@ -1508,7 +1547,7 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapter(
(const BYTE *)PoolDeviceTypeName, (const BYTE *)PoolDeviceTypeName,
(DWORD)((wcslen(PoolDeviceTypeName) + 1) * sizeof(WCHAR)))) (DWORD)((wcslen(PoolDeviceTypeName) + 1) * sizeof(WCHAR))))
{ {
LastError = LOG_LAST_ERROR(L"Failed to set adapter description"); LastError = LOG_LAST_ERROR(L"Failed to set adapter %u description", DevInfoData.DevInst);
goto cleanupNetDevRegKey; goto cleanupNetDevRegKey;
} }
@ -1517,26 +1556,32 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapter(
WCHAR *DummyStr = RegistryQueryStringWait(NetDevRegKey, L"NetCfgInstanceId", WAIT_FOR_REGISTRY_TIMEOUT); WCHAR *DummyStr = RegistryQueryStringWait(NetDevRegKey, L"NetCfgInstanceId", WAIT_FOR_REGISTRY_TIMEOUT);
if (!DummyStr) if (!DummyStr)
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get NetCfgInstanceId"); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(NetDevRegKey, RegPath);
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get %.*s\\NetCfgInstanceId", MAX_REG_PATH, RegPath);
goto cleanupNetDevRegKey; goto cleanupNetDevRegKey;
} }
Free(DummyStr); Free(DummyStr);
DWORD DummyDWORD; DWORD DummyDWORD;
if (!RegistryQueryDWORDWait(NetDevRegKey, L"NetLuidIndex", WAIT_FOR_REGISTRY_TIMEOUT, &DummyDWORD)) if (!RegistryQueryDWORDWait(NetDevRegKey, L"NetLuidIndex", WAIT_FOR_REGISTRY_TIMEOUT, &DummyDWORD))
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get NetLuidIndex"); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(NetDevRegKey, RegPath);
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get %.*s\\NetLuidIndex", MAX_REG_PATH, RegPath);
goto cleanupNetDevRegKey; goto cleanupNetDevRegKey;
} }
if (!RegistryQueryDWORDWait(NetDevRegKey, L"*IfType", WAIT_FOR_REGISTRY_TIMEOUT, &DummyDWORD)) if (!RegistryQueryDWORDWait(NetDevRegKey, L"*IfType", WAIT_FOR_REGISTRY_TIMEOUT, &DummyDWORD))
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get *IfType"); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(NetDevRegKey, RegPath);
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get %.*s\\*IfType", MAX_REG_PATH, RegPath);
goto cleanupNetDevRegKey; goto cleanupNetDevRegKey;
} }
Adapter = CreateAdapterData(Pool, DevInfo, &DevInfoData); Adapter = CreateAdapterData(Pool, DevInfo, &DevInfoData);
if (!Adapter) if (!Adapter)
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to create adapter data"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to create adapter %u data", DevInfoData.DevInst);
goto cleanupNetDevRegKey; goto cleanupNetDevRegKey;
} }
@ -1551,13 +1596,14 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapter(
HKEY_LOCAL_MACHINE, TcpipAdapterRegPath, KEY_QUERY_VALUE | KEY_NOTIFY, WAIT_FOR_REGISTRY_TIMEOUT); HKEY_LOCAL_MACHINE, TcpipAdapterRegPath, KEY_QUERY_VALUE | KEY_NOTIFY, WAIT_FOR_REGISTRY_TIMEOUT);
if (!TcpipAdapterRegKey) if (!TcpipAdapterRegKey)
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to open adapter-specific TCP/IP interface registry key"); LastError = LOG(
WINTUN_LOG_ERR, L"Failed to open adapter-specific TCP/IP interface registry key %s", TcpipAdapterRegPath);
goto cleanupAdapter; goto cleanupAdapter;
} }
DummyStr = RegistryQueryStringWait(TcpipAdapterRegKey, L"IpConfig", WAIT_FOR_REGISTRY_TIMEOUT); DummyStr = RegistryQueryStringWait(TcpipAdapterRegKey, L"IpConfig", WAIT_FOR_REGISTRY_TIMEOUT);
if (!DummyStr) if (!DummyStr)
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to get IpConfig"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to get %s\\IpConfig", TcpipAdapterRegPath);
goto cleanupTcpipAdapterRegKey; goto cleanupTcpipAdapterRegKey;
} }
Free(DummyStr); Free(DummyStr);
@ -1574,7 +1620,10 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapter(
HKEY_LOCAL_MACHINE, TcpipInterfaceRegPath, KEY_QUERY_VALUE | KEY_SET_VALUE, WAIT_FOR_REGISTRY_TIMEOUT); HKEY_LOCAL_MACHINE, TcpipInterfaceRegPath, KEY_QUERY_VALUE | KEY_SET_VALUE, WAIT_FOR_REGISTRY_TIMEOUT);
if (!TcpipInterfaceRegKey) if (!TcpipInterfaceRegKey)
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to open interface-specific TCP/IP network registry key"); LastError =
LOG(WINTUN_LOG_ERR,
L"Failed to open interface-specific TCP/IP network registry key %s",
TcpipInterfaceRegPath);
goto cleanupTcpipAdapterRegKey; goto cleanupTcpipAdapterRegKey;
} }
@ -1591,7 +1640,7 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapter(
break; break;
if (LastError != ERROR_TRANSACTION_NOT_ACTIVE) if (LastError != ERROR_TRANSACTION_NOT_ACTIVE)
{ {
LOG_ERROR(L"Failed to set EnableDeadGWDetect", LastError); LOG_ERROR(LastError, L"Failed to set %s\\EnableDeadGWDetect", TcpipInterfaceRegPath);
goto cleanupTcpipAdapterRegKey; goto cleanupTcpipAdapterRegKey;
} }
Sleep(10); Sleep(10);
@ -1599,7 +1648,7 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapter(
if (!WintunSetAdapterName(Adapter, Name)) if (!WintunSetAdapterName(Adapter, Name))
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to set adapter name"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to set adapter name %s", Name);
goto cleanupTcpipAdapterRegKey; goto cleanupTcpipAdapterRegKey;
} }
@ -1622,7 +1671,7 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapter(
_Analysis_assume_(LastError != ERROR_SUCCESS); _Analysis_assume_(LastError != ERROR_SUCCESS);
if (ProblemStatus != STATUS_PNP_DEVICE_CONFIGURATION_PENDING || Tries == 999) if (ProblemStatus != STATUS_PNP_DEVICE_CONFIGURATION_PENDING || Tries == 999)
{ {
LOG_ERROR(L"Failed to setup adapter", LastError); LOG_ERROR(LastError, L"Failed to setup adapter (status: 0x%x)", ProblemStatus);
goto cleanupTcpipAdapterRegKey; goto cleanupTcpipAdapterRegKey;
} }
Sleep(10); Sleep(10);
@ -1673,7 +1722,7 @@ static _Return_type_success_(return != NULL)
HANDLE Mutex = NamespaceTakePoolMutex(Pool); HANDLE Mutex = NamespaceTakePoolMutex(Pool);
if (!Mutex) if (!Mutex)
{ {
LOG(WINTUN_LOG_ERR, L"Failed to take pool mutex"); LOG(WINTUN_LOG_ERR, L"Failed to take %s pool mutex", Pool);
return NULL; return NULL;
} }
DWORD LastError; DWORD LastError;
@ -1682,11 +1731,16 @@ static _Return_type_success_(return != NULL)
SP_DEVINFO_DATA DevInfoData; SP_DEVINFO_DATA DevInfoData;
if (!GetDevInfoData(CfgInstanceID, &DevInfo, &DevInfoData)) if (!GetDevInfoData(CfgInstanceID, &DevInfo, &DevInfoData))
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to locate adapter"); WCHAR Guid[MAX_GUID_STRING_LEN];
LastError =
LOG(WINTUN_LOG_ERR,
L"Failed to locate adapter %.*s",
StringFromGUID2(CfgInstanceID, Guid, _countof(Guid)),
Guid);
goto cleanupMutex; goto cleanupMutex;
} }
Adapter = CreateAdapterData(Pool, DevInfo, &DevInfoData); Adapter = CreateAdapterData(Pool, DevInfo, &DevInfoData);
LastError = Adapter ? ERROR_SUCCESS : LOG(WINTUN_LOG_ERR, L"Failed to create adapter data"); LastError = Adapter ? ERROR_SUCCESS : LOG(WINTUN_LOG_ERR, L"Failed to create adapter %u data", DevInfoData.DevInst);
SetupDiDestroyDeviceInfoList(DevInfo); SetupDiDestroyDeviceInfoList(DevInfo);
cleanupMutex: cleanupMutex:
NamespaceReleaseMutex(Mutex); NamespaceReleaseMutex(Mutex);
@ -1750,7 +1804,7 @@ _Return_type_success_(return != FALSE) BOOL WINAPI WintunDeleteAdapter(
HANDLE Mutex = NamespaceTakePoolMutex(Adapter->Pool); HANDLE Mutex = NamespaceTakePoolMutex(Adapter->Pool);
if (!Mutex) if (!Mutex)
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to take pool mutex"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to take %s pool mutex", Adapter->Pool);
goto cleanupToken; goto cleanupToken;
} }
@ -1761,12 +1815,18 @@ _Return_type_success_(return != FALSE) BOOL WINAPI WintunDeleteAdapter(
if ((LastError = GetLastError()) == ERROR_FILE_NOT_FOUND) if ((LastError = GetLastError()) == ERROR_FILE_NOT_FOUND)
LastError = ERROR_SUCCESS; LastError = ERROR_SUCCESS;
else else
LOG(WINTUN_LOG_ERR, L"Failed to get adapter info data"); {
WCHAR Guid[MAX_GUID_STRING_LEN];
LOG(WINTUN_LOG_ERR,
L"Failed to get adapter %.*s info data",
StringFromGUID2(&Adapter->CfgInstanceID, Guid, _countof(Guid)),
Guid);
}
goto cleanupMutex; goto cleanupMutex;
} }
if (ForceCloseSessions && !ForceCloseWintunAdapterHandle(DevInfo, &DevInfoData)) if (ForceCloseSessions && !ForceCloseWintunAdapterHandle(DevInfo, &DevInfoData))
LOG(WINTUN_LOG_WARN, L"Failed to force close adapter handles"); LOG(WINTUN_LOG_WARN, L"Failed to force close adapter %u handles", DevInfoData.DevInst);
SetQuietInstall(DevInfo, &DevInfoData); SetQuietInstall(DevInfo, &DevInfoData);
SP_REMOVEDEVICE_PARAMS Params = { .ClassInstallHeader = { .cbSize = sizeof(SP_CLASSINSTALL_HEADER), SP_REMOVEDEVICE_PARAMS Params = { .ClassInstallHeader = { .cbSize = sizeof(SP_CLASSINSTALL_HEADER),
@ -1776,7 +1836,7 @@ _Return_type_success_(return != FALSE) BOOL WINAPI WintunDeleteAdapter(
!SetupDiCallClassInstaller(DIF_REMOVE, DevInfo, &DevInfoData)) && !SetupDiCallClassInstaller(DIF_REMOVE, DevInfo, &DevInfoData)) &&
GetLastError() != ERROR_NO_SUCH_DEVINST) GetLastError() != ERROR_NO_SUCH_DEVINST)
{ {
LastError = LOG_LAST_ERROR(L"Failed to remove existing adapter"); LastError = LOG_LAST_ERROR(L"Failed to remove adapter %u", DevInfoData.DevInst);
goto cleanupDevInfo; goto cleanupDevInfo;
} }
LastError = ERROR_SUCCESS; LastError = ERROR_SUCCESS;
@ -1796,7 +1856,7 @@ static _Return_type_success_(return != FALSE) BOOL
HANDLE Mutex = NamespaceTakePoolMutex(Pool); HANDLE Mutex = NamespaceTakePoolMutex(Pool);
if (!Mutex) if (!Mutex)
{ {
LOG(WINTUN_LOG_ERR, L"Failed to take pool mutex"); LOG(WINTUN_LOG_ERR, L"Failed to take %s pool mutex", Pool);
return FALSE; return FALSE;
} }
DWORD LastError = ERROR_SUCCESS; DWORD LastError = ERROR_SUCCESS;
@ -1822,16 +1882,16 @@ static _Return_type_success_(return != FALSE) BOOL
if (!IsOurAdapter(DevInfo, &DevInfoData) || !IsPoolMember(Pool, DevInfo, &DevInfoData)) if (!IsOurAdapter(DevInfo, &DevInfoData) || !IsPoolMember(Pool, DevInfo, &DevInfoData))
continue; continue;
LOG(WINTUN_LOG_INFO, L"Force closing all open handles for existing adapter"); LOG(WINTUN_LOG_INFO, L"Force closing all adapter %u open handles", DevInfoData.DevInst);
if (!ForceCloseWintunAdapterHandle(DevInfo, &DevInfoData)) if (!ForceCloseWintunAdapterHandle(DevInfo, &DevInfoData))
LOG(WINTUN_LOG_WARN, L"Failed to force close adapter handles"); LOG(WINTUN_LOG_WARN, L"Failed to force close adapter %u handles", DevInfoData.DevInst);
LOG(WINTUN_LOG_INFO, L"Removing existing adapter"); LOG(WINTUN_LOG_INFO, L"Removing adapter %u", DevInfoData.DevInst);
if ((!SetupDiSetClassInstallParamsW(DevInfo, &DevInfoData, &Params.ClassInstallHeader, sizeof(Params)) || if ((!SetupDiSetClassInstallParamsW(DevInfo, &DevInfoData, &Params.ClassInstallHeader, sizeof(Params)) ||
!SetupDiCallClassInstaller(DIF_REMOVE, DevInfo, &DevInfoData)) && !SetupDiCallClassInstaller(DIF_REMOVE, DevInfo, &DevInfoData)) &&
GetLastError() != ERROR_NO_SUCH_DEVINST) GetLastError() != ERROR_NO_SUCH_DEVINST)
{ {
LOG_LAST_ERROR(L"Failed to remove existing adapter"); LOG_LAST_ERROR(L"Failed to remove adapter %u", DevInfoData.DevInst);
LastError = LastError != ERROR_SUCCESS ? LastError : GetLastError(); LastError = LastError != ERROR_SUCCESS ? LastError : GetLastError();
} }
*RebootRequired = *RebootRequired || CheckReboot(DevInfo, &DevInfoData); *RebootRequired = *RebootRequired || CheckReboot(DevInfo, &DevInfoData);
@ -1900,10 +1960,11 @@ _Return_type_success_(return != FALSE) BOOL WINAPI
continue; continue;
if (!_wcsicmp(DriverDetail->HardwareID, WINTUN_HWID)) if (!_wcsicmp(DriverDetail->HardwareID, WINTUN_HWID))
{ {
LOG(WINTUN_LOG_INFO, L"Removing existing driver"); LPCWSTR Path = PathFindFileNameW(DriverDetail->InfFileName);
if (!SetupUninstallOEMInfW(PathFindFileNameW(DriverDetail->InfFileName), 0, NULL)) LOG(WINTUN_LOG_INFO, L"Removing driver %s", Path);
if (!SetupUninstallOEMInfW(Path, 0, NULL))
{ {
LOG_LAST_ERROR(L"Unable to remove existing driver"); LOG_LAST_ERROR(L"Unable to remove driver %s", Path);
LastError = LastError != ERROR_SUCCESS ? LastError : GetLastError(); LastError = LastError != ERROR_SUCCESS ? LastError : GetLastError();
} }
} }
@ -1925,7 +1986,7 @@ _Return_type_success_(return != FALSE) BOOL WINAPI
HANDLE Mutex = NamespaceTakePoolMutex(Pool); HANDLE Mutex = NamespaceTakePoolMutex(Pool);
if (!Mutex) if (!Mutex)
{ {
LOG(WINTUN_LOG_ERR, L"Failed to take pool mutex"); LOG(WINTUN_LOG_ERR, L"Failed to take %s pool mutex", Pool);
return FALSE; return FALSE;
} }
DWORD LastError = ERROR_SUCCESS; DWORD LastError = ERROR_SUCCESS;
@ -1952,7 +2013,7 @@ _Return_type_success_(return != FALSE) BOOL WINAPI
WINTUN_ADAPTER *Adapter = CreateAdapterData(Pool, DevInfo, &DevInfoData); WINTUN_ADAPTER *Adapter = CreateAdapterData(Pool, DevInfo, &DevInfoData);
if (!Adapter) if (!Adapter)
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to create adapter data"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to create adapter %u data", DevInfoData.DevInst);
break; break;
} }
Continue = Func(Adapter, Param); Continue = Func(Adapter, Param);

View File

@ -42,7 +42,7 @@ _Return_type_success_(return != FALSE) BOOL ElevateToSystem(void)
CloseHandle(CurrentProcessToken); CloseHandle(CurrentProcessToken);
if (!Ret) if (!Ret)
{ {
LOG_ERROR(L"Failed to get token information", LastError); LOG_ERROR(LastError, L"Failed to get token information");
goto cleanup; goto cleanup;
} }
if (EqualSid(TokenUserBuffer.MaybeLocalSystem.User.Sid, LocalSystemSid)) if (EqualSid(TokenUserBuffer.MaybeLocalSystem.User.Sid, LocalSystemSid))

View File

@ -4,7 +4,9 @@
*/ */
#include "logger.h" #include "logger.h"
#include "ntdll.h"
#include <Windows.h> #include <Windows.h>
#include <winternl.h>
#include <wchar.h> #include <wchar.h>
static BOOL CALLBACK static BOOL CALLBACK
@ -25,6 +27,13 @@ WintunSetLogger(_In_ WINTUN_LOGGER_CALLBACK NewLogger)
Logger = NewLogger; Logger = NewLogger;
} }
static VOID
StrTruncate(_Inout_count_(StrChars) WCHAR *Str, _In_ SIZE_T StrChars)
{
Str[StrChars - 2] = L'\u2026'; /* Horizontal Ellipsis */
Str[StrChars - 1] = 0;
}
_Post_equals_last_error_ DWORD _Post_equals_last_error_ DWORD
LoggerLog(_In_ WINTUN_LOGGER_LEVEL Level, _In_z_ const WCHAR *Function, _In_z_ const WCHAR *LogLine) LoggerLog(_In_ WINTUN_LOGGER_LEVEL Level, _In_z_ const WCHAR *Function, _In_z_ const WCHAR *LogLine)
{ {
@ -33,10 +42,7 @@ LoggerLog(_In_ WINTUN_LOGGER_LEVEL Level, _In_z_ const WCHAR *Function, _In_z_ c
{ {
WCHAR Combined[0x400]; WCHAR Combined[0x400];
if (_snwprintf_s(Combined, _countof(Combined), _TRUNCATE, L"%s: %s", Function, LogLine) == -1) if (_snwprintf_s(Combined, _countof(Combined), _TRUNCATE, L"%s: %s", Function, LogLine) == -1)
{ StrTruncate(Combined, _countof(Combined));
Combined[_countof(Combined) - 2] = L'\u2026'; /* Horizontal Ellipsis */
Combined[_countof(Combined) - 1] = 0;
}
Logger(Level, Combined); Logger(Level, Combined);
} }
else else
@ -46,7 +52,26 @@ LoggerLog(_In_ WINTUN_LOGGER_LEVEL Level, _In_z_ const WCHAR *Function, _In_z_ c
} }
_Post_equals_last_error_ DWORD _Post_equals_last_error_ DWORD
LoggerError(_In_z_ const WCHAR *Function, _In_z_ const WCHAR *Prefix, _In_ DWORD Error) LoggerLogV(
_In_ WINTUN_LOGGER_LEVEL Level,
_In_z_ const WCHAR *Function,
_In_z_ _Printf_format_string_ const WCHAR *Format,
_In_ va_list Args)
{
DWORD LastError = GetLastError();
WCHAR LogLine[0x400];
if (_vsnwprintf_s(LogLine, _countof(LogLine), _TRUNCATE, Format, Args) == -1)
StrTruncate(LogLine, _countof(LogLine));
if (Function)
LoggerLog(Level, Function, LogLine);
else
Logger(Level, LogLine);
SetLastError(LastError);
return LastError;
}
_Post_equals_last_error_ DWORD
LoggerError(_In_ DWORD Error, _In_z_ const WCHAR *Function, _In_z_ const WCHAR *Prefix)
{ {
WCHAR *SystemMessage = NULL, *FormattedMessage = NULL; WCHAR *SystemMessage = NULL, *FormattedMessage = NULL;
FormatMessageW( FormatMessageW(
@ -72,3 +97,43 @@ LoggerError(_In_z_ const WCHAR *Function, _In_z_ const WCHAR *Prefix, _In_ DWORD
LocalFree(SystemMessage); LocalFree(SystemMessage);
return Error; return Error;
} }
_Post_equals_last_error_ DWORD
LoggerErrorV(
_In_ DWORD Error,
_In_z_ const WCHAR *Function,
_In_z_ _Printf_format_string_ const WCHAR *Format,
_In_ va_list Args)
{
WCHAR Prefix[0x400];
if (_vsnwprintf_s(Prefix, _countof(Prefix), _TRUNCATE, Format, Args) == -1)
StrTruncate(Prefix, _countof(Prefix));
return LoggerError(Error, Function, Prefix);
}
VOID
LoggerGetRegistryKeyPath(_In_ HKEY Key, _Out_cap_c_(MAX_REG_PATH) WCHAR *Path)
{
DWORD LastError = GetLastError();
if (Key == NULL)
{
wcscpy_s(Path, MAX_REG_PATH, L"<null>");
goto out;
}
if (_snwprintf_s(Path, MAX_REG_PATH, _TRUNCATE, L"0x%p", Key) == -1)
StrTruncate(Path, MAX_REG_PATH);
union
{
KEY_NAME_INFORMATION KeyNameInfo;
WCHAR Data[offsetof(KEY_NAME_INFORMATION, Name) + MAX_REG_PATH];
} Buffer;
DWORD Size;
if (!NT_SUCCESS(NtQueryKey(Key, 3, &Buffer, sizeof(Buffer), &Size)) ||
Size < offsetof(KEY_NAME_INFORMATION, Name) || Buffer.KeyNameInfo.NameLength >= MAX_REG_PATH * sizeof(WCHAR))
goto out;
Buffer.KeyNameInfo.NameLength /= sizeof(WCHAR);
wmemcpy_s(Path, MAX_REG_PATH, Buffer.KeyNameInfo.Name, Buffer.KeyNameInfo.NameLength);
Path[Buffer.KeyNameInfo.NameLength] = L'\0';
out:
SetLastError(LastError);
}

View File

@ -7,7 +7,10 @@
#include "wintun.h" #include "wintun.h"
#include "entry.h" #include "entry.h"
#include "registry.h"
#include <Windows.h> #include <Windows.h>
#include <stdarg.h>
#include <wchar.h>
extern WINTUN_LOGGER_CALLBACK Logger; extern WINTUN_LOGGER_CALLBACK Logger;
@ -21,22 +24,73 @@ _Post_equals_last_error_ DWORD
LoggerLog(_In_ WINTUN_LOGGER_LEVEL Level, _In_z_ const WCHAR *Function, _In_z_ const WCHAR *LogLine); LoggerLog(_In_ WINTUN_LOGGER_LEVEL Level, _In_z_ const WCHAR *Function, _In_z_ const WCHAR *LogLine);
_Post_equals_last_error_ DWORD _Post_equals_last_error_ DWORD
LoggerError(_In_z_ const WCHAR *Function, _In_z_ const WCHAR *Prefix, _In_ DWORD Error); LoggerLogV(
_In_ WINTUN_LOGGER_LEVEL Level,
_In_z_ const WCHAR *Function,
_In_z_ _Printf_format_string_ const WCHAR *Format,
_In_ va_list Args);
static inline _Post_equals_last_error_ DWORD static inline _Post_equals_last_error_ DWORD
LoggerLastError(_In_z_ const WCHAR *Function, _In_z_ const WCHAR *Prefix) LoggerLogFmt(
_In_ WINTUN_LOGGER_LEVEL Level,
_In_z_ const WCHAR *Function,
_In_z_ _Printf_format_string_ const WCHAR *Format,
...)
{
va_list Args;
va_start(Args, Format);
DWORD LastError = LoggerLogV(Level, Function, Format, Args);
va_end(Args);
return LastError;
}
_Post_equals_last_error_ DWORD
LoggerError(_In_ DWORD Error, _In_z_ const WCHAR *Function, _In_z_ const WCHAR *Prefix);
_Post_equals_last_error_ DWORD
LoggerErrorV(
_In_ DWORD Error,
_In_z_ const WCHAR *Function,
_In_z_ _Printf_format_string_ const WCHAR *Format,
_In_ va_list Args);
static inline _Post_equals_last_error_ DWORD
LoggerErrorFmt(_In_ DWORD Error, _In_z_ const WCHAR *Function, _In_z_ _Printf_format_string_ const WCHAR *Format, ...)
{
va_list Args;
va_start(Args, Format);
DWORD LastError = LoggerErrorV(Error, Function, Format, Args);
va_end(Args);
return LastError;
}
static inline _Post_equals_last_error_ DWORD
LoggerLastErrorV(_In_z_ const WCHAR *Function, _In_z_ _Printf_format_string_ const WCHAR *Format, _In_ va_list Args)
{ {
DWORD LastError = GetLastError(); DWORD LastError = GetLastError();
LoggerError(Function, Prefix, LastError); LoggerErrorV(LastError, Function, Format, Args);
SetLastError(LastError); SetLastError(LastError);
return LastError; return LastError;
} }
static inline _Post_equals_last_error_ DWORD
LoggerLastErrorFmt(_In_z_ const WCHAR *Function, _In_z_ _Printf_format_string_ const WCHAR *Format, ...)
{
va_list Args;
va_start(Args, Format);
DWORD LastError = LoggerLastErrorV(Function, Format, Args);
va_end(Args);
return LastError;
}
VOID
LoggerGetRegistryKeyPath(_In_ HKEY Key, _Out_cap_c_(MAX_REG_PATH) WCHAR *Path);
#define __L(x) L##x #define __L(x) L##x
#define _L(x) __L(x) #define _L(x) __L(x)
#define LOG(lvl, msg) (LoggerLog((lvl), _L(__FUNCTION__), msg)) #define LOG(lvl, msg, ...) (LoggerLogFmt((lvl), _L(__FUNCTION__), msg, __VA_ARGS__))
#define LOG_ERROR(msg, err) (LoggerError(_L(__FUNCTION__), msg, (err))) #define LOG_ERROR(err, msg, ...) (LoggerErrorFmt((err), _L(__FUNCTION__), msg, __VA_ARGS__))
#define LOG_LAST_ERROR(msg) (LoggerLastError(_L(__FUNCTION__), msg)) #define LOG_LAST_ERROR(msg, ...) (LoggerLastErrorFmt(_L(__FUNCTION__), msg, __VA_ARGS__))
#define RET_ERROR(Ret, Error) ((Error) == ERROR_SUCCESS ? (Ret) : (SetLastError(Error), 0)) #define RET_ERROR(Ret, Error) ((Error) == ERROR_SUCCESS ? (Ret) : (SetLastError(Error), 0))
@ -46,13 +100,14 @@ static inline _Return_type_success_(return != NULL) _Ret_maybenull_
void *Data = HeapAlloc(ModuleHeap, Flags, Size); void *Data = HeapAlloc(ModuleHeap, Flags, Size);
if (!Data) if (!Data)
{ {
LoggerLog(WINTUN_LOG_ERR, Function, L"Out of memory"); LoggerLogFmt(WINTUN_LOG_ERR, Function, L"Out of memory (flags: 0x%x, requested size: 0x%zx)", Flags, Size);
SetLastError(ERROR_OUTOFMEMORY); SetLastError(ERROR_OUTOFMEMORY);
} }
return Data; return Data;
} }
#define Alloc(Size) LoggerAlloc(_L(__FUNCTION__), 0, Size) #define Alloc(Size) LoggerAlloc(_L(__FUNCTION__), 0, Size)
#define Zalloc(Size) LoggerAlloc(_L(__FUNCTION__), HEAP_ZERO_MEMORY, Size) #define Zalloc(Size) LoggerAlloc(_L(__FUNCTION__), HEAP_ZERO_MEMORY, Size)
static inline void static inline void
Free(void *Ptr) Free(void *Ptr)
{ {

View File

@ -32,7 +32,7 @@ static _Return_type_success_(
Free(Str); Free(Str);
if (GetLastError() != ERROR_INSUFFICIENT_BUFFER) if (GetLastError() != ERROR_INSUFFICIENT_BUFFER)
{ {
LOG_LAST_ERROR(L"Failed"); LOG_LAST_ERROR(L"Failed: %s", Source);
return NULL; return NULL;
} }
Len = -Len; Len = -Len;
@ -53,7 +53,7 @@ static _Return_type_success_(return != FALSE) BOOL NamespaceRuntimeInit(void)
NTSTATUS Status; NTSTATUS Status;
if (!BCRYPT_SUCCESS(Status = BCryptOpenAlgorithmProvider(&AlgProvider, BCRYPT_SHA256_ALGORITHM, NULL, 0))) if (!BCRYPT_SUCCESS(Status = BCryptOpenAlgorithmProvider(&AlgProvider, BCRYPT_SHA256_ALGORITHM, NULL, 0)))
{ {
LOG(WINTUN_LOG_ERR, L"Failed to open algorithm provider"); LOG(WINTUN_LOG_ERR, L"Failed to open algorithm provider (status: 0x%x)", Status);
LastError = RtlNtStatusToDosError(Status); LastError = RtlNtStatusToDosError(Status);
goto cleanupLeaveCriticalSection; goto cleanupLeaveCriticalSection;
} }
@ -88,10 +88,10 @@ static _Return_type_success_(return != FALSE) BOOL NamespaceRuntimeInit(void)
break; break;
if ((LastError = GetLastError()) == ERROR_PATH_NOT_FOUND) if ((LastError = GetLastError()) == ERROR_PATH_NOT_FOUND)
continue; continue;
LOG_ERROR(L"Failed to open private namespace", LastError); LOG_ERROR(LastError, L"Failed to open private namespace");
} }
else else
LOG_ERROR(L"Failed to create private namespace", LastError); LOG_ERROR(LastError, L"Failed to create private namespace");
goto cleanupBoundaryDescriptor; goto cleanupBoundaryDescriptor;
} }
@ -118,7 +118,7 @@ _Return_type_success_(return != NULL) HANDLE NamespaceTakePoolMutex(_In_z_ const
NTSTATUS Status; NTSTATUS Status;
if (!BCRYPT_SUCCESS(Status = BCryptCreateHash(AlgProvider, &Sha256, NULL, 0, NULL, 0, 0))) if (!BCRYPT_SUCCESS(Status = BCryptCreateHash(AlgProvider, &Sha256, NULL, 0, NULL, 0, 0)))
{ {
LOG(WINTUN_LOG_ERR, L"Failed to create hash"); LOG(WINTUN_LOG_ERR, L"Failed to create hash (status: 0x%x)", Status);
SetLastError(RtlNtStatusToDosError(Status)); SetLastError(RtlNtStatusToDosError(Status));
return NULL; return NULL;
} }
@ -127,7 +127,7 @@ _Return_type_success_(return != NULL) HANDLE NamespaceTakePoolMutex(_In_z_ const
if (!BCRYPT_SUCCESS( if (!BCRYPT_SUCCESS(
Status = BCryptHashData(Sha256, (PUCHAR)mutex_label, sizeof(mutex_label) /* Including NULL 2 bytes */, 0))) Status = BCryptHashData(Sha256, (PUCHAR)mutex_label, sizeof(mutex_label) /* Including NULL 2 bytes */, 0)))
{ {
LOG(WINTUN_LOG_ERR, L"Failed to hash data"); LOG(WINTUN_LOG_ERR, L"Failed to hash data (status: 0x%x)", Status);
LastError = RtlNtStatusToDosError(Status); LastError = RtlNtStatusToDosError(Status);
goto cleanupSha256; goto cleanupSha256;
} }
@ -140,14 +140,14 @@ _Return_type_success_(return != NULL) HANDLE NamespaceTakePoolMutex(_In_z_ const
if (!BCRYPT_SUCCESS( if (!BCRYPT_SUCCESS(
Status = BCryptHashData(Sha256, (PUCHAR)PoolNorm, (int)wcslen(PoolNorm) + 2 /* Add in NULL 2 bytes */, 0))) Status = BCryptHashData(Sha256, (PUCHAR)PoolNorm, (int)wcslen(PoolNorm) + 2 /* Add in NULL 2 bytes */, 0)))
{ {
LOG(WINTUN_LOG_ERR, L"Failed to hash data"); LOG(WINTUN_LOG_ERR, L"Failed to hash data (status: 0x%x)", Status);
LastError = RtlNtStatusToDosError(Status); LastError = RtlNtStatusToDosError(Status);
goto cleanupPoolNorm; goto cleanupPoolNorm;
} }
BYTE Hash[32]; BYTE Hash[32];
if (!BCRYPT_SUCCESS(Status = BCryptFinishHash(Sha256, Hash, sizeof(Hash), 0))) if (!BCRYPT_SUCCESS(Status = BCryptFinishHash(Sha256, Hash, sizeof(Hash), 0)))
{ {
LOG(WINTUN_LOG_ERR, L"Failed to calculate hash"); LOG(WINTUN_LOG_ERR, L"Failed to calculate hash (status: 0x%x)", Status);
LastError = RtlNtStatusToDosError(Status); LastError = RtlNtStatusToDosError(Status);
goto cleanupPoolNorm; goto cleanupPoolNorm;
} }
@ -159,10 +159,11 @@ _Return_type_success_(return != NULL) HANDLE NamespaceTakePoolMutex(_In_z_ const
HANDLE Mutex = CreateMutexW(&SecurityAttributes, FALSE, MutexName); HANDLE Mutex = CreateMutexW(&SecurityAttributes, FALSE, MutexName);
if (!Mutex) if (!Mutex)
{ {
LastError = LOG_LAST_ERROR(L"Failed to create mutex"); LastError = LOG_LAST_ERROR(L"Failed to create mutex %s", MutexName);
goto cleanupPoolNorm; goto cleanupPoolNorm;
} }
switch (WaitForSingleObject(Mutex, INFINITE)) DWORD Result = WaitForSingleObject(Mutex, INFINITE);
switch (Result)
{ {
case WAIT_OBJECT_0: case WAIT_OBJECT_0:
case WAIT_ABANDONED: case WAIT_ABANDONED:
@ -170,7 +171,7 @@ _Return_type_success_(return != NULL) HANDLE NamespaceTakePoolMutex(_In_z_ const
BCryptDestroyHash(Sha256); BCryptDestroyHash(Sha256);
return Mutex; return Mutex;
} }
LOG(WINTUN_LOG_ERR, L"Failed to get mutex"); LOG(WINTUN_LOG_ERR, L"Failed to get mutex %s (status: 0x%x)", MutexName, Result);
LastError = ERROR_GEN_FAILURE; LastError = ERROR_GEN_FAILURE;
CloseHandle(Mutex); CloseHandle(Mutex);
cleanupPoolNorm: cleanupPoolNorm:
@ -192,13 +193,14 @@ _Return_type_success_(return != NULL) HANDLE NamespaceTakeDriverInstallationMute
LOG_LAST_ERROR(L"Failed to create mutex"); LOG_LAST_ERROR(L"Failed to create mutex");
return NULL; return NULL;
} }
switch (WaitForSingleObject(Mutex, INFINITE)) DWORD Result = WaitForSingleObject(Mutex, INFINITE);
switch (Result)
{ {
case WAIT_OBJECT_0: case WAIT_OBJECT_0:
case WAIT_ABANDONED: case WAIT_ABANDONED:
return Mutex; return Mutex;
} }
LOG(WINTUN_LOG_ERR, L"Failed to get mutex"); LOG(WINTUN_LOG_ERR, L"Failed to get mutex (status: 0x%x)", Result);
CloseHandle(Mutex); CloseHandle(Mutex);
SetLastError(ERROR_GEN_FAILURE); SetLastError(ERROR_GEN_FAILURE);
return NULL; return NULL;

View File

@ -32,6 +32,12 @@ typedef struct _RTL_PROCESS_MODULES
RTL_PROCESS_MODULE_INFORMATION Modules[1]; RTL_PROCESS_MODULE_INFORMATION Modules[1];
} RTL_PROCESS_MODULES, *PRTL_PROCESS_MODULES; } RTL_PROCESS_MODULES, *PRTL_PROCESS_MODULES;
typedef struct _KEY_NAME_INFORMATION
{
ULONG NameLength;
WCHAR Name[1];
} KEY_NAME_INFORMATION, *PKEY_NAME_INFORMATION;
#define STATUS_INFO_LENGTH_MISMATCH ((NTSTATUS)0xC0000004L) // TODO: #include <ntstatus.h> instead of this #define STATUS_INFO_LENGTH_MISMATCH ((NTSTATUS)0xC0000004L) // TODO: #include <ntstatus.h> instead of this
#define STATUS_PNP_DEVICE_CONFIGURATION_PENDING ((NTSTATUS)0xC0000495L) #define STATUS_PNP_DEVICE_CONFIGURATION_PENDING ((NTSTATUS)0xC0000495L)
@ -46,3 +52,12 @@ typedef struct _RTL_PROCESS_MODULES
EXTERN_C EXTERN_C
DECLSPEC_IMPORT VOID NTAPI DECLSPEC_IMPORT VOID NTAPI
RtlGetNtVersionNumbers(_Out_opt_ DWORD *MajorVersion, _Out_opt_ DWORD *MinorVersion, _Out_opt_ DWORD *BuildNumber); RtlGetNtVersionNumbers(_Out_opt_ DWORD *MajorVersion, _Out_opt_ DWORD *MinorVersion, _Out_opt_ DWORD *BuildNumber);
EXTERN_C
DECLSPEC_IMPORT DWORD NTAPI
NtQueryKey(
_In_ HANDLE KeyHandle,
_In_ int KeyInformationClass,
_Out_bytecap_post_bytecount_(Length, *ResultLength) PVOID KeyInformation,
_In_ ULONG Length,
_Out_ PULONG ResultLength);

View File

@ -28,7 +28,9 @@ static _Return_type_success_(return != NULL) HKEY
LastError = RegNotifyChangeKeyValue(Key, FALSE, REG_NOTIFY_CHANGE_NAME, Event, TRUE); LastError = RegNotifyChangeKeyValue(Key, FALSE, REG_NOTIFY_CHANGE_NAME, Event, TRUE);
if (LastError != ERROR_SUCCESS) if (LastError != ERROR_SUCCESS)
{ {
LOG_ERROR(L"Failed to setup notification", LastError); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG_ERROR(LastError, L"Failed to setup registry key %.*s notification", MAX_REG_PATH, RegPath);
break; break;
} }
@ -56,16 +58,26 @@ static _Return_type_success_(return != NULL) HKEY
} }
if (LastError != ERROR_FILE_NOT_FOUND && LastError != ERROR_PATH_NOT_FOUND) if (LastError != ERROR_FILE_NOT_FOUND && LastError != ERROR_PATH_NOT_FOUND)
{ {
LOG_ERROR(L"Failed to open", LastError); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG_ERROR(LastError, L"Failed to open registry key %.*s\\%s", MAX_REG_PATH, RegPath, Path);
break; break;
} }
LONGLONG TimeLeft = Deadline - GetTickCount64(); LONGLONG TimeLeft = Deadline - GetTickCount64();
if (TimeLeft < 0) if (TimeLeft < 0)
TimeLeft = 0; TimeLeft = 0;
if (WaitForSingleObject(Event, (DWORD)TimeLeft) != WAIT_OBJECT_0) DWORD Result = WaitForSingleObject(Event, (DWORD)TimeLeft);
if (Result != WAIT_OBJECT_0)
{ {
LOG(WINTUN_LOG_ERR, L"Timeout waiting"); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG(WINTUN_LOG_ERR,
L"Timeout waiting for registry key %.*s\\%s (status: 0x%x)",
MAX_REG_PATH,
RegPath,
Path,
Result);
break; break;
} }
} }
@ -80,7 +92,7 @@ _Return_type_success_(return != NULL) HKEY
WCHAR Buf[MAX_REG_PATH]; WCHAR Buf[MAX_REG_PATH];
if (wcsncpy_s(Buf, _countof(Buf), Path, _TRUNCATE) == STRUNCATE) if (wcsncpy_s(Buf, _countof(Buf), Path, _TRUNCATE) == STRUNCATE)
{ {
LOG(WINTUN_LOG_ERR, L"Registry path too long"); LOG(WINTUN_LOG_ERR, L"Registry path too long: %s", Path);
SetLastError(ERROR_INVALID_PARAMETER); SetLastError(ERROR_INVALID_PARAMETER);
return NULL; return NULL;
} }
@ -118,7 +130,7 @@ _Return_type_success_(return != FALSE) BOOL RegistryGetString(_Inout_ WCHAR **Bu
DWORD Result = ExpandEnvironmentStringsW(*Buf, Expanded, Len); DWORD Result = ExpandEnvironmentStringsW(*Buf, Expanded, Len);
if (!Result) if (!Result)
{ {
LOG_LAST_ERROR(L"Failed to expand environment variables"); LOG_LAST_ERROR(L"Failed to expand environment variables: %s", *Buf);
Free(Expanded); Free(Expanded);
return FALSE; return FALSE;
} }
@ -204,7 +216,11 @@ static _Return_type_success_(return != NULL) void *RegistryQuery(
if (LastError != ERROR_MORE_DATA) if (LastError != ERROR_MORE_DATA)
{ {
if (Log) if (Log)
LOG_ERROR(L"Querying value failed", LastError); {
WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG_ERROR(LastError, L"Querying registry value %.*s\\%s failed", MAX_REG_PATH, RegPath, Name);
}
SetLastError(LastError); SetLastError(LastError);
return NULL; return NULL;
} }
@ -227,10 +243,18 @@ _Return_type_success_(
return Value; return Value;
LastError = GetLastError(); LastError = GetLastError();
break; break;
default: default: {
LOG(WINTUN_LOG_ERR, L"Value is not a string"); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG(WINTUN_LOG_ERR,
L"Registry value %.*s\\%s is not a string (type: %u)",
MAX_REG_PATH,
RegPath,
Name,
ValueType);
LastError = ERROR_INVALID_DATATYPE; LastError = ERROR_INVALID_DATATYPE;
} }
}
Free(Value); Free(Value);
SetLastError(LastError); SetLastError(LastError);
return NULL; return NULL;
@ -252,7 +276,9 @@ _Return_type_success_(
LastError = RegNotifyChangeKeyValue(Key, FALSE, REG_NOTIFY_CHANGE_LAST_SET, Event, TRUE); LastError = RegNotifyChangeKeyValue(Key, FALSE, REG_NOTIFY_CHANGE_LAST_SET, Event, TRUE);
if (LastError != ERROR_SUCCESS) if (LastError != ERROR_SUCCESS)
{ {
LOG_ERROR(L"Failed to setup notification", LastError); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG_ERROR(LastError, L"Failed to setup registry key %.*s notification", MAX_REG_PATH, RegPath);
break; break;
} }
WCHAR *Value = RegistryQueryString(Key, Name, FALSE); WCHAR *Value = RegistryQueryString(Key, Name, FALSE);
@ -267,9 +293,17 @@ _Return_type_success_(
LONGLONG TimeLeft = Deadline - GetTickCount64(); LONGLONG TimeLeft = Deadline - GetTickCount64();
if (TimeLeft < 0) if (TimeLeft < 0)
TimeLeft = 0; TimeLeft = 0;
if (WaitForSingleObject(Event, (DWORD)TimeLeft) != WAIT_OBJECT_0) DWORD Result = WaitForSingleObject(Event, (DWORD)TimeLeft);
if (Result != WAIT_OBJECT_0)
{ {
LOG(WINTUN_LOG_ERR, L"Timeout waiting"); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG(WINTUN_LOG_ERR,
L"Timeout waiting for registry value %.*s\\%s (status: 0x%x)",
MAX_REG_PATH,
RegPath,
Name,
Result);
break; break;
} }
} }
@ -286,19 +320,27 @@ _Return_type_success_(return != FALSE) BOOL
if (LastError != ERROR_SUCCESS) if (LastError != ERROR_SUCCESS)
{ {
if (Log) if (Log)
LOG_ERROR(L"Querying failed", LastError); {
WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG_ERROR(LastError, L"Querying registry value %.*s\\%s failed", MAX_REG_PATH, RegPath, Name);
}
SetLastError(LastError); SetLastError(LastError);
return FALSE; return FALSE;
} }
if (ValueType != REG_DWORD) if (ValueType != REG_DWORD)
{ {
LOG(WINTUN_LOG_ERR, L"Value is not a DWORD"); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG(WINTUN_LOG_ERR, L"Value %.*s\\%s is not a DWORD (type: %u)", MAX_REG_PATH, RegPath, Name, ValueType);
SetLastError(ERROR_INVALID_DATATYPE); SetLastError(ERROR_INVALID_DATATYPE);
return FALSE; return FALSE;
} }
if (Size != sizeof(DWORD)) if (Size != sizeof(DWORD))
{ {
LOG(WINTUN_LOG_ERR, L"Value size is not 4 bytes"); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG(WINTUN_LOG_ERR, L"Value %.*s\\%s size is not 4 bytes (size: %u)", MAX_REG_PATH, RegPath, Name, Size);
SetLastError(ERROR_INVALID_DATA); SetLastError(ERROR_INVALID_DATA);
return FALSE; return FALSE;
} }
@ -321,7 +363,9 @@ _Return_type_success_(return != FALSE) BOOL
LastError = RegNotifyChangeKeyValue(Key, FALSE, REG_NOTIFY_CHANGE_LAST_SET, Event, TRUE); LastError = RegNotifyChangeKeyValue(Key, FALSE, REG_NOTIFY_CHANGE_LAST_SET, Event, TRUE);
if (LastError != ERROR_SUCCESS) if (LastError != ERROR_SUCCESS)
{ {
LOG_ERROR(L"Failed to setup notification", LastError); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG_ERROR(LastError, L"Failed to setup registry key %.*s notification", MAX_REG_PATH, RegPath);
break; break;
} }
if (RegistryQueryDWORD(Key, Name, Value, FALSE)) if (RegistryQueryDWORD(Key, Name, Value, FALSE))
@ -335,9 +379,17 @@ _Return_type_success_(return != FALSE) BOOL
LONGLONG TimeLeft = Deadline - GetTickCount64(); LONGLONG TimeLeft = Deadline - GetTickCount64();
if (TimeLeft < 0) if (TimeLeft < 0)
TimeLeft = 0; TimeLeft = 0;
if (WaitForSingleObject(Event, (DWORD)TimeLeft) != WAIT_OBJECT_0) DWORD Result = WaitForSingleObject(Event, (DWORD)TimeLeft);
if (Result != WAIT_OBJECT_0)
{ {
LOG(WINTUN_LOG_ERR, L"Timeout waiting"); WCHAR RegPath[MAX_REG_PATH];
LoggerGetRegistryKeyPath(Key, RegPath);
LOG(WINTUN_LOG_ERR,
L"Timeout waiting registry value %.*s\\%s (status: 0x%x)",
MAX_REG_PATH,
RegPath,
Name,
Result);
break; break;
} }
} }

View File

@ -14,25 +14,25 @@ _Return_type_success_(return != NULL) _Ret_bytecount_(*Size) const
HRSRC FoundResource = FindResourceW(ResourceModule, ResourceName, RT_RCDATA); HRSRC FoundResource = FindResourceW(ResourceModule, ResourceName, RT_RCDATA);
if (!FoundResource) if (!FoundResource)
{ {
LOG_LAST_ERROR(L"Failed to find resource"); LOG_LAST_ERROR(L"Failed to find resource %s", ResourceName);
return NULL; return NULL;
} }
*Size = SizeofResource(ResourceModule, FoundResource); *Size = SizeofResource(ResourceModule, FoundResource);
if (!*Size) if (!*Size)
{ {
LOG_LAST_ERROR(L"Failed to query resource size"); LOG_LAST_ERROR(L"Failed to query resource %s size", ResourceName);
return NULL; return NULL;
} }
HGLOBAL LoadedResource = LoadResource(ResourceModule, FoundResource); HGLOBAL LoadedResource = LoadResource(ResourceModule, FoundResource);
if (!LoadedResource) if (!LoadedResource)
{ {
LOG_LAST_ERROR(L"Failed to load resource"); LOG_LAST_ERROR(L"Failed to load resource %s", ResourceName);
return NULL; return NULL;
} }
BYTE *Address = LockResource(LoadedResource); BYTE *Address = LockResource(LoadedResource);
if (!Address) if (!Address)
{ {
LOG(WINTUN_LOG_ERR, L"Failed to lock resource"); LOG(WINTUN_LOG_ERR, L"Failed to lock resource %s", ResourceName);
SetLastError(ERROR_LOCK_FAILED); SetLastError(ERROR_LOCK_FAILED);
return NULL; return NULL;
} }
@ -46,7 +46,7 @@ _Return_type_success_(return != FALSE) BOOL
const void *LockedResource = ResourceGetAddress(ResourceName, &SizeResource); const void *LockedResource = ResourceGetAddress(ResourceName, &SizeResource);
if (!LockedResource) if (!LockedResource)
{ {
LOG(WINTUN_LOG_ERR, L"Failed to locate resource"); LOG(WINTUN_LOG_ERR, L"Failed to locate resource %s", ResourceName);
return FALSE; return FALSE;
} }
HANDLE DestinationHandle = CreateFileW( HANDLE DestinationHandle = CreateFileW(
@ -59,19 +59,23 @@ _Return_type_success_(return != FALSE) BOOL
NULL); NULL);
if (DestinationHandle == INVALID_HANDLE_VALUE) if (DestinationHandle == INVALID_HANDLE_VALUE)
{ {
LOG_LAST_ERROR(L"Failed to create file"); LOG_LAST_ERROR(L"Failed to create file %s", DestinationPath);
return FALSE; return FALSE;
} }
DWORD BytesWritten; DWORD BytesWritten;
DWORD LastError; DWORD LastError;
if (!WriteFile(DestinationHandle, LockedResource, SizeResource, &BytesWritten, NULL)) if (!WriteFile(DestinationHandle, LockedResource, SizeResource, &BytesWritten, NULL))
{ {
LastError = LOG_LAST_ERROR(L"Failed to write file"); LastError = LOG_LAST_ERROR(L"Failed to write file %s", DestinationPath);
goto cleanupDestinationHandle; goto cleanupDestinationHandle;
} }
if (BytesWritten != SizeResource) if (BytesWritten != SizeResource)
{ {
LOG(WINTUN_LOG_ERR, L"Incomplete write"); LOG(WINTUN_LOG_ERR,
L"Incomplete write to %s (written: %u, expected: %u)",
DestinationPath,
BytesWritten,
SizeResource);
LastError = ERROR_WRITE_FAULT; LastError = ERROR_WRITE_FAULT;
goto cleanupDestinationHandle; goto cleanupDestinationHandle;
} }

View File

@ -102,7 +102,7 @@ static _Return_type_success_(return != FALSE) BOOL ExecuteRunDll32(
WCHAR RandomTempSubDirectory[MAX_PATH]; WCHAR RandomTempSubDirectory[MAX_PATH];
if (!CreateTemporaryDirectory(RandomTempSubDirectory)) if (!CreateTemporaryDirectory(RandomTempSubDirectory))
{ {
LOG(WINTUN_LOG_ERR, L"Failed to create temporary folder"); LOG(WINTUN_LOG_ERR, L"Failed to create temporary folder %s", RandomTempSubDirectory);
return FALSE; return FALSE;
} }
WCHAR DllPath[MAX_PATH] = { 0 }; WCHAR DllPath[MAX_PATH] = { 0 };
@ -121,13 +121,13 @@ static _Return_type_success_(return != FALSE) BOOL ExecuteRunDll32(
WintunDllResourceName = L"wintun-arm64.dll"; WintunDllResourceName = L"wintun-arm64.dll";
break; break;
default: default:
LOG(WINTUN_LOG_ERR, L"Unsupported platform"); LOG(WINTUN_LOG_ERR, L"Unsupported platform 0x%x", NativeMachine);
LastError = ERROR_NOT_SUPPORTED; LastError = ERROR_NOT_SUPPORTED;
goto cleanupDirectory; goto cleanupDirectory;
} }
if (!ResourceCopyToFile(DllPath, WintunDllResourceName)) if (!ResourceCopyToFile(DllPath, WintunDllResourceName))
{ {
LastError = LOG(WINTUN_LOG_ERR, L"Failed to copy resource"); LastError = LOG(WINTUN_LOG_ERR, L"Failed to copy resource %s to %s", WintunDllResourceName, DllPath);
goto cleanupDelete; goto cleanupDelete;
} }
size_t CommandLineLen = 10 + MAX_PATH + 2 + wcslen(Arguments) + 1; size_t CommandLineLen = 10 + MAX_PATH + 2 + wcslen(Arguments) + 1;
@ -184,7 +184,7 @@ static _Return_type_success_(return != FALSE) BOOL ExecuteRunDll32(
} }
if (!CreateProcessAsUserW(ProcessToken, RunDll32Path, CommandLine, NULL, NULL, TRUE, 0, NULL, NULL, &si, &pi)) if (!CreateProcessAsUserW(ProcessToken, RunDll32Path, CommandLine, NULL, NULL, TRUE, 0, NULL, NULL, &si, &pi))
{ {
LastError = LOG_LAST_ERROR(L"Failed to create process"); LastError = LOG_LAST_ERROR(L"Failed to create process: %s", CommandLine);
goto cleanupToken; goto cleanupToken;
} }
LastError = ERROR_SUCCESS; LastError = ERROR_SUCCESS;
@ -210,7 +210,7 @@ cleanupThreads:
if (!GetExitCodeThread(ThreadStdout, &ThreadResult)) if (!GetExitCodeThread(ThreadStdout, &ThreadResult))
LOG_LAST_ERROR(L"Failed to retrieve stdout reader result"); LOG_LAST_ERROR(L"Failed to retrieve stdout reader result");
else if (ThreadResult != ERROR_SUCCESS) else if (ThreadResult != ERROR_SUCCESS)
LOG_ERROR(L"Failed to read process output", LastError); LOG_ERROR(LastError, L"Failed to read process output");
CloseHandle(ThreadStdout); CloseHandle(ThreadStdout);
} }
cleanupPipes: cleanupPipes:
@ -252,7 +252,7 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapterViaRun
WCHAR Response[8 + 1 + MAX_GUID_STRING_LEN + 1 + 8 + 1]; WCHAR Response[8 + 1 + MAX_GUID_STRING_LEN + 1 + 8 + 1];
if (!ExecuteRunDll32(Arguments, Response, _countof(Response))) if (!ExecuteRunDll32(Arguments, Response, _countof(Response)))
{ {
LOG(WINTUN_LOG_ERR, L"Error executing worker process"); LOG(WINTUN_LOG_ERR, L"Error executing worker process: %s", Arguments);
return NULL; return NULL;
} }
DWORD LastError; DWORD LastError;
@ -262,14 +262,14 @@ static _Return_type_success_(return != NULL) WINTUN_ADAPTER *CreateAdapterViaRun
GUID CfgInstanceID; GUID CfgInstanceID;
if (Argc < 3 || FAILED(CLSIDFromString(Argv[1], &CfgInstanceID))) if (Argc < 3 || FAILED(CLSIDFromString(Argv[1], &CfgInstanceID)))
{ {
LOG(WINTUN_LOG_ERR, L"Incomplete or invalid response"); LOG(WINTUN_LOG_ERR, L"Incomplete or invalid response: %s", Response);
LastError = ERROR_INVALID_PARAMETER; LastError = ERROR_INVALID_PARAMETER;
goto cleanupArgv; goto cleanupArgv;
} }
LastError = wcstoul(Argv[0], NULL, 16); LastError = wcstoul(Argv[0], NULL, 16);
if (LastError == ERROR_SUCCESS && (Adapter = GetAdapter(Pool, &CfgInstanceID)) == NULL) if (LastError == ERROR_SUCCESS && (Adapter = GetAdapter(Pool, &CfgInstanceID)) == NULL)
{ {
LOG(WINTUN_LOG_ERR, L"Failed to get adapter"); LOG(WINTUN_LOG_ERR, L"Failed to get adapter %s", Argv[1]);
LastError = ERROR_FILE_NOT_FOUND; LastError = ERROR_FILE_NOT_FOUND;
} }
if (wcstoul(Argv[2], NULL, 16)) if (wcstoul(Argv[2], NULL, 16))
@ -305,14 +305,14 @@ static _Return_type_success_(return != FALSE) BOOL DeleteAdapterViaRundll32(
DWORD LastError; DWORD LastError;
if (!ExecuteRunDll32(Arguments, Response, _countof(Response))) if (!ExecuteRunDll32(Arguments, Response, _countof(Response)))
{ {
LOG(WINTUN_LOG_ERR, L"Error executing worker process"); LOG(WINTUN_LOG_ERR, L"Error executing worker process: %s", Arguments);
return FALSE; return FALSE;
} }
int Argc; int Argc;
WCHAR **Argv = CommandLineToArgvW(Response, &Argc); WCHAR **Argv = CommandLineToArgvW(Response, &Argc);
if (Argc < 2) if (Argc < 2)
{ {
LOG(WINTUN_LOG_ERR, L"Incomplete or invalid response"); LOG(WINTUN_LOG_ERR, L"Incomplete or invalid response: %s", Response);
LastError = ERROR_INVALID_PARAMETER; LastError = ERROR_INVALID_PARAMETER;
goto cleanupArgv; goto cleanupArgv;
} }
@ -340,14 +340,14 @@ static _Return_type_success_(return != FALSE) BOOL
DWORD LastError; DWORD LastError;
if (!ExecuteRunDll32(Arguments, Response, _countof(Response))) if (!ExecuteRunDll32(Arguments, Response, _countof(Response)))
{ {
LOG(WINTUN_LOG_ERR, L"Error executing worker process"); LOG(WINTUN_LOG_ERR, L"Error executing worker process: %s", Arguments);
return FALSE; return FALSE;
} }
int Argc; int Argc;
WCHAR **Argv = CommandLineToArgvW(Response, &Argc); WCHAR **Argv = CommandLineToArgvW(Response, &Argc);
if (Argc < 2) if (Argc < 2)
{ {
LOG(WINTUN_LOG_ERR, L"Incomplete or invalid response"); LOG(WINTUN_LOG_ERR, L"Incomplete or invalid response: %s", Response);
LastError = ERROR_INVALID_PARAMETER; LastError = ERROR_INVALID_PARAMETER;
goto cleanupArgv; goto cleanupArgv;
} }

View File

@ -83,7 +83,7 @@ _Return_type_success_(return != NULL) TUN_SESSION *WINAPI
BYTE *AllocatedRegion = VirtualAlloc(0, (size_t)RingSize * 2, MEM_COMMIT | MEM_RESERVE, PAGE_READWRITE); BYTE *AllocatedRegion = VirtualAlloc(0, (size_t)RingSize * 2, MEM_COMMIT | MEM_RESERVE, PAGE_READWRITE);
if (!AllocatedRegion) if (!AllocatedRegion)
{ {
LastError = LOG_LAST_ERROR(L"Failed to allocate ring memory"); LastError = LOG_LAST_ERROR(L"Failed to allocate ring memory (requested size: 0x%zx)", (size_t)RingSize * 2);
goto cleanupRings; goto cleanupRings;
} }
if (!ElevateToSystem()) if (!ElevateToSystem())