xref: /spdk/lib/log/log.c (revision 30e3f4d9006346a1ea182c80fad4a3a847fd3b0b)
1 /*-
2  *   BSD LICENSE
3  *
4  *   Copyright (c) Intel Corporation.
5  *   All rights reserved.
6  *
7  *   Redistribution and use in source and binary forms, with or without
8  *   modification, are permitted provided that the following conditions
9  *   are met:
10  *
11  *     * Redistributions of source code must retain the above copyright
12  *       notice, this list of conditions and the following disclaimer.
13  *     * Redistributions in binary form must reproduce the above copyright
14  *       notice, this list of conditions and the following disclaimer in
15  *       the documentation and/or other materials provided with the
16  *       distribution.
17  *     * Neither the name of Intel Corporation nor the names of its
18  *       contributors may be used to endorse or promote products derived
19  *       from this software without specific prior written permission.
20  *
21  *   THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
22  *   "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
23  *   LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
24  *   A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
25  *   OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
26  *   SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
27  *   LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
28  *   DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
29  *   THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
30  *   (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
31  *   OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
32  */
33 
34 #include "spdk/stdinc.h"
35 
36 #include "spdk_internal/log.h"
37 
38 #ifdef SPDK_LOG_BACKTRACE_LVL
39 #define UNW_LOCAL_ONLY
40 #include <libunwind.h>
41 #endif
42 
43 static const char *const spdk_level_names[] = {
44 	[SPDK_LOG_ERROR]	= "ERROR",
45 	[SPDK_LOG_WARN]		= "WARNING",
46 	[SPDK_LOG_NOTICE]	= "NOTICE",
47 	[SPDK_LOG_INFO]		= "INFO",
48 	[SPDK_LOG_DEBUG]	= "DEBUG",
49 };
50 
51 #define MAX_TMPBUF 1024
52 
53 static logfunc *g_log = NULL;
54 
55 void
56 spdk_log_open(logfunc *logf)
57 {
58 	if (logf) {
59 		g_log = logf;
60 	} else {
61 		openlog("spdk", LOG_PID, LOG_LOCAL7);
62 	}
63 }
64 
65 void
66 spdk_log_close(void)
67 {
68 	if (!g_log) {
69 		closelog();
70 	}
71 }
72 
73 #ifdef SPDK_LOG_BACKTRACE_LVL
74 static void
75 spdk_log_unwind_stack(FILE *fp, enum spdk_log_level level)
76 {
77 	unw_error_t err;
78 	unw_cursor_t cursor;
79 	unw_context_t uc;
80 	unw_word_t ip;
81 	unw_word_t offp;
82 	char f_name[64];
83 	int frame;
84 
85 	if (level > g_spdk_log_backtrace_level) {
86 		return;
87 	}
88 
89 	unw_getcontext(&uc);
90 	unw_init_local(&cursor, &uc);
91 	fprintf(fp, "*%s*: === BACKTRACE START ===\n", spdk_level_names[level]);
92 
93 	unw_step(&cursor);
94 	for (frame = 1; unw_step(&cursor) > 0; frame++) {
95 		unw_get_reg(&cursor, UNW_REG_IP, &ip);
96 		err = unw_get_proc_name(&cursor, f_name, sizeof(f_name), &offp);
97 		if (err || strcmp(f_name, "main") == 0) {
98 			break;
99 		}
100 
101 		fprintf(fp, "*%s*: %3d: %*s%s() at %#lx\n", spdk_level_names[level], frame, frame - 1, "", f_name,
102 			(unsigned long)ip);
103 	}
104 	fprintf(fp, "*%s*: === BACKTRACE END ===\n", spdk_level_names[level]);
105 }
106 
107 #else
108 #define spdk_log_unwind_stack(fp, lvl)
109 #endif
110 
111 static void
112 get_timestamp_prefix(char *buf, int buf_size)
113 {
114 	struct tm *info;
115 	char date[24];
116 	struct timespec ts;
117 	long usec;
118 
119 	clock_gettime(CLOCK_REALTIME, &ts);
120 	info = localtime(&ts.tv_sec);
121 	usec = ts.tv_nsec / 1000;
122 
123 	strftime(date, sizeof(date), "%Y-%m-%d %H:%M:%S", info);
124 	snprintf(buf, buf_size, "[%s.%06ld] ", date, usec);
125 }
126 
127 void
128 spdk_log(enum spdk_log_level level, const char *file, const int line, const char *func,
129 	 const char *format, ...)
130 {
131 	va_list ap;
132 
133 	va_start(ap, format);
134 	spdk_vlog(level, file, line, func, format, ap);
135 	va_end(ap);
136 }
137 
138 void
139 spdk_vlog(enum spdk_log_level level, const char *file, const int line, const char *func,
140 	  const char *format, va_list ap)
141 {
142 	int severity = LOG_INFO;
143 	char buf[MAX_TMPBUF];
144 	char timestamp[32];
145 
146 	if (g_log) {
147 		g_log(level, file, line, func, format, ap);
148 		return;
149 	}
150 
151 	if (level > g_spdk_log_print_level && level > g_spdk_log_level) {
152 		return;
153 	}
154 
155 	switch (level) {
156 	case SPDK_LOG_ERROR:
157 		severity = LOG_ERR;
158 		break;
159 	case SPDK_LOG_WARN:
160 		severity = LOG_WARNING;
161 		break;
162 	case SPDK_LOG_NOTICE:
163 		severity = LOG_NOTICE;
164 		break;
165 	case SPDK_LOG_INFO:
166 	case SPDK_LOG_DEBUG:
167 		severity = LOG_INFO;
168 		break;
169 	case SPDK_LOG_DISABLED:
170 		return;
171 	}
172 
173 	vsnprintf(buf, sizeof(buf), format, ap);
174 
175 	if (level <= g_spdk_log_print_level) {
176 		get_timestamp_prefix(timestamp, sizeof(timestamp));
177 		if (file) {
178 			fprintf(stderr, "%s%s:%4d:%s: *%s*: %s", timestamp, file, line, func, spdk_level_names[level], buf);
179 			spdk_log_unwind_stack(stderr, level);
180 		} else {
181 			fprintf(stderr, "%s%s", timestamp, buf);
182 		}
183 	}
184 
185 	if (level <= g_spdk_log_level) {
186 		if (file) {
187 			syslog(severity, "%s:%4d:%s: *%s*: %s", file, line, func, spdk_level_names[level], buf);
188 		} else {
189 			syslog(severity, "%s", buf);
190 		}
191 	}
192 }
193 
194 static void
195 fdump(FILE *fp, const char *label, const uint8_t *buf, size_t len)
196 {
197 	char tmpbuf[MAX_TMPBUF];
198 	char buf16[16 + 1];
199 	size_t total;
200 	unsigned int idx;
201 
202 	fprintf(fp, "%s\n", label);
203 
204 	memset(buf16, 0, sizeof buf16);
205 	total = 0;
206 	for (idx = 0; idx < len; idx++) {
207 		if (idx != 0 && idx % 16 == 0) {
208 			snprintf(tmpbuf + total, sizeof tmpbuf - total,
209 				 " %s", buf16);
210 			memset(buf16, 0, sizeof buf16);
211 			fprintf(fp, "%s\n", tmpbuf);
212 			total = 0;
213 		}
214 		if (idx % 16 == 0) {
215 			total += snprintf(tmpbuf + total, sizeof tmpbuf - total,
216 					  "%08x ", idx);
217 		}
218 		if (idx % 8 == 0) {
219 			total += snprintf(tmpbuf + total, sizeof tmpbuf - total,
220 					  "%s", " ");
221 		}
222 		total += snprintf(tmpbuf + total, sizeof tmpbuf - total,
223 				  "%2.2x ", buf[idx] & 0xff);
224 		buf16[idx % 16] = isprint(buf[idx]) ? buf[idx] : '.';
225 	}
226 	for (; idx % 16 != 0; idx++) {
227 		if (idx == 8) {
228 			total += snprintf(tmpbuf + total, sizeof tmpbuf - total,
229 					  " ");
230 		}
231 
232 		total += snprintf(tmpbuf + total, sizeof tmpbuf - total, "   ");
233 	}
234 	snprintf(tmpbuf + total, sizeof tmpbuf - total, "  %s", buf16);
235 	fprintf(fp, "%s\n", tmpbuf);
236 	fflush(fp);
237 }
238 
239 void
240 spdk_log_dump(FILE *fp, const char *label, const void *buf, size_t len)
241 {
242 	fdump(fp, label, buf, len);
243 }
244