[Question] Error during file fetching; aborting: Failed to open TCP connection

Question

[Question] Error during file fetching; aborting: Failed to open TCP connection

apupier opened this issue a year ago · 4 comments

I'm trying to use the dependabot cli but it is failing with a network error:

$ dependabot update maven apache/camel
0 apache
1 camel
    cli | 2024/01/03 15:20:03 Adding missing credentials-metadata into job definition
    cli | 2024/01/03 15:20:03 using image ghcr.io/github/dependabot-update-job-proxy/dependabot-update-job-proxy:latest at sha256:2f6d77226d2436c80cbdcd059307e2f60116e51cc9998710d75fea5c0c5b6560
    cli | 2024/01/03 15:20:03 using image ghcr.io/dependabot/dependabot-updater-maven at sha256:5b87ce52168ff255ff1d8084bb5a644a4f1a63fec85a2e06df23302c19a87c05
  proxy | 2024/01/03 15:20:05 proxy starting, commit: 02a8910b917eff32ef3fe812e35a131d6286bc20
  proxy | 2024/01/03 15:20:05 initializing metrics client: No address passed and autodetection from environment failed
  proxy | 2024/01/03 15:20:05 GitHubAPIHandler has no app access tokens
  proxy | 2024/01/03 15:20:05 Listening (:1080)
updater | Updating certificates in /etc/ssl/certs...
updater | rehash: warning: skipping ca-certificates.crt,it does not contain exactly one certificate or CRL
updater | 1 added, 0 removed; done.
updater | Running hooks in /etc/ca-certificates/update.d...
updater | done.
updater | 2024/01/03 15:20:07 INFO Raven 3.1.2 configured not to capture errors: DSN not set
updater | 2024/01/03 15:20:09 INFO Starting job processing
updater | 2024/01/03 15:20:09 ERROR Error during file fetching; aborting: Failed to open TCP connection to 172.20.0.2:1080 (No route to host - connect(2) for "172.20.0.2" port 1080)
updater | 2024/01/03 15:20:09 ERROR Failed to open TCP connection to 172.20.0.2:1080 (No route to host - connect(2) for "172.20.0.2" port 1080)
updater | 2024/01/03 15:20:09 ERROR /usr/local/lib/ruby/3.1.0/net/http.rb:1018:in `initialize'
updater | 2024/01/03 15:20:09 ERROR /usr/local/lib/ruby/3.1.0/net/http.rb:1018:in `open'
updater | 2024/01/03 15:20:09 ERROR /usr/local/lib/ruby/3.1.0/net/http.rb:1018:in `block in connect'
updater | 2024/01/03 15:20:09 ERROR /usr/local/lib/ruby/3.1.0/timeout.rb:107:in `block in timeout'
updater | 2024/01/03 15:20:09 ERROR /usr/local/lib/ruby/3.1.0/timeout.rb:117:in `timeout'
updater | 2024/01/03 15:20:09 ERROR /usr/local/lib/ruby/3.1.0/net/http.rb:1016:in `connect'
updater | 2024/01/03 15:20:09 ERROR /usr/local/lib/ruby/3.1.0/net/http.rb:995:in `do_start'
updater | 2024/01/03 15:20:09 ERROR /usr/local/lib/ruby/3.1.0/net/http.rb:984:in `start'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/faraday-net_http-3.0.2/lib/faraday/adapter/net_http.rb:112:in `request_with_wrapped_block'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/faraday-net_http-3.0.2/lib/faraday/adapter/net_http.rb:102:in `perform_request'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/faraday-net_http-3.0.2/lib/faraday/adapter/net_http.rb:66:in `block in call'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/faraday-2.7.11/lib/faraday/adapter.rb:45:in `connection'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/faraday-net_http-3.0.2/lib/faraday/adapter/net_http.rb:65:in `call'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/faraday-2.7.11/lib/faraday/middleware.rb:17:in `call'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/faraday-2.7.11/lib/faraday/middleware.rb:17:in `call'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/octokit-6.1.1/lib/octokit/middleware/follow_redirects.rb:73:in `perform_with_redirection'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/octokit-6.1.1/lib/octokit/middleware/follow_redirects.rb:61:in `call'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/faraday-retry-2.2.0/lib/faraday/retry/middleware.rb:153:in `call'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/faraday-2.7.11/lib/faraday/rack_builder.rb:153:in `build_response'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/faraday-2.7.11/lib/faraday/connection.rb:444:in `run_request'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/faraday-2.7.11/lib/faraday/connection.rb:200:in `get'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sawyer-0.9.2/lib/sawyer/agent.rb:99:in `call'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/octokit-6.1.1/lib/octokit/connection.rb:156:in `request'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/octokit-6.1.1/lib/octokit/connection.rb:19:in `get'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/octokit-6.1.1/lib/octokit/client/repositories.rb:27:in `repository'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/common/lib/dependabot/clients/github_with_retries.rb:121:in `public_send'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/common/lib/dependabot/clients/github_with_retries.rb:121:in `method_missing'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/common/lib/dependabot/clients/github_with_retries.rb:78:in `fetch_default_branch'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/common/lib/dependabot/file_fetchers/base.rb:289:in `default_branch_for_repo'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sorbet-runtime-0.5.11142/lib/types/private/methods/call_validation.rb:256:in `bind_call'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sorbet-runtime-0.5.11142/lib/types/private/methods/call_validation.rb:256:in `validate_call'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sorbet-runtime-0.5.11142/lib/types/private/methods/_methods.rb:275:in `block in _on_method_added'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/common/lib/dependabot/file_fetchers/base.rb:121:in `commit'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sorbet-runtime-0.5.11142/lib/types/private/methods/call_validation.rb:256:in `bind_call'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sorbet-runtime-0.5.11142/lib/types/private/methods/call_validation.rb:256:in `validate_call'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sorbet-runtime-0.5.11142/lib/types/private/methods/_methods.rb:275:in `block in _on_method_added'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/lib/dependabot/file_fetcher_command.rb:26:in `perform_job'
updater | 2024/01/03 15:20:09 ERROR /home/dependabot/dependabot-updater/lib/dependabot/base_command.rb:53:in `run'
updater | 2024/01/03 15:20:09 ERROR bin/fetch_files.rb:24:in `<main>'
updater | 2024/01/03 15:20:26 ERROR failed to connect: No route to host - connect(2) for "172.20.0.2" port 1080
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/http-5.1.1/lib/http/timeout/null.rb:21:in `initialize'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/http-5.1.1/lib/http/timeout/null.rb:21:in `open'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/http-5.1.1/lib/http/timeout/null.rb:21:in `connect'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/http-5.1.1/lib/http/connection.rb:42:in `initialize'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/http-5.1.1/lib/http/client.rb:70:in `new'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/http-5.1.1/lib/http/client.rb:70:in `perform'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/http-5.1.1/lib/http/client.rb:31:in `request'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/http-5.1.1/lib/http/chainable.rb:27:in `post'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/lib/dependabot/api_client.rb:117:in `record_update_job_error'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sorbet-runtime-0.5.11142/lib/types/private/methods/call_validation.rb:256:in `bind_call'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sorbet-runtime-0.5.11142/lib/types/private/methods/call_validation.rb:256:in `validate_call'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sorbet-runtime-0.5.11142/lib/types/private/methods/_methods.rb:275:in `block in _on_method_added'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/lib/dependabot/service.rb:64:in `record_update_job_error'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sorbet-runtime-0.5.11142/lib/types/private/methods/call_validation.rb:256:in `bind_call'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sorbet-runtime-0.5.11142/lib/types/private/methods/call_validation.rb:256:in `validate_call'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/vendor/ruby/3.1.0/gems/sorbet-runtime-0.5.11142/lib/types/private/methods/_methods.rb:275:in `block in _on_method_added'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/lib/dependabot/file_fetcher_command.rb:208:in `record_error'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/lib/dependabot/file_fetcher_command.rb:192:in `handle_file_fetcher_error'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/lib/dependabot/file_fetcher_command.rb:45:in `rescue in perform_job'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/lib/dependabot/file_fetcher_command.rb:23:in `perform_job'
updater | 2024/01/03 15:20:26 ERROR /home/dependabot/dependabot-updater/lib/dependabot/base_command.rb:53:in `run'
updater | 2024/01/03 15:20:26 ERROR bin/fetch_files.rb:24:in `<main>'
updater | 2024/01/03 15:20:51 INFO Results:
updater | Dependabot encountered '2' error(s) during execution, please check the logs for more details.
updater | +--------------------+
updater | |       Errors       |
updater | +--------------------+
updater | | file_fetcher_error |
updater | | unknown_error      |
updater | +--------------------+
  proxy | 2024/01/03 15:20:51 0/0 calls cached (0%)

Any ideas what could be going wrong and how to investigate it?

Answer 1 · 2024-01-03T16:02:21.000Z

The Dependabot CLI creates Docker networks to restrict the Updater from communicating except through the Proxy:

flowchart LR
  proxy --> internet
  proxy-- host.docker.internal -->api
subgraph host
  api
  subgraph internal
  updater --> proxy
  end
end

Since the Proxy listens on port 1080, it seems the Updater is failing to connect to the Proxy.

Docker networks are implemented with firewalls, so there's probably a firewall rule interfering with Docker's networking. Check to see if you have any firewall rules involving port 1080.

Answer 2 · 2024-01-03T16:17:39.000Z

Thanks for the answer.
At first sight, i have nothing, I tried sudo firewall-cmd --list-all-zones | grep 1080 and it gives no result.
and also:

sudo firewall-cmd --add-port=1080/tcp
Warning: ALREADY_ENABLED: '1080:tcp' already in 'FedoraWorkstation'
success

Based on https://docs.docker.com/network/packet-filtering-firewalls/#integration-with-firewalld , I checked the docker firewall which is created automatically, it is :

docker (active)
  target: ACCEPT
  ingress-priority: 0
  egress-priority: 0
  icmp-block-inversion: no
  interfaces: br-0540fac5ebc7 docker0
  sources: 
  services: 
  ports: 
  protocols: 
  forward: no
  masquerade: no
  forward-ports: 
  source-ports: 
  icmp-blocks: 
  rich rules:

EDIT: I tried to add the same port range on the docker config than onthe efault one, which gives:

docker (active)
  target: ACCEPT
  ingress-priority: 0
  egress-priority: 0
  icmp-block-inversion: no
  interfaces: br-0540fac5ebc7 docker0
  sources: 
  services: 
  ports: 1025-65535/udp 1025-65535/tcp
  protocols: 
  forward: no
  masquerade: no
  forward-ports: 
  source-ports: 
  icmp-blocks: 
  rich rules:

but it is failing with the same error

Answer 3 · 2024-01-03T16:38:06.000Z

Another possibility is the subnet Docker is using is overlapping with existing routes. This post does a better job of explaining things than I could: https://stackoverflow.com/questions/50514275/docker-bridge-conflicts-with-host-network

We sometimes see this in GitHub Enterprise Server: https://docs.github.com/en/enterprise-server@3.10/admin/github-actions/enabling-github-actions-for-github-enterprise-server/managing-self-hosted-runners-for-dependabot-updates#configuring-self-hosted-runners-for-dependabot-updates

Answer 4 · 2024-01-04T13:38:54.000Z

Thanks for the pointers. I wasn't able to configure things correctly even after trying most of the solutions pointed out. But at least I tried to deactivate the firewall and it is working. So definitely related to some firewall configuration.
I will close this issue to not pollute your issue tracker with my local configuration issue.

Thanks again for your help.