xref: /spdk/lib/log/log.c (revision 0ce363bebe8ca422f8a9e2bd103dc1eaee71fb2e)
1 /*   SPDX-License-Identifier: BSD-3-Clause
2  *   Copyright (C) 2016 Intel Corporation.
3  *   All rights reserved.
4  */
5 
6 #include "spdk/stdinc.h"
7 #include "spdk/util.h"
8 
9 #include "spdk/log.h"
10 
11 static const char *const spdk_level_names[] = {
12 	[SPDK_LOG_ERROR]	= "ERROR",
13 	[SPDK_LOG_WARN]		= "WARNING",
14 	[SPDK_LOG_NOTICE]	= "NOTICE",
15 	[SPDK_LOG_INFO]		= "INFO",
16 	[SPDK_LOG_DEBUG]	= "DEBUG",
17 };
18 
19 #define MAX_TMPBUF 1024
20 
21 static struct spdk_log_opts g_log_opts = {
22 	.log = NULL,
23 	.open = NULL,
24 	.close = NULL,
25 	.user_ctx = NULL,
26 };
27 static bool g_log_timestamps = true;
28 
29 enum spdk_log_level g_spdk_log_level;
30 enum spdk_log_level g_spdk_log_print_level;
31 
32 void
33 spdk_log_set_level(enum spdk_log_level level)
34 {
35 	assert(level >= SPDK_LOG_DISABLED);
36 	assert(level <= SPDK_LOG_DEBUG);
37 	g_spdk_log_level = level;
38 }
39 
40 enum spdk_log_level
41 spdk_log_get_level(void) {
42 	return g_spdk_log_level;
43 }
44 
45 void
46 spdk_log_set_print_level(enum spdk_log_level level)
47 {
48 	assert(level >= SPDK_LOG_DISABLED);
49 	assert(level <= SPDK_LOG_DEBUG);
50 	g_spdk_log_print_level = level;
51 }
52 
53 enum spdk_log_level
54 spdk_log_get_print_level(void) {
55 	return g_spdk_log_print_level;
56 }
57 
58 static void
59 log_open(void *ctx)
60 {
61 	openlog("spdk", LOG_PID, LOG_LOCAL7);
62 }
63 
64 static void
65 log_close(void *ctx)
66 {
67 	closelog();
68 }
69 
70 void
71 spdk_log_open(spdk_log_cb *log)
72 {
73 	if (log) {
74 		struct spdk_log_opts opts = {.log = log};
75 		opts.size = SPDK_SIZEOF(&opts, log);
76 		spdk_log_open_ext(&opts);
77 	} else {
78 		spdk_log_open_ext(NULL);
79 	}
80 }
81 
82 void
83 spdk_log_open_ext(struct spdk_log_opts *opts)
84 {
85 	if (!opts) {
86 		g_log_opts.open = log_open;
87 		g_log_opts.close = log_close;
88 		goto out;
89 	}
90 
91 	g_log_opts.log = SPDK_GET_FIELD(opts, log, NULL);
92 	g_log_opts.open = SPDK_GET_FIELD(opts, open, NULL);
93 	g_log_opts.close = SPDK_GET_FIELD(opts, close, NULL);
94 	g_log_opts.user_ctx = SPDK_GET_FIELD(opts, user_ctx, NULL);
95 
96 out:
97 	if (g_log_opts.open) {
98 		g_log_opts.open(g_log_opts.user_ctx);
99 	}
100 }
101 
102 void
103 spdk_log_close(void)
104 {
105 	if (g_log_opts.close) {
106 		g_log_opts.close(g_log_opts.user_ctx);
107 	}
108 	memset(&g_log_opts, 0, sizeof(g_log_opts));
109 }
110 
111 void
112 spdk_log_enable_timestamps(bool value)
113 {
114 	g_log_timestamps = value;
115 }
116 
117 static void
118 get_timestamp_prefix(char *buf, int buf_size)
119 {
120 	struct tm *info;
121 	char date[24];
122 	struct timespec ts;
123 	long usec;
124 
125 	if (!g_log_timestamps) {
126 		buf[0] = '\0';
127 		return;
128 	}
129 
130 	clock_gettime(CLOCK_REALTIME, &ts);
131 	info = localtime(&ts.tv_sec);
132 	usec = ts.tv_nsec / 1000;
133 	if (info == NULL) {
134 		snprintf(buf, buf_size, "[%s.%06ld] ", "unknown date", usec);
135 		return;
136 	}
137 
138 	strftime(date, sizeof(date), "%Y-%m-%d %H:%M:%S", info);
139 	snprintf(buf, buf_size, "[%s.%06ld] ", date, usec);
140 }
141 
142 void
143 spdk_log(enum spdk_log_level level, const char *file, const int line, const char *func,
144 	 const char *format, ...)
145 {
146 	va_list ap;
147 
148 	va_start(ap, format);
149 	spdk_vlog(level, file, line, func, format, ap);
150 	va_end(ap);
151 }
152 
153 int
154 spdk_log_to_syslog_level(enum spdk_log_level level)
155 {
156 	switch (level) {
157 	case SPDK_LOG_DEBUG:
158 	case SPDK_LOG_INFO:
159 		return LOG_INFO;
160 	case SPDK_LOG_NOTICE:
161 		return LOG_NOTICE;
162 	case SPDK_LOG_WARN:
163 		return LOG_WARNING;
164 	case SPDK_LOG_ERROR:
165 		return LOG_ERR;
166 	case SPDK_LOG_DISABLED:
167 		return -1;
168 	default:
169 		break;
170 	}
171 
172 	return LOG_INFO;
173 }
174 
175 void
176 spdk_vlog(enum spdk_log_level level, const char *file, const int line, const char *func,
177 	  const char *format, va_list ap)
178 {
179 	int severity = LOG_INFO;
180 	char *buf, _buf[MAX_TMPBUF], *ext_buf = NULL;
181 	char timestamp[64];
182 	va_list ap_copy;
183 	int rc;
184 
185 	if (g_log_opts.log) {
186 		g_log_opts.log(level, file, line, func, format, ap);
187 		return;
188 	}
189 
190 	if (level > g_spdk_log_print_level && level > g_spdk_log_level) {
191 		return;
192 	}
193 
194 	severity = spdk_log_to_syslog_level(level);
195 	if (severity < 0) {
196 		return;
197 	}
198 
199 	buf = _buf;
200 
201 	va_copy(ap_copy, ap);
202 	rc = vsnprintf(_buf, sizeof(_buf), format, ap);
203 	if (rc > MAX_TMPBUF) {
204 		/* The output including the terminating was more than MAX_TMPBUF bytes.
205 		 * Try allocating memory large enough to hold the output.
206 		 */
207 		rc = vasprintf(&ext_buf, format, ap_copy);
208 		if (rc < 0) {
209 			/* Failed to allocate memory. Allow output to be truncated. */
210 		} else {
211 			buf = ext_buf;
212 		}
213 	}
214 	va_end(ap_copy);
215 
216 	if (level <= g_spdk_log_print_level) {
217 		get_timestamp_prefix(timestamp, sizeof(timestamp));
218 		if (file) {
219 			fprintf(stderr, "%s%s:%4d:%s: *%s*: %s", timestamp, file, line, func, spdk_level_names[level], buf);
220 		} else {
221 			fprintf(stderr, "%s%s", timestamp, buf);
222 		}
223 	}
224 
225 	if (level <= g_spdk_log_level) {
226 		if (file) {
227 			syslog(severity, "%s:%4d:%s: *%s*: %s", file, line, func, spdk_level_names[level], buf);
228 		} else {
229 			syslog(severity, "%s", buf);
230 		}
231 	}
232 
233 	free(ext_buf);
234 }
235 
236 void
237 spdk_vflog(FILE *fp, const char *file, const int line, const char *func,
238 	   const char *format, va_list ap)
239 {
240 	char buf[MAX_TMPBUF];
241 	char timestamp[64];
242 
243 	vsnprintf(buf, sizeof(buf), format, ap);
244 
245 	get_timestamp_prefix(timestamp, sizeof(timestamp));
246 
247 	if (file) {
248 		fprintf(fp, "%s%s:%4d:%s: %s", timestamp, file, line, func, buf);
249 	} else {
250 		fprintf(fp, "%s%s", timestamp, buf);
251 	}
252 
253 	fflush(fp);
254 }
255 
256 void
257 spdk_flog(FILE *fp, const char *file, const int line, const char *func,
258 	  const char *format, ...)
259 {
260 	va_list ap;
261 
262 	va_start(ap, format);
263 	spdk_vflog(fp, file, line, func, format, ap);
264 	va_end(ap);
265 }
266 
267 static void
268 fdump(FILE *fp, const char *label, const uint8_t *buf, size_t len)
269 {
270 	char tmpbuf[MAX_TMPBUF];
271 	char buf16[16 + 1];
272 	size_t total;
273 	unsigned int idx;
274 
275 	fprintf(fp, "%s\n", label);
276 
277 	memset(buf16, 0, sizeof buf16);
278 	total = 0;
279 	for (idx = 0; idx < len; idx++) {
280 		if (idx != 0 && idx % 16 == 0) {
281 			snprintf(tmpbuf + total, sizeof tmpbuf - total,
282 				 " %s", buf16);
283 			memset(buf16, 0, sizeof buf16);
284 			fprintf(fp, "%s\n", tmpbuf);
285 			total = 0;
286 		}
287 		if (idx % 16 == 0) {
288 			total += snprintf(tmpbuf + total, sizeof tmpbuf - total,
289 					  "%08x ", idx);
290 		}
291 		if (idx % 8 == 0) {
292 			total += snprintf(tmpbuf + total, sizeof tmpbuf - total,
293 					  "%s", " ");
294 		}
295 		total += snprintf(tmpbuf + total, sizeof tmpbuf - total,
296 				  "%2.2x ", buf[idx] & 0xff);
297 		buf16[idx % 16] = isprint(buf[idx]) ? buf[idx] : '.';
298 	}
299 	for (; idx % 16 != 0; idx++) {
300 		if (idx == 8) {
301 			total += snprintf(tmpbuf + total, sizeof tmpbuf - total,
302 					  " ");
303 		}
304 
305 		total += snprintf(tmpbuf + total, sizeof tmpbuf - total, "   ");
306 	}
307 	snprintf(tmpbuf + total, sizeof tmpbuf - total, "  %s", buf16);
308 	fprintf(fp, "%s\n", tmpbuf);
309 	fflush(fp);
310 }
311 
312 void
313 spdk_log_dump(FILE *fp, const char *label, const void *buf, size_t len)
314 {
315 	fdump(fp, label, buf, len);
316 }
317