You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@qpid.apache.org by as...@apache.org on 2019/11/14 06:30:19 UTC

[qpid-proton] branch master updated (9dd0133 -> 825ab55)

This is an automated email from the ASF dual-hosted git repository.

astitcher pushed a change to branch master
in repository https://gitbox.apache.org/repos/asf/qpid-proton.git.


    from 9dd0133  PROTON-2131: Introduce new proton logging API - Converted all uses in the Proton core library to use the new API - Currently no higher language API bindings (Python/Ruby/C++) - This introduces some portable library infrastructure to globally initialise/   shutdown the library independent of it's clients.
     new 2fca661  PROTON-2131: Improve and rationalise logger settings from the environment - Introduced a new environment variable PN_LOG which can be used to set   multiple logger levels active.
     new c692aa8  PROTON-2131: Improved documentation of logger API
     new 825ab55  PROTON-2131: Document environment variables used to control proton logging

The 3 revisions listed above as "new" are entirely new to this
repository and will be described in separate emails.  The revisions
listed as "add" were already present in the repository and have only
been added to this reference.


Summary of changes:
 c/docs/advanced.md        |   1 +
 c/docs/logging.md         |  57 ++++++++++++++++++
 c/include/proton/logger.h | 145 ++++++++++++++++++++++++++++++++++++----------
 c/src/core/logger.c       |  50 ++++++++++++++--
 4 files changed, 218 insertions(+), 35 deletions(-)
 create mode 100644 c/docs/logging.md


---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@qpid.apache.org
For additional commands, e-mail: commits-help@qpid.apache.org


[qpid-proton] 03/03: PROTON-2131: Document environment variables used to control proton logging

Posted by as...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

astitcher pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/qpid-proton.git

commit 825ab55e16887b62cbd4535bc984a4c3049863a3
Author: Andrew Stitcher <as...@apache.org>
AuthorDate: Thu Nov 14 01:29:01 2019 -0500

    PROTON-2131: Document environment variables used to control proton logging
---
 c/docs/advanced.md |  1 +
 c/docs/logging.md  | 57 ++++++++++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 58 insertions(+)

diff --git a/c/docs/advanced.md b/c/docs/advanced.md
index 6293958..e81f3d9 100644
--- a/c/docs/advanced.md
+++ b/c/docs/advanced.md
@@ -3,3 +3,4 @@
 * @subpage threads
 * @subpage io_page
 * @subpage buffering
+* @subpage logging
diff --git a/c/docs/logging.md b/c/docs/logging.md
new file mode 100644
index 0000000..b2279ac
--- /dev/null
+++ b/c/docs/logging.md
@@ -0,0 +1,57 @@
+## Logging {#logging}
+
+### Backward compatible logging control
+
+Proton has always supported some control over its internal logging using environment variables. The one that has seen
+the most use is `PN_TRACE_FRM` which when set to '1', 'on' or 'true' turns on logging of protocol frame traces.
+This is commonly used on a Unix shell command line like so:
+
+    PN_TRACE_FRM=1 ./proton_program
+
+Setting `PN_TRACE_FRM` is equivalent to using the @ref PN_LEVEL_FRAME log level setting in the proton @ref logger API.
+
+There are several other (less used) environment variables which are supported:
+
+* `PN_TRACE_RAW` - This turns on raw protocol frame tracing and is equivalent to @ref PN_LEVEL_RAW.
+* `PN_TRACE_EVT` - This is useful for tracing events, but has no direct equivalent in the Logger API.
+* `PN_TRACE_DRV` - This turns on very verbose miscellaneous tracing, again it has no direct equivalent in the Logger API.
+
+The last two variables are still supported, but their effect may not be to turn on exactly the same logging messages as
+prior to the introduction of the Logger API.
+
+### Logger control introduced with the @ref logger API
+
+The @ref logger API uses a single environment variable to control the default logging state - `PN_LOG`. This can include
+a number of strings which correspond to log levels to turn on, these are in descending order of importance (case is not significant):
+
+* Error
+* Warning
+* Info
+* Debug
+* Trace
+
+These strings can also be suffixed with '+' to mean this level and all the ones above. So specifying 'Info+' means turn on 'Error', 'Warning' and 'Info' levels.
+For example:
+
+    PN_LOG='info+' ./broker
+
+* Frame
+* Raw
+
+These string are equivalent to the frame and raw frame protocol traces from `PN_TRACE_FRM` and `PN_TRACE_RAW`, they will ignore any '+' appended to them. For example:
+
+    PN_LOG='frame' ./proton_program
+
+will have the same effect as the first example in this document.
+
+* All
+
+This will turn all known logging levels on. This is probably hardly ever useful as it will produce huge amounts of output. Appending '+' will again have no effect as all logging is already turned on!
+
+Multiple specifiers can be in the string for more logging levels:
+
+    PN_LOG='error frame' ./proton_program
+
+this would be useful to see the frame trace logged together with any errors.
+
+


---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@qpid.apache.org
For additional commands, e-mail: commits-help@qpid.apache.org


[qpid-proton] 01/03: PROTON-2131: Improve and rationalise logger settings from the environment - Introduced a new environment variable PN_LOG which can be used to set multiple logger levels active.

Posted by as...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

astitcher pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/qpid-proton.git

commit 2fca6618dc79aa937ffcf22d8bbdb325bded5206
Author: Andrew Stitcher <as...@apache.org>
AuthorDate: Wed Nov 13 23:46:02 2019 -0500

    PROTON-2131: Improve and rationalise logger settings from the environment
    - Introduced a new environment variable PN_LOG which can be used to set
      multiple logger levels active.
---
 c/src/core/logger.c | 50 ++++++++++++++++++++++++++++++++++++++++++++------
 1 file changed, 44 insertions(+), 6 deletions(-)

diff --git a/c/src/core/logger.c b/c/src/core/logger.c
index 4ff0d3c..b414150 100644
--- a/c/src/core/logger.c
+++ b/c/src/core/logger.c
@@ -54,6 +54,46 @@ void pni_logger_fini(pn_logger_t *logger)
   logger->scratch = NULL;
 }
 
+#define LOGLEVEL(x) {#x, sizeof(#x)-1, PN_LEVEL_ ## x, (pn_log_level_t)(PN_LEVEL_ ## x-1)}
+#define TRACE(x) {#x, sizeof(#x)-1, PN_LEVEL_ ## x, PN_LEVEL_NONE}
+typedef struct {
+    const char *str;
+    size_t     strlen;
+    pn_log_level_t level;
+    pn_log_level_t plus_levels;
+} log_level;
+static const log_level log_levels[] = {
+  LOGLEVEL(ERROR),
+  LOGLEVEL(WARNING),
+  LOGLEVEL(INFO),
+  LOGLEVEL(DEBUG),
+  LOGLEVEL(TRACE),
+  LOGLEVEL(ALL),
+  TRACE(FRAME),
+  TRACE(RAW),
+  {NULL, 0, PN_LEVEL_ALL}
+};
+
+void pni_decode_log_env(const char *log_env, int *setmask)
+{
+  if (!log_env) return;
+
+  for (int i = 0; log_env[i]; i++) {
+    for (const log_level *level = &log_levels[0]; level->str; level++) {
+      if (pn_strncasecmp(&log_env[i], level->str, level->strlen)==0) {
+        *setmask |= level->level;
+        i += level->strlen;
+        if (log_env[i]=='+') {
+          i++;
+          *setmask |= level->plus_levels;
+        }
+        i--;
+        break;
+      }
+    }
+  }
+}
+
 void pni_init_default_logger(void)
 {
   int sev_mask = 0;
@@ -62,15 +102,13 @@ void pni_init_default_logger(void)
   if (pn_env_bool("PN_TRACE_RAW")) { sev_mask |= PN_LEVEL_RAW; }
   if (pn_env_bool("PN_TRACE_FRM")) { sev_mask |= PN_LEVEL_FRAME; }
 
-  /* These aren't used enough to make them back compatible */
+  /* These are close enough for obscure undocumented settings */
   if (pn_env_bool("PN_TRACE_DRV")) { sev_mask |= PN_LEVEL_TRACE | PN_LEVEL_DEBUG; }
   if (pn_env_bool("PN_TRACE_EVT")) { sev_mask |= PN_LEVEL_DEBUG; }
 
-  if (pn_env_bool("PN_TRACE_LOG")) { sev_mask |= PN_LEVEL_TRACE; }
-  if (pn_env_bool("PN_DEBUG_LOG")) { sev_mask |= PN_LEVEL_DEBUG; }
-  if (pn_env_bool("PN_INFO_LOG"))  { sev_mask |= PN_LEVEL_INFO; }
-  if (pn_env_bool("PN_WARNING_LOG")) { sev_mask |= PN_LEVEL_WARNING; }
-  if (pn_env_bool("PN_ERROR_LOG")) { sev_mask |= PN_LEVEL_ERROR; }
+  /* Decode PN_LOG into logger settings */
+  pni_decode_log_env(getenv("PN_LOG"), &sev_mask);
+
   the_default_logger.sev_mask = (pn_log_level_t) (the_default_logger.sev_mask | sev_mask);
   the_default_logger.sub_mask = (pn_log_subsystem_t) (the_default_logger.sub_mask | sub_mask);
   the_default_logger.scratch = pn_string(NULL);


---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@qpid.apache.org
For additional commands, e-mail: commits-help@qpid.apache.org


[qpid-proton] 02/03: PROTON-2131: Improved documentation of logger API

Posted by as...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

astitcher pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/qpid-proton.git

commit c692aa831d838aa1ee7efe3a819862b5522bd700
Author: Andrew Stitcher <as...@apache.org>
AuthorDate: Wed Nov 13 23:48:30 2019 -0500

    PROTON-2131: Improved documentation of logger API
---
 c/include/proton/logger.h | 145 ++++++++++++++++++++++++++++++++++++----------
 1 file changed, 116 insertions(+), 29 deletions(-)

diff --git a/c/include/proton/logger.h b/c/include/proton/logger.h
index ae4d153..f19d175 100644
--- a/c/include/proton/logger.h
+++ b/c/include/proton/logger.h
@@ -19,9 +19,13 @@
  * under the License.
  */
 
-/**@file
+/**
+ * @file
+ * @copybrief logger
+ * @copydetails logger
  *
- * General proton logging facility
+ * @defgroup logger Logger
+ * @ingroup core
  */
 
 #include <proton/import_export.h>
@@ -34,22 +38,67 @@
 extern "C" {
 #endif
 
+/**
+ * @addtogroup logger
+ * @{
+ *
+ * Facility for logging messages
+ *
+ * The proton library has internal logging which provides information about the
+ * functioning of the library. This Logger system (see @ref pn_logger_t) allows applications
+ * to customize how the logging is recorded and output.
+ *
+ * Each logged message has an attached level (see @ref pn_log_level_t) which
+ * indicates how important the message is; and also has an attached subsystem
+ * (see @ref pn_log_subsystem_t) which indicates which part of proton is producing#
+ * the log message. The levels go from "Critical" which indicates a condition the library cannot
+ * recover from.
+ *
+ * Applications receive log messages by registering a callback function (@ref pn_log_sink_t). This
+ * receives the logged message and other information and allows the application to consume the
+ * logged messages as it wants. Applications can filter the messages that they receive by setting
+ * bit masks in the logger. They can set the logger filtering both by subsystem and by level.
+ * Additionally, since the callback contains both the subsystem and level information for each
+ * logged message, applications can impose further, more complex, filters of their own.
+ *
+ * Each application will have a default logger which can be retrieved with @ref pn_default_logger.
+ * The default logger is used as the template for every other logger that is created. So an efficient
+ * way to configure logging is to configure the default logger at the very start of the application
+ * before any other loggers get created.
+ *
+ * Loggers are associated with different proton objects, primarily the transport object
+ * (@ref pn_transport_t) and each logger controls the logging for the associated object. This means
+ * that for example in order to control the logging for an AMQP connection you need to acquire the
+ * logger object from the transport object using @ref pn_transport_logger and to configure that.
+ *
+ * Initially the defaults are to log every subsystem but not any level (except 'Critical' which is
+ * always logged). This means in effect that it is only necessary to turn on the log levels that
+ * are interesting and all subsystems will log. Of course you can turn off subsystems that are not
+ * interesting or are too verbose.
+ *
+ * There is also a default log sink if the application does not register their own, but logging
+ * is turned on - this will output the log message to standard error.
+ */
+
+/**
+ * The logger object allows library logging to be controlled
+ */
 typedef struct pn_logger_t pn_logger_t;
 
 /**
- * Definitions for different subsystems that can log messages
+ * Definitions for different subsystems that can log messages.
  * Note that these are exclusive bits so that you can specify multiple
  * subsystems to filter
  */
 typedef enum pn_log_subsystem_t {
-    PN_SUBSYSTEM_NONE    = 0,
-    PN_SUBSYSTEM_IO      = 1,
-    PN_SUBSYSTEM_EVENT   = 2,
-    PN_SUBSYSTEM_AMQP    = 4,
-    PN_SUBSYSTEM_SSL     = 8,
-    PN_SUBSYSTEM_SASL    = 16,
-    PN_SUBSYSTEM_BINDING = 32,
-    PN_SUBSYSTEM_ALL     = 65535
+    PN_SUBSYSTEM_NONE    = 0,    /**< No subsystem */
+    PN_SUBSYSTEM_IO      = 1,    /**< Low level Input/Output */
+    PN_SUBSYSTEM_EVENT   = 2,    /**< Events */
+    PN_SUBSYSTEM_AMQP    = 4,    /**< AMQP protocol processing */
+    PN_SUBSYSTEM_SSL     = 8,    /**< TLS/SSL protocol processing */
+    PN_SUBSYSTEM_SASL    = 16,   /**< SASL protocol processing */
+    PN_SUBSYSTEM_BINDING = 32,   /**< Language binding */
+    PN_SUBSYSTEM_ALL     = 65535 /**< Every subsystem */
 } pn_log_subsystem_t; /* We hint to the compiler it can use 16 bits for this value */
 
 /**
@@ -58,16 +107,16 @@ typedef enum pn_log_subsystem_t {
  * severities to filter
  */
 typedef enum pn_log_level_t {
-    PN_LEVEL_NONE     = 0,
-    PN_LEVEL_CRITICAL = 1,    /* Something is wrong and can't be fixed - probably a library bug */
-    PN_LEVEL_ERROR    = 2,    /* Something went wrong */
-    PN_LEVEL_WARNING  = 4,    /* Something unusual happened but not necessarily an error */
-    PN_LEVEL_INFO     = 8,    /* Something that might be interesting happened */
-    PN_LEVEL_DEBUG    = 16,   /* Something you might want to know about happened */
-    PN_LEVEL_TRACE    = 32,   /* Detail about something that happened */
-    PN_LEVEL_FRAME    = 64,   /* Protocol frame traces */
-    PN_LEVEL_RAW      = 128,  /* Raw protocol bytes */
-    PN_LEVEL_ALL      = 65535 /* Every possible severity */
+    PN_LEVEL_NONE     = 0,    /**< No level */
+    PN_LEVEL_CRITICAL = 1,    /**< Something is wrong and can't be fixed - probably a library bug */
+    PN_LEVEL_ERROR    = 2,    /**< Something went wrong */
+    PN_LEVEL_WARNING  = 4,    /**< Something unusual happened but not necessarily an error */
+    PN_LEVEL_INFO     = 8,    /**< Something that might be interesting happened */
+    PN_LEVEL_DEBUG    = 16,   /**< Something you might want to know about happened */
+    PN_LEVEL_TRACE    = 32,   /**< Detail about something that happened */
+    PN_LEVEL_FRAME    = 64,   /**< Protocol frame traces */
+    PN_LEVEL_RAW      = 128,  /**< Raw protocol bytes */
+    PN_LEVEL_ALL      = 65535 /**< Every possible level */
 } pn_log_level_t; /* We hint to the compiler that it can use 16 bits for this value */
 
 /**
@@ -75,52 +124,86 @@ typedef enum pn_log_level_t {
  */
 typedef void (*pn_log_sink_t)(intptr_t sink_context, pn_log_subsystem_t subsystem, pn_log_level_t severity, const char *message);
 
-/*
+/**
  * Return the default library logger
+ *
+ * @return The global default logger
  */
 PN_EXTERN pn_logger_t *pn_default_logger(void);
 
 /**
  * Create a new logger
+ *
+ * Note that loggers must be deallocated with @ref pn_logger_free after use.
+ *
+ * @return a newly constructed logger
  */
 PN_EXTERN pn_logger_t *pn_logger(void);
 
 /**
  * Free an existing logger
+ *
+ * @param[in] logger the logger to free
  */
 PN_EXTERN void pn_logger_free(pn_logger_t *logger);
 
 /**
  * Get a human readable name for a logger severity
+ *
+ * @param[in] level the logging level
+ * @return readable name for that level
  */
-PN_EXTERN const char *pn_logger_level_name(pn_log_level_t severity);
+PN_EXTERN const char *pn_logger_level_name(pn_log_level_t level);
 
 /**
  * Get a human readable name for a logger subsystem
+ *
+ * @param[in] subsystem
+ * @return readable name for that subsystem
  */
 PN_EXTERN const char *pn_logger_subsystem_name(pn_log_subsystem_t subsystem);
 
 /**
  * Set a logger's tracing flags.
  *
- * Set trace flags to control what a logger logs.
+ * Set individual trace flags to control what a logger logs.
  *
  * The trace flags for a logger control what sort of information is
- * logged. See pn_log_severity_t and pn_log_subsystem_t for more details.
+ * logged. See @ref pn_log_level_t and @ref pn_log_subsystem_t for more details.
+ *
+ * Note that log messages with a level of @ref PN_LEVEL_CRITICAL will always be logged.
+ * Otherwise log message are only logged if the subsystem and level flags both match a
+ * flag in the masks held by the logger.
+ *
+ * If you don't want to affect the subsystem flags then you can set subsystem to
+ * PN_SUBSYSTEM_NONE. likewise level to PN_LEVEL_NONE if you don't want to
+ * affect the level flags.
  *
  * @param[in] logger the logger
+ * @param[in] subsystem bits representing subsystems to turn on trace for
+ * @param[in] level bits representing log levels to turn on trace for
  */
-PN_EXTERN void pn_logger_set_mask(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity);
+PN_EXTERN void pn_logger_set_mask(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t level);
 
 /**
  * Clear a logger's tracing flags.
  *
- * Clear trace flags to control what a logger logs.
+ * Clear individual trace flags to control what a logger logs.
  *
  * The trace flags for a logger control what sort of information is
- * logged. See pn_log_severity_t and pn_log_subsystem_t for more details.
+ * logged. See @ref pn_log_level_t and @ref pn_log_subsystem_t for more details.
+ *
+ * Note that log messages with a level of @ref PN_LEVEL_CRITICAL will always be logged.
+ * Otherwise log message are only logged if the subsystem and level flags both match a
+ * flag in the masks held by the logger.
+ *
+ * If you don't want to affect the subsystem flags then you can set subsystem to
+ * PN_SUBSYSTEM_NONE. likewise level to PN_LEVEL_NONE if you don't want to
+ * affect the level flags.
  *
  * @param[in] logger the logger
+ * @param[in] subsystem bits representing subsystems to turn off trace for
+ * @param[in] level bits representing log levels to turn off trace for
  */
 PN_EXTERN void pn_logger_reset_mask(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity);
 
@@ -154,7 +237,7 @@ PN_EXTERN pn_log_sink_t pn_logger_get_log_sink(pn_logger_t *logger);
 PN_EXTERN intptr_t pn_logger_get_log_sink_context(pn_logger_t *logger);
 
 /**
- *  * Log a printf formatted using the logger
+ * Log a printf formatted message using the logger
  *
  * This is mainly for use in proton internals , but will allow application log messages to
  * be processed the same way.
@@ -168,4 +251,8 @@ PN_EXTERN void pn_logger_logf(pn_logger_t *logger, pn_log_subsystem_t subsystem,
 }
 #endif
 
+/**
+ * @}
+ */
+
 #endif


---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@qpid.apache.org
For additional commands, e-mail: commits-help@qpid.apache.org