Merge pull request #109 from Neo23x0/refactor-logging

Refactor logging

README.md

@@ -204,6 +204,12 @@ An entry is generated by every blocking event in the `Application` eventlog.
 
 ![Eventlog](https://raw.githubusercontent.com/Neo23x0/Raccine/main/images/eventlog2.png)
 
+The IDs that Raccine generates
+
+- EventId 1 - Setup activity
+- EventId 2 - Malicious activity detected
+- EventId 3 - Benign activity detected
+
 ## Simulation Mode
 
 Since version 0.10.0, Raccine can be installed in "simulation mode", which activates all triggers, logs all actions but doesn't kill anything. This mode should be used in environments in which backup solutions or other legitimate software for a reasonable amount of time to check if Raccine would interfere with other software. The idea is to install Raccine in simulation mode, let it log for a week or month and then check the logs to see if it would have blocked legitimate software used in the organisation. 

install-raccine.bat

@@ -132,7 +132,6 @@ COPY RaccineRulesSync.exe "%ProgramFiles%\Raccine\"
 COPY Raccine%ARCH%.exe "%ProgramFiles%\Raccine\Raccine.exe"
 COPY yara\yara%ARCHITECTURE_SUFFIX%.exe "%ProgramFiles%\Raccine\"
 COPY yara\yarac%ARCHITECTURE_SUFFIX%.exe "%ProgramFiles%\Raccine\"
-
 :: YARA Rules
 MKDIR "%ProgramFiles%\Raccine\yara"
 MKDIR "%ProgramFiles%\Raccine\yara\in-memory"
@@ -148,8 +147,9 @@ ECHO Creating empty log file ...
 echo. 2>"%ProgramData%\Raccine\Raccine_log.txt"
 icacls "%ProgramData%\Raccine\Raccine_log.txt" /grant Users:F
 ECHO Registering Eventlog Events
-eventcreate.exe /L Application /T Information /id 1 /so Raccine /d "Raccine Setup: Registration of Event ID 1" 2> nul
-eventcreate.exe /L Application /T Information /id 2 /so Raccine /d "Raccine Setup: Registration of Event ID 2" 2> nul
+eventcreate.exe /L Application /T Information /id 1 /so Raccine /d "Raccine Setup: Registration of Event ID 1 - Used for Informational Messages" 2> nul
+eventcreate.exe /L Application /T Information /id 2 /so Raccine /d "Raccine Setup: Registration of Event ID 2 - Used for Malicious Actitivty" 2> nul
+eventcreate.exe /L Application /T Information /id 3 /so Raccine /d "Raccine Setup: Registration of Event ID 3 - Used for Benign Activity" 2> nul
 :: Registry Settings
 REG.EXE ADD HKLM\Software\Raccine /v ShowGui /t REG_DWORD /d 1 /F
 REG.EXE ADD HKLM\Software\Raccine /v ScanMemory /t REG_DWORD /d 1 /F

robot-tests/robot-tests.ps1

@@ -133,7 +133,7 @@ Foreach ($Cmd in $GoodCmds) {
 
     # Eventlog
     $Result = Get-EventLog -LogName Application -Message *Raccine* -Newest 1
-    If ( $Result.Message -Match $Cmd ) { 
+    If ( $Result.Message -Match $Cmd -and $Result.Message -Match 'malicious') { 
         Write-Host $Result.Message
         Write-Host "Error: Eventlog entry of detection found"
         exit 1 

source/Raccine/raccine.cpp

@@ -104,6 +104,7 @@ int wmain(int argc, WCHAR* argv[])
             std::wstring message;
             // Eventlog
             message = L"Raccine detected benign activity:\r\n" + sCommandLine + L"\r\n(simulation mode)";
+            WriteEventLogEntryWithId(message, RACCINE_EVENTID_BENIGN_ACTIVITY);
             // Log to the text log file
             sListLogs.append(logFormat(sCommandLine, L"Raccine detected benign activity (simulation mode)"));
         }

source/RaccineLib/Raccine.h

@@ -20,6 +20,7 @@
 // Log Config and Flags
 #define RACCINE_DEFAULT_EVENTID  1
 #define RACCINE_EVENTID_MALICIOUS_ACTIVITY  2
+#define RACCINE_EVENTID_BENIGN_ACTIVITY  3
 
 #define RACCINE_DATA_DIRECTORY  L"%PROGRAMDATA%\\Raccine"
 #define RACCINE_YARA_DIRECTORY  L"%PROGRAMFILES%\\Raccine\\yara"

source/RaccineLib/Utils.cpp

@@ -534,4 +534,11 @@ std::wstring getFileName(const std::wstring& s)
     return(s);
 }
 
+int removeNewLines(std::wstring& str)
+{
+    std::replace(str.begin(), str.end(), L'\r', L' ');
+    std::replace(str.begin(), str.end(), L'\n', L' ');
+    return 0;
+}
+
 }

source/RaccineLib/Utils.h

@@ -74,4 +74,6 @@ DWORD getCurrentSessionId();
 
 std::wstring getUserSid();
 
+int removeNewLines(std::wstring& str);
+
 }

source/RaccineLib/raccine.cpp

@@ -123,10 +123,16 @@ void WriteEventLogEntryWithId(const std::wstring& pszMessage, DWORD dwEventId)
 
     LPCWSTR lpszStrings[2] = { pszMessage.c_str() , nullptr };
 
+    // Select an eventlog message type
+    WORD eventType = EVENTLOG_INFORMATION_TYPE;
+    if (dwEventId == RACCINE_EVENTID_MALICIOUS_ACTIVITY) {
+        eventType = EVENTLOG_WARNING_TYPE;
+    }
+
     constexpr PSID NO_USER_SID = nullptr;
     constexpr LPVOID NO_BINARY_DATA = nullptr;
-    ReportEventW(hEventSource,               // Event log handle
-        EVENTLOG_INFORMATION_TYPE,  // Event type
+    ReportEventW(hEventSource,      // Event log handle
+        eventType,                  // Event type
         0,                          // Event category
         dwEventId,                  // Event identifier
         NO_USER_SID,                // No security identifier
@@ -205,7 +211,7 @@ std::wstring logFormat(const std::wstring& cmdLine, const std::wstring& comment)
 {
     const std::string timeString = getTimeStamp();
     const std::wstring timeStringW(timeString.cbegin(), timeString.cend());
-    std::wstring logLine = timeStringW + L" DETECTED_CMD: '" + cmdLine + L" COMMENT: " + comment + L"\n";
+    std::wstring logLine = timeStringW + L" DETECTED_CMD: '" + cmdLine + L"' COMMENT: " + comment + L"\n";
     return logLine;
 }
 
@@ -242,9 +248,12 @@ void logSend(const std::wstring& logStr)
             return;   // bail out if we can't log
         }
     }
+    // Replace new line characters
+    std::wstring logString = logStr;
+    utils::removeNewLines(logString);
 
     if (logFile != nullptr) {
-        fwprintf(logFile, L"%s", logStr.c_str());
+        fwprintf(logFile, L"%s\n", logString.c_str());
         fflush(logFile);
         fclose(logFile);
         logFile = nullptr;