blob: 704a6bf1d8448026b22030fe622e70ada15519e5 [file] [log] [blame]
Heinrich Schuchardta7813912020-05-31 10:46:12 +02001.. SPDX-License-Identifier: GPL-2.0+
2.. Copyright (c) 2017 Simon Glass <sjg@chromium.org>
3
4Logging in U-Boot
5=================
6
7Introduction
8------------
9
10U-Boot's internal operation involves many different steps and actions. From
11setting up the board to displaying a start-up screen to loading an Operating
12System, there are many component parts each with many actions.
13
14Most of the time this internal detail is not useful. Displaying it on the
15console would delay booting (U-Boot's primary purpose) and confuse users.
16
17But for digging into what is happening in a particular area, or for debugging
18a problem it is often useful to see what U-Boot is doing in more detail than
19is visible from the basic console output.
20
21U-Boot's logging feature aims to satisfy this goal for both users and
22developers.
23
Heinrich Schuchardta7813912020-05-31 10:46:12 +020024Logging levels
25--------------
26
Sean Anderson8ba0f892020-10-27 19:55:41 -040027There are a number logging levels available.
Heinrich Schuchardta7813912020-05-31 10:46:12 +020028
Heinrich Schuchardta6aaeb22021-01-25 21:06:57 +010029See enum :c:type:`log_level_t`
Heinrich Schuchardta7813912020-05-31 10:46:12 +020030
31Logging category
32----------------
33
34Logging can come from a wide variety of places within U-Boot. Each log message
35has a category which is intended to allow messages to be filtered according to
36their source.
37
Heinrich Schuchardta6aaeb22021-01-25 21:06:57 +010038See enum :c:type:`log_category_t`
Heinrich Schuchardta7813912020-05-31 10:46:12 +020039
40Enabling logging
41----------------
42
43The following options are used to enable logging at compile time:
44
45* CONFIG_LOG - Enables the logging system
46* CONFIG_LOG_MAX_LEVEL - Max log level to build (anything higher is compiled
47 out)
48* CONFIG_LOG_CONSOLE - Enable writing log records to the console
49
50If CONFIG_LOG is not set, then no logging will be available.
51
52The above have SPL and TPL versions also, e.g. CONFIG_SPL_LOG_MAX_LEVEL and
53CONFIG_TPL_LOG_MAX_LEVEL.
54
Simon Glasse1cbd912021-05-08 13:46:54 -060055If logging is disabled, the default behaviour is to output any message at
56level LOGL_INFO and below. If logging is disabled and DEBUG is defined (at
57the very top of a C file) then any message at LOGL_DEBUG will be written.
58
Heinrich Schuchardta7813912020-05-31 10:46:12 +020059Temporary logging within a single file
60--------------------------------------
61
62Sometimes it is useful to turn on logging just in one file. You can use this
63
64.. code-block:: c
65
66 #define LOG_DEBUG
67
68to enable building in of all logging statements in a single file. Put it at
Patrick Delaunay54e89a82022-07-12 09:39:49 +020069the top of the file, before any #includes and any message in the file will be
70written, regardless of the value of CONFIG_LOG_DEFAULT_LEVEL.
Sean Anderson8ba0f892020-10-27 19:55:41 -040071
72Using DEBUG
73-----------
74
75U-Boot has traditionally used a #define called DEBUG to enable debugging on a
Patrick Delaunay54e89a82022-07-12 09:39:49 +020076file-by-file basis but LOG_DEBUG are intended to replace it with the logging
77facilities; DEBUG is activated when LOG_DEBUG is activated.
Sean Anderson8ba0f892020-10-27 19:55:41 -040078
79With logging enabled, debug() statements are interpreted as logging output
Patrick Delaunay54e89a82022-07-12 09:39:49 +020080with a level of LOGL_DEBUG and a category of LOG_CATEGORY.
Sean Anderson8ba0f892020-10-27 19:55:41 -040081
Patrick Delaunay54e89a82022-07-12 09:39:49 +020082With logging disabled, the debug() macro compiles to a printf() statement
83if DEBUG is enabled and to an empty statement if not.
Sean Anderson8ba0f892020-10-27 19:55:41 -040084
85Logging statements
86------------------
87
88The main logging function is:
89
90.. code-block:: c
91
92 log(category, level, format_string, ...)
93
94Also debug() and error() will generate log records - these use LOG_CATEGORY
95as the category, so you should #define this right at the top of the source
96file to ensure the category is correct.
97
Simon Glass9ad7a6c2021-01-20 20:10:53 -070098Generally each log format_string ends with a newline. If it does not, then the
99next log statement will have the LOGRECF_CONT flag set. This can be used to
100continue the statement on the same line as the previous one without emitting
101new header information (such as category/level). This behaviour is implemented
102with log_console. Here is an example that prints a list all on one line with
103the tags at the start:
104
105.. code-block:: c
106
107 log_debug("Here is a list:");
108 for (i = 0; i < count; i++)
109 log_debug(" item %d", i);
110 log_debug("\n");
111
112Also see the special category LOGL_CONT and level LOGC_CONT.
113
Sean Anderson8ba0f892020-10-27 19:55:41 -0400114You can also define CONFIG_LOG_ERROR_RETURN to enable the log_ret() macro. This
115can be used whenever your function returns an error value:
116
117.. code-block:: c
118
Simon Glass7bd06582021-01-20 20:10:54 -0700119 return log_ret(uclass_first_device_err(UCLASS_MMC, &dev));
Sean Anderson8ba0f892020-10-27 19:55:41 -0400120
121This will write a log record when an error code is detected (a value < 0). This
122can make it easier to trace errors that are generated deep in the call stack.
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200123
Simon Glass7bd06582021-01-20 20:10:54 -0700124The log_msg_ret() variant will print a short string if CONFIG_LOG_ERROR_RETURN
125is enabled. So long as the string is unique within the function you can normally
126determine exactly which call failed:
127
128.. code-block:: c
129
130 ret = gpio_request_by_name(dev, "cd-gpios", 0, &desc, GPIOD_IS_IN);
131 if (ret)
132 return log_msg_ret("gpio", ret);
133
134Some functions return 0 for success and any other value is an error. For these,
135log_retz() and log_msg_retz() are available.
136
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200137Convenience functions
Sean Anderson8ba0f892020-10-27 19:55:41 -0400138~~~~~~~~~~~~~~~~~~~~~
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200139
140A number of convenience functions are available to shorten the code needed
141for logging:
142
143* log_err(_fmt...)
144* log_warning(_fmt...)
145* log_notice(_fmt...)
146* log_info(_fmt...)
147* log_debug(_fmt...)
148* log_content(_fmt...)
149* log_io(_fmt...)
150
151With these the log level is implicit in the name. The category is set by
152LOG_CATEGORY, which you can only define once per file, above all #includes, e.g.
153
154.. code-block:: c
155
156 #define LOG_CATEGORY LOGC_ALLOC
157
Simon Glass7ad1e0b2020-10-13 19:55:07 -0600158or
159
160.. code-block:: c
161
162 #define LOG_CATEGORY UCLASS_SPI
163
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200164Remember that all uclasses IDs are log categories too.
165
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200166Logging destinations
167--------------------
168
169If logging information goes nowhere then it serves no purpose. U-Boot provides
170several possible determinations for logging information, all of which can be
171enabled or disabled independently:
172
173* console - goes to stdout
174* syslog - broadcast RFC 3164 messages to syslog servers on UDP port 514
175
176The syslog driver sends the value of environmental variable 'log_hostname' as
177HOSTNAME if available.
178
Sean Anderson8ba0f892020-10-27 19:55:41 -0400179Filters
180-------
181
182Filters are attached to log drivers to control what those drivers emit. FIlters
183can either allow or deny a log message when they match it. Only records which
184are allowed by a filter make it to the driver.
185
186Filters can be based on several criteria:
187
188* minimum or maximum log level
189* in a set of categories
190* in a set of files
191
192If no filters are attached to a driver then a default filter is used, which
193limits output to records with a level less than CONFIG_MAX_LOG_LEVEL.
194
195Log command
196-----------
197
198The 'log' command provides access to several features:
199
200* level - list log levels or set the default log level
201* categories - list log categories
202* drivers - list log drivers
203* filter-list - list filters
204* filter-add - add a new filter
205* filter-remove - remove filters
206* format - access the console log format
207* rec - output a log record
208
209Type 'help log' for details.
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200210
211Log format
Sean Anderson8ba0f892020-10-27 19:55:41 -0400212~~~~~~~~~~
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200213
214You can control the log format using the 'log format' command. The basic
215format is::
216
217 LEVEL.category,file.c:123-func() message
218
219In the above, file.c:123 is the filename where the log record was generated and
Sean Anderson8ba0f892020-10-27 19:55:41 -0400220func() is the function name. By default ('log format default') only the message
221is displayed on the console. You can control which fields are present, but not
222the field order.
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200223
Sean Anderson8ba0f892020-10-27 19:55:41 -0400224Adding Filters
225~~~~~~~~~~~~~~
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200226
Sean Anderson8ba0f892020-10-27 19:55:41 -0400227To add new filters at runtime, use the 'log filter-add' command. For example, to
228suppress messages from the SPI and MMC subsystems, run::
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200229
Sean Anderson8ba0f892020-10-27 19:55:41 -0400230 log filter-add -D -c spi -c mmc
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200231
Sean Anderson8ba0f892020-10-27 19:55:41 -0400232You will also need to add another filter to allow other messages (because the
233default filter no longer applies)::
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200234
Sean Anderson8ba0f892020-10-27 19:55:41 -0400235 log filter-add -A -l info
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200236
Sean Anderson8ba0f892020-10-27 19:55:41 -0400237Log levels may be either symbolic names (like above) or numbers. For example, to
238disable all debug and above (log level 7) messages from ``drivers/core/lists.c``
239and ``drivers/core/ofnode.c``, run::
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200240
Sean Anderson8ba0f892020-10-27 19:55:41 -0400241 log filter-add -D -f drivers/core/lists.c,drivers/core/ofnode.c -L 7
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200242
Sean Anderson8ba0f892020-10-27 19:55:41 -0400243To view active filters, use the 'log filter-list' command. Some example output
244is::
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200245
Sean Anderson8ba0f892020-10-27 19:55:41 -0400246 => log filter-list
247 num policy level categories files
248 2 deny >= DEBUG drivers/core/lists.c,drivers/core/ofnode.c
249 0 deny <= IO spi
250 mmc
251 1 allow <= INFO
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200252
Sean Anderson8ba0f892020-10-27 19:55:41 -0400253Note that filters are processed in-order from top to bottom, not in the order of
254their filter number. Filters are added to the top of the list if they deny when
255they match, and to the bottom if they allow when they match. For more
256information, consult the usage of the 'log' command, by running 'help log'.
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200257
258Code size
259---------
260
261Code size impact depends largely on what is enabled. The following numbers are
262generated by 'buildman -S' for snow, which is a Thumb-2 board (all units in
263bytes)::
264
265 This series: adds bss +20.0 data +4.0 rodata +4.0 text +44.0
266 CONFIG_LOG: bss -52.0 data +92.0 rodata -635.0 text +1048.0
267 CONFIG_LOG_MAX_LEVEL=7: bss +188.0 data +4.0 rodata +49183.0 text +98124.0
268
269The last option turns every debug() statement into a logging call, which
270bloats the code hugely. The advantage is that it is then possible to enable
271all logging within U-Boot.
272
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200273To Do
274-----
275
276There are lots of useful additions that could be made. None of the below is
Sean Anderson8ba0f892020-10-27 19:55:41 -0400277implemented! If you do one, please add a test in test/log/log_test.c
278log filter-add -D -f drivers/core/lists.c,drivers/core/ofnode.c -l 6
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200279Convenience functions to support setting the category:
280
281* log_arch(level, format_string, ...) - category LOGC_ARCH
282* log_board(level, format_string, ...) - category LOGC_BOARD
283* log_core(level, format_string, ...) - category LOGC_CORE
284* log_dt(level, format_string, ...) - category LOGC_DT
285
286More logging destinations:
287
288* device - goes to a device (e.g. serial)
289* buffer - recorded in a memory buffer
290
291Convert debug() statements in the code to log() statements
292
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200293Convert error() statements in the code to log() statements
294
295Figure out what to do with BUG(), BUG_ON() and warn_non_spl()
296
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200297Add a way to browse log records
298
299Add a way to record log records for browsing using an external tool
300
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200301Add commands to add and remove log devices
302
303Allow sharing of printf format strings in log records to reduce storage size
304for large numbers of log records
305
Heinrich Schuchardta7813912020-05-31 10:46:12 +0200306Consider making log() calls emit an automatic newline, perhaps with a logn()
307function to avoid that
308
309Passing log records through to linux (e.g. via device tree /chosen)
310
311Provide a command to access the number of log records generated, and the
312number dropped due to them being generated before the log system was ready.
313
314Add a printf() format string pragma so that log statements are checked properly
315
Sean Anderson8ba0f892020-10-27 19:55:41 -0400316Add a command to delete existing log records.