blob: dc19cf3046103f0b74168829e841735aca4a3a9c [file] [log] [blame]
Neels Hofmeyr17518fe2017-06-20 04:35:06 +02001/*! \file logging.c
2 * Debugging/Logging support code. */
3/*
4 * (C) 2008-2010 by Harald Welte <laforge@gnumonks.org>
Harald Welte4a2bb9e2010-03-26 09:33:40 +08005 * (C) 2008 by Holger Hans Peter Freyther <zecke@selfish.org>
6 * All Rights Reserved
7 *
Harald Weltee08da972017-11-13 01:00:26 +09008 * SPDX-License-Identifier: GPL-2.0+
9 *
Harald Welte4a2bb9e2010-03-26 09:33:40 +080010 * This program is free software; you can redistribute it and/or modify
11 * it under the terms of the GNU General Public License as published by
12 * the Free Software Foundation; either version 2 of the License, or
13 * (at your option) any later version.
14 *
15 * This program is distributed in the hope that it will be useful,
16 * but WITHOUT ANY WARRANTY; without even the implied warranty of
17 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
18 * GNU General Public License for more details.
19 *
Harald Welte4a2bb9e2010-03-26 09:33:40 +080020 */
21
Harald Weltef01b2382017-10-16 13:55:34 +020022/*! \addtogroup logging
Harald Welte18fc4652011-08-17 14:14:17 +020023 * @{
Neels Hofmeyr87e45502017-06-20 00:17:59 +020024 * libosmocore Logging sub-system
Neels Hofmeyr17518fe2017-06-20 04:35:06 +020025 *
26 * \file logging.c */
Harald Welte18fc4652011-08-17 14:14:17 +020027
Pau Espin Pedrol88955fb2023-01-18 18:54:00 +010028#include "config.h"
Harald Welte01fd5cb2010-03-26 23:51:31 +080029
Harald Welte4a2bb9e2010-03-26 09:33:40 +080030#include <stdarg.h>
31#include <stdlib.h>
32#include <stdio.h>
33#include <string.h>
Harald Welteb72867f2020-09-26 21:45:16 +020034#include <unistd.h>
Harald Welte01fd5cb2010-03-26 23:51:31 +080035
36#ifdef HAVE_STRINGS_H
Harald Welte4a2bb9e2010-03-26 09:33:40 +080037#include <strings.h>
Harald Welte01fd5cb2010-03-26 23:51:31 +080038#endif
Vadim Yanitskiy04f42712020-09-09 04:47:25 +070039
40#ifdef HAVE_SYSLOG_H
41#include <syslog.h>
42#endif
43
Harald Welte433005c2020-09-26 11:51:32 +020044#ifdef HAVE_SYSTEMTAP
45/* include the generated probes header and put markers in code */
46#include "probes.h"
47#define TRACE(probe) probe
48#define TRACE_ENABLED(probe) probe ## _ENABLED()
49#else
50/* Wrap the probe to allow it to be removed when no systemtap available */
51#define TRACE(probe)
52#define TRACE_ENABLED(probe) (0)
53#endif /* HAVE_SYSTEMTAP */
54
Harald Welte4a2bb9e2010-03-26 09:33:40 +080055#include <time.h>
Jacob Erlbeckb61b2ca2015-03-17 10:21:15 +010056#include <sys/time.h>
Harald Welteb72867f2020-09-26 21:45:16 +020057#include <sys/types.h>
58#include <sys/stat.h>
59#include <fcntl.h>
Harald Welte4a2bb9e2010-03-26 09:33:40 +080060#include <errno.h>
Pau Espin Pedrold12f6982019-09-17 18:38:58 +020061#include <pthread.h>
Harald Welte4a2bb9e2010-03-26 09:33:40 +080062
Pablo Neira Ayuso83419342011-03-22 16:36:13 +010063#include <osmocom/core/talloc.h>
64#include <osmocom/core/utils.h>
65#include <osmocom/core/logging.h>
Neels Hofmeyr8e2f7e82016-09-22 03:58:13 +020066#include <osmocom/core/timer.h>
Pau Espin Pedrol662d10d2021-02-18 18:19:23 +010067#include <osmocom/core/thread.h>
Harald Welteb72867f2020-09-26 21:45:16 +020068#include <osmocom/core/select.h>
69#include <osmocom/core/write_queue.h>
Vadim Yanitskiy2f4186a2021-12-29 21:58:19 +060070#include <osmocom/core/gsmtap_util.h>
Harald Welte4a2bb9e2010-03-26 09:33:40 +080071
Pablo Neira Ayuso04139f12011-03-09 13:05:08 +010072#include <osmocom/vty/logging.h> /* for LOGGING_STR. */
73
Harald Weltea8b1b212020-09-27 17:21:07 +020074/* maximum length of the log string of a single log event (typically line) */
75#define MAX_LOG_SIZE 4096
76
Harald Welteb72867f2020-09-26 21:45:16 +020077/* maximum number of log statements we queue in file/stderr target write queue */
Harald Weltea0b57d02020-09-27 17:15:10 +020078#define LOG_WQUEUE_LEN 156
Harald Welteb72867f2020-09-26 21:45:16 +020079
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +010080osmo_static_assert(_LOG_CTX_COUNT <= ARRAY_SIZE(((struct log_context*)NULL)->ctx),
Neels Hofmeyr812ba6d2017-02-17 16:35:27 +010081 enum_logging_ctx_items_fit_in_struct_log_context);
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +010082osmo_static_assert(_LOG_FLT_COUNT <= ARRAY_SIZE(((struct log_target*)NULL)->filter_data),
Neels Hofmeyr812ba6d2017-02-17 16:35:27 +010083 enum_logging_filters_fit_in_log_target_filter_data);
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +010084osmo_static_assert(_LOG_FLT_COUNT <= 8*sizeof(((struct log_target*)NULL)->filter_map),
Neels Hofmeyr812ba6d2017-02-17 16:35:27 +010085 enum_logging_filters_fit_in_log_target_filter_map);
86
Harald Welteb43bc042011-06-27 10:29:17 +020087struct log_info *osmo_log_info;
Harald Welte4a2bb9e2010-03-26 09:33:40 +080088
Harald Welte3ae27582010-03-26 21:24:24 +080089static struct log_context log_context;
Neels Hofmeyrba0762d2018-09-10 13:56:03 +020090void *tall_log_ctx = NULL;
Harald Welte28222962011-02-18 20:37:04 +010091LLIST_HEAD(osmo_log_target_list);
Harald Welte4a2bb9e2010-03-26 09:33:40 +080092
Pau Espin Pedrol662d10d2021-02-18 18:19:23 +010093static __thread long int logging_tid;
94
Pau Espin Pedrold12f6982019-09-17 18:38:58 +020095#if (!EMBEDDED)
96/*! This mutex must be held while using osmo_log_target_list or any of its
97 log_targets in a multithread program. Prevents race conditions between threads
98 like producing unordered timestamps or VTY deleting a target while another
99 thread is writing to it */
100static pthread_mutex_t osmo_log_tgt_mutex;
101static bool osmo_log_tgt_mutex_on = false;
102
103/*! Enable multithread support (mutex) in libosmocore logging system.
104 * Must be called by processes willing to use logging subsystem from several
105 * threads. Once enabled, it's not possible to disable it again.
106 */
107void log_enable_multithread(void) {
108 if (osmo_log_tgt_mutex_on)
109 return;
110 pthread_mutex_init(&osmo_log_tgt_mutex, NULL);
111 osmo_log_tgt_mutex_on = true;
112}
113
114/*! Acquire the osmo_log_tgt_mutex. Don't use this function directly, always use
115 * macro log_tgt_mutex_lock() instead.
116 */
117void log_tgt_mutex_lock_impl(void) {
118 /* These lines are useful to debug scenarios where there's only 1 thread
119 and a double lock appears, for instance during startup and some
120 unlock() missing somewhere:
121 if (osmo_log_tgt_mutex_on && pthread_mutex_trylock(&osmo_log_tgt_mutex) != 0)
122 osmo_panic("acquiring already locked mutex!\n");
123 return;
124 */
125
126 if (osmo_log_tgt_mutex_on)
127 pthread_mutex_lock(&osmo_log_tgt_mutex);
128}
129
130/*! Release the osmo_log_tgt_mutex. Don't use this function directly, always use
131 * macro log_tgt_mutex_unlock() instead.
132 */
133void log_tgt_mutex_unlock_impl(void) {
134 if (osmo_log_tgt_mutex_on)
135 pthread_mutex_unlock(&osmo_log_tgt_mutex);
136}
137
138#else /* if (!EMBEDDED) */
139#pragma message ("logging multithread support disabled in embedded build")
140void log_enable_multithread(void) {}
141void log_tgt_mutex_lock_impl(void) {}
142void log_tgt_mutex_unlock_impl(void) {}
143#endif /* if (!EMBEDDED) */
144
Neels Hofmeyr098038a2018-09-11 23:49:13 +0200145const struct value_string loglevel_strs[] = {
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800146 { LOGL_DEBUG, "DEBUG" },
147 { LOGL_INFO, "INFO" },
148 { LOGL_NOTICE, "NOTICE" },
149 { LOGL_ERROR, "ERROR" },
150 { LOGL_FATAL, "FATAL" },
151 { 0, NULL },
152};
153
Harald Welte4c0e1a12020-12-07 22:03:09 +0100154/* 256 color palette see https://en.wikipedia.org/wiki/ANSI_escape_code#8-bit */
Harald Welteb43bc042011-06-27 10:29:17 +0200155#define INT2IDX(x) (-1*(x)-1)
156static const struct log_info_cat internal_cat[OSMO_NUM_DLIB] = {
157 [INT2IDX(DLGLOBAL)] = { /* -1 becomes 0 */
158 .name = "DLGLOBAL",
159 .description = "Library-internal global log family",
160 .loglevel = LOGL_NOTICE,
161 .enabled = 1,
162 },
root8a996b42011-09-26 11:22:21 +0200163 [INT2IDX(DLLAPD)] = { /* -2 becomes 1 */
164 .name = "DLLAPD",
165 .description = "LAPD in libosmogsm",
Harald Welte1f0b8c22011-06-27 10:51:37 +0200166 .loglevel = LOGL_NOTICE,
167 .enabled = 1,
Pau Espin Pedrol1573add2021-10-14 18:13:48 +0200168 .color = "\033[38;5;12m",
Harald Welte1f0b8c22011-06-27 10:51:37 +0200169 },
Harald Welte892e6212011-07-19 14:31:44 +0200170 [INT2IDX(DLINP)] = {
Harald Welte087e1132011-07-29 11:43:39 +0200171 .name = "DLINP",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200172 .description = "A-bis Intput Subsystem",
173 .loglevel = LOGL_NOTICE,
174 .enabled = 1,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100175 .color = "\033[38;5;23m",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200176 },
Harald Welte892e6212011-07-19 14:31:44 +0200177 [INT2IDX(DLMUX)] = {
Harald Welte087e1132011-07-29 11:43:39 +0200178 .name = "DLMUX",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200179 .description = "A-bis B-Subchannel TRAU Frame Multiplex",
180 .loglevel = LOGL_NOTICE,
181 .enabled = 1,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100182 .color = "\033[38;5;25m",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200183 },
Harald Welte892e6212011-07-19 14:31:44 +0200184 [INT2IDX(DLMI)] = {
Harald Welte087e1132011-07-29 11:43:39 +0200185 .name = "DLMI",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200186 .description = "A-bis Input Driver for Signalling",
187 .enabled = 0, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100188 .color = "\033[38;5;27m",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200189 },
Harald Welte892e6212011-07-19 14:31:44 +0200190 [INT2IDX(DLMIB)] = {
Harald Welte087e1132011-07-29 11:43:39 +0200191 .name = "DLMIB",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200192 .description = "A-bis Input Driver for B-Channels (voice)",
193 .enabled = 0, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100194 .color = "\033[38;5;29m",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200195 },
Andreas Eversbergc626da92011-10-28 03:53:50 +0200196 [INT2IDX(DLSMS)] = {
197 .name = "DLSMS",
198 .description = "Layer3 Short Message Service (SMS)",
199 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100200 .color = "\033[38;5;31m",
Andreas Eversbergc626da92011-10-28 03:53:50 +0200201 },
Harald Welte7fd0c832014-08-20 19:58:13 +0200202 [INT2IDX(DLCTRL)] = {
203 .name = "DLCTRL",
204 .description = "Control Interface",
205 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100206 .color = "\033[38;5;33m",
Harald Welte7fd0c832014-08-20 19:58:13 +0200207 },
Holger Hans Peter Freythera5dc19d2014-12-04 14:35:21 +0100208 [INT2IDX(DLGTP)] = {
209 .name = "DLGTP",
210 .description = "GPRS GTP library",
211 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100212 .color = "\033[38;5;35m",
Holger Hans Peter Freythera5dc19d2014-12-04 14:35:21 +0100213 },
Jacob Erlbeck79125ec2015-11-02 15:17:50 +0100214 [INT2IDX(DLSTATS)] = {
215 .name = "DLSTATS",
216 .description = "Statistics messages and logging",
217 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100218 .color = "\033[38;5;37m",
Jacob Erlbeck79125ec2015-11-02 15:17:50 +0100219 },
Neels Hofmeyr9795cf12016-12-10 17:01:06 +0100220 [INT2IDX(DLGSUP)] = {
221 .name = "DLGSUP",
222 .description = "Generic Subscriber Update Protocol",
223 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100224 .color = "\033[38;5;39m",
Neels Hofmeyr9795cf12016-12-10 17:01:06 +0100225 },
Harald Weltec0f00072016-04-27 18:32:35 +0200226 [INT2IDX(DLOAP)] = {
227 .name = "DLOAP",
228 .description = "Osmocom Authentication Protocol",
229 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100230 .color = "\033[38;5;41m",
Harald Weltec0f00072016-04-27 18:32:35 +0200231 },
Harald Welte059c4042017-04-03 22:20:49 +0200232 [INT2IDX(DLSS7)] = {
233 .name = "DLSS7",
234 .description = "libosmo-sigtran Signalling System 7",
235 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100236 .color = "\033[38;5;43m",
Harald Welte059c4042017-04-03 22:20:49 +0200237 },
238 [INT2IDX(DLSCCP)] = {
239 .name = "DLSCCP",
240 .description = "libosmo-sigtran SCCP Implementation",
241 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100242 .color = "\033[38;5;45m",
Harald Welte059c4042017-04-03 22:20:49 +0200243 },
244 [INT2IDX(DLSUA)] = {
245 .name = "DLSUA",
246 .description = "libosmo-sigtran SCCP User Adaptation",
247 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100248 .color = "\033[38;5;47m",
Harald Welte059c4042017-04-03 22:20:49 +0200249 },
250 [INT2IDX(DLM3UA)] = {
251 .name = "DLM3UA",
252 .description = "libosmo-sigtran MTP3 User Adaptation",
253 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100254 .color = "\033[38;5;49m",
Harald Welte059c4042017-04-03 22:20:49 +0200255 },
Neels Hofmeyra7ccf612017-07-11 18:43:09 +0200256 [INT2IDX(DLMGCP)] = {
257 .name = "DLMGCP",
258 .description = "libosmo-mgcp Media Gateway Control Protocol",
259 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100260 .color = "\033[38;5;51m",
Neels Hofmeyra7ccf612017-07-11 18:43:09 +0200261 },
Pau Espin Pedrol8fd85572018-02-27 19:43:10 +0100262 [INT2IDX(DLJIBUF)] = {
263 .name = "DLJIBUF",
264 .description = "libosmo-netif Jitter Buffer",
265 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100266 .color = "\033[38;5;53m",
Pau Espin Pedrol8fd85572018-02-27 19:43:10 +0100267 },
Max450f5ac2019-02-14 19:12:03 +0100268 [INT2IDX(DLRSPRO)] = {
269 .name = "DLRSPRO",
270 .description = "Remote SIM protocol",
271 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100272 .color = "\033[38;5;55m",
Max450f5ac2019-02-14 19:12:03 +0100273 },
Alexander Couzens6a161492020-07-12 13:45:50 +0200274 [INT2IDX(DLNS)] = {
275 .name = "DLNS",
276 .description = "GPRS NS layer",
277 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100278 .color = "\033[38;5;57m",
Alexander Couzens6a161492020-07-12 13:45:50 +0200279 },
Harald Weltefde19ed2020-12-07 21:43:51 +0100280 [INT2IDX(DLBSSGP)] = {
281 .name = "DLBSSGP",
282 .description = "GPRS BSSGP layer",
283 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100284 .color = "\033[38;5;59m",
Harald Weltefde19ed2020-12-07 21:43:51 +0100285 },
Alexander Couzens6cf65d92021-01-18 17:55:35 +0100286 [INT2IDX(DLNSDATA)] = {
287 .name = "DLNSDATA",
288 .description = "GPRS NS layer data PDU",
289 .enabled = 1, .loglevel = LOGL_NOTICE,
290 .color = "\033[38;5;61m",
291 },
292 [INT2IDX(DLNSSIGNAL)] = {
293 .name = "DLNSSIGNAL",
294 .description = "GPRS NS layer signal PDU",
295 .enabled = 1, .loglevel = LOGL_NOTICE,
296 .color = "\033[38;5;63m",
297 },
Harald Welte9fe1f9f2018-11-29 13:47:39 +0100298 [INT2IDX(DLIUUP)] = {
299 .name = "DLIUUP",
300 .description = "Iu UP layer",
301 .enabled = 1, .loglevel = LOGL_NOTICE,
302 .color = "\033[38;5;65m",
303 },
Neels Hofmeyr13fa00e2021-11-26 11:02:47 +0100304 [INT2IDX(DLPFCP)] = {
305 .name = "DLPFCP",
306 .description = "libosmo-pfcp Packet Forwarding Control Protocol",
307 .enabled = 1, .loglevel = LOGL_NOTICE,
308 .color = "\033[38;5;51m",
309 },
Vadim Yanitskiy8137d9a2022-08-03 05:35:04 +0700310 [INT2IDX(DLCSN1)] = {
311 .name = "DLCSN1",
312 .description = "libosmo-csn1 Concrete Syntax Notation 1 codec",
313 .enabled = 1, .loglevel = LOGL_NOTICE,
314 .color = "\033[38;5;11m",
315 },
Harald Welte8857f3b2022-11-18 13:54:44 +0100316 [INT2IDX(DLIO)] = {
317 .name = "DLIO",
318 .description = "libosmocore IO Subsystem",
319 .enabled = 1, .loglevel = LOGL_NOTICE,
320 .color = "\033[38;5;67m",
321 },
Harald Welteb43bc042011-06-27 10:29:17 +0200322};
323
Neels Hofmeyrba0762d2018-09-10 13:56:03 +0200324void assert_loginfo(const char *src)
Harald Welte18a7d812017-03-16 23:54:55 +0100325{
326 if (!osmo_log_info) {
327 fprintf(stderr, "ERROR: osmo_log_info == NULL! "
Max68bf16a2018-01-10 17:00:43 +0100328 "You must call log_init() before using logging in %s()!\n", src);
Harald Welte18a7d812017-03-16 23:54:55 +0100329 OSMO_ASSERT(osmo_log_info);
330 }
331}
332
Harald Welteb43bc042011-06-27 10:29:17 +0200333/* special magic for negative (library-internal) log subsystem numbers */
334static int subsys_lib2index(int subsys)
335{
336 return (subsys * -1) + (osmo_log_info->num_cat_user-1);
337}
338
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200339/*! Parse a human-readable log level into a numeric value
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +0700340 * \param[in] lvl zero-terminated string containing log level name
Harald Welte2d2e2cc2016-04-25 12:11:20 +0200341 * \returns numeric log level
342 */
Harald Welte3ae27582010-03-26 21:24:24 +0800343int log_parse_level(const char *lvl)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800344{
345 return get_string_value(loglevel_strs, lvl);
346}
347
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200348/*! convert a numeric log level into human-readable string
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +0700349 * \param[in] lvl numeric log level
Harald Welte2d2e2cc2016-04-25 12:11:20 +0200350 * \returns zero-terminated string (log level name)
351 */
Harald Welte9ac22252010-05-11 11:19:40 +0200352const char *log_level_str(unsigned int lvl)
353{
354 return get_value_string(loglevel_strs, lvl);
355}
356
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200357/*! parse a human-readable log category into numeric form
Harald Welte18fc4652011-08-17 14:14:17 +0200358 * \param[in] category human-readable log category name
359 * \returns numeric category value, or -EINVAL otherwise
360 */
Harald Welte3ae27582010-03-26 21:24:24 +0800361int log_parse_category(const char *category)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800362{
363 int i;
364
Max68bf16a2018-01-10 17:00:43 +0100365 assert_loginfo(__func__);
Harald Welte18a7d812017-03-16 23:54:55 +0100366
Harald Welte4ebdf742010-05-19 19:54:00 +0200367 for (i = 0; i < osmo_log_info->num_cat; ++i) {
Harald Welteb43bc042011-06-27 10:29:17 +0200368 if (osmo_log_info->cat[i].name == NULL)
369 continue;
Harald Welte4ebdf742010-05-19 19:54:00 +0200370 if (!strcasecmp(osmo_log_info->cat[i].name+1, category))
Harald Weltefaadfe22010-03-26 21:05:43 +0800371 return i;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800372 }
373
374 return -EINVAL;
375}
376
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200377/*! parse the log category mask
Harald Welte18fc4652011-08-17 14:14:17 +0200378 * \param[in] target log target to be configured
379 * \param[in] _mask log category mask string
380 *
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800381 * The format can be this: category1:category2:category3
382 * or category1,2:category2,3:...
383 */
Harald Welte3ae27582010-03-26 21:24:24 +0800384void log_parse_category_mask(struct log_target* target, const char *_mask)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800385{
386 int i = 0;
387 char *mask = strdup(_mask);
388 char *category_token = NULL;
389
Max68bf16a2018-01-10 17:00:43 +0100390 assert_loginfo(__func__);
Harald Welte18a7d812017-03-16 23:54:55 +0100391
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800392 /* Disable everything to enable it afterwards */
Harald Welteb43bc042011-06-27 10:29:17 +0200393 for (i = 0; i < osmo_log_info->num_cat; ++i)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800394 target->categories[i].enabled = 0;
395
396 category_token = strtok(mask, ":");
Neels Hofmeyrda1b20c2016-04-14 15:12:16 +0200397 OSMO_ASSERT(category_token);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800398 do {
Harald Welte4ebdf742010-05-19 19:54:00 +0200399 for (i = 0; i < osmo_log_info->num_cat; ++i) {
Nico Golde0262d3f2012-09-21 17:44:58 +0200400 size_t length, cat_length;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800401 char* colon = strstr(category_token, ",");
Nico Golde0262d3f2012-09-21 17:44:58 +0200402
403 if (!osmo_log_info->cat[i].name)
404 continue;
405
406 length = strlen(category_token);
407 cat_length = strlen(osmo_log_info->cat[i].name);
Pablo Neira Ayuso300e78d2011-08-11 13:24:18 +0200408
409 /* Use longest length not to match subocurrences. */
410 if (cat_length > length)
411 length = cat_length;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800412
413 if (colon)
414 length = colon - category_token;
415
Harald Welte4ebdf742010-05-19 19:54:00 +0200416 if (strncasecmp(osmo_log_info->cat[i].name,
417 category_token, length) == 0) {
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800418 int level = 0;
419
420 if (colon)
421 level = atoi(colon+1);
422
Harald Weltefaadfe22010-03-26 21:05:43 +0800423 target->categories[i].enabled = 1;
424 target->categories[i].loglevel = level;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800425 }
426 }
427 } while ((category_token = strtok(NULL, ":")));
428
429 free(mask);
430}
431
432static const char* color(int subsys)
433{
Harald Welte4ebdf742010-05-19 19:54:00 +0200434 if (subsys < osmo_log_info->num_cat)
435 return osmo_log_info->cat[subsys].color;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800436
Harald Welted788f662010-03-26 09:45:03 +0800437 return NULL;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800438}
439
Neels Hofmeyrf3fa3692018-01-16 02:56:01 +0100440static const struct value_string level_colors[] = {
Neels Hofmeyrf2644ae2019-11-20 04:00:29 +0100441 { LOGL_DEBUG, OSMO_LOGCOLOR_BLUE },
442 { LOGL_INFO, OSMO_LOGCOLOR_GREEN },
443 { LOGL_NOTICE, OSMO_LOGCOLOR_YELLOW },
444 { LOGL_ERROR, OSMO_LOGCOLOR_RED },
445 { LOGL_FATAL, OSMO_LOGCOLOR_RED },
Neels Hofmeyrf3fa3692018-01-16 02:56:01 +0100446 { 0, NULL }
447};
448
449static const char *level_color(int level)
450{
451 const char *c = get_value_string_or_null(level_colors, level);
452 if (!c)
453 return get_value_string(level_colors, LOGL_FATAL);
454 return c;
455}
456
Harald Welteaa00f992016-12-02 15:30:02 +0100457const char* log_category_name(int subsys)
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100458{
459 if (subsys < osmo_log_info->num_cat)
460 return osmo_log_info->cat[subsys].name;
461
462 return NULL;
463}
464
Neels Hofmeyr0e2a9432018-01-16 02:49:48 +0100465static const char *const_basename(const char *path)
466{
467 const char *bn = strrchr(path, '/');
468 if (!bn || !bn[1])
469 return path;
470 return bn + 1;
471}
472
Harald Weltea0b57d02020-09-27 17:15:10 +0200473/*! main output formatting function for log lines.
474 * \param[out] buf caller-allocated output buffer for the generated string
475 * \param[in] buf_len number of bytes available in buf
476 * \param[in] target log target for which the string is to be formatted
477 * \param[in] subsys Log sub-system number
478 * \param[in] level Log level
479 * \param[in] file name of source code file generating the log
480 * \param[in] line line source code line number within 'file' generating the log
481 * \param[in] cont is this a continuation (true) or not (false)
482 * \param[in] format format string
483 * \param[in] ap variable argument list for format
484 * \returns number of bytes written to out */
485static int _output_buf(char *buf, int buf_len, struct log_target *target, unsigned int subsys,
486 unsigned int level, const char *file, int line, int cont,
487 const char *format, va_list ap)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800488{
Harald Weltea0b57d02020-09-27 17:15:10 +0200489 int ret, len = 0, offset = 0, rem = buf_len;
Neels Hofmeyrf3fa3692018-01-16 02:56:01 +0100490 const char *c_subsys = NULL;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800491
492 /* are we using color */
493 if (target->use_color) {
Neels Hofmeyrf3fa3692018-01-16 02:56:01 +0100494 c_subsys = color(subsys);
495 if (c_subsys) {
Neels Hofmeyr5e518b52018-01-17 13:20:02 +0100496 ret = snprintf(buf + offset, rem, "%s", c_subsys);
Pablo Neira Ayuso7503fb82011-05-03 22:32:43 +0200497 if (ret < 0)
498 goto err;
499 OSMO_SNPRINTF_RET(ret, rem, offset, len);
Harald Welted788f662010-03-26 09:45:03 +0800500 }
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800501 }
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800502 if (!cont) {
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100503 if (target->print_ext_timestamp) {
Harald Welte14c4c492018-06-28 08:28:52 +0200504#ifdef HAVE_LOCALTIME_R
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100505 struct tm tm;
Jacob Erlbeckb61b2ca2015-03-17 10:21:15 +0100506 struct timeval tv;
Neels Hofmeyr8e2f7e82016-09-22 03:58:13 +0200507 osmo_gettimeofday(&tv, NULL);
Jacob Erlbeckb61b2ca2015-03-17 10:21:15 +0100508 localtime_r(&tv.tv_sec, &tm);
509 ret = snprintf(buf + offset, rem, "%04d%02d%02d%02d%02d%02d%03d ",
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100510 tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday,
Jacob Erlbeckb61b2ca2015-03-17 10:21:15 +0100511 tm.tm_hour, tm.tm_min, tm.tm_sec,
512 (int)(tv.tv_usec / 1000));
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100513 if (ret < 0)
514 goto err;
515 OSMO_SNPRINTF_RET(ret, rem, offset, len);
Harald Welte14c4c492018-06-28 08:28:52 +0200516#endif
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100517 } else if (target->print_timestamp) {
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800518 time_t tm;
Pau Espin Pedrol3aef2382019-06-12 18:50:29 +0200519 if ((tm = time(NULL)) == (time_t) -1)
520 goto err;
Pau Espin Pedrolcc794e92019-06-12 16:22:53 +0200521 /* Get human-readable representation of time.
522 man ctime: we need at least 26 bytes in buf */
523 if (rem < 26 || !ctime_r(&tm, buf + offset))
Pablo Neira Ayuso7503fb82011-05-03 22:32:43 +0200524 goto err;
Pau Espin Pedrolcc794e92019-06-12 16:22:53 +0200525 ret = strlen(buf + offset);
526 if (ret <= 0)
527 goto err;
528 /* Get rid of useless final '\n' added by ctime_r. We want a space instead. */
529 buf[offset + ret - 1] = ' ';
Pablo Neira Ayuso7503fb82011-05-03 22:32:43 +0200530 OSMO_SNPRINTF_RET(ret, rem, offset, len);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800531 }
Pau Espin Pedrol662d10d2021-02-18 18:19:23 +0100532 if (target->print_tid) {
533 if (logging_tid == 0)
534 logging_tid = (long int)osmo_gettid();
535 ret = snprintf(buf + offset, rem, "%ld ", logging_tid);
536 if (ret < 0)
537 goto err;
538 OSMO_SNPRINTF_RET(ret, rem, offset, len);
539 }
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100540 if (target->print_category) {
Neels Hofmeyre6534722018-01-16 03:02:06 +0100541 ret = snprintf(buf + offset, rem, "%s%s%s%s ",
542 target->use_color ? level_color(level) : "",
543 log_category_name(subsys),
Neels Hofmeyrf2644ae2019-11-20 04:00:29 +0100544 target->use_color ? OSMO_LOGCOLOR_END : "",
Neels Hofmeyre6534722018-01-16 03:02:06 +0100545 c_subsys ? c_subsys : "");
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100546 if (ret < 0)
547 goto err;
548 OSMO_SNPRINTF_RET(ret, rem, offset, len);
549 }
Neels Hofmeyr886e5482018-01-16 01:49:37 +0100550 if (target->print_level) {
Neels Hofmeyrf3fa3692018-01-16 02:56:01 +0100551 ret = snprintf(buf + offset, rem, "%s%s%s%s ",
552 target->use_color ? level_color(level) : "",
553 log_level_str(level),
Neels Hofmeyrf2644ae2019-11-20 04:00:29 +0100554 target->use_color ? OSMO_LOGCOLOR_END : "",
Neels Hofmeyrf3fa3692018-01-16 02:56:01 +0100555 c_subsys ? c_subsys : "");
Neels Hofmeyr886e5482018-01-16 01:49:37 +0100556 if (ret < 0)
557 goto err;
558 OSMO_SNPRINTF_RET(ret, rem, offset, len);
559 }
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +0100560 if (target->print_category_hex) {
561 ret = snprintf(buf + offset, rem, "<%4.4x> ", subsys);
Holger Hans Peter Freytherdb153362012-09-11 11:24:51 +0200562 if (ret < 0)
563 goto err;
564 OSMO_SNPRINTF_RET(ret, rem, offset, len);
565 }
Neels Hofmeyr77ae45d2018-08-27 20:32:36 +0200566
567 if (target->print_filename_pos == LOG_FILENAME_POS_HEADER_END) {
568 switch (target->print_filename2) {
569 case LOG_FILENAME_NONE:
570 break;
571 case LOG_FILENAME_PATH:
572 ret = snprintf(buf + offset, rem, "%s:%d ", file, line);
573 if (ret < 0)
574 goto err;
575 OSMO_SNPRINTF_RET(ret, rem, offset, len);
576 break;
577 case LOG_FILENAME_BASENAME:
578 ret = snprintf(buf + offset, rem, "%s:%d ", const_basename(file), line);
579 if (ret < 0)
580 goto err;
581 OSMO_SNPRINTF_RET(ret, rem, offset, len);
582 break;
583 }
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +0100584 }
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800585 }
Pablo Neira Ayuso7503fb82011-05-03 22:32:43 +0200586 ret = vsnprintf(buf + offset, rem, format, ap);
587 if (ret < 0)
588 goto err;
589 OSMO_SNPRINTF_RET(ret, rem, offset, len);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800590
Neels Hofmeyr77ae45d2018-08-27 20:32:36 +0200591 /* For LOG_FILENAME_POS_LAST, print the source file info only when the caller ended the log
592 * message in '\n'. If so, nip the last '\n' away, insert the source file info and re-append an
593 * '\n'. All this to allow LOGP("start..."); LOGPC("...end\n") constructs. */
594 if (target->print_filename_pos == LOG_FILENAME_POS_LINE_END
Vadim Yanitskiye56f1b62022-01-29 19:37:39 +0600595 && offset > 0 && buf[offset - 1] == '\n') {
Neels Hofmeyr77ae45d2018-08-27 20:32:36 +0200596 switch (target->print_filename2) {
597 case LOG_FILENAME_NONE:
598 break;
599 case LOG_FILENAME_PATH:
Vadim Yanitskiye56f1b62022-01-29 19:37:39 +0600600 offset--;
Vadim Yanitskiy83f423b2022-01-29 20:34:45 +0600601 len--;
Neels Hofmeyr77ae45d2018-08-27 20:32:36 +0200602 ret = snprintf(buf + offset, rem, " (%s:%d)\n", file, line);
603 if (ret < 0)
604 goto err;
605 OSMO_SNPRINTF_RET(ret, rem, offset, len);
606 break;
607 case LOG_FILENAME_BASENAME:
Vadim Yanitskiye56f1b62022-01-29 19:37:39 +0600608 offset--;
Vadim Yanitskiy83f423b2022-01-29 20:34:45 +0600609 len--;
Neels Hofmeyr77ae45d2018-08-27 20:32:36 +0200610 ret = snprintf(buf + offset, rem, " (%s:%d)\n", const_basename(file), line);
611 if (ret < 0)
612 goto err;
613 OSMO_SNPRINTF_RET(ret, rem, offset, len);
614 break;
615 }
616 }
617
Pau Espin Pedrol6407c822020-07-20 16:41:44 +0200618 if (target->use_color && c_subsys) {
Manawyrm11a41682023-11-07 11:56:02 +0100619 /* Ensure the last color escape is sent before the newline
620 * (to not clobber journald, which works on single-lines only) */
621 if (offset > 0 && buf[offset - 1] == '\n') {
622 offset--; rem++;
623 ret = snprintf(buf + offset, rem, OSMO_LOGCOLOR_END "\n");
624 } else {
625 ret = snprintf(buf + offset, rem, OSMO_LOGCOLOR_END);
626 }
627
Neels Hofmeyrc4759882018-01-16 02:10:48 +0100628 if (ret < 0)
629 goto err;
630 OSMO_SNPRINTF_RET(ret, rem, offset, len);
631 }
Pablo Neira Ayuso7503fb82011-05-03 22:32:43 +0200632err:
Pau Espin Pedrolbeaf2a22022-01-04 13:36:18 +0100633 len = OSMO_MIN(buf_len - 1, len);
634 buf[len] = '\0';
Harald Weltea0b57d02020-09-27 17:15:10 +0200635 return len;
636}
637
638/* Format the log line for given target; use a stack buffer and call target->output */
639static void _output(struct log_target *target, unsigned int subsys,
640 unsigned int level, const char *file, int line, int cont,
641 const char *format, va_list ap)
642{
643 char buf[MAX_LOG_SIZE];
644 int rc;
645
646 rc = _output_buf(buf, sizeof(buf), target, subsys, level, file, line, cont, format, ap);
647 if (rc > 0)
648 target->output(target, level, buf);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800649}
650
Neels Hofmeyr42240de2016-12-12 15:13:56 +0100651/* Catch internal logging category indexes as well as out-of-bounds indexes.
652 * For internal categories, the ID is negative starting with -1; and internal
653 * logging categories are added behind the user categories. For out-of-bounds
654 * indexes, return the index of DLGLOBAL. The returned category index is
655 * guaranteed to exist in osmo_log_info, otherwise the program would abort,
656 * which should never happen unless even the DLGLOBAL category is missing. */
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100657static inline int map_subsys(int subsys)
658{
Neels Hofmeyr74802262016-12-12 16:00:24 +0100659 /* Note: comparing signed and unsigned integers */
660
661 if (subsys > 0 && ((unsigned int)subsys) >= osmo_log_info->num_cat_user)
662 subsys = DLGLOBAL;
663
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100664 if (subsys < 0)
665 subsys = subsys_lib2index(subsys);
666
Neels Hofmeyrca135742016-12-12 14:18:54 +0100667 if (subsys < 0 || subsys >= osmo_log_info->num_cat)
Neels Hofmeyr42240de2016-12-12 15:13:56 +0100668 subsys = subsys_lib2index(DLGLOBAL);
669
Neels Hofmeyrca135742016-12-12 14:18:54 +0100670 OSMO_ASSERT(!(subsys < 0 || subsys >= osmo_log_info->num_cat));
671
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100672 return subsys;
673}
674
Maxc65c5b42017-03-15 13:20:23 +0100675static inline bool should_log_to_target(struct log_target *tar, int subsys,
676 int level)
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100677{
678 struct log_category *category;
679
680 category = &tar->categories[subsys];
681
682 /* subsystem is not supposed to be logged */
683 if (!category->enabled)
Maxc65c5b42017-03-15 13:20:23 +0100684 return false;
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100685
686 /* Check the global log level */
687 if (tar->loglevel != 0 && level < tar->loglevel)
Maxc65c5b42017-03-15 13:20:23 +0100688 return false;
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100689
690 /* Check the category log level */
691 if (tar->loglevel == 0 && category->loglevel != 0 &&
692 level < category->loglevel)
Maxc65c5b42017-03-15 13:20:23 +0100693 return false;
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100694
Holger Hans Peter Freyther79599ac2016-01-15 16:49:06 +0100695 /* Apply filters here... if that becomes messy we will
696 * need to put filters in a list and each filter will
697 * say stop, continue, output */
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +0100698 if ((tar->filter_map & (1 << LOG_FLT_ALL)) != 0)
Maxc65c5b42017-03-15 13:20:23 +0100699 return true;
Holger Hans Peter Freyther79599ac2016-01-15 16:49:06 +0100700
701 if (osmo_log_info->filter_fn)
702 return osmo_log_info->filter_fn(&log_context, tar);
703
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100704 /* TODO: Check the filter/selector too? */
Maxc65c5b42017-03-15 13:20:23 +0100705 return true;
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100706}
707
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200708/*! vararg version of logging function
Harald Welte2d2e2cc2016-04-25 12:11:20 +0200709 * \param[in] subsys Logging sub-system
710 * \param[in] level Log level
711 * \param[in] file name of source code file
712 * \param[in] cont continuation (1) or new line (0)
713 * \param[in] format format string
714 * \param[in] ap vararg-list containing format string arguments
715 */
Holger Hans Peter Freytherfb4bfc22012-07-12 09:26:25 +0200716void osmo_vlogp(int subsys, int level, const char *file, int line,
Harald Welte36c5a3e2011-08-27 14:33:19 +0200717 int cont, const char *format, va_list ap)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800718{
Harald Welte3ae27582010-03-26 21:24:24 +0800719 struct log_target *tar;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800720
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100721 subsys = map_subsys(subsys);
Harald Welteb43bc042011-06-27 10:29:17 +0200722
Pau Espin Pedrold12f6982019-09-17 18:38:58 +0200723 log_tgt_mutex_lock();
724
Harald Welte28222962011-02-18 20:37:04 +0100725 llist_for_each_entry(tar, &osmo_log_target_list, entry) {
Pablo Neira Ayusodd93bf42011-05-19 01:40:43 +0200726 va_list bp;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800727
Maxc65c5b42017-03-15 13:20:23 +0100728 if (!should_log_to_target(tar, subsys, level))
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800729 continue;
730
Pablo Neira Ayusodd93bf42011-05-19 01:40:43 +0200731 /* According to the manpage, vsnprintf leaves the value of ap
732 * in undefined state. Since _output uses vsnprintf and it may
733 * be called several times, we have to pass a copy of ap. */
734 va_copy(bp, ap);
Harald Welted7c0a372016-12-02 13:52:59 +0100735 if (tar->raw_output)
736 tar->raw_output(tar, subsys, level, file, line, cont, format, bp);
737 else
738 _output(tar, subsys, level, file, line, cont, format, bp);
Pablo Neira Ayusodd93bf42011-05-19 01:40:43 +0200739 va_end(bp);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800740 }
Pau Espin Pedrold12f6982019-09-17 18:38:58 +0200741
742 log_tgt_mutex_unlock();
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800743}
744
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200745/*! logging function used by DEBUGP() macro
Harald Welte2d2e2cc2016-04-25 12:11:20 +0200746 * \param[in] subsys Logging sub-system
747 * \param[in] file name of source code file
748 * \param[in] cont continuation (1) or new line (0)
749 * \param[in] format format string
750 */
Holger Hans Peter Freytherfb4bfc22012-07-12 09:26:25 +0200751void logp(int subsys, const char *file, int line, int cont,
Harald Welte3ae27582010-03-26 21:24:24 +0800752 const char *format, ...)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800753{
754 va_list ap;
755
756 va_start(ap, format);
Harald Welte36c5a3e2011-08-27 14:33:19 +0200757 osmo_vlogp(subsys, LOGL_DEBUG, file, line, cont, format, ap);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800758 va_end(ap);
759}
760
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200761/*! logging function used by LOGP() macro
Harald Welte2d2e2cc2016-04-25 12:11:20 +0200762 * \param[in] subsys Logging sub-system
763 * \param[in] level Log level
764 * \param[in] file name of source code file
765 * \param[in] cont continuation (1) or new line (0)
766 * \param[in] format format string
767 */
Holger Hans Peter Freytherfb4bfc22012-07-12 09:26:25 +0200768void logp2(int subsys, unsigned int level, const char *file, int line, int cont, const char *format, ...)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800769{
770 va_list ap;
771
Harald Welte433005c2020-09-26 11:51:32 +0200772 TRACE(LIBOSMOCORE_LOG_START());
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800773 va_start(ap, format);
Harald Welte36c5a3e2011-08-27 14:33:19 +0200774 osmo_vlogp(subsys, level, file, line, cont, format, ap);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800775 va_end(ap);
Harald Welte433005c2020-09-26 11:51:32 +0200776 TRACE(LIBOSMOCORE_LOG_DONE());
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800777}
778
Philipp Maier4c44d462022-01-19 11:43:05 +0100779/* This logging function is used as a fallback when the logging framework is
780 * not is not properly initialized. */
781void logp_stub(const char *file, int line, int cont, const char *format, ...)
782{
783 va_list ap;
784 if (!cont)
785 fprintf(stderr, "%s:%d ", file, line);
786 va_start(ap, format);
787 vfprintf(stderr, format, ap);
788 va_end(ap);
789}
790
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200791/*! Register a new log target with the logging core
Harald Welte18fc4652011-08-17 14:14:17 +0200792 * \param[in] target Log target to be registered
793 */
Harald Welte3ae27582010-03-26 21:24:24 +0800794void log_add_target(struct log_target *target)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800795{
Harald Welte28222962011-02-18 20:37:04 +0100796 llist_add_tail(&target->entry, &osmo_log_target_list);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800797}
798
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200799/*! Unregister a log target from the logging core
Harald Welte18fc4652011-08-17 14:14:17 +0200800 * \param[in] target Log target to be unregistered
801 */
Harald Welte3ae27582010-03-26 21:24:24 +0800802void log_del_target(struct log_target *target)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800803{
804 llist_del(&target->entry);
805}
806
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200807/*! Reset (clear) the logging context */
Harald Welte3ae27582010-03-26 21:24:24 +0800808void log_reset_context(void)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800809{
Harald Welte3ae27582010-03-26 21:24:24 +0800810 memset(&log_context, 0, sizeof(log_context));
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800811}
812
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200813/*! Set the logging context
Harald Welte18fc4652011-08-17 14:14:17 +0200814 * \param[in] ctx_nr logging context number
815 * \param[in] value value to which the context is to be set
Harald Welte2d2e2cc2016-04-25 12:11:20 +0200816 * \returns 0 in case of success; negative otherwise
Harald Welte18fc4652011-08-17 14:14:17 +0200817 *
818 * A logging context is something like the subscriber identity to which
819 * the currently processed message relates, or the BTS through which it
820 * was received. As soon as this data is known, it can be set using
821 * this function. The main use of context information is for logging
822 * filters.
823 */
Harald Welte3ae27582010-03-26 21:24:24 +0800824int log_set_context(uint8_t ctx_nr, void *value)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800825{
Harald Welte3ae27582010-03-26 21:24:24 +0800826 if (ctx_nr > LOG_MAX_CTX)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800827 return -EINVAL;
828
Harald Welte3ae27582010-03-26 21:24:24 +0800829 log_context.ctx[ctx_nr] = value;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800830
831 return 0;
832}
833
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200834/*! Enable the \ref LOG_FLT_ALL log filter
Harald Welte18fc4652011-08-17 14:14:17 +0200835 * \param[in] target Log target to be affected
836 * \param[in] all enable (1) or disable (0) the ALL filter
837 *
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +0100838 * When the \ref LOG_FLT_ALL filter is enabled, all log messages will be
Neels Hofmeyr812ba6d2017-02-17 16:35:27 +0100839 * printed. It acts as a wildcard. Setting it to \a 1 means there is no
840 * filtering.
Harald Welte18fc4652011-08-17 14:14:17 +0200841 */
Harald Welte3ae27582010-03-26 21:24:24 +0800842void log_set_all_filter(struct log_target *target, int all)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800843{
844 if (all)
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +0100845 target->filter_map |= (1 << LOG_FLT_ALL);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800846 else
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +0100847 target->filter_map &= ~(1 << LOG_FLT_ALL);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800848}
849
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200850/*! Enable or disable the use of colored output
Harald Welte18fc4652011-08-17 14:14:17 +0200851 * \param[in] target Log target to be affected
852 * \param[in] use_color Use color (1) or don't use color (0)
853 */
Harald Welte3ae27582010-03-26 21:24:24 +0800854void log_set_use_color(struct log_target *target, int use_color)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800855{
856 target->use_color = use_color;
857}
858
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200859/*! Enable or disable printing of timestamps while logging
Harald Welte18fc4652011-08-17 14:14:17 +0200860 * \param[in] target Log target to be affected
861 * \param[in] print_timestamp Enable (1) or disable (0) timestamps
862 */
Harald Welte3ae27582010-03-26 21:24:24 +0800863void log_set_print_timestamp(struct log_target *target, int print_timestamp)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800864{
865 target->print_timestamp = print_timestamp;
866}
867
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200868/*! Enable or disable printing of extended timestamps while logging
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100869 * \param[in] target Log target to be affected
870 * \param[in] print_timestamp Enable (1) or disable (0) timestamps
871 *
872 * When both timestamp and extended timestamp is enabled then only
873 * the extended timestamp will be used. The format of the timestamp
874 * is YYYYMMDDhhmmssnnn.
875 */
876void log_set_print_extended_timestamp(struct log_target *target, int print_timestamp)
877{
878 target->print_ext_timestamp = print_timestamp;
879}
880
Pau Espin Pedrol662d10d2021-02-18 18:19:23 +0100881/*! Enable or disable printing of timestamps while logging
882 * \param[in] target Log target to be affected
883 * \param[in] print_tid Enable (1) or disable (0) Thread ID logging
884 */
885void log_set_print_tid(struct log_target *target, int print_tid)
886{
887 target->print_tid = print_tid;
888}
889
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +0100890/*! Use log_set_print_filename2() instead.
891 * Call log_set_print_filename2() with LOG_FILENAME_PATH or LOG_FILENAME_NONE, *as well as* call
892 * log_set_print_category_hex() with the argument passed to this function. This is to mirror legacy
893 * behavior, which combined the category in hex with the filename. For example, if the category-hex
894 * output were no longer affected by log_set_print_filename(), many unit tests (in libosmocore as well as
895 * dependent projects) would fail since they expect the category to disappear along with the filename.
Holger Hans Peter Freytherdb153362012-09-11 11:24:51 +0200896 * \param[in] target Log target to be affected
897 * \param[in] print_filename Enable (1) or disable (0) filenames
898 */
899void log_set_print_filename(struct log_target *target, int print_filename)
900{
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +0100901 log_set_print_filename2(target, print_filename ? LOG_FILENAME_PATH : LOG_FILENAME_NONE);
902 log_set_print_category_hex(target, print_filename);
903}
904
905/*! Enable or disable printing of the filename while logging.
906 * \param[in] target Log target to be affected.
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +0700907 * \param[in] lft An LOG_FILENAME_* enum value.
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +0100908 * LOG_FILENAME_NONE omits the source file and line information from logs.
909 * LOG_FILENAME_PATH prints the entire source file path as passed to LOGP macros.
910 */
911void log_set_print_filename2(struct log_target *target, enum log_filename_type lft)
912{
913 target->print_filename2 = lft;
Holger Hans Peter Freytherdb153362012-09-11 11:24:51 +0200914}
915
Neels Hofmeyr77ae45d2018-08-27 20:32:36 +0200916/*! Set the position where on a log line the source file info should be logged.
917 * \param[in] target Log target to be affected.
918 * \param[in] pos A LOG_FILENAME_POS_* enum value.
919 * LOG_FILENAME_POS_DEFAULT logs just before the caller supplied log message.
920 * LOG_FILENAME_POS_LAST logs only at the end of a log line, where the caller issued an '\n' to end the
921 */
922void log_set_print_filename_pos(struct log_target *target, enum log_filename_pos pos)
923{
924 target->print_filename_pos = pos;
925}
926
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200927/*! Enable or disable printing of the category name
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100928 * \param[in] target Log target to be affected
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +0700929 * \param[in] print_category Enable (1) or disable (0) filenames
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100930 *
931 * Print the category/subsys name in front of every log message.
932 */
933void log_set_print_category(struct log_target *target, int print_category)
934{
935 target->print_category = print_category;
936}
937
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +0100938/*! Enable or disable printing of the category number in hex ('<000b>').
939 * \param[in] target Log target to be affected.
940 * \param[in] print_category_hex Enable (1) or disable (0) hex category.
941 */
942void log_set_print_category_hex(struct log_target *target, int print_category_hex)
943{
944 target->print_category_hex = print_category_hex;
945}
946
Neels Hofmeyr886e5482018-01-16 01:49:37 +0100947/*! Enable or disable printing of the log level name.
948 * \param[in] target Log target to be affected
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +0700949 * \param[in] print_level Enable (1) or disable (0) log level name
Neels Hofmeyr886e5482018-01-16 01:49:37 +0100950 *
951 * Print the log level name in front of every log message.
952 */
953void log_set_print_level(struct log_target *target, int print_level)
954{
955 target->print_level = (bool)print_level;
956}
957
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200958/*! Set the global log level for a given log target
Harald Welte18fc4652011-08-17 14:14:17 +0200959 * \param[in] target Log target to be affected
960 * \param[in] log_level New global log level
961 */
Harald Welte3ae27582010-03-26 21:24:24 +0800962void log_set_log_level(struct log_target *target, int log_level)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800963{
964 target->loglevel = log_level;
965}
966
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200967/*! Set a category filter on a given log target
Harald Weltede6e4982012-12-06 21:25:27 +0100968 * \param[in] target Log target to be affected
969 * \param[in] category Log category to be affected
970 * \param[in] enable whether to enable or disable the filter
971 * \param[in] level Log level of the filter
972 */
Harald Welte3ae27582010-03-26 21:24:24 +0800973void log_set_category_filter(struct log_target *target, int category,
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800974 int enable, int level)
975{
Neels Hofmeyr886d6fd2016-12-12 13:49:03 +0100976 if (!target)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800977 return;
Neels Hofmeyr886d6fd2016-12-12 13:49:03 +0100978 category = map_subsys(category);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800979 target->categories[category].enabled = !!enable;
980 target->categories[category].loglevel = level;
981}
982
Harald Welte44c0f632017-01-15 17:58:29 +0100983#if (!EMBEDDED)
Harald Welte78d73672020-09-29 11:32:35 +0200984/* write-queue tells us we should write another msgb (log line) to the output fd */
985static int _file_wq_write_cb(struct osmo_fd *ofd, struct msgb *msg)
986{
987 int rc;
988
989 rc = write(ofd->fd, msgb_data(msg), msgb_length(msg));
990 if (rc < 0)
991 return rc;
992 if (rc != msgb_length(msg)) {
993 /* pull the number of bytes we have already written */
994 msgb_pull(msg, rc);
995 /* ask write_queue to re-insert the msgb at the head of the queue */
996 return -EAGAIN;
997 }
998 return 0;
999}
1000
1001/* output via buffered, blocking stdio streams */
Harald Welteb72867f2020-09-26 21:45:16 +02001002static void _file_output_stream(struct log_target *target, unsigned int level,
1003 const char *log)
1004{
1005 OSMO_ASSERT(target->tgt_file.out);
1006 fputs(log, target->tgt_file.out);
1007 fflush(target->tgt_file.out);
1008}
1009
1010/* output via non-blocking write_queue, doing internal buffering */
Harald Weltea0b57d02020-09-27 17:15:10 +02001011static void _file_raw_output(struct log_target *target, int subsys, unsigned int level, const char *file,
1012 int line, int cont, const char *format, va_list ap)
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001013{
Harald Welteb72867f2020-09-26 21:45:16 +02001014 struct msgb *msg;
Harald Weltea0b57d02020-09-27 17:15:10 +02001015 int rc;
Harald Welteb72867f2020-09-26 21:45:16 +02001016
1017 OSMO_ASSERT(target->tgt_file.wqueue);
Harald Weltea0b57d02020-09-27 17:15:10 +02001018 msg = msgb_alloc_c(target->tgt_file.wqueue, MAX_LOG_SIZE, "log_file_msg");
Harald Welteb72867f2020-09-26 21:45:16 +02001019 if (!msg)
1020 return;
1021
1022 /* we simply enqueue the log message to a write queue here, to avoid any blocking
1023 * writes on the output file. The write queue will tell us once the file is writable
1024 * and call _file_wq_write_cb() */
Harald Weltea0b57d02020-09-27 17:15:10 +02001025 rc = _output_buf((char *)msgb_data(msg), msgb_tailroom(msg), target, subsys, level, file, line, cont, format, ap);
1026 msgb_put(msg, rc);
Harald Welte78d73672020-09-29 11:32:35 +02001027
1028 /* attempt a synchronous, non-blocking write, if the write queue is empty */
1029 if (target->tgt_file.wqueue->current_length == 0) {
1030 rc = _file_wq_write_cb(&target->tgt_file.wqueue->bfd, msg);
1031 if (rc == 0) {
1032 /* the write was complete, we can exit early */
1033 msgb_free(msg);
1034 return;
1035 }
1036 }
1037 /* if we reach here, either we already had elements in the write_queue, or the synchronous write
1038 * failed: enqueue the message to the write_queue (backlog) */
Harald Welte9a9627e2021-11-25 13:38:19 +01001039 if (osmo_wqueue_enqueue_quiet(target->tgt_file.wqueue, msg) < 0) {
1040 msgb_free(msg);
1041 /* TODO: increment some counter so we can see that messages were dropped */
1042 }
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001043}
Harald Welte44c0f632017-01-15 17:58:29 +01001044#endif
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001045
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001046/*! Create a new log target skeleton
Harald Welte2d2e2cc2016-04-25 12:11:20 +02001047 * \returns dynamically-allocated log target
1048 * This funcition allocates a \ref log_target and initializes it
1049 * with some default values. The newly created target is not
1050 * registered yet.
1051 */
Harald Welte3ae27582010-03-26 21:24:24 +08001052struct log_target *log_target_create(void)
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001053{
Harald Welte3ae27582010-03-26 21:24:24 +08001054 struct log_target *target;
Harald Weltecc6313c2010-03-26 22:04:03 +08001055 unsigned int i;
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001056
Max68bf16a2018-01-10 17:00:43 +01001057 assert_loginfo(__func__);
Harald Welte18a7d812017-03-16 23:54:55 +01001058
Harald Welte3ae27582010-03-26 21:24:24 +08001059 target = talloc_zero(tall_log_ctx, struct log_target);
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001060 if (!target)
1061 return NULL;
1062
Pau Espin Pedrol9d4a36e2018-07-26 11:55:33 +02001063 target->categories = talloc_zero_array(target,
Harald Welteb43bc042011-06-27 10:29:17 +02001064 struct log_category,
1065 osmo_log_info->num_cat);
1066 if (!target->categories) {
1067 talloc_free(target);
1068 return NULL;
1069 }
1070
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001071 INIT_LLIST_HEAD(&target->entry);
Harald Weltecc6313c2010-03-26 22:04:03 +08001072
1073 /* initialize the per-category enabled/loglevel from defaults */
Harald Welte4ebdf742010-05-19 19:54:00 +02001074 for (i = 0; i < osmo_log_info->num_cat; i++) {
Harald Weltecc6313c2010-03-26 22:04:03 +08001075 struct log_category *cat = &target->categories[i];
Harald Welte4ebdf742010-05-19 19:54:00 +02001076 cat->enabled = osmo_log_info->cat[i].enabled;
1077 cat->loglevel = osmo_log_info->cat[i].loglevel;
Harald Weltecc6313c2010-03-26 22:04:03 +08001078 }
1079
1080 /* global settings */
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001081 target->use_color = 1;
1082 target->print_timestamp = 0;
Pau Espin Pedrol662d10d2021-02-18 18:19:23 +01001083 target->print_tid = 0;
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +01001084 target->print_filename2 = LOG_FILENAME_PATH;
1085 target->print_category_hex = true;
Harald Weltecc6313c2010-03-26 22:04:03 +08001086
1087 /* global log level */
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001088 target->loglevel = 0;
1089 return target;
1090}
1091
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001092/*! Create the STDERR log target
Harald Welte2d2e2cc2016-04-25 12:11:20 +02001093 * \returns dynamically-allocated \ref log_target for STDERR */
Harald Welte3ae27582010-03-26 21:24:24 +08001094struct log_target *log_target_create_stderr(void)
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001095{
Harald Weltea3b844c2010-03-27 00:04:40 +08001096/* since C89/C99 says stderr is a macro, we can safely do this! */
Harald Welteb93ce5a2017-05-15 10:58:15 +02001097#if !EMBEDDED && defined(stderr)
Harald Welte3ae27582010-03-26 21:24:24 +08001098 struct log_target *target;
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001099
Harald Welte3ae27582010-03-26 21:24:24 +08001100 target = log_target_create();
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001101 if (!target)
1102 return NULL;
1103
Harald Welte28222962011-02-18 20:37:04 +01001104 target->type = LOG_TGT_TYPE_STDERR;
Harald Welte0083cd32010-08-25 14:55:44 +02001105 target->tgt_file.out = stderr;
Harald Welteb72867f2020-09-26 21:45:16 +02001106 target->output = _file_output_stream;
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001107 return target;
Harald Weltea3b844c2010-03-27 00:04:40 +08001108#else
1109 return NULL;
1110#endif /* stderr */
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001111}
1112
Harald Welte44c0f632017-01-15 17:58:29 +01001113#if (!EMBEDDED)
Harald Welteb72867f2020-09-26 21:45:16 +02001114/*! Create a new file-based log target using buffered, blocking stream output
Harald Welte18fc4652011-08-17 14:14:17 +02001115 * \param[in] fname File name of the new log file
1116 * \returns Log target in case of success, NULL otherwise
1117 */
Harald Welteb72867f2020-09-26 21:45:16 +02001118struct log_target *log_target_create_file_stream(const char *fname)
Harald Welte3086c392010-08-25 19:10:50 +02001119{
1120 struct log_target *target;
1121
1122 target = log_target_create();
1123 if (!target)
1124 return NULL;
1125
Harald Welte28222962011-02-18 20:37:04 +01001126 target->type = LOG_TGT_TYPE_FILE;
Harald Welte3086c392010-08-25 19:10:50 +02001127 target->tgt_file.out = fopen(fname, "a");
Vadim Yanitskiyb89114b2020-09-09 04:51:04 +07001128 if (!target->tgt_file.out) {
1129 log_target_destroy(target);
Harald Welte3086c392010-08-25 19:10:50 +02001130 return NULL;
Vadim Yanitskiyb89114b2020-09-09 04:51:04 +07001131 }
Harald Welteb72867f2020-09-26 21:45:16 +02001132 target->output = _file_output_stream;
1133 target->tgt_file.fname = talloc_strdup(target, fname);
Harald Welte3086c392010-08-25 19:10:50 +02001134
Harald Welteb72867f2020-09-26 21:45:16 +02001135 return target;
1136}
1137
1138/*! switch from non-blocking/write-queue to blocking + buffered stream output
1139 * \param[in] target log target which we should switch
Pau Espin Pedrol843a84c2021-11-03 17:31:47 +01001140 * \return 0 on success; 1 if already switched before; negative on error
1141 * Must be called with mutex osmo_log_tgt_mutex held, see log_tgt_mutex_lock.
1142 */
Harald Welteb72867f2020-09-26 21:45:16 +02001143int log_target_file_switch_to_stream(struct log_target *target)
1144{
1145 struct osmo_wqueue *wq;
Harald Welteb72867f2020-09-26 21:45:16 +02001146
1147 if (!target)
1148 return -ENODEV;
1149
Harald Welteb72867f2020-09-26 21:45:16 +02001150 if (target->tgt_file.out) {
1151 /* target has already been switched over */
1152 return 1;
1153 }
1154
Harald Welteb72867f2020-09-26 21:45:16 +02001155 wq = target->tgt_file.wqueue;
1156 OSMO_ASSERT(wq);
1157
1158 /* re-open output as stream */
1159 if (target->type == LOG_TGT_TYPE_STDERR)
1160 target->tgt_file.out = stderr;
1161 else
1162 target->tgt_file.out = fopen(target->tgt_file.fname, "a");
1163 if (!target->tgt_file.out) {
Harald Welteb72867f2020-09-26 21:45:16 +02001164 return -EIO;
1165 }
1166
1167 /* synchronously write anything left in the queue */
1168 while (!llist_empty(&wq->msg_queue)) {
1169 struct msgb *msg = msgb_dequeue(&wq->msg_queue);
1170 fwrite(msgb_data(msg), msgb_length(msg), 1, target->tgt_file.out);
1171 msgb_free(msg);
1172 }
1173
1174 /* now that everything succeeded, we can finally close the old output fd */
1175 if (target->type == LOG_TGT_TYPE_FILE) {
1176 osmo_fd_unregister(&wq->bfd);
1177 close(wq->bfd.fd);
Pau Espin Pedrolfc376502023-03-14 14:32:46 +01001178 wq->bfd.fd = -1;
Harald Welteb72867f2020-09-26 21:45:16 +02001179 }
1180
1181 /* release the queue itself */
1182 talloc_free(wq);
1183 target->tgt_file.wqueue = NULL;
1184 target->output = _file_output_stream;
1185 target->raw_output = NULL;
1186
1187 return 0;
1188}
1189
1190/*! switch from blocking + buffered file output to non-blocking write-queue based output.
1191 * \param[in] target log target which we should switch
Pau Espin Pedrol843a84c2021-11-03 17:31:47 +01001192 * \return 0 on success; 1 if already switched before; negative on error
1193 * Must be called with mutex osmo_log_tgt_mutex held, see log_tgt_mutex_lock.
1194 */
Harald Welteb72867f2020-09-26 21:45:16 +02001195int log_target_file_switch_to_wqueue(struct log_target *target)
1196{
1197 struct osmo_wqueue *wq;
Harald Welteb72867f2020-09-26 21:45:16 +02001198 int rc;
1199
1200 if (!target)
1201 return -ENODEV;
1202
Harald Welteb72867f2020-09-26 21:45:16 +02001203 if (!target->tgt_file.out) {
1204 /* target has already been switched over */
1205 return 1;
1206 }
1207
Harald Welteb72867f2020-09-26 21:45:16 +02001208 /* we create a ~640kB sized talloc pool within the write-queue to ensure individual
1209 * log lines (stored as msgbs) will not put result in malloc() calls, and also to
1210 * reduce the OOM probability within logging, as the pool is already allocated */
1211 wq = talloc_pooled_object(target, struct osmo_wqueue, LOG_WQUEUE_LEN,
Harald Weltea0b57d02020-09-27 17:15:10 +02001212 LOG_WQUEUE_LEN*(sizeof(struct msgb)+MAX_LOG_SIZE));
Harald Welteb72867f2020-09-26 21:45:16 +02001213 if (!wq)
1214 return -ENOMEM;
1215 osmo_wqueue_init(wq, LOG_WQUEUE_LEN);
1216
1217 fflush(target->tgt_file.out);
1218 if (target->type == LOG_TGT_TYPE_FILE) {
1219 rc = open(target->tgt_file.fname, O_WRONLY|O_APPEND|O_CREAT|O_NONBLOCK, 0660);
1220 if (rc < 0) {
Harald Welteb72867f2020-09-26 21:45:16 +02001221 talloc_free(wq);
1222 return -errno;
1223 }
1224 } else {
1225 rc = STDERR_FILENO;
1226 }
1227 wq->bfd.fd = rc;
1228 wq->bfd.when = OSMO_FD_WRITE;
1229 wq->write_cb = _file_wq_write_cb;
1230
1231 rc = osmo_fd_register(&wq->bfd);
1232 if (rc < 0) {
1233 talloc_free(wq);
1234 return -EIO;
1235 }
1236 target->tgt_file.wqueue = wq;
Harald Weltea0b57d02020-09-27 17:15:10 +02001237 target->raw_output = _file_raw_output;
1238 target->output = NULL;
Harald Welte3086c392010-08-25 19:10:50 +02001239
Harald Welteb72867f2020-09-26 21:45:16 +02001240 /* now that everything succeeded, we can finally close the old output stream */
1241 if (target->type == LOG_TGT_TYPE_FILE)
1242 fclose(target->tgt_file.out);
1243 target->tgt_file.out = NULL;
1244
1245 return 0;
1246}
1247
1248/*! Create a new file-based log target using non-blocking write_queue
1249 * \param[in] fname File name of the new log file
1250 * \returns Log target in case of success, NULL otherwise
1251 */
1252struct log_target *log_target_create_file(const char *fname)
1253{
1254 struct log_target *target;
1255 struct osmo_wqueue *wq;
1256 int rc;
1257
1258 target = log_target_create();
1259 if (!target)
1260 return NULL;
1261
1262 target->type = LOG_TGT_TYPE_FILE;
1263 /* we create a ~640kB sized talloc pool within the write-queue to ensure individual
1264 * log lines (stored as msgbs) will not put result in malloc() calls, and also to
1265 * reduce the OOM probability within logging, as the pool is already allocated */
1266 wq = talloc_pooled_object(target, struct osmo_wqueue, LOG_WQUEUE_LEN,
Harald Weltea0b57d02020-09-27 17:15:10 +02001267 LOG_WQUEUE_LEN*(sizeof(struct msgb)+MAX_LOG_SIZE));
Harald Welteb72867f2020-09-26 21:45:16 +02001268 if (!wq) {
1269 log_target_destroy(target);
1270 return NULL;
1271 }
1272 osmo_wqueue_init(wq, LOG_WQUEUE_LEN);
1273 wq->bfd.fd = open(fname, O_WRONLY|O_APPEND|O_CREAT|O_NONBLOCK, 0660);
1274 if (wq->bfd.fd < 0) {
1275 talloc_free(wq);
1276 log_target_destroy(target);
1277 return NULL;
1278 }
1279 wq->bfd.when = OSMO_FD_WRITE;
1280 wq->write_cb = _file_wq_write_cb;
1281
1282 rc = osmo_fd_register(&wq->bfd);
1283 if (rc < 0) {
1284 talloc_free(wq);
1285 log_target_destroy(target);
1286 return NULL;
1287 }
1288
1289 target->tgt_file.wqueue = wq;
Harald Weltea0b57d02020-09-27 17:15:10 +02001290 target->raw_output = _file_raw_output;
Harald Welte3086c392010-08-25 19:10:50 +02001291 target->tgt_file.fname = talloc_strdup(target, fname);
1292
1293 return target;
1294}
Harald Welte44c0f632017-01-15 17:58:29 +01001295#endif
Harald Welte3086c392010-08-25 19:10:50 +02001296
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001297/*! Find a registered log target
Harald Welte18fc4652011-08-17 14:14:17 +02001298 * \param[in] type Log target type
1299 * \param[in] fname File name
1300 * \returns Log target (if found), NULL otherwise
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001301 * Must be called with mutex osmo_log_tgt_mutex held, see log_tgt_mutex_lock.
Harald Welte18fc4652011-08-17 14:14:17 +02001302 */
Harald Weltee6fb8902022-01-09 12:00:03 +01001303struct log_target *log_target_find(enum log_target_type type, const char *fname)
Harald Welte28222962011-02-18 20:37:04 +01001304{
1305 struct log_target *tgt;
1306
1307 llist_for_each_entry(tgt, &osmo_log_target_list, entry) {
1308 if (tgt->type != type)
1309 continue;
Maxc90f40a2018-01-11 10:52:28 +01001310 switch (tgt->type) {
1311 case LOG_TGT_TYPE_FILE:
Harald Welte28222962011-02-18 20:37:04 +01001312 if (!strcmp(fname, tgt->tgt_file.fname))
1313 return tgt;
Maxc90f40a2018-01-11 10:52:28 +01001314 break;
1315 case LOG_TGT_TYPE_GSMTAP:
1316 if (!strcmp(fname, tgt->tgt_gsmtap.hostname))
1317 return tgt;
1318 break;
1319 default:
Harald Welte28222962011-02-18 20:37:04 +01001320 return tgt;
Maxc90f40a2018-01-11 10:52:28 +01001321 }
Harald Welte28222962011-02-18 20:37:04 +01001322 }
1323 return NULL;
1324}
1325
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001326/*! Unregister, close and delete a log target
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +07001327 * \param[in] target log target to unregister, close and delete */
Harald Welte3086c392010-08-25 19:10:50 +02001328void log_target_destroy(struct log_target *target)
1329{
Harald Welte3086c392010-08-25 19:10:50 +02001330 /* just in case, to make sure we don't have any references */
1331 log_del_target(target);
1332
Harald Welte44c0f632017-01-15 17:58:29 +01001333#if (!EMBEDDED)
Harald Welteb72867f2020-09-26 21:45:16 +02001334 struct osmo_wqueue *wq;
Vadim Yanitskiy744236b2020-09-09 04:42:22 +07001335 switch (target->type) {
1336 case LOG_TGT_TYPE_FILE:
Harald Welteb72867f2020-09-26 21:45:16 +02001337 case LOG_TGT_TYPE_STDERR:
1338 if (target->tgt_file.out) {
1339 if (target->type == LOG_TGT_TYPE_FILE)
1340 fclose(target->tgt_file.out);
1341 target->tgt_file.out = NULL;
1342 }
1343 wq = target->tgt_file.wqueue;
1344 if (wq) {
1345 if (wq->bfd.fd >= 0) {
Pau Espin Pedrolfc376502023-03-14 14:32:46 +01001346 osmo_fd_unregister(&wq->bfd);
Harald Welteb72867f2020-09-26 21:45:16 +02001347 if (target->type == LOG_TGT_TYPE_FILE)
1348 close(wq->bfd.fd);
1349 wq->bfd.fd = -1;
1350 }
Harald Welteb72867f2020-09-26 21:45:16 +02001351 osmo_wqueue_clear(wq);
1352 talloc_free(wq);
1353 target->tgt_file.wqueue = NULL;
1354 }
1355 talloc_free((void *)target->tgt_file.fname);
1356 target->tgt_file.fname = NULL;
Vadim Yanitskiy744236b2020-09-09 04:42:22 +07001357 break;
Vadim Yanitskiy2f4186a2021-12-29 21:58:19 +06001358 case LOG_TGT_TYPE_GSMTAP:
1359 gsmtap_source_free(target->tgt_gsmtap.gsmtap_inst);
1360 break;
Vadim Yanitskiy04f42712020-09-09 04:47:25 +07001361#ifdef HAVE_SYSLOG_H
1362 case LOG_TGT_TYPE_SYSLOG:
1363 closelog();
1364 break;
1365#endif /* HAVE_SYSLOG_H */
Vadim Yanitskiy744236b2020-09-09 04:42:22 +07001366 default:
1367 /* make GCC happy */
1368 break;
Harald Welte3086c392010-08-25 19:10:50 +02001369 }
Harald Welte44c0f632017-01-15 17:58:29 +01001370#endif
Harald Welte3086c392010-08-25 19:10:50 +02001371
1372 talloc_free(target);
1373}
1374
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001375/*! close and re-open a log file (for log file rotation)
Harald Welte2d2e2cc2016-04-25 12:11:20 +02001376 * \param[in] target log target to re-open
1377 * \returns 0 in case of success; negative otherwise */
Harald Welte3086c392010-08-25 19:10:50 +02001378int log_target_file_reopen(struct log_target *target)
1379{
Harald Welteb72867f2020-09-26 21:45:16 +02001380 struct osmo_wqueue *wq;
1381 int rc;
Harald Welte3086c392010-08-25 19:10:50 +02001382
Harald Welteb72867f2020-09-26 21:45:16 +02001383 OSMO_ASSERT(target->type == LOG_TGT_TYPE_FILE || target->type == LOG_TGT_TYPE_STDERR);
1384 OSMO_ASSERT(target->tgt_file.out || target->tgt_file.wqueue);
Harald Welte3086c392010-08-25 19:10:50 +02001385
Harald Welteb72867f2020-09-26 21:45:16 +02001386 if (target->tgt_file.out) {
1387 fclose(target->tgt_file.out);
1388 target->tgt_file.out = fopen(target->tgt_file.fname, "a");
1389 if (!target->tgt_file.out)
1390 return -errno;
1391 } else {
1392 wq = target->tgt_file.wqueue;
Harald Welteb72867f2020-09-26 21:45:16 +02001393 if (wq->bfd.fd >= 0) {
Pau Espin Pedrolfc376502023-03-14 14:32:46 +01001394 osmo_fd_unregister(&wq->bfd);
Harald Welteb72867f2020-09-26 21:45:16 +02001395 close(wq->bfd.fd);
1396 wq->bfd.fd = -1;
1397 }
1398
1399 rc = open(target->tgt_file.fname, O_WRONLY|O_APPEND|O_CREAT|O_NONBLOCK, 0660);
1400 if (rc < 0)
1401 return -errno;
1402 wq->bfd.fd = rc;
1403 rc = osmo_fd_register(&wq->bfd);
1404 if (rc < 0)
1405 return rc;
1406 }
Harald Welte3086c392010-08-25 19:10:50 +02001407
1408 return 0;
1409}
1410
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001411/*! close and re-open all log files (for log file rotation)
Harald Welte2d2e2cc2016-04-25 12:11:20 +02001412 * \returns 0 in case of success; negative otherwise */
Harald Welte4de854d2013-03-18 19:01:40 +01001413int log_targets_reopen(void)
1414{
1415 struct log_target *tar;
1416 int rc = 0;
1417
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001418 log_tgt_mutex_lock();
1419
Harald Welte4de854d2013-03-18 19:01:40 +01001420 llist_for_each_entry(tar, &osmo_log_target_list, entry) {
1421 switch (tar->type) {
1422 case LOG_TGT_TYPE_FILE:
1423 if (log_target_file_reopen(tar) < 0)
1424 rc = -1;
1425 break;
1426 default:
1427 break;
1428 }
1429 }
1430
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001431 log_tgt_mutex_unlock();
1432
Harald Welte4de854d2013-03-18 19:01:40 +01001433 return rc;
1434}
1435
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001436/*! Initialize the Osmocom logging core
Max72dfd432018-12-04 11:24:18 +01001437 * \param[in] inf Information regarding logging categories, could be NULL
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +07001438 * \param[in] ctx talloc context for logging allocations
Harald Welte18fc4652011-08-17 14:14:17 +02001439 * \returns 0 in case of success, negative in case of error
Max72dfd432018-12-04 11:24:18 +01001440 *
1441 * If inf is NULL then only library-internal categories are initialized.
Harald Welte18fc4652011-08-17 14:14:17 +02001442 */
Harald Welteb43bc042011-06-27 10:29:17 +02001443int log_init(const struct log_info *inf, void *ctx)
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001444{
Harald Welteb43bc042011-06-27 10:29:17 +02001445 int i;
Philipp Maierdcad1c52020-03-25 11:25:59 +01001446 struct log_info_cat *cat_ptr;
Harald Welteb43bc042011-06-27 10:29:17 +02001447
Philipp Maierdc02c062020-05-12 17:51:25 +02001448 /* Ensure that log_init is not called multiple times */
1449 OSMO_ASSERT(tall_log_ctx == NULL)
1450
Harald Welteb43bc042011-06-27 10:29:17 +02001451 tall_log_ctx = talloc_named_const(ctx, 1, "logging");
1452 if (!tall_log_ctx)
1453 return -ENOMEM;
1454
1455 osmo_log_info = talloc_zero(tall_log_ctx, struct log_info);
1456 if (!osmo_log_info)
1457 return -ENOMEM;
1458
Max72dfd432018-12-04 11:24:18 +01001459 osmo_log_info->num_cat = ARRAY_SIZE(internal_cat);
1460
1461 if (inf) {
1462 osmo_log_info->filter_fn = inf->filter_fn;
1463 osmo_log_info->num_cat_user = inf->num_cat;
1464 osmo_log_info->num_cat += inf->num_cat;
1465 }
Harald Welteb43bc042011-06-27 10:29:17 +02001466
Philipp Maierdcad1c52020-03-25 11:25:59 +01001467 cat_ptr = talloc_zero_array(osmo_log_info, struct log_info_cat,
1468 osmo_log_info->num_cat);
1469 if (!cat_ptr) {
Harald Welteb43bc042011-06-27 10:29:17 +02001470 talloc_free(osmo_log_info);
1471 osmo_log_info = NULL;
1472 return -ENOMEM;
1473 }
1474
Philipp Maierdcad1c52020-03-25 11:25:59 +01001475 /* copy over the user part and sanitize loglevel */
1476 if (inf) {
Max72dfd432018-12-04 11:24:18 +01001477 for (i = 0; i < inf->num_cat; i++) {
Philipp Maierdcad1c52020-03-25 11:25:59 +01001478 memcpy(&cat_ptr[i], &inf->cat[i],
1479 sizeof(struct log_info_cat));
1480
1481 /* Make sure that the loglevel is set to NOTICE in case
1482 * no loglevel has been preset. */
1483 if (!cat_ptr[i].loglevel) {
1484 cat_ptr[i].loglevel = LOGL_NOTICE;
1485 }
Max72dfd432018-12-04 11:24:18 +01001486 }
Harald Welteb43bc042011-06-27 10:29:17 +02001487 }
1488
1489 /* copy over the library part */
Harald Welte9fe16522011-06-27 14:00:03 +02001490 for (i = 0; i < ARRAY_SIZE(internal_cat); i++) {
Harald Weltece9fec32011-06-27 14:19:16 +02001491 unsigned int cn = osmo_log_info->num_cat_user + i;
Philipp Maierdcad1c52020-03-25 11:25:59 +01001492 memcpy(&cat_ptr[cn], &internal_cat[i], sizeof(struct log_info_cat));
Harald Welte9fe16522011-06-27 14:00:03 +02001493 }
1494
Philipp Maierdcad1c52020-03-25 11:25:59 +01001495 osmo_log_info->cat = cat_ptr;
1496
Harald Welte9fe16522011-06-27 14:00:03 +02001497 return 0;
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001498}
Harald Welte18fc4652011-08-17 14:14:17 +02001499
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001500/* De-initialize the Osmocom logging core
Harald Welte69e6c3c2016-04-20 10:41:27 +02001501 * This function destroys all targets and releases associated memory */
1502void log_fini(void)
1503{
1504 struct log_target *tar, *tar2;
1505
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001506 log_tgt_mutex_lock();
1507
Harald Welte69e6c3c2016-04-20 10:41:27 +02001508 llist_for_each_entry_safe(tar, tar2, &osmo_log_target_list, entry)
1509 log_target_destroy(tar);
1510
1511 talloc_free(osmo_log_info);
1512 osmo_log_info = NULL;
1513 talloc_free(tall_log_ctx);
1514 tall_log_ctx = NULL;
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001515
1516 log_tgt_mutex_unlock();
Harald Welte69e6c3c2016-04-20 10:41:27 +02001517}
1518
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001519/*! Check whether a log entry will be generated.
Jacob Erlbeckde6dd722015-11-17 11:52:24 +01001520 * \returns != 0 if a log entry might get generated by at least one target */
1521int log_check_level(int subsys, unsigned int level)
1522{
1523 struct log_target *tar;
1524
Max68bf16a2018-01-10 17:00:43 +01001525 assert_loginfo(__func__);
Harald Welte18a7d812017-03-16 23:54:55 +01001526
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +01001527 subsys = map_subsys(subsys);
Jacob Erlbeckde6dd722015-11-17 11:52:24 +01001528
1529 /* TODO: The following could/should be cached (update on config) */
1530
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001531 log_tgt_mutex_lock();
1532
Jacob Erlbeckde6dd722015-11-17 11:52:24 +01001533 llist_for_each_entry(tar, &osmo_log_target_list, entry) {
Maxc65c5b42017-03-15 13:20:23 +01001534 if (!should_log_to_target(tar, subsys, level))
Jacob Erlbeckde6dd722015-11-17 11:52:24 +01001535 continue;
1536
1537 /* This might get logged (ignoring filters) */
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001538 log_tgt_mutex_unlock();
Jacob Erlbeckde6dd722015-11-17 11:52:24 +01001539 return 1;
1540 }
1541
1542 /* We are sure, that this will not be logged. */
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001543 log_tgt_mutex_unlock();
Jacob Erlbeckde6dd722015-11-17 11:52:24 +01001544 return 0;
1545}
1546
Sylvain Munautdca7d2c2012-04-18 21:53:23 +02001547/*! @} */