We cannot use sandbox memory at 0 since other things use memory at that address. Move it up out of the way.

Note that the pre-console buffer is currently disabled with sandbox, but this change will avoid confusion if it is manually enabled.

Signed-off-by: Simon Glass sjg@chromium.org ---

Changes in v3: None Changes in v2: - Split pre-console address change into a separate patch

configs/sandbox_defconfig | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/configs/sandbox_defconfig b/configs/sandbox_defconfig index 08eec8ecc6f..b8d1e8cf31a 100644 --- a/configs/sandbox_defconfig +++ b/configs/sandbox_defconfig @@ -15,7 +15,7 @@ CONFIG_CONSOLE_RECORD=y CONFIG_CONSOLE_RECORD_OUT_SIZE=0x1000 CONFIG_SILENT_CONSOLE=y CONFIG_PRE_CONSOLE_BUFFER=y -CONFIG_PRE_CON_BUF_ADDR=0 +CONFIG_PRE_CON_BUF_ADDR=0x100000 CONFIG_CMD_CPU=y CONFIG_CMD_LICENSE=y CONFIG_CMD_BOOTZ=y

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

Signed-off-by: Simon Glass sjg@chromium.org Reviewed-by: Bin Meng bmeng.cn@gmail.com ---

Changes in v3: None Changes in v2: None

include/common.h | 46 +------------------------------------------ include/log.h | 59 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 60 insertions(+), 45 deletions(-) create mode 100644 include/log.h

diff --git a/include/common.h b/include/common.h index e14e1daa88b..90334a8c086 100644 --- a/include/common.h +++ b/include/common.h @@ -45,51 +45,7 @@ typedef volatile unsigned char vu_char; #define CONFIG_SYS_SUPPORT_64BIT_DATA #endif

-#ifdef DEBUG -#define _DEBUG 1 -#else -#define _DEBUG 0 -#endif - -#ifdef CONFIG_SPL_BUILD -#define _SPL_BUILD 1 -#else -#define _SPL_BUILD 0 -#endif - -/* - * 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 - * optimization. - */ -#define debug_cond(cond, fmt, args...) \ - do { \ - if (cond) \ - printf(pr_fmt(fmt), ##args); \ - } while (0) - -/* Show a message if DEBUG is defined in a file */ -#define debug(fmt, args...) \ - debug_cond(_DEBUG, fmt, ##args) - -/* Show a message if not in SPL */ -#define warn_non_spl(fmt, args...) \ - debug_cond(!_SPL_BUILD, fmt, ##args) - -/* - * An assertion is run-time check done in debug mode only. If DEBUG is not - * defined then it is skipped. If DEBUG is defined and the assertion fails, - * then it calls panic*( which may or may not reset/halt U-Boot (see - * CONFIG_PANIC_HANG), It is hoped that all failing assertions are found - * before release, and after release it is hoped that they don't matter. But - * in any case these failing assertions cannot be fixed with a reset (which - * may just do the same assertion again). - */ -void __assert_fail(const char *assertion, const char *file, unsigned line, - const char *function); -#define assert(x) \ - ({ if (!(x) && _DEBUG) \ - __assert_fail(#x, __FILE__, __LINE__, __func__); }) +#include <log.h>

typedef void (interrupt_handler_t)(void *);

diff --git a/include/log.h b/include/log.h new file mode 100644 index 00000000000..08ad44cf497 --- /dev/null +++ b/include/log.h @@ -0,0 +1,59 @@ +/* + * Logging support + * + * Copyright (c) 2017 Google, Inc + * Written by Simon Glass sjg@chromium.org + * + * SPDX-License-Identifier: GPL-2.0+ + */ + +#ifndef __LOG_H +#define __LOG_H + +#ifdef DEBUG +#define _DEBUG 1 +#else +#define _DEBUG 0 +#endif + +#ifdef CONFIG_SPL_BUILD +#define _SPL_BUILD 1 +#else +#define _SPL_BUILD 0 +#endif + +/* + * 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 + * optimization. + */ +#define debug_cond(cond, fmt, args...) \ + do { \ + if (cond) \ + printf(pr_fmt(fmt), ##args); \ + } while (0) + +/* Show a message if DEBUG is defined in a file */ +#define debug(fmt, args...) \ + debug_cond(_DEBUG, fmt, ##args) + +/* Show a message if not in SPL */ +#define warn_non_spl(fmt, args...) \ + debug_cond(!_SPL_BUILD, fmt, ##args) + +/* + * An assertion is run-time check done in debug mode only. If DEBUG is not + * defined then it is skipped. If DEBUG is defined and the assertion fails, + * then it calls panic*( which may or may not reset/halt U-Boot (see + * CONFIG_PANIC_HANG), It is hoped that all failing assertions are found + * before release, and after release it is hoped that they don't matter. But + * in any case these failing assertions cannot be fixed with a reset (which + * may just do the same assertion again). + */ +void __assert_fail(const char *assertion, const char *file, unsigned int line, + const char *function); +#define assert(x) \ + ({ if (!(x) && _DEBUG) \ + __assert_fail(#x, __FILE__, __LINE__, __func__); }) + +#endif

The debug() macro now evaluates its expression so does not need #ifdef protection. In fact the current code causes a warning with the new log implementation. Adjust the code to fix this.

Signed-off-by: Simon Glass sjg@chromium.org Reviewed-by: Bin Meng bmeng.cn@gmail.com ---

Changes in v3: None Changes in v2: None

cmd/mtdparts.c | 3 --- 1 file changed, 3 deletions(-)

diff --git a/cmd/mtdparts.c b/cmd/mtdparts.c index 3275eb919bf..13677faf4b4 100644 --- a/cmd/mtdparts.c +++ b/cmd/mtdparts.c @@ -873,15 +873,12 @@ static int device_parse(const char *const mtd_dev, const char **ret, struct mtd_ return 1; }

-#ifdef DEBUG pend = strchr(p, ';'); -#endif debug("dev type = %d (%s), dev num = %d, mtd-id = %s\n", id->type, MTD_DEV_TYPE(id->type), id->num, id->mtd_id); debug("parsing partitions %.*s\n", (int)(pend ? pend - p : strlen(p)), p);

- /* parse partitions */ num_parts = 0;

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

Signed-off-by: Simon Glass sjg@chromium.org ---

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

diff --git a/MAINTAINERS b/MAINTAINERS index b167b028ecf..6814c2fc566 100644 --- a/MAINTAINERS +++ b/MAINTAINERS @@ -291,6 +291,13 @@ S: Maintained T: git git://git.denx.de/u-boot-i2c.git F: drivers/i2c/

+LOGGING +M: Simon Glass sjg@chromium.org +S: Maintained +T: git git://git.denx.de/u-boot.git +F: common/log.c +F: cmd/log.c + MICROBLAZE M: Michal Simek monstr@monstr.eu S: Maintained diff --git a/common/Kconfig b/common/Kconfig index c50d6ebb2ad..9747443feb2 100644 --- a/common/Kconfig +++ b/common/Kconfig @@ -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 + can be displayed on the console, recorded in a memory buffer, or + discarded if not needed. Logging supports various categories and + levels of severity. + +config SPL_LOG + bool "Enable logging support in SPL" + help + This enables support for logging of status and debug messages. These + can be displayed on the console, recorded in a memory buffer, or + discarded if not needed. Logging supports various categories and + 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 + higher than this will be ignored. If possible log statements below + 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 + higher than this will be ignored. If possible log statements below + 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 diff --git a/common/Makefile b/common/Makefile index cec506fe3e1..f4b632761fa 100644 --- a/common/Makefile +++ b/common/Makefile @@ -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 diff --git a/common/log.c b/common/log.c new file mode 100644 index 00000000000..a7d9a548f2a --- /dev/null +++ b/common/log.c @@ -0,0 +1,244 @@ +/* + * Logging support + * + * Copyright (c) 2017 Google, Inc + * Written by Simon Glass sjg@chromium.org + * + * 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) +{ + 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) +{ + int i; + + for (i = 0; i < LOGF_MAX_CATEGORIES && cat_list[i] != LOGC_END; i++) { + 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 + */ +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)) + 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) +{ + struct log_filter *filt; + + /* If there are no filters, filter on the default log level */ + 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) + */ +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, + 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[], + enum log_level_t max_level, const char *file_list) +{ + struct log_filter *filt; + struct log_device *ldev; + int i; + + ldev = log_device_find_by_name(drv_name); + if (!ldev) + return -ENOENT; + filt = (struct log_filter *)calloc(1, sizeof(*filt)); + if (!filt) + return -ENOMEM; + + if (cat_list) { + filt->flags |= LOGFF_HAS_CAT; + for (i = 0; ; i++) { + 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); + const int count = ll_entry_count(struct log_driver, log_driver); + struct log_driver *end = drv + count; + + /* + * We cannot add runtime data to the driver since it is likely stored + * in rodata. Instead, set up a 'device' corresponding to each driver. + * 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__); + 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; +} diff --git a/include/asm-generic/global_data.h 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 @@ -114,6 +114,11 @@ typedef struct global_data { struct bootstage_data *bootstage; /* Bootstage information */ struct bootstage_data *new_bootstage; /* Relocated bootstage info */ #endif +#ifdef CONFIG_LOG + int log_drop_count; /* Number of dropped log messages */ + int default_log_level; /* For devices with no filters */ + struct list_head log_head; /* List of struct log_device */ +#endif } gd_t; #endif

diff --git a/include/log.h b/include/log.h index 08ad44cf497..5dced16880b 100644 --- a/include/log.h +++ b/include/log.h @@ -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 */ + LOGL_CRIT, /* Critical conditions */ + LOGL_ERR, /* Error that prevents something from working */ + LOGL_WARNING, /* Warning may prevent optimial operation */ + LOGL_NOTICE, /* Normal but significant condition, printf() */ + LOGL_INFO, /* General information message */ + LOGL_DEBUG, /* Basic debug-level message */ + LOGL_DEBUG_CONTENT, /* Debug message showing full message content */ + LOGL_DEBUG_IO, /* Debug message showing hardware I/O access */ + + 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 + */ +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, + 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 +#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. + */ +#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 @@ -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) + */ +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 + */ +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 + * for processing. The filter is checked before calling this function. + */ + 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 + */ +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 */ +}; + +enum log_filter_flags { + LOGFF_HAS_CAT = 1 << 0, /* Filter has a category list */ +}; + +/** + * 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 + */ +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[], + 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 + */ +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 + */ +int log_init(void); +#else +static inline int log_init(void) +{ + return 0; +} +#endif + #endif

Set up logging both before and after relocation.

Signed-off-by: Simon Glass sjg@chromium.org Reviewed-by: Bin Meng bmeng.cn@gmail.com ---

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(-)

diff --git a/common/board_f.c b/common/board_f.c index 1e8bf63ec10..e46eceda7d0 100644 --- a/common/board_f.c +++ b/common/board_f.c @@ -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 * UART if available. + * + * Do the same with log drivers since the memory may not be available. */ - gd->flags &= ~GD_FLG_SERIAL_READY; + gd->flags &= ~(GD_FLG_SERIAL_READY | GD_FLG_LOG_READY); #ifdef CONFIG_TIMER gd->timer = NULL; #endif diff --git a/common/board_r.c b/common/board_r.c index 89729d77360..09167c13cc8 100644 --- a/common/board_r.c +++ b/common/board_r.c @@ -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++) diff --git a/common/log.c b/common/log.c index a7d9a548f2a..c94a3c17592 100644 --- a/common/log.c +++ b/common/log.c @@ -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; diff --git a/include/asm-generic/global_data.h 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 @@ -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 sjg@chromium.org Reviewed-by: Bin Meng bmeng.cn@gmail.com ---

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

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

diff --git a/configs/sandbox_defconfig b/configs/sandbox_defconfig index b8d1e8cf31a..7efb4ebf117 100644 --- a/configs/sandbox_defconfig +++ b/configs/sandbox_defconfig @@ -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 @@ -64,6 +66,7 @@ CONFIG_CMD_CBFS=y CONFIG_CMD_CRAMFS=y CONFIG_CMD_EXT4_WRITE=y CONFIG_CMD_MTDPARTS=y +CONFIG_CMD_LOG=y CONFIG_MAC_PARTITION=y CONFIG_AMIGA_PARTITION=y CONFIG_OF_CONTROL=y

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

Signed-off-by: Simon Glass sjg@chromium.org ---

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

diff --git a/MAINTAINERS b/MAINTAINERS index 47f68651a7c..09ff9e76df9 100644 --- a/MAINTAINERS +++ b/MAINTAINERS @@ -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 monstr@monstr.eu diff --git a/test/py/tests/test_log.py b/test/py/tests/test_log.py new file mode 100644 index 00000000000..fa9a25e8dc0 --- /dev/null +++ b/test/py/tests/test_log.py @@ -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. +""" + +import pytest + +LOGL_FIRST, LOGL_WARNING, LOGL_INFO = (0, 4, 6) + +@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) + 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@chromium.org): Consider structuring this as separate tests + cons = u_boot_console + test0() + test1() + test2() + test3() + test4() + test5() + test6() + test7() + test8() + test9()

Add documentation for the log system.

Signed-off-by: Simon Glass sjg@chromium.org Reviewed-by: Bin Meng bmeng.cn@gmail.com ---

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

diff --git a/doc/README.log b/doc/README.log new file mode 100644 index 00000000000..f653fe7d797 --- /dev/null +++ b/doc/README.log @@ -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. + +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: + + 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 + 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 + 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. + +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) + 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 + out) + CONFIG_LOG_CONSOLE - Enable writing log records to the console + +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. + +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. + + +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: + + 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. + +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. + + +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. + + +Code size +--------- + +Code size impact depends largely on what is enabled. The following numbers are +for snow, which is a Thumb-2 board: + +This series: adds bss +20.0 data +4.0 rodata +4.0 text +44.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. + + +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 + +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: + + #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 + +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() + 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 + +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 sjg@chromium.org +15-Sep-17