erepo: ignores ssh-agent keys in windows git-bash

[B3QL]

Bug Report

pull: ignores ssh-agent keys

Description

DVC 2.10.0 stops using ssh-agent (passed via SSH_AUTH_SOCK variable) for git clone operation resulting in Permission denied error.

Traceback (most recent call last):
[...]
  File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\gall-UFKFKqae-py3.8\lib\site-packages\asyncssh\connection.py", line 2262, in wait_established

    await self._waiter

asyncssh.misc.PermissionDenied: Permission denied
[...]

Reproduce

- name: Setup SSH Keys and known_hosts
  env:
    SSH_AUTH_SOCK: /tmp/ssh_agent.sock
  run: |
    ssh-agent -a $SSH_AUTH_SOCK > /dev/null
    ssh-add - <<< "${{ secrets.SSH_KEY }}"
    mkdir ~/.ssh/
    ssh-keyscan -H github.com > ~/.ssh/known_hosts

- name: "Pull latest model"
  run: dvc pull
  env:
    SSH_AUTH_SOCK: /tmp/ssh_agent.sock
    AZURE_STORAGE_CONNECTION_STRING: <connection_string>

Expected

Artefacts are downloaded as in <=2.9.5 version

Environment information

GitHub Actions

Current runner version: '2.291.1'
Operating System
  Microsoft Windows Server 2022
  10.0.20348
  Datacenter
Virtual Environment
  Environment: windows-2022
  Version: 20220503.1
  Included Software: https://github.com/actions/virtual-environments/blob/win22/20220503.1/images/win/Windows2022-Readme.md
  Image Release: https://github.com/actions/virtual-environments/releases/tag/win22%2F20220503.1

[piotlinski]

Bug Report

[...]

Following up: the data pulled in dvc pull command are files imported from another repository; the error happens while trying to clone that repository before pulling the data.

[daavoo]

@piotlinski Thanks for the report. Could you share a little more traceback detail from dvc pull -v ?

[daavoo]

@pmrowla is this a "duplicated" version (but with ssh) of #7670 ?

[piotlinski]

@daavoo Sure, here is the output of dvc pull -v:

**Click to show spoiler**

2022-05-04T19:14:31.1077220Z 2022-05-04 19:14:31,106 DEBUG: Creating external repo git@github.com:<link-to-repo>.git@410deb307a1e3b7a69232fa3ce600845fe412ad8
2022-05-04T19:14:31.1077978Z 
2022-05-04T19:14:31.1078893Z 2022-05-04 19:14:31,107 DEBUG: erepo: git clone 'git@github.com:<link-to-repo>.git' to a temporary dir
2022-05-04T19:14:31.1079790Z 
2022-05-04T19:14:32.7994161Z Everything is up to date.
2022-05-04T19:14:32.7994584Z 
2022-05-04T19:14:32.9122668Z 2022-05-04 19:14:32,798 ERROR: failed to pull data from the cloud - Failed to clone repo 'git@github.com:<link-to-repo>.git' to 'C:\Users\RUNNER~1\AppData\Local\Temp\tmprf2afvw0dvc-clone'
2022-05-04T19:14:32.9124234Z 
2022-05-04T19:14:32.9126106Z ------------------------------------------------------------
2022-05-04T19:14:32.9126632Z 
2022-05-04T19:14:32.9127034Z Traceback (most recent call last):
2022-05-04T19:14:32.9127654Z 
2022-05-04T19:14:32.9129861Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\scmrepo\git\backend\dulwich\__init__.py", line 193, in clone
2022-05-04T19:14:32.9130832Z 
2022-05-04T19:14:32.9131202Z     repo = clone_from()
2022-05-04T19:14:32.9131629Z 
2022-05-04T19:14:32.9132718Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dulwich\porcelain.py", line 443, in clone
2022-05-04T19:14:32.9133537Z 
2022-05-04T19:14:32.9133904Z     return client.clone(
2022-05-04T19:14:32.9134329Z 
2022-05-04T19:14:32.9135435Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dulwich\client.py", line 535, in clone
2022-05-04T19:14:32.9136139Z 
2022-05-04T19:14:32.9136601Z     result = self.fetch(path, target, progress=progress, depth=depth)
2022-05-04T19:14:32.9137099Z 
2022-05-04T19:14:32.9138011Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dulwich\client.py", line 601, in fetch
2022-05-04T19:14:32.9138716Z 
2022-05-04T19:14:32.9139065Z     result = self.fetch_pack(
2022-05-04T19:14:32.9139423Z 
2022-05-04T19:14:32.9140378Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dulwich\client.py", line 1088, in fetch_pack
2022-05-04T19:14:32.9141074Z 
2022-05-04T19:14:32.9141630Z     proto, can_read, stderr = self._connect(b"upload-pack", path)
2022-05-04T19:14:32.9142112Z 
2022-05-04T19:14:32.9143034Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dulwich\client.py", line 1756, in _connect
2022-05-04T19:14:32.9143712Z 
2022-05-04T19:14:32.9144096Z     con = self.ssh_vendor.run_command(
2022-05-04T19:14:32.9144487Z 
2022-05-04T19:14:32.9145393Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\fsspec\asyn.py", line 85, in wrapper
2022-05-04T19:14:32.9146291Z 
2022-05-04T19:14:32.9146682Z     return sync(self.loop, func, *args, **kwargs)
2022-05-04T19:14:32.9147120Z 
2022-05-04T19:14:32.9149535Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\fsspec\asyn.py", line 65, in sync
2022-05-04T19:14:32.9150364Z 
2022-05-04T19:14:32.9150715Z     raise return_result
2022-05-04T19:14:32.9151045Z 
2022-05-04T19:14:32.9151928Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\fsspec\asyn.py", line 25, in _runner
2022-05-04T19:14:32.9152582Z 
2022-05-04T19:14:32.9152828Z     result[0] = await coro
2022-05-04T19:14:32.9153141Z 
2022-05-04T19:14:32.9154088Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\scmrepo\git\backend\dulwich\asyncssh_vendor.py", line 163, in _run_command
2022-05-04T19:14:32.9154809Z 
2022-05-04T19:14:32.9155115Z     conn = await asyncssh.connect(
2022-05-04T19:14:32.9155450Z 
2022-05-04T19:14:32.9156323Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\asyncssh\connection.py", line 7707, in connect
2022-05-04T19:14:32.9156962Z 
2022-05-04T19:14:32.9157265Z     return await asyncio.wait_for(
2022-05-04T19:14:32.9157618Z 
2022-05-04T19:14:32.9158154Z   File "C:\hostedtoolcache\windows\Python\3.9.12\x64\lib\asyncio\tasks.py", line 442, in wait_for
2022-05-04T19:14:32.9158642Z 
2022-05-04T19:14:32.9158897Z     return await fut
2022-05-04T19:14:32.9159180Z 
2022-05-04T19:14:32.9160045Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\asyncssh\connection.py", line 440, in _connect
2022-05-04T19:14:32.9160682Z 
2022-05-04T19:14:32.9160965Z     await options.waiter
2022-05-04T19:14:32.9161257Z 
2022-05-04T19:14:32.9161661Z asyncssh.misc.PermissionDenied: Permission denied
2022-05-04T19:14:32.9162043Z 
2022-05-04T19:14:32.9162115Z 
2022-05-04T19:14:32.9162182Z 
2022-05-04T19:14:32.9162597Z The above exception was the direct cause of the following exception:
2022-05-04T19:14:32.9163027Z 
2022-05-04T19:14:32.9163087Z 
2022-05-04T19:14:32.9163140Z 
2022-05-04T19:14:32.9163452Z Traceback (most recent call last):
2022-05-04T19:14:32.9163792Z 
2022-05-04T19:14:32.9164612Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\scm.py", line 126, in clone
2022-05-04T19:14:32.9165220Z 
2022-05-04T19:14:32.9165623Z     git = Git.clone(url, to_path, progress=pbar.update_git, **kwargs)
2022-05-04T19:14:32.9166044Z 
2022-05-04T19:14:32.9166905Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\scmrepo\git\__init__.py", line 143, in clone
2022-05-04T19:14:32.9169232Z 2022-05-04 19:14:32,915 DEBUG: Analytics is disabled.
2022-05-04T19:14:32.9169666Z 
2022-05-04T19:14:32.9169682Z 
2022-05-04T19:14:32.9170047Z     backend.clone(url, to_path, **kwargs)
2022-05-04T19:14:32.9170396Z 
2022-05-04T19:14:32.9171321Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\scmrepo\git\backend\dulwich\__init__.py", line 196, in clone
2022-05-04T19:14:32.9173747Z 
2022-05-04T19:14:32.9174652Z     raise CloneError(url, to_path) from exc
2022-05-04T19:14:32.9175117Z 
2022-05-04T19:14:32.9176141Z scmrepo.exceptions.CloneError: Failed to clone repo 'git@github.com:<link-to-repo>.git' to 'C:\Users\RUNNER~1\AppData\Local\Temp\tmprf2afvw0dvc-clone'
2022-05-04T19:14:32.9176796Z 
2022-05-04T19:14:32.9176851Z 
2022-05-04T19:14:32.9176905Z 
2022-05-04T19:14:32.9177362Z During handling of the above exception, another exception occurred:
2022-05-04T19:14:32.9178257Z 
2022-05-04T19:14:32.9178312Z 
2022-05-04T19:14:32.9178366Z 
2022-05-04T19:14:32.9178709Z Traceback (most recent call last):
2022-05-04T19:14:32.9179037Z 
2022-05-04T19:14:32.9180114Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\commands\data_sync.py", line 31, in run
2022-05-04T19:14:32.9180753Z 
2022-05-04T19:14:32.9181584Z     stats = self.repo.pull(
2022-05-04T19:14:32.9182374Z 
2022-05-04T19:14:32.9183303Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\repo\__init__.py", line 48, in wrapper
2022-05-04T19:14:32.9183928Z 
2022-05-04T19:14:32.9184235Z     return f(repo, *args, **kwargs)
2022-05-04T19:14:32.9184561Z 
2022-05-04T19:14:32.9185399Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\repo\pull.py", line 34, in pull
2022-05-04T19:14:32.9186046Z 
2022-05-04T19:14:32.9186441Z     processed_files_count = self.fetch(
2022-05-04T19:14:32.9186803Z 
2022-05-04T19:14:32.9187664Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\repo\__init__.py", line 48, in wrapper
2022-05-04T19:14:32.9188638Z 
2022-05-04T19:14:32.9188928Z     return f(repo, *args, **kwargs)
2022-05-04T19:14:32.9189274Z 
2022-05-04T19:14:32.9190121Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\repo\fetch.py", line 45, in fetch
2022-05-04T19:14:32.9190759Z 
2022-05-04T19:14:32.9191008Z     used = self.used_objs(
2022-05-04T19:14:32.9191325Z 
2022-05-04T19:14:32.9192212Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\repo\__init__.py", line 418, in used_objs
2022-05-04T19:14:32.9196541Z 
2022-05-04T19:14:32.9196907Z     for odb, objs in self.index.used_objs(
2022-05-04T19:14:32.9197306Z 
2022-05-04T19:14:32.9198656Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\repo\index.py", line 226, in used_objs
2022-05-04T19:14:32.9199515Z 
2022-05-04T19:14:32.9200029Z     for odb, objs in stage.get_used_objs(
2022-05-04T19:14:32.9200374Z 
2022-05-04T19:14:32.9201276Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\stage\__init__.py", line 661, in get_used_objs
2022-05-04T19:14:32.9201926Z 
2022-05-04T19:14:32.9202307Z     for odb, objs in out.get_used_objs(*args, **kwargs).items():
2022-05-04T19:14:32.9202710Z 
2022-05-04T19:14:32.9203552Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\output.py", line 912, in get_used_objs
2022-05-04T19:14:32.9204206Z 
2022-05-04T19:14:32.9204510Z     return self.get_used_external(**kwargs)
2022-05-04T19:14:32.9204868Z 
2022-05-04T19:14:32.9205702Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\output.py", line 967, in get_used_external
2022-05-04T19:14:32.9206349Z 
2022-05-04T19:14:32.9206636Z     return dep.get_used_objs(**kwargs)
2022-05-04T19:14:32.9206989Z 
2022-05-04T19:14:32.9208070Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\dependency\repo.py", line 94, in get_used_objs
2022-05-04T19:14:32.9208772Z 
2022-05-04T19:14:32.9209074Z     used, _ = self._get_used_and_obj(**kwargs)
2022-05-04T19:14:32.9209432Z 
2022-05-04T19:14:32.9210351Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\dependency\repo.py", line 108, in _get_used_and_obj
2022-05-04T19:14:32.9210993Z 
2022-05-04T19:14:32.9211258Z     with self._make_repo(
2022-05-04T19:14:32.9211552Z 
2022-05-04T19:14:32.9212079Z   File "C:\hostedtoolcache\windows\Python\3.9.12\x64\lib\contextlib.py", line 119, in __enter__
2022-05-04T19:14:32.9212561Z 
2022-05-04T19:14:32.9212820Z     return next(self.gen)
2022-05-04T19:14:32.9213107Z 
2022-05-04T19:14:32.9213976Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\external_repo.py", line 39, in external_repo
2022-05-04T19:14:32.9215276Z 
2022-05-04T19:14:32.9215631Z     path = _cached_clone(url, rev, for_write=for_write)
2022-05-04T19:14:32.9216086Z 
2022-05-04T19:14:32.9216989Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\external_repo.py", line 165, in _cached_clone
2022-05-04T19:14:32.9218259Z 
2022-05-04T19:14:32.9218682Z     clone_path, shallow = _clone_default_branch(url, rev, for_write=for_write)
2022-05-04T19:14:32.9219147Z 
2022-05-04T19:14:32.9220002Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\funcy\decorators.py", line 45, in wrapper
2022-05-04T19:14:32.9220640Z 
2022-05-04T19:14:32.9220935Z     return deco(call, *dargs, **dkwargs)
2022-05-04T19:14:32.9221294Z 
2022-05-04T19:14:32.9222115Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\funcy\flow.py", line 274, in wrap_with
2022-05-04T19:14:32.9222772Z 
2022-05-04T19:14:32.9223051Z     return call()
2022-05-04T19:14:32.9223357Z 
2022-05-04T19:14:32.9224199Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\funcy\decorators.py", line 66, in __call__
2022-05-04T19:14:32.9224826Z 
2022-05-04T19:14:32.9225157Z     return self._func(*self._args, **self._kwargs)
2022-05-04T19:14:32.9225511Z 
2022-05-04T19:14:32.9226401Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\external_repo.py", line 235, in _clone_default_branch
2022-05-04T19:14:32.9227051Z 
2022-05-04T19:14:32.9227376Z     git = clone(url, clone_path)
2022-05-04T19:14:32.9227688Z 
2022-05-04T19:14:32.9228509Z   File "C:\Users\runneradmin\AppData\Local\pypoetry\Cache\virtualenvs\<repo>-UFKFKqae-py3.8\lib\site-packages\dvc\scm.py", line 131, in clone
2022-05-04T19:14:32.9229109Z 
2022-05-04T19:14:32.9229405Z     raise CloneError(str(exc))
2022-05-04T19:14:32.9229704Z 
2022-05-04T19:14:32.9230603Z dvc.scm.CloneError: Failed to clone repo 'git@github.com:<link-to-repo>.git' to 'C:\Users\RUNNER~1\AppData\Local\Temp\tmprf2afvw0dvc-clone'
2022-05-04T19:14:32.9231229Z 
2022-05-04T19:14:32.9231698Z ------------------------------------------------------------
2022-05-04T19:14:32.9232141Z 
2022-05-04T19:14:33.1007166Z ##[error]Process completed with exit code 1.

btw. calling git clone <link-to-repo> works OK in this environment

[daavoo]

Thanks @piotlinski . So, indeed looks like a duplicate of #7670 but using SSH client instead of HTTP.

[pmrowla]

This is not the same issue. #7670 is due to git credential storage being unsupported. This looks like a problem with asyncssh support for ssh-agent on windows.

@piotlinski what shell are you using in windows?

edit: I see this is in github actions, I'm not sure how GHA translates unix style paths in actions (like SSH_AUTH_SOCK: /tmp/ssh_agent.sock) on windows, but I'm guessing this is what ends up being unsupported and/or broken in asyncssh

[piotlinski]

@pmrowla I did try with a dedicated action for setting up ssh-agent: https://github.com/webfactory/ssh-agent (I supposed it should handle every OS available @ GitHub Actions properly), but the error occurred as well. With previous DVC versions we did not have any issues with the approach presented above.

[daavoo]

This is not the same issue. #7670 is due to git credential storage being unsupported. This looks like a problem with asyncssh support for ssh-agent on windows.

Meant that because 2.10 is the version that introduced the issue appears to be related to adopting dulwich for clone?

[mdekstrand]

@daavoo Yes, adopting dulwich for clone seems to be causing a problem. I am having a similar problem with HTTPS remotes with their credentials stored in the Windows credential store, because dulwich does not yet support Git credential helpers.

[daavoo]

Hi @mdekstrand . @dtrifiro is working on adding support for credential helpers in dulwich, see #7307 (comment) :)