Ktorのauto-reload時にpluginエラーがあると応答しなくなり、原因究明ができない問題のワークアラウンド
前提とするバージョン
io.ktor:ktor-server-core-jvm:2.3.8
io.ktor:ktor-server-netty-jvm:2.3.8
問題
development = trueによるAuto-reload中に、プラグインにエラーが発生すると、ログが何もでず、Ktorが応答しなくなる。
issueは、以下で起票済みです。
Ktor becoming unresponsive when a plugin errors during auto-reload. : KTOR-6799
auto-reload時にエラーとなるプラグインに気づく方法
auto-reloadのときは、embeddedServerの戻り値がApplicationEngineEnvironmentReloadingというクラスになる。
このクラスにio.ktor.server.engine.ApplicationEngineEnvironmentReloading#reloadが生えているので、サーバー起動後にそれを実行することでエラーになってくれるので、問題のあるプラグインに気づくことができる。
では、なぜ実際のauto-reloadではなんでエラーのログが出ないのか？
と思うことでしょう。
前提の説明として、実際のauto-reload時には、reloadメソッドとは別のio.ktor.server.engine.ApplicationEngineEnvironmentReloading#currentApplicationというメソッドで処理がされていて、ここで必要であればreloadをするという処理が行われているらしい（これ自体は問題ない）。
で、currentApplicationを呼び出す側のエラーハンドリングがしっかりとされていないまま、Nettyを終了しているのが大まかな原因のようです。
ktorがauto-reload時にpluginでエラーになると、Nettyがio.netty.channel.AbstractChannelHandlerContext#invokeChannelRead(java.lang.Object)から例外がスローされ、io.netty.channel.AbstractChannelHandlerContext#invokeExceptionCaught(java.lang.Throwable)で、エラーをキャッチしているようです。キャッチした後は、io.ktor.server.netty.http1.NettyHttp1Handler#exceptionCaughtへ戻ってきて、エラー処理は何もせずに、io.ktor.server.netty.http1.NettyHttp1Handler#exceptionCaughtで、io.netty.channel.ChannelHandlerContext#close()を呼んでNettyを終了しているというのが原因です。
ワークアラウンド
start(await = true)での例です。
fun main() {
val server = embeddedServer(
Netty,
commandLineEnvironment(arrayOf("-config=application.conf"))
)
// 自動リロードできないプラグインのエラーに気づけます
ensureReloadableAsync(server.environment)
server.start(wait = true)
}
private fun ensureReloadableAsync(environment: ApplicationEngineEnvironment) {
Thread {
Thread.sleep(1_000)
if (environment is ApplicationEngineEnvironmentReloading) {
environment.reload()
}
}.start()
}
start(await = false)、（起動後、blockしない）場合の実装例は以下を参考にしてください。
最後にひとこと
エラーログが出ないエラーは、ネットでの検索のしようがないので、とりあえずなんらかのエラーログは出て欲しいです。今回は、ktorでreloadを行うコードを探してデバッガーでで内部の挙動を見て分かりました。
Discussion