Non-deterministic/incorrect version history

[vito]

When configuring dev_releases: true, we're seeing the version history "jump around". This indicates that check is returning version history in a non-deterministic order, and seems to result in different versions being deemed "latest".

I don't quite know how to reason about this, but I at least have steps to reproduce:

---
resource_types:
- name: bosh-release
  type: registry-image
  source:
    repository: dpb587/bosh-release-resource

resources:
- name: release
  type: bosh-release
  source:
    uri: https://github.com/concourse/concourse-bosh-release
    branch: bosh-release-resource-repro
    dev_releases: true

jobs:
- name: get-latest
  plan:
  - get: release
    trigger: true

I made a dedicated branch, bosh-release-resource-repro, whose latest commit is currently 3c91de4. If I configure the resource fresh, it correctly detects that as the latest (and only) version:

$ fly -t l rvs -r repro/release
id     version                                            enabled
29681  version:5.5.1-dev.20191217T164227Z.commit.3c91de4  yes

This isn't very helpful for the repro case, so let's try to pull in more versions:

$ fly -t l cr -r repro/release -f version:5.5.1-doesnt.matter.commit.7693bed5ae9051a00887fdd66117d4ea7118246b
id     name          status     check_error
30184  bosh-release  succeeded
id     name     status     check_error
30185  release  succeeded

Now we have this:

$ fly -t l rvs -r repro/release
id     version                                            enabled
29741  version:5.5.1-dev.20191121T171051Z.commit.7ed50df  yes
29740  version:5.5.1-dev.20191122T162948Z.commit.4edcd11  yes
29739  version:5.5.1-dev.20191126T174444Z.commit.11c190a  yes
29720  version:5.5.1-dev.20191216T195330Z.commit.f0465ac  yes
29681  version:5.5.1-dev.20191217T164227Z.commit.3c91de4  yes

Strangely, this doesn't include 7693bed which I had requested. (Resource types are supposed to return the requested version if it still exists; this way people can populate the history with their desired version through running fly check-resource.)

Even more strangely, note that 3c91de4 is no longer the latest version - it's the oldest! In fact, the entire history seems to be in the opposite order.

If we wait a while, the order will actually change next time Concourse runs a check:

$ fly -t l rvs -r repro/release
id     version                                            enabled
29740  version:5.5.1-dev.20191122T162948Z.commit.4edcd11  yes
29739  version:5.5.1-dev.20191126T174444Z.commit.11c190a  yes
29720  version:5.5.1-dev.20191216T195330Z.commit.f0465ac  yes
29681  version:5.5.1-dev.20191217T164227Z.commit.3c91de4  yes
29741  version:5.5.1-dev.20191121T171051Z.commit.7ed50df  yes

...and again...:

$ fly -t l rvs -r repro/release
id     version                                            enabled
29739  version:5.5.1-dev.20191126T174444Z.commit.11c190a  yes
29720  version:5.5.1-dev.20191216T195330Z.commit.f0465ac  yes
29681  version:5.5.1-dev.20191217T164227Z.commit.3c91de4  yes
29740  version:5.5.1-dev.20191122T162948Z.commit.4edcd11  yes
29741  version:5.5.1-dev.20191121T171051Z.commit.7ed50df  yes

...and again...:

$ fly -t l rvs -r repro/release
id     version                                            enabled
29720  version:5.5.1-dev.20191216T195330Z.commit.f0465ac  yes
29681  version:5.5.1-dev.20191217T164227Z.commit.3c91de4  yes
29739  version:5.5.1-dev.20191126T174444Z.commit.11c190a  yes
29740  version:5.5.1-dev.20191122T162948Z.commit.4edcd11  yes
29741  version:5.5.1-dev.20191121T171051Z.commit.7ed50df  yes

...and once last time, this time stabilizing on the "correct" order:

$ fly -t l rvs -r repro/release
id     version                                            enabled
29681  version:5.5.1-dev.20191217T164227Z.commit.3c91de4  yes
29720  version:5.5.1-dev.20191216T195330Z.commit.f0465ac  yes
29739  version:5.5.1-dev.20191126T174444Z.commit.11c190a  yes
29740  version:5.5.1-dev.20191122T162948Z.commit.4edcd11  yes
29741  version:5.5.1-dev.20191121T171051Z.commit.7ed50df  yes

I'm not really sure what to make of this, but hopefully this barrage of information helps. :sweat_smile:

If I had to make a guess, there seem to be two bugs:

1. The requested version isn't included in the response.
2. The versions are just being returned in the wrong order, i.e. reverse-chronological. And things finally stabilize once the latest version makes it to the 'latest' position, after which point no more commits are found?

[dpb587]

Thanks for the detailed report. Your analysis was right:

1. Latest/requested version was not included in the check results. I have been thinking that the version passed to check need not be included again, but agree it makes sense (and have briefly wondered about the inclusive check-resource use case in the past). I think I have a couple other resource types to fix for that now.
2. Dev versions were indeed being listed based on git's log output and not reversed for Concourse output. I guess I had not yet noticed that bug on my quieter repos. Additionally my tests were not explicitly testing output ordering.

I think the combination of the two led to the deterministic-non-deterministic behavior. With your example, I was able to reproduce the results locally.

Original Output

``` $ ./bin/local-run-from-pipeline tmp/issue-8.yml release check | jq -r '.[].version' 5.5.1-dev.20191217T164227Z.commit.3c91de4a $ ./bin/local-run-from-pipeline tmp/issue-8.yml release check version:5.5.1-doesnt.matter.commit.7693bed5ae9051a00887fdd66117d4ea7118246b | jq -r '.[].version' 5.5.1-dev.20191217T164227Z.commit.3c91de4a 5.5.1-dev.20191216T195330Z.commit.f0465ac6 5.5.1-dev.20191126T174444Z.commit.11c190a6 5.5.1-dev.20191122T162948Z.commit.4edcd11d 5.5.1-dev.20191121T171051Z.commit.7ed50df2 $ ./bin/local-run-from-pipeline tmp/issue-8.yml release check version:5.5.1-dev.20191217T164227Z.commit.3c91de4a | jq -r '.[].version' ```

After the two fixes, the results look like the following, which I believe matches what's expected:

$ ./bin/local-run-from-pipeline tmp/issue-8.yml release check | jq -r '.[].version'
5.5.1-dev.20191217T164227Z.commit.3c91de4a

$ ./bin/local-run-from-pipeline tmp/issue-8.yml release check version:5.5.1-doesnt.matter.commit.7693bed5ae9051a00887fdd66117d4ea7118246b | jq -r '.[].version'
5.5.1-dev.20191120T162138Z.commit.7693bed5
5.5.1-dev.20191121T171051Z.commit.7ed50df2
5.5.1-dev.20191122T162948Z.commit.4edcd11d
5.5.1-dev.20191126T174444Z.commit.11c190a6
5.5.1-dev.20191216T195330Z.commit.f0465ac6
5.5.1-dev.20191217T164227Z.commit.3c91de4a

$ ./bin/local-run-from-pipeline tmp/issue-8.yml release check version:5.5.1-dev.20191217T164227Z.commit.3c91de4a | jq -r '.[].version'
5.5.1-dev.20191217T164227Z.commit.3c91de4a

The fixes have been pushed to the latest image, with the prior image demoted to v0.6.0.

Thanks, again, for the feedback.

[vito]

@dpb587 :turtle: Awesome, thanks for the fix!