API Gateway responding with a status of 0, Integration latency 10000ms

Question

Here's the error I got back from my API Gateway autogenerated javascript SDK.

{
    "data": "",
    "status": 0,
    "statusText": "",
    "headers": {

    },
    "config": {
        "method": "POST",
        "headers": {
            "Content-Type": "application/json",
            "Accept": "application/json",
            "x-amz-date": "20180127T231842Z",
            "Authorization": "AWS4-HMAC-SHA256 Credential=.....",
            "x-amz-security-token": "....."
        },
        "timeout": 0,
        "transformRequest": [null],
        "transformResponse": [null],
        "url": "https://somevalues.execute-api.us-west-2.amazonaws.com/env/some/path",
        "data": "{\"startDay\":0,\"endDay\":1}"
    }
}

I've looked through my cloudwatch logs, and the call succeeded. I have API gateway tied up to AWS lambda as a serverless function setup.

I've never seen these types of errors, but today I got 5 of them. Subsequent calls all worked.

Edit: Could this be related to CORS settings? Every once in a while API Gateway seems to hiccup and not send back the appropriate CORS. It might be when the function is cold maybe? I'm not sure...

Edit 2: I just verified--all of my OPTIONS endpoints (which is what's used for CORS) do NOT require an auth or api key. So I don't think it's that.

Edit 4: Edit 3 was wrong, I was hitting the wrong endpoint. Hitting my API OPTIONS endpoints using curl works properly.

Edit 5: Looking at the API Gateway logs in cloudwatch, here's what they look like... completely lost at this point.

[32m/aws/lambda/supercoolsoftware-prod-createInviteCode[0m [36m2018/02/26/[$LATEST]8578bb59ab0538558fabef7bd1f484a2[0m START RequestId: e3g4f130-1b35-11e8-b0cf-e7f75f2e4dc1 Version: $LATEST
[32m/aws/lambda/supercoolsoftware-prod-createInviteCode[0m [36m2018/02/26/[$LATEST]8578bb59ab0538558fabef7bd1f484a2[0m END RequestId: e3g4f130-1b35-11e8-b0cf-e7f75f2e4dc1
[32m/aws/lambda/supercoolsoftware-prod-createInviteCode[0m [36m2018/02/26/[$LATEST]8578bb59ab0538558fabef7bd1f484a2[0m REPORT RequestId: e3g4f130-1b35-11e8-b0cf-e7f75f2e4dc1   Duration: 10007.96 ms   Billed Duration: 10000 ms   Memory Size: 128 MB Max Memory Used: 51 MB
[32m/aws/lambda/supercoolsoftware-prod-createInviteCode[0m [36m2018/02/26/[$LATEST]8578bb59ab0538558fabef7bd1f484a2[0m 2018-02-26T20:44:58.994Z e3g4f130-1b35-11e8-b0cf-e7f75f2e4dc1 Task timed out after 10.01 seconds

Edit 6: It's also showing an integration latency of 10000ms....

[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Verifying Usage Plan for request: e2f406ec-1b35-11e8-bce8-e3c6368e1bfc. API Key:  API Stage: xxxxxxxxxx/prod
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) API Key  authorized because method 'POST /accounts/inviteCode' does not require API Key. Request will not contribute to throttle or quota limits
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Usage Plan check succeeded for API Key  and API Stage xxxxxxxxxx/prod
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Starting execution for request: e2f406ec-1b35-11e8-bce8-e3c6368e1bfc
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) HTTP Method: POST, Resource Path: /accounts/inviteCode
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Method request path: {}
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Method request query string: {}
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Method request headers: {Accept=application/json, x-amz-date=20180226T204447Z, CloudFront-Viewer-Country=US, CloudFront-Forwarded-Proto=https, CloudFront-Is-Tablet-Viewer=false, origin=https://app.supercoolsoftware.io, CloudFront-Is-Mobile-Viewer=false, Referer=https://app.supercoolsoftware.io/devices, User-Agent=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.167 Safari/537.36, X-Forwarded-Proto=https, CloudFront-Is-SmartTV-Viewer=false, Host=xxxxxxxxxx.execute-api.us-west-2.amazonaws.com, Accept-Encoding=gzip, deflate, br, dnt=1, x-amz-security-token=FQoDYXdzEK7//////////wEaDFrfZM8Y6J3xvLiS2iKTBF5YIv8VFsraozz/AxRzj10S9RzrOoJTswlhoOfX/gfGYPWP5PNQ1ue7IHEUeUpm+ewB5wANsbydmqGQzVCCvIZkYq+/1X0Iqr74rFuUWBO8ATrKtXBz7zJzpmLtXaOaIzwlFwq/6cKvh4r8HLvSjxBAG4H+ayyUU1IDKmUKAVtpCDvk9FUJM7D5zm4Wlt/yu8/dc3F4a8ID0it93GTQSSi/1YaDmGrkEJ3ySxxE0O0TAZzV50Yprj2gkOX4zNuPsQfWGenILaAog6FLw4asv1J+lE6zKgJtpSiYXyASf54jWnUT4VSiuHL2zU0p1B3tn/wkLF14dCS/IhzAtBgxpqGcRiqy6S05l3MsXJl3WHxMt1iSu5yNLLy2wjlg9j2BoEs18ravB [TRUNCATED]
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Method request body before transformations: {"deviceType":"USER","deviceName":"Me"}
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Endpoint request URI: https://lambda.us-west-2.amazonaws.com/2015-03-31/functions/arn:aws:lambda:us-west-2:122312312312:function:supercoolsoftware-prod-createInviteCode/invocations
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Endpoint request headers: {x-amzn-lambda-integration-tag=e2f406ec-1b35-11e8-bce8-e3c6368e1bfc, Authorization=*******************************************************************************************************************************************************************************************************************************************************************************************************e57bd5, X-Amz-Date=20180226T204448Z, x-amzn-apigateway-api-id=xxxxxxxxxx, Accept=application/json, User-Agent=AmazonAPIGateway_xxxxxxxxxx, X-Amz-Security-Token=FQoDYXdzEK7//////////wEaDHJUDFmtbGGy6Q/bcyKOBn+NX/e9T3+kv8LYDm//MnuArciU8olgca3VHeUDpqmrYaD7w+RQtnmSVQvZ8VqZw0G13UUxen8Ppageped//Yq3QPOEAjLLPICkaplSQh//iDYHYcjEOcrSY/IdeNelF+npPONj/+8Yfg7CGjYa+CCIdTwlrygtAzucAkzn0VxmmAsnmbcXbw6OMJJKd9Ujz7xIsTGOo3RaBsgGfkxHVA/OtMTNEACCWu2KAus1cFxf+gJxVCS2lb0QxcA7dCqc4NyB9cwJXopG5oQSx1sZ8EbJvNcvvHNgumrxpr2qk5hmIJVVhmdqJ3HdZUd+xePNpwtY/pd84Iy7hyjucVX6RIsxfQOd+TYGrgJMIb4hdpAFXGKXlRLfl7E8Dpp5jpOpVW4uRXOvMGVzncUMfJH6ph/YAVPsKn6F [TRUNCATED]
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Endpoint request body after transformations: {"resource":"/accounts/inviteCode","path":"/accounts/inviteCode","httpMethod":"POST","headers":{"Accept":"application/json","Accept-Encoding":"gzip, deflate, br","Accept-Language":"en-US,en;q=0.9","CloudFront-Forwarded-Proto":"https","CloudFront-Is-Desktop-Viewer":"true","CloudFront-Is-Mobile-Viewer":"false","CloudFront-Is-SmartTV-Viewer":"false","CloudFront-Is-Tablet-Viewer":"false","CloudFront-Viewer-Country":"US","content-type":"application/json","dnt":"1","Host":"xxxxxxxxxx.execute-api.us-west-2.amazonaws.com","origin":"https://app.supercoolsoftware.io","Referer":"https://app.supercoolsoftware.io/devices","User-Agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.167 Safari/537.36","Via":"2.0 cbec82431a010799f206b43dbd0489c3.cloudfront.net (CloudFront)","X-Amz-Cf-Id":"zM1gObCVuZ9UXh_beuWr-o9XomlnGGyYFWEn5HJNGk8cBQOMOSCMEw==","x-amz-date":"20180226T204447Z","x-amz-security-token":"FQoDYXdzEK7//////////wEaDFrfZM8Y6J3xvLiS2iKTBF5YIv8 [TRUNCATED]
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Sending request to https://lambda.us-west-2.amazonaws.com/2015-03-31/functions/arn:aws:lambda:us-west-2:122312312312:function:supercoolsoftware-prod-createInviteCode/invocations
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Received response. Integration latency: 10026 ms
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Endpoint response body before transformations: {"errorMessage":"2018-02-26T20:44:58.994Z e2f4f130-1b35-11e8-b0cf-e7f75f2e4dc1 Task timed out after 10.01 seconds"}
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Endpoint response headers: {X-Amz-Executed-Version=$LATEST, x-amzn-Remapped-Content-Length=0, Connection=keep-alive, x-amzn-RequestId=e2f4f130-1b35-11e8-b0cf-e7f75f2e4dc1, Content-Length=115, X-Amz-Function-Error=Unhandled, Date=Mon, 26 Feb 2018 20:44:58 GMT, X-Amzn-Trace-Id=root=1-5a9471c0-0b361380a48e2bc0743673a5;sampled=0, Content-Type=application/json}
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Execution failed due to configuration error: Malformed Lambda proxy response
[32mAPI-Gateway-Execution-Logs_xxxxxxxxxx/prod[0m [36m69adc1e107f7f7d035d7baf04342e1ca[0m (e2f406ec-1b35-11e8-bce8-e3c6368e1bfc) Method completed with status: 502

Edit 7: Here's how the start of EVERY function I write is...

module.exports.unsubscribeFromDailyEmails = function(event, context, cb) {
  logRequest(event, context);
//more logic

function logRequest(event, context) {
  console.log('event: ' + JSON.stringify(event));
  console.log('context: ' + JSON.stringify(context));
}

I want to emphasize, the logRequest function is NEVER reached in the situation I'm talking about--there are no logs written to cloud watch. And yes, logRequest is the very first thing I do in every function.

Edit 8: I haven't seen this occur in the past week or so... so maybe it was on AWS side and its fixed? I'll update if I find out otherwise.

Edit 9: I have now seen this occur on some other endpoints due to exceptions being thrown and not handled. However, this is not the same scenario as the 10000 integration latency error.

How long does it typically take to process a request? "Cold start" was mentioned, is C# or Java being used? If so, how long does a "cold start" typically take? If it nears 30 seconds (API Gateway limitation) I'd try upping the memory on the Lambda (more memory = more cpu). — Zaxxon, Feb 07 '18 at 16:18
@Zaxxon its nodejs--cold starts only seem to take a couple seconds at most... I can't seem to reproduce it consistently. I'm wondering if it has to do with authentication failure now... maybe my token is expiring and not getting refreshed properly. — CamHart, Feb 08 '18 at 07:03
The issue is with your Lambda timing out not API Gateway. Can you show the relevant parts (e.g. how you use callback) in your handler code? — Noel Llevares, Feb 28 '18 at 22:45
@dashmug I don't believe so... my functions work correctly 99% of the time, there are just these odd ones that don't. However with that being said, I've updated the original question to contain the bits I think you were talking about. — CamHart, Mar 01 '18 at 02:30
Definitely weird. What code do you have outside your Lambda? — Noel Llevares, Mar 01 '18 at 04:07
Can you confirm that your lambda callback is always called to end execution? e.g. Is there a random element to your implementation which may result in no cb()? — Nicholas Sizer, Mar 01 '18 at 04:30
@dashmug requiring a handful of different libraries--stripe, bugsnag, internal dependencies and then a bunch of AWS libraries. But its only ever requiring libraries and I use the serverless framework--so every single one of my functions uses the same exact initialization code. And this error occurs randomly across all of them it appears (not just one function). Not really sure what to make of it. — CamHart, Mar 01 '18 at 04:35
@NicholasSizer Yes I can confirm that the call always calls the cb with the exception of potentially unhandled exceptions. However since I'm not seeing the logRequest logs I doubt that could even be the issue... unless you understand something I dont? — CamHart, Mar 01 '18 at 04:37
Yeah, unhandled exceptions bubble out and end up being logged in Cloudwatch. My thinking was that if cb isn't called, then the lambda execution continues until it hits a timeout; doesn't sound like this is the cause — Nicholas Sizer, Mar 01 '18 at 04:47
Maybe a bug with Lambda. It might resolve itself. Have you tried AWS support? — Noel Llevares, Mar 01 '18 at 12:36
@dashmug No I haven't. I don't have a support plan... I wouldnt hesitate to buy it for a single month--but they dont like that. — CamHart, Mar 01 '18 at 15:46
@CamHart this SO answer just popped up in my side bar, it might be relevant: https://stackoverflow.com/a/43709502/242311 Apparently you can get intermittent API Gateway 502's with Malformed Lambda proxy response if AWS Lambda throttling is occurring... Are you hammering your lambda per-chance? — Nicholas Sizer, Mar 02 '18 at 00:31
@NicholasSizer No throttling occuring... Max simultaneous invocations in the past 7 days has been 15. No throttled requests in the past 7 days. I like the thought though--thanks for thinking. — CamHart, Mar 02 '18 at 05:10
@CamHart I'm experiencing the same issue now, did you find a solution? — Naguib Ihab, Sep 15 '20 at 04:05

score 4 · Answer 1 · answered Feb 11 '18 at 00:19

4

I think you are on the Right track, with the cors please read this it will lay it out nicely for you. Click here

answered Feb 11 '18 at 00:19

Jon Cluff

109
7

I just looked through all of my "Options" endpoints in API gateway (which is what's used for CORS) and none of them require authentication. It does seem very similar to that post, however I don't have any auth set for options. – CamHart Feb 11 '18 at 08:06
Hmmm, I do get a missing authentication token when I hit my OPTIONS endpoint tho.... – CamHart Feb 11 '18 at 08:22
I would suspect not having authentication may be your problem – Jon Cluff Feb 11 '18 at 13:54

score 0 · Answer 2 · answered Mar 06 '18 at 23:49

0

Hope you are referring to custom status code and not http status code. API gateway would give back only a non-zero status code if connection was successful. To isolate the problem, you may remove any custom authorizer you have in this setup. Most of the time rejection status from custom authorizer would be a 403 forbidden status, however here it seems to be different. Also remove any quota based usage that may be setup as per the logs. The absolute number of 10000 seems to me as a configuration in API gateway.

answered Mar 06 '18 at 23:49

Sandeep Nair

357
3
8

That is the exact response object returned through the auto generated api gateway javascript SDK. I could dive into it further I guess to see whats going on... it looks like the autogenerated sdk's use axios under the hood... Problem is I can't successfully duplicate the problem... it's only happening randomly and I'm handling several thousand requests a day. As of late, I haven't seen it occur in the past week.... which is making me think it's AWS's problem. – CamHart Mar 08 '18 at 08:13

API Gateway responding with a status of 0, Integration latency 10000ms

2 Answers2