Refactor Event Log sink

This commit is contained in:
bandana2004 2020-02-09 11:52:26 +02:00
parent db1a221427
commit 4bece787c8
4 changed files with 364 additions and 350 deletions

View File

@ -1,100 +0,0 @@
// Copyright(c) 2015-present, Gabi Melman & spdlog contributors.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
// Requires the following registry entries to be present, with the following modifications:
// 1. {app_name} should be replaced with your application name
// 2. {log_name} should be replaced with the specific log name and the key should be duplicated for
// each log used in the application
/*---------------------------------------------------------------------------------------
Windows Registry Editor Version 5.00
[HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog\{app_name}]
[HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog\{app_name}\{log_name}]
"TypesSupported"=dword:00000007
"EventMessageFile"=hex(2):25,00,73,00,79,00,73,00,74,00,65,00,6d,00,72,00,6f,\
00,6f,00,74,00,25,00,5c,00,53,00,79,00,73,00,74,00,65,00,6d,00,33,00,32,00,\
5c,00,6d,00,73,00,63,00,6f,00,72,00,65,00,65,00,2e,00,64,00,6c,00,6c,00,00,\
00
-----------------------------------------------------------------------------------------*/
#pragma once
#ifdef _WIN32
#include <winbase.h>
#endif
#include <spdlog/details/null_mutex.h>
#include <spdlog/sinks/base_sink.h>
#include <mutex>
#include <string>
namespace spdlog {
namespace sinks {
/*
* Windows Event Log sink
*/
template<typename Mutex>
class eventlog_sink : public base_sink<Mutex>
{
public:
explicit eventlog_sink(
std::string const& source,
std::string const& log = "Application",
std::string const& message_file_path = "%windir%\\System32\\mscoree.dll");
eventlog_sink(eventlog_sink const&) = delete;
eventlog_sink& operator=(eventlog_sink const&) = delete;
protected:
void sink_it_(const details::log_msg &msg) override;
void flush_() override {}
virtual void set_pattern_(const std::string &pattern) override;
virtual void set_formatter_(std::unique_ptr<spdlog::formatter> sink_formatter) override;
private:
std::unique_ptr<sink> impl_;
};
#ifdef _WIN32
#include "eventlog_sink_win32.h"
#else
template <typename Mutex>
eventlog_sink<Mutex>::eventlog_sink(std::string const& source, std::string const& log, std::string const& message_file_path)
{
}
template <typename Mutex>
void eventlog_sink<Mutex>::sink_it_(const details::log_msg &msg)
{}
#endif
template <typename Mutex>
void eventlog_sink<Mutex>::set_pattern_(const std::string &pattern)
{
if (impl_)
impl_->set_pattern(pattern);
}
template <typename Mutex>
void eventlog_sink<Mutex>::set_formatter_(std::unique_ptr<spdlog::formatter> sink_formatter)
{
if (impl_)
impl_->set_formatter(std::move(sink_formatter));
}
using eventlog_sink_mt = eventlog_sink<std::mutex>;
using eventlog_sink_st = eventlog_sink<details::null_mutex>;
using windebug_sink_mt = eventlog_sink_mt;
using windebug_sink_st = eventlog_sink_st;
} // namespace sinks
} // namespace spdlog

View File

@ -1,246 +0,0 @@
// Copyright(c) 2020 bandana2004@gmail.com
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
namespace eventlog_sink_win32 {
struct win32_error : public spdlog_ex
{
static std::string format(std::string const& func, DWORD error = GetLastError())
{
return fmt::format(func + " failed ({0})", error);
}
static void report(char const* message) SPDLOG_NOEXCEPT
{
fprintf(stderr, "%s", message);
fflush(stderr);
}
static void report(std::string const& message) SPDLOG_NOEXCEPT
{
report(message.c_str());
}
win32_error(std::string const& func_name, DWORD error = GetLastError())
: spdlog_ex(format(func_name, error), error)
{}
};
struct sid
{
static SID* duplicate(SID* p_src_sid)
{
if (!IsValidSid(p_src_sid))
SPDLOG_THROW(spdlog_ex("sid::duplicate: invalid SID received"));
DWORD sid_size = ::GetLengthSid(p_src_sid);
SID* p_dest_sid = (SID*) ::HeapAlloc(GetProcessHeap(), HEAP_ZERO_MEMORY, sid_size);
if (!p_dest_sid)
SPDLOG_THROW(win32_error("HeapAlloc"));
if (!CopySid(sid_size, p_dest_sid, p_src_sid))
{
sid::free(&p_dest_sid);
SPDLOG_THROW(win32_error("CopySid"));
}
return p_dest_sid;
}
static void free(SID** ppsid)
{
if (ppsid && *ppsid)
{
if (!HeapFree(GetProcessHeap(), 0, (LPVOID) *ppsid))
{
SPDLOG_THROW(win32_error("HeapFree"));
}
}
*ppsid = nullptr;
}
static SID* get_current_user_sid()
{
struct process_token_t
{
HANDLE hToken_;
bool hasToken_;
process_token_t(HANDLE process)
: hToken_(0)
, hasToken_(OpenProcessToken(process, TOKEN_QUERY, &hToken_))
{
if (!hasToken_)
SPDLOG_THROW(win32_error("OpenProcessToken"));
}
~process_token_t()
{
if (hasToken_ && !CloseHandle(hToken_))
win32_error::report(win32_error::format("CloseHandle"));
}
} current_process_token(GetCurrentProcess()); // GetCurrentProcess returns pseudohandle, no leak here!
// Get the required size
DWORD tusize = 0;
GetTokenInformation(current_process_token.hToken_, TokenUser, NULL, 0, &tusize);
if (GetLastError() != ERROR_INSUFFICIENT_BUFFER)
SPDLOG_THROW(win32_error("GetTokenInformation"));
std::vector<unsigned char> buffer(tusize);
if (!GetTokenInformation(current_process_token.hToken_, TokenUser, (LPVOID) buffer.data(), tusize, &tusize))
SPDLOG_THROW(win32_error("GetTokenInformation"));
return sid::duplicate((SID *) ((TOKEN_USER*) buffer.data())->User.Sid);
}
};
struct eventlog
{
static WORD get_event_type(details::log_msg const& msg)
{
WORD type = EVENTLOG_SUCCESS;
if (msg.level >= level::info)
{
type = EVENTLOG_INFORMATION_TYPE;
if (msg.level >= level::warn)
{
type = EVENTLOG_WARNING_TYPE;
if (msg.level >= level::err)
{
type = EVENTLOG_ERROR_TYPE;
}
}
}
return type;
}
static WORD get_event_category(details::log_msg const& msg)
{
WORD category = 1;
if (msg.level >= level::debug)
{
category = 2;
if (msg.level >= level::info)
{
category = 3;
if (msg.level >= level::warn)
{
category = 4;
if (msg.level >= level::err)
{
category = 5;
if (msg.level >= level::critical)
{
category = 6;
}
}
}
}
}
return category;
}
};
class sink : public base_sink<spdlog::details::null_mutex>
{
private:
HANDLE hEventLog_;
SID* current_user_sid_;
std::string source_;
std::string log_;
void add_registry_info(std::string const& message_file_path)
{
std::string subkey("SYSTEM\\CurrentControlSet\\Services\\EventLog\\");
subkey += log_ + "\\" + source_;
::HKEY hkey {};
DWORD disposition {};
long stat = RegCreateKeyEx(HKEY_LOCAL_MACHINE, subkey.c_str(), 0, NULL,
REG_OPTION_NON_VOLATILE, KEY_SET_VALUE, NULL,
&hkey, &disposition);
if (stat == ERROR_SUCCESS)
{
if (disposition == REG_CREATED_NEW_KEY && !message_file_path.empty())
{
auto const expanded_message_file_path_length = ExpandEnvironmentStrings(message_file_path.c_str(), (LPSTR) &disposition, 0);
std::vector<char>expanded_message_file_path(expanded_message_file_path_length + 1);
ExpandEnvironmentStrings(message_file_path.c_str(), expanded_message_file_path.data(), expanded_message_file_path_length);
RegSetValueEx(hkey, "EventMessageFile", 0, REG_SZ, (LPBYTE) expanded_message_file_path.data(), expanded_message_file_path_length);
DWORD typesSupported = 7;
RegSetValueEx(hkey, "TypesSupported", 0, REG_DWORD, (LPBYTE) &typesSupported, sizeof(DWORD));
}
}
else
{
SPDLOG_THROW(win32_error("RegCreateKeyEx", stat));
}
RegCloseKey(hkey);
}
protected:
void sink_it_(const details::log_msg &msg) override
{
memory_buf_t formatted;
formatter_->format(msg, formatted);
auto formatted_string = fmt::to_string(formatted);
auto formatted_string_lpsz = formatted_string.c_str();
if (!ReportEvent(hEventLog_, eventlog::get_event_type(msg), eventlog::get_event_category(msg), 1000, current_user_sid_, 1, 0, &formatted_string_lpsz, nullptr))
SPDLOG_THROW(win32_error("ReportEvent"));
}
void flush_() override {}
public:
sink(
std::string const& source,
std::string const& log,
std::string const& message_file_path)
: source_(source)
, log_(log)
{
if (!message_file_path.empty())
add_registry_info(message_file_path);
current_user_sid_ = sid::get_current_user_sid();
hEventLog_ = RegisterEventSource(nullptr, source.c_str());
if (!hEventLog_)
SPDLOG_THROW(win32_error("RegisterEventSource"));
}
~sink()
{
try
{
if (hEventLog_ && !DeregisterEventSource(hEventLog_))
win32_error::report(win32_error::format("DeregisterEventSource"));
sid::free(&current_user_sid_);
}
catch (std::exception const& e)
{
win32_error::report(e.what());
}
}
};
} // namespace eventlog_sink_win32
template <typename Mutex>
eventlog_sink<Mutex>::eventlog_sink(std::string const& source, std::string const& log, std::string const& message_file_path)
: impl_(std::make_unique<eventlog_sink_win32::sink>(source, log, message_file_path))
{}
template <typename Mutex>
void eventlog_sink<Mutex>::sink_it_(const details::log_msg &msg)
{
impl_->log(msg);
}

View File

@ -0,0 +1,357 @@
// Copyright(c) 2015-present, Gabi Melman & spdlog contributors.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
// Writing to Windows Event Log requires the registry entries below to be present, with the following modifications:
// 1. {log_name} should be replaced with your log name (e.g. your application name)
// 2. {source_name} should be replaced with the specific source name and the key should be duplicated for
// each source used in the application
//
// Since typically modifications of this kind require elevation, it's better to do it as a part of setup procedure.
// However, the win_eventlog_sink constructor can do it for you in runtime if you set the message_file_path parameter to
// win_eventlog_sink::DEFAULT_MESSAGE_FILE
//
// You can also specify a custom message file if needed.
// Please refer to Event Log functions descriptions in MSDN for more details on custom message files.
/*---------------------------------------------------------------------------------------
Windows Registry Editor Version 5.00
[HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog\{log_name}]
[HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog\{log_name}\{source_name}]
"TypesSupported"=dword:00000007
"EventMessageFile"=hex(2):25,00,73,00,79,00,73,00,74,00,65,00,6d,00,72,00,6f,\
00,6f,00,74,00,25,00,5c,00,53,00,79,00,73,00,74,00,65,00,6d,00,33,00,32,00,\
5c,00,6d,00,73,00,63,00,6f,00,72,00,65,00,65,00,2e,00,64,00,6c,00,6c,00,00,\
00
-----------------------------------------------------------------------------------------*/
#pragma once
#include <winbase.h>
#include <spdlog/details/null_mutex.h>
#include <spdlog/sinks/base_sink.h>
#include <mutex>
#include <string>
namespace spdlog {
namespace sinks {
namespace win_eventlog {
namespace internal
{
struct utils
{
/** Reports a message to stderr */
static void report(char const* message) SPDLOG_NOEXCEPT
{
fprintf(stderr, "%s", message);
fflush(stderr);
}
/** Reports a message to stderr */
static void report(std::string const& message) SPDLOG_NOEXCEPT
{
report(message.c_str());
}
/** Runs a func and reports an exception to stderr if any */
template <typename Result>
static Result report_exceptions(std::function<Result()> func, Result defaultValue)
{
try
{
return func();
}
catch (std::exception const& e)
{
report(e.what());
return defaultValue;
}
}
/** Runs a func and reports an exception to stderr if any */
static void report_exceptions(std::function<void()> func)
{
report_exceptions<int>([&func] () { func(); return 0; }, 0);
}
};
/** Windows error */
struct win32_error : public spdlog_ex
{
/** Formats an error report line: "user-message: error-code (system message)" */
static std::string format(std::string const& user_message, DWORD error_code = GetLastError())
{
std::string system_message;
LPSTR format_message_result {};
auto format_message_succeeded = FormatMessage(
FORMAT_MESSAGE_ALLOCATE_BUFFER | FORMAT_MESSAGE_FROM_SYSTEM | FORMAT_MESSAGE_IGNORE_INSERTS, nullptr,
error_code, MAKELANGID(LANG_NEUTRAL, SUBLANG_DEFAULT), (LPSTR) &format_message_result, 0, nullptr);
if (format_message_succeeded && format_message_result)
{
system_message = fmt::format(" ({})", format_message_result);
}
if (format_message_result)
LocalFree((HLOCAL) format_message_result);
return fmt::format("{}: {}{}", user_message, error_code, system_message);
}
win32_error(std::string const& func_name, DWORD error = GetLastError())
: spdlog_ex(format(func_name, error))
{}
};
/** Wrapper for security identifiers (SID) on Windows */
struct sid_t
{
std::vector<char> buffer_;
public:
sid_t()
{}
/** creates a wrapped SID copy */
static sid_t duplicate_sid(PSID psid)
{
if (!IsValidSid(psid))
SPDLOG_THROW(spdlog_ex("sid_t::sid_t(): invalid SID received"));
auto const sid_length {::GetLengthSid(psid)};
sid_t result;
result.buffer_.resize(sid_length);
if (!CopySid(sid_length, (PSID) result.as_sid(), psid))
SPDLOG_THROW(win32_error("CopySid"));
return result;
}
/** Retrieves pointer to the internal buffer contents as SID* */
SID * as_sid() const
{
return buffer_.empty() ? nullptr : (SID *) buffer_.data();
}
/** Get SID for the current user */
static sid_t get_current_user_sid()
{
/* create and init RAII holder for process token */
struct process_token_t
{
HANDLE hToken_;
bool hasToken_;
process_token_t(HANDLE process)
: hToken_(0)
, hasToken_(OpenProcessToken(process, TOKEN_QUERY, &hToken_))
{
if (!hasToken_)
SPDLOG_THROW(win32_error("OpenProcessToken"));
}
~process_token_t()
{
if (hasToken_ && !CloseHandle(hToken_))
utils::report(win32_error::format("CloseHandle"));
}
} current_process_token(GetCurrentProcess()); // GetCurrentProcess returns pseudohandle, no leak here!
// Get the required size, this is expected to fail with ERROR_INSUFFICIENT_BUFFER and return the token size
DWORD tusize = 0;
GetTokenInformation(current_process_token.hToken_, TokenUser, NULL, 0, &tusize);
if (GetLastError() != ERROR_INSUFFICIENT_BUFFER)
SPDLOG_THROW(win32_error("GetTokenInformation"));
// get user token
std::vector<unsigned char> buffer(tusize);
if (!GetTokenInformation(current_process_token.hToken_, TokenUser, (LPVOID) buffer.data(), tusize, &tusize))
SPDLOG_THROW(win32_error("GetTokenInformation"));
// create a wrapper of the SID data as stored in the user token
return sid_t::duplicate_sid(((TOKEN_USER*) buffer.data())->User.Sid);
}
};
struct eventlog
{
static WORD get_event_type(details::log_msg const& msg)
{
switch (msg.level)
{
case level::trace:
case level::debug:
return EVENTLOG_SUCCESS;
case level::info:
return EVENTLOG_INFORMATION_TYPE;
case level::warn:
return EVENTLOG_WARNING_TYPE;
case level::err:
case level::critical:
case level::off:
return EVENTLOG_ERROR_TYPE;
default:
// should be unreachable
SPDLOG_THROW(std::logic_error(fmt::format("Unsupported log level {}", msg.level)));
}
}
static WORD get_event_category(details::log_msg const& msg)
{
return (WORD) msg.level;
}
};
} // namespace internal
/*
* Windows Event Log sink
*/
template <typename Mutex>
class win_eventlog_sink : public base_sink<Mutex>
{
private:
HANDLE hEventLog_ {NULL};
internal::sid_t current_user_sid_;
std::string source_;
WORD event_id_ {DEFAULT_EVENT_ID};
HANDLE event_log_handle()
{
if (!hEventLog_)
{
hEventLog_ = RegisterEventSource(nullptr, source_.c_str());
if (!hEventLog_ || hEventLog_ == (HANDLE) ERROR_ACCESS_DENIED)
SPDLOG_THROW(internal::win32_error("RegisterEventSource"));
}
return hEventLog_;
}
protected:
void sink_it_(const details::log_msg &msg) override
{
using namespace internal;
memory_buf_t formatted;
formatter_->format(msg, formatted);
auto formatted_string = fmt::to_string(formatted);
auto formatted_string_lpsz = formatted_string.c_str();
bool succeeded = ReportEvent(
event_log_handle(),
eventlog::get_event_type(msg),
eventlog::get_event_category(msg),
event_id_,
current_user_sid_.as_sid(),
1,
0,
&formatted_string_lpsz,
nullptr);
if (!succeeded)
SPDLOG_THROW(win32_error("ReportEvent"));
}
void flush_() override {}
public:
static const std::string DEFAULT_MESSAGE_FILE;
static const WORD DEFAULT_EVENT_ID {1000};
win_eventlog_sink( std::string const& source )
: source_(source)
{
using namespace internal;
utils::report_exceptions([this] () {
current_user_sid_ = sid_t::get_current_user_sid();
});
}
~win_eventlog_sink()
{
using namespace internal;
utils::report_exceptions([this]()
{
if (hEventLog_ && !DeregisterEventSource(hEventLog_))
utils::report(win32_error::format("DeregisterEventSource"));
});
}
/**
Register the log source in the Windows registry.
Requires elevation on Windows Vista and later.
*/
void add_registry_info(std::string const& log = "Application", std::string const& message_file_path = DEFAULT_MESSAGE_FILE, WORD event_id = DEFAULT_EVENT_ID)
{
using namespace internal;
event_id_ = event_id;
std::string subkey = fmt::format("SYSTEM\\CurrentControlSet\\Services\\EventLog\\{}\\{}", log, source_);
::HKEY hkey {};
DWORD disposition {};
long stat = RegCreateKeyEx(HKEY_LOCAL_MACHINE, subkey.c_str(), 0, NULL,
REG_OPTION_NON_VOLATILE, KEY_SET_VALUE, NULL,
&hkey, &disposition);
if (stat == ERROR_SUCCESS)
{
if (disposition == REG_CREATED_NEW_KEY && !message_file_path.empty())
{
auto const expanded_message_file_path_length = ExpandEnvironmentStrings(message_file_path.c_str(), (LPSTR) &disposition, 0);
if (!expanded_message_file_path_length)
SPDLOG_THROW(win32_error("ExpandEnvironmentStrings"));
std::vector<char>expanded_message_file_path(expanded_message_file_path_length);
ExpandEnvironmentStrings(message_file_path.c_str(), expanded_message_file_path.data(), expanded_message_file_path_length); // this can't fail if the preivous ExpandEnvironmentStrings succeeded
stat = RegSetValueEx(hkey, "EventMessageFile", 0, REG_SZ, (LPBYTE) expanded_message_file_path.data(), expanded_message_file_path_length);
if (stat != ERROR_SUCCESS)
SPDLOG_THROW(win32_error("RegSetValueEx", stat));
DWORD typesSupported = 7;
stat = RegSetValueEx(hkey, "TypesSupported", 0, REG_DWORD, (LPBYTE) &typesSupported, sizeof(DWORD));
if (stat != ERROR_SUCCESS)
SPDLOG_THROW(win32_error("RegSetValueEx", stat));
}
}
else
{
SPDLOG_THROW(win32_error("RegCreateKeyEx", stat));
}
RegCloseKey(hkey);
}
};
template <typename Mutex>
const std::string win_eventlog_sink<Mutex>::DEFAULT_MESSAGE_FILE = "%systemroot%\\system32\\mscoree.dll";
} // namespace win_eventlog
using win_eventlog_sink_mt = win_eventlog::win_eventlog_sink<std::mutex>;
using win_eventlog_sink_st = win_eventlog::win_eventlog_sink<details::null_mutex>;
} // namespace sinks
} // namespace spdlog

View File

@ -2,10 +2,13 @@
#include "test_sink.h" #include "test_sink.h"
#include "spdlog/fmt/bin_to_hex.h" #include "spdlog/fmt/bin_to_hex.h"
#include "spdlog/sinks/eventlog_sink.h"
#if _WIN32 #if _WIN32
#include "spdlog/sinks/win_eventlog_sink.h"
static const LPCSTR TEST_LOG = "my log";
static const LPCSTR TEST_SOURCE = "my source";
static void test_single_print(std::function<void(std::string const&)> do_print, std::string const& expectedContents, WORD expectedEventType) static void test_single_print(std::function<void(std::string const&)> do_print, std::string const& expectedContents, WORD expectedEventType)
{ {
do_print(expectedContents); do_print(expectedContents);
@ -22,7 +25,7 @@ static void test_single_print(std::function<void(std::string const&)> do_print,
if (handle_) if (handle_)
REQUIRE(CloseEventLog(handle_)); REQUIRE(CloseEventLog(handle_));
} }
} eventLog {OpenEventLog(nullptr, "my_source")}; } eventLog {OpenEventLog(nullptr, TEST_SOURCE)};
REQUIRE(eventLog.handle_); REQUIRE(eventLog.handle_);
@ -49,7 +52,7 @@ TEST_CASE("eventlog", "[eventlog]")
{ {
using namespace spdlog; using namespace spdlog;
auto test_sink = std::make_shared<sinks::eventlog_sink_mt>("my_source", "my_spd_log"); auto test_sink = std::make_shared<sinks::win_eventlog_sink_mt>(TEST_SOURCE);
spdlog::logger test_logger("eventlog", test_sink); spdlog::logger test_logger("eventlog", test_sink);
test_logger.set_level(level::trace); test_logger.set_level(level::trace);