Error while running fluentd image on container into EC2

[ftes...@keyneticdigital.com]

I am trying to run my fluentd docker image in an ec2 container (AWS). Yet there is a problem in what regards to file permissions related to my sources pos_file

Here I post my ltd-agent log entries:

2016-09-29 14:23:00 +0000 [info]: reading config file path="/etc/td-agent/td-agent.conf"
2016-09-29 14:23:00 +0000 [info]: starting fluentd-0.12.26
2016-09-29 14:23:00 +0000 [info]: gem 'fluent-mixin-config-placeholders' version '0.4.0'
2016-09-29 14:23:00 +0000 [info]: gem 'fluent-mixin-plaintextformatter' version '0.2.6'
2016-09-29 14:23:00 +0000 [info]: gem 'fluent-plugin-kinesis' version '1.1.1'
2016-09-29 14:23:00 +0000 [info]: gem 'fluent-plugin-mongo' version '0.7.13'
2016-09-29 14:23:00 +0000 [info]: gem 'fluent-plugin-rewrite-tag-filter' version '1.5.5'
2016-09-29 14:23:00 +0000 [info]: gem 'fluent-plugin-s3' version '0.6.8'
2016-09-29 14:23:00 +0000 [info]: gem 'fluent-plugin-scribe' version '0.10.14'
2016-09-29 14:23:00 +0000 [info]: gem 'fluent-plugin-td' version '0.10.28'
2016-09-29 14:23:00 +0000 [info]: gem 'fluent-plugin-td-monitoring' version '0.2.2'
2016-09-29 14:23:00 +0000 [info]: gem 'fluent-plugin-webhdfs' version '0.4.2'
2016-09-29 14:23:00 +0000 [info]: gem 'fluentd' version '0.12.26'
2016-09-29 14:23:00 +0000 [info]: adding match pattern="nginx.log" type="stdout"
2016-09-29 14:23:00 +0000 [info]: adding match pattern="nginx.track" type="stdout"
2016-09-29 14:23:00 +0000 [info]: adding source type="tail"
2016-09-29 14:23:00 +0000 [info]: adding source type="tail"

2016-09-29 14:23:00 +0000 [info]: using configuration file:

<ROOT>


  <source>
    type tail
    format /^(?<remote>[^ ]*) (?<host>[^ ]*) (?<user>[^ ]*) \[(?<time>[^\]]*)\] "(?<method>\S+)(?: +(?<path>[^ ]*) +\S*)?" (?<code>[^ ]*) (?<size>[^ ]*)(?: "(?<referer>[^\"]*)" "(?<agent>[^\"]*)" "(?<forwarder>[^\"]*)")?/
    time_format %d/%b/%Y:%H:%M:%S %z
    path /tmp/log/nginx/access.log
    pos_file /var/log/td-agent/nginx-access.pos
    tag nginx.log
  </source>
  <source>
    type tail
    format /^(?<time_iso8601>[^ ]*) [^ ]* (?<remote_addr>[^ ]*) [^ ]* (?<uid_got>[^ ]*) [^ ]* (?<http_x_forwarded_for>[^ ]*) [^ ]* (?<http_referer>[^ ]*) [^ ]* (?<http_user_agent>[^\"]*\)[^:-:]*) [^ ]* (?<geoip_country_code>[^ ]*) [^ ]* (?<geoip_region>[^ ]*) [^ ]* (?<geoip_city>[^ ]*) [^ ]* (?<geoip_latitude>[^ ]*) [^ ]* (?<geoip_longitude>[^ ]*) [^ ]* (?<query_string>[^ ]*)?/
    time_format %d/%b/%Y:%H:%M:%S %z
    path /tmp/log/nginx/tracking.log
    pos_file /var/log/td-agent/nginx-tracking.pos
    tag nginx.track
  </source>
  <match nginx.log>
    @type stdout
  </match>
  <match nginx.track>
    @type stdout
  </match>
</ROOT>

2016-09-29 14:23:00 +0000 [error]: unexpected error error_class=Errno::EACCES error=#<Errno::EACCES: Permission denied @ rb_sysopen - /var/log/td-agent/nginx-access.pos>

  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/plugin/in_tail.rb:107:in `initialize'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/plugin/in_tail.rb:107:in `open'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/plugin/in_tail.rb:107:in `start'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/root_agent.rb:115:in `block in start'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/root_agent.rb:114:in `each'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/root_agent.rb:114:in `start'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/engine.rb:237:in `start'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/engine.rb:187:in `run'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/supervisor.rb:570:in `run_engine'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/supervisor.rb:162:in `block in start'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/supervisor.rb:366:in `call'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/supervisor.rb:366:in `main_process'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/supervisor.rb:339:in `block in supervise'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/supervisor.rb:338:in `fork'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/supervisor.rb:338:in `supervise'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/supervisor.rb:156:in `start'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/lib/fluent/command/fluentd.rb:173:in `<top (required)>'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/site_ruby/2.1.0/rubygems/core_ext/kernel_require.rb:54:in `require'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/site_ruby/2.1.0/rubygems/core_ext/kernel_require.rb:54:in `require'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.26/bin/fluentd:5:in `<top (required)>'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/bin/fluentd:23:in `load'
  2016-09-29 14:23:00 +0000 [error]: /opt/td-agent/embedded/bin/fluentd:23:in `<top (required)>'
  2016-09-29 14:23:00 +0000 [error]: /usr/sbin/td-agent:7:in `load'
  2016-09-29 14:23:00 +0000 [error]: /usr/sbin/td-agent:7:in `<main>'

2016-09-29 14:23:00 +0000 [info]: shutting down fluentd
2016-09-29 14:23:00 +0000 [info]: shutting down output type="stdout" plugin_id="object:3ffaf1162c78"
2016-09-29 14:23:00 +0000 [info]: shutting down output type="stdout" plugin_id="object:3ffaf11d505c"
2016-09-29 14:23:00 +0000 [info]: process finished code=0
2016-09-29 14:23:00 +0000 [warn]: process died within 1 second. exit.

Is there any solution or workaround like granting my docker image some permissions in my Dockerfile?

At the moment I have already added sudo usermod -aG adm td-agent in my Dockerfile.

P.S: while running the docker image on my personal computer everything was ok; yet while using EC2 instance I cannot make it run properly.

Docker Image: francotestori/kd-fluentd-kinesis

Thanks in advance for any guidance on the subject.

[Kazuya Yokogawa]

Hi

Ownership of pos_files("/var/log/td-agent/{nginx-access.pos,nginx-tracking.pos}") is root in francotestori/kd-fluentd-kinesis docker hub image.

So you should change ownership of their pos_files or not copy their pos_files when building your own docker image.

$ docker history --no-trunc francotestori/kd-fluentd-kinesis | tail -n+2 | cut -b 106-250 | tac

#(nop) ADD file:7d01e28262e78b1d7fd9ff5c2999e4519a338e8447becf947af04004c45b6be9 in /

set -xe   && echo '#!/bin/sh' > /usr/sbin/policy-rc.d  && echo 'exit 101' >> /usr/sbin/policy-rc.d  && chmod +x /usr/sbin/policy-rc.d   && dpkg-d

rm -rf /var/lib/apt/lists/*

sed -i 's/^#\s*\(deb.*universe\)$/\1/g' /etc/apt/sources.list

mkdir -p /run/systemd && echo 'docker' > /run/systemd/container

#(nop)  CMD ["/bin/bash"]

#(nop)  USER [root]

apt-get update && apt-get install -y curl && apt-get install -y sudo

curl -L https://toolbelt.treasuredata.com/sh/install-ubuntu-xenial-td-agent2.sh | sh

sudo td-agent-gem install fluent-plugin-kinesis

sudo usermod -aG adm td-agent

#(nop) COPY file:172f2fb592c6b062acb9163b203c4dad7311243d1affbd14eb538a6bafa6ed9e in /var/log/td-agent/nginx-access.pos

#(nop) COPY file:bf7904f29d061dc664bd6b07782d79c4c0f89c131b7792ac649833dda184ff47 in /var/log/td-agent/nginx-tracking.pos

#(nop) COPY file:d233cddbbe55f79fcc497c8858dc90b1db4f8601247f8f3819549be594937433 in /etc/td-agent/td-agent.conf

#(nop)  CMD ["/bin/sh" "-c" "/etc/init.d/td-agent restart && tail -F /var/log/td-agent/td-agent.conf"]

# tail -F /var/log/td-agent/td-agent.conf => tail -F /var/log/td-agent/td-agent.log ?

File Permission:

[mapk0y@kona:~/tmp]$ docker run --rm francotestori/kd-fluentd-kinesis ls -l /var/log/td-agent

total 0

-rw-rw-r-- 1 root root 0 Sep 29 13:16 nginx-access.pos

-rw-rw-r-- 1 root root 0 Sep 29 14:19 nginx-tracking.pos

# Failed
[mapk0y@kona:~]$ docker run -it --rm francotestori/kd-fluentd-kinesis bash

root@fa0b9bc3e1e4:/# /etc/init.d/td-agent restart

Restarting td-agent:  * td-agent

root@fa0b9bc3e1e4:/# grep 'Permission denied' /var/log/td-agent/td-agent.log 

2016-09-29 16:57:03 +0000 [error]: unexpected error error_class=Errno::EACCES error=#<Errno::EACCES: Permission denied @ rb_sysopen - /var/log/td-agent/nginx-access.pos>

root@fa0b9bc3e1e4:/# ps auxf

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND

root         1  0.0  0.0  18244  3132 ?        Ss   16:56   0:00 bash

root        50  0.0  0.0  34428  2792 ?        R+   16:57   0:00 ps auxf

# Succeeded - change ownership version

[mapk0y@kona:~]$ docker run -it --rm francotestori/kd-fluentd-kinesis bash

root@46e4f1fc1430:/# ls -l /var/log/td-agent/

total 0

-rw-rw-r-- 1 root root 0 Sep 29 13:16 nginx-access.pos

-rw-rw-r-- 1 root root 0 Sep 29 14:19 nginx-tracking.pos

root@46e4f1fc1430:/# chown -v td-agent. /var/log/td-agent/*.pos                                                                                                                                                                              

changed ownership of '/var/log/td-agent/nginx-access.pos' from root:root to td-agent:td-agent

changed ownership of '/var/log/td-agent/nginx-tracking.pos' from root:root to td-agent:td-agent

root@46e4f1fc1430:/# ls -l /var/log/td-agent/                                                                                                                                                                                                

total 0

-rw-rw-r-- 1 td-agent td-agent 0 Sep 29 13:16 nginx-access.pos

-rw-rw-r-- 1 td-agent td-agent 0 Sep 29 14:19 nginx-tracking.pos

root@46e4f1fc1430:/# /etc/init.d/td-agent restart

Restarting td-agent:  * td-agent

root@46e4f1fc1430:/# grep 'Permission denied' /var/log/td-agent/td-agent.log

root@46e4f1fc1430:/# ps auxf

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND

root         1  0.0  0.0  18244  3156 ?        Ss   16:57   0:00 bash

td-agent    45  0.0  0.1 118700 22748 ?        Sl   16:58   0:00 /opt/td-agent/embedded/bin/ruby /usr/sbin/td-agent --log /var/log/td-agent/td-agent.log --daemon /var/run/td-agent/td-agent.pid

td-agent    48  0.3  0.1 141724 30716 ?        Sl   16:58   0:00  \_ /opt/td-agent/embedded/bin/ruby /usr/sbin/td-agent --log /var/log/td-agent/td-agent.log --daemon /var/run/td-agent/td-agent.pid

root        54  0.0  0.0  34428  2792 ?        R+   16:58   0:00 ps auxf

# Succeeded - remove pos file version

[mapk0y@kona:~/tmp]$ docker run -it --rm francotestori/kd-fluentd-kinesis bash

root@bcd6575ce0f6:/# ls -l /var//log/td-agent/

total 0

-rw-rw-r-- 1 root root 0 Sep 29 13:16 nginx-access.pos

-rw-rw-r-- 1 root root 0 Sep 29 14:19 nginx-tracking.pos

root@bcd6575ce0f6:/# rm -v /var//log/td-agent/*.pos

removed '/var//log/td-agent/nginx-access.pos'

removed '/var//log/td-agent/nginx-tracking.pos'

root@bcd6575ce0f6:/# /etc/init.d/td-agent restart

Restarting td-agent:  * td-agent

root@bcd6575ce0f6:/# grep 'Permission denied' /var/log/td-agent/td-agent.log

root@bcd6575ce0f6:/# ls -l /var//log/td-agent/

total 12

-rw-r--r-- 1 td-agent td-agent   60 Sep 29 17:10 nginx-access.pos

-rw-r--r-- 1 td-agent td-agent   62 Sep 29 17:10 nginx-tracking.pos

-rw-r--r-- 1 td-agent td-agent 2440 Sep 29 17:10 td-agent.log

root@bcd6575ce0f6:/# ps auxf

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND

root         1  0.0  0.0  18248  3172 ?        Ss   17:10   0:00 bash

td-agent    44  0.0  0.1 118700 22728 ?        Sl   17:10   0:00 /opt/td-agent/embedded/bin/ruby /usr/sbin/td-agent --log /var/log/td-agent/td-agent.log --daemon /var/run/td-agent/td-agent.pid

td-agent    47  0.3  0.1 141724 30576 ?        Sl   17:10   0:00  \_ /opt/td-agent/embedded/bin/ruby /usr/sbin/td-agent --log /var/log/td-agent/td-agent.log --daemon /var/run/td-agent/td-agent.pid

root        54  0.0  0.0  34428  2796 ?        R+   17:11   0:00 ps auxf

2016年9月29日木曜日 23時37分18秒 UTC+9 ftes...@keyneticdigital.com: