Bug: UnixHTTPConnectionPool Error

[fade2black]

Today I have updated both Docker and AWS SAM.

Description (of sam build --debug):

2024-01-03 17:57:00,654 | Building to following folder /Users/bayramkuliyev/Projects/Rails/court-jobs/import_court_data/.aws-sam/build/WorkerFunction                     
2024-01-03 17:57:00,655 | Building image for WorkerFunction function                                                                                                      
2024-01-03 17:58:00,660 | Telemetry endpoint configured to be https://aws-serverless-tools-telemetry.us-west-2.amazonaws.com/metrics                                      
2024-01-03 17:58:00,666 | Telemetry endpoint configured to be https://aws-serverless-tools-telemetry.us-west-2.amazonaws.com/metrics                                      
2024-01-03 17:58:00,667 | Unable to find Click Context for getting session_id. 

Error: UnixHTTPConnectionPool(host='localhost', port=None): Read timed out. (read timeout=60)
Traceback:
  File "click/core.py", line 1078, in main
  File "click/core.py", line 1688, in invoke
  File "click/core.py", line 1434, in invoke
  File "click/core.py", line 783, in invoke
  File "samcli/cli/cli_config_file.py", line 347, in wrapper
  File "click/decorators.py", line 92, in new_func
  File "click/core.py", line 783, in invoke
  File "samcli/lib/telemetry/metric.py", line 184, in wrapped
  File "samcli/lib/telemetry/metric.py", line 149, in wrapped
  File "samcli/lib/utils/version_checker.py", line 42, in wrapped
  File "samcli/cli/main.py", line 95, in wrapper
  File "samcli/commands/build/command.py", line 174, in cli
  File "samcli/commands/build/command.py", line 263, in do_cli
  File "samcli/commands/build/build_context.py", line 283, in run
  File "samcli/lib/build/app_builder.py", line 219, in build
  File "samcli/lib/build/build_strategy.py", line 82, in build
  File "samcli/lib/build/build_strategy.py", line 92, in _build_functions
  File "samcli/lib/build/build_strategy.py", line 165, in build_single_function_definition
  File "samcli/lib/build/app_builder.py", line 645, in _build_function
  File "samcli/lib/build/app_builder.py", line 399, in _build_lambda_image
  File "samcli/local/docker/utils.py", line 91, in is_docker_reachable
  File "docker/client.py", line 203, in ping
  File "docker/api/daemon.py", line 166, in ping
  File "docker/utils/decorators.py", line 46, in inner
  File "docker/api/client.py", line 237, in _get
  File "requests/sessions.py", line 602, in get
  File "requests/sessions.py", line 589, in request
  File "requests/sessions.py", line 703, in send
  File "requests/adapters.py", line 532, in send

Additional environment details

1. MacOS Sonoma 14.2.1 (23C71)
2. sam --version: SAM CLI, version 1.105.0
3. AWS region: eu-central-1
4. Docker version: 24.0.7, build afdd53b

{
  "version": "1.105.0",
  "system": {
    "python": "3.8.13",
    "os": "macOS-14.2.1-arm64-arm-64bit"
  },
  "additional_dependencies": {
    "docker_engine": "Not available",
    "aws_cdk": "Not available",
    "terraform": "Not available"
  },
  "available_beta_feature_env_vars": [
    "SAM_CLI_BETA_FEATURES",
    "SAM_CLI_BETA_BUILD_PERFORMANCE",
    "SAM_CLI_BETA_TERRAFORM_SUPPORT",
    "SAM_CLI_BETA_RUST_CARGO_LAMBDA"
  ]
}

I think it is related to the Docker, because

1. UnixHTTPConnectionPool error
2. I stop the Docker, then restart , and run sam build. Everything works fine.

In addition to it I tried to run sam --info it got stuck. After I killed the Docker process completely and ran sam --info, it showed the info. That's why it says "docker_engine": "Not available".

After I restart the Docker I run sam build again. It works fine. I am even able to sam deploy it. Next time I try to build, I get the same error.

I am not sure it is SAM CLI bug or Docker bug.

UPDATE
I have also noticed that the building progress like following

...

Step 1/8 : FROM public.ecr.aws/lambda/ruby:3.2
 ---> 74061974f58b
Step 2/8 : RUN yum install -y amazon-linux-extras                      ruby-devel make gcc libxml2-devel
 ---> Using cache
 ---> 69deb25d30d8
Step 3/8 : COPY Gemfile handler.rb initialize.rb ./
 ---> 6cdcf1d25bbe
Step 4/8 : COPY concern ./concern
 ---> fce6a5743a67
Step 5/8 : ENV GEM_HOME=${LAMBDA_TASK_ROOT}
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 2ac8aedf332b
...

does not appear anymore while building and only shows up when building is successful and over. In case of failure, it does not appear, only the failure msg appears.

[mildaniel]

Hey @fade2black, let me try to clarify my understanding of the problem. The first time you try running a Docker-based SAM CLI command the execution succeeds, and then subsequent Docker-based commands fail with the error you listed? Is my understanding correct?

[fade2black]

@mildaniel Hi!
It started after I updated both SAM and Docker.

The first time you try running a Docker-based SAM CLI command the execution succeeds, and then subsequent Docker-based commands fail with the error you listed?

Yes, correct. But now it works fine. Yesterday, after 4-5 hours recurring like this it finally works without any issue. Even more, I'd say it's started to build faster. But I don't know why the build progress does not show any more. It appears ONLY after the build finishes successfully.

[fade2black]

Just in case, my terminal is zsh.

[mildaniel]

And the build progress not showing up is specifically when building image-based functions?

[fade2black]

@mildaniel Yes, image-based project. I type sam build + Enter
It starts with:

Building codeuri: blah blah blah

and gets stuck with

Building image for DataImportFunction function                                                                                                                     
Setting DockerBuildArgs: {} for DataImportFunction function 

After it builds successfully, all the history shows up at once:

Building image for DataImportFunction function                                                                                                                     
Setting DockerBuildArgs: {} for DataImportFunction function                                                                                                        
Step 1/8 : FROM public.ecr.aws/lambda/ruby:3.2
 ---> 74061974f58b
Step 2/8 : RUN yum install -y amazon-linux-extras                      ruby-devel make gcc libxml2-devel
 ---> Using cache
 ---> 69deb25d30d8
...
Build Succeeded

Built Artifacts  : .aws-sam/build
Built Template   : .aws-sam/build/template.yaml

Commands you can use next
=========================
[*] Validate SAM template: sam validate
[*] Invoke Function: sam local invoke
[*] Test Function in the Cloud: sam sync --stack-name {{stack-name}} --watch
[*] Deploy: sam deploy --guided

[mildaniel]

Thanks @fade2black, I was able to reproduce this too. This part is a bug, but I don't think there is any action to take on the Docker side of things.

[sidhujus]

We previously switched away from using the lower level api call to build images to using images.build so that we could surface any errors encountered during an image build. You can see the reasoning in this issue #5026

The reason logs are not printed until a build is finished is because the images.build call is blocking until the build completes, and because of that we can't surface any logs until after the build completes.

This ticket docker/docker-py#3108 raises the issue of no errors being surfaced by the lower level call and until a resolution is made we will have to continue using the images.build instead which means displaying build logs will be delayed

[fade2black]

We previously switched away from using the lower level api call to build images to using images.build so that we could surface any errors encountered during an image build. You can see the reasoning in this issue #5026

The reason logs are not printed until a build is finished is because the images.build call is blocking until the build completes, and because of that we can't surface any logs until after the build completes.

This ticket docker/docker-py#3108 raises the issue of no errors being surfaced by the lower level call and until a resolution is made we will have to continue using the images.build instead which means displaying build logs will be delayed

This is such a pain in the ass. When are you planning to fix it?