diff --git a/docs/root/operations/cli.rst b/docs/root/operations/cli.rst index a14f7efe97f43..a4729f1e3f078 100644 --- a/docs/root/operations/cli.rst +++ b/docs/root/operations/cli.rst @@ -94,7 +94,13 @@ following are the command line options that Envoy supports. *(optional)* The format string to use for laying out the log message metadata. If this is not set, a default format string ``"[%Y-%m-%d %T.%e][%t][%l][%n] %v"`` is used. - When used in conjunction with ``--log-format-escaped``, the logger can be configured + When used in conjunction with :option:`--log-format-prefix-with-location` set to 0, the logger can be + configured to not prefix ``%v`` by a file path and a line number. + + **NOTE**: The default log format will be changed to ``"[%Y-%m-%d %T.%e][%t][%l][%n] [%g:%#] %v"`` + together with the default value of :option:`--log-format-prefix-with-location` to 0 at 1.16.0 release. + + When used in conjunction with :option:`--log-format-escaped`, the logger can be configured to log in a format that is parsable by log viewers. Known integrations are documented in the :ref:`application logging configuration ` section. @@ -129,6 +135,20 @@ following are the command line options that Envoy supports. :%T, %X: ISO 8601 time format (HH:MM:SS), equivalent to %H:%M:%S ("13:25:06") :%z: ISO 8601 offset from UTC in timezone ([+/-]HH:MM) ("-07:00") :%%: The % sign ("%") + :%@: Source file and line ("my_file.cc:123") + :%s: Basename of the source file ("my_file.cc") + :%g: Full relative path of the source file ("/some/dir/my_file.cc") + :%#: Source line ("123") + :%!: Source function ("myFunc") + +.. option:: --log-format-prefix-with-location <1|0> + + *(optional)* This temporary flag allows replacing all entries of ``"%v"`` in the log format by + ``"[%g:%#] %v"``. This flag is provided for migration purposes only. If this is not set, a + default value 1 is used. + + **NOTE**: The default value will be changed to 0 at 1.16.0 release and the flag will be + removed at 1.17.0 release. .. option:: --log-format-escaped diff --git a/docs/root/version_history/current.rst b/docs/root/version_history/current.rst index 662f014a72d2a..a445ccfb421e5 100644 --- a/docs/root/version_history/current.rst +++ b/docs/root/version_history/current.rst @@ -15,6 +15,7 @@ Changes `google.api.HttpBody `_. * http: fixed a bug where the upgrade header was not cleared on responses to non-upgrade requests. Can be reverted temporarily by setting runtime feature `envoy.reloadable_features.fix_upgrade_response` to false. +* logger: added :ref:`--log-format-prefix-with-location ` command line option to prefix '%v' with file path and line number. * network filters: added a :ref:`postgres proxy filter `. * router: allow retries of streaming or incomplete requests. This removes stat `rq_retry_skipped_request_not_complete`. * tracing: tracing configuration has been made fully dynamic and every HTTP connection manager diff --git a/source/common/common/logger.h b/source/common/common/logger.h index 324d08e476a28..30b44628076dc 100644 --- a/source/common/common/logger.h +++ b/source/common/common/logger.h @@ -282,19 +282,15 @@ template class Loggable { } // namespace Logger -// Convert the line macro to a string literal for concatenation in log macros. -#define DO_STRINGIZE(x) STRINGIZE(x) -#define STRINGIZE(x) #x -#define LINE_STRING DO_STRINGIZE(__LINE__) -#define LOG_PREFIX "[" __FILE__ ":" LINE_STRING "] " - /** * Base logging macros. It is expected that users will use the convenience macros below rather than * invoke these directly. */ -#define ENVOY_LOG_COMP_LEVEL(LOGGER, LEVEL) \ - (static_cast(Envoy::Logger::Logger::LEVEL) >= LOGGER.level()) +#define ENVOY_SPDLOG_LEVEL(LEVEL) \ + (static_cast(Envoy::Logger::Logger::LEVEL)) + +#define ENVOY_LOG_COMP_LEVEL(LOGGER, LEVEL) (ENVOY_SPDLOG_LEVEL(LEVEL) >= LOGGER.level()) // Compare levels before invoking logger. This is an optimization to avoid // executing expressions computing log contents when they would be suppressed. @@ -302,7 +298,8 @@ template class Loggable { #define ENVOY_LOG_COMP_AND_LOG(LOGGER, LEVEL, ...) \ do { \ if (ENVOY_LOG_COMP_LEVEL(LOGGER, LEVEL)) { \ - LOGGER.LEVEL(LOG_PREFIX __VA_ARGS__); \ + LOGGER.log(::spdlog::source_loc{__FILE__, __LINE__, __func__}, ENVOY_SPDLOG_LEVEL(LEVEL), \ + __VA_ARGS__); \ } \ } while (0) diff --git a/source/server/options_impl.cc b/source/server/options_impl.cc index f054546f11c7f..e2ca56f39e26b 100644 --- a/source/server/options_impl.cc +++ b/source/server/options_impl.cc @@ -15,6 +15,7 @@ #include "server/options_impl_platform.h" +#include "absl/strings/str_replace.h" #include "absl/strings/str_split.h" #include "absl/strings/string_view.h" #include "spdlog/spdlog.h" @@ -92,6 +93,11 @@ OptionsImpl::OptionsImpl(std::vector args, TCLAP::SwitchArg log_format_escaped("", "log-format-escaped", "Escape c-style escape sequences in the application logs", cmd, false); + TCLAP::ValueArg log_format_prefix_with_location( + "", "log-format-prefix-with-location", + "Prefix all occurrences of '%v' in log format with with '[%g:%#] ' ('[path/to/file.cc:99] " + "').", + false, true, "bool", cmd); TCLAP::ValueArg log_path("", "log-path", "Path to logfile", false, "", "string", cmd); TCLAP::ValueArg restart_epoch("", "restart-epoch", "hot restart epoch #", false, 0, @@ -168,6 +174,9 @@ OptionsImpl::OptionsImpl(std::vector args, } log_format_ = log_format.getValue(); + if (log_format_prefix_with_location.getValue()) { + log_format_ = absl::StrReplaceAll(log_format_, {{"%%", "%%"}, {"%v", "[%g:%#] %v"}}); + } log_format_escaped_ = log_format_escaped.getValue(); parseComponentLogLevels(component_log_level.getValue()); diff --git a/test/server/options_impl_test.cc b/test/server/options_impl_test.cc index 2ec9f3cb90a46..efb4b2565f2dd 100644 --- a/test/server/options_impl_test.cc +++ b/test/server/options_impl_test.cc @@ -48,6 +48,11 @@ class OptionsImplTest : public testing::Test { return std::make_unique( std::move(words), [](bool) { return "1"; }, spdlog::level::warn); } + + std::unique_ptr createOptionsImpl(std::vector args) { + return std::make_unique( + std::move(args), [](bool) { return "1"; }, spdlog::level::warn); + } }; TEST_F(OptionsImplTest, HotRestartVersion) { @@ -90,7 +95,7 @@ TEST_F(OptionsImplTest, All) { EXPECT_EQ(1U, options->restartEpoch()); EXPECT_EQ(spdlog::level::info, options->logLevel()); EXPECT_EQ(2, options->componentLogLevels().size()); - EXPECT_EQ("[%v]", options->logFormat()); + EXPECT_EQ("[[%g:%#] %v]", options->logFormat()); EXPECT_EQ("/foo/bar", options->logPath()); EXPECT_EQ("cluster", options->serviceClusterName()); EXPECT_EQ("node", options->serviceNodeName()); @@ -256,7 +261,8 @@ TEST_F(OptionsImplTest, OptionsAreInSyncWithProto) { // 4. allow-unknown-fields - deprecated alias of allow-unknown-static-fields. // 5. use-fake-symbol-table - short-term override for rollout of real symbol-table implementation. // 6. hot restart version - print the hot restart version and exit. - EXPECT_EQ(options->count() - 6, command_line_options->GetDescriptor()->field_count()); + // 7. log-format-prefix-with-location - short-term override for rollout of dynamic log format. + EXPECT_EQ(options->count() - 7, command_line_options->GetDescriptor()->field_count()); } TEST_F(OptionsImplTest, OptionsFromArgv) { @@ -401,6 +407,30 @@ TEST_F(OptionsImplTest, SetCpusetOnly) { EXPECT_NE(options->concurrency(), 0); } +TEST_F(OptionsImplTest, LogFormatDefault) { + std::unique_ptr options = createOptionsImpl({"envoy", "-c", "hello"}); + EXPECT_EQ(options->logFormat(), "[%Y-%m-%d %T.%e][%t][%l][%n] [%g:%#] %v"); +} + +TEST_F(OptionsImplTest, LogFormatDefaultNoPrefix) { + std::unique_ptr options = + createOptionsImpl({"envoy", "-c", "hello", "--log-format-prefix-with-location", "0"}); + EXPECT_EQ(options->logFormat(), "[%Y-%m-%d %T.%e][%t][%l][%n] %v"); +} + +TEST_F(OptionsImplTest, LogFormatOverride) { + std::unique_ptr options = + createOptionsImpl({"envoy", "-c", "hello", "--log-format", "%%v %v %t %v"}); + EXPECT_EQ(options->logFormat(), "%%v [%g:%#] %v %t [%g:%#] %v"); +} + +TEST_F(OptionsImplTest, LogFormatOverrideNoPrefix) { + std::unique_ptr options = + createOptionsImpl({"envoy", "-c", "hello", "--log-format", "%%v %v %t %v", + "--log-format-prefix-with-location 0"}); + EXPECT_EQ(options->logFormat(), "%%v %v %t %v"); +} + #if defined(__linux__) using testing::DoAll;