test_force_checkdatapresent - started to fail on master with most recent git-annex

[yarikoptic]

I thought it is just spurious but seems to be the same fail on both linux and windows

windows

https://github.com/datalad/git-annex/actions/runs/7620671274/job/20755945970

FAILED ..\datalad\core\distributed\tests\test_push.py::test_force_checkdatapresent - AssertionError: Desired result
  {
   "action": "publish",
   "refspec": "refs/heads/git-annex:refs/heads/git-annex",
   "status": "notneeded"
  }
not found among
  [
   {
    "action": "copy",
    "annexkey": "MD5E-s12--f01b6f1223d1baf9cc6288f9172bbbf5",
    "message": "to target...",
    "path": "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\datalad_temp_pzmwu19h\\test_mod_annex_file",
    "refds": "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\datalad_temp_pzmwu19h",
    "status": "ok",
    "target": "target",
    "type": "file"
   },
   {
    "action": "publish",
    "hints": null,
    "message": "refs/heads/dl-test-branch->target:refs/heads/dl-test-branch [up to date]",
    "operations": [
     "uptodate"
    ],
    "path": "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\datalad_temp_pzmwu19h",
    "refds": "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\datalad_temp_pzmwu19h",
    "refspec": "refs/heads/dl-test-branch:refs/heads/dl-test-branch",
    "status": "notneeded",
    "target": "target",
    "type": "dataset"
   },
   {
    "action": "publish",
    "hints": null,
    "message": "refs/heads/git-annex->target:refs/heads/git-annex b109968..2872376",
    "operations": [
     "fast-forward"
    ],
    "path": "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\datalad_temp_pzmwu19h",
    "refds": "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\datalad_temp_pzmwu19h",
    "refspec": "refs/heads/git-annex:refs/heads/git-annex",
    "status": "ok",
    "target": "target",
    "type": "dataset"
   }
  ]
= 1 failed, 1066 passed, 215 skipped, 1 xfailed, 1 xpassed, 8 warnings in 4082.21s (1:08:02) =

linux

https://github.com/datalad/git-annex/actions/runs/7620324411/job/20755009005

FAILED ../datalad/core/distributed/tests/test_push.py::test_force_checkdatapresent - AssertionError: Desired result
  {
   "action": "publish",
   "refspec": "refs/heads/git-annex:refs/heads/git-annex",
   "status": "notneeded"
  }
not found among
  [
   {
    "action": "copy",
    "annexkey": "MD5E-s12--f01b6f1223d1baf9cc6288f9172bbbf5",
    "message": "to target...",
    "path": "/tmp/datalad_temp_test_force_checkdatapresente2r8jiod/test_mod_annex_file",
    "refds": "/tmp/datalad_temp_test_force_checkdatapresente2r8jiod",
    "status": "ok",
    "target": "target",
    "type": "file"
   },
   {
    "action": "publish",
    "hints": null,
    "message": "refs/heads/dl-test-branch->target:refs/heads/dl-test-branch [up to date]",
    "operations": [
     "uptodate"
    ],
    "path": "/tmp/datalad_temp_test_force_checkdatapresente2r8jiod",
    "refds": "/tmp/datalad_temp_test_force_checkdatapresente2r8jiod",
    "refspec": "refs/heads/dl-test-branch:refs/heads/dl-test-branch",
    "status": "notneeded",
    "target": "target",
    "type": "dataset"
   },
   {
    "action": "publish",
    "hints": null,
    "message": "refs/heads/git-annex->target:refs/heads/git-annex 5fda262..a0be107",
    "operations": [
     "fast-forward"
    ],
    "path": "/tmp/datalad_temp_test_force_checkdatapresente2r8jiod",
    "refds": "/tmp/datalad_temp_test_force_checkdatapresente2r8jiod",
    "refspec": "refs/heads/git-annex:refs/heads/git-annex",
    "status": "ok",
    "target": "target",
    "type": "dataset"
   }
  ]
= 1 failed, 1220 passed, 58 skipped, 2 xfailed, 2 xpassed, 8 warnings in 3394.42s (0:56:34) =

and it is fresh

and I just tuned up for a change in behaviour recently in that test in https://github.com/datalad/datalad/pull/7544/files
and there were no changes to git-annex for the past 3 days, so odd -- seems like possibly a spurious fail still.

edit: on a later day failed on OSX

[yarikoptic]

(git)smaug:/mnt/datasets/datalad/ci/logs/2024[master]
$> datalad foreach-dataset --o-s relpath -r -J10 git grep 'FAILED ../distributed/tests/test_push.py::test_force_checkdatapresent - AssertionError: Desired result'
01/24/pr/7550/4abd2b2/github-Test on macOS-4857-failed/0_test (brew).txt:2024-01-24T21:10:29.4942580Z FAILED ../distributed/tests/test_push.py::test_force_checkdatapresent - AssertionError: Desired result
01/24/pr/7550/4abd2b2/github-Test on macOS-4857-failed/test (brew)/8_Run tests.txt:2024-01-24T21:10:29.4942580Z FAILED ../distributed/tests/test_push.py::test_force_checkdatapresent - AssertionError: Desired result
01/31/pr/7553/ac778d5/github-CrippledFS-4249-failed/0_test.txt:2024-01-31T21:36:28.8425784Z FAILED ../distributed/tests/test_push.py::test_force_checkdatapresent - AssertionError: Desired result
01/31/pr/7553/ac778d5/github-CrippledFS-4249-failed/test/8_Run tests.txt:2024-01-31T21:36:28.8425781Z FAILED ../distributed/tests/test_push.py::test_force_checkdatapresent - AssertionError: Desired result
02/05/pr/7556/6411506/github-Test on macOS-4873-failed/1_test (snapshot).txt:2024-02-05T02:50:12.4644640Z FAILED ../distributed/tests/test_push.py::test_force_checkdatapresent - AssertionError: Desired result
02/05/pr/7556/6411506/github-Test on macOS-4873-failed/test (snapshot)/8_Run tests.txt:2024-02-05T02:50:12.4644640Z FAILED ../distributed/tests/test_push.py::test_force_checkdatapresent - AssertionError: Desired result
02/13/push/ci-singulary-dep/f38a77e/github-Test on macOS-4880-failed/0_test (brew).txt:2024-02-13T13:55:09.7532990Z FAILED ../distributed/tests/test_push.py::test_force_checkdatapresent - AssertionError: Desired result
02/13/push/ci-singulary-dep/f38a77e/github-Test on macOS-4880-failed/test (brew)/8_Run tests.txt:2024-02-13T13:55:09.7532990Z FAILED ../distributed/tests/test_push.py::test_force_checkdatapresent - AssertionError: Desired result

[yarikoptic]

we keep getting fails in this test once in awhile for up to date git-annex testing. Most likely for the same reason as was accounted for in

• BF(TST): due to recent change in git-annex dropping sub-second clock precision - we might not report push of git-annex branch #7544
  which is a drop of subsecond resolution at git-annex level, which I guess leads to fluctuating "exact behaviors" now across runs. E.g. from the most recent fail:

FAILED ../datalad/core/distributed/tests/test_push.py::test_force_checkdatapresent - AssertionError: Desired result
  {
   "action": "publish",
   "refspec": "refs/heads/git-annex:refs/heads/git-annex",
   "status": "notneeded"
  }
not found among
  [
   {
    "action": "copy",
    "annexkey": "MD5E-s12--f01b6f1223d1baf9cc6288f9172bbbf5",
    "message": "to target...",
    "path": "/tmp/datalad_temp_test_force_checkdatapresentgyk5c98l/test_mod_annex_file",
    "refds": "/tmp/datalad_temp_test_force_checkdatapresentgyk5c98l",
    "status": "ok",
    "target": "target",
    "type": "file"
   },
   {
    "action": "publish",
    "hints": null,
    "message": "refs/heads/dl-test-branch->target:refs/heads/dl-test-branch [up to date]",
    "operations": [
     "uptodate"
    ],
    "path": "/tmp/datalad_temp_test_force_checkdatapresentgyk5c98l",
    "refds": "/tmp/datalad_temp_test_force_checkdatapresentgyk5c98l",
    "refspec": "refs/heads/dl-test-branch:refs/heads/dl-test-branch",
    "status": "notneeded",
    "target": "target",
    "type": "dataset"
   },
   {
    "action": "publish",
    "hints": null,
    "message": "refs/heads/git-annex->target:refs/heads/git-annex 8245df3..4cecaed",
    "operations": [
     "fast-forward"
    ],
    "path": "/tmp/datalad_temp_test_force_checkdatapresentgyk5c98l",
    "refds": "/tmp/datalad_temp_test_force_checkdatapresentgyk5c98l",
    "refspec": "refs/heads/git-annex:refs/heads/git-annex",
    "status": "ok",
    "target": "target",
    "type": "dataset"
   }
  ]

so we had a push of git-annex although we expected it to be "not needed".

[yarikoptic]

presumably

• Relax condition in test_force_checkdatapresent to avoid flaky test failures #7581
  by @christian-monch (and with my statement of "clear" understanding) which was merged/released recently was to fix this (?) issue but we still got on windows:

following fail

https://github.com/datalad/git-annex/actions/runs/8888867175/job/24406502022

FAILED ..\datalad\core\distributed\tests\test_push.py::test_force_checkdatapresent - AssertionError: Desired result
  {
   "action": "publish",
   "refspec": "refs/heads/git-annex:refs/heads/git-annex",
   "status": "notneeded"
  }
not found among
  [
   {
    "action": "copy",
    "annexkey": "MD5E-s12--f01b6f1223d1baf9cc6288f9172bbbf5",
    "message": "to target...",
    "path": "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\datalad_temp_h5v8obrn\\test_mod_annex_file",
    "refds": "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\datalad_temp_h5v8obrn",
    "status": "ok",
    "target": "target",
    "type": "file"
   },
   {
    "action": "publish",
    "hints": null,
    "message": "refs/heads/dl-test-branch->target:refs/heads/dl-test-branch [up to date]",
    "operations": [
     "uptodate"
    ],
    "path": "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\datalad_temp_h5v8obrn",
    "refds": "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\datalad_temp_h5v8obrn",
    "refspec": "refs/heads/dl-test-branch:refs/heads/dl-test-branch",
    "status": "notneeded",
    "target": "target",
    "type": "dataset"
   },
   {
    "action": "publish",
    "hints": null,
    "message": "refs/heads/git-annex->target:refs/heads/git-annex 7b5c445..ea96c18",
    "operations": [
     "fast-forward"
    ],
    "path": "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\datalad_temp_h5v8obrn",
    "refds": "C:\\Users\\runneradmin\\AppData\\Local\\Temp\\datalad_temp_h5v8obrn",
    "refspec": "refs/heads/git-annex:refs/heads/git-annex",
    "status": "ok",
    "target": "target",
    "type": "dataset"
   }
  ]