Add logging for backing parameters

plugins/apitracing/Readme.md

@@ -55,10 +55,18 @@ Modules:
       ReturnValue: BOOL
 Structures:
   LPPROCESS_INFORMATION:
-    hProcess: HANDLE
-    hThread: HANDLE
-    dwProcessId: DWORD
-    dwThreadId: DWORD
+  hProcess:
+    Type: HANDLE
+    Offset: 0
+  hThread:
+    Type: HANDLE
+    Offset: 8
+  dwProcessId:
+    Type: DWORD
+    Offset: 16
+  dwThreadId:
+    Type: DWORD
+    Offset: 20
 HighLevelParameterTypes:
   AddressWidth32Bit:
     DWORD: unsigned long
@@ -88,4 +96,74 @@ type *LPPROCESS_INFORMATION*.
 For example the parameter *hProcess* is of the type *HANDLE*. Depending on the address width of the process it gets
 resolved
 to either *unsigned int* or *unsigned _int64*. Those are *BackingParameterTypes* so either 8 or 4 byte are read when
-extracting this structure from the heap.
+extracting this structure from the heap.
+
+## Extraction Format
+
+Function call traces are logged in an unindented json format which is illustrated indented below for better visibility.
+The parameter extraction logs are identified by the *key* ```Parameterlist:```.
+Its *value* is a list of all function call parameters, whereby the parameter names form the *keys* of the contained *key:value* pairs.
+Each *value* is either the value of the parameter as integer or string value, or it is a list containing
+the *key:value* pairs of backing parameters if it's a pointer to a struct.
+
+
+```json
+{
+    "Parameterlist": [
+                    {"FileHandle":[
+                                    {"HANDLE":45}]},
+                    {"DesiredAccess":1180063},
+                    {"ObjectAttributes":[
+                                    {"Length":48},
+                                    {"RootDirectory":0},
+                                    {"ObjectName":"\\Device\\ConDrv\\Server"},
+                                    {"Attributes":66},
+                                    {"SecurityDescriptor":0},
+                                    {"SecurityQualityOfService":0}]},
+                  {"IoStatusBlock":958106952720},
+                  {"AllocationSize":0},
+                  {"FileAttributes":0},
+                  {"ShareAccess":7},
+                  {"CreateDisposition":2},
+                  {"CreateOptions":0},
+                  {"EaBuffer":0},
+                  {"EaLength":0}]
+}
+```
+
+The log example above is a function call of *NtCreateFile* with these parameters:
+
+```c
+__kernel_entry NTSTATUS NtCreateFile(
+  [out]          PHANDLE            FileHandle,
+  [in]           ACCESS_MASK        DesiredAccess,
+  [in]           POBJECT_ATTRIBUTES ObjectAttributes,
+  [out]          PIO_STATUS_BLOCK   IoStatusBlock,
+  [in, optional] PLARGE_INTEGER     AllocationSize,
+  [in]           ULONG              FileAttributes,
+  [in]           ULONG              ShareAccess,
+  [in]           ULONG              CreateDisposition,
+  [in]           ULONG              CreateOptions,
+  [in]           PVOID              EaBuffer,
+  [in]           ULONG              EaLength
+);
+```
+
+*FileHandle, DesiredAccess, ObjectAttributues, IOStatusBlocck,AllocationSize, FileAttributes,ShareAccess, CreateDisposition,
+CreateOptions, EaBuffer* and *EaLength* are members of the list in parameterlist *value*.
+
+```c
+typedef struct _OBJECT_ATTRIBUTES {
+  ULONG           Length;
+  HANDLE          RootDirectory;
+  PUNICODE_STRING ObjectName;
+  ULONG           Attributes;
+  PVOID           SecurityDescriptor;
+  PVOID           SecurityQualityOfService;
+} OBJECT_ATTRIBUTES;
+```
+
+*ObjectAttributes* is a pointer to a struct, so its value is a list containing the backing parameters.
+The parameter *ObjectName* is a pointer to a unicode and forms an exception since it is extracted directly.
+Both *PVOID* at the end are structs, that are currently not covered by our definitions.
+You can find a list under the struct section in the [function definitions file](configuration/functiondefinitions/functionDefinitions.yaml).

plugins/apitracing/src/lib/ApiTracing.cpp

@@ -46,12 +46,20 @@ namespace ApiTracing
 
         logger->debug("ApiTracing plugin version info", {{"Version", PLUGIN_VERSION}, {"BuildNumber", BUILD_VERSION}});
 
-        auto apiTracingConfig = std::make_unique<Config>(config);
+        auto apiTracingConfig = std::make_unique<Config>(pluginInterface, config);
+
+        std::string commandLine;
+        for (const auto& piece : args)
+        {
+            commandLine += " " + piece;
+        }
+        logger->info("ApiTracing command line", {{"commandLine:", commandLine}});
 
         if (functionDefinitionsPath.isSet())
         {
             apiTracingConfig->setFunctionDefinitionsPath(functionDefinitionsPath);
         }
+
         if (traceProcessName.isSet())
         {
             apiTracingConfig->addTracingTarget(traceProcessName);

plugins/apitracing/src/lib/CMakeLists.txt

@@ -44,7 +44,22 @@ set_property(TARGET yaml-cpp PROPERTY POSITION_INDEPENDENT_CODE TRUE)
 target_compile_definitions(apitracing-obj PUBLIC YAML_CPP_SUPPORT)
 target_link_libraries(apitracing-obj PUBLIC yaml-cpp)
 
+# Setup json-cpp
+
+FetchContent_Declare(
+        jsoncpp
+        GIT_REPOSITORY https://github.com/open-source-parsers/jsoncpp.git
+        GIT_TAG 1.9.5
+)
+option(JSONCPP_WITH_TESTS "" OFF)
+option(JSONCPP_WITH_POST_BUILD_UNITTEST "" OFF)
+option(JSONCPP_WITH_EXAMPLE "" OFF)
+FetchContent_MakeAvailable(jsoncpp)
+set_property(TARGET jsoncpp_static PROPERTY POSITION_INDEPENDENT_CODE TRUE)
+target_link_libraries(apitracing-obj PUBLIC jsoncpp_static)
+
 # Add public vmicore headers
 
 add_subdirectory("${VMICORE_DIRECTORY_ROOT}/src/include" "${CMAKE_CURRENT_BINARY_DIR}/vmicore-public-headers")
 target_link_libraries(apitracing-obj PUBLIC vmicore-public-headers)
+

plugins/apitracing/src/lib/FunctionHook.cpp

@@ -29,6 +29,7 @@ namespace ApiTracing
           logger(this->pluginInterface->newNamedLogger(APITRACING_LOGGER_NAME))
     {
         logger->bind({{VmiCore::WRITE_TO_FILE_TAG, LOG_FILENAME}});
+        builder["indentation"] = "";
     }
 
     void FunctionHook::hookFunction(VmiCore::addr_t moduleBaseAddress,
@@ -52,25 +53,40 @@ namespace ApiTracing
         }
 
         auto extractedParameters = extractor->extractParameters(event, parameterInformation);
-        logParameterList(extractedParameters);
+        auto json = getParameterListAsJson(extractedParameters);
+        std::string unformattedTraces = Json::writeString(builder, json);
+
+        logger->info("Monitored function called",
+                     {{"FunctionName", functionName},
+                      {"ModuleName", moduleName},
+                      {"ProcessDtb", fmt::format("{:x}", event.getCr3())},
+                      {"ProcessTeb", fmt::format("{:x}", event.getGs())},
+                      {"Parameterlist", unformattedTraces}});
 
         return BpResponse::Continue;
     }
 
-    void FunctionHook::logParameterList(const std::vector<ExtractedParameterInformation>& extractedParameters)
+    Json::Value
+    FunctionHook::getParameterListAsJson(const std::vector<ExtractedParameterInformation>& extractedParameters)
     {
+        Json::Value parameterList;
+
         for (const auto& extractedParameter : extractedParameters)
         {
-            std::visit(
-                [&extractedParameter = extractedParameter, &logger = logger](auto&& arg)
-                {
-                    logger->info("Parameter",
-                                 {{"Name", extractedParameter.name},
-                                  {"Value", std::forward<std::remove_reference_t<decltype(arg)>>(arg)}});
-                },
-                extractedParameter.data);
-            // TODO: Log backing parameters
+            Json::Value parameter;
+            if (!extractedParameter.backingParameters.empty())
+            {
+                parameter[extractedParameter.name] = getParameterListAsJson(extractedParameter.backingParameters);
+            }
+            else
+            {
+                std::visit([&parameter = parameter, &extractedParameter = extractedParameter]<typename T>(T&& arg)
+                           { parameter[extractedParameter.name] = std::forward<T>(arg); },
+                           extractedParameter.data);
+            }
+            parameterList.append(parameter);
         }
+        return parameterList;
     }
 
     void FunctionHook::teardown() const

plugins/apitracing/src/lib/FunctionHook.h

@@ -4,6 +4,8 @@
 #include "ConstantDefinitions.h"
 #include "config/FunctionDefinitions.h"
 #include "os/Extractor.h"
+#include <json/value.h>
+#include <json/writer.h>
 #include <vmicore/io/ILogger.h>
 #include <vmicore/plugins/PluginInterface.h>
 #include <vmicore/vmi/IBreakpoint.h>
@@ -36,8 +38,9 @@ namespace ApiTracing
         std::shared_ptr<std::vector<ParameterInformation>> parameterInformation;
         VmiCore::Plugin::PluginInterface* pluginInterface;
         std::unique_ptr<VmiCore::ILogger> logger;
+        Json::StreamWriterBuilder builder;
 
-        void logParameterList(const std::vector<ExtractedParameterInformation>& extractedParameters);
+        Json::Value getParameterListAsJson(const std::vector<ExtractedParameterInformation>& extractedParameters);
     };
 }
 #endif // APITRACING_FUNCTIONHOOK_H

plugins/apitracing/src/lib/config/Config.cpp

@@ -1,10 +1,14 @@
 #include "Config.h"
+#include "../Filenames.h"
 #include "TracingDefinitions.h"
 #include <vmicore/plugins/IPluginConfig.h>
+#include <vmicore/plugins/PluginInterface.h>
 
 namespace ApiTracing
 {
-    Config::Config(const VmiCore::Plugin::IPluginConfig& pluginConfig)
+    Config::Config(const VmiCore::Plugin::PluginInterface* pluginInterface,
+                   const VmiCore::Plugin::IPluginConfig& pluginConfig)
+        : logger(pluginInterface->newNamedLogger(APITRACING_LOGGER_NAME))
     {
         auto configRootNode = pluginConfig.rootNode();
         if (auto configFilePath = pluginConfig.configFilePath())
@@ -96,7 +100,12 @@ namespace ApiTracing
 
     void Config::addTracingTarget(const std::string& name)
     {
+        logger->debug("addTracingTarget", {{"Name", name}});
         processTracingProfiles.emplace(name, profiles["default"]);
+        for (auto [processName, profile] : processTracingProfiles)
+        {
+            logger->debug("tracing profiles", {{"ProcessName", processName}, {"TracingProfile", profile.name}});
+        }
     }
 
     void Config::setFunctionDefinitionsPath(const std::filesystem::path& path)

plugins/apitracing/src/lib/config/Config.h

@@ -6,7 +6,9 @@
 #include <map>
 #include <optional>
 #include <string_view>
+#include <vmicore/io/ILogger.h>
 #include <vmicore/plugins/IPluginConfig.h>
+#include <vmicore/plugins/PluginInterface.h>
 #include <yaml-cpp/yaml.h>
 
 namespace ApiTracing
@@ -31,7 +33,8 @@ namespace ApiTracing
     class Config : public IConfig
     {
       public:
-        explicit Config(const VmiCore::Plugin::IPluginConfig& pluginConfig);
+        explicit Config(const VmiCore::Plugin::PluginInterface* pluginInterface,
+                        const VmiCore::Plugin::IPluginConfig& pluginConfig);
 
         ~Config() override = default;
 
@@ -44,6 +47,7 @@ namespace ApiTracing
         void setFunctionDefinitionsPath(const std::filesystem::path& path) override;
 
       private:
+        std::unique_ptr<VmiCore::ILogger> logger;
         std::filesystem::path configFileDir;
         std::filesystem::path functionDefinitions;
         std::map<std::string, TracingProfile, std::less<>> profiles;

plugins/apitracing/test/Config_UnitTest.cpp

@@ -2,15 +2,32 @@
 #include <gmock/gmock.h>
 #include <gtest/gtest.h>
 #include <string_view>
+#include <vmicore_test/io/mock_Logger.h>
 #include <vmicore_test/plugins/mock_PluginConfig.h>
+#include <vmicore_test/plugins/mock_PluginInterface.h>
 
+using testing::_; // NOLINT(bugprone-reserved-identifier,cert-dcl37-c,cert-dcl51-cpp)
+using testing::NiceMock;
 using testing::Return;
 using VmiCore::Plugin::MockPluginConfig;
+using VmiCore::Plugin::MockPluginInterface;
 
 namespace ApiTracing
 {
     constexpr std::string_view defaultMainConfigFileDir = "/usr/local/var/";
 
+    class ConfigTestFixture : public testing::Test
+    {
+      protected:
+        std::unique_ptr<MockPluginInterface> pluginInterface = std::make_unique<NiceMock<MockPluginInterface>>();
+
+        void SetUp() override
+        {
+            ON_CALL(*pluginInterface, newNamedLogger(_))
+                .WillByDefault([]() { return std::make_unique<NiceMock<VmiCore::MockLogger>>(); });
+        }
+    };
+
     std::unique_ptr<MockPluginConfig> createMockPluginConfig(const YAML::Node& configNode)
     {
         auto mockPluginConfig = std::make_unique<MockPluginConfig>();
@@ -32,17 +49,17 @@ namespace ApiTracing
         return mockPluginConfig;
     }
 
-    TEST(ConfigTests, constructor_functionDefinitionsKeyMissing_throws)
+    TEST_F(ConfigTestFixture, constructor_functionDefinitionsKeyMissing_throws)
     {
         YAML::Node emptyConfigRootNode;
 
-        EXPECT_ANY_THROW(std::make_unique<Config>(*createMockPluginConfig(emptyConfigRootNode)));
+        EXPECT_ANY_THROW(std::make_unique<Config>(pluginInterface.get(), *createMockPluginConfig(emptyConfigRootNode)));
     }
 
-    TEST(ConfigTests, getTracingProfile_calcProcess_correctProfile)
+    TEST_F(ConfigTestFixture, getTracingProfile_calcProcess_correctProfile)
     {
-
-        auto config = std::make_unique<Config>(*createMockPluginConfig("testConfiguration.yaml"));
+        auto config =
+            std::make_unique<Config>(pluginInterface.get(), *createMockPluginConfig("testConfiguration.yaml"));
         TracingProfile expectedTracingProfile{
             .name = "calc",
             .traceChildren = true,
@@ -54,9 +71,10 @@ namespace ApiTracing
         EXPECT_EQ(tracingProfile, expectedTracingProfile);
     }
 
-    TEST(ConfigTests, getTracingProfile_processWithoutProfile_defaultProfile)
+    TEST_F(ConfigTestFixture, getTracingProfile_processWithoutProfile_defaultProfile)
     {
-        auto config = std::make_unique<Config>(*createMockPluginConfig("testConfiguration.yaml"));
+        auto config =
+            std::make_unique<Config>(pluginInterface.get(), *createMockPluginConfig("testConfiguration.yaml"));
         TracingProfile expectedTracingProfile{
             .name = "default", .traceChildren = true, .modules = {{.name = "ntdll.dll", .functions = {{"function1"}}}}};
 
@@ -65,28 +83,30 @@ namespace ApiTracing
         EXPECT_EQ(tracingProfile, expectedTracingProfile);
     }
 
-    TEST(ConfigTests, getTracingProfile_unknownProcessName_nullopt)
+    TEST_F(ConfigTestFixture, getTracingProfile_unknownProcessName_nullopt)
     {
-        auto config = std::make_unique<Config>(*createMockPluginConfig("testConfiguration.yaml"));
+        auto config =
+            std::make_unique<Config>(pluginInterface.get(), *createMockPluginConfig("testConfiguration.yaml"));
 
         auto tracingProfile = config->getTracingProfile("unknown.exe");
 
         EXPECT_FALSE(tracingProfile);
     }
 
-    TEST(ConfigTests, getFunctionDefinitionsPath_configFromVmiCoreConfigFile_correctAbsolutePath)
+    TEST_F(ConfigTestFixture, getFunctionDefinitionsPath_configFromVmiCoreConfigFile_correctAbsolutePath)
     {
         YAML::Node configRootNode;
         configRootNode["function_definitions"] = "test.yaml";
 
-        auto config = std::make_unique<Config>(*createMockPluginConfig(configRootNode));
+        auto config = std::make_unique<Config>(pluginInterface.get(), *createMockPluginConfig(configRootNode));
 
         EXPECT_EQ(config->getFunctionDefinitionsPath(), std::filesystem::path(defaultMainConfigFileDir) / "test.yaml");
     }
 
-    TEST(ConfigTests, getFunctionDefinitionsPath_configWithFunctionDefinitionsKey_correctFilePath)
+    TEST_F(ConfigTestFixture, getFunctionDefinitionsPath_configWithFunctionDefinitionsKey_correctFilePath)
     {
-        auto config = std::make_unique<Config>(*createMockPluginConfig("testConfiguration.yaml"));
+        auto config =
+            std::make_unique<Config>(pluginInterface.get(), *createMockPluginConfig("testConfiguration.yaml"));
 
         EXPECT_NO_THROW(YAML::LoadFile(config->getFunctionDefinitionsPath()));
     }