Multiple container name preprended to logs

[amenophis]

Hi, All my logs are preprended by the container name 7 times ... If i run the command executed in the docker-entrypoint.sh:

curl -s --no-buffer -XGET --unix-socket /var/run/docker.sock "http:/containers/ct1/logs?stderr=1&stdout=1&tail=1&follow=1" | sed "s;^;[ct1] ;"

on ubuntu with zsh, i get the following output:

[ct1] My log line

and on the ash inside the container, i get the following output:

[ct1] [ct1] [ct1] [ct1] [ct1] [ct1] [ct1] My log line

Did you see this before ?

Thanks ?

[c6decacb79e8ca046dcb61002aac5280]

+1 I see exactly the same issue, @amenophis did you get over this?

[taigrrr8]

I'm also seeing the same thing. Not only the container name of the containers being logged but both the container names being logged and the filebeat container name.

[container_name][container_name][container_name].....log text........[filebeat_container_name][filebeat_container_name][filebeat_container_name].....

[vingrad]

+1

[pcornelissen]

Same thing...

[setup_admin_1]
[setup_admin_1] [setup_admin_1] [setup_admin_1] [setup_admin_1] [setup_admin_1] �2016-09-09 10:58:37.807 DEBUG 7 --- [nio-8090-exec-4] d.o.k.a.proxy.ForwardSessionPreFilter :...

it's even worse, the number isn't always the same:

[setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] �2016-09-09 14:27:44.241 WARN 7 --- [ main] c.n.c.sources.URLConfigurationSource : No URLs will be polled as dynamic configuration sources.
[setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] �2016-09-09 14:27:34.823 INFO 7 --- [ost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
[setup_filebeat_1] [setup_filebeat_1] [setup_filebeat_1] [setup_filebeat_1] [setup_filebeat_1] [setup_filebeat_1] [setup_filebeat_1] ?2016/09/09 15:01:26.555724 publish.go:104: INFO Events sent: 9
[setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] �2016-09-09 16:00:32.859  INFO 7 --- [           main] d.o.k.eureka.EurekaApplication           : Started EurekaApplication in 1.02 seconds (JVM running for 41.514)
[setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] + :: Spring Boot ::        (v1.4.0.RELEASE)
[setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] [setup_eureka_1] �2016-09-09 15:59:57.847  INFO 7 --- [           main] d.o.k.eureka.EurekaApplication           : The following profiles are active: docker,dev

A nightmare to write grok filters for this

[gimler]

+1

[gimler]

A quick hack would be change the grok filter to

    grok {
      match => {
        "message" => "(\[%{WORD:containerName}\]\s?)+ %{GREEDYDATA:message_remainder}"
      }
    }

[gdubya]

+1

[gdubya]

This seems to be related to the way the script tries to prepend the container name to the response from the Docker Remote API logs command. According to the Docker documentation, the response contains an 8-byte header. Cutting the first 8 bytes from each line seems to fix the issue. See my fork for details.

[zietek]

Hey,

I resolved that issue by editing docker-enterpoint.sh script. You can find that in my forked repo https://github.com/zietek/docker-filebeat

[willfarrell]

@gdubya is correct, it's due to the 8-byte header, the null unicode chars mess up sed - I solved it a little differently due to the the cut cli changed in alpine 3.5 - https://github.com/willfarrell/docker-filebeat/tree/master/5-stdin