Restarting container causes fluentd.conf to duplicate config

[Cryptophobia]

From @jschneiderhan on October 26, 2016 18:51

Logs of a deis fluentd container during it's first run:

ubuntu@ip-172-20-12-148:~$ sudo docker logs cf1ae5af2bc1
2016-10-24 18:45:58 +0000 [info]: reading config file path="/opt/fluentd/conf/fluentd.conf"
2016-10-24 18:45:58 +0000 [info]: starting fluentd-0.14.4
2016-10-24 18:45:58 +0000 [info]: spawn command to main: /usr/bin/ruby2.3 -Eascii-8bit:ascii-8bit /usr/local/bin/fluentd -c /opt/fluentd/conf/fluentd.conf --under-supervisor
2016-10-24 18:45:58 +0000 [info]: reading config file path="/opt/fluentd/conf/fluentd.conf"
2016-10-24 18:45:58 +0000 [info]: starting fluentd-0.14.4 without supervision
2016-10-24 18:45:58 +0000 [info]: gem 'fluent-mixin-config-placeholders' version '0.4.0'
2016-10-24 18:45:58 +0000 [info]: gem 'fluent-mixin-plaintextformatter' version '0.2.6'
2016-10-24 18:45:58 +0000 [info]: gem 'fluent-mixin-rewrite-tag-name' version '0.1.0'
2016-10-24 18:45:58 +0000 [info]: gem 'fluent-plugin-deis_output' version '0.1.0'
2016-10-24 18:45:58 +0000 [info]: gem 'fluent-plugin-elasticsearch' version '1.6.0'
2016-10-24 18:45:58 +0000 [info]: gem 'fluent-plugin-kubernetes_metadata_filter' version '0.25.3'
2016-10-24 18:45:58 +0000 [info]: gem 'fluent-plugin-remote_syslog' version '0.3.2'
2016-10-24 18:45:58 +0000 [info]: gem 'fluent-plugin-sumologic-mattk42' version '0.0.4'
2016-10-24 18:45:58 +0000 [info]: gem 'fluentd' version '0.14.4'
2016-10-24 18:45:58 +0000 [info]: gem 'fluentd' version '0.14.0'
2016-10-24 18:45:58 +0000 [info]: adding filter pattern="kubernetes.**" type="kubernetes_metadata"
2016-10-24 18:45:59 +0000 [info]: adding match pattern="**" type="copy"
2016-10-24 18:45:59 +0000 [info]: adding source type="tail"
2016-10-24 18:45:59 +0000 [info]: using configuration file: <ROOT>
  <source>
    @type tail
    path "/var/log/containers/*.log"
    pos_file "/var/log/containers.log.pos"
    tag "kubernetes.*"
    format json
    read_from_head false
  </source>
  <filter kubernetes.**>
    @type kubernetes_metadata
    kubernetes_url "https://172.28.0.1:443"
    bearer_token_file "/var/run/secrets/kubernetes.io/serviceaccount/token"
    verify_ssl false
  </filter>
  <match **>
    @type copy
    <store>
      @type "deis"
    </store>
  </match>
</ROOT>
[... and so on ...]

If I restart the container, the config is duplicated:

ubuntu@ip-172-20-12-148:~$ sudo docker restart cf1ae5af2bc1
cf1ae5af2bc1
ubuntu@ip-172-20-12-148:~$ sudo docker logs cf1ae5af2bc1
[... previous logs ...]
2016-10-26 18:46:46 +0000 [info]: reading config file path="/opt/fluentd/conf/fluentd.conf"
2016-10-26 18:46:46 +0000 [info]: starting fluentd-0.14.4 without supervision
2016-10-26 18:46:46 +0000 [info]: gem 'fluent-mixin-config-placeholders' version '0.4.0'
2016-10-26 18:46:46 +0000 [info]: gem 'fluent-mixin-plaintextformatter' version '0.2.6'
2016-10-26 18:46:46 +0000 [info]: gem 'fluent-mixin-rewrite-tag-name' version '0.1.0'
2016-10-26 18:46:46 +0000 [info]: gem 'fluent-plugin-deis_output' version '0.1.0'
2016-10-26 18:46:46 +0000 [info]: gem 'fluent-plugin-elasticsearch' version '1.6.0'
2016-10-26 18:46:46 +0000 [info]: gem 'fluent-plugin-kubernetes_metadata_filter' version '0.25.3'
2016-10-26 18:46:46 +0000 [info]: gem 'fluent-plugin-remote_syslog' version '0.3.2'
2016-10-26 18:46:46 +0000 [info]: gem 'fluent-plugin-sumologic-mattk42' version '0.0.4'
2016-10-26 18:46:46 +0000 [info]: gem 'fluentd' version '0.14.4'
2016-10-26 18:46:46 +0000 [info]: gem 'fluentd' version '0.14.0'
2016-10-26 18:46:46 +0000 [info]: adding filter pattern="kubernetes.**" type="kubernetes_metadata"
2016-10-26 18:46:47 +0000 [info]: adding match pattern="**" type="copy"
2016-10-26 18:46:47 +0000 [info]: adding filter pattern="kubernetes.**" type="kubernetes_metadata"
2016-10-26 18:46:47 +0000 [info]: adding match pattern="**" type="copy"
2016-10-26 18:46:47 +0000 [info]: adding filter pattern="kubernetes.**" type="kubernetes_metadata"
2016-10-26 18:46:47 +0000 [info]: adding match pattern="**" type="copy"
2016-10-26 18:46:47 +0000 [info]: adding source type="tail"
2016-10-26 18:46:47 +0000 [info]: adding source type="tail"
2016-10-26 18:46:47 +0000 [info]: adding source type="tail"
2016-10-26 18:46:47 +0000 [info]: using configuration file: <ROOT>
  <source>
    @type tail
    path "/var/log/containers/*.log"
    pos_file "/var/log/containers.log.pos"
    tag "kubernetes.*"
    format json
    read_from_head false
  </source>
  <filter kubernetes.**>
    @type kubernetes_metadata
    kubernetes_url "https://172.28.0.1:443"
    bearer_token_file "/var/run/secrets/kubernetes.io/serviceaccount/token"
    verify_ssl false
  </filter>
  <match **>
    @type copy
    <store>
      @type "deis"
    </store>
  </match>
  <source>
    @type tail
    path "/var/log/containers/*.log"
    pos_file "/var/log/containers.log.pos"
    tag "kubernetes.*"
    format json
    read_from_head false
  </source>
  <filter kubernetes.**>
    @type kubernetes_metadata
    kubernetes_url "https://172.28.0.1:443"
    bearer_token_file "/var/run/secrets/kubernetes.io/serviceaccount/token"
    verify_ssl false
  </filter>
  <match **>
    @type copy
    <store>
      @type "deis"
    </store>
  </match>
  <source>
    @type tail
    path "/var/log/containers/*.log"
    pos_file "/var/log/containers.log.pos"
    tag "kubernetes.*"
    format json
    read_from_head false
  </source>
  <filter kubernetes.**>
    @type kubernetes_metadata
    kubernetes_url "https://172.28.0.1:443"
    bearer_token_file "/var/run/secrets/kubernetes.io/serviceaccount/token"
    verify_ssl false
  </filter>
  <match **>
    @type copy
    <store>
      @type "deis"
    </store>
  </match>
</ROOT>
[... and so on ...]

I'm not sure what's up yet. Looking into it now. Apologies in advance if this is already known or intentional behavior.

Copied from original issue: deis/fluentd#68

[Cryptophobia]

From @jschneiderhan on October 26, 2016 19:10

Oh - looks like the boot script is just appending the custom configs to the file without wiping any previous ones. Perhaps it would make sense to wrap all the custom configs between a custom comment string and wipe it at every boot before appending the new configs?

[Cryptophobia]

From @jchauncey on October 26, 2016 19:18

if the pod died that should have been a new config. hwo did the container restart without the pod dying?

[Cryptophobia]

From @jschneiderhan on October 26, 2016 19:28

I was testing out a config change quickly and restarted the container manually. If you're never worried about the container restarting, then this isn't an issue.

[Cryptophobia]

From @jchauncey on October 26, 2016 19:32

ah k that makes sense. Its definitely a valid usecase just something I hadnt considered. We should probably make sure that we are building the config file correctly.

[Cryptophobia]

From @jschneiderhan on October 26, 2016 19:35

Oh good. I was worried I was being a PITA.

I notice that fluentd supports an @include directive. Perhaps we include the custom config and rewrite the file each time? I'm happy to give it a shot if you think it's a decent idea.

[Cryptophobia]

From @jchauncey on October 26, 2016 21:8

well the includes would need to be conditional which means you just move them from 1 spot to another. Might not be too bad but i wonder if it makes it confusing on what needs to happen for a paritcular config file to be included in the main one. Make sense?

[Cryptophobia]

From @jschneiderhan on October 27, 2016 12:17

I guess what I'm suggesting is putting all the dynamic configuration in a different file that we can rebuild each time instead of appending to the fluentd.conf file, then having a single include for the dynamic configuration at the end of fluentd.conf. So basically the fluentd.conf becomes static, and instead of appending to fluentd.conf we append to fluentd.custom.conf. All the logic for what gets written stays the same, things just get appended to the dynamic file, and it's rebuilt each time boot is run, so it should end up in the right state no matter how many times boot is run.

[Cryptophobia]

From @jchauncey on October 27, 2016 14:23

Alright let me think about this for a day. I have some ideas but I have a ton of prs in flight so want to make sure I get those merged before I start on this.

[Cryptophobia]

From @jschneiderhan on October 27, 2016 14:34

@jchauncey Sure thing! Like you mentioned, if a pod dies it would recreate the container, so this is probably a pretty rare edge case, so not that important. Thanks for entertaining the idea. When/if you settle on an implementation direction, let me know. I'd be happy to help out and create a PR.