Sometimes failed builds are not cached as failed

Summary

Upon investigating #1096 (closed), I noticed that the example Ben provided (df50bf76) never shows a "failed" build - even though the manual.bst element fails to build everytime.

Each time you build manual.bst and it fails, a further bst show manual.bst will show the state of manual.bst as "buildable".

I then deliberately made our "hello.bst" element in the autotools project deliberately fail by appending a nonsense build command. When building this, it fails, and then a further bst show hello.bst will show the state as "failed", thus I'm able to retrieve the logs.

Here is what's happening for manual.bst:


 $ bst --no-interactive build manual.bst 
[--:--:--][        ][    main:core activity                 ] START   Build
[--:--:--][        ][    main:core activity                 ] START   Loading elements
[00:00:00][        ][    main:core activity                 ] SUCCESS Loading elements

[snip]

Pipeline
   buildable 0b5c52df06a373ed6d1fcbd3c6b3a4d22fc1b77d3e069eaed8603f066df36557 manual.bst 
===============================================================================
[--:--:--][0b5c52df][   build:manual.bst                    ] START   scratch/manual/0b5c52df-build.9983.log
[--:--:--][0b5c52df][   build:manual.bst                    ] START   Staging dependencies
[00:00:00][0b5c52df][   build:manual.bst                    ] SUCCESS Staging dependencies
[--:--:--][0b5c52df][   build:manual.bst                    ] START   Integrating sandbox
[00:00:00][0b5c52df][   build:manual.bst                    ] SUCCESS Integrating sandbox
[--:--:--][0b5c52df][   build:manual.bst                    ] START   Staging sources
[00:00:00][0b5c52df][   build:manual.bst                    ] SUCCESS Staging sources
[--:--:--][0b5c52df][   build:manual.bst                    ] START   Running build-commands
[--:--:--][0b5c52df][   build:manual.bst                    ] STATUS  Running command

    echo "hello"

[00:00:00][0b5c52df][   build:manual.bst                    ] FAILURE Running build-commands
[00:00:00][0b5c52df][   build:manual.bst                    ] FAILURE Staged artifacts do not provide command 'sh'

[snip]

[00:00:00][        ][    main:core activity                 ] FAILURE Build

Failure Summary
  manual.bst:
    [00:00:00][0b5c52df][   build:manual.bst                    ] FAILURE Running build-commands
    [00:00:00][0b5c52df][   build:manual.bst                    ] FAILURE Staged artifacts do not provide command 'sh'

        Printing the last 20 lines from log file:
        /home/jennis/.cache/buildstream/logs/scratch/manual/0b5c52df-build.9983.log
        ======================================================================
            TERM: dumb
            USER: tomjon
            USERNAME: tomjon
            LOGNAME: tomjon
            LC_ALL: C
            HOME: /tmp
            TZ: UTC
            SOURCE_DATE_EPOCH: '1320937200'
        [--:--:--] START   manual.bst: Staging dependencies
        [00:00:00] SUCCESS manual.bst: Staging dependencies
        [--:--:--] START   manual.bst: Integrating sandbox
        [00:00:00] SUCCESS manual.bst: Integrating sandbox
        [--:--:--] START   manual.bst: Staging sources
        [00:00:00] SUCCESS manual.bst: Staging sources
        [--:--:--] START   manual.bst: Running build-commands
        [--:--:--] STATUS  manual.bst: Running command

            echo "hello"
        [00:00:00] FAILURE manual.bst: Running build-commands
        [00:00:00] FAILURE manual.bst: Staged artifacts do not provide command 'sh'
        ======================================================================

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


 $ bst show manual.bst 
[--:--:--][        ][    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
   buildable 0b5c52df06a373ed6d1fcbd3c6b3a4d22fc1b77d3e069eaed8603f066df36557 manual.bst 

However, doing the exact same thing for an hello.bst element which fails:

kind: autotools
variables:
  command-subdir: doc/amhello

sources:
- kind: tar
  url: gnu:automake-1.16.tar.gz
  ref: 80da43bb5665596ee389e6d8b64b4f122ea4b92a685b1dbd813cd1f0e0c2d83f

depends:
- base.bst

config:
  build-commands:
    (>):
    - aibdq

shows as a failure:

 $ bst show hello.bst 
[--:--:--][        ][    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
      cached 33f047cb7d5b0c4eec9d336bbec11db9fe54eb675188eafbc97539e4af8ea40d base/alpine.bst 
      cached daf56f20c10459d0bc410cb319fe6817874d435118d9b1751b3e91abdf2909b8 base.bst 
      failed 1a1c740776f61e5215af2bc234ca50887e9816a94d457656236ec90fff07a924 hello.bst 

Some investigation

Upon some further investigation, I noticed that Artifact.cache() is not being called when building manual.bst. I'm not sure why.