2 * SPDX-License-Identifier: MIT
4 * Copyright (c) 2016 wonder-mice
5 * Copyright (c) 2016-2023 Philippe Proulx <pproulx@efficios.com>
7 * This is very inspired by zf_log.c (see
8 * <https://github.com/wonder-mice/zf_log/>), but modified (mostly
9 * stripped down) for the use cases of Babeltrace.
22 #if defined(_WIN32) || defined(_WIN64)
27 # include <sys/prctl.h>
28 # include <sys/syscall.h>
43 #include "common/assert.h"
44 #include "common/common.h"
45 #include "common/macros.h"
46 #include "compat/time.h"
51 extern unsigned long pthread_getsequence_np(pthread_t
*);
55 * Thread-local logging message buffer to put the next message and write
56 * it with a single system call.
58 static __thread
char msg_buf
[4 * 4096];
61 * Returns the number of available bytes in `msg_buf` considering the
62 * writing position `at`.
65 size_t avail_msg_buf_bytes(char *at
)
67 return msg_buf
+ sizeof(msg_buf
) - at
;
71 * Appends the character `ch` to `msg_buf`.
74 void append_char_to_msg_buf(char ** const at
, const char ch
)
81 * Appends a space character to `msg_buf`.
84 void append_sp_to_msg_buf(char ** const at
)
86 append_char_to_msg_buf(at
, ' ');
90 * Appends the null-terminated string `str` to `msg_buf`.
93 void append_str_to_msg_buf(char ** const at
, const char * const str
)
95 const size_t len
= strlen(str
);
97 memcpy(*at
, str
, len
);
102 * Formats the unsigned integer `val` with sprintf() using `fmt` and
103 * appends the resulting string to `msg_buf`.
106 void append_uint_to_msg_buf(char ** const at
, const char * const fmt
,
107 const unsigned int val
)
109 #pragma GCC diagnostic push
110 #pragma GCC diagnostic ignored "-Wformat-nonliteral"
111 const int written_len
= sprintf(*at
, fmt
, val
);
112 #pragma GCC diagnostic pop
114 BT_ASSERT_DBG(written_len
> 0);
115 *at
+= (size_t) written_len
;
119 * Thread-local cache of seconds and milliseconds to formatted date/time
120 * string (null terminated).
122 * This is often useful because many log messages may happen during the
125 * Does not need any kind of protection since it's TLS.
127 struct date_time_cache
{
133 static __thread
struct date_time_cache date_time_cache
= {0};
136 const char *date_time_cache_get(const struct timeval tv
)
138 const uint64_t s
= (uint64_t) tv
.tv_sec
;
139 const uint32_t ms
= (uint32_t) (tv
.tv_usec
/ 1000);
141 if (date_time_cache
.s
!= s
|| date_time_cache
.ms
!= ms
) {
142 /* Add to cache now */
144 const time_t time_s
= (time_t) tv
.tv_sec
;
146 date_time_cache
.s
= (uint64_t) tv
.tv_sec
;
147 date_time_cache
.ms
= (uint32_t) (tv
.tv_usec
/ 1000);
148 (void) bt_localtime_r(&time_s
, &tm
);
149 (void) sprintf(date_time_cache
.str
, "%02u-%02u %02u:%02u:%02u.%03u",
150 tm
.tm_mon
+ 1, tm
.tm_mday
,
151 tm
.tm_hour
, tm
.tm_min
, tm
.tm_sec
, date_time_cache
.ms
);
154 return date_time_cache
.str
;
158 * Appends a formatted date/time for `tv` to `msg_buf`.
161 void append_date_time_to_msg_buf(char ** const at
, const struct timeval tv
)
163 const char *str
= date_time_cache_get(tv
);
165 append_str_to_msg_buf(at
, str
);
169 * Appends the PID and TID to `msg_buf`.
172 void append_pid_tid_to_msg_buf(char ** const at
)
174 const unsigned int pid
= (unsigned int) getpid();
177 /* Look at this beautiful portability */
178 #if defined(_WIN32) || defined(_WIN64)
179 tid
= (unsigned int) GetCurrentThreadId();
180 #elif defined(__CYGWIN__)
182 pthread_t thr
= pthread_self();
184 tid
= (unsigned int) pthread_getsequence_np(&thr
);
186 #elif defined(__sun__)
187 tid
= (unsigned int) pthread_self();
188 #elif defined(__linux__)
189 tid
= (unsigned int) syscall(SYS_gettid
);
190 #elif defined(__APPLE__) && defined(__MACH__)
191 tid
= (unsigned int) pthread_mach_thread_np(pthread_self());
192 #elif defined(__GNU__)
194 mach_port_t mach_port
= mach_thread_self();
196 mach_port_deallocate(mach_task_self(), mach_port
);
197 tid
= (unsigned int) mach_port
;
199 #elif defined(__FreeBSD__)
206 * The thread ID is an integer in the range from
207 * `PID_MAX + 2` (100001) to `INT_MAX`.
209 tid
= (unsigned int) ltid
;
212 # error "Platform not supported"
215 /* Append them now */
216 append_uint_to_msg_buf(at
, "%u", pid
);
217 append_sp_to_msg_buf(at
);
218 append_uint_to_msg_buf(at
, "%u", tid
);
222 * Writes the initial part of the log message to `msg_buf`, without the
223 * message and without resetting the terminal color).
226 void common_write_init(char ** const at
, const char * const file_name
,
227 const char * const func_name
, const unsigned int line_no
,
228 const enum bt_log_level lvl
, const char * const tag
)
230 const char *color_p
= "";
233 /* Get time immediately */
234 gettimeofday(&tv
, 0);
236 /* Write the terminal color code to use, if any */
239 color_p
= bt_common_color_fg_blue();
242 color_p
= bt_common_color_fg_yellow();
246 color_p
= bt_common_color_fg_red();
252 append_str_to_msg_buf(at
, color_p
);
254 /* Write date/time */
255 append_date_time_to_msg_buf(at
, tv
);
256 append_sp_to_msg_buf(at
);
259 append_pid_tid_to_msg_buf(at
);
260 append_sp_to_msg_buf(at
);
262 /* Write log level letter */
263 append_char_to_msg_buf(at
, bt_log_get_letter_from_level(lvl
));
264 append_sp_to_msg_buf(at
);
268 append_str_to_msg_buf(at
, tag
);
269 append_sp_to_msg_buf(at
);
272 /* Write source location */
273 append_str_to_msg_buf(at
, func_name
);
274 append_char_to_msg_buf(at
, '@');
275 append_str_to_msg_buf(at
, file_name
);
276 append_uint_to_msg_buf(at
, ":%u", line_no
);
277 append_sp_to_msg_buf(at
);
281 * Writes the final part of the log message to `msg_buf` (resets the
282 * terminal color and appends a newline), and then writes the whole log
283 * message to the standard error.
286 void common_write_fini(char ** const at
)
288 append_str_to_msg_buf(at
, bt_common_color_reset());
289 append_char_to_msg_buf(at
, '\n');
290 (void) write(STDERR_FILENO
, msg_buf
, *at
- msg_buf
);
293 void bt_log_write(const char * const file_name
, const char * const func_name
,
294 const unsigned int line_no
, const enum bt_log_level lvl
,
295 const char * const tag
, const char * const msg
)
299 common_write_init(&at
, file_name
, func_name
, line_no
, lvl
, tag
);
300 append_str_to_msg_buf(&at
, msg
);
301 common_write_fini(&at
);
304 _BT_LOG_PRINTFLIKE(6, 0)
306 void write_vprintf(const char * const file_name
, const char * const func_name
,
307 const unsigned int line_no
, const enum bt_log_level lvl
,
308 const char * const tag
, const char * const fmt
, va_list args
)
313 common_write_init(&at
, file_name
, func_name
, line_no
, lvl
, tag
);
314 written_len
= vsnprintf(at
, avail_msg_buf_bytes(at
) - 16,
316 if (written_len
> 0) {
317 at
+= (size_t) written_len
;
320 common_write_fini(&at
);
323 void bt_log_write_printf(const char * const file_name
,
324 const char * const func_name
, const unsigned int line_no
,
325 const enum bt_log_level lvl
, const char * const tag
,
326 const char * const fmt
, ...)
331 write_vprintf(file_name
, func_name
, line_no
, lvl
, tag
, fmt
, va
);
336 * Writes the initial part of the log message to `msg_buf`, including
337 * the initial message and `errno` string, without the message and
338 * without resetting the terminal color).
341 void common_write_errno_init(char ** const at
, const char * const file_name
,
342 const char * const func_name
, const unsigned int line_no
,
343 const enum bt_log_level lvl
, const char * const tag
,
344 const char * const init_msg
)
346 BT_ASSERT_DBG(errno
!= 0);
348 const char * const errno_msg
= g_strerror(errno
);
350 common_write_init(at
, file_name
, func_name
, line_no
, lvl
, tag
);
351 append_str_to_msg_buf(at
, init_msg
);
352 append_char_to_msg_buf(at
, ':');
353 append_sp_to_msg_buf(at
);
354 append_str_to_msg_buf(at
, errno_msg
);
357 void bt_log_write_errno(const char * const file_name
,
358 const char * const func_name
, const unsigned int line_no
,
359 const enum bt_log_level lvl
, const char * const tag
,
360 const char * const init_msg
, const char * const msg
)
364 common_write_errno_init(&at
, file_name
, func_name
, line_no
, lvl
,
366 append_str_to_msg_buf(&at
, msg
);
367 common_write_fini(&at
);
370 void bt_log_write_errno_printf(const char * const file_name
,
371 const char * const func_name
, const unsigned int line_no
,
372 const enum bt_log_level lvl
, const char * const tag
,
373 const char * const init_msg
, const char * const fmt
, ...)
379 common_write_errno_init(&at
, file_name
, func_name
, line_no
, lvl
,
382 written_len
= vsnprintf(at
, avail_msg_buf_bytes(at
) - 16, fmt
, va
);
384 if (written_len
> 0) {
385 at
+= (size_t) written_len
;
388 common_write_fini(&at
);
392 * Logs `mem_len` bytes of `mem_data` on a single line.
395 void write_mem_line(const char * const file_name
, const char * const func_name
,
396 const unsigned int line_no
, const enum bt_log_level lvl
,
397 const char * const tag
, const uint8_t * const mem_data
,
398 const size_t mem_len
, const size_t max_mem_line_len
)
400 static const char * const hex_chars
= "0123456789abcdef";
404 common_write_init(&at
, file_name
, func_name
, line_no
, lvl
, tag
);
406 /* Write hexadecimal representation */
407 for (i
= 0; i
< mem_len
; i
++) {
408 const uint8_t byte
= mem_data
[i
];
411 append_char_to_msg_buf(&at
, hex_chars
[byte
>> 4]);
412 append_char_to_msg_buf(&at
, hex_chars
[byte
& 0xf]);
415 append_sp_to_msg_buf(&at
);
418 /* Insert spaces to align the following ASCII representation */
419 for (i
= 0; i
< max_mem_line_len
- mem_len
; i
++) {
420 append_sp_to_msg_buf(&at
);
421 append_sp_to_msg_buf(&at
);
422 append_sp_to_msg_buf(&at
);
425 /* Insert a vertical line between the representations */
426 append_str_to_msg_buf(&at
, "| ");
428 /* Write the ASCII representation */
429 for (i
= 0; i
< mem_len
; i
++) {
430 const uint8_t byte
= mem_data
[i
];
433 append_char_to_msg_buf(&at
, (char) byte
);
435 /* Non-printable character */
436 append_char_to_msg_buf(&at
, '.');
440 common_write_fini(&at
);
444 * Logs `mem_len` bytes of `mem_data` on one or more lines.
447 void write_mem_lines(const char * const file_name
, const char * const func_name
,
448 const unsigned int line_no
, const enum bt_log_level lvl
,
449 const char * const tag
, const uint8_t * const mem_data
,
450 const size_t mem_len
)
452 const uint8_t *mem_at
= mem_data
;
453 size_t rem_mem_len
= mem_len
;
455 if (!mem_data
|| mem_len
== 0) {
456 /* Nothing to write */
460 while (rem_mem_len
> 0) {
461 static const size_t max_mem_line_len
= 16;
463 /* Number of bytes to write on this line */
464 const size_t mem_line_len
= rem_mem_len
> max_mem_line_len
?
465 max_mem_line_len
: rem_mem_len
;
467 /* Log those bytes */
468 write_mem_line(file_name
, func_name
, line_no
, lvl
, tag
,
469 mem_at
, mem_line_len
, max_mem_line_len
);
471 /* Adjust for next iteration */
472 rem_mem_len
-= mem_line_len
;
473 mem_at
+= mem_line_len
;
480 void bt_log_write_mem(const char * const file_name
, const char * const func_name
,
481 const unsigned int line_no
, const enum bt_log_level lvl
,
482 const char * const tag
, const void * const mem_data
,
483 const size_t mem_len
, const char * const msg
)
485 bt_log_write(file_name
, func_name
, line_no
, lvl
, tag
, msg
);
486 write_mem_lines(file_name
, func_name
, line_no
, lvl
, tag
,
490 void bt_log_write_mem_printf(const char * const file_name
,
491 const char * const func_name
, const unsigned int line_no
,
492 const enum bt_log_level lvl
, const char * const tag
,
493 const void * const mem_data
, const size_t mem_len
,
494 const char * const fmt
, ...)
499 write_vprintf(file_name
, func_name
, line_no
, lvl
, tag
, fmt
, va
);
502 write_mem_lines(file_name
, func_name
, line_no
, lvl
, tag
,