[engine] caught signal (SIGSEGV) in the version 2.0.9

[conung-vic]

Bug Report

I am using fluent-bit for making a PoC of log monitoring. If I add any line to monitored log, fluentbit fails with SIGSEGV

Here is a log of the Fluent-bit 2.0.9 (installed as curl https://raw.githubusercontent.com/fluent/fluent-bit/master/install.sh | sh )

Fluent Bit v2.0.9
* Copyright (C) 2015-2022 The Fluent Bit Authors
* Fluent Bit is a CNCF sub-project under the umbrella of Fluentd
* https://fluentbit.io

[2023/02/07 11:59:59] [ info] Configuration:
[2023/02/07 11:59:59] [ info]  flush time     | 1.000000 seconds
[2023/02/07 11:59:59] [ info]  grace          | 5 seconds
[2023/02/07 11:59:59] [ info]  daemon         | 0
[2023/02/07 11:59:59] [ info] ___________
[2023/02/07 11:59:59] [ info]  inputs:
[2023/02/07 11:59:59] [ info]      tail
[2023/02/07 11:59:59] [ info] ___________
[2023/02/07 11:59:59] [ info]  filters:
[2023/02/07 11:59:59] [ info] ___________
[2023/02/07 11:59:59] [ info]  outputs:
[2023/02/07 11:59:59] [ info]      stdout.0
[2023/02/07 11:59:59] [ info] ___________
[2023/02/07 11:59:59] [ info]  collectors:
[2023/02/07 11:59:59] [ info] [fluent bit] version=2.0.9, commit=, pid=27034
[2023/02/07 11:59:59] [debug] [engine] coroutine stack size: 24576 bytes (24.0K)
[2023/02/07 11:59:59] [ info] [storage] ver=1.4.0, type=memory, sync=normal, checksum=off, max_chunks_up=128
[2023/02/07 11:59:59] [ info] [cmetrics] version=0.5.8
[2023/02/07 11:59:59] [ info] [ctraces ] version=0.2.7
[2023/02/07 11:59:59] [ info] [input:tail:tail.0] initializing
[2023/02/07 11:59:59] [ info] [input:tail:tail.0] storage_strategy='memory' (memory only)
[2023/02/07 11:59:59] [debug] [tail:tail.0] created event channels: read=21 write=22
[2023/02/07 11:59:59] [debug] [input:tail:tail.0] flb_tail_fs_inotify_init() initializing inotify tail input
[2023/02/07 11:59:59] [debug] [input:tail:tail.0] inotify watch fd=27
[2023/02/07 11:59:59] [debug] [input:tail:tail.0] scanning path /path/to/my/log/file.log
[2023/02/07 11:59:59] [debug] [input:tail:tail.0] inode=22157105 with offset=404 appended as /path/to/my/log/file.log
[2023/02/07 11:59:59] [debug] [input:tail:tail.0] scan_glob add(): /path/to/my/log/file.log, inode 22157105
[2023/02/07 11:59:59] [debug] [input:tail:tail.0] 1 new files found on path '/path/to/my/log/file.log'
[2023/02/07 11:59:59] [debug] [stdout:stdout.0] created event channels: read=29 write=30
[2023/02/07 11:59:59] [ info] [sp] stream processor started
[2023/02/07 11:59:59] [debug] [input:tail:tail.0] inode=22157105 file=/path/to/my/log/file.log promote to TAIL_EVENT
[2023/02/07 11:59:59] [ info] [input:tail:tail.0] inotify_fs_add(): inode=22157105 watch_fd=1 name=/path/to/my/log/file.log
[2023/02/07 11:59:59] [debug] [input:tail:tail.0] [static files] processed 0b, done
[2023/02/07 11:59:59] [ info] [output:stdout:stdout.0] worker #0 started
[2023/02/07 12:00:00] [debug] [input:tail:tail.0] scanning path /path/to/my/log/file.log
[2023/02/07 12:00:00] [debug] [input:tail:tail.0] scan_blog add(): dismissed: /path/to/my/log/file.log, inode 22157105
[2023/02/07 12:00:00] [debug] [input:tail:tail.0] 0 new files found on path '/path/to/my/log/file.log'
[2023/02/07 12:00:01] [debug] [input:tail:tail.0] scanning path /path/to/my/log/file.log
[2023/02/07 12:00:01] [debug] [input:tail:tail.0] scan_blog add(): dismissed: /path/to/my/log/file.log, inode 22157105
[2023/02/07 12:00:01] [debug] [input:tail:tail.0] 0 new files found on path '/path/to/my/log/file.log'
[2023/02/07 12:00:02] [debug] [input:tail:tail.0] scanning path /path/to/my/log/file.log
[2023/02/07 12:00:02] [debug] [input:tail:tail.0] scan_blog add(): dismissed: /path/to/my/log/file.log, inode 22157105
[2023/02/07 12:00:02] [debug] [input:tail:tail.0] 0 new files found on path '/path/to/my/log/file.log'
[2023/02/07 12:00:03] [debug] [input:tail:tail.0] scanning path /path/to/my/log/file.log
[2023/02/07 12:00:03] [debug] [input:tail:tail.0] scan_blog add(): dismissed: /path/to/my/log/file.log, inode 22157105
[2023/02/07 12:00:03] [debug] [input:tail:tail.0] 0 new files found on path '/path/to/my/log/file.log'
[2023/02/07 12:00:04] [debug] [input:tail:tail.0] scanning path /path/to/my/log/file.log
[2023/02/07 12:00:04] [debug] [input:tail:tail.0] scan_blog add(): dismissed: /path/to/my/log/file.log, inode 22157105
[2023/02/07 12:00:04] [debug] [input:tail:tail.0] 0 new files found on path '/path/to/my/log/file.log'
[2023/02/07 12:00:05] [debug] [input:tail:tail.0] scanning path /path/to/my/log/file.log
[2023/02/07 12:00:05] [debug] [input:tail:tail.0] scan_blog add(): dismissed: /path/to/my/log/file.log, inode 22157105
[2023/02/07 12:00:05] [debug] [input:tail:tail.0] 0 new files found on path '/path/to/my/log/file.log'
[2023/02/07 12:00:06] [debug] [input:tail:tail.0] scanning path /path/to/my/log/file.log
[2023/02/07 12:00:06] [debug] [input:tail:tail.0] scan_blog add(): dismissed: /path/to/my/log/file.log, inode 22157105
[2023/02/07 12:00:06] [debug] [input:tail:tail.0] 0 new files found on path '/path/to/my/log/file.log'
[2023/02/07 12:00:06] [engine] caught signal (SIGSEGV)
#0  0x7f518ad9f97d      in  ???() at 4/multiarch/strlen-avx2.S:74
#1  0x7f518ac78db0      in  __vfprintf_internal() at fprintf-internal.c:1517
#2  0x7f518ac8a519      in  __vsnprintf_internal() at f.c:114
#3  0x55ac226db7bd      in  flb_sds_printf() at src/flb_sds.c:429
#4  0x55ac228ae700      in  debug_event_mask() at plugins/in_tail/tail_fs_inotify.c:69
#5  0x55ac228aec74      in  tail_fs_event() at plugins/in_tail/tail_fs_inotify.c:199
#6  0x55ac226ec4e9      in  flb_input_collector_fd() at src/flb_input.c:1882
#7  0x55ac22724195      in  flb_engine_handle_event() at src/flb_engine.c:490
#8  0x55ac22724195      in  flb_engine_start() at src/flb_engine.c:853
#9  0x55ac226c2b29      in  flb_lib_worker() at src/flb_lib.c:629
#10 0x7f518ac96b42      in  start_thread() at reate.c:442
#11 0x7f518ad289ff      in  ???() at sysv/linux/x86_64/clone3.S:81
#12 0xffffffffffffffff  in  ???() at ???:0
Aborted (core dumped)

Here is the analyzed log (edited manually, not real log from real app)

2023-02-07T09:24:30.034Z error [AuthRoutes] Can't check whether user is authorized, respond with 401
2023-02-07T09:24:30.034Z error [AuthRoutes] Can't check whether user is authorized, respond with 401

Here is used config:

[SERVICE]
    flush        1
    daemon       Off
    log_level    trace
    http_server  Off
    http_listen  0.0.0.0
    http_port    2020
    storage.metrics off

[INPUT]
    Name                tail
    Path                /path/to/my/log/file.log
    Tag                 TheAppServer  
    Refresh_Interval    1
    Skip_Empty_Lines    On    

[OUTPUT]
    name                        stdout
    match                       TheAppServer*

The version 2.0.8 is working as well on the same config, same log and same system.

[leonardo-albertovich]

The arguments in this line are backwards flb_sds_printf(&buf, "inode=%"PRIu64", %s, events: ", file->name, file->inode);, should be a simple fix.

Thanks for reporting the issue @conung-vic.

[ChezBunch]

I'm making a patch to check arguments passed to flb_sds_printf(), at least on GCC/Clang.

[ChezBunch]

See the PR #6800 for the patch.

[leonardo-albertovich]

Super cool, I already approved it, we might want to add that to cfl and the flb_log_* functions as well.

I think it's a very valuable improvement with no downsides, thank you @ChezBunch.

[ChezBunch]

Do you want me to make a PR for each of these functions?

[pavlozt]

Thanks for report. Affected to me. Even in simple configurations.

[leonardo-albertovich]

I'm sorry @ChezBunch but I missed that reply, if you were able to do that PR for the other functions I would really appreciate it.