Bug: `sam local` commands sometimes miss the first few lines of container output
- Dominant language
- Python
- Stars
- 6.7k
- Forks
- 1.2k
- Avg merge
- 1d 10h
- Merged PRs (30d)
- 52
Description
### Description:
When invoking a function, SAM CLI won't always output the full container logs:
>Mounting /home/ec2-user/environment/lambda-nodejs12.x/hello-world as /var/task:ro,delegated inside runtime container
END RequestId: 37988e88-12c7-44be-86ae-787c697dfe8a
REPORT RequestId: 37988e88-12c7-44be-86ae-787c697dfe8a Init Duration: 1.52 ms Duration: 115.42 ms Billed Duration: 116 ms Memory Size: 128 MB Max Memory Used: 128 MB
I would expect to see `START RequestId: 37988e88-12c7-44be-86ae-787c697dfe8a Version: $LATEST` in the output but I do not. **This is important because the AWS Toolkit depends on certain output to know when to attach the debugger**. SAM CLI can miss something like `Debugger listening on ws://0.0.0.0:xxxx/yyyyyyy` which prevents the Toolkit from starting the debugging session.
I'm using `sam local invoke` + `nodejs12.x` though the bug probably applies to different combinations. This seems to primarily affect slower machines (e.g. a Cloud9 t2.micro instance).
### Steps to reproduce:
1. Use a sufficiently slow machine
2. Create a new SAM application (I'm using `nodejs12.x`)
3. Run `sam local invoke`
### Observed result:
> 2022-09-19 21:28:26,497 | Mounting /home/ec2-user/environment/lambda-nodejs12.x/hello-world as /var/task:ro,delegated inside runtime container
2022-09-19 21:28:27,691 | Starting a timer for 3 seconds for function 'HelloWorldFunction'
END RequestId: c7925ba1-16ed-4b95-8ed2-8d3bed436c40
REPORT RequestId: c7925ba1-16ed-4b95-8ed2-8d3bed436c40 Init Duration: 1.52 ms Duration: 285.53 ms Billed Duration: 286 ms Memory Size: 128 MB Max Memory Used: 128 MB
### Expected result:
> 2022-09-19 21:28:26,497 | Mounting /home/ec2-user/environment/lambda-nodejs12.x/hello-world as /var/task:ro,delegated inside runtime container
2022-09-19 21:28:27,691 | Starting a timer for 3 seconds for function 'HelloWorldFunction'
START RequestId: c7925ba1-16ed-4b95-8ed2-8d3bed436c40 Version: $LATEST
END RequestId: c7925ba1-16ed-4b95-8ed2-8d3bed436c40
REPORT RequestId: c7925ba1-16ed-4b95-8ed2-8d3bed436c40 Init Duration: 1.52 ms Duration: 285.53 ms Billed Duration: 286 ms Memory Size: 128 MB Max Memory Used: 128 MB
### Additional environment details (Ex: Windows, Mac, Amazon Linux etc)
1. OS: Amazon Linux
4. `sam --version`: 1.57.0
5. AWS region: N/A
Contributor guide
Research direction
Reproduce the issue with `sam local invoke --debug` on a slow machine using the `nodejs12.x` runtime, and compare the observed and expected container output. Trace how `sam local` captures and emits runtime logs; done means the initial `START` line and debugger-listening output are not missed.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- docker, nodejs, python
- Domain
- cli, devtools
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100