GitHub Actionsのcacheでどハマりした


## はじめに
タイトルそのままのことがおこりました。

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

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

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

![スクリーンショット 2020-04-13 15.04.38.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/261043/5abc4d2f-7a56-7399-d332-4d611a627db0.png)

jobの終了時、キャッシュを保存しようとすると、`Cache already exists.`となり、もうあるで？って言われる。おや？？？？( ˘ω˘ )
![スクリーンショット 2020-04-13 15.04.03.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/261043/645c9f11-7070-123a-511b-3730916806f5.png)


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

[このissue](https://github.com/actions/cache/issues/144)がドンピシャ。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](https://github.com/actions/cache)を参考に、盛り込み方は以下。

``` .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日間アクセスがなかったら、ってどっかでみた気がする。ので。)

キーの作り直しには、環境変数を使う方法([参考](https://tech.guitarrapc.com/entry/2020/01/06/071911#Cache))が良さげでした。
もともと、`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で、**キャッシュの作成を失敗しているんですね**。この原因は、キャッシュ情報を保存するディレクトリがないからでした。なんと初歩的！

![スクリーンショット 2020-04-13 21.35.44.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/261043/38bd988b-cfe8-7d7d-fd6d-06f39f2453de.png)


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

なので、突貫工事。。。

``` .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のタイトルに執念を感じます~~

![スクリーンショット 2020-04-13 19.32.12.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/261043/30885756-f83d-c4e5-753b-aa78f46f4e85.png)

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

![スクリーンショット 2020-04-13 21.14.00.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/261043/cda7ce0c-3a8a-7a1b-87d2-fea13a87d354.png)

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](https://github.com/actions/cache/issues/193)に載っていて、ここは、`bool`じゃなくて、`string`が返ってるっぽいと察するのに時間がかかりました...。

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


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

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

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

4/15追記: 筋肉実装すぎて本当にアホだったので、こちらもどうぞ。
[GitHub Actionsでcacheに転んでいた](https://qiita.com/yawn_yawn_yawn_/items/3f1f796d6eb600447222)

## 参考
- [GitHub Actionsのdoc](https://help.github.com/ja/actions/configuring-and-managing-workflows/caching-dependencies-to-speed-up-workflows#matching-a-cache-key)
- [actions/cacheのリポジトリ](https://github.com/actions/cache)
- [issue](https://github.com/actions/cache/issues/144)
- [cache-hitの確認時、参考にしたissue](https://github.com/actions/cache/issues/193)
- [GitHub Actions ことはじめ](https://tech.guitarrapc.com/entry/2020/01/06/071911#Cache)
- [GitHub Actions でキャッシュを使った高速化](https://www.kaizenprogrammer.com/entry/2019/12/15/220137#%E3%82%AD%E3%83%A3%E3%83%83%E3%82%B7%E3%83%A5%E3%82%AF%E3%83%AA%E3%82%A2)

## 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
```