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