[aufs] Not picking up /etc/logstash-forwarder.conf within containers

[cookandy]

Hello,

I have a simple docker image (called webapp:latest) which is nothing more than a tomcat app server with a simple web app inside. My Dockerfile is pretty straight forward - it only copies in the webapp and the logstash-forwarder.conf

FROM tomcat:8.0.28-jre8

MAINTAINER andy@cookandy.com
COPY etc/ /etc
COPY webapps/ /usr/local/tomcat/webapps

Within the etc folder, I've got a logstash-forwarder.conf with the following configuration:

{
  "files": [ { "paths": [ "/usr/local/tomcat/logs/*.log" ], "fields": { "type": "webapp"} } ]
}

I've confirmed that when I start the container, I can see the logstash-forwarder.conf within.

When I start the docker-logstash-forwarder image, I can see the configuration pick up the logs from docker. However, I can't see anything with the type of webpp (as defined in my logstash-forwarder.conf):

2015/11/12 19:14:21.767613 {
  "network": {
    "servers": [
      "logstash.service.consul:5043"
    ],
    "ssl certificate": "/mnt/logstash-forwarder/logstash-forwarder.crt",
    "ssl key": "/mnt/logstash-forwarder/logstash-forwarder.key",
    "ssl ca": "/mnt/logstash-forwarder/logstash-forwarder.crt",
    "timeout": 15
  },
  "files": [
    {
      "paths": [
        "/var/lib/docker/containers/e33bad245200a4b970f986aad34b58be3812e36035fd62f58a9d7157c04df705/e33bad245200a4b970f986aad34b58be3812e36035fd62f58a9d7157c04df705-json.log"
      ],
      "fields": {
        "codec": "json",
        "docker/hostname": "e33bad245200",
        "docker/id": "e33bad245200a4b970f986aad34b58be3812e36035fd62f58a9d7157c04df705",
        "docker/image": "webapp",
        "docker/name": "/webapp",
        "type": "docker"
      }
    },
    {
      "paths": [
        "/var/lib/docker/containers/8f189e657162185240f7f2abcd683e39628f65acd50636a1a18987e2265ff55a/8f189e657162185240f7f2abcd683e39628f65acd50636a1a18987e2265ff55a-json.log"
      ],
      "fields": {
        "codec": "json",
        "docker/hostname": "8f189e657162",
        "docker/id": "8f189e657162185240f7f2abcd683e39628f65acd50636a1a18987e2265ff55a",
        "docker/image": "logstash-forwarder",
        "docker/name": "/elegant_aryabhata",
        "type": "docker"
      }
    }
  ]
}

When I stop and start the webapp container and monitor the running docker-logstash-forwarder container, I can see that logstash-forwarder reloads the configuration. However, it only adds back the 2 existing (docker) logs, and never the webapp one:

2015/11/12 19:14:21.769518 Loading registrar data from //.logstash-forwarder
2015/11/12 19:14:21.769662 Waiting for 2 prospectors to initialise
2015/11/12 19:14:21.769737 Launching harvester on new file: /var/lib/docker/containers/e33bad245200a4b970f986aad34b58be3812e36035fd62f58a9d7157c04df705/e33bad245200a4b970f986aad34b58be3812e36035fd62f58a9d7157c04df705-json.log
2015/11/12 19:14:21.769898 harvest: "/var/lib/docker/containers/e33bad245200a4b970f986aad34b58be3812e36035fd62f58a9d7157c04df705/e33bad245200a4b970f986aad34b58be3812e36035fd62f58a9d7157c04df705-json.log" (offset snapshot:0)
2015/11/12 19:14:21.769964 Registrar will re-save state for /var/lib/docker/containers/8f189e657162185240f7f2abcd683e39628f65acd50636a1a18987e2265ff55a/8f189e657162185240f7f2abcd683e39628f65acd50636a1a18987e2265ff55a-json.log
2015/11/12 19:14:21.770036 Resuming harvester on a previously harvested file: /var/lib/docker/containers/8f189e657162185240f7f2abcd683e39628f65acd50636a1a18987e2265ff55a/8f189e657162185240f7f2abcd683e39628f65acd50636a1a18987e2265ff55a-json.log
2015/11/12 19:14:21.770662 harvest: "/var/lib/docker/containers/8f189e657162185240f7f2abcd683e39628f65acd50636a1a18987e2265ff55a/8f189e657162185240f7f2abcd683e39628f65acd50636a1a18987e2265ff55a-json.log" position:31738 (offset snapshot:31738)
2015/11/12 19:14:21.770753 All prospectors initialised with 2 states to persist
2015/11/12 19:14:21.771123 Loading client ssl certificate: /mnt/logstash-forwarder/logstash-forwarder.crt and /mnt/logstash-forwarder/logstash-forwarder.key
2015/11/12 19:14:21.995714 Setting trusted CA from file: /mnt/logstash-forwarder/logstash-forwarder.crt
2015/11/12 19:14:30.011208 Connecting to [172.20.13.177]:5043 (logstash.service.consul)
2015/11/12 19:14:30.126830 Connected to 172.20.13.177
2015/11/12 19:14:32.276032 Registrar: processing 160 events
2015/11/12 19:14:36.269787 Registrar: processing 4 events
2015/11/12 19:14:41.776004 Registrar: processing 1 events

As you can see, it only re-registers the two existing logs (from Docker), and never includes the one with a type of webapp.

Do you have any ideas why this is happening?

Thanks in advance!

[cookandy]

Hello,

I set this up in a new environment and am experiencing the same issue. It looks identical to this closed issue: https://github.com/digital-wonderland/docker-logstash-forwarder/issues/8

However, within my logstash-forwarder container I can see the aufs folder listed under /var/lib/docker

docker exec -it logstash-forwarder bash

[root@184a4324c488 /]# ls /var/lib/docker/
aufs  containers  graph  linkgraph.db  repositories-aufs  tmp  trust  volumes

My driver appears to be using aufs

docker inspect logstash-forwarder | grep Driver

    "Driver": "aufs",
    "ExecDriver": "native-0.2",
    "GraphDriver": {

Similarly to the closed issue, I'd expect to see "Found logstash-forwarder config" somewhere in my logs, but I don't see it. Am I missing something obvious?

[digital-wonderland]

Thanks a lot for the additional info. Your problems probably come from using the aufs driver which you can verify by checking that your logstash-forwarder.conf file is bellow aufs/mnt.

I don't use any OS with the aufs driver normally but was first told that the logstash-forwarder.conf would be bellow aufs/mnt. Later I've been told it would be now bellow aufs/diff - which I confirmed to be the case with Debian 8 & Ubuntu 15.04 - so the code got changed but it doesn't seem to be consistent (see https://github.com/digital-wonderland/docker-logstash-forwarder/issues/1).

So, long story short: we need a way to consistently figure out the directory where the logstash-forwarder.conf files are based on the containers id. I'm happy to update the code once someone reads it up and links it here but I wont do it myself since I have neither the usecase nor the test env and frankly am lacking the time currently.

Besides that: what OS are you using? Perhaps updating to a newer version would help since it currently should work with Debian 8 / Ubuntu 15.04.

[cookandy]

Hi, thanks for the reply. I'm a bit confused when you say the logstash-forwarder.conf file should be below aufs/mnt. Are you referring to /var/lib/docker/aufs/mnt and diff within the docker-logstash-forwarder container? All I see in there are what look like docker image IDs:

91bac885982d483318e92036e26574e0c329d0d52299fe47462c12c5e554eb67/
9b96ad634e0ad7bfedcc43acf5a147d562904bb8a6ff424536b928251259bbc5/
a719479f5894e94befa7b0a678f52b0e65c4cfa055eb14c1d219d2b6d3acf574/
ab1f9b243443b4ccdd427d7b0681274f57967cf4b42d175b063988b33858b442/
adb272bab93c608fc3d4de5d735411d4e23dc3b7cb2667b6ff8fe80eb676c086/

There is no conf file under either of those directories.

I am running on an OS X machine, running docker-machine to connect to what are essentially virtualbox VMs (similar to the old boot2docker).

I have also tried in Ubuntu 14 Trusty. I think I'm just missing something if my conf file isn't where it should be.

[digital-wonderland]

Your docker host must be some Linux since it doesn't work on OS X (your local docker client connects to the server, which is running within your Virtualbox VMs). What OS are you using for the VM that runs your docker host?

Please run find /var/lib/docker -name logstash-forwarder.conf as root within your docker host (the VM) and share the output here.

I dunno about Ubuntu Trusty. All I can say it worked with 15.04 (whatever name that would be).

[cookandy]

Ok, yeah docker-machine uses boot2docker, which is based on some Tine Core Linux. That's where my containers are running.

Here's the output of the search on the boot2docker machine:

[root@4e55a496d69f /]# find /var/lib/docker -name logstash-forwarder.conf
/var/lib/docker/aufs/mnt/4e55a496d69f5879c42d7dd12f9dadaaa036cefe56003a20726c2594361c81c2/tmp/logstash-forwarder.conf
/var/lib/docker/aufs/diff/db0fc19013dc34957dc974f1c9e29c07e0617f0954c0774169775f8be3d0707d/tmp/logstash-forwarder.conf
/var/lib/docker/aufs/diff/4e55a496d69f5879c42d7dd12f9dadaaa036cefe56003a20726c2594361c81c2/tmp/logstash-forwarder.conf
/var/lib/docker/aufs/diff/702e489318af3ec4a3d2bc940c3d9d4aec048d9c2c3aaba102173a735cf8d2ac/etc/logstash-forwarder.conf

...and from my Ubuntu install:

[root@c62e00b673b3 /]# find /var/lib/docker -name logstash-forwarder.conf
/var/lib/docker/aufs/diff/d6b77fdee35f636930a30d2633e0048eb7232fd9fa11df53e3eeae8218e8bb0a/etc/logstash-forwarder.conf
/var/lib/docker/aufs/diff/c62e00b673b3d278485fe16388d3305dbffc9138edbb7a320b7fbaf64535d336/tmp/logstash-forwarder.conf
/var/lib/docker/aufs/mnt/e33bad245200a4b970f986aad34b58be3812e36035fd62f58a9d7157c04df705/etc/logstash-forwarder.conf
/var/lib/docker/aufs/mnt/c62e00b673b3d278485fe16388d3305dbffc9138edbb7a320b7fbaf64535d336/tmp/logstash-forwarder.conf

[digital-wonderland]

Ah well, that's that aufs mess. As you can see it is kinda not consistent (or I am missing the obvious).

Currently docker-logstash-forwarder looks for logstash-forwarder.conf files at /var/lib/docker/aufs/diff/$CONTAINER_ID/etc/logstash-forwarder.conf as you can see here.

So, depending what of the above are image, layer or container ids it should find some (cross check the id of the container where it should pick up a logstash-forwarder.conf but doesn't pick it up with the above listings / what is the container id?).

As said, I'm happy to update the code if someone is able to figure out what the reasoning behind the different directories is but I wont spend any time myself on it since it works with Debian 8 & Ubuntu 15.04 and I frankly don't have any time left at the moment. Last but not least you could use CoreOS as a drop in replacement for boot2docker which just works since it doesn't use that aufs driver.

[digital-wonderland]

FWIW: according to this it works the following way:

Running containers are mounted at locations in the /var/lib/docker/aufs/mnt/<container-id> directory. This is the AUFS union mount point that exposes the container and all underlying image layers as a single unified view.

while image layers are bellow /var/lib/docker/aufs/diff. So actually the change was wrong and should get reverted.

Can you please check those paths with your containers if that makes sense?

@tfnico could you also please check your setup once more since, according to the above docs, one of the lines you posted here should be the logstash-forwarder.conf from the image and the other on (in /tmp) the generated one from the running container. However, both should show up in aufs/mnt as well.

[cookandy]

Hi,

Ok, I've done a little more research.

First I start my docker-logstash-forwarder container:

docker run -d --name logstash-forwarder -v /var/lib/docker:/var/lib/docker -v /var/run/docker.sock:/var/run/docker.sock -v /Users/andy/Desktop/docker-elk/logstash-forwarder:/mnt/logstash-forwarder -e LOGSTASH_HOST=192.168.99.100:5043 -e SERVICE_NAME=logstash-forwarder logstash-forwarder

I then get inside the running container and look for the conf files:

[root@7c4874b7360e /]# find /var/lib/docker -name logstash-forwarder.conf
/var/lib/docker/aufs/mnt/7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4/tmp/logstash-forwarder.conf
/var/lib/docker/aufs/diff/7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4/tmp/logstash-forwarder.conf
/var/lib/docker/aufs/diff/702e489318af3ec4a3d2bc940c3d9d4aec048d9c2c3aaba102173a735cf8d2ac/etc/logstash-forwarder.conf

As you can see, there are 3 of them. I will then start my webapp container and verify my config is in etc:

$ docker run -d --name webapp webapp
3853daa68968ca6dbf2e11c19d1bb961f4adb7efb47c341f7fc8ccf0f04380d4

$ docker exec -it 385 cat /etc/logstash-forwarder.conf
{
  "files": [ { "paths": [ "/usr/local/tomcat/logs/*.log" ], "fields": { "type": "webapp"} } ]
}

And if I look at the log, I'll see the trigger (again, not showing my webapp configuration):

2015/11/16 18:43:56.729010 INFO [RegisterDockerEventListener] Triggering refresh in 5 seconds
2015/11/16 18:43:57.291191 Registrar: processing 1 events
2015/11/16 18:44:01.731283 INFO [generateConfig] Triggering refresh...
2015/11/16 18:44:01.736930 INFO [TriggerRefresh] Wrote logstash-forwarder config to /tmp/logstash-forwarder.conf
2015/11/16 18:44:01.736972 INFO [TriggerRefresh] Waiting for logstash-forwarder to stop
2015/11/16 18:44:01.737636 INFO [TriggerRefresh] Stopped logstash-forwarder
2015/11/16 18:44:01.738809 INFO [TriggerRefresh] Starting logstash-forwarder...
2015/11/16 18:44:01.741491  --- options -------
2015/11/16 18:44:01.743249  config-arg:          /tmp/logstash-forwarder.conf
2015/11/16 18:44:01.743306  idle-timeout:        5s
2015/11/16 18:44:01.743395  spool-size:          1024
2015/11/16 18:44:01.744070  harvester-buff-size: 16384
2015/11/16 18:44:01.744653  --- flags ---------
2015/11/16 18:44:01.744945  tail (on-rotation):  false
2015/11/16 18:44:01.744954  log-to-syslog:          false
2015/11/16 18:44:01.744957  quiet:             false
2015/11/16 18:44:01.747561 {
  "network": {
    "servers": [
      "192.168.99.100:5043"
    ],
    "ssl certificate": "/mnt/logstash-forwarder/logstash-forwarder.crt",
    "ssl key": "/mnt/logstash-forwarder/logstash-forwarder.key",
    "ssl ca": "/mnt/logstash-forwarder/logstash-forwarder.crt",
    "timeout": 15
  },
  "files": [
    {
      "paths": [
        "/var/lib/docker/containers/b54c1d71e1a5df2fe960ca33e3063fd121388d20adf678f9b277048acc5d261a/b54c1d71e1a5df2fe960ca33e3063fd121388d20adf678f9b277048acc5d261a-json.log"
      ],
      "fields": {
        "codec": "json",
        "docker/hostname": "b54c1d71e1a5",
        "docker/id": "b54c1d71e1a5df2fe960ca33e3063fd121388d20adf678f9b277048acc5d261a",
        "docker/image": "webapp",
        "docker/name": "/fervent_bose",
        "type": "docker"
      }
    },
    {
      "paths": [
        "/var/lib/docker/containers/7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4/7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4-json.log"
      ],
      "fields": {
        "codec": "json",
        "docker/hostname": "7c4874b7360e",
        "docker/id": "7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4",
        "docker/image": "logstash-forwarder",
        "docker/name": "/logstash-forwarder",
        "type": "docker"
      }
    }
  ]
}
2015/11/16 18:44:01.748454 Loading registrar data from //.logstash-forwarder
2015/11/16 18:44:01.748513 Waiting for 2 prospectors to initialise
2015/11/16 18:44:01.748564 Launching harvester on new file: /var/lib/docker/containers/b54c1d71e1a5df2fe960ca33e3063fd121388d20adf678f9b277048acc5d261a/b54c1d71e1a5df2fe960ca33e3063fd121388d20adf678f9b277048acc5d261a-json.log
2015/11/16 18:44:01.748612 harvest: "/var/lib/docker/containers/b54c1d71e1a5df2fe960ca33e3063fd121388d20adf678f9b277048acc5d261a/b54c1d71e1a5df2fe960ca33e3063fd121388d20adf678f9b277048acc5d261a-json.log" (offset snapshot:0)
2015/11/16 18:44:01.748812 Registrar will re-save state for /var/lib/docker/containers/7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4/7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4-json.log
2015/11/16 18:44:01.749130 Resuming harvester on a previously harvested file: /var/lib/docker/containers/7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4/7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4-json.log
2015/11/16 18:44:01.770772 harvest: "/var/lib/docker/containers/7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4/7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4-json.log" position:8198 (offset snapshot:8198)
2015/11/16 18:44:01.770839 All prospectors initialised with 1 states to persist
2015/11/16 18:44:01.770884 Loading client ssl certificate: /mnt/logstash-forwarder/logstash-forwarder.crt and /mnt/logstash-forwarder/logstash-forwarder.key
2015/11/16 18:44:02.051068 Setting trusted CA from file: /mnt/logstash-forwarder/logstash-forwarder.crt
2015/11/16 18:44:02.058835 Connecting to [192.168.99.100]:5043 (192.168.99.100) 
2015/11/16 18:44:02.147356 Connected to 192.168.99.100
2015/11/16 18:44:06.965788 Registrar: processing 107 events

If I go back to the logstash-forwarder container, I can see that I still only have 3 conf files:

[root@7c4874b7360e /]# find /var/lib/docker -name logstash-forwarder.conf
/var/lib/docker/aufs/mnt/7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4/tmp/logstash-forwarder.conf
/var/lib/docker/aufs/diff/7c4874b7360e501f3ae1f95fd022d57b00a318ef29d89c7923e1672d7a1be7a4/tmp/logstash-forwarder.conf
/var/lib/docker/aufs/diff/702e489318af3ec4a3d2bc940c3d9d4aec048d9c2c3aaba102173a735cf8d2ac/etc/logstash-forwarder.conf

I've looked at all 3, but none of them contain my config. I'll keep digging.

[digital-wonderland]

Ok, of those 3 find lines you posted, the first should be the docker-logstash-forwarder container via its union mount point. The second is the writeable layer of the docker-logstash-forwarder container and the third should be some image which contains a logstash-forwarder.conf (IIRC there is none in the docker-logstash-forwarder image).

Can you confirm that 702e489318af3ec4a3d2bc940c3d9d4aec048d9c2c3aaba102173a735cf8d2ac is the image id (or some layer) of your webapp image? Also please run the find command twice. The second time while your webapp container is running. This should result in a logstash-forwarder.conf being shown bellow its union mount point (at /var/lib/docker/aufs/mnt/<container-id>). Can you confirm?

Also I'm kinda confused since the id of your webapp container is first 3853daa68968ca6dbf2e11c19d1bb961f4adb7efb47c341f7fc8ccf0f04380d4 and then later it seems to be b54c1d71e1a5df2fe960ca33e3063fd121388d20adf678f9b277048acc5d261a.

[cookandy]

Hi,

Yes, you are right - the third one is the logstash-forwarder.conf from my webapp image. And yes, I can confirm that 702e489318af3ec4a3d2bc940c3d9d4aec048d9c2c3aaba102173a735cf8d2ac is a layer of my webapp image.

I can confirm that running the find command twice results in the same output. Both before and after the webapp container is running there are 3 results. Below are the contents of each file.

Both the fist and second file have this:

{
  "network": {
    "servers": [
      "192.168.99.100:5043"
    ],
    "ssl certificate": "/mnt/logstash-forwarder/logstash-forwarder.crt",
    "ssl key": "/mnt/logstash-forwarder/logstash-forwarder.key",
    "ssl ca": "/mnt/logstash-forwarder/logstash-forwarder.crt",
    "timeout": 15
  },
  "files": [
    {
      "paths": [
        "/var/lib/docker/containers/2e5cb46cadd9e0aebb761ffcb9c4e5789d100caa7cfa7c4f44eacfe68c473b14/2e5cb46cadd9e0aebb761ffcb9c4e5789d100caa7cfa7c4f44eacfe68c473b14-json.log"
      ],
      "fields": {
        "codec": "json",
        "docker/hostname": "2e5cb46cadd9",
        "docker/id": "2e5cb46cadd9e0aebb761ffcb9c4e5789d100caa7cfa7c4f44eacfe68c473b14",
        "docker/image": "logstash-forwarder",
        "docker/name": "/romantic_kilby",
        "type": "docker"
      }
    }
  ]
}

And the last one has this:

{
  "files": [ { "paths": [ "/usr/local/tomcat/logs/*.log" ], "fields": { "type": "webapp"} } ]
}

The above is the config I need, which isn't getting picked up in the logs. I see the above in the third conf file, before I even start the webapp container.

As I mentioned, after starting the webapp container, I still see the same 3 conf files, and they contain the same information in them, with the exception of the first two, which now have the webapp docker running config

{
  "network": {
    "servers": [
      "192.168.99.100:5043"
    ],
    "ssl certificate": "/mnt/logstash-forwarder/logstash-forwarder.crt",
    "ssl key": "/mnt/logstash-forwarder/logstash-forwarder.key",
    "ssl ca": "/mnt/logstash-forwarder/logstash-forwarder.crt",
    "timeout": 15
  },
  "files": [
    {
      "paths": [
        "/var/lib/docker/containers/c07b25637839737a35b57527a784b5d5645f4517af38d16c8779be3e2ed776a3/c07b25637839737a35b57527a784b5d5645f4517af38d16c8779be3e2ed776a3-json.log"
      ],
      "fields": {
        "codec": "json",
        "docker/hostname": "c07b25637839",
        "docker/id": "c07b25637839737a35b57527a784b5d5645f4517af38d16c8779be3e2ed776a3",
        "docker/image": "webapp",
        "docker/name": "/ecstatic_engelbart",
        "type": "docker"
      }
    },
    {
      "paths": [
        "/var/lib/docker/containers/2e5cb46cadd9e0aebb761ffcb9c4e5789d100caa7cfa7c4f44eacfe68c473b14/2e5cb46cadd9e0aebb761ffcb9c4e5789d100caa7cfa7c4f44eacfe68c473b14-json.log"
      ],
      "fields": {
        "codec": "json",
        "docker/hostname": "2e5cb46cadd9",
        "docker/id": "2e5cb46cadd9e0aebb761ffcb9c4e5789d100caa7cfa7c4f44eacfe68c473b14",
        "docker/image": "logstash-forwarder",
        "docker/name": "/romantic_kilby",
        "type": "docker"
      }
    }
  ]
}

However - if I start the docker-logstash-forwarder container AFTER I start the webapp container, I notice there are four conf files

[root@5ba69b8e6fd3 /]# find /var/lib/docker -name logstash-forwarder.conf
/var/lib/docker/aufs/mnt/5ba69b8e6fd3528c5ed706bd2b176a73263e76771a095ddce12394924e4d77e8/tmp/logstash-forwarder.conf
/var/lib/docker/aufs/mnt/c07b25637839737a35b57527a784b5d5645f4517af38d16c8779be3e2ed776a3/etc/logstash-forwarder.conf
/var/lib/docker/aufs/diff/5ba69b8e6fd3528c5ed706bd2b176a73263e76771a095ddce12394924e4d77e8/tmp/logstash-forwarder.conf
/var/lib/docker/aufs/diff/702e489318af3ec4a3d2bc940c3d9d4aec048d9c2c3aaba102173a735cf8d2ac/etc/logstash-forwarder.conf

This time, the first and third contain the information about the docker containers, while the second and fourth contain my webapp information:

{
  "files": [ { "paths": [ "/usr/local/tomcat/logs/*.log" ], "fields": { "type": "webapp"} } ]
}

However, when looking at the startup logs I still don't see my config:

2015/11/16 19:56:43 Starting up
2015/11/16 19:56:43.148822 INFO [main] Connected to docker at unix:///var/run/docker.sock (v1.8.3)
2015/11/16 19:56:43.148859 INFO [generateConfig] Triggering refresh...
2015/11/16 19:56:43.151593 INFO [TriggerRefresh] Wrote logstash-forwarder config to /tmp/logstash-forwarder.conf
2015/11/16 19:56:43.151936 INFO [TriggerRefresh] Starting logstash-forwarder...
2015/11/16 19:56:43.152171 INFO [RegisterDockerEventListener] Listening to docker events...
2015/11/16 19:56:43.153715  --- options -------
2015/11/16 19:56:43.153784  config-arg:          /tmp/logstash-forwarder.conf
2015/11/16 19:56:43.153804  idle-timeout:        5s
2015/11/16 19:56:43.153829  spool-size:          1024
2015/11/16 19:56:43.153843  harvester-buff-size: 16384
2015/11/16 19:56:43.153857  --- flags ---------
2015/11/16 19:56:43.153870  tail (on-rotation):  false
2015/11/16 19:56:43.153883  log-to-syslog:          false
2015/11/16 19:56:43.153896  quiet:             false
2015/11/16 19:56:43.153945 {
  "network": {
    "servers": [
      "192.168.99.100:5043"
    ],
    "ssl certificate": "/mnt/logstash-forwarder/logstash-forwarder.crt",
    "ssl key": "/mnt/logstash-forwarder/logstash-forwarder.key",
    "ssl ca": "/mnt/logstash-forwarder/logstash-forwarder.crt",
    "timeout": 15
  },
  "files": [
    {
      "paths": [
        "/var/lib/docker/containers/5ba69b8e6fd3528c5ed706bd2b176a73263e76771a095ddce12394924e4d77e8/5ba69b8e6fd3528c5ed706bd2b176a73263e76771a095ddce12394924e4d77e8-json.log"
      ],
      "fields": {
        "codec": "json",
        "docker/hostname": "5ba69b8e6fd3",
        "docker/id": "5ba69b8e6fd3528c5ed706bd2b176a73263e76771a095ddce12394924e4d77e8",
        "docker/image": "logstash-forwarder",
        "docker/name": "/trusting_brattain",
        "type": "docker"
      }
    },
    {
      "paths": [
        "/var/lib/docker/containers/c07b25637839737a35b57527a784b5d5645f4517af38d16c8779be3e2ed776a3/c07b25637839737a35b57527a784b5d5645f4517af38d16c8779be3e2ed776a3-json.log"
      ],
      "fields": {
        "codec": "json",
        "docker/hostname": "c07b25637839",
        "docker/id": "c07b25637839737a35b57527a784b5d5645f4517af38d16c8779be3e2ed776a3",
        "docker/image": "webapp",
        "docker/name": "/ecstatic_engelbart",
        "type": "docker"
      }
    }
  ]
}
2015/11/16 19:56:43.154636 Waiting for 2 prospectors to initialise
2015/11/16 19:56:43.154694 Launching harvester on new file: /var/lib/docker/containers/5ba69b8e6fd3528c5ed706bd2b176a73263e76771a095ddce12394924e4d77e8/5ba69b8e6fd3528c5ed706bd2b176a73263e76771a095ddce12394924e4d77e8-json.log
2015/11/16 19:56:43.154743 Launching harvester on new file: /var/lib/docker/containers/c07b25637839737a35b57527a784b5d5645f4517af38d16c8779be3e2ed776a3/c07b25637839737a35b57527a784b5d5645f4517af38d16c8779be3e2ed776a3-json.log
2015/11/16 19:56:43.154788 harvest: "/var/lib/docker/containers/5ba69b8e6fd3528c5ed706bd2b176a73263e76771a095ddce12394924e4d77e8/5ba69b8e6fd3528c5ed706bd2b176a73263e76771a095ddce12394924e4d77e8-json.log" (offset snapshot:0)
2015/11/16 19:56:43.154835 All prospectors initialised with 0 states to persist
2015/11/16 19:56:43.154909 harvest: "/var/lib/docker/containers/c07b25637839737a35b57527a784b5d5645f4517af38d16c8779be3e2ed776a3/c07b25637839737a35b57527a784b5d5645f4517af38d16c8779be3e2ed776a3-json.log" (offset snapshot:0)
2015/11/16 19:56:43.155232 Loading client ssl certificate: /mnt/logstash-forwarder/logstash-forwarder.crt and /mnt/logstash-forwarder/logstash-forwarder.key
2015/11/16 19:56:43.282686 Setting trusted CA from file: /mnt/logstash-forwarder/logstash-forwarder.crt
2015/11/16 19:56:43.283763 Connecting to [192.168.99.100]:5043 (192.168.99.100) 
2015/11/16 19:56:43.349256 Connected to 192.168.99.100
2015/11/16 19:56:48.381293 Registrar: processing 233 events
2015/11/16 19:56:55.660264 Registrar: processing 1 events

[digital-wonderland]

Ok, it seems there are two different issues:

1. if a new mount is created bellow /var/lib/docker/aufs/mnt (which is what seems to happen when aufs creates a new union mount point) it doesn't show up in the volume shared with the docker-logstash-forwarder container. @nuth this also explains your problems.
2. docker-logstash-forwarder doesn't pick up your logstash-forwarder.conf file.

Regarding 1.: I'm not sure if we can do anything. Perhaps creating an issue with the docker folks might help? Also try to mount some other disk bellow the shared /var/lib/docker directory and see if that shows up (so we see if it is a general mount problem or specific to aufs).

Regarding 2.: Please change your logstash-forwarder.conf file so it contains also a network section as seen here (the network section will get ignored). If this helps marking that section as optional might help and it is something we can fix here. Also run the docker-logstash-forwarder container with the -debug flag (simply append that at the end of your docker run line) - this makes it more verbose regarding where it searches and what it finds.

[nuth]

Actually, regarding issue #2, I found that the driver for aufs creates two directories on the host /var/lib/docker/aufs/mnt and /var/lib/docker/aufs/diff. Your current version only attempts to find it in /var/lib/docker/aufs/diff, which I believe only contains files that are created while running the application, not if you add it as a static part of your container (ie. in the image). This explains why your elasticsearch logstash-forwarder.conf file is picked up, as it's created from the initialization script.

I've made a fork https://github.com/nuth/docker-logstash-forwarder (will do cleanup, but first attempt at go here as well) and planning to do a pull request, but I wanted to find a solution to issue #1 first, but I simply haven't had time to work more with docker. Relevant change is https://github.com/nuth/docker-logstash-forwarder/commit/15f2b83802452e3926e12370783486ef532aed0e#diff-41a4036e8cb0fca47770e0cc7e264a16R146 (calculateFilePath can return two different directories to try).

I've also made a docker-compose yml for the elk stack with my modifications which you can see here (poor documentation) https://github.com/nuth/docker-elk . Just remember that for aufs, you'll have to start up the elk stack last, which like @digital-wonderland says kinda defeats the whole purpose.

I think as of right now, I'd maybe try to use overlayfs or something as a storage engine, rather than aufs.

[cookandy]

Regarding 1: I started the docker-logstash-forwarder container and then went into the docker-machine and created a mount:

$ docker-machine ssh n2
                        ##         .
                  ## ## ##        ==
               ## ## ## ## ##    ===
           /"""""""""""""""""\___/ ===
      ~~~ {~~ ~~~~ ~~~ ~~~~ ~~~ ~ /  ===- ~~~
           \______ o           __/
             \    \         __/
              \____\_______/
 _                 _   ____     _            _
| |__   ___   ___ | |_|___ \ __| | ___   ___| | _____ _ __
| '_ \ / _ \ / _ \| __| __) / _` |/ _ \ / __| |/ / _ \ '__|
| |_) | (_) | (_) | |_ / __/ (_| | (_) | (__|   <  __/ |
|_.__/ \___/ \___/ \__|_____\__,_|\___/ \___|_|\_\___|_|
Boot2Docker version 1.8.3, build master : af8b089 - Mon Oct 12 18:56:54 UTC 2015
Docker version 1.8.3, build f4bf5c7
docker@n2:~$ sudo mkdir /var/lib/docker/test
docker@n2:~$ ls /var/lib/docker/test/
docker@n2:~$ sudo mount /dev/sda1 /var/lib/docker/test
docker@n2:~$ ls /var/lib/docker/test/
lost+found/ tmp/        var/

You can see that I have the lost+found, tmp, and var directories. I then went back into the running docker-logstash-forwarder and could see the /var/lib/docker/test directory. However, I was unable to view the contents

[root@5ba69b8e6fd3 docker]# ll /var/lib/docker/
total 48
drwxr-xr-x  5 root root  4096 Nov 15 16:23 aufs
drwx------  4 root root  4096 Nov 16 19:56 containers
drwx------ 35 root root 12288 Nov 15 16:36 graph
-rw-r--r--  1 root root  7168 Nov 16 19:56 linkgraph.db
-rw-------  1 root root   291 Nov 15 16:36 repositories-aufs
drwxr-xr-x  2 root root  4096 Nov 16 20:44 test
drwx------  2 root root  4096 Nov 16 19:36 tmp
drwx------  2 root root  4096 Nov 15 16:23 trust
drwx------  3 root root  4096 Nov 15 16:31 volumes
[root@5ba69b8e6fd3 docker]# ls /var/lib/docker/test/

So maybe something has changed? I am using Docker version 1.8.3, build f4bf5c7.

Regarding 2: I updated my config to contain the following (the network stuff is invalid, but shouldn't matter), and I rebuilt my image:

{
  "network": {
    "servers": [ "logstash:5043" ],
    "ssl certificate": "./lumberjack.crt",
    "ssl key": "./lumberjack.key",
    "ssl ca": "./lumberjack_ca.crt"
  },
  "files": [
    {
      "paths": [ 
        "/usr/local/tomcat/logs/*.log"
      ],
      "fields": {
        "type": "webapp"
      }
    }
  ]
}

I had the exact same behavior as before - both starting the docker-logstash-forwarder container before or after the webapp container. So it appears that having the network stuff in there didn't make any difference.

[digital-wonderland]

@nuth Thanks a lot for the quick response :)

The way aufs seems to be working is that all the different layers of your image, including the currently writeable one of your running container are bellow aufs/diff. The sum of all those layers (as in how the disk as a whole looks) is made available bellow aufs/mnt. See here for details.

If you create the logstash-forwarder.conf during startup then it will be bellow aufs/diff/$CONTAINER_ID (the writeable layer of your container). So a workaround for aufs might be to put the logstash-forwarder.conf at /where/ever/logstash-forwarder.conf and then copy it to /etc/logstash-forwarder.conf during startup of your container.

This seems to be a shortcoming of aufs where I don't see how we can do anything besides the above workaround and creating an issue with the docker folks.

[digital-wonderland]

@cookandy Ok, so it kinda confirms that new mounts bellow some volume, shared with a container, don't show up for the container (not aufs specific but a general issue with mounting things).

Can you please create an issue with the docker folks and link this one?

Regarding 2.: can you please rerun docker-logstash-forwarder with the -debug flag? As said above, just append it to your docker run line since that should give some insight where it looks for configs and what it finds.

[digital-wonderland]

@cookandy I'm sorry, I was missing the obvious. Your logstash-forwarder.conf will not be found since it will be buried bellow aufs/diff/$NOT_YOUR_CONTAINER_ID.

Please put the logstash-forwarder.conf (which contains also the network section) at /some/where/logstash-forwarder.conf and copy it to /etc/logstash-forwarder.conf in some script that is run during startup. Then it should work since it will now be bellow aufs/diff/$CONTAINER_ID (the writeable layer of the running container).

[cookandy]

@digital-wonderland Doing what you suggested with the copy script seems to work. The docker-logstash-forwarder picks up the running container and the logstash-forwarder.conf file as expected!

This is great, however - I don't think building all of our images with a custom run script will always be possible. Are you suggesting this is a limitation of Docker? Thanks again for all of your help!

[nuth]

@cookandy My modification will work without the copy script: https://hub.docker.com/r/nuthman/logstash-forwarder/

[cookandy]

Hi @nuth. I pulled your image from the Docker rep, but I experienced the same issue as @digital-wonderland's build. When the configuration refreshes, it's only got the docker configurations.

I tested in both of my environments. I noticed the Docker image is about a month old, and your branch is only a day old. Could I have an old image?

Update: @nuth I cloned your repo and built the Docker image that way and I still had the same problem. Any ideas?

[digital-wonderland]

@cookandy glad you got it working. It isn't really a limitation but there are a few problems which sum up:

1. the docker folks refuse to make the path of a containers file system available via their API since they consider it internal so it must be found out by trying to take an educated guess based on the driver being used (docker/docker#7198).
2. also, as we found out, new mounts aren't available in a volume shared with a running container (only seems to be relevant if one uses the aufs driver). For this it might make sense to create an issue @ docker. Perhaps they are able to fix this (then simply aufs/mnt/$CONTAINER_ID needs to be checked and all is fine).

The workaround is to create the logstash-forwarder.conf file during container startup so it is bellow aufs/diff/$CONTAINER_ID (the writeable layer of your currently running container). This should be always possible but I can understand if one doesn't want to have to do this all the time.

Personally I would simply use something else than aufs. Just for local development you could use CoreOS with Vagrant, instead boot2docker, which would also give you other goodies like Kubernetes and rkt.

@nuth I don't see how your changes would work since you just check aufs/diff/$CONTAINER_ID and aufs/mnt/$CONTAINER_ID with the later not showing up due to 2. above. Please correct me if I'm misunderstanding your intentions, I just had a short look.

To get it currently working one would have to check not only aufs/diff/$CONTAINER_ID but also every other layer or the image the container is using bellow aufs/diff/$LAYER_ID. It seems like one could use Client.ImageHistory and then retrieve the layer ids from the different ImageHistory structs. Those layers then need to be checked in chronological order (newest to oldest) and the first found logstash-forwarder.conf should be used.

I wouldn't be against merging something that does this but I don't see myself working on it in the near future. Also, IMHO, this would be a workaround so I would first create an issue with the docker folks so new mounts show up in shared volumes since it then would be enough to just check aufs/mnt/$CONTAINER_ID.

[cookandy]

@digital-wonderland: thanks for the reply. In my real (production) environment, I will actually be using CentOS 7.1 which I believe uses devicemapper. I can try to switch to overlayFS or something too...

[cookandy]

@digital-wonderland

Before I left today, I had a chance to test with CentOS 7.1, which uses devicemapper.

I experienced the same issue.

[root@PaaS-S4 ~]# docker info
Containers: 1
Images: 38
Server Version: 1.9.0
Storage Driver: devicemapper
 Pool Name: docker-253:0-134833621-pool
 Pool Blocksize: 65.54 kB
 Base Device Size: 107.4 GB
 Backing Filesystem: xfs
 Data file: /dev/loop0
 Metadata file: /dev/loop1
 Data Space Used: 2.506 GB
 Data Space Total: 107.4 GB
 Data Space Available: 37.76 GB
 Metadata Space Used: 3.064 MB
 Metadata Space Total: 2.147 GB
 Metadata Space Available: 2.144 GB
 Udev Sync Supported: true
 Deferred Removal Enabled: false
 Deferred Deletion Enabled: false
 Deferred Deleted Device Count: 0
 Data loop file: /var/lib/docker/devicemapper/devicemapper/data
 Metadata loop file: /var/lib/docker/devicemapper/devicemapper/metadata
 Library Version: 1.02.93-RHEL7 (2015-01-28)
Execution Driver: native-0.2
Logging Driver: json-file
Kernel Version: 3.10.0-229.20.1.el7.x86_64
Operating System: CentOS Linux 7 (Core)
CPUs: 4
Total Memory: 7.64 GiB

[cookandy]

Just another update... I switched to overlayFS, backed by ext4, but I'm still having the same issue.

[root@PaaS-S4 ~]# docker info
Containers: 1
Images: 38
Server Version: 1.9.0
Storage Driver: overlay
 Backing Filesystem: extfs
Execution Driver: native-0.2
Logging Driver: json-file
Kernel Version: 4.3.0-1.el7.elrepo.x86_64
Operating System: CentOS Linux 7 (Core)
CPUs: 4
Total Memory: 7.797 GiB
Name: PaaS-S4.cs.myharris.net
ID: QHMQ:3S3H:VUM4:NG32:667U:FXB6:LCCU:RRP5:WWJI:YTLB:NJGK:HG7H
WARNING: bridge-nf-call-iptables is disabled
WARNING: bridge-nf-call-ip6tables is disabled

I'm not sure how you guys are getting this working.

[cookandy]

One more update.

The copy trick doesn't seem to work with devicemapper or overlay. It only works with aufs.

I haven't tried btrfs.

[digital-wonderland]

I'm sorry you are still running into issues. I don't run anything currently which uses devicemapper but seeing the mnt part in the path, it might be cause of the same reason.

Could you please provide the paths where the layers are when using devicemapper? If those are organized in a similar manner as with aufs both most likely can be fixed in the same way.

Regarding things not working with overlayfs I'm unable to reproduce this since it works with the Vagrant project included in this repository (CoreOS which uses overlayfs).

How to verify this:

1. clone this repository & cd into it
2. start the VM via Vagrant: vagrant up and wait until all the containers are downloaded and started - once Kibana is available at http://localhost:5601 everything should be running.
3. ssh into the VM: vagrant ssh
4. hop into the logstash container: docker exec -ti logstash /bin/bash. There is a logstash-forwarder.conf which forwards /var/log/logstash/logstash.log which is currently not used
5. append something to /var/log/logstash/logstash.log: echo "It works" >> /var/log/logstash/logstash.log
6. verify it shows up in Kibana - look for the type logstash

I just did the above and it shows up as expected. Also CoreOS (which I used for development of docker-logstash-forwarder) used btrfs before switching to overlayfs so it should work (but I haven't tried it since they switched).

[cookandy]

Hi @digital-wonderland - thanks for the reply.

I used your vagrant machine without any problems - thank you. I was able to see the It works messages in Kibana.

However, I connected to the vagrant machine: vagrant ssh, and created a simple Dockerfile:

FROM tomcat:latest

COPY etc/ /etc

I created a simple config file under etc

mkdir etc
vi etc/logstash-forwarder.conf

{
  "network": {
    "servers": [ "logstash:5043" ],
    "ssl certificate": "./lumberjack.crt",
    "ssl key": "./lumberjack.key",
    "ssl ca": "./lumberjack_ca.crt"
  },
  "files": [
    {
      "paths": [ 
        "/usr/local/tomcat/logs/*.log"
      ],
      "fields": {
        "type": "webapp"
      }
    }
  ]
}

I then built the Docker image: docker build -t webapp .

And started the container: docker run -it --rm webapp

However, I never see any logs in Kibana with a type of webapp. Does this work for you?

[digital-wonderland]

Sorry for the late response. I'm able to reproduce it, as you said but I honestly have no idea why that would happen - as in why it doesn't work with that container while it works with the others.