diff --git a/cmd/log.c b/cmd/log.c index abc523b..12bac0e 100644 --- a/cmd/log.c +++ b/cmd/log.c @@ -10,6 +10,8 @@ #include #include +static char log_fmt_chars[LOGF_COUNT] = "clFLfm"; + static int do_log_level(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]) { @@ -21,11 +23,85 @@ static int do_log_level(cmd_tbl_t *cmdtp, int flag, int argc, return 0; } +static int do_log_format(cmd_tbl_t *cmdtp, int flag, int argc, + char * const argv[]) +{ + int i; + + if (argc > 1) { + const char *str = argv[1]; + + if (!strcmp(str, "default")) { + gd->log_fmt = LOGF_DEFAULT; + } else if (!strcmp(str, "all")) { + gd->log_fmt = LOGF_ALL; + } else { + gd->log_fmt = 0; + for (; *str; str++) { + char *ptr = strchr(log_fmt_chars, *str); + + if (!ptr) { + printf("Invalid log char '%c'\n", *str); + return CMD_RET_FAILURE; + } + gd->log_fmt |= 1 << (ptr - log_fmt_chars); + } + } + } else { + printf("Log format: "); + for (i = 0; i < LOGF_COUNT; i++) { + if (gd->log_fmt & (1 << i)) + printf("%c", log_fmt_chars[i]); + } + printf("\n"); + } + + return 0; +} + +static int do_log_rec(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]) +{ + enum log_category_t cat; + enum log_level_t level; + const char *file; + uint line; + const char *func; + const char *msg; + char *end; + + if (argc < 7) + return CMD_RET_USAGE; + cat = log_get_cat_by_name(argv[1]); + level = simple_strtoul(argv[2], &end, 10); + if (end == argv[2]) { + level = log_get_level_by_name(argv[2]); + + if (level == LOGL_NONE) { + printf("Invalid log level '%s'\n", argv[2]); + return CMD_RET_USAGE; + } + } + if (level >= LOGL_MAX) { + printf("Invalid log level %u\n", level); + return CMD_RET_USAGE; + } + file = argv[3]; + line = simple_strtoul(argv[4], NULL, 10); + func = argv[5]; + msg = argv[6]; + if (_log(cat, level, file, line, func, "%s\n", msg)) + return CMD_RET_FAILURE; + + return 0; +} + static cmd_tbl_t log_sub[] = { U_BOOT_CMD_MKENT(level, CONFIG_SYS_MAXARGS, 1, do_log_level, "", ""), #ifdef CONFIG_LOG_TEST U_BOOT_CMD_MKENT(test, 2, 1, do_log_test, "", ""), #endif + U_BOOT_CMD_MKENT(format, CONFIG_SYS_MAXARGS, 1, do_log_format, "", ""), + U_BOOT_CMD_MKENT(rec, CONFIG_SYS_MAXARGS, 1, do_log_rec, "", ""), }; static int do_log(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]) @@ -52,6 +128,12 @@ static char log_help_text[] = #ifdef CONFIG_LOG_TEST "log test - run log tests\n" #endif + "log format - set log output format. is a string where\n" + "\teach letter indicates something that should be displayed:\n" + "\tc=category, l=level, F=file, L=line number, f=function, m=msg\n" + "\tor 'default', equivalent to 'fm', or 'all' for all\n" + "log rec - " + "output a log record" ; #endif diff --git a/common/Kconfig b/common/Kconfig index 21e067c..dcab69d 100644 --- a/common/Kconfig +++ b/common/Kconfig @@ -504,6 +504,19 @@ config LOG_TEST in various different ways to test that the logging system works correctly with varoius settings. +config LOG_ERROR_RETURN + bool "Log all functions which return an error" + depends on LOG + help + When an error is returned in U-Boot it is sometimes difficult to + figure out the root cause. For eaxmple, reading from SPI flash may + fail due to a problem in the SPI controller or due to the flash part + not returning the expected information. This option changes + log_ret() to log any errors it sees. With this option disabled, + log_ret() is a nop. + + You can add log_ret() to all functions which return an error code. + endmenu config DEFAULT_FDT_FILE diff --git a/common/log.c b/common/log.c index 45e46dd..680a60f 100644 --- a/common/log.c +++ b/common/log.c @@ -10,9 +10,77 @@ #include #include #include +#include DECLARE_GLOBAL_DATA_PTR; +static const char *log_cat_name[LOGC_COUNT - LOGC_NONE] = { + "none", + "arch", + "board", + "core", + "driver-model", + "device-tree", + "efi", +}; + +static const char *log_level_name[LOGL_COUNT] = { + "EMERG", + "ALERT", + "CRIT", + "ERR", + "WARNING", + "NOTICE", + "INFO", + "DEBUG", + "CONTENT", + "IO", +}; + +const char *log_get_cat_name(enum log_category_t cat) +{ + if (cat > LOGC_COUNT) + return "invalid"; + if (cat >= LOGC_NONE) + return log_cat_name[cat - LOGC_NONE]; + + return uclass_get_name((enum uclass_id)cat); +} + +enum log_category_t log_get_cat_by_name(const char *name) +{ + enum uclass_id id; + int i; + + for (i = LOGC_NONE; i < LOGC_COUNT; i++) + if (!strcmp(name, log_cat_name[i - LOGC_NONE])) + return i; + id = uclass_get_by_name(name); + if (id != UCLASS_INVALID) + return (enum log_category_t)id; + + return LOGC_NONE; +} + +const char *log_get_level_name(enum log_level_t level) +{ + if (level >= LOGL_COUNT) + return "INVALID"; + return log_level_name[level]; +} + +enum log_level_t log_get_level_by_name(const char *name) +{ + int i; + + for (i = 0; i < LOGL_COUNT; i++) { + if (!strcasecmp(log_level_name[i], name)) + return i; + } + + return LOGL_NONE; +} + static struct log_device *log_device_find_by_name(const char *drv_name) { struct log_device *ldev; @@ -240,6 +308,7 @@ int log_init(void) } gd->flags |= GD_FLG_LOG_READY; gd->default_log_level = LOGL_INFO; + gd->log_fmt = LOGF_DEFAULT; return 0; } diff --git a/common/log_console.c b/common/log_console.c index 5af73bd..2902733 100644 --- a/common/log_console.c +++ b/common/log_console.c @@ -10,9 +10,34 @@ #include #include +DECLARE_GLOBAL_DATA_PTR; + static int log_console_emit(struct log_device *ldev, struct log_rec *rec) { - puts(rec->msg); + int fmt = gd->log_fmt; + + /* + * The output format is designed to give someone a fighting chance of + * figuring out which field is which: + * - level is in CAPS + * - cat is lower case and ends with comma + * - file normally has a .c extension and ends with a colon + * - line is integer and ends with a - + * - function is an identifier and ends with () + * - message has a space before it unless it is on its own + */ + if (fmt & (1 << LOGF_LEVEL)) + printf("%s.", log_get_level_name(rec->level)); + if (fmt & (1 << LOGF_CAT)) + printf("%s,", log_get_cat_name(rec->cat)); + if (fmt & (1 << LOGF_FILE)) + printf("%s:", rec->file); + if (fmt & (1 << LOGF_LINE)) + printf("%d-", rec->line); + if (fmt & (1 << LOGF_FUNC)) + printf("%s()", rec->func); + if (fmt & (1 << LOGF_MSG)) + printf("%s%s", fmt != (1 << LOGF_MSG) ? " " : "", rec->msg); return 0; } diff --git a/configs/sandbox_defconfig b/configs/sandbox_defconfig index 7efb4eb..41a2e34 100644 --- a/configs/sandbox_defconfig +++ b/configs/sandbox_defconfig @@ -18,6 +18,7 @@ CONFIG_PRE_CONSOLE_BUFFER=y CONFIG_PRE_CON_BUF_ADDR=0x100000 CONFIG_LOG=y CONFIG_LOG_MAX_LEVEL=6 +CONFIG_LOG_ERROR_RETURN=y CONFIG_CMD_CPU=y CONFIG_CMD_LICENSE=y CONFIG_CMD_BOOTZ=y diff --git a/doc/README.log b/doc/README.log index f653fe7..dc9e2de 100644 --- a/doc/README.log +++ b/doc/README.log @@ -51,6 +51,7 @@ The following main categories are defined: LOGC_BOARD - Related to board-specific code LOGC_CORE - Related to core driver-model support LOGC_DT - Related to device tree control + LOGC_EFI - Related to EFI implementation Enabling logging @@ -68,6 +69,19 @@ 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. +Log commands +------------ + +The 'log' command provides access to several features: + + level - access the default log level + format - access the console log format + rec - output a log record + test - run tests + +Type 'help log' for details. + + Using DEBUG ----------- @@ -94,6 +108,20 @@ enabled or disabled independently: console - goes to stdout +Log format +---------- + +You can control the log format using the 'log format' command. The basic +format is: + + LEVEL.category,file.c:123-func() message + +In the above, file.c:123 is the filename where the log record was generated and +func() is the function name. By default ('log format default') only the +function name and message are displayed on the console. You can control which +fields are present, but not the field order. + + Filters ------- @@ -121,6 +149,14 @@ 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. +You can also define CONFIG_LOG_ERROR_RETURN to enable the log_ret() macro. This +can be used whenever your function returns an error value: + + return log_ret(uclass_first_device(UCLASS_MMC, &dev)); + +This will write a log record when an error code is detected (a value < 0). This +can make it easier to trace errors that are generated deep in the call stack. + Code size --------- diff --git a/drivers/core/uclass.c b/drivers/core/uclass.c index f5e4067..1aedaa0 100644 --- a/drivers/core/uclass.c +++ b/drivers/core/uclass.c @@ -158,6 +158,20 @@ const char *uclass_get_name(enum uclass_id id) return uc->uc_drv->name; } +enum uclass_id uclass_get_by_name(const char *name) +{ + int i; + + for (i = 0; i < UCLASS_COUNT; i++) { + struct uclass_driver *uc_drv = lists_uclass_lookup(i); + + if (uc_drv && !strcmp(uc_drv->name, name)) + return i; + } + + return UCLASS_INVALID; +} + int uclass_find_device(enum uclass_id id, int index, struct udevice **devp) { struct uclass *uc; diff --git a/include/asm-generic/global_data.h b/include/asm-generic/global_data.h index fd8cd45..1de67e8 100644 --- a/include/asm-generic/global_data.h +++ b/include/asm-generic/global_data.h @@ -119,6 +119,7 @@ typedef struct global_data { 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 */ + int log_fmt; /* Mask containing log format info */ #endif } gd_t; #endif diff --git a/include/dm/uclass.h b/include/dm/uclass.h index 709f661..3a01abc 100644 --- a/include/dm/uclass.h +++ b/include/dm/uclass.h @@ -128,6 +128,14 @@ int uclass_get(enum uclass_id key, struct uclass **ucp); const char *uclass_get_name(enum uclass_id id); /** + * uclass_get_by_name() - Look up a uclass by its driver name + * + * @name: Name to look up + * @returns the associated uclass ID, or UCLASS_INVALID if not found + */ +enum uclass_id uclass_get_by_name(const char *name); + +/** * uclass_get_device() - Get a uclass device based on an ID and index * * The device is probed to activate it ready for use. diff --git a/include/log.h b/include/log.h index 8083b64..20dc528 100644 --- a/include/log.h +++ b/include/log.h @@ -27,8 +27,10 @@ enum log_level_t { LOGL_DEBUG_IO, /* Debug message showing hardware I/O access */ LOGL_COUNT, + LOGL_NONE, + LOGL_FIRST = LOGL_EMERG, - LOGL_MAX = LOGL_DEBUG, + LOGL_MAX = LOGL_DEBUG_IO, }; /** @@ -42,7 +44,9 @@ enum log_category_t { LOGC_ARCH, LOGC_BOARD, LOGC_CORE, - LOGC_DT, + LOGC_DM, /* Core driver-model */ + LOGC_DT, /* Device-tree */ + LOGL_EFI, /* EFI implementation */ LOGC_COUNT, LOGC_END, @@ -156,6 +160,17 @@ void __assert_fail(const char *assertion, const char *file, unsigned int line, ({ if (!(x) && _DEBUG) \ __assert_fail(#x, __FILE__, __LINE__, __func__); }) +#ifdef CONFIG_LOG_ERROR_RETURN +#define log_ret(_ret) ({ \ + int __ret = (_ret); \ + if (__ret < 0) \ + log(LOG_CATEGORY, LOGL_ERR, "returning err=%d\n", __ret); \ + __ret; \ + }) +#else +#define log_ret(_ret) (_ret) +#endif + /** * struct log_rec - a single log record * @@ -256,6 +271,52 @@ struct log_filter { #define LOG_DRIVER(_name) \ ll_entry_declare(struct log_driver, _name, log_driver) +/** + * log_get_cat_name() - Get the name of a category + * + * @cat: Category to look up + * @return category name (which may be a uclass driver name) + */ +const char *log_get_cat_name(enum log_category_t cat); + +/** + * log_get_cat_by_name() - Look up a category by name + * + * @name: Name to look up + * @return category ID, or LOGC_NONE if not found + */ +enum log_category_t log_get_cat_by_name(const char *name); + +/** + * log_get_level_name() - Get the name of a log level + * + * @level: Log level to look up + * @return log level name (in ALL CAPS) + */ +const char *log_get_level_name(enum log_level_t level); + +/** + * log_get_level_by_name() - Look up a log level by name + * + * @name: Name to look up + * @return log level ID, or LOGL_NONE if not found + */ +enum log_level_t log_get_level_by_name(const char *name); + +/* Log format flags (bit numbers) for gd->log_fmt. See log_fmt_chars */ +enum log_fmt { + LOGF_CAT = 0, + LOGF_LEVEL, + LOGF_FILE, + LOGF_LINE, + LOGF_FUNC, + LOGF_MSG, + + LOGF_COUNT, + LOGF_DEFAULT = (1 << LOGF_FUNC) | (1 << LOGF_MSG), + LOGF_ALL = 0x3f, +}; + /* Handle the 'log test' command */ int do_log_test(cmd_tbl_t *cmdtp, int flag, int argc, char *const argv[]); diff --git a/test/dm/core.c b/test/dm/core.c index 50ee41b..052bf8f 100644 --- a/test/dm/core.c +++ b/test/dm/core.c @@ -862,3 +862,12 @@ static int dm_test_device_get_uclass_id(struct unit_test_state *uts) return 0; } DM_TEST(dm_test_device_get_uclass_id, DM_TESTF_SCAN_PDATA); + +static int dm_test_uclass_names(struct unit_test_state *uts) +{ + ut_asserteq_str("test", uclass_get_name(UCLASS_TEST)); + ut_asserteq(UCLASS_TEST, uclass_get_by_name("test")); + + return 0; +} +DM_TEST(dm_test_uclass_names, DM_TESTF_SCAN_PDATA); diff --git a/test/py/tests/test_log.py b/test/py/tests/test_log.py index fa9a25e..76f9236 100644 --- a/test/py/tests/test_log.py +++ b/test/py/tests/test_log.py @@ -28,9 +28,9 @@ def test_log(u_boot_console): """ for i in range(max_level): if mask & 1: - assert 'log %d' % i == lines.next() + assert 'log_run() log %d' % i == lines.next() if mask & 3: - assert '_log %d' % i == lines.next() + assert 'func() _log %d' % i == lines.next() def run_test(testnum): """Run a particular test number (the 'log test' command) @@ -40,7 +40,6 @@ def test_log(u_boot_console): 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() @@ -99,3 +98,30 @@ def test_log(u_boot_console): test7() test8() test9() + +@pytest.mark.buildconfigspec('log') +def test_log_format(u_boot_console): + """Test the 'log format' and 'log rec' commands""" + def run_with_format(fmt, expected_output): + """Set up the log format and then write a log record + + Args: + fmt: Format to use for 'log format' + expected_output: Expected output from the 'log rec' command + """ + output = cons.run_command('log format %s' % fmt) + assert output == '' + output = cons.run_command('log rec arch notice file.c 123 func msg') + assert output == expected_output + + cons = u_boot_console + with cons.log.section('format'): + run_with_format('all', 'NOTICE.arch,file.c:123-func() msg') + output = cons.run_command('log format') + assert output == 'Log format: clFLfm' + + run_with_format('fm', 'func() msg') + run_with_format('clfm', 'NOTICE.arch,func() msg') + run_with_format('FLfm', 'file.c:123-func() msg') + run_with_format('lm', 'NOTICE. msg') + run_with_format('m', 'msg')