Gunicorn: socket-error-processing-request-with-flask-gunicorn

[oddball]

I apologize, I know this really belongs more at StackOverflow, but didnt get any answers at all at https://stackoverflow.com/questions/51619559/socket-error-processing-request-with-flask-gunicorn-docker-and-azure , so thought I give it a try here!

Running a python flask app with gunicorn. When I spin up the docker image locally everything is fine, but when I run the docker image on azure with kubernetes, I get this OSError. The request is fine, but get an error in the log.

Does anyone know what is happening?

10.242.0.1 - - [31/Jul/2018:15:11:04 +0000] "GET /api/evaluation HTTP/1.1" 200 14343  "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36"
[2018-07-31 15:11:05 +0000] [10] [ERROR] Socket error processing request.
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 134, in handle
    req = six.next(parser)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/parser.py", line 41, in __next__
    self.mesg = self.mesg_class(self.cfg, self.unreader, self.req_count)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 181, in __init__
    super(Request, self).__init__(cfg, unreader)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 54, in __init__
    unused = self.parse(self.unreader)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 193, in parse
    self.get_data(unreader, buf, stop=True)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 184, in get_data
    data = unreader.read()
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/unreader.py", line 38, in read
    d = self.chunk()
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/unreader.py", line 65, in chunk
    return self.sock.recv(self.mxchunk)
  File "/usr/local/lib/python3.6/ssl.py", line 994, in recv
    return self.read(buflen)
  File "/usr/local/lib/python3.6/ssl.py", line 871, in read
    return self._sslobj.read(len, buffer)
  File "/usr/local/lib/python3.6/ssl.py", line 633, in read
    v = self._sslobj.read(len)
OSError: [Errno 0] Error

Starting the app with

gunicorn --certfile Config/cert.crt --keyfile Config/cert.key -w 2 -b :8084 --access-logfile - gunicorn_app:app

Would be much obliged, for any lead on how to debug this

[benoitc]

is the client connecting using ssl?

[oddball]

@benoitc, Yes. And the request is fine. Response come back with expected data. FYI: Before I added "-w 2" as a switch to gunicorn, the request took 15 seconds though. When I added " -w 2 " it takes ~180 ms.

[oddball]

some more info, doing a request from command line

$ curl -i -H "Content-Type: application/json" "https://whatever.whatnot.com/api/ping"
HTTP/1.1 200 OK
Server: gunicorn/19.9.0
Date: Thu, 27 Sep 2018 14:25:02 GMT
Connection: close
Content-Type: application/json
Content-Length: 15
Access-Control-Allow-Origin: *

{"pong": true}

and the log says:

10.244.0.1 - - [27/Sep/2018:14:25:02 +0000] "GET /api/ping HTTP/1.1" 200 15 "-" "curl/7.54.0"
[2018-09-27 14:25:03 +0000] [16] [ERROR] Socket error processing request.
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 134, in handle
    req = six.next(parser)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/parser.py", line 41, in __next__
    self.mesg = self.mesg_class(self.cfg, self.unreader, self.req_count)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 181, in __init__
    super(Request, self).__init__(cfg, unreader)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 54, in __init__
    unused = self.parse(self.unreader)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 193, in parse
    self.get_data(unreader, buf, stop=True)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 184, in get_data
    data = unreader.read()
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/unreader.py", line 38, in read
    d = self.chunk()
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/unreader.py", line 65, in chunk
    return self.sock.recv(self.mxchunk)
  File "/usr/local/lib/python3.6/ssl.py", line 994, in recv
    return self.read(buflen)
  File "/usr/local/lib/python3.6/ssl.py", line 871, in read
    return self._sslobj.read(len, buffer)
  File "/usr/local/lib/python3.6/ssl.py", line 633, in read
    v = self._sslobj.read(len)
OSError: [Errno 0] Error
[2018-09-27 14:25:08 +0000] [16] [ERROR] Socket error processing request.
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 134, in handle
    req = six.next(parser)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/parser.py", line 41, in __next__
    self.mesg = self.mesg_class(self.cfg, self.unreader, self.req_count)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 181, in __init__
    super(Request, self).__init__(cfg, unreader)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 54, in __init__
    unused = self.parse(self.unreader)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 193, in parse
    self.get_data(unreader, buf, stop=True)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 184, in get_data
    data = unreader.read()
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/unreader.py", line 38, in read
    d = self.chunk()
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/unreader.py", line 65, in chunk
    return self.sock.recv(self.mxchunk)
  File "/usr/local/lib/python3.6/ssl.py", line 994, in recv
    return self.read(buflen)
  File "/usr/local/lib/python3.6/ssl.py", line 871, in read
    return self._sslobj.read(len, buffer)
  File "/usr/local/lib/python3.6/ssl.py", line 633, in read
    v = self._sslobj.read(len)
OSError: [Errno 0] Error
[2018-09-27 14:25:13 +0000] [17] [ERROR] Socket error processing request.
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 134, in handle
    req = six.next(parser)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/parser.py", line 41, in __next__
    self.mesg = self.mesg_class(self.cfg, self.unreader, self.req_count)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 181, in __init__
    super(Request, self).__init__(cfg, unreader)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 54, in __init__
    unused = self.parse(self.unreader)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 193, in parse
    self.get_data(unreader, buf, stop=True)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/message.py", line 184, in get_data
    data = unreader.read()
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/unreader.py", line 38, in read
    d = self.chunk()
  File "/usr/local/lib/python3.6/site-packages/gunicorn/http/unreader.py", line 65, in chunk
    return self.sock.recv(self.mxchunk)
  File "/usr/local/lib/python3.6/ssl.py", line 994, in recv
    return self.read(buflen)
  File "/usr/local/lib/python3.6/ssl.py", line 871, in read
    return self._sslobj.read(len, buffer)
  File "/usr/local/lib/python3.6/ssl.py", line 633, in read
    v = self._sslobj.read(len)
OSError: [Errno 0] Error

So the request is fine, but every 5 seconds I get:

[2018-09-27 14:25:23 +0000] [16] [ERROR] Socket error processing request.

Points in the direction of Azure. Some hearbeat check or something. But get no indication of what it is. It just floods my logs

[oddball]

Wonder if it is related to https://github.com/miguelgrinberg/Flask-SocketIO/issues/160

[tilgovi]

That does sound like it could be a load balancer heartbeat. These might be the relevant docs: https://docs.microsoft.com/en-us/azure/load-balancer/load-balancer-custom-probe-overview

[oddball]

@tilgovi could be. But but my kubernetes pods running Node/Express webservers does not have this error in the logs. So still gunicorn specific

[benoitc]

@oddball are you sure it's related to the ping ? Seems like the issue appear or another request.

[oddball]

@benoitc I am pretty sure it is unrelated to GET /api/ping

But I cant see any other requests. I actually dont know more then the log I pasted above

[Blaskyy]

I have got same issue, also use cloud virtual machine.
But if I use port 443 for https, "-b :443". The error log no longer appears.

[oddball]

@Blaskyy good info. But would still be nice if I could expose one port, and map it to 443 in kubernetes like below

apiVersion: apps/v1beta1
kind: Deployment
metadata:
  name: whatever
spec:
  replicas: 1
  template:
    metadata:
      labels:
        app: whatever
    spec:
      containers:
      - name: whatever
        image: my.azurecr.io/whatnot:latest
        ports:
        - containerPort: 8084
---
apiVersion: v1
kind: Service
metadata:
  name: whatever
spec:
  type: LoadBalancer
  ports:
  - port: 443
    targetPort: 8084
  selector:
    app: whatever

[oddball]

@Blaskyy I still see the issue using -b :443

[oddball]

The issue originates from load-balancer health-probes that azure adds automatically.

The probes should be able to use http, but cant get that to work. There still is a question of why

gunicorn --certfile cert.crt --keyfile cert.key -w 2 -b :443 --access-logfile - gunicorn_app:app

that should only listen port 443, picks up tcp packets going to another port.

[benoitc]

@oddball the page you're shoing shows a tcp probe though not an http or https one. Can you try to probe to https? also are you using nginx on top? If yes you may want to use it as an sssl reverse proxy as well.

[solsticedhiver]

I am self hosting a small web site on https and gunicorn+flask and i got a lot of these errors too.

Definitvly annyoing. Happens a most of the time when I try to reach my site over 4G and may be connection is not good enough ??? But happens also on ethernet+VDSL

OMG! hello @benoitc. Do you remember the times of archlinuxfr.org ?

[oddball]

I found a solution that worked for 10-20 minutes, then it did not, and then it started working. Instable with other words.
I am not using it, but thought I write it down.

A health-probe is created for each port on the loadbalancer.

There are 2 types of probes. Basic and Standard. The Basic supports protocols http and tcp. Standard allegedly supports https as well, but at the moment that is not the one you get in azure kubernetes.

I setup a http server on my docker image as well as a https.

Running :

$ kubectl get services
NAME        TYPE           CLUSTER-IP     EXTERNAL-IP       PORT(S)                         AGE
whatever    LoadBalancer   10.1.207.83    CENSORED       80:31498/TCP,443:30370/TCP      56d

gets me the ports running in

In https://portal.azure.com Home > kubernetes - Health probes ,
I found the probe for port 443 on the loadbalancer, and set the protocol to http and the port to 31498 and the path to my endpoint /api/ping that answers 200 on GET.

In https://portal.azure.com Home > kubernetes - Load balancing rules,
I found the rule for port 443 on the loadbalancer, and set the Backend port to 30370

[oddball]

running a C# dotnet server Kestrel on Azure kubernetes shows the same issue.

dbug: HttpsConnectionAdapter[1]
      Failed to authenticate HTTPS connection.
System.IO.IOException: Authentication failed because the remote party has closed the transport stream.
   at System.Net.Security.SslState.StartReadFrame(Byte[] buffer, Int32 readBytes, AsyncProtocolRequest asyncRequest)
   at System.Net.Security.SslState.PartialFrameCallback(AsyncProtocolRequest asyncRequest)
--- End of stack trace from previous location where exception was thrown ---
   at System.Net.Security.SslState.ThrowIfExceptional()
   at System.Net.Security.SslState.InternalEndProcessAuthentication(LazyAsyncResult lazyResult)
   at System.Net.Security.SslState.EndProcessAuthentication(IAsyncResult result)
   at System.Net.Security.SslStream.EndAuthenticateAsServer(IAsyncResult asyncResult)
   at System.Net.Security.SslStream.<>c.<AuthenticateAsServerAsync>b__51_1(IAsyncResult iar)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Server.Kestrel.Https.Internal.HttpsConnectionAdapter.InnerOnConnectionAsync(ConnectionAdapterContext context)

[andreblumenau]

I am facing the exact same issue, and I also use Azure.

[ngpgopi]

I'm running on Kube + AWS, I also face the same issue when gunicorn binds to HTTPS. However, when the binding to http, seems to work fine. Any solutions please?

[benoitc]

@ngpgopi how did you bind it to https?

[ngpgopi]

gunicorn --workers 3 --certfile=/path/to/cert --keyfile=/path/to/key -b :8443 superset:app

[oddball]

running a C# dotnet server Kestrel on Azure kubernetes shows the same issue.

�dbug�: HttpsConnectionAdapter[1]
      Failed to authenticate HTTPS connection.
System.IO.IOException: Authentication failed because the remote party has closed the transport stream.
   at System.Net.Security.SslState.StartReadFrame(Byte[] buffer, Int32 readBytes, AsyncProtocolRequest asyncRequest)
   at System.Net.Security.SslState.PartialFrameCallback(AsyncProtocolRequest asyncRequest)
--- End of stack trace from previous location where exception was thrown ---
   at System.Net.Security.SslState.ThrowIfExceptional()
   at System.Net.Security.SslState.InternalEndProcessAuthentication(LazyAsyncResult lazyResult)
   at System.Net.Security.SslState.EndProcessAuthentication(IAsyncResult result)
   at System.Net.Security.SslStream.EndAuthenticateAsServer(IAsyncResult asyncResult)
   at System.Net.Security.SslStream.<>c.<AuthenticateAsServerAsync>b__51_1(IAsyncResult iar)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Server.Kestrel.Https.Internal.HttpsConnectionAdapter.InnerOnConnectionAsync(ConnectionAdapterContext context)

With a C# dotnet2.2 Kestrel API server , I dont get this issue anymore. So Kestrel must have done something. Issue persist on my gunicorn/flask API server.

[oddball]

I dont have this issue anymore. I dont know how it was solved. But I have not done anything. Maybe Azure did something.

[jpmorris]

I have this problem. I've tried everything to stop it. I've changed the health probes TCP, HTTP, HTTPS. I can't really run on HTTP though so gunicron is only

gunicorn --certfile cert.crt --keyfile key.key -b 0.0.0.0:800 --workers=2 --threads=2 myapp.app:app

my health probe is on HTTPS:30876/ping (the port auto-generated by azure)
I deploy with helm and my loadballancer is on 443, the port container is on 443, the liveenessprobe/readnessprobe (in kubernetes config) is on 8000.

[ramnes]

I'm also experiencing this issue, but with a bare-metal Kubernetes cluster, not Azure. In my case, adding initialDelaySeconds: 20 to the readiness and liveness probes helps. It seems that something is preventing gunicorn to read the certificates (mounted from a secret) right away.

[vishnukraj1111]

I ran into the same issue. I was using a TCP health check in k8s and when I changed to a HTTP health check the error is gone.

[bestavillo]

I just ran into the same issue on an Azure Kubernetes cluster. As @vishnukraj1111 mentioned, changing the heath check from TCP to HTTPS solved the error. That setting is now in Load balancers -> kubernetes -> Health probes. Note that the port specified must match the private port number.

[avvijeet]

@bestavillo Thanks for the solution.
Adding on to it.
Pre-requisite:
--> nodeport value = (on the cli type "kubectl describe service ")
--> /healthz endpoint in your Code with over GET method which returns HTTP_200_OK
1: Get admin access to your Kubernetes Cluster.
2: Go to Kubernetes -> Health Probes
3: Find your service's probe using its nodeport value.
4: Change protocol from TCP to HTTPS and port value from 443 to your service's node port value
5: Save

Voila! your SSL error logs are gone.