Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

DynamoDB write EPROTO #862

Closed
phsstory opened this issue Jan 5, 2016 · 149 comments
Closed

DynamoDB write EPROTO #862

phsstory opened this issue Jan 5, 2016 · 149 comments
Labels
third-party This issue is related to third-party libraries or applications.

Comments

@phsstory
Copy link

phsstory commented Jan 5, 2016

Node: 4.2.1
AWS-SDK: 2.1.21
From the logs

{ [NetworkingError: write EPROTO]
  message: 'write EPROTO',
  code: 'NetworkingError',
  errno: 'EPROTO',
  syscall: 'write',
  address: undefined,
  region: 'us-east-1',
  hostname: 'dynamodb.us-east-1.amazonaws.com',
  retryable: true,
  time: Tue Jan 05 2016 17:35:05 GMT+0000 (UTC) } 'Error: write EPROTO\n    at Object.exports._errnoException (util.js:874:11)\n    at exports._exceptionWithHostPort (util.js:897:20)\n    at WriteWrap.afterWrite (net.js:763:14)'

Other server on node 0.12.0 does not have this issue.

If issue with current node and sdk, please follow up on AWS forums
https://forums.aws.amazon.com/thread.jspa?messageID=694520&#694520
https://forums.aws.amazon.com/thread.jspa?messageID=693172#693172


Summary (as of 2016/05/13):

Edit: potential keepAlive errors noted.
Edit: Removed untested status, see @southpolesteve's comment

new AWS.DynamoDB({
  httpOptions: {
    agent: new https.Agent({
      rejectUnauthorized: true,
      keepAlive: true,                // workaround part i. 
                                      // shouldn't be used in AWS Lambda functions
      secureProtocol: "TLSv1_method", // workaround part ii.
      ciphers: "ALL"                  // workaround part ii.
    })
  }
});

Server side mitigation (2016/06/29):

DynamoDB confirmed for me that they have updated to support TLS1.2 everywhere. We're still going to keep this issue open because we want to see the openSSL fix merged as well. That said, the root cause of this issue has been mitigated and users should no longer be affected by this bug.

If you do encounter this error after removing your workarounds, please post here. Knowing the version of node.js, the sdk, and the region the issue was encountered in would be helpful if you see this error again.
@chrisradek's comment

@chrisradek
Copy link
Contributor

@phsstory
How often are you seeing this sort of error? Can you provide any information, like a code snippet that reproduces the issue, or details on where your client is running (i.e. on EC2, local machine, etc)?

Is this only happening with dynamodb or other services as well? Do you have any httpOptions set for the SDK?

@phsstory
Copy link
Author

phsstory commented Jan 5, 2016

Error is intermittent. S3, DynamoDB and STS are only services used, only calls to DynamoDB reported issues. Did not show in logs on a 0.12.0 node server; however the load on that server is significantly less so no calls could have happened during the error windows.

37 Failures 0 Success
Start: Mon Dec 28 2015 21:01:05 GMT+0000 (UTC)
End: Mon Dec 28 2015 21:01:11 GMT+0000 (UTC)
...
hundreds of successes
...
48 Failures 12 Success
Start: Mon Dec 28 2015 21:02:25 GMT+0000 (UTC)
End: Mon Dec 28 2015 21:02:30 GMT+0000 (UTC)
... pattern continues.

Mon Dec 28 2015 21:02:42 GMT+0000 (UTC)
Mon Dec 28 2015 21:02:47 GMT+0000 (UTC)

Mon Dec 28 2015 21:03:13 GMT+0000 (UTC)
Mon Dec 28 2015 21:03:19 GMT+0000 (UTC)

Mon Dec 28 2015 21:03:19 GMT+0000 (UTC)
Mon Dec 28 2015 21:03:29 GMT+0000 (UTC)

Mon Dec 28 2015 21:03:29 GMT+0000 (UTC)
Mon Dec 28 2015 21:03:36 GMT+0000 (UTC)
...
Tue Jan 05 2016 17:33:51 GMT+0000 (UTC)
Tue Jan 05 2016 17:33:53 GMT+0000 (UTC)

Tue Jan 05 2016 17:34:21 GMT+0000 (UTC)
Tue Jan 05 2016 17:41:18 GMT+0000 (UTC)

Our client is running on ElasticBeanstalk but there are reports of this error in other environments (see links to amazon forums)

function awslog(namespace) {
    var debug = require('debug')(namespace);
    return { log: function (msg) { debug(msg); } };
}
var _db = new AWS.DynamoDB({
  credentials: new AWS.TemporaryCredentials({
    RoleArn: REDACTED
    logger: awslog('phDev:phUser:STS')
  }),
  logger: awslog('phDev:phUser:DynamoDB')
});

_db.query(params, function (err, data) {
  if (err) { // Error is defined, app fails, err object failed to log }
  /*
    at User.<anonymous> (REDACTED)
    at Request.<anonymous> (/var/app/current/node_modules/aws-sdk/lib/request.js:350:18)
    at Request.callListeners (/var/app/current/node_modules/aws-sdk/lib/sequential_executor.js:100:18)
    at Request.emit (/var/app/current/node_modules/aws-sdk/lib/sequential_executor.js:77:10)
    at Request.emit (/var/app/current/node_modules/aws-sdk/lib/request.js:604:14)
    at Request.transition (/var/app/current/node_modules/aws-sdk/lib/request.js:21:12)
    at AcceptorStateMachine.runTo (/var/app/current/node_modules/aws-sdk/lib/state_machine.js:14:12)
    at /var/app/current/node_modules/aws-sdk/lib/state_machine.js:26:10
    at Request.<anonymous> (/var/app/current/node_modules/aws-sdk/lib/request.js:22:9)
    at Request.<anonymous> (/var/app/current/node_modules/aws-sdk/lib/request.js:606:12)
*/
}

This is close to the extent of information I am able to provide on a public location.

@chrisradek
Copy link
Contributor

@phsstory
Thanks for the information you've provided, I'll try to reproduce the issue on my end as well. In the meantime, one suggestion I found for ERPROTO errors was to set keepAlive on the http agent. The reasoning was that using SSL means each connection requires more work, so using keepAlive to reuse existing connections cuts down on that. You might want to give that a try by adding the following to the config passed into new AWS.DynamoDB:

httpOptions: {
  agent: new https.Agent({
    rejectUnauthorized: true,
    keepAlive: true
  })
}

More agent options here: https://nodejs.org/api/http.html#http_new_agent_options

@luizstacio
Copy link

I'm having this same problem.
node: v5.2.0

@phsstory
Copy link
Author

phsstory commented Jan 6, 2016

@chrisradek

as an update, it has been 24hrs since we downgraded node to 0.12.0 with no indication of EPROTO errors, same code and sdk versions. I would guess it has to do with a combination of certain machines behind a load balancer (intermittent with varying time periods among reported users) and some internal deprecated feature of node or one of it's libraries. There is some speculation that it might be related to nodejs/node#2244

Have you had a chance to contact the DynamoDB infrastructure guys to see what might have changed on Dec 28th or if there are any machines/loadbalancers still in the cluster still serving up RC4-SHA?

@natelaws
Copy link

Also got the same error using node v4.1.2. Adding what @chrisradek suggested appears to work for me.

@phsstory
Copy link
Author

from the sounds of it this is a compatibility issue between the sdk/node and the DynamoDB service clusters, keepAlive is only mitigating the chances of connecting to a problematic machine/loadbalancer.

Unfortunately the amazon forums are the worst place to get information about amazon changes/issues since there is never a follow up by the techs.

@chrisradek can you run this through the inter-department channels to see if there are DynamoDB machines/loadbalncers that attempt to TLS negotiate with RC4-SHA?

@chrisradek
Copy link
Contributor

@phsstory
I'll bring this up with the DynamoDB team and report back what I learn.

@chrisradek
Copy link
Contributor

@phsstory
I heard back, and DynamoDB does not make use of RC4.

@awerlang
Copy link

I also have noticed this issue. And because I set keepAlive to true, it was unable to serve any request.

My Beanstalk configuration:

  • 64bit Amazon Linux 2015.09 v2.0.4 running Node.js
  • Node v4.2.1

I was just wondering if we could interfere in choosing the cipher (if that is indeed the case): https://nodejs.org/api/https.html#https_https_request_options_callback

@phsstory
Copy link
Author

@chrisradek That is unfortunate as it would have been a quick diagnosis to the issue.

As a recap:
Does not appear to affect node 0.12
Does affect 4.1, 4.2, 5.2
Errors appear to be grouped in 5s windows.
keepAlive mitigates the error but not believed to fix the problem.

@awerlang
Copy link

It seems to be an issue in node:

nodejs/node#3692

@mhkhung
Copy link

mhkhung commented Jan 20, 2016

It's happening a lot. I am using only Dynamo with latest node 5.4.0 and is having the problem.

@tristanls
Copy link
Contributor

Continuing to observe this issue on Node.js v5.4.0, setting keepAlive does not prevent this from occurring:

new AWS.DynamoDB(
{
    httpOptions: {
        agent: new https.Agent(
        {
            rejectUnauthorized: true,
            keepAlive: true
        })
    }
});
{
    "target": {
        "module": "aws-sdk",
        "version": "2.2.28",
        "export": "DynamoDB",
        "method": "putItem",
        "args": [
            {
                "Item": "*REDACTED*"
            }
        ]
    },
    "type": "log",
    "level": "error",
    "message": "failed to put item in DynamoDB",
    "error": {
        "message": "write EPROTO",
        "code": "NetworkingError",
        "errno": "EPROTO",
        "syscall": "write",
        "region": "us-east-1",
        "hostname": "dynamodb.us-east-1.amazonaws.com",
        "retryable": true,
        "time": "2016-01-23T02:56:44.705Z"
    },
    "stack": "Error: write EPROTO\n    at Object.exports._errnoException (util.js:856:11)\n    at exports._exceptionWithHostPort (util.js:879:20)\n    at WriteWrap.afterWrite (net.js:763:14)",
    "timestamp": "2016-01-23T02:56:44.706Z"
}

@phsstory
Copy link
Author

@chrisradek I still believe this to be an issue with deprecated node functionality and a portion, likely small, of the DynamoDB stack using said encryption.

Since we have no knowledge of the DynamoDB stack architecture, I can only take make a wild guess. based on the time windows and the mitigation effect of keepalive, we will find it in the mechanism that handles dynamic growth while maintaining network connectivity for clients connecting during those brief periods.

In the interim, can you get a list of the available cyphers and options from DynamoDB so we can correlate them with the supported options in node to restrict the negotiation as mentioned by @awerlang ?

@tristanls
Copy link
Contributor

I did look into ciphers by refreshing this over and over again (trying to catch different IPs) https://www.ssllabs.com/ssltest/analyze.html?d=dynamodb.us-east-1.amazonaws.com&latest

From my most recent run (54.239.20.144, 54.239.16.203):

TLS 1.0 only

TLS_RSA_WITH_AES_128_CBC_SHA (0x2f) 128
TLS_RSA_WITH_AES_256_CBC_SHA (0x35) 256
TLS_RSA_WITH_3DES_EDE_CBC_SHA (0xa) 112

@tristanls
Copy link
Contributor

I forgot an additional detail that I haven't seen reported yet. I happen to be measuring the latency of the HTTPS calls to DynamoDB using aws-sdk, and when I get an EPROTO error back, the latency (except in one case) is 25 seconds, more precisely, most of it is between 25600 and 25700, some between 25700 and 25800 milliseconds. (the one exception was 12915 milliseconds ¯\_(ツ)_/¯)

(edit: there was no exception to 25 seconds for EPROTO error, my initial search was too inclusive)

edit 2: Looks like 25 seconds comes from DynamoDB aws-sdk retry policy https://github.com/aws/aws-sdk-js/blob/master/lib/services/dynamodb.js#L48 which would add 25550 milliseconds of delays across total of 11 attempts it makes

@phsstory
Copy link
Author

Thanks @tristanls,

This is starting to have the signs of a load balancer shuffle with connections being sent to a machine not quite ready to handle load and dumping the connection prematurely causing the TLS endpoint to bail on the client connection mid buffer. The odd ball is node 0.12 not having any issue. I wonder if 0.12 was less strict on this particular protocol error or silently ignored it.

@phsstory
Copy link
Author

@chrisradek,

you might want to see if the DynamoDB dev env shows this same behavior with one of the reported node version under heavy load by multiple simulated accounts. You might be able to capture the connection and rebuild for protocol analysis.

@tristanls
Copy link
Contributor

@phsstory looking at where EPROTO can come out of based on comments in nodejs/node#3692 the paths look (to my untrained eye) quite different.

latest: https://github.com/nodejs/node/blob/master/src/tls_wrap.cc#L593
0.12: https://github.com/nodejs/node/blob/v0.12.7-release/src/tls_wrap.cc#L607

@phsstory
Copy link
Author

@tristanls 0.12 doesn't throw EPROTO for this issue, it continues on without issue or degraded performance.

We had to downgrade our production servers until this issue can be resolved.

@tristanls
Copy link
Contributor

@phsstory understood. I am working on the assumption that this is what's causing the EPROTO issue in v5.5.0 and latest: https://github.com/nodejs/node/blob/master/src/tls_wrap.cc#L592-L593. This code path for throwing EPROTO doesn't seem to exist in 0.12, which could explain the difference.

@tristanls
Copy link
Contributor

Well, I haven't reproduced the problem (because in the stack below v0.12.7 also fails with EPROTO) error. But I'm not gonna be able to get back to this for a bit so wanted to post findings so far.

The c-server below is compiled using gcc server.c -o c-server.
The node-patched is node with this patch nodejs/node#3692 (comment) included (I think... it compiled, and it's the main executable that got built).
node is vanilla v5.5.0.

I'm hoping to keep iterating on server.c until v0.12.7 passes and v5.5.0 fails in order to maybe reproduce eventually. I'm guessing next step will be to include SSL along the lines of http://stackoverflow.com/questions/7698488/turn-a-simple-socket-into-an-ssl-socket

In the meantime, I dumped the existing setup to docker hub https://hub.docker.com/r/tristanls/eproto-plus-patched-node/

[root@8fec5290e6f7 patched]# ll 
total 18740
-rwxr-xr-x 1 root root     9244 Jan 25 03:16 c-server
-rw-r--r-- 1 root root      259 Jan 25 03:16 client.js
-rwxr-xr-x 1 root root 19161989 Jan 24 00:34 node-patched
-rw-r--r-- 1 root root     1576 Jan 25 02:55 server.c
drwxr-xr-x 6 root root     4096 Jan 25 03:16 v0.12.7
[root@8fec5290e6f7 patched]# v0.12.7/bin/node -v
v0.12.7
[root@8fec5290e6f7 patched]# node -v
v5.5.0
[root@8fec5290e6f7 patched]# ./node-patched -v
v5.5.0
[root@8fec5290e6f7 patched]# cat client.js 
"use strict";

var https = require("https");
var options = {
    port: 443
};
var req = https.request(options, function(res)
{
    console.log(res.statusCode);
    res.on("data", function(data)
    {
        process.stdout.write(data);
    });
});
req.end();
[root@8fec5290e6f7 patched]# cat server.c 
/* A simple server in the internet domain using TCP
   The port number is passed as an argument */
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>
#include <sys/types.h>
#include <sys/socket.h>
#include <netinet/in.h>

void error(const char *msg)
{
    perror(msg);
    exit(1);
}

int main(int argc, char *argv[])
{
     int sockfd, newsockfd, portno;
     socklen_t clilen;
     char buffer[256];
     struct sockaddr_in serv_addr, cli_addr;
     int n;
     if (argc < 2) {
         fprintf(stderr,"ERROR, no port provided\n");
         exit(1);
     }
     sockfd = socket(AF_INET, SOCK_STREAM, 0);
     if (sockfd < 0)
        error("ERROR opening socket");
     bzero((char *) &serv_addr, sizeof(serv_addr));
     portno = atoi(argv[1]);
     serv_addr.sin_family = AF_INET;
     serv_addr.sin_addr.s_addr = INADDR_ANY;
     serv_addr.sin_port = htons(portno);
     if (bind(sockfd, (struct sockaddr *) &serv_addr,
              sizeof(serv_addr)) < 0)
              error("ERROR on binding");
     listen(sockfd,5);
     clilen = sizeof(cli_addr);
     newsockfd = accept(sockfd,
                 (struct sockaddr *) &cli_addr,
                 &clilen);
     if (newsockfd < 0)
          error("ERROR on accept");
     bzero(buffer,256);
     n = read(newsockfd,buffer,255);
     if (n < 0) error("ERROR reading from socket");
     printf("Here is the message: %s\n",buffer);
     n = write(newsockfd,"I got your message",18);
     if (n < 0) error("ERROR writing to socket");
     close(newsockfd);
     close(sockfd);
     return 0;
}
[root@8fec5290e6f7 patched]# ./c-server 443 &
[1] 20
[root@8fec5290e6f7 patched]# v0.12.7/bin/node client.js 
Here is the message: %
events.js:85
      throw er; // Unhandled 'error' event
            ^
Error: write EPROTO 139816494778176:error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown protocol:../deps/openssl/openssl/ssl/s23_clnt.c:782:

    at exports._errnoException (util.js:746:11)
    at WriteWrap.afterWrite (net.js:775:14)
[1]+  Done                    ./c-server 443
[root@8fec5290e6f7 patched]# ./c-server 443 &
[1] 26
[root@8fec5290e6f7 patched]# node client.js 
Here is the message: 
events.js:154
      throw er; // Unhandled 'error' event
      ^

Error: write EPROTO
    at Object.exports._errnoException (util.js:856:11)
    at exports._exceptionWithHostPort (util.js:879:20)
    at WriteWrap.afterWrite (net.js:763:14)
[1]+  Done                    ./c-server 443
[root@8fec5290e6f7 patched]# ./c-server 443 &
[1] 36
[root@8fec5290e6f7 patched]# ./node-patched client.js 
Here is the message: 
events.js:154
      throw er; // Unhandled 'error' event
      ^

Error: write EPROTO
    at Object.exports._errnoException (util.js:856:11)
    at exports._exceptionWithHostPort (util.js:879:20)
    at WriteWrap.afterWrite (net.js:763:14)
[1]+  Done                    ./c-server 443

@laurihosio
Copy link

This also started happening in our ELB environments after updating nodejs from 0.12.9 to 4.2.3

{ [NetworkingError: write EPROTO]
message: 'write EPROTO',
code: 'NetworkingError',
errno: 'EPROTO',
syscall: 'write',
address: undefined,
region: 'us-east-1',
hostname: 'dynamodb.us-east-1.amazonaws.com',
retryable: true,

time: Mon Jan 25 2016 16:29:07 GMT+0000 (UTC) } Error
at /var/app/current/shared/data.js:333:16 (error handler throwing it)
at Response. (/var/app/current/shared/dynamodb.js:272:4)
at Request. (/var/app/current/node_modules/aws-sdk/lib/request.js:354:18)
at Request.callListeners (/var/app/current/node_modules/aws-sdk/lib/sequential_executor.js:105:20)
at Request.emit (/var/app/current/node_modules/aws-sdk/lib/sequential_executor.js:77:10)
at Request.emit (/var/app/current/node_modules/aws-sdk/lib/request.js:596:14)
at Request.transition (/var/app/current/node_modules/aws-sdk/lib/request.js:21:10)
at AcceptorStateMachine.runTo (/var/app/current/node_modules/aws-sdk/lib/state_machine.js:14:12)
at /var/app/current/node_modules/aws-sdk/lib/state_machine.js:26:10
at Request. (/var/app/current/node_modules/aws-sdk/lib/request.js:37:9)

@koresar
Copy link

koresar commented Jul 14, 2016

I experience the same problem with DynamoDBLocal. No workarounds from above help.
I wonder if anyone has a solution for the locally running Dynamo?
Couldn't google it out.

Thanks people.

@re1ro
Copy link

re1ro commented Jul 14, 2016

@koresar how do you connect to local?

@koresar
Copy link

koresar commented Jul 15, 2016

const aws = require('aws-sdk');

const dynamo = new aws.DynamoDB({
    region: 'foo-west-1',
    apiVersion: '2012-08-10',
    accessKeyId: 'bar',
    secretAccessKey: 'baz'
    endpoint: new aws.Endpoint('localhost:8000'), // tried all kinds of uris
    httpOptions: {
        agent: new https.Agent({ // tried all combinations
            rejectUnauthorized: true,
            keepAlive: true,
            secureProtocol: 'TLSv1_method', // tried all the openssl supported methods
            ciphers: 'ALL'
        })
    }
});

dynamo.describeTable({TableName: 'my-table'}, callback); // get error after a timeout

Error:

  [NetworkingError: write EPROTO 140735265157120:error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number:../deps/openssl/openssl/ssl/s3_pkt.c:362:
   ]
     message: 'write EPROTO 140735265157120:error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number:../deps/openssl/openssl/ssl/s3_pkt.c:362:\n',
     code: 'NetworkingError',
     errno: 'EPROTO',
     syscall: 'write',
     region: 'foo-west-1',
     hostname: 'localhost',
     retryable: true,
     time: Fri Jul 15 2016 10:00:08 GMT+1000 (AEST)

However, there is a workaround - use non-encrypted connection.
I.e. use http.Agent instead of https.Agent.

Problem solved (until you need TLS).

@re1ro
Copy link

re1ro commented Jul 15, 2016

@koresar DynamoDBLocal listens for HTTP on port 8000
all this https.Agent fix was needed for actual AWS DynamoDB services, not for local. And seems like problem is already fixed on their side.
For local you should use just this

const dynamo = new aws.DynamoDB({
    region: 'foo-west-1',
    apiVersion: '2012-08-10',
    accessKeyId: 'bar',
    secretAccessKey: 'baz',
    endpoint: 'http://localhost:8000'
});

@bradennapier
Copy link

Has anyone noticed that while the issue is "fixed" with dynamo - it is still there for all the other amazon services? Namely if i want to invoke Lambdas from within Lambda....?

@chrisradek
Copy link
Contributor

@bradennapier
Have you experienced this issue with other services? We haven't received any reports about getting this error when invoking Lambda functions from within Lambda.

The issue was specific to DynamoDB, since their servers were configured in such a way that they were affected by a bug in openssl.

If you are seeing this issue with another service, please let us know.

@bradennapier
Copy link

Yes I am currently experiencing the problem on one function. I am only assuming it is due to Lambda because allm y other functions appear to be fine. I am not sure if this is the exact same issue but it always shows in the same way - functions start with a second or so left and I get charged the entire timeout period for every call until I re-upload the function.

2016-07-22T01:53:46.098Z    1aedc582-4faf-11e6-8110-8350aa252064    Starting System Info 
2016-07-22T01:53:46.098Z    1aedc582-4faf-11e6-8110-8350aa252064    Remaining Time: 1016 
2016-07-22T01:53:46.150Z    1aedc582-4faf-11e6-8110-8350aa252064    Correct Keys

My functions getting called with 1 second to spare... 10 second function window... you charge me for it all... 

2016-07-22T01:52:51.150Z    f9c946bb-4fae-11e6-a4b6-ff7eb659c9ce    Starting System Info 
2016-07-22T01:52:51.150Z    f9c946bb-4fae-11e6-a4b6-ff7eb659c9ce    Remaining Time: 354 
2016-07-22T01:52:51.211Z    f9c946bb-4fae-11e6-a4b6-ff7eb659c9ce    Correct Keys 
2016-07-22T01:52:51.293Z    f9c946bb-4fae-11e6-a4b6-ff7eb659c9ce    Token is Valid Current: 1469152371251 Expires 1469757102163

2016-07-22T01:52:59.988Z    ffdf5964-4fae-11e6-9319-61a75113d4f2    Starting System Info 
2016-07-22T01:53:00.008Z    ffdf5964-4fae-11e6-9319-61a75113d4f2    Remaining Time: 1710 
2016-07-22T01:53:00.029Z    ffdf5964-4fae-11e6-9319-61a75113d4f2    Correct Keys 
2016-07-22T01:53:00.070Z    ffdf5964-4fae-11e6-9319-61a75113d4f2    Token is Valid Current: 1469152380068 Expires 1469757097928 
2016-07-22T01:53:00.071Z    ffdf5964-4fae-11e6-9319-61a75113d4f2    The Calls Required Parameters are: 

TART RequestId: 07ef8f10-4faf-11e6-bc0e-7f5932792b4b Version: $LATEST 
2016-07-22T01:53:13.949Z    07ef8f10-4faf-11e6-bc0e-7f5932792b4b    Starting System Info 
2016-07-22T01:53:13.991Z    07ef8f10-4faf-11e6-bc0e-7f5932792b4b    Remaining Time: 1253 
2016-07-22T01:53:13.995Z    07ef8f10-4faf-11e6-bc0e-7f5932792b4b    Correct Keys 
2016-07-22T01:53:14.031Z    07ef8f10-4faf-11e6-bc0e-7f5932792b4b    Token is Valid Current: 1469152394030 Expires 1469757105179 
2016-07-22T01:53:14.088Z    07ef8f10-4faf-11e6-bc0e-7f5932792b4b    The Calls Required Parameters are: 
2016-07-22T01:53:14.990Z    07ef8f10-4faf-11e6-bc0e-7f5932792b4b    Received Table Data: Dash_Systems

For example, the above is a function which has 15 second timeout - the first call I make is to log remaining time.

@phsstory
Copy link
Author

That sounds like a timeout issue which is not what we experience with this bug.

Have you tried turning off keepalive?
#862 (comment)

@bradennapier
Copy link

bradennapier commented Jul 27, 2016

@phsstory are you saying to do that for dynamo? My other functions seem fine so I believe this one is due to lambda but i cant be sure - its a simple function so it's fairly annoying

const Doc = documentPromised({
    region: 'us-west-2',
    httpOptions: { agent: new https.Agent({  ciphers: 'ALL', secureProtocol: 'TLSv1_method' }) }
})

So I should turn that into

const Doc = documentPromised({
    region: 'us-west-2',
    httpOptions: { agent: new https.Agent({  keepAlive: false, ciphers: 'ALL', secureProtocol: 'TLSv1_method' }) }
})

in my lambda function?

(FYI Yes I tried without the promised with the same result)

@chrisradek
Copy link
Contributor

@bradennapier
You can actually get rid of the custom https.Agent now.

Am I understanding correctly that your Lambda functions are failing to complete within a given amount of time? Are you getting an error? If you extend your Lambda function to allow it to run longer, do your functions complete?

@benoittgt
Copy link

Hello

Just tried this code with and without the httpOptions

var aws = require('aws-sdk');
var https = require('https');

exports.handler = function(event, context) {
  var dynamo = new aws.DynamoDB({
    region: 'eu-west-1',
    httpOptions: {
      agent: new https.Agent({
        rejectUnauthorized: true,
        keepAlive: false,
        ciphers: 'ALL',
        secureProtocol: 'TLSv1_method'
      })
    }
  });

  dynamo.listTables(function(err, data) {
    console.log('inside listTables');
    if (err)
      console.log(JSON.stringify(err, null, 2));
    else
      console.log(data.TableNames);
  });
};

And I get timeout. No problem locally calling AWS database.

@chrisradek
Copy link
Contributor

Without the httpOptions specified, can you share the exact error you're getting? If it's not the one that's specified at the top of this thread, can you open a new issue?

@re1ro
Copy link

re1ro commented Aug 3, 2016

@benoittgt you need to add maxRetries: 8 to you options. Otherwise DynamoDB client keeps retrying and your lambda exceeds 10 sec timeout and you don't get the real ErrorMessage

 var dynamo = new aws.DynamoDB({
    region: 'eu-west-1',
    maxRetries: 8
  });

PS make sure that you have 10sec timeout for lambda, cuz it's 6sec by default

@chrisradek could you guys put this stuff in Docs everywhere, because people never get real dynamo error messages if error is retry-able. And DynamoDB client has hardcoded retry logic which is not configurable as other AWS-SDK service clients.
I was to determine amount of retries for most common cases
maxRetries: 7 for lambda with timeout 6 sec (default)
maxRetries: 8 for lambda with timeout 10 sec (10 seconds if much better then 6)
maxReties: 12 for lambda with timeout 300 sec (for lambda not behind APIG, like DynamoDB stream worker)

cheers and happy coding

@benoittgt
Copy link

Thanks to both of you for the fast answers.

With :

var aws = require('aws-sdk');
var https = require('https');

exports.handler = function(event, context) {
  var dynamo = new aws.DynamoDB({
    region: 'eu-west-1',
    maxRetries: 8
  });

  dynamo.listTables(function(err, data) {
    console.log('inside listTables');
    if (err)
      console.log(JSON.stringify(err, null, 2));
    else
      console.log(data.TableNames);
  });
};

I get

START RequestId: 6ebafb49-59b1-11e6-b05b-f79f63e71369 Version: $LATEST
END RequestId: 6ebafb49-59b1-11e6-b05b-f79f63e71369
REPORT RequestId: 6ebafb49-59b1-11e6-b05b-f79f63e71369  Duration: 10000.24 ms   Billed Duration: 10000 ms   Memory Size: 128 MB Max Memory Used: 24 MB  
2016-08-03T19:35:38.781Z 6ebafb49-59b1-11e6-b05b-f79f63e71369 Task timed out after 10.00 seconds

@chrisradek
Copy link
Contributor

@benoittgt
Are you using node.js 0.10.x in Lambda?
Your function may also be timing out due to not calling context.succeed and context.fail. Can you replace (or add) those where you've made your console.log calls in your callback function?

@benoittgt
Copy link

benoittgt commented Aug 3, 2016

I did the test with context on both Node version available with the same errors posted on #862 (comment).

var aws = require('aws-sdk');

exports.handler = function(event, context) {
  var dynamo = new aws.DynamoDB({
    region: 'eu-west-1',
    maxRetries: 8
  });

  dynamo.listTables(function(err, data) {
    if (err) {
      context.fail(err.stack)
    } else {
      context.succeed('Function Finished! Data :' + data.TableNames);
    }
  });
};

@chrisradek
Copy link
Contributor

@benoittgt
I created #1086 so we can discuss your issue there. It's not the same error as reported in this thread so I don't want to continue it here.

@jeskew
Copy link
Contributor

jeskew commented Mar 4, 2017

The NodeJS commit referenced in #862 (comment) has been present in all releases since 6.0.0, and DynamoDB has updated their servers to use TLS 1.2 everywhere, so I don't believe customers are continuing to see this issue.

@jeskew jeskew closed this as completed Mar 4, 2017
tobysimone pushed a commit to tobysimone/nodejs-ebay-api that referenced this issue Dec 7, 2017
As of 3/22/2016, the eBay API has several servers that can only
negotiate TLS v1.0 sessions, and several servers that can negotiate TLS
v1.0, v1.1 and v1.2. Node/OpenSSL get confused by this, and occasionally
attempt to parse a v1.2 response using TLS v1.0 and vice versa. The
error you get back from the request looks something like this:

```
{ [Error: write EPROTO 140113357338496:error:1408F10B:SSL
routines:SSL3_GET_RECORD:wrong version number:../deps/openssl/openssl/ssl/s3_pkt.c:362:
] code: 'EPROTO',
errno: 'EPROTO',
syscall: 'write' }
```

As far as I can tell, this isn't patched yet, in Node or OpenSSL. But
setting the following options forces all connections to be negotiated
with TLS v1.0, effectively fixing the issue.

More reading:

aws/aws-sdk-js#862
nodejs/node#3692
https://www.ssllabs.com/ssltest/analyze.html?d=api.ebay.com

If you know anyone at eBay, please tell them it's a) unacceptable to
have servers that can only negotiate TLS v1.0, and b) unacceptable to
have a SSL certificate that was signed with SHA1, and they should
upgrade both things.
@srchase srchase added third-party This issue is related to third-party libraries or applications. and removed third-party labels Jan 4, 2019
@lock
Copy link

lock bot commented Sep 28, 2019

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs and link to relevant comments in this thread.

@lock lock bot locked as resolved and limited conversation to collaborators Sep 28, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
third-party This issue is related to third-party libraries or applications.
Projects
None yet
Development

No branches or pull requests