GitHub Actionsのcacheでどハマりした

はじめに

タイトルそのままのことがおこりました。

4/15追記: 今回ハマったこと自体は、原因がわかり、形的に成功しているように見えるのですが、8割解決してないです。
こちらも合わせてどうぞ...。
GitHub Actionsでcacheに転んでいた

実現したかったこと

CIにgoの静的解析とテスト、ビルドを盛り込むこと。
その過程で、毎回go moduleのインストールが挟まると時間がかかっちゃうので、キャッシュを用いることでで解決したい。

ハマったこと

キャッシュの探索では、Cache not found for input keys: ...となり、ごめん見つからんかったわーって言われる。

jobの終了時、キャッシュを保存しようとすると、Cache already exists.となり、もうあるで？って言われる。おや？？？？( ˘ω˘ )

原因

一言でいうと、キャッシュできていなかったことが原因でした。

このissueがドンピシャ。issueのコメントから引用。

When creating the cache fails, the cache for a given key is stuck in a reserved state for up to a day, resulting in no cache found and the cache "already exists"

ガバガバ翻訳するます。
キャッシュの作成が失敗した時、指定したkeyが(キャッシュ作成のために)予約された状態で詰まってしまう。結果、キャッシュは、(実際には)存在しないが、(keyを見る限りだと)存在すると認識されてしまう。

そもそも、キャッシュに失敗しているんですね。できてると思い込んでいました...。

なぜキャッシュができてると思ってしまったかですが、原因は、キャッシュが成功しようが失敗しようが、jobは成功してしまうからでした。
この辺の詳細は次項で！

やったこと

知識整理

はじめに、このactionについて軽く説明。
githubを参考に、盛り込み方は以下。

.github/workflow/builds.yml

- uses: actions/cache@v1
  with:
    path: ~/go/pkg/mod 
    key: ${{ runner.os }}-go-${{ hashFiles('**/go.sum') }}
    restore-keys: |
      ${{ runner.os }}-go-

• pathで、キャッシュの保存先（ディレクトリ）を指定する。
• keyで、どのキャッシュを使うかなどの識別に用います。
• restore-keysでは、keyで指定したキャッシュが見つからなかった時、他のキャッシュを探索するのに使うキーを指定できます。
• 出力として、cache-hitというbool値が出力されます
  • githubにはこう書いてありますが、falseが空値(?)で返ってくることや、後に出てくる判定で'true'を使っていることから、文字列が返ってきている気がします。

path, keyは必須で、restore-keysのみオプションです。

次に、このactionが何をやっているのか、簡単に整理します。

1. keyやrestore-keysに基づいて、キャッシュが存在するか調査します。
2. 調査結果ごとの処理を行います。

• キャッシュが存在すれば、cache-hitにtrueが入る。job終了時、キャッシュの保存は行われない。
• キャッシュが存在しなかった場合、keyを予約。cache-hitには空値が入っている。job終了時、pathで指定されたディレクトリにキャッシュの保存を試みる。作られるキャッシュは、keyで識別可能になります。

原因から色々と試行する

原因が、キャッシュの失敗。
今使っているkeyだと、すでにキャッシュが作成されていると認識されるため、新しいキャッシュが作れない...

ってことは、キーを作り直せばいいじゃん！！！！
(issueの方には、clean upのスパンを短くするってあったけれど、github actionsのキャッシュが綺麗になるのが7日間アクセスがなかったら、ってどっかでみた気がする。ので。)

キーの作り直しには、環境変数を使う方法(参考)が良さげでした。
もともと、go.sumをハッシュして作成しているので、go.sumに変更があれば良いのですが、今回はそれができない...。

.github/workflows/build.yml

name: Go
on:
  ...省略
# 追記
env:
    cache-version: v1
    
jobs:
  build:
    ... 省略

    steps:
    ... 省略

    - name: cache
      uses: actions/cache@v1
      with:
        id: cache-go
        path: ~/go/pkg/mod
        key: ${{env.cache-version}}-${{ runner.os }}-go-${{ hashFiles('**/go.sum') }}
        restore-keys: |
          ${{ runner.os }}-go-
    
    # cacheがヒットしたか確認。
    - name: after cache
      run: |
        echo "-->${{steps.cache-go.outputs.cache-hit}}<--"

※キャッシュがヒットしたら行わないactionを用意する場合、ヒットしたか確認するためにcacheのidは必須になります。

よっしゃこれでいけるやろ！って思ったがそんなことはなかった。今思うとそりゃそうだってなる...。

ここまできて、初めて元凶がわかりました。
ハマったこと以前に起こっていたことが原因というか、元凶でした。
そもそも、cacheを使った初回のCIで、キャッシュの作成を失敗しているんですね。この原因は、キャッシュ情報を保存するディレクトリがないからでした。なんと初歩的！

これがエラーにならないので、キャッシュは作成されているものと思ってしまっていた。うおぉ。

なので、突貫工事。。。

.github/workflows/build.yml

  build:
    ... 省略

    steps:
    ... 省略
    
    # cache保存用にディレクトリを作っておく
    - name: before cache
      run: |
        mkdir -p ~/go/pkg/mod
        ls ~/go/pkg/

    - name: cache
      uses: actions/cache@v1
      with:
        id: cache-go
        path: ~/go/pkg/mod
        key: ${{ env.cache-version }}-${{ runner.os }}-go-${{ hashFiles('**/go.sum') }}
        restore-keys: |
          ${{ runner.os }}-go-
    
    ... 省略

これで、やっとキャッシュが成功し、ヒットし、actionのスキップが可能になりました。大変だった。

最終結果

ビルドの時間についてはこんな感じ。1分くらい浮いてます。
PRのタイトルに執念を感じます

実際にGet dependenciesがスキップされてますね。映ってないですが、テストなども正常終了してます。

yamlファイルは以下。
重要な部分以外は省略してあります。全文はこの記事の最後を参考にしてください。テストに必要だったのでmysqlのコンテナを初期化しています。

.github/workflows/build.yml

name: Go

on:
  pull_request:
    branches:
      - '*'
# go.sumに変更がなくても、キャッシュを作り変えられるように
env:
  cache-version: v5

jobs:
  # cacheが関係ないジョブ
  static-check:
    ... # fmtやlintを行っているjobです

  build:
    name: Test-Build
    runs-on: ubuntu-latest
    needs: [static-check]
    services:
      mysql:
        ... # testで必要なので、コンテナを用意

    steps:
    - name: Set up Go
      uses: actions/setup-go@v1
      with:
        go-version: 1.12
      id: go

    - name: Check out code into the Go module directory
      uses: actions/checkout@v2
    
    # cache保存用にディレクトリを作っておく
    - name: before cache
      run: |
        mkdir -p ~/go/pkg/mod
        ls ~/go/pkg/

    # cacheを実行
    - name: cache
      uses: actions/cache@v1
      id: cache-go
      with:
        path: ~/go/pkg/mod
        key: ${{ env.cache-version }}-${{ runner.os }}-go-${{ hashFiles('**/go.sum') }}
        restore-keys: |
          ${{ runner.os }}-go-

    # cacheがヒットしたか確認。本番では不要かな。
    - name: after cache
      run: |
        echo "-->${{steps.cache-go.outputs.cache-hit}}<--"
    
    # キャッシュがヒットしなかった時のみ実行される
    # install module
    - name: Get dependencies
      if: steps.cache-go.outputs.cache-hit != 'true'
      run: |
        go get -v -t -d ./...
        if [ -f Gopkg.toml ]; then
            curl https://raw.githubusercontent.com/golang/dep/master/install.sh | sh
            dep ensure
        fi

    # Run vet
    - name: Go vet
      run: |
        go vet ./...
        
    # Run test
    - name: Test
      run: go test -v ./...
      
    # Rub build
    - name: Build
      run: go build -v ./cmd/main.go

go vetも静的解析の一部なので、StaticCacheのjobに突っ込みたかったのですが、ちょっと詰まってうまくいかないので、要修正ですね。

余談

最初、本当に意味わからんすぎたので、steps.[id].outputs.cache-hitの値を検証しまくってました。
boolがくると思いきや空値。
はじめは、これは？なに？という状態に...。この辺も別のissueに載っていて、ここは、boolじゃなくて、stringが返ってるっぽいと察するのに時間がかかりました...。

あとは少し、中でどういう処理がされているかをみようと思い、コードを読んでみました。多分ここで詰まってるんだろうなーって部分はありましたが、根本的な解決にはならず...。

まとめ

そもそも、最初のキャッシュ作成失敗、って部分を見つけ出すまでにものすごく時間がかかってしまった。だってjobが成功してるんだもん。issueにすごく助けられました。
キャッシュの作成失敗がエラーとして吐かれないとは...と思いましたが、ちゃんと考えると、キャッシュの失敗はCIの本質部分の失敗ではない気がするので、エラーにはならないですね...。にほんごよわい。
フローは成功しててもある程度中を見る必要がありそうですね...。

解決策についてですが、ディレクトリを作成してーって、すごく力技な気がします。スマートにいきたいですね。要改善...。
ブログを書いてて、私はトラブルシュートが下手だなあと...精進します。しかしまあトラブルシュートは楽しいですね。

トラブルシュートではない、GitHub Actionsについての知見をアウトプットしたいなあ...

4/15追記: 筋肉実装すぎて本当にアホだったので、こちらもどうぞ。
GitHub Actionsでcacheに転んでいた

参考

• GitHub Actionsのdoc
• actions/cacheのリポジトリ
• issue
• cache-hitの確認時、参考にしたissue
• GitHub Actions ことはじめ
• GitHub Actions でキャッシュを使った高速化

yaml全体

最後に、一応、yamlの全体を載っけておきます。

.github/workflows/build.yml

name: Go

on:
  pull_request:
    branches:
      - '*'

env:
  cache-version: v5

jobs:
  # cacheが関係ないジョブ
  static-check:
    name: StaticCheck
    runs-on: ubuntu-latest
    container: golang:1.12
    steps:
      # set go version
      - name: Set up Go 1.12
        uses: actions/setup-go@v1
        with:
          go-version: 1.12
        id: go

      - name: Check out code into the Go module directory
        uses: actions/checkout@v2
        
      # Run fmt
      - name: Go fmt
        run: |
          GO111MODULE=off go get -u golang.org/x/tools/cmd/goimports
          gofmt -s -w cmd/
          goimports -w cmd/

      # Run lint
      - name: Go Lint
        run: |
          GO111MODULE=off go get -u golang.org/x/lint/golint
          golint ./...

  build:
    name: Test-Build
    runs-on: ubuntu-latest
    needs: [static-check]
    services:
      mysql:
        image: mysql:5.7
        ports:
          - 3306:3306
        options: --health-cmd "mysqladmin ping -h localhost" --health-interval 20s --health-timeout 10s --health-retries 10
        env:
          MYSQL_ROOT_PASSWORD: pass
          MYSQL_DATABASE: sample

    steps:
    - name: Set up Go 1.13
      uses: actions/setup-go@v1
      with:
        go-version: 1.12
      id: go

    - name: Check out code into the Go module directory
      uses: actions/checkout@v2

    - name: SetUp ddl
      run: |
        mysql --protocol=tcp -u root -ppass sample < ./ddl.sql
    
    # cache保存用にディレクトリを作っておく
    - name: before cache
      run: |
        mkdir -p ~/go/pkg/mod
        ls ~/go/pkg/

    # cache
    - name: cache
      uses: actions/cache@v1
      id: cache-go # 必須
      with:
        path: ~/go/pkg/mod
        key: ${{ env.cache-version }}-${{ runner.os }}-go-${{ hashFiles('**/go.sum') }}
        restore-keys: |
          ${{ runner.os }}-go-

    # cacheがヒットしたか確認
    - name: after cache
      run: |
        echo "-->${{steps.cache-go.outputs.cache-hit}}<--"
    
    # install module
    - name: Get dependencies
      if: steps.cache-go.outputs.cache-hit != 'true'
      run: |
        go get -v -t -d ./...
        if [ -f Gopkg.toml ]; then
            curl https://raw.githubusercontent.com/golang/dep/master/install.sh | sh
            dep ensure
        fi

    # Run vet
    - name: Go vet
      run: |
        go vet ./...
        
    # Run test
    - name: Test
      run: go test -v ./...
      
    # Rub build
    - name: Build
      run: go build -v ./cmd/main.go