Merge pull request #6189 from y-zeng/default-verbosity

Add knob for default core output verbosity

grpc.def

@@ -136,6 +136,8 @@ EXPORTS
     grpc_raw_byte_buffer_from_reader
     gpr_log
     gpr_log_message
+    gpr_set_log_verbosity
+    gpr_log_verbosity_init
     gpr_set_log_function
     gpr_slice_ref
     gpr_slice_unref

include/grpc/impl/codegen/log.h

@@ -61,6 +61,8 @@ typedef enum gpr_log_severity {
   GPR_LOG_SEVERITY_ERROR
 } gpr_log_severity;
 
+#define GPR_LOG_VERBOSITY_UNSET -1
+
 /* Returns a string representation of the log severity */
 const char *gpr_log_severity_string(gpr_log_severity severity);
 
@@ -77,6 +79,11 @@ GPRAPI void gpr_log(const char *file, int line, gpr_log_severity severity,
 GPRAPI void gpr_log_message(const char *file, int line,
                             gpr_log_severity severity, const char *message);
 
+/* Set global log verbosity */
+GPRAPI void gpr_set_log_verbosity(gpr_log_severity min_severity_to_print);
+
+GPRAPI void gpr_log_verbosity_init();
+
 /* Log overrides: applications can use this API to intercept logging calls
    and use their own implementations */
 

src/core/lib/support/log.c

@@ -31,14 +31,20 @@
  *
  */
 
+#include <grpc/support/alloc.h>
+#include <grpc/support/atm.h>
 #include <grpc/support/log.h>
 #include <grpc/support/port_platform.h>
 
+#include "src/core/lib/support/env.h"
+#include "src/core/lib/support/string.h"
+
 #include <stdio.h>
 #include <string.h>
 
 extern void gpr_default_log(gpr_log_func_args *args);
 static gpr_log_func g_log_func = gpr_default_log;
+static gpr_atm g_min_severity_to_print = GPR_LOG_VERBOSITY_UNSET;
 
 const char *gpr_log_severity_string(gpr_log_severity severity) {
   switch (severity) {
@@ -54,6 +60,9 @@ const char *gpr_log_severity_string(gpr_log_severity severity) {
 
 void gpr_log_message(const char *file, int line, gpr_log_severity severity,
                      const char *message) {
+  if ((gpr_atm)severity < gpr_atm_no_barrier_load(&g_min_severity_to_print))
+    return;
+
   gpr_log_func_args lfargs;
   memset(&lfargs, 0, sizeof(lfargs));
   lfargs.file = file;
@@ -63,4 +72,28 @@ void gpr_log_message(const char *file, int line, gpr_log_severity severity,
   g_log_func(&lfargs);
 }
 
+void gpr_set_log_verbosity(gpr_log_severity min_severity_to_print) {
+  gpr_atm_no_barrier_store(&g_min_severity_to_print,
+                           (gpr_atm)min_severity_to_print);
+}
+
+void gpr_log_verbosity_init() {
+  char *verbosity = gpr_getenv("GRPC_VERBOSITY");
+  if (verbosity == NULL) return;
+
+  gpr_atm min_severity_to_print = GPR_LOG_VERBOSITY_UNSET;
+  if (strcmp(verbosity, "DEBUG") == 0) {
+    min_severity_to_print = (gpr_atm)GPR_LOG_SEVERITY_DEBUG;
+  } else if (strcmp(verbosity, "INFO") == 0) {
+    min_severity_to_print = (gpr_atm)GPR_LOG_SEVERITY_INFO;
+  } else if (strcmp(verbosity, "ERROR") == 0) {
+    min_severity_to_print = (gpr_atm)GPR_LOG_SEVERITY_ERROR;
+  }
+  gpr_free(verbosity);
+  if ((gpr_atm_no_barrier_load(&g_min_severity_to_print)) ==
+      GPR_LOG_VERBOSITY_UNSET) {
+    gpr_atm_no_barrier_store(&g_min_severity_to_print, min_severity_to_print);
+  }
+}
+
 void gpr_set_log_function(gpr_log_func f) { g_log_func = f; }

src/core/lib/surface/init.c

@@ -38,6 +38,7 @@
 
 #include <grpc/grpc.h>
 #include <grpc/support/alloc.h>
+#include <grpc/support/log.h>
 #include <grpc/support/time.h>
 #include "src/core/lib/channel/channel_stack.h"
 #include "src/core/lib/channel/compress_filter.h"
@@ -69,6 +70,7 @@ static gpr_mu g_init_mu;
 static int g_initializations;
 
 static void do_basic_init(void) {
+  gpr_log_verbosity_init();
   gpr_mu_init(&g_init_mu);
   grpc_register_built_in_plugins();
   g_initializations = 0;

src/python/grpcio/grpc/_cython/imports.generated.c

@@ -174,6 +174,8 @@ grpc_byte_buffer_reader_readall_type grpc_byte_buffer_reader_readall_import;
 grpc_raw_byte_buffer_from_reader_type grpc_raw_byte_buffer_from_reader_import;
 gpr_log_type gpr_log_import;
 gpr_log_message_type gpr_log_message_import;
+gpr_set_log_verbosity_type gpr_set_log_verbosity_import;
+gpr_log_verbosity_init_type gpr_log_verbosity_init_import;
 gpr_set_log_function_type gpr_set_log_function_import;
 gpr_slice_ref_type gpr_slice_ref_import;
 gpr_slice_unref_type gpr_slice_unref_import;
@@ -440,6 +442,8 @@ void pygrpc_load_imports(HMODULE library) {
   grpc_raw_byte_buffer_from_reader_import = (grpc_raw_byte_buffer_from_reader_type) GetProcAddress(library, "grpc_raw_byte_buffer_from_reader");
   gpr_log_import = (gpr_log_type) GetProcAddress(library, "gpr_log");
   gpr_log_message_import = (gpr_log_message_type) GetProcAddress(library, "gpr_log_message");
+  gpr_set_log_verbosity_import = (gpr_set_log_verbosity_type) GetProcAddress(library, "gpr_set_log_verbosity");
+  gpr_log_verbosity_init_import = (gpr_log_verbosity_init_type) GetProcAddress(library, "gpr_log_verbosity_init");
   gpr_set_log_function_import = (gpr_set_log_function_type) GetProcAddress(library, "gpr_set_log_function");
   gpr_slice_ref_import = (gpr_slice_ref_type) GetProcAddress(library, "gpr_slice_ref");
   gpr_slice_unref_import = (gpr_slice_unref_type) GetProcAddress(library, "gpr_slice_unref");

src/python/grpcio/grpc/_cython/imports.generated.h

@@ -472,6 +472,12 @@ extern gpr_log_type gpr_log_import;
 typedef void(*gpr_log_message_type)(const char *file, int line, gpr_log_severity severity, const char *message);
 extern gpr_log_message_type gpr_log_message_import;
 #define gpr_log_message gpr_log_message_import
+typedef void(*gpr_set_log_verbosity_type)(gpr_log_severity min_severity_to_print);
+extern gpr_set_log_verbosity_type gpr_set_log_verbosity_import;
+#define gpr_set_log_verbosity gpr_set_log_verbosity_import
+typedef void(*gpr_log_verbosity_init_type)();
+extern gpr_log_verbosity_init_type gpr_log_verbosity_init_import;
+#define gpr_log_verbosity_init gpr_log_verbosity_init_import
 typedef void(*gpr_set_log_function_type)(gpr_log_func func);
 extern gpr_set_log_function_type gpr_set_log_function_import;
 #define gpr_set_log_function gpr_set_log_function_import

src/ruby/ext/grpc/rb_grpc_imports.generated.c

@@ -174,6 +174,8 @@ grpc_byte_buffer_reader_readall_type grpc_byte_buffer_reader_readall_import;
 grpc_raw_byte_buffer_from_reader_type grpc_raw_byte_buffer_from_reader_import;
 gpr_log_type gpr_log_import;
 gpr_log_message_type gpr_log_message_import;
+gpr_set_log_verbosity_type gpr_set_log_verbosity_import;
+gpr_log_verbosity_init_type gpr_log_verbosity_init_import;
 gpr_set_log_function_type gpr_set_log_function_import;
 gpr_slice_ref_type gpr_slice_ref_import;
 gpr_slice_unref_type gpr_slice_unref_import;
@@ -436,6 +438,8 @@ void grpc_rb_load_imports(HMODULE library) {
   grpc_raw_byte_buffer_from_reader_import = (grpc_raw_byte_buffer_from_reader_type) GetProcAddress(library, "grpc_raw_byte_buffer_from_reader");
   gpr_log_import = (gpr_log_type) GetProcAddress(library, "gpr_log");
   gpr_log_message_import = (gpr_log_message_type) GetProcAddress(library, "gpr_log_message");
+  gpr_set_log_verbosity_import = (gpr_set_log_verbosity_type) GetProcAddress(library, "gpr_set_log_verbosity");
+  gpr_log_verbosity_init_import = (gpr_log_verbosity_init_type) GetProcAddress(library, "gpr_log_verbosity_init");
   gpr_set_log_function_import = (gpr_set_log_function_type) GetProcAddress(library, "gpr_set_log_function");
   gpr_slice_ref_import = (gpr_slice_ref_type) GetProcAddress(library, "gpr_slice_ref");
   gpr_slice_unref_import = (gpr_slice_unref_type) GetProcAddress(library, "gpr_slice_unref");

src/ruby/ext/grpc/rb_grpc_imports.generated.h

@@ -472,6 +472,12 @@ extern gpr_log_type gpr_log_import;
 typedef void(*gpr_log_message_type)(const char *file, int line, gpr_log_severity severity, const char *message);
 extern gpr_log_message_type gpr_log_message_import;
 #define gpr_log_message gpr_log_message_import
+typedef void(*gpr_set_log_verbosity_type)(gpr_log_severity min_severity_to_print);
+extern gpr_set_log_verbosity_type gpr_set_log_verbosity_import;
+#define gpr_set_log_verbosity gpr_set_log_verbosity_import
+typedef void(*gpr_log_verbosity_init_type)();
+extern gpr_log_verbosity_init_type gpr_log_verbosity_init_import;
+#define gpr_log_verbosity_init gpr_log_verbosity_init_import
 typedef void(*gpr_set_log_function_type)(gpr_log_func func);
 extern gpr_set_log_function_type gpr_set_log_function_import;
 #define gpr_set_log_function gpr_set_log_function_import

test/core/support/log_test.c

@@ -33,16 +33,40 @@
 
 #include <grpc/support/log.h>
 
+#include <stdbool.h>
 #include <string.h>
 
+#include "src/core/lib/support/env.h"
 #include "test/core/util/test_config.h"
 
+static bool log_func_reached = false;
+
 static void test_callback(gpr_log_func_args *args) {
   GPR_ASSERT(0 == strcmp(__FILE__, args->file));
   GPR_ASSERT(args->severity == GPR_LOG_SEVERITY_INFO);
   GPR_ASSERT(0 == strcmp(args->message, "hello 1 2 3"));
 }
 
+static void test_should_log(gpr_log_func_args *args) {
+  log_func_reached = true;
+}
+
+static void test_should_not_log(gpr_log_func_args *args) { GPR_ASSERT(false); }
+
+#define test_log_function_reached(SEVERITY)     \
+  gpr_set_log_function(test_should_log);        \
+  log_func_reached = false;                     \
+  gpr_log_message(SEVERITY, "hello 1 2 3");     \
+  GPR_ASSERT(log_func_reached);                 \
+  log_func_reached = false;                     \
+  gpr_log(SEVERITY, "hello %d %d %d", 1, 2, 3); \
+  GPR_ASSERT(log_func_reached);
+
+#define test_log_function_unreached(SEVERITY) \
+  gpr_set_log_function(test_should_not_log);  \
+  gpr_log_message(SEVERITY, "hello 1 2 3");   \
+  gpr_log(SEVERITY, "hello %d %d %d", 1, 2, 3);
+
 int main(int argc, char **argv) {
   grpc_test_init(argc, argv);
   /* test logging at various verbosity levels */
@@ -54,6 +78,44 @@ int main(int argc, char **argv) {
   gpr_set_log_function(test_callback);
   gpr_log_message(GPR_INFO, "hello 1 2 3");
   gpr_log(GPR_INFO, "hello %d %d %d", 1, 2, 3);
+
+  /* gpr_log_verbosity_init() will be effective only once, and only before
+   * gpr_set_log_verbosity() is called */
+  gpr_setenv("GRPC_VERBOSITY", "ERROR");
+  gpr_log_verbosity_init();
+  test_log_function_reached(GPR_ERROR);
+  test_log_function_unreached(GPR_INFO);
+  test_log_function_unreached(GPR_DEBUG);
+
+  /* gpr_log_verbosity_init() should not be effective */
+  gpr_setenv("GRPC_VERBOSITY", "DEBUG");
+  gpr_log_verbosity_init();
+  test_log_function_reached(GPR_ERROR);
+  test_log_function_unreached(GPR_INFO);
+  test_log_function_unreached(GPR_DEBUG);
+
+  gpr_set_log_verbosity(GPR_LOG_SEVERITY_DEBUG);
+  test_log_function_reached(GPR_ERROR);
+  test_log_function_reached(GPR_INFO);
+  test_log_function_reached(GPR_DEBUG);
+
+  gpr_set_log_verbosity(GPR_LOG_SEVERITY_INFO);
+  test_log_function_reached(GPR_ERROR);
+  test_log_function_reached(GPR_INFO);
+  test_log_function_unreached(GPR_DEBUG);
+
+  gpr_set_log_verbosity(GPR_LOG_SEVERITY_ERROR);
+  test_log_function_reached(GPR_ERROR);
+  test_log_function_unreached(GPR_INFO);
+  test_log_function_unreached(GPR_DEBUG);
+
+  /* gpr_log_verbosity_init() should not be effective */
+  gpr_setenv("GRPC_VERBOSITY", "DEBUG");
+  gpr_log_verbosity_init();
+  test_log_function_reached(GPR_ERROR);
+  test_log_function_unreached(GPR_INFO);
+  test_log_function_unreached(GPR_DEBUG);
+
   /* TODO(ctiller): should we add a GPR_ASSERT failure test here */
   return 0;
 }