ktorio / ktor

Framework for quickly creating connected applications in Kotlin with minimal effort
https://ktor.io
Apache License 2.0
13.09k stars 1.07k forks source link

Multipart, Broken delimiter occurred #1901

Closed agcom closed 4 years ago

agcom commented 4 years ago

Ktor Version and Engine Used (client or server and name) 1.3.2, CIO engine client/server

Describe the bug Imagine the following server

fun main() {
    embeddedServer(CIO, host = "localhost", port = 8080, module = Application::module).start(wait = true)
}

fun Application.module() {
    routing {
        post {
            try {
                call.receiveMultipart().readPart()
            } catch (ex: IOException) {
                call.respond(HttpStatusCode.BadRequest, "Can't receive multipart")
            }
        }
    }
}

Which tries to read a part from a multipart request.

But the client can be tricky. What trick? Sending empty body for a multipart request.

For example, in ktor language it can be expressed like this (the problem is not related to any particular client)

fun main() = runBlocking {
    val client = HttpClient(CIO) {
        defaultRequest {
            host = "localhost"
            port = 8080
        }
        expectSuccess = false
    }

    val res = client.submitFormWithBinaryData<HttpResponse>() //EMPTY MULTIPART REQUEST

    println(res.status)
    println(res.readText())

    client.close()
}

Run the server, then make the request. It will timeout (or hangs indefinitely) and the server logs

21:00:12.389 [DefaultDispatcher-worker-1] INFO ktor.application - 400 Bad Request: POST - /, cancelled

Also tested with Netty server engine but that worked as expected (client receives 400, Can't recieve multipart).

WAIT! Haven't reach the interesting part yet.

Install StatusPages feature on the server module and add an exception (so it will intercept the pipeline), like this

install(StatusPages) {
    exception<Error> { call.respond(HttpStatusCode.InternalServerError) }
}

Then run the server and make the request again.

Surprise! one step forward. Now the server logs (yet the request times out on the client)

20:56:41.896 [DefaultDispatcher-worker-2] ERROR ktor.application - 400 Bad Request: POST - /
java.io.IOException: Broken delimiter occurred
    at io.ktor.utils.io.DelimitedKt$skipDelimiterSuspend$2.invokeSuspend(Delimited.kt:58)
    at io.ktor.utils.io.DelimitedKt$skipDelimiterSuspend$2.invoke(Delimited.kt)
    at io.ktor.utils.io.ByteBufferChannel.lookAheadSuspend$suspendImpl(ByteBufferChannel.kt:1872)
    at io.ktor.utils.io.ByteBufferChannel.lookAheadSuspend(ByteBufferChannel.kt)
    at io.ktor.utils.io.DelimitedKt.skipDelimiterSuspend(Delimited.kt:56)
    at io.ktor.utils.io.DelimitedKt.skipDelimiter(Delimited.kt:51)
    at io.ktor.http.cio.MultipartKt.skipBoundary(Multipart.kt:201)
    at io.ktor.http.cio.MultipartKt$parseMultipart$1.invokeSuspend(Multipart.kt:325)
    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
    at kotlinx.coroutines.DispatchedContinuationKt.resumeCancellableWith(DispatchedContinuation.kt:314)
    at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:26)
    at kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:109)
    at kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt:158)
    at kotlinx.coroutines.channels.ProduceKt.produce(Produce.kt:98)
    at kotlinx.coroutines.channels.ProduceKt.produce$default(Produce.kt:92)
    at io.ktor.http.cio.MultipartKt.parseMultipart(Multipart.kt:311)
    at io.ktor.http.cio.MultipartKt.parseMultipart(Multipart.kt:287)
    at io.ktor.http.cio.CIOMultipartDataBase.<init>(CIOMultipartData.kt:30)
    at io.ktor.http.cio.CIOMultipartDataBase.<init>(CIOMultipartData.kt:28)
    at io.ktor.server.engine.DefaultTransformKt.multiPartData(DefaultTransform.kt:99)
    at io.ktor.server.engine.DefaultTransformKt.access$multiPartData(DefaultTransform.kt:1)
    at io.ktor.server.engine.DefaultTransformKt$installDefaultTransformations$2.invokeSuspend(DefaultTransform.kt:50)
    at io.ktor.server.engine.DefaultTransformKt$installDefaultTransformations$2.invoke(DefaultTransform.kt)
    at io.ktor.util.pipeline.SuspendFunctionGun.loop(PipelineContext.kt:318)
    at io.ktor.util.pipeline.SuspendFunctionGun.proceed(PipelineContext.kt:163)
    at io.ktor.util.pipeline.SuspendFunctionGun.execute(PipelineContext.kt:183)
    at io.ktor.util.pipeline.Pipeline.execute(Pipeline.kt:27)
    at io.ktor.request.ApplicationReceiveFunctionsKt.receive(ApplicationReceiveFunctions.kt:110)
    at ServerKt$module$2$1.invokeSuspend(Server.kt:49)
    at ServerKt$module$2$1.invoke(Server.kt)
    at io.ktor.util.pipeline.SuspendFunctionGun.loop(PipelineContext.kt:318)
    at io.ktor.util.pipeline.SuspendFunctionGun.proceed(PipelineContext.kt:163)
    at io.ktor.util.pipeline.SuspendFunctionGun.execute(PipelineContext.kt:183)
    at io.ktor.util.pipeline.Pipeline.execute(Pipeline.kt:27)
    at io.ktor.routing.Routing.executeResult(Routing.kt:147)
    at io.ktor.routing.Routing.interceptor(Routing.kt:34)
    at io.ktor.routing.Routing$Feature$install$1.invokeSuspend(Routing.kt:99)
    at io.ktor.routing.Routing$Feature$install$1.invoke(Routing.kt)
    at io.ktor.util.pipeline.SuspendFunctionGun.loop(PipelineContext.kt:318)
    at io.ktor.util.pipeline.SuspendFunctionGun.proceed(PipelineContext.kt:163)
    at io.ktor.features.StatusPages$interceptCall$2.invokeSuspend(StatusPages.kt:101)
    at io.ktor.features.StatusPages$interceptCall$2.invoke(StatusPages.kt)
    at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturn(Undispatched.kt:91)
    at kotlinx.coroutines.CoroutineScopeKt.coroutineScope(CoroutineScope.kt:177)
    at io.ktor.features.StatusPages.interceptCall(StatusPages.kt:100)
    at io.ktor.features.StatusPages$Feature$install$2.invokeSuspend(StatusPages.kt:140)
    at io.ktor.features.StatusPages$Feature$install$2.invoke(StatusPages.kt)
    at io.ktor.util.pipeline.SuspendFunctionGun.loop(PipelineContext.kt:318)
    at io.ktor.util.pipeline.SuspendFunctionGun.proceed(PipelineContext.kt:163)
    at io.ktor.util.pipeline.SuspendFunctionGun.execute(PipelineContext.kt:183)
    at io.ktor.util.pipeline.Pipeline.execute(Pipeline.kt:27)
    at io.ktor.server.engine.DefaultEnginePipelineKt$defaultEnginePipeline$2.invokeSuspend(DefaultEnginePipeline.kt:120)
    at io.ktor.server.engine.DefaultEnginePipelineKt$defaultEnginePipeline$2.invoke(DefaultEnginePipeline.kt)
    at io.ktor.util.pipeline.SuspendFunctionGun.loop(PipelineContext.kt:318)
    at io.ktor.util.pipeline.SuspendFunctionGun.proceed(PipelineContext.kt:163)
    at io.ktor.util.pipeline.SuspendFunctionGun.execute(PipelineContext.kt:183)
    at io.ktor.util.pipeline.Pipeline.execute(Pipeline.kt:27)
    at io.ktor.server.cio.CIOApplicationEngine$startConnector$server$1$1.invokeSuspend(CIOApplicationEngine.kt:167)
    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
    at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:56)
    at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:571)
    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:738)
    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:678)
    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:665)

Also tested with Netty engine. She is more reasonable. Throws the same exception but the client receives the expected message 400, Can't recieve multipart.

It seems like the server is trying to fully read the request before responding.

Expected behavior I caught the IOException and responded accordingly. Why would the server try again and rise that exception again?

Expected behavior would be the client receiving 400, Can't recieve multipart and no error logs in the server.

e5l commented 4 years ago

Hi @Agcom, I managed to reproduce the problem. It looks like we have 2 issues here: one with the server logging and one with the freeze.

agcom commented 4 years ago

Hi @e5l Yes, and they should be related I believe (in this particular use case). Noticeable issues:

  1. CIO engine not responding
  2. The exception being logged, only after installing StatusPages (Netty, CIO).
  3. Netty engine, responding with 400, Can't recieve multipart, after a non caught exception (should do 500, Internal server error).

MultiPartData.readPart() documentation says:

Reads next part data or null if end of multipart stream encountered.

Then, instead of the exception, it should just return null.

  1. MultiPartData.readPart() throwing the exception

    • 1,2 and 3, are also pointing to a vulnerability in the send pipeline.
    • I also bumped into other issues related to multiparts (soon will submit em). I think the multipart API needs a polish.