test_upload_dandiset_metadata: assert d.version.name == "shorty"

[yarikoptic]

upon release of dand-archive 0.2.53, CI integration testing in dandi-archive failed testing against released version of dandi-cli (which is odd since master is at release 0.46.4)

https://github.com/dandi/dandi-archive/actions/runs/3199087354/jobs/5224475301

________________________ test_upload_dandiset_metadata _________________________

new_dandiset = SampleDandiset(api=DandiAPI(api_key='e60f126ff4a8331b6149ff3bcdf87cc757cce935', client=<dandi.dandiapi.DandiAPIClient ...ndiset194'), dandiset=<dandi.dandiapi.RemoteDandiset object at 0x7ff76008ffa0>, dandiset_id='000199', upload_kwargs={})

    def test_upload_dandiset_metadata(new_dandiset: SampleDandiset) -> None:
        # For now let's "manually" populate dandiset.yaml in that downloaded location
        # which is missing due to https://github.com/dandi/dandi-api/issues/63
        d = new_dandiset.dandiset
        dspath = new_dandiset.dspath
        ds_orig = APIDandiset(dspath)
        ds_metadata = ds_orig.metadata
        assert ds_metadata is not None
        ds_metadata["description"] = "very long"
        ds_metadata["name"] = "shorty"
        (dspath / dandiset_metadata_file).write_text(yaml_dump(ds_metadata))
        new_dandiset.upload(
            paths=[dspath / dandiset_metadata_file], upload_dandiset_metadata=True
        )
        d.refresh()
>       assert d.version.name == "shorty"
E       AssertionError: assert 'Sample Dandi...iset_metadata' == 'shorty'
E         - shorty
E         + Sample Dandiset for test_upload_dandiset_metadata

which is odd... I searched into dandi/dandi-cli#1052 (comment) so we had exactly the same occasional failure before. Smells like some race condition in dandi-archive , but I want to confirm first before transferring this issue to dandi-archive since might be some bug in dandi-cli lazy properties etc. @jwodder WDYT?

[jwodder]

@yarikoptic I also suspect it's a race condition on the Archive side.

[yarikoptic]

@dandi/dandiarchive a little more context comes in test logs capture:

022-10-06T17:28:11.8966041Z >       assert d.version.name == "shorty"
2022-10-06T17:28:11.8966516Z E       AssertionError: assert 'Sample Dandi...iset_metadata' == 'shorty'
2022-10-06T17:28:11.8966879Z E         - shorty
2022-10-06T17:28:11.8967183Z E         + Sample Dandiset for test_upload_dandiset_metadata
2022-10-06T17:28:11.8967377Z 
2022-10-06T17:28:11.8968128Z /opt/hostedtoolcache/Python/3.10.7/x64/lib/python3.10/site-packages/dandi/tests/test_upload.py:59: AssertionError
2022-10-06T17:28:11.8968995Z ------------------------------ Captured log setup ------------------------------
2022-10-06T17:28:11.8969629Z DEBUG    dandi:dandiapi.py:208 POST http://localhost:8000/api/dandisets/
2022-10-06T17:28:11.8970108Z DEBUG    dandi:dandiapi.py:255 Response: 200
2022-10-06T17:28:11.8970534Z ----------------------------- Captured stdout call -----------------------------
2022-10-06T17:28:11.8970855Z {'size': 57}
2022-10-06T17:28:11.8971129Z {'status': 'updating metadata'}
2022-10-06T17:28:11.8971400Z {'status': 'updated metadata'}
2022-10-06T17:28:11.8971670Z PATH                 SIZE    ERRORS UPLOAD STATUS MESSAGE
2022-10-06T17:28:11.8971953Z dandiset.yaml                                            
2022-10-06T17:28:11.8972194Z Summary:             0 Bytes                             
2022-10-06T17:28:11.8972600Z ------------------------------ Captured log call -------------------------------
2022-10-06T17:28:11.8972969Z DEBUG    dandi:dandiapi.py:208 GET http://localhost:8000/api/info/
2022-10-06T17:28:11.8973264Z DEBUG    dandi:dandiapi.py:255 Response: 200
2022-10-06T17:28:11.8973585Z DEBUG    dandi:dandiapi.py:208 GET http://localhost:8000/api/auth/token
2022-10-06T17:28:11.8973898Z DEBUG    dandi:dandiapi.py:255 Response: 200
2022-10-06T17:28:11.8974318Z DEBUG    dandi:dandiset.py:102 Found identifier 000199 in top level 'identifier'
2022-10-06T17:28:11.8974630Z INFO     dandi:upload.py:99 Found 1 files to consider
2022-10-06T17:28:11.8974984Z DEBUG    dandi:dandiapi.py:208 PUT http://localhost:8000/api/dandisets/000199/versions/draft/
2022-10-06T17:28:11.8975323Z DEBUG    dandi:dandiapi.py:255 Response: 200
2022-10-06T17:28:11.8975947Z DEBUG    dandi:dandiapi.py:208 GET http://localhost:8000/api/dandisets/000199/
2022-10-06T17:28:11.8976270Z DEBUG    dandi:dandiapi.py:255 Response: 200

so we are providing new metadata for dandiset and then immediately request "updated" version of metadata back. Is there guarantee that PUT returns only whenever metadata record already stored and thus would be picked up by the next GET?

[waxlamp]

@mvandenburgh, do you have any insight into what might be happening here? This seems like it could be connected to the recent work in avoiding double-publish...

[mvandenburgh]

The test_upload_dandiset_metadata test doesn't appear to touch any of the code involved with the double-publish fix. I'm also unable to reproduce this locally. The fact that the PUT request succeeds with a 200 and then the GET request still returns outdated info is very strange... i'll take a closer look

[danlamanna]

As another data point - I looked at the code and nothing stood out. I couldn't get it to reproduce either, despite running the CLI tests in a loop overnight.