2014-06-16 08:13:40 +00:00
|
|
|
#pragma once
|
2010-03-26 13:24:24 +00:00
|
|
|
|
2011-08-17 12:14:17 +00:00
|
|
|
/*! \defgroup logging Osmocom logging framework
|
|
|
|
|
* @{
|
2017-06-20 02:35:06 +00:00
|
|
|
* \file logging.h */
|
2011-08-17 12:14:17 +00:00
|
|
|
|
2010-03-26 13:24:24 +00:00
|
|
|
#include <stdio.h>
|
|
|
|
|
#include <stdint.h>
|
2011-09-01 14:22:17 +00:00
|
|
|
#include <stdarg.h>
|
2016-12-02 14:30:02 +00:00
|
|
|
#include <stdbool.h>
|
2017-01-13 10:01:12 +00:00
|
|
|
#include <osmocom/core/defs.h>
|
2011-03-22 15:36:13 +00:00
|
|
|
#include <osmocom/core/linuxlist.h>
|
2010-03-26 13:24:24 +00:00
|
|
|
|
2019-06-13 11:41:00 +00:00
|
|
|
#ifndef DEBUG
|
2010-03-26 13:24:24 +00:00
|
|
|
#define DEBUG
|
2019-06-13 11:41:00 +00:00
|
|
|
#endif
|
2010-03-26 13:24:24 +00:00
|
|
|
|
2021-11-24 19:24:46 +00:00
|
|
|
#ifdef LIBOSMOCORE_NO_LOGGING
|
|
|
|
|
#undef DEBUG
|
|
|
|
|
#endif
|
|
|
|
|
|
2010-03-26 13:24:24 +00:00
|
|
|
#ifdef DEBUG
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Log a debug message through the Osmocom logging framework
|
2016-04-25 10:11:20 +00:00
|
|
|
* \param[in] ss logging subsystem (e.g. \ref DLGLOBAL)
|
|
|
|
|
* \param[in] fmt format string
|
|
|
|
|
* \param[in] args variable argument list
|
|
|
|
|
*/
|
2017-01-13 10:01:12 +00:00
|
|
|
#define DEBUGP(ss, fmt, args...) LOGP(ss, LOGL_DEBUG, fmt, ##args)
|
|
|
|
|
#define DEBUGPC(ss, fmt, args...) LOGPC(ss, LOGL_DEBUG, fmt, ##args)
|
2010-03-26 13:24:24 +00:00
|
|
|
#else
|
|
|
|
|
#define DEBUGP(xss, fmt, args...)
|
|
|
|
|
#define DEBUGPC(ss, fmt, args...)
|
|
|
|
|
#endif
|
|
|
|
|
|
|
|
|
|
|
2012-07-12 07:26:25 +00:00
|
|
|
void osmo_vlogp(int subsys, int level, const char *file, int line,
|
2011-08-27 12:33:19 +00:00
|
|
|
int cont, const char *format, va_list ap);
|
|
|
|
|
|
2017-01-13 10:01:12 +00:00
|
|
|
void logp(int subsys, const char *file, int line, int cont, const char *format, ...) OSMO_DEPRECATED("Use DEBUGP* macros instead");
|
2010-03-26 13:24:24 +00:00
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Log a new message through the Osmocom logging framework
|
2011-08-16 21:26:52 +00:00
|
|
|
* \param[in] ss logging subsystem (e.g. \ref DLGLOBAL)
|
|
|
|
|
* \param[in] level logging level (e.g. \ref LOGL_NOTICE)
|
|
|
|
|
* \param[in] fmt format string
|
|
|
|
|
* \param[in] args variable argument list
|
|
|
|
|
*/
|
2010-03-26 13:24:24 +00:00
|
|
|
#define LOGP(ss, level, fmt, args...) \
|
fsm: log caller's source for events and state changes, not fsm.c lines
When looking at log output, it is not interesting to see that a state
transition's petty details are implemented in fsm.c. Rather log the *caller's*
source file and line that caused an event, state change and cascading events.
To that end, introduce LOGPSRC() absorbing the guts of LOGP(), to be able to
explicitly pass the source file and line information.
Prepend an underscore to the function names of osmo_fsm_inst_state_chg(),
osmo_fsm_inst_dispatch() and osmo_fsm_inst_term(), and add file and line
arguments to them. Provide the previous names as macros that insert the
caller's __BASE_FILE__ and __LINE__ constants for the new arguments. Hence no
calling code needs to be changed.
In fsm.c, add LOGPFSMSRC to call LOGPSRC, and add LOGPFSMLSRC, and use them in
above _osmo_fsm_inst_* functions.
In addition, in _osmo_fsm_inst_term(), pass the caller's source file and line
on to nested event dispatches, so showing where a cascade originated from.
Change-Id: Iae72aba7bbf99e19dd584ccabea5867210650dcd
2016-12-14 16:24:54 +00:00
|
|
|
LOGPSRC(ss, level, NULL, 0, fmt, ## args)
|
2011-08-16 21:26:52 +00:00
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Continue a log message through the Osmocom logging framework
|
2011-08-16 21:26:52 +00:00
|
|
|
* \param[in] ss logging subsystem (e.g. \ref DLGLOBAL)
|
|
|
|
|
* \param[in] level logging level (e.g. \ref LOGL_NOTICE)
|
|
|
|
|
* \param[in] fmt format string
|
|
|
|
|
* \param[in] args variable argument list
|
|
|
|
|
*/
|
2021-11-26 20:09:01 +00:00
|
|
|
#ifndef LIBOSMOCORE_NO_LOGGING
|
2010-03-26 13:24:24 +00:00
|
|
|
#define LOGPC(ss, level, fmt, args...) \
|
2015-11-17 10:52:25 +00:00
|
|
|
do { \
|
|
|
|
|
if (log_check_level(ss, level)) \
|
2018-08-20 10:33:22 +00:00
|
|
|
logp2(ss, level, __FILE__, __LINE__, 1, fmt, ##args); \
|
2015-11-17 10:52:25 +00:00
|
|
|
} while(0)
|
2021-11-26 20:09:01 +00:00
|
|
|
#else
|
|
|
|
|
#define LOGPC(ss, level, fmt, args...)
|
|
|
|
|
#endif
|
2010-03-26 13:24:24 +00:00
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Log through the Osmocom logging framework with explicit source.
|
2018-08-20 10:33:22 +00:00
|
|
|
* If caller_file is passed as NULL, __FILE__ and __LINE__ are used
|
fsm: log caller's source for events and state changes, not fsm.c lines
When looking at log output, it is not interesting to see that a state
transition's petty details are implemented in fsm.c. Rather log the *caller's*
source file and line that caused an event, state change and cascading events.
To that end, introduce LOGPSRC() absorbing the guts of LOGP(), to be able to
explicitly pass the source file and line information.
Prepend an underscore to the function names of osmo_fsm_inst_state_chg(),
osmo_fsm_inst_dispatch() and osmo_fsm_inst_term(), and add file and line
arguments to them. Provide the previous names as macros that insert the
caller's __BASE_FILE__ and __LINE__ constants for the new arguments. Hence no
calling code needs to be changed.
In fsm.c, add LOGPFSMSRC to call LOGPSRC, and add LOGPFSMLSRC, and use them in
above _osmo_fsm_inst_* functions.
In addition, in _osmo_fsm_inst_term(), pass the caller's source file and line
on to nested event dispatches, so showing where a cascade originated from.
Change-Id: Iae72aba7bbf99e19dd584ccabea5867210650dcd
2016-12-14 16:24:54 +00:00
|
|
|
* instead of caller_file and caller_line (so that this macro here defines
|
|
|
|
|
* both cases in the same place, and to catch cases where callers fail to pass
|
|
|
|
|
* a non-null filename string).
|
|
|
|
|
* \param[in] ss logging subsystem (e.g. \ref DLGLOBAL)
|
|
|
|
|
* \param[in] level logging level (e.g. \ref LOGL_NOTICE)
|
2018-08-20 10:33:22 +00:00
|
|
|
* \param[in] caller_file caller's source file string (e.g. __FILE__)
|
fsm: log caller's source for events and state changes, not fsm.c lines
When looking at log output, it is not interesting to see that a state
transition's petty details are implemented in fsm.c. Rather log the *caller's*
source file and line that caused an event, state change and cascading events.
To that end, introduce LOGPSRC() absorbing the guts of LOGP(), to be able to
explicitly pass the source file and line information.
Prepend an underscore to the function names of osmo_fsm_inst_state_chg(),
osmo_fsm_inst_dispatch() and osmo_fsm_inst_term(), and add file and line
arguments to them. Provide the previous names as macros that insert the
caller's __BASE_FILE__ and __LINE__ constants for the new arguments. Hence no
calling code needs to be changed.
In fsm.c, add LOGPFSMSRC to call LOGPSRC, and add LOGPFSMLSRC, and use them in
above _osmo_fsm_inst_* functions.
In addition, in _osmo_fsm_inst_term(), pass the caller's source file and line
on to nested event dispatches, so showing where a cascade originated from.
Change-Id: Iae72aba7bbf99e19dd584ccabea5867210650dcd
2016-12-14 16:24:54 +00:00
|
|
|
* \param[in] caller_line caller's source line nr (e.g. __LINE__)
|
|
|
|
|
* \param[in] fmt format string
|
|
|
|
|
* \param[in] args variable argument list
|
|
|
|
|
*/
|
|
|
|
|
#define LOGPSRC(ss, level, caller_file, caller_line, fmt, args...) \
|
2017-11-29 03:46:39 +00:00
|
|
|
LOGPSRCC(ss, level, caller_file, caller_line, 0, fmt, ##args)
|
|
|
|
|
|
|
|
|
|
/*! Log through the Osmocom logging framework with explicit source.
|
2018-08-20 10:33:22 +00:00
|
|
|
* If caller_file is passed as NULL, __FILE__ and __LINE__ are used
|
2017-11-29 03:46:39 +00:00
|
|
|
* instead of caller_file and caller_line (so that this macro here defines
|
|
|
|
|
* both cases in the same place, and to catch cases where callers fail to pass
|
|
|
|
|
* a non-null filename string).
|
|
|
|
|
* \param[in] ss logging subsystem (e.g. \ref DLGLOBAL)
|
|
|
|
|
* \param[in] level logging level (e.g. \ref LOGL_NOTICE)
|
2018-08-20 10:33:22 +00:00
|
|
|
* \param[in] caller_file caller's source file string (e.g. __FILE__)
|
2017-11-29 03:46:39 +00:00
|
|
|
* \param[in] caller_line caller's source line nr (e.g. __LINE__)
|
|
|
|
|
* \param[in] cont continuation (1) or new line (0)
|
|
|
|
|
* \param[in] fmt format string
|
|
|
|
|
* \param[in] args variable argument list
|
|
|
|
|
*/
|
2021-11-26 20:09:01 +00:00
|
|
|
#ifndef LIBOSMOCORE_NO_LOGGING
|
2017-11-29 03:46:39 +00:00
|
|
|
#define LOGPSRCC(ss, level, caller_file, caller_line, cont, fmt, args...) \
|
fsm: log caller's source for events and state changes, not fsm.c lines
When looking at log output, it is not interesting to see that a state
transition's petty details are implemented in fsm.c. Rather log the *caller's*
source file and line that caused an event, state change and cascading events.
To that end, introduce LOGPSRC() absorbing the guts of LOGP(), to be able to
explicitly pass the source file and line information.
Prepend an underscore to the function names of osmo_fsm_inst_state_chg(),
osmo_fsm_inst_dispatch() and osmo_fsm_inst_term(), and add file and line
arguments to them. Provide the previous names as macros that insert the
caller's __BASE_FILE__ and __LINE__ constants for the new arguments. Hence no
calling code needs to be changed.
In fsm.c, add LOGPFSMSRC to call LOGPSRC, and add LOGPFSMLSRC, and use them in
above _osmo_fsm_inst_* functions.
In addition, in _osmo_fsm_inst_term(), pass the caller's source file and line
on to nested event dispatches, so showing where a cascade originated from.
Change-Id: Iae72aba7bbf99e19dd584ccabea5867210650dcd
2016-12-14 16:24:54 +00:00
|
|
|
do { \
|
|
|
|
|
if (log_check_level(ss, level)) {\
|
|
|
|
|
if (caller_file) \
|
2017-11-29 03:46:39 +00:00
|
|
|
logp2(ss, level, caller_file, caller_line, cont, fmt, ##args); \
|
fsm: log caller's source for events and state changes, not fsm.c lines
When looking at log output, it is not interesting to see that a state
transition's petty details are implemented in fsm.c. Rather log the *caller's*
source file and line that caused an event, state change and cascading events.
To that end, introduce LOGPSRC() absorbing the guts of LOGP(), to be able to
explicitly pass the source file and line information.
Prepend an underscore to the function names of osmo_fsm_inst_state_chg(),
osmo_fsm_inst_dispatch() and osmo_fsm_inst_term(), and add file and line
arguments to them. Provide the previous names as macros that insert the
caller's __BASE_FILE__ and __LINE__ constants for the new arguments. Hence no
calling code needs to be changed.
In fsm.c, add LOGPFSMSRC to call LOGPSRC, and add LOGPFSMLSRC, and use them in
above _osmo_fsm_inst_* functions.
In addition, in _osmo_fsm_inst_term(), pass the caller's source file and line
on to nested event dispatches, so showing where a cascade originated from.
Change-Id: Iae72aba7bbf99e19dd584ccabea5867210650dcd
2016-12-14 16:24:54 +00:00
|
|
|
else \
|
2018-08-20 10:33:22 +00:00
|
|
|
logp2(ss, level, __FILE__, __LINE__, cont, fmt, ##args); \
|
fsm: log caller's source for events and state changes, not fsm.c lines
When looking at log output, it is not interesting to see that a state
transition's petty details are implemented in fsm.c. Rather log the *caller's*
source file and line that caused an event, state change and cascading events.
To that end, introduce LOGPSRC() absorbing the guts of LOGP(), to be able to
explicitly pass the source file and line information.
Prepend an underscore to the function names of osmo_fsm_inst_state_chg(),
osmo_fsm_inst_dispatch() and osmo_fsm_inst_term(), and add file and line
arguments to them. Provide the previous names as macros that insert the
caller's __BASE_FILE__ and __LINE__ constants for the new arguments. Hence no
calling code needs to be changed.
In fsm.c, add LOGPFSMSRC to call LOGPSRC, and add LOGPFSMLSRC, and use them in
above _osmo_fsm_inst_* functions.
In addition, in _osmo_fsm_inst_term(), pass the caller's source file and line
on to nested event dispatches, so showing where a cascade originated from.
Change-Id: Iae72aba7bbf99e19dd584ccabea5867210650dcd
2016-12-14 16:24:54 +00:00
|
|
|
}\
|
|
|
|
|
} while(0)
|
2021-11-26 20:09:01 +00:00
|
|
|
#else
|
|
|
|
|
#define LOGPSRCC(ss, level, caller_file, caller_line, cont, fmt, args...)
|
|
|
|
|
#endif
|
fsm: log caller's source for events and state changes, not fsm.c lines
When looking at log output, it is not interesting to see that a state
transition's petty details are implemented in fsm.c. Rather log the *caller's*
source file and line that caused an event, state change and cascading events.
To that end, introduce LOGPSRC() absorbing the guts of LOGP(), to be able to
explicitly pass the source file and line information.
Prepend an underscore to the function names of osmo_fsm_inst_state_chg(),
osmo_fsm_inst_dispatch() and osmo_fsm_inst_term(), and add file and line
arguments to them. Provide the previous names as macros that insert the
caller's __BASE_FILE__ and __LINE__ constants for the new arguments. Hence no
calling code needs to be changed.
In fsm.c, add LOGPFSMSRC to call LOGPSRC, and add LOGPFSMLSRC, and use them in
above _osmo_fsm_inst_* functions.
In addition, in _osmo_fsm_inst_term(), pass the caller's source file and line
on to nested event dispatches, so showing where a cascade originated from.
Change-Id: Iae72aba7bbf99e19dd584ccabea5867210650dcd
2016-12-14 16:24:54 +00:00
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! different log levels */
|
|
|
|
|
#define LOGL_DEBUG 1 /*!< debugging information */
|
|
|
|
|
#define LOGL_INFO 3 /*!< general information */
|
|
|
|
|
#define LOGL_NOTICE 5 /*!< abnormal/unexpected condition */
|
|
|
|
|
#define LOGL_ERROR 7 /*!< error condition, requires user action */
|
|
|
|
|
#define LOGL_FATAL 8 /*!< fatal, program aborted */
|
2010-03-26 13:24:24 +00:00
|
|
|
|
2019-11-20 03:28:52 +00:00
|
|
|
/* logging subsystems defined by the library itself */
|
2016-04-25 10:11:20 +00:00
|
|
|
#define DLGLOBAL -1 /*!< global logging */
|
|
|
|
|
#define DLLAPD -2 /*!< LAPD implementation */
|
|
|
|
|
#define DLINP -3 /*!< (A-bis) Input sub-system */
|
|
|
|
|
#define DLMUX -4 /*!< Osmocom Multiplex (Osmux) */
|
|
|
|
|
#define DLMI -5 /*!< ISDN-layer below input sub-system */
|
|
|
|
|
#define DLMIB -6 /*!< ISDN layer B-channel */
|
|
|
|
|
#define DLSMS -7 /*!< SMS sub-system */
|
|
|
|
|
#define DLCTRL -8 /*!< Control Interface */
|
|
|
|
|
#define DLGTP -9 /*!< GTP (GPRS Tunneling Protocol */
|
|
|
|
|
#define DLSTATS -10 /*!< Statistics */
|
2016-12-10 16:01:06 +00:00
|
|
|
#define DLGSUP -11 /*!< Generic Subscriber Update Protocol */
|
2016-04-27 16:32:35 +00:00
|
|
|
#define DLOAP -12 /*!< Osmocom Authentication Protocol */
|
2017-04-03 17:37:11 +00:00
|
|
|
#define DLSS7 -13 /*!< Osmocom SS7 */
|
|
|
|
|
#define DLSCCP -14 /*!< Osmocom SCCP */
|
|
|
|
|
#define DLSUA -15 /*!< Osmocom SUA */
|
|
|
|
|
#define DLM3UA -16 /*!< Osmocom M3UA */
|
2017-07-11 16:43:09 +00:00
|
|
|
#define DLMGCP -17 /*!< Osmocom MGCP */
|
2018-02-27 18:43:10 +00:00
|
|
|
#define DLJIBUF -18 /*!< Osmocom Jitter Buffer */
|
2018-08-13 18:54:44 +00:00
|
|
|
#define DLRSPRO -19 /*!< Osmocom Remote SIM Protocol */
|
2020-07-12 11:45:50 +00:00
|
|
|
#define DLNS -20 /*!< Osmocom NS layer */
|
2020-12-07 20:43:51 +00:00
|
|
|
#define DLBSSGP -21 /*!< Osmocom BSSGP layer */
|
2021-01-18 16:55:35 +00:00
|
|
|
#define DLNSDATA -22 /*!< Osmocom NS layer data pdus */
|
|
|
|
|
#define DLNSSIGNAL -23 /*!< Osmocom NS layer signal pdus */
|
2018-11-29 12:47:39 +00:00
|
|
|
#define DLIUUP -24 /*!< Osmocom IuUP layer */
|
|
|
|
|
#define OSMO_NUM_DLIB 24 /*!< Number of logging sub-systems in libraries */
|
2016-04-25 10:11:20 +00:00
|
|
|
|
2019-11-20 03:00:29 +00:00
|
|
|
/* Colors that can be used in log_info_cat.color */
|
|
|
|
|
#define OSMO_LOGCOLOR_NORMAL NULL
|
|
|
|
|
#define OSMO_LOGCOLOR_RED "\033[1;31m"
|
|
|
|
|
#define OSMO_LOGCOLOR_GREEN "\033[1;32m"
|
|
|
|
|
#define OSMO_LOGCOLOR_YELLOW "\033[1;33m"
|
|
|
|
|
#define OSMO_LOGCOLOR_BLUE "\033[1;34m"
|
|
|
|
|
#define OSMO_LOGCOLOR_PURPLE "\033[1;35m"
|
|
|
|
|
#define OSMO_LOGCOLOR_CYAN "\033[1;36m"
|
|
|
|
|
#define OSMO_LOGCOLOR_DARKRED "\033[31m"
|
|
|
|
|
#define OSMO_LOGCOLOR_DARKGREEN "\033[32m"
|
|
|
|
|
#define OSMO_LOGCOLOR_DARKYELLOW "\033[33m"
|
|
|
|
|
#define OSMO_LOGCOLOR_DARKBLUE "\033[34m"
|
|
|
|
|
#define OSMO_LOGCOLOR_DARKPURPLE "\033[35m"
|
|
|
|
|
#define OSMO_LOGCOLOR_DARKCYAN "\033[36m"
|
|
|
|
|
#define OSMO_LOGCOLOR_DARKGREY "\033[1;30m"
|
|
|
|
|
#define OSMO_LOGCOLOR_GREY "\033[37m"
|
|
|
|
|
#define OSMO_LOGCOLOR_BRIGHTWHITE "\033[1;37m"
|
|
|
|
|
#define OSMO_LOGCOLOR_END "\033[0;m"
|
|
|
|
|
|
2017-06-20 02:29:38 +00:00
|
|
|
/*! Configuration of single log category / sub-system */
|
2010-03-26 13:24:24 +00:00
|
|
|
struct log_category {
|
2016-04-25 10:11:20 +00:00
|
|
|
uint8_t loglevel; /*!< configured log-level */
|
|
|
|
|
uint8_t enabled; /*!< is logging enabled? */
|
2010-03-26 13:24:24 +00:00
|
|
|
};
|
|
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Information regarding one logging category */
|
2010-03-26 13:24:24 +00:00
|
|
|
struct log_info_cat {
|
2011-08-17 12:14:17 +00:00
|
|
|
const char *name; /*!< name of category */
|
|
|
|
|
const char *color; /*!< color string for cateyory */
|
|
|
|
|
const char *description; /*!< description text */
|
|
|
|
|
uint8_t loglevel; /*!< currently selected log-level */
|
|
|
|
|
uint8_t enabled; /*!< is this category enabled or not */
|
2010-03-26 13:24:24 +00:00
|
|
|
};
|
|
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Indexes to indicate the object currently acted upon.
|
2017-02-23 16:45:26 +00:00
|
|
|
* Array indexes for the global \a log_context array. */
|
2017-02-23 17:03:28 +00:00
|
|
|
enum log_ctx_index {
|
|
|
|
|
LOG_CTX_GB_NSVC,
|
|
|
|
|
LOG_CTX_GB_BVC,
|
|
|
|
|
LOG_CTX_BSC_SUBSCR,
|
|
|
|
|
LOG_CTX_VLR_SUBSCR,
|
2019-09-12 15:13:34 +00:00
|
|
|
LOG_CTX_L1_SAPI,
|
2020-12-02 17:59:44 +00:00
|
|
|
LOG_CTX_GB_NSE,
|
2017-02-23 17:03:28 +00:00
|
|
|
_LOG_CTX_COUNT
|
2017-02-17 15:35:27 +00:00
|
|
|
};
|
|
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Indexes to indicate objects that should be logged.
|
2017-02-23 16:45:26 +00:00
|
|
|
* Array indexes to log_target->filter_data and bit indexes for
|
|
|
|
|
* log_target->filter_map. */
|
2017-02-23 17:03:28 +00:00
|
|
|
enum log_filter_index {
|
|
|
|
|
LOG_FLT_ALL,
|
|
|
|
|
LOG_FLT_GB_NSVC,
|
|
|
|
|
LOG_FLT_GB_BVC,
|
|
|
|
|
LOG_FLT_BSC_SUBSCR,
|
|
|
|
|
LOG_FLT_VLR_SUBSCR,
|
2019-09-12 15:13:34 +00:00
|
|
|
LOG_FLT_L1_SAPI,
|
2020-12-02 17:59:44 +00:00
|
|
|
LOG_FLT_GB_NSE,
|
2017-02-23 17:03:28 +00:00
|
|
|
_LOG_FLT_COUNT
|
2017-02-17 15:35:27 +00:00
|
|
|
};
|
|
|
|
|
|
2020-12-02 17:14:17 +00:00
|
|
|
/*! Maximum number of logging contexts */
|
|
|
|
|
#define LOG_MAX_CTX _LOG_CTX_COUNT
|
|
|
|
|
/*! Maximum number of logging filters */
|
|
|
|
|
#define LOG_MAX_FILTERS _LOG_FLT_COUNT
|
|
|
|
|
|
|
|
|
|
/*! Log context information, passed to filter */
|
|
|
|
|
struct log_context {
|
|
|
|
|
void *ctx[LOG_MAX_CTX+1];
|
|
|
|
|
};
|
|
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Compatibility with older libosmocore versions */
|
2017-02-23 17:03:28 +00:00
|
|
|
#define LOG_FILTER_ALL (1<<LOG_FLT_ALL)
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Compatibility with older libosmocore versions */
|
2017-02-23 17:03:28 +00:00
|
|
|
#define GPRS_CTX_NSVC LOG_CTX_GB_NSVC
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Compatibility with older libosmocore versions */
|
2017-02-23 17:03:28 +00:00
|
|
|
#define GPRS_CTX_BVC LOG_CTX_GB_BVC
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Indexes to indicate the object currently acted upon.
|
2017-02-23 17:03:28 +00:00
|
|
|
* Array indexes for the global \a log_context array. */
|
2017-02-23 16:34:35 +00:00
|
|
|
|
2010-03-26 13:24:24 +00:00
|
|
|
struct log_target;
|
|
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Log filter function */
|
2010-03-26 13:24:24 +00:00
|
|
|
typedef int log_filter(const struct log_context *ctx,
|
|
|
|
|
struct log_target *target);
|
|
|
|
|
|
2013-06-06 05:33:54 +00:00
|
|
|
struct log_info;
|
|
|
|
|
struct vty;
|
2016-12-02 14:30:02 +00:00
|
|
|
struct gsmtap_inst;
|
2013-06-06 05:33:54 +00:00
|
|
|
|
|
|
|
|
typedef void log_print_filters(struct vty *vty,
|
|
|
|
|
const struct log_info *info,
|
|
|
|
|
const struct log_target *tgt);
|
|
|
|
|
|
|
|
|
|
typedef void log_save_filters(struct vty *vty,
|
|
|
|
|
const struct log_info *info,
|
|
|
|
|
const struct log_target *tgt);
|
|
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Logging configuration, passed to \ref log_init */
|
2010-03-26 13:24:24 +00:00
|
|
|
struct log_info {
|
2017-06-19 22:17:59 +00:00
|
|
|
/* filter callback function */
|
2010-03-26 13:24:24 +00:00
|
|
|
log_filter *filter_fn;
|
|
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! per-category information */
|
2012-09-11 08:31:29 +00:00
|
|
|
const struct log_info_cat *cat;
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! total number of categories */
|
2010-03-26 13:24:24 +00:00
|
|
|
unsigned int num_cat;
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! total number of user categories (not library) */
|
2011-06-27 08:29:17 +00:00
|
|
|
unsigned int num_cat_user;
|
2013-06-06 05:33:54 +00:00
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! filter saving function */
|
2013-06-06 05:33:54 +00:00
|
|
|
log_save_filters *save_fn;
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! filter saving function */
|
2013-06-06 05:33:54 +00:00
|
|
|
log_print_filters *print_fn;
|
2010-03-26 13:24:24 +00:00
|
|
|
};
|
|
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Type of logging target */
|
2011-02-18 19:37:04 +00:00
|
|
|
enum log_target_type {
|
2017-06-19 22:17:59 +00:00
|
|
|
LOG_TGT_TYPE_VTY, /*!< VTY logging */
|
|
|
|
|
LOG_TGT_TYPE_SYSLOG, /*!< syslog based logging */
|
|
|
|
|
LOG_TGT_TYPE_FILE, /*!< text file logging */
|
|
|
|
|
LOG_TGT_TYPE_STDERR, /*!< stderr logging */
|
|
|
|
|
LOG_TGT_TYPE_STRRB, /*!< osmo_strrb-backed logging */
|
|
|
|
|
LOG_TGT_TYPE_GSMTAP, /*!< GSMTAP network logging */
|
logging: introduce 'systemd-journal' target
This change implements 'systemd-journal' logging target, that is
similar to the existing 'syslog' target. The key difference is
that 'systemd-journal' allows us to offload rendering of the meta
information, such as location (file name, line number), subsystem,
and logging level, to systemd. Moreover, we can attach arbitrary,
user-specific fields [1] to the logging messages, so they can be
used for advanced log filtering (e.g. by IMSI/TMSI/TLLI):
$ journalctl OSMO_SUBSYS=DMSC -f
Since we don't want to make libsystemd a required dependency, this
feature is optional, and needs to be enabled at build-time:
$ ./configure --enable-systemd-logging
The new logging target can be configured in the same way as any
other one - via the VTY interface, or using the configuration file:
log systemd-journal [raw]
logging level set-all notice
logging filter all 1
Two logging handlers are available: generic and raw. The first one
behaves similarly to both 'syslog' and 'stderr', i.e. all the meta
information is rendered by libosmocore itself, and then passed to
systemd together with the logging message. The later is more like
the 'gsmtap' target, so all available meta information is handed
over to systemd in form of fields [1]:
- CODE_FILE / CODE_LINE - location info,
- PRIORITY - syslog-compatible logging level,
- OSMO_SUBSYS - Osmocom-specific sub-system (e.g. DMSC),
- OSMO_SUBSYS_HEX - same as OSMO_SUBSYS, but encoded in hex,
- MESSAGE - the logging message itself,
and then can be rendered in any supported format (e.g. JSON).
More details about the API can be found in [2].
[1] https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html
[2] https://www.freedesktop.org/software/systemd/man/sd-journal.html
Change-Id: I609f5cf438e6ad9038d8fc95f00add6aac29fb23
2020-09-08 20:36:48 +00:00
|
|
|
LOG_TGT_TYPE_SYSTEMD, /*!< systemd journal logging */
|
2011-02-18 19:37:04 +00:00
|
|
|
};
|
|
|
|
|
|
2018-01-16 00:52:29 +00:00
|
|
|
/*! Whether/how to log the source filename (and line number). */
|
|
|
|
|
enum log_filename_type {
|
|
|
|
|
LOG_FILENAME_NONE,
|
|
|
|
|
LOG_FILENAME_PATH,
|
2018-01-16 01:49:48 +00:00
|
|
|
LOG_FILENAME_BASENAME,
|
2018-01-16 00:52:29 +00:00
|
|
|
};
|
|
|
|
|
|
log: add 'last' option to 'logging print file'
Allow printing the source file information *after* the log information.
Add target->print_filename_pos, log_set_print_filename_pos() and enum
log_filename_pos, and the optional 'last' keyword to the 'logging print file'
vty command. (An enum in case we want to add other positions later.)
Rationale: on log lines, the logging context is usually printed first in the
logging text. Without the source file information, this logging context pretty
much aligns in an easily readable way. When adding the source file information,
each line's logging context info is shifted right by a pretty much random
amount and it is hard to spot recurring logging contexts.
One solution is to switch off source file info, of course, but that's not an
option when actively hacking on bugs and new features.
For example, it is unnecessarily hard to spot lchan FSM related log lines in
this osmo-bsc log snippet:
DRSL NOTICE mgw_endpoint_fsm.c:603 mgw-endpoint(conn0){WAIT_MGW_RESPONSE}: Freeing instance
DRSL NOTICE fsm.c:381 mgw-endpoint(conn0){WAIT_MGW_RESPONSE}: Deallocated
DMSC NOTICE mgw_endpoint_fsm.c:603 SUBSCR_CONN(conn0){CLEARING}: Received Event FORGET_MGW_ENDPOINT
DCHAN DEBUG lchan_rtp_fsm.c:741 lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED
DCHAN DEBUG lchan_rtp_fsm.c:520 lchan_rtp(0-0-1-TCH_F-0){ROLLBACK}: Freeing instance
DCHAN DEBUG fsm.c:381 lchan_rtp(0-0-1-TCH_F-0){ROLLBACK}: Deallocated
DCHAN DEBUG lchan_rtp_fsm.c:520 lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED
DCHAN DEBUG lchan_fsm.c:1232 lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: state_chg to WAIT_RF_RELEASE_ACK
DRSL NOTICE handover_fsm.c:762 handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DRSL NOTICE handover_fsm.c:762 handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Freeing instance
DRSL NOTICE fsm.c:381 handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Deallocated
DCHAN DEBUG lchan_fsm.c:1196 lchan(0-0-1-TCH_F-0){WAIT_RF_RELEASE_ACK}: state_chg to BORKEN
DCHAN DEBUG lchan_fsm.c:354 lchan(0-0-1-TCH_F-0){BORKEN}: (type=TCH_F) Clearing lchan state
DLMGCP DEBUG mgcp_client.c:741 Tx MGCP msg to MGCP GW: 'DLCX 3 2@mgw MGCP 1.0'
DLMGCP DEBUG mgcp_client.c:743 Sending msg to MGCP GW size: 66
DRLL NOTICE mgcp_client_fsm.c:422 MGCP_CONN(to-BTS){ST_DLCX_RESP}: Received Event EV_DLCX_RESP
Placing the source file info behind the log text makes it much easier to
follow, while the source file info is still available:
DRSL NOTICE mgw-endpoint(conn0){WAIT_MGW_RESPONSE}: Freeing instance (mgw_endpoint_fsm.c:603)
DRSL NOTICE mgw-endpoint(conn0){WAIT_MGW_RESPONSE}: Deallocated (fsm.c:381)
DMSC NOTICE SUBSCR_CONN(conn0){CLEARING}: Received Event FORGET_MGW_ENDPOINT (mgw_endpoint_fsm.c:603)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED (lchan_rtp_fsm.c:741)
DCHAN DEBUG lchan_rtp(0-0-1-TCH_F-0){ROLLBACK}: Freeing instance (lchan_rtp_fsm.c:520)
DCHAN DEBUG lchan_rtp(0-0-1-TCH_F-0){ROLLBACK}: Deallocated (fsm.c:381)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED (lchan_rtp_fsm.c:520)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: state_chg to WAIT_RF_RELEASE_ACK (lchan_fsm.c:1232)
DRSL NOTICE handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (handover_fsm.c:745)
DRSL NOTICE handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Freeing instance (handover_fsm.c:745)
DRSL NOTICE handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Deallocated (fsm.c:381)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){WAIT_RF_RELEASE_ACK}: state_chg to BORKEN (lchan_fsm.c:1196)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){BORKEN}: (type=TCH_F) Clearing lchan state (lchan_fsm.c:354)
DLMGCP DEBUG Tx MGCP msg to MGCP GW: 'DLCX 3 12@mgw MGCP 1.0' (mgcp_client.c:741)
DLMGCP DEBUG Sending msg to MGCP GW size: 67 (mgcp_client.c:743)
DRLL NOTICE MGCP_CONN(to-BTS){ST_DLCX_RESP}: Received Event EV_DLCX_RESP (mgcp_client_fsm.c:422)
Implementation: for 'last', insert source file info only when an '\n' is found
at the end of the log line composition buffer, so that LOGP()...LOGPC()
constructs also print source file info only when a log line actually ends.
Change-Id: I393907b3c9e0cc1145e102328adad0a83ee13a9f
2018-08-27 18:32:36 +00:00
|
|
|
/*! Where on a log line source file and line should be logged. */
|
|
|
|
|
enum log_filename_pos {
|
|
|
|
|
LOG_FILENAME_POS_HEADER_END,
|
|
|
|
|
LOG_FILENAME_POS_LINE_END,
|
|
|
|
|
};
|
|
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! structure representing a logging target */
|
2010-03-26 13:24:24 +00:00
|
|
|
struct log_target {
|
2017-06-19 22:17:59 +00:00
|
|
|
struct llist_head entry; /*!< linked list */
|
2010-03-26 13:24:24 +00:00
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Internal data for filtering */
|
2010-03-26 13:24:24 +00:00
|
|
|
int filter_map;
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! Internal data for filtering */
|
2010-03-26 13:24:24 +00:00
|
|
|
void *filter_data[LOG_MAX_FILTERS+1];
|
|
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! logging categories */
|
2011-06-27 08:29:17 +00:00
|
|
|
struct log_category *categories;
|
|
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! global log level */
|
2010-03-26 13:24:24 +00:00
|
|
|
uint8_t loglevel;
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! should color be used when printing log messages? */
|
2011-07-16 09:57:53 +00:00
|
|
|
unsigned int use_color:1;
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! should log messages be prefixed with a timestamp? */
|
2011-07-16 09:57:53 +00:00
|
|
|
unsigned int print_timestamp:1;
|
2021-02-18 17:19:23 +00:00
|
|
|
/*! should log messages be prefixed with the logger Thread ID? */
|
|
|
|
|
unsigned int print_tid:1;
|
2018-01-16 00:52:29 +00:00
|
|
|
/*! DEPRECATED: use print_filename2 instead. */
|
2012-09-11 09:24:51 +00:00
|
|
|
unsigned int print_filename:1;
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! should log messages be prefixed with a category name? */
|
2014-12-05 08:35:30 +00:00
|
|
|
unsigned int print_category:1;
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! should log messages be prefixed with an extended timestamp? */
|
2014-12-05 08:35:30 +00:00
|
|
|
unsigned int print_ext_timestamp:1;
|
2010-03-26 13:24:24 +00:00
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! the type of this log taget */
|
2011-02-18 19:37:04 +00:00
|
|
|
enum log_target_type type;
|
|
|
|
|
|
2010-03-26 13:24:24 +00:00
|
|
|
union {
|
|
|
|
|
struct {
|
logging: Change stderr + file target to use non-blocking write
So far, we used blocking, buffered fwrite() to write to stderr
and file targets. This causes problems if there are [slow] consumers
causing delays, such as gnome-terminal (when the program is started
interactively) or systemd/journald (where we observe 64..128ms blocks on
stderr).
This patch introduces stderr/file based logging via write_queue
and osmo_select_main(), i.e. switch from glibc-buffered, blocking
to internally buffered, non-blocking writes.
* when osmo_stderr_target is created via application.c, we create it
in blocking stream mode for backwards compatibility, particularly
for [smaller] programs that don't use osmo_select_main()
* when the VTY code encounters 'log stderr' or 'log file FILENAME',
we switch that respective target to non-blocking write-queue mode,
as this means the application is in fact using osmo_select_main()
* The config file can now state 'log stderr blocking-io' or
'log file FILENAME blocking-io' to explicitly enforce using blocking
stream based I/O
* The application can at any time use API functions to switch either way
Closes: OS#4311
Change-Id: Ia58fd78535c41b3da3aeb7733aadc785ace610da
2020-09-26 19:45:16 +00:00
|
|
|
/* direct, blocking output via stdio */
|
2010-03-26 13:24:24 +00:00
|
|
|
FILE *out;
|
2010-08-25 17:24:00 +00:00
|
|
|
const char *fname;
|
logging: Change stderr + file target to use non-blocking write
So far, we used blocking, buffered fwrite() to write to stderr
and file targets. This causes problems if there are [slow] consumers
causing delays, such as gnome-terminal (when the program is started
interactively) or systemd/journald (where we observe 64..128ms blocks on
stderr).
This patch introduces stderr/file based logging via write_queue
and osmo_select_main(), i.e. switch from glibc-buffered, blocking
to internally buffered, non-blocking writes.
* when osmo_stderr_target is created via application.c, we create it
in blocking stream mode for backwards compatibility, particularly
for [smaller] programs that don't use osmo_select_main()
* when the VTY code encounters 'log stderr' or 'log file FILENAME',
we switch that respective target to non-blocking write-queue mode,
as this means the application is in fact using osmo_select_main()
* The config file can now state 'log stderr blocking-io' or
'log file FILENAME blocking-io' to explicitly enforce using blocking
stream based I/O
* The application can at any time use API functions to switch either way
Closes: OS#4311
Change-Id: Ia58fd78535c41b3da3aeb7733aadc785ace610da
2020-09-26 19:45:16 +00:00
|
|
|
/* indirect output via write_queue and osmo_select_main() */
|
|
|
|
|
struct osmo_wqueue *wqueue;
|
2010-08-25 12:55:44 +00:00
|
|
|
} tgt_file;
|
2010-03-26 13:24:24 +00:00
|
|
|
|
|
|
|
|
struct {
|
|
|
|
|
int priority;
|
2011-02-18 19:37:04 +00:00
|
|
|
int facility;
|
2010-03-26 13:24:24 +00:00
|
|
|
} tgt_syslog;
|
|
|
|
|
|
|
|
|
|
struct {
|
|
|
|
|
void *vty;
|
|
|
|
|
} tgt_vty;
|
2013-02-21 05:16:29 +00:00
|
|
|
|
|
|
|
|
struct {
|
|
|
|
|
void *rb;
|
|
|
|
|
} tgt_rb;
|
2016-12-02 14:30:02 +00:00
|
|
|
|
|
|
|
|
struct {
|
|
|
|
|
struct gsmtap_inst *gsmtap_inst;
|
|
|
|
|
const char *ident;
|
|
|
|
|
const char *hostname;
|
|
|
|
|
} tgt_gsmtap;
|
logging: introduce 'systemd-journal' target
This change implements 'systemd-journal' logging target, that is
similar to the existing 'syslog' target. The key difference is
that 'systemd-journal' allows us to offload rendering of the meta
information, such as location (file name, line number), subsystem,
and logging level, to systemd. Moreover, we can attach arbitrary,
user-specific fields [1] to the logging messages, so they can be
used for advanced log filtering (e.g. by IMSI/TMSI/TLLI):
$ journalctl OSMO_SUBSYS=DMSC -f
Since we don't want to make libsystemd a required dependency, this
feature is optional, and needs to be enabled at build-time:
$ ./configure --enable-systemd-logging
The new logging target can be configured in the same way as any
other one - via the VTY interface, or using the configuration file:
log systemd-journal [raw]
logging level set-all notice
logging filter all 1
Two logging handlers are available: generic and raw. The first one
behaves similarly to both 'syslog' and 'stderr', i.e. all the meta
information is rendered by libosmocore itself, and then passed to
systemd together with the logging message. The later is more like
the 'gsmtap' target, so all available meta information is handed
over to systemd in form of fields [1]:
- CODE_FILE / CODE_LINE - location info,
- PRIORITY - syslog-compatible logging level,
- OSMO_SUBSYS - Osmocom-specific sub-system (e.g. DMSC),
- OSMO_SUBSYS_HEX - same as OSMO_SUBSYS, but encoded in hex,
- MESSAGE - the logging message itself,
and then can be rendered in any supported format (e.g. JSON).
More details about the API can be found in [2].
[1] https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html
[2] https://www.freedesktop.org/software/systemd/man/sd-journal.html
Change-Id: I609f5cf438e6ad9038d8fc95f00add6aac29fb23
2020-09-08 20:36:48 +00:00
|
|
|
|
|
|
|
|
struct {
|
|
|
|
|
bool raw;
|
|
|
|
|
} sd_journal;
|
2010-03-26 13:24:24 +00:00
|
|
|
};
|
|
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! call-back function to be called when the logging framework
|
2016-12-02 12:52:59 +00:00
|
|
|
* wants to log a fully formatted string
|
2013-02-15 12:27:59 +00:00
|
|
|
* \param[in] target logging target
|
2011-08-17 12:14:17 +00:00
|
|
|
* \param[in] level log level of currnet message
|
|
|
|
|
* \param[in] string the string that is to be written to the log
|
|
|
|
|
*/
|
2011-02-17 14:52:39 +00:00
|
|
|
void (*output) (struct log_target *target, unsigned int level,
|
|
|
|
|
const char *string);
|
2016-12-02 12:52:59 +00:00
|
|
|
|
2017-06-19 22:17:59 +00:00
|
|
|
/*! alternative call-back function to which the logging
|
2016-12-02 12:52:59 +00:00
|
|
|
* framework passes the unfortmatted input arguments,
|
|
|
|
|
* i.e. bypassing the internal string formatter
|
|
|
|
|
* \param[in] target logging target
|
|
|
|
|
* \param[in] subsys logging sub-system
|
|
|
|
|
* \param[in] level logging level
|
|
|
|
|
* \param[in] file soure code file name
|
|
|
|
|
* \param[in] line source code file line number
|
|
|
|
|
* \param[in] cont continuation of previous statement?
|
|
|
|
|
* \param[in] format format string
|
|
|
|
|
* \param[in] ap vararg list of printf arguments
|
|
|
|
|
*/
|
|
|
|
|
void (*raw_output)(struct log_target *target, int subsys,
|
|
|
|
|
unsigned int level, const char *file, int line,
|
|
|
|
|
int cont, const char *format, va_list ap);
|
2018-01-16 00:49:37 +00:00
|
|
|
|
|
|
|
|
/* Should the log level be printed? */
|
|
|
|
|
bool print_level;
|
2018-01-16 00:52:29 +00:00
|
|
|
/* Should we print the subsys in hex like '<000b>'? */
|
|
|
|
|
bool print_category_hex;
|
|
|
|
|
/* Should we print the source file and line, and in which way? */
|
|
|
|
|
enum log_filename_type print_filename2;
|
log: add 'last' option to 'logging print file'
Allow printing the source file information *after* the log information.
Add target->print_filename_pos, log_set_print_filename_pos() and enum
log_filename_pos, and the optional 'last' keyword to the 'logging print file'
vty command. (An enum in case we want to add other positions later.)
Rationale: on log lines, the logging context is usually printed first in the
logging text. Without the source file information, this logging context pretty
much aligns in an easily readable way. When adding the source file information,
each line's logging context info is shifted right by a pretty much random
amount and it is hard to spot recurring logging contexts.
One solution is to switch off source file info, of course, but that's not an
option when actively hacking on bugs and new features.
For example, it is unnecessarily hard to spot lchan FSM related log lines in
this osmo-bsc log snippet:
DRSL NOTICE mgw_endpoint_fsm.c:603 mgw-endpoint(conn0){WAIT_MGW_RESPONSE}: Freeing instance
DRSL NOTICE fsm.c:381 mgw-endpoint(conn0){WAIT_MGW_RESPONSE}: Deallocated
DMSC NOTICE mgw_endpoint_fsm.c:603 SUBSCR_CONN(conn0){CLEARING}: Received Event FORGET_MGW_ENDPOINT
DCHAN DEBUG lchan_rtp_fsm.c:741 lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED
DCHAN DEBUG lchan_rtp_fsm.c:520 lchan_rtp(0-0-1-TCH_F-0){ROLLBACK}: Freeing instance
DCHAN DEBUG fsm.c:381 lchan_rtp(0-0-1-TCH_F-0){ROLLBACK}: Deallocated
DCHAN DEBUG lchan_rtp_fsm.c:520 lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED
DCHAN DEBUG lchan_fsm.c:1232 lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: state_chg to WAIT_RF_RELEASE_ACK
DRSL NOTICE handover_fsm.c:762 handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DRSL NOTICE handover_fsm.c:762 handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Freeing instance
DRSL NOTICE fsm.c:381 handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Deallocated
DCHAN DEBUG lchan_fsm.c:1196 lchan(0-0-1-TCH_F-0){WAIT_RF_RELEASE_ACK}: state_chg to BORKEN
DCHAN DEBUG lchan_fsm.c:354 lchan(0-0-1-TCH_F-0){BORKEN}: (type=TCH_F) Clearing lchan state
DLMGCP DEBUG mgcp_client.c:741 Tx MGCP msg to MGCP GW: 'DLCX 3 2@mgw MGCP 1.0'
DLMGCP DEBUG mgcp_client.c:743 Sending msg to MGCP GW size: 66
DRLL NOTICE mgcp_client_fsm.c:422 MGCP_CONN(to-BTS){ST_DLCX_RESP}: Received Event EV_DLCX_RESP
Placing the source file info behind the log text makes it much easier to
follow, while the source file info is still available:
DRSL NOTICE mgw-endpoint(conn0){WAIT_MGW_RESPONSE}: Freeing instance (mgw_endpoint_fsm.c:603)
DRSL NOTICE mgw-endpoint(conn0){WAIT_MGW_RESPONSE}: Deallocated (fsm.c:381)
DMSC NOTICE SUBSCR_CONN(conn0){CLEARING}: Received Event FORGET_MGW_ENDPOINT (mgw_endpoint_fsm.c:603)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED (lchan_rtp_fsm.c:741)
DCHAN DEBUG lchan_rtp(0-0-1-TCH_F-0){ROLLBACK}: Freeing instance (lchan_rtp_fsm.c:520)
DCHAN DEBUG lchan_rtp(0-0-1-TCH_F-0){ROLLBACK}: Deallocated (fsm.c:381)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED (lchan_rtp_fsm.c:520)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: state_chg to WAIT_RF_RELEASE_ACK (lchan_fsm.c:1232)
DRSL NOTICE handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (handover_fsm.c:745)
DRSL NOTICE handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Freeing instance (handover_fsm.c:745)
DRSL NOTICE handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Deallocated (fsm.c:381)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){WAIT_RF_RELEASE_ACK}: state_chg to BORKEN (lchan_fsm.c:1196)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){BORKEN}: (type=TCH_F) Clearing lchan state (lchan_fsm.c:354)
DLMGCP DEBUG Tx MGCP msg to MGCP GW: 'DLCX 3 12@mgw MGCP 1.0' (mgcp_client.c:741)
DLMGCP DEBUG Sending msg to MGCP GW size: 67 (mgcp_client.c:743)
DRLL NOTICE MGCP_CONN(to-BTS){ST_DLCX_RESP}: Received Event EV_DLCX_RESP (mgcp_client_fsm.c:422)
Implementation: for 'last', insert source file info only when an '\n' is found
at the end of the log line composition buffer, so that LOGP()...LOGPC()
constructs also print source file info only when a log line actually ends.
Change-Id: I393907b3c9e0cc1145e102328adad0a83ee13a9f
2018-08-27 18:32:36 +00:00
|
|
|
/* Where on a log line to put the source file info. */
|
|
|
|
|
enum log_filename_pos print_filename_pos;
|
2010-03-26 13:24:24 +00:00
|
|
|
};
|
|
|
|
|
|
|
|
|
|
/* use the above macros */
|
2012-07-10 11:10:15 +00:00
|
|
|
void logp2(int subsys, unsigned int level, const char *file,
|
2010-03-26 13:24:24 +00:00
|
|
|
int line, int cont, const char *format, ...)
|
|
|
|
|
__attribute__ ((format (printf, 6, 7)));
|
2011-06-27 08:29:17 +00:00
|
|
|
int log_init(const struct log_info *inf, void *talloc_ctx);
|
2016-04-20 08:41:27 +00:00
|
|
|
void log_fini(void);
|
2015-11-17 10:52:24 +00:00
|
|
|
int log_check_level(int subsys, unsigned int level);
|
2010-03-26 13:24:24 +00:00
|
|
|
|
|
|
|
|
/* context management */
|
|
|
|
|
void log_reset_context(void);
|
|
|
|
|
int log_set_context(uint8_t ctx, void *value);
|
|
|
|
|
|
|
|
|
|
/* filter on the targets */
|
|
|
|
|
void log_set_all_filter(struct log_target *target, int);
|
|
|
|
|
|
|
|
|
|
void log_set_use_color(struct log_target *target, int);
|
2014-12-05 08:35:30 +00:00
|
|
|
void log_set_print_extended_timestamp(struct log_target *target, int);
|
2010-03-26 13:24:24 +00:00
|
|
|
void log_set_print_timestamp(struct log_target *target, int);
|
2021-02-18 17:19:23 +00:00
|
|
|
void log_set_print_tid(struct log_target *target, int);
|
2021-02-18 18:27:38 +00:00
|
|
|
void log_set_print_filename(struct log_target *target, int) OSMO_DEPRECATED("Use log_set_print_filename2() instead");
|
2018-01-16 00:52:29 +00:00
|
|
|
void log_set_print_filename2(struct log_target *target, enum log_filename_type lft);
|
log: add 'last' option to 'logging print file'
Allow printing the source file information *after* the log information.
Add target->print_filename_pos, log_set_print_filename_pos() and enum
log_filename_pos, and the optional 'last' keyword to the 'logging print file'
vty command. (An enum in case we want to add other positions later.)
Rationale: on log lines, the logging context is usually printed first in the
logging text. Without the source file information, this logging context pretty
much aligns in an easily readable way. When adding the source file information,
each line's logging context info is shifted right by a pretty much random
amount and it is hard to spot recurring logging contexts.
One solution is to switch off source file info, of course, but that's not an
option when actively hacking on bugs and new features.
For example, it is unnecessarily hard to spot lchan FSM related log lines in
this osmo-bsc log snippet:
DRSL NOTICE mgw_endpoint_fsm.c:603 mgw-endpoint(conn0){WAIT_MGW_RESPONSE}: Freeing instance
DRSL NOTICE fsm.c:381 mgw-endpoint(conn0){WAIT_MGW_RESPONSE}: Deallocated
DMSC NOTICE mgw_endpoint_fsm.c:603 SUBSCR_CONN(conn0){CLEARING}: Received Event FORGET_MGW_ENDPOINT
DCHAN DEBUG lchan_rtp_fsm.c:741 lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED
DCHAN DEBUG lchan_rtp_fsm.c:520 lchan_rtp(0-0-1-TCH_F-0){ROLLBACK}: Freeing instance
DCHAN DEBUG fsm.c:381 lchan_rtp(0-0-1-TCH_F-0){ROLLBACK}: Deallocated
DCHAN DEBUG lchan_rtp_fsm.c:520 lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED
DCHAN DEBUG lchan_fsm.c:1232 lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: state_chg to WAIT_RF_RELEASE_ACK
DRSL NOTICE handover_fsm.c:762 handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DRSL NOTICE handover_fsm.c:762 handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Freeing instance
DRSL NOTICE fsm.c:381 handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Deallocated
DCHAN DEBUG lchan_fsm.c:1196 lchan(0-0-1-TCH_F-0){WAIT_RF_RELEASE_ACK}: state_chg to BORKEN
DCHAN DEBUG lchan_fsm.c:354 lchan(0-0-1-TCH_F-0){BORKEN}: (type=TCH_F) Clearing lchan state
DLMGCP DEBUG mgcp_client.c:741 Tx MGCP msg to MGCP GW: 'DLCX 3 2@mgw MGCP 1.0'
DLMGCP DEBUG mgcp_client.c:743 Sending msg to MGCP GW size: 66
DRLL NOTICE mgcp_client_fsm.c:422 MGCP_CONN(to-BTS){ST_DLCX_RESP}: Received Event EV_DLCX_RESP
Placing the source file info behind the log text makes it much easier to
follow, while the source file info is still available:
DRSL NOTICE mgw-endpoint(conn0){WAIT_MGW_RESPONSE}: Freeing instance (mgw_endpoint_fsm.c:603)
DRSL NOTICE mgw-endpoint(conn0){WAIT_MGW_RESPONSE}: Deallocated (fsm.c:381)
DMSC NOTICE SUBSCR_CONN(conn0){CLEARING}: Received Event FORGET_MGW_ENDPOINT (mgw_endpoint_fsm.c:603)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED (lchan_rtp_fsm.c:741)
DCHAN DEBUG lchan_rtp(0-0-1-TCH_F-0){ROLLBACK}: Freeing instance (lchan_rtp_fsm.c:520)
DCHAN DEBUG lchan_rtp(0-0-1-TCH_F-0){ROLLBACK}: Deallocated (fsm.c:381)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED (lchan_rtp_fsm.c:520)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){WAIT_RLL_RTP_ESTABLISH}: state_chg to WAIT_RF_RELEASE_ACK (lchan_fsm.c:1232)
DRSL NOTICE handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (handover_fsm.c:745)
DRSL NOTICE handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Freeing instance (handover_fsm.c:745)
DRSL NOTICE handover(interBSCin_conn0){WAIT_RR_HO_DETECT}: Deallocated (fsm.c:381)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){WAIT_RF_RELEASE_ACK}: state_chg to BORKEN (lchan_fsm.c:1196)
DCHAN DEBUG lchan(0-0-1-TCH_F-0){BORKEN}: (type=TCH_F) Clearing lchan state (lchan_fsm.c:354)
DLMGCP DEBUG Tx MGCP msg to MGCP GW: 'DLCX 3 12@mgw MGCP 1.0' (mgcp_client.c:741)
DLMGCP DEBUG Sending msg to MGCP GW size: 67 (mgcp_client.c:743)
DRLL NOTICE MGCP_CONN(to-BTS){ST_DLCX_RESP}: Received Event EV_DLCX_RESP (mgcp_client_fsm.c:422)
Implementation: for 'last', insert source file info only when an '\n' is found
at the end of the log line composition buffer, so that LOGP()...LOGPC()
constructs also print source file info only when a log line actually ends.
Change-Id: I393907b3c9e0cc1145e102328adad0a83ee13a9f
2018-08-27 18:32:36 +00:00
|
|
|
void log_set_print_filename_pos(struct log_target *target, enum log_filename_pos pos);
|
2014-12-05 08:35:30 +00:00
|
|
|
void log_set_print_category(struct log_target *target, int);
|
2018-01-16 00:52:29 +00:00
|
|
|
void log_set_print_category_hex(struct log_target *target, int);
|
2018-01-16 00:49:37 +00:00
|
|
|
void log_set_print_level(struct log_target *target, int);
|
2010-03-26 13:24:24 +00:00
|
|
|
void log_set_log_level(struct log_target *target, int log_level);
|
|
|
|
|
void log_parse_category_mask(struct log_target *target, const char* mask);
|
2016-12-02 14:30:02 +00:00
|
|
|
const char* log_category_name(int subsys);
|
2017-07-06 14:57:15 +00:00
|
|
|
int log_parse_level(const char *lvl) OSMO_DEPRECATED_OUTSIDE_LIBOSMOCORE;
|
|
|
|
|
const char *log_level_str(unsigned int lvl) OSMO_DEPRECATED_OUTSIDE_LIBOSMOCORE;
|
2010-03-26 13:24:24 +00:00
|
|
|
int log_parse_category(const char *category);
|
|
|
|
|
void log_set_category_filter(struct log_target *target, int category,
|
|
|
|
|
int enable, int level);
|
|
|
|
|
|
|
|
|
|
/* management of the targets */
|
|
|
|
|
struct log_target *log_target_create(void);
|
2010-08-25 17:24:00 +00:00
|
|
|
void log_target_destroy(struct log_target *target);
|
2010-03-26 13:24:24 +00:00
|
|
|
struct log_target *log_target_create_stderr(void);
|
2010-08-25 17:24:00 +00:00
|
|
|
struct log_target *log_target_create_file(const char *fname);
|
2011-02-17 14:56:56 +00:00
|
|
|
struct log_target *log_target_create_syslog(const char *ident, int option,
|
|
|
|
|
int facility);
|
2016-12-02 14:30:02 +00:00
|
|
|
struct log_target *log_target_create_gsmtap(const char *host, uint16_t port,
|
|
|
|
|
const char *ident,
|
|
|
|
|
bool ofd_wq_mode,
|
|
|
|
|
bool add_sink);
|
logging: introduce 'systemd-journal' target
This change implements 'systemd-journal' logging target, that is
similar to the existing 'syslog' target. The key difference is
that 'systemd-journal' allows us to offload rendering of the meta
information, such as location (file name, line number), subsystem,
and logging level, to systemd. Moreover, we can attach arbitrary,
user-specific fields [1] to the logging messages, so they can be
used for advanced log filtering (e.g. by IMSI/TMSI/TLLI):
$ journalctl OSMO_SUBSYS=DMSC -f
Since we don't want to make libsystemd a required dependency, this
feature is optional, and needs to be enabled at build-time:
$ ./configure --enable-systemd-logging
The new logging target can be configured in the same way as any
other one - via the VTY interface, or using the configuration file:
log systemd-journal [raw]
logging level set-all notice
logging filter all 1
Two logging handlers are available: generic and raw. The first one
behaves similarly to both 'syslog' and 'stderr', i.e. all the meta
information is rendered by libosmocore itself, and then passed to
systemd together with the logging message. The later is more like
the 'gsmtap' target, so all available meta information is handed
over to systemd in form of fields [1]:
- CODE_FILE / CODE_LINE - location info,
- PRIORITY - syslog-compatible logging level,
- OSMO_SUBSYS - Osmocom-specific sub-system (e.g. DMSC),
- OSMO_SUBSYS_HEX - same as OSMO_SUBSYS, but encoded in hex,
- MESSAGE - the logging message itself,
and then can be rendered in any supported format (e.g. JSON).
More details about the API can be found in [2].
[1] https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html
[2] https://www.freedesktop.org/software/systemd/man/sd-journal.html
Change-Id: I609f5cf438e6ad9038d8fc95f00add6aac29fb23
2020-09-08 20:36:48 +00:00
|
|
|
struct log_target *log_target_create_systemd(bool raw);
|
|
|
|
|
void log_target_systemd_set_raw(struct log_target *target, bool raw);
|
2010-08-25 17:24:00 +00:00
|
|
|
int log_target_file_reopen(struct log_target *tgt);
|
logging: Change stderr + file target to use non-blocking write
So far, we used blocking, buffered fwrite() to write to stderr
and file targets. This causes problems if there are [slow] consumers
causing delays, such as gnome-terminal (when the program is started
interactively) or systemd/journald (where we observe 64..128ms blocks on
stderr).
This patch introduces stderr/file based logging via write_queue
and osmo_select_main(), i.e. switch from glibc-buffered, blocking
to internally buffered, non-blocking writes.
* when osmo_stderr_target is created via application.c, we create it
in blocking stream mode for backwards compatibility, particularly
for [smaller] programs that don't use osmo_select_main()
* when the VTY code encounters 'log stderr' or 'log file FILENAME',
we switch that respective target to non-blocking write-queue mode,
as this means the application is in fact using osmo_select_main()
* The config file can now state 'log stderr blocking-io' or
'log file FILENAME blocking-io' to explicitly enforce using blocking
stream based I/O
* The application can at any time use API functions to switch either way
Closes: OS#4311
Change-Id: Ia58fd78535c41b3da3aeb7733aadc785ace610da
2020-09-26 19:45:16 +00:00
|
|
|
int log_target_file_switch_to_stream(struct log_target *tgt);
|
|
|
|
|
int log_target_file_switch_to_wqueue(struct log_target *tgt);
|
2013-03-18 18:01:40 +00:00
|
|
|
int log_targets_reopen(void);
|
2010-08-25 17:24:00 +00:00
|
|
|
|
2010-03-26 13:24:24 +00:00
|
|
|
void log_add_target(struct log_target *target);
|
|
|
|
|
void log_del_target(struct log_target *target);
|
|
|
|
|
|
2022-01-09 11:00:03 +00:00
|
|
|
struct log_target *log_target_find(enum log_target_type type, const char *fname);
|
2011-02-18 19:37:04 +00:00
|
|
|
|
2019-09-17 16:38:58 +00:00
|
|
|
void log_enable_multithread(void);
|
|
|
|
|
|
|
|
|
|
void log_tgt_mutex_lock_impl(void);
|
|
|
|
|
void log_tgt_mutex_unlock_impl(void);
|
|
|
|
|
#define LOG_MTX_DEBUG 0
|
|
|
|
|
#if LOG_MTX_DEBUG
|
|
|
|
|
#include <pthread.h>
|
|
|
|
|
#define log_tgt_mutex_lock() do { fprintf(stderr, "[%lu] %s:%d [%s] lock\n", pthread_self(), __FILE__, __LINE__, __func__); log_tgt_mutex_lock_impl(); } while (0)
|
|
|
|
|
#define log_tgt_mutex_unlock() do { fprintf(stderr, "[%lu] %s:%d [%s] unlock\n", pthread_self(), __FILE__, __LINE__, __func__); log_tgt_mutex_unlock_impl(); } while (0)
|
|
|
|
|
#else
|
|
|
|
|
#define log_tgt_mutex_lock() log_tgt_mutex_lock_impl()
|
|
|
|
|
#define log_tgt_mutex_unlock() log_tgt_mutex_unlock_impl()
|
|
|
|
|
#endif
|
|
|
|
|
|
2012-04-18 19:53:23 +00:00
|
|
|
/*! @} */
|
