Merge pull request #1418 from ban-dana/v1.x

Add eventlog_sink for logging to Windows Event Log (local only)
This commit is contained in:
Gabi Melman 2020-02-09 23:27:00 +02:00 committed by GitHub
commit fccee959b1
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 337 additions and 0 deletions

View File

@ -0,0 +1,267 @@
// 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.
// The snippet below uses mscoree.dll as the message file as it exists on most of the Windows systems anyway and
// happens to contain the needed resource.
//
// 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
{
/** 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_);
}
} 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_;
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:
win_eventlog_sink(std::string const& source, WORD event_id = 1000 /* according to mscoree.dll */)
: source_(source)
, event_id_ (event_id)
{
try
{
current_user_sid_ = internal::sid_t::get_current_user_sid();
}
catch (...)
{
// get_current_user_sid() is unlikely to fail and if it does, we can still proceed without
// current_user_sid but in the event log the record will have no user name
}
}
~win_eventlog_sink()
{
if (hEventLog_)
DeregisterEventSource(hEventLog_);
}
};
} // 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

@ -19,6 +19,7 @@ set(SPDLOG_UTESTS_SOURCES
test_file_logging.cpp
test_daily_logger.cpp
test_misc.cpp
test_eventlog.cpp
test_pattern_formatter.cpp
test_async.cpp
test_registry.cpp

69
tests/test_eventlog.cpp Normal file
View File

@ -0,0 +1,69 @@
#include "includes.h"
#include "test_sink.h"
#include "spdlog/fmt/bin_to_hex.h"
#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)
{
do_print(expectedContents);
using namespace std::chrono;
const auto expectedTimeGenerated = duration_cast<seconds>(system_clock::now().time_since_epoch()).count();
struct handle_t
{
HANDLE handle_;
~handle_t()
{
if (handle_)
REQUIRE(CloseEventLog(handle_));
}
} eventLog {OpenEventLog(nullptr, TEST_SOURCE)};
REQUIRE(eventLog.handle_);
DWORD readBytes {}, sizeNeeded {};
auto ok = ReadEventLog(eventLog.handle_, EVENTLOG_SEQUENTIAL_READ | EVENTLOG_BACKWARDS_READ, 0, &readBytes, 0, &readBytes, &sizeNeeded);
REQUIRE(!ok);
REQUIRE(GetLastError() == ERROR_INSUFFICIENT_BUFFER);
std::vector<char> recordBuffer(sizeNeeded);
PEVENTLOGRECORD record = (PEVENTLOGRECORD)recordBuffer.data();
ok = ReadEventLog(eventLog.handle_, EVENTLOG_SEQUENTIAL_READ | EVENTLOG_BACKWARDS_READ, 0, record, sizeNeeded, &readBytes, &sizeNeeded);
REQUIRE(ok);
REQUIRE(record->NumStrings == 1);
REQUIRE(record->EventType == expectedEventType);
REQUIRE(record->TimeGenerated == expectedTimeGenerated);
std::string message_in_log(((char*) record + record->StringOffset));
REQUIRE(message_in_log == expectedContents + "\r\n");
}
TEST_CASE("eventlog", "[eventlog]")
{
using namespace spdlog;
auto test_sink = std::make_shared<sinks::win_eventlog_sink_mt>(TEST_SOURCE);
spdlog::logger test_logger("eventlog", test_sink);
test_logger.set_level(level::trace);
test_sink->set_pattern("%v");
test_single_print([&test_logger] (std::string const& msg) { test_logger.debug(msg); }, "my debug message", EVENTLOG_SUCCESS);
test_single_print([&test_logger] (std::string const& msg) { test_logger.info(msg); }, "my info message", EVENTLOG_INFORMATION_TYPE);
test_single_print([&test_logger] (std::string const& msg) { test_logger.warn(msg); }, "my warn message", EVENTLOG_WARNING_TYPE);
test_single_print([&test_logger] (std::string const& msg) { test_logger.error(msg); }, "my error message", EVENTLOG_ERROR_TYPE);
test_single_print([&test_logger] (std::string const& msg) { test_logger.critical(msg); }, "my critical message", EVENTLOG_ERROR_TYPE);
}
#endif