test_sibling_enable_sameas started to FAIL on appveyor (Ubu) recently

[yarikoptic]

spotted while reviewing #7318 .

looked like

FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
[{'action': 'get',
  'annexkey': 'SHA256E-s1--5feceb66ffc86f38d952786c6d696c79c2dbc239dd4e91b46729d73a27fb57e9',
  'error_message': 'rsync failed\nrsync failed\nrsync failed',
  'path': '/home/appveyor/DLTMP/datalad_temp_test_sibling_enable_sameast7tzb2z1/f0',
  'refds': '/home/appveyor/DLTMP/datalad_temp_test_sibling_enable_sameast7tzb2z1',
  'status': 'error',
  'type': 'file'}]

and apparently not for the first time but started recently:

$> git grep 'FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas'
08/pr/7317/d3a47bc/appveyor-9170-failed/1o7ovh42loqs1udv.txt:[00:25:10] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
08/pr/7317/d3a47bc/appveyor-9170-failed/1o7ovh42loqs1udv.txt:[00:27:06] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
08/pr/7317/d3a47bc/appveyor-9170-failed/ulnb0prc4odiwjcl.txt:[00:23:38] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
08/pr/7317/d3a47bc/appveyor-9170-failed/ulnb0prc4odiwjcl.txt:[00:25:24] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
08/push/maint/901c8f4/appveyor-9167-failed/ni3la8616gomqukn.txt:[00:24:30] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
08/push/maint/901c8f4/appveyor-9167-failed/ni3la8616gomqukn.txt:[00:26:13] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
08/push/maint/901c8f4/appveyor-9167-failed/td81tnkiw3rfc5f6.txt:[00:22:52] [gw0] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
08/push/maint/901c8f4/appveyor-9167-failed/td81tnkiw3rfc5f6.txt:[00:24:51] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
08/push/maint/c1b079f/appveyor-9166-failed/hxrjorsunge47o1d.txt:[00:23:21] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
08/push/maint/c1b079f/appveyor-9166-failed/hxrjorsunge47o1d.txt:[00:25:13] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
08/push/maint/c1b079f/appveyor-9166-failed/pe7etil04hh9e2ux.txt:[00:25:07] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
08/push/maint/c1b079f/appveyor-9166-failed/pe7etil04hh9e2ux.txt:[00:27:07] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
09/pr/7317/03da886/appveyor-9178-failed/9v3v9awdts4ybclk.txt:[00:25:55] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
09/pr/7317/03da886/appveyor-9178-failed/9v3v9awdts4ybclk.txt:[00:27:48] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
09/pr/7317/03da886/appveyor-9178-failed/n5emh379373mrc5m.txt:[00:23:53] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
09/pr/7317/03da886/appveyor-9178-failed/n5emh379373mrc5m.txt:[00:25:38] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
09/pr/7317/43cb9f0/appveyor-9176-failed/9y2trs40gvv5edpw.txt:[00:23:15] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
09/pr/7317/43cb9f0/appveyor-9176-failed/9y2trs40gvv5edpw.txt:[00:24:58] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
09/pr/7317/43cb9f0/appveyor-9176-failed/ob9l82pjtbmfk6w2.txt:[00:25:40] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
09/pr/7317/43cb9f0/appveyor-9176-failed/ob9l82pjtbmfk6w2.txt:[00:27:43] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
09/pr/7317/ff72c14/appveyor-9173-failed/cc39wnjusvhy0og7.txt:[00:25:24] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
09/pr/7317/ff72c14/appveyor-9173-failed/cc39wnjusvhy0og7.txt:[00:27:17] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
09/pr/7317/ff72c14/appveyor-9173-failed/difgngng03j2vqsq.txt:[00:23:41] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
09/pr/7317/ff72c14/appveyor-9173-failed/difgngng03j2vqsq.txt:[00:25:27] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
09/pr/7318/e0acb7e/appveyor-9175-failed/1h871v79409t03a1.txt:[00:25:08] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
09/pr/7318/e0acb7e/appveyor-9175-failed/1h871v79409t03a1.txt:[00:27:08] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
09/pr/7318/e0acb7e/appveyor-9175-failed/kskka21kr42q3kpn.txt:[00:22:47] [gw0] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
09/pr/7318/e0acb7e/appveyor-9175-failed/kskka21kr42q3kpn.txt:[00:24:50] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
09/push/maint/6c42103/appveyor-9171-failed/awlarnbxu4865miy.txt:[00:25:59] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
09/push/maint/6c42103/appveyor-9171-failed/awlarnbxu4865miy.txt:[00:27:53] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:
09/push/maint/6c42103/appveyor-9171-failed/r7wd7ljfhc6cabqw.txt:[00:23:37] [gw1] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas 
09/push/maint/6c42103/appveyor-9171-failed/r7wd7ljfhc6cabqw.txt:[00:25:27] FAILED ../datalad/distribution/tests/test_siblings.py::test_sibling_enable_sameas - datalad.support.exceptions.IncompleteResultsError: Command did not complete successfully. 1 failed:

[adswa]

I checked the rsync version on appveyor since I couldn't reproduce it locally; leaving it here in case someone else is looking for it

appveyor@appveyor-vm:~$ apt-cache policy rsync
rsync:
  Installed: 3.1.3-8ubuntu0.5
  Candidate: 3.1.3-8ubuntu0.5
  Version table:
 *** 3.1.3-8ubuntu0.5 500
        500 http://us.archive.ubuntu.com/ubuntu focal-updates/main amd64 Packages
        500 http://us.archive.ubuntu.com/ubuntu focal-security/main amd64 Packages
        100 /var/lib/dpkg/status
     3.1.3-8 500
        500 http://us.archive.ubuntu.com/ubuntu focal/main amd64 Packages

[adswa]

Here's a debug log from within appveyor:

appveyor@appveyor-vm:/tmp/datalad_temp_test_sibling_enable_sameas_5bb2agc$ ls
f0
appveyor@appveyor-vm:/tmp/datalad_temp_test_sibling_enable_sameas_5bb2agc$ git remote -v
dl-test-remote	/tmp/datalad_temp__wrap_with_sameas_remotebq90_vhg (fetch)
dl-test-remote	/tmp/datalad_temp__wrap_with_sameas_remotebq90_vhg (push)
r_rsync	
appveyor@appveyor-vm:/tmp/datalad_temp_test_sibling_enable_sameas_5bb2agc$ git annex info r_rsync
uuid: abbffec1-fae8-414f-8c15-86d369639df9
description: r_dir [r_rsync]
trust: semitrusted
remote: r_rsync
cost: 200.0
type: rsync
url: datalad-test:/tmp/datalad_temp__wrap_with_sameas_remotebufmihmy
encryption: none
chunking: none
remote annex keys: 1
remote annex size: 1 byte
appveyor@appveyor-vm:/tmp/datalad_temp_test_sibling_enable_sameas_5bb2agc$ git annex --debug -v get f0
[2023-03-13 09:55:43.977543503] (Utility.Process) process [257216] read: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","symbolic-ref","-q","HEAD"]
[2023-03-13 09:55:43.978397413] (Utility.Process) process [257216] done ExitSuccess
[2023-03-13 09:55:43.981100744] (Utility.Process) process [257218] read: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","show-ref","refs/heads/dl-test-branch"]
[2023-03-13 09:55:43.983399171] (Utility.Process) process [257218] done ExitSuccess
[2023-03-13 09:55:43.985184892] (Utility.Process) process [257219] read: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","ls-files","--stage","-z","--","f0"]
[2023-03-13 09:55:43.987882523] (Utility.Process) process [257220] chat: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","cat-file","--batch-check=%(objectname) %(objecttype) %(objectsize)","--buffer"]
[2023-03-13 09:55:43.990566054] (Utility.Process) process [257221] chat: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","cat-file","--batch=%(objectname) %(objecttype) %(objectsize)","--buffer"]
[2023-03-13 09:55:43.995908915] (Utility.Process) process [257223] chat: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","cat-file","--batch=%(objectname) %(objecttype) %(objectsize)","--buffer"]
get f0 [2023-03-13 09:55:44.001031575] (Utility.Process) process [257224] read: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","show-ref","git-annex"]
[2023-03-13 09:55:44.008007155] (Utility.Process) process [257224] done ExitSuccess
[2023-03-13 09:55:44.00838376] (Utility.Process) process [257225] read: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","show-ref","--hash","refs/heads/git-annex"]
[2023-03-13 09:55:44.010554685] (Utility.Process) process [257225] done ExitSuccess
[2023-03-13 09:55:44.01104779] (Utility.Process) process [257226] read: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","log","refs/heads/git-annex..407cb6bd764893bf6f4a19a23a820eed6750adb3","--pretty=%H","-n1"]
[2023-03-13 09:55:44.013474318] (Utility.Process) process [257226] done ExitSuccess
[2023-03-13 09:55:44.028908396] (Utility.Process) process [257227] chat: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","cat-file","--batch"]
[2023-03-13 09:55:44.031141722] (Utility.Process) process [257228] chat: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","cat-file","--batch-check=%(objectname) %(objecttype) %(objectsize)"]
[2023-03-13 09:55:44.037357894] (Utility.Process) process [257229] read: git ["config","--null","--list"]
[2023-03-13 09:55:44.038926612] (Utility.Process) process [257229] done ExitSuccess
(from r_rsync...) 
[2023-03-13 09:55:44.044680378] (Utility.Process) process [257231] read: ssh ["-o","BatchMode=true","-S",".git/annex/ssh/datalad-test","-o","ControlMaster=auto","-o","ControlPersist=yes","-n","-T","datalad-test","true"]
[2023-03-13 09:55:44.228778103] (Utility.Process) process [257231] done ExitSuccess
[2023-03-13 09:55:44.229717314] (Utility.Process) process [257294] read: rsync ["-e","'ssh' '-S' '.git/annex/ssh/datalad-test' '-o' 'ControlMaster=auto' '-o' 'ControlPersist=yes' '-T'","--progress","--inplace","datalad-test:/tmp/datalad_temp__wrap_with_sameas_remotebufmihmy/b3a/c08/'SHA256E-s1--5feceb66ffc86f38d952786c6d696c79c2dbc239dd4e91b46729d73a27fb57e9/SHA256E-s1--5feceb66ffc86f38d952786c6d696c79c2dbc239dd4e91b46729d73a27fb57e9'",".git/annex/tmp/SHA256E-s1--5feceb66ffc86f38d952786c6d696c79c2dbc239dd4e91b46729d73a27fb57e9"]
rsync: change_dir "/tmp/datalad_temp__wrap_with_sameas_remotebufmihmy/b3a/c08/'SHA256E-s1--5feceb66ffc86f38d952786c6d696c79c2dbc239dd4e91b46729d73a27fb57e9" failed: No such file or directory (2)
rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1684) [Receiver=3.1.3]
rsync: [Receiver] write error: Broken pipe (32)
[2023-03-13 09:55:44.344139634] (Utility.Process) process [257294] done ExitFailure 23
rsync exited 23
[2023-03-13 09:55:44.345426549] (Utility.Process) process [257342] read: rsync ["-e","'ssh' '-S' '.git/annex/ssh/datalad-test' '-o' 'ControlMaster=auto' '-o' 'ControlPersist=yes' '-T'","--progress","--inplace","datalad-test:/tmp/datalad_temp__wrap_with_sameas_remotebufmihmy/gp/2z/'SHA256E-s1--5feceb66ffc86f38d952786c6d696c79c2dbc239dd4e91b46729d73a27fb57e9/SHA256E-s1--5feceb66ffc86f38d952786c6d696c79c2dbc239dd4e91b46729d73a27fb57e9'",".git/annex/tmp/SHA256E-s1--5feceb66ffc86f38d952786c6d696c79c2dbc239dd4e91b46729d73a27fb57e9"]
rsync: change_dir "/tmp/datalad_temp__wrap_with_sameas_remotebufmihmy/gp/2z/'SHA256E-s1--5feceb66ffc86f38d952786c6d696c79c2dbc239dd4e91b46729d73a27fb57e9" failed: No such file or directory (2)
[2023-03-13 09:55:44.457504943] (Utility.Process) process [257342] done ExitFailure 23
rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1684) [Receiver=3.1.3]
rsync: [Receiver] write error: Broken pipe (32)
rsync exited 23

  rsync failed -- run git annex again to resume file transfer

  rsync failed
[2023-03-13 09:55:44.465994941] (Utility.Process) process [257227] done ExitSuccess
[2023-03-13 09:55:44.466358245] (Utility.Process) process [257228] done ExitSuccess

  Unable to access these remotes: r_rsync
[2023-03-13 09:55:44.46769836] (Utility.Process) process [257389] chat: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","cat-file","--batch"]
[2023-03-13 09:55:44.468221566] (Utility.Process) process [257390] chat: git ["--git-dir=.git","--work-tree=.","--literal-pathspecs","-c","annex.debug=true","cat-file","--batch-check=%(objectname) %(objecttype) %(objectsize)"]

  No other repository is known to contain the file.
failed
[2023-03-13 09:55:44.473345025] (Utility.Process) process [257389] done ExitSuccess
[2023-03-13 09:55:44.47373153] (Utility.Process) process [257390] done ExitSuccess
[2023-03-13 09:55:44.473897532] (Utility.Process) process [257223] done ExitSuccess
[2023-03-13 09:55:44.474047734] (Utility.Process) process [257221] done ExitSuccess
[2023-03-13 09:55:44.474183235] (Utility.Process) process [257220] done ExitSuccess
[2023-03-13 09:55:44.474309337] (Utility.Process) process [257219] done ExitSuccess
[2023-03-13 09:55:44.47550285] (Utility.Process) process [257392] read: ssh ["-O","stop","-S","datalad-test","-o","ControlMaster=auto","-o","ControlPersist=yes","localhost"]
[2023-03-13 09:55:44.491450334] (Utility.Process) process [257392] done ExitSuccess
get: 1 failed

It looks like it might be this https://git-annex.branchable.com/bugs/Redundant_quote_in_the_filepath_with_rsync_remote

Unsure why it only started failing now, but maybe Appveyor used to have an older rsync before (there was an Ubuntu Image Update 5 days ago). According to the git-annex bug report, git-annex version 10.20220504 has a fix for it (appveyor runs 8.20210903)

[bpoldrack]

FTR:
Was confused, b/c the reported version on appveyor is older than the one that broke behavior according to Joey. (3.1.3-8 vs 3.2.4)
Checking the changelog of the ubuntu package suggests that ubuntu added backported patches from 3.2.4 to their 3.1.3-8 version.
Working on a version kludge.