akka-http で request-timeout が機能しなかった話

この記事は MicroAd Advent Calendar 2020 の4日目の記事です。

## 概要

akka-http には `akka.http.server.request-timeout` という設定があり、クライアントからのリクエストに対してレスポンス生成する際にかかる最大時間を制限できます。（デフォルト値は 20 秒）

今回、その設定が効かないパターンがあったという話です。

https://doc.akka.io/docs/akka-http/current/common/timeouts.html#request-timeout


なお、今回使用する akka-http のバージョンは `10.2.1` です。


## 事前準備

検証するにあたり、適当にサーバーを立てます。


```scala
object ExampleServer extends App {
  // resources/application.conf が読み込まれ、defaultの設定とマージされる。
  // application.confが存在しなければ、そのままdefaultの設定が使われる。
  private val config: Config = ConfigFactory.load()

  // akka-http が使う
  implicit private val system: ActorSystem = ActorSystem("ExampleServer", config)

  // ExampleRoute が使う
  implicit private val ec: ExecutionContext = system.dispatcher

  // ルーティング
  private val exampleRoute: ExampleRoute = new ExampleRoute

  // バインド先のインターフェイスとポートを指定し、httpサーバーを起動
  Http().newServerAt("127.0.0.1", 8080).bind(exampleRoute.root)
}
```


akka-http デフォルトの request-timeout は 20 秒と長いので、 100ms に設定します。

```conf
akka {
  http.server {
    request-timeout = 100 ms
  }
}
```


## 効かないパターン

例えば下記のようにした時 `path b` では、 `Thread.sleep(150)` しているので request-time が発動して欲しいところです。

```scala
class ExampleRoute(implicit ec: ExecutionContext) {

  def root: Route = get {
    concat(
      path("a") {
        complete("path a!")
      },
      path("b") {
        Thread.sleep(150) // なんかの処理とかを仮定
        complete("path b!")
      }
    )
  }

}
```

実際にリクエストを送ってみます。

- `path a`

```sh
 % http localhost:8080/a
HTTP/1.1 200 OK
Content-Length: 7
Content-Type: text/plain; charset=UTF-8
Date: Thu, 03 Dec 2020 09:30:01 GMT
Server: akka-http/10.2.1

path a!
```

- `path b`

```sh
% http localhost:8080/b
HTTP/1.1 200 OK
Content-Length: 7
Content-Type: text/plain; charset=UTF-8
Date: Thu, 03 Dec 2020 09:30:05 GMT
Server: akka-http/10.2.1

path b!
```


`path b` でも `path a` 同様に `status 200` でレスポンスされてしまっていることがわかります。


## 効くパターン

request-timeout が効くパターンですが、下記のように response に Future を返すようにすることで実現できます。

しかし、`path a` では request-timeout が効いて、 `path b` では request-timeout が効きません。


```scala
class ExampleRoute(implicit ec: ExecutionContext) {

  def root: Route = get {
    concat(
      path("a") {
        val f = Future {
          Thread.sleep(150) // なんかの処理とかを仮定
          "path a!"
        }
        complete(f)
      },
      path("b") {
        Thread.sleep(150) // なんかの処理とかを仮定
        complete(Future.successful("path b!"))
      }
    )
  }

}
```


- `path a`

```sh
% http localhost:8080/a
HTTP/1.1 503 Service Unavailable
Content-Length: 105
Content-Type: text/plain; charset=UTF-8
Date: Thu, 03 Dec 2020 09:39:17 GMT
Server: akka-http/10.2.1

The server was not able to produce a timely response to your request.
Please try again in a short while!
```

- `path b`

```sh
% http localhost:8080/b
HTTP/1.1 200 OK
Content-Length: 7
Content-Type: text/xml; charset=UTF-8
Date: Thu, 03 Dec 2020 09:39:19 GMT
Server: akka-http/10.2.1

path b!
```

## akka-http が 受け取ったレスポンスの Future にタイムアウトを設定しているっぽい

とりあえず、**`レスポンスとして返却された Future が complete するまで待つ時間` = `request-timeout`**だということです。

`path b` では、`Thread.sleep(150)` してからレスポンスとして Future を渡しているので、Future が complete するのにかかる時間はほぼ0なので`request-timeout`が効かないように見えますね。  
  
  
また、akka-http には `onComplete` のようなメソッドがあり、その場合もしっかりと request-time が適用されます。

```scala
path("c") {
  onComplete(Future { Thread.sleep(150); "path c!" }) {
      case Success(value) => complete(value)
      case Failure(_) => complete(InternalServerError)
  }
}
```

`onComplete` を使った場合でも `onComplete`の中でブロッキング処理を書いてしまうと、当然ですがそこでかかった時間はカウントされないということです。

つまり下記のような書き方だと、タイムアウトされずに `status 200` でレスポンスされます。

```scala

path("c") {
  onComplete(Future { "path c!" }) {
    case Success(value) => Thread.sleep(150); complete(value)
    case Failure(_) => complete(InternalServerError)
  }
}
```

下記のような、ただ Future の successful でラップしたような書き方もダメです。 (まぁ `path b` のところでやってることと同じですね。)

```scala
def nannka: Future[String] = {
  val value = { Thread.sleep(150); "nannka omoisyori done!" }
  Future.successful(value)
}

path("c") {
  onComplete(nannka) {
    case Success(value1) => complete(value1)
    case Failure(_) => complete(InternalServerError)
  }
}
```

## 注意点

akka-http がタイムアウトしたとき、 **処理が中断されるわけではない** のでそこは注意が必要です。 ( [Future は基本的には中止できない](https://qiita.com/somasomaso-ma/items/65cbade4ff4e4c67bcc1) )

例えば、何らかのデータをDBに登録する処理がある場合にタイムアウトで `503 Service Unavailable` を返しても、処理が中断されるわけではないので実際にデータが登録されうるということです。
この場合、クライアントから見るとデータの登録が失敗したように見えるので、再度登録処理を実行しようとするかもしれません。
その場合重複してデータの登録や更新が走ることになるので、 そういうデータ登録系の path には `TimeoutDirectives` などを使って別途タイムアウトを設定するなどした方がいいかもしれません。

request-timeout の1番の目的は プログラミングエラーにより Future が完了しない場合などに、レスポンスが漏洩して無期限に留まることを防ぐことですが、request-timeoutでのレスポンスはクライアントに返却されるので、（全てのリクエストがタイムアウトするようなリクエストでなければ）コネクションが空くことで処理量が微量ながらスケールするかもしれません。 (akka-http の 並列数は `max-connections`)


## まとめ

akka を使う以上、基本的に「ExecutionContext を伴う Future を使わずにブロッキング処理をする」 などをしないような気はしますが、 
「onComplete 配下の Logger でうっかりクソデカ文字列を出力してて~」 とか 「ブロッキングなライブラリやモジュールを使ってて~、その返り値をとりあえず Future.successful で返してた~」 
とかあるかもしれないので、もし akka-http を使っていて「なんか request-timeout が効かないんだよなぁ」って思ったらその辺を疑ってみるといいかもしれません。