Marathon: Marathon event bus stops sending messages if a marathon instance restarts

[sybrandy]

We've seen this several times where an app is restarted and Traefik (short version: http proxy that can listen for Marathon events to keep it's config up to date) does not update. This results in 502 errors until Traefik is restarted. Up until today, we had no idea why this was occurring as it happens sporadically. Only recently did we confirm that it was because it stopped getting events. The initial suspect was Traefik, but digging around showed that a library that is used does reconnect if the connection is lost. Also, no errors have been reported.

Today, this happened again and I decided to check the Marathon logs to see if there was an error. The first one I checked had it's log starting shortly after I saw the events stop for one of my nodes. In this case, this node had rebooted earlier in the day. The error cropped up some time later and I investigated. Other instances of Traefik were restarted and I could see them getting events, but not the "debugging" instance I have running. If I connect to the events endpoint with curl, I can see events.

So, it appears that something inside of Marathon is holding the event stream connection open, but fails to read/receive events until the connections are closed/reopened. If this happens again, I'll update the bug to confirm it, but I will have to wait until it happens again as we need to keep the system as stable as possible.

[xiaods]

+1

[jangie]

I am seeing similar, if not identical issues, running traefik against marathon. I have tried, from the marathon side, tcpkill-ing connections that traefik has open against the event bus, which does result in a reconnect from traefik, so it does indeed seem that traefik (specifically its dependency's dependency eventsource) deals with closed connections well.

[jangie]

I suspect that the issue is here: https://github.com/mesosphere/marathon/blob/6df72cdc9535e4dce3e67a3329dca87a1cfe3879/src/main/scala/mesosphere/marathon/core/event/impl/stream/HttpEventStreamActor.scala#L112-L114

I am very much not a scala or akka person, but my suspicion is that handle.close() should be called in there as well, to ensure that the underlying connection, and not just the actor servicing the connection, is killed.

[jangie]

@sybrandy I think I'm seeing that this does not in fact seem to be caused by election events at the very least; running against the abdication endpoint does not seem to trigger the behavior that I was hoping to replicate. I am curious to see if you've found a resolution to this, as we are at a loss as to what is going on.

[sybrandy]

@jangie Unfortunately I don't have any new information. As stated, this appears to occur when a node goes down, so perhaps it's something more than leader election? It's happened a couple more times since I reported this, but we haven't been able to replicate it under a controlled environment as this is currently happening on a production system, so we don't want to mess with it, and our staging environment is still being stood up.

[jangie]

@sybrandy do you still happen to have logs from marathon from when you experienced the issue? I suspect that #4356 will fix this issue and am hopeful that your logs bear out a similar situation.

[lewisheadden]

@sybrandy I believe this is to do with a mis-configuration of the Go HTTP Client in Traefik. I have opened this pull request with Traefik. I believe it solves the problem that myself and @jangie have been seeing -- https://github.com/containous/traefik/pull/784. I would be intrigued to see if it helps you.

[sybrandy]

@jangie Sorry for the late reply. Unfortunately, I don't have the logs any more and I'm pretty sure that I didn't have them back then. Taking a quick look, it definitely sounds similar to what I'm seeing.

@lewisheadden The fix looks interesting. It's still a workaround since it doesn't resolve the server issue, but it makes a lot of sense in case like you described where IP addresses change. Unfortunately, I can't test the fix on our system right now as it's been very stable for some time and it's important that Traefik stays up. Even then, the marathon instance that crashed periodically hasn't do so in some time, so I'm not sure if I would be able to test it properly without killing it. Not something I want to do on a production system.

[lewisheadden]

@sybrandy "the server issue" - can you expand upon that?

I don't think the server is doing anything wrong. I think Traefik is not enabling TCP Keep Alive and because Traefik sends no data on the connection it will never find out the connection is closed, it'll just keep indefinitely trying to perform read operations on it.

Appreciate you don't want to test on a system like that! 👍

[sybrandy]

@lewisheadden Did you check out @jangie 's comments? He's seen a couple things that may be related to this on the server-side that should be/will be fixed. Neither one may be the exact issue, but those things are what I was referring to when I said "the server issue." Until those are fixed, older versions of Traefik and possibly other systems doing the same thing will have issues unless they are updated or it's fixed in Marathon and Marathon is upgraded.

[jangie]

@sybrandy @lewisheadden and I actually work on the same team and have been jointly trying to resolve the situation that we've been seeing. In the case of what we're seeing, at least, the timeout as put in containous/traefik#784 seems to have resolved this; we had seen traefik continue to hold on to a stale TCP connection which no longer sent marathon events for days past the DNS entry for an ELB resolving to the IP that represented the other side of the connection.

In situations where a connection is no longer responsive to keepalives, at least, this will resolve the issue. #4356 is still something that would be good for Traefik to work against, but with a newer release of Traefik with the fix, I believe this will resolve more situations more cleanly.

[meichstedt]

Note: This issue has been migrated to https://jira.mesosphere.com/browse/MARATHON-4781. For more information see https://groups.google.com/forum/#!topic/marathon-framework/khtvf-ifnp8.

[meichstedt]

Note: This issue has been migrated to https://jira.mesosphere.com/browse/MARATHON-4781. For more information see https://groups.google.com/forum/#!topic/marathon-framework/khtvf-ifnp8.