tests/sources/keytest.py is buggy

Summary

In tests/sources/keytest.py, we try to test that BuildStream never calls get_unique_key() on sources before their refs are resolved. We try to do a soure track and a build. While the tests asserts that the operations were successful, they do not assert that they indeed did what they were suppposed to do.

For example, in this case, if you bst source track key-test.bst you'd expect its state to go from inconsistent to resolved, but that's not what happens. Similarly, after bst build key-test.bst, you'd expect its state to go from resolved to cached, but that doesn't happen either. The state remains inconsistent even after building.

Looking more into it, it seems like the build is never scheduled, bst build only ends scheduling one track operation and nothing else. (See terminal output at the bottom)

Steps to reproduce

# Take a fresh clone of buildstream
cd tests/sources/project_key_test
bst build --track key-test.bst
bst show key-test.bst
# At this point, we expect it to be cached, but it is still inconsistent

What is the current bug behavior?

The state of key-test.bst does not update correctly after tracking and building.

What is the expected correct behavior?

The state of key-test.bst does update correctly after tracking and building.

Possible fixes

The immediate reason this is happening because the custom plugin used by these tests does not behave correctly. However, even when plugins are misbehaving, BuildStream must cope with that correclty.

Terminal output

$ bst build --track key-test.bst
[--:--:--][        ][    main:core activity                 ] START   Build
[--:--:--][        ][    main:core activity                 ] START   Loading elements
[00:00:00][        ][    main:core activity                 ] SUCCESS Loading elements
[--:--:--][        ][    main:core activity                 ] START   Resolving elements
[00:00:00][        ][    main:core activity                 ] SUCCESS Resolving elements
[--:--:--][        ][    main:core activity                 ] START   Resolving cached state
[00:00:00][        ][    main:core activity                 ] SUCCESS Resolving cached state
[--:--:--][        ][    main:core activity                 ] START   Checking sources
[00:00:00][        ][    main:core activity                 ] SUCCESS Checking sources

BuildStream Version 1.91.1+21.g27d3c61a
  Session Start: Tuesday, 22-10-2019 at 15:31:59
  Project:       key-test (/Users/csingh43/buildstream/bst-tmp/tests/sources/project_key_test)
  Targets:       key-test.bst

User Configuration
  Configuration File:      Default Configuration
  Cache Directory:         /tmp/bst/buildstream
  Log Files:               /tmp/bst/buildstream/logs
  Source Mirrors:          /tmp/bst/buildstream/sources
  Build Area:              /tmp/bst/buildstream/build
  Strict Build Plan:       Yes
  Maximum Fetch Tasks:     10
  Maximum Build Tasks:     4
  Maximum Push Tasks:      4
  Maximum Network Retries: 2

Loaded Plugins
  Source Plugins
    - key-test

Pipeline
no reference ???????????????????????????????????????????????????????????????? key-test.bst
===============================================================================
[--:--:--][????????][   track:key-test.bst                  ] START   key-test/key-test/????????-track.37166.log
[00:00:00][????????][   track:key-test.bst                  ] SUCCESS key-test/key-test/????????-track.37166.log
[00:00:00][        ][    main:core activity                 ] SUCCESS Build

Pipeline Summary
  Total:       1
  Session:     1
  Track Queue: processed 1, skipped 0, failed 0
  Fetch Queue: processed 0, skipped 0, failed 0
  Build Queue: processed 0, skipped 0, failed 0