Open rklec opened 1 month ago
Error: could not listen on npipe:////./pipe/docker_engine: open //./pipe/docker_engine: Zugriff verweigert time="2024-07-09T15:16:59+02:00" level=info msg="Got WSL2 VM" guid=48b7ebae-da49-4b92-94ee-31f889238512
Hmm, that's probably the issue: we fail to set up the (Windows-side) docker socket listener, so running docker.exe load …
fails because it couldn't talk to the server.
Given your woes of installing WSL and whatnot, I guess your IT people might have done some policy things to make this not work? You might be able to get something working by switching to containerd; that might be an acceptable solution depending on what you want to do with Rancher Desktop.
Either way, it would be useful to see if you can figure out why access was denied. If we can have a good way to knowing that is going to happen, we might be able to listen on a TCP port instead? (But that might take a while to implement.)
You might be able to get something working by switching to containerd;
Surprisingly, this has worked. 😆
Either way, it would be useful to see if you can figure out why access was denied.
If I would understand that thing then maybe I could help. See maybe the security products I have mentioned.
So it tries to access the pipe npipe:////./pipe/docker_engine
to communicate? I have no idea why that fails.
- I do have docker already installed in the WSL manually before and I was able to start it with
dockerd
. Unfortunately, my tries making it a real service or so always failed so far (and it was not important).
I wonder if your experiments did set up some kind of service that already creates the named pipe instead, making it unavailable to Rancher Desktop.
When Rancher Desktop is not running, could you run the following command in PowerShell:
[System.IO.Directory]::GetFiles("\\.\\pipe\\") | findstr docker
If it finds the pipe, it means there is a conflict with something else already running on your system.
Well I use containerd
now, but okay, I exit rancher and indeed it finds sth:
> [System.IO.Directory]::GetFiles("\\.\\pipe\\") | findstr docker
\\.\\pipe\\docker_engine
That said, I would argue against that this is me setting sth. up:
- There is Windows docker.exe already installed, also as a windows service, that may be it, but not related to WSL?
Do you have "Docker Desktop" installed on the machine? Maybe it is auto-starting or something?
Anyways, I think this is a local conflict on your machine; if you manage to resolve this, the Rancher Desktop likely will start working even with moby
instead of containerd
.
Docker Desktop is not installed. But the docker service on Windows is started:
And indeed, if I stop that service, it works: [System.IO.Directory]::GetFiles("\\.\\pipe\\") | findstr docker
finds nothing anymore.
Ah and indeed, now also Rancher seems to work even if I switch back to dockerd.,
The only suggestion I would have is: could not you catch this error and show a more meaningful error message? I mean form the error itself, one would not come up with "Ah yeah, this is a conflicting docker installation!". Maybe you could hint at that potential cause, when the error happens though, so one does not need to search for GitHub or so, especially as I guess this could be a quite common error, is not it?
could not you catch this error and show a more meaningful error message?
Yes, I think we should detect if the named pipe already exists. I'll edit the issue subject line to reflect this.
I guess this could be a quite common error, is not it?
I'm not sure about that; I don't remember seeing other GitHub issues or Slack threads about this. Normally this can only happen when people run Docker Desktop at the same time. It is quite rare that people try to setup the docker service on Windows without it.
Actual Behavior
I tried activating WSL support and it failed like this:
AFAIK I had Kubernetes checked and I thought let's just try... but as it did not work I have unchecked it and tried using pure Docker (which would be fine for my use case for now).
Steps to Reproduce
This could be related due to many problems:
dockerd
. Unfortunately, my tries making it a real service or so always failed so far (and it was not important).I just started Rancher and let it do it's thing... activated WSL etc.
Result
see screenshot above, or in text:
This is reproducible, no matter whether I (try to) disable or (try to) enable WSL again (note the toggle in the settings is always toggled, and I can always click it again), it's always some error about
rdx-proxy.tar
.Thus, I searched for
rdx-proxy.tar
in the provided logs folder and found only results inbackground.log
:(This is basically everything in that file... repeated several times in a similar way.)
It all looks very successful, but I cannot find useful error information. So I've just searched for "error" in all files (> 25.000 results 😆)
Warning: many logs ahead
`docker.log`: ``` time="2024-07-09T13:27:22.776338100+02:00" level=info msg="containerd successfully booted in 0.062553s" time="2024-07-09T13:27:23.655698900+02:00" level=info msg="[graphdriver] using prior storage driver: overlay2" time="2024-07-09T13:27:23.660546900+02:00" level=info msg="Loading containers: start." time="2024-07-09T13:27:24.010384700+02:00" level=info msg="Removing stale sandbox bbb070c05b637400e69c47c7493ac679171dd51a432046ee7b0fc8a35eba8cc8 (af4d41e0b147205deccec869c18530f52b832eae204ce56c26f623e96f170839)" time="2024-07-09T13:27:24.017123100+02:00" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 8a6fad1cd747d3e0e56a8bc5437421ebfde9040f4e10cd930af85d49152398c0 8ddc0faa6f44fdb65a7ae180d0c4f858d8a2c13ee4bcc924c411c19d705dda7a], retrying...." time="2024-07-09T13:27:24.035288500+02:00" level=info msg="Removing stale sandbox f7093513f19efc77b0b8dfc4404e4a3744df11aeae0e1a5270bb56324bb46981 (7f713d2db18c3f90e3c081ee8e22c62e3f8e1ab45932276d75b4d4ae487c3d19)" time="2024-07-09T13:27:24.041503600+02:00" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 8a6fad1cd747d3e0e56a8bc5437421ebfde9040f4e10cd930af85d49152398c0 2b486cc6b2357221177c9f27402ed1f490101490f02db1179918d0e5126ade9d], retrying...." time="2024-07-09T13:27:24.065178900+02:00" level=info msg="Removing stale sandbox 59f9d6d4996e9cc687db09aa8e5f7294220408a973b3066127926c263436f79f (3aa1a29f397e9d9c1bbc5fbb917e169674925791fce6304725058ae26d99f5c7)" time="2024-07-09T13:27:24.071938600+02:00" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 8a6fad1cd747d3e0e56a8bc5437421ebfde9040f4e10cd930af85d49152398c0 3bbee5ca84600c68c90c09837728e86fa2f0dfb3a817b187a892feb90dd4760f], retrying...." time="2024-07-09T13:27:24.090617600+02:00" level=info msg="Removing stale sandbox 805b38efbafcd2a22c36990813ea2ab7289eab07727dd9662d5970205da03feb (60be1572bfae16a716715592bb875fcca6e932233faca44dca4a9b0c3bc67899)" time="2024-07-09T13:27:24.097089900+02:00" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 8a6fad1cd747d3e0e56a8bc5437421ebfde9040f4e10cd930af85d49152398c0 1659398e1e19b0fa880fe00a57d55d3e3055cb7a5a77a0c41b88523bda980e83], retrying...." time="2024-07-09T13:27:24.116382800+02:00" level=info msg="Removing stale sandbox a6b7063afdb75768c9356be711d3743f3ff7d74e0d7befe195648711270eea62 (07b46af379ba11a7b8c511daf53115504c1de7fc057a23aaeaa6a7ffb422ef3e)" time="2024-07-09T13:27:24.123336400+02:00" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 8a6fad1cd747d3e0e56a8bc5437421ebfde9040f4e10cd930af85d49152398c0 4f1d4e1884e1e47140952019e0579bff90b02e646873278715921c0bcf1a90a6], retrying...." time="2024-07-09T13:27:24.175637900+02:00" level=info msg="Default bridge (docker0) is assigned with an IP address 172.17.0.0/16. Daemon option --bip can be used to set a preferred IP address" time="2024-07-09T13:27:24.212149300+02:00" level=info msg="Loading containers: done." time="2024-07-09T13:27:24.232408700+02:00" level=warning msg="WARNING: No blkio throttle.read_bps_device support" time="2024-07-09T13:27:24.233105600+02:00" level=warning msg="WARNING: No blkio throttle.write_bps_device support" time="2024-07-09T13:27:24.233627800+02:00" level=warning msg="WARNING: No blkio throttle.read_iops_device support" time="2024-07-09T13:27:24.234107500+02:00" level=warning msg="WARNING: No blkio throttle.write_iops_device support" time="2024-07-09T13:27:24.235068200+02:00" level=info msg="Docker daemon" commit=e63daec8672d77ac0b2b5c262ef525c7cf17fd20 containerd-snapshotter=false storage-driver=overlay2 version=25.0.5 time="2024-07-09T13:27:24.235990900+02:00" level=info msg="Daemon has completed initialization" time="2024-07-09T13:27:24.255774500+02:00" level=info msg="API listen on /var/run/docker.sock" time="2024-07-09T13:27:24.255777500+02:00" level=info msg="API listen on /mnt/wsl/rancher-desktop/run/docker.sock" error accepting client connection: bad file descriptor error accepting client connection: invalid argument error accepting client connection: invalid argument error accepting client connection: invalid argument error accepting client connection: invalid argument error accepting client connection: invalid argument error accepting client connection: invalid argument [this line repeats **very** often] could not connect to docker: dial unix /mnt/wsl/rancher-desktop/run/docker.sock: connect: connection refused time="2024-07-09T16:43:37.027830100+02:00" level=info msg="Starting up" time="2024-07-09T16:43:37.030514400+02:00" level=info msg="containerd not running, starting managed containerd" ``` I also can find a lot of these errors (translated = permission denied; again repeated maybe 1000 times): ``` Error: could not listen on npipe:////./pipe/docker_engine: open //./pipe/docker_engine: Zugriff verweigert time="2024-07-09T15:16:53+02:00" level=info msg="Got WSL2 VM" guid=48b7ebae-da49-4b92-94ee-31f889238512 Error: could not listen on npipe:////./pipe/docker_engine: open //./pipe/docker_engine: Zugriff verweigert time="2024-07-09T15:16:54+02:00" level=info msg="Got WSL2 VM" guid=48b7ebae-da49-4b92-94ee-31f889238512 Error: could not listen on npipe:////./pipe/docker_engine: open //./pipe/docker_engine: Zugriff verweigert time="2024-07-09T15:16:55+02:00" level=info msg="Got WSL2 VM" guid=48b7ebae-da49-4b92-94ee-31f889238512 Error: could not listen on npipe:////./pipe/docker_engine: open //./pipe/docker_engine: Zugriff verweigert time="2024-07-09T15:16:57+02:00" level=info msg="Got WSL2 VM" guid=48b7ebae-da49-4b92-94ee-31f889238512 Error: could not listen on npipe:////./pipe/docker_engine: open //./pipe/docker_engine: Zugriff verweigert time="2024-07-09T15:16:58+02:00" level=info msg="Got WSL2 VM" guid=48b7ebae-da49-4b92-94ee-31f889238512 Error: could not listen on npipe:////./pipe/docker_engine: open //./pipe/docker_engine: Zugriff verweigert time="2024-07-09T15:16:59+02:00" level=info msg="Got WSL2 VM" guid=48b7ebae-da49-4b92-94ee-31f889238512 ``` `host-switch.log`: ``` time="2024-07-09T13:23:20+02:00" level=info msg="port forwarding API server is running on: 192.168.127.1:80" time="2024-07-09T13:23:20+02:00" level=info msg="new connection from 48b7ebae-da49-4b92-94ee-31f889238512:181b1e2f-facb-11e6-bd58-64006a7986d3 to 48b7ebae-da49-4b92-94ee-31f889238512:00001a00-facb-11e6-bd58-64006a7986d3" 2024/07/09 13:23:25 tcpproxy: for incoming conn 127.0.0.1:62322, error dialing "192.168.127.2:6443": connect tcp 192.168.127.2:6443: connection was refused 2024/07/09 13:26:48 tcpproxy: for incoming conn 127.0.0.1:63057, error dialing "192.168.127.2:6443": connect tcp 192.168.127.2:6443: connection was refused 2024/07/09 13:26:51 tcpproxy: for incoming conn 127.0.0.1:63059, error dialing "192.168.127.2:6443": connect tcp 192.168.127.2:6443: connection was refused time="2024-07-09T13:26:53+02:00" level=error msg="accept tcp [::]:443: use of closed network connection" time="2024-07-09T13:26:53+02:00" level=error msg="accept tcp [::]:80: use of closed network connection" ``` `k3s.log`: ``` I0709 13:23:58.702934 559 apf_controller.go:379] Running API Priority and Fairness config worker I0709 13:23:58.708131 559 apf_controller.go:382] Running API Priority and Fairness periodic rebalancing process time="2024-07-09T13:23:58+02:00" level=error msg="Sending HTTP 502 response to 127.0.0.1:39114: dial tcp 10.42.0.4:10250: connect: connection refused" time="2024-07-09T13:23:58+02:00" level=error msg="Sending HTTP 502 response to 127.0.0.1:39110: dial tcp 10.42.0.4:10250: connect: connection refused" time="2024-07-09T13:23:58+02:00" level=error msg="Sending HTTP 502 response to 127.0.0.1:39118: dial tcp 10.42.0.4:10250: connect: connection refused" time="2024-07-09T13:23:58+02:00" level=error msg="Sending HTTP 502 response to 127.0.0.1:39120: dial tcp 10.42.0.4:10250: connect: connection refused" time="2024-07-09T13:23:58+02:00" level=error msg="Sending HTTP 502 response to 127.0.0.1:39112: dial tcp 10.42.0.4:10250: connect: connection refused" I0709 13:23:58.721416 559 shared_informer.go:318] Caches are synced for crd-autoregister I0709 13:23:58.727398 559 aggregator.go:165] initial CRD sync complete... I0709 13:23:58.728755 559 autoregister_controller.go:141] Starting autoregister controller I0709 13:23:58.729662 559 cache.go:32] Waiting for caches to sync for autoregister controller I0709 13:23:58.730781 559 cache.go:39] Caches are synced for autoregister controller time="2024-07-09T13:23:58+02:00" level=error msg="Sending HTTP 502 response to 127.0.0.1:39132: dial tcp 10.42.0.4:10250: connect: connection refused" E0709 13:23:58.731783 559 available_controller.go:460] v1beta1.metrics.k8s.io failed with: failing or missing response from https://10.42.0.4:10250/apis/metrics.k8s.io/v1beta1: Get "https://10.42.0.4:10250/apis/metrics.k8s.io/v1beta1": proxy error from 127.0.0.1:6443 while dialing 10.42.0.4:10250, code 502: 502 Bad Gateway time="2024-07-09T13:23:58+02:00" level=error msg="Sending HTTP 502 response to 127.0.0.1:39134: dial tcp 10.42.0.4:10250: connect: connection refused" I0709 13:23:58.735026 559 handler.go:275] Adding GroupVersion metrics.k8s.io v1beta1 to ResourceManager time="2024-07-09T13:23:58+02:00" level=error msg="Sending HTTP 502 response to 127.0.0.1:39140: dial tcp 10.42.0.4:10250: connect: connection refused" E0709 13:23:58.735905 559 controller.go:102] Error removing old endpoints from kubernetes service: no API server IP addresses were listed in storage, refusing to erase all endpoints for the kubernetes Service time="2024-07-09T13:23:58+02:00" level=error msg="Sending HTTP 502 response to 127.0.0.1:39142: dial tcp 10.42.0.4:10250: connect: connection refused" E0709 13:23:58.737121 559 controller.go:146] Error updating APIService "v1beta1.metrics.k8s.io" with err: failed to download v1beta1.metrics.k8s.io: failed to retrieve openAPI spec, http error: ResponseCode: 503, Body: error trying to reach service: proxy error from 127.0.0.1:6443 while dialing 10.42.0.4:10250, code 502: 502 Bad Gateway , Header: map[Content-Type:[text/plain; charset=utf-8] X-Content-Type-Options:[nosniff]] W0709 13:23:58.745976 559 handler_proxy.go:93] no RequestInfo found in the context E0709 13:23:58.746652 559 controller.go:146] Error updating APIService "v1beta1.metrics.k8s.io" with err: failed to download v1beta1.metrics.k8s.io: failed to retrieve openAPI spec, http error: ResponseCode: 503, Body: service unavailable , Header: map[Content-Type:[text/plain; charset=utf-8] X-Content-Type-Options:[nosniff]] time="2024-07-09T13:23:58+02:00" level=error msg="Sending HTTP 502 response to 127.0.0.1:39148: dial tcp 10.42.0.4:10250: connect: connection refused" ``` `network-setup.log` (this is the whole file content): ``` time="2024-07-09T13:23:19+02:00" level=info msg="starting handshake process with host-switch" time="2024-07-09T13:23:19+02:00" level=error msg="listenForHandshake reading signature phrase failed: EOF" time="2024-07-09T13:23:20+02:00" level=info msg="listenForHandshake successful handshake with host-switch" time="2024-07-09T13:23:20+02:00" level=info msg="created a new namespace NS(10: 4, 4026532193) NS(10: 4, 4026532193)" time="2024-07-09T13:23:20+02:00" level=info msg="successfully started the vm-switch running with a PID: 463" time="2024-07-09T13:23:20+02:00" level=info msg="created veth pair veth-rd0 and veth-rd1" time="2024-07-09T13:26:54+02:00" level=error msg="vm-switch exited with error: signal: killed" time="2024-07-09T13:26:54+02:00" level=info msg="tearing down link veth-rd0:Edit: Oh I just noticed some errors are about
docker.exe
, so these likely occur when WSL is disabled and it (apparently also with errors) tries to use the Windows docker.Expected Behavior
Installation works? Or I can at least revert my decision to use Kubernetes or somehow make this work?
Additional Information
Windows host powershell:
Inside WSL (Ubuntu 20.04.6 LTS (Focal Fossa)):
As WSL is not installed from Windows Store it's hard to get out it's version.
Rancher Desktop Version
1.14.1
Rancher Desktop K8s Version
N/A
Which container engine are you using?
dockerd
What operating system are you using?
Windows
Operating System / Build Version
Windows 10 Enterprise Version 22H2 build 19045.4529
What CPU architecture are you using?
x64
Linux only: what package format did you use to install Rancher Desktop?
None
Windows User Only
Yes some VPN, but likely unrelated as this is not a networking issue, but long before?
Rancher Desktop also installed via chocolately.