Log security error automatically

Log the error automatically when the signature & cetification verification fails:

1. Write error log (the security part) into %LOCALUSERDATA%\WinGUp\log\securityError.log, and add "-errLogPath=" argument to make it overridable.
2. Add the download URL + sha256 value of the downloaded file in the log.
3. Log also if the download URL is not what we expected.

Fix #98, close #100

Author: donho

src/Common.cpp

@@ -23,15 +23,146 @@
 
 using namespace std;
 
-void writeLog(const wchar_t* logFileName, const wchar_t* logSuffix, const wchar_t* log2write)
+void expandEnv(wstring& s)
+{
+	wchar_t buffer[MAX_PATH] = { '\0' };
+	// This returns the resulting string length or 0 in case of error.
+	DWORD ret = ExpandEnvironmentStrings(s.c_str(), buffer, static_cast<DWORD>(std::size(buffer)));
+	if (ret != 0)
+	{
+		if (ret == static_cast<DWORD>(lstrlen(buffer) + 1))
+		{
+			s = buffer;
+		}
+		else
+		{
+			// Buffer was too small, try with a bigger buffer of the required size.
+			std::vector<wchar_t> buffer2(ret, 0);
+			ret = ExpandEnvironmentStrings(s.c_str(), buffer2.data(), static_cast<DWORD>(buffer2.size()));
+			s = buffer2.data();
+		}
+	}
+}
+
+namespace
+{
+	constexpr wchar_t timeFmtEscapeChar = 0x1;
+	constexpr wchar_t middayFormat[] = L"tt";
+
+	// Returns AM/PM string defined by the system locale for the specified time.
+	// This string may be empty or customized.
+	wstring getMiddayString(const wchar_t* localeName, const SYSTEMTIME& st)
+	{
+		wstring midday;
+		midday.resize(MAX_PATH);
+		int ret = GetTimeFormatEx(localeName, 0, &st, middayFormat, &midday[0], static_cast<int>(midday.size()));
+		if (ret > 0)
+			midday.resize(ret - 1); // Remove the null-terminator.
+		else
+			midday.clear();
+		return midday;
+	}
+
+	// Replaces conflicting time format specifiers by a special character.
+	bool escapeTimeFormat(wstring& format)
+	{
+		bool modified = false;
+		for (auto& ch : format)
+		{
+			if (ch == middayFormat[0])
+			{
+				ch = timeFmtEscapeChar;
+				modified = true;
+			}
+		}
+		return modified;
+	}
+
+	// Replaces special time format characters by actual AM/PM string.
+	void unescapeTimeFormat(wstring& format, const wstring& midday)
+	{
+		if (midday.empty())
+		{
+			auto it = std::remove(format.begin(), format.end(), timeFmtEscapeChar);
+			if (it != format.end())
+				format.erase(it, format.end());
+		}
+		else
+		{
+			size_t i = 0;
+			while ((i = format.find(timeFmtEscapeChar, i)) != wstring::npos)
+			{
+				if (i + 1 < format.size() && format[i + 1] == timeFmtEscapeChar)
+				{
+					// 'tt' => AM/PM
+					format.erase(i, std::size(middayFormat) - 1);
+					format.insert(i, midday);
+				}
+				else
+				{
+					// 't' => A/P
+					format[i] = midday[0];
+				}
+			}
+		}
+	}
+}
+
+wstring getDateTimeStrFrom(const wstring& dateTimeFormat, const SYSTEMTIME& st)
+{
+	const wchar_t* localeName = LOCALE_NAME_USER_DEFAULT;
+	const DWORD flags = 0;
+
+	constexpr int bufferSize = MAX_PATH;
+	wchar_t buffer[bufferSize] = {};
+	int ret = 0;
+
+
+	// 1. Escape 'tt' that means AM/PM or 't' that means A/P.
+	// This is needed to avoid conflict with 'M' date format that stands for month.
+	wstring newFormat = dateTimeFormat;
+	const bool hasMiddayFormat = escapeTimeFormat(newFormat);
+
+	// 2. Format the time (h/m/s/t/H).
+	ret = GetTimeFormatEx(localeName, flags, &st, newFormat.c_str(), buffer, bufferSize);
+	if (ret != 0)
+	{
+		// 3. Format the date (d/y/g/M). 
+		// Now use the buffer as a format string to process the format specifiers not recognized by GetTimeFormatEx().
+		ret = GetDateFormatEx(localeName, flags, &st, buffer, buffer, bufferSize, nullptr);
+	}
+
+	if (ret != 0)
+	{
+		if (hasMiddayFormat)
+		{
+			// 4. Now format only the AM/PM string.
+			const wstring midday = getMiddayString(localeName, st);
+			wstring result = buffer;
+			unescapeTimeFormat(result, midday);
+			return result;
+		}
+		return buffer;
+	}
+
+	return {};
+}
+
+void writeLog(const wchar_t* logFileName, const wchar_t* logPrefix, const wchar_t* log2write)
 {
 	FILE* f = _wfopen(logFileName, L"a+, ccs=UTF-16LE");
 	if (f)
 	{
-		wstring log = logSuffix;
-		log += log2write;
-		log += L'\n';
-		fwrite(log.c_str(), sizeof(log.c_str()[0]), log.length(), f);
+		SYSTEMTIME currentTime = {};
+		::GetLocalTime(&currentTime);
+		wstring log2writeStr = getDateTimeStrFrom(L"yyyy-MM-dd HH:mm:ss", currentTime);
+
+		log2writeStr += L"  ";
+		log2writeStr += logPrefix;
+		log2writeStr += L" ";
+		log2writeStr += log2write;
+		log2writeStr += L'\n';
+		fwrite(log2writeStr.c_str(), sizeof(log2writeStr.c_str()[0]), log2writeStr.length(), f);
 		fflush(f);
 		fclose(f);
 	}

src/Common.h

@@ -18,6 +18,8 @@
 
 #include <string>
 
+void expandEnv(std::wstring& s);
+std::wstring getDateTimeStrFrom(const std::wstring& dateTimeFormat, const SYSTEMTIME& st);
 void writeLog(const wchar_t* logFileName, const wchar_t* logSuffix, const wchar_t* log2write);
 std::wstring s2ws(const std::string& str);
 std::string ws2s(const std::wstring& wstr);

src/verifySignedfile.cpp

@@ -26,27 +26,49 @@
 #include <sensapi.h>
 #include <iomanip>
 #include <sstream>
+#include <shlwapi.h>
+#include <shlobj_core.h>
 #include "verifySignedfile.h"
-#include "Common.h"
+
 
 using namespace std;
 
 
 // Debug use
 bool doLogCertifError = false;
 
+void SecurityGuard::writeSecurityError(const std::wstring& prefix, const std::wstring& log2write) const
+{
+	// Expand the environment variable
+	wstring expandedLogFileName = _errLogPath;
+	expandEnv(expandedLogFileName);
+
+	// Create the folder & sub-folders for the log file
+	wchar_t logDir[MAX_PATH];
+	lstrcpy(logDir, expandedLogFileName.c_str());
+	::PathRemoveFileSpec(logDir);
+	int result = SHCreateDirectoryEx(NULL, logDir, NULL);
+
+	// If folder doesn't exit or folder creation failed
+	if (result != ERROR_SUCCESS && result != ERROR_ALREADY_EXISTS)
+	{
+		// process %TEMP% treatment
+		wchar_t* fileName = ::PathFindFileName(expandedLogFileName.c_str());
+		expandedLogFileName = L"%TEMP%\\";
+		expandedLogFileName += fileName;
+		expandEnv(expandedLogFileName);
+	}
+
+	writeLog(expandedLogFileName.c_str(), prefix.c_str(), log2write.c_str());
+}
+
 bool SecurityGuard::verifySignedBinary(const std::wstring& filepath)
 {
 	wstring display_name;
 	wstring key_id_hex;
 	wstring subject;
 	wstring authority_key_id_hex;
 
-	if (doLogCertifError)
-	{
-		writeLog(L"c:\\tmp\\certifError.log", L"verifySignedBinary: ", filepath.c_str());
-	}
-
 	//
 	// Signature verification
 	//
@@ -69,9 +91,6 @@ bool SecurityGuard::verifySignedBinary(const std::wstring& filepath)
 	if (!_doCheckRevocation)
 	{
 		winTEXTrust_data.fdwRevocationChecks = WTD_REVOKE_NONE;
-
-		if (doLogCertifError)
-			writeLog(L"c:\\tmp\\certifError.log", L"verifySignedBinary: ", L"certificate revocation checking is disabled");
 	}
 	else
 	{
@@ -87,9 +106,6 @@ bool SecurityGuard::verifySignedBinary(const std::wstring& filepath)
 		if (!online)
 		{
 			winTEXTrust_data.fdwRevocationChecks = WTD_REVOKE_NONE;
-
-			if (doLogCertifError)
-				writeLog(L"c:\\tmp\\certifError.log", L"verifySignedBinary: ", L"system is offline - certificate revocation won't be checked");
 		}
 	}
 
@@ -105,17 +121,13 @@ bool SecurityGuard::verifySignedBinary(const std::wstring& filepath)
 
 		if (vtrust)
 		{
-			if (doLogCertifError)
-				writeLog(L"c:\\tmp\\certifError.log", L"verifySignedBinary: ", L"trust verification failed");
-
+			writeSecurityError(filepath.c_str(), L": chain of trust verification failed");
 			return false;
 		}
 
 		if (t2)
 		{
-			if (doLogCertifError)
-				writeLog(L"c:\\tmp\\certifError.log", L"verifySignedBinary: ", L"error encountered while cleaning up after WinVerifyTrust");
-
+			writeSecurityError(filepath.c_str(), L": error encountered while cleaning up after WinVerifyTrust");
 			return false;
 		}
 	}
@@ -206,9 +218,6 @@ bool SecurityGuard::verifySignedBinary(const std::wstring& filepath)
 		}
 		key_id_hex = ss.str();
 
-		if (doLogCertifError)
-			writeLog(L"c:\\tmp\\certifError.log", L"verifySignedBinary: ", key_id_hex.c_str());
-
 		// Getting the display name
 		auto sze = ::CertGetNameString(context, CERT_NAME_SIMPLE_DISPLAY_TYPE, 0, NULL, NULL, 0);
 		if (sze <= 1)
@@ -265,63 +274,44 @@ bool SecurityGuard::verifySignedBinary(const std::wstring& filepath)
 				LocalFree(pAuthKeyIdInfo);
 			}
 		}
-		else
-		{
-			// Authority Key Identifier extension not found
-			if (doLogCertifError)
-				writeLog(L"c:\\tmp\\certifError.log", L"Authority Key ID: ", L"Extension not found");
-		}
 		// --- End AKI Retrieval ---
 
 	}
 	catch (const string& s) {
-		if (doLogCertifError)
-		{
-			writeLog(L"c:\\tmp\\certifError.log", L" verifySignedBinary: error while getting certificate information: ", s2ws(s).c_str());
-		}
+		writeSecurityError((filepath + L" - error while getting certificate information: ").c_str(), s2ws(s).c_str());
 		status = false;
 	}
 	catch (...) {
 		// Unknown error
-		if (doLogCertifError)
-			writeLog(L"c:\\tmp\\certifError.log", L"verifySignedBinary: ", L"error while getting certificate information");
-
+		writeSecurityError(filepath.c_str(), L": Unknow error while getting certificate information");
 		status = false;
 	}
 
 	//
-	// fields verifications - if status is true, and string to compare (from the parameter) is not empty, then do compare
+	// fields verifications - if status is true, and demaded parameter string to compare (from the parameter) is not empty, then do compare
 	//
 	if (status &&  (!_signer_display_name.empty() && _signer_display_name != display_name))
 	{
 		status = false;
-
-		if (doLogCertifError)
-			writeLog(L"c:\\tmp\\certifError.log", L"verifySignedBinary: ", L"Invalid certificate display name");
+		writeSecurityError(filepath.c_str(), display_name + L": Invalid certificate display name");
 	}
 
 	if (status && (!_signer_subject.empty() && _signer_subject != subject))
 	{
 		status = false;
-
-		if (doLogCertifError)
-			writeLog(L"c:\\tmp\\certifError.log", L"verifySignedBinary: ", L"Invalid certificate subject");
+		writeSecurityError(filepath.c_str(), subject + L": Invalid certificate subject");
 	}
 
 	if (status && (!_signer_key_id.empty() && stringToUpper(_signer_key_id) != key_id_hex))
 	{
 		status = false;
-
-		if (doLogCertifError)
-			writeLog(L"c:\\tmp\\certifError.log", L"verifySignedBinary: ", L"Invalid certificate key id");
+		writeSecurityError(filepath.c_str(), key_id_hex + L": Invalid certificate key id");
 	}
 
 	if (status && (!_authority_key_id.empty() && stringToUpper(_authority_key_id) != authority_key_id_hex))
 	{
 		status = false;
-
-		if (doLogCertifError)
-			writeLog(L"c:\\tmp\\certifError.log", L"verifySignedBinary: ", L"Invalid authority key id");
+		writeSecurityError(filepath.c_str(), authority_key_id_hex + L": Invalid authority key id");
 	}
 
 	// Clean up.

src/verifySignedfile.h

@@ -47,6 +47,7 @@
 
 #include <string>
 #include <vector>
+#include "Common.h"
 
 class SecurityGuard final
 {
@@ -61,6 +62,11 @@ class SecurityGuard final
 	void setKeyId(const std::wstring& signer_key_id) { _signer_key_id = signer_key_id; }
 	void setAuthorityKeyId(const std::wstring& authority_key_id) { _authority_key_id = authority_key_id; }
 
+	void setErrLogPath(std::wstring& errLogPath) { _errLogPath = errLogPath; }
+	std::wstring errLogPath() const { return _errLogPath; }
+
+	void writeSecurityError(const std::wstring& prefix, const std::wstring& log2write) const;
+
 private:
 	// Code signing certificate
 	std::wstring _signer_display_name; // = L"Notepad++"
@@ -70,5 +76,7 @@ class SecurityGuard final
 
 	bool _doCheckRevocation = false;
 	bool _doCheckChainOfTrust = false;
+
+	std::wstring _errLogPath = L"%LOCALAPPDATA%\\WinGUp\\log\\securityError.log"; // By default, but overrideable
 };