はじめに
タイトルそのままのことがおこりました。
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を参考に、盛り込み方は以下。
- 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'を使っていることから、文字列が返ってきている気がします。
- githubにはこう書いてありますが、falseが空値(?)で返ってくることや、後に出てくる判定で
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に変更があれば良いのですが、今回はそれができない...。
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で、キャッシュの作成を失敗しているんですね。この原因は、キャッシュ情報を保存するディレクトリがないからでした。なんと初歩的！
これがエラーにならないので、キャッシュは作成されているものと思ってしまっていた。うおぉ。
なので、突貫工事。。。
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のコンテナを初期化しています。
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の全体を載っけておきます。
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