From patchwork Sat Sep 12 17:13:34 2020 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Simon Glass X-Patchwork-Id: 1362891 X-Patchwork-Delegate: trini@ti.com Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Authentication-Results: ozlabs.org; spf=pass (sender SPF authorized) smtp.mailfrom=lists.denx.de (client-ip=85.214.62.61; helo=phobos.denx.de; envelope-from=u-boot-bounces@lists.denx.de; receiver=) Authentication-Results: ozlabs.org; dmarc=pass (p=none dis=none) header.from=chromium.org Authentication-Results: ozlabs.org; dkim=pass (1024-bit key; unprotected) header.d=chromium.org header.i=@chromium.org header.a=rsa-sha256 header.s=google header.b=cQ/ICfLb; dkim-atps=neutral Received: from phobos.denx.de (phobos.denx.de [85.214.62.61]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (No client certificate requested) by ozlabs.org (Postfix) with ESMTPS id 4BpfNh66ldz9sTM for ; Sun, 13 Sep 2020 03:13:53 +1000 (AEST) Received: from h2850616.stratoserver.net (localhost [IPv6:::1]) by phobos.denx.de (Postfix) with ESMTP id 56EC7821DB; Sat, 12 Sep 2020 19:13:47 +0200 (CEST) Authentication-Results: phobos.denx.de; dmarc=pass (p=none dis=none) header.from=chromium.org Authentication-Results: phobos.denx.de; spf=pass smtp.mailfrom=u-boot-bounces@lists.denx.de Authentication-Results: phobos.denx.de; dkim=pass (1024-bit key; unprotected) header.d=chromium.org header.i=@chromium.org header.b="cQ/ICfLb"; dkim-atps=neutral Received: by phobos.denx.de (Postfix, from userid 109) id DA41A822B5; Sat, 12 Sep 2020 19:13:45 +0200 (CEST) X-Spam-Checker-Version: SpamAssassin 3.4.2 (2018-09-13) on phobos.denx.de X-Spam-Level: X-Spam-Status: No, score=-2.0 required=5.0 tests=BAYES_00,DKIMWL_WL_HIGH, DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,SPF_HELO_NONE,URIBL_BLOCKED autolearn=ham autolearn_force=no version=3.4.2 Received: from mail-il1-x144.google.com (mail-il1-x144.google.com [IPv6:2607:f8b0:4864:20::144]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits)) (No client certificate requested) by phobos.denx.de (Postfix) with ESMTPS id D3B5680390 for ; Sat, 12 Sep 2020 19:13:42 +0200 (CEST) Authentication-Results: phobos.denx.de; dmarc=pass (p=none dis=none) header.from=chromium.org Authentication-Results: phobos.denx.de; spf=pass smtp.mailfrom=sjg@chromium.org Received: by mail-il1-x144.google.com with SMTP id b17so11895530ilh.4 for ; Sat, 12 Sep 2020 10:13:42 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=chromium.org; s=google; h=from:to:cc:subject:date:message-id:mime-version :content-transfer-encoding; bh=1EbcAEN1eX8DNqH2Tm8L7Nprxsocp2JZ7IfbfKv2ptc=; b=cQ/ICfLbo362seIA61qTrEqcTItAvpr+phWm3ffuOSsQHr+suPRzo8oVs6zU3LoNGX NutMMpGRv21/Hz3YjFzJroUkXtvjRlvQAeper5VjqrHFZYQgOrR3PqfpFpPkklJmxj3F DFD5tIKVVgOzf0/IMQeZiRzVLDbGvxKPsR6Es= X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:from:to:cc:subject:date:message-id:mime-version :content-transfer-encoding; bh=1EbcAEN1eX8DNqH2Tm8L7Nprxsocp2JZ7IfbfKv2ptc=; b=B7QDZq/VpudBp1nbYnCrQdra6HrfeDZpyCDejfDkUuhX2ZdZkFFrHeaWpvVH9W7VJk gbmfbOIIHnyYYzhkDuY1n3A1WHrI/N41Cqt/u/lR/PgI5zDrSWQLsIeSa47/yPkQdhSj THl81vPtV1ILXZnehfQq24OnCyGxvgs0UB+9LnUG7NcaFOGT+YG9FVPU76SQgMkRgeHa 8hM4saNORcocM9dU1nLccz8GxqRsuGee3l/ALj2LDnBzQbarTT0i/XNfTbKmVZRSeNqY sD1FM3+B2KzMkcAtDgRxzZ9jtDmzqWjDjXbzyWttquub6B1HLA59h+pFK36J/qOkiD4w mUgg== X-Gm-Message-State: AOAM531skPIE5sUqrEF7K/FbDOyc3Ev9AoSk5O/mqTgXQgDq5m2Y3Fua 1MFodqbYIrKVUV1d37zENincXOpIoa8nVoVc X-Google-Smtp-Source: ABdhPJzDP6W/BBoq8C4HONOwIEE/KsOw1Sohn+z6xc8Uy0DPkYQgMjHzEVrqe6ZGfLRCPdb590rtPg== X-Received: by 2002:a05:6e02:892:: with SMTP id z18mr6246943ils.71.1599930820813; Sat, 12 Sep 2020 10:13:40 -0700 (PDT) Received: from localhost.localdomain (c-73-14-175-90.hsd1.co.comcast.net. [73.14.175.90]) by smtp.gmail.com with ESMTPSA id r5sm3464134ilc.2.2020.09.12.10.13.39 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Sat, 12 Sep 2020 10:13:40 -0700 (PDT) From: Simon Glass To: U-Boot Mailing List Cc: Heinrich Schuchardt , Simon Glass , Bin Meng , Patrick Delaunay , Sean Anderson , Wolfgang Wallner Subject: [PATCH v2 1/2] log: Allow LOG_DEBUG to always enable log output Date: Sat, 12 Sep 2020 11:13:34 -0600 Message-Id: <20200912171335.3889616-1-sjg@chromium.org> X-Mailer: git-send-email 2.28.0.618.gf4bc123cb7-goog MIME-Version: 1.0 X-BeenThere: u-boot@lists.denx.de X-Mailman-Version: 2.1.34 Precedence: list List-Id: U-Boot discussion List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: u-boot-bounces@lists.denx.de Sender: "U-Boot" X-Virus-Scanned: clamav-milter 0.102.3 at phobos.denx.de X-Virus-Status: Clean At present if CONFIG_LOG enabled, putting LOG_DEBUG at the top of a file (before log.h inclusion) causes _log() to be executed for every log() call, regardless of the build- or run-time logging level. However there is no guarantee that the log record will actually be displayed. If the current log level is lower than LOGL_DEBUG then it will not be. Add a way to signal that the log record should always be displayed and update log_passes_filters() to handle this. With the new behaviour, log_debug() will always log if LOG_DEBUG is enabled. Move log_test_syslog_nodebug() into its own file since it cannot be made to work where it is, with LOG_DEBUG defined. Signed-off-by: Simon Glass --- Changes in v2: - Move log_test_syslog_nodebug() into its own file - Add casts for the enum to keep clang happy common/log.c | 6 ++- doc/README.log | 7 +--- include/log.h | 18 +++++++-- test/log/Makefile | 1 + test/log/syslog_test.c | 76 +---------------------------------- test/log/syslog_test.h | 50 +++++++++++++++++++++++ test/log/syslog_test_ndebug.c | 55 +++++++++++++++++++++++++ 7 files changed, 129 insertions(+), 84 deletions(-) create mode 100644 test/log/syslog_test.h create mode 100644 test/log/syslog_test_ndebug.c diff --git a/common/log.c b/common/log.c index 734d26de4af..f44f15743ff 100644 --- a/common/log.c +++ b/common/log.c @@ -157,6 +157,9 @@ static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec) { struct log_filter *filt; + if (rec->force_debug) + return true; + /* If there are no filters, filter on the default log level */ if (list_empty(&ldev->filter_head)) { if (rec->level > gd->default_log_level) @@ -208,7 +211,8 @@ int _log(enum log_category_t cat, enum log_level_t level, const char *file, va_list args; rec.cat = cat; - rec.level = level; + rec.level = level & LOGL_LEVEL_MASK; + rec.force_debug = level & LOGL_FORCE_DEBUG; rec.file = file; rec.line = line; rec.func = func; diff --git a/doc/README.log b/doc/README.log index ba838824a99..a313399fc93 100644 --- a/doc/README.log +++ b/doc/README.log @@ -78,11 +78,8 @@ Sometimes it is useful to turn on logging just in one file. You can use this: #define LOG_DEBUG to enable building in of all logging statements in a single file. Put it at -the top of the file, before any #includes. - -To actually get U-Boot to output this you need to also set the default logging -level - e.g. set CONFIG_LOG_DEFAULT_LEVEL to 7 (LOGL_DEBUG) or more. Otherwise -debug output is suppressed and will not be generated. +the top of the file, before any #includes. This overrides any log-level setting +in U-Boot, including CONFIG_LOG_DEFAULT_LEVEL, but just for that file. Convenience functions diff --git a/include/log.h b/include/log.h index 2859ce1f2e7..86c8d7be09d 100644 --- a/include/log.h +++ b/include/log.h @@ -33,6 +33,9 @@ enum log_level_t { LOGL_COUNT, LOGL_NONE, + LOGL_LEVEL_MASK = 0xf, /* Mask for valid log levels */ + LOGL_FORCE_DEBUG = 0x10, /* Mask to force output due to LOG_DEBUG */ + LOGL_FIRST = LOGL_EMERG, LOGL_MAX = LOGL_DEBUG_IO, }; @@ -133,7 +136,7 @@ static inline int _log_nop(enum log_category_t cat, enum log_level_t level, #if CONFIG_IS_ENABLED(LOG) #ifdef LOG_DEBUG -#define _LOG_DEBUG 1 +#define _LOG_DEBUG LOGL_FORCE_DEBUG #else #define _LOG_DEBUG 0 #endif @@ -141,9 +144,11 @@ static inline int _log_nop(enum log_category_t cat, enum log_level_t level, /* Emit a log record if the level is less that the maximum */ #define log(_cat, _level, _fmt, _args...) ({ \ int _l = _level; \ - if (CONFIG_IS_ENABLED(LOG) && (_l <= _LOG_MAX_LEVEL || _LOG_DEBUG)) \ - _log((enum log_category_t)(_cat), _l, __FILE__, __LINE__, \ - __func__, \ + if (CONFIG_IS_ENABLED(LOG) && \ + (_LOG_DEBUG != 0 || _l <= _LOG_MAX_LEVEL)) \ + _log((enum log_category_t)(_cat), \ + (enum log_level_t)(_l | _LOG_DEBUG), __FILE__, \ + __LINE__, __func__, \ pr_fmt(_fmt), ##_args); \ }) #else @@ -279,8 +284,12 @@ void __assert_fail(const char *assertion, const char *file, unsigned int line, * Memebers marked as 'allocated' are allocated (e.g. via strdup()) by the log * system. * + * TODO(sjg@chromium.org): Compress this struct down a bit to reduce space, e.g. + * a single u32 for cat, level, line and force_debug + * * @cat: Category, representing a uclass or part of U-Boot * @level: Severity level, less severe is higher + * @force_debug: Force output of debug * @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) @@ -289,6 +298,7 @@ void __assert_fail(const char *assertion, const char *file, unsigned int line, struct log_rec { enum log_category_t cat; enum log_level_t level; + bool force_debug; const char *file; int line; const char *func; diff --git a/test/log/Makefile b/test/log/Makefile index 4c92550f6e3..52e2f7b41c3 100644 --- a/test/log/Makefile +++ b/test/log/Makefile @@ -10,6 +10,7 @@ obj-y += test-main.o ifdef CONFIG_SANDBOX obj-$(CONFIG_LOG_SYSLOG) += syslog_test.o +obj-$(CONFIG_LOG_SYSLOG) += syslog_test_ndebug.o endif ifndef CONFIG_LOG diff --git a/test/log/syslog_test.c b/test/log/syslog_test.c index 120a8b2537b..abcb9ffd28b 100644 --- a/test/log/syslog_test.c +++ b/test/log/syslog_test.c @@ -18,48 +18,11 @@ #include #include #include +#include DECLARE_GLOBAL_DATA_PTR; -#define LOGF_TEST (BIT(LOGF_FUNC) | BIT(LOGF_MSG)) - -/** - * struct sb_log_env - private data for sandbox ethernet driver - * - * This structure is used for the private data of the sandbox ethernet - * driver. - * - * @expected: string expected to be written by the syslog driver - * @uts: unit test state - */ -struct sb_log_env { - const char *expected; - struct unit_test_state *uts; -}; - -/** - * sb_log_tx_handler() - transmit callback function - * - * This callback function is invoked when a network package is sent using the - * sandbox Ethernet driver. The private data of the driver holds a sb_log_env - * structure with the unit test state and the expected UDP payload. - * - * The following checks are executed: - * - * * the Ethernet packet indicates a IP broadcast message - * * the IP header is for a local UDP broadcast message to port 514 - * * the UDP payload matches the expected string - * - * After testing the pointer to the expected string is set to NULL to signal - * that the callback function has been called. - * - * @dev: sandbox ethernet device - * @packet: Ethernet packet - * @len: length of Ethernet packet - * Return: 0 = success - */ -static int sb_log_tx_handler(struct udevice *dev, void *packet, - unsigned int len) +int sb_log_tx_handler(struct udevice *dev, void *packet, unsigned int len) { struct eth_sandbox_priv *priv = dev_get_priv(dev); struct sb_log_env *env = priv->priv; @@ -251,38 +214,3 @@ static int log_test_syslog_debug(struct unit_test_state *uts) return 0; } LOG_TEST(log_test_syslog_debug); - -/** - * log_test_syslog_nodebug() - test logging level filter - * - * Verify that log_debug() does not lead to a log message if the logging level - * is set to LOGL_INFO. - * - * @uts: unit test state - * Return: 0 = success - */ -static int log_test_syslog_nodebug(struct unit_test_state *uts) -{ - int old_log_level = gd->default_log_level; - struct sb_log_env env; - - gd->log_fmt = LOGF_TEST; - gd->default_log_level = LOGL_INFO; - env_set("ethact", "eth@10002000"); - env_set("log_hostname", "sandbox"); - env.expected = "<7>sandbox uboot: log_test_syslog_nodebug() " - "testing log_debug\n"; - env.uts = uts; - sandbox_eth_set_tx_handler(0, sb_log_tx_handler); - /* Used by ut_assert macros in the tx_handler */ - sandbox_eth_set_priv(0, &env); - log_debug("testing %s\n", "log_debug"); - sandbox_eth_set_tx_handler(0, NULL); - /* Check that the callback function was not called */ - ut_assertnonnull(env.expected); - gd->default_log_level = old_log_level; - gd->log_fmt = log_get_default_format(); - - return 0; -} -LOG_TEST(log_test_syslog_nodebug); diff --git a/test/log/syslog_test.h b/test/log/syslog_test.h new file mode 100644 index 00000000000..75900f3aad3 --- /dev/null +++ b/test/log/syslog_test.h @@ -0,0 +1,50 @@ +/* SPDX-License-Identifier: GPL-2.0+ */ +/* + * Copyright (c) 2020, Heinrich Schuchardt + * + * Header file for logging tests + */ + +#ifndef __SYSLOG_TEST_H +#define __SYSLOG_TEST_H + +#define LOGF_TEST (BIT(LOGF_FUNC) | BIT(LOGF_MSG)) + +/** + * struct sb_log_env - private data for sandbox ethernet driver + * + * This structure is used for the private data of the sandbox ethernet + * driver. + * + * @expected: string expected to be written by the syslog driver + * @uts: unit test state + */ +struct sb_log_env { + const char *expected; + struct unit_test_state *uts; +}; + +/** + * sb_log_tx_handler() - transmit callback function + * + * This callback function is invoked when a network package is sent using the + * sandbox Ethernet driver. The private data of the driver holds a sb_log_env + * structure with the unit test state and the expected UDP payload. + * + * The following checks are executed: + * + * * the Ethernet packet indicates a IP broadcast message + * * the IP header is for a local UDP broadcast message to port 514 + * * the UDP payload matches the expected string + * + * After testing the pointer to the expected string is set to NULL to signal + * that the callback function has been called. + * + * @dev: sandbox ethernet device + * @packet: Ethernet packet + * @len: length of Ethernet packet + * Return: 0 = success + */ +int sb_log_tx_handler(struct udevice *dev, void *packet, unsigned int len); + +#endif diff --git a/test/log/syslog_test_ndebug.c b/test/log/syslog_test_ndebug.c new file mode 100644 index 00000000000..7815977ea27 --- /dev/null +++ b/test/log/syslog_test_ndebug.c @@ -0,0 +1,55 @@ +// SPDX-License-Identifier: GPL-2.0+ +/* + * Copyright (c) 2020, Heinrich Schuchardt + * + * Logging function tests for CONFIG_LOG_SYSLOG=y. + * + * Invoke the test with: ./u-boot -d arch/sandbox/dts/test.dtb + */ + +#include +#include +#include +#include +#include +#include +#include +#include +#include + +DECLARE_GLOBAL_DATA_PTR; + +/** + * log_test_syslog_nodebug() - test logging level filter + * + * Verify that log_debug() does not lead to a log message if the logging level + * is set to LOGL_INFO. + * + * @uts: unit test state + * Return: 0 = success + */ +static int log_test_syslog_nodebug(struct unit_test_state *uts) +{ + int old_log_level = gd->default_log_level; + struct sb_log_env env; + + gd->log_fmt = LOGF_TEST; + gd->default_log_level = LOGL_INFO; + env_set("ethact", "eth@10002000"); + env_set("log_hostname", "sandbox"); + env.expected = "<7>sandbox uboot: log_test_syslog_nodebug() " + "testing log_debug\n"; + env.uts = uts; + sandbox_eth_set_tx_handler(0, sb_log_tx_handler); + /* Used by ut_assert macros in the tx_handler */ + sandbox_eth_set_priv(0, &env); + log_debug("testing %s\n", "log_debug"); + sandbox_eth_set_tx_handler(0, NULL); + /* Check that the callback function was not called */ + ut_assertnonnull(env.expected); + gd->default_log_level = old_log_level; + gd->log_fmt = log_get_default_format(); + + return 0; +} +LOG_TEST(log_test_syslog_nodebug);