Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bug: sam local invoke - ReadTimeout #6191

Closed
Joymaker opened this issue Nov 2, 2023 · 6 comments
Closed

Bug: sam local invoke - ReadTimeout #6191

Joymaker opened this issue Nov 2, 2023 · 6 comments
Labels
area/local/invoke sam local invoke command blocked/close-if-inactive Blocked for >14 days with no response, will be closed if still inactive after 7 days blocked/more-info-needed More info is needed from the requester. If no response in 14 days, it will become stale.

Comments

@Joymaker
Copy link

Joymaker commented Nov 2, 2023

Description:

Running on Mac with Docker desktop 4.24.0 and Docker engine 24.0.6. I ran the "hello world" SAM tutorial https://docs.aws.amazon.com/serverless-application-model/latest/developerguide/serverless-getting-started-hello-world.html except that I opted into X-ray. Everything went according to plan through step 6. But then:

% sam local invoke
<silence of 1-2 minutes>
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 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 297, 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/local/invoke/cli.py", line 103, in cli
File "samcli/commands/local/invoke/cli.py", line 178, in do_cli
File "samcli/commands/local/cli_common/invoke_context.py", line 266, in enter
File "samcli/local/docker/manager.py", line 55, in is_docker_reachable
File "samcli/local/docker/utils.py", line 90, 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

An unexpected error was encountered while executing "sam local invoke".
Search for an existing issue:
https://github.com/aws/aws-sam-cli/issues?q=is%3Aissue+is%3Aopen+Bug%3A%20sam%20local%20invoke%20-%20ReadTimeout
Or create a bug report:
https://github.com/aws/aws-sam-cli/issues/new?template=Bug_report.md&title=Bug%3A%20sam%20local%20invoke%20-%20ReadTimeout

Observed result:

% sam local invoke --debug
2023-11-02 08:43:21,628 | Config file location: /Users/ken/Snthesis/Tools/SAM tutorial/samconfig.toml
2023-11-02 08:43:21,633 | Loading configuration values from [default.['local', 'invoke'].parameters]
(env.command_name.section) in config file at '/Users/ken/Snthesis/Tools/SAM tutorial/samconfig.toml'...
2023-11-02 08:43:21,635 | Configuration values successfully loaded.
2023-11-02 08:43:21,636 | Configuration values are: {'stack_name': 'sam-app'}
2023-11-02 08:43:21,644 | Using SAM Template at /Users/ken/Snthesis/Tools/SAM tutorial/.aws-sam/build/template.yaml
2023-11-02 08:43:21,694 | Using config file: samconfig.toml, config environment: default
2023-11-02 08:43:21,696 | Expand command line arguments to:
2023-11-02 08:43:21,697 | --template_file=/Users/ken/Snthesis/Tools/SAM tutorial/.aws-sam/build/template.yaml
--no_event --layer_cache_basedir=/Users/ken/.aws-sam/layers-pkg --container_host=localhost
--container_host_interface=127.0.0.1
2023-11-02 08:43:21,699 | local invoke command is called
2023-11-02 08:43:21,706 | No Parameters detected in the template
2023-11-02 08:43:21,747 | Sam customer defined id is more priority than other IDs. Customer defined id for resource
HelloWorldFunction is HelloWorldFunction
2023-11-02 08:43:21,748 | There is no customer defined id or cdk path defined for resource ServerlessRestApi, so we
will use the resource logical id as the resource id
2023-11-02 08:43:21,751 | 0 stacks found in the template
2023-11-02 08:43:21,753 | No Parameters detected in the template
2023-11-02 08:43:21,795 | Sam customer defined id is more priority than other IDs. Customer defined id for resource
HelloWorldFunction is HelloWorldFunction
2023-11-02 08:43:21,797 | There is no customer defined id or cdk path defined for resource ServerlessRestApi, so we
will use the resource logical id as the resource id
2023-11-02 08:43:21,799 | 2 resources found in the stack
2023-11-02 08:43:21,800 | Found Serverless function with name='HelloWorldFunction' and CodeUri='HelloWorldFunction'
2023-11-02 08:43:21,801 | --base-dir is not presented, adjusting uri HelloWorldFunction relative to
/Users/ken/Snthesis/Tools/SAM tutorial/.aws-sam/build/template.yaml
2023-11-02 08:44:21,812 | Telemetry endpoint configured to be
https://aws-serverless-tools-telemetry.us-west-2.amazonaws.com/metrics
2023-11-02 08:44:21,902 | Telemetry endpoint configured to be
https://aws-serverless-tools-telemetry.us-west-2.amazonaws.com/metrics
2023-11-02 08:44:21,905 | Sending Telemetry: {'metrics': [{'commandRun': {'requestId':
'a7ec3911-0076-457b-a376-d1c059d6ea0e', 'installationId': 'fbec54fc-a77c-4092-8591-fffb078d0066', 'sessionId':
'7a5e9614-bc70-4397-bdb6-7b6d6fac76ae', 'executionEnvironment': 'CLI', 'ci': False, 'pyversion': '3.8.13',
'samcliVersion': '1.99.0', 'awsProfileProvided': False, 'debugFlagProvided': True, 'region': '', 'commandName':
'sam local invoke', 'metricSpecificAttributes': {'projectType': 'CFN', 'gitOrigin': None, 'projectName':
'6ab8971aae664fa1dae8d905143149c4ba902d09cea5f08ebdf59f2d51f1f57e', 'initialCommit': None}, 'duration': 60120,
'exitReason': 'ReadTimeout', 'exitCode': 255}}]}
2023-11-02 08:44:21,905 | Unable to find Click Context for getting session_id.
2023-11-02 08:44:21,913 | Sending Telemetry: {'metrics': [{'events': {'requestId':
'63ef94f3-2eed-4d4e-b42e-aeebc79d85c4', 'installationId': 'fbec54fc-a77c-4092-8591-fffb078d0066', 'sessionId':
'7a5e9614-bc70-4397-bdb6-7b6d6fac76ae', 'executionEnvironment': 'CLI', 'ci': False, 'pyversion': '3.8.13',
'samcliVersion': '1.99.0', 'commandName': 'sam local invoke', 'metricSpecificAttributes': {'events':
[{'event_name': 'SamConfigFileExtension', 'event_value': '.toml', 'thread_id': '1d89df6b1c9640e8a85a8f90487f8b29',
'time_stamp': '2023-11-02 12:43:21.627', 'exception_name': None}, {'event_name': 'SamConfigFileExtension',
'event_value': '.toml', 'thread_id': 'c2205ea080924f74b49c88f5d6954ff1', 'time_stamp': '2023-11-02 12:43:21.694',
'exception_name': None}]}}}]}
2023-11-02 08:44:22,385 | HTTPSConnectionPool(host='aws-serverless-tools-telemetry.us-west-2.amazonaws.com',
port=443): Read timed out. (read timeout=0.1)

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 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 297, 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/local/invoke/cli.py", line 103, in cli
File "samcli/commands/local/invoke/cli.py", line 178, in do_cli
File "samcli/commands/local/cli_common/invoke_context.py", line 266, in enter
File "samcli/local/docker/manager.py", line 55, in is_docker_reachable
File "samcli/local/docker/utils.py", line 90, 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

An unexpected error was encountered while executing "sam local invoke".
Search for an existing issue:
https://github.com/aws/aws-sam-cli/issues?q=is%3Aissue+is%3Aopen+Bug%3A%20sam%20local%20invoke%20-%20ReadTimeout
Or create a bug report:
https://github.com/aws/aws-sam-cli/issues/new?template=Bug_report.md&title=Bug%3A%20sam%20local%20invoke%20-%20ReadTimeout
2023-11-02 08:44:22,393 | HTTPSConnectionPool(host='aws-serverless-tools-telemetry.us-west-2.amazonaws.com',
port=443): Read timed out. (read timeout=0.1)

Expected result:

(As scripted in the tutorial)

Additional environment details (Ex: Windows, Mac, Amazon Linux etc)

  1. OS: Mac OS 11.6
  2. sam --version: SAM CLI, version 1.99.0
  3. AWS region: us-west-2
# Paste the output of `sam --info` here
<hangs>
Traceback (most recent call last):
  File "urllib3/connectionpool.py", line 466, in _make_request
  File "<string>", line 3, in raise_from
  File "urllib3/connectionpool.py", line 461, in _make_request
  File "http/client.py", line 1348, in getresponse
  File "http/client.py", line 316, in begin
  File "http/client.py", line 277, in _read_status
  File "socket.py", line 669, in readinto
socket.timeout: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "requests/adapters.py", line 486, in send
  File "urllib3/connectionpool.py", line 798, in urlopen
  File "urllib3/util/retry.py", line 550, in increment
  File "urllib3/packages/six.py", line 770, in reraise
  File "urllib3/connectionpool.py", line 714, in urlopen
  File "urllib3/connectionpool.py", line 468, in _make_request
  File "urllib3/connectionpool.py", line 357, in _raise_timeout
urllib3.exceptions.ReadTimeoutError: UnixHTTPConnectionPool(host='localhost', port=None): Read timed out. (read timeout=60)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "samcli/__main__.py", line 12, in <module>
  File "click/core.py", line 1157, in __call__
  File "click/core.py", line 1077, in main
  File "click/core.py", line 943, in make_context
  File "click/core.py", line 1644, in parse_args
  File "click/core.py", line 1408, in parse_args
  File "click/core.py", line 2400, in handle_parse_result
  File "click/core.py", line 2362, in process_value
  File "samcli/cli/main.py", line 58, in print_info
  File "samcli/lib/utils/system_info.py", line 37, in gather_additional_dependencies_info
  File "samcli/lib/utils/system_info.py", line 61, in _gather_docker_info
  File "samcli/local/docker/utils.py", line 90, 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
requests.exceptions.ReadTimeout: UnixHTTPConnectionPool(host='localhost', port=None): Read timed out. (read timeout=60)
[7263] Failed to execute script '__main__' due to unhandled exception!

@Joymaker Joymaker added the stage/needs-triage Automatically applied to new issues and PRs, indicating they haven't been looked at. label Nov 2, 2023
@moelasmar
Copy link
Contributor

thanks @Joymaker for raising this issue. It looks like that the docker daemon is not running, could you please make sure that the docker daemon is running by executing the docker info and docker ps commands.

@moelasmar moelasmar added blocked/more-info-needed More info is needed from the requester. If no response in 14 days, it will become stale. blocked/close-if-inactive Blocked for >14 days with no response, will be closed if still inactive after 7 days area/local/invoke sam local invoke command and removed stage/needs-triage Automatically applied to new issues and PRs, indicating they haven't been looked at. labels Nov 3, 2023
@Joymaker
Copy link
Author

Joymaker commented Nov 3, 2023

Here you go. I noticed the following line:

daemon is not using the default seccomp profile

I don't understand what would have happened here, because I did a total naïve, new-user install.

% docker info
Client:
 Version:    24.0.6
 Context:    desktop-linux
 Debug Mode: false
 Plugins:
  buildx: Docker Buildx (Docker Inc.)
    Version:  v0.11.2-desktop.5
    Path:     /Users/ken/.docker/cli-plugins/docker-buildx
  compose: Docker Compose (Docker Inc.)
    Version:  v2.22.0-desktop.2
    Path:     /Users/ken/.docker/cli-plugins/docker-compose
  dev: Docker Dev Environments (Docker Inc.)
    Version:  v0.1.0
    Path:     /Users/ken/.docker/cli-plugins/docker-dev
  extension: Manages Docker extensions (Docker Inc.)
    Version:  v0.2.20
    Path:     /Users/ken/.docker/cli-plugins/docker-extension
  init: Creates Docker-related starter files for your project (Docker Inc.)
    Version:  v0.1.0-beta.8
    Path:     /Users/ken/.docker/cli-plugins/docker-init
  sbom: View the packaged-based Software Bill Of Materials (SBOM) for an image (Anchore Inc.)
    Version:  0.6.0
    Path:     /Users/ken/.docker/cli-plugins/docker-sbom
  scan: Docker Scan (Docker Inc.)
    Version:  v0.26.0
    Path:     /Users/ken/.docker/cli-plugins/docker-scan
  scout: Docker Scout (Docker Inc.)
    Version:  v1.0.7
    Path:     /Users/ken/.docker/cli-plugins/docker-scout

Server:
 Containers: 4
  Running: 0
  Paused: 0
  Stopped: 4
 Images: 10
 Server Version: 24.0.6
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Using metacopy: false
  Native Overlay Diff: true
  userxattr: false
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Cgroup Version: 2
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 8165feabfdfe38c65b599c4993d227328c231fca
 runc version: v1.1.8-0-g82f18fe
 init version: de40ad0
 Security Options:
  seccomp
   Profile: unconfined
  cgroupns
 Kernel Version: 6.4.16-linuxkit
 Operating System: Docker Desktop
 OSType: linux
 Architecture: x86_64
 CPUs: 8
 Total Memory: 7.672GiB
 Name: docker-desktop
 ID: 0da1384b-83d5-4383-9ff5-a32b5849f01b
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 HTTP Proxy: http.docker.internal:3128
 HTTPS Proxy: http.docker.internal:3128
 No Proxy: hubproxy.docker.internal
 Experimental: false
 Insecure Registries:
  hubproxy.docker.internal:5555
  127.0.0.0/8
 Live Restore Enabled: false

WARNING: daemon is not using the default seccomp profile
% docker ps
CONTAINER ID   IMAGE     COMMAND   CREATED   STATUS    PORTS     NAMES

@Endlessline
Copy link

I'm having the exact same issue as well

➜  ~ docker info
Client:
 Version:    24.0.6
 Context:    desktop-linux
 Debug Mode: false
 Plugins:
  buildx: Docker Buildx (Docker Inc.)
    Version:  v0.11.2-desktop.5
    Path:     /Users/collin.white/.docker/cli-plugins/docker-buildx
  compose: Docker Compose (Docker Inc.)
    Version:  v2.22.0-desktop.2
    Path:     /Users/collin.white/.docker/cli-plugins/docker-compose
  dev: Docker Dev Environments (Docker Inc.)
    Version:  v0.1.0
    Path:     /Users/collin.white/.docker/cli-plugins/docker-dev
  extension: Manages Docker extensions (Docker Inc.)
    Version:  v0.2.20
    Path:     /Users/collin.white/.docker/cli-plugins/docker-extension
  init: Creates Docker-related starter files for your project (Docker Inc.)
    Version:  v0.1.0-beta.8
    Path:     /Users/collin.white/.docker/cli-plugins/docker-init
  sbom: View the packaged-based Software Bill Of Materials (SBOM) for an image (Anchore Inc.)
    Version:  0.6.0
    Path:     /Users/collin.white/.docker/cli-plugins/docker-sbom
  scan: Docker Scan (Docker Inc.)
    Version:  v0.26.0
    Path:     /Users/collin.white/.docker/cli-plugins/docker-scan
  scout: Docker Scout (Docker Inc.)
    Version:  v1.0.7
    Path:     /Users/collin.white/.docker/cli-plugins/docker-scout

Server:
 Containers: 20
  Running: 0
  Paused: 0
  Stopped: 20
 Images: 12
 Server Version: 24.0.6
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Using metacopy: false
  Native Overlay Diff: true
  userxattr: false
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Cgroup Version: 2
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 8165feabfdfe38c65b599c4993d227328c231fca
 runc version: v1.1.8-0-g82f18fe
 init version: de40ad0
 Security Options:
  seccomp
   Profile: unconfined
  cgroupns
 Kernel Version: 6.4.16-linuxkit
 Operating System: Docker Desktop
 OSType: linux
 Architecture: x86_64
 CPUs: 8
 Total Memory: 7.77GiB
 Name: docker-desktop
 ID: f624dc3d-120c-4470-909a-f8cc863422f9
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 HTTP Proxy: http.docker.internal:3128
 HTTPS Proxy: http.docker.internal:3128
 No Proxy: hubproxy.docker.internal
 Experimental: false
 Insecure Registries:
  hubproxy.docker.internal:5555
  127.0.0.0/8
 Live Restore Enabled: false

WARNING: daemon is not using the default seccomp profile

➜  ~ docker ps
CONTAINER ID   IMAGE     COMMAND   CREATED   STATUS    PORTS     NAMES
➜  ~ 

@Joymaker
Copy link
Author

Joymaker commented Nov 6, 2023

In the end I got past this problem by doing a radical uninstall (manually) and reinstall of Docker. I used the form
brew install --cask docker
instead of downloading an installer, which seemed to work better. My original install had other problems including hanging while trying to update itself.

@hnnasit
Copy link
Contributor

hnnasit commented Jan 18, 2024

It seems the issue has been resolved after re-installing docker. I am closing this issue, feel free to open a new issue with more details if you are still facing issues or have concerns.

@hnnasit hnnasit closed this as completed Jan 18, 2024
Copy link
Contributor

⚠️COMMENT VISIBILITY WARNING⚠️

Comments on closed issues are hard for our team to see.
If you need more assistance, please either tag a team member or open a new issue that references this one.
If you wish to keep having a conversation with other community members under this issue feel free to do so.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/local/invoke sam local invoke command blocked/close-if-inactive Blocked for >14 days with no response, will be closed if still inactive after 7 days blocked/more-info-needed More info is needed from the requester. If no response in 14 days, it will become stale.
Projects
None yet
Development

No branches or pull requests

4 participants