Skip to content

in_syslog: A null byte before ending byte puts off the parser loop #2741

New issue
New issue
Open
#10437
Open
in_syslog: A null byte before ending byte puts off the parser loop#2741
#10437
@pawpy

Description

@pawpy
pawpy
opened on Nov 1, 2020

Bug Report

Describe the bug

A null byte before the ending byte in the syslog message puts off parser loop making it to send incomplete message into parser (flb_parser_do). This causes the logs to be spammed with apparent message error parsing log message with parser ... for every character of the message.

To Reproduce

  • Rubular link if applicable: NA
  • Example log message if applicable:
[2020/10/29 19:34:48] [trace] [input:syslog:syslog.0 at plugins/in_syslog/syslog_conn.c:73] read()=389 pre_len=0 now_len=389
[2020/10/29 19:34:48] [trace] [input:syslog:syslog.0 at plugins/in_syslog/syslog_conn.c:73] read()=389 pre_len=0 now_len=389
[2020/10/29 19:34:48] [trace] [input:syslog:syslog.0 at plugins/in_syslog/syslog_conn.c:73] read()=1107 pre_len=0 now_len=1107
[2020/10/29 19:34:48] [trace] [input:syslog:syslog.0 at plugins/in_syslog/syslog_conn.c:73] read()=1520 pre_len=1106 now_len=2626
[2020/10/29 19:34:48] [ warn] [input:syslog:syslog.0] error parsing log message with parser 'rfc5424-fluentd'
[2020/10/29 19:34:48] [debug] [input:syslog:syslog.0] unparsed log message: 133>1 2020-10-29T19:34:48.932381+00:00 i-0c3b7e731bd7c8b6a php.access.log - - [] 2020-10-29 19:34:48 GET 200 468.829 ms 2048 kB 81.05% /graphql?operationName=getHeaderConfig&query=query%20getHeaderConfig%20%7B%0A%20%20headerLinks%20%7B%0A%20%20%20%20list%20%7B%0A%20%20%20%20%20%20name%0A%20%20%20%20%20%20url%0A%20%20%20%20%20%20code%0A%20%20%20%20%20%20menu%20%7B%0A%20%20%20%20%20%20%20%20name%0A%20%20%20%20%20%20%20%20url%0A%20%20%20%20%20%20%20%20links%20%7B%0A%20%20%20%20%20%20%20%20%20%20name%0A%20%20%20%20%20%20%20%20%20%20url%0A%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%7D%0A%20%20%20%20%7D%0A%20%20%7D%0A%20%20topMenuInfo%20%7B%0A%20%20%20%20list%20%7B%0A%20%20%20%20%20%20name%0A%20%20%20%20%20%20url%0A%20%20%20%20%20%20icon%0A%20%20%20%20%20%20subcategory%20%7B%0A%20%20%20%20%20%20%20%20name%0A%20%20%20%20%20%20%20%20url%0A%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20special_category%20%7B%0A%20%20%20%20%20%20%20%20category_info%20%7B%0A%20%20%20%20%20%20%20%20%20%20name%0A%20%20%20%20%20%20%20%20%20%20url%0A%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%7D%0A%20%20%20%20%7D%
[2020/10/29 19:34:48] [ warn] [input:syslog:syslog.0] error parsing log message with parser 'rfc5424-fluentd'
[2020/10/29 19:34:48] [debug] [input:syslog:syslog.0] unparsed log message: 33>1 2020-10-29T19:34:48.932381+00:00 i-0c3b7e731bd7c8b6a php.access.log - - [] 2020-10-29 19:34:48 GET 200 468.829 ms 2048 kB 81.05% /graphql?operationName=getHeaderConfig&query=query%20getHeaderConfig%20%7B%0A%20%20headerLinks%20%7B%0A%20%20%20%20list%20%7B%0A%20%20%20%20%20%20name%0A%20%20%20%20%20%20url%0A%20%20%20%20%20%20code%0A%20%20%20%20%20%20menu%20%7B%0A%20%20%20%20%20%20%20%20name%0A%20%20%20%20%20%20%20%20url%0A%20%20%20%20%20%20%20%20links%20%7B%0A%20%20%20%20%20%20%20%20%20%20name%0A%20%20%20%20%20%20%20%20%20%20url%0A%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%7D%0A%20%20%20%20%7D%0A%20%20%7D%0A%20%20topMenuInfo%20%7B%0A%20%20%20%20list%20%7B%0A%20%20%20%20%20%20name%0A%20%20%20%20%20%20url%0A%20%20%20%20%20%20icon%0A%20%20%20%20%20%20subcategory%20%7B%0A%20%20%20%20%20%20%20%20name%0A%20%20%20%20%20%20%20%20url%0A%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20special_category%20%7B%0A%20%20%20%20%20%20%20%20category_info%20%7B%0A%20%20%20%20%20%20%20%20%20%20name%0A%20%20%20%20%20%20%20%20%20%20url%0A%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%7D%0A%20%20%20%20%7D%
[2020/10/29 19:34:48] [ warn] [input:syslog:syslog.0] error parsing log message with parser 'rfc5424-fluentd'
[2020/10/29 19:34:48] [debug] [input:syslog:syslog.0] unparsed log message: 3>1 2020-10-29T19:34:48.932381+00:00 i-0c3b7e731bd7c8b6a php.access.log - - [] 2020-10-29 19:34:48 GET 200 468.829 ms 2048 kB 81.05% /graphql?operationName=getHeaderConfig&query=query%20getHeaderConfig%20%7B%0A%20%20headerLinks%20%7B%0A%20%20%20%20list%20%7B%0A%20%20%20%20%20%20name%0A%20%20%20%20%20%20url%0A%20%20%20%20%20%20code%0A%20%20%20%20%20%20menu%20%7B%0A%20%20%20%20%20%20%20%20name%0A%20%20%20%20%20%20%20%20url%0A%20%20%20%20%20%20%20%20links%20%7B%0A%20%20%20%20%20%20%20%20%20%20name%0A%20%20%20%20%20%20%20%20%20%20url%0A%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%7D%0A%20%20%20%20%7D%0A%20%20%7D%0A%20%20topMenuInfo%20%7B%0A%20%20%20%20list%20%7B%0A%20%20%20%20%20%20name%0A%20%20%20%20%20%20url%0A%20%20%20%20%20%20icon%0A%20%20%20%20%20%20subcategory%20%7B%0A%20%20%20%20%20%20%20%20name%0A%20%20%20%20%20%20%20%20url%0A%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20special_category%20%7B%0A%20%20%20%20%20%20%20%20category_info%20%7B%0A%20%20%20%20%20%20%20%20%20%20name%0A%20%20%20%20%20%20%20%20%20%20url%0A%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%7D%0A%20%20%20%20%7D%
[2020/10/29 19:34:48] [ warn] [input:syslog:syslog.0] error parsing log message with parser 'rfc5424-fluentd'
...
[2020/10/29 19:34:48] [debug] [input:syslog:syslog.0] unparsed log message: 7D%
[2020/10/29 19:34:48] [ warn] [input:syslog:syslog.0] error parsing log message with parser 'rfc5424-fluentd'
[2020/10/29 19:34:48] [debug] [input:syslog:syslog.0] unparsed log message: D%
[2020/10/29 19:34:48] [ warn] [input:syslog:syslog.0] error parsing log message with parser 'rfc5424-fluentd'
[2020/10/29 19:34:48] [debug] [input:syslog:syslog.0] unparsed log message: %

The xxd of the log line is here: xxd_fail_log_line.log

  • Steps to reproduce the problem:
    A null byte before the ending byte in the syslog message

Expected behavior

The string collected till the null byte be successfully parsed and subsequently prevent sending incomplete message into the parser

Screenshots

Your Environment

  • Version used: 1.5.4 (but issues seen on latest master as well)
  • Configuration:

FB config

[INPUT]
    Name syslog
    Buffer_Max_Size 128k
    Tag  syslog-source
    Mode tcp
    Listen 127.255.0.1
    Port 1020
    Parser rfc5424-fluentd

[FILTER]
    Name  record_modifier
    Match syslog-source
    Record cluster 4kc5wroz7gwqs
    Record fb.input syslog
    Record hostName i-0c3b7e731bd7c8b6a
    Record hostType unified
    Record ipAddress 192.168.5.5

[FILTER]
    Name  record_modifier
    Match *
    Record entity.guid.INFRA MjQzMDk3MXxJTkZSQXxOQXw1OTc5MzA3Mjk3MTAzODczNTI3
    Record hostname i-0c3b7e731bd7c8b6a
    Record plugin.type nri-agent

[OUTPUT]
    Name                newrelic
    Match               *
    licenseKey          <redacted>
    validateProxyCerts  false

[SERVICE]
    Log_Level trace

parsers.conf

[PARSER]
    Name        rfc5424-fluentd
    Format      regex
    Regex       /\A\<(?<pri>[0-9]{1,3})\>[1-9]\d{0,2} (?<time>[^ ]+) (?<host>[!-~]{1,255}) (?<ident>[!-~]{1,48}) (?<pid>[!-~]{1,128}) (?<msgid>[!-~]{1,32}) (?<extradata>(?:\-|(?:\[.*?(?<!\\)\])+))(?: (?<message>.+))?\z/
    Time_Key    time
    Time_Format %Y-%m-%dT%H:%M:%S.%L%z
    Time_Keep   On
  • Environment name and version (e.g. Kubernetes? What version?):
  • Server type and version: Debian Stretch
  • Operating System and version: Linux kernel 4.19.43
  • Filters and plugins:

Additional context

Our setup uses New relic infra agent (newrelic-infra.service), which is thin wrapper over fluent-bit, to collect and forward the logs into the New relic infra monitoring. rsyslog is used to ingest log into the new relic infra agent.
We are seeing a large number of our hosted merchants that have URLs ending in pattern described above, causing log spamming.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions