Re: RFC[2/2] Common logging infrastructure and API


Nashif, Anas
 

Hi

On 24/02/2016, 17:13, "Saucedo Tejada, Genaro" <genaro.saucedo.tejada(a)intel.com> wrote:

From 9baee79d211bfb94aeed970c55f31cd3c4b2a8ad Mon Sep 17 00:00:00 2001
From: Genaro Saucedo Tejada <genaro.saucedo.tejada(a)intel.com>
Date: Fri, 19 Feb 2016 17:10:28 -0600
Subject: [PATCH] Log macros unified in a common API

Introduces a header to concentrate logging macro definitions for all
code to
reuse, change aims to provide all currently existing logging
functionality so
every C file can replace it's compile-unit definitions by common code.

Later enhancements to log can now be performed in a single file.

Features:
* Optional printing of thread pointer
* Optional printing of colored messages
* Optional printing of a label to indicate logging level (info, error,
warning, debug)
* Caller function name printing
* Incremental log levels
* One point log disable

See my comments on the first email..

- we need to make all existing code use this feature and how it was defined and avoid designing it to match EVERY existing custom logging and debugging implementation we currently have.
- support multiple logging backends

- split this patch, add the feature and testcases then add a sample that can be used for as a reference by developers
- need to work on better variable names, avoid extreme abbreviations (LV -> LEVEL, DMN -> DOMAIN,...)

few comments below..


Change-Id: Ibe542d69912778703bb43c7afef0889f0591ba6a
Signed-off-by: Genaro Saucedo Tejada <genaro.saucedo.tejada(a)intel.com>
---
drivers/grove/lcd_rgb.c | 14 +---
include/bluetooth/log.h | 28 +++----
include/logging.h | 166
++++++++++++++++++++++++++++++++++++++++
misc/debug/Kconfig | 66 ++++++++++++++++
net/bluetooth/Kconfig | 3 +-
net/bluetooth/hci_core.c | 5 --
tests/bluetooth/tester/prj.conf | 2 +
7 files changed, 250 insertions(+), 34 deletions(-)
create mode 100644 include/logging.h

diff --git a/drivers/grove/lcd_rgb.c b/drivers/grove/lcd_rgb.c
index 58b86c5..7ef6a78 100644
--- a/drivers/grove/lcd_rgb.c
+++ b/drivers/grove/lcd_rgb.c
@@ -29,17 +29,9 @@
#define GROVE_LCD_DISPLAY_ADDR (0x3E)
#define GROVE_RGB_BACKLIGHT_ADDR (0x62)

-#ifndef CONFIG_GROVE_DEBUG
-#define DBG(...) { ; }
-#else
-#if defined(CONFIG_STDOUT_CONSOLE)
-#include <stdio.h>
-#define DBG printf
-#else
-#include <misc/printk.h>
-#define DBG printk
-#endif /* CONFIG_STDOUT_CONSOLE */
-#endif /* CONFIG_GROVE_DEBUG */
+/* module specific logging check */
+#define LOG_THIS_MODULE CONFIG_GROVE_DEBUG
+#include <logging.h>

struct command {
uint8_t control;
diff --git a/include/bluetooth/log.h b/include/bluetooth/log.h
index e47453a..e5abbab 100644
--- a/include/bluetooth/log.h
+++ b/include/bluetooth/log.h
@@ -26,25 +26,19 @@
extern "C" {
#endif

-#if defined(CONFIG_BLUETOOTH_DEBUG_COLOR)
-#define BT_COLOR_OFF "\x1B[0m"
-#define BT_COLOR_RED "\x1B[0;31m"
-#define BT_COLOR_YELLOW "\x1B[0;33m"
-#else
-#define BT_COLOR_OFF ""
-#define BT_COLOR_RED ""
-#define BT_COLOR_YELLOW ""
-#endif
-
#if defined(CONFIG_BLUETOOTH_DEBUG)
+
+/* module specific logging check */
+#define LOG_THIS_MODULE CONFIG_BLUETOOTH_DEBUG_HCI_CORE
+/* specify logging domain */
+#define LOG_DMN "bt"
+#include <logging.h>
+
#include <nanokernel.h>
-#define BT_DBG(fmt, ...) printf("bt: %s (%p): " fmt "\n", __func__, \
- sys_thread_self_get(), ##__VA_ARGS__)
-#define BT_ERR(fmt, ...) printf("bt: %s: %s" fmt "%s\n", __func__, \
- BT_COLOR_RED, ##__VA_ARGS__,
BT_COLOR_OFF)
-#define BT_WARN(fmt, ...) printf("bt: %s: %s" fmt "%s\n", __func__, \
- BT_COLOR_YELLOW, ##__VA_ARGS__,
BT_COLOR_OFF)
-#define BT_INFO(fmt, ...) printf("bt: " fmt "\n", ##__VA_ARGS__)
+#define BT_DBG(fmt, ...) DBG(fmt, ##__VA_ARGS__)
+#define BT_ERR(fmt, ...) ERR(fmt, ##__VA_ARGS__)
+#define BT_WARN(fmt, ...) WRN(fmt, ##__VA_ARGS__)
+#define BT_INFO(fmt, ...) INF(fmt, ##__VA_ARGS__)
#define BT_ASSERT(cond) if (!(cond)) { \
BT_ERR("assert: '" #cond "' failed");
\
}
diff --git a/include/logging.h b/include/logging.h
new file mode 100644
index 0000000..d778da9
--- /dev/null
+++ b/include/logging.h
@@ -0,0 +1,166 @@
+/*
+ * Copyright (c) 2015 Intel Corporation
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or
implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+/** @file logging.h
+ * @brief Logging macros.
+ */
+#ifndef __LOGGING_H
+#define __LOGGING_H
+
+#if !defined LOG_THIS_MODULE
+#error DO NOT include this header without defining LOG_THIS_MODULE
+#endif
+
+#if defined CONFIG_USE_COMPILE_LOG && (1 == LOG_THIS_MODULE)
+
+#define IS_LOGGING_ACTIVE 1
+#define THREAD_FN_CALL sys_thread_self_get()
+
+/* decide print func */
+#if defined(CONFIG_STDOUT_CONSOLE)
+#include <stdio.h>
+#define LOG_FN printf
+#else
+#include <misc/printk.h>
+#define LOG_FN printk
+#endif /* CONFIG_STDOUT_CONSOLE */
+
The above should be defined using backend support.


+/* Should use color? */
+#if defined(CONFIG_USE_LOG_COLOR)
+#define LOG_COLOR_OFF "\x1B[0m"
+#define LOG_COLOR_RED "\x1B[0;31m"
+#define LOG_COLOR_YELLOW "\x1B[0;33m"
+#else
+#define LOG_COLOR_OFF ""
+#define LOG_COLOR_RED ""
+#define LOG_COLOR_YELLOW ""
+#endif /* CONFIG_BLUETOOTH_DEBUG_COLOR */
+
+/* Should use log lv labels? */
+#if defined(CONFIG_USE_LOG_LV_TAGS)
+#define LOG_LV_ERR "ERR "
+#define LOG_LV_WRN "WRN "
+#define LOG_LV_INF "INF "
+#define LOG_LV_DBG "DBG "
+#else
+#define LOG_LV_ERR ""
+#define LOG_LV_WRN ""
+#define LOG_LV_INF ""
+#define LOG_LV_DBG ""
+#endif /* CONFIG_USE_LOG_LV_TAGS */

Use LEVEL instead of LV


+
+/* Log domain name */
+#if defined LOG_DMN
+#define LOG_DMN_TAG LOG_DMN ":\t"
+#else
+#define LOG_DMN_TAG ""
+#endif /* LOG_DMN */

DOMAIN

+
+/* Should thread be printed on log? */
+#if defined CONFIG_PRINT_THREAD_LOG
+#define LOG_LAYOUT LOG_DMN_TAG "%s%s\t%p: %s" /* label func thread */
+#define LOG_FN_CALL(log_lv, log_color, log_format, color_off, ...)
\
+ LOG_FN(LOG_LAYOUT log_format "%s\n",
\
+ log_lv, __func__, THREAD_FN_CALL, log_color, ##__VA_ARGS__,
color_off)
+#else
+#define LOG_LAYOUT LOG_DMN_TAG "%s%s\t: %s" /* label func */
+#define LOG_FN_CALL(log_lv, log_color, log_format, color_off, ...)
\
+ LOG_FN(LOG_LAYOUT log_format "%s\n",
\
+ log_lv, __func__, log_color, ##__VA_ARGS__, color_off)
+#endif /* CONFIG_PRINT_THREAD_LOG */
+
+#define LOG_NO_COLOR(log_lv, log_format, ...)
\
+ LOG_FN_CALL(log_lv, "", log_format, "", ##__VA_ARGS__)
+#define LOG_COLOR(log_lv, log_color, log_format, ...)
\
+ LOG_FN_CALL(log_lv, log_color, log_format, LOG_COLOR_OFF,
\
+ ##__VA_ARGS__)
+
+/**
+ * @def INF
+ *
+ * @brief Writes information to log
+ *
+ * @details Lowest logging lv, these messages are not disabled unless
whole
+ * logging gets disabled.
+ *
+ * @param A kprint valid format string and optinally, kprint
formateable
+ * arguments.
+ */
+#define INF(...) LOG_NO_COLOR(LOG_LV_INF, ##__VA_ARGS__)
+
+#if defined(CONFIG_LOG_LV_ERR) || defined(CONFIG_LOG_LV_WRN) \
+ || defined(CONFIG_LOG_LV_DBG)
+/**
+ * @def ERR
+ *
+ * @brief Writes Errors to log
+ *
+ * @details available if CONFIG_USE_COMPILE_LOG is CONFIG_LOG_LV_ERR
or higiher,
+ * it's meant to report fatal errors that can't be recovered from.
+ *
+ * @param A kprint valid format string and optinally, kprint
formateable
+ * arguments.
+ */
+#define ERR(...) LOG_COLOR(LOG_LV_ERR, LOG_COLOR_RED, ##__VA_ARGS__)
+#else
+#define ERR(...) { ; }
+#endif
+
+#if defined(CONFIG_LOG_LV_WRN) || defined(CONFIG_LOG_LV_DBG)
+/**
+ * @def WRN
+ *
+ * @brief Writes warnings to log
+ *
+ * @details available if CONFIG_USE_COMPILE_LOG is CONFIG_LOG_LV_WRN
or higiher,
+ * it's meant to print unexpedted situations that are not necesarily
an error.
+ *
+ * @param A kprint valid format string and optinally, kprint
formateable
+ * arguments.
+ */
+#define WRN(...) LOG_COLOR(LOG_LV_WRN, LOG_COLOR_YELLOW,
##__VA_ARGS__)
+#else
+#define WRN(...) { ; }
+#endif
+
+#if defined(CONFIG_LOG_LV_DBG)
+/**
+ * @def DBG
+ *
+ * @brief Writes debugging information to log
+ *
+ * @details highest logging level, available if CONFIG_USE_COMPILE_LOG
is
+ * CONFIG_LOG_LV_DBG, it's meant to print developer information.
+ *
+ * @param A kprint valid format string and optinally, kprint
formateable
+ * arguments.
+ */
+#define DBG(...) LOG_NO_COLOR(LOG_LV_DBG, ##__VA_ARGS__)
+#else
+#define DBG(...) { ; }
+#endif
+
+#else
+#define IS_LOGGING_ACTIVE 0
+/* create dummy macros */
+#define DBG(...) { ; }
+#define ERR(...) { ; }
+#define WRN(...) { ; }
+#define INF(...) { ; }
+
+#endif /*USE_COMPILE_LOG*/
+
+#endif /* __LOGGING_H */
diff --git a/misc/debug/Kconfig b/misc/debug/Kconfig
index 51a3d3f..716a361 100644
--- a/misc/debug/Kconfig
+++ b/misc/debug/Kconfig
@@ -16,6 +16,72 @@
# limitations under the License.
#

+config USE_COMPILE_LOG
+ bool
+ prompt "Enable Logging"
+ default n
+ help
+ Global switch for logging.
+
+config USE_LOG_LV_TAGS
+ bool
+ prompt "Prepend level tags to logs"
+ depends on USE_COMPILE_LOG
+ default y
+ help
+ Log lines will beging with one of INF, ERR, WRN or DBG,
depending on the
+ macro used at C code.
+
+config USE_LOG_COLOR
+ bool
+ prompt "Use colored logs"
+ depends on USE_COMPILE_LOG
+ default n
+ help
+ Use color in the logs. This requires an ANSI capable
terminal.
+
+config PRINT_THREAD_LOG
+ bool
+ prompt "Include thread on log messages"
+ depends on USE_COMPILE_LOG
+ default n
+ help
+ Each log line will include the pointer of the thread that
printed it
+
+choice
+depends on USE_COMPILE_LOG
+prompt "Log level"
+
+config LOG_LV_INF
+ bool
+ prompt "Info"
+ help
+ Print just unfiltered logging.
+
+config LOG_LV_ERR
+ bool
+ prompt "Error"
+ help
+ Do not filter printing of ERR logging macro, it is meant to
report fatal
+ errors.
+
+config LOG_LV_WRN
+ bool
+ prompt "Warning"
+ help
+ Do not filter printing of WRN and above logging macros, WRN
marcro is
+ meant to print messages generated under unexpedted
circumstances, not
+ necesarily errors.
+
+config LOG_LV_DBG
+ bool
+ prompt "Debug"
+ help
+ Enable printing of all logging macros, DBG is meant to print
developer
+ information.
+
+endchoice
+

menu "Safe memory access"

diff --git a/net/bluetooth/Kconfig b/net/bluetooth/Kconfig
index 8dcbbcf..222199d 100644
--- a/net/bluetooth/Kconfig
+++ b/net/bluetooth/Kconfig
@@ -218,7 +218,8 @@ config BLUETOOTH_DEBUG
serial console.

if BLUETOOTH_DEBUG
-config BLUETOOTH_DEBUG_COLOR
+config BLUETOOTH_DEBUG_COLOR
+ select USE_LOG_COLOR
bool "Use colored logs"
default y
help
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index d5b6d24..00ad8d2 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -50,11 +50,6 @@
#include "smp.h"
#endif /* CONFIG_BLUETOOTH_SMP */

-#if !defined(CONFIG_BLUETOOTH_DEBUG_HCI_CORE)
-#undef BT_DBG
-#define BT_DBG(fmt, ...)
-#endif
-
/* Stacks for the fibers */
static BT_STACK_NOINIT(rx_fiber_stack,
CONFIG_BLUETOOTH_RX_STACK_SIZE);
static BT_STACK_NOINIT(rx_prio_fiber_stack, 256);
diff --git a/tests/bluetooth/tester/prj.conf
b/tests/bluetooth/tester/prj.conf
index 617e07c..af53ace 100644
--- a/tests/bluetooth/tester/prj.conf
+++ b/tests/bluetooth/tester/prj.conf
@@ -1,5 +1,7 @@
CONFIG_UART_PIPE=y
CONFIG_CONSOLE_HANDLER=y
+CONFIG_USE_COMPILE_LOG=y
+CONFIG_LOG_LV_DBG=y
CONFIG_BLUETOOTH=y
CONFIG_BLUETOOTH_LE=y
CONFIG_BLUETOOTH_CENTRAL=y
--
2.5.0

Join {devel@lists.zephyrproject.org to automatically receive all group messages.