Skip to content

Implement fine grain logging groups #44428

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
etruong42 wants to merge 1 commit into
base: main
Choose a base branch
from
Draft

Implement fine grain logging groups #44428

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
20 changes: 17 additions & 3 deletions source/common/common/fine_grain_logger.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
#include "source/common/common/fine_grain_logger.h"

#include <atomic>
#include <cstddef>
#include <memory>
#include <tuple>

Expand Down Expand Up @@ -209,11 +210,19 @@ void FineGrainLogContext::appendVerbosityLogUpdate(absl::string_view update_patt
verbosity_update_info_.emplace_back(std::string(update_pattern), update_is_path, log_level);
}

level_enum FineGrainLogContext::getLogLevel(absl::string_view file) const {
level_enum FineGrainLogContext::getLogLevel(absl::string_view key) const {
if (verbosity_update_info_.empty()) {
return verbosity_default_level_;
}

absl::string_view file = key;
absl::string_view logger_name;
const size_t colon = file.rfind(':');
if (colon != file.npos) {
logger_name = file.substr(colon + 1);
file = file.substr(0, colon);
}

// Get basename for file.
absl::string_view basename = file;
{
Expand All @@ -236,8 +245,13 @@ level_enum FineGrainLogContext::getLogLevel(absl::string_view file) const {
if (safeFileNameMatch(info.update_pattern, file)) {
return info.log_level;
}
} else if (safeFileNameMatch(info.update_pattern, stem_basename)) {
return info.log_level;
} else {
if (safeFileNameMatch(info.update_pattern, stem_basename)) {
return info.log_level;
}
if (!logger_name.empty() && safeFileNameMatch(info.update_pattern, logger_name)) {
return info.log_level;
}
}
}

Expand Down
32 changes: 21 additions & 11 deletions source/common/common/fine_grain_logger.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -154,10 +154,10 @@ class FineGrainLogContext {
ABSL_EXCLUSIVE_LOCKS_REQUIRED(fine_grain_log_lock_);

/**
* Returns the current log level of `file`. Default log level is used if there is no
* Returns the current log level of `key`. Default log level is used if there is no
* match in verbosity_update_info_.
*/
spdlog::level::level_enum getLogLevel(absl::string_view file) const
spdlog::level::level_enum getLogLevel(absl::string_view key) const
ABSL_SHARED_LOCKS_REQUIRED(fine_grain_log_lock_);

/**
Expand Down Expand Up @@ -194,12 +194,17 @@ FineGrainLogContext& getFineGrainLogContext();
* The local pointer is used to avoid another load() when logging. Here we use
* spdlog::logger* as atomic<shared_ptr> is a C++20 feature.
*/
#define FINE_GRAIN_LOGGER() \
([]() -> spdlog::logger* { \
#define FINE_GRAIN_LOGGER(NAME) \
([&]() -> spdlog::logger* { \
static std::atomic<spdlog::logger*> flogger{nullptr}; \
spdlog::logger* local_flogger = flogger.load(std::memory_order_acquire); \
if (!local_flogger) { \
::Envoy::getFineGrainLogContext().initFineGrainLogger(__FILE__, flogger); \
const std::string logger_name(NAME); \
std::string key = __FILE__; \
if (!logger_name.empty()) { \
key = key + ":" + logger_name; \
} \
::Envoy::getFineGrainLogContext().initFineGrainLogger(key, flogger); \
local_flogger = flogger.load(std::memory_order_acquire); \
} \
return local_flogger; \
Expand All @@ -208,9 +213,9 @@ FineGrainLogContext& getFineGrainLogContext();
/**
* Macro for fine-grain logger to log.
*/
#define FINE_GRAIN_LOG(LEVEL, ...) \
#define FINE_GRAIN_LOG(LEVEL, NAME, ...) \
do { \
spdlog::logger* local_flogger = FINE_GRAIN_LOGGER(); \
spdlog::logger* local_flogger = FINE_GRAIN_LOGGER(NAME); \
if (ENVOY_LOG_COMP_LEVEL(*local_flogger, LEVEL)) { \
local_flogger->log(spdlog::source_loc{__FILE__, __LINE__, __func__}, \
ENVOY_SPDLOG_LEVEL(LEVEL), __VA_ARGS__); \
Expand All @@ -221,22 +226,27 @@ FineGrainLogContext& getFineGrainLogContext();
* Convenient macro for connection log.
*/
#define FINE_GRAIN_CONN_LOG(LEVEL, FORMAT, CONNECTION, ...) \
FINE_GRAIN_LOG(LEVEL, "[C{}] " FORMAT, (CONNECTION).id(), ##__VA_ARGS__)
FINE_GRAIN_LOG(LEVEL, "", "[C{}] " FORMAT, (CONNECTION).id(), ##__VA_ARGS__)

/**
* Convenient macro for stream log.
*/
#define FINE_GRAIN_STREAM_LOG(LEVEL, FORMAT, STREAM, ...) \
FINE_GRAIN_LOG(LEVEL, "[C{}][S{}] " FORMAT, \
FINE_GRAIN_LOG(LEVEL, "", "[C{}][S{}] " FORMAT, \
(STREAM).connection() ? (STREAM).connection()->id() : 0, (STREAM).streamId(), \
##__VA_ARGS__)

/**
* Convenient macro for log flush.
*/
#define FINE_GRAIN_FLUSH_LOG() \
#define FINE_GRAIN_FLUSH_LOG(NAME) \
do { \
SpdLoggerSharedPtr p = ::Envoy::getFineGrainLogContext().getFineGrainLogEntry(__FILE__); \
const std::string logger_name(NAME); \
std::string key = __FILE__; \
if (!logger_name.empty()) { \
key = key + ":" + logger_name; \
} \
SpdLoggerSharedPtr p = ::Envoy::getFineGrainLogContext().getFineGrainLogEntry(key); \
if (p) { \
p->flush(); \
} \
Expand Down
2 changes: 1 addition & 1 deletion source/common/common/logger.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -174,7 +174,7 @@ void Context::changeAllLogLevels(spdlog::level::level_enum level) {
} else {
// Level setting with Fine-Grain Logger.
FINE_GRAIN_LOG(
info,
info, "",
"change all log levels and default verbosity level for fine grain loggers: level='{}'",
spdlog::level::level_string_views[level]);
getFineGrainLogContext().updateVerbosityDefaultLevel(level);
Expand Down
6 changes: 3 additions & 3 deletions source/common/common/logger.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -498,7 +498,7 @@ class ExtractedMessage : public spdlog::custom_flag_formatter {
*/
#define ENVOY_LOG_COMP_LEVEL_FINE_GRAIN_IF(LOGGER, LEVEL) \
(Envoy::Logger::Context::useFineGrainLogger() \
? (ENVOY_SPDLOG_LEVEL(LEVEL) >= (*FINE_GRAIN_LOGGER()).level()) \
? (ENVOY_SPDLOG_LEVEL(LEVEL) >= (*FINE_GRAIN_LOGGER(LOGGER.name())).level()) \
: (ENVOY_SPDLOG_LEVEL(LEVEL) >= (LOGGER).level()))

/**
Expand All @@ -523,7 +523,7 @@ class ExtractedMessage : public spdlog::custom_flag_formatter {
#define ENVOY_LOG_TO_LOGGER(LOGGER, LEVEL, ...) \
do { \
if (Envoy::Logger::should_log && Envoy::Logger::Context::useFineGrainLogger()) { \
FINE_GRAIN_LOG(LEVEL, ##__VA_ARGS__); \
FINE_GRAIN_LOG(LEVEL, LOGGER.name(), ##__VA_ARGS__); \
} else { \
ENVOY_LOG_COMP_AND_LOG(LOGGER, LEVEL, ##__VA_ARGS__); \
} \
Expand Down Expand Up @@ -775,7 +775,7 @@ using t_logclock = std::chrono::steady_clock; // NOLINT
#define ENVOY_FLUSH_LOG() \
do { \
if (Envoy::Logger::Context::useFineGrainLogger()) { \
FINE_GRAIN_FLUSH_LOG(); \
FINE_GRAIN_FLUSH_LOG(ENVOY_LOGGER().name()); \
} else { \
ENVOY_LOGGER().flush(); \
} \
Expand Down
4 changes: 2 additions & 2 deletions source/docs/fine_grain_log.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,8 +7,8 @@ Fine-Grain Logger is a logger with finer grained log level control and runtime l
### Basic Usage
The basic usage of Fine-Grain Logger is to explicitly call its macros:
```
FINE_GRAIN_LOG(info, "Hello world! Here's a line of fine-grain log!");
FINE_GRAIN_LOG(error, "FineGrainLog Error! Here's the second message!");
FINE_GRAIN_LOG(info, "", "Hello world! Here's a line of fine-grain log!");
FINE_GRAIN_LOG(error, "", "FineGrainLog Error! Here's the second message!");
```
If the level of log message is higher than that of the file, macros above will print messages with the file name like this:
```
Expand Down
2 changes: 1 addition & 1 deletion source/extensions/load_balancing_policies/common/thread_aware_lb_impl.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -42,7 +42,7 @@ class ThreadAwareLoadBalancerBase : public LoadBalancerBase, public ThreadAwareL
host->metadata().get(), Config::MetadataFilters::get().ENVOY_LB,
Config::MetadataEnvoyLbKeys::get().HASH_KEY);
if (val.kind_case() != val.kStringValue && val.kind_case() != val.KIND_NOT_SET) {
FINE_GRAIN_LOG(debug, "hash_key must be string type, got: {}",
FINE_GRAIN_LOG(debug, "", "hash_key must be string type, got: {}",
static_cast<int>(val.kind_case()));
}
absl::string_view hash_key = val.string_value();
Expand Down
4 changes: 4 additions & 0 deletions source/server/admin/admin.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -198,6 +198,10 @@ AdminImpl::AdminImpl(const std::string& profile_path, Server::Instance& server,
"If fine grain logging is enabled, use __FILE__ or a glob experision as "
"the logger name. "
"For example, source/common*:warning"},
{Admin::ParamDescriptor::Type::String, "group",
"Change given logger group to desired level, set to "
"<logger_group_name>:<desired_level>. "
"logger_group_name can be a logger name or a glob expression."},
{Admin::ParamDescriptor::Type::Enum, "level",
"desired logging level, this will change all loggers's level",
prepend("", LogsHandler::levelStrings())}}),
Expand Down
99 changes: 61 additions & 38 deletions source/server/admin/logs_handler.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,12 +1,14 @@
#include "source/server/admin/logs_handler.h"

#include <string>
#include <vector>

#include "source/common/common/fine_grain_logger.h"
#include "source/common/common/logger.h"
#include "source/server/admin/utils.h"

#include "absl/strings/str_split.h"
#include "fmt/format.h"

namespace Envoy {
namespace Server {
Expand Down Expand Up @@ -50,6 +52,7 @@ Http::Code LogsHandler::handlerLogging(Http::ResponseHeaderMap&, Buffer::Instanc
response.add("usage: /logging?<name>=<level> (change single level)\n");
response.add("usage: /logging?paths=name1:level1,name2:level2,... (change multiple levels)\n");
response.add("usage: /logging?level=<level> (change all levels)\n");
response.add("usage: /logging?group=<group_name>:<level> (change group of loggers)\n");
response.add("levels: ");
for (auto level_string_view : spdlog::level::level_string_views) {
response.add(fmt::format("{} ", level_string_view));
Expand Down Expand Up @@ -83,30 +86,33 @@ Http::Code LogsHandler::handlerReopenLogs(Http::ResponseHeaderMap&, Buffer::Inst
}

absl::Status LogsHandler::changeLogLevel(Http::Utility::QueryParamsMulti& params) {
// "level" and "paths" will be set to the empty string when this is invoked
// from HTML without setting them, so clean out empty values.
auto level = params.getFirstValue("level");
if (level.has_value() && level.value().empty()) {
params.remove("level");
level = std::nullopt;
}
auto paths = params.getFirstValue("paths");
if (paths.has_value() && paths.value().empty()) {
params.remove("paths");
paths = std::nullopt;
// Identify active non-empty parameters.
std::string active_key;
std::string active_value;
int active_params_count = 0;

for (auto const& [key, values] : params.data()) {
if (values.empty() || values[0].empty()) {
continue;
}
active_params_count++;
active_key = key;
active_value = values[0];
}

if (params.data().empty()) {
if (active_params_count == 0) {
return absl::OkStatus();
}

if (params.data().size() != 1) {
if (active_params_count != 1) {
return absl::InvalidArgumentError("invalid number of parameters");
}

if (level.has_value()) {
const bool use_fine_grain_logger = Logger::Context::useFineGrainLogger();

if (active_key == "level") {
// Change all log levels.
const absl::StatusOr<spdlog::level::level_enum> level_to_use = parseLogLevel(level.value());
const absl::StatusOr<spdlog::level::level_enum> level_to_use = parseLogLevel(active_value);
if (!level_to_use.ok()) {
return level_to_use.status();
}
Expand All @@ -119,21 +125,20 @@ absl::Status LogsHandler::changeLogLevel(Http::Utility::QueryParamsMulti& params
// not common to call this function at a high rate.
absl::flat_hash_map<absl::string_view, spdlog::level::level_enum> name_levels;
std::vector<std::pair<absl::string_view, int>> glob_levels;
const bool use_fine_grain_logger = Logger::Context::useFineGrainLogger();

if (paths.has_value()) {
if (active_key == "paths") {
// Bulk change log level by name:level pairs, separated by comma.
std::vector<absl::string_view> pairs =
absl::StrSplit(paths.value(), ',', absl::SkipWhitespace());
absl::StrSplit(active_value, ',', absl::SkipWhitespace());
for (const auto& name_level : pairs) {
const std::pair<absl::string_view, absl::string_view> name_level_pair =
absl::StrSplit(name_level, absl::MaxSplits(':', 1), absl::SkipWhitespace());
auto [name, level] = name_level_pair;
if (name.empty() || level.empty()) {
auto [name, level_str] = name_level_pair;
if (name.empty() || level_str.empty()) {
return absl::InvalidArgumentError("empty logger name or empty logger level");
}

const absl::StatusOr<spdlog::level::level_enum> level_to_use = parseLogLevel(level);
const absl::StatusOr<spdlog::level::level_enum> level_to_use = parseLogLevel(level_str);
if (!level_to_use.ok()) {
return level_to_use.status();
}
Expand All @@ -146,31 +151,49 @@ absl::Status LogsHandler::changeLogLevel(Http::Utility::QueryParamsMulti& params
name_levels[name] = *level_to_use;
}
}
} else {
// The HTML admin interface will always populate "level" and "paths" though
// they may be empty. There's a legacy non-HTML-accessible mechanism to
// set a single logger to a level, which we'll handle now. In this scenario,
// "level" and "paths" will not be populated.
if (params.data().size() != 1) {
return absl::InvalidArgumentError("invalid number of parameters");
} else if (active_key == "group") {
// Group parameter requires fine-grain logging to be enabled
if (!use_fine_grain_logger) {
return absl::InvalidArgumentError(
"group parameter requires fine-grain logging to be enabled");
}

// Change particular log level by name.
const auto it = params.data().begin();
const std::string& key = it->first;
const std::string& value = it->second[0];

const absl::StatusOr<spdlog::level::level_enum> level_to_use = parseLogLevel(value);
const std::pair<absl::string_view, absl::string_view> name_level_pair =
absl::StrSplit(active_value, absl::MaxSplits(':', 1), absl::SkipWhitespace());
auto [name, level_str] = name_level_pair;
if (name.empty() || level_str.empty()) {
return absl::InvalidArgumentError("empty logger name or empty logger level in group");
}
const absl::StatusOr<spdlog::level::level_enum> level_to_use = parseLogLevel(level_str);
if (!level_to_use.ok()) {
return level_to_use.status();
}
if (Logger::Registry::logger(std::string(name)) != nullptr) {
ENVOY_LOG(info, "adding fine-grain log update, glob='{}' level='{}'", name,
spdlog::level::level_string_views[*level_to_use]);
glob_levels.emplace_back(name, *level_to_use);
} else {
return absl::InvalidArgumentError(fmt::format("unknown logger group: {}", name));
}
} else {
// Change particular log level by name (legacy non-HTML mechanism).
const absl::StatusOr<spdlog::level::level_enum> level_to_use = parseLogLevel(active_value);
if (!level_to_use.ok()) {
return level_to_use.status();
}

if (use_fine_grain_logger) {
ENVOY_LOG(info, "adding fine-grain log update, glob='{}' level='{}'", key,
ENVOY_LOG(info, "adding fine-grain log update, glob='{}' level='{}'", active_key,
spdlog::level::level_string_views[*level_to_use]);
glob_levels.emplace_back(key, *level_to_use);
glob_levels.emplace_back(active_key, *level_to_use);
} else {
name_levels[key] = *level_to_use;
if (active_key == "level" || active_key == "paths" || active_key == "group") {
if (active_key == "group") {
return absl::InvalidArgumentError(
"group parameter requires fine-grain logging to be enabled");
}
return absl::InvalidArgumentError(fmt::format("invalid parameter: {}", active_key));
}
name_levels[active_key] = *level_to_use;
}
}

Expand Down
1 change: 1 addition & 0 deletions source/server/admin/logs_handler.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@
#include "envoy/server/admin.h"
#include "envoy/server/instance.h"

#include "source/common/common/logger.h"
#include "source/server/admin/handler_ctx.h"

#include "absl/container/flat_hash_map.h"
Expand Down
Loading
Loading