Logstash tcp/udp inputs stop working after container restart about elk-docker HOT 9 CLOSED

Hi (and thanks for the kind words!),

I haven't been able to reproduce your issue, but here are some suggestions to try and figure out what's going on.

First, this is what I did to try and reproduce the issue:

• I took your configuration file and Dockerfile, and built an image, to make sure I have the same image as you.

• I started a container using docker run -P 2b095abc596b (didn't bother giving the image a name, so used the raw id instead)

• I made sure everything was running and got the dynamically assigned ports with docker ps:

  dd7afb389180        2b095abc596b        "/usr/local/bin/star   10 minutes ago      Up 2 minutes        0.0.0.0:32783->5000/tcp, 0.0.0.0:32782->5601/tcp, 0.0.0.0:32781->9200/tcp, 0.0.0.0:32780->9300/tcp, 0.0.0.0:32771->25000/udp   silly_davinci
  

• Quick sanity check to make sure that UDP port 32771 is listening:

  $ netstat -au
  Active Internet connections (servers and established)
  Proto Recv-Q Send-Q Local Address           Foreign Address         State
  udp6       0      0 [::]:32771              [::]:*
  

• On another machine, I created a steady flow of logs using netcat:

  $ while true; do echo -n {\"foo\": \"$RANDOM\"} | nc -u -q 0 logs.xxxxxxxxxx.com 32771; done
  

• I checked Kibana and made sure that everything was behaving nicely.

• On the machine running Docker, I also made sure that incoming UDP requests were flowing in:

  $ sudo conntrack -L
  ...
  udp      17 15 src=xxx.xxx.xxx.xxx dst=yyy.yyy.yyy.yyy sport=60532 dport=32771 [UNREPLIED] src=172.17.0.11 dst=XXX.XXX.XXX.XXX sport=25000 dport=60532 mark=0 use=1
  udp      17 9 src=xxx.xxx.xxx.xxx dst=yyy.yyy.yyy.yyy sport=57062 dport=32771 [UNREPLIED] src=172.17.0.11 dst=XXX.XXX.XXX.XXX sport=25000 dport=57062 mark=0 use=1
  udp      17 8 src=xxx.xxx.xxx.xxx dst=yyy.yyy.yyy.yyy sport=36638 dport=32771 [UNREPLIED] src=172.17.0.11 dst=XXX.XXX.XXX.XXX sport=25000 dport=36638 mark=0 use=1
  conntrack v1.4.1 (conntrack-tools): 388 flow entries have been shown.
  

• I then stopped the container (docker stop silly_davinci) and checked that it was indeed stopped (docker ps).

• I restarted the container with docker start -a silly_davinci, and retrieved the newly assigned ports:

  $ docker port silly_davinci
  25000/udp -> 0.0.0.0:32772
  5000/tcp -> 0.0.0.0:32787
  5601/tcp -> 0.0.0.0:32786
  9200/tcp -> 0.0.0.0:32785
  9300/tcp -> 0.0.0.0:32784
  

• From another machine, I started sending logs again with nc, to the newly assigned UDP port (32772).

• I had a look at Kibana, and saw that everything was working as expected (a pause while the container was stopped, then log activity resumes once the container is started and logs come flowing back in).

So again, I'm not sure what (if anything) I'm doing differently from you, but I have your image working and containers behaving properly after being restarted.

A few pointers to troubleshoot your situation:

• Try to run the tests above to see if you still have the problem.
• If you don't, then walk me through what you're doing step-by-step and I'll try to reproduce on my side.
• If you still have the same problem using the steps above, then check if the TCP and UDP ports are actually open where you expect (docker port and netstat -au). If they are then you may be facing this peculiar bug on your machine: see the discussion on the page for a workaround.

Hope that helps, let me know how it goes.

from elk-docker.

Hey! Thanks for such a detailed answer and help:)
I tried doing everything step by step, and got stuck with this: after restart the port in the container isn't open!
Here's what I did (everything localhost, but I tried it on two separate machines either):

sudo docker run -P --name elk my/elk

sudo docker port elk

# 9300/tcp -> 0.0.0.0:32776
# 25000/udp -> 0.0.0.0:32770
# 5000/tcp -> 0.0.0.0:32779
# 5601/tcp -> 0.0.0.0:32778
# 9200/tcp -> 0.0.0.0:32777

echo -n "{\"foo\": \"$RANDOM\"}" | nc -u -q 0 0.0.0.0 32770

#everything ok, kibana got the entry

sudo docker exec -it elk netstat -au
# udp6       0      0 [::]:25000              [::]:*                             
# udp6       0      0 [::]:54328              [::]:*  // what is this btw ?

Everything is ok for now (except the unknown second udp port). Now I'm restarting it.

sudo docker stop elk

sudo docker start -a elk  

sudo docker exec -it elk netstat -au
# udp6       0      0 [::]:54328              [::]:* 

Aaaaaand it's gone. Of course now everything else fails.

I tried this on my local ubuntu computer, and an AWS EC2 instance. Both the same.
Looked through the issue you referenced... Maybe it is the problem.

Please, tell if you have some thoughts on it. And anyway, I guess this is not an image problem, so we can close this one..

from elk-docker.

OK, good news: I managed to kind of reproduce the issue, and I think I might be on to something.

After a series of successful stop's and start's with everything working nicely (UDP port 25000 open after a short while once Logstash is up, and everything behaving as expected), suddenly, after one innocent start, I experienced the issue you're having.

Here's what happened:

$ docker start -a evil_hypatia 
 * Starting Elasticsearch Server
sysctl: setting key "vm.max_map_count": Read-only file system
logstash is already running
waiting for Elasticsearch to be up (1/30)
...

Logstash is "detected" as already running and is therefore not started. Of course, Logstash isn't actually running, but the init script believes that it is because the PID in Logstash's pidfile (/var/run/logstash.pid) corresponds to a process that exists... which — incidentally — is something that the init file warns about.

As I can't control what PID each process gets assigned, the problem is that I can't reliably reproduce the issue (I ran into it a couple of times randomly) to check if my explanation is correct, but I'm pretty sure that this is the problem (could you check on your side if you're getting logstash is already running?).
The only surprising thing is that I'm having the issue somewhat randomly, whereas you're facing it all the time... so there might be something else, but to begin with, what I can (and will) do is rework the init scripts to improve the way they check if processes are up or down.

So, turns out it probably is an issue with the image after all! 😊

Oh, and one last thing: UDP port 54328 is opened by Elasticsearch's zen discovery module.

from elk-docker.

I do get logstash is already running.

Can't think of any advice on reproducing, because I had this everywhere I tried:)

here's my docker version, maybe this can help...

Client:
 Version:      1.8.2
 API version:  1.20
 Go version:   go1.4.2
 Git commit:   0a8c2e3
 Built:        Thu Sep 10 19:19:00 UTC 2015
 OS/Arch:      linux/amd64

Server:
 Version:      1.8.2
 API version:  1.20
 Go version:   go1.4.2
 Git commit:   0a8c2e3
 Built:        Thu Sep 10 19:19:00 UTC 2015
 OS/Arch:      linux/amd64

Ping me if I can help you with anything else :)

from elk-docker.

OK, great (so to speak!), that would tend to confirm that this is indeed the problem, which makes it so much easier to solve!
A workaround for the time being is to modify the start.sh to have rm /var/run/logstash.pid and /var/run/kibana4.pid before attempting to start the services.

I'll get busy during the weekend to sort this out — keep you posted.

from elk-docker.

Great, thank you:)

from elk-docker.

Right, the last commit (Logstash's init script properly deletes its pidfile when stopping, and ELK launch script stops all ELK services when it receives a SIGTERM signal as sent by docker stop) should sort out the issue.
Everything's working on my side (both on my local CentOS and a Ubuntu instance on DigitalOcean) with the latest sebp/elk and your Dockerfile and config file… but as we've clearly established, it might not mean it's really really working 😄
Anyway, give it a spin when you can and let me know if you have better luck with this one.

from elk-docker.

@spujadas It works now!:) Thanks for your effort!:)

from elk-docker.

Perfect, cheers!

from elk-docker.