Sam local with NodeJS - where does request spend so much time

Asked Feb 04 '20 at 20:24

Active Feb 07 '20 at 19:31

Viewed 287 times

I have written a NodeJS lambda function and I am testing it locally with sam local. I have noticed the browser takes much more time to download it than I can see the lambda execution from the logs. Chrome shows that it waited 6,13 seconds before the server responded.

2020-02-04 21:02:18 127.0.0.1 - - [04/Feb/2020 21:02:18] "GET /v1/verify/Yk6QwCF1 HTTP/1.1" 502 -
Invoking src/handlers/users/verifyUser.handler (nodejs10.x)
Fetching lambci/lambda:nodejs10.x Docker container image......
Mounting C:\dev\mezinamiridici\infrastructure as /var/task:ro,delegated inside runtime container
?[32mREPORT RequestId: 56060b6c-2bef-1241-03a4-fb2fca321096     Init Duration: 2238.80 ms       
Duration: 127.36 ms     Billed Duration: 200 ms Memory Size: 128 MB     Max Memory Used: 59 MB  ?[0m
2020-02-04 21:03:10 127.0.0.1 - - [04/Feb/2020 21:03:10] "GET /v1/verify/Yk6QwCF1 HTTP/1.1" 403 -

It should be some 2,5 seconds. Where are the remaining almost 4 seconds spent?

The source code is there: https://github.com/literakl/mezinamiridici/blob/master/infrastructure/src/handlers/users/verifyUser.js

asked Feb 04 '20 at 20:24

Leos Literak

8,805
19
81
156

1

Finding: sam local start-api --skip-pull-image will save two seconds .. See https://github.com/awslabs/aws-sam-cli/issues/239. But I am still at 4 seconds – Leos Literak Feb 04 '20 at 20:37
Where is your database? – Jason Wadsworth Feb 04 '20 at 20:39
Localhost. I can see that the lambda execution is under 200 ms. – Leos Literak Feb 04 '20 at 21:05
Can you add the `--debug` option and have a look where the logs are "hanging" when waiting for the request to respond? Does this also happen when you consecutively request your function or does it only happen for the first request? – s.hesse Feb 05 '20 at 08:25
Thanks for the tip, I will try. Yes, it happens even if I run it again within few seconds. The time is the same. – Leos Literak Feb 05 '20 at 09:51
Debug does not show the time :-( I submitted an enhancement https://github.com/awslabs/aws-sam-cli/issues/1773 – Leos Literak Feb 05 '20 at 17:47
Does it fetch the docker image in every request? That's weird. – Noel Llevares Feb 12 '20 at 02:39
Network latency? Can you please try the same code with some other ISP? – Gandalf the White Feb 13 '20 at 07:15
Network latency on 127.0.0.1 should be 0. – Leos Literak Feb 13 '20 at 09:54
Are you running the command through any NICs or switches? – Vendetta Feb 14 '20 at 16:38
No, it is plain localhost. – Leos Literak Mar 02 '20 at 09:08

Sam local with NodeJS - where does request spend so much time

0 Answers0