Unable to capture docker log using fluentd log driver

[chrfergen]

Issue: I'm not able to capture docker log if fluent-bit is executed as a docker container itself, but it works if fluent-bit is executed as a linux process.

Environment descrition:

Ubuntu version:

tiian@ubuntu002:~$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 16.04.5 LTS
Release: 16.04
Codename: xenial

Docker version:

tiian@ubuntu002:~$ docker --version
Docker version 17.12.1-ce, build 7390fc6

Host installed fluent-bit version:

tiian@ubuntu002:/opt/td-agent-bit/bin$ ./td-agent-bit --version
Fluent Bit v0.13.8

Docker fluent-bit image:

tiian@ubuntu002:~/fluent-bit/0.13$ git log
commit 0144ac0
Author: Eduardo Silva [email protected]
Date: Sat Aug 18 09:55:43 2018 -0600

Release: v0.13.8 (with debian-base:0.3.1)

Signed-off-by: Eduardo Silva <...>

Test of fluent-bit using the local installation:

config file:

[SERVICE]
Flush 1
Daemon Off
Log_Level debug
Parsers_File parsers.conf
Parsers_File parsers_java.conf

[INPUT]
Name forward
Listen 127.0.0.1
Port 24224

[OUTPUT]
Name file
Match *
Path /tmp/output.txt

starting fluent-bit as a standard process:

tiian@ubuntu002:/opt/td-agent-bit/bin$ ./td-agent-bit -c /home/tiian/fluent-bit/0.13/fluent-bit.conf
Fluent-Bit v0.13.8
Copyright (C) Treasure Data

[2018/08/23 11:44:45] [ info] [engine] started (pid=10581)
[2018/08/23 11:44:45] [debug] [in_fw] Listen='127.0.0.1' TCP_Port=24224
[2018/08/23 11:44:45] [ info] [in_fw] binding 127.0.0.1:24224
[2018/08/23 11:44:45] [debug] [router] input=forward.0 'DYNAMIC TAG'

checking TCP port binding:

tiian@ubuntu002:~/fluent-bit/0.13$ sudo netstat -unta | grep 24224
tcp 0 0 127.0.0.1:24224 0.0.0.0:* LISTEN

executing ubuntu demo container to write log twice:

tiian@ubuntu002:/fluent-bit/0.13$ docker run --log-driver=fluentd --log-opt fluentd-address=127.0.0.1:24224 -t ubuntu echo "Testing a log message"
Testing a log message
tiian@ubuntu002:/fluent-bit/0.13$ docker run --log-driver=fluentd --log-opt fluentd-address=127.0.0.1:24224 -t ubuntu echo "Testing a log message"
Testing a log message

log produced by td-agent-bit process:

tiian@ubuntu002:/opt/td-agent-bit/bin$ ./td-agent-bit -c /home/tiian/fluent-bit/0.13/fluent-bit.conf
Fluent-Bit v0.13.8
Copyright (C) Treasure Data

[2018/08/23 11:44:45] [ info] [engine] started (pid=10581)
[2018/08/23 11:44:45] [debug] [in_fw] Listen='127.0.0.1' TCP_Port=24224
[2018/08/23 11:44:45] [ info] [in_fw] binding 127.0.0.1:24224
[2018/08/23 11:44:45] [debug] [router] input=forward.0 'DYNAMIC TAG'
[2018/08/23 11:47:11] [debug] [input forward.0] [mem buf] size = 158
[2018/08/23 11:47:11] [debug] [task] created task=0x7f493ea4e0e0 id=0 OK
[2018/08/23 11:47:11] [debug] [task] destroy task=0x7f493ea4e0e0 (task_id=0)
[2018/08/23 11:47:11] [debug] [dyntag forward.0] 0x7f493ea380c0 destroy (tag=f43d9ff92740, bytes=158)
[2018/08/23 11:47:15] [debug] [input forward.0] [mem buf] size = 161
[2018/08/23 11:47:15] [debug] [task] created task=0x7f493ea4e0e0 id=0 OK
[2018/08/23 11:47:15] [debug] [task] destroy task=0x7f493ea4e0e0 (task_id=0)
[2018/08/23 11:47:15] [debug] [dyntag forward.0] 0x7f493ea380c0 destroy (tag=697c76807872, bytes=161)

content of file /tmp/output.txt:

tiian@ubuntu002:~/fluent-bit/0.13$ cat /tmp/output.txt
f43d9ff92740: [1535017631.000000, {"container_id":"f43d9ff92740c5feb0789d5768344de252386fb447a3105ccef34f8c2d4df1df", "container_name":"/keen_heyrovsky", "source":"stdout", "log":"Testing a log message\r"}]
697c76807872: [1535017635.000000, {"container_id":"697c76807872eb49feb90ea4676bc24e7e3f75321937419d754ab138d4f4b039", "container_name":"/objective_lamport", "source":"stdout", "log":"Testing a log message\r"}]

Test of fluent-bit using a Docker container:

config file:

[SERVICE]
Flush 1
Daemon Off
Log_Level debug
Log_File /fluent-bit/log/fluent-bit.log
Parsers_File parsers.conf
Parsers_File parsers_java.conf

[INPUT]
Name forward
Listen 127.0.0.1
Port 24224

[OUTPUT]
Name file
Match *
Path /tmp/output.txt

image build:

tiian@ubuntu002:~/fluent-bit/0.13$ docker build -t fluent/fluent-bit:0.13 ./ Sending build context to Docker daemon 20.48kB
Step 1/17 : FROM gcr.io/google-containers/debian-base-amd64:0.3.1 as builder
---> dc02d73f229d
Step 2/17 : ENV FLB_MAJOR 0
---> Using cache
---> e24c12dfd2c9
Step 3/17 : ENV FLB_MINOR 13
---> Using cache
---> daeabe577cc4
Step 4/17 : ENV FLB_PATCH 8
---> Using cache
---> c83915325cda
Step 5/17 : ENV FLB_VERSION 0.13.8
---> Using cache
---> 127e5218110b
Step 6/17 : ENV DEBIAN_FRONTEND noninteractive
---> Using cache
---> aca51e584627
Step 7/17 : ENV FLB_TARBALL http://github.com/fluent/fluent-bit/archive/v$FLB_VERSION.zip
---> Using cache
---> c874a392b6c8
Step 8/17 : RUN mkdir -p /fluent-bit/bin /fluent-bit/etc /fluent-bit/log /tmp/src/
---> Using cache
---> 06ca160850d7
Step 9/17 : RUN apt-get update && apt-get dist-upgrade -y && apt-get install -y build-essential cmake make wget unzip libsystemd-dev libssl1.0-dev libasl-dev && wget -O "/tmp/fluent-bit-${FLB_VERSION}.zip" ${FLB_TARBALL} && cd /tmp && unzip "fluent-bit-$FLB_VERSION.zip" && cd "fluent-bit-$FLB_VERSION"/build/ && cmake -DFLB_DEBUG=On -DFLB_TRACE=Off -DFLB_JEMALLOC=On -DFLB_BUFFERING=On -DFLB_TLS=On -DFLB_WITHOUT_SHARED_LIB=On -DFLB_WITHOUT_EXAMPLES=On -DFLB_HTTP_SERVER=On -DFLB_OUT_KAFKA=On .. && make && install bin/fluent-bit /fluent-bit/bin/
---> Using cache
---> a38d577f2aee
Step 10/17 : COPY fluent-bit.conf parsers.conf parsers_java.conf parsers_mult.conf parsers_openstack.conf parsers_cinder.conf /fluent-bit/etc/
---> a6fb04aa35e5
Step 11/17 : FROM gcr.io/google-containers/debian-base-amd64:0.3.1
---> dc02d73f229d
Step 12/17 : MAINTAINER Eduardo Silva <...>
---> Using cache
---> d849c4007ea2
Step 13/17 : LABEL Description="Fluent Bit docker image" Vendor="Fluent Organization" Version="1.1"
---> Using cache
---> a7dca0aaf370
Step 14/17 : RUN apt-get update && apt-get dist-upgrade -y && apt-get install --no-install-recommends ca-certificates libssl1.0.2 -y && rm -rf /var/lib/apt/lists/* && apt-get autoclean
---> Using cache
---> 5b58cda454b8
Step 15/17 : COPY --from=builder /fluent-bit /fluent-bit
---> 224f0a816db7
Step 16/17 : EXPOSE 2020
---> Running in cfad89423352
Removing intermediate container cfad89423352
---> 84aeb850af84
Step 17/17 : CMD ["/fluent-bit/bin/fluent-bit", "-c", "/fluent-bit/etc/fluent-bit.conf"]
---> Running in 970c14f349ab
Removing intermediate container 970c14f349ab
---> f29477b24975
Successfully built f29477b24975
Successfully tagged fluent/fluent-bit:0.13

starting fluent-bit as a Docker container:

tiian@ubuntu002:/opt/td-agent-bit/bin$ docker run -p 127.0.0.1:24224:24224 fluent/fluent-bit:0.13

checking TCP port binding:

tiian@ubuntu002:~/fluent-bit/0.13$ sudo netstat -unta | grep 24224
tcp 0 0 127.0.0.1:24224 0.0.0.0:* LISTEN

executing ubuntu demo container to write log twice:

tiian@ubuntu002:/fluent-bit/0.13$ docker run --log-driver=fluentd --log-opt fluentd-address=127.0.0.1:24224 -t ubuntu echo "Testing a log message"
Testing a log message
tiian@ubuntu002:/fluent-bit/0.13$ docker run --log-driver=fluentd --log-opt fluentd-address=127.0.0.1:24224 -t ubuntu echo "Testing a log message"
Testing a log message

log produced by td-agent-bit (inside Docker container):

tiian@ubuntu002:$ docker container ls
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
b58742fec2a0 fluent/fluent-bit:0.13 "/fluent-bit/bin/flu…" 3 minutes ago Up 3 minutes 2020/tcp, 127.0.0.1:24224->24224/tcp lucid_meitner
tiian@ubuntu002:$ docker exec -ti b58742fec2a0 bash
root@b58742fec2a0:/# cat /fluent-bit/log/fluent-bit.log
[2018/08/23 09:51:13] [ info] [engine] started (pid=1)
[2018/08/23 09:51:13] [debug] [in_fw] Listen='127.0.0.1' TCP_Port=24224
[2018/08/23 09:51:13] [ info] [in_fw] binding 127.0.0.1:24224
[2018/08/23 09:51:13] [debug] [router] input=forward.0 'DYNAMIC TAG'

no file /tmp/output.txt produced (inside Docker container):

root@b58742fec2a0:/# ls -la /tmp/
total 8
drwxrwxrwt 2 root root 4096 Jul 20 19:09 .
drwxr-xr-x 1 root root 4096 Aug 23 09:51 ..

Issue summary:

1. if executed inside a docker container fluent-bit does not log the messages related to the arrival and processing of docker log entries:
   [2018/08/23 11:47:11] [debug] [input forward.0] [mem buf] size = 158
   [2018/08/23 11:47:11] [debug] [task] created task=0x7f493ea4e0e0 id=0 OK
   [2018/08/23 11:47:11] [debug] [task] destroy task=0x7f493ea4e0e0 (task_id=0)
   [2018/08/23 11:47:11] [debug] [dyntag forward.0] 0x7f493ea380c0 destroy (tag=f43d9ff92740, bytes=158)
   [2018/08/23 11:47:15] [debug] [input forward.0] [mem buf] size = 161
   [2018/08/23 11:47:15] [debug] [task] created task=0x7f493ea4e0e0 id=0 OK
   [2018/08/23 11:47:15] [debug] [task] destroy task=0x7f493ea4e0e0 (task_id=0)
   [2018/08/23 11:47:15] [debug] [dyntag forward.0] 0x7f493ea380c0 destroy (tag=697c76807872, bytes=161)

2. output file is not created by fluent-bit output/file plugin

[ShankarSumanth]

Have a similar issue on mac. The fluent-bit docker image outputs logs of cpu.local but was unable to get logs from another container which echo's Testing a log message

Used the same commands provided in the README.

docker run -p 127.0.0.1:24224:24224 fluent/fluent-bit:latest

docker run --log-driver=fluentd -t ubuntu echo "Testing a log message"

[ShankarSumanth]

Ok finally solved it for MAC. Somehow the configuration

STEP 1: Config file

Create a config file test.conf and put in the below contents

[INPUT]
    Name Forward
    Port 24224

[OUTPUT]
    Name  stdout
    Match *

Step 2: Start the docker container

Use the below command( and ajust accordingly) to start the fluent bit container.

docker run -it -p 24224:24224 -v $(pwd)/test.conf:/fluent-bit/etc/fluent-bit.conf fluent/fluent-bit:latest

Step 3: Test your configuration

Now in a new terminal start a new docker container and set the log-driver to fluentd

docker run --log-driver=fluentd -t ubuntu echo "Testing a log message".

You should be able to see the output from the docker container, but now I have to figure out why the output message shows up in a wrong format.

For eg:
[0] 72ba16e02658: [1544998108.000000000, {"container_id"=>"72ba16e02658ffb44367972db7fc11c9e8079b0e341152bb9bbf08f6d32e9f17", "container_name"=>"/hungry_hofstadter", "source"=>"stdout", "log"=>"Testing a log "}]sage

Update:

You can of course use the default config provided by fluent-bit but for some reason the config has to be passed as a volume mount as shown in the first step.

[StudioEtrange]

On linux
this do not work even using a conf file !

[edsiper]

I totally missed this ticket.

@StudioEtrange please elaborate on the issue so I can troubleshoot, steps to reproduce ?

[StudioEtrange]

First my env

$ docker version
Client:
 Version:       18.03.0-ce
 API version:   1.37
 Go version:    go1.9.4
 Git commit:    0520e24
 Built: Wed Mar 21 23:10:22 2018
 OS/Arch:       linux/amd64
 Experimental:  false
 Orchestrator:  swarm

Server:
 Engine:
  Version:      18.03.0-ce
  API version:  1.37 (minimum version 1.12)
  Go version:   go1.9.4
  Git commit:   0520e24
  Built:        Wed Mar 21 23:08:52 2018
  OS/Arch:      linux/amd64
  Experimental: false

Secondly, the problem

What i have tested :

HOST_IP=$(hostname -I | awk '{split($1, a, " "); print a[1]}')

docker run --rm --name fluentbit  -p 24224:24224 fluent/fluent-bit:1.3.7 /fluent-bit/bin/fluent-bit -i forward://0.0.0.0:24224 -o stdout
docker run --rm --log-driver=fluentd --log-opt fluentd-address=${HOST_IP}:24224 -t ubuntu echo "Testing a log message"

Should ouput log message BUT do not work

Lastly, side notes

My commands are inspired from https://github.com/fluent/fluent-bit-docker-image readme commands which do not work either because default input is cpu not forward. Which is not what readme says

By default, the configuration set a listener on TCP port 24224 through Forward protocol

docker run -p 127.0.0.1:24224:24224 fluent/fluent-bit:latest
docker run --log-driver=fluentd -t ubuntu echo "Testing a log message"

[edsiper]

it's working here:

do you see any difference if you force the IP to 127.0.0.1 ?

[edsiper]

ah, do not use -t

[StudioEtrange]

trying specify 127.0.0.1 for fluentbit only

• not specifying any fluentd driver address
• specifying 127.0.0.1 for mapping

docker run --rm --name fluentbit  -p 127.0.0.1:24224:24224 fluent/fluent-bit:1.3.7 /fluent-bit/bin/fluent-bit -i forward://0.0.0.0:24224 -o stdout
Fluent Bit v1.3.7
Copyright (C) Treasure Data

[2020/02/17 02:19:38] [ info] [storage] initializing...
[2020/02/17 02:19:38] [ info] [storage] in-memory
[2020/02/17 02:19:38] [ info] [storage] normal synchronization mode, checksum disabled, max_chunks_up=128
[2020/02/17 02:19:38] [ info] [engine] started (pid=1)
[2020/02/17 02:19:38] [ info] [in_fw] binding 0.0.0.0:24224
[2020/02/17 02:19:38] [ info] [sp] stream processor started

$ docker run --rm --log-driver=fluentd  ubuntu echo "Testing a log message"
Testing a log message

trying specify 127.0.0.1 for fluentbit and host ip for driver : generate another error

• specifying 127.0.0.1 for mapping
• specifying HOST_IP (first of the three host address) for fluentd driver address

docker run --rm --name fluentbit  -p 127.0.0.1:24224:24224 fluent/fluent-bit:1.3.7 /fluent-bit/bin/fluent-bit -i forward://0.0.0.0:24224 -o stdout
Fluent Bit v1.3.7
Copyright (C) Treasure Data

[2020/02/17 02:05:00] [ info] [storage] initializing...
[2020/02/17 02:05:00] [ info] [storage] in-memory
[2020/02/17 02:05:00] [ info] [storage] normal synchronization mode, checksum disabled, max_chunks_up=128
[2020/02/17 02:05:00] [ info] [engine] started (pid=1)
[2020/02/17 02:05:00] [ info] [in_fw] binding 0.0.0.0:24224
[2020/02/17 02:05:00] [ info] [sp] stream processor started

HOST_IP=$(hostname -I | awk '{split($1, a, " "); print a[1]}')
$ docker run -t --rm --log-driver=fluentd --log-opt fluentd-address=${HOST_IP}:24224  ubuntu echo "Testing a log message"
docker: Error response from daemon: failed to initialize logging driver: dial tcp 192.168.0.50:24224: getsockopt: connection refused.

Ok, when launching fluentbit docker, with 127.0.0.1, the log driver can't connect. I have several IP on my host, so I dont know which fluentd-address use

$ hostname -i
192.168.0.50 192.168.1.50 192.168.2.50

trying specify first hostname IP (192.168.0.50) for fluentbit and driver : error

• specifying one of the host IP for mapping
• specifying one of the host IP for fluentd driver address

 docker run --rm --name fluentbit  -p 192.168.0.50:24224:24224 fluent/fluent-bit:1.3.7 /fluent-bit/bin/fluent-bit -i forward://0.0.0.0:24224 -o stdout

 docker run --rm --log-driver=fluentd --log-opt fluentd-address=192.168.0.50:24224  ubuntu echo "Testing a log message"
docker: Error response from daemon: failed to initialize logging driver: dial tcp 192.168.0.50:24224: i/o timeout.

attach to host net : it works

• not using -t (using -t trunk log)
• attach fluentbit to host network

This works :

$ docker run --rm --name fluentbit --network host -ti fluent/fluent-bit:1.3.7 /fluent-bit/bin/fluent-bit -i forward://0.0.0.0:24224 -o stdout
Fluent Bit v1.3.7
Copyright (C) Treasure Data

[2020/02/17 02:28:41] [ info] [storage] initializing...
[2020/02/17 02:28:41] [ info] [storage] in-memory
[2020/02/17 02:28:41] [ info] [storage] normal synchronization mode, checksum disabled, max_chunks_up=128
[2020/02/17 02:28:41] [ info] [engine] started (pid=1)
[2020/02/17 02:28:41] [ info] [in_fw] binding 0.0.0.0:24224
[2020/02/17 02:28:41] [ info] [sp] stream processor started
[0] 3e2e2292f600: [1581906661.000000000, {"container_id"=>"3e2e2292f600665d70324f030a0a1942bb00b13dc6da85993591a7141e9deb9e", "container_name"=>"/upbeat_bhaskara", "source"=>"stdout", "log"=>"Testing a log message"}]


HOST_IP=$(hostname -I | awk '{split($1, a, " "); print a[1]}')
docker run --rm --log-driver=fluentd --log-opt fluentd-address=${HOST_IP}:24224 ubuntu echo "Testing a log message"
Testing a log message