suricata之日志截断

一、背景

在suricata的调试过程中,使用SCLogXXX api进行信息的输出,发现输出的日志被截断了,最开始以为是解析逻辑有问题,没有解析完整,经过排查后,发现SCLogXXX api内部进行了长度限制,最长2K。

OS:Ubuntu 22.04.5 LTS
IDE: vscode
Suricata: suricata 7.0.5

二、 问题复现

拷贝一个规则,将规则内容填充任意内容,使其达到2K以上
请添加图片描述

规则重复时,输出错误日志,日志截断
请添加图片描述

三、分析

3.1 源码实现

// src/util-debug.h
/* The maximum length of the log message */
#define SC_LOG_MAX_LOG_MSG_LEN 2048

// src/util-debug.c
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 ||
             SCLogMatchFGFilterWL(file, func, line) == 1 ||
             SCLogMatchFGFilterBL(file, func, line) == 1) &&
            (sc_log_fd_filters_present == 0 ||
             SCLogMatchFDFilter(func) == 1))
    {
        char msg[SC_LOG_MAX_LOG_MSG_LEN];
        va_list ap;
        va_start(ap, fmt);
        vsnprintf(msg, sizeof(msg), fmt, ap);
        va_end(ap);
        SCLogMessage(x, file, line, func, module, msg);
    }
}

从实现中可以看出,首先将数据格式化到一个局部临时变量中,再将临时变量输出。
而临时变量是一个2K的字符数组,因此需要输出的数据超过2K将被截断。

3.2 为啥需要临时变量

  1. 将可变参数格式化成一个字符串,需要一个存储空间
  2. 栈变量是线程安全的
  3. 简单通用

3.3 是否可以增加空间

可以增加SC_LOG_MAX_LOG_MSG_LEN的值,但是不推荐

  1. 每条日志大小一般都很小,2K已经满足90%以上的情况
  2. 栈变量太大,递归或深层调用可能会耗尽栈空间
// 栈默认大小(KB)
$ ulimit -s
8192 

// 栈最大上限,受系统内存限制
$ ulimit -Hs
unlimited

// glibc 中的默认值
$ getconf PTHREAD_STACK_MIN
16384

3.4 非要解决截断问题如何处理

man vsnprintf

The  functions snprintf() and vsnprintf() do not write more than size bytes (including the
       terminating null byte ('\0')).  If the output was truncated due to this  limit,  then  the
       return value is the number of characters (excluding the terminating null byte) which would
       have been written to the final string if enough space had been available.  Thus, a  return
       value of size or more means that the output was truncated.  

根据man手册的说明,可以判断vsnprintf的返回值,返回值超过2048时,可以动态申请空间,再次进行格式化

    char msg[SC_LOG_MAX_LOG_MSG_LEN];
    char *real_msg = msg;

    va_list ap;
    va_start(ap, fmt);
    int ret = vsnprintf(msg, sizeof(msg), fmt, ap);
    va_end(ap);

    if (ret > SC_LOG_MAX_LOG_MSG_LEN) { // 被截断
        real_msg = SCMalloc(ret+1); // 动态分配空间
        if (likely(real_msg != NULL)) {
            va_start(ap, fmt);
            vsnprintf(real_msg, ret+1, fmt, ap); // 重新格式化
            va_end(ap);
        } else {
            real_msg = msg; // 空间申请失败
        }
    }
    SCLogMessage(x, file, line, func, module, real_msg);
    if (real_msg != msg) {
        SCFree(real_msg);
    }

结果是依然被截断了,继续分析SCLogMessage实现

SCError SCLogMessage(const SCLogLevel log_level, const char *file, const unsigned int line,
        const char *function, const char *module, const char *message)
{
    char buffer[SC_LOG_MAX_LOG_MSG_LEN] = "";
 ...
    case SC_LOG_OP_IFACE_CONSOLE:
        if (SCLogMessageGetBuffer(ts, op_iface_ctx->use_color, 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, module, message) == 0) {
            SCLogPrintToStream((log_level == SC_LOG_ERROR)? stderr: stdout, buffer);
        }
        break;
            ...
    return SC_OK;
}

又一个buffer[SC_LOG_MAX_LOG_MSG_LEN], 再次被截断

3.5 为啥是两次格式化

请添加图片描述

第一次是将用户输入的信息格式化;
第二次增加额外信息(时间、函数名,行号等),可通过配置决定添加的信息
suricata.yaml

logging:
  default-log-format: "%D: %S:%l %M"

总结

日志截断问题的主要原因是日志内容经过两次格式化,且每次格式化都使用了固定大小的缓冲区。通过动态分配缓冲区,可以有效避免日志被截断的问题。

评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值