gosshagent.ForwardToRemote fails with ssh agent from git for windows

[adastraperangusta]

Hello,

I am using DevPod v0.5.0-alpha.1 on windows (build 1607) and I am using ssh client from git.

What happened?

I'm getting the following error every time i try to set up a workspace (with any provider like ssh or docker)

[14:41:38] info Workspace src-1 already exists
[14:41:38] debug Acquire workspace lock...
[14:41:38] debug Acquired workspace lock...
[14:41:38] info Creating devcontainer...
[14:41:38] debug Inject and run command: '/tmp/devpod/agent' helper ssh-server --stdio --debug
[14:41:38] debug execute inject script
[14:41:38] debug download agent from https://github.com/loft-sh/devpod/releases/download/v0.5.0-alpha.1
[14:41:38] debug Attempting to create SSH client
[14:41:38] debug Run command provider command: ${SSH_PROVIDER} command
[14:41:46] debug Received line after pong: done
[14:41:46] debug SSH client created
[14:41:46] debug SSH session created
[14:41:47] info Execute SSH server command: bash -c '/tmp/devpod/agent' agent workspace up --workspace-info '....' --debug
[14:41:47] info No root required, because neither docker nor agent daemon needs to be installed
[14:41:47] info Use /home/user/.devpod/agent/contexts/default/workspaces/src-1 as workspace dir
[14:41:47] debug Created logger
[14:41:47] debug Received ping from agent
[14:41:47] debug Credentials server started on port 16886...
[14:41:48] debug Incoming client connection at /
[14:41:48] debug Credentials server started...
[14:41:48] debug Wrote docker credentials helper to /home/user/.devpod/agent/contexts/default/workspaces/src-1/.cache/hmofachtfmjr/docker-credential-devpod
[14:41:48] debug Workspace Folder already exists /home/user/.devpod/agent/contexts/default/workspaces/src-1/content
[14:41:48] debug Workspace exists, skip downloading
[14:41:48] debug Using docker command 'docker'
[14:41:48] info find dev container: docker ps: Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running?
[14:41:48] info exit status 1
[14:41:48] info devcontainer up
[14:41:48] info github.com/loft-sh/devpod/cmd/agent/workspace.(*UpCmd).Run
[14:41:48] info /home/runner/work/devpod/devpod/cmd/agent/workspace/up.go:95
[14:41:48] info github.com/loft-sh/devpod/cmd/agent/workspace.NewUpCmd.func1
[14:41:48] info /home/runner/work/devpod/devpod/cmd/agent/workspace/up.go:52
[14:41:48] info github.com/spf13/cobra.(*Command).execute
[14:41:48] info /home/runner/work/devpod/devpod/vendor/github.com/spf13/cobra/command.go:916
[14:41:48] info github.com/spf13/cobra.(*Command).ExecuteC
[14:41:48] info /home/runner/work/devpod/devpod/vendor/github.com/spf13/cobra/command.go:1044
[14:41:48] info github.com/spf13/cobra.(*Command).Execute
[14:41:48] info /home/runner/work/devpod/devpod/vendor/github.com/spf13/cobra/command.go:968
[14:41:48] info github.com/loft-sh/devpod/cmd.Execute
[14:41:48] info /home/runner/work/devpod/devpod/cmd/root.go:90
[14:41:48] info main.main
[14:41:48] info /home/runner/work/devpod/devpod/main.go:8
[14:41:48] info runtime.main
[14:41:48] info /opt/hostedtoolcache/go/1.20.5/x64/src/runtime/proc.go:250
[14:41:48] info runtime.goexit
[14:41:48] info /opt/hostedtoolcache/go/1.20.5/x64/src/runtime/asm_amd64.s:1598
[14:41:48] debug done inject
[14:41:48] debug done injecting
[14:41:48] debug Done InjectAgentAndExecute
[14:41:48] debug Connection to SSH Server closed
[14:41:48] debug Done executing ssh server helper command
[14:41:48] debug Done creating devcontainer
[14:41:48] debug done exec
[14:41:48] fatal dial unix /tmp/ssh-pXI49uWqMjo3/agent.1902: socket: Une adresse incompatible avec le protocole demandé a été utilisée.
forward agent
github.com/loft-sh/devpod/pkg/devcontainer/sshtunnel.ExecuteCommand.func2
        D:/a/devpod/devpod/pkg/devcontainer/sshtunnel/sshtunnel.go:109
runtime.goexit
        C:/hostedtoolcache/windows/go/1.20.5/x64/src/runtime/asm_amd64.s:1598

"Une adresse incompatible avec le protocole demandé a été utilisée." means "An address incompatible with the requested protocol was used."

I have checked in a git bash :

$  ls /tmp/ssh-pXI49uWqMjo3/agent.1902
/tmp/ssh-pXI49uWqMjo3/agent.1902=

BTW, I have the same error message if I put any non-existing file in SSH_AUTH_SOCK environment varaible.

What did you expect to happen instead?
Being able to have a fully working workspace.

How can we reproduce the bug? (as minimally and precisely as possible)

create any workspace on any ssh backend will fail

Local Environment:

• DevPod Version: 0.5.0-alpha.1
• Operating System: windows (build 1607)
• ARCH of the OS: AMD64

DevPod Provider:

• Local/remote provider: docker and ssh

Anything else we need to know?
ssh from latest portable git bash for windows.

ssh-agent works great with other programs (vs code, idea, shh ...).

Regards,

[pascalbreuninger]

@adastraperangusta thanks for reporting the issue, we'll look into it 👍 are you using WSL?
There's also this log line:
[14:41:48] info find dev container: docker ps: Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running?

[adastraperangusta]

Hello,

I don't use wsl2. I only have a docker binary on the windows machine and DOCKER_HOST is set to a remote linux vm with docker:
DOCKER_HOST=ssh://user@host

I have redone a test with this properly set so there is no error with docker. I have the feeling it is a bug in the go crypto ssh agent that doesn't work with the socket created by the ssh-agent from git for windows.

Furthermore I did a test with a similar setting on a windows machine with the windows openssh client and agent, and I don't have this error.

[10:04:49] debug Acquire workspace lock...
[10:04:49] debug Acquired workspace lock...
[10:04:49] info Creating devcontainer...
[10:04:49] debug Inject and run command: '/tmp/devpod/agent' helper ssh-server --stdio --debug
[10:04:49] debug execute inject script
[10:04:49] debug download agent from https://github.com/loft-sh/devpod/releases/download/v0.5.0-alpha.2
[10:04:49] debug Attempting to create SSH client
[10:04:49] debug Run command provider command: ${SSH_PROVIDER} command
[10:04:52] debug Received line after pong: done
[10:04:53] debug SSH client created
[10:04:53] debug SSH session created
[10:04:53] info Execute SSH server command: bash -c '/tmp/devpod/agent' agent workspace up --workspace-info 'H4sIAAAAAAA....AA' --debug
[10:04:53] info No root required, because neither docker nor agent daemon needs to be installed
[10:04:53] info Use /home/user/.devpod/agent/contexts/default/workspaces/src-ssh as workspace dir
[10:04:53] debug Created logger
[10:04:53] debug Received ping from agent
[10:04:53] debug Credentials server started on port 13722...
[10:04:54] debug Incoming client connection at /
[10:04:54] debug Credentials server started...
[10:04:54] debug Wrote docker credentials helper to /home/user/.devpod/agent/contexts/default/workspaces/src-ssh/.cache/icqvpyagpfbx/docker-credential-devpod
[10:04:54] debug Create content folder /home/user/.devpod/agent/contexts/default/workspaces/src-ssh/content
[10:04:54] debug Clone Repository
[10:04:54] info Cloning into '/home/user/.devpod/agent/contexts/default/workspaces/src-ssh/content'...
[10:04:54] debug Incoming client connection at /git-credentials
[10:04:54] debug Received git credentials post data: {"protocol":"https","host":"********"}
[10:04:58] debug Successfully wrote back 103 bytes
[10:04:58] debug Using docker command 'docker'
[10:04:58] info Couldn't find a devcontainer.json
[10:04:59] info Try detecting project programming language...
[10:04:59] info Detected project language 'JavaScript'
[10:04:59] debug Incoming client connection at /docker-credentials
[10:04:59] debug Received docker credentials post data: {"ServerURL":"mcr.microsoft.com/devcontainers/javascript-node"}
[10:04:59] debug Successfully wrote back 89 bytes
[10:04:59] debug Incoming client connection at /docker-credentials
[10:04:59] debug Received docker credentials post data: {"ServerURL":"mcr.microsoft.com"}
[10:04:59] debug Successfully wrote back 59 bytes
[10:05:00] debug Running docker command: docker run --sig-proxy=false --mount type=bind,src=/home/user/.devpod/agent/contexts/default/workspaces/src-ssh/content,dst=/workspaces/src-ssh -u root -l dev.containers.id=src-ssh-de-9ecfd -l devcontainer.metadata=[{"id":"ghcr.io/devcontainers/features/common-utils:2"},{"id":"ghcr.io/devcontainers/features/git:1"},{"id":"ghcr.io/devcontainers/features/node:1","customizations":{"vscode":{"extensions":["dbaeumer.vscode-eslint"]}}},{"remoteUser":"node","customizations":{"vscode":{"extensions":["dbaeumer.vscode-eslint"]}}},{}] -l devpod.user=root -d --entrypoint /bin/sh mcr.microsoft.com/devcontainers/javascript-node -c echo Container started
trap "exit 0" 15

exec "$@"
while sleep 1 & wait $!; do :; done -
[10:05:00] info Unable to find image 'mcr.microsoft.com/devcontainers/javascript-node:latest' locally
[10:05:00] debug Incoming client connection at /docker-credentials
[10:05:00] debug Received docker credentials post data: {"ServerURL":"mcr.microsoft.com"}
[10:05:00] debug Successfully wrote back 59 bytes
[10:05:01] info latest: Pulling from devcontainers/javascript-node
[10:05:01] info bc0734b949dc: Pulling fs layer
[10:05:01] info b5de22c0f5cd: Pulling fs layer
[10:05:01] info 917ee5330e73: Pulling fs layer
[10:05:01] info b43bd898d5fb: Pulling fs layer
[10:05:01] info 9b5852c9e7e7: Pulling fs layer
[10:05:01] info ffce7831deb3: Pulling fs layer
[10:05:01] info 4360a670e724: Pulling fs layer
[10:05:01] info 657e9acbc9b4: Pulling fs layer
[10:05:01] info 37a6152d8890: Pulling fs layer
[10:05:01] info 6d36feaab2b9: Pulling fs layer
[10:05:01] info 294eff86a761: Pulling fs layer
[10:05:01] info dffe9e48a582: Pulling fs layer
[10:05:01] info d1f899ff368b: Pulling fs layer
[10:05:01] info c10c17fa7c9b: Pulling fs layer
[10:05:01] info 3c942730d2ae: Pulling fs layer
[10:05:01] info cde427c7fe81: Pulling fs layer
[10:05:01] info b43bd898d5fb: Waiting
[10:05:01] info 9b5852c9e7e7: Waiting
[10:05:01] info ffce7831deb3: Waiting
[10:05:01] info 4360a670e724: Waiting
[10:05:01] info 657e9acbc9b4: Waiting
[10:05:01] info 37a6152d8890: Waiting
[10:05:01] info 6d36feaab2b9: Waiting
[10:05:01] info 294eff86a761: Waiting
[10:05:01] info dffe9e48a582: Waiting
[10:05:01] info d1f899ff368b: Waiting
[10:05:01] info c10c17fa7c9b: Waiting
[10:05:01] info cde427c7fe81: Waiting
[10:05:01] info 3c942730d2ae: Waiting
[10:05:12] info bc0734b949dc: Verifying Checksum
[10:05:12] info bc0734b949dc: Download complete
[10:05:17] info 917ee5330e73: Verifying Checksum
[10:05:17] info 917ee5330e73: Download complete
[10:05:18] info 9b5852c9e7e7: Verifying Checksum
[10:05:18] info 9b5852c9e7e7: Download complete
[10:05:18] info bc0734b949dc: Pull complete
[10:05:25] info b5de22c0f5cd: Verifying Checksum
[10:05:25] info b5de22c0f5cd: Download complete
[10:05:26] info 4360a670e724: Verifying Checksum
[10:05:26] info 4360a670e724: Download complete
[10:05:26] info 657e9acbc9b4: Verifying Checksum
[10:05:26] info 657e9acbc9b4: Download complete
[10:05:29] info 37a6152d8890: Verifying Checksum
[10:05:29] info 37a6152d8890: Download complete
[10:05:30] info 6d36feaab2b9: Verifying Checksum
[10:05:30] info 6d36feaab2b9: Download complete
[10:05:31] info 294eff86a761: Verifying Checksum
[10:05:31] info 294eff86a761: Download complete
[10:05:31] info dffe9e48a582: Verifying Checksum
[10:05:31] info dffe9e48a582: Download complete
[10:05:33] info b5de22c0f5cd: Pull complete
[10:05:33] info d1f899ff368b: Verifying Checksum
[10:05:33] info d1f899ff368b: Download complete
[10:05:37] info ffce7831deb3: Verifying Checksum
[10:05:37] info ffce7831deb3: Download complete
[10:05:47] info 917ee5330e73: Pull complete
[10:05:55] info c10c17fa7c9b: Verifying Checksum
[10:05:55] info c10c17fa7c9b: Download complete
[10:05:58] info cde427c7fe81: Verifying Checksum
[10:05:58] info cde427c7fe81: Download complete
[10:06:01] info 3c942730d2ae: Verifying Checksum
[10:06:01] info 3c942730d2ae: Download complete
[10:06:27] info b43bd898d5fb: Verifying Checksum
[10:06:27] info b43bd898d5fb: Download complete
[10:06:44] info b43bd898d5fb: Pull complete
[10:06:51] info 9b5852c9e7e7: Pull complete
[10:06:59] info ffce7831deb3: Pull complete
[10:07:06] info 4360a670e724: Pull complete
[10:07:10] info 657e9acbc9b4: Pull complete
[10:07:17] info 37a6152d8890: Pull complete
[10:07:23] info 6d36feaab2b9: Pull complete
[10:07:28] info 294eff86a761: Pull complete
[10:07:34] info dffe9e48a582: Pull complete
[10:07:39] info d1f899ff368b: Pull complete
[10:07:51] info c10c17fa7c9b: Pull complete
[10:08:03] info 3c942730d2ae: Pull complete
[10:08:12] info cde427c7fe81: Pull complete
[10:08:13] info Digest: sha256:ff7fcaf39a616aed41b7e9af6ebedfee1c605e89ba9416c6fa79f33762345aa7
[10:08:13] info Status: Downloaded newer image for mcr.microsoft.com/devcontainers/javascript-node:latest
[10:08:28] info d73e77fc1393652efef480dc4b4a4bfbe7f5c19d3e2bafb1b949805c086bb21d
[10:08:28] debug execute inject script
[10:08:28] debug Received line after pong: ARM-false
[10:08:28] debug Inject binary
[10:08:28] debug Done injecting binary
[10:08:28] debug done exec
[10:08:28] debug done inject
[10:08:28] debug done injecting
[10:08:29] debug Done InjectAgentAndExecute
[10:08:29] debug Injected into container
[10:08:29] info Setup container...
[10:08:29] debug Inject and run command: '/usr/local/bin/devpod' helper ssh-server --stdio --debug
[10:08:29] debug Attempting to create SSH client
[10:08:29] debug SSH client created
[10:08:29] debug SSH session created
[10:08:29] info Execute SSH server command: bash -c '/usr/local/bin/devpod' agent container setup --setup-info 'H4sIAAAAA...8AAA==' --container-workspace-info 'H4sIA...AAA=' --chown-workspace --debug
[10:08:29] debug Created logger
[10:08:29] debug Received ping from agent
[10:08:29] debug Start setting up container...
[10:08:29] info Chown workspace...
[10:08:29] debug Patch etc environment & profile...
[10:08:29] debug Run post create commands...
[10:08:29] debug Done setting up environment
[10:08:29] debug Setup vscode...
[10:08:29] info Install extensions 'dbaeumer.vscode-eslint' in the background
[10:08:29] debug Connection to SSH Server closed
[10:08:29] debug Done executing ssh server helper command
[10:08:29] debug Done setting up container
[10:08:30] debug done inject
[10:08:30] debug Connection to SSH Server closed
[10:08:30] debug done injecting
[10:08:30] debug Done InjectAgentAndExecute
[10:08:30] debug Done executing ssh server helper command
[10:08:30] debug Done creating devcontainer
[10:08:30] debug done exec
[10:08:30] fatal dial unix C:/Temp/ssh-SnVBCr9uN9eo/agent.2041: socket: Une adresse incompatible avec le protocole demandé a été utilisée.
forward agent
github.com/loft-sh/devpod/pkg/devcontainer/sshtunnel.ExecuteCommand.func2
        D:/a/devpod/devpod/pkg/devcontainer/sshtunnel/sshtunnel.go:109
runtime.goexit
        C:/hostedtoolcache/windows/go/1.20.5/x64/src/runtime/asm_amd64.s:1598

[pascalbreuninger]

Thanks for the pointer! We'll test it specifically with git bash

[pascalbreuninger]

@adastraperangusta In the meantime you can use the DevPod SSH Provider directly to connect your workspace on the machine from which you currently expose docker.

[adastraperangusta]

Hello,

I have yet to test this direct use of the provider to connect.
But meanwhile I have noticed this message in crypto/ssh/agent testsuite :

if runtime.GOOS == "windows" {
      t.Skip("skipping on windows, we don't support connecting to the ssh-agent via a named pipe")
}

I appears the the ssh-agent.exe is using named pipe on windows since there is no support for unix socket.
I think it explains this error message for an incompatible protocol, we're trying to use a socket while it is a named pipe.

fatal dial unix /tmp/ssh-pXI49uWqMjo3/agent.1902: socket: Une adresse incompatible avec le protocole demandé a été utilisée.
forward agent

So I'm afraid that my use case won't be supported until golang ssh-agent support is improved.

[pascalbreuninger]

Thanks for looking a bit more into this @adastraperangusta. As you mentioned this requires an upstream change that we don't have the bandwidth to do right now. Maybe someone contributes it to the golang ssh library. Until then I'd close this ticket