Skip to content

Commit

Permalink
log: Add module and subsystem identifiers to log
Browse files Browse the repository at this point in the history 
Issue: 2497

This changeset provides subsystem and module identifiers in the log when
the log format string contains "%S". By convention, the log format
surrounds "%S" with brackets.

The subsystem name is generally the same as the thread name. The module
name is derived from the source code module name and usually consists of
the first one or 2 segments of the name using the dash character as the
segment delimiter.
  • Loading branch information
@jlucovsky @victorjulien
jlucovsky authored and victorjulien committed Dec 20, 2022
1 parent 197aa01 commit f847434
Show file tree
Hide file tree
Showing 8 changed files with 181 additions and 56 deletions.
3 changes: 3 additions & 0 deletions configure.ac
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2454,6 +2454,9 @@ if test "${enable_ebpf}" = "yes" || test "${enable_nfqueue}" = "yes" || test "${
AC_DEFINE([CAPTURE_OFFLOAD], [1],[Building flow capture bypass code])
fi

# Add diagnostic filename
CPPFLAGS="${CPPFLAGS} -D__SCFILENAME__=\\\"\$(*F)\\\""

AC_SUBST(CFLAGS)
AC_SUBST(LDFLAGS)
AC_SUBST(CPPFLAGS)
Expand Down
6 changes: 6 additions & 0 deletions etc/schema.json
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1371,6 +1371,12 @@
},
"message": {
"type": "string"
},
"thread_name": {
"type": "string"
},
"module": {
"type": "string"
}
},
"additionalProperties": false
Expand Down
1 change: 1 addition & 0 deletions rust/src/core.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -129,6 +129,7 @@ pub type SCLogMessageFunc =
filename: *const std::os::raw::c_char,
line: std::os::raw::c_uint,
function: *const std::os::raw::c_char,
subsystem: *const std::os::raw::c_char,
message: *const std::os::raw::c_char) -> std::os::raw::c_int;

pub type DetectEngineStateFreeFunc =
Expand Down
4 changes: 4 additions & 0 deletions rust/src/log.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -71,10 +71,12 @@ pub fn sclog(level: Level, file: &str, line: u32, function: &str,
message: &str)
{
let filename = basename(file);
let noext = &filename[0..filename.len() - 3];
sc_log_message(level,
filename,
line,
function,
noext,
message);
}

Expand Down Expand Up @@ -167,6 +169,7 @@ pub fn sc_log_message(level: Level,
filename: &str,
line: std::os::raw::c_uint,
function: &str,
module: &str,
message: &str) -> std::os::raw::c_int
{
unsafe {
Expand All @@ -176,6 +179,7 @@ pub fn sc_log_message(level: Level,
to_safe_cstring(filename).as_ptr(),
line,
to_safe_cstring(function).as_ptr(),
to_safe_cstring(module).as_ptr(),
to_safe_cstring(message).as_ptr());
}
}
Expand Down
4 changes: 2 additions & 2 deletions src/rust-context.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -37,8 +37,8 @@ typedef struct HttpRangeContainerBlock HttpRangeContainerBlock;
struct AppLayerParser;

typedef struct SuricataContext_ {
SCError (*SCLogMessage)(
const SCLogLevel, const char *, const unsigned int, const char *, const char *message);
SCError (*SCLogMessage)(const SCLogLevel, const char *, const unsigned int, const char *,
const char *, const char *message);
void (*DetectEngineStateFree)(DetectEngineState *);
void (*AppLayerDecoderEventsSetEventRaw)(AppLayerDecoderEvents **,
uint8_t);
Expand Down
129 changes: 114 additions & 15 deletions src/util-debug.c
View file
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
/* Copyright (C) 2007-2020 Open Information Security Foundation
/* Copyright (C) 2007-2021 Open Information Security Foundation
*
* You can copy, redistribute or modify this Program under the terms of
* the GNU General Public License version 2 as published by the Free
Expand Down Expand Up @@ -68,6 +68,11 @@ SCEnumCharMap sc_log_op_iface_map[ ] = {
static SCMutex sc_log_stream_lock;
#endif /* OS_WIN32 */

/**
* \brief Transform the module name into display module name for logging
*/
static const char *SCTransformModule(const char *module_name, int *dn_len);

/**
* \brief Holds the config state for the logging module
*/
Expand Down Expand Up @@ -193,7 +198,7 @@ static inline void SCLogPrintToSyslog(int syslog_log_level, const char *msg)
*/
static int SCLogMessageJSON(struct timeval *tval, char *buffer, size_t buffer_size,
SCLogLevel log_level, const char *file, unsigned line, const char *function,
const char *message)
const char *module, const char *message)
{
json_t *js = json_object();
if (unlikely(js == NULL))
Expand All @@ -218,6 +223,18 @@ static int SCLogMessageJSON(struct timeval *tval, char *buffer, size_t buffer_si
if (message)
json_object_set_new(ejs, "message", json_string(message));

if (t_thread_name[0] != '\0') {
json_object_set_new(ejs, "thread_name", json_string(t_thread_name));
}

if (module) {
/* Determine how much of module name to display */
int dn_len = 0;
const char *dn_name;
dn_name = SCTransformModule(module, &dn_len);
json_object_set_new(ejs, "module", json_string(dn_name));
}

if (log_level >= SC_LOG_DEBUG) {
if (function)
json_object_set_new(ejs, "function", json_string(function));
Expand Down Expand Up @@ -246,6 +263,68 @@ static int SCLogMessageJSON(struct timeval *tval, char *buffer, size_t buffer_si
return -1;
}

static const int transform_max_segs = 2; /* The maximum segment count to display */
/*
* \brief Return a display name for the given module name for logging.
*
* The transformation is dependent upon the source code module names
* that use the dash character to separate incremental refinements of
* the subsystem.
*
* The transformation uses the local constant "transform_max_segs" to determine
* how many segments to display; the transformed name will never consist
* of more than this many segments.
*
* E.g., "detect-http-content-len" ==> "detect-http" when the max is 2
*
* \param module_name The source code module name to be transformed.
* \param dn_len The number of characters in the display name to print.
*
* \retval Pointer to the display name
*/
static const char *SCTransformModule(const char *module_name, int *dn_len)
{
/*
* special case for source code module names beginning with:
* Prefixes skipped
* tm-*
* util-*
* source-*
* No transformation
* app-layer-*
*/
if (strncmp("tm-", module_name, 3) == 0) {
*dn_len = strlen(module_name) - 3;
return module_name + 3;
} else if (strncmp("util-", module_name, 5) == 0) {
*dn_len = strlen(module_name) - 5;
return module_name + 5;
} else if (strncmp("source-", module_name, 7) == 0) {
*dn_len = strlen(module_name) - 7;
return module_name + 7;
} else if (strncmp("app-layer-", module_name, 10) == 0) {
*dn_len = strlen(module_name);
return module_name;
}

int seg_cnt = 0;

char *last;
char *w = (char *)module_name;
while (w && (w = strchr(w, '-')) != NULL && seg_cnt < transform_max_segs) {
seg_cnt++;
last = w;
w++; /* skip past '-' */
}

if (seg_cnt < transform_max_segs)
*dn_len = strlen(module_name);
else
*dn_len = last - module_name;

return module_name;
}

/**
* \brief Adds the global log_format to the outgoing buffer
*
Expand All @@ -258,14 +337,13 @@ static int SCLogMessageJSON(struct timeval *tval, char *buffer, size_t buffer_si
* \retval 0 on success; else a negative value on error
*/
static SCError SCLogMessageGetBuffer(struct timeval *tval, int color, SCLogOPType type,
char *buffer, size_t buffer_size, const char *log_format,

const SCLogLevel log_level, const char *file, const unsigned int line, const char *function,
char *buffer, size_t buffer_size, const char *log_format, const SCLogLevel log_level,
const char *file, const unsigned int line, const char *function, const char *module,
const char *message)
{
if (type == SC_LOG_OP_TYPE_JSON)
return SCLogMessageJSON(
tval, buffer, buffer_size, log_level, file, line, function, message);
tval, buffer, buffer_size, log_level, file, line, function, module, message);

char *temp = buffer;
const char *s = NULL;
Expand Down Expand Up @@ -346,6 +424,7 @@ static SCError SCLogMessageGetBuffer(struct timeval *tval, int color, SCLogOPTyp
substr++;
break;

case SC_LOG_FMT_THREAD_NAME:
case SC_LOG_FMT_TM:
temp_fmt[0] = '\0';
cw = snprintf(temp, SC_LOG_MAX_LOG_MSG_LEN - (temp - buffer), "%s%s%s%s", substr,
Expand Down Expand Up @@ -410,6 +489,26 @@ static SCError SCLogMessageGetBuffer(struct timeval *tval, int color, SCLogOPTyp
substr++;
break;

case SC_LOG_FMT_SUBSYSTEM:
temp_fmt[0] = '\0';

/* Determine how much of module name to display */
int dn_len = 0;
const char *dn_name = "unknown";
if (module) {
dn_name = SCTransformModule(module, &dn_len);
}

cw = snprintf(temp, SC_LOG_MAX_LOG_MSG_LEN - (temp - buffer), "%s%s%s%s", substr,
green, dn_name, reset);
if (cw < 0)
return -1;
temp += cw;
temp_fmt++;
substr = temp_fmt;
substr++;
break;

case SC_LOG_FMT_FUNCTION:
temp_fmt[0] = '\0';
cw = snprintf(temp, SC_LOG_MAX_LOG_MSG_LEN - (temp - buffer),
Expand All @@ -421,7 +520,6 @@ static SCError SCLogMessageGetBuffer(struct timeval *tval, int color, SCLogOPTyp
substr = temp_fmt;
substr++;
break;

}
temp_fmt++;
}
Expand Down Expand Up @@ -493,7 +591,7 @@ static int SCLogReopen(SCLogOPIfaceCtx *op_iface_ctx)
* \retval SC_OK on success; else an error code
*/
SCError SCLogMessage(const SCLogLevel log_level, const char *file, const unsigned int line,
const char *function, const char *message)
const char *function, const char *module, const char *message)
{
char buffer[SC_LOG_MAX_LOG_MSG_LEN] = "";
SCLogOPIfaceCtx *op_iface_ctx = NULL;
Expand Down Expand Up @@ -521,15 +619,15 @@ SCError SCLogMessage(const SCLogLevel log_level, const char *file, const unsigne
buffer, sizeof(buffer),
op_iface_ctx->log_format ? op_iface_ctx->log_format
: sc_log_config->log_format,
log_level, file, line, function, message) == 0) {
log_level, file, line, function, module, message) == 0) {
SCLogPrintToStream((log_level == SC_LOG_ERROR)? stderr: stdout, buffer);
}
break;
case SC_LOG_OP_IFACE_FILE:
if (SCLogMessageGetBuffer(&tval, 0, op_iface_ctx->type, buffer, sizeof(buffer),
op_iface_ctx->log_format ? op_iface_ctx->log_format
: sc_log_config->log_format,
log_level, file, line, function, message) == 0) {
log_level, file, line, function, module, message) == 0) {
int r = 0;
SCMutexLock(&op_iface_ctx->fp_mutex);
if (op_iface_ctx->rotation_flag) {
Expand All @@ -550,7 +648,7 @@ SCError SCLogMessage(const SCLogLevel log_level, const char *file, const unsigne
if (SCLogMessageGetBuffer(&tval, 0, op_iface_ctx->type, buffer, sizeof(buffer),
op_iface_ctx->log_format ? op_iface_ctx->log_format
: sc_log_config->log_format,
log_level, file, line, function, message) == 0) {
log_level, file, line, function, module, message) == 0) {
SCLogPrintToSyslog(SCLogMapLogLevelToSyslogLevel(log_level), buffer);
}
break;
Expand All @@ -562,7 +660,7 @@ SCError SCLogMessage(const SCLogLevel log_level, const char *file, const unsigne
return SC_OK;
}

void SCLog(int x, const char *file, const char *func, const int line,
void SCLog(int x, const char *file, const char *func, const int line, const char *module,
const char *fmt, ...)
{
if (sc_log_global_log_level >= x &&
Expand All @@ -577,11 +675,12 @@ void SCLog(int x, const char *file, const char *func, const int line,
va_start(ap, fmt);
vsnprintf(msg, sizeof(msg), fmt, ap);
va_end(ap);
SCLogMessage(x, file, line, func, msg);
SCLogMessage(x, file, line, func, module, msg);
}
}

void SCLogErr(int x, const char *file, const char *func, const int line, const char *fmt, ...)
void SCLogErr(int x, const char *file, const char *func, const int line, const char *module,
const char *fmt, ...)
{
if (sc_log_global_log_level >= x &&
(sc_log_fg_filters_present == 0 ||
Expand All @@ -595,7 +694,7 @@ void SCLogErr(int x, const char *file, const char *func, const int line, const c
va_start(ap, fmt);
vsnprintf(msg, sizeof(msg), fmt, ap);
va_end(ap);
SCLogMessage(x, file, line, func, msg);
SCLogMessage(x, file, line, func, module, msg);
}
}

Expand Down
Loading

0 comments on commit f847434

Please sign in to comment.