OrcLib: update some log messages

DFIR-ORC · Dec 1, 2020 · d30d2db · d30d2db
1 parent 245004f
commit d30d2db
Show file tree

Hide file tree

Showing 10 changed files with 77 additions and 36 deletions.
diff --git a/src/OrcCommand/WolfExecution_Config.cpp b/src/OrcCommand/WolfExecution_Config.cpp
@@ -808,11 +808,15 @@ HRESULT WolfExecution::SetRepeatBehaviour(const Repeat behavior)
     return S_OK;
 }
 
-HRESULT WolfExecution::SetCompressionLevel(const std::wstring& strCompressionLevel)
+HRESULT WolfExecution::SetCompressionLevel(const std::wstring& level)
 {
-    if (strCompressionLevel.empty())
+    if (level.empty())
+    {
+        Log::Debug(L"Specified compression level is empty");
         return S_OK;
+    }
 
-    m_strCompressionLevel = strCompressionLevel;
+    Log::Debug(L"Set compression level to {}", level);
+    m_strCompressionLevel = level;
     return S_OK;
 }
diff --git a/src/OrcCommand/WolfLauncher_Config.cpp b/src/OrcCommand/WolfLauncher_Config.cpp
@@ -693,6 +693,8 @@ HRESULT Main::CheckConfiguration()
 
         if (!config.strCompressionLevel.empty())
         {
+            Log::Debug(
+                L"Command has no compression level, using main compression level: {}", config.strCompressionLevel);
             wolfexec->SetCompressionLevel(config.strCompressionLevel);
         }
 

diff --git a/src/OrcLib/Archive/7z/Archive7z.cpp b/src/OrcLib/Archive/7z/Archive7z.cpp
@@ -107,12 +107,14 @@ Lib7zCompressionLevel ToLib7zLevel(CompressionLevel level)
 
 void SetCompressionLevel(const CComPtr<IOutArchive>& archiver, CompressionLevel level, std::error_code& ec)
 {
+    Log::Debug("Archive7z: SetCompressionLevel to {}", level);
+
     CMyComPtr<ISetProperties> setProperties;
     HRESULT hr = archiver->QueryInterface(IID_ISetProperties, (void**)&setProperties);
     if (setProperties == nullptr)
     {
         ec.assign(hr, std::system_category());
-        // TODO: spdlog::warn("Failed retrieve IID_ISetProperties: {}", ec.message());
+        Log::Error("Failed to set compresion level on IID_ISetProperties [{}]", ec);
         return;
     }
 
@@ -124,7 +126,7 @@ void SetCompressionLevel(const CComPtr<IOutArchive>& archiver, CompressionLevel
     if (FAILED(hr))
     {
         ec.assign(hr, std::system_category());
-        // TODO: spdlog::warn("Failed to set property: {}", ec.message());
+        Log::Error("Failed to change compresion level while setting property [{}]", ec);
         return;
     }
 }
@@ -168,14 +170,14 @@ void Archive7z::Compress(
     if (FAILED(hr))
     {
         ec.assign(hr, std::system_category());
-        // TODO: spdlog::debug("Failed to get IID_IOutArchive: {}", ec.message());
+        Log::Error(L"Failed to retrieve IID_IOutArchive [{}]", ec);
         return;
     }
 
     ::SetCompressionLevel(archiver, m_compressionLevel, ec);
     if (ec)
     {
-        // TODO: spdlog::debug("Failed to update compression level");
+        Log::Error(L"Failed to update compression level to {} [{}]", m_compressionLevel, ec);
         return;
     }
 
@@ -186,15 +188,15 @@ void Archive7z::Compress(
         if (FAILED(hr))
         {
             ec.assign(hr, std::system_category());
-            // TODO: log::Error(_L_, hr, L"Temp archive stream cannot be read\r\n");
+            Log::Error(L"Failed to read 'inputArchive' [{}]", ec);
             return;
         }
 
         hr = inputArchive->SetFilePointer(0LL, FILE_BEGIN, NULL);
         if (FAILED(hr))
         {
             ec.assign(hr, std::system_category());
-            // TODO: log::Error(_L_, hr, L"Failed to rewind Temp stream\r\n");
+            Log::Error(L"Failed to seek input archive to the begining [{}]", ec);
             return;
         }
 
@@ -205,14 +207,15 @@ void Archive7z::Compress(
         if (FAILED(hr))
         {
             ec.assign(hr, std::system_category());
-            // TODO: log::Error(_L_, hr, L"Failed to open archive stream\r\n");
+            Log::Error(L"Failed to open input archive [{}]", ec);
             return;
         }
 
         hr = archiverIn->GetNumberOfItems(&numberOfArchivedItems);
         if (FAILED(hr))
         {
             ec.assign(hr, std::system_category());
+            Log::Error(L"Failed to retrieve number of items [{}]", ec);
             return;
         }
     }
@@ -229,7 +232,7 @@ void Archive7z::Compress(
     if (FAILED(hr))
     {
         ec.assign(hr, std::system_category());
-        // TODO: spdlog::debug("Failed to compress: {}", ec.message());
+        Log::Error("Failed to update archive [{}]", ec);
         return;
     }
 

diff --git a/src/OrcLib/Archive/7z/ArchiveUpdateCallback.cpp b/src/OrcLib/Archive/7z/ArchiveUpdateCallback.cpp
@@ -11,8 +11,10 @@
 #include "Archive/7z/ArchiveUpdateCallback.h"
 
 #include "Archive/7z/InStreamAdapter.h"
+#include "Utils/Result.h"
 
 using namespace Orc::Archive;
+using namespace Orc;
 
 namespace {
 
@@ -25,7 +27,7 @@ FILETIME NowTimestamp()
     BOOL ret = SystemTimeToFileTime(&st, &ft);
     if (ret == FALSE)
     {
-        // TODO: add log
+        Log::Error("Failed to convert SystemTime to FileTime [{}]", LastWin32Error());
         return {0};
     }
 
@@ -34,6 +36,9 @@ FILETIME NowTimestamp()
 
 }  // namespace
 
+namespace Orc {
+namespace Archive {
+
 ArchiveUpdateCallback::ArchiveUpdateCallback(Items items, std::wstring password, uint64_t numberOfInputArchiveItems)
     : m_newItems(std::move(items))
     , m_password(std::move(password))
@@ -235,7 +240,7 @@ STDMETHODIMP ArchiveUpdateCallback::SetOperationResult(Int32 operationResult)
 
     if (operationResult != NArchive::NUpdate::NOperationResult::kOK)
     {
-        // TODO: add log
+        Log::Error("Failure code for operation result");
         m_ec.assign(E_FAIL, std::system_category());
     }
 
@@ -280,3 +285,6 @@ STDMETHODIMP ArchiveUpdateCallback::CryptoGetTextPassword2(Int32* pPasswordIsDef
 
     return S_OK;
 }
+
+}  // namespace Archive
+}  // namespace Orc
diff --git a/src/OrcLib/Archive/Appender.h b/src/OrcLib/Archive/Appender.h
@@ -44,13 +44,15 @@ class Appender
             const auto tempPath = GetTempPathApi(ec);
             if (ec)
             {
+                Log::Error("Failed to get temporary path [{}]", ec);
                 return {};
             }
 
             HRESULT hr = tempStreams[i]->Open(tempPath.c_str(), L"", bufferSize, kDontReleaseOnClose);
             if (FAILED(hr))
             {
                 ec.assign(hr, std::system_category());
+                Log::Error(L"Failed to open temporary path {} [{}]", tempPath, ec);
                 return {};
             }
         }
@@ -106,20 +108,23 @@ class Appender
         m_archiver.Compress(dstStream, srcStream, ec);
         if (ec)
         {
+            Log::Error("Failed to compress stream [{}]", ec);
             return;
         }
 
         HRESULT hr = srcStream->SetFilePointer(0, FILE_BEGIN, nullptr);
         if (FAILED(hr))
         {
             ec.assign(hr, std::system_category());
+            Log::Error("Failed to seek source stream [{}]", ec);
             return;
         }
 
         hr = srcStream->SetSize(0);
         if (FAILED(hr))
         {
             ec.assign(hr, std::system_category());
+            Log::Error("Failed to resize source stream [{}]", ec);
             return;
         }
 
@@ -137,15 +142,16 @@ class Appender
         Flush(ec);
         if (ec)
         {
+            Log::Error("Failed to flush stream [{}]", ec);
             return;
         }
 
         auto& tempStream = m_tempStreams[m_srcStreamIndex];
         HRESULT hr = tempStream->MoveTo(m_output.c_str());
         if (FAILED(hr))
         {
-            // TODO: add log
             ec.assign(hr, std::system_category());
+            Log::Error(L"Failed to move stream to {} [{}]", m_output, ec);
             return;
         }
     }

diff --git a/src/OrcLib/FileStream.cpp b/src/OrcLib/FileStream.cpp
@@ -244,8 +244,6 @@ __data_entrypoint(File) HRESULT FileStream::Read(
         return hr;
     }
 
-    Log::Trace(L"ReadFile read {} bytes (hFile: {:p})", dwBytesRead, m_hFile);
-
     *pcbBytesRead = dwBytesRead;
     return S_OK;
 }

diff --git a/src/OrcLib/PipeStream.cpp b/src/OrcLib/PipeStream.cpp
@@ -64,7 +64,7 @@ __data_entrypoint(File) HRESULT PipeStream::Read(
             return hr;
         }
     }
-    Log::Debug("ReadFile read {} bytes (hFile={:p})", dwBytesRead, m_hReadPipe);
+
     *pcbBytesRead = dwBytesRead;
     return S_OK;
 }

diff --git a/src/OrcLib/ProfileList.cpp b/src/OrcLib/ProfileList.cpp
@@ -68,11 +68,11 @@ ProfileResult ProfileList::GetProfiles()
             auto rSID = Registry::Read<ByteBuffer>(hKey, keyName.get(), L"Sid");
             if (rSID.has_error())
             {
-                Log::Debug(L"Failed to read SID for profile {}, using key name", keyName.get());
+                Log::Warn(L"Failed to read SID for profile using key name: '{}'", keyName.get());
                 PSID pSID = NULL;
                 if (!ConvertStringSidToSidW(keyName.get(), &pSID))
                 {
-                    Log::Debug(L"Failed profile key name {} is not a valid sid", keyName.get());
+                    Log::Error(L"Failed to convert to SID the key '{}'", keyName.get());
                     continue;
                 }
                 sid.assign((LPBYTE)pSID, GetLengthSid(pSID));

diff --git a/src/OrcLib/Registry.cpp b/src/OrcLib/Registry.cpp
@@ -25,7 +25,7 @@ Result<ULONG32> Orc::Registry::Read<ULONG32>(HKEY hParentKey, LPWSTR szKeyName,
             status != ERROR_SUCCESS)
         {
             const auto ec = Win32Error(status);
-            Log::Error(L"Failed to registry key {} [{}]", szKeyName, ec);
+            Log::Debug(L"Failed to open registry key {} [{}]", szKeyName, ec);
             return ec;
         }
     }
@@ -53,12 +53,12 @@ Result<ULONG32> Orc::Registry::Read<ULONG32>(HKEY hParentKey, LPWSTR szKeyName,
 
         if (status == ERROR_MORE_DATA)
         {
-            Log::Error(L"Unexepected registry value '{}' is bigger than expected (ULONG32)", szValueName);
+            Log::Error(L"Unexpected registry value '{}' is bigger than expected (ULONG32)", szValueName);
             return ec;
         }
         else
         {
-            Log::Error(L"Failed to open registry '{}' value [{}]", szValueName, ec);
+            Log::Debug(L"Failed to open registry value '{}' [{}]", szValueName, ec);
             return ec;
         }
     }
@@ -69,7 +69,7 @@ Result<ULONG32> Orc::Registry::Read<ULONG32>(HKEY hParentKey, LPWSTR szKeyName,
 
     if (dwValueType != REG_DWORD || (dwValueType != REG_BINARY && cbBytes != sizeof(ULONG32)))
     {
-        Log::Error(L"Unexpected value \"{}\" type (not ULONG32 compatible)", szValueName);
+        Log::Error(L"Unexpected value '{}' type (not ULONG32 compatible)", szValueName);
         return Win32Error(ERROR_DATATYPE_MISMATCH);
     }
 
@@ -87,7 +87,7 @@ Result<ULONG64> Orc::Registry::Read<ULONG64>(HKEY hParentKey, LPWSTR szKeyName,
             status != ERROR_SUCCESS)
         {
             const auto ec = Win32Error(status);
-            Log::Error(L"Failed to registry key {} [{}]", szKeyName, ec);
+            Log::Error(L"Failed to open registry key {} [{}]", szKeyName, ec);
             return ec;
         }
     }
@@ -114,12 +114,12 @@ Result<ULONG64> Orc::Registry::Read<ULONG64>(HKEY hParentKey, LPWSTR szKeyName,
         const auto ec = Win32Error(status);
         if (status == ERROR_MORE_DATA)
         {
-            Log::Error(L"Unexepected registry value '{}' is bigger than expected (ULONG32)", szValueName);
+            Log::Error(L"Unexpected registry value '{}' is bigger than expected (ULONG32)", szValueName);
             return ec;
         }
         else
         {
-            Log::Error(L"Failed to open registry '{}' value [{}]", szValueName, ec);
+            Log::Debug(L"Failed to query registry '{}' value [{}]", szValueName, ec);
             return ec;
         }
     }
@@ -129,7 +129,7 @@ Result<ULONG64> Orc::Registry::Read<ULONG64>(HKEY hParentKey, LPWSTR szKeyName,
     }
     if (dwValueType != REG_QWORD || (dwValueType != REG_BINARY && cbBytes != sizeof(ULONG64)))
     {
-        Log::Error(L"Unexpected value \"{}\" type (not ULONG32 compatible)", szValueName);
+        Log::Error(L"Unexpected value '{}' type (not ULONG32 compatible)", szValueName);
         return Win32Error(ERROR_DATATYPE_MISMATCH);
     }
 
@@ -147,7 +147,7 @@ Result<Orc::ByteBuffer> Orc::Registry::Read<Orc::ByteBuffer>(HKEY hParentKey, LP
             status != ERROR_SUCCESS)
         {
             const auto ec = Win32Error(status);
-            Log::Error(L"Failed to registry key {} [{}]", szKeyName, ec);
+            Log::Debug(L"Failed to open registry key {} [{}]", szKeyName, ec);
             return ec;
         }
     }
@@ -178,14 +178,15 @@ Result<Orc::ByteBuffer> Orc::Registry::Read<Orc::ByteBuffer>(HKEY hParentKey, LP
             if (auto status = RegQueryValueExW(hKey, szValueName, NULL, NULL, (LPBYTE)valueBuffer.get(), &cbBytes);
                 status != ERROR_SUCCESS)
             {
-                Log::Error(L"Failed to reg value '{}:{}' value [{}]", szKeyName ? szKeyName : L"", szValueName, ec);
+                Log::Debug(
+                    L"Failed to query registry value '{}:{}' value [{}]", szKeyName ? szKeyName : L"", szValueName, ec);
                 return ec;
             }
         }
         else
         {
-            Log::Error(
-                L"Failed to query registry value \"{}:{}\" value [{}]", szKeyName ? szKeyName : L"", szValueName, ec);
+            Log::Debug(
+                L"Failed to query registry value '{}:{}' value [{}]", szKeyName ? szKeyName : L"", szValueName, ec);
             return ec;
         }
     }
@@ -207,7 +208,7 @@ Result<std::wstring> Orc::Registry::Read<std::wstring>(HKEY hParentKey, LPWSTR s
             status != ERROR_SUCCESS)
         {
             const auto result = Win32Error(status);
-            Log::Error(L"Failed to registry key '{}' [{}]", szKeyName, result);
+            Log::Error(L"Failed to open registry key '{}' [{}]", szKeyName, result);
             return result;
         }
     }
@@ -238,13 +239,13 @@ Result<std::wstring> Orc::Registry::Read<std::wstring>(HKEY hParentKey, LPWSTR s
             if (auto status = RegQueryValueExW(hKey, szValueName, NULL, NULL, (LPBYTE)valueBuffer.get(), &cbBytes);
                 status != ERROR_SUCCESS)
             {
-                Log::Error(L"Failed to reg value '{}' value [{}])", szValueName, ec);
+                Log::Debug(L"Failed to query registry value '{}' value [{}])", szValueName, ec);
                 return ec;
             }
         }
         else
         {
-            Log::Error(L"Failed to open profile list '{}' value [{}]", szValueName, ec);
+            Log::Debug(L"Failed to query registry value '{}' [{}]", szValueName, ec);
             return ec;
         }
     }