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

Since Version 2.575.0 - CognitoIdentity.getOpenIdTokenForDeveloperIdentity is too slow #3005

Closed
3 tasks done
khacminh opened this issue Dec 9, 2019 · 33 comments
Closed
3 tasks done
Labels
closed-for-staleness service-api This issue is due to a problem in a service API, not the SDK implementation.

Comments

@khacminh
Copy link

khacminh commented Dec 9, 2019

Confirm by changing [ ] to [x] below to ensure that it's a bug:

Describe the bug

Is the issue in the browser/Node.js?
Node.js

If on Node.js, are you running this on AWS Lambda?
No

Details of the Node.js version
v10.7

SDK version number
v2.585.0

To Reproduce (observed behavior)

Today, I updated aws-sdk on my project from version 2.555.0 to the latest version 2.585.0. Then, I figured out that the function: cognito.getOpenIdTokenForDeveloperIdentity run longer than expected.

  • Before updating, it only took about 200-300ms to get the result
  • After updating, it took about 4-5s to get the result

The following is the code snippet that I use and the the application is running on a EC2 machine.

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

async function getToken(username) {
  const cognito = new Aws.CognitoIdentity({ region: process.env.AWS_REGION });
  const Logins = {
     'my-logins': username
  };

  const result = await cognito.getOpenIdTokenForDeveloperIdentity({
    IdentityPoolId: process.env.IDENTITY_POOL_ID,
    Logins,
    TokenDuration: 20,
  }).promise();

  return result.Token;
}

UPDATE 1

My buddy find out that the problem occurred since version 2.575.0


UPDATE 2 (05 Feb 2020)

  • I executed the script on ubuntu 18.04 machine and it took only 100ms to run the script
  • I installed docker and executed the script on a container that built on the image base mhart/alpine-node:10.7. It took about 5s to run the script
  • The same problem with image base node:12.16.0-alpine3.11
@khacminh khacminh added the bug This issue is a bug. label Dec 9, 2019
@khacminh khacminh changed the title Version 2.585.0 - getOpenIdTokenForDeveloperIdentity is too slow Version 2.585.0 - CognitoIdentity.getOpenIdTokenForDeveloperIdentity is too slow Dec 9, 2019
@ajredniwja
Copy link
Contributor

Hey @khacminh, Thank-you for reaching out to us with your issue.

Can you please provide the logs, to do that you can do something like:

To do you can do something like following:

var cognito = new AWS.CognitoIdentity({logger: console});

@ajredniwja ajredniwja added guidance Question that needs advice or information. response-requested Waiting on additional info and feedback. Will move to \"closing-soon\" in 7 days. and removed bug This issue is a bug. labels Dec 11, 2019
@khacminh
Copy link
Author

khacminh commented Dec 17, 2019

hi @ajredniwja, here is the log that I got

 [AWS cognitoidentity 200 5.272 s 0 retries] getOpenIdTokenForDeveloperIdentity({
   IdentityPoolId: 'my-pool-id',
   Logins: {
     'my-logins': 'xxxxxx'
   },
   TokenDuration: 20
 })

@ajredniwja
Copy link
Contributor

@khacminh, do you get the same output when you run it locally?

@khacminh
Copy link
Author

khacminh commented Jan 2, 2020

@ajredniwja it's only takes over 1 second when I run it from my PC (with Access Key ID and Secret Access Key provided). On the EC2 machine, I attached an IAM role to the machine instead of providing the access keys.

@ajredniwja ajredniwja added service-api This issue is due to a problem in a service API, not the SDK implementation. and removed response-requested Waiting on additional info and feedback. Will move to \"closing-soon\" in 7 days. labels Jan 21, 2020
@ajredniwja
Copy link
Contributor

Hey @khacminh I was not able to reproduce this, is there any additional context you can provide?

@ajredniwja ajredniwja added the response-requested Waiting on additional info and feedback. Will move to \"closing-soon\" in 7 days. label Jan 22, 2020
@khacminh
Copy link
Author

khacminh commented Feb 5, 2020

Hi @ajredniwja ,

I created a new EC2 machine running Ubuntu 18.04 and run the script with node.js 10.7 and as you said, there is no problem with it. It took only 100ms to get the OpenId Token.

Then, I installed docker and run the script inside a container with the image base is mhart/alpine-node:10.7 and it took about 5s to run the script.

@khacminh
Copy link
Author

@ajredniwja

I tried with the base image is the official node:12.16.0-alpine3.11 and met the same problem

@ajredniwja ajredniwja removed the response-requested Waiting on additional info and feedback. Will move to \"closing-soon\" in 7 days. label Feb 14, 2020
@khacminh
Copy link
Author

Hi @ajredniwja

Any update for this issue? Today, I meet the same issue with CognitoIdentityServiceProvider.adminGetUser()

@khacminh khacminh changed the title Version 2.585.0 - CognitoIdentity.getOpenIdTokenForDeveloperIdentity is too slow Since Version 2.575.0 - CognitoIdentity.getOpenIdTokenForDeveloperIdentity is too slow May 12, 2020
@ajredniwja
Copy link
Contributor

Hey @khacminh, I believe the SDK didn't made any major updates, this would be how EC2 is handling things, reached out to the service team, will update you once I hear back from the service team.

@wdittmer-mp
Copy link

For record keeping, possibly same problem for #3223 .

@ajredniwja
Copy link
Contributor

Hey @khacminh and @wdittmer-mp

Can you collect some logs using something like

NODE_DEBUG=cluster,net,http,fs,tls,module,timers node app.js

@ajredniwja ajredniwja added the response-requested Waiting on additional info and feedback. Will move to \"closing-soon\" in 7 days. label May 15, 2020
@wdittmer-mp
Copy link

Here are the logs for both 574 and 575.
574.txt
575.txt

Hope this helps!

@github-actions github-actions bot removed the response-requested Waiting on additional info and feedback. Will move to \"closing-soon\" in 7 days. label May 19, 2020
@wdittmer-mp
Copy link

Hi, any news on this?

@ajredniwja
Copy link
Contributor

Hey @wdittmer-mp sorry for late response, can you try supplying the credentials explicitly so that you don't touch any metadata server, this might not be related to the SDK but how the communication is done with the instance metadata server. Also can you confirm if it is still the case with the latest version of the SDK?

@ajredniwja ajredniwja added the response-requested Waiting on additional info and feedback. Will move to \"closing-soon\" in 7 days. label May 28, 2020
@wdittmer-mp
Copy link

wdittmer-mp commented May 29, 2020

I can try out the latest version of the SDK yes:
With v2.686.0 it is still slow: AWS s3 200 4.294s 0 retries] putObject({
686.txt

I am not sure what you mean with supplying the credentials explicitly? I use the following:

const awsAccessKeyId = process.env.AWS_ACCESS_KEY_ID;
const awsSecretAccessKey = process.env.AWS_SECRET_ACCESS_KEY;
const awsRegion = process.env.AWS_DEFAULT_REGION || 'eu-west-1';
const awsBucketName = 'YOUR_BUCKET_NAME';

const s3Options = {
  accessKeyId: awsAccessKeyId,
  secretAccessKey: awsSecretAccessKey,
  region: awsRegion,
  s3ForcePathStyle: true,
};

I don't know how to be more explicit 😅 .

@github-actions github-actions bot removed the response-requested Waiting on additional info and feedback. Will move to \"closing-soon\" in 7 days. label May 30, 2020
@khacminh
Copy link
Author

khacminh commented May 30, 2020

@ajredniwja

Here is my testing environment:

  • EKS 1.15
  • The worker nodes has attached the IAM role to access the resources
  • Dockerfile:
FROM node:12.16.0-alpine3.11

RUN mkdir -p /opt/app

ARG NODE_ENV=production
ENV NODE_ENV $NODE_ENV

WORKDIR /opt
COPY package.json package-lock.json ./
RUN npm install --only=prod && npm cache clean --force

WORKDIR /opt/app
COPY ./index.js /opt/app

ENV NODE_DEBUG=cluster,net,http,fs,tls,module,timers

CMD [ "node", "index.js" ]
  • app/index.js file:
const Aws = require('aws-sdk');

async function getToken(username) {
  const cognito = new Aws.CognitoIdentity({ region: process.env.AWS_REGION, logger: console });
  const Logins = {
     'my-logins': username
  };

  const result = await cognito.getOpenIdTokenForDeveloperIdentity({
    IdentityPoolId: process.env.IDENTITY_POOL_ID,
    Logins,
    TokenDuration: 20,
  }).promise();

  return result.Token;
}

console.log('================= Start ====================');
getToken('test-username').then(() => {
  console.log('================= Done ====================');
  process.exit(0);
});

Comparing 2.574 and 2.575 logs, the following maybe the one that make the difference

Screen Shot 2020-05-30 at 16 22 37

@ajredniwja ajredniwja added the investigating Issue has been looked at and needs deep dive work by OSDS. label Jun 2, 2020
@wdittmer-mp
Copy link

Hi @ajredniwja, can you share if investigation is still in progress, something has been found or if you require additional info?

@ajredniwja
Copy link
Contributor

Hi @ajredniwja, can you share if investigation is still in progress, something has been found or if you require additional info?

Apologies, I lost track for this issue, I was not able to find any core root cause for it, reaching out to the service team for help, will update you once I hear back from them.

@ajredniwja ajredniwja removed the guidance Question that needs advice or information. label Jul 1, 2020
@wdittmer-mp
Copy link

Hi @ajredniwja, can you share if investigation is still in progress, something has been found or if you require additional info?

Apologies, I lost track for this issue, I was not able to find any core root cause for it, reaching out to the service team for help, will update you once I hear back from them.

Hi, is there any news on this?

@ajredniwja
Copy link
Contributor

Hi @ajredniwja, can you share if investigation is still in progress, something has been found or if you require additional info?

Apologies, I lost track for this issue, I was not able to find any core root cause for it, reaching out to the service team for help, will update you once I hear back from them.

Hi, is there any news on this?

I reached out to the service team, awaited reply from them as the SDK doesn't do anything significantly differently between those versions that could affect this.

@ajredniwja
Copy link
Contributor

ajredniwja commented Aug 6, 2020

Hey @khacminh, @wdittmer-mp, @azimiester

Can you guys try to add the following to your code:

AWS.MetadataService.disableFetchToken = true

https://docs.aws.amazon.com/AWSJavaScriptSDK/latest/AWS/MetadataService.html#disableFetchToken-property

If that doesn't work can you please provide impacted instance id and the time period?

@ajredniwja ajredniwja added response-requested Waiting on additional info and feedback. Will move to \"closing-soon\" in 7 days. and removed investigating Issue has been looked at and needs deep dive work by OSDS. labels Aug 6, 2020
@github-actions
Copy link

This issue has not received a response in 1 week. If you still think there is a problem, please leave a comment to avoid the issue from automatically closing.

@github-actions github-actions bot added the closing-soon This issue will automatically close in 4 days unless further comments are made. label Aug 14, 2020
@khacminh
Copy link
Author

khacminh commented Aug 14, 2020

Hi @ajredniwja ,
I tried with your suggestion but with the same result

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

Aws.MetadataService.disableFetchToken = true;

async function getToken(username) {
  const cognito = new Aws.CognitoIdentity({ region: process.env.AWS_REGION, logger: console });
  const Logins = {
     'my-logins': username
  };

  const result = await cognito.getOpenIdTokenForDeveloperIdentity({
    IdentityPoolId: process.env.IDENTITY_POOL_ID,
    Logins,
    TokenDuration: 20,
  }).promise();

  return result.Token;
}

console.log('================= Start ====================');
getToken('test-username').then(() => {
  console.log('================= Done ====================');
  process.exit(0);
});
[AWS cognitoidentity 200 4.696s 0 retries] getOpenIdTokenForDeveloperIdentity({
  IdentityPoolId: 'us-east-2:xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx',
  Logins: { 'my-logins': 'test-username' },
  TokenDuration: 20
})

I also tried with the aws-sdk version 2.733 and node:12.18.3-alpine3.12, the same result received


2.686.0.log
2.733.0.log

@github-actions github-actions bot removed closing-soon This issue will automatically close in 4 days unless further comments are made. response-requested Waiting on additional info and feedback. Will move to \"closing-soon\" in 7 days. labels Aug 15, 2020
@wdittmer-mp
Copy link

wdittmer-mp commented Aug 26, 2020

Hi @ajredniwja,
Was unavailable for a bit. I tried your suggestion, but I did not see any improvement either.
It still takes 4+ seconds.

[[A[AWS s3 200 4.546s 0 retries] putObject({ Body: <Buffer 7b 22 69 64 22 3a 22 74 65 73 74 49 64 31 22 2c 22 6b 65 79 22 3a 22 76 61 6c 75 65 31 22 2c 22 6b 65 79 32 22 3a 22 6c 6f 6f 6f 6f 6f 6f 6f 6f 6f 6f ... 43 more bytes>, Bucket: 'YOUR_TEST_BUCKET', Key: 'TEST_WRDtestId1.json', ContentType: 'application/json' })

The instance-id should be: i-0bd45f49e548fc04b
Around 14:45 Wed 26 Aug CEST.

The instance will most likely be destroyed tonight to save cost for the test environment.
If you need an instance to be up, I will try to get permission on a different environment.

Kind regards,
Wilfred

@mhassan1
Copy link
Contributor

mhassan1 commented Sep 1, 2020

This appears to be related to IMDSv2 being the default starting with 2.575.0. I can see that with the new fetchMetadataToken method added in that release.

I can reproduce this issue by executing curl -XPUT 'http://169.254.169.254/latest/api/token' -H 'x-aws-ec2-metadata-token-ttl-seconds: 21600' inside a Docker container running in EC2; it never responds. In the SDK, it times out after 1 second, and retries 3 times, which is where the 4 seconds comes from. If I execute that command on the host, it responds immediately.

The reason why IMDSv2 does not work from inside a Docker container is explained here: https://stackoverflow.com/a/62326320/13124514

I've also noticed that setting AWS.MetadataService.disableFetchToken = true doesn't actually modify self.disableFetchToken inside the loadCredentials method, which is why setting it doesn't do anything. If it did set it correctly, that would resolve our issue by keeping us on IMDSv1.

So it seems there are two issues at play:

  • curl -XPUT 'http://169.254.169.254/latest/api/token' from inside a Docker container never responds
  • There is no way to set disableFetchToken = true

EDIT: This is probably unsupported, but it works: AWS.MetadataService.prototype.disableFetchToken = true

@khacminh
Copy link
Author

khacminh commented Sep 1, 2020

Hi @ajredniwja,

I tried @mhassan1 workaround and it does solve the problem. Could you please take a look at @mhassan1 explanation. If it makes sense to you, please escalate the issue as bug.

@wdittmer-mp
Copy link

wdittmer-mp commented Sep 10, 2020

I followed the discussion/links from the stackoverflow of @mhassan1 (thanks!)
In aws/aws-sdk-ruby#2177 they also discuss the relation with running your own kubernetes cluster which we are using. Did not find a definitive solution yet (pinning the SDK I don't like).

@chartrand22 also talks about the IMDSv2 in #3024

@geoffreyrobichaux
Copy link

geoffreyrobichaux commented Jan 27, 2021

I had the same issue happen in the last two weeks. I finally found that I can run this line before calling into AWS resources and it has resolved my issue. This is for sure a hack, but gets past my issue for now.

const AWS = require('aws-sdk')
AWS.config.credentials = new AWS.EC2MetadataCredentials({ disableFetchToken: true });

Keep in mind, this only works in raw javascript, the Typescript definition does not expose access to this property.

@turntayble81
Copy link

I ran into the same issue: calling s3.getObject() on a 33 byte file from within a docker container on an ec2 instance takes about 5 seconds using node aws-sdk v 2.826.0. Disabling the fetch token resolved the issue. I reverted back to aws-sdk v2.574.0 and getObject() was as fast as expected without having to disable the fetch token.

@ghobolds
Copy link

I was having the same issue when upgrading from 2.574.0 to 2.575.0, the S3 upload response time went from 200 ms to 4 seconds. Setting the disableFetchToken to true worked and now the response time is back to 200ms.

@jb00ster
Copy link

Hello,
is this something planned to be fixed in next release,
because this issue is opened since 2019

@augustolima
Copy link

Hello, any updates here?
I've been experiencing something similar nowadays. Mostly related to initiateAuth and signup using CognitoIdentityServiceProvider.

Current version: "aws-sdk": "^2.1064.0"
Node version: "node": "16.13.2"

@github-actions
Copy link

Greetings! We’re closing this issue because it has been open a long time and hasn’t been updated in a while and may not be getting the attention it deserves. We encourage you to check if this is still an issue in the latest release and if you find that this is still a problem, please feel free to comment or open a new issue.

@github-actions github-actions bot added closing-soon This issue will automatically close in 4 days unless further comments are made. closed-for-staleness and removed closing-soon This issue will automatically close in 4 days unless further comments are made. labels Feb 22, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
closed-for-staleness service-api This issue is due to a problem in a service API, not the SDK implementation.
Projects
None yet
Development

No branches or pull requests

9 participants