logger.c 5.8 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239
  1. // SPDX-License-Identifier: GPL-2.0-only
  2. /*
  3. * Copyright 2023 Red Hat
  4. */
  5. #include "logger.h"
  6. #include <asm/current.h>
  7. #include <linux/delay.h>
  8. #include <linux/hardirq.h>
  9. #include <linux/module.h>
  10. #include <linux/printk.h>
  11. #include <linux/sched.h>
  12. #include "errors.h"
  13. #include "thread-device.h"
  14. #include "thread-utils.h"
  15. int vdo_log_level = VDO_LOG_DEFAULT;
  16. int vdo_get_log_level(void)
  17. {
  18. int log_level_latch = READ_ONCE(vdo_log_level);
  19. if (unlikely(log_level_latch > VDO_LOG_MAX)) {
  20. log_level_latch = VDO_LOG_DEFAULT;
  21. WRITE_ONCE(vdo_log_level, log_level_latch);
  22. }
  23. return log_level_latch;
  24. }
  25. static const char *get_current_interrupt_type(void)
  26. {
  27. if (in_nmi())
  28. return "NMI";
  29. if (in_hardirq())
  30. return "HI";
  31. if (in_softirq())
  32. return "SI";
  33. return "INTR";
  34. }
  35. /**
  36. * emit_log_message_to_kernel() - Emit a log message to the kernel at the specified priority.
  37. *
  38. * @priority: The priority at which to log the message
  39. * @fmt: The format string of the message
  40. */
  41. static void emit_log_message_to_kernel(int priority, const char *fmt, ...)
  42. {
  43. va_list args;
  44. struct va_format vaf;
  45. if (priority > vdo_get_log_level())
  46. return;
  47. va_start(args, fmt);
  48. vaf.fmt = fmt;
  49. vaf.va = &args;
  50. switch (priority) {
  51. case VDO_LOG_EMERG:
  52. case VDO_LOG_ALERT:
  53. case VDO_LOG_CRIT:
  54. pr_crit("%pV", &vaf);
  55. break;
  56. case VDO_LOG_ERR:
  57. pr_err("%pV", &vaf);
  58. break;
  59. case VDO_LOG_WARNING:
  60. pr_warn("%pV", &vaf);
  61. break;
  62. case VDO_LOG_NOTICE:
  63. case VDO_LOG_INFO:
  64. pr_info("%pV", &vaf);
  65. break;
  66. case VDO_LOG_DEBUG:
  67. pr_debug("%pV", &vaf);
  68. break;
  69. default:
  70. printk(KERN_DEFAULT "%pV", &vaf);
  71. break;
  72. }
  73. va_end(args);
  74. }
  75. /**
  76. * emit_log_message() - Emit a log message to the kernel log in a format suited to the current
  77. * thread context.
  78. *
  79. * Context info formats:
  80. *
  81. * interrupt: uds[NMI]: blah
  82. * kvdo thread: kvdo12:foobarQ: blah
  83. * thread w/device id: kvdo12:myprog: blah
  84. * other thread: uds: myprog: blah
  85. *
  86. * Fields: module name, interrupt level, process name, device ID.
  87. *
  88. * @priority: the priority at which to log the message
  89. * @module: The name of the module doing the logging
  90. * @prefix: The prefix of the log message
  91. * @vaf1: The first message format descriptor
  92. * @vaf2: The second message format descriptor
  93. */
  94. static void emit_log_message(int priority, const char *module, const char *prefix,
  95. const struct va_format *vaf1, const struct va_format *vaf2)
  96. {
  97. int device_instance;
  98. /*
  99. * In interrupt context, identify the interrupt type and module. Ignore the process/thread
  100. * since it could be anything.
  101. */
  102. if (in_interrupt()) {
  103. const char *type = get_current_interrupt_type();
  104. emit_log_message_to_kernel(priority, "%s[%s]: %s%pV%pV\n", module, type,
  105. prefix, vaf1, vaf2);
  106. return;
  107. }
  108. /* Not at interrupt level; we have a process we can look at, and might have a device ID. */
  109. device_instance = vdo_get_thread_device_id();
  110. if (device_instance >= 0) {
  111. emit_log_message_to_kernel(priority, "%s%u:%s: %s%pV%pV\n", module,
  112. device_instance, current->comm, prefix, vaf1,
  113. vaf2);
  114. return;
  115. }
  116. /*
  117. * If it's a kernel thread and the module name is a prefix of its name, assume it is ours
  118. * and only identify the thread.
  119. */
  120. if (((current->flags & PF_KTHREAD) != 0) &&
  121. (strncmp(module, current->comm, strlen(module)) == 0)) {
  122. emit_log_message_to_kernel(priority, "%s: %s%pV%pV\n", current->comm,
  123. prefix, vaf1, vaf2);
  124. return;
  125. }
  126. /* Identify the module and the process. */
  127. emit_log_message_to_kernel(priority, "%s: %s: %s%pV%pV\n", module, current->comm,
  128. prefix, vaf1, vaf2);
  129. }
  130. /*
  131. * vdo_log_embedded_message() - Log a message embedded within another message.
  132. * @priority: the priority at which to log the message
  133. * @module: the name of the module doing the logging
  134. * @prefix: optional string prefix to message, may be NULL
  135. * @fmt1: format of message first part (required)
  136. * @args1: arguments for message first part (required)
  137. * @fmt2: format of message second part
  138. */
  139. void vdo_log_embedded_message(int priority, const char *module, const char *prefix,
  140. const char *fmt1, va_list args1, const char *fmt2, ...)
  141. {
  142. va_list args1_copy;
  143. va_list args2;
  144. struct va_format vaf1, vaf2;
  145. va_start(args2, fmt2);
  146. if (module == NULL)
  147. module = VDO_LOGGING_MODULE_NAME;
  148. if (prefix == NULL)
  149. prefix = "";
  150. /*
  151. * It is implementation dependent whether va_list is defined as an array type that decays
  152. * to a pointer when passed as an argument. Copy args1 and args2 with va_copy so that vaf1
  153. * and vaf2 get proper va_list pointers irrespective of how va_list is defined.
  154. */
  155. va_copy(args1_copy, args1);
  156. vaf1.fmt = fmt1;
  157. vaf1.va = &args1_copy;
  158. vaf2.fmt = fmt2;
  159. vaf2.va = &args2;
  160. emit_log_message(priority, module, prefix, &vaf1, &vaf2);
  161. va_end(args1_copy);
  162. va_end(args2);
  163. }
  164. int vdo_vlog_strerror(int priority, int errnum, const char *module, const char *format,
  165. va_list args)
  166. {
  167. char errbuf[VDO_MAX_ERROR_MESSAGE_SIZE];
  168. const char *message = uds_string_error(errnum, errbuf, sizeof(errbuf));
  169. vdo_log_embedded_message(priority, module, NULL, format, args, ": %s (%d)",
  170. message, errnum);
  171. return errnum;
  172. }
  173. int __vdo_log_strerror(int priority, int errnum, const char *module, const char *format, ...)
  174. {
  175. va_list args;
  176. va_start(args, format);
  177. vdo_vlog_strerror(priority, errnum, module, format, args);
  178. va_end(args);
  179. return errnum;
  180. }
  181. void vdo_log_backtrace(int priority)
  182. {
  183. if (priority > vdo_get_log_level())
  184. return;
  185. dump_stack();
  186. }
  187. void __vdo_log_message(int priority, const char *module, const char *format, ...)
  188. {
  189. va_list args;
  190. va_start(args, format);
  191. vdo_log_embedded_message(priority, module, NULL, format, args, "%s", "");
  192. va_end(args);
  193. }
  194. /*
  195. * Sleep or delay a few milliseconds in an attempt to allow the log buffers to be flushed lest they
  196. * be overrun.
  197. */
  198. void vdo_pause_for_logger(void)
  199. {
  200. fsleep(4000);
  201. }