Help us understand the problem. What is going on with this article?

Ktor Clientのconfigを変更しようとしたら大量のThreadが生成されてた話

More than 1 year has passed since last update.

やりたかったこと

以前書いた記事で少ないThreadでノンブロッキングなネットワークI/Oを実現できて万々歳でした。
リクエスト毎にタイムアウト時間を変えたり、許可されたProxyに設定を変えたかったので、最終的には接続先をみて最適なクライアントを生成する仕組みを作成しようと思いました。

つまり
今回は「リクエスト毎にconfigを変更」できればいいわけです。

試してみた

環境

  • Intellij
  • spring boot
  • kotlin

まずはリクエスト毎にconfigを変更してみました。

fun main(args: Array<String>) = runBlocking {
  val applicationContext = runApplication<SkaleApplication>(*args)
  val app = applicationContext.getBean(SkaleApplication::class.java)

  val log = LoggerFactory.getLogger(app::class.java)

  log.info("start")
  log.info("thread num = ${Thread.activeCount()}")

  val rand = Random(LocalDateTime.now().second)
  val ktorClient = HttpClient(Apache)

  for (i in 1..50) {
    val timeout = rand.nextInt(50)

    launch {
      runCatching {
        log.info("req start $i")

        // 設定値を変える(Proxyなどを変更している想定)
        val client = val client = ktorClient.config {
            ApacheEngineConfig().apply {
                connectionRequestTimeout = 0
                connectTimeout = timeout
            }
        }

        val result = client.get<HttpResponse>(
            scheme = "https", host = "httpbin.org", path = "/delay/5", port = 443)
        client.close()
        result

      }.fold(
          onSuccess = {
            log.info("req end = $i")
            log.info("thread num = ${Thread.activeCount()}")
          },
          onFailure = {
            log.info("req failure = $i / result = $it")
          }
      )
    }
  }
}

失敗した

原因はココ

val client = ktorClient.config {
  ApacheEngineConfig().apply {
    connectionRequestTimeout = 0
    connectTimeout = timeout
  }
}

以下のメソッドがあったので
HttpClient::config(block: HttpClientConfig<*>.() -> Unit)
これで設定値を変えられるかなと思ってやってみたら
そもそもRequest自体がorg.apache.http.ConnectionClosedExceptionで失敗してだめでした。

よくよく見てみたら内部では設定を上書きして新たにClientをnewしています。ConnectionClosedExceptionが起きている理由までは調べていませんが、今回は「できる」か「できないか」がわかれば十分なので割愛。

/**
 * Returns a new [HttpClient] copying this client configuration,
 * and additionally configured by the [block] parameter.
 */
fun config(block: HttpClientConfig<*>.() -> Unit): HttpClient = HttpClient(
    engine, HttpClientConfig<HttpClientEngineConfig>().apply {
        this += userConfig
        block()
    }
)

(ちなみに「+=」は演算子オーバーロードで内部で設定を上書きしています。)

そういうことなら都度生成

以下の形で実行

fun main(args: Array<String>) = runBlocking {
  val applicationContext = runApplication<SkaleApplication>(*args)
  val app = applicationContext.getBean(SkaleApplication::class.java)

  val log = LoggerFactory.getLogger(app::class.java)

  log.info("start")
  log.info("thread num = ${Thread.activeCount()}")

  val rand = Random(LocalDateTime.now().second)

  for (i in 1..50) {
    val timeout = rand.nextInt(50)

    launch {
      runCatching {
        log.info("req start $i")

        // 設定値を変える(Proxyなどをリクエストにより変更している想定)
        val client = HttpClient(Apache) {
          engine {
            connectionRequestTimeout = 0
            connectTimeout = timeout
          }
        }

        val result = client.get<HttpResponse>(
            scheme = "https", host = "httpbin.org", path = "/delay/5", port = 443)
        client.close()

        result

      }.fold(
          onSuccess = {
            log.info("req end = $i")
            log.info("thread num = ${Thread.activeCount()}")
          },
          onFailure = {
            log.info("req failure = $i / result = $it")
          }
      )
    }
  }
}

結果

  • リクエストは成功してレスポンスも返ってきた
  • が、しかし

Thread数を見てみた

19-02-27 19:17:20.630 INFO  30049 [main] || - start
19-02-27 19:17:20.630 INFO  30049 [main] || - thread num = 5
19-02-27 19:17:20.645 INFO  30049 [main] || - req start 1
19-02-27 19:17:20.756 INFO  30049 [main] || - req start 2
19-02-27 19:17:20.759 INFO  30049 [main] || - req start 3
19-02-27 19:17:20.761 INFO  30049 [main] || - req start 4
19-02-27 19:17:20.763 INFO  30049 [main] || - req start 5
19-02-27 19:17:20.765 INFO  30049 [main] || - req start 6
19-02-27 19:17:20.767 INFO  30049 [main] || - req start 7
~~~~~~ 省略 ~~~~~~
19-02-27 19:17:26.773 INFO  30049 [main] || - req end = 5
19-02-27 19:17:26.773 INFO  30049 [main] || - thread num = 396
19-02-27 19:17:26.776 INFO  30049 [main] || - req end = 3
19-02-27 19:17:26.776 INFO  30049 [main] || - thread num = 388
19-02-27 19:17:26.780 INFO  30049 [main] || - req end = 13
19-02-27 19:17:26.780 INFO  30049 [main] || - thread num = 380
19-02-27 19:17:26.783 INFO  30049 [main] || - req end = 33
19-02-27 19:17:26.783 INFO  30049 [main] || - thread num = 372
~~~~~~ 省略 ~~~~~~
19-02-27 19:17:26.857 INFO  30049 [main] || - req end = 14
19-02-27 19:17:26.857 INFO  30049 [main] || - thread num = 20
19-02-27 19:17:26.857 INFO  30049 [main] || - req end = 34
19-02-27 19:17:26.857 INFO  30049 [main] || - thread num = 12
19-02-27 19:17:26.858 INFO  30049 [main] || - req end = 48
19-02-27 19:17:26.858 INFO  30049 [main] || - thread num = 4
19-02-27 19:17:26.860 INFO  30049 [Thread-1] || - アプリケション終了の準備中

thread num = 396 おや。。。?

考察

クライアントを都度生成するとその分Threadを生成してしまうようです。上記の396という数字が今回のテストで計測できた中でのThread数最大値となります。50個のクライアントを生成しているわけですから
396 / 50 = 7.92
ものすごくざっくりですが、1 オブジェクトあたり8 Threadが生成されている計算になります。

結論

私が今回やりたかった「リクエスト毎にconfigを変更する」とKtor Clientの良さを活かせないようです。
クライアントが都度生成されることになり、それによってThreadも増えてしまいました。私のようにconfigを変えたいというケースはあまりないとは思いますが、Ktor Clientの良さを活かすには一つのオブジェクトを使い回すのが良さそうです。

Nabesuke
フロントエンド、バックエンド、ネイティブアプリなど一通り触ってます。love kotlin
valus
導入社数業界No.1の自動価格調査&更新システムサービス「プライスサーチ」の開発・運営するスタートアップ
https://valus.co.jp/
Why not register and get more from Qiita?
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away