From patchwork Tue Oct 27 23:55:41 2020 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Sean Anderson X-Patchwork-Id: 1389070 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=gmail.com Authentication-Results: ozlabs.org; dkim=pass (2048-bit key; unprotected) header.d=gmail.com header.i=@gmail.com header.a=rsa-sha256 header.s=20161025 header.b=Y73t7tcj; 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)) (No client certificate requested) by ozlabs.org (Postfix) with ESMTPS id 4CLTGW0ls1z9s0b for ; Wed, 28 Oct 2020 11:00:03 +1100 (AEDT) Received: from h2850616.stratoserver.net (localhost [IPv6:::1]) by phobos.denx.de (Postfix) with ESMTP id 1A4DD82569; Wed, 28 Oct 2020 00:57:06 +0100 (CET) Authentication-Results: phobos.denx.de; dmarc=pass (p=none dis=none) header.from=gmail.com Authentication-Results: phobos.denx.de; spf=pass smtp.mailfrom=u-boot-bounces@lists.denx.de Authentication-Results: phobos.denx.de; dkim=pass (2048-bit key; unprotected) header.d=gmail.com header.i=@gmail.com header.b="Y73t7tcj"; dkim-atps=neutral Received: by phobos.denx.de (Postfix, from userid 109) id 523088251D; Wed, 28 Oct 2020 00:56:24 +0100 (CET) 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,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_AU,FREEMAIL_FROM,SPF_HELO_NONE,URIBL_BLOCKED autolearn=ham autolearn_force=no version=3.4.2 Received: from mail-qt1-x82f.google.com (mail-qt1-x82f.google.com [IPv6:2607:f8b0:4864:20::82f]) (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 6B1A7824F4 for ; Wed, 28 Oct 2020 00:56:20 +0100 (CET) Authentication-Results: phobos.denx.de; dmarc=pass (p=none dis=none) header.from=gmail.com Authentication-Results: phobos.denx.de; spf=pass smtp.mailfrom=seanga2@gmail.com Received: by mail-qt1-x82f.google.com with SMTP id h19so2406655qtq.4 for ; Tue, 27 Oct 2020 16:56:20 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=siQ0aopy0j6Y5cFqud9iFyO6/GJPUKkS21SBnEdzPm4=; b=Y73t7tcjKoVM5mSx/o/qhArN4xg2ejqNxjo2pygXLdSDRe1GLDMpHuQteAu2tevuDx MdR1xvrnGAlidwzlc4YEDNl7I0sTsjfLm3vAOBYv/1TUHB8EiGjJfnK+2EZ71iY4xkeP IU0X99lceSsBebKGecCz6wXYeeiBybqcv7GsZwQ6Kgh1vkC1Xu2gSKatbcbNuAYlKWLX bJc/YLx6lQUhODK3dd/PfpQ29XuRgo8OjwU4WRnVH1pkcygulak1Yt4EUaEwhDTJ7zq2 nVxSkKgULFvd2LBQ859cEL0icedswGL4Y1iqT7R7+hczMqOSJZ84cJOmla/5Z1/ovGVt k0DQ== 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:in-reply-to :references:mime-version:content-transfer-encoding; bh=siQ0aopy0j6Y5cFqud9iFyO6/GJPUKkS21SBnEdzPm4=; b=YrUbblgqRcHypAX0MOtDKKUCpA5++0jgNmlaLQ3V8E3rv+aL25ajZY2unOD5qJM6yn raMY8CKCWS+/lrZKDOpC9lPBvNTTz98BocSFPS4K77EswBO3g08WB9W0Bj5/5dRuJasZ Bz/28LS0zj+bn6hP0hUWHgwj2RNqzGM6h0YCma63lrJqUe83ce7AaRLnX3N/dZhZ/zEl y1qaXvIc4vFvjLcdSQBmbkpIGQTdc3BuKaCthC/FDdDgR3lBo3wsiFguklQtFPcBUXFH eDR/ZT/0pHNH9VQ2SO+Wkuy438p7WE8hdVhu8PNu0J84HPzB/FcEKbKPsM5WfS1wzIVx JA8Q== X-Gm-Message-State: AOAM532Bkds5rkTV+wgwWSYWPFq6XAtWrwzBC8bQV4iqP2h3Uf1T/BTD o4eCt3F+DwB6QQOXIPkOz0Y37prFI9tuNg== X-Google-Smtp-Source: ABdhPJwclCqPcVdxGDeCx8ehzUV+2skx5CR+oBSA5ZWOcM3UoSvvgeS/2u3YXYFF/9p9yZ3cCct+Gw== X-Received: by 2002:ac8:578f:: with SMTP id v15mr4484141qta.81.1603842978813; Tue, 27 Oct 2020 16:56:18 -0700 (PDT) Received: from godwin.fios-router.home (pool-108-51-35-162.washdc.fios.verizon.net. [108.51.35.162]) by smtp.gmail.com with ESMTPSA id 69sm1907543qko.48.2020.10.27.16.56.17 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Tue, 27 Oct 2020 16:56:18 -0700 (PDT) From: Sean Anderson To: u-boot@lists.denx.de Cc: Tom Rini , Heinrich Schuchardt , Simon Glass , Sean Anderson Subject: [PATCH v4 22/22] doc: Update logging documentation Date: Tue, 27 Oct 2020 19:55:41 -0400 Message-Id: <20201027235541.706077-23-seanga2@gmail.com> X-Mailer: git-send-email 2.28.0 In-Reply-To: <20201027235541.706077-1-seanga2@gmail.com> References: <20201027235541.706077-1-seanga2@gmail.com> 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 This updates logging documentation with some examples of the new commands added in the previous commits. It also removes some items from the to-do list which have been implemented. Signed-off-by: Sean Anderson Reviewed-by: Simon Glass --- Changes in v4: - Add some more examples to docs Changes in v3: - Fix heading level of Filters section - Remove a few more already-implemented features from the TODO list Changes in v2: - Add a few informational commands - Clarify wording of filter documentation - Include enum definitions instead of re-documenting them - Reorganize log documentation; related sections should now be more proximate doc/develop/logging.rst | 221 ++++++++++++++++++++-------------------- 1 file changed, 110 insertions(+), 111 deletions(-) diff --git a/doc/develop/logging.rst b/doc/develop/logging.rst index 52ccd2009e..7fdd1132ef 100644 --- a/doc/develop/logging.rst +++ b/doc/develop/logging.rst @@ -21,23 +21,13 @@ 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 +There are a number logging levels available. +.. kernel-doc:: include/log.h + :identifiers: log_level_t Logging category ---------------- @@ -46,16 +36,8 @@ 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 -* LOGC_EFI - Related to EFI implementation - +.. kernel-doc:: include/log.h + :identifiers: log_category_t Enabling logging ---------------- @@ -72,7 +54,6 @@ If CONFIG_LOG is not set, then no logging will be available. The above have SPL and TPL versions also, e.g. CONFIG_SPL_LOG_MAX_LEVEL and CONFIG_TPL_LOG_MAX_LEVEL. - Temporary logging within a single file -------------------------------------- @@ -83,12 +64,52 @@ 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. This overrides any log-level setting -in U-Boot, including CONFIG_LOG_DEFAULT_LEVEL, but just for that file. +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 (:c:type:`LOGL_DEBUG`) or more. +Otherwise debug output is suppressed and will not be generated. + +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 statements +------------------ + +The main logging function is: + +.. code-block:: c + + 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. + +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: + +.. code-block:: c + + 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. Convenience functions ---------------------- +~~~~~~~~~~~~~~~~~~~~~ A number of convenience functions are available to shorten the code needed for logging: @@ -116,36 +137,6 @@ or Remember that all uclasses IDs are log categories too. - -Log command ------------ - -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 ------------ - -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 -------------------- @@ -159,9 +150,40 @@ enabled or disabled independently: The syslog driver sends the value of environmental variable 'log_hostname' as HOSTNAME if available. +Filters +------- + +Filters are attached to log drivers to control what those drivers emit. FIlters +can either allow or deny a log message when they match it. Only records which +are allowed by a filter make it to the driver. + +Filters can be based on several criteria: + +* minimum or 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_MAX_LOG_LEVEL. + +Log command +----------- + +The 'log' command provides access to several features: + +* level - list log levels or set the default log level +* categories - list log categories +* drivers - list log drivers +* filter-list - list filters +* filter-add - add a new filter +* filter-remove - remove filters +* format - access the console log format +* rec - output a log record + +Type 'help log' for details. Log format ----------- +~~~~~~~~~~ You can control the log format using the 'log format' command. The basic format is:: @@ -169,50 +191,43 @@ 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. +func() is the function name. By default ('log format default') only the message +is displayed on the console. You can control which fields are present, but not +the field order. +Adding Filters +~~~~~~~~~~~~~~ -Filters -------- +To add new filters at runtime, use the 'log filter-add' command. For example, to +suppress messages from the SPI and MMC subsystems, run:: -Filters are attached to log drivers to control what those drivers emit. Only -records that pass through the filter make it to the driver. + log filter-add -D -c spi -c mmc -Filters can be based on several criteria: +You will also need to add another filter to allow other messages (because the +default filter no longer applies):: -* maximum log level -* in a set of categories -* in a set of files + log filter-add -A -l info -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_MAX_LOG_LEVEL. +Log levels may be either symbolic names (like above) or numbers. For example, to +disable all debug and above (log level 7) messages from ``drivers/core/lists.c`` +and ``drivers/core/ofnode.c``, run:: + log filter-add -D -f drivers/core/lists.c,drivers/core/ofnode.c -L 7 -Logging statements ------------------- +To view active filters, use the 'log filter-list' command. Some example output +is:: -The main logging function is: - -.. code-block:: c - - 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. - -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: - -.. code-block:: c - - 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. + => log filter-list + num policy level categories files + 2 deny >= DEBUG drivers/core/lists.c,drivers/core/ofnode.c + 0 deny <= IO spi + mmc + 1 allow <= INFO +Note that filters are processed in-order from top to bottom, not in the order of +their filter number. Filters are added to the top of the list if they deny when +they match, and to the bottom if they allow when they match. For more +information, consult the usage of the 'log' command, by running 'help log'. Code size --------- @@ -229,13 +244,12 @@ 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 - +implemented! If you do one, please add a test in test/log/log_test.c +log filter-add -D -f drivers/core/lists.c,drivers/core/ofnode.c -l 6 Convenience functions to support setting the category: * log_arch(level, format_string, ...) - category LOGC_ARCH @@ -256,25 +270,15 @@ 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 @@ -285,12 +289,7 @@ 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 +Add a command to delete existing log records. Logging API -----------