log: Add a new logging feature

Before adding new features, move these definitions to a separate header to avoid further cluttering common.h.

Signed-off-by Simon Glass <[email protected]>

Reviewed-by Bin Meng <[email protected]>

Add the logging header file and implementation with some configuration options to control it.

Signed-off-by Simon Glass <[email protected]>

---

Changes in v3: None
Changes in v2:
- Add a comment as to why CONFIG_LOG_MAX_LEVEL is not defined
- Drop MAINTAINERS entries for files not added by this patch
- Drop the use of 'continue' in the macro
- Fix LOG_SPL_MAX_LEVEL typo (should be SPL_LOG_MAX_LEVEL)
- Fix up bad use of #if CONFIG_VAL() - use #ifdef instead
- Line up log levels with Linux

 MAINTAINERS                       |   7 ++
 common/Kconfig                    |  56 +++++++++
 common/Makefile                   |   1 +
 common/log.c                      | 244

++++++++++++++++++++++++++++++++++++++
include/asm-generic/global_data.h | 5 +
include/log.h | 235
++++++++++++++++++++++++++++++++++++ 6 files changed, 548 insertions(+) create mode 100644 common/log.c

MAINTAINERS +7 -0

index b167b028ecf..6814c2fc566 100644
@@ -291,6 +291,13 @@ S:	Maintained
 T:	git git://git.denx.de/u-boot-i2c.git
 F:	drivers/i2c/
 
+LOGGING
+M:	Simon Glass <[email protected]>
+S:	Maintained
+T:	git git://git.denx.de/u-boot.git
+F:	common/log.c
+F:	cmd/log.c
+
 MICROBLAZE
 M:	Michal Simek <[email protected]>
 S:	Maintained

common/Kconfig +6 -0

index c50d6ebb2ad..9747443feb2 100644
@@ -420,6 +420,62 @@ config SYS_STDIO_DEREGISTER
 
 endmenu
 
+menu "Logging"
+
+config LOG
+	bool "Enable logging support"
+	help
+	  This enables support for logging of status and debug

messages. These

common/Kconfig +1 -0

+	  can be displayed on the console, recorded in a memory

buffer, or

common/Kconfig +1 -0

+	  discarded if not needed. Logging supports various

categories and

common/Kconfig +6 -0

+	  levels of severity.
+
+config SPL_LOG
+	bool "Enable logging support in SPL"
+	help
+	  This enables support for logging of status and debug

messages. These

common/Kconfig +1 -0

+	  can be displayed on the console, recorded in a memory

buffer, or

common/Kconfig +1 -0

+	  discarded if not needed. Logging supports various

categories and

common/Kconfig +8 -0

+	  levels of severity.
+
+config LOG_MAX_LEVEL
+	int "Maximum log level to record"
+	depends on LOG
+	default 5
+	help
+	  This selects the maximum log level that will be recorded.

Any value

common/Kconfig +1 -0

+	  higher than this will be ignored. If possible log

statements below

common/Kconfig +17 -0

+	  this level will be discarded at build time. Levels:
+
+	    0 - panic
+	    1 - critical
+	    2 - error
+	    3 - warning
+	    4 - note
+	    5 - info
+	    6 - detail
+	    7 - debug
+
+config SPL_LOG_MAX_LEVEL
+	int "Maximum log level to record in SPL"
+	depends on SPL_LOG
+	default 3
+	help
+	  This selects the maximum log level that will be recorded.

Any value

common/Kconfig +1 -0

+	  higher than this will be ignored. If possible log

statements below

common/Kconfig +13 -0

+	  this level will be discarded at build time. Levels:
+
+	    0 - panic
+	    1 - critical
+	    2 - error
+	    3 - warning
+	    4 - note
+	    5 - info
+	    6 - detail
+	    7 - debug
+
+endmenu
+
 config DEFAULT_FDT_FILE
 	string "Default fdt file"
 	help

common/Makefile +1 -0

index cec506fe3e1..f4b632761fa 100644
@@ -128,5 +128,6 @@ obj-y += cli.o
 obj-$(CONFIG_FSL_DDR_INTERACTIVE) += cli_simple.o cli_readline.o
 obj-$(CONFIG_CMD_DFU) += dfu.o
 obj-y += command.o
+obj-$(CONFIG_$(SPL_)LOG) += log.o
 obj-y += s_record.o
 obj-y += xyzModem.o

common/log.c new file +16 -0

new file mode 100644
index 00000000000..a7d9a548f2a
@@ -0,0 +1,244 @@
+/*
+ * Logging support
+ *
+ * Copyright (c) 2017 Google, Inc
+ * Written by Simon Glass <[email protected]>
+ *
+ * SPDX-License-Identifier:	GPL-2.0+
+ */
+
+#include <common.h>
+#include <log.h>
+#include <malloc.h>
+
+DECLARE_GLOBAL_DATA_PTR;
+
+static struct log_device *log_device_find_by_name(const char

*drv_name) +{

common/log.c new file +14 -0

+	struct log_device *ldev;
+
+	list_for_each_entry(ldev, &gd->log_head, sibling_node) {
+		if (!strcmp(drv_name, ldev->drv->name))
+			return ldev;
+	}
+
+	return NULL;
+}
+
+/**
+ * log_has_cat() - check if a log category exists within a list
+ *
+ * @cat_list: List of categories to check, at most

LOGF_MAX_CATEGORIES entries
+ * long, terminated by LC_END if fewer
+ * @cat: Category to search for
+ * @return true if @cat is in @cat_list, else false
+ */
+static bool log_has_cat(enum log_category_t cat_list[], enum log_category_t cat) +{

common/log.c new file +3 -0

+	int i;
+
+	for (i = 0; i < LOGF_MAX_CATEGORIES && cat_list[i] !=

LOGC_END; i++) {

common/log.c new file +12 -0

+		if (cat_list[i] == cat)
+			return true;
+	}
+
+	return false;
+}
+
+/**
+ * log_has_file() - check if a file is with a list
+ *
+ * @file_list: List of files to check, separated by comma
+ * @file: File to check for. This string is matched against the end

of each
+ * file in the list, i.e. ignoring any preceeding path. The
list is
+ * intended to consist of relative pathnames, e.g.
common/main.c,cmd/log.c
+ * @return true if @file is in @file_list, else false
+ */

common/log.c new file +11 -0

+static bool log_has_file(const char *file_list, const char *file)
+{
+	int file_len = strlen(file);
+	const char *s, *p;
+	int substr_len;
+
+	for (s = file_list; *s; s = p + (*p != '\0')) {
+		p = strchrnul(s, ',');
+		substr_len = p - s;
+		if (file_len >= substr_len &&
+		    !strncmp(file + file_len - substr_len, s,

substr_len))

common/log.c new file +8 -0

+			return true;
+	}
+
+	return false;
+}
+
+/**
+ * log_passes_filters() - check if a log record passes the filters

for a device
+ *
+ * @ldev: Log device to check
+ * @rec: Log record to check
+ * @return true if @rec is not blocked by the filters in @ldev, false if it is
+ */
+static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec) +{

common/log.c new file +3 -0

+	struct log_filter *filt;
+
+	/* If there are no filters, filter on the default log level

*/

common/log.c new file +23 -0

+	if (list_empty(&ldev->filter_head)) {
+		if (rec->level > gd->default_log_level)
+			return false;
+		return true;
+	}
+
+	list_for_each_entry(filt, &ldev->filter_head, sibling_node) {
+		if (rec->level > filt->max_level)
+			continue;
+		if ((filt->flags & LOGFF_HAS_CAT) &&
+		    !log_has_cat(filt->cat_list, rec->cat))
+			continue;
+		if (filt->file_list &&
+		    !log_has_file(filt->file_list, rec->file))
+			continue;
+		return true;
+	}
+
+	return false;
+}
+
+/**
+ * log_dispatch() - Send a log record to all log devices for

processing
+ *
+ * The log record is sent to each log device in turn, skipping those which have
+ * filters which block the record
+ *
+ * @rec: Log record to dispatch
+ * @return 0 (meaning success)
+ */

common/log.c new file +13 -0

+static int log_dispatch(struct log_rec *rec)
+{
+	struct log_device *ldev;
+
+	list_for_each_entry(ldev, &gd->log_head, sibling_node) {
+		if (log_passes_filters(ldev, rec))
+			ldev->drv->emit(ldev, rec);
+	}
+
+	return 0;
+}
+
+int _log(enum log_category_t cat, enum log_level_t level, const char

*file,

common/log.c new file +26 -0

+	 int line, const char *func, const char *fmt, ...)
+{
+	char buf[CONFIG_SYS_CBSIZE];
+	struct log_rec rec;
+	va_list args;
+
+	rec.cat = cat;
+	rec.level = level;
+	rec.file = file;
+	rec.line = line;
+	rec.func = func;
+	va_start(args, fmt);
+	vsnprintf(buf, sizeof(buf), fmt, args);
+	va_end(args);
+	rec.msg = buf;
+	if (!gd || !(gd->flags & GD_FLG_LOG_READY)) {
+		if (gd)
+			gd->log_drop_count++;
+		return -ENOSYS;
+	}
+	log_dispatch(&rec);
+
+	return 0;
+}
+
+int log_add_filter(const char *drv_name, enum log_category_t

cat_list[],

common/log.c new file +6 -0

+		   enum log_level_t max_level, const char *file_list)
+{
+	struct log_filter *filt;
+	struct log_device *ldev;
+	int i;
+

common/log.c new file +47 -0

+			if (i == ARRAY_SIZE(filt->cat_list))
+				return -ENOSPC;
+			filt->cat_list[i] = cat_list[i];
+			if (cat_list[i] == LOGC_END)
+				break;
+		}
+	}
+	filt->max_level = max_level;
+	if (file_list) {
+		filt->file_list = strdup(file_list);
+		if (!filt->file_list)
+			goto nomem;
+	}
+	filt->filter_num = ldev->next_filter_num++;
+	list_add_tail(&filt->sibling_node, &ldev->filter_head);
+
+	return filt->filter_num;
+
+nomem:
+	free(filt);
+	return -ENOMEM;
+}
+
+int log_remove_filter(const char *drv_name, int filter_num)
+{
+	struct log_filter *filt;
+	struct log_device *ldev;
+
+	ldev = log_device_find_by_name(drv_name);
+	if (!ldev)
+		return -ENOENT;
+
+	list_for_each_entry(filt, &ldev->filter_head, sibling_node) {
+		if (filt->filter_num == filter_num) {
+			list_del(&filt->sibling_node);
+			free(filt);
+
+			return 0;
+		}
+	}
+
+	return -ENOENT;
+}
+
+int log_init(void)
+{
+	struct log_driver *drv = ll_entry_start(struct log_driver,

log_driver);

common/log.c new file +1 -0

+	const int count = ll_entry_count(struct log_driver,

log_driver);

common/log.c new file +4 -0

+	struct log_driver *end = drv + count;
+
+	/*
+	 * We cannot add runtime data to the driver since it is

likely stored

common/log.c new file +1 -0

+	 * in rodata. Instead, set up a 'device' corresponding to

each driver.

common/log.c new file +9 -0

+	 * We only support having a single device.
+	 */
+	INIT_LIST_HEAD((struct list_head *)&gd->log_head);
+	while (drv < end) {
+		struct log_device *ldev;
+
+		ldev = calloc(1, sizeof(*ldev));
+		if (!ldev) {
+			debug("%s: Cannot allocate memory\n",

__func__);

common/log.c new file +12 -0

+			return -ENOMEM;
+		}
+		INIT_LIST_HEAD(&ldev->filter_head);
+		ldev->drv = drv;
+		list_add_tail(&ldev->sibling_node,
+			      (struct list_head *)&gd->log_head);
+		drv++;
+	}
+	gd->default_log_level = LOGL_INFO;
+
+	return 0;
+}

(quoted diff) +0 -0

b/include/asm-generic/global_data.h index 79197acfa42..77755dbb068 100644 --- a/include/asm-generic/global_data.h
+++ b/include/asm-generic/global_data.h

(quoted diff) +0 -0

@@ -114,6 +114,11 @@ typedef struct global_data {
 	struct bootstage_data *bootstage;	/* Bootstage

information */ struct bootstage_data *new_bootstage; /*
Relocated bootstage info */ #endif

(quoted diff) +2 -0

+#ifdef CONFIG_LOG
+	int log_drop_count;		/* Number of dropped log

messages */

(quoted diff) +1 -0

+	int default_log_level;		/* For devices with no

filters */

(quoted diff) +1 -0

+	struct list_head log_head;	/* List of struct

log_device */ +#endif
} gd_t;
#endif

include/log.h +7 -0

index 08ad44cf497..5dced16880b 100644
@@ -10,6 +10,87 @@
 #ifndef __LOG_H
 #define __LOG_H
 
+#include <dm/uclass-id.h>
+#include <linux/list.h>
+
+/** Log levels supported, ranging from most to least important */
+enum log_level_t {
+	LOGL_EMERG = 0,		/*U-Boot is unstable */
+	LOGL_ALERT,		/* Action must be taken

immediately */

include/log.h +2 -0

+	LOGL_CRIT,		/* Critical conditions */
+	LOGL_ERR,		/* Error that prevents something

from working */

include/log.h +1 -0

+	LOGL_WARNING,		/* Warning may prevent optimial

operation */

include/log.h +1 -0

+	LOGL_NOTICE,		/* Normal but significant

condition, printf() */

include/log.h +3 -0

+	LOGL_INFO,		/* General information message */
+	LOGL_DEBUG,		/* Basic debug-level message */
+	LOGL_DEBUG_CONTENT,	/* Debug message showing full

message content */

include/log.h +1 -0

+	LOGL_DEBUG_IO,		/* Debug message showing

hardware I/O access */ +

include/log.h +7 -0

+	LOGL_COUNT,
+	LOGL_FIRST = LOGL_EMERG,
+	LOGL_MAX = LOGL_DEBUG,
+};
+
+/**
+ * Log categories supported. Most of these correspond to uclasses

(i.e.
+ * enum uclass_id) but there are also some more generic categories
+ */

include/log.h +17 -0

+enum log_category_t {
+	LOGC_FIRST = 0,	/* First part mirrors UCLASS_... */
+
+	LOGC_NONE = UCLASS_COUNT,
+	LOGC_ARCH,
+	LOGC_BOARD,
+	LOGC_CORE,
+	LOGC_DT,
+
+	LOGC_COUNT,
+	LOGC_END,
+};
+
+/**
+ * _log() - Internal function to emit a new log record
+ *
+ * @cat: Category of log record (indicating which subsystem

generated it)
+ * @level: Level of log record (indicating its severity)
+ * @file: File name of file where log record was generated
+ * @line: Line number in file where log record was generated
+ * @func: Function where log record was generated
+ * @fmt: printf() format string for log record
+ * @...: Optional parameters, according to the format string @fmt
+ * @return 0 if log record was emitted, -ve on error
+ */
+int _log(enum log_category_t cat, enum log_level_t level, const char *file,

include/log.h +3 -0

+	 int line, const char *func, const char *fmt, ...);
+
+/* Define this at the top of a file to add a prefix to debug

messages */ +#ifndef pr_fmt

include/log.h +10 -0

+#define pr_fmt(fmt) fmt
+#endif
+
+/* Use a default category if this file does not supply one */
+#ifndef LOG_CATEGORY
+#define LOG_CATEGORY LOGC_NONE
+#endif
+
+/*
+ * This header may be including when CONFIG_LOG is disabled, in

which case
+ * CONFIG_LOG_MAX_LEVEL is not defined. Add a check for this.
+ */

include/log.h +24 -0

+#if CONFIG_IS_ENABLED(LOG)
+#define _LOG_MAX_LEVEL CONFIG_VAL(LOG_MAX_LEVEL)
+#else
+#define _LOG_MAX_LEVEL LOGL_INFO
+#endif
+
+/* Emit a log record if the level is less that the maximum */
+#define log(_cat, _level, _fmt, _args...) ({ \
+	int _l = _level; \
+	if (_l <= _LOG_MAX_LEVEL) \
+		_log(_cat, _l, __FILE__, __LINE__, __func__, \
+		     pr_fmt(_fmt), ##_args); \
+	})
+
 #ifdef DEBUG
 #define _DEBUG	1
 #else

@@ -22,6 +103,16 @@
 #define _SPL_BUILD	0
 #endif
 
+#if !_DEBUG && CONFIG_IS_ENABLED(LOG)
+
+#define debug_cond(cond, fmt, args...)			\
+	do {						\
+		if (1)				\
+			log(LOG_CATEGORY, LOGL_DEBUG, fmt, ##args); \
+	} while (0)
+
+#else /* _DEBUG */
+
 /*
  * Output a debug text when condition "cond" is met. The "cond"

should be
* computed by a preprocessor in the best case, allowing for the best

include/log.h +8 -0

@@ -33,6 +124,8 @@
 			printf(pr_fmt(fmt), ##args);	\
 	} while (0)
 
+#endif /* _DEBUG */
+
 /* Show a message if DEBUG is defined in a file */
 #define debug(fmt, args...)			\
 	debug_cond(_DEBUG, fmt, ##args)

@@ -56,4 +149,146 @@ void __assert_fail(const char *assertion, const
 char *file, unsigned int line, ({ if (!(x) && _DEBUG) \
 		__assert_fail(#x, __FILE__, __LINE__, __func__); })
 
+/**
+ * struct log_rec - a single log record
+ *
+ * Holds information about a single record in the log
+ *
+ * Members marked as 'not allocated' are stored as pointers and the

caller is
+ * responsible for making sure that the data pointed to is not overwritten.
+ * Memebers marked as 'allocated' are allocated (e.g. via strdup()) by the log
+ * system.
+ *
+ * @cat: Category, representing a uclass or part of U-Boot
+ * @level: Severity level, less severe is higher
+ * @file: Name of file where the log record was generated (not allocated)
+ * @line: Line number where the log record was generated
+ * @func: Function where the log record was generated (not allocated)
+ * @msg: Log message (allocated)
+ */

include/log.h +13 -0

+struct log_rec {
+	enum log_category_t cat;
+	enum log_level_t level;
+	const char *file;
+	int line;
+	const char *func;
+	const char *msg;
+};
+
+struct log_device;
+
+/**
+ * struct log_driver - a driver which accepts and processes log

records
+ *
+ * @name: Name of driver
+ */

include/log.h +6 -0

+struct log_driver {
+	const char *name;
+	/**
+	 * emit() - emit a log record
+	 *
+	 * Called by the log system to pass a log record to a

particular driver

include/log.h +1 -0

+	 * for processing. The filter is checked before calling this

function.

include/log.h +8 -0

+	 */
+	int (*emit)(struct log_device *ldev, struct log_rec *rec);
+};
+
+/**
+ * struct log_device - an instance of a log driver
+ *
+ * Since drivers are set up at build-time we need to have a separate

device for
+ * the run-time aspects of drivers (currently just a list of filters to apply
+ * to records send to this device).
+ *
+ * @next_filter_num: Seqence number of next filter filter added (0=no filters
+ * yet). This increments with each new filter on the device,
but never
+ * decrements
+ * @drv: Pointer to driver for this device
+ * @filter_head: List of filters for this device
+ * @sibling_node: Next device in the list of all devices
+ */

include/log.h +9 -0

+struct log_device {
+	int next_filter_num;
+	struct log_driver *drv;
+	struct list_head filter_head;
+	struct list_head sibling_node;
+};
+
+enum {
+	LOGF_MAX_CATEGORIES = 5,	/* maximum categories per

filter */ +};

include/log.h +3 -0

+
+enum log_filter_flags {
+	LOGFF_HAS_CAT		= 1 << 0,	/* Filter has

a category list */ +};

include/log.h +5 -0

+
+/**
+ * struct log_filter - criterial to filter out log messages
+ *
+ * @filter_num: Sequence number of this filter.  This is returned

when adding a
+ * new filter, and must be provided when removing a
previously added
+ * filter.
+ * @flags: Flags for this filter (LOGFF_...)
+ * @cat_list: List of categories to allow (terminated by LOGC_none). If empty
+ * then all categories are permitted. Up to
LOGF_MAX_CATEGORIES entries
+ * can be provided
+ * @max_level: Maximum log level to allow
+ * @file_list: List of files to allow, separated by comma. If NULL then all
+ * files are permitted
+ * @sibling_node: Next filter in the list of filters for this log device
+ */

include/log.h +16 -0

+struct log_filter {
+	int filter_num;
+	int flags;
+	enum log_category_t cat_list[LOGF_MAX_CATEGORIES];
+	enum log_level_t max_level;
+	const char *file_list;
+	struct list_head sibling_node;
+};
+
+#define LOG_DRIVER(_name) \
+	ll_entry_declare(struct log_driver, _name, log_driver)
+
+/**
+ * log_add_filter() - Add a new filter to a log device
+ *
+ * @drv_name: Driver name to add the filter to (since each driver

only has a
+ * single device)
+ * @cat_list: List of categories to allow (terminated by LOGC_none). If empty
+ * then all categories are permitted. Up to
LOGF_MAX_CATEGORIES entries
+ * can be provided
+ * @max_level: Maximum log level to allow
+ * @file_list: List of files to allow, separated by comma. If NULL then all
+ * files are permitted
+ * @return the sequence number of the new filter (>=0) if the filter was added,
+ * or a -ve value on error
+ */
+int log_add_filter(const char *drv_name, enum log_category_t cat_list[],

include/log.h +1 -0

+		   enum log_level_t max_level, const char

*file_list); +
+/**
+ * log_remove_filter() - Remove a filter from a log device
+ *
+ * @drv_name: Driver name to remove the filter from (since each driver only has
+ * a single device)
+ * @filter_num: Filter number to remove (as returned by log_add_filter())
+ * @return 0 if the filter was removed, -ENOENT if either the driver or the
+ * filter number was not found
+ */

include/log.h +7 -0

+int log_remove_filter(const char *drv_name, int filter_num);
+
+#if CONFIG_IS_ENABLED(LOG)
+/**
+ * log_init() - Set up the log system ready for use
+ *
+ * @return 0 if OK, -ENOMEM if out of memory

Quoted 2 lines · On Mon, 20 Nov 2017 15:33:28 -0700 Simon Glass <[email protected]> wrote:

Add the logging header file and implementation with some configuration options to control it.

Despite one question -

Reviewed-by Lukasz Majewski <[email protected]>

Quoted 24 lines

Signed-off-by Simon Glass <[email protected]>

---

Changes in v3: None
Changes in v2:
- Add a comment as to why CONFIG_LOG_MAX_LEVEL is not defined
- Drop MAINTAINERS entries for files not added by this patch
- Drop the use of 'continue' in the macro
- Fix LOG_SPL_MAX_LEVEL typo (should be SPL_LOG_MAX_LEVEL)
- Fix up bad use of #if CONFIG_VAL() - use #ifdef instead
- Line up log levels with Linux

 MAINTAINERS                       |   7 ++
 common/Kconfig                    |  56 +++++++++
 common/Makefile                   |   1 +
 common/log.c                      | 244

++++++++++++++++++++++++++++++++++++++
include/asm-generic/global_data.h | 5 +
include/log.h | 235
++++++++++++++++++++++++++++++++++++ 6 files changed, 548 insertions(+) create mode 100644 common/log.c

common/log.c line 170

Quoted 3 lines

common/log.c new file +3 -0

+     if (cat_list) {
+             filt->flags |= LOGFF_HAS_CAT;
+             for (i = 0; ; i++) {

^^^^ - I suppose that this is "true"
Does it comply with any standard (is it the undefined behaviour?)

Quoted 7 lines

common/log.c new file +7 -0

+                     if (i == ARRAY_SIZE(filt->cat_list))
+                             return -ENOSPC;
+                     filt->cat_list[i] = cat_list[i];
+                     if (cat_list[i] == LOGC_END)
+                             break;
+             }
+     }

It is useful to display log messages on the console. Add a simple driver to handle this.

Note that this driver outputs to the console, which may be serial or video. It does not specifically select serial output.

Signed-off-by Simon Glass <[email protected]>

Reviewed-by Bin Meng <[email protected]>

---

Changes in v3: None
Changes in v2:
- Update commit message to explain that this is not just for serial output

 common/Kconfig       | 20 ++++++++++++++++++++
 common/Makefile      |  1 +
 common/log_console.c | 23 +++++++++++++++++++++++
 3 files changed, 44 insertions(+)
 create mode 100644 common/log_console.c

common/Kconfig +6 -0

index 9747443feb2..1b157e47c3d 100644
@@ -474,6 +474,26 @@ config SPL_LOG_MAX_LEVEL
 	    6 - detail
 	    7 - debug
 
+config LOG_CONSOLE
+	bool "Allow log output to the console"
+	depends on LOG
+	default y
+	help
+	  Enables a log driver which writes log records to the

console.

common/Kconfig +1 -0

+	  Generally the console is the serial port or LCD display.

Only the

common/Kconfig +1 -0

+	  log message is shown - other details like level, category,

file and

common/Kconfig +8 -0

+	  line number are omitted.
+
+config LOG_SPL_CONSOLE
+	bool "Allow log output to the console in SPL"
+	depends on LOG_SPL
+	default y
+	help
+	  Enables a log driver which writes log records to the

console.

common/Kconfig +1 -0

+	  Generally the console is the serial port or LCD display.

Only the

common/Kconfig +1 -0

+	  log message is shown - other details like level, category,

file and

common/Kconfig +2 -0

+	  line number are omitted.
+
 endmenu
 
 config DEFAULT_FDT_FILE

common/Makefile +0 -0

index f4b632761fa..14166209fe4 100644
@@ -129,5 +129,6 @@ obj-$(CONFIG_FSL_DDR_INTERACTIVE) += cli_simple.o

cli_readline.o obj-$(CONFIG_CMD_DFU) += dfu.o
obj-y += command.o
obj-$(CONFIG_$(SPL_)LOG) += log.o

common/Makefile +1 -0

+obj-$(CONFIG_$(SPL_)LOG_CONSOLE) += log_console.o
 obj-y += s_record.o
 obj-y += xyzModem.o

common/log_console.c new file +13 -0

new file mode 100644
index 00000000000..5af73bd8be4
@@ -0,0 +1,23 @@
+/*
+ * Logging support
+ *
+ * Copyright (c) 2017 Google, Inc
+ * Written by Simon Glass <[email protected]>
+ *
+ * SPDX-License-Identifier:	GPL-2.0+
+ */
+
+#include <common.h>
+#include <log.h>
+
+static int log_console_emit(struct log_device *ldev, struct log_rec

*rec) +{

Add a command for adjusting the log level.

Signed-off-by Simon Glass <[email protected]>

Reviewed-by Bin Meng <[email protected]>

---

Changes in v3: None
Changes in v2: None

 cmd/Kconfig  |  7 +++++++
 cmd/Makefile |  1 +
 cmd/log.c    | 55

+++++++++++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 63 insertions(+) create mode 100644 cmd/log.c

cmd/Kconfig +0 -0

index 5a6afab99b7..b745a7e977a 100644
@@ -1502,6 +1502,13 @@ config CMD_KGDB
 	  single-stepping, inspecting variables, etc. This is

supported only on PowerPC at present.

cmd/Kconfig +4 -0

+config CMD_LOG
+	bool "log - Generation, control and access to logging"
+	help
+	  This provides access to logging features. It allows the

output of

cmd/Kconfig +1 -0

+	  log data to be controlled to a limited extent (setting up

the default

cmd/Kconfig +2 -0

+	  maximum log level for emitting of records).
+
 config CMD_TRACE
 	bool "trace - Support tracing of function calls and timing"
 	help

cmd/Makefile +1 -0

index f9eb76090d6..00e38696daa 100644
@@ -76,6 +76,7 @@ obj-$(CONFIG_LED_STATUS_CMD) += legacy_led.o
 obj-$(CONFIG_CMD_LED) += led.o
 obj-$(CONFIG_CMD_LICENSE) += license.o
 obj-y += load.o
+obj-$(CONFIG_CMD_LOG) += log.o
 obj-$(CONFIG_ID_EEPROM) += mac.o
 obj-$(CONFIG_CMD_MD5SUM) += md5sum.o
 obj-$(CONFIG_CMD_MEMORY) += mem.o

cmd/log.c new file +17 -0

new file mode 100644
index 00000000000..44e04ab16a8
@@ -0,0 +1,55 @@
+/*
+ * Copyright (c) 2017 Google, Inc
+ * Written by Simon Glass <[email protected]>
+ *
+ * SPDX-License-Identifier:     GPL-2.0+
+ */
+
+#include <common.h>
+#include <command.h>
+#include <dm.h>
+#include <log.h>
+
+static int do_log_level(cmd_tbl_t *cmdtp, int flag, int argc,
+			char * const argv[])
+{
+	if (argc > 1)
+		gd->default_log_level = simple_strtol(argv[1], NULL,

10);

cmd/log.c new file +2 -0

+	else
+		printf("Default log level: %d\n",

gd->default_log_level); +

cmd/log.c new file +5 -0

+	return 0;
+}
+
+static cmd_tbl_t log_sub[] = {
+	U_BOOT_CMD_MKENT(level, CONFIG_SYS_MAXARGS, 1, do_log_level,

"", ""), +};

cmd/log.c new file +2 -0

+
+static int do_log(cmd_tbl_t *cmdtp, int flag, int argc, char * const

argv[]) +{

cmd/log.c new file +16 -0

+	cmd_tbl_t *cp;
+
+	if (argc < 2)
+		return CMD_RET_USAGE;
+
+	/* drop initial "log" arg */
+	argc--;
+	argv++;
+
+	cp = find_cmd_tbl(argv[0], log_sub, ARRAY_SIZE(log_sub));
+	if (cp)
+		return cp->cmd(cmdtp, flag, argc, argv);
+
+	return CMD_RET_USAGE;
+}
+

Add a command which exercises the logging system.

Signed-off-by Simon Glass <[email protected]>

---

Changes in v3: None
Changes in v2:
- Fix function called when test command is selected
- Fix help output for 'log test'
- Rename LOGL_WARN to LOGL_WARNING

 MAINTAINERS         |   1 +
 cmd/Kconfig         |   3 +-
 cmd/log.c           |   6 ++
 common/Kconfig      |  10 +++
 include/log.h       |   3 +
 test/Makefile       |   1 +
 test/log/Makefile   |   7 ++
 test/log/log_test.c | 203
++++++++++++++++++++++++++++++++++++++++++++++++++++ 8 files changed,
233 insertions(+), 1 deletion(-) create mode 100644 test/log/Makefile
 create mode 100644 test/log/log_test.c

MAINTAINERS +1 -0

index 6814c2fc566..47f68651a7c 100644
@@ -297,6 +297,7 @@ S:	Maintained
 T:	git git://git.denx.de/u-boot.git
 F:	common/log.c
 F:	cmd/log.c
+F:	test/log/log_test.c
 
 MICROBLAZE
 M:	Michal Simek <[email protected]>

cmd/Kconfig +0 -0

index b745a7e977a..c0332235261 100644
@@ -1507,7 +1507,8 @@ config CMD_LOG
 	help
 	  This provides access to logging features. It allows the

output of log data to be controlled to a limited extent (setting up the default

cmd/Kconfig +1 -1

-	  maximum log level for emitting of records).
+	  maximum log level for emitting of records). It also

provides access

cmd/Kconfig +1 -0

+	  to a command used for testing the log system.
 
 config CMD_TRACE
 	bool "trace - Support tracing of function calls and timing"

cmd/log.c +0 -0

index 44e04ab16a8..abc523b4971 100644
@@ -23,6 +23,9 @@ static int do_log_level(cmd_tbl_t *cmdtp, int flag,
 int argc, 
 static cmd_tbl_t log_sub[] = {
 	U_BOOT_CMD_MKENT(level, CONFIG_SYS_MAXARGS, 1, do_log_level,

"", ""), +#ifdef CONFIG_LOG_TEST

cmd/log.c +2 -0

+	U_BOOT_CMD_MKENT(test, 2, 1, do_log_test, "", ""),
+#endif
 };
 
 static int do_log(cmd_tbl_t *cmdtp, int flag, int argc, char * const

argv[]) @@ -46,6 +49,9 @@ static int do_log(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]) #ifdef CONFIG_SYS_LONGHELP
static char log_help_text[] =

cmd/log.c +3 -0

 	"level - get/set log level\n"
+#ifdef CONFIG_LOG_TEST
+	"log test - run log tests\n"
+#endif
 	;
 #endif

common/Kconfig +0 -0

index 1b157e47c3d..4da095a4fd7 100644
@@ -494,6 +494,16 @@ config LOG_SPL_CONSOLE
 	  log message is shown - other details like level, category,

file and line number are omitted.

common/Kconfig +6 -0

+config LOG_TEST
+	bool "Provide a test for logging"
+	depends on LOG
+	default y if SANDBOX
+	help
+	  This enables a 'log test' command to test logging. It is

normally

common/Kconfig +1 -0

+	  executed from a pytest and simply outputs logging

information

common/Kconfig +1 -0

+	  in various different ways to test that the logging system

works

common/Kconfig +2 -0

+	  correctly with varoius settings.
+
 endmenu
 
 config DEFAULT_FDT_FILE

include/log.h +2 -0

index 5dced16880b..7f69a17a27b 100644
@@ -249,6 +249,9 @@ struct log_filter {
 #define LOG_DRIVER(_name) \
 	ll_entry_declare(struct log_driver, _name, log_driver)
 
+/* Handle the 'log test' command */
+int do_log_test(cmd_tbl_t *cmdtp, int flag, int argc, char *const

argv[]); +
/**
* log_add_filter() - Add a new filter to a log device *

test/Makefile +1 -0

index 6305afb2119..40f2244b79b 100644
@@ -10,3 +10,4 @@ obj-$(CONFIG_SANDBOX) += command_ut.o
 obj-$(CONFIG_SANDBOX) += compression.o
 obj-$(CONFIG_SANDBOX) += print_ut.o
 obj-$(CONFIG_UT_TIME) += time_ut.o
+obj-$(CONFIG_$(SPL_)LOG) += log/

test/log/Makefile new file +7 -0

new file mode 100644
index 00000000000..b0da8dee282
@@ -0,0 +1,7 @@
+#
+# Copyright (c) 2017 Google, Inc
+#
+# SPDX-License-Identifier:	GPL-2.0+
+#
+
+obj-$(CONFIG_LOG_TEST) += log_test.o

test/log/log_test.c new file +33 -0

new file mode 100644
index 00000000000..38618a3b139
@@ -0,0 +1,203 @@
+/*
+ * Logging support test program
+ *
+ * Copyright (c) 2017 Google, Inc
+ * Written by Simon Glass <[email protected]>
+ *
+ * SPDX-License-Identifier:	GPL-2.0+
+ */
+
+#include <common.h>
+
+/* emit some sample log records in different ways, for testing */
+static int log_run(enum log_category_t cat, const char *file)
+{
+	int i;
+
+	debug("debug\n");
+	for (i = LOGL_FIRST; i < LOGL_COUNT; i++) {
+		log(cat, i, "log %d\n", i);
+		_log(cat, i, file, 100 + i, "func", "_log %d\n", i);
+	}
+
+	return 0;
+}
+
+static int log_test(int testnum)
+{
+	int ret;
+
+	printf("test %d\n", testnum);
+	switch (testnum) {
+	case 0: {
+		/* Check a category filter using the first category

*/

test/log/log_test.c new file +5 -0

+		enum log_category_t cat_list[] = {
+			UCLASS_MMC, UCLASS_SPI, LOGC_NONE, LOGC_END
+		};
+
+		ret = log_add_filter("console", cat_list, LOGL_MAX,

NULL);

test/log/log_test.c new file +10 -0

+		if (ret < 0)
+			return ret;
+		log_run(UCLASS_MMC, "file");
+		ret = log_remove_filter("console", ret);
+		if (ret < 0)
+			return ret;
+		break;
+	}
+	case 1: {
+		/* Check a category filter using the second category

*/

test/log/log_test.c new file +5 -0

+		enum log_category_t cat_list[] = {
+			UCLASS_MMC, UCLASS_SPI, LOGC_END
+		};
+
+		ret = log_add_filter("console", cat_list, LOGL_MAX,

NULL);

test/log/log_test.c new file +10 -0

+		if (ret < 0)
+			return ret;
+		log_run(UCLASS_SPI, "file");
+		ret = log_remove_filter("console", ret);
+		if (ret < 0)
+			return ret;
+		break;
+	}
+	case 2: {
+		/* Check a category filter that should block log

entries */

test/log/log_test.c new file +5 -0

+		enum log_category_t cat_list[] = {
+			UCLASS_MMC,  LOGC_NONE, LOGC_END
+		};
+
+		ret = log_add_filter("console", cat_list, LOGL_MAX,

NULL);

test/log/log_test.c new file +11 -0

+		if (ret < 0)
+			return ret;
+		log_run(UCLASS_SPI, "file");
+		ret = log_remove_filter("console", ret);
+		if (ret < 0)
+			return ret;
+		break;
+	}
+	case 3: {
+		/* Check a passing file filter */
+		ret = log_add_filter("console", NULL, LOGL_MAX,

"file");

test/log/log_test.c new file +11 -0

+		if (ret < 0)
+			return ret;
+		log_run(UCLASS_SPI, "file");
+		ret = log_remove_filter("console", ret);
+		if (ret < 0)
+			return ret;
+		break;
+	}
+	case 4: {
+		/* Check a failing file filter */
+		ret = log_add_filter("console", NULL, LOGL_MAX,

"file");

test/log/log_test.c new file +11 -0

+		if (ret < 0)
+			return ret;
+		log_run(UCLASS_SPI, "file2");
+		ret = log_remove_filter("console", ret);
+		if (ret < 0)
+			return ret;
+		break;
+	}
+	case 5: {
+		/* Check a passing file filter (second in list) */
+		ret = log_add_filter("console", NULL, LOGL_MAX,

"file,file2");

test/log/log_test.c new file +23 -0

+		if (ret < 0)
+			return ret;
+		log_run(UCLASS_SPI, "file2");
+		ret = log_remove_filter("console", ret);
+		if (ret < 0)
+			return ret;
+		break;
+	}
+	case 6: {
+		/* Check a passing file filter */
+		ret = log_add_filter("console", NULL, LOGL_MAX,
+				     "file,file2,log/log_test.c");
+		if (ret < 0)
+			return ret;
+		log_run(UCLASS_SPI, "file2");
+		ret = log_remove_filter("console", ret);
+		if (ret < 0)
+			return ret;
+		break;
+	}
+	case 7: {
+		/* Check a log level filter */
+		ret = log_add_filter("console", NULL, LOGL_WARNING,

NULL);

test/log/log_test.c new file +10 -0

+		if (ret < 0)
+			return ret;
+		log_run(UCLASS_SPI, "file");
+		ret = log_remove_filter("console", ret);
+		if (ret < 0)
+			return ret;
+		break;
+	}
+	case 8: {
+		/* Check two filters, one of which passes everything

*/

test/log/log_test.c new file +3 -0

+		int filt1, filt2;
+
+		ret = log_add_filter("console", NULL, LOGL_WARNING,

NULL);

test/log/log_test.c new file +4 -0

+		if (ret < 0)
+			return ret;
+		filt1 = ret;
+		ret = log_add_filter("console", NULL, LOGL_MAX,

NULL);

test/log/log_test.c new file +14 -0

+		if (ret < 0)
+			return ret;
+		filt2 = ret;
+		log_run(UCLASS_SPI, "file");
+		ret = log_remove_filter("console", filt1);
+		if (ret < 0)
+			return ret;
+		ret = log_remove_filter("console", filt2);
+		if (ret < 0)
+			return ret;
+		break;
+	}
+	case 9: {
+		/* Check three filters, which together pass

everything */

test/log/log_test.c new file +3 -0

+		int filt1, filt2, filt3;
+
+		ret = log_add_filter("console", NULL, LOGL_MAX,

"file)");

test/log/log_test.c new file +4 -0

+		if (ret < 0)
+			return ret;
+		filt1 = ret;
+		ret = log_add_filter("console", NULL, LOGL_MAX,

"file2");

test/log/log_test.c new file +27 -0

+		if (ret < 0)
+			return ret;
+		filt2 = ret;
+		ret = log_add_filter("console", NULL, LOGL_MAX,
+				     "log/log_test.c");
+		if (ret < 0)
+			return ret;
+		filt3 = ret;
+		log_run(UCLASS_SPI, "file2");
+		ret = log_remove_filter("console", filt1);
+		if (ret < 0)
+			return ret;
+		ret = log_remove_filter("console", filt2);
+		if (ret < 0)
+			return ret;
+		ret = log_remove_filter("console", filt3);
+		if (ret < 0)
+			return ret;
+		break;
+	}
+	}
+
+	return 0;
+}
+
+#ifdef CONFIG_LOG_TEST
+int do_log_test(cmd_tbl_t *cmdtp, int flag, int argc, char *const

argv[]) +{

test/log/log_test.c new file +3 -0

+	int testnum = 0;
+	int ret;
+

Add a command which exercises the logging system.

Signed-off-by Simon Glass <[email protected]>

Reviewed-by Lukasz Majewski <[email protected]>

Quoted 4 lines · Simon Glass

Add a command which exercises the logging system.

Signed-off-by Simon Glass <[email protected]>

Reviewed-by Lukasz Majewski <[email protected]>

NAK. With clang-3.8 we see this (and many more):
test/log/log_test.c:35:16: warning: implicit conversion from enumeration type 'enum uclass_id' to different enumeration type 'enum log_category_t' [-Wenum-conversion]
UCLASS_MMC, UCLASS_SPI, LOGC_NONE, LOGC_END
^~~~~~~~~~

For nearly all instances of UCLASS_MMC and UCLASS_SPI in the code.

Hi Tom,

Quoted 14 lines · Tom Rini

Quoted 4 lines · Simon Glass

Add a command which exercises the logging system.

Signed-off-by Simon Glass <[email protected]>

Reviewed-by Lukasz Majewski <[email protected]>

NAK. With clang-3.8 we see this (and many more):
test/log/log_test.c:35:16: warning: implicit conversion from enumeration type 'enum uclass_id' to different enumeration type 'enum log_category_t' [-Wenum-conversion]
UCLASS_MMC, UCLASS_SPI, LOGC_NONE, LOGC_END
^~~~~~~~~~

Quoted 1 line

For nearly all instances of UCLASS_MMC and UCLASS_SPI in the code.

That is unfortunate. I was really hoping to use the uclass as the logging class. I'll have to add a cast or something like that,

Set up logging both before and after relocation.

Signed-off-by Simon Glass <[email protected]>

Reviewed-by Bin Meng <[email protected]>

---

Changes in v3: None
Changes in v2: None

 common/board_f.c                  | 5 ++++-
 common/board_r.c                  | 2 ++
 common/log.c                      | 1 +
 include/asm-generic/global_data.h | 1 +
 4 files changed, 8 insertions(+), 1 deletion(-)

common/board_f.c +1 -0

index 1e8bf63ec10..e46eceda7d0 100644
@@ -751,6 +751,7 @@ static const init_fnc_t init_sequence_f[] = {
 	trace_early_init,
 #endif
 	initf_malloc,
+	log_init,
 	initf_bootstage,	/* uses its own timer, so does not
 need DM */ initf_console_record,
 #if defined(CONFIG_HAVE_FSP)

@@ -932,8 +933,10 @@ void board_init_f_r(void)
 	 * The pre-relocation drivers may be using memory that has

now gone
* away. Mark serial as unavailable - this will fall back to
the debug

common/board_f.c +2 -0

 	 * UART if available.
+	 *
+	 * Do the same with log drivers since the memory may not be

available. */

common/board_f.c +1 -1

-	gd->flags &= ~GD_FLG_SERIAL_READY;
+	gd->flags &= ~(GD_FLG_SERIAL_READY | GD_FLG_LOG_READY);
 #ifdef CONFIG_TIMER
 	gd->timer = NULL;
 #endif

common/board_r.c +2 -0

index 89729d77360..09167c13cc8 100644
@@ -691,6 +691,7 @@ static init_fnc_t init_sequence_r[] = {
 #endif
 	initr_barrier,
 	initr_malloc,
+	log_init,
 	initr_bootstage,	/* Needs malloc() but has its own
 timer */ initr_console_record,
 #ifdef CONFIG_SYS_NONCACHED_MEMORY

@@ -884,6 +885,7 @@ void board_init_r(gd_t *new_gd, ulong dest_addr)
 #if !defined(CONFIG_X86) && !defined(CONFIG_ARM)
 && !defined(CONFIG_ARM64) gd = new_gd;
 #endif
+	gd->flags &= ~GD_FLG_LOG_READY;
 
 #ifdef CONFIG_NEEDS_MANUAL_RELOC
 	for (i = 0; i < ARRAY_SIZE(init_sequence_r); i++)

common/log.c +1 -0

index a7d9a548f2a..c94a3c17592 100644
@@ -238,6 +238,7 @@ int log_init(void)
 			      (struct list_head *)&gd->log_head);
 		drv++;
 	}
+	gd->flags |= GD_FLG_LOG_READY;
 	gd->default_log_level = LOGL_INFO;
 
 	return 0;

(quoted diff) +0 -0

b/include/asm-generic/global_data.h index 77755dbb068..73e036d6fd4 100644 --- a/include/asm-generic/global_data.h
+++ b/include/asm-generic/global_data.h

(quoted diff) +0 -0

@@ -146,5 +146,6 @@ typedef struct global_data {
 #define GD_FLG_RECORD		0x01000	/* Record

console */ #define GD_FLG_ENV_DEFAULT
0x02000 /* Default variable flag */ #define
GD_FLG_SPL_EARLY_INIT 0x04000 /* Early SPL init is
done */ +#define GD_FLG_LOG_READY 0x08000 /* Log
system is ready for use */ #endif /*
__ASM_GENERIC_GBL_DATA_H */

Enable all logging features on sandbox so that the tests can be run.

Signed-off-by Simon Glass <[email protected]>

Reviewed-by Bin Meng <[email protected]>

---

Changes in v3: None
Changes in v2:
- Change sandbox log level to 6

 configs/sandbox_defconfig | 3 +++
 1 file changed, 3 insertions(+)

configs/sandbox_defconfig +2 -0

index b8d1e8cf31a..7efb4ebf117 100644
@@ -16,6 +16,8 @@ CONFIG_CONSOLE_RECORD_OUT_SIZE=0x1000
 CONFIG_SILENT_CONSOLE=y
 CONFIG_PRE_CONSOLE_BUFFER=y
 CONFIG_PRE_CON_BUF_ADDR=0x100000
+CONFIG_LOG=y
+CONFIG_LOG_MAX_LEVEL=6
 CONFIG_CMD_CPU=y
 CONFIG_CMD_LICENSE=y
 CONFIG_CMD_BOOTZ=y

Add a test which tries out various filters and options to make sure that logging works as expected.

Signed-off-by Simon Glass <[email protected]>

---

Changes in v3: None
Changes in v2:
- Change log levels to match new header
- Only execute log tests if CONFIG_LOG is enabled
- Rename LOGL_WARN to LOGL_WARNING

 MAINTAINERS               |   1 +
 test/py/tests/test_log.py | 101

++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 102 insertions(+) create mode 100644 test/py/tests/test_log.py

MAINTAINERS +1 -0

index 47f68651a7c..09ff9e76df9 100644
@@ -298,6 +298,7 @@ T:	git git://git.denx.de/u-boot.git
 F:	common/log.c
 F:	cmd/log.c
 F:	test/log/log_test.c
+F:	test/py/tests/test_log.py
 
 MICROBLAZE
 M:	Michal Simek <[email protected]>

test/py/tests/test_log.py new file +8 -0

new file mode 100644
index 00000000000..fa9a25e8dc0
@@ -0,0 +1,101 @@
+# Copyright (c) 2016, Google Inc.
+#
+# SPDX-License-Identifier:      GPL-2.0+
+#
+# U-Boot Verified Boot Test
+
+"""
+This tests U-Boot logging. It uses the 'log test' command with

various options +and checks that the output is correct. +"""

test/py/tests/test_log.py new file +35 -0

+
+import pytest
+
+LOGL_FIRST, LOGL_WARNING, LOGL_INFO = (0, 4, 6)
+
+ at pytest.mark.buildconfigspec('log')
+def test_log(u_boot_console):
+    """Test that U-Boot logging works correctly."""
+    def check_log_entries(lines, mask, max_level=LOGL_INFO):
+        """Check that the expected log records appear in the output
+
+        Args:
+            lines: iterator containing lines to check
+            mask: bit mask to select which lines to check for:
+                bit 0: standard log line
+                bit 1: _log line
+            max_level: maximum log level to expect in the output
+        """
+        for i in range(max_level):
+            if mask & 1:
+                assert 'log %d' % i == lines.next()
+            if mask & 3:
+                assert '_log %d' % i == lines.next()
+
+    def run_test(testnum):
+        """Run a particular test number (the 'log test' command)
+
+        Args:
+            testnum: Test number to run
+        Returns:
+            iterator containing the lines output from the command
+        """
+
+        with cons.log.section('basic'):
+           output = u_boot_console.run_command('log test %d' %

testnum)

test/py/tests/test_log.py new file +45 -0

+        split = output.replace('\r', '').splitlines()
+        lines = iter(split)
+        assert 'test %d' % testnum == lines.next()
+        return lines
+
+    def test0():
+        lines = run_test(0)
+        check_log_entries(lines, 3)
+
+    def test1():
+        lines = run_test(1)
+        check_log_entries(lines, 3)
+
+    def test2():
+        lines = run_test(2)
+
+    def test3():
+        lines = run_test(3)
+        check_log_entries(lines, 2)
+
+    def test4():
+        lines = run_test(4)
+        assert next(lines, None) == None
+
+    def test5():
+        lines = run_test(5)
+        check_log_entries(lines, 2)
+
+    def test6():
+        lines = run_test(6)
+        check_log_entries(lines, 3)
+
+    def test7():
+        lines = run_test(7)
+        check_log_entries(lines, 3, LOGL_WARNING)
+
+    def test8():
+        lines = run_test(8)
+        check_log_entries(lines, 3)
+
+    def test9():
+        lines = run_test(9)
+        check_log_entries(lines, 3)
+
+    # TODO(sjg at chromium.org): Consider structuring this as separate

tests

test/py/tests/test_log.py new file +1 -0

+    cons = u_boot_console

Add documentation for the log system.

Signed-off-by Simon Glass <[email protected]>

Reviewed-by Bin Meng <[email protected]>

---

Changes in v3:
- Rebase to master

Changes in v2:
- Drop the special log() functions from the README

 doc/README.log | 214

+++++++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 214 insertions(+) create mode 100644 doc/README.log

doc/README.log new file +7 -0

new file mode 100644
index 00000000000..f653fe7d797
@@ -0,0 +1,214 @@
+Logging in U-Boot
+=================
+
+Introduction
+------------
+
+U-Boot's internal operation involves many different steps and

actions. From +setting up the board to displaying a start-up screen to loading an Operating +System, there are many component parts each with many actions. +
+Most of the time this internal detail is not useful. Displaying it on the +console would delay booting (U-Boot's primary purpose) and confuse users. +
+But for digging into what is happening in a particular area, or for debugging +a problem it is often useful to see what U-Boot is doing in more detail than +is visible from the basic console output.

doc/README.log new file +9 -0

+
+U-Boot's logging feature aims to satisfy this goal for both users and
+developers.
+
+
+Logging levels
+--------------
+
+There are a number logging levels available, in increasing order of

verbosity: +

doc/README.log new file +2 -0

+   LOGL_EMERG	- Printed before U-Boot halts
+   LOGL_ALERT	- Indicates action must be taken immediate or

U-Boot will crash
+ LOGL_CRIT - Indicates a critical error that will cause
boot failure

doc/README.log new file +5 -0

+   LOGL_ERR	- Indicates an error that may cause boot failure
+   LOGL_WARNING	- Warning about an unexpected condition
+   LOGL_NOTE	- Important information about progress
+   LOGL_INFO	- Information about normal boot progress
+   LOGL_DEBUG	- Debug information (useful for debugging a

driver or subsystem)
+ LOGL_DEBUG_CONTENT - Debug message showing full message
content

doc/README.log new file +7 -0

+   LOGL_DEBUG_IO	- Debug message showing hardware I/O access
+
+
+Logging category
+----------------
+
+Logging can come from a wide variety of places within U-Boot. Each

log message +has a category which is intended to allow messages to be filtered according to +their source.

doc/README.log new file +5 -0

+
+The following main categories are defined:
+
+   LOGC_NONE	- Unknown category (e.g. a debug() statement)
+   UCLASS_...	- Related to a particular uclass (e.g.

UCLASS_USB)

doc/README.log new file +13 -0

+   LOGC_ARCH	- Related to architecture-specific code
+   LOGC_BOARD	- Related to board-specific code
+   LOGC_CORE	- Related to core driver-model support
+   LOGC_DT	- Related to device tree control
+
+
+Enabling logging
+----------------
+
+The following options are used to enable logging at compile time:
+
+   CONFIG_LOG		- Enables the logging system
+   CONFIG_MAX_LOG_LEVEL - Max log level to build (anything higher is

compiled

doc/README.log new file +2 -0

+				out)
+   CONFIG_LOG_CONSOLE	- Enable writing log records to the

console +

doc/README.log new file +9 -0

+If CONFIG_LOG is not set, then no logging will be available.
+
+The above have SPL versions also, e.g. CONFIG_SPL_MAX_LOG_LEVEL.
+
+
+Using DEBUG
+-----------
+
+U-Boot has traditionally used a #define called DEBUG to enable

debugging on a +file-by-file basis. The debug() macro compiles to a printf() statement if +DEBUG is enabled, and an empty statement if not. +
+With logging enabled, debug() statements are interpreted as logging output +with a level of LOGL_DEBUG and a category of LOGC_NONE.

doc/README.log new file +2 -0

+
+The logging facilities are intended to replace DEBUG, but if DEBUG

is defined +at the top of a file, then it takes precedence. This means that debug() +statements will result in output to the console and this output will not be +logged.

doc/README.log new file +6 -0

+
+
+Logging destinations
+--------------------
+
+If logging information goes nowhere then it serves no purpose.

U-Boot provides +several possible determinations for logging information, all of which can be +enabled or disabled independently:

doc/README.log new file +8 -0

+
+   console - goes to stdout
+
+
+Filters
+-------
+
+Filters are attached to log drivers to control what those drivers

emit. Only +records that pass through the filter make it to the driver. +

doc/README.log new file +7 -0

+Filters can be based on several criteria:
+
+   - maximum log level
+   - in a set of categories
+   - in a set of files
+
+If no filters are attached to a driver then a default filter is

used, which +limits output to records with a level less than CONFIG_LOG_MAX_LEVEL. +

doc/README.log new file +9 -0

+
+Logging statements
+------------------
+
+The main logging function is:
+
+   log(category, level, format_string, ...)
+
+Also debug() and error() will generate log records  - these use

LOG_CATEGORY +as the category, so you should #define this right at the top of the source +file to ensure the category is correct.

doc/README.log new file +6 -0

+
+
+Code size
+---------
+
+Code size impact depends largely on what is enabled. The following

numbers are +for snow, which is a Thumb-2 board:

doc/README.log new file +4 -0

+CONFIG_LOG: bss -52.0 data +92.0 rodata -635.0 text +1048.0
+CONFIG_LOG_MAX_LEVEL=7: bss +188.0 data +4.0 rodata +49183.0 text
+98124.0 +
+The last option turns every debug() statement into a logging call,

which +bloats the code hugely. The advantage is that it is then possible to enable +all logging within U-Boot.

doc/README.log new file +6 -0

+
+
+To Do
+-----
+
+There are lots of useful additions that could be made. None of the

below is +implemented! If you do one, please add a test in test/py/tests/test_log.py +

doc/README.log new file +8 -0

+Convenience functions to support setting the category:
+
+   log_arch(level, format_string, ...) - category LOGC_ARCH
+   log_board(level, format_string, ...) - category LOGC_BOARD
+   log_core(level, format_string, ...) - category LOGC_CORE
+   log_dt(level, format_string, ...) - category LOGC_DT
+
+Convenience functions to support a category defined for a single

file, for +example:

doc/README.log new file +32 -0

+
+   #define LOG_CATEGORY   UCLASS_USB
+
+all of these can use LOG_CATEGORY as the category, and a log level
+corresponding to the function name:
+
+   logc(level, format_string, ...)
+
+More logging destinations:
+
+   device - goes to a device (e.g. serial)
+   buffer - recorded in a memory buffer
+
+Convert debug() statements in the code to log() statements
+
+Support making printf() emit log statements a L_INFO level
+
+Convert error() statements in the code to log() statements
+
+Figure out what to do with BUG(), BUG_ON() and warn_non_spl()
+
+Figure out what to do with assert()
+
+Add a way to browse log records
+
+Add a way to record log records for browsing using an external tool
+
+Add commands to add and remove filters
+
+Add commands to add and remove log devices
+
+Allow sharing of printf format strings in log records to reduce

storage size +for large numbers of log records

doc/README.log new file +8 -0

+
+Add a command-line option to sandbox to set the default logging level
+
+Convert core driver model code to use logging
+
+Convert uclasses to use logging with the correct category
+
+Consider making log() calls emit an automatic newline, perhaps with

a logn()

doc/README.log new file +5 -0

+   function to avoid that
+
+Passing log records through to linux (e.g. via device tree /chosen)
+
+Provide a command to access the number of log records generated, and

the +number dropped due to them being generated before the log system was ready. +
+Add a printf() format string pragma so that log statements are checked properly +

doc/README.log new file +6 -0

+Enhance the log console driver to show level / category / file / line
+information
+
+Add a command to add new log records and delete existing records.
+
+Provide additional log() functions - e.g. logc() to specify the

category +
+--
+Simon Glass <[email protected]>
+15-Sep-17

Quoted 15 lines · On Mon, 20 Nov 2017 15:33:35 -0700 Simon Glass <[email protected]> wrote:

Add documentation for the log system.

Signed-off-by Simon Glass <[email protected]>

Reviewed-by Bin Meng <[email protected]>

---

Changes in v3:
- Rebase to master

Changes in v2:
- Drop the special log() functions from the README

 doc/README.log | 214

+++++++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 214 insertions(+) create mode 100644 doc/README.log

Review

Quoted 7 lines

doc/README.log new file +4 -0

+Code size
+---------
+
+Code size impact depends largely on what is enabled. The following

numbers are +for snow, which is a Thumb-2 board:

(quoted diff) +2 -0

+
+This series: adds bss +20.0 data +4.0 rodata +4.0 text +44.0

It would be more informative to add units (KiB, B).

Quoted 8 lines

(quoted diff) +4 -0

+CONFIG_LOG: bss -52.0 data +92.0 rodata -635.0 text +1048.0
+CONFIG_LOG_MAX_LEVEL=7: bss +188.0 data +4.0 rodata +49183.0 text
+98124.0 +
+The last option turns every debug() statement into a logging call,

which +bloats the code hugely. The advantage is that it is then possible to enable +all logging within U-Boot.
+

As I said before - this is a great piece of SW.

Reviewed-by Lukasz Majewski <[email protected]>

Best regards,

Lukasz Majewski