Git branching issues: failed to checkout, failed to delete

[agile]

re: https://spectacles-ci.slack.com/archives/CPXFRB17C/p1624380233002300

I think I might finally have a clue what has been happening from time to time where spectacles fails with an error that it was unable to checkout or delete an ephemeral tmp_spectacles_<hash> branch..

Our setup:

• On prem, currently looker 21.12.14, using 3.1 API, spectacles 1.0.0
• Travis runs spectacles from a shell script triggered by PRs and spectacles configured with a user that is only used by spectacles.
• The shell script runs spectacles sequentially for the sub-commands: sql, assert and content
• Each time spectacles is run it is given the --commit-ref param referencing the commit that triggered to run

I updated the script to reset the spectacles log between each run and cat that log if/when a git branching issue is detected and today we finally had one pop up. This time it occurred on the assert (2nd in the sequence) run and below is the log excerpt. In retrospect I wish I'd not reset the log between runs because I assume the referenced tmp_spectacles_998f868ef7 branch might be from the prior sql run but not sure, prepended a column of line numbers for easier referencing.

1 | 2021-08-18 22:30:21,817 DEBUG | Authenticating Looker API credentials
2 | 2021-08-18 22:30:22,794 DEBUG | Checking Looker instance release version
3 | 2021-08-18 22:30:22,926 INFO | Connected to Looker version 21.12.14 using Looker API 3.1
4 | 2021-08-18 22:30:22,926 DEBUG | Setting up branch manager in project 'looker_project'
5 | 2021-08-18 22:30:22,926 DEBUG | Getting the workspace in use by this session
6 | 2021-08-18 22:30:23,050 DEBUG | Getting active branch for project 'looker_project'
7 | 2021-08-18 22:30:23,249 DEBUG | The active branch is 'master'
8 | 2021-08-18 22:30:23,250 DEBUG | Getting manifest details
9 | 2021-08-18 22:30:23,370 DEBUG | Project 'looker_project' imports the following projects: []
10 | 2021-08-18 22:30:23,370 DEBUG | Updating session to use the dev workspace
11 | 2021-08-18 22:30:23,500 DEBUG | Getting the workspace in use by this session
12 | 2021-08-18 22:30:23,638 DEBUG | Getting active branch for project 'looker_project'
13 | 2021-08-18 22:30:23,826 DEBUG | The active branch is 'tmp_spectacles_998f868ef7'
14 | 2021-08-18 22:30:23,826 DEBUG | Branching 'tmp_spectacles_44c9620249' off '9c97fdae1ea1f774de3cdec7344a5aac71329141'. Afterwards, restoring to branch 'master' in project 'looker_project'
15 | 2021-08-18 22:30:23,826 DEBUG | Creating branch 'tmp_spectacles_44c9620249' on project 'looker_project'
16 | 2021-08-18 22:30:24,260 DEBUG | Hard resetting branch 'tmp_spectacles_44c9620249' on project 'looker_project' to ref '9c97fdae1ea1f774de3cdec7344a5aac71329141'
17 | 2021-08-18 22:30:26,266 DEBUG | Set project 'looker_project' to branch 'tmp_spectacles_44c9620249' @ 9c97fd in dev workspace [ephemeral = True]
18 | 2021-08-18 22:30:26,266 DEBUG | Project 'looker_project' doesn't import any other projects
19 | 2021-08-18 22:30:26,266 INFO | Building LookML project hierarchy for project 'looker_project' @ 9c97fd
20 | 2021-08-18 22:30:26,266 DEBUG | Getting all models and explores from https://looker/
21 | 
22 | =================== Running data tests based on 133 explores ===================
23 | 
24 | 2021-08-18 22:30:29,956 DEBUG | Getting LookML tests for project looker_project
25 | ... test results ...
26 | 2021-08-18 22:30:55,598 DEBUG | Restoring project 'looker_project' to branch 'master' and deleting temporary branch 'tmp_spectacles_44c9620249'
27 | 2021-08-18 22:30:55,598 DEBUG | Setting project 'looker_project' branch to 'tmp_spectacles_998f868ef7'
28 | 2021-08-18 22:30:56,029 INFO | Completed data test validation in 34 seconds.
29 | 
30 | 2021-08-18 22:30:56,029 ERROR | 
31 | Couldn't checkout Git branch. Unable to checkout Git branch 'tmp_spectacles_998f868ef7'. If you have uncommitted changes on the current branch, please commit or revert them, then try again.
32 | 
33 | Run in verbose mode (-v) or check your log file to see the full response from the Looker API. For support, please create an issue at https://github.com/spectacles-ci/spectacles/issues
34 | 
35 | 2021-08-18 22:30:56,029 DEBUG | Spectacles received a 422 response code from the Looker API with the following details: {
36 |   "message": "Missing branch 'tmp_spectacles_998f868ef7'",
37 |   "documentation_url": "http://docs.looker.com/"
38 | }

We've also seen cases before where it's an issue deleting an ephemeral branch rather than checking out but this is the only one I've got any log clues from so far.

[DylanBaker]

Hi @agile. Thanks for creating the issue.

This is really useful. In theory, the tmp_spectacles_ branches should get cleaned up at the end of the run and we should be restarting from a clean slate, but as you've noted, that seems to not be the case here.

I agree that it would be really useful to have the logs from the prior run as well. Would you be able to make that change and re-share the logs when it next occurs? I think that should be enough for us to figure out what's happening. Thanks!