From 0dfa3df2ea413fa25ab2cb206957e6ec150d7271 Mon Sep 17 00:00:00 2001 From: Ryan Hamilton Date: Mon, 27 Sep 2021 13:20:17 -0700 Subject: [PATCH] alternate_protocols_cache: Move alternate_protocols_cache logging to the alternate_protocols_cache log ID. (#18224) alternate_protocols_cache: Move alternate_protocols_cache logging to the alternate_protocols_cache log ID. Also add a new doc which describes how Envoy logging works. Risk Level: Low Testing: N/A Docs Changes: Add a new doc: source/docs/logging.md Release Notes: N/A Platform Specific Features: N/A Signed-off-by: Ryan Hamilton --- source/common/common/logger.h | 4 +- .../http/alternate_protocols_cache_impl.h | 5 +- source/docs/logging.md | 89 +++++++++++++++++++ .../http/alternate_protocols_cache/filter.h | 3 +- 4 files changed, 98 insertions(+), 3 deletions(-) create mode 100644 source/docs/logging.md diff --git a/source/common/common/logger.h b/source/common/common/logger.h index fdae426b8acf..284ca290df5d 100644 --- a/source/common/common/logger.h +++ b/source/common/common/logger.h @@ -28,6 +28,7 @@ namespace Logger { // TODO: find out a way for extensions to register new logger IDs #define ALL_LOGGER_IDS(FUNCTION) \ FUNCTION(admin) \ + FUNCTION(alternate_protocols_cache) \ FUNCTION(aws) \ FUNCTION(assert) \ FUNCTION(backtrace) \ @@ -332,9 +333,10 @@ template class Loggable { protected: /** * Do not use this directly, use macros defined below. + * See source/docs/logging.md for more details. * @return spdlog::logger& the static log instance to use for class local logging. */ - static spdlog::logger& __log_do_not_use_read_comment() { + static spdlog::logger& __log_do_not_use_read_comment() { // NOLINT(readability-identifier-naming) static spdlog::logger& instance = Registry::getLog(id); return instance; } diff --git a/source/common/http/alternate_protocols_cache_impl.h b/source/common/http/alternate_protocols_cache_impl.h index df216bf0407c..d6e28eb5333d 100644 --- a/source/common/http/alternate_protocols_cache_impl.h +++ b/source/common/http/alternate_protocols_cache_impl.h @@ -10,6 +10,8 @@ #include "envoy/common/time.h" #include "envoy/http/alternate_protocols_cache.h" +#include "source/common/common/logger.h" + #include "absl/strings/string_view.h" namespace Envoy { @@ -17,7 +19,8 @@ namespace Http { // An implementation of AlternateProtocolsCache. // See: source/docs/http3_upstream.md -class AlternateProtocolsCacheImpl : public AlternateProtocolsCache { +class AlternateProtocolsCacheImpl : public AlternateProtocolsCache, + Logger::Loggable { public: AlternateProtocolsCacheImpl(TimeSource& time_source, std::unique_ptr&& store); ~AlternateProtocolsCacheImpl() override; diff --git a/source/docs/logging.md b/source/docs/logging.md new file mode 100644 index 000000000000..965a50f77048 --- /dev/null +++ b/source/docs/logging.md @@ -0,0 +1,89 @@ +### Overview + +Envoy uses the [spdlog library](https://github.com/gabime/spdlog#readme) for logging +through a variety of Envoy specific macros. + +### Concepts + +#### Level + +Log messages are emitted with a log level chosen from one of the following: +* trace +* debug +* info +* warn +* error +* critical + +This log level can be used to restrict which log messages are actually +shown via the `setLevel()` method of `Envoy::Logger::Logger` or via the command +line argument `--l `. Any messages which has a level less than the specified +level will be squelched. + +In addition, the log level is typically show in the emitted log line. For example +in the following line, you can see the level is `debug`: + +``` +[2021-09-22 18:39:01.268][28][debug][pool] [source/common/conn_pool/conn_pool_base.cc:293] [C18299946955195659044] attaching to next stream +``` + +#### ID + +In addition the the level, every log is emitted with an ID. This ID is not +a numeric ID (like a stream ID or a connection ID) but is instead a token that +is used to groups log messages in by category. The list of known ID is defined +in `ALL_LOGGER_IDS` from `source/common/common/logger.h`. Similar to level, these +IDs show up in log lines. For example in the following line, you can see the +ID is `pool`: + +``` +[2021-09-22 18:39:01.268][28][debug][pool] [source/common/conn_pool/conn_pool_base.cc:293] [C18299946955195659044] attaching to next stream +``` + +### APIs + +#### ENVOY_LOG + +Most log messages in Envoy are generated via the `ENVOY_LOG()` macro. For example: + +``` +ENVOY_LOG(debug, "subset lb: fallback load balancer disabled"); +``` + +This macro takes the log level as the first argument and the log message as the +second argument. However the ID is not explicitly specified. Instead, the ID +typically comes via the class inheriting from `Logger::Loggable`. By doing this, +`ENVOY_LOG()` calls are able to find the relevant log ID. + +#### ENVOY_LOG_TO_LOGGER + +Under some circumstances, code will not be in a method of a class which extends +`Loggable`. In those cases, there are a couple of options. One is to use +`ENVOY_LOG_TO_LOGGER` and pass in an existing logger. This logger can come via +the caller, or by requesting the logger for a specific ID. For example: + +``` + ENVOY_LOG_TO_LOGGER(Envoy::Logger::Registry::getLog(Envoy::Logger::Id::pool), warn, + "Failed to create Http/3 client. Transport socket " + "factory is not configured correctly."); +``` + +#### ENVOY_LOG_MISC + +As a last resort, the `ENVOY_LOG_MISC` macro can be used to log with the `misc` ID. For +example: + +``` +ENVOY_LOG_MISC(warn, "failed to enable core dump"); +``` +However, it is usually much better to log to a more specific ID. + +#### ENVOY_CONN_LOG / ENVOY_STREAM_LOG + +There is another API which can be used specifically for `Connection` or `Stream` +related log messages. `ENVOY_CONN_LOG` takes an additional `Connection` argument +and `ENVOY_STREAM_LOG` takes an additional `Stream` argument. These macros work +like `ENVOY_LOG` except that they prepend the log message with `[C123]` or +`[C123][S456` based on the connection/stream ID of the specified argument. +Note that the IDs here are the Envoy IDs *NOT* the on-the-wire IDs from HTTP/2 +or HTTP/3. diff --git a/source/extensions/filters/http/alternate_protocols_cache/filter.h b/source/extensions/filters/http/alternate_protocols_cache/filter.h index a77d30f672a1..f15bcee161d2 100644 --- a/source/extensions/filters/http/alternate_protocols_cache/filter.h +++ b/source/extensions/filters/http/alternate_protocols_cache/filter.h @@ -39,7 +39,8 @@ using FilterConfigSharedPtr = std::shared_ptr; * Alternate protocol cache filter which parses the alt-svc response header and updates * the cache accordingly. */ -class Filter : public Http::PassThroughEncoderFilter, Logger::Loggable { +class Filter : public Http::PassThroughEncoderFilter, + Logger::Loggable { public: explicit Filter(const FilterConfigSharedPtr& config);