Stack demo1 failed to deploy

[Arvind644]

While running make deploy command, I am getting this error :

[agn-7]

Same issue!

here's the error stdout:

> make deploy 
make[1]: Entering directory '/home/benyamin/PycharmProjects/localstack-demo'
npm install
npm WARN deprecated uuid@3.4.0: Please upgrade  to version 7 or higher.  Older versions may use Math.random() in certain circumstances, which is known to be problematic.  See https://v8.dev/blog/math-random for details.
npm WARN deprecated superagent@7.1.6: Please downgrade to v7.1.5 if you need IE/ActiveXObject support OR upgrade to v8.0.0 as we no longer support IE and published an incorrect patch version (see https://github.com/visionmedia/superagent/issues/1731)
npm WARN deprecated querystring@0.2.0: The querystring API is considered Legacy. new code should use the URLSearchParams API instead.
npm WARN deprecated querystring@0.2.1: The querystring API is considered Legacy. new code should use the URLSearchParams API instead.

added 532 packages, and audited 533 packages in 50s

74 packages are looking for funding
  run `npm fund` for details

4 moderate severity vulnerabilities

To address all issues, run:
  npm audit fix

Run `npm audit` for details.
npm notice 
npm notice New major version of npm available! 8.15.0 -> 10.2.0
npm notice Changelog: https://github.com/npm/cli/releases/tag/v10.2.0
npm notice Run npm install -g npm@10.2.0 to update!
npm notice 
which serverless || npm install -g serverless
npm WARN deprecated querystring@0.2.1: The querystring API is considered Legacy. new code should use the URLSearchParams API instead.
npm WARN deprecated querystring@0.2.0: The querystring API is considered Legacy. new code should use the URLSearchParams API instead.
npm WARN deprecated querystring@0.2.0: The querystring API is considered Legacy. new code should use the URLSearchParams API instead.
npm WARN deprecated superagent@7.1.6: Please downgrade to v7.1.5 if you need IE/ActiveXObject support OR upgrade to v8.0.0 as we no longer support IE and published an incorrect patch version (see https://github.com/visionmedia/superagent/issues/1731)

added 504 packages, and audited 505 packages in 2m

70 packages are looking for funding
  run `npm fund` for details

found 0 vulnerabilities
which localstack || pip install localstack
/home/benyamin/.local/bin/localstack
make[1]: Leaving directory '/home/benyamin/PycharmProjects/localstack-demo'
Deploying Serverless app to local environment
Running "serverless" from node_modules
config.options_stage: local
serverless.service.custom.stage: undefined
serverless.service.provider.stage: local
config.stage: local

Deploying localstack-demo to stage local (us-east-1)
config.options_stage: local
serverless.service.custom.stage: undefined
serverless.service.provider.stage: local
config.stage: local
config.options_stage: local
serverless.service.custom.stage: undefined
serverless.service.provider.stage: local
config.stage: local
Using serverless-localstack
Reconfiguring service acm to use http://127.0.0.1:4566
Reconfiguring service amplify to use http://127.0.0.1:4566
Reconfiguring service apigateway to use http://127.0.0.1:4566
Reconfiguring service apigatewayv2 to use http://127.0.0.1:4566
Reconfiguring service application-autoscaling to use http://127.0.0.1:4566
Reconfiguring service appsync to use http://127.0.0.1:4566
Reconfiguring service athena to use http://127.0.0.1:4566
Reconfiguring service autoscaling to use http://127.0.0.1:4566
Reconfiguring service batch to use http://127.0.0.1:4566
Reconfiguring service cloudformation to use http://127.0.0.1:4566
Reconfiguring service cloudfront to use http://127.0.0.1:4566
Reconfiguring service cloudsearch to use http://127.0.0.1:4566
Reconfiguring service cloudtrail to use http://127.0.0.1:4566
Reconfiguring service cloudwatch to use http://127.0.0.1:4566
Reconfiguring service cloudwatchlogs to use http://127.0.0.1:4566
Reconfiguring service codecommit to use http://127.0.0.1:4566
Reconfiguring service cognito-idp to use http://127.0.0.1:4566
Reconfiguring service cognito-identity to use http://127.0.0.1:4566
Reconfiguring service docdb to use http://127.0.0.1:4566
Reconfiguring service dynamodb to use http://127.0.0.1:4566
Reconfiguring service dynamodbstreams to use http://127.0.0.1:4566
Reconfiguring service ec2 to use http://127.0.0.1:4566
Reconfiguring service ecr to use http://127.0.0.1:4566
Reconfiguring service ecs to use http://127.0.0.1:4566
Reconfiguring service eks to use http://127.0.0.1:4566
Reconfiguring service elasticache to use http://127.0.0.1:4566
Reconfiguring service elasticbeanstalk to use http://127.0.0.1:4566
Reconfiguring service elb to use http://127.0.0.1:4566
Reconfiguring service elbv2 to use http://127.0.0.1:4566
Reconfiguring service emr to use http://127.0.0.1:4566
Reconfiguring service es to use http://127.0.0.1:4566
Reconfiguring service events to use http://127.0.0.1:4566
Reconfiguring service firehose to use http://127.0.0.1:4566
Reconfiguring service glacier to use http://127.0.0.1:4566
Reconfiguring service glue to use http://127.0.0.1:4566
Reconfiguring service iam to use http://127.0.0.1:4566
Reconfiguring service iot to use http://127.0.0.1:4566
Reconfiguring service iotanalytics to use http://127.0.0.1:4566
Reconfiguring service iotevents to use http://127.0.0.1:4566
Reconfiguring service iot-data to use http://127.0.0.1:4566
Reconfiguring service iot-jobs-data to use http://127.0.0.1:4566
Reconfiguring service kafka to use http://127.0.0.1:4566
Reconfiguring service kinesis to use http://127.0.0.1:4566
Reconfiguring service kinesisanalytics to use http://127.0.0.1:4566
Reconfiguring service kms to use http://127.0.0.1:4566
Reconfiguring service lambda to use http://127.0.0.1:4566
Reconfiguring service logs to use http://127.0.0.1:4566
Reconfiguring service mediastore to use http://127.0.0.1:4566
Reconfiguring service neptune to use http://127.0.0.1:4566
Reconfiguring service organizations to use http://127.0.0.1:4566
Reconfiguring service qldb to use http://127.0.0.1:4566
Reconfiguring service rds to use http://127.0.0.1:4566
Reconfiguring service redshift to use http://127.0.0.1:4566
Reconfiguring service route53 to use http://127.0.0.1:4566
Reconfiguring service s3 to use http://127.0.0.1:4566
Reconfiguring service s3control to use http://127.0.0.1:4566
Reconfiguring service sagemaker to use http://127.0.0.1:4566
Reconfiguring service sagemaker-runtime to use http://127.0.0.1:4566
Reconfiguring service secretsmanager to use http://127.0.0.1:4566
Reconfiguring service ses to use http://127.0.0.1:4566
Reconfiguring service sns to use http://127.0.0.1:4566
Reconfiguring service sqs to use http://127.0.0.1:4566
Reconfiguring service ssm to use http://127.0.0.1:4566
Reconfiguring service stepfunctions to use http://127.0.0.1:4566
Reconfiguring service sts to use http://127.0.0.1:4566
Reconfiguring service timestream to use http://127.0.0.1:4566
Reconfiguring service transfer to use http://127.0.0.1:4566
Reconfiguring service xray to use http://127.0.0.1:4566
serverless-localstack: Reconfigured endpoints
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Creating deployment bucket 'localstack-test-bucket'...
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using deployment bucket 'localstack-test-bucket'
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for Lambda: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for Lambda: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for Lambda: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for Lambda: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for S3: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Skipping template validation: Unsupported in Localstack
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Overriding S3 templateUrl to http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)
Using custom endpoint for CloudFormation: http://127.0.0.1:4566
Skipping reconfiguring of endpoints (already reconfigured)

✖ Stack demo1 failed to deploy (259s)
Environment: linux, node 16.17.0, framework 3.29.0 (local) 3.35.2v (global), plugin 6.2.3, SDK 4.3.2
Credentials: Local, environment variables
Docs:        docs.serverless.com
Support:     forum.serverless.com
Bugs:        github.com/serverless/serverless/issues

Error:
CREATE_FAILED: BackendProcessRequestLambdaFunction (AWS::Lambda::Function)
Waiter FunctionActiveV2 failed: Max attempts exceeded. Previously accepted state: For expression "Configuration.State" we matched expected path: "Pending"

View the full error: https://us-east-1.console.aws.amazon.com/cloudformation/home?region=us-east-1#/stack/detail?stackId=arn%3Aaws%3Acloudformation%3Aus-east-1%3A000000000000%3Astack%2Fdemo1%2F07c8985e

1 deprecation found: run 'serverless doctor' for more details
^[[A^[[Bmake: *** [Makefile:14: deploy] Error 1

[simonrw]

Thanks for reporting @Arvind644 and @agn-7.

Unfortunately I cannot reproduce this issue locally. Would you be able to share the logs from the LocalStack container: docker logs localstack_main after you have run make deploy?

[agn-7]

@simonrw
Here's the related logs:

2023-10-04T09:55:45.823  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS sts.GetCallerIdentity => 200
2023-10-04T09:55:46.398  INFO --- [   asgi_gw_1] localstack.utils.bootstrap : Execution of "_load_service_plugin" took 812.59ms
2023-10-04T09:55:46.398  INFO --- [   asgi_gw_1] localstack.utils.bootstrap : Execution of "require" took 813.42ms
2023-10-04T09:55:46.416  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.HeadBucket => 404 (NoSuchBucket)
2023-10-04T09:55:46.431  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.CreateBucket => 200
2023-10-04T09:55:46.439  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.HeadBucket => 200
2023-10-04T09:55:46.449  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.GetBucketVersioning => 200
2023-10-04T09:55:46.458  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetBucketAccelerateConfiguration => 200
2023-10-04T09:55:46.467  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.GetBucketTagging => 404 (NoSuchTagSet)
2023-10-04T09:55:46.478  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetPublicAccessBlock => 404 (NoSuchPublicAccessBlockConfiguration)
2023-10-04T09:55:46.487  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.GetBucketLogging => 200
2023-10-04T09:55:51.083  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.HeadBucket => 200
2023-10-04T09:55:51.091  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetBucketVersioning => 200
2023-10-04T09:55:51.099  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.GetBucketAccelerateConfiguration => 200
2023-10-04T09:55:51.107  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetBucketTagging => 404 (NoSuchTagSet)
2023-10-04T09:55:51.117  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.GetPublicAccessBlock => 404 (NoSuchPublicAccessBlockConfiguration)
2023-10-04T09:55:51.124  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetBucketLogging => 200
2023-10-04T09:55:52.432  INFO --- [   asgi_gw_0] localstack.utils.bootstrap : Execution of "_load_service_plugin" took 1296.17ms
2023-10-04T09:55:52.433  INFO --- [   asgi_gw_0] localstack.utils.bootstrap : Execution of "require" took 1296.89ms
2023-10-04T09:55:53.024  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS cloudformation.DescribeStacks => 400 (ValidationError)
2023-10-04T09:55:53.035  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetBucketLocation => 200
2023-10-04T09:55:53.052  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.ListObjectsV2 => 200
2023-10-04T09:55:53.350  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS lambda.GetFunction => 404 (ResourceNotFoundException)
2023-10-04T09:55:53.350  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS lambda.GetFunction => 404 (ResourceNotFoundException)
2023-10-04T09:55:53.360  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS lambda.GetFunction => 404 (ResourceNotFoundException)
2023-10-04T09:55:53.361  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS lambda.GetFunction => 404 (ResourceNotFoundException)
2023-10-04T09:55:53.535  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.PutObject => 200
2023-10-04T09:55:53.548  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.PutObject => 200
2023-10-04T09:55:53.561  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.PutObject => 200
2023-10-04T09:55:53.578  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetObject => 200
2023-10-04T09:55:53.587  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS cloudformation.CreateChangeSet => 200
2023-10-04T09:55:53.598  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS cloudformation.DescribeChangeSet => 200
2023-10-04T09:55:53.620  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS cloudformation.ExecuteChangeSet => 200
2023-10-04T09:55:58.634  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T09:55:59.439  INFO --- [   asgi_gw_0] localstack.utils.bootstrap : Execution of "require" took 2029.61ms
2023-10-04T09:56:03.665  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T09:56:08.703  INFO --- [   asgi_gw_2] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T09:56:13.745  INFO --- [   asgi_gw_3] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T09:56:16.583  WARN --- [   asgi_gw_3] l.s.stepfunctions.provider : The 'v1' StepFunctions provider (current default) will be deprecated with the next major release (3.0). Set 'PROVIDER_OVERRIDE_STEPFUNCTIONS=v2' to opt-in to the new StepFunctions 'v2' provider.
2023-10-04T09:56:18.786  INFO --- [   asgi_gw_8] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T09:56:21.227  WARN --- [   asgi_gw_3] localstack.utils.functions : error calling function on_before_start: Installation of stepfunctions-local failed.
2023-10-04T09:56:21.235  INFO --- [   asgi_gw_3] localstack.utils.bootstrap : Execution of "require" took 4661.52ms
2023-10-04T09:56:21.265 ERROR --- [   asgi_gw_3] l.aws.handlers.logging     : exception during call chain: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7faa33bbad90>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-10-04T09:56:21.300 ERROR --- [   asgi_gw_3] l.aws.handlers.logging     : exception during call chain: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7faa33a14a10>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-10-04T09:56:21.573 ERROR --- [   asgi_gw_8] l.aws.handlers.logging     : exception during call chain: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7faa338fd410>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-10-04T09:56:23.855  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T09:56:25.389 ERROR --- [   asgi_gw_1] l.aws.handlers.logging     : exception during call chain: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7faa39f86590>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-10-04T09:56:28.907  INFO --- [   asgi_gw_7] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T09:56:31.812 ERROR --- [   asgi_gw_1] l.aws.handlers.logging     : exception during call chain: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7faa392cf2d0>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-10-04T09:56:31.823  WARN --- [uncthread371] l.s.c.resource_provider    : Error calling <bound method ClientCreator._create_api_method.<locals>._api_call of <botocore.client.SFN object at 0x7faa3859ca10>> with params: {'name': 'processingStateMachine', 'definition': '{\n  "StartAt": "ProcessRequest",\n  "States": {\n    "ProcessRequest": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest",\n      "Next": "ArchiveResult"\n    },\n    "ArchiveResult": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult",\n      "End": true\n    }\n  }\n}\n', 'roleArn': 'arn:aws:iam::000000000000:role/demo1-processingStateMachineRo-c9ff8281'} for resource: {'Type': 'AWS::StepFunctions::StateMachine', 'LogicalResourceId': 'processingStateMachine', 'Properties': {'StateMachineName': 'processingStateMachine', 'RoleArn': 'arn:aws:iam::000000000000:role/demo1-processingStateMachineRo-c9ff8281', 'DefinitionString': '{\n  "StartAt": "ProcessRequest",\n  "States": {\n    "ProcessRequest": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest",\n      "Next": "ArchiveResult"\n    },\n    "ArchiveResult": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult",\n      "End": true\n    }\n  }\n}\n'}, 'SpecifiedProperties': {'StateMachineName': 'processingStateMachine', 'RoleArn': 'arn:aws:iam::000000000000:role/demo1-processingStateMachineRo-c9ff8281', 'DefinitionString': '{\n  "StartAt": "ProcessRequest",\n  "States": {\n    "ProcessRequest": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest",\n      "Next": "ArchiveResult"\n    },\n    "ArchiveResult": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult",\n      "End": true\n    }\n  }\n}\n'}}
2023-10-04T09:56:33.978  INFO --- [   asgi_gw_3] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200

[simonrw]

@agn-7 thanks for the output, but can you include the lines at the beginning that look like:

LocalStack version: 2.3.3.dev20231003195604
LocalStack Docker container id: c9a769bbffdd
LocalStack build date: 2023-10-04
LocalStack build git hash: 000806f

[agn-7]

@simonrw

LocalStack version: 2.3.2.dev
LocalStack Docker container id: c43870d9c97b
LocalStack build date: 2023-10-02
LocalStack build git hash: dcd9f152

[simonrw]

Ok great, thanks. That looks like a very recent image. You can try updating it but I can't see any changes since that git hash that would have broken something. Doubly so since the original report from @Arvind644 is from a month ago.

From your log, there is a line error calling function on_before_start: Installation of stepfunctions-local failed which suggests that there was a problem downloading the stepfunctions .jar file. The lines like

exception during call chain: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7faa33bbad90>: Failed to establish a new connection: [Errno 111] Connection refused'))

are our health check for the running stepfunctions process.

Could you re-run with DEBUG=1 which should give us more information about the actual error raised.

[agn-7]

@simonrw

Here's the full log with DEBUG=1

2023-10-04T11:45:12.379 DEBUG --- [   asgi_gw_0] plugin.manager             : instantiating plugin PluginSpec(localstack.aws.provider.sts:default = <function sts at 0x7f12932ae840>)
2023-10-04T11:45:12.381 DEBUG --- [   asgi_gw_0] plugin.manager             : loading plugin localstack.aws.provider:sts:default
2023-10-04T11:45:12.400 DEBUG --- [   asgi_gw_1] plugin.manager             : instantiating plugin PluginSpec(localstack.aws.provider.s3:default = <function s3 at 0x7f12932afce0>)
2023-10-04T11:45:12.400 DEBUG --- [   asgi_gw_1] plugin.manager             : loading plugin localstack.aws.provider:s3:default
2023-10-04T11:45:12.720  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS sts.GetCallerIdentity => 200
2023-10-04T11:45:12.973  INFO --- [   asgi_gw_1] localstack.utils.bootstrap : Execution of "_load_service_plugin" took 573.59ms
2023-10-04T11:45:12.974  INFO --- [   asgi_gw_1] localstack.utils.bootstrap : Execution of "require" took 574.41ms
2023-10-04T11:45:12.993  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.HeadBucket => 404 (NoSuchBucket)
2023-10-04T11:45:13.012  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.CreateBucket => 200
2023-10-04T11:45:13.020  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.HeadBucket => 200
2023-10-04T11:45:13.034  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.GetBucketVersioning => 200
2023-10-04T11:45:13.043  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetBucketAccelerateConfiguration => 200
2023-10-04T11:45:13.053  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.GetBucketTagging => 404 (NoSuchTagSet)
2023-10-04T11:45:13.068  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetPublicAccessBlock => 404 (NoSuchPublicAccessBlockConfiguration)
2023-10-04T11:45:13.078  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.GetBucketLogging => 200
2023-10-04T11:45:18.074  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.HeadBucket => 200
2023-10-04T11:45:18.087  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetBucketVersioning => 200
2023-10-04T11:45:18.098  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.GetBucketAccelerateConfiguration => 200
2023-10-04T11:45:18.109  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetBucketTagging => 404 (NoSuchTagSet)
2023-10-04T11:45:18.124  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.GetPublicAccessBlock => 404 (NoSuchPublicAccessBlockConfiguration)
2023-10-04T11:45:18.135  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetBucketLogging => 200
2023-10-04T11:45:18.162 DEBUG --- [   asgi_gw_0] plugin.manager             : instantiating plugin PluginSpec(localstack.aws.provider.cloudformation:default = <function cloudformation at 0x7f12932add00>)
2023-10-04T11:45:18.163 DEBUG --- [   asgi_gw_0] plugin.manager             : loading plugin localstack.aws.provider:cloudformation:default
2023-10-04T11:45:19.568  INFO --- [   asgi_gw_0] localstack.utils.bootstrap : Execution of "_load_service_plugin" took 1405.93ms
2023-10-04T11:45:19.569  INFO --- [   asgi_gw_0] localstack.utils.bootstrap : Execution of "require" took 1406.75ms
2023-10-04T11:45:19.827  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS cloudformation.DescribeStacks => 400 (ValidationError)
2023-10-04T11:45:19.842  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetBucketLocation => 200
2023-10-04T11:45:19.863  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.ListObjectsV2 => 200
2023-10-04T11:45:20.004 DEBUG --- [   asgi_gw_0] plugin.manager             : instantiating plugin PluginSpec(localstack.aws.provider.lambda:default = <function lambda_ at 0x7f12932ac5e0>)
2023-10-04T11:45:20.010 DEBUG --- [   asgi_gw_0] plugin.manager             : loading plugin localstack.aws.provider:lambda:default
2023-10-04T11:45:20.049 DEBUG --- [   asgi_gw_0] plugin.manager             : no extensions found in namespace localstack.hooks.lambda_inject_layer_fetcher
2023-10-04T11:45:20.099 DEBUG --- [   asgi_gw_0] l.s.lambda_.urlrouter      : Registering parameterized Lambda routes.
2023-10-04T11:45:20.102 DEBUG --- [   asgi_gw_0] stevedore.extension        : found extension EntryPoint(name='docker', value='localstack.services.lambda_.invocation.plugins:DockerRuntimeExecutorPlugin', group='localstack.lambda.runtime_executor')
2023-10-04T11:45:20.102 DEBUG --- [   asgi_gw_0] plugin.manager             : instantiating plugin PluginSpec(localstack.lambda.runtime_executor.docker = <class 'localstack.services.lambda_.invocation.plugins.DockerRuntimeExecutorPlugin'>)
2023-10-04T11:45:20.102 DEBUG --- [   asgi_gw_0] plugin.manager             : loading plugin localstack.lambda.runtime_executor:docker
2023-10-04T11:45:20.259  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS lambda.GetFunction => 404 (ResourceNotFoundException)
2023-10-04T11:45:20.263  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS lambda.GetFunction => 404 (ResourceNotFoundException)
2023-10-04T11:45:20.273  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS lambda.GetFunction => 404 (ResourceNotFoundException)
2023-10-04T11:45:20.274  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS lambda.GetFunction => 404 (ResourceNotFoundException)
2023-10-04T11:45:20.632  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.PutObject => 200
2023-10-04T11:45:20.646  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS s3.PutObject => 200
2023-10-04T11:45:20.660  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.PutObject => 200
2023-10-04T11:45:20.693  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS s3.GetObject => 200
2023-10-04T11:45:20.702  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS cloudformation.CreateChangeSet => 200
2023-10-04T11:45:20.713  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS cloudformation.DescribeChangeSet => 200
2023-10-04T11:45:20.732 DEBUG --- [   asgi_gw_0] l.s.c.provider             : Executing change set "demo1-change-set" for stack "demo1" with 26 resources ...
2023-10-04T11:45:20.734  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS cloudformation.ExecuteChangeSet => 200
2023-10-04T11:45:20.895 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "HttpHandleRequestLogGroup" (1/26) type "AWS::Logs::LogGroup" in loop iteration 1 (should_deploy=True)
2023-10-04T11:45:20.895 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::Logs::LogGroup" id "HttpHandleRequestLogGroup"
2023-10-04T11:45:20.904 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::Logs::LogGroup" in account 000000000000 region us-east-1: create_log_group {'logGroupName': '/aws/lambda/localstack-demo-local-httpHandleRequest'}
2023-10-04T11:45:20.914 DEBUG --- [   asgi_gw_1] plugin.manager             : instantiating plugin PluginSpec(localstack.aws.provider.logs:default = <function logs at 0x7f12932af1a0>)
2023-10-04T11:45:20.914 DEBUG --- [   asgi_gw_1] plugin.manager             : loading plugin localstack.aws.provider:logs:default
2023-10-04T11:45:20.987 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::Logs::LogGroup:HttpHandleRequestLogGroup
2023-10-04T11:45:21.024 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "SqsHandleItemLogGroup" (1/25) type "AWS::Logs::LogGroup" in loop iteration 1 (should_deploy=True)
2023-10-04T11:45:21.024 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::Logs::LogGroup" id "SqsHandleItemLogGroup"
2023-10-04T11:45:21.024 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::Logs::LogGroup" in account 000000000000 region us-east-1: create_log_group {'logGroupName': '/aws/lambda/localstack-demo-local-sqsHandleItem'}
2023-10-04T11:45:21.032 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::Logs::LogGroup:SqsHandleItemLogGroup
2023-10-04T11:45:21.063 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "BackendProcessRequestLogGroup" (1/24) type "AWS::Logs::LogGroup" in loop iteration 1 (should_deploy=True)
2023-10-04T11:45:21.063 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::Logs::LogGroup" id "BackendProcessRequestLogGroup"
2023-10-04T11:45:21.064 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::Logs::LogGroup" in account 000000000000 region us-east-1: create_log_group {'logGroupName': '/aws/lambda/localstack-demo-local-backendProcessRequest'}
2023-10-04T11:45:21.070 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::Logs::LogGroup:BackendProcessRequestLogGroup
2023-10-04T11:45:21.101 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "BackendArchiveResultLogGroup" (1/23) type "AWS::Logs::LogGroup" in loop iteration 1 (should_deploy=True)
2023-10-04T11:45:21.101 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::Logs::LogGroup" id "BackendArchiveResultLogGroup"
2023-10-04T11:45:21.101 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::Logs::LogGroup" in account 000000000000 region us-east-1: create_log_group {'logGroupName': '/aws/lambda/localstack-demo-local-backendArchiveResult'}
2023-10-04T11:45:21.109 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::Logs::LogGroup:BackendArchiveResultLogGroup
2023-10-04T11:45:22.364 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "IamRoleLambdaExecution" not yet satisfied, retrying in next loop: Unresolved dependencies: requestQueue
2023-10-04T11:45:22.433 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "HttpHandleRequestLambdaFunction" not yet satisfied, retrying in next loop: Unresolved dependencies: IamRoleLambdaExecution
2023-10-04T11:45:22.594 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "SqsHandleItemLambdaFunction" not yet satisfied, retrying in next loop: Unable to resolve attribute ref processingStateMachine.Arn
2023-10-04T11:45:22.669 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "BackendProcessRequestLambdaFunction" not yet satisfied, retrying in next loop: Unresolved dependencies: IamRoleLambdaExecution
2023-10-04T11:45:22.761 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "BackendArchiveResultLambdaFunction" not yet satisfied, retrying in next loop: Unresolved dependencies: IamRoleLambdaExecution
2023-10-04T11:45:22.779 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Unable to resolve Ref for resource "HttpHandleRequestLambdaFunction" (yet) - {'Type': 'AWS::Lambda::Function', 'DependsOn': ['HttpHandleRequestLogGroup'], 'LogicalResourceId': 'HttpHandleRequestLambdaFunction', 'Properties': {'Code': {'S3Bucket': 'localstack-test-bucket', 'S3Key': 'serverless/localstack-demo/local/1696419918030-2023-10-04T11:45:18.030Z/localstack-demo.zip'}, 'Handler': 'demo/lambdas/app.handleRequest', 'Runtime': 'nodejs14.x', 'FunctionName': 'localstack-demo-local-httpHandleRequest', 'MemorySize': 1024, 'Timeout': 15, 'Role': {'Fn::GetAtt': ['IamRoleLambdaExecution', 'Arn']}}}
2023-10-04T11:45:22.779 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "HttpHandleRequestLambdaVersionRY1qbZ74r8ccATUGipmVa0Jga5HAQc2zexBrSk789E" not yet satisfied, retrying in next loop: Unable to resolve Ref for resource "HttpHandleRequestLambdaFunction" (yet)
2023-10-04T11:45:22.797 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Unable to resolve Ref for resource "SqsHandleItemLambdaFunction" (yet) - {'Type': 'AWS::Lambda::Function', 'DependsOn': ['SqsHandleItemLogGroup'], 'LogicalResourceId': 'SqsHandleItemLambdaFunction', 'Properties': {'Code': {'S3Bucket': 'localstack-test-bucket', 'S3Key': 'serverless/localstack-demo/local/1696419918030-2023-10-04T11:45:18.030Z/localstack-demo.zip'}, 'Handler': 'demo/lambdas/worker.triggerProcessing', 'Runtime': 'ruby2.7', 'FunctionName': 'localstack-demo-local-sqsHandleItem', 'MemorySize': 1024, 'Timeout': 15, 'Environment': {'Variables': {'STATE_MACHINE_ARN': {'Fn::Sub': '${processingStateMachine.Arn}'}}}, 'Role': {'Fn::GetAtt': ['IamRoleLambdaExecution', 'Arn']}}}
2023-10-04T11:45:22.797 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "SqsHandleItemLambdaVersion0AEAXJamGgssLk9pNg1oN2f0ejz2glYGQ3qrq1dvo" not yet satisfied, retrying in next loop: Unable to resolve Ref for resource "SqsHandleItemLambdaFunction" (yet)
2023-10-04T11:45:22.814 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Unable to resolve Ref for resource "BackendProcessRequestLambdaFunction" (yet) - {'Type': 'AWS::Lambda::Function', 'DependsOn': ['BackendProcessRequestLogGroup'], 'LogicalResourceId': 'BackendProcessRequestLambdaFunction', 'Properties': {'Code': {'S3Bucket': 'localstack-test-bucket', 'S3Key': 'serverless/localstack-demo/local/1696419918030-2023-10-04T11:45:18.030Z/localstack-demo.zip'}, 'Handler': 'demo/lambdas/processing.handle_request', 'Runtime': 'python3.7', 'FunctionName': 'localstack-demo-local-backendProcessRequest', 'MemorySize': 1024, 'Timeout': 15, 'Role': {'Fn::GetAtt': ['IamRoleLambdaExecution', 'Arn']}}}
2023-10-04T11:45:22.814 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "BackendProcessRequestLambdaVersionBbNNGNO040Ry6iFXMEcOkqFYK3rqF1Q2Jm9ipy0aA" not yet satisfied, retrying in next loop: Unable to resolve Ref for resource "BackendProcessRequestLambdaFunction" (yet)
2023-10-04T11:45:22.831 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Unable to resolve Ref for resource "BackendArchiveResultLambdaFunction" (yet) - {'Type': 'AWS::Lambda::Function', 'DependsOn': ['BackendArchiveResultLogGroup'], 'LogicalResourceId': 'BackendArchiveResultLambdaFunction', 'Properties': {'Code': {'S3Bucket': 'localstack-test-bucket', 'S3Key': 'serverless/localstack-demo/local/1696419918030-2023-10-04T11:45:18.030Z/localstack-demo.zip'}, 'Handler': 'demo/lambdas/processing.archive_result', 'Runtime': 'python3.7', 'FunctionName': 'localstack-demo-local-backendArchiveResult', 'MemorySize': 1024, 'Timeout': 15, 'Environment': {'Variables': {'ARCHIVE_BUCKET': 'archive-bucket'}}, 'Role': {'Fn::GetAtt': ['IamRoleLambdaExecution', 'Arn']}}}
2023-10-04T11:45:22.831 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "BackendArchiveResultLambdaVersionjjIXMf3A4GHidwnrx24HuUiyySCMeOlaHN8TTO1qcUs" not yet satisfied, retrying in next loop: Unable to resolve Ref for resource "BackendArchiveResultLambdaFunction" (yet)
2023-10-04T11:45:22.871 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "ApiGatewayRestApi" (10/22) type "AWS::ApiGateway::RestApi" in loop iteration 1 (should_deploy=True)
2023-10-04T11:45:22.871 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::ApiGateway::RestApi" id "ApiGatewayRestApi"
2023-10-04T11:45:23.011 DEBUG --- [   asgi_gw_0] plugin.manager             : instantiating plugin PluginSpec(localstack.aws.provider.apigateway:default = <function apigateway at 0x7f12932adbc0>)
2023-10-04T11:45:23.011 DEBUG --- [   asgi_gw_0] plugin.manager             : loading plugin localstack.aws.provider:apigateway:default
2023-10-04T11:45:23.270 DEBUG --- [   asgi_gw_0] l.s.apigateway.router_asf  : Registering parameterized API Gateway routes.
2023-10-04T11:45:23.536 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::ApiGateway::RestApi:ApiGatewayRestApi
2023-10-04T11:45:23.597 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "ApiGatewayResourceRequests" (10/21) type "AWS::ApiGateway::Resource" in loop iteration 1 (should_deploy=True)
2023-10-04T11:45:23.598 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::ApiGateway::Resource" id "ApiGatewayResourceRequests"
2023-10-04T11:45:23.603 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::ApiGateway::Resource" in account 000000000000 region us-east-1: create_resource {'restApiId': 'ftytsywd7v', 'pathPart': 'requests', 'parentId': 'yuhom1qmg7'}
2023-10-04T11:45:23.612 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::ApiGateway::Resource:ApiGatewayResourceRequests
2023-10-04T11:45:23.854 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "ApiGatewayMethodRequestsOptions" (10/20) type "AWS::ApiGateway::Method" in loop iteration 1 (should_deploy=True)
2023-10-04T11:45:23.854 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::ApiGateway::Method" id "ApiGatewayMethodRequestsOptions"
2023-10-04T11:45:23.855 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::ApiGateway::Method" in account 000000000000 region us-east-1: put_method {'authorizationType': 'NONE', 'httpMethod': 'OPTIONS', 'requestParameters': {}, 'resourceId': 'waownzrog5', 'restApiId': 'ftytsywd7v', 'requestModels': {}}
2023-10-04T11:45:23.863 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::ApiGateway::Method:ApiGatewayMethodRequestsOptions
2023-10-04T11:45:24.051 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "ApiGatewayMethodRequestsPost" not yet satisfied, retrying in next loop: Unresolved dependencies: HttpHandleRequestLambdaFunction
2023-10-04T11:45:24.185 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "ApiGatewayMethodRequestsGet" not yet satisfied, retrying in next loop: Unresolved dependencies: HttpHandleRequestLambdaFunction
2023-10-04T11:45:24.221 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "ApiGatewayDeployment1696419911247" (12/19) type "AWS::ApiGateway::Deployment" in loop iteration 1 (should_deploy=True)
2023-10-04T11:45:24.222 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependency for resource {'Type': 'AWS::ApiGateway::Deployment', 'DependsOn': ['ApiGatewayMethodRequestsOptions', 'ApiGatewayMethodRequestsPost', 'ApiGatewayMethodRequestsGet'], 'LogicalResourceId': 'ApiGatewayDeployment1696419911247', 'Properties': {'RestApiId': 'ftytsywd7v', 'StageName': 'local'}} not yet deployed: ApiGatewayMethodRequestsGet {'Type': 'AWS::ApiGateway::Method', 'DependsOn': ['HttpHandleRequestLambdaPermissionApiGateway'], 'LogicalResourceId': 'ApiGatewayMethodRequestsGet', 'Properties': {'HttpMethod': 'GET', 'RequestParameters': {}, 'ResourceId': 'waownzrog5', 'RestApiId': 'ftytsywd7v', 'ApiKeyRequired': False, 'AuthorizationType': 'NONE', 'Integration': {'IntegrationHttpMethod': 'POST', 'Type': 'AWS_PROXY', 'Uri': {'Fn::Join': ['', ['arn:', {'Ref': 'AWS::Partition'}, ':apigateway:', {'Ref': 'AWS::Region'}, ':lambda:path/2015-03-31/functions/', {'Fn::GetAtt': ['HttpHandleRequestLambdaFunction', 'Arn']}, '/invocations']]}}, 'MethodResponses': []}}
2023-10-04T11:45:24.240 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "HttpHandleRequestLambdaPermissionApiGateway" not yet satisfied, retrying in next loop: Unresolved dependencies: HttpHandleRequestLambdaFunction
2023-10-04T11:45:24.272 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "SqsHandleItemEventSourceMappingSQSRequestQueue" not yet satisfied, retrying in next loop: Unresolved dependencies: requestQueue
2023-10-04T11:45:24.375 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "appDatabase" (15/19) type "AWS::DynamoDB::Table" in loop iteration 1 (should_deploy=True)
2023-10-04T11:45:24.376 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::DynamoDB::Table" id "appDatabase"
2023-10-04T11:45:24.550 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::DynamoDB::Table" in account 000000000000 region us-east-1: create_table {'TableName': 'appRequests', 'AttributeDefinitions': [{'AttributeName': 'id', 'AttributeType': 'S'}, {'AttributeName': 'requestID', 'AttributeType': 'S'}], 'KeySchema': [{'AttributeName': 'id', 'KeyType': 'HASH'}, {'AttributeName': 'requestID', 'KeyType': 'RANGE'}], 'BillingMode': 'PAY_PER_REQUEST'}
2023-10-04T11:45:24.564 DEBUG --- [   asgi_gw_0] plugin.manager             : instantiating plugin PluginSpec(localstack.aws.provider.dynamodb:default = <function dynamodb at 0x7f12932ae0c0>)
2023-10-04T11:45:24.564 DEBUG --- [   asgi_gw_0] plugin.manager             : loading plugin localstack.aws.provider:dynamodb:default
2023-10-04T11:45:24.587 DEBUG --- [   asgi_gw_0] localstack.packages.api    : Installation of dynamodb-local skipped (already installed).
2023-10-04T11:45:24.587 DEBUG --- [   asgi_gw_0] localstack.packages.api    : Performing runtime setup for already installed package.
2023-10-04T11:45:24.588 DEBUG --- [   asgi_gw_0] l.services.dynamodb.server : Starting DynamoDB Local: ['java', '-Xmx256m', '-javaagent:/usr/lib/localstack/dynamodb-local/latest/ddb-local-loader-0.1.jar', '-Djava.library.path=/usr/lib/localstack/dynamodb-local/latest/DynamoDBLocal_lib', '-jar', '/usr/lib/localstack/dynamodb-local/latest/DynamoDBLocal.jar', '-port', '40631', '-dbPath', '/var/lib/localstack/tmp/state/dynamodb']
2023-10-04T11:45:24.588 DEBUG --- [functhread66] localstack.utils.run       : Executing command: ['java', '-Xmx256m', '-javaagent:/usr/lib/localstack/dynamodb-local/latest/ddb-local-loader-0.1.jar', '-Djava.library.path=/usr/lib/localstack/dynamodb-local/latest/DynamoDBLocal_lib', '-jar', '/usr/lib/localstack/dynamodb-local/latest/DynamoDBLocal.jar', '-port', '40631', '-dbPath', '/var/lib/localstack/tmp/state/dynamodb']
2023-10-04T11:45:24.977 DEBUG --- [functhread66] l.services.dynamodb.server : Initializing DynamoDB Local with the following configuration:
2023-10-04T11:45:24.977 DEBUG --- [functhread66] l.services.dynamodb.server : Port:	40631
2023-10-04T11:45:24.977 DEBUG --- [functhread66] l.services.dynamodb.server : InMemory:	false
2023-10-04T11:45:24.977 DEBUG --- [functhread66] l.services.dynamodb.server : DbPath:	/var/lib/localstack/tmp/state/dynamodb
2023-10-04T11:45:24.977 DEBUG --- [functhread66] l.services.dynamodb.server : SharedDb:	false
2023-10-04T11:45:24.977 DEBUG --- [functhread66] l.services.dynamodb.server : shouldDelayTransientStatuses:	false
2023-10-04T11:45:24.978 DEBUG --- [functhread66] l.services.dynamodb.server : CorsParams:	null
2023-10-04T11:45:24.978 DEBUG --- [functhread66] l.services.dynamodb.server : 
2023-10-04T11:45:25.747  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T11:45:26.695  INFO --- [   asgi_gw_0] localstack.utils.bootstrap : Execution of "require" took 2130.34ms
2023-10-04T11:45:27.051 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::DynamoDB::Table:appDatabase
2023-10-04T11:45:27.161 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "archiveBucket" (15/18) type "AWS::S3::Bucket" in loop iteration 1 (should_deploy=True)
2023-10-04T11:45:27.161 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::S3::Bucket" id "archiveBucket"
2023-10-04T11:45:27.379 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::S3::Bucket:archiveBucket
2023-10-04T11:45:27.603 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "requestQueue" (15/17) type "AWS::SQS::Queue" in loop iteration 1 (should_deploy=True)
2023-10-04T11:45:27.603 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::IAM::AccessKey', value='localstack.services.iam.resource_providers.aws_iam_accesskey:IAMAccessKeyProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.605 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::IAM::Group', value='localstack.services.iam.resource_providers.aws_iam_group:IAMGroupProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.606 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::IAM::InstanceProfile', value='localstack.services.iam.resource_providers.aws_iam_instanceprofile:IAMInstanceProfileProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.607 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::IAM::ManagedPolicy', value='localstack.services.iam.resource_providers.aws_iam_managedpolicy:IAMManagedPolicyProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.608 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::IAM::Policy', value='localstack.services.iam.resource_providers.aws_iam_policy:IAMPolicyProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.609 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::IAM::Role', value='localstack.services.iam.resource_providers.aws_iam_role:IAMRoleProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.610 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::IAM::ServiceLinkedRole', value='localstack.services.iam.resource_providers.aws_iam_servicelinkedrole:IAMServiceLinkedRoleProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.611 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::IAM::User', value='localstack.services.iam.resource_providers.aws_iam_user:IAMUserProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.612 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::Kinesis::Stream', value='localstack.services.kinesis.resource_providers.aws_kinesis_stream:KinesisStreamProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.613 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::Kinesis::StreamConsumer', value='localstack.services.kinesis.resource_providers.aws_kinesis_streamconsumer:KinesisStreamConsumerProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.614 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::Lambda::Alias', value='localstack.services.awslambda.resource_providers.aws_lambda_alias:LambdaAliasProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.616 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::OpenSearchService::Domain', value='localstack.services.opensearch.resource_providers.aws_opensearchservice_domain:OpenSearchServiceDomainProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.620 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::Route53::HealthCheck', value='localstack.services.route53.resource_providers.aws_route53_healthcheck:Route53HealthCheckProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.622 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::Route53::RecordSet', value='localstack.services.route53.resource_providers.aws_route53_recordset:Route53RecordSetProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.623 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::SNS::Topic', value='localstack.services.sns.resource_providers.aws_sns_topic:SNSTopicProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.625 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::SQS::Queue', value='localstack.services.sqs.resource_providers.aws_sqs_queue:SQSQueueProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.627 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::SQS::QueuePolicy', value='localstack.services.sqs.resource_providers.aws_sqs_queuepolicy:SQSQueuePolicyProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.627 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::SSM::Parameter', value='localstack.services.ssm.resource_providers.aws_ssm_parameter:SSMParameterProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.629 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::Scheduler::Schedule', value='localstack.services.scheduler.resource_providers.aws_scheduler_schedule:SchedulerScheduleProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.632 DEBUG --- [functhread41] stevedore.extension        : found extension EntryPoint(name='AWS::Scheduler::ScheduleGroup', value='localstack.services.scheduler.resource_providers.aws_scheduler_schedulegroup:SchedulerScheduleGroupProviderPlugin', group='localstack.cloudformation.resource_providers')
2023-10-04T11:45:27.633 DEBUG --- [functhread41] plugin.manager             : instantiating plugin PluginSpec(localstack.cloudformation.resource_providers.AWS::SQS::Queue = <class 'localstack.services.sqs.resource_providers.aws_sqs_queue.SQSQueueProviderPlugin'>)
2023-10-04T11:45:27.633 DEBUG --- [functhread41] plugin.manager             : loading plugin localstack.cloudformation.resource_providers:AWS::SQS::Queue
2023-10-04T11:45:27.826 DEBUG --- [   asgi_gw_1] plugin.manager             : instantiating plugin PluginSpec(localstack.aws.provider.sqs:default = <function sqs at 0x7f12932d8860>)
2023-10-04T11:45:27.826 DEBUG --- [   asgi_gw_1] plugin.manager             : loading plugin localstack.aws.provider:sqs:default
2023-10-04T11:45:27.985 DEBUG --- [   asgi_gw_1] l.services.sqs.provider    : creating queue key=requestQueue attributes=None tags=None
2023-10-04T11:45:28.071 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "processingStateMachine" not yet satisfied, retrying in next loop: Unable to resolve attribute ref processingStateMachineRole.Arn
2023-10-04T11:45:28.465 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "processingStateMachineRole" not yet satisfied, retrying in next loop: Unable to resolve attribute ref BackendProcessRequestLambdaFunction.Arn
2023-10-04T11:45:29.351 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "IamRoleLambdaExecution" (1/16) type "AWS::IAM::Role" in loop iteration 2 (should_deploy=True)
2023-10-04T11:45:29.351 DEBUG --- [functhread41] plugin.manager             : instantiating plugin PluginSpec(localstack.cloudformation.resource_providers.AWS::IAM::Role = <class 'localstack.services.iam.resource_providers.aws_iam_role.IAMRoleProviderPlugin'>)
2023-10-04T11:45:29.351 DEBUG --- [functhread41] plugin.manager             : loading plugin localstack.cloudformation.resource_providers:AWS::IAM::Role
2023-10-04T11:45:29.387 DEBUG --- [   asgi_gw_1] plugin.manager             : instantiating plugin PluginSpec(localstack.aws.provider.iam:default = <function iam at 0x7f12932ae700>)
2023-10-04T11:45:29.387 DEBUG --- [   asgi_gw_1] plugin.manager             : loading plugin localstack.aws.provider:iam:default
2023-10-04T11:45:29.504 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "HttpHandleRequestLambdaFunction" (1/15) type "AWS::Lambda::Function" in loop iteration 2 (should_deploy=True)
2023-10-04T11:45:29.504 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::Lambda::Function" id "HttpHandleRequestLambdaFunction"
2023-10-04T11:45:29.518 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::Lambda::Function" in account 000000000000 region us-east-1: create_function {'Code': {'S3Bucket': 'localstack-test-bucket', 'S3Key': 'serverless/localstack-demo/local/1696419918030-2023-10-04T11:45:18.030Z/localstack-demo.zip'}, 'FunctionName': 'localstack-demo-local-httpHandleRequest', 'Handler': 'demo/lambdas/app.handleRequest', 'MemorySize': 1024, 'Runtime': 'nodejs14.x', 'Role': 'arn:aws:iam::000000000000:role/localstack-demo-local-us-east-1-lambdaRole', 'Timeout': 15}
2023-10-04T11:45:30.582 DEBUG --- [rvice-task_0] plugin.manager             : no extensions found in namespace localstack.hooks.lambda_prepare_docker_executors
2023-10-04T11:45:30.582 DEBUG --- [rvice-task_0] l.s.l.i.lambda_models      : Saving code localstack-demo-local-httpHandleRequest-d3a474e4-e0b8-4549-8ada-47bc16e0eaef to disk
2023-10-04T11:45:30.585 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::Lambda::Function:HttpHandleRequestLambdaFunction
2023-10-04T11:45:30.747 DEBUG --- [rvice-task_0] localstack.utils.run       : Executing command: ['unzip', '-o', '-q', '/tmp/tmpt3ifrlla']
2023-10-04T11:45:30.777  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T11:45:30.778 DEBUG --- [rvice-task_0] l.u.c.docker_sdk_client    : Pulling Docker image: public.ecr.aws/lambda/nodejs:14
2023-10-04T11:45:35.814  INFO --- [   asgi_gw_1] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T11:45:37.626 DEBUG --- [rvice-task_0] l.s.l.i.version_manager    : Version preparation of function arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-httpHandleRequest:$LATEST took 7043.57ms
2023-10-04T11:45:37.626 DEBUG --- [rvice-task_0] l.s.l.i.version_manager    : Changing Lambda arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-httpHandleRequest:$LATEST (id fd46ab99) to active
2023-10-04T11:45:37.626 DEBUG --- [rvice-task_0] l.s.l.i.event_manager      : Starting event manager arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-httpHandleRequest:$LATEST id 139718010503248
2023-10-04T11:45:38.041 DEBUG --- [   asgi_gw_0] l.services.sqs.provider    : creating queue key=localstack-demo-local-httpHandleRequest-31c2a5188022659c723b4e6bc66e04bb attributes=None tags=None
2023-10-04T11:45:38.980 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "SqsHandleItemLambdaFunction" not yet satisfied, retrying in next loop: Unable to resolve attribute ref processingStateMachine.Arn
2023-10-04T11:45:39.054 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "BackendProcessRequestLambdaFunction" (2/14) type "AWS::Lambda::Function" in loop iteration 2 (should_deploy=True)
2023-10-04T11:45:39.055 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::Lambda::Function" id "BackendProcessRequestLambdaFunction"
2023-10-04T11:45:39.056 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::Lambda::Function" in account 000000000000 region us-east-1: create_function {'Code': {'S3Bucket': 'localstack-test-bucket', 'S3Key': 'serverless/localstack-demo/local/1696419918030-2023-10-04T11:45:18.030Z/localstack-demo.zip'}, 'FunctionName': 'localstack-demo-local-backendProcessRequest', 'Handler': 'demo/lambdas/processing.handle_request', 'MemorySize': 1024, 'Runtime': 'python3.7', 'Role': 'arn:aws:iam::000000000000:role/localstack-demo-local-us-east-1-lambdaRole', 'Timeout': 15}
2023-10-04T11:45:39.331 DEBUG --- [rvice-task_0] l.s.l.i.lambda_models      : Saving code localstack-demo-local-backendProcessRequest-b5019902-2d4e-445c-8e5c-dc31dec9b727 to disk
2023-10-04T11:45:39.334 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::Lambda::Function:BackendProcessRequestLambdaFunction
2023-10-04T11:45:39.632 DEBUG --- [rvice-task_0] localstack.utils.run       : Executing command: ['unzip', '-o', '-q', '/tmp/tmpqegcsa8r']
2023-10-04T11:45:39.642 DEBUG --- [rvice-task_0] l.u.c.docker_sdk_client    : Pulling Docker image: public.ecr.aws/lambda/python:3.7
2023-10-04T11:45:40.093 DEBUG --- [   asgi_gw_2] plugin.manager             : instantiating plugin PluginSpec(localstack.aws.provider.cloudwatch:default = <function cloudwatch at 0x7f12932adf80>)
2023-10-04T11:45:40.093 DEBUG --- [   asgi_gw_2] plugin.manager             : loading plugin localstack.aws.provider:cloudwatch:default
2023-10-04T11:45:40.106 DEBUG --- [   asgi_gw_2] l.s.cloudwatch.provider    : starting cloudwatch scheduler
2023-10-04T11:45:40.859  INFO --- [   asgi_gw_2] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T11:45:45.448 DEBUG --- [rvice-task_0] l.s.l.i.version_manager    : Version preparation of function arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest:$LATEST took 6116.66ms
2023-10-04T11:45:45.448 DEBUG --- [rvice-task_0] l.s.l.i.version_manager    : Changing Lambda arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest:$LATEST (id ce200429) to active
2023-10-04T11:45:45.448 DEBUG --- [rvice-task_0] l.s.l.i.event_manager      : Starting event manager arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest:$LATEST id 139717107978512
2023-10-04T11:45:45.458 DEBUG --- [   asgi_gw_0] l.services.sqs.provider    : creating queue key=localstack-demo-local-backendProcessRequest-c58ef2c7f23a609904d09563184733f6 attributes=None tags=None
2023-10-04T11:45:45.891  INFO --- [   asgi_gw_0] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T11:45:46.637 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "BackendArchiveResultLambdaFunction" (2/13) type "AWS::Lambda::Function" in loop iteration 2 (should_deploy=True)
2023-10-04T11:45:46.638 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::Lambda::Function" id "BackendArchiveResultLambdaFunction"
2023-10-04T11:45:46.639 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::Lambda::Function" in account 000000000000 region us-east-1: create_function {'Code': {'S3Bucket': 'localstack-test-bucket', 'S3Key': 'serverless/localstack-demo/local/1696419918030-2023-10-04T11:45:18.030Z/localstack-demo.zip'}, 'Environment': {'Variables': {'ARCHIVE_BUCKET': 'archive-bucket'}}, 'FunctionName': 'localstack-demo-local-backendArchiveResult', 'Handler': 'demo/lambdas/processing.archive_result', 'MemorySize': 1024, 'Runtime': 'python3.7', 'Role': 'arn:aws:iam::000000000000:role/localstack-demo-local-us-east-1-lambdaRole', 'Timeout': 15}
2023-10-04T11:45:47.251 DEBUG --- [rvice-task_0] l.s.l.i.lambda_models      : Saving code localstack-demo-local-backendArchiveResult-b3b0d909-3740-49e6-b7ee-dfb82e8eb1cd to disk
2023-10-04T11:45:47.254 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::Lambda::Function:BackendArchiveResultLambdaFunction
2023-10-04T11:45:47.568 DEBUG --- [rvice-task_0] localstack.utils.run       : Executing command: ['unzip', '-o', '-q', '/tmp/tmpg3q98_3x']
2023-10-04T11:45:47.577 DEBUG --- [rvice-task_0] l.s.l.i.version_manager    : Version preparation of function arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult:$LATEST took 325.88ms
2023-10-04T11:45:47.577 DEBUG --- [rvice-task_0] l.s.l.i.version_manager    : Changing Lambda arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult:$LATEST (id eca51201) to active
2023-10-04T11:45:47.577 DEBUG --- [rvice-task_0] l.s.l.i.event_manager      : Starting event manager arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult:$LATEST id 139716481149840
2023-10-04T11:45:47.582 DEBUG --- [   asgi_gw_0] l.services.sqs.provider    : creating queue key=localstack-demo-local-backendArchiveResult-52693a7458b0fabac579611b12d2d0de attributes=None tags=None
2023-10-04T11:45:48.327 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "HttpHandleRequestLambdaVersionRY1qbZ74r8ccATUGipmVa0Jga5HAQc2zexBrSk789E" (2/12) type "AWS::Lambda::Version" in loop iteration 2 (should_deploy=True)
2023-10-04T11:45:48.327 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::Lambda::Version" id "HttpHandleRequestLambdaVersionRY1qbZ74r8ccATUGipmVa0Jga5HAQc2zexBrSk789E"
2023-10-04T11:45:48.327 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::Lambda::Version" in account 000000000000 region us-east-1: publish_version {'FunctionName': 'localstack-demo-local-httpHandleRequest', 'CodeSha256': 'n3CrpOYRu3s0C/1lwf5U2bua69Ql9XhDgQ/8ZpYJf5c='}
2023-10-04T11:45:48.336 DEBUG --- [   asgi_gw_2] l.s.l.i.version_manager    : Version preparation of function arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-httpHandleRequest:1 took 0.18ms
2023-10-04T11:45:48.336 DEBUG --- [   asgi_gw_2] l.s.l.i.version_manager    : Changing Lambda arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-httpHandleRequest:1 (id fd46ab99) to active
2023-10-04T11:45:48.336 DEBUG --- [   asgi_gw_2] l.s.l.i.event_manager      : Starting event manager arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-httpHandleRequest:1 id 139717304150800
2023-10-04T11:45:48.343 DEBUG --- [   asgi_gw_5] l.services.sqs.provider    : creating queue key=localstack-demo-local-httpHandleRequest-436447060cd7df1f723a75e7021c4b3f attributes=None tags=None
2023-10-04T11:45:48.373 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::Lambda::Version:HttpHandleRequestLambdaVersionRY1qbZ74r8ccATUGipmVa0Jga5HAQc2zexBrSk789E
2023-10-04T11:45:48.446 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Unable to resolve Ref for resource "SqsHandleItemLambdaFunction" (yet) - {'Type': 'AWS::Lambda::Function', 'DependsOn': ['SqsHandleItemLogGroup'], 'LogicalResourceId': 'SqsHandleItemLambdaFunction', 'Properties': {'Code': {'S3Bucket': 'localstack-test-bucket', 'S3Key': 'serverless/localstack-demo/local/1696419918030-2023-10-04T11:45:18.030Z/localstack-demo.zip'}, 'Handler': 'demo/lambdas/worker.triggerProcessing', 'Runtime': 'ruby2.7', 'FunctionName': 'localstack-demo-local-sqsHandleItem', 'MemorySize': 1024, 'Timeout': 15, 'Environment': {'Variables': {'STATE_MACHINE_ARN': {'Fn::Sub': '${processingStateMachine.Arn}'}}}, 'Role': {'Fn::GetAtt': ['IamRoleLambdaExecution', 'Arn']}}}
2023-10-04T11:45:48.447 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "SqsHandleItemLambdaVersion0AEAXJamGgssLk9pNg1oN2f0ejz2glYGQ3qrq1dvo" not yet satisfied, retrying in next loop: Unable to resolve Ref for resource "SqsHandleItemLambdaFunction" (yet)
2023-10-04T11:45:48.484 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "BackendProcessRequestLambdaVersionBbNNGNO040Ry6iFXMEcOkqFYK3rqF1Q2Jm9ipy0aA" (3/11) type "AWS::Lambda::Version" in loop iteration 2 (should_deploy=True)
2023-10-04T11:45:48.485 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::Lambda::Version" id "BackendProcessRequestLambdaVersionBbNNGNO040Ry6iFXMEcOkqFYK3rqF1Q2Jm9ipy0aA"
2023-10-04T11:45:48.485 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::Lambda::Version" in account 000000000000 region us-east-1: publish_version {'FunctionName': 'localstack-demo-local-backendProcessRequest', 'CodeSha256': 'n3CrpOYRu3s0C/1lwf5U2bua69Ql9XhDgQ/8ZpYJf5c='}
2023-10-04T11:45:48.493 DEBUG --- [   asgi_gw_2] l.s.l.i.version_manager    : Version preparation of function arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest:1 took 0.13ms
2023-10-04T11:45:48.493 DEBUG --- [   asgi_gw_2] l.s.l.i.version_manager    : Changing Lambda arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest:1 (id ce200429) to active
2023-10-04T11:45:48.493 DEBUG --- [   asgi_gw_2] l.s.l.i.event_manager      : Starting event manager arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest:1 id 139716477018960
2023-10-04T11:45:48.506 DEBUG --- [   asgi_gw_5] l.services.sqs.provider    : creating queue key=localstack-demo-local-backendProcessRequest-a36cac440ec5da78b40a6e51e72dd8f3 attributes=None tags=None
2023-10-04T11:45:48.536 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::Lambda::Version:BackendProcessRequestLambdaVersionBbNNGNO040Ry6iFXMEcOkqFYK3rqF1Q2Jm9ipy0aA
2023-10-04T11:45:48.608 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "BackendArchiveResultLambdaVersionjjIXMf3A4GHidwnrx24HuUiyySCMeOlaHN8TTO1qcUs" (3/10) type "AWS::Lambda::Version" in loop iteration 2 (should_deploy=True)
2023-10-04T11:45:48.608 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::Lambda::Version" id "BackendArchiveResultLambdaVersionjjIXMf3A4GHidwnrx24HuUiyySCMeOlaHN8TTO1qcUs"
2023-10-04T11:45:48.609 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::Lambda::Version" in account 000000000000 region us-east-1: publish_version {'FunctionName': 'localstack-demo-local-backendArchiveResult', 'CodeSha256': 'n3CrpOYRu3s0C/1lwf5U2bua69Ql9XhDgQ/8ZpYJf5c='}
2023-10-04T11:45:48.617 DEBUG --- [   asgi_gw_2] l.s.l.i.version_manager    : Version preparation of function arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult:1 took 0.28ms
2023-10-04T11:45:48.618 DEBUG --- [   asgi_gw_2] l.s.l.i.version_manager    : Changing Lambda arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult:1 (id eca51201) to active
2023-10-04T11:45:48.618 DEBUG --- [   asgi_gw_2] l.s.l.i.event_manager      : Starting event manager arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult:1 id 139716477292304
2023-10-04T11:45:48.628 DEBUG --- [   asgi_gw_7] l.services.sqs.provider    : creating queue key=localstack-demo-local-backendArchiveResult-9852efdb861adca975e6d0eccf7086da attributes=None tags=None
2023-10-04T11:45:48.658 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::Lambda::Version:BackendArchiveResultLambdaVersionjjIXMf3A4GHidwnrx24HuUiyySCMeOlaHN8TTO1qcUs
2023-10-04T11:45:48.891 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "ApiGatewayMethodRequestsPost" (3/9) type "AWS::ApiGateway::Method" in loop iteration 2 (should_deploy=True)
2023-10-04T11:45:48.891 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependency for resource {'Type': 'AWS::ApiGateway::Method', 'DependsOn': ['HttpHandleRequestLambdaPermissionApiGateway'], 'LogicalResourceId': 'ApiGatewayMethodRequestsPost', 'Properties': {'HttpMethod': 'POST', 'RequestParameters': {}, 'ResourceId': 'waownzrog5', 'RestApiId': 'ftytsywd7v', 'ApiKeyRequired': False, 'AuthorizationType': 'NONE', 'Integration': {'IntegrationHttpMethod': 'POST', 'Type': 'AWS_PROXY', 'Uri': 'arn:aws:apigateway:us-east-1:lambda:path/2015-03-31/functions/arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-httpHandleRequest/invocations'}, 'MethodResponses': []}} not yet deployed: HttpHandleRequestLambdaPermissionApiGateway {'Type': 'AWS::Lambda::Permission', 'LogicalResourceId': 'HttpHandleRequestLambdaPermissionApiGateway', 'Properties': {'FunctionName': {'Fn::GetAtt': ['HttpHandleRequestLambdaFunction', 'Arn']}, 'Action': 'lambda:InvokeFunction', 'Principal': 'apigateway.amazonaws.com', 'SourceArn': {'Fn::Join': ['', ['arn:', {'Ref': 'AWS::Partition'}, ':execute-api:', {'Ref': 'AWS::Region'}, ':', {'Ref': 'AWS::AccountId'}, ':', {'Ref': 'ApiGatewayRestApi'}, '/*/*']]}}}
2023-10-04T11:45:49.089 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "ApiGatewayMethodRequestsGet" (4/9) type "AWS::ApiGateway::Method" in loop iteration 2 (should_deploy=True)
2023-10-04T11:45:49.090 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependency for resource {'Type': 'AWS::ApiGateway::Method', 'DependsOn': ['HttpHandleRequestLambdaPermissionApiGateway'], 'LogicalResourceId': 'ApiGatewayMethodRequestsGet', 'Properties': {'HttpMethod': 'GET', 'RequestParameters': {}, 'ResourceId': 'waownzrog5', 'RestApiId': 'ftytsywd7v', 'ApiKeyRequired': False, 'AuthorizationType': 'NONE', 'Integration': {'IntegrationHttpMethod': 'POST', 'Type': 'AWS_PROXY', 'Uri': 'arn:aws:apigateway:us-east-1:lambda:path/2015-03-31/functions/arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-httpHandleRequest/invocations'}, 'MethodResponses': []}} not yet deployed: HttpHandleRequestLambdaPermissionApiGateway {'Type': 'AWS::Lambda::Permission', 'LogicalResourceId': 'HttpHandleRequestLambdaPermissionApiGateway', 'Properties': {'FunctionName': {'Fn::GetAtt': ['HttpHandleRequestLambdaFunction', 'Arn']}, 'Action': 'lambda:InvokeFunction', 'Principal': 'apigateway.amazonaws.com', 'SourceArn': {'Fn::Join': ['', ['arn:', {'Ref': 'AWS::Partition'}, ':execute-api:', {'Ref': 'AWS::Region'}, ':', {'Ref': 'AWS::AccountId'}, ':', {'Ref': 'ApiGatewayRestApi'}, '/*/*']]}}}
2023-10-04T11:45:49.137 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "ApiGatewayDeployment1696419911247" (5/9) type "AWS::ApiGateway::Deployment" in loop iteration 2 (should_deploy=True)
2023-10-04T11:45:49.137 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependency for resource {'Type': 'AWS::ApiGateway::Deployment', 'DependsOn': ['ApiGatewayMethodRequestsOptions', 'ApiGatewayMethodRequestsPost', 'ApiGatewayMethodRequestsGet'], 'LogicalResourceId': 'ApiGatewayDeployment1696419911247', 'Properties': {'RestApiId': 'ftytsywd7v', 'StageName': 'local'}} not yet deployed: ApiGatewayMethodRequestsGet {'Type': 'AWS::ApiGateway::Method', 'DependsOn': ['HttpHandleRequestLambdaPermissionApiGateway'], 'LogicalResourceId': 'ApiGatewayMethodRequestsGet', 'Properties': {'HttpMethod': 'GET', 'RequestParameters': {}, 'ResourceId': 'waownzrog5', 'RestApiId': 'ftytsywd7v', 'ApiKeyRequired': False, 'AuthorizationType': 'NONE', 'Integration': {'IntegrationHttpMethod': 'POST', 'Type': 'AWS_PROXY', 'Uri': 'arn:aws:apigateway:us-east-1:lambda:path/2015-03-31/functions/arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-httpHandleRequest/invocations'}, 'MethodResponses': []}}
2023-10-04T11:45:49.281 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "HttpHandleRequestLambdaPermissionApiGateway" (6/9) type "AWS::Lambda::Permission" in loop iteration 2 (should_deploy=True)
2023-10-04T11:45:49.282 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::Lambda::Permission" id "HttpHandleRequestLambdaPermissionApiGateway"
2023-10-04T11:45:49.283 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::Lambda::Permission" in account 000000000000 region us-east-1: add_permission {'FunctionName': 'arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-httpHandleRequest', 'Action': 'lambda:InvokeFunction', 'Principal': 'apigateway.amazonaws.com', 'SourceArn': 'arn:aws:execute-api:us-east-1:000000000000:ftytsywd7v/*/*', 'StatementId': 'demo1-HttpHandleRequestLambdaPermissionApiGateway-YYKSG6IYY9SCQ'}
2023-10-04T11:45:49.293 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::Lambda::Permission:HttpHandleRequestLambdaPermissionApiGateway
2023-10-04T11:45:49.358 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "SqsHandleItemEventSourceMappingSQSRequestQueue" not yet satisfied, retrying in next loop: Unresolved dependencies: SqsHandleItemLambdaFunction
2023-10-04T11:45:49.435 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "processingStateMachine" not yet satisfied, retrying in next loop: Unable to resolve attribute ref processingStateMachineRole.Arn
2023-10-04T11:45:50.155 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "processingStateMachineRole" (8/8) type "AWS::IAM::Role" in loop iteration 2 (should_deploy=True)
2023-10-04T11:45:50.491 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "SqsHandleItemLambdaFunction" not yet satisfied, retrying in next loop: Unable to resolve attribute ref processingStateMachine.Arn
2023-10-04T11:45:50.516 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Unable to resolve Ref for resource "SqsHandleItemLambdaFunction" (yet) - {'Type': 'AWS::Lambda::Function', 'DependsOn': ['SqsHandleItemLogGroup'], 'LogicalResourceId': 'SqsHandleItemLambdaFunction', 'Properties': {'Code': {'S3Bucket': 'localstack-test-bucket', 'S3Key': 'serverless/localstack-demo/local/1696419918030-2023-10-04T11:45:18.030Z/localstack-demo.zip'}, 'Handler': 'demo/lambdas/worker.triggerProcessing', 'Runtime': 'ruby2.7', 'FunctionName': 'localstack-demo-local-sqsHandleItem', 'MemorySize': 1024, 'Timeout': 15, 'Environment': {'Variables': {'STATE_MACHINE_ARN': {'Fn::Sub': '${processingStateMachine.Arn}'}}}, 'Role': {'Fn::GetAtt': ['IamRoleLambdaExecution', 'Arn']}}}
2023-10-04T11:45:50.516 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "SqsHandleItemLambdaVersion0AEAXJamGgssLk9pNg1oN2f0ejz2glYGQ3qrq1dvo" not yet satisfied, retrying in next loop: Unable to resolve Ref for resource "SqsHandleItemLambdaFunction" (yet)
2023-10-04T11:45:50.638 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "ApiGatewayMethodRequestsPost" (3/7) type "AWS::ApiGateway::Method" in loop iteration 3 (should_deploy=True)
2023-10-04T11:45:50.640 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::ApiGateway::Method" id "ApiGatewayMethodRequestsPost"
2023-10-04T11:45:50.640 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::ApiGateway::Method" in account 000000000000 region us-east-1: put_method {'httpMethod': 'POST', 'requestParameters': {}, 'resourceId': 'waownzrog5', 'restApiId': 'ftytsywd7v', 'apiKeyRequired': False, 'authorizationType': 'NONE', 'requestModels': {}}
2023-10-04T11:45:50.650 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::ApiGateway::Method:ApiGatewayMethodRequestsPost
2023-10-04T11:45:50.840 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "ApiGatewayMethodRequestsGet" (3/6) type "AWS::ApiGateway::Method" in loop iteration 3 (should_deploy=True)
2023-10-04T11:45:50.841 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::ApiGateway::Method" id "ApiGatewayMethodRequestsGet"
2023-10-04T11:45:50.841 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::ApiGateway::Method" in account 000000000000 region us-east-1: put_method {'httpMethod': 'GET', 'requestParameters': {}, 'resourceId': 'waownzrog5', 'restApiId': 'ftytsywd7v', 'apiKeyRequired': False, 'authorizationType': 'NONE', 'requestModels': {}}
2023-10-04T11:45:50.853 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::ApiGateway::Method:ApiGatewayMethodRequestsGet
2023-10-04T11:45:50.926  INFO --- [   asgi_gw_2] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200
2023-10-04T11:45:50.952 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "ApiGatewayDeployment1696419911247" (3/5) type "AWS::ApiGateway::Deployment" in loop iteration 3 (should_deploy=True)
2023-10-04T11:45:50.954 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::ApiGateway::Deployment" id "ApiGatewayDeployment1696419911247"
2023-10-04T11:45:50.954 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::ApiGateway::Deployment" in account 000000000000 region us-east-1: create_deployment {'restApiId': 'ftytsywd7v', 'stageName': 'local'}
2023-10-04T11:45:50.966 DEBUG --- [functhread41] l.s.c.resource_provider    : Executing callback method for AWS::ApiGateway::Deployment:ApiGatewayDeployment1696419911247
2023-10-04T11:45:51.033 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Dependencies for "SqsHandleItemEventSourceMappingSQSRequestQueue" not yet satisfied, retrying in next loop: Unresolved dependencies: SqsHandleItemLambdaFunction
2023-10-04T11:45:51.218 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Handling "Add" for resource "processingStateMachine" (4/4) type "AWS::StepFunctions::StateMachine" in loop iteration 3 (should_deploy=True)
2023-10-04T11:45:51.219 DEBUG --- [functhread41] l.s.c.resource_provider    : Running action "Add" for resource type "AWS::StepFunctions::StateMachine" id "processingStateMachine"
2023-10-04T11:45:51.228 DEBUG --- [functhread41] l.s.c.resource_provider    : Request for resource type "AWS::StepFunctions::StateMachine" in account 000000000000 region us-east-1: create_state_machine {'name': 'processingStateMachine', 'definition': '{\n  "StartAt": "ProcessRequest",\n  "States": {\n    "ProcessRequest": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest",\n      "Next": "ArchiveResult"\n    },\n    "ArchiveResult": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult",\n      "End": true\n    }\n  }\n}\n', 'roleArn': 'arn:aws:iam::000000000000:role/demo1-processingStateMachineRo-568e4d3f'}
2023-10-04T11:45:51.238 DEBUG --- [   asgi_gw_5] plugin.manager             : instantiating plugin PluginSpec(localstack.aws.provider.stepfunctions:default = <function stepfunctions at 0x7f12932d8c20>)
2023-10-04T11:45:51.238 DEBUG --- [   asgi_gw_5] plugin.manager             : loading plugin localstack.aws.provider:stepfunctions:default
2023-10-04T11:45:51.250  WARN --- [   asgi_gw_5] l.s.stepfunctions.provider : The 'v1' StepFunctions provider (current default) will be deprecated with the next major release (3.0). Set 'PROVIDER_OVERRIDE_STEPFUNCTIONS=v2' to opt-in to the new StepFunctions 'v2' provider.
2023-10-04T11:45:51.250 DEBUG --- [   asgi_gw_5] localstack.packages.api    : Starting installation of stepfunctions-local...
2023-10-04T11:45:52.617 ERROR --- [   asgi_gw_5] localstack.utils.functions : error calling function on_before_start
Traceback (most recent call last):
  File "/opt/code/localstack/localstack/packages/api.py", line 91, in install
    self._install(target)
  File "/opt/code/localstack/localstack/services/stepfunctions/packages.py", line 110, in _install
    download_stepfunctions_jar(SFN_IMAGE, SFN_IMAGE_LAYER_DIGEST, target.value)
  File "/opt/code/localstack/localstack/services/stepfunctions/packages.py", line 99, in download_stepfunctions_jar
    token = json.loads(token_request.content.decode("utf-8"))["token"]
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/json/__init__.py", line 346, in loads
    return _default_decoder.decode(s)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/opt/code/localstack/localstack/utils/functions.py", line 41, in call_safe
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/stepfunctions/provider.py", line 50, in on_before_start
    start_stepfunctions()
  File "/opt/code/localstack/localstack/services/stepfunctions/stepfunctions_starter.py", line 76, in start_stepfunctions
    stepfunctions_local_package.install()
  File "/opt/code/localstack/localstack/packages/api.py", line 210, in install
    self.get_installer(version).install(target)
  File "/opt/code/localstack/localstack/packages/api.py", line 102, in install
    raise PackageException(f"Installation of {self.name} failed.") from e
localstack.packages.api.PackageException: Installation of stepfunctions-local failed.
2023-10-04T11:45:52.634  INFO --- [   asgi_gw_5] localstack.utils.bootstrap : Execution of "require" took 1396.49ms
2023-10-04T11:45:52.650 ERROR --- [   asgi_gw_5] l.aws.handlers.logging     : exception during call chain
Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 174, in _new_conn
    conn = connection.create_connection(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 95, in create_connection
    raise err
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 85, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 714, in urlopen
    httplib_response = self._make_request(
                       ^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 415, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 244, in request
    super(HTTPConnection, self).request(method, url, body=body, headers=headers)
  File "/usr/local/lib/python3.11/http/client.py", line 1286, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1332, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1281, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1041, in _send_output
    self.send(msg)
  File "/usr/local/lib/python3.11/http/client.py", line 979, in send
    self.connect()
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 205, in connect
    conn = self._new_conn()
           ^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 186, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7f126cd95090>: Failed to establish a new connection: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 486, in send
    resp = conn.urlopen(
           ^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 798, in urlopen
    retries = retries.increment(
              ^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/retry.py", line 592, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f126cd95090>: Failed to establish a new connection: [Errno 111] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/localstack/aws/chain.py", line 90, in handle
    handler(self, self.context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 123, in __call__
    handler(chain, context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 93, in __call__
    skeleton_response = self.skeleton.invoke(context)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 154, in invoke
    return self.dispatch_request(context, instance)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 166, in dispatch_request
    result = handler(context, instance) or {}
             ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 60, in _call
    return handler(context, req)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 118, in __call__
    return self.fn(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/stepfunctions/provider.py", line 76, in create_state_machine
    return self.forward_request(context, request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 92, in _forward_request
    return forward_request(context, forward_url_getter)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 103, in forward_request
    return dispatch_to_backend(context, _call_http_backend)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 120, in dispatch_to_backend
    http_response = http_request_dispatcher(context)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 101, in _call_http_backend
    return forward(context.request, forward_url_getter())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 24, in forward
    return proxy.forward(request, forward_path=forward_path, headers=headers)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 90, in forward
    return self.client.request(proxy_request, server=f"{target.scheme}://{target.netloc}")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/client.py", line 103, in request
    response = self.session.request(
               ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 589, in request
    resp = self.send(prep, **send_kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 703, in send
    r = adapter.send(request, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 519, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f126cd95090>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-10-04T11:45:52.940 ERROR --- [   asgi_gw_6] l.aws.handlers.logging     : exception during call chain
Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 174, in _new_conn
    conn = connection.create_connection(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 95, in create_connection
    raise err
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 85, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 714, in urlopen
    httplib_response = self._make_request(
                       ^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 415, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 244, in request
    super(HTTPConnection, self).request(method, url, body=body, headers=headers)
  File "/usr/local/lib/python3.11/http/client.py", line 1286, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1332, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1281, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1041, in _send_output
    self.send(msg)
  File "/usr/local/lib/python3.11/http/client.py", line 979, in send
    self.connect()
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 205, in connect
    conn = self._new_conn()
           ^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 186, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7f1278cdc250>: Failed to establish a new connection: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 486, in send
    resp = conn.urlopen(
           ^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 798, in urlopen
    retries = retries.increment(
              ^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/retry.py", line 592, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f1278cdc250>: Failed to establish a new connection: [Errno 111] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/localstack/aws/chain.py", line 90, in handle
    handler(self, self.context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 123, in __call__
    handler(chain, context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 93, in __call__
    skeleton_response = self.skeleton.invoke(context)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 154, in invoke
    return self.dispatch_request(context, instance)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 166, in dispatch_request
    result = handler(context, instance) or {}
             ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 60, in _call
    return handler(context, req)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 118, in __call__
    return self.fn(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/stepfunctions/provider.py", line 76, in create_state_machine
    return self.forward_request(context, request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 92, in _forward_request
    return forward_request(context, forward_url_getter)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 103, in forward_request
    return dispatch_to_backend(context, _call_http_backend)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 120, in dispatch_to_backend
    http_response = http_request_dispatcher(context)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 101, in _call_http_backend
    return forward(context.request, forward_url_getter())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 24, in forward
    return proxy.forward(request, forward_path=forward_path, headers=headers)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 90, in forward
    return self.client.request(proxy_request, server=f"{target.scheme}://{target.netloc}")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/client.py", line 103, in request
    response = self.session.request(
               ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 589, in request
    resp = self.send(prep, **send_kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 703, in send
    r = adapter.send(request, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 519, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f1278cdc250>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-10-04T11:45:53.219 ERROR --- [   asgi_gw_2] l.aws.handlers.logging     : exception during call chain
Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 174, in _new_conn
    conn = connection.create_connection(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 95, in create_connection
    raise err
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 85, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 714, in urlopen
    httplib_response = self._make_request(
                       ^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 415, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 244, in request
    super(HTTPConnection, self).request(method, url, body=body, headers=headers)
  File "/usr/local/lib/python3.11/http/client.py", line 1286, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1332, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1281, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1041, in _send_output
    self.send(msg)
  File "/usr/local/lib/python3.11/http/client.py", line 979, in send
    self.connect()
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 205, in connect
    conn = self._new_conn()
           ^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 186, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7f1278c1a090>: Failed to establish a new connection: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 486, in send
    resp = conn.urlopen(
           ^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 798, in urlopen
    retries = retries.increment(
              ^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/retry.py", line 592, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f1278c1a090>: Failed to establish a new connection: [Errno 111] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/localstack/aws/chain.py", line 90, in handle
    handler(self, self.context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 123, in __call__
    handler(chain, context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 93, in __call__
    skeleton_response = self.skeleton.invoke(context)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 154, in invoke
    return self.dispatch_request(context, instance)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 166, in dispatch_request
    result = handler(context, instance) or {}
             ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 60, in _call
    return handler(context, req)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 118, in __call__
    return self.fn(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/stepfunctions/provider.py", line 76, in create_state_machine
    return self.forward_request(context, request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 92, in _forward_request
    return forward_request(context, forward_url_getter)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 103, in forward_request
    return dispatch_to_backend(context, _call_http_backend)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 120, in dispatch_to_backend
    http_response = http_request_dispatcher(context)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 101, in _call_http_backend
    return forward(context.request, forward_url_getter())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 24, in forward
    return proxy.forward(request, forward_path=forward_path, headers=headers)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 90, in forward
    return self.client.request(proxy_request, server=f"{target.scheme}://{target.netloc}")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/client.py", line 103, in request
    response = self.session.request(
               ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 589, in request
    resp = self.send(prep, **send_kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 703, in send
    r = adapter.send(request, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 519, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f1278c1a090>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-10-04T11:45:53.830 ERROR --- [   asgi_gw_2] l.aws.handlers.logging     : exception during call chain
Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 174, in _new_conn
    conn = connection.create_connection(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 95, in create_connection
    raise err
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 85, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 714, in urlopen
    httplib_response = self._make_request(
                       ^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 415, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 244, in request
    super(HTTPConnection, self).request(method, url, body=body, headers=headers)
  File "/usr/local/lib/python3.11/http/client.py", line 1286, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1332, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1281, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1041, in _send_output
    self.send(msg)
  File "/usr/local/lib/python3.11/http/client.py", line 979, in send
    self.connect()
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 205, in connect
    conn = self._new_conn()
           ^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 186, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7f1278cf6390>: Failed to establish a new connection: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 486, in send
    resp = conn.urlopen(
           ^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 798, in urlopen
    retries = retries.increment(
              ^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/retry.py", line 592, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f1278cf6390>: Failed to establish a new connection: [Errno 111] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/localstack/aws/chain.py", line 90, in handle
    handler(self, self.context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 123, in __call__
    handler(chain, context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 93, in __call__
    skeleton_response = self.skeleton.invoke(context)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 154, in invoke
    return self.dispatch_request(context, instance)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 166, in dispatch_request
    result = handler(context, instance) or {}
             ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 60, in _call
    return handler(context, req)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 118, in __call__
    return self.fn(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/stepfunctions/provider.py", line 76, in create_state_machine
    return self.forward_request(context, request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 92, in _forward_request
    return forward_request(context, forward_url_getter)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 103, in forward_request
    return dispatch_to_backend(context, _call_http_backend)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 120, in dispatch_to_backend
    http_response = http_request_dispatcher(context)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 101, in _call_http_backend
    return forward(context.request, forward_url_getter())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 24, in forward
    return proxy.forward(request, forward_path=forward_path, headers=headers)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 90, in forward
    return self.client.request(proxy_request, server=f"{target.scheme}://{target.netloc}")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/client.py", line 103, in request
    response = self.session.request(
               ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 589, in request
    resp = self.send(prep, **send_kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 703, in send
    r = adapter.send(request, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 519, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f1278cf6390>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-10-04T11:45:55.884 ERROR --- [   asgi_gw_4] l.aws.handlers.logging     : exception during call chain
Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 174, in _new_conn
    conn = connection.create_connection(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 95, in create_connection
    raise err
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 85, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 714, in urlopen
    httplib_response = self._make_request(
                       ^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 415, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 244, in request
    super(HTTPConnection, self).request(method, url, body=body, headers=headers)
  File "/usr/local/lib/python3.11/http/client.py", line 1286, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1332, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1281, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1041, in _send_output
    self.send(msg)
  File "/usr/local/lib/python3.11/http/client.py", line 979, in send
    self.connect()
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 205, in connect
    conn = self._new_conn()
           ^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 186, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7f1278c04450>: Failed to establish a new connection: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 486, in send
    resp = conn.urlopen(
           ^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 798, in urlopen
    retries = retries.increment(
              ^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/retry.py", line 592, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f1278c04450>: Failed to establish a new connection: [Errno 111] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/localstack/aws/chain.py", line 90, in handle
    handler(self, self.context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 123, in __call__
    handler(chain, context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 93, in __call__
    skeleton_response = self.skeleton.invoke(context)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 154, in invoke
    return self.dispatch_request(context, instance)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 166, in dispatch_request
    result = handler(context, instance) or {}
             ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 60, in _call
    return handler(context, req)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 118, in __call__
    return self.fn(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/stepfunctions/provider.py", line 76, in create_state_machine
    return self.forward_request(context, request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 92, in _forward_request
    return forward_request(context, forward_url_getter)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 103, in forward_request
    return dispatch_to_backend(context, _call_http_backend)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 120, in dispatch_to_backend
    http_response = http_request_dispatcher(context)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 101, in _call_http_backend
    return forward(context.request, forward_url_getter())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 24, in forward
    return proxy.forward(request, forward_path=forward_path, headers=headers)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 90, in forward
    return self.client.request(proxy_request, server=f"{target.scheme}://{target.netloc}")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/client.py", line 103, in request
    response = self.session.request(
               ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 589, in request
    resp = self.send(prep, **send_kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 703, in send
    r = adapter.send(request, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 519, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f1278c04450>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-10-04T11:45:55.907  WARN --- [functhread41] l.s.c.resource_provider    : Error calling <bound method ClientCreator._create_api_method.<locals>._api_call of <botocore.client.SFN object at 0x7f12789a08d0>> with params: {'name': 'processingStateMachine', 'definition': '{\n  "StartAt": "ProcessRequest",\n  "States": {\n    "ProcessRequest": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest",\n      "Next": "ArchiveResult"\n    },\n    "ArchiveResult": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult",\n      "End": true\n    }\n  }\n}\n', 'roleArn': 'arn:aws:iam::000000000000:role/demo1-processingStateMachineRo-568e4d3f'} for resource: {'Type': 'AWS::StepFunctions::StateMachine', 'LogicalResourceId': 'processingStateMachine', 'Properties': {'StateMachineName': 'processingStateMachine', 'RoleArn': 'arn:aws:iam::000000000000:role/demo1-processingStateMachineRo-568e4d3f', 'DefinitionString': '{\n  "StartAt": "ProcessRequest",\n  "States": {\n    "ProcessRequest": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest",\n      "Next": "ArchiveResult"\n    },\n    "ArchiveResult": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult",\n      "End": true\n    }\n  }\n}\n'}, 'SpecifiedProperties': {'StateMachineName': 'processingStateMachine', 'RoleArn': 'arn:aws:iam::000000000000:role/demo1-processingStateMachineRo-568e4d3f', 'DefinitionString': '{\n  "StartAt": "ProcessRequest",\n  "States": {\n    "ProcessRequest": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendProcessRequest",\n      "Next": "ArchiveResult"\n    },\n    "ArchiveResult": {\n      "Type": "Task",\n      "Resource": "arn:aws:lambda:us-east-1:000000000000:function:localstack-demo-local-backendArchiveResult",\n      "End": true\n    }\n  }\n}\n'}}
2023-10-04T11:45:55.910 DEBUG --- [functhread41] l.s.c.e.template_deployer  : Error applying changes for CloudFormation stack "demo1": An error occurred (InternalError) when calling the CreateStateMachine operation (reached max retries: 4): exception while calling stepfunctions.CreateStateMachine: Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 174, in _new_conn
    conn = connection.create_connection(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 95, in create_connection
    raise err
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 85, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 714, in urlopen
    httplib_response = self._make_request(
                       ^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 415, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 244, in request
    super(HTTPConnection, self).request(method, url, body=body, headers=headers)
  File "/usr/local/lib/python3.11/http/client.py", line 1286, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1332, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1281, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1041, in _send_output
    self.send(msg)
  File "/usr/local/lib/python3.11/http/client.py", line 979, in send
    self.connect()
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 205, in connect
    conn = self._new_conn()
           ^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 186, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7f1278c04450>: Failed to establish a new connection: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 486, in send
    resp = conn.urlopen(
           ^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 798, in urlopen
    retries = retries.increment(
              ^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/retry.py", line 592, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f1278c04450>: Failed to establish a new connection: [Errno 111] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/localstack/aws/chain.py", line 90, in handle
    handler(self, self.context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 123, in __call__
    handler(chain, context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 93, in __call__
    skeleton_response = self.skeleton.invoke(context)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 154, in invoke
    return self.dispatch_request(context, instance)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 166, in dispatch_request
    result = handler(context, instance) or {}
             ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 60, in _call
    return handler(context, req)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 118, in __call__
    return self.fn(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/stepfunctions/provider.py", line 76, in create_state_machine
    return self.forward_request(context, request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 92, in _forward_request
    return forward_request(context, forward_url_getter)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 103, in forward_request
    return dispatch_to_backend(context, _call_http_backend)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 120, in dispatch_to_backend
    http_response = http_request_dispatcher(context)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 101, in _call_http_backend
    return forward(context.request, forward_url_getter())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 24, in forward
    return proxy.forward(request, forward_path=forward_path, headers=headers)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 90, in forward
    return self.client.request(proxy_request, server=f"{target.scheme}://{target.netloc}")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/client.py", line 103, in request
    response = self.session.request(
               ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 589, in request
    resp = self.send(prep, **send_kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 703, in send
    r = adapter.send(request, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 519, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f1278c04450>: Failed to establish a new connection: [Errno 111] Connection refused'))
 Traceback (most recent call last):
  File "/opt/code/localstack/localstack/services/cloudformation/engine/template_deployer.py", line 1172, in _run
    self.do_apply_changes_in_loop(changes, stack)
  File "/opt/code/localstack/localstack/services/cloudformation/engine/template_deployer.py", line 1246, in do_apply_changes_in_loop
    self.apply_change(change, stack=stack)
  File "/opt/code/localstack/localstack/services/cloudformation/engine/template_deployer.py", line 1361, in apply_change
    progress_event = executor.deploy_loop(resource_provider_payload)  # noqa
                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/cloudformation/resource_provider.py", line 646, in deploy_loop
    event = self.execute_action(resource_provider, payload)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/cloudformation/resource_provider.py", line 715, in execute_action
    return resource_provider.create(request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/cloudformation/resource_provider.py", line 400, in create
    return self.create_or_delete(request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/cloudformation/resource_provider.py", line 543, in create_or_delete
    result = invoke_function(
             ^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/cloudformation/resource_provider.py", line 262, in invoke_function
    raise e
  File "/opt/code/localstack/localstack/services/cloudformation/resource_provider.py", line 241, in invoke_function
    result = function(**params)
             ^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/botocore/client.py", line 535, in _api_call
    return self._make_api_call(operation_name, kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/botocore/client.py", line 980, in _make_api_call
    raise error_class(parsed_response, operation_name)
botocore.exceptions.ClientError: An error occurred (InternalError) when calling the CreateStateMachine operation (reached max retries: 4): exception while calling stepfunctions.CreateStateMachine: Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 174, in _new_conn
    conn = connection.create_connection(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 95, in create_connection
    raise err
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/connection.py", line 85, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 714, in urlopen
    httplib_response = self._make_request(
                       ^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 415, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 244, in request
    super(HTTPConnection, self).request(method, url, body=body, headers=headers)
  File "/usr/local/lib/python3.11/http/client.py", line 1286, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1332, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1281, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.11/http/client.py", line 1041, in _send_output
    self.send(msg)
  File "/usr/local/lib/python3.11/http/client.py", line 979, in send
    self.connect()
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 205, in connect
    conn = self._new_conn()
           ^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connection.py", line 186, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7f1278c04450>: Failed to establish a new connection: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 486, in send
    resp = conn.urlopen(
           ^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 798, in urlopen
    retries = retries.increment(
              ^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/urllib3/util/retry.py", line 592, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f1278c04450>: Failed to establish a new connection: [Errno 111] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/code/localstack/localstack/aws/chain.py", line 90, in handle
    handler(self, self.context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 123, in __call__
    handler(chain, context, response)
  File "/opt/code/localstack/localstack/aws/handlers/service.py", line 93, in __call__
    skeleton_response = self.skeleton.invoke(context)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 154, in invoke
    return self.dispatch_request(context, instance)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 166, in dispatch_request
    result = handler(context, instance) or {}
             ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 60, in _call
    return handler(context, req)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/skeleton.py", line 118, in __call__
    return self.fn(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/stepfunctions/provider.py", line 76, in create_state_machine
    return self.forward_request(context, request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 92, in _forward_request
    return forward_request(context, forward_url_getter)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 103, in forward_request
    return dispatch_to_backend(context, _call_http_backend)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 120, in dispatch_to_backend
    http_response = http_request_dispatcher(context)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/aws/forwarder.py", line 101, in _call_http_backend
    return forward(context.request, forward_url_getter())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 24, in forward
    return proxy.forward(request, forward_path=forward_path, headers=headers)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/proxy.py", line 90, in forward
    return self.client.request(proxy_request, server=f"{target.scheme}://{target.netloc}")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/http/client.py", line 103, in request
    response = self.session.request(
               ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 589, in request
    resp = self.send(prep, **send_kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/sessions.py", line 703, in send
    r = adapter.send(request, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/.venv/lib/python3.11/site-packages/requests/adapters.py", line 519, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: MyHTTPConnectionPool(host='localhost', port=8083): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f1278c04450>: Failed to establish a new connection: [Errno 111] Connection refused'))


2023-10-04T11:45:55.961  INFO --- [   asgi_gw_3] localstack.request.aws     : AWS cloudformation.DescribeStackEvents => 200

[simonrw]

Capturing the true error:

2023-10-04T11:45:52.617 ERROR --- [   asgi_gw_5] localstack.utils.functions : error calling function on_before_start
Traceback (most recent call last):
  File "/opt/code/localstack/localstack/packages/api.py", line 91, in install
    self._install(target)
  File "/opt/code/localstack/localstack/services/stepfunctions/packages.py", line 110, in _install
    download_stepfunctions_jar(SFN_IMAGE, SFN_IMAGE_LAYER_DIGEST, target.value)
  File "/opt/code/localstack/localstack/services/stepfunctions/packages.py", line 99, in download_stepfunctions_jar
    token = json.loads(token_request.content.decode("utf-8"))["token"]
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/json/__init__.py", line 346, in loads
    return _default_decoder.decode(s)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/opt/code/localstack/localstack/utils/functions.py", line 41, in call_safe
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/code/localstack/localstack/services/stepfunctions/provider.py", line 50, in on_before_start
    start_stepfunctions()
  File "/opt/code/localstack/localstack/services/stepfunctions/stepfunctions_starter.py", line 76, in start_stepfunctions
    stepfunctions_local_package.install()
  File "/opt/code/localstack/localstack/packages/api.py", line 210, in install
    self.get_installer(version).install(target)
  File "/opt/code/localstack/localstack/packages/api.py", line 102, in install
    raise PackageException(f"Installation of {self.name} failed.") from e
localstack.packages.api.PackageException: Installation of stepfunctions-local failed.

@dominikschubert have you seen this before? A failure to download the stepfunctions jar

RCA

Git Blame
Functionality limitation was introduced in localstack/localstack#6916

Speculation

@simonrw and @dominikschubert , although it's impossible to say for this specific problem without a confirmation on the part of the original two posters like @Arvind644 , the cause is ultimately network related. One scenario in which this issue can occur is when a machine connects to a virtual private network (VPN) that has setup network policies that block requests to public registries to ensure all software artifacts are pulled through an internal registry for resiliency or security reason. That said, there are multiple reasons why the egress of requests to the public docker or maven registry could be blocked.

Reproduction

This problem can be confirmed by running the following commands inside a network that rejects requests to the host docker.io:

git clone https://github.com/regclient/regclient.git
cd regclient
make
bin/regctl version
# VCSTag:     (devel)
# VCSRef:     02106133f71ed54db77b8d12af87fc6bb8f11d46
# VCSCommit:  02106133f71ed54db77b8d12af87fc6bb8f11d46
# VCSState:   clean
# VCSDate:    2023-11-19T22:03:46Z
# Platform:   darwin/amd64
# GoVer:      go1.20.4
# GoCompiler: gc
$ bin/regctl image manifest amazon/aws-stepfunctions-local:1.7.9 --platform local
# WARN[0000] Sleeping for backoff Host=docker.io Seconds=1.999996941
# WARN[0002] Sleeping for backoff Host=docker.io Seconds=3.999996667
# failed to get manifest docker.io/amazon/aws-stepfunctions-local:1.7.9: Get "https://registry-1.docker.io/v2/amazon/aws-stepfunctions-local/manifests/1.7.9"....

Root Cause

tl;dr
Unconfigurable variables with strings hard-coded to public registries, such as registry_base.

details

0. Block outbound requests to hostname docker.io
1. Run localstack start in shell session
2. Run make deploy in shell session with the pwd set to the root of the localstack-demo repository
   a. make deploy calls serverless deploy --stage local
3. Serverless reads the contents of serverless.yml
   a. The function sqsHandleItem is created with a AWS::StepFunctions::StateMachine called processingStateMachine
   b. The lambda function has a ruby runtime which will require aws-sdk-state will run start_execution and reach the running localstack.
4. Consequently, localstack attempts to pull amazon/aws-stepfunctions-local to run state machines locally
5. StepFunctionsLocalPackageInstaller._install determines the path install_destination does not exist.
6. localstack calls download_stepfunctions_jar as part of this setup which instructs the localstack runtime to use docker.io as the registry_base.

Workaround

This workaround assumes localstack is used via docker-compose and forces a False evaluation on the condition if not os.path.exists(install_destination): inside the implementation of the function StepFunctionsLocalPackageInstaller._install.

1. Download the required .tar.gz from Amazon
2. Untar the gzipped tar ball and move the file StepFunctionsLocal.jar onto your machine
3. Create an initializing script like /etc/localstack/init/boot.d/stepfunction-local.sh to utilize this file via the volume parameter as shown in the example below:

#!/bin/bash
mkdir -p /usr/lib/localstack/stepfunctions-local/
cd /usr/lib/localstack/stepfunctions-local/
curl --silent https://s3.amazonaws.com/stepfunctionslocal/StepFunctionsLocal.tar.gz  --output StepFunctionsLocal.tar.gz &> /dev/null
tar -zxf StepFunctionsLocal.tar.gz

4. Lastly, provide the env LAMBDA_RUNTIME_IMAGE_MAPPING like export LAMBDA_RUNTIME_IMAGE_MAPPING= '{"python3.7":"private.registry.com/lambda/python:3.7","nodejs14.x":"private.registry.com/lambda/nodejs:14","ruby2.7":"private.registry.com/lambda/ruby:2.7"}'

Solution Discussion

No strong recommendation on the appropriate approach here, but I believe the change would likely fall around one of the following approaches:

1. Don't support private registries
2. Functions like download_stepfunctions_jar reference configurable values defaulting to public registries.
3. Change download from docker.io to https://s3.amazonaws.com/stepfunctionslocal/StepFunctionsLocal.tar.gz
4. Use git lfs to add the necessary dependencies to a GitHub destination like https://github.com/localstack/localstack-artifacts.
5. Update the localstack-demo to avoid using AWS::StepFunctions or any service requiring public registries.

Semi-related Bug

1. Ideally in v3.0.0, LAMBDA_RUNTIME_IMAGE_MAPPING would support something like the following LAMBDA_RUNTIME_IMAGE_MAPPING: 'private.registry.com/lambda/<runtime>' and use the mapping's value instead of the key.

The issue #69 is also likely related and has a similar solution/workaround. Unfortunately, both issues provide insufficient data to be certain on what is causing the issue as serverless attempts to startup.

One final note on a step that is required for having a fully function app using private registries for this particular repository is the need to set the registry for the pip and npm binary in a boot.d script.

NodeJS
npm config set registry https://private.registry.com/npm/mirror

Python (pip.conf)

[global]

extra-index-url = https://private.registry.com/pypi/mirror/
index-url = https://private.registry.com/pypi/mirror/

[install]
trusted-host = private.registry.com

This issue #44 is also likely related. Given the prolific nature of this setup confusion. It would probably be a good idea to have dedicate documentation to running and troubleshooting localstack with private registries pro/community.

Yet another final note about network related issues with the demo, it's important to check the values set on HTTP_PROXY, HTTPS_PROXY, and NO_PROXY for the docker daemon. To see whether or not the issue you're facing is caused by network interference, look for keywords in the following:

• stack traces that include a file like proxy.py
• Err connection refused (no handshake)
• tcp dial timeout on connections
• SSL ERR and invalid certificate errors
• Failure to pull images

I personally recommend either keeping two shell sessions open with bifurcated logging traffic to with(out) proxy in the foreground or on OSX streaming system logs associated with docker like so pred='(process matches ".*(ocker|vpnkit).*" && eventMessage contains[c] "pulling") || (process in {"taskgated-helper", "launchservicesd", "kernel"} && eventMessage contains[c] "docker" && eventMessage contains[c] "pulling image")'