fluent-bit icon indicating copy to clipboard operation
fluent-bit copied to clipboard

inline messages

Open mashkouski opened this issue 1 year ago • 3 comments

fluent-bit 2.2.1 (very often) (and 2.2.2 (rarely)) in windows with small flush time (1 sec) sends inline messages in forward output. (We have our own tcp "forward" server written in rust)

inline messages example:

[
"tag",
  [
     [ time, {message} ],
     [ time, {message} ],
   ],
  
  [ 
     "tag",
        [
            [ time, {message} ],
            [ time, {message} ],
        ],
       {
         options
       }
  ]
]

And sometimes we get multi-level nesting, but always with one options section

I think it is not expected behaviour (I don't found it in forward protocol specifications)

Used fluent config:

[SERVICE]
    flush        1

    daemon       Off

    log_level    info

    parsers_file parsers.conf
    plugins_file plugins.conf

    http_server  Off
    http_listen  0.0.0.0
    http_port    2020

    storage.metrics on
    storage.path C:/Program Files/fluent-bit/storage
    storage.sync normal
    storage.checksum off

[INPUT]
    Name         winevtlog
    Channels     application,system,security
    Interval_Sec 1
    Read_Existing_Events True
    storage.type  filesystem
    Tag ws.windows.machine-name

[OUTPUT]
    Name          forward
    Match         ws.windows.machine-name
    Host          10.10.120.55
    Port          24225
    Require_ack_response True
    storage.total_limit_size 10000M
    Retry_Limit no_limits

(parsers_file and plugins_file - with default options)

Environment

  • fluent-bit 2.2.1 (well reproduces) / 2.2.2
  • Windows 11 Desktop, Intel x64

mashkouski avatar Jan 24 '24 12:01 mashkouski

Could you check the forward protocol specification v1.5 ? https://github.com/fluent/fluentd/wiki/Forward-Protocol-Specification-v1.5#event-modes

nokute78 avatar Jan 27 '24 00:01 nokute78

Yep and 99% messages has normal format:

[
  "tag.name",
  [
    [1441588984, {"message": "foo"}],
    [1441588985, {"message": "bar"}],
    [1441588986, {"message": "baz"}]
  ],
  {"option": "optional", "fluent_signal": 0}
]

(time in fixext8 and fluent_signal = 0)

but 1% instead "option" section has nesting message, like:

[
  "tag.name",
  [
    [1441588984, {"message": "foo"}],
    [1441588985, {"message": "bar"}],
    [1441588986, {"message": "baz"}]
  ],
  [
    "tag.name",
    [
      [1441588984, {"message": "foo"}],
      [1441588985, {"message": "bar"}],
      [1441588986, {"message": "baz"}]
    ],
    {"option": "optional", "fluent_signal": 0}
  ]
]

(nested message has fluent_signal = 0)

First tag and second - has the same value

This nesting can also be multi-level

And I can't find in protocol 1.5 description this behaviour


Nested message example:

I split message to 3 parts:

[
  "tag.name", <- idx-0.txt
  [ time + messages], <- idx-1.txt
  {"option": "optional", "fluent_signal": 0} <- idx-2.txt
]
  1. idx-0.txt - tag - file size 114 bytes - OK
  2. idx-1.txt - messages - file size 6.3 MB - OK
  3. idx-2.txt - should be options - file size 93.8 MB !!!!! - ???

idx-0.txt:

[184, 115, 101, 114, 118, 101, 114, 46, 119, 105, 110, 100, 111, 119, 115, 46, 68, 67, 84, 84, 45, 48, 50, 45, 86]

"server.windows.DCTT-02-V"

idx-1.txt

[220, 17, 68,  - array 16
221, 0, 0, 0, 2, - array 32 - 2 elements
215, 0, 101, 176, 202, 55, 42, 190, 116, 192, - fixext 8
222, 0, 20, 172, 80, 114, 111, 118, 105, 100, 101, 114, ... - map 16 - message

[
  [time,  {message}],
  [time,  {message}],
]

idx-2.txt

[147,  - fixarray, 3 - elements ????? - should be map with options
190, 115, 101, 114, 118, 101, 114, 46, 119, 105, 110, 100, 111, 119, 115, 46, 77, 79, 71, 48, 49, 45, 68, 67, 84, 82, 45, 48, 50, 45, 86, 220, 9, 121, 221, 0, 0, 0, 2, 215, 0, 101, 176, 202, 74, 4, 217, 97, 92, 222, 0, 20, 172, 80, 114, 111, 118, 105, 100, 101, 114, 78, 97, 109, 101, 160, 172, 80, 114, 111, 118, 105, 100, 101, 114, 71, 117, 105, 100, 160, 170, 81, 117, 97, 108, 105, 102, 105, 101, 114, 115, 205, 64, 0, 167, 69, 118, 101, 110, 116, 73, 68, 205, 3, 235, 167, 86, 101, 114, 115, 105, 111, 110, 0, 165, 76, 101, 118, 101, 108, 4, 164, 84, 97, 115, 107, 0, 166, 79, 112, 99, 111, 100, 101, 0, 168, 75, 101, 121, 119, 111, 114, 100, 115, 176, 48, 120, 56, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 171, 84, 105, 109, 101, 67, 114, 101, 97, 116, 101, 100, 185, 50, 48, 49, 57, 45, 48, 56, 45, 48, 49, 32, 49, 49, 58, 50, 56, 58, 53, 51, 32, 43, 48, 51, 48, 48, 173, 69, 118, 101, 110, 116, 82, 101, 99, 111, 114, 100, 73, 68, 206, 0, 1, 230, 13, 170, 65, 99, 116, 105, 118, 105, 116, 121, 73, 68, 160, 177, 82, 101, 108, 97, 116, 101, 100, 65, 99, 116, 105, 118, 105, 116, 121, 73, 68, 160, 169, 80, 114, 111, 99, 101, 115, 115, 73, 68, 0, 168, 84, 104, 114, 101, 97, 100, 73, 68, 0, 167, 67, 104, 97, 110, 110, 101, 108, 160, 168, 67, 111, 109, 112, 117, 116, 101, 114, 160, 166, 85, 115, 101, 114, 73, 68, 160, 167, 77, 101, 115, 115, 97, 103, 101, 160, 173, 83, 116, 114, 105, 110, 103, 73, 110, 115, 101, 114, 116, 115, 146, 160, 160, 221, 0, 0, 0, 2, 215, 0, 101, 176, 202, 74, 4, 223, 98, 20, 222, 0, 20, 172, 80, 114, 111, 118, 105, 100, 101, 114, 78, 97, 109, 101, 160, 172, 80, 114, 111, 118, 105, 100, 101, 114, 71, 117, 105, 100, 160, 170, 81, 117, 97, 108, 105, 102, 105, 101, 114, 115, 205, 64, 0, 167, 69, 118, 101, 110, 116, 73, 68, 205, 3, 235, 167, 86, 101, 114, 115, 105, 111, 110, 0, ...

mashkouski avatar Jan 27 '24 19:01 mashkouski

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] avatar May 01 '24 01:05 github-actions[bot]

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

github-actions[bot] avatar May 07 '24 01:05 github-actions[bot]