Uwsgi: high latency with uwsgi behind AWS ELB

[vsuthichai]

I'm experiencing an issue while applying load to uwsgi instances placed behind an Amazon Elastic Load Balancer. Specifically, there is a strange latency that appears to surface when applying load to the ELB. After a session of wireshark, uwsgitop, and other debugging methods, I've determined that ELB is sending out additional socket requests to the backend that are not generated from the client and not from ELB's internal health check. There's a 3rd mysterious source of load that opens a socket and closes a socket to the uwsgi backend every few seconds. Looking at uwsgitop, I can frequently see workers in a "busy" state even when the client is not generating load. Understandably, some of the requests going to uwsgi will be ELB health check requests, but there shouldn't be anything else beyond that.

I suspect that this mysterious opening and closing of sockets consumes a spot in the listen queue and is the cause for the latency I'm experiencing. Does this sound familiar and has anyone else experienced it? I've already opened a case with Amazon Web Services and awaiting a response, but I thought I'd reach out here as well to see if this is a known issue. If I take ELB out of the equation and just apply load from the client directly to uwsgi, everything works great and there is no increase in latency.

[tuukkamustonen]

@vsuthichai I just bumped into https://forums.aws.amazon.com/thread.jspa?messageID=323793 and then to this.

Behind the link, an AWS engineer states:

There is a second health check that we implemented in Oct/Nov 2011, which behaves as you suggested -- it opens a connection and closes it. The reason for this second health check is that it provides protection against instances being terminated without being de-registered. We will be improving how this health check is executed, but it was intended to be non-intrusive. Other than filling up logs, are there any negative impacts you are seeing?

I also had similar experiences earlier with uwsgi behind ELB - throw in couple of requests and it works just fine, but increase load slightly and environment starts to crumble. My solution was to install nginx in between ELB and uwsgi - that fixed the performance issues.

However, as I just noticed, we are still getting those extra ELB healthchecks that end up as following in the nginx error logs:

2015/07/28 14:15:38 [info] 3590#0: *978 client timed out (110: Connection timed out) while waiting for request, client: X.X.X.X, server: 0.0.0.0:8000
2015/07/28 14:16:36 [info] 3590#0: *990 client closed connection while waiting for request, client: Y.Y.Y.Y, server: 0.0.0.0:8000

Funny thing is, if I drop nginx and route ELB directly to uwsgi, uwsgi does not show any similar errors...

What sort of an answer did you get from AWS regarding the issue?

[vsuthichai]

@tuukkamustonen Hi, thanks for responding. I did receive a response from AWS support regarding the issue. They acknowledged that there was such a mechanism in place that opened up a socket every few seconds, but they verified it was a "pre-connect optimization" and not a health check. I didn't fully understand the details of it myself, just knew that it was causing unwanted latency and taking up spots in the listen queue. I also didn't see anything show up in the uwsgi log regarding the extra socket requests. I was only able to see the issue through uwsgitop and wireshark. Eventually, I requested they disable the feature on my ELB. They obliged, and the issue disappeared.

Other workarounds:

1) A suggested enhancement for uwsgi is to somehow prevent these seemingly benign socket requests to consume a spot in the listen queue.

2) Insert HAProxy, Nginx, or some load balancer that one has better control over considering ELB is pretty much a black box. This is something you've attempted with some success @tuukkamustonen ?

[tuukkamustonen]

@vsuthichai Indeed, I was in contact with AWS support as well, and as you wrote, ELB is opening up TCP-level(?) connections to backend and leaving them idle, so actual request handling would not require handshaking. It seems like I'm experiencing the same, and the open-close healthcheck that I linked to, is actually not shown in the logs (as it's lower level traffic and one that does not timeout and connections are closed right away).

To summarize, there are 4 types of activities a HTTP-mode ELB throws to backend:

1) Normal health check. The interval is configurable in ELB settings.
2) Open-close connection healthcheck (the one I linked to). These follow the ELB healthcheck interval.
3) Optimization where ELB opens up connections to backend and leaves them idle. This may result in ELB closing the connection after 60s or timeouts (if nginx, for example, closes them before ELB does).
4) The standard request handling

I'm not sure how uwsgi really works, but I'm kinda surprised that it would crumble to the ELB optimization (point 3 above), as ELB would utilize the pre-existing open connections, anyway.

It's been a while since I added nginx on top of uwsgi so I cannot remember the details. It was just a quick fix, that seemed to work. I don't know how/why nginx really remedies the situation, because it basically just proxies the requests to uwsgi anyway (I'm using proxy_pass with HTTP connection to upstream).

I guess I would need to try it out again without nginx. Who know what I did wrong back then, but it's comforting to hear you've had similar problems :)

[unbit]

So if i understand correctly ELB opens a connection and leave it open for 60 seconds without sending data ?

[unbit]

Just as a note, uWSGI uses deferred accept so it does not get ack of connection until at least 1 byte is received

[methane]

Have anyone tried Connection: close ?
ELB uses keep-alive for 60secs. It may blocks uWSGI worker.

[methane]

In case of backlog shortage, accept() may returns socket without any data received.
So somaxconn and backlog are important for deferred accept.

[unbit]

@methane but even in such a case uWSGI will ignore and suddenly closes the connection https://github.com/unbit/uwsgi/blob/master/proto/http.c#L836 (this was required for supporting heroku healthcheck). Even if ELB does not send data and do not close the connection, uWSGI will drop it after uwsgi.socket_timeout (4 seconds)

[tuukkamustonen]

So if i understand correctly ELB opens a connection and leave it open for 60 seconds without sending data ?

@unit That's right. But if there is actual traffic coming in, then the opened connections will be used (but ELB can open up new idle connections to serve more requests, as it determines that traffic is growing).

Have anyone tried Connection: close ?
ELB uses keep-alive for 60secs. It may blocks uWSGI worker.

@methane I also saw keep-alive connections being closed after 60s in my nginx logs. But without nginx, uWSGI+Flask by default shouldn't set keep-alive headers, so in my case at least, no keep-alive was used without nginx (nginx, by default seems to add them). That's how I interpret http://uwsgi-docs.readthedocs.org/en/latest/HTTP.html at least, correct me if wrong?

I have listen: 1024 in uwsgi configs. Even if ELB threw in some extra requests, it shouldn't fill up quickly...?

Even if ELB does not send data and do not close the connection, uWSGI will drop it after uwsgi.socket_timeout (4 seconds)

Is this logged anywhere? I have logs going to a file (logto) but I can't recall seeing any info on dropped connections there and I don't know how to adjust the level of logging either.

[simon-weber]

We ran into this too, running 2.0.13.1.

From some pretty unscientific testing I see an improvement when:

• switching from http-socket to http
• adding a route like route=^/healthcheck static:/tmp/health and sending the ELB healthchecks there
• turning on offloading for the static serving
• turning on keepalive

Turning on buffering may help with larger requests as well (I haven't tested that yet). I'll post back once I try this under more representative traffic.

However, there's one thing I can't figure out: is there a way I can separate the health check onto a different socket? I tried binding http to two different ports, but they still seem to share the same listen queue (for the auto-assigned uwsgi socket port). I'd like to do this to prevent health checks from failing if load fills up the listen queue, to avoid taking out healthy (but slow) hosts under load.

[simon-weber]

AKX on irc had the clever idea to use the stats module for health checks, since it serves from a separate socket directly from the master loop.

[simon-weber]

The stats module didn't seem to work well in this case, since it seemed to block the master loop occasionally (and I couldn't find a way to offload it).

Instead, I managed to create a separate listen queue for tcp health checks with a config like:

# ELB listener.
http=127.0.0.1:8000

# Socket for http listen queue (used for http -> uwsgi communication).
socket=:56000

# Socket for tcp health checks.
raw-socket=:56001

# Give 6 workers to http and 2 to health checks.
map-socket=0:1,2,3,4,5,6
map-socket=1:7,8
processes=8

So far, this has fixed the problems we've seen. But, I've only tested it under a percent of our true load so far; I'll post back with any other major findings as we ramp it up.

[simon-weber]

This is working well for us: busy workers more than halved after the change. We also saw an improvement from turning on keepalive:

add-header         = Connection: Keep-Alive
# Milliseconds to wait before closing a connection.
# Must be higher than the ELB's timeout.
http-keepalive     = 65000

I didn't test post buffering.

[alanjds]

Hi. I followed the @simon-weber tip on socket/raw-socket, but uwsgitop shows not a single answer count on the raw-socket process. Is this happening on your side too?

[tuukkamustonen]

@alanjds Can't comment on uwsgitop (don't have it installed) but I just tested @simon-weber's healthcheck solution. I only set:

uwsgi-socket: /tmp/foobar  # requests through nginx get here, old config
listen: 1024  # old config

raw-socket: 0.0.0.0:56000  # added this

...in my uwsgi YAML config. I didn't define any map-socket.

What happens is when I telnet 127.0.0.1:56000 connection is opened and auto-closed. I would assume this is enough - if my application is bad, uwsgi process crashes and there's nothing to respond on port 56000.

Configured ELB to use TCP:56000 healthchecking (bypassing nginx in my case) and it seems to be happy with this setup.

But honestly, I'm not sure what I'm doing here. Without map-socket declaration, does uwsgi just default everything for the socket that is specified first (uwsgi-socket in my case)? Also, do requests to raw-socket actually bypass the listen queue on the uwsgi-socket?

Uwsgi documents listen as:

set the socket listen queue size

But which socket is that? Is it same value for any sockets specified? Do they still hold their own queues (I would assume so)?

[simon-weber]

@alanjds I can check once I'm back at work, but I believe showing 0 connections on the health check socket is expected. I think that count increases once a connection is being worked on, and the ELB (or telnet or netcat) never actually send any data.

@tuukkamustonen my best shot at those questions:

Without map-socket declaration, does uwsgi just default everything for the socket that is specified first (uwsgi-socket in my case)?

I think so: I think you'll get one worker shared between two sockets with that config. The uwsgi startup output should tell you for sure (it prints the mapping of ports/listeners onto sockets and processes).

Also, do requests to raw-socket actually bypass the listen queue on the uwsgi-socket?

So long as the startup output shows two separate sockets, you should be fine, but you can double check by filling up the listen queue for the uwsgi socket and then trying the raw-socket again. I just configured our app to sleep on a certain endpoint when testing this.

Uwsgi documents listen as "set the socket listen queue size". But which socket is that? Is it same value for any sockets specified? Do they still hold their own queues (I would assume so)?

Yeah, the listen queue size applies to all sockets. As far as I can tell, it's not possible to create sockets with different listen queue lengths.

[alanjds]

Got it to work, after changing the ELB healthchecks to type TCP:

Notice the 92 on col REQ of process 5

[alanjds]

I am thinking about this route=^/healthcheck static:/tmp/health shortcut...

Is possible to route specific urlpaths to specific sockets or processes, so the healthchecks can be all answered by the process 5 in my case?

I am asking that because, well, my healthcheck checks the application too, not only if uWSGI is up. I would like to turn back to HTTP checks if possible.

[simon-weber]

I was never able to get http separated onto a separate listen queue so I ruled them out.

If you're ok with your health checks failing when the listen queue is full, then you could use either map-socket or static file offloading to separate them from your normal worker processes.

[tuukkamustonen]

We are drifting away form the original topic... but:

I think so: I think you'll get one worker shared between two sockets with that config. The uwsgi startup output should tell you for sure (it prints the mapping of ports/listeners onto sockets and processes).

@simon-weber Seems like by default it doesn't show that mapping (if you're running only 1 process).

uwsgi socket 0 bound to UNIX address /tmp/foobar.sock fd 6
uwsgi socket 1 bound to TCP address 0.0.0.0:56000 fd 7
...
spawned uWSGI master process (pid: 1376)
spawned uWSGI worker 1 (pid: 1408, cores: 5)

However, if you run multiple processes it does print that mapping (see below).

So long as the startup output shows two separate sockets, you should be fine, but you can double check by filling up the listen queue for the uwsgi socket and then trying the raw-socket again. I just configured our app to sleep on a certain endpoint when testing this.

Alright, I tested it out. In all scenarios I have:

uwsgi-socket: /tmp/foobar.sock

Requests are served via nginx.

I made an endpoint with 60s sleep and ran in enough requests to reserve all my worker threads. The result is that:

• raw-socket always responds as it's TCP-level and there's nothing more to do.
• http-socket and http do not. This is because they share the same workers.

However, I did:

uwsgi-socket: /tmp/foobar.sock
http-socket: 0.0.0.0:56000
processes: 2
map-socket: 0:1
map-socket: 1:2

And this gives:

spawned uWSGI worker 1 (pid: 2107, cores: 5)
spawned uWSGI worker 2 (pid: 2108, cores: 5)
mapped socket 1 (0.0.0.0:56000) to worker 2
mapped socket 0 (/tmp/foobar.sock) to worker 1

This works: bloating uwsgi-socket (through nginx) does not block requests on HTTP:56000/health!

So you could use that @alanjds. Although it feels a bit wasteful that you need to dedicate a single worker for just service health check... but if you have RAM to spend then it's not a problem.

You can even open two similar sockets in case you don't have nginx:

http-socket: 0.0.0.0:8000
http-socket: 0.0.0.0:56000

Or I guess:

http: 0.0.0.0:8000
http-socket: 0.0.0.0:56000

And it will work (as long as you have map-socket declarations).

[luke3141]

I'm not sure if this will work for anyone else, but we've managed to work around the issue by setting our ELB to use TCP rather than HTTP. We've gone from 200 requests/min to 20,000 requests/min.

[Fitblip]

IIRC you lose a lot of functionality by switching to the raw TCP load balancing. Our solution was to move to Gunicorn and our headaches were pretty immediately relieved.

[blablacio]

@Fitblip I thought the same when we switched from Gunicorn to uWSGI for the exact same reason couple of months ago. Just today, we started experiencing the problem with uWSGI too. Using a TCP ELB doesn't seem to help either.

[six8]

Seeing similar problems with Cheroot/Cherrypy, Gunicorn, and uWSGI if not using eventlet/gevent. We don't want to use eventlet/gevent so this is becoming quite the annoying problem. Strange that it's happening everywhere but there's no definitive answer.

[vsuthichai]

Surprised to see this issue still open. I haven't worked on it in quite a while, but I thought I'd mention that I think it's possible to disable the pre-connect optimization by opening a ticket with AWS support for the ELB instance in question. I think this is what fixed it for us a few years back. Granted, this is really not a good fix. It shouldn't be happening at all.

[alanjds]

I too would prefer to see it solved here instead of rely on asking AWS to disable the

[methane]

We use nginx in front of uWSGI and there are no problem. Very stable.
I recommend it.

[unbit]

So, after years, the problem is almost clear, but unfortunately only fully featured webservers are able to cooperate out-of-the-box with this. I think (unless you want to do worker-socket mapping, that is a too advanced trick for the vast majority of users) removing the --http layer and use nginx (or something like this) as proxy, is the easiest solution. Co-routines/non-blocking engines do not suffer from the problem as they are built from the ground up to support long-running connections, but for thread/process-based systems opening this "fake" connection means wasting precious resources. Another solution would be improving the http router, but except for the subscription system and some ssl/sni magic, nginx, or caddy, or modern apaches are a way superior solution for http proxying. (note about the subscription system: you can use the fastrouter to continue having dynamic routing behind nginx and friends)

[jonathansp]

as 2019, is it still valid?

[sebyul2]

oh...

[jonathansp]

as 2020, is it still valid?

[BenjamenMeyer]

still happening; here's a nice article that has some more in-depth information: https://medium.com/@gabriel.m.troy/aws-alb-docker-uwsgi-502-bad-gateway-16d0a36f6240
may be that will give some insight.