blob: 00d75c3bda440953ec2342e4de37758982d5aa55 [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 *
20 * You should have received a copy of the GNU General Public License along
21 * with this program; if not, write to the Free Software Foundation, Inc.,
22 * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
23 *
24 */
25
Harald Weltef01b2382017-10-16 13:55:34 +020026/*! \addtogroup logging
Harald Welte18fc4652011-08-17 14:14:17 +020027 * @{
Neels Hofmeyr87e45502017-06-20 00:17:59 +020028 * libosmocore Logging sub-system
Neels Hofmeyr17518fe2017-06-20 04:35:06 +020029 *
30 * \file logging.c */
Harald Welte18fc4652011-08-17 14:14:17 +020031
Harald Welte01fd5cb2010-03-26 23:51:31 +080032#include "../config.h"
33
Harald Welte4a2bb9e2010-03-26 09:33:40 +080034#include <stdarg.h>
35#include <stdlib.h>
36#include <stdio.h>
37#include <string.h>
Harald Welteb72867f2020-09-26 21:45:16 +020038#include <unistd.h>
Harald Welte01fd5cb2010-03-26 23:51:31 +080039
40#ifdef HAVE_STRINGS_H
Harald Welte4a2bb9e2010-03-26 09:33:40 +080041#include <strings.h>
Harald Welte01fd5cb2010-03-26 23:51:31 +080042#endif
Vadim Yanitskiy04f42712020-09-09 04:47:25 +070043
44#ifdef HAVE_SYSLOG_H
45#include <syslog.h>
46#endif
47
Harald Welte433005c2020-09-26 11:51:32 +020048#ifdef HAVE_SYSTEMTAP
49/* include the generated probes header and put markers in code */
50#include "probes.h"
51#define TRACE(probe) probe
52#define TRACE_ENABLED(probe) probe ## _ENABLED()
53#else
54/* Wrap the probe to allow it to be removed when no systemtap available */
55#define TRACE(probe)
56#define TRACE_ENABLED(probe) (0)
57#endif /* HAVE_SYSTEMTAP */
58
Harald Welte4a2bb9e2010-03-26 09:33:40 +080059#include <time.h>
Jacob Erlbeckb61b2ca2015-03-17 10:21:15 +010060#include <sys/time.h>
Harald Welteb72867f2020-09-26 21:45:16 +020061#include <sys/types.h>
62#include <sys/stat.h>
63#include <fcntl.h>
Harald Welte4a2bb9e2010-03-26 09:33:40 +080064#include <errno.h>
Pau Espin Pedrold12f6982019-09-17 18:38:58 +020065#include <pthread.h>
Harald Welte4a2bb9e2010-03-26 09:33:40 +080066
Pablo Neira Ayuso83419342011-03-22 16:36:13 +010067#include <osmocom/core/talloc.h>
68#include <osmocom/core/utils.h>
69#include <osmocom/core/logging.h>
Neels Hofmeyr8e2f7e82016-09-22 03:58:13 +020070#include <osmocom/core/timer.h>
Pau Espin Pedrol662d10d2021-02-18 18:19:23 +010071#include <osmocom/core/thread.h>
Harald Welteb72867f2020-09-26 21:45:16 +020072#include <osmocom/core/select.h>
73#include <osmocom/core/write_queue.h>
Harald Welte4a2bb9e2010-03-26 09:33:40 +080074
Pablo Neira Ayuso04139f12011-03-09 13:05:08 +010075#include <osmocom/vty/logging.h> /* for LOGGING_STR. */
76
Harald Weltea8b1b212020-09-27 17:21:07 +020077/* maximum length of the log string of a single log event (typically line) */
78#define MAX_LOG_SIZE 4096
79
Harald Welteb72867f2020-09-26 21:45:16 +020080/* maximum number of log statements we queue in file/stderr target write queue */
Harald Weltea0b57d02020-09-27 17:15:10 +020081#define LOG_WQUEUE_LEN 156
Harald Welteb72867f2020-09-26 21:45:16 +020082
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +010083osmo_static_assert(_LOG_CTX_COUNT <= ARRAY_SIZE(((struct log_context*)NULL)->ctx),
Neels Hofmeyr812ba6d2017-02-17 16:35:27 +010084 enum_logging_ctx_items_fit_in_struct_log_context);
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +010085osmo_static_assert(_LOG_FLT_COUNT <= ARRAY_SIZE(((struct log_target*)NULL)->filter_data),
Neels Hofmeyr812ba6d2017-02-17 16:35:27 +010086 enum_logging_filters_fit_in_log_target_filter_data);
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +010087osmo_static_assert(_LOG_FLT_COUNT <= 8*sizeof(((struct log_target*)NULL)->filter_map),
Neels Hofmeyr812ba6d2017-02-17 16:35:27 +010088 enum_logging_filters_fit_in_log_target_filter_map);
89
Harald Welteb43bc042011-06-27 10:29:17 +020090struct log_info *osmo_log_info;
Harald Welte4a2bb9e2010-03-26 09:33:40 +080091
Harald Welte3ae27582010-03-26 21:24:24 +080092static struct log_context log_context;
Neels Hofmeyrba0762d2018-09-10 13:56:03 +020093void *tall_log_ctx = NULL;
Harald Welte28222962011-02-18 20:37:04 +010094LLIST_HEAD(osmo_log_target_list);
Harald Welte4a2bb9e2010-03-26 09:33:40 +080095
Pau Espin Pedrol662d10d2021-02-18 18:19:23 +010096static __thread long int logging_tid;
97
Pau Espin Pedrold12f6982019-09-17 18:38:58 +020098#if (!EMBEDDED)
99/*! This mutex must be held while using osmo_log_target_list or any of its
100 log_targets in a multithread program. Prevents race conditions between threads
101 like producing unordered timestamps or VTY deleting a target while another
102 thread is writing to it */
103static pthread_mutex_t osmo_log_tgt_mutex;
104static bool osmo_log_tgt_mutex_on = false;
105
106/*! Enable multithread support (mutex) in libosmocore logging system.
107 * Must be called by processes willing to use logging subsystem from several
108 * threads. Once enabled, it's not possible to disable it again.
109 */
110void log_enable_multithread(void) {
111 if (osmo_log_tgt_mutex_on)
112 return;
113 pthread_mutex_init(&osmo_log_tgt_mutex, NULL);
114 osmo_log_tgt_mutex_on = true;
115}
116
117/*! Acquire the osmo_log_tgt_mutex. Don't use this function directly, always use
118 * macro log_tgt_mutex_lock() instead.
119 */
120void log_tgt_mutex_lock_impl(void) {
121 /* These lines are useful to debug scenarios where there's only 1 thread
122 and a double lock appears, for instance during startup and some
123 unlock() missing somewhere:
124 if (osmo_log_tgt_mutex_on && pthread_mutex_trylock(&osmo_log_tgt_mutex) != 0)
125 osmo_panic("acquiring already locked mutex!\n");
126 return;
127 */
128
129 if (osmo_log_tgt_mutex_on)
130 pthread_mutex_lock(&osmo_log_tgt_mutex);
131}
132
133/*! Release the osmo_log_tgt_mutex. Don't use this function directly, always use
134 * macro log_tgt_mutex_unlock() instead.
135 */
136void log_tgt_mutex_unlock_impl(void) {
137 if (osmo_log_tgt_mutex_on)
138 pthread_mutex_unlock(&osmo_log_tgt_mutex);
139}
140
141#else /* if (!EMBEDDED) */
142#pragma message ("logging multithread support disabled in embedded build")
143void log_enable_multithread(void) {}
144void log_tgt_mutex_lock_impl(void) {}
145void log_tgt_mutex_unlock_impl(void) {}
146#endif /* if (!EMBEDDED) */
147
Neels Hofmeyr098038a2018-09-11 23:49:13 +0200148const struct value_string loglevel_strs[] = {
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800149 { LOGL_DEBUG, "DEBUG" },
150 { LOGL_INFO, "INFO" },
151 { LOGL_NOTICE, "NOTICE" },
152 { LOGL_ERROR, "ERROR" },
153 { LOGL_FATAL, "FATAL" },
154 { 0, NULL },
155};
156
Harald Welte4c0e1a12020-12-07 22:03:09 +0100157/* 256 color palette see https://en.wikipedia.org/wiki/ANSI_escape_code#8-bit */
Harald Welteb43bc042011-06-27 10:29:17 +0200158#define INT2IDX(x) (-1*(x)-1)
159static const struct log_info_cat internal_cat[OSMO_NUM_DLIB] = {
160 [INT2IDX(DLGLOBAL)] = { /* -1 becomes 0 */
161 .name = "DLGLOBAL",
162 .description = "Library-internal global log family",
163 .loglevel = LOGL_NOTICE,
164 .enabled = 1,
165 },
root8a996b42011-09-26 11:22:21 +0200166 [INT2IDX(DLLAPD)] = { /* -2 becomes 1 */
167 .name = "DLLAPD",
168 .description = "LAPD in libosmogsm",
Harald Welte1f0b8c22011-06-27 10:51:37 +0200169 .loglevel = LOGL_NOTICE,
170 .enabled = 1,
Pau Espin Pedrol1573add2021-10-14 18:13:48 +0200171 .color = "\033[38;5;12m",
Harald Welte1f0b8c22011-06-27 10:51:37 +0200172 },
Harald Welte892e6212011-07-19 14:31:44 +0200173 [INT2IDX(DLINP)] = {
Harald Welte087e1132011-07-29 11:43:39 +0200174 .name = "DLINP",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200175 .description = "A-bis Intput Subsystem",
176 .loglevel = LOGL_NOTICE,
177 .enabled = 1,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100178 .color = "\033[38;5;23m",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200179 },
Harald Welte892e6212011-07-19 14:31:44 +0200180 [INT2IDX(DLMUX)] = {
Harald Welte087e1132011-07-29 11:43:39 +0200181 .name = "DLMUX",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200182 .description = "A-bis B-Subchannel TRAU Frame Multiplex",
183 .loglevel = LOGL_NOTICE,
184 .enabled = 1,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100185 .color = "\033[38;5;25m",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200186 },
Harald Welte892e6212011-07-19 14:31:44 +0200187 [INT2IDX(DLMI)] = {
Harald Welte087e1132011-07-29 11:43:39 +0200188 .name = "DLMI",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200189 .description = "A-bis Input Driver for Signalling",
190 .enabled = 0, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100191 .color = "\033[38;5;27m",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200192 },
Harald Welte892e6212011-07-19 14:31:44 +0200193 [INT2IDX(DLMIB)] = {
Harald Welte087e1132011-07-29 11:43:39 +0200194 .name = "DLMIB",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200195 .description = "A-bis Input Driver for B-Channels (voice)",
196 .enabled = 0, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100197 .color = "\033[38;5;29m",
Pablo Neira Ayuso199f3772011-07-07 19:46:38 +0200198 },
Andreas Eversbergc626da92011-10-28 03:53:50 +0200199 [INT2IDX(DLSMS)] = {
200 .name = "DLSMS",
201 .description = "Layer3 Short Message Service (SMS)",
202 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100203 .color = "\033[38;5;31m",
Andreas Eversbergc626da92011-10-28 03:53:50 +0200204 },
Harald Welte7fd0c832014-08-20 19:58:13 +0200205 [INT2IDX(DLCTRL)] = {
206 .name = "DLCTRL",
207 .description = "Control Interface",
208 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100209 .color = "\033[38;5;33m",
Harald Welte7fd0c832014-08-20 19:58:13 +0200210 },
Holger Hans Peter Freythera5dc19d2014-12-04 14:35:21 +0100211 [INT2IDX(DLGTP)] = {
212 .name = "DLGTP",
213 .description = "GPRS GTP library",
214 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100215 .color = "\033[38;5;35m",
Holger Hans Peter Freythera5dc19d2014-12-04 14:35:21 +0100216 },
Jacob Erlbeck79125ec2015-11-02 15:17:50 +0100217 [INT2IDX(DLSTATS)] = {
218 .name = "DLSTATS",
219 .description = "Statistics messages and logging",
220 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100221 .color = "\033[38;5;37m",
Jacob Erlbeck79125ec2015-11-02 15:17:50 +0100222 },
Neels Hofmeyr9795cf12016-12-10 17:01:06 +0100223 [INT2IDX(DLGSUP)] = {
224 .name = "DLGSUP",
225 .description = "Generic Subscriber Update Protocol",
226 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100227 .color = "\033[38;5;39m",
Neels Hofmeyr9795cf12016-12-10 17:01:06 +0100228 },
Harald Weltec0f00072016-04-27 18:32:35 +0200229 [INT2IDX(DLOAP)] = {
230 .name = "DLOAP",
231 .description = "Osmocom Authentication Protocol",
232 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100233 .color = "\033[38;5;41m",
Harald Weltec0f00072016-04-27 18:32:35 +0200234 },
Harald Welte059c4042017-04-03 22:20:49 +0200235 [INT2IDX(DLSS7)] = {
236 .name = "DLSS7",
237 .description = "libosmo-sigtran Signalling System 7",
238 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100239 .color = "\033[38;5;43m",
Harald Welte059c4042017-04-03 22:20:49 +0200240 },
241 [INT2IDX(DLSCCP)] = {
242 .name = "DLSCCP",
243 .description = "libosmo-sigtran SCCP Implementation",
244 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100245 .color = "\033[38;5;45m",
Harald Welte059c4042017-04-03 22:20:49 +0200246 },
247 [INT2IDX(DLSUA)] = {
248 .name = "DLSUA",
249 .description = "libosmo-sigtran SCCP User Adaptation",
250 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100251 .color = "\033[38;5;47m",
Harald Welte059c4042017-04-03 22:20:49 +0200252 },
253 [INT2IDX(DLM3UA)] = {
254 .name = "DLM3UA",
255 .description = "libosmo-sigtran MTP3 User Adaptation",
256 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100257 .color = "\033[38;5;49m",
Harald Welte059c4042017-04-03 22:20:49 +0200258 },
Neels Hofmeyra7ccf612017-07-11 18:43:09 +0200259 [INT2IDX(DLMGCP)] = {
260 .name = "DLMGCP",
261 .description = "libosmo-mgcp Media Gateway Control Protocol",
262 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100263 .color = "\033[38;5;51m",
Neels Hofmeyra7ccf612017-07-11 18:43:09 +0200264 },
Pau Espin Pedrol8fd85572018-02-27 19:43:10 +0100265 [INT2IDX(DLJIBUF)] = {
266 .name = "DLJIBUF",
267 .description = "libosmo-netif Jitter Buffer",
268 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100269 .color = "\033[38;5;53m",
Pau Espin Pedrol8fd85572018-02-27 19:43:10 +0100270 },
Max450f5ac2019-02-14 19:12:03 +0100271 [INT2IDX(DLRSPRO)] = {
272 .name = "DLRSPRO",
273 .description = "Remote SIM protocol",
274 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100275 .color = "\033[38;5;55m",
Max450f5ac2019-02-14 19:12:03 +0100276 },
Alexander Couzens6a161492020-07-12 13:45:50 +0200277 [INT2IDX(DLNS)] = {
278 .name = "DLNS",
279 .description = "GPRS NS layer",
280 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100281 .color = "\033[38;5;57m",
Alexander Couzens6a161492020-07-12 13:45:50 +0200282 },
Harald Weltefde19ed2020-12-07 21:43:51 +0100283 [INT2IDX(DLBSSGP)] = {
284 .name = "DLBSSGP",
285 .description = "GPRS BSSGP layer",
286 .enabled = 1, .loglevel = LOGL_NOTICE,
Harald Welte4c0e1a12020-12-07 22:03:09 +0100287 .color = "\033[38;5;59m",
Harald Weltefde19ed2020-12-07 21:43:51 +0100288 },
Alexander Couzens6cf65d92021-01-18 17:55:35 +0100289 [INT2IDX(DLNSDATA)] = {
290 .name = "DLNSDATA",
291 .description = "GPRS NS layer data PDU",
292 .enabled = 1, .loglevel = LOGL_NOTICE,
293 .color = "\033[38;5;61m",
294 },
295 [INT2IDX(DLNSSIGNAL)] = {
296 .name = "DLNSSIGNAL",
297 .description = "GPRS NS layer signal PDU",
298 .enabled = 1, .loglevel = LOGL_NOTICE,
299 .color = "\033[38;5;63m",
300 },
Harald Welteb43bc042011-06-27 10:29:17 +0200301};
302
Neels Hofmeyrba0762d2018-09-10 13:56:03 +0200303void assert_loginfo(const char *src)
Harald Welte18a7d812017-03-16 23:54:55 +0100304{
305 if (!osmo_log_info) {
306 fprintf(stderr, "ERROR: osmo_log_info == NULL! "
Max68bf16a2018-01-10 17:00:43 +0100307 "You must call log_init() before using logging in %s()!\n", src);
Harald Welte18a7d812017-03-16 23:54:55 +0100308 OSMO_ASSERT(osmo_log_info);
309 }
310}
311
Harald Welteb43bc042011-06-27 10:29:17 +0200312/* special magic for negative (library-internal) log subsystem numbers */
313static int subsys_lib2index(int subsys)
314{
315 return (subsys * -1) + (osmo_log_info->num_cat_user-1);
316}
317
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200318/*! Parse a human-readable log level into a numeric value
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +0700319 * \param[in] lvl zero-terminated string containing log level name
Harald Welte2d2e2cc2016-04-25 12:11:20 +0200320 * \returns numeric log level
321 */
Harald Welte3ae27582010-03-26 21:24:24 +0800322int log_parse_level(const char *lvl)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800323{
324 return get_string_value(loglevel_strs, lvl);
325}
326
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200327/*! convert a numeric log level into human-readable string
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +0700328 * \param[in] lvl numeric log level
Harald Welte2d2e2cc2016-04-25 12:11:20 +0200329 * \returns zero-terminated string (log level name)
330 */
Harald Welte9ac22252010-05-11 11:19:40 +0200331const char *log_level_str(unsigned int lvl)
332{
333 return get_value_string(loglevel_strs, lvl);
334}
335
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200336/*! parse a human-readable log category into numeric form
Harald Welte18fc4652011-08-17 14:14:17 +0200337 * \param[in] category human-readable log category name
338 * \returns numeric category value, or -EINVAL otherwise
339 */
Harald Welte3ae27582010-03-26 21:24:24 +0800340int log_parse_category(const char *category)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800341{
342 int i;
343
Max68bf16a2018-01-10 17:00:43 +0100344 assert_loginfo(__func__);
Harald Welte18a7d812017-03-16 23:54:55 +0100345
Harald Welte4ebdf742010-05-19 19:54:00 +0200346 for (i = 0; i < osmo_log_info->num_cat; ++i) {
Harald Welteb43bc042011-06-27 10:29:17 +0200347 if (osmo_log_info->cat[i].name == NULL)
348 continue;
Harald Welte4ebdf742010-05-19 19:54:00 +0200349 if (!strcasecmp(osmo_log_info->cat[i].name+1, category))
Harald Weltefaadfe22010-03-26 21:05:43 +0800350 return i;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800351 }
352
353 return -EINVAL;
354}
355
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200356/*! parse the log category mask
Harald Welte18fc4652011-08-17 14:14:17 +0200357 * \param[in] target log target to be configured
358 * \param[in] _mask log category mask string
359 *
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800360 * The format can be this: category1:category2:category3
361 * or category1,2:category2,3:...
362 */
Harald Welte3ae27582010-03-26 21:24:24 +0800363void log_parse_category_mask(struct log_target* target, const char *_mask)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800364{
365 int i = 0;
366 char *mask = strdup(_mask);
367 char *category_token = NULL;
368
Max68bf16a2018-01-10 17:00:43 +0100369 assert_loginfo(__func__);
Harald Welte18a7d812017-03-16 23:54:55 +0100370
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800371 /* Disable everything to enable it afterwards */
Harald Welteb43bc042011-06-27 10:29:17 +0200372 for (i = 0; i < osmo_log_info->num_cat; ++i)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800373 target->categories[i].enabled = 0;
374
375 category_token = strtok(mask, ":");
Neels Hofmeyrda1b20c2016-04-14 15:12:16 +0200376 OSMO_ASSERT(category_token);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800377 do {
Harald Welte4ebdf742010-05-19 19:54:00 +0200378 for (i = 0; i < osmo_log_info->num_cat; ++i) {
Nico Golde0262d3f2012-09-21 17:44:58 +0200379 size_t length, cat_length;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800380 char* colon = strstr(category_token, ",");
Nico Golde0262d3f2012-09-21 17:44:58 +0200381
382 if (!osmo_log_info->cat[i].name)
383 continue;
384
385 length = strlen(category_token);
386 cat_length = strlen(osmo_log_info->cat[i].name);
Pablo Neira Ayuso300e78d2011-08-11 13:24:18 +0200387
388 /* Use longest length not to match subocurrences. */
389 if (cat_length > length)
390 length = cat_length;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800391
392 if (colon)
393 length = colon - category_token;
394
Harald Welte4ebdf742010-05-19 19:54:00 +0200395 if (strncasecmp(osmo_log_info->cat[i].name,
396 category_token, length) == 0) {
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800397 int level = 0;
398
399 if (colon)
400 level = atoi(colon+1);
401
Harald Weltefaadfe22010-03-26 21:05:43 +0800402 target->categories[i].enabled = 1;
403 target->categories[i].loglevel = level;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800404 }
405 }
406 } while ((category_token = strtok(NULL, ":")));
407
408 free(mask);
409}
410
411static const char* color(int subsys)
412{
Harald Welte4ebdf742010-05-19 19:54:00 +0200413 if (subsys < osmo_log_info->num_cat)
414 return osmo_log_info->cat[subsys].color;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800415
Harald Welted788f662010-03-26 09:45:03 +0800416 return NULL;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800417}
418
Neels Hofmeyrf3fa3692018-01-16 02:56:01 +0100419static const struct value_string level_colors[] = {
Neels Hofmeyrf2644ae2019-11-20 04:00:29 +0100420 { LOGL_DEBUG, OSMO_LOGCOLOR_BLUE },
421 { LOGL_INFO, OSMO_LOGCOLOR_GREEN },
422 { LOGL_NOTICE, OSMO_LOGCOLOR_YELLOW },
423 { LOGL_ERROR, OSMO_LOGCOLOR_RED },
424 { LOGL_FATAL, OSMO_LOGCOLOR_RED },
Neels Hofmeyrf3fa3692018-01-16 02:56:01 +0100425 { 0, NULL }
426};
427
428static const char *level_color(int level)
429{
430 const char *c = get_value_string_or_null(level_colors, level);
431 if (!c)
432 return get_value_string(level_colors, LOGL_FATAL);
433 return c;
434}
435
Harald Welteaa00f992016-12-02 15:30:02 +0100436const char* log_category_name(int subsys)
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100437{
438 if (subsys < osmo_log_info->num_cat)
439 return osmo_log_info->cat[subsys].name;
440
441 return NULL;
442}
443
Neels Hofmeyr0e2a9432018-01-16 02:49:48 +0100444static const char *const_basename(const char *path)
445{
446 const char *bn = strrchr(path, '/');
447 if (!bn || !bn[1])
448 return path;
449 return bn + 1;
450}
451
Harald Weltea0b57d02020-09-27 17:15:10 +0200452/*! main output formatting function for log lines.
453 * \param[out] buf caller-allocated output buffer for the generated string
454 * \param[in] buf_len number of bytes available in buf
455 * \param[in] target log target for which the string is to be formatted
456 * \param[in] subsys Log sub-system number
457 * \param[in] level Log level
458 * \param[in] file name of source code file generating the log
459 * \param[in] line line source code line number within 'file' generating the log
460 * \param[in] cont is this a continuation (true) or not (false)
461 * \param[in] format format string
462 * \param[in] ap variable argument list for format
463 * \returns number of bytes written to out */
464static int _output_buf(char *buf, int buf_len, struct log_target *target, unsigned int subsys,
465 unsigned int level, const char *file, int line, int cont,
466 const char *format, va_list ap)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800467{
Harald Weltea0b57d02020-09-27 17:15:10 +0200468 int ret, len = 0, offset = 0, rem = buf_len;
Neels Hofmeyrf3fa3692018-01-16 02:56:01 +0100469 const char *c_subsys = NULL;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800470
471 /* are we using color */
472 if (target->use_color) {
Neels Hofmeyrf3fa3692018-01-16 02:56:01 +0100473 c_subsys = color(subsys);
474 if (c_subsys) {
Neels Hofmeyr5e518b52018-01-17 13:20:02 +0100475 ret = snprintf(buf + offset, rem, "%s", c_subsys);
Pablo Neira Ayuso7503fb82011-05-03 22:32:43 +0200476 if (ret < 0)
477 goto err;
478 OSMO_SNPRINTF_RET(ret, rem, offset, len);
Harald Welted788f662010-03-26 09:45:03 +0800479 }
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800480 }
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800481 if (!cont) {
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100482 if (target->print_ext_timestamp) {
Harald Welte14c4c492018-06-28 08:28:52 +0200483#ifdef HAVE_LOCALTIME_R
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100484 struct tm tm;
Jacob Erlbeckb61b2ca2015-03-17 10:21:15 +0100485 struct timeval tv;
Neels Hofmeyr8e2f7e82016-09-22 03:58:13 +0200486 osmo_gettimeofday(&tv, NULL);
Jacob Erlbeckb61b2ca2015-03-17 10:21:15 +0100487 localtime_r(&tv.tv_sec, &tm);
488 ret = snprintf(buf + offset, rem, "%04d%02d%02d%02d%02d%02d%03d ",
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100489 tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday,
Jacob Erlbeckb61b2ca2015-03-17 10:21:15 +0100490 tm.tm_hour, tm.tm_min, tm.tm_sec,
491 (int)(tv.tv_usec / 1000));
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100492 if (ret < 0)
493 goto err;
494 OSMO_SNPRINTF_RET(ret, rem, offset, len);
Harald Welte14c4c492018-06-28 08:28:52 +0200495#endif
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100496 } else if (target->print_timestamp) {
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800497 time_t tm;
Pau Espin Pedrol3aef2382019-06-12 18:50:29 +0200498 if ((tm = time(NULL)) == (time_t) -1)
499 goto err;
Pau Espin Pedrolcc794e92019-06-12 16:22:53 +0200500 /* Get human-readable representation of time.
501 man ctime: we need at least 26 bytes in buf */
502 if (rem < 26 || !ctime_r(&tm, buf + offset))
Pablo Neira Ayuso7503fb82011-05-03 22:32:43 +0200503 goto err;
Pau Espin Pedrolcc794e92019-06-12 16:22:53 +0200504 ret = strlen(buf + offset);
505 if (ret <= 0)
506 goto err;
507 /* Get rid of useless final '\n' added by ctime_r. We want a space instead. */
508 buf[offset + ret - 1] = ' ';
Pablo Neira Ayuso7503fb82011-05-03 22:32:43 +0200509 OSMO_SNPRINTF_RET(ret, rem, offset, len);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800510 }
Pau Espin Pedrol662d10d2021-02-18 18:19:23 +0100511 if (target->print_tid) {
512 if (logging_tid == 0)
513 logging_tid = (long int)osmo_gettid();
514 ret = snprintf(buf + offset, rem, "%ld ", logging_tid);
515 if (ret < 0)
516 goto err;
517 OSMO_SNPRINTF_RET(ret, rem, offset, len);
518 }
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100519 if (target->print_category) {
Neels Hofmeyre6534722018-01-16 03:02:06 +0100520 ret = snprintf(buf + offset, rem, "%s%s%s%s ",
521 target->use_color ? level_color(level) : "",
522 log_category_name(subsys),
Neels Hofmeyrf2644ae2019-11-20 04:00:29 +0100523 target->use_color ? OSMO_LOGCOLOR_END : "",
Neels Hofmeyre6534722018-01-16 03:02:06 +0100524 c_subsys ? c_subsys : "");
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100525 if (ret < 0)
526 goto err;
527 OSMO_SNPRINTF_RET(ret, rem, offset, len);
528 }
Neels Hofmeyr886e5482018-01-16 01:49:37 +0100529 if (target->print_level) {
Neels Hofmeyrf3fa3692018-01-16 02:56:01 +0100530 ret = snprintf(buf + offset, rem, "%s%s%s%s ",
531 target->use_color ? level_color(level) : "",
532 log_level_str(level),
Neels Hofmeyrf2644ae2019-11-20 04:00:29 +0100533 target->use_color ? OSMO_LOGCOLOR_END : "",
Neels Hofmeyrf3fa3692018-01-16 02:56:01 +0100534 c_subsys ? c_subsys : "");
Neels Hofmeyr886e5482018-01-16 01:49:37 +0100535 if (ret < 0)
536 goto err;
537 OSMO_SNPRINTF_RET(ret, rem, offset, len);
538 }
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +0100539 if (target->print_category_hex) {
540 ret = snprintf(buf + offset, rem, "<%4.4x> ", subsys);
Holger Hans Peter Freytherdb153362012-09-11 11:24:51 +0200541 if (ret < 0)
542 goto err;
543 OSMO_SNPRINTF_RET(ret, rem, offset, len);
544 }
Neels Hofmeyr77ae45d2018-08-27 20:32:36 +0200545
546 if (target->print_filename_pos == LOG_FILENAME_POS_HEADER_END) {
547 switch (target->print_filename2) {
548 case LOG_FILENAME_NONE:
549 break;
550 case LOG_FILENAME_PATH:
551 ret = snprintf(buf + offset, rem, "%s:%d ", file, line);
552 if (ret < 0)
553 goto err;
554 OSMO_SNPRINTF_RET(ret, rem, offset, len);
555 break;
556 case LOG_FILENAME_BASENAME:
557 ret = snprintf(buf + offset, rem, "%s:%d ", const_basename(file), line);
558 if (ret < 0)
559 goto err;
560 OSMO_SNPRINTF_RET(ret, rem, offset, len);
561 break;
562 }
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +0100563 }
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800564 }
Pablo Neira Ayuso7503fb82011-05-03 22:32:43 +0200565 ret = vsnprintf(buf + offset, rem, format, ap);
566 if (ret < 0)
567 goto err;
568 OSMO_SNPRINTF_RET(ret, rem, offset, len);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800569
Neels Hofmeyr77ae45d2018-08-27 20:32:36 +0200570 /* For LOG_FILENAME_POS_LAST, print the source file info only when the caller ended the log
571 * message in '\n'. If so, nip the last '\n' away, insert the source file info and re-append an
572 * '\n'. All this to allow LOGP("start..."); LOGPC("...end\n") constructs. */
573 if (target->print_filename_pos == LOG_FILENAME_POS_LINE_END
574 && offset > 0 && buf[offset-1] == '\n') {
575 switch (target->print_filename2) {
576 case LOG_FILENAME_NONE:
577 break;
578 case LOG_FILENAME_PATH:
579 offset --;
580 ret = snprintf(buf + offset, rem, " (%s:%d)\n", file, line);
581 if (ret < 0)
582 goto err;
583 OSMO_SNPRINTF_RET(ret, rem, offset, len);
584 break;
585 case LOG_FILENAME_BASENAME:
586 offset --;
587 ret = snprintf(buf + offset, rem, " (%s:%d)\n", const_basename(file), line);
588 if (ret < 0)
589 goto err;
590 OSMO_SNPRINTF_RET(ret, rem, offset, len);
591 break;
592 }
593 }
594
Pau Espin Pedrol6407c822020-07-20 16:41:44 +0200595 if (target->use_color && c_subsys) {
Neels Hofmeyrf2644ae2019-11-20 04:00:29 +0100596 ret = snprintf(buf + offset, rem, OSMO_LOGCOLOR_END);
Neels Hofmeyrc4759882018-01-16 02:10:48 +0100597 if (ret < 0)
598 goto err;
599 OSMO_SNPRINTF_RET(ret, rem, offset, len);
600 }
Pablo Neira Ayuso7503fb82011-05-03 22:32:43 +0200601err:
Harald Weltea0b57d02020-09-27 17:15:10 +0200602 buf[buf_len-1] = '\0';
603 return len;
604}
605
606/* Format the log line for given target; use a stack buffer and call target->output */
607static void _output(struct log_target *target, unsigned int subsys,
608 unsigned int level, const char *file, int line, int cont,
609 const char *format, va_list ap)
610{
611 char buf[MAX_LOG_SIZE];
612 int rc;
613
614 rc = _output_buf(buf, sizeof(buf), target, subsys, level, file, line, cont, format, ap);
615 if (rc > 0)
616 target->output(target, level, buf);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800617}
618
Neels Hofmeyr42240de2016-12-12 15:13:56 +0100619/* Catch internal logging category indexes as well as out-of-bounds indexes.
620 * For internal categories, the ID is negative starting with -1; and internal
621 * logging categories are added behind the user categories. For out-of-bounds
622 * indexes, return the index of DLGLOBAL. The returned category index is
623 * guaranteed to exist in osmo_log_info, otherwise the program would abort,
624 * which should never happen unless even the DLGLOBAL category is missing. */
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100625static inline int map_subsys(int subsys)
626{
Neels Hofmeyr74802262016-12-12 16:00:24 +0100627 /* Note: comparing signed and unsigned integers */
628
629 if (subsys > 0 && ((unsigned int)subsys) >= osmo_log_info->num_cat_user)
630 subsys = DLGLOBAL;
631
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100632 if (subsys < 0)
633 subsys = subsys_lib2index(subsys);
634
Neels Hofmeyrca135742016-12-12 14:18:54 +0100635 if (subsys < 0 || subsys >= osmo_log_info->num_cat)
Neels Hofmeyr42240de2016-12-12 15:13:56 +0100636 subsys = subsys_lib2index(DLGLOBAL);
637
Neels Hofmeyrca135742016-12-12 14:18:54 +0100638 OSMO_ASSERT(!(subsys < 0 || subsys >= osmo_log_info->num_cat));
639
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100640 return subsys;
641}
642
Maxc65c5b42017-03-15 13:20:23 +0100643static inline bool should_log_to_target(struct log_target *tar, int subsys,
644 int level)
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100645{
646 struct log_category *category;
647
648 category = &tar->categories[subsys];
649
650 /* subsystem is not supposed to be logged */
651 if (!category->enabled)
Maxc65c5b42017-03-15 13:20:23 +0100652 return false;
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100653
654 /* Check the global log level */
655 if (tar->loglevel != 0 && level < tar->loglevel)
Maxc65c5b42017-03-15 13:20:23 +0100656 return false;
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100657
658 /* Check the category log level */
659 if (tar->loglevel == 0 && category->loglevel != 0 &&
660 level < category->loglevel)
Maxc65c5b42017-03-15 13:20:23 +0100661 return false;
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100662
Holger Hans Peter Freyther79599ac2016-01-15 16:49:06 +0100663 /* Apply filters here... if that becomes messy we will
664 * need to put filters in a list and each filter will
665 * say stop, continue, output */
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +0100666 if ((tar->filter_map & (1 << LOG_FLT_ALL)) != 0)
Maxc65c5b42017-03-15 13:20:23 +0100667 return true;
Holger Hans Peter Freyther79599ac2016-01-15 16:49:06 +0100668
669 if (osmo_log_info->filter_fn)
670 return osmo_log_info->filter_fn(&log_context, tar);
671
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100672 /* TODO: Check the filter/selector too? */
Maxc65c5b42017-03-15 13:20:23 +0100673 return true;
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100674}
675
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200676/*! vararg version of logging function
Harald Welte2d2e2cc2016-04-25 12:11:20 +0200677 * \param[in] subsys Logging sub-system
678 * \param[in] level Log level
679 * \param[in] file name of source code file
680 * \param[in] cont continuation (1) or new line (0)
681 * \param[in] format format string
682 * \param[in] ap vararg-list containing format string arguments
683 */
Holger Hans Peter Freytherfb4bfc22012-07-12 09:26:25 +0200684void osmo_vlogp(int subsys, int level, const char *file, int line,
Harald Welte36c5a3e2011-08-27 14:33:19 +0200685 int cont, const char *format, va_list ap)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800686{
Harald Welte3ae27582010-03-26 21:24:24 +0800687 struct log_target *tar;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800688
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +0100689 subsys = map_subsys(subsys);
Harald Welteb43bc042011-06-27 10:29:17 +0200690
Pau Espin Pedrold12f6982019-09-17 18:38:58 +0200691 log_tgt_mutex_lock();
692
Harald Welte28222962011-02-18 20:37:04 +0100693 llist_for_each_entry(tar, &osmo_log_target_list, entry) {
Pablo Neira Ayusodd93bf42011-05-19 01:40:43 +0200694 va_list bp;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800695
Maxc65c5b42017-03-15 13:20:23 +0100696 if (!should_log_to_target(tar, subsys, level))
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800697 continue;
698
Pablo Neira Ayusodd93bf42011-05-19 01:40:43 +0200699 /* According to the manpage, vsnprintf leaves the value of ap
700 * in undefined state. Since _output uses vsnprintf and it may
701 * be called several times, we have to pass a copy of ap. */
702 va_copy(bp, ap);
Harald Welted7c0a372016-12-02 13:52:59 +0100703 if (tar->raw_output)
704 tar->raw_output(tar, subsys, level, file, line, cont, format, bp);
705 else
706 _output(tar, subsys, level, file, line, cont, format, bp);
Pablo Neira Ayusodd93bf42011-05-19 01:40:43 +0200707 va_end(bp);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800708 }
Pau Espin Pedrold12f6982019-09-17 18:38:58 +0200709
710 log_tgt_mutex_unlock();
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800711}
712
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200713/*! logging function used by DEBUGP() macro
Harald Welte2d2e2cc2016-04-25 12:11:20 +0200714 * \param[in] subsys Logging sub-system
715 * \param[in] file name of source code file
716 * \param[in] cont continuation (1) or new line (0)
717 * \param[in] format format string
718 */
Holger Hans Peter Freytherfb4bfc22012-07-12 09:26:25 +0200719void logp(int subsys, const char *file, int line, int cont,
Harald Welte3ae27582010-03-26 21:24:24 +0800720 const char *format, ...)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800721{
722 va_list ap;
723
724 va_start(ap, format);
Harald Welte36c5a3e2011-08-27 14:33:19 +0200725 osmo_vlogp(subsys, LOGL_DEBUG, file, line, cont, format, ap);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800726 va_end(ap);
727}
728
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200729/*! logging function used by LOGP() macro
Harald Welte2d2e2cc2016-04-25 12:11:20 +0200730 * \param[in] subsys Logging sub-system
731 * \param[in] level Log level
732 * \param[in] file name of source code file
733 * \param[in] cont continuation (1) or new line (0)
734 * \param[in] format format string
735 */
Holger Hans Peter Freytherfb4bfc22012-07-12 09:26:25 +0200736void logp2(int subsys, unsigned int level, const char *file, int line, int cont, const char *format, ...)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800737{
738 va_list ap;
739
Harald Welte433005c2020-09-26 11:51:32 +0200740 TRACE(LIBOSMOCORE_LOG_START());
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800741 va_start(ap, format);
Harald Welte36c5a3e2011-08-27 14:33:19 +0200742 osmo_vlogp(subsys, level, file, line, cont, format, ap);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800743 va_end(ap);
Harald Welte433005c2020-09-26 11:51:32 +0200744 TRACE(LIBOSMOCORE_LOG_DONE());
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800745}
746
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200747/*! Register a new log target with the logging core
Harald Welte18fc4652011-08-17 14:14:17 +0200748 * \param[in] target Log target to be registered
749 */
Harald Welte3ae27582010-03-26 21:24:24 +0800750void log_add_target(struct log_target *target)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800751{
Harald Welte28222962011-02-18 20:37:04 +0100752 llist_add_tail(&target->entry, &osmo_log_target_list);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800753}
754
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200755/*! Unregister a log target from the logging core
Harald Welte18fc4652011-08-17 14:14:17 +0200756 * \param[in] target Log target to be unregistered
757 */
Harald Welte3ae27582010-03-26 21:24:24 +0800758void log_del_target(struct log_target *target)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800759{
760 llist_del(&target->entry);
761}
762
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200763/*! Reset (clear) the logging context */
Harald Welte3ae27582010-03-26 21:24:24 +0800764void log_reset_context(void)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800765{
Harald Welte3ae27582010-03-26 21:24:24 +0800766 memset(&log_context, 0, sizeof(log_context));
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800767}
768
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200769/*! Set the logging context
Harald Welte18fc4652011-08-17 14:14:17 +0200770 * \param[in] ctx_nr logging context number
771 * \param[in] value value to which the context is to be set
Harald Welte2d2e2cc2016-04-25 12:11:20 +0200772 * \returns 0 in case of success; negative otherwise
Harald Welte18fc4652011-08-17 14:14:17 +0200773 *
774 * A logging context is something like the subscriber identity to which
775 * the currently processed message relates, or the BTS through which it
776 * was received. As soon as this data is known, it can be set using
777 * this function. The main use of context information is for logging
778 * filters.
779 */
Harald Welte3ae27582010-03-26 21:24:24 +0800780int log_set_context(uint8_t ctx_nr, void *value)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800781{
Harald Welte3ae27582010-03-26 21:24:24 +0800782 if (ctx_nr > LOG_MAX_CTX)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800783 return -EINVAL;
784
Harald Welte3ae27582010-03-26 21:24:24 +0800785 log_context.ctx[ctx_nr] = value;
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800786
787 return 0;
788}
789
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200790/*! Enable the \ref LOG_FLT_ALL log filter
Harald Welte18fc4652011-08-17 14:14:17 +0200791 * \param[in] target Log target to be affected
792 * \param[in] all enable (1) or disable (0) the ALL filter
793 *
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +0100794 * When the \ref LOG_FLT_ALL filter is enabled, all log messages will be
Neels Hofmeyr812ba6d2017-02-17 16:35:27 +0100795 * printed. It acts as a wildcard. Setting it to \a 1 means there is no
796 * filtering.
Harald Welte18fc4652011-08-17 14:14:17 +0200797 */
Harald Welte3ae27582010-03-26 21:24:24 +0800798void log_set_all_filter(struct log_target *target, int all)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800799{
800 if (all)
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +0100801 target->filter_map |= (1 << LOG_FLT_ALL);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800802 else
Neels Hofmeyr8b86cd72017-02-23 18:03:28 +0100803 target->filter_map &= ~(1 << LOG_FLT_ALL);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800804}
805
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200806/*! Enable or disable the use of colored output
Harald Welte18fc4652011-08-17 14:14:17 +0200807 * \param[in] target Log target to be affected
808 * \param[in] use_color Use color (1) or don't use color (0)
809 */
Harald Welte3ae27582010-03-26 21:24:24 +0800810void log_set_use_color(struct log_target *target, int use_color)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800811{
812 target->use_color = use_color;
813}
814
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200815/*! Enable or disable printing of timestamps while logging
Harald Welte18fc4652011-08-17 14:14:17 +0200816 * \param[in] target Log target to be affected
817 * \param[in] print_timestamp Enable (1) or disable (0) timestamps
818 */
Harald Welte3ae27582010-03-26 21:24:24 +0800819void log_set_print_timestamp(struct log_target *target, int print_timestamp)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800820{
821 target->print_timestamp = print_timestamp;
822}
823
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200824/*! Enable or disable printing of extended timestamps while logging
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100825 * \param[in] target Log target to be affected
826 * \param[in] print_timestamp Enable (1) or disable (0) timestamps
827 *
828 * When both timestamp and extended timestamp is enabled then only
829 * the extended timestamp will be used. The format of the timestamp
830 * is YYYYMMDDhhmmssnnn.
831 */
832void log_set_print_extended_timestamp(struct log_target *target, int print_timestamp)
833{
834 target->print_ext_timestamp = print_timestamp;
835}
836
Pau Espin Pedrol662d10d2021-02-18 18:19:23 +0100837/*! Enable or disable printing of timestamps while logging
838 * \param[in] target Log target to be affected
839 * \param[in] print_tid Enable (1) or disable (0) Thread ID logging
840 */
841void log_set_print_tid(struct log_target *target, int print_tid)
842{
843 target->print_tid = print_tid;
844}
845
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +0100846/*! Use log_set_print_filename2() instead.
847 * Call log_set_print_filename2() with LOG_FILENAME_PATH or LOG_FILENAME_NONE, *as well as* call
848 * log_set_print_category_hex() with the argument passed to this function. This is to mirror legacy
849 * behavior, which combined the category in hex with the filename. For example, if the category-hex
850 * output were no longer affected by log_set_print_filename(), many unit tests (in libosmocore as well as
851 * dependent projects) would fail since they expect the category to disappear along with the filename.
Holger Hans Peter Freytherdb153362012-09-11 11:24:51 +0200852 * \param[in] target Log target to be affected
853 * \param[in] print_filename Enable (1) or disable (0) filenames
854 */
855void log_set_print_filename(struct log_target *target, int print_filename)
856{
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +0100857 log_set_print_filename2(target, print_filename ? LOG_FILENAME_PATH : LOG_FILENAME_NONE);
858 log_set_print_category_hex(target, print_filename);
859}
860
861/*! Enable or disable printing of the filename while logging.
862 * \param[in] target Log target to be affected.
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +0700863 * \param[in] lft An LOG_FILENAME_* enum value.
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +0100864 * LOG_FILENAME_NONE omits the source file and line information from logs.
865 * LOG_FILENAME_PATH prints the entire source file path as passed to LOGP macros.
866 */
867void log_set_print_filename2(struct log_target *target, enum log_filename_type lft)
868{
869 target->print_filename2 = lft;
Holger Hans Peter Freytherdb153362012-09-11 11:24:51 +0200870}
871
Neels Hofmeyr77ae45d2018-08-27 20:32:36 +0200872/*! Set the position where on a log line the source file info should be logged.
873 * \param[in] target Log target to be affected.
874 * \param[in] pos A LOG_FILENAME_POS_* enum value.
875 * LOG_FILENAME_POS_DEFAULT logs just before the caller supplied log message.
876 * LOG_FILENAME_POS_LAST logs only at the end of a log line, where the caller issued an '\n' to end the
877 */
878void log_set_print_filename_pos(struct log_target *target, enum log_filename_pos pos)
879{
880 target->print_filename_pos = pos;
881}
882
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200883/*! Enable or disable printing of the category name
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100884 * \param[in] target Log target to be affected
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +0700885 * \param[in] print_category Enable (1) or disable (0) filenames
Holger Hans Peter Freyther2d6ad132014-12-05 09:35:30 +0100886 *
887 * Print the category/subsys name in front of every log message.
888 */
889void log_set_print_category(struct log_target *target, int print_category)
890{
891 target->print_category = print_category;
892}
893
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +0100894/*! Enable or disable printing of the category number in hex ('<000b>').
895 * \param[in] target Log target to be affected.
896 * \param[in] print_category_hex Enable (1) or disable (0) hex category.
897 */
898void log_set_print_category_hex(struct log_target *target, int print_category_hex)
899{
900 target->print_category_hex = print_category_hex;
901}
902
Neels Hofmeyr886e5482018-01-16 01:49:37 +0100903/*! Enable or disable printing of the log level name.
904 * \param[in] target Log target to be affected
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +0700905 * \param[in] print_level Enable (1) or disable (0) log level name
Neels Hofmeyr886e5482018-01-16 01:49:37 +0100906 *
907 * Print the log level name in front of every log message.
908 */
909void log_set_print_level(struct log_target *target, int print_level)
910{
911 target->print_level = (bool)print_level;
912}
913
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200914/*! Set the global log level for a given log target
Harald Welte18fc4652011-08-17 14:14:17 +0200915 * \param[in] target Log target to be affected
916 * \param[in] log_level New global log level
917 */
Harald Welte3ae27582010-03-26 21:24:24 +0800918void log_set_log_level(struct log_target *target, int log_level)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800919{
920 target->loglevel = log_level;
921}
922
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200923/*! Set a category filter on a given log target
Harald Weltede6e4982012-12-06 21:25:27 +0100924 * \param[in] target Log target to be affected
925 * \param[in] category Log category to be affected
926 * \param[in] enable whether to enable or disable the filter
927 * \param[in] level Log level of the filter
928 */
Harald Welte3ae27582010-03-26 21:24:24 +0800929void log_set_category_filter(struct log_target *target, int category,
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800930 int enable, int level)
931{
Neels Hofmeyr886d6fd2016-12-12 13:49:03 +0100932 if (!target)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800933 return;
Neels Hofmeyr886d6fd2016-12-12 13:49:03 +0100934 category = map_subsys(category);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800935 target->categories[category].enabled = !!enable;
936 target->categories[category].loglevel = level;
937}
938
Harald Welte44c0f632017-01-15 17:58:29 +0100939#if (!EMBEDDED)
Harald Welte78d73672020-09-29 11:32:35 +0200940/* write-queue tells us we should write another msgb (log line) to the output fd */
941static int _file_wq_write_cb(struct osmo_fd *ofd, struct msgb *msg)
942{
943 int rc;
944
945 rc = write(ofd->fd, msgb_data(msg), msgb_length(msg));
946 if (rc < 0)
947 return rc;
948 if (rc != msgb_length(msg)) {
949 /* pull the number of bytes we have already written */
950 msgb_pull(msg, rc);
951 /* ask write_queue to re-insert the msgb at the head of the queue */
952 return -EAGAIN;
953 }
954 return 0;
955}
956
957/* output via buffered, blocking stdio streams */
Harald Welteb72867f2020-09-26 21:45:16 +0200958static void _file_output_stream(struct log_target *target, unsigned int level,
959 const char *log)
960{
961 OSMO_ASSERT(target->tgt_file.out);
962 fputs(log, target->tgt_file.out);
963 fflush(target->tgt_file.out);
964}
965
966/* output via non-blocking write_queue, doing internal buffering */
Harald Weltea0b57d02020-09-27 17:15:10 +0200967static void _file_raw_output(struct log_target *target, int subsys, unsigned int level, const char *file,
968 int line, int cont, const char *format, va_list ap)
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800969{
Harald Welteb72867f2020-09-26 21:45:16 +0200970 struct msgb *msg;
Harald Weltea0b57d02020-09-27 17:15:10 +0200971 int rc;
Harald Welteb72867f2020-09-26 21:45:16 +0200972
973 OSMO_ASSERT(target->tgt_file.wqueue);
Harald Weltea0b57d02020-09-27 17:15:10 +0200974 msg = msgb_alloc_c(target->tgt_file.wqueue, MAX_LOG_SIZE, "log_file_msg");
Harald Welteb72867f2020-09-26 21:45:16 +0200975 if (!msg)
976 return;
977
978 /* we simply enqueue the log message to a write queue here, to avoid any blocking
979 * writes on the output file. The write queue will tell us once the file is writable
980 * and call _file_wq_write_cb() */
Harald Weltea0b57d02020-09-27 17:15:10 +0200981 rc = _output_buf((char *)msgb_data(msg), msgb_tailroom(msg), target, subsys, level, file, line, cont, format, ap);
982 msgb_put(msg, rc);
Harald Welte78d73672020-09-29 11:32:35 +0200983
984 /* attempt a synchronous, non-blocking write, if the write queue is empty */
985 if (target->tgt_file.wqueue->current_length == 0) {
986 rc = _file_wq_write_cb(&target->tgt_file.wqueue->bfd, msg);
987 if (rc == 0) {
988 /* the write was complete, we can exit early */
989 msgb_free(msg);
990 return;
991 }
992 }
993 /* if we reach here, either we already had elements in the write_queue, or the synchronous write
994 * failed: enqueue the message to the write_queue (backlog) */
Harald Welteb72867f2020-09-26 21:45:16 +0200995 osmo_wqueue_enqueue_quiet(target->tgt_file.wqueue, msg);
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800996}
Harald Welte44c0f632017-01-15 17:58:29 +0100997#endif
Harald Welte4a2bb9e2010-03-26 09:33:40 +0800998
Neels Hofmeyr87e45502017-06-20 00:17:59 +0200999/*! Create a new log target skeleton
Harald Welte2d2e2cc2016-04-25 12:11:20 +02001000 * \returns dynamically-allocated log target
1001 * This funcition allocates a \ref log_target and initializes it
1002 * with some default values. The newly created target is not
1003 * registered yet.
1004 */
Harald Welte3ae27582010-03-26 21:24:24 +08001005struct log_target *log_target_create(void)
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001006{
Harald Welte3ae27582010-03-26 21:24:24 +08001007 struct log_target *target;
Harald Weltecc6313c2010-03-26 22:04:03 +08001008 unsigned int i;
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001009
Max68bf16a2018-01-10 17:00:43 +01001010 assert_loginfo(__func__);
Harald Welte18a7d812017-03-16 23:54:55 +01001011
Harald Welte3ae27582010-03-26 21:24:24 +08001012 target = talloc_zero(tall_log_ctx, struct log_target);
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001013 if (!target)
1014 return NULL;
1015
Pau Espin Pedrol9d4a36e2018-07-26 11:55:33 +02001016 target->categories = talloc_zero_array(target,
Harald Welteb43bc042011-06-27 10:29:17 +02001017 struct log_category,
1018 osmo_log_info->num_cat);
1019 if (!target->categories) {
1020 talloc_free(target);
1021 return NULL;
1022 }
1023
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001024 INIT_LLIST_HEAD(&target->entry);
Harald Weltecc6313c2010-03-26 22:04:03 +08001025
1026 /* initialize the per-category enabled/loglevel from defaults */
Harald Welte4ebdf742010-05-19 19:54:00 +02001027 for (i = 0; i < osmo_log_info->num_cat; i++) {
Harald Weltecc6313c2010-03-26 22:04:03 +08001028 struct log_category *cat = &target->categories[i];
Harald Welte4ebdf742010-05-19 19:54:00 +02001029 cat->enabled = osmo_log_info->cat[i].enabled;
1030 cat->loglevel = osmo_log_info->cat[i].loglevel;
Harald Weltecc6313c2010-03-26 22:04:03 +08001031 }
1032
1033 /* global settings */
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001034 target->use_color = 1;
1035 target->print_timestamp = 0;
Pau Espin Pedrol662d10d2021-02-18 18:19:23 +01001036 target->print_tid = 0;
Neels Hofmeyrbd7bd392018-01-16 01:52:29 +01001037 target->print_filename2 = LOG_FILENAME_PATH;
1038 target->print_category_hex = true;
Harald Weltecc6313c2010-03-26 22:04:03 +08001039
1040 /* global log level */
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001041 target->loglevel = 0;
1042 return target;
1043}
1044
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001045/*! Create the STDERR log target
Harald Welte2d2e2cc2016-04-25 12:11:20 +02001046 * \returns dynamically-allocated \ref log_target for STDERR */
Harald Welte3ae27582010-03-26 21:24:24 +08001047struct log_target *log_target_create_stderr(void)
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001048{
Harald Weltea3b844c2010-03-27 00:04:40 +08001049/* since C89/C99 says stderr is a macro, we can safely do this! */
Harald Welteb93ce5a2017-05-15 10:58:15 +02001050#if !EMBEDDED && defined(stderr)
Harald Welte3ae27582010-03-26 21:24:24 +08001051 struct log_target *target;
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001052
Harald Welte3ae27582010-03-26 21:24:24 +08001053 target = log_target_create();
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001054 if (!target)
1055 return NULL;
1056
Harald Welte28222962011-02-18 20:37:04 +01001057 target->type = LOG_TGT_TYPE_STDERR;
Harald Welte0083cd32010-08-25 14:55:44 +02001058 target->tgt_file.out = stderr;
Harald Welteb72867f2020-09-26 21:45:16 +02001059 target->output = _file_output_stream;
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001060 return target;
Harald Weltea3b844c2010-03-27 00:04:40 +08001061#else
1062 return NULL;
1063#endif /* stderr */
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001064}
1065
Harald Welte44c0f632017-01-15 17:58:29 +01001066#if (!EMBEDDED)
Harald Welteb72867f2020-09-26 21:45:16 +02001067/*! Create a new file-based log target using buffered, blocking stream output
Harald Welte18fc4652011-08-17 14:14:17 +02001068 * \param[in] fname File name of the new log file
1069 * \returns Log target in case of success, NULL otherwise
1070 */
Harald Welteb72867f2020-09-26 21:45:16 +02001071struct log_target *log_target_create_file_stream(const char *fname)
Harald Welte3086c392010-08-25 19:10:50 +02001072{
1073 struct log_target *target;
1074
1075 target = log_target_create();
1076 if (!target)
1077 return NULL;
1078
Harald Welte28222962011-02-18 20:37:04 +01001079 target->type = LOG_TGT_TYPE_FILE;
Harald Welte3086c392010-08-25 19:10:50 +02001080 target->tgt_file.out = fopen(fname, "a");
Vadim Yanitskiyb89114b2020-09-09 04:51:04 +07001081 if (!target->tgt_file.out) {
1082 log_target_destroy(target);
Harald Welte3086c392010-08-25 19:10:50 +02001083 return NULL;
Vadim Yanitskiyb89114b2020-09-09 04:51:04 +07001084 }
Harald Welteb72867f2020-09-26 21:45:16 +02001085 target->output = _file_output_stream;
1086 target->tgt_file.fname = talloc_strdup(target, fname);
Harald Welte3086c392010-08-25 19:10:50 +02001087
Harald Welteb72867f2020-09-26 21:45:16 +02001088 return target;
1089}
1090
1091/*! switch from non-blocking/write-queue to blocking + buffered stream output
1092 * \param[in] target log target which we should switch
1093 * \return 0 on success; 1 if already switched before; negative on error */
1094int log_target_file_switch_to_stream(struct log_target *target)
1095{
1096 struct osmo_wqueue *wq;
1097 const char *name;
1098
1099 if (!target)
1100 return -ENODEV;
1101
1102 /* this only works for file/stderr targets */
1103 switch (target->type) {
1104 case LOG_TGT_TYPE_FILE:
1105 name = target->tgt_file.fname;
1106 break;
1107 case LOG_TGT_TYPE_STDERR:
1108 name = "stderr";
1109 break;
1110 default:
1111 return -EINVAL;
1112 }
1113
1114 if (target->tgt_file.out) {
1115 /* target has already been switched over */
1116 return 1;
1117 }
1118
1119 LOGP(DLGLOBAL, LOGL_INFO, "Switching log target '%s' to blocking stream I/O\n", name);
1120
1121 wq = target->tgt_file.wqueue;
1122 OSMO_ASSERT(wq);
1123
1124 /* re-open output as stream */
1125 if (target->type == LOG_TGT_TYPE_STDERR)
1126 target->tgt_file.out = stderr;
1127 else
1128 target->tgt_file.out = fopen(target->tgt_file.fname, "a");
1129 if (!target->tgt_file.out) {
1130 LOGP(DLGLOBAL, LOGL_ERROR, "Cannot open log target '%s' as blocking stream I/O: %s\n",
1131 name, strerror(errno));
1132 return -EIO;
1133 }
1134
1135 /* synchronously write anything left in the queue */
1136 while (!llist_empty(&wq->msg_queue)) {
1137 struct msgb *msg = msgb_dequeue(&wq->msg_queue);
1138 fwrite(msgb_data(msg), msgb_length(msg), 1, target->tgt_file.out);
1139 msgb_free(msg);
1140 }
1141
1142 /* now that everything succeeded, we can finally close the old output fd */
1143 if (target->type == LOG_TGT_TYPE_FILE) {
1144 osmo_fd_unregister(&wq->bfd);
1145 close(wq->bfd.fd);
1146 }
1147
1148 /* release the queue itself */
1149 talloc_free(wq);
1150 target->tgt_file.wqueue = NULL;
1151 target->output = _file_output_stream;
1152 target->raw_output = NULL;
1153
1154 return 0;
1155}
1156
1157/*! switch from blocking + buffered file output to non-blocking write-queue based output.
1158 * \param[in] target log target which we should switch
1159 * \return 0 on success; 1 if already switched before; negative on error */
1160int log_target_file_switch_to_wqueue(struct log_target *target)
1161{
1162 struct osmo_wqueue *wq;
1163 const char *name;
1164 int rc;
1165
1166 if (!target)
1167 return -ENODEV;
1168
1169 /* this only works for file/stderr targets */
1170 switch (target->type) {
1171 case LOG_TGT_TYPE_FILE:
1172 name = target->tgt_file.fname;
1173 break;
1174 case LOG_TGT_TYPE_STDERR:
1175 name = "stderr";
1176 break;
1177 default:
1178 return -EINVAL;
1179 }
1180
1181 if (!target->tgt_file.out) {
1182 /* target has already been switched over */
1183 return 1;
1184 }
1185
1186 LOGP(DLGLOBAL, LOGL_INFO, "Switching log target '%s' to non-blocking I/O\n", name);
1187
1188 /* we create a ~640kB sized talloc pool within the write-queue to ensure individual
1189 * log lines (stored as msgbs) will not put result in malloc() calls, and also to
1190 * reduce the OOM probability within logging, as the pool is already allocated */
1191 wq = talloc_pooled_object(target, struct osmo_wqueue, LOG_WQUEUE_LEN,
Harald Weltea0b57d02020-09-27 17:15:10 +02001192 LOG_WQUEUE_LEN*(sizeof(struct msgb)+MAX_LOG_SIZE));
Harald Welteb72867f2020-09-26 21:45:16 +02001193 if (!wq)
1194 return -ENOMEM;
1195 osmo_wqueue_init(wq, LOG_WQUEUE_LEN);
1196
1197 fflush(target->tgt_file.out);
1198 if (target->type == LOG_TGT_TYPE_FILE) {
1199 rc = open(target->tgt_file.fname, O_WRONLY|O_APPEND|O_CREAT|O_NONBLOCK, 0660);
1200 if (rc < 0) {
1201 LOGP(DLGLOBAL, LOGL_ERROR, "Cannot open log target '%s' as non-blocking I/O: %s\n",
1202 name, strerror(errno));
1203 talloc_free(wq);
1204 return -errno;
1205 }
1206 } else {
1207 rc = STDERR_FILENO;
1208 }
1209 wq->bfd.fd = rc;
1210 wq->bfd.when = OSMO_FD_WRITE;
1211 wq->write_cb = _file_wq_write_cb;
1212
1213 rc = osmo_fd_register(&wq->bfd);
1214 if (rc < 0) {
1215 talloc_free(wq);
1216 return -EIO;
1217 }
1218 target->tgt_file.wqueue = wq;
Harald Weltea0b57d02020-09-27 17:15:10 +02001219 target->raw_output = _file_raw_output;
1220 target->output = NULL;
Harald Welte3086c392010-08-25 19:10:50 +02001221
Harald Welteb72867f2020-09-26 21:45:16 +02001222 /* now that everything succeeded, we can finally close the old output stream */
1223 if (target->type == LOG_TGT_TYPE_FILE)
1224 fclose(target->tgt_file.out);
1225 target->tgt_file.out = NULL;
1226
1227 return 0;
1228}
1229
1230/*! Create a new file-based log target using non-blocking write_queue
1231 * \param[in] fname File name of the new log file
1232 * \returns Log target in case of success, NULL otherwise
1233 */
1234struct log_target *log_target_create_file(const char *fname)
1235{
1236 struct log_target *target;
1237 struct osmo_wqueue *wq;
1238 int rc;
1239
1240 target = log_target_create();
1241 if (!target)
1242 return NULL;
1243
1244 target->type = LOG_TGT_TYPE_FILE;
1245 /* we create a ~640kB sized talloc pool within the write-queue to ensure individual
1246 * log lines (stored as msgbs) will not put result in malloc() calls, and also to
1247 * reduce the OOM probability within logging, as the pool is already allocated */
1248 wq = talloc_pooled_object(target, struct osmo_wqueue, LOG_WQUEUE_LEN,
Harald Weltea0b57d02020-09-27 17:15:10 +02001249 LOG_WQUEUE_LEN*(sizeof(struct msgb)+MAX_LOG_SIZE));
Harald Welteb72867f2020-09-26 21:45:16 +02001250 if (!wq) {
1251 log_target_destroy(target);
1252 return NULL;
1253 }
1254 osmo_wqueue_init(wq, LOG_WQUEUE_LEN);
1255 wq->bfd.fd = open(fname, O_WRONLY|O_APPEND|O_CREAT|O_NONBLOCK, 0660);
1256 if (wq->bfd.fd < 0) {
1257 talloc_free(wq);
1258 log_target_destroy(target);
1259 return NULL;
1260 }
1261 wq->bfd.when = OSMO_FD_WRITE;
1262 wq->write_cb = _file_wq_write_cb;
1263
1264 rc = osmo_fd_register(&wq->bfd);
1265 if (rc < 0) {
1266 talloc_free(wq);
1267 log_target_destroy(target);
1268 return NULL;
1269 }
1270
1271 target->tgt_file.wqueue = wq;
Harald Weltea0b57d02020-09-27 17:15:10 +02001272 target->raw_output = _file_raw_output;
Harald Welte3086c392010-08-25 19:10:50 +02001273 target->tgt_file.fname = talloc_strdup(target, fname);
1274
1275 return target;
1276}
Harald Welte44c0f632017-01-15 17:58:29 +01001277#endif
Harald Welte3086c392010-08-25 19:10:50 +02001278
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001279/*! Find a registered log target
Harald Welte18fc4652011-08-17 14:14:17 +02001280 * \param[in] type Log target type
1281 * \param[in] fname File name
1282 * \returns Log target (if found), NULL otherwise
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001283 * Must be called with mutex osmo_log_tgt_mutex held, see log_tgt_mutex_lock.
Harald Welte18fc4652011-08-17 14:14:17 +02001284 */
Harald Welte28222962011-02-18 20:37:04 +01001285struct log_target *log_target_find(int type, const char *fname)
1286{
1287 struct log_target *tgt;
1288
1289 llist_for_each_entry(tgt, &osmo_log_target_list, entry) {
1290 if (tgt->type != type)
1291 continue;
Maxc90f40a2018-01-11 10:52:28 +01001292 switch (tgt->type) {
1293 case LOG_TGT_TYPE_FILE:
Harald Welte28222962011-02-18 20:37:04 +01001294 if (!strcmp(fname, tgt->tgt_file.fname))
1295 return tgt;
Maxc90f40a2018-01-11 10:52:28 +01001296 break;
1297 case LOG_TGT_TYPE_GSMTAP:
1298 if (!strcmp(fname, tgt->tgt_gsmtap.hostname))
1299 return tgt;
1300 break;
1301 default:
Harald Welte28222962011-02-18 20:37:04 +01001302 return tgt;
Maxc90f40a2018-01-11 10:52:28 +01001303 }
Harald Welte28222962011-02-18 20:37:04 +01001304 }
1305 return NULL;
1306}
1307
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001308/*! Unregister, close and delete a log target
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +07001309 * \param[in] target log target to unregister, close and delete */
Harald Welte3086c392010-08-25 19:10:50 +02001310void log_target_destroy(struct log_target *target)
1311{
Harald Welte3086c392010-08-25 19:10:50 +02001312 /* just in case, to make sure we don't have any references */
1313 log_del_target(target);
1314
Harald Welte44c0f632017-01-15 17:58:29 +01001315#if (!EMBEDDED)
Harald Welteb72867f2020-09-26 21:45:16 +02001316 struct osmo_wqueue *wq;
Vadim Yanitskiy744236b2020-09-09 04:42:22 +07001317 switch (target->type) {
1318 case LOG_TGT_TYPE_FILE:
Harald Welteb72867f2020-09-26 21:45:16 +02001319 case LOG_TGT_TYPE_STDERR:
1320 if (target->tgt_file.out) {
1321 if (target->type == LOG_TGT_TYPE_FILE)
1322 fclose(target->tgt_file.out);
1323 target->tgt_file.out = NULL;
1324 }
1325 wq = target->tgt_file.wqueue;
1326 if (wq) {
1327 if (wq->bfd.fd >= 0) {
1328 if (target->type == LOG_TGT_TYPE_FILE)
1329 close(wq->bfd.fd);
1330 wq->bfd.fd = -1;
1331 }
1332 osmo_fd_unregister(&wq->bfd);
1333 osmo_wqueue_clear(wq);
1334 talloc_free(wq);
1335 target->tgt_file.wqueue = NULL;
1336 }
1337 talloc_free((void *)target->tgt_file.fname);
1338 target->tgt_file.fname = NULL;
Vadim Yanitskiy744236b2020-09-09 04:42:22 +07001339 break;
Vadim Yanitskiy04f42712020-09-09 04:47:25 +07001340#ifdef HAVE_SYSLOG_H
1341 case LOG_TGT_TYPE_SYSLOG:
1342 closelog();
1343 break;
1344#endif /* HAVE_SYSLOG_H */
Vadim Yanitskiy744236b2020-09-09 04:42:22 +07001345 default:
1346 /* make GCC happy */
1347 break;
Harald Welte3086c392010-08-25 19:10:50 +02001348 }
Harald Welte44c0f632017-01-15 17:58:29 +01001349#endif
Harald Welte3086c392010-08-25 19:10:50 +02001350
1351 talloc_free(target);
1352}
1353
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001354/*! close and re-open a log file (for log file rotation)
Harald Welte2d2e2cc2016-04-25 12:11:20 +02001355 * \param[in] target log target to re-open
1356 * \returns 0 in case of success; negative otherwise */
Harald Welte3086c392010-08-25 19:10:50 +02001357int log_target_file_reopen(struct log_target *target)
1358{
Harald Welteb72867f2020-09-26 21:45:16 +02001359 struct osmo_wqueue *wq;
1360 int rc;
Harald Welte3086c392010-08-25 19:10:50 +02001361
Harald Welteb72867f2020-09-26 21:45:16 +02001362 OSMO_ASSERT(target->type == LOG_TGT_TYPE_FILE || target->type == LOG_TGT_TYPE_STDERR);
1363 OSMO_ASSERT(target->tgt_file.out || target->tgt_file.wqueue);
Harald Welte3086c392010-08-25 19:10:50 +02001364
Harald Welteb72867f2020-09-26 21:45:16 +02001365 if (target->tgt_file.out) {
1366 fclose(target->tgt_file.out);
1367 target->tgt_file.out = fopen(target->tgt_file.fname, "a");
1368 if (!target->tgt_file.out)
1369 return -errno;
1370 } else {
1371 wq = target->tgt_file.wqueue;
1372 osmo_fd_unregister(&wq->bfd);
1373 if (wq->bfd.fd >= 0) {
1374 close(wq->bfd.fd);
1375 wq->bfd.fd = -1;
1376 }
1377
1378 rc = open(target->tgt_file.fname, O_WRONLY|O_APPEND|O_CREAT|O_NONBLOCK, 0660);
1379 if (rc < 0)
1380 return -errno;
1381 wq->bfd.fd = rc;
1382 rc = osmo_fd_register(&wq->bfd);
1383 if (rc < 0)
1384 return rc;
1385 }
Harald Welte3086c392010-08-25 19:10:50 +02001386
1387 return 0;
1388}
1389
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001390/*! close and re-open all log files (for log file rotation)
Harald Welte2d2e2cc2016-04-25 12:11:20 +02001391 * \returns 0 in case of success; negative otherwise */
Harald Welte4de854d2013-03-18 19:01:40 +01001392int log_targets_reopen(void)
1393{
1394 struct log_target *tar;
1395 int rc = 0;
1396
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001397 log_tgt_mutex_lock();
1398
Harald Welte4de854d2013-03-18 19:01:40 +01001399 llist_for_each_entry(tar, &osmo_log_target_list, entry) {
1400 switch (tar->type) {
1401 case LOG_TGT_TYPE_FILE:
1402 if (log_target_file_reopen(tar) < 0)
1403 rc = -1;
1404 break;
1405 default:
1406 break;
1407 }
1408 }
1409
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001410 log_tgt_mutex_unlock();
1411
Harald Welte4de854d2013-03-18 19:01:40 +01001412 return rc;
1413}
1414
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001415/*! Initialize the Osmocom logging core
Max72dfd432018-12-04 11:24:18 +01001416 * \param[in] inf Information regarding logging categories, could be NULL
Vadim Yanitskiy73e66b32019-03-25 21:24:20 +07001417 * \param[in] ctx talloc context for logging allocations
Harald Welte18fc4652011-08-17 14:14:17 +02001418 * \returns 0 in case of success, negative in case of error
Max72dfd432018-12-04 11:24:18 +01001419 *
1420 * If inf is NULL then only library-internal categories are initialized.
Harald Welte18fc4652011-08-17 14:14:17 +02001421 */
Harald Welteb43bc042011-06-27 10:29:17 +02001422int log_init(const struct log_info *inf, void *ctx)
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001423{
Harald Welteb43bc042011-06-27 10:29:17 +02001424 int i;
Philipp Maierdcad1c52020-03-25 11:25:59 +01001425 struct log_info_cat *cat_ptr;
Harald Welteb43bc042011-06-27 10:29:17 +02001426
Philipp Maierdc02c062020-05-12 17:51:25 +02001427 /* Ensure that log_init is not called multiple times */
1428 OSMO_ASSERT(tall_log_ctx == NULL)
1429
Harald Welteb43bc042011-06-27 10:29:17 +02001430 tall_log_ctx = talloc_named_const(ctx, 1, "logging");
1431 if (!tall_log_ctx)
1432 return -ENOMEM;
1433
1434 osmo_log_info = talloc_zero(tall_log_ctx, struct log_info);
1435 if (!osmo_log_info)
1436 return -ENOMEM;
1437
Max72dfd432018-12-04 11:24:18 +01001438 osmo_log_info->num_cat = ARRAY_SIZE(internal_cat);
1439
1440 if (inf) {
1441 osmo_log_info->filter_fn = inf->filter_fn;
1442 osmo_log_info->num_cat_user = inf->num_cat;
1443 osmo_log_info->num_cat += inf->num_cat;
1444 }
Harald Welteb43bc042011-06-27 10:29:17 +02001445
Philipp Maierdcad1c52020-03-25 11:25:59 +01001446 cat_ptr = talloc_zero_array(osmo_log_info, struct log_info_cat,
1447 osmo_log_info->num_cat);
1448 if (!cat_ptr) {
Harald Welteb43bc042011-06-27 10:29:17 +02001449 talloc_free(osmo_log_info);
1450 osmo_log_info = NULL;
1451 return -ENOMEM;
1452 }
1453
Philipp Maierdcad1c52020-03-25 11:25:59 +01001454 /* copy over the user part and sanitize loglevel */
1455 if (inf) {
Max72dfd432018-12-04 11:24:18 +01001456 for (i = 0; i < inf->num_cat; i++) {
Philipp Maierdcad1c52020-03-25 11:25:59 +01001457 memcpy(&cat_ptr[i], &inf->cat[i],
1458 sizeof(struct log_info_cat));
1459
1460 /* Make sure that the loglevel is set to NOTICE in case
1461 * no loglevel has been preset. */
1462 if (!cat_ptr[i].loglevel) {
1463 cat_ptr[i].loglevel = LOGL_NOTICE;
1464 }
Max72dfd432018-12-04 11:24:18 +01001465 }
Harald Welteb43bc042011-06-27 10:29:17 +02001466 }
1467
1468 /* copy over the library part */
Harald Welte9fe16522011-06-27 14:00:03 +02001469 for (i = 0; i < ARRAY_SIZE(internal_cat); i++) {
Harald Weltece9fec32011-06-27 14:19:16 +02001470 unsigned int cn = osmo_log_info->num_cat_user + i;
Philipp Maierdcad1c52020-03-25 11:25:59 +01001471 memcpy(&cat_ptr[cn], &internal_cat[i], sizeof(struct log_info_cat));
Harald Welte9fe16522011-06-27 14:00:03 +02001472 }
1473
Philipp Maierdcad1c52020-03-25 11:25:59 +01001474 osmo_log_info->cat = cat_ptr;
1475
Harald Welte9fe16522011-06-27 14:00:03 +02001476 return 0;
Harald Welte4a2bb9e2010-03-26 09:33:40 +08001477}
Harald Welte18fc4652011-08-17 14:14:17 +02001478
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001479/* De-initialize the Osmocom logging core
Harald Welte69e6c3c2016-04-20 10:41:27 +02001480 * This function destroys all targets and releases associated memory */
1481void log_fini(void)
1482{
1483 struct log_target *tar, *tar2;
1484
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001485 log_tgt_mutex_lock();
1486
Harald Welte69e6c3c2016-04-20 10:41:27 +02001487 llist_for_each_entry_safe(tar, tar2, &osmo_log_target_list, entry)
1488 log_target_destroy(tar);
1489
1490 talloc_free(osmo_log_info);
1491 osmo_log_info = NULL;
1492 talloc_free(tall_log_ctx);
1493 tall_log_ctx = NULL;
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001494
1495 log_tgt_mutex_unlock();
Harald Welte69e6c3c2016-04-20 10:41:27 +02001496}
1497
Neels Hofmeyr87e45502017-06-20 00:17:59 +02001498/*! Check whether a log entry will be generated.
Jacob Erlbeckde6dd722015-11-17 11:52:24 +01001499 * \returns != 0 if a log entry might get generated by at least one target */
1500int log_check_level(int subsys, unsigned int level)
1501{
1502 struct log_target *tar;
1503
Max68bf16a2018-01-10 17:00:43 +01001504 assert_loginfo(__func__);
Harald Welte18a7d812017-03-16 23:54:55 +01001505
Holger Hans Peter Freythere0dc6a12015-12-21 14:45:16 +01001506 subsys = map_subsys(subsys);
Jacob Erlbeckde6dd722015-11-17 11:52:24 +01001507
1508 /* TODO: The following could/should be cached (update on config) */
1509
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001510 log_tgt_mutex_lock();
1511
Jacob Erlbeckde6dd722015-11-17 11:52:24 +01001512 llist_for_each_entry(tar, &osmo_log_target_list, entry) {
Maxc65c5b42017-03-15 13:20:23 +01001513 if (!should_log_to_target(tar, subsys, level))
Jacob Erlbeckde6dd722015-11-17 11:52:24 +01001514 continue;
1515
1516 /* This might get logged (ignoring filters) */
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001517 log_tgt_mutex_unlock();
Jacob Erlbeckde6dd722015-11-17 11:52:24 +01001518 return 1;
1519 }
1520
1521 /* We are sure, that this will not be logged. */
Pau Espin Pedrold12f6982019-09-17 18:38:58 +02001522 log_tgt_mutex_unlock();
Jacob Erlbeckde6dd722015-11-17 11:52:24 +01001523 return 0;
1524}
1525
Sylvain Munautdca7d2c2012-04-18 21:53:23 +02001526/*! @} */