CodeGenieApp / serverless-express

Run Express and other Node.js frameworks on AWS Serverless technologies such as Lambda, API Gateway, Lambda@Edge, and more.
https://codegenie.codes
Apache License 2.0
5.13k stars 667 forks source link

Error: EADDRINUSE /tmp/server0.sock incrementing socketPathSuffix #5

Closed karli2000 closed 7 years ago

karli2000 commented 7 years ago

Hi,

when i run my express-app on lambda i get sometimes this error: EADDRINUSE /tmp/server0.sock incrementing socketPathSuffix. EADDRINUSE /tmp/server1.sock incrementing socketPathSuffix. EADDRINUSE /tmp/server2.sock incrementing socketPathSuffix. EADDRINUSE /tmp/server3.sock incrementing socketPathSuffix. EADDRINUSE /tmp/server4.sock incrementing socketPathSuffix. EADDRINUSE /tmp/server5.sock incrementing socketPathSuffix. EADDRINUSE /tmp/server6.sock incrementing socketPathSuffix.

When a call gets this error it will take around 1800ms to resolve (compared to a 3-8ms normally). Is this releated to aws-serverless-express or to my app?

vkkis93 commented 7 years ago

:+1:

brettstack commented 7 years ago

I wouldn't expect it to increase execution time so drastically like this. I'll look into it and get back to you.

brettstack commented 7 years ago

I'm only able to get this error locally. I tried testing with 200rpm against a Lambda function and still could not repro the error. What version of aws-serverless-express are you using?

karli2000 commented 7 years ago

When testing it in production it was 1.1.1 It looks like the problem is starting when you have some load on the lambda function, we had around 10-20 requests/seconds, so my guess is that it runs out of sockets somewhere.

We tested it without express (the app is just a simple password-strength wrapper) and we don't see this error.

brettstack commented 7 years ago

@karli2000 the message is certainly from this library - we show it when the socket it is trying to use is already in use, and then "increment" the socket path. Perhaps a better solution is to use a random suffix instead.

The reason you are seeing 1800ms execution times is almost certainly due to a cold start, and not specifically related to the library. The correlation is that you will only see this message on cold starts. If you look into your cold start times (when a new Lambda container is created), I expect you will see similar 1800ms execution times. I generally see ~300ms due to Lambda's overhead of creating a new container, and the rest due to my app's initialization (importing modules, setting up express, connecting to db, etc.)

brettstack commented 7 years ago

I load tested at 40rps and still did not see this message. I'm leaving this open in hopes that someone else can provide more insights.

karli2000 commented 7 years ago

Hi,

i looked into the logs, the 1800ms was not a cold start, it was only when the app was waiting for a socket. A cold start of our app is only 140-180ms.

Could it be that the vm that runs the lambda function has some limits on sockets?

I am sorry that i cannot give you more insight because we recoded our app to not use express anymore. But maybe you can reproduce it: it was just this express-app: https://github.com/wcjr/zxcvbn-api , there is no db or anything else involved.

brettstack commented 7 years ago

Thank you, that will be most helpful.

brettstack commented 7 years ago

@karli2000 which route/method were you experiencing this on? Also, I don't see any commit which uses aws-serverless-express. Was this just not commited?

Thanks, Brett.

brettstack commented 7 years ago

@karli2000 we were able to get EADDRINUSE when using test invoke, and also see the increased execution time. This is caused when an error is thrown (in this case, as a result of event.headers being null in test invoke). In your logs, are there any other errors you see in the requests where you get the EADDRINUSE. Now that we are able to reproduce it, a fix will follow shortly. Thanks for bringing this to our attention.

karli2000 commented 7 years ago

Great to hear! Keep up the good work! Edit: no, as far as i can remember there where no other errors.

brettstack commented 7 years ago

This is fixed in 1.1.4.

dncrews commented 7 years ago

@brettstack v1.2.0, and I'm having this issue. I've run it 15 times locally:

EADDRINUSE /tmp/server0.sock incrementing socketPathSuffix.
EADDRINUSE /tmp/server1.sock incrementing socketPathSuffix.
EADDRINUSE /tmp/server2.sock incrementing socketPathSuffix.
...
...
EADDRINUSE /tmp/server14.sock incrementing socketPathSuffix.
EADDRINUSE /tmp/server15.sock incrementing socketPathSuffix.
dncrews commented 7 years ago

Just to make sure it wasn't something I did, I separate cloned the repo, installed the example, and I'm npm run local, and I'm getting the same problem.

brettstack commented 7 years ago

This is safe to ignore locally, though we will fix in the future. If you encounter this in your CW logs, it means you have an unhandled error in your app, and will result in longer processing times for the next request.

On Wed, 11 Jan 2017, 5:22 p.m. Dan Crews, notifications@github.com wrote:

Specifically, I've cloned the repo, installed the example, and I'm npm run local

— You are receiving this because you were mentioned.

Reply to this email directly, view it on GitHub https://github.com/awslabs/aws-serverless-express/issues/5#issuecomment-272048620, or mute the thread https://github.com/notifications/unsubscribe-auth/ABy6l-haRzxA8OWhIDS6haa9bqaKuWIBks5rRYBPgaJpZM4KWNuJ .

dncrews commented 7 years ago

@brettstack just to be clear: these are never clearing up. I just ran it for the first time in 2 days, and it's already at 19 EADDRINUSE

guzmonne commented 7 years ago

If someone is still having problem with this issue, check that you are not calling createServer on each function call.

Create the server outside the scope of your handler function and then pass it to the proxy function with the event and the context.

zeronil commented 7 years ago

I just got this for the first time while a Claudia.js app was starting up. Not sure if it's something to be concerned about or not since it's only happened once (though right now I'm the only one hitting the Lambda function). Didn't see any increments logged -- the Lambda function timed out after 10 seconds.

2017-02-09_14-57-43

ajmcgarry commented 7 years ago

I just had the same issue. It turned out to be a coding error in my controller. I was accessing a using the wrong path parameter which didn't exist result in me using undefined as a search parameter to elasticsearch. There was nothing in the logs or in Cloudwatch to tell me I had a simple logic error.

I think it may be when the lambda timeout is exceeded the socket remains open and no further requests to the function can acquire sockets.

Mojo90 commented 7 years ago

I experience the same error when testing with lambda-local and I am on version 2.1.3 (@brettstack you mention this socket error is fixed since 1.1.4). And the last output is: [Error: 'value' required in setHeader("x-apigateway-context", value).] Not sure how to fix that but the lambda function works on lambda but not local. Is there another way to test local as with the lambda-local repo? Pls see my comment here to reproduce the EADDRINUSE /tmp/server0.sock incrementing socketPathSuffix. output very fast: https://github.com/ashiina/lambda-local/issues/69#issuecomment-280323322 Where does this come from?

gvnn commented 7 years ago

We have been following the example in the README, but the issue still appears

EADDRINUSE /tmp/server0.sock incrementing socketPathSuffix.
...
EADDRINUSE /tmp/server458.sock incrementing socketPathSuffix.

just a few. I'm not sure on how to implement following the comment couple of lines above. At the moment my handler is

const server = awsServerlessExpress.createServer(app)
exports.handler = (event, context) => awsServerlessExpress.proxy(server, event, context)

and then 400+ warnings appear :(

hackash commented 7 years ago

This is still actual on my end , "aws-serverless-express": "^2.2.0"

brettstack commented 7 years ago

If you're only experiencing this while running it locally, you can safely ignore it for now. Any errors you receive are unlikely directly related to this message, and likely related to your application throwing an error that isn't being handled.

gvnn commented 7 years ago

It was happening on my lambda... I tried to move the creation of the server outside the handler, but it was still happening. I found that catching exceptions correctly and returning response.status(500).send(new ServerError(ex)) for example looks like that is working

brettstack commented 7 years ago

Released. Please update to version 3.0.0

heitorlessa commented 7 years ago

I'm also experiencing this error when using API Gateway + Lambda. No DB involved and using the latest:

"aws-serverless-express": "^3.0.0"

Similarly to others this only appeared after some load

brettstack commented 7 years ago

@heitorlessa Check your CloudWatch Logs in the request(s) immediately before the request which throws the EADDRINUSE error and you will likely find an uncaught error in your application. I have been unable to reproduce this for some time now, so it appears to be only certain errors, or errors thrown at specific points in the application lifecycle.

Any additional info you can share that may help me repro will allow me to get this fixed.

heitorlessa commented 7 years ago

@brettstack here's something that might help:

2017-05-16T07:15:47.823Z    7b8c65d7-3a07-11e7-9a4b-1bd321fae251    Example app listening at http://0.0.0.0:3000
2017-05-16T07:15:47.823Z    7b8c65d7-3a07-11e7-9a4b-1bd321fae251    EADDRINUSE /tmp/server0.sock incrementing socketPathSuffix.
2017-05-16T07:15:47.824Z    7b8c65d7-3a07-11e7-9a4b-1bd321fae251    EADDRINUSE /tmp/server1.sock incrementing socketPathSuffix.
2017-05-16T07:15:47.832Z    7b8c65d7-3a07-11e7-9a4b-1bd321fae251    EADDRINUSE /tmp/server2.sock incrementing socketPathSuffix.
2017-05-16T07:15:47.833Z    7b8c65d7-3a07-11e7-9a4b-1bd321fae251    EADDRINUSE /tmp/server3.sock incrementing socketPathSuffix.
2017-05-16T07:15:47.833Z    7b8c65d7-3a07-11e7-9a4b-1bd321fae251    EADDRINUSE /tmp/server4.sock incrementing socketPathSuffix.
2017-05-16T07:15:47.833Z    7b8c65d7-3a07-11e7-9a4b-1bd321fae251    EADDRINUSE /tmp/server5.sock incrementing socketPathSuffix.
2017-05-16T07:15:47.833Z    7b8c65d7-3a07-11e7-9a4b-1bd321fae251    EADDRINUSE /tmp/server6.sock incrementing socketPathSuffix.
2017-05-16T07:15:47.833Z    7b8c65d7-3a07-11e7-9a4b-1bd321fae251    EADDRINUSE /tmp/server7.sock incrementing socketPathSuffix.
2017-05-16T07:15:47.833Z    7b8c65d7-3a07-11e7-9a4b-1bd321fae251    EADDRINUSE /tmp/server8.sock incrementing socketPathSuffix.
2017-05-16T07:15:47.834Z    7b8c65d7-3a07-11e7-9a4b-1bd321fae251    (node:1) Warning: Possible EventEmitter memory leak detected. 11 connection listeners added. Use emitter.setMaxListeners() to increase limit
2017-05-16T07:15:47.834Z    7b8c65d7-3a07-11e7-9a4b-1bd321fae251    EADDRINUSE /tmp/server9.sock incrementing socketPathSuffix.

and created a simple bash script to loop overnight and was able to reproduce this issue:

#!/bin/bash

iterations=1000000

function add(){
    echo "Adding a new order...."
    curl -X POST \
        https://r89f4mey78.execute-api.eu-west-1.amazonaws.com/dev/order \
        -H 'cache-control: no-cache' \
        -H 'content-type: application/json' \
        -d '{
            "message": "X-Ray here I go....."
        }'
}

function retrieve(){
    echo "Gathering orders..."
    curl https://r89f4mey78.execute-api.eu-west-1.amazonaws.com/dev/orders \
        -H 'cache-control: no-cache' \
        -H 'content-type: application/json'
}

echo "Ha!"
for x in $(seq 1 ${iterations})
    do
        echo "Iteration...${x}"
        add
        retrieve
        sleep 10
    done
brettstack commented 7 years ago

I was unable to reproduce with that, but I was able to reproduce by running the example and:

  1. Reducing the Lambda function's Memory to 704mb and Timeout to 1S
  2. Hit the /users resource - this (usually) succeeds since it's a simple operation
  3. Hit the index / resource - this (usually) fails with "Internal server error" since it's a more complex operation
  4. Repeat steps 2 and 3 and you will see the EADDRINUSE error message in CloudWatch logs.
heitorlessa commented 7 years ago

If that helps @brettstack I used 128MB and happy to share demo code for this too. In my POST my Lambda function is adding an item to a DynamoDB table, a message into SQS queue and making a HTTP call to an API Gateway.

All of this being captured by X-Ray so happy to share data if helpful too.

brettstack commented 7 years ago

This error is a red-herring. I've updated it to tell you something likely went wrong in your previous invocation(s), e.g. an unhandled error in Express, or a Lambda timeout (NOTE: an unhandled error will result in a timeout because no response gets sent, but there are cases where you simply have not allocated a high enough time to live or memory/cpu allocation for it to complete it time).

brettstack commented 7 years ago

I considered changing the socket to be random instead of incrementing, which would mean this message would (almost) never show. However, I think it's more useful to call out that something went wrong in a previous invocation.