ダウンロードできてたCSVファイルが、突然ページ表示されるようになった。

突貫工事で、複数人が入力したデータを、CSV形式でファイルダウンロードするWebアプリケーションをリリースしました。
利用したのは以下のOSSです。

* Spring Boot 2.2.4.RELEASE
    * 組み込みのTomcat 9.0.30
* Chrome 79.0.3945.130

運用開始当日は特に問題がなく、退社して友達と飲んでたら、何やら自分のスマホが騒がしい。。。着信に出てみると「ダウンロードができない」との連絡が。詳細を確認すると「3時間前まではダウンロードを行うとCSVファイルが出力されていたのに、突然、ブラウザ上にCSVが表示されるようになった」とのこと。

友人に誤り、飲みを切り上げ、原因の調査を開始。一応、こう修正すれば動くというが判ったので、まずはサービス優先でリリースしました。しかし、原理が不明なままなので、継続調査を実施しました。

## 修正の内容

以下は、今回の問題となったダウンロード処理の簡略化したコードと、修正後のコードです。

* 修正前

```kotlin
  @PostMapping
  fun export(response: HttpServletResponse) {
    /**
     * CSVをresponse.outputStreamに書き込む。
     */

    response.contentType = "text/csv"
    response.setHeader("Content-Disposition", "attachment; filename=export.csv")
    response.outputStream.flush()
  }
```

* 修正後

```kotlin
  @PostMapping
  fun export(response: HttpServletResponse) {
    response.contentType = "text/csv"
    response.setHeader("Content-Disposition", "attachment; filename=export.csv")

    /**
     * CSVをresponse.outputStreamに書き込む。
     */

    response.outputStream.flush()
  }
```

要はContent-TypeとContent-Dispositionが、outputStreamへの書き込みの後か前かです。
その後の調査ではContent-Dispositionが前にあれば、ファイルダウンロードされることが判りました。

なぜoutputStreamへの書き込みの後にContent-Dispositionの設定を行ったかと言えば、たまたま参考にした記事がこうだったのと、ヘッダの設定とボディ（ストリーム）への書き込みは独立した処理だと思っていたという理由です。

## 原因調査
ただ、outputStreamへの書き込みの後にContent-Dispositionを設定しても、しばらくは正常にファイルダウンロードができていたので、CSV出力のサイズが影響していることが推測できます。そこで画面にデータサイズを入力し、そのサイズのCSV出力を行う再現プログラムを作成してみました。

```kotlin
  @PostMapping
  fun export(@RequestParam size: Int, response: HttpServletResponse) {
    (1..size).forEach {
      response.outputStream.print("a")
    }
    response.contentType = "text/csv"
    response.setHeader("Content-Disposition", "attachment; filename=export.csv")
    response.outputStream.flush()
  }
```

すると、サイズが8KByteだとChromeの開発者ツールで確認した応答ヘッダは

```
Connection: keep-alive
Content-Disposition: attachment; filename=export.csv
Content-Type: text/csv
Date: Sat, 08 Feb 2020 10:26:07 GMT
Keep-Alive: timeout=60
Transfer-Encoding: chunked
```

でしたが9KByteだと

```
Connection: keep-alive
Date: Sat, 08 Feb 2020 10:27:48 GMT
Keep-Alive: timeout=60
Transfer-Encoding: chunked
```

のようにContent-Dispositionが消えてしまうではありませんか！突き詰めて行くと8191byteだと前者で、8192byteだと後者になります。
2の累乗である8192が設定された何かを超えたことが影響していると思います。

## 考察
おそらくは以下のようなことがTomcatで発生しているのだと考えています。

* HTTPボディへの出力が8191byte以下ならHTTPヘッダと一緒にデータを送り出せる。
* けど、HTTPボディへの出力が8192byte以上になると、そこまでのHTTPヘッダ情報を送信してから、8191byte単位にHTTPボディを送信する。
    * なのでHTTPボディへの出力後に、HTTPヘッダの設定を行っても、既にHTTPヘッダが送信済みなために、その設定は破棄されてしまった。

## 原因調査2
そこで手っ取り早くtcpdumpでパケットを監視しながら、デバッガで8190byteから1byteずつ書き込みをステップ実行してみたところ、8192byteを書き込んだところでブラウザにHTTPヘッダとボディが送信されていることが確認できました。

ついでに、8192byteを書き込時にステップインしていくと、以下のコードがありました。

```java:org.apache.catalina.connector.OutputBuffer
    public void append(byte src[], int off, int len) throws IOException {
        if (bb.remaining() == 0) {
            appendByteArray(src, off, len);
        } else {
            int n = transfer(src, off, len, bb);
            len = len - n;
            off = off + n;
            if (isFull(bb)) {
                flushByteBuffer();
                appendByteArray(src, off, len);
            }
        }
    }
```
bbはByteBuffer型のメンバ変数で、appendByteArrayおよびtransferメソッド内でbbに送信データを蓄積しています。
isFullメソッドではbbに蓄積されたサイズが許容量に達するとtrueになり、flushByteBufferメソッドでブラウザへ送信します。

flushByteBufferメソッドの中を更に追うと、

```java:org.apache.coyote.http11.Http11OutputBuffer
    @Override
    public int doWrite(ByteBuffer chunk) throws IOException {

        if (!response.isCommitted()) {
            // Send the connector a request for commit. The connector should
            // then validate the headers, send them (using sendHeaders) and
            // set the filters accordingly.
            response.action(ActionCode.COMMIT, null);
        }

        if (lastActiveFilter == -1) {
            return outputStreamOutputBuffer.doWrite(chunk);
        } else {
            return activeFilters[lastActiveFilter].doWrite(chunk);
        }
    }
```
コミット済みでなければ、コミット処理を行う中でHTTPヘッダを送信して、コミット済みフラグをセットします。
それ以降は、HTTPボディの書き込みが行われます。

## 考察2
ということで安易に作ってしまったコードが、たまたま意図した動作をしていたから気づかずにリリースしてしまいましたが、さまざまなサイズの処理を行うTomcat側の苦労を考えれば当然の実装で、そこにわざわざハマりにいってしまったというお話でした。


---
(2020/2/8) 投稿。
(2020/2/9) 原因調査で事象が前後で切り替わるサイズの誤記を修正。原因調査2と考察を追記。