sam-build is slow even with cached, skip pull image flags
- Dominant language
- Python
- Stars
- 6.7k
- Forks
- 1.2k
- Avg merge
- 1d 10h
- Merged PRs (30d)
- 52
Description
### Description:
I am using `sam-build` to build a SAM application that has a lambda with package type as `Image`. Every time I execute `sam-build` (event with `--cached --parallel --skip-pull-image`) it seems to take a lot of time at a certain step. From verbose logs, it looks like there's some step that takes time after this line:
```
2021-11-01 17:09:46,846 | Setting DockerBuildArgs: {} for ReportsGeneratorFunction function
```
and then after about 3-4 minutes, I see this lines that quickly execute:
```
Step 1/20 : FROM public.ecr.aws/lambda/python:3.8
---> ca2592cfa705
Step 2/20 : ....
...
...
```
It seems to me that it's pulling the base image `public.ecr.aws/lambda/python:3.8` on every build request.
### Steps to reproduce:
Dockerfile:
```
FROM public.ecr.aws/lambda/python:3.8
COPY src/app_core ./app_core
ENV ENV_TYPE prod
# copy the dependencies file to the working directory
COPY src/app_core/lambda_requirements.txt .
# install dependencies
RUN python3.8 -m pip install -r lambda_requirements.txt -t .
# Command can be overwritten by providing a different command in the template directly.
CMD ["app_core.serverless.latest_reports_scheduler.lambda_handler"]
```
### Observed result:
```
2021-11-01 17:09:46,468 | Telemetry endpoint configured to be https://aws-serverless-tools-telemetry.us-west-2.amazonaws.com/metrics
2021-11-01 17:09:46,468 | Using config file: samconfig.toml, config environment: default
2021-11-01 17:09:46,468 | Expand command line arguments to:
2021-11-01 17:09:46,468 | --template_file=/Users/ayusc/app/template.yaml --cached --parallel --skip_pull_image --build_dir=.aws-sam/build --cache_dir=.aws-sam/cache
2021-11-01 17:09:46,678 | 'build' command is called
2021-11-01 17:09:46,678 | Starting Build use cache
2021-11-01 17:09:46,696 | No Parameters detected in the template
2021-11-01 17:09:46,728 | 5 stacks found in the template
2021-11-01 17:09:46,728 | No Parameters detected in the template
2021-11-01 17:09:46,754 | 5 resources found in the stack
2021-11-01 17:09:46,754 | No Parameters detected in the template
2021-11-01 17:09:46,787 | Found Serverless function with name='LatestReportsSchedulerFunction' and ImageUri='None'
2021-11-01 17:09:46,787 | --base-dir is not presented, adjusting uri ./ relative to /Users/ayusc/app/template.yaml
2021-11-01 17:09:46,787 | --base-dir is not presented, adjusting uri . relative to /Users/ayusc/app/template.yaml
2021-11-01 17:09:46,787 | Found Serverless function with name='ReportsGeneratorFunction' and ImageUri='None'
2021-11-01 17:09:46,787 | --base-dir is not presented, adjusting uri ./ relative to /Users/ayusc/app/template.yaml
2021-11-01 17:09:46,787 | --base-dir is not presented, adjusting uri . relative to /Users/ayusc/app/template.yaml
2021-11-01 17:09:46,787 | No Parameters detected in the template
2021-11-01 17:09:46,826 | Instantiating build definitions
2021-11-01 17:09:46,831 | Unique function build definition found, adding as new (Function Build Definition: BuildDefinition(None, /Users/ayusc/app, Image, , fb41ba1e-8fbd-4a56-bf7b-b789a0818a67, {'Dockerfile': 'LambdaDockerfile', 'DockerContext': '/Users/ayusc/app', 'DockerTag': 'python3.8-v1-latest-reports-scheduler'}, {}, x86_64, []), Function: Function(name='LatestReportsSchedulerFunction', functionname='LatestReportsSchedulerFunction', runtime=None, memory=None, timeout=60, handler=None, imageuri=None, packagetype='Image', imageconfig={'Command': ['app_core.serverless.latest_reports_scheduler.lambda_handler']}, codeuri='/Users/ayusc/app', environment=None, rolearn=None, layers=[], events={'LatestReportSchedule': {'Type': 'Schedule', 'Properties': {'Schedule': 'rate(5 minutes)', 'Name': 'LatestReportSchedule', 'DeadLetterConfig': {'Arn': 'arn:aws:lambda:us-east-1:123456789012:function:LatestReportScheduleDLQ'}, 'RetryPolicy': {'MaximumRetryAttempts': 1}}}}, metadata={'Dockerfile': 'LambdaDockerfile', 'DockerContext': '/Users/ayusc/app', 'DockerTag': 'python3.8-v1-latest-reports-scheduler'}, inlinecode=None, codesign_config_arn=None, architectures=['x86_64'], stack_path=''))
2021-11-01 17:09:46,831 | Unique function build definition found, adding as new (Function Build Definition: BuildDefinition(None, /Users/ayusc/app, Image, , 60bb3d96-7a85-48c2-8568-68b476a77ca2, {'Dockerfile': 'LambdaDockerfile', 'DockerContext': '/Users/ayusc/app', 'DockerTag': 'python3.8-v1-reports-generator-'}, {}, x86_64, []), Function: Function(name='ReportsGeneratorFunction', functionname='ReportsGeneratorFunction', runtime=None, memory=None, timeout=60, handler=None, imageuri=None, packagetype='Image', imageconfig={'Command': ['app_core.serverless.reports_generator.lambda_handler']}, codeuri='/Users/ayusc/app', environment=None, rolearn=None, layers=[], events={'SQSEvent': {'Type': 'SQS', 'Properties': {'Queue': 'arn:aws:lambda:us-east-1:123456789012:function:ReportsGenerationEventsQueue', 'BatchSize': 10, 'Enabled': False}}}, metadata={'Dockerfile': 'LambdaDockerfile', 'DockerContext': '/Users/ayusc/app', 'DockerTag': 'python3.8-v1-reports-generator-'}, inlinecode=None, codesign_config_arn=None, architectures=['x86_64'], stack_path=''))
2021-11-01 17:09:46,833 | Async execution started
2021-11-01 17:09:46,833 | Invoking function functools.partial(>, )
2021-11-01 17:09:46,834 | Running incremental build for runtime None for build definition fb41ba1e-8fbd-4a56-bf7b-b789a0818a67
2021-11-01 17:09:46,834 | Invoking function functools.partial(>, )
2021-11-01 17:09:46,834 | Building codeuri: /Users/ayusc/app runtime: None metadata: {'Dockerfile': 'LambdaDockerfile', 'DockerContext': '/Users/ayusc/app', 'DockerTag': 'python3.8-v1-latest-reports-scheduler'} architecture: x86_64 functions: ['LatestReportsSchedulerFunction']
2021-11-01 17:09:46,834 | Running incremental build for runtime None for build definition 60bb3d96-7a85-48c2-8568-68b476a77ca2
2021-11-01 17:09:46,834 | Building to following folder /Users/ayusc/app/.aws-sam/build/LatestReportsSchedulerFunction
2021-11-01 17:09:46,834 | Waiting for async results
2021-11-01 17:09:46,835 | Building codeuri: /Users/ayusc/app runtime: None metadata: {'Dockerfile': 'LambdaDockerfile', 'DockerContext': '/Users/ayusc/app', 'DockerTag': 'python3.8-v1-reports-generator-'} architecture: x86_64 functions: ['ReportsGeneratorFunction']
2021-11-01 17:09:46,835 | Building image for LatestReportsSchedulerFunction function
2021-11-01 17:09:46,835 | Building to following folder /Users/ayusc/app/.aws-sam/build/ReportsGeneratorFunction
2021-11-01 17:09:46,835 | Building image for ReportsGeneratorFunction function
2021-11-01 17:09:46,846 | Setting DockerBuildArgs: {} for LatestReportsSchedulerFunction function
2021-11-01 17:09:46,846 | Setting DockerBuildArgs: {} for ReportsGeneratorFunction function
Step 1/20 : FROM public.ecr.aws/lambda/python:3.8
---> ca2592cfa705
Step 2/20 : COPY src/app_core ./app_core
---> Using cache
---> 20e8e259f013
...
```
The latency/delay is after `Setting DockerBuildArgs: {} for ReportsGeneratorFunction function`
### Expected result:
It should reuse the previous image (if that's the reason for the delay)
### Additional environment details (Ex: Windows, Mac, Amazon Linux etc)
1. OS: MacOS
2. `sam --version`: SAM CLI, version 1.34.1
3. AWS region: eu-west-1
`Add --debug flag to command you are running`
Contributor guide
Assessment
This issue has not been assessed yet.