Topics

RFC[2/2] Common logging infrastructure and API


Saucedo Tejada, Genaro <genaro.saucedo.tejada@...>
 

From 9baee79d211bfb94aeed970c55f31cd3c4b2a8ad Mon Sep 17 00:00:00 2001
From: Genaro Saucedo Tejada <genaro.saucedo.tejada(a)intel.com>
Date: Fri, 19 February 2016 23:10:28 +0000
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

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 */
+
+/* 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 */
+
+/* Log domain name */
+#if defined LOG_DMN
+#define LOG_DMN_TAG LOG_DMN ":\t"
+#else
+#define LOG_DMN_TAG ""
+#endif /* LOG_DMN */
+
+/* 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


Luiz Augusto von Dentz
 

Hi Genaro,

On Thu, Feb 25, 2016 at 12:13 AM, 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
I welcome these changes but Im not so sure logging levels are actually
necessary if one can define different domains, at least in case of
Bluetooth when you turn on debug for one particular domain you just
get everything, if that is too much perhaps the domain needs to be
split in sub-domains, anyway since your changes was based in Bluetooth
and we did not have levels in the first place I assume it is no needed
right now and can be added later provided someone make a case.


Tomasz Bursztyka
 

Hi Genaro,

The idea is nice, at least it will prevent to declare debug macros
everywhere.

However, split the patch:
- first provide a patch with the logging.h and it's related Kconfig file
- and only then whatever usage of it in further patch.

I have small comments about logging.h and Kconfig:

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
I wouldn't use LOG_THIS_MODULE also, rather something like LOG_ENABLE
(Ok taste issue here, but a short name is nicer imo)
And I do want to be able to include logging.h even if don't define it.

So instead of the above just do:

#ifdef LOG_ENABLE

and add a relevant #endif below.

Then I could use it like:

#ifdef CONFIG_SPI_DEBUG
#define LOG_ENABLE 1
#endif
#include <logging.h>

It avoids thes superfluous lines
#else
#define LOG_ENABLE 0

+
+#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 */
+
+/* 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 */
+
+/* Log domain name */
+#if defined LOG_DMN
+#define LOG_DMN_TAG LOG_DMN ":\t"
+#else
+#define LOG_DMN_TAG ""
+#endif /* LOG_DMN */
+
+/* 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
Better something like LOG_COMPILE_TIME
Thus it will ease grep on CONFIG_LOG_* for instance.

+ bool
+ prompt "Enable Logging"
Just do bool "Enable Logging"
No need of the prompt. You can apply that at all options below.

+ default n
+ help
+ Global switch for logging.
+
+config USE_LOG_LV_TAGS
LOG_USE_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
LOG_USE_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
LOG_PRINT_THREAD

+ 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
+
In the end we only have to deal with CONFIG_LOG_* prefixed options.

Tomasz


Dirk Brandewie <dirk.j.brandewie@...>
 

On 02/24/2016 02:13 PM, Saucedo Tejada, Genaro 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
I like this in general we need a common set of debug output macros
that all drivers can use. Currently we have a *bunch* of different
versions of the same thing in use throughout the driver tree.

I don't like the naming, we already have a kernel event logging API
people may assume that the two facilities are connected based on the name.

Can we change the names to debug_* or something else?


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 */
+
+/* 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 */
+
+/* Log domain name */
+#if defined LOG_DMN
+#define LOG_DMN_TAG LOG_DMN ":\t"
+#else
+#define LOG_DMN_TAG ""
+#endif /* LOG_DMN */
+
+/* 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


Benjamin Walsh <benjamin.walsh@...>
 

On Thu, Feb 25, 2016 at 07:05:49AM -0800, Dirk Brandewie wrote:


On 02/24/2016 02:13 PM, Saucedo Tejada, Genaro 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
I like this in general we need a common set of debug output macros
that all drivers can use. Currently we have a *bunch* of different
versions of the same thing in use throughout the driver tree.

I don't like the naming, we already have a kernel event logging API
people may assume that the two facilities are connected based on the name.

Can we change the names to debug_* or something else?
Again, do we want to take over _another_ namespace ? Maybe it should be
sys_debug or sys_dbg or sys_dbg_log ?

The sample implementation is adding all these in logging.h, which is a
public API file:

DBG, ERR, INF, WRN, THREAD_FN_CALL, IS_LOGGING_ACTIVE

which are very generic names. Don't forget that the application writer
is operating in the same C namespace, and we have been trying to keep
the namespaces the kernel owns to a minimum to minimize the number or
potential clashes:

See doc/collaboration/code/naming_conventions.rst.


Dirk Brandewie <dirk.j.brandewie@...>
 

On 02/25/2016 07:47 AM, Benjamin Walsh wrote:
On Thu, Feb 25, 2016 at 07:05:49AM -0800, Dirk Brandewie wrote:


On 02/24/2016 02:13 PM, Saucedo Tejada, Genaro 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
I like this in general we need a common set of debug output macros
that all drivers can use. Currently we have a *bunch* of different
versions of the same thing in use throughout the driver tree.

I don't like the naming, we already have a kernel event logging API
people may assume that the two facilities are connected based on the name.

Can we change the names to debug_* or something else?
Again, do we want to take over _another_ namespace ? Maybe it should be
sys_debug or sys_dbg or sys_dbg_log ?

The sample implementation is adding all these in logging.h, which is a
public API file:

DBG, ERR, INF, WRN, THREAD_FN_CALL, IS_LOGGING_ACTIVE

which are very generic names. Don't forget that the application writer
is operating in the same C namespace, and we have been trying to keep
the namespaces the kernel owns to a minimum to minimize the number or
potential clashes:
It's the MACRO names the need fixed up IMO. Any functions that are
added should be in the sys_* space sure. I didn't see any new C
functions being added.



See doc/collaboration/code/naming_conventions.rst.


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


Saucedo Tejada, Genaro <genaro.saucedo.tejada@...>
 

On Thu, 2016-02-25 at 07:54 -0800, Dirk Brandewie wrote:

On 02/25/2016 07:47 AM, Benjamin Walsh wrote:
On Thu, Feb 25, 2016 at 07:05:49AM -0800, Dirk Brandewie wrote:


On 02/24/2016 02:13 PM, Saucedo Tejada, Genaro 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
I like this in general we need a common set of debug output
macros
that all drivers can use.  Currently we have a *bunch* of
different
versions of the same thing in use throughout the driver tree.

I don't like the naming, we already have a kernel event logging
API
people may assume that the two facilities are connected based on
the name.

Can we change the names to debug_* or something else?
Although a namespace is needed (as noted bellow) debug is not the only
goal of this infrastructure INFO and ERROR level might be used for big
production environments in the future.

I reused some existing Kconfig variables but, as Anas pointed out, they
should be updated to reflect the wider nature of logging, some of them
do control debugging and should be split.



Again, do we want to take over _another_ namespace ? Maybe it
should be
sys_debug or sys_dbg or sys_dbg_log ?

The sample implementation is adding all these in logging.h, which
is a
public API file:

   DBG, ERR, INF, WRN, THREAD_FN_CALL, IS_LOGGING_ACTIVE

which are very generic names. Don't forget that the application
writer
is operating in the same C namespace, and we have been trying to
keep
the namespaces the kernel owns to a minimum to minimize the number
or
potential clashes:
It's the MACRO names the need fixed up IMO.  Any functions that are
added should be in the sys_* space sure.  I didn't see any new C
functions being added.
I propose 'LOG_' as the prefix of all the function-like macros and
Kconfig variables, I'm using it for the improved patch set as place
holder anyway but expect to mass rename if, for example, it gets
decided to keep such name for the kernel event logger facility.

An actual name space would be needed for a run-time implementation of a
more complex logging facility, such as sys_log() instead of printf.



See doc/collaboration/code/naming_conventions.rst.


Kalowsky, Daniel <daniel.kalowsky@...>
 

-----Original Message-----
From: Saucedo Tejada, Genaro [mailto:genaro.saucedo.tejada(a)intel.com]
Sent: Tuesday, March 1, 2016 4:27 PM
To: Brandewie, Dirk J <dirk.j.brandewie(a)intel.com>; Walsh, Benjamin (Wind
River) <benjamin.walsh(a)windriver.com>
Cc: devel(a)lists.zephyrproject.org
Subject: [devel] Re: Re: Re: RFC[2/2] Common logging infrastructure and API

On Thu, 2016-02-25 at 07:54 -0800, Dirk Brandewie wrote:

On 02/25/2016 07:47 AM, Benjamin Walsh wrote:
On Thu, Feb 25, 2016 at 07:05:49AM -0800, Dirk Brandewie wrote:


On 02/24/2016 02:13 PM, Saucedo Tejada, Genaro 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
I like this in general we need a common set of debug output
macros
that all drivers can use.  Currently we have a *bunch* of
different
versions of the same thing in use throughout the driver tree.

I don't like the naming, we already have a kernel event logging
API
people may assume that the two facilities are connected based on
the name.

Can we change the names to debug_* or something else?
Although a namespace is needed (as noted bellow) debug is not the only
goal of this infrastructure INFO and ERROR level might be used for big
production environments in the future.
Can you share what a "production environment in the future" means?

<... snip ...>

I propose 'LOG_' as the prefix of all the function-like macros and
Kconfig variables, I'm using it for the improved patch set as place
holder anyway but expect to mass rename if, for example, it gets
decided to keep such name for the kernel event logger facility.

An actual name space would be needed for a run-time implementation of a
more complex logging facility, such as sys_log() instead of printf.
Right. I think you're overlooking that by selecting LOG_, you're selecting the most obvious name for such a feature. By doing so, you're now taking that namespace away from any application developer. This is why we are suggesting the macros and any code functionality all start with the SYS_ prefix as that is already reserved by the kernel.


Saucedo Tejada, Genaro <genaro.saucedo.tejada@...>
 

On Wed, 2016-03-02 at 01:29 +0000, Kalowsky, Daniel wrote:

-----Original Message-----
From: Saucedo Tejada, Genaro [mailto:genaro.saucedo.tejada(a)intel.co
m]
Sent: Tuesday, March 1, 2016 4:27 PM
To: Brandewie, Dirk J <dirk.j.brandewie(a)intel.com>; Walsh, Benjamin
(Wind
River) <benjamin.walsh(a)windriver.com>
Cc: devel(a)lists.zephyrproject.org
Subject: [devel] Re: Re: Re: RFC[2/2] Common logging infrastructure
and API

On Thu, 2016-02-25 at 07:54 -0800, Dirk Brandewie wrote:

On 02/25/2016 07:47 AM, Benjamin Walsh wrote:
On Thu, Feb 25, 2016 at 07:05:49AM -0800, Dirk Brandewie wrote:


On 02/24/2016 02:13 PM, Saucedo Tejada, Genaro wrote:
 From 9baee79d211bfb94aeed970c55f31cd3c4b2a8ad Mon Sep 17
00:00:00 2001
From: Genaro Saucedo Tejada <genaro.saucedo.tejada(a)intel.co
m>
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
I like this in general we need a common set of debug output
macros
that all drivers can use.  Currently we have a *bunch* of
different
versions of the same thing in use throughout the driver tree.

I don't like the naming, we already have a kernel event
logging
API
people may assume that the two facilities are connected based
on
the name.

Can we change the names to debug_* or something else?
Although a namespace is needed (as noted bellow) debug is not the
only
goal of this infrastructure INFO and ERROR level might be used for
big
production environments in the future.
Can you share what a "production environment in the future" means?

<... snip ...>
I mean applications could rely on log API to report the most important
messages even in a complete application (that's what I meant by
production), it wouldn't make sense to expect a terminal in that case
but a rollover log on a file system could store these messages (future
work), in this case a developer wouldn't be debugging the application,
instead a user could be dealing with problems caused by external
factors or simply monitoring.

Other "logging" examples not exclusive to debugging were mentioned by
Anas in another thread: "...send messages to a remote endpoint or write
messages to a connected display".


I propose 'LOG_' as the prefix of all the function-like macros and
Kconfig variables, I'm using it for the improved patch set as place
holder anyway but expect to mass rename if, for example, it gets
decided to keep such name for the kernel event logger facility.

An actual name space would be needed for a run-time implementation
of a
more complex logging facility, such as sys_log() instead of printf.
Right.  I think you're overlooking that by selecting LOG_, you're
selecting the most obvious name for such a feature.  By doing
so,  you're now taking that namespace away from any application
developer.  This is why we are suggesting the macros and any code
functionality all start with the SYS_ prefix as that is already
reserved by the kernel.
Got it, will change it to 'SYS_LOG_'.


Tomasz Bursztyka
 

Hi,

How is this logging infra RFC going? :)

Just noticed one thing to change as well: include/misc/__assert.h
Would be nice if those __ASSERT macros would use this logging facilities
as well.

Tomasz