logger: implement Fancy Logger with fine-grained log control #11822

PrinceS17 · 2020-06-30T17:44:58Z

Commit Message: Implement a new logger called Fancy Logger with fine-grained control, e.g. file, function and line level.

Additional Description: Some new macros are defined for basic usage but not hooked with any existing log macros. API for the logger is still in progress.

Risk Level: Low
Testing: unit test & benchmark
Docs Changes: None
Release Notes: None

alyssawilk

Very exciting - all us googlers miss having vlogs :-)

I think as long as benchmarks show that with fancy-mode off the performance changes are negligible we can do this inline. Meanwhile I'd encourage you to check out your CI results (doing a master merge might fix - we were having CI problems last week) @penguingao would you be up for first pass?

penguingao

Flushing out some readability comments first. I'll read the code more carefully later.

source/common/common/logger.cc

source/common/common/logger.h

source/common/common/fancy_logger.cc

penguingao · 2020-07-07T13:00:00Z

source/common/common/logger.h

+
+extern FancyMapPtr getFancyLogMap();
+
+extern void setFancyLogger(std::string key, spdlog::level::level_enum log_level);


Why do you need extern for these functions?

If you simply want to declare and use them in the macros, would it make sense to create a fancy_logger.h and group these just there?

Indeed I don't. Addressed now.

source/common/common/fancy_logger.cc

source/common/common/logger.h

source/common/common/fancy_logger.cc

Signed-off-by: Jinhui Song <jinhuisong@google.com>

PrinceS17 · 2020-07-10T15:38:43Z

/retest

repokitteh-read-only · 2020-07-10T15:38:45Z

🤷‍♀️ nothing to rebuild.

🐱

Caused by: a #11822 (comment) was created by @PrinceS17.

see: more, trace.

source/common/common/fancy_logger.cc

source/common/common/fancy_logger.h

source/common/common/fancy_logger.cc

penguingao · 2020-07-10T18:12:09Z

source/common/common/logger.cc

  Registry::getSink()->setLock(lock_);
  Registry::getSink()->set_should_escape(should_escape_);
  Registry::setLogLevel(log_level_);
  Registry::setLogFormat(log_format_);
+
+  if (mode == LoggerMode::Fancy) {


I am not sure this is the right place to set your default log level. class Context is used to override logging behavior when it is created and restore the previous behavior when it is destructed.

But getFancyDefaultLevel is only used once for each log key (file name), meaning the Context class does not affect fancy log's behavior once fancy log is initialized.

I think the better way is to provide a pair of function in FancyContext that iterates through the loggers and change their log level and format.

The function is added in FancyContext to enable later update of default level/format of different Context, and it's called in activate() now. But I think it's still necessary to set the default level in Context() as the map isn't complete when the 1st Context is initialized.

Maybe make fancy_default_level_ and fancy_log_format_ non-static member? You can access them via the current_context_ global var. I think this makes it clearer about the life span of the fancy_default_level_ and fancy_log_format_.

Seems making them non-static needs another variable to represent the previous default level. Currently I set default before setting fancy_default_level so that I can compare new level with the old one.

Signed-off-by: Jinhui Song <jinhuisong@google.com>

PrinceS17 · 2020-07-15T15:37:37Z

/retest

repokitteh-read-only · 2020-07-15T15:37:40Z

🤷‍♀️ nothing to rebuild.

🐱

Caused by: a #11822 (comment) was created by @PrinceS17.

see: more, trace.

Signed-off-by: Jinhui Song <jinhuisong@google.com>

penguingao

LGTM! modulo some more nits.

source/common/common/fancy_logger.h

penguingao · 2020-07-16T13:14:20Z

source/common/common/fancy_logger.h

+    spdlog::logger* local_flogger = flogger.load(std::memory_order_relaxed);                       \
+    if (!local_flogger) {                                                                          \
+      FancyContext::initFancyLogger(FANCY_KEY, flogger);                                           \
+      flogger.load(std::memory_order_relaxed)                                                      \


nit: If you want to avoid the duplicated log(spdlog::source_loc{}...) call, you can do local_flogger = flogger.load() here. Remove the else condition. So:

if (!local_flogger) {
FancyContext::initFancyLogger(FANCY_KEY, flogger);
local_flogger = flogger.load(std::memory_order_relaxed);
}
local_flogger.log(...)

Addressed. I didn't thought of that

penguingao · 2020-07-16T13:18:28Z

source/common/common/fancy_logger.cc

+  return false;
+}
+
+void FancyContext::setDefaultFancyLevelFormat(spdlog::level::level_enum level, std::string format)


I think you want to compare the previous default level vs the new default level. So that you can avoid the for loop if nothing changes.

Also, you can compare the logger's log level vs default log level so that you can avoid overriding the log level set to non default value.

Sure. About the later comment: if fancy_default_level & fancy_log_format are made non-static, it seems I need another variable for previous default level & format. So I keep them static for now...

penguingao · 2020-07-16T13:23:11Z

source/common/common/logger.cc

  Registry::getSink()->setLock(lock_);
  Registry::getSink()->set_should_escape(should_escape_);
  Registry::setLogLevel(log_level_);
  Registry::setLogFormat(log_format_);
+
+  if (mode == LoggerMode::Fancy) {


Maybe make fancy_default_level_ and fancy_log_format_ non-static member? You can access them via the current_context_ global var. I think this makes it clearer about the life span of the fancy_default_level_ and fancy_log_format_.

test/common/common/log_macros_test.cc

Signed-off-by: Jinhui Song <jinhuisong@google.com>

lizan · 2020-07-23T12:22:48Z

source/common/common/BUILD

@@ -137,8 +137,14 @@ envoy_cc_library(
 # Contains minimal code for logging to stderr.
 envoy_cc_library(
    name = "minimal_logger_lib",
-    srcs = ["logger.cc"],
-    hdrs = ["logger.h"],
+    srcs = [


split this to a separate target? this is no longer minimal with fancy logger

In the next PR I plan to hook ENVOY_LOG with FANCY_LOG (with option provided to developers), and logically I think Fancy logger will be part of the logger as we need to include fancy_logger.h in that case?

still, in the next PR you can just change their names?

So you mean using another name like "fancy_logger_lib" for readability and keep current lib structure?

@lizan Could you please give some clarification on which names you want me to change (or the lib structure)? Because the change of "minimal_logger_lib" seems unnecessary and very dirty. Thanks!

Thanks this is now looks better.

source/common/common/fancy_logger.h

source/common/common/logger.h

Signed-off-by: Jinhui Song <jinhuisong@google.com>

source/common/common/fancy_logger.h

lizan · 2020-07-24T02:23:29Z

source/common/common/BUILD

@@ -137,8 +137,14 @@ envoy_cc_library(
 # Contains minimal code for logging to stderr.
 envoy_cc_library(
    name = "minimal_logger_lib",
-    srcs = ["logger.cc"],
-    hdrs = ["logger.h"],
+    srcs = [


still, in the next PR you can just change their names?

Signed-off-by: Jinhui Song <jinhuisong@google.com>

lizan

Last set of nit, otherwise LGTM

lizan · 2020-07-28T06:21:53Z

test/common/common/BUILD

@@ -105,7 +105,9 @@ envoy_cc_test(
 envoy_cc_test(
    name = "log_macros_test",
    srcs = ["log_macros_test.cc"],
+    external_deps = ["benchmark"],


Deleted now.

lizan · 2020-07-28T06:22:38Z

test/common/common/BUILD

@@ -114,6 +116,21 @@ envoy_cc_test(
    ],
 )

+envoy_cc_benchmark_binary(
+    name = "logger_perf_test",
+    srcs = ["logger_perf_test.cc"],


We name this *_speed_test for rest benchmarks, can you rename this one too? same for below

lizan · 2020-07-28T06:23:04Z

test/common/common/logger_perf_test.cc

+  FANCY_LOG(info, "Slow path test begins.");
+  std::atomic<spdlog::logger*> logger;
+  for (auto _ : state) {
+    (void)_;


Suggested change

(void)_;

UNREFERENCED_PARAMETER(_);

…ance test. Signed-off-by: Jinhui Song <jinhuisong@google.com>

PrinceS17 · 2020-07-29T15:08:28Z

@lizan Could you please help merge my branch as all checks have passed? Thanks!

…oxy#11822) Implement a new logger called Fancy Logger with fine-grained control, e.g. file, function and line level. Additional Description: Some new macros are defined for basic usage but not hooked with any existing log macros. API for the logger is still in progress. Risk Level: Low Testing: unit test & benchmark Docs Changes: None Release Notes: None Signed-off-by: Jinhui Song <jinhuisong@google.com>

…oxy#11822) Implement a new logger called Fancy Logger with fine-grained control, e.g. file, function and line level. Additional Description: Some new macros are defined for basic usage but not hooked with any existing log macros. API for the logger is still in progress. Risk Level: Low Testing: unit test & benchmark Docs Changes: None Release Notes: None Signed-off-by: Jinhui Song <jinhuisong@google.com> Signed-off-by: chaoqinli <chaoqinli@google.com>

PrinceS17 marked this pull request as ready for review June 30, 2020 17:45

PrinceS17 marked this pull request as draft June 30, 2020 21:40

ggreenway assigned alyssawilk Jul 6, 2020

alyssawilk reviewed Jul 6, 2020

View reviewed changes

alyssawilk assigned penguingao Jul 6, 2020

penguingao reviewed Jul 7, 2020

View reviewed changes

Latest change from patch; fix DCO.

d618b96

Signed-off-by: Jinhui Song <jinhuisong@google.com>

PrinceS17 force-pushed the fancy-pr branch 3 times, most recently from e0ed7f8 to d618b96 Compare July 10, 2020 03:55

Merge branch 'master' into fancy-pr

37a250d

Signed-off-by: Jinhui Song <jinhuisong@google.com>

PrinceS17 marked this pull request as ready for review July 10, 2020 14:44

penguingao reviewed Jul 10, 2020

View reviewed changes

PrinceS17 added 4 commits July 11, 2020 00:22

Polich 2nd round: comments.

7a19aec

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Second round polish: thread annotation & context.

f8557e2

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Second round: polish some missing comments.

d75359f

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Fix FANCY_LOG comment.

688f9ce

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Add comment for getFancyLogEntry.

2c33098

Signed-off-by: Jinhui Song <jinhuisong@google.com>

This comment has been minimized.

Sign in to view

penguingao previously approved these changes Jul 16, 2020

View reviewed changes

Third round: default fancy level, etc.

5a30d45

Signed-off-by: Jinhui Song <jinhuisong@google.com>

PrinceS17 dismissed penguingao’s stale review via ad378f6 July 17, 2020 20:04

PrinceS17 force-pushed the fancy-pr branch 2 times, most recently from 5a30d45 to 2c33098 Compare July 18, 2020 00:44

PrinceS17 added 2 commits July 18, 2020 02:26

Format fix in fancy_logger.cc.

c1bac45

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Add test for setting & getting default level & format.

79de63b

Signed-off-by: Jinhui Song <jinhuisong@google.com>

PrinceS17 added 4 commits July 22, 2020 23:01

Trivial change to test again..

e6cdcff

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Merge branch 'master' into fancy-pr

af43922

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Use setShouldEscape to comply with new master.

1b996a6

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Trivial comment change to retest.

aa69a58

Signed-off-by: Jinhui Song <jinhuisong@google.com>

lizan suggested changes Jul 23, 2020

View reviewed changes

PrinceS17 added 6 commits July 23, 2020 21:48

Fourth round: convert FancyContext into singleton.

f86e8d0

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Convert fancy default to non-static.

1410fa6

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Fix format.

1ba45df

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Adjust macro.h for format.

64b7dcc

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Merge branch 'master' into fancy-pr

c07c27b

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Fix get default level/format when Context is not instantiated.

8e176bf

Signed-off-by: Jinhui Song <jinhuisong@google.com>

lizan reviewed Jul 24, 2020

View reviewed changes

PrinceS17 added 8 commits July 24, 2020 02:29

Add do{} while(0) for flush.

371a241

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Merge branch 'master' into fancy-pr

4a34abd

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Merge branch 'master' into fancy-pr

8283b20

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Merge branch 'master' into fancy-pr

aad7d0d

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Split the build target.

aadd93e

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Fix format.

458011f

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Merge branch 'master' into fancy-pr

0446dcd

Signed-off-by: Jinhui Song <jinhuisong@google.com>

Trivial change to retest.

d5f006e

Signed-off-by: Jinhui Song <jinhuisong@google.com>

lizan approved these changes Jul 28, 2020

View reviewed changes

lizan suggested changes Jul 28, 2020

View reviewed changes

Remove benchmark dependency for test's BUILD; rename & polish perform…

e791d56

…ance test. Signed-off-by: Jinhui Song <jinhuisong@google.com>

lizan approved these changes Jul 28, 2020

View reviewed changes

lizan merged commit c1d116e into envoyproxy:master Jul 29, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

logger: implement Fancy Logger with fine-grained log control #11822

logger: implement Fancy Logger with fine-grained log control #11822

PrinceS17 commented Jun 30, 2020

alyssawilk left a comment

penguingao left a comment

penguingao Jul 7, 2020

PrinceS17 Jul 7, 2020

PrinceS17 commented Jul 10, 2020

repokitteh-read-only bot commented Jul 10, 2020

penguingao Jul 10, 2020

PrinceS17 Jul 14, 2020

penguingao Jul 16, 2020

PrinceS17 Jul 18, 2020

PrinceS17 commented Jul 15, 2020

repokitteh-read-only bot commented Jul 15, 2020

This comment has been minimized.

penguingao left a comment

penguingao Jul 16, 2020

PrinceS17 Jul 17, 2020

penguingao Jul 16, 2020

PrinceS17 Jul 17, 2020 •

edited

Loading

penguingao Jul 16, 2020

lizan Jul 23, 2020

PrinceS17 Jul 23, 2020

lizan Jul 24, 2020

PrinceS17 Jul 24, 2020

PrinceS17 Jul 27, 2020

lizan Jul 28, 2020

lizan Jul 24, 2020

lizan left a comment

lizan Jul 28, 2020

PrinceS17 Jul 28, 2020

lizan Jul 28, 2020

PrinceS17 Jul 28, 2020

lizan Jul 28, 2020

PrinceS17 Jul 28, 2020

PrinceS17 commented Jul 29, 2020


		extern FancyMapPtr getFancyLogMap();

		extern void setFancyLogger(std::string key, spdlog::level::level_enum log_level);

logger: implement Fancy Logger with fine-grained log control #11822

logger: implement Fancy Logger with fine-grained log control #11822

Conversation

PrinceS17 commented Jun 30, 2020

alyssawilk left a comment

Choose a reason for hiding this comment

penguingao left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

PrinceS17 commented Jul 10, 2020

repokitteh-read-only bot commented Jul 10, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

PrinceS17 commented Jul 15, 2020

repokitteh-read-only bot commented Jul 15, 2020

This comment has been minimized.

penguingao left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

PrinceS17 Jul 17, 2020 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

lizan left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

PrinceS17 commented Jul 29, 2020

PrinceS17 Jul 17, 2020 •

edited

Loading