Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 4 additions & 4 deletions source/common/common/logger.cc
Original file line number Diff line number Diff line change
Expand Up @@ -66,7 +66,7 @@ StderrSinkDelegate::StderrSinkDelegate(DelegatingLogSinkSharedPtr log_sink)

StderrSinkDelegate::~StderrSinkDelegate() { restoreDelegate(); }

void StderrSinkDelegate::log(absl::string_view msg) {
void StderrSinkDelegate::log(absl::string_view msg, const spdlog::details::log_msg&) {
Thread::OptionalLockGuard guard(lock_);
std::cerr << msg;
}
Expand Down Expand Up @@ -94,11 +94,11 @@ void DelegatingLogSink::log(const spdlog::details::log_msg& msg) {
}
lock.Release();

auto log_to_sink = [this, msg_view](SinkDelegate& sink) {
auto log_to_sink = [this, msg_view, msg](SinkDelegate& sink) {
if (should_escape_) {
sink.log(escapeLogLine(msg_view));
sink.log(escapeLogLine(msg_view), msg);
} else {
sink.log(msg_view);
sink.log(msg_view, msg);
}
};
auto* tls_sink = tlsDelegate();
Expand Down
21 changes: 19 additions & 2 deletions source/common/common/logger.h
Original file line number Diff line number Diff line change
Expand Up @@ -109,9 +109,26 @@ class SinkDelegate : NonCopyable {
explicit SinkDelegate(DelegatingLogSinkSharedPtr log_sink);
virtual ~SinkDelegate();

virtual void log(absl::string_view msg) PURE;
/**
* Called to log a single log line.
* @param formatted_msg The final, formatted message.
* @param the original log message, including additional metadata.
*/
virtual void log(absl::string_view msg, const spdlog::details::log_msg& log_msg) PURE;

/**
* Called to log a single log line with a stable name.
* @param stable_name stable name of this log line.
* @param level the string representation of the log level for this log line.
* @param component the component this log was logged via.
* @param msg the log line to log.
*/
virtual void logWithStableName(absl::string_view stable_name, absl::string_view level,
absl::string_view component, absl::string_view msg);

/**
* Called to flush the log sink.
*/
virtual void flush() PURE;

protected:
Expand Down Expand Up @@ -151,7 +168,7 @@ class StderrSinkDelegate : public SinkDelegate {
~StderrSinkDelegate() override;

// SinkDelegate
void log(absl::string_view msg) override;
void log(absl::string_view msg, const spdlog::details::log_msg& log_msg) override;
void flush() override;

bool hasLock() const { return lock_ != nullptr; }
Expand Down
2 changes: 1 addition & 1 deletion source/common/common/logger_delegates.cc
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@ FileSinkDelegate::FileSinkDelegate(const std::string& log_path,

FileSinkDelegate::~FileSinkDelegate() { restoreDelegate(); }

void FileSinkDelegate::log(absl::string_view msg) {
void FileSinkDelegate::log(absl::string_view msg, const spdlog::details::log_msg&) {
// Log files have internal locking to ensure serial, non-interleaved
// writes, so no additional locking needed here.
log_file_->write(msg);
Expand Down
2 changes: 1 addition & 1 deletion source/common/common/logger_delegates.h
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,7 @@ class FileSinkDelegate : public SinkDelegate {
~FileSinkDelegate() override;

// SinkDelegate
void log(absl::string_view msg) override;
void log(absl::string_view msg, const spdlog::details::log_msg& log_msg) override;
void flush() override;

private:
Expand Down
47 changes: 33 additions & 14 deletions test/common/common/logger_test.cc
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@
#include "gtest/gtest.h"

using testing::_;
using testing::HasSubstr;
using testing::Invoke;

namespace Envoy {
Expand Down Expand Up @@ -154,11 +155,11 @@ TEST_F(LoggerCustomFlagsTest, LogMessageAsJsonStringEscaped) {
"\\\"transport: Error while dialing dial tcp [::1]:15012: connect: connection refused\\\"");
}

struct NamedLogSink : SinkDelegate {
NamedLogSink(DelegatingLogSinkSharedPtr log_sink) : SinkDelegate(log_sink) { setDelegate(); }
~NamedLogSink() override { restoreDelegate(); }
struct MockLogSink : SinkDelegate {
MockLogSink(DelegatingLogSinkSharedPtr log_sink) : SinkDelegate(log_sink) { setDelegate(); }
~MockLogSink() override { restoreDelegate(); }

MOCK_METHOD(void, log, (absl::string_view));
MOCK_METHOD(void, log, (absl::string_view, const spdlog::details::log_msg&));
MOCK_METHOD(void, logWithStableName,
(absl::string_view, absl::string_view, absl::string_view, absl::string_view));
void flush() override {}
Expand All @@ -167,20 +168,22 @@ struct NamedLogSink : SinkDelegate {
class NamedLogTest : public Loggable<Id::assert>, public testing::Test {};

TEST_F(NamedLogTest, NamedLogsAreSentToSink) {
NamedLogSink sink(Envoy::Logger::Registry::getSink());
MockLogSink sink(Envoy::Logger::Registry::getSink());

Envoy::Logger::Registry::setLogLevel(spdlog::level::info);
// Log level is above debug, so we shouldn't get any logs.
ENVOY_LOG_EVENT(debug, "test_event", "not logged");

Envoy::Logger::Registry::setLogLevel(spdlog::level::debug);

EXPECT_CALL(sink, log(_));
EXPECT_CALL(sink, log(_, _));
EXPECT_CALL(sink, logWithStableName("test_event", "debug", "assert", "test log 1"));
ENVOY_LOG_EVENT(debug, "test_event", "test {} {}", "log", 1);

// Verify that ENVOY_LOG_EVENT_TO_LOGGER does the right thing.
EXPECT_CALL(sink, log(_)).WillOnce(Invoke([](auto log) { EXPECT_TRUE(log.find("[misc]")); }));
EXPECT_CALL(sink, log(_, _)).WillOnce(Invoke([](auto log, const auto&) {
EXPECT_TRUE(log.find("[misc]"));
}));
EXPECT_CALL(sink, logWithStableName("misc_event", "debug", "misc", "log"));
ENVOY_LOG_EVENT_TO_LOGGER(Registry::getLog(Id::misc), debug, "misc_event", "log");
}
Expand All @@ -189,31 +192,32 @@ struct TlsLogSink : SinkDelegate {
TlsLogSink(DelegatingLogSinkSharedPtr log_sink) : SinkDelegate(log_sink) { setTlsDelegate(); }
~TlsLogSink() override { restoreTlsDelegate(); }

MOCK_METHOD(void, log, (absl::string_view));
MOCK_METHOD(void, log, (absl::string_view, const spdlog::details::log_msg&));
MOCK_METHOD(void, logWithStableName,
(absl::string_view, absl::string_view, absl::string_view, absl::string_view));
MOCK_METHOD(void, flush, ());
};

TEST(NamedLogtest, OverrideSink) {
NamedLogSink global_sink(Envoy::Logger::Registry::getSink());
// Verifies that we can register a thread local sink override.
TEST(TlsLoggingOverrideTest, OverrideSink) {
MockLogSink global_sink(Envoy::Logger::Registry::getSink());
testing::InSequence s;

{
TlsLogSink tls_sink(Envoy::Logger::Registry::getSink());

// Calls on the current thread goes to the TLS sink.
EXPECT_CALL(tls_sink, log(_));
EXPECT_CALL(tls_sink, log(_, _));
ENVOY_LOG_MISC(info, "hello tls");

// Calls on other threads should use the global sink.
std::thread([&]() {
EXPECT_CALL(global_sink, log(_));
EXPECT_CALL(global_sink, log(_, _));
ENVOY_LOG_MISC(info, "hello global");
}).join();

// Sanity checking that we're still using the TLS sink.
EXPECT_CALL(tls_sink, log(_));
EXPECT_CALL(tls_sink, log(_, _));
ENVOY_LOG_MISC(info, "hello tls");

// All the logging functions should be delegated to the TLS override.
Expand All @@ -226,8 +230,23 @@ TEST(NamedLogtest, OverrideSink) {

// Now that the TLS sink is out of scope, log calls on this thread should use the global sink
// again.
EXPECT_CALL(global_sink, log(_));
EXPECT_CALL(global_sink, log(_, _));
ENVOY_LOG_MISC(info, "hello global 2");
}

TEST(LoggerTest, LogWithLogDetails) {
Envoy::Logger::Registry::setLogLevel(spdlog::level::info);

MockLogSink sink(Envoy::Logger::Registry::getSink());

EXPECT_CALL(sink, log(_, _)).WillOnce(Invoke([](auto msg, auto& log) {
EXPECT_THAT(msg, HasSubstr("[info]"));
EXPECT_THAT(msg, HasSubstr("hello"));

EXPECT_EQ(log.logger_name, "misc");
}));
ENVOY_LOG_MISC(info, "hello");
}

} // namespace Logger
} // namespace Envoy
4 changes: 2 additions & 2 deletions test/test_common/logging.cc
Original file line number Diff line number Diff line change
Expand Up @@ -41,8 +41,8 @@ LogRecordingSink::LogRecordingSink(Logger::DelegatingLogSinkSharedPtr log_sink)

LogRecordingSink::~LogRecordingSink() { restoreDelegate(); }

void LogRecordingSink::log(absl::string_view msg) {
previousDelegate()->log(msg);
void LogRecordingSink::log(absl::string_view msg, const spdlog::details::log_msg& log_msg) {
previousDelegate()->log(msg, log_msg);

absl::MutexLock ml(&mtx_);
messages_.push_back(std::string(msg));
Expand Down
2 changes: 1 addition & 1 deletion test/test_common/logging.h
Original file line number Diff line number Diff line change
Expand Up @@ -54,7 +54,7 @@ class LogRecordingSink : public Logger::SinkDelegate {
~LogRecordingSink() override;

// Logger::SinkDelegate
void log(absl::string_view msg) override;
void log(absl::string_view msg, const spdlog::details::log_msg& log_msg) override;
void flush() override;

const std::vector<std::string> messages() const {
Expand Down