ktor
ktor copied to clipboard
ktorio
When unable to get JWKS, JWTAuth swallows the underlying exception and only logs the last message
https://github.com/ktorio/ktor/blob/2406dc5b5970205593efa51867c0e5a05f149210/ktor-features/ktor-auth-jwt/jvm/src/io/ktor/auth/jwt/JWTAuth.kt#L164
When unable to retrieve the JWKS, JWTAuth swallows the underlying exception and only logs the message.
This means we only get to see:
TRACE io.ktor.auth.jwt - Failed to get JWK: Failed to get key with kid 1
When stack trace is:
com.auth0.jwk.SigningKeyNotFoundException: Failed to get key with kid 1
Caused by: com.auth0.jwk.SigningKeyNotFoundException: Cannot obtain jwks from url https://localhost:2222/jwks
Caused by: java.net.ConnectException: Connection refused (Connection refused)
Simple example to reproduce:
val TestJWT = "eyJraWQiOiIxIiwiYWxnIjoiUlMyNTYifQ.eyJpc3MiOiJodHRwOi8vbG9jYWxob3N0OjgwNjAvaXNzby9vYXV0aDIiLCJleHAiOjE3MTE4NzQ3MDAsImp0aSI6IjZvWkZWa3lGX2RSd1dpcXNhQkJkWkEiLCJpYXQiOjE1NTQxOTQ3MDAsInN1YiI6Im15dXNlciIsImF1ZCI6Ik9JREMiLCJhY3IiOiJMZXZlbDQiLCJhenAiOiJPSURDIn0.NuWfe1BZK3i-VVC1l7EIvJydd9m3Pcr2_0AanhbS3YEXSq_NWKhqtFd4qM_KUhLURTTwhNhAb43Zr2HzxGFUhnYnU4uCi95fLcw3Cq8mTM3o4I0r-pgpPTkfiheUUtOA4d43cwWpyEaBdypwO_F-VLA4zBw1oTRE_M0_G-16Q6yezpjTVBvOI7nsEWLHUZ-i10hE3V53cx2-Qm5OUOtEFF-UqqFhgBU6VSRYS5J3puWQFGlLr5hGSAW3Nll1DkJbiNaHB4y7EPnSlCPcNdZ98PXckylsiJ6nhRJXg4mke-C2WWckJ5H4dgsjeoUmXDuLekO1IrvwT1JLGJYiPwlQJw"
fun main(args: Array<String>): Unit {
Thread {
io.ktor.server.netty.EngineMain.main(args)
}.run()
Thread {
println("Testing in 3 secs...")
Thread.sleep(3000);
println("Testing...")
GlobalScope.launch {
val resp = HttpClient(Apache).use { client ->
client.get<String>(URL("http://localhost:8080/")) {
this.header("Authorization", "Bearer " + TestJWT);
}
}
println("RESP: ${resp}")
}
}.run()
}
@Suppress("unused") // Referenced in application.conf
@kotlin.jvm.JvmOverloads
fun Application.module(testing: Boolean = false) {
install(Authentication) {
jwt {
verifier(JwkProviderBuilder(URL("https://localhost:2222/jwks")).build(), "http://localhost:8060/isso/oauth2");
validate { credentials ->
if (credentials.payload.subject == "myuser") {
JWTPrincipal(credentials.payload)
} else {
log.info("${credentials.payload.subject} is not authorized to use this app, denying access")
null
}
}
}
}
routing {
authenticate {
get("/") {
call.respondText("HELLO WORLD!", contentType = ContentType.Text.Plain)
}
}
}
}
This is by design. There are reasons for that decision. We can't log stacktrace due to possible DoS. For sure we can't rethrow an exception due to the same reason.
Hmm, I see. That's probably a valid concern. It would be logging like 100 lines instead og 1 line. I still don't quite like the fact that there is no way to find the message from the root-cause by other ways than debugging the code though :-/ Not even with trace-level-logging. I guess it would be possible to extract the root cause and it's message, but that would of course introduce a little bit of complexity...
Shouldn't we log it in trace mode? As it's unlikely that someone is going to run in production with trace enabled, it seems a reasonable option.
No, you see, that's the thing: Only the message (ex.message) of the last exception is logged (i.e: "Failed to get JWK: Failed to get key with kid 1"), and not the stack-trace nor the root-cause (here: Connection refused towards https://localhost:2222/jwks)
Please check the following ticket on YouTrack for follow-ups to this issue. GitHub issues will be closed in the coming weeks.
