logging.rst 10 KB

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