Occasional errors occur when using the parser plugin

[littlejoyo]

Bug Report

Describe the bug In most cases, the parser plugin will work normally. Generally, error logs will be printed out and log loss will occur within a few hours.

To Reproduce

• Rubular link if applicable:
• Example log message if applicable:

  [2023/10/23 19:18:22] [error] [filter:parser:syslog-10.74.11.9-1_1] Log event encoder error : -4
  [2023/10/23 19:18:22] [error] [filter:parser:syslog-10.74.11.9-1_2] Log event encoder error : -4

• Steps to reproduce the problem:

Expected behavior

Your Environment fluent-bit version: v2.1.3

[FILTER]
    name         parser
    key_name     message
    parser       syslog-rfc3164
    reserve_data true
    match        syslog-10.65.172.188-2
    alias        syslog-10.65.172.188-2_1
[FILTER]
    name         parser
    key_name     message
    parser       json
    reserve_data true
    match        syslog-10.65.172.188-2
    alias        syslog-10.65.172.188-2_2
[FILTER]
    name   modify
    match  syslog-10.65.172.188-2
    rename account username
    add    tenant xsds1223
    alias  syslog-10.65.172.188-2_3

parser

[PARSER]
    Name        syslog-rfc3164
    Format      regex
    Regex       /^\<(?<pri>[0-9]+)\>(?<time>[^ ]* {1,2}[^ ]* [^ ]*) (?<host>[^ ]*) (?<ident>[a-zA-Z0-9_\/\.\-\@]*)(?:\[(?<pid>[0-9]+)\])?(?:\:)? *(?<message>.*)$/
    Time_Key    time
    Time_Format %b %d %H:%M:%S
    Time_Keep   On

By looking at the source code, I found that the error message was deleted in lines 387~390 of the plugins/filter_parser/filter_parser.c file.

if (log_encoder.output_length > 0) {
        *ret_buf   = log_encoder.output_buffer;
        *ret_bytes = log_encoder.output_length;

        ret = FLB_FILTER_MODIFIED;

        flb_log_event_encoder_claim_internal_buffer_ownership(&log_encoder);
    }
    else {
        flb_plg_error(ctx->ins,
                      "Log event encoder error : %d", ret);

        ret = FLB_FILTER_NOTOUCH;
    }

and -4 error is #define FLB_EVENT_DECODER_ERROR_WRONG_ROOT_TYPE -4

#define FLB_EVENT_DECODER_SUCCESS                        0
#define FLB_EVENT_DECODER_ERROR_INITIALIZATION_FAILURE  -1
#define FLB_EVENT_DECODER_ERROR_INVALID_CONTEXT         -2
#define FLB_EVENT_DECODER_ERROR_INVALID_ARGUMENT        -3
#define FLB_EVENT_DECODER_ERROR_WRONG_ROOT_TYPE         -4
#define FLB_EVENT_DECODER_ERROR_WRONG_ROOT_SIZE         -5
#define FLB_EVENT_DECODER_ERROR_WRONG_HEADER_TYPE       -6
#define FLB_EVENT_DECODER_ERROR_WRONG_HEADER_SIZE       -7
#define FLB_EVENT_DECODER_ERROR_WRONG_TIMESTAMP_TYPE    -8
#define FLB_EVENT_DECODER_ERROR_WRONG_METADATA_TYPE     -9
#define FLB_EVENT_DECODER_ERROR_WRONG_BODY_TYPE         -10
#define FLB_EVENT_DECODER_ERROR_DESERIALIZATION_FAILURE -11
#define FLB_EVENT_DECODER_ERROR_INSUFFICIENT_DATA       -12

It works normally in most cases. Do you think this is a msgpack bug? hope to receive help！

[littlejoyo]

The specific code location where the error was reported：

int flb_event_decoder_decode_object(struct flb_log_event_decoder *context,
                                    struct flb_log_event *event,
                                    msgpack_object *input)
{
    msgpack_object *timestamp;
    msgpack_object *metadata;
    int             result;
    int             format;
    msgpack_object *header;
    msgpack_object *body;
    msgpack_object *root;

    memset(event, 0, sizeof(struct flb_log_event));

    /* Ensure that the root element is a 2 element array*/
    root = input;

    if (root->type != MSGPACK_OBJECT_ARRAY) {
        // flag
        flb_warn("===> flb_event_decoder_decode_object type:%d",root->type);
        return FLB_EVENT_DECODER_ERROR_WRONG_ROOT_TYPE;
    }

The final type printed is MSGPACK_OBJECT_POSITIVE_INTEGER

typedef enum {
    MSGPACK_OBJECT_NIL                  = 0x00,
    MSGPACK_OBJECT_BOOLEAN              = 0x01,
    MSGPACK_OBJECT_POSITIVE_INTEGER     = 0x02,
    MSGPACK_OBJECT_NEGATIVE_INTEGER     = 0x03,
    MSGPACK_OBJECT_FLOAT32              = 0x0a,
    MSGPACK_OBJECT_FLOAT64              = 0x04,
    MSGPACK_OBJECT_FLOAT                = 0x04,
#if defined(MSGPACK_USE_LEGACY_NAME_AS_FLOAT)
    MSGPACK_OBJECT_DOUBLE               = MSGPACK_OBJECT_FLOAT, /* obsolete */
#endif /* MSGPACK_USE_LEGACY_NAME_AS_FLOAT */
    MSGPACK_OBJECT_STR                  = 0x05,
    MSGPACK_OBJECT_ARRAY                = 0x06,
    MSGPACK_OBJECT_MAP                  = 0x07,
    MSGPACK_OBJECT_BIN                  = 0x08,
    MSGPACK_OBJECT_EXT                  = 0x09
} msgpack_object_type;

The running log is as follows：

[2023/10/24 06:54:02] [ warn] ===> flb_event_decoder_decode_object type:2
2023/10/24 06:54:02 record:map[host:10.107.32.241 ident:abc@proxyLog message:{ "actor": { "type": "user", "id": "1b187860-43 pri:14 time:Oct 23 22:59:24]

json data is truncated

[github-actions[bot]]

This issue is stale because it has been open 90 days with no activity. Remove stale label or comment or this will be closed in 5 days. Maintainers can add the exempt-stale label.

[github-actions[bot]]

This issue was closed because it has been stalled for 5 days with no activity.