aws / aws-toolkit-vscode

Amazon Q, CodeCatalyst, Local Lambda debug, SAM/CFN syntax, ECS Terminal, AWS resources
https://marketplace.visualstudio.com/items?itemName=AmazonWebServices.amazon-q-vscode
Apache License 2.0
1.51k stars 436 forks source link

SamLaunchRequestError: "sam build" failed, even though sam build succeeds from terminal. #4035

Closed francisEEL closed 12 months ago

francisEEL commented 12 months ago

Problem

Since last week (that I have noticed) I can't debug my Lambda functions anymore due to the extension failing to perform sam build. This is the verbose log from aws toolkit:

2023-11-13 14:27:03 [INFO]: log level: debug
2023-11-13 14:27:03 [DEBUG]: Logging started: file:///Users/francis/Library/Application%20Support/Code/logs/20231113T135840/window3/exthost/amazonwebservices.aws-toolkit-vscode/aws_toolkit_20231113T142703.log
2023-11-13 14:27:04 [INFO]: endpoints: retrieving AWS endpoints data
2023-11-13 14:27:04 [VERBOSE]: loading file resource: "/Users/francis/.vscode/extensions/amazonwebservices.aws-toolkit-vscode-1.98.0/resources/endpoints.json"
2023-11-13 14:27:04 [INFO]: OS: Darwin arm64 23.0.0
2023-11-13 14:27:04 [INFO]: Visual Studio Code extension host:  1.84.2
2023-11-13 14:27:04 [INFO]: AWS Toolkit:  1.98.0
2023-11-13 14:27:04 [INFO]: node: 18.15.0
2023-11-13 14:27:04 [INFO]: electron: 25.9.2
2023-11-13 14:27:04 [DEBUG]: firstStartup: This is not the users first use of the extension. Skipped showing Add Connections page.
2023-11-13 14:27:04 [VERBOSE]: downloading: https://idetoolkits.amazonwebservices.com/endpoints.json
2023-11-13 14:27:04 [VERBOSE]: downloading: https://api.github.com/repos/devfile/api/releases/latest
2023-11-13 14:27:04 [VERBOSE]: codecatalyst: not a devenv, getThisDevEnv() returned empty
2023-11-13 14:27:04 [DEBUG]: SSO token cache: loaded key: https://view.awsapps.com/start?scopes=codecatalyst:read_write,codewhisperer:analysis,codewhisperer:completions
2023-11-13 14:27:04 [INFO]: codecatalyst: reconnect: onDidChangeActiveConnection: startUrl=https://view.awsapps.com/start
2023-11-13 14:27:04 [INFO]: codecatalyst: attempting to poll dev environments
2023-11-13 14:27:04 [DEBUG]: codewhisperer: Connection expired = false,
                           secondaryAuth connection expired = false,
                           connection is undefined = false
2023-11-13 14:27:04 [DEBUG]: codewhisperer: isValidCodeWhispererConnection = true
2023-11-13 14:27:04 [DEBUG]: codewhisperer: Connection is valid = true, 
                            connection is undefined = false,
                            secondaryAuth connection expired = false
2023-11-13 14:27:04 [DEBUG]: codewhisperer: Connection expired = false,
                           secondaryAuth connection expired = false,
                           connection is undefined = false
2023-11-13 14:27:04 [DEBUG]: codewhisperer: isValidCodeWhispererConnection = true
2023-11-13 14:27:04 [VERBOSE]: credentials: EC2 metadata service unavailable: Error: connect EHOSTUNREACH 169.254.169.254:80 - Local (192.168.7.102:50074)
2023-11-13 14:27:04 [VERBOSE]: credentials: EC2 metadata service call took 7ms
2023-11-13 14:27:04 [VERBOSE]: auth: "instance" provider unavailable
2023-11-13 14:27:04 [VERBOSE]: auth: "instance" provider unavailable
2023-11-13 14:27:04 [VERBOSE]: auth: "variables" provider unavailable
2023-11-13 14:27:04 [VERBOSE]: downloaded: https://idetoolkits.amazonwebservices.com/endpoints.json
2023-11-13 14:27:04 [DEBUG]: git: repo "/Users/francis/Development/english-backend" changed head from "unknown" to "main"
2023-11-13 14:27:04 [VERBOSE]: credentials: found sections: profile:default
2023-11-13 14:27:04 [DEBUG]: codewhisperer: Connection expired = false,
                           secondaryAuth connection expired = false,
                           connection is undefined = false
2023-11-13 14:27:04 [DEBUG]: codewhisperer: isValidCodeWhispererConnection = true
2023-11-13 14:27:04 [DEBUG]: codewhisperer: Connection is valid = true, 
                            connection is undefined = false,
                            secondaryAuth connection expired = false
2023-11-13 14:27:04 [DEBUG]: codewhisperer: Connection expired = false,
                           secondaryAuth connection expired = false,
                           connection is undefined = false
2023-11-13 14:27:04 [DEBUG]: codewhisperer: isValidCodeWhispererConnection = true
2023-11-13 14:27:04 [DEBUG]: codewhisperer: Connection expired = false,
                           secondaryAuth connection expired = false,
                           connection is undefined = false
2023-11-13 14:27:04 [DEBUG]: codewhisperer: isValidCodeWhispererConnection = true
2023-11-13 14:27:04 [VERBOSE]: downloaded: https://api.github.com/repos/devfile/api/releases/latest
2023-11-13 14:27:04 [VERBOSE]: loading file resource: "/Users/francis/Library/Application Support/Code/User/globalStorage/amazonwebservices.aws-toolkit-vscode/sam.schema.json"
2023-11-13 14:27:05 [INFO]: CodelensRootRegistry: building with: Watching **/requirements.txt, **/package.json, **/*.csproj, **/go.mod, **/build.gradle, **/pom.xml
2023-11-13 14:27:05 [VERBOSE]: E-Tag, W/"cdab20dce13691457b7c14194cd92699639c28cbf5c3d594406cf1fdc11b2eb8", matched. No content downloaded from: https://raw.githubusercontent.com/aws/serverless-application-model/main/samtranslator/schema/schema.json
2023-11-13 14:27:05 [VERBOSE]: loading file resource: "/Users/francis/Library/Application Support/Code/User/globalStorage/amazonwebservices.aws-toolkit-vscode/sam.schema.json"
2023-11-13 14:27:05 [VERBOSE]: E-Tag, W/"cdab20dce13691457b7c14194cd92699639c28cbf5c3d594406cf1fdc11b2eb8", matched. No content downloaded from: https://raw.githubusercontent.com/aws/serverless-application-model/main/samtranslator/schema/schema.json
2023-11-13 14:27:05 [VERBOSE]: loading file resource: "/Users/francis/Library/Application Support/Code/User/globalStorage/amazonwebservices.aws-toolkit-vscode/devfile.schema.json"
2023-11-13 14:27:05 [INFO]: CodelensRootRegistry: processed 2 items
2023-11-13 14:27:05 [VERBOSE]: activateCodefileOverlays took 419ms
2023-11-13 14:27:06 [INFO]: CloudFormationTemplateRegistry: building with: Watching **/*.{yaml,yml}, Untitled Files, Excluding /.*devfile\.(yaml|yml)/i, /.*[/\\]\.aws-sam([/\\].*|$)/
2023-11-13 14:27:06 [DEBUG]: cfn: getInstance() requested, still initializing
2023-11-13 14:27:06 [INFO]: CloudFormationTemplateRegistry: failed to process: file:///Users/francis/Development/english-backend/api.yaml
2023-11-13 14:27:06 [INFO]: CloudFormationTemplateRegistry: failed to process: file:///Users/francis/Development/english-backend/pipeline/buildspec_deploy.yml
2023-11-13 14:27:06 [INFO]: CloudFormationTemplateRegistry: failed to process: file:///Users/francis/Development/english-backend/pipeline/buildspec_feature.yml
2023-11-13 14:27:06 [INFO]: CloudFormationTemplateRegistry: failed to process: file:///Users/francis/Development/english-backend/pipeline/buildspec_integration_test.yml
2023-11-13 14:27:06 [INFO]: CloudFormationTemplateRegistry: failed to process: file:///Users/francis/Development/english-backend/pipeline/buildspec_build_package.yml
2023-11-13 14:27:06 [INFO]: CloudFormationTemplateRegistry: failed to process: file:///Users/francis/Development/english-backend/pipeline/buildspec_unit_test.yml
2023-11-13 14:27:06 [INFO]: CloudFormationTemplateRegistry: processed 2 items, skipped 6
2023-11-13 14:27:06 [VERBOSE]: cfn: template registry setup took 81ms
2023-11-13 14:27:06 [DEBUG]: schema service: handle yaml mapping: cfn -> file:///Users/francis/Development/english-backend/codepipeline.yaml
2023-11-13 14:27:06 [DEBUG]: Activating extension: redhat.vscode-yaml
2023-11-13 14:27:06 [DEBUG]: Extension activated: redhat.vscode-yaml
2023-11-13 14:27:06 [DEBUG]: schema service: handle yaml mapping: sam -> file:///Users/francis/Development/english-backend/template.yaml
2023-11-13 14:27:06 [DEBUG]: schema service: handle yaml mapping: [removed] -> file:///Users/francis/Development/english-backend/api.yaml
2023-11-13 14:27:06 [DEBUG]: schema service: handle yaml mapping: [removed] -> file:///Users/francis/Development/english-backend/pipeline/buildspec_deploy.yml
2023-11-13 14:27:06 [DEBUG]: schema service: handle yaml mapping: [removed] -> file:///Users/francis/Development/english-backend/pipeline/buildspec_feature.yml
2023-11-13 14:27:06 [DEBUG]: schema service: handle yaml mapping: [removed] -> file:///Users/francis/Development/english-backend/pipeline/buildspec_integration_test.yml
2023-11-13 14:27:06 [DEBUG]: schema service: handle yaml mapping: [removed] -> file:///Users/francis/Development/english-backend/pipeline/buildspec_build_package.yml
2023-11-13 14:27:06 [DEBUG]: schema service: handle yaml mapping: [removed] -> file:///Users/francis/Development/english-backend/pipeline/buildspec_unit_test.yml
2023-11-13 14:27:08 [DEBUG]: cfn: getInstance() ready
2023-11-13 14:27:09 [VERBOSE]: SAM debug: config: "levels:exercises_per_level"
2023-11-13 14:27:09 [WARN]: SAM debug: missing AWS credentials (Toolkit is not connected)
2023-11-13 14:27:09 [DEBUG]: pythonCodeLensProvider.makePythonDebugManifest params: {
  "isImageLambda": false,
  "samProjectCodeRoot": "/Users/francis/Development/english-backend/src",
  "outputDir": "/tmp/aws-toolkit-vscode/vsctkhlBfku",
  "useIkpdb": false
}
2023-11-13 14:27:09 [INFO]: SAM CLI location (from settings): /usr/local/bin/sam
2023-11-13 14:27:11 [INFO]: Preparing to debug locally: Lambda "handlers.levels.get_level_exercises.handler"
2023-11-13 14:27:11 [INFO]: Building SAM application...
2023-11-13 14:27:11 [VERBOSE]: running: (not started) [/usr/local/bin/sam build --debug --build-dir /tmp/aws-toolkit-vscode/vsctkhlBfku/output --template /tmp/aws-toolkit-vscode/vsctkhlBfku/app___vsctk___template.yaml --base-dir /Users/francis/Development/english-backend/src --manifest /tmp/aws-toolkit-vscode/vsctkhlBfku/debug-requirements.txt]
2023-11-13 14:27:11 [INFO]: Command: (not started) [/usr/local/bin/sam build --debug --build-dir /tmp/aws-toolkit-vscode/vsctkhlBfku/output --template /tmp/aws-toolkit-vscode/vsctkhlBfku/app___vsctk___template.yaml --base-dir /Users/francis/Development/english-backend/src --manifest /tmp/aws-toolkit-vscode/vsctkhlBfku/debug-requirements.txt]
2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,449 | Using SAM Template at /tmp/aws-toolkit-vscode/vsctkhlBfku/app___vsctk___template.yaml

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,449 | No config file found in this directory.
2023-11-13 14:27:11,449 | OSError occurred while reading TOML file: [Errno 2] No such file or directory: '/tmp/aws-toolkit-vscode/vsctkhlBfku/samconfig.toml'
2023-11-13 14:27:11,449 | Config file location: /tmp/aws-toolkit-vscode/vsctkhlBfku/samconfig.toml
2023-11-13 14:27:11,449 | Config file '/tmp/aws-toolkit-vscode/vsctkhlBfku/samconfig.toml' does not exist

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,468 | OSError occurred while reading TOML file: [Errno 2] No such file or directory: '/tmp/aws-toolkit-vscode/vsctkhlBfku/samconfig.toml'

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,468 | Using config file: samconfig.toml, config environment: default
2023-11-13 14:27:11,468 | Expand command line arguments to:
2023-11-13 14:27:11,468 | --template_file=/tmp/aws-toolkit-vscode/vsctkhlBfku/app___vsctk___template.yaml --build_dir=/tmp/aws-toolkit-vscode/vsctkhlBfku/output --base_dir=/Users/francis/Development/english-backend/src --manifest=/tmp/aws-toolkit-vscode/vsctkhlBfku/debug-requirements.txt --mount_with=READ --cache_dir=.aws-sam/cache 

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,513 | 'build' command is called
2023-11-13 14:27:11,514 | No Parameters detected in the template

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,528 | There is no customer defined id or cdk path defined for resource src, so we will use the resource logical id as the resource id

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,528 | 0 stacks found in the template
2023-11-13 14:27:11,528 | No Parameters detected in the template

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,540 | There is no customer defined id or cdk path defined for resource src, so we will use the resource logical id as the resource id

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,540 | 1 resources found in the stack 
2023-11-13 14:27:11,540 | Found Serverless function with name='src' and CodeUri='/Users/francis/Development/english-backend/src'

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,541 | 1 resources found in the stack 

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,541 | Found Serverless function with name='src' and CodeUri='/Users/francis/Development/english-backend/src'

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,541 | Instantiating build definitions

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,541 | No previous build graph found, generating new one
2023-11-13 14:27:11,541 | Unique function build definition found, adding as new (Function Build Definition: BuildDefinition(python3.11, /Users/francis/Development/english-backend/src, Zip, , 6b73b1c1-c015-471a-9715-789f7e702e5d, {}, {}, x86_64, []), Function: Function(function_id='src', name='src', functionname='src', runtime='python3.11', memory=None, timeout=None, handler='handlers.levels.get_level_exercises.handler', imageuri=None, packagetype='Zip', imageconfig=None, codeuri='/Users/francis/Development/english-backend/src', environment={'Variables': {'ENV': 'test', 'LOG_LEVEL_CONDITION': 'DEBUG'}}, rolearn=None, layers=[], events=None, metadata={'SamResourceId': 'src'}, inlinecode=None, codesign_config_arn=None, architectures=None, function_url_config=None, function_build_info=<FunctionBuildInfo.BuildableZip: ('BuildableZip', 'Regular ZIP function which can be build with SAM CLI')>, stack_path='', runtime_management_config=None))

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,542 | Building codeuri: /Users/francis/Development/english-backend/src runtime: python3.11 metadata: {} architecture: x86_64 functions: src

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,543 | Building to following folder /private/tmp/aws-toolkit-vscode/vsctkhlBfku/output/src

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,543 | Loading workflow module 'aws_lambda_builders.workflows'

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,544 | Registering workflow 'CustomMakeBuilder' with capability 'Capability(language='provided', dependency_manager=None, application_framework=None)'

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,544 | Registering workflow 'DotnetCliPackageBuilder' with capability 'Capability(language='dotnet', dependency_manager='cli-package', application_framework=None)'

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,545 | Registering workflow 'GoModulesBuilder' with capability 'Capability(language='go', dependency_manager='modules', application_framework=None)'

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,546 | Registering workflow 'JavaGradleWorkflow' with capability 'Capability(language='java', dependency_manager='gradle', application_framework=None)'

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,546 | Registering workflow 'JavaMavenWorkflow' with capability 'Capability(language='java', dependency_manager='maven', application_framework=None)'
2023-11-13 14:27:11,547 | Registering workflow 'NodejsNpmBuilder' with capability 'Capability(language='nodejs', dependency_manager='npm', application_framework=None)'

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,548 | Registering workflow 'NodejsNpmEsbuildBuilder' with capability 'Capability(language='nodejs', dependency_manager='npm-esbuild', application_framework=None)'

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,549 | Registering workflow 'PythonPipBuilder' with capability 'Capability(language='python', dependency_manager='pip', application_framework=None)'
2023-11-13 14:27:11,550 | Registering workflow 'RubyBundlerBuilder' with capability 'Capability(language='ruby', dependency_manager='bundler', application_framework=None)'

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,551 | Registering workflow 'RustCargoLambdaBuilder' with capability 'Capability(language='rust', dependency_manager='cargo', application_framework=None)'
2023-11-13 14:27:11,551 | Found workflow 'PythonPipBuilder' to support capabilities 'Capability(language='python', dependency_manager='pip', application_framework=None)'

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,579 | Running workflow 'PythonPipBuilder'
2023-11-13 14:27:11,579 |  Running PythonPipBuilder:ResolveDependencies

2023-11-13 14:27:11 [VERBOSE]: stderr: 2023-11-13 14:27:11,628 | calling pip download -r /tmp/aws-toolkit-vscode/vsctkhlBfku/debug-requirements.txt --dest /var/folders/y0/8fql3fwd0q9683gs2d7g918m0000gn/T/tmp0_au_c1o --exists-action i

2023-11-13 14:27:12 [ERROR]: SamLaunchRequestError: "sam build" failed. Timed out waiting for build. [BuildFailure]
2023-11-13 14:27:17 [DEBUG]: command: running "aws.viewLogsAtMessage" with arguments [97]

This is my sam cli version:

sam --version                                                                                                    
SAM CLI, version 1.100.0

If I run the same command in my terminal:

/usr/local/bin/sam build --build-dir /tmp/aws-toolkit-vscode/vsctk9Tdq75/output --template /tmp/aws-toolkit-vscode/vsctk9Tdq75/app___vsctk___template.yaml --base-dir /Users/francis/Development/english-backend/src --manifest /tmp/aws-toolkit-vscode/vsctk9Tdq75/debug-requirements.txt
Building codeuri: /Users/francis/Development/english-backend/src runtime: python3.11 metadata: {} architecture: x86_64 functions: src                                                              
 Running PythonPipBuilder:ResolveDependencies                                                                                                                                                      
 Running PythonPipBuilder:CopySource                                                                                                                                                               

Build Succeeded

Built Artifacts  : ../../../../private/tmp/aws-toolkit-vscode/vsctk9Tdq75/output
Built Template   : ../../../../private/tmp/aws-toolkit-vscode/vsctk9Tdq75/output/template.yaml

I didn't change my launch.json configuration since it was working. Calling pip download -r /tmp/aws-toolkit-vscode/vsctkhlBfku/debug-requirements.txt --dest /var/folders/y0/8fql3fwd0q9683gs2d7g918m0000gn/T/tmp0_au_c1o --exists-action i also succeeds.

Steps to reproduce the issue

I just try to debug any of my Lambda functions and I get the error.

Expected behavior

Sam build will succeed and I can proceed to debug my Lambda functions.

System details (run the AWS: About Toolkit command)

francisEEL commented 12 months ago

It seems that it's related to the Lambda timeout in https://github.com/aws/aws-toolkit-vscode/issues/4004.