Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Lua filter receiving garbage data #1343

Open
hamishforbes opened this issue May 23, 2019 · 1 comment

Comments

Projects
None yet
1 participant
@hamishforbes
Copy link

commented May 23, 2019

Bug Report

My Lua filter sometimes receives garbage values for the Tag argument.
This appears to be data from other messages leaking into the Tag field

I am using Docker with the fluentd log driver writing to fluentbit on the host.

In production this is affecting an Amazon Linux 2 system running in an AWS ECS cluster with fluentbit running directly on the host.

I've reproduced it on Ubuntu configured as below.

Your Environment

  • Version used: v1.1.1
  • Operating System and version: Ubuntu 18.04.2 LTS
  • Filters and plugins: Lua
  • Docker Version: Docker version 18.09.2, build 6247962

Configuration

fluentbit.conf

[SERVICE]
    Flush        5
    Daemon       Off
    Log_Level    info

[INPUT]
    Name forward
    Listen 127.0.0.1
    Port 24224

[FILTER]
    Name lua
    Match *
    script format.lua
    call format

[OUTPUT]
    Name stdout

format.lua

function format(tag, timestamp, record)
    print( tag );
    return 0, timestamp, record
end

Reproduction
Run FluentBit container on the host network, run another container and output something to FluentBit via the Docker fluentd log driver.

docker run --name 'test01' --rm -it --log-driver=fluentd --log-opt fluentd-buffer-limit=10m --log-opt fluentd-async-connect=true --log-opt tag=docker.{{.Name}} alpine  echo 'foobar'
test01.staging:~/fluent_bug# docker run --name fluentbit --rm -it --net=host --mount type=bind,source=/root/fluent_bug,target=/conf/  -ti fluent/fluent-bit:1.1 /fluent-bit/bin/fluent-bit -c /conf/fluentbit.conf

Fluent Bit v1.1.1
Copyright (C) Treasure Data

[2019/05/23 10:33:22] [ info] [storage] initializing...
[2019/05/23 10:33:22] [ info] [storage] in-memory
[2019/05/23 10:33:22] [ info] [storage] normal synchronization mode, checksum disabled
[2019/05/23 10:33:22] [ info] [engine] started (pid=1)
[2019/05/23 10:33:22] [ info] [in_fw] binding 127.0.0.1:24224
[2019/05/23 10:33:22] [ info] [sp] stream processor started





�ocker.test01�\�v�container_id�@ac6d6c8c39b6adcd4dbc53628e43a760b9090d4a74f6428585645cb4e3201003�container_name�/test01�source�stdout�log�foobar
nodev	tracefs
nodev	securityfs
nodev	sockfs
nodev	dax
nodev	bpf
nodev	pipefs
nodev	hugetlbfs
nodev	devpts
	ext3
	ext2
	ext4
	squashfs
	vfat
nodev	ecryptfs
	fuseblk
nodev	fuse
nodev	fusectl
nodev	pstore
nodev	mqueue
	btrfs
nodev	autofs
nodev	aufs
nodev	overlay

�ocker.test01�\�vcontainer_id�@2b8c52df8c39e39d717d8bc03d22b07f6b7bce2f67560756d7fbd467fe26426e�container_name�/test01�source�stdout�log�foobar
nodev	tracefs
nodev	securityfs
nodev	sockfs
nodev	dax
nodev	bpf
nodev	pipefs
nodev	hugetlbfs
nodev	devpts
	ext3
	ext2
	ext4
	squashfs
	vfat
nodev	ecryptfs
	fuseblk
nodev	fuse
nodev	fusectl
nodev	pstore
nodev	mqueue
	btrfs
nodev	autofs
nodev	aufs
nodev	overlay

[0] docker.test01: [1558607604.000000000, {"container_id"=>"ac6d6c8c39b6adcd4dbc53628e43a760b9090d4a74f6428585645cb4e3201003", "container_name"=>"/test0"}] "source"=>"stdout", "log"=>"foobar
[1] docker.test01: [1558607598.000000000, {"container_id"=>"2b8c52df8c39e39d717d8bc03d22b07f6b7bce2f67560756d7fbd467fe26426e", "container_name"=>"/test0"}] "source"=>"stdout", "log"=>"foobar
^C[engine] caught signal (SIGINT)
[2019/05/23 10:33:48] [ info] [input] pausing forward.0
@hamishforbes

This comment has been minimized.

Copy link
Author

commented May 23, 2019

Actually on further testing this doesn't seem to be related to the Lua filter:

test01.staging:~/fluent_bug# docker run --name fluentbit --rm -it --net=host fluent/fluent-bit:1.1 /fluent-bit/bin/fluent-bit -i forward -o stdout
Fluent Bit v1.1.1
Copyright (C) Treasure Data

[2019/05/23 10:48:32] [ info] [storage] initializing...
[2019/05/23 10:48:32] [ info] [storage] in-memory
[2019/05/23 10:48:32] [ info] [storage] normal synchronization mode, checksum disabled
[2019/05/23 10:48:32] [ info] [engine] started (pid=1)
[2019/05/23 10:48:32] [ info] [in_fw] binding 0.0.0.0:24224
[2019/05/23 10:48:32] [ info] [sp] stream processor started
", "container_id"=>"8662777bd474e8f60d6ab32ad310a230310b6c106808f8ee37a4d95a8b62c4ef"}]", "log"=>"foobar1
"}] docker.test2: [1558608516.000000000, {"container_id"=>"ca1af702ecc2af6dd2ffa81ad693ac447734501b3aedfdcb6530c3ec67772242", "container_name"=>"/test2", "source"=>"stdout", "log"=>"foobar2
", "container_id"=>"b773dbf5c17f16e2f781f2b342599fdb01ceeb2941de9da9180a5275197a8c89", "container_name"=>"/test3", "source"=>"stdout"}]
", "container_id"=>"94cfeb8adb418772749a63b8fc8e29974d23fe797a1f4fb321c59857dc108e28", "container_name"=>"/test4"}]
", "container_id"=>"f578fecac59badee5ee49aabe354892a9a4a22e08499b19a944b881883752c91", "container_name"=>"/test5"}]
^C[engine] caught signal (SIGINT)
[2019/05/23 10:48:51] [ info] [input] pausing forward.0
test01.staging:~# for i in {1..5}; do  docker run --name "test$i" --rm -it --log-driver=fluentd --log-opt fluentd-buffer-limit=10m --log-opt fluentd-async-connect=true --log-opt tag=docker.{{.Name}} alpine  echo "foobar$i"; done
foobar1
foobar2
foobar3
foobar4
foobar5
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.