「書き直した方が早い」は9割のケースで間違いだった

はじめに、本エントリは特定の企業、チーム、個人を指して書いたものでは一切ない。100%僕の個人的な経験から来ている。

さて、職業プログラミングに従事していると一度は「これ書き直した方が早いっす」とか言ったことある気がする。自分の場合、多くは歴史のあるレガシーコードを読んだときだ。思い返せば、自分がこう思ったときはほとんどそれは間違いであった。

「なんだこのコード…」
「これ何書いてあるか分かんないっす」
「うーんこれもう書き直した方が早くないっすか?」

この流れは非常に危険だ。
なぜならプログラムというのは本質的に書いてある通りにしか動かないからだ。ちゃんと読めば絶対に何を書いてあるかは分かる。

ここで安易に選んだ書き直しという選択は、自分が慣れ親しんだやり方でその部分をそっくり置き換えるというだけで、それは他人にとってあたらしい「これ何書いてあるかあるか分かんない」を生む結果にしかならない。

ここで取るべき行動は、注意深く辛抱強くコードを読み、解きほぐし、チームメンバやテックリードに相談し、リファクタリングすることだ。安易に「書き直す」なんて言ってはならない。少なくともそこに「何書いてあるか分かるまで」書き直すなんて言えないはずだ。

うわー読みづらいなー、つらいなー、書き直したいなーと思ったら、その行動が実装、テスト、QA含めて前のコードと同等の品質に持っていけるか熟考と見積もりを重ねて、経営陣に納得してもらえるだけの説明がつくか、その覚悟はあるか、思い返したいところだ。

自戒を強くこめて。

Date, Last-ModifiedヘッダがありCache-Controlが不適切な場合OkHttpが思いもよらないCacheをするので注意

(お詫びと訂正)

本件、「思いもよらないCache」ではなく、RFCに示された通りの実装でした。以下に追記します。

RFC7234 4.2.2 Calculating Heuristic Freshness にすべて書いてあるので詳しくはそちらを参照して欲しいですが、サーバが文書の失効に関する明示的な情報を何も返さない場合、キャッシュは他のヘッダを用いてコンテンツの鮮度をヒューリスティック*1に設定するかもしれないとのことです。

RFC7234の当該項目にたとえば代わりに"Last-Modified"を用いることやヒューリスティックな計算結果は最大10%にすることなど何もかも説明がありました。つまりOkHttpがこのようなキャッシュ戦略を取ることは思いもよらないでも何でもなくRFCの勧告通りということです。お詫びして訂正します。

Twitterにて指摘してくださった @hydrakecat さんありがとうございました🙇

 

以下、それを踏まえてお読みください。追記ここまで。

 

 TL;DR

随分長いタイトルになったが、次の条件を満たす場合にOkHttpのCacheが思いもよらない挙動をする場合がある。

  1. HTTPレスポンスに"Date", "Last-Modified"ヘッダが両方指定されている
  2. HTTPレスポンスの"Cache-Control"ヘッダにno-cache, no-store, max-age=0*2 のいずれもが未指定
  3. HTTPレスポンスの"Expires"ヘッダが未指定
  4. "Date" - "Last-Modified" が長い期間(たとえば3日間)

このとき、端的に言うと、思いがけず長い期間Cacheが破棄されずネットワークリクエストすら送られずローカルのCacheを見続ける

 

な…何を言っているのかわからねーと思うが、俺も何をされたのかわからなかったので順番に書いていく。

 

事の発端

そもそもこれに気付いたきっかけが、弊社アプリでCloudFrontに置いた小さな設定ファイルを見に行っている部分がファイルが更新されてもいつまで経っても再DLされず、よく観察してみるとリクエストすら飛んでないことが発覚したためだ。

ファイルにcurl -Iして見ると、たしかに"Cache-Control"ヘッダは設定が漏れている。

しかしOkHttpで"Cache-Control"ヘッダがない場合のキャッシュ戦略がどうなっているか、ソースを読むより方法がない。

 

CacheStrategy

OkHttpのキャッシュはCacheInterceptorという内部Interceptorによって制御されており、その名の通りCacheというクラスによってリクエストURLをキーにしたDiskLruCacheとして実装されている。*3

 

そしてCacheの動きを決める最も重要なクラスがCacheStrategyである。

CacheStrategyはこれからネットワークに向かっていくリクエストとヒットしたキャッシュエントリを受け取って色んなヘッダを見て、クラス名が表すとおりキャッシュ戦略を決定する。

 

まず、CacheStrategy.Factory がレスポンスヘッダをフィールドにマップしていく。

this.sentRequestMillis = cacheResponse.sentRequestAtMillis();
this.receivedResponseMillis = cacheResponse.receivedResponseAtMillis();
Headers headers = cacheResponse.headers();
for (int i = 0, size = headers.size(); i < size; i++) {
String fieldName = headers.name(i);
String value = headers.value(i);
if ("Date".equalsIgnoreCase(fieldName)) {
servedDate = HttpDate.parse(value);
servedDateString = value;
} else if ("Expires".equalsIgnoreCase(fieldName)) {
expires = HttpDate.parse(value);
} else if ("Last-Modified".equalsIgnoreCase(fieldName)) {
lastModified = HttpDate.parse(value);
lastModifiedString = value;
} else if ("ETag".equalsIgnoreCase(fieldName)) {
etag = value;
} else if ("Age".equalsIgnoreCase(fieldName)) {
ageSeconds = HttpHeaders.parseSeconds(value, -1);
}
}

"Date"ヘッダが servedDate に、"Last-Modified"ヘッダが lastModifled に、"Expires"ヘッダが expires にマップされたのを覚えておいて欲しい。

 

次のCacheStrategy#get() とそこから呼ばれる getCandidate() がフィールドにマップされた値を元にキャッシュ戦略を組み立てる心臓部である。

long ageMillis = cacheResponseAge();
long freshMillis = computeFreshnessLifetime();
if (!responseCaching.noCache() && ageMillis + minFreshMillis < freshMillis + maxStaleMillis) {
Response.Builder builder = cacheResponse.newBuilder();
if (ageMillis + minFreshMillis >= freshMillis) {
builder.addHeader("Warning", "110 HttpURLConnection \"Response is stale\"");
}
long oneDayMillis = 24 * 60 * 60 * 1000L;
if (ageMillis > oneDayMillis && isFreshnessLifetimeHeuristic()) {
builder.addHeader("Warning", "113 HttpURLConnection \"Heuristic expiration\"");
}
return new CacheStrategy(null, builder.build());
}

ここが問題のコードだ。

理解のために先に答えを書くと、

  • ageMillis…レスポンスがどのくらい古くなったか
  • freshMillis…キャッシュはどのくらいの期間新鮮か
  • そしてキャッシュを使ってよく、age < fresh ならキャッシュは新鮮だとみなし、ネットワークリクエストすら行わない。
return new CacheStrategy(null, builder.build());

この第一引数がネットワークリクエストだが、これがnullだとCacheInterceptorがネットワークリクエストを一切行わない。

僕が疑問を持っているのがこの計算方法である。

 

cacheResponseAge()

レスポンスのageの計算をしているメソッドだ。この計算方法はRFC 2616 13.2.3 Age Calculationsに明示してある。*4

long apparentReceivedAge = servedDate != null
? Math.max(0, receivedResponseMillis - servedDate.getTime())
: 0;
long receivedAge = ageSeconds != -1
? Math.max(apparentReceivedAge, SECONDS.toMillis(ageSeconds))
: apparentReceivedAge;
long responseDuration = receivedResponseMillis - sentRequestMillis;
long residentDuration = nowMillis - receivedResponseMillis;
return receivedAge + responseDuration + residentDuration;

コンテンツが発行されてから実際に受信に要した時間を計算し、現時点までの経過時間を加算するなどしてageを計算している。*5

ここはいいだろう。

 

computeFreshnessLifetime()

キャッシュが新鮮だと考えられる期間を計算する。コメントを読むと

Returns the number of milliseconds that the response was fresh for, starting from the served date.

とのことで「コンテンツが発行されたときから考えて、レスポンスが新鮮だとみなされるミリ秒」という感じか。

CacheControl responseCaching = cacheResponse.cacheControl();
if (responseCaching.maxAgeSeconds() != -1) {
return SECONDS.toMillis(responseCaching.maxAgeSeconds());
} else if (expires != null) {
long servedMillis = servedDate != null
? servedDate.getTime()
: receivedResponseMillis;
long delta = expires.getTime() - servedMillis;
return delta > 0 ? delta : 0;
} else if (lastModified != null
&& cacheResponse.request().url().query() == null) {
// As recommended by the HTTP RFC and implemented in Firefox, the
// max age of a document should be defaulted to 10% of the
// document's age at the time it was served. Default expiration
// dates aren't used for URIs containing a query.
long servedMillis = servedDate != null
? servedDate.getTime()
: sentRequestMillis;
long delta = servedMillis - lastModified.getTime();
return delta > 0 ? (delta / 10) : 0;
}
return 0;

冒頭の「特定条件」を見直していただければ分かるが、ここでは

} else if (lastModified != null
&& cacheResponse.request().url().query() == null) {

のブロックに入る。

なんとここでは、servedDate(要するにDateヘッダ)から lastModified(Last-Modifiedヘッダ)を引き、10で割って返している。10で割る…

当然だが、"Date"ヘッダと"Last-Modified"が非常に長い期間空いていると(いくら10%とはいえ)非常に長い期間になり、結果的にageを上回ってしまい、この期間ローカルのキャッシュしか見ない状態に陥ってしまう。

 

謎のRFC

コメントには次のようにある

As recommended by the HTTP RFC and implemented in Firefox, the
max age of a document should be defaulted to 10% of the
document's age at the time it was served. Default expiration
dates aren't used for URIs containing a query.

 HTTP RFCが勧告しFirefoxの実装が従っているように、ある文書のmax ageは文書が返されてから経過した時間の10%をデフォルトとすべきだ。

このRFCが何番の何項か分からないので、原文にあたりようがない。したがって現時点でこの仕様と実装が妥当なのか判断がつかない。

これについて何かご存知のかた、是非情報ください。

 

Cache-Controlヘッダが適切に存在する場合

"Cache-Control"ヘッダに

  • max-age=0(というかageより小さければなんでも)
  • no-cache, no-store

がある場合は、いずれもこの謎の計算式に到達せず、キャッシュは古いものとしてネットワークリクエストが送られる。

 

max-ageが計算したageより小さい場合とno-cacheの場合はETag(のための"If-None-Match")ヘッダも正しく使われるし、no-storeの場合はヘッダに従ってキャッシュエントリの保存自体が行われない。

この辺はこれまでに挙げたクラスのソースコードを実際に見て欲しい。行数も少なく、シンプルに書かれているので読みやすい。

 

Date, Last-Modifiedヘッダ

この挙動に触れるまで、"Date"ヘッダと"Last-Modified"ヘッダについてきちんとRFCで読んだことがなかったので改めて読んでみた。

 

RFC2616 14.18 Date

要約すると、メッセージが生成された日時ということだ。(これはそのファイルが置かれた日時という意味ではないので注意)

ざっくりと、このHTTPレスポンスのボディが生成されてクライアントに向けて送出する直前ぐらいまでの時間のようだ。

サーバエラー等やNTPサーバが利用できないような状況を除いて、基本的に全てのHTTPレスポンスに付けなければならない。日本語訳はこちら

 

RFC7232 2.2 Last-Modified

これは提供するコンテンツが最後に更新された日時だ。

更新されたという定義はコンテキストによるようで、それがファイルであればファイルの更新タイムスタンプかもしれないし、XMLJSONの一部ならツリーの一部コンテンツ以下の更新を意味するかもしれない。

条件付きリクエストやキャッシュ鮮度によってネットワークトラフィックを軽減できるため、サーバはLast-Modifiedヘッダを返すべきである。

An origin server SHOULD obtain the Last-Modified value of the
representation as close as possible to the time that it generates the
Date field value for its response.

そしてここは個人的に重要だと思ったので引用したが、Last-Modifiedは可能な限りDateに近づけるようにすべきだと書いてある。正しく運用することでより正確なキャッシュ運用が可能だからだろう。日本語訳はこちら

 

まとめ

まとめと言っても難しいな…特定のヘッダの組み合わせでOkHttpが思いもよらないキャッシュを持つというのを誰かに共有したかった。

敢えて教訓を挙げるならば、キャッシュして欲しくないコンテンツは正しく"Cache-Control"ヘッダを設定しようということだ。

 

弊社ではCloudFrontに置いたファイルを更新してもアプリがそれをいつまで経っても読みに行ってくれず、一体何が起こってるんだ!?とソースコードを読んでこのような挙動を発見した。

同じような運用をしている人は一度そのファイルにcurl -Iしてレスポンスヘッダを確認してみて欲しい。

 

最終的に少し発散してしまったが、computeFreshnessLifetime() の計算式がいかなる根拠によるものか未だに興味があるので、何かご存知のかたは教えてください。宜しくお願い申し上げます。

*1:正確でないかもしれないが経験的にある程度近似しそうなアプローチ

*2:正確に言うと0である必要はなく、後述のage以下ならよい

*3:この辺りに関連することはOkHttpのInterceptorとNetworkInterceptorとCacheの関係 - 怠惰を求めて勤勉に行き着くに書いた

*4:日本語訳はたとえばこちら

*5:本当はより正確な"Age"ヘッダがあればそれを利用する。詳しくはRFC2616参照。

OkHttpのInterceptorとNetworkInterceptorとCacheの関係

TL;DR

先に結論を書くと、NetworkInterceptorはCacheの後ろに居るからちゃんと理解してInterceptorを設定しないと思いもよらない結果になるよという話。

 

もっというと、この話題はYukiの枝折: OkHttp Interceptorに図付きで分かりやすく解説されているのでそちらの方が分かりよい。

 

自分で痛い目をみると人間は学習する

 じゃあなんでこの記事を書いたかというと、僕は前述の分かりやすいエントリを拝読していたにもかかわらずちゃんと理解しておらず、手痛いバグを入れてしまったからだ。

 

まず、僕のところで起きていた問題は

  1. 開発の便宜上HttpLoggingInterceptorを使ってHTTP通信をロギング
  2. OkHttpは特に指定がない場合 "Accept-Encoding: gzip" を付けてリクエストする
  3. gzipはLogcatに出ないから開発時だけはPlainTextで出したいので次のようなInterceptorをNetworkInterceptorとして追加した
  4. この状態でリクエストするとキャッシュがあるはずなのにも関わらずEtagを利用するための "If-None-Match" ヘッダが使われない
public class DisableGzipInterceptor implements Interceptor {
@Override
public Response intercept(Chain chain) throws IOException {
Request request = chain.request();
if (!BuildConfig.DEBUG) {
return chain.proceed(request);
}
Request newRequest = request.newBuilder()
.header("Accept-Encoding", "identity")
.build();
return chain.proceed(newRequest);
}
}
client = new OkHttpClient.Builder()
.addNetworkInterceptor(new HttpLoggingInterceptor())
.addNetworkInterceptor(new DisableGzipInterceptor())
.cache(getCache(getApplicationContext()))
.build();

 

このコードのどこが悪いか一瞬で分かる方は以降の記事は一切読む必要がない。

そう、これは

.addInterceptor(new DisableGzipInterceptor())

としないといけないのだ。なぜか?

 

OkHttpのCacheとVaryヘッダ

OkHttpに限らずHTTPのキャッシュ戦略を考えた場合、Varyヘッダの存在は重要である。Varyヘッダはレスポンスの生成に列挙する内容を考慮したかもしれないということを示す。

たとえば "Vary: accept-encoding, accept-language" と指定されていると、コンテンツは「エンコーディングの種類」や「言語設定」によって違うかもしれないという意味だ。もしキャッシュのキーとしてHTTPメソッド+パスを単純に用いるとこれらの状況に対応できないため、Varyヘッダは必ず考慮する必要があるというわけだ。

 

さて、OkHttpに話を戻そう。

OkHttpはInterceptor, NetworkInterceptorをどのようにチェインしてリクエスト/レスポンスを作るかというと、ずばり RealCall#getResponseWithInterceptorChain という部分である。抜粋する。

List<Interceptor> interceptors = new ArrayList<>();
interceptors.addAll(client.interceptors());
interceptors.add(retryAndFollowUpInterceptor);
interceptors.add(new BridgeInterceptor(client.cookieJar()));
interceptors.add(new CacheInterceptor(client.internalCache()));
interceptors.add(new ConnectInterceptor(client));
if (!forWebSocket) {
interceptors.addAll(client.networkInterceptors());
}
interceptors.add(new CallServerInterceptor(forWebSocket));

Interceptor.Chain chain = new RealInterceptorChain(interceptors, null, null, null, 0,
originalRequest, this, eventListener, client.connectTimeoutMillis(),
client.readTimeoutMillis(), client.writeTimeoutMillis());

return chain.proceed(originalRequest);
  1. client.interceptors() でユーザのInterceptorを全て登録
  2. 内部のInterceptorであるBridgeInterceptorを登録
  3. 内部のInterceptorであるCacheInterceptorを登録
  4. しかる後にユーザのNetworkInterceptorを全て登録

そしてこの順にチェインされるのである。

 

注目すべきは BridgeInterceptor で、

boolean transparentGzip = false;
if (userRequest.header("Accept-Encoding") == null && userRequest.header("Range") == null) {
transparentGzip = true;
requestBuilder.header("Accept-Encoding", "gzip");
}

ここに到達するまでに "Accept-Encoding" が設定されていない場合は gzip を勝手に追加する。

 

次に注目すべきは CacheInterceptor で、これは BridgeInterceptor のあとにチェインされる点を覚えておいて欲しい。

 

CacheInterceptor

OkHttpのキャッシュを一手に担うInterceptorである。詳しくは別エントリに譲るが、注目すべきは Cache#get である。

if (!entry.matches(request, response)) {
Util.closeQuietly(response.body());
return null;
}

DiskLruCacheには単純にリクエストURLをキーにキャッシュしているが、entry.matches(request, response) でVaryヘッダをチェックしている。

public boolean matches(Request request, Response response) {
return url.equals(request.url().toString())
&& requestMethod.equals(request.method())
&& HttpHeaders.varyMatches(response, varyHeaders, request);
}

せっかくキャッシュエントリにヒットしても、Varyヘッダが異なると別コンテンツとみなしてそのままnullが返され、ネットワークリクエストが継続されるという寸法だ。

 

流れを整理すると

  1. DisableGzipInterceptorをNetworkInterceptorとしてセットしてしまったので、最終的にネットワークリクエストされるときに "Accept-Encoding: identity" に書き換わり、それがキャッシュされる
  2. BridgeInterceptor が次回リクエスト時に透過的に gzip ヘッダを追加
  3. CacheInterceptor がキャッシュエントリをチェックするが、レスポンスとリクエストでVaryヘッダが異なるのでキャッシュがいつまでも使われない

というのが本件の顛末である。

 

まとめ

InterceptorとNetworkInterceptorの関係はOkHttpのドキュメントにも書いてあるが、Cacheとの関係はドキュメントに明示がない。

Stethoでリクエストとレスポンスを監視しても「なぜか "If-None-Match" ヘッダが付いてないのでキャッシュヒットしてなさそうだ」というのはすぐに分かるのだが「なぜキャッシュヒットしないのか」はソースを読むまでよく分からなかった。

 

ただ今回のきっかけでOkHttpのCache周りの実装にひととおり目を通すことができて非常に勉強になった。オープンソースの素晴らしいところはソースがオープンであるところだ(プ並感)

 

なお、今回調査して抜粋したコードはすべてOkHttp 3.9.1である。注意されたい。

ひほうをよこせ!おれはかみになるんだ!

リビングで物音を感じた私は不審者がいると確信して寝室を出たがエアコンのメンテナンスモードだった。意を決してブログを開設することにする。

 

思えばブログの続かぬ人生であった。ブログの続かなさに関しては東洋太平洋チャンピオンである。これだけ続かぬので肩肘張らぬ意味合いを込めてMedium等でなくて読者として愛するはてなブログを選んだ。

 

ブログを書くと決めた私は我が家の論理冷蔵庫であるところのセブンイレブンまで歩きサッポロ黒ラベルベビースターラーメンいきなりステーキ味を買ったのである。ベビースターラーメンいきなりステーキ味は、あのいきなりステーキを出たあと髪の毛にまで染み込んだいきなりソースの香りがして大変良い。

 

セブンイレブンといえばこの程セブンプレミアムワッフルコーンチョコミントをリニューアルしたが、妻がわざわざTwitterで「チョコミント売ってねえ」と2回つぶやくほど気にしていたので午前4時にビールを買いに行く後ろめたさを感じていた私がこのアイスを供物として求めたのは自然な流れと言えるが果たして売っておらない。

 

未練がましくアイス売り場を徘徊していると、ふと雪見だいふくの下からあのチョコミントを示す警戒色であるところの青緑色が目に飛び込んでくるではないか。なんとセブンプレミアムワッフルコーンチョコミントはアイス売り場上段からは物理的に届かない下段に隠されていたのである。元コンビニ店員の私としては、これは発注担当がどうしてもバイト上がりに品薄が予想されるセブンプレミアムワッフルコーンチョコミントを買い占めてメルカリで転売したいがさりとて客に買われたくはない、かと言って発注したアリバイは本部に残したいという苦肉の策だと察するに余りある。

 

勝利を確信した私はセブンプレミアムワッフルコーンチョコミントを4つ放り込み、カゴに入れたワンカップ大関を上撰にアップグレードしてから帰路についた。そしてこのブログを書いているのである。

 

ブログのタイトル「怠惰を求めて勤勉に行き着く」というのは昔ジャンプで連載していた坊や哲という麻雀漫画に出てくる房州さんという博打打ちがバーのママに「あんたら博打打ちは楽して儲けようっていう連中だろ。サイコロ振りの練習なんて妙に勉強熱心じゃないか」と指摘されて「『怠惰を求めて勤勉に行き着く』か、こりゃ一本取られた」みたいな感じで発する台詞である。20年ぐらい読んでないうろ覚えなので細部はだいぶ間違っているかも知れないが許して欲しい。とにかく流れ流れてプログラマになった私はこの台詞を生涯の目標にしようと決めたのだ。プログラマは楽をするためならどんな苦労も厭わない存在でなくてはならない。

 

丁度酒がなくなったのでここで筆を置くことにする。

リビングに置いてあるドジョウの水槽にいるタニシがお腹を空かせているのではないかと心配した私はインターネットの叡智を信じ乾燥昆布を投入したが、一晩経って水槽には茶色く出汁がでてタニシは壁面からこぼれ落ちていた。これからその水換えをせねばならない。それではまたいつの日か。