https://kotlinlang.org logo
Join Slack
Powered by
i have a question regarding uploading files using ...
# ktor
b
i have a question regarding uploading files using the Apache http client. i do a simple submitFormWithBinaryData (that's the code https://gist.github.com/bitkid/e49c12c63cc4277a6139d3992a16ecb8) in multiple upload coroutines and the weird thing is .. it never gets to the log message. on the server side i see that the server returns status code 409 (conflict) which is correct but it never makes it to that log line and it just blocks in that call. any ideas?
e
Hi @bitkid, could you install logging feature and show the output?
b
i init the client like this
Copy code
private val httpClient = HttpClient(Apache) {
        install(Auth) {
            basic {
                username = "bla"
                password = "blubb"
                sendWithoutRequest = true
            }
        }
        engine {
            customizeClient {
                connectTimeout = 0
                socketTimeout = 0
            }
        }
    }
e
b
sure .. cool. gimme 2 minutes
@e5l so one funny thing that happens .. when i init the logging with
Copy code
level = LogLevel.ALL
my integration tests immediately start to fail, but they work with LogLever.HEADERS
👀 1
LogLevel.INFO also works
e
It looks like a bug. Could you provide where it fails?
b
this is with log level=HEADERS which works
this is with log level=ALL
which failes
changing the log level is the only difference between these 2
ah sorry .. there are also the ktor server logs in there
let me remove them
e
What 
body
do you try to pass?
b
`
Copy code
2020-01-21 11:58:45.317 [DefaultDispatcher-worker-5 @coroutine#5] INFO  io.ktor.client.HttpClient - 

---7484af384037e9be-506970d9-67a2ebac-70592eff12f476f731ac94c4-5cf322841
Content-Disposition: form-data; name=file; file; name=scientific1; filename=scientific1.csv

"","counts","calc_data","calc_data_dim"
"ENSG00000000003",1e+05,6.44626,"log2tpm"
"ENSG00000000005",9,0.163499e+02,"log2tpm"
"ENSG00000000419",2931,5.86146,"log2tpm"

---7484af384037e9be-506970d9-67a2ebac-70592eff12f476f731ac94c4-5cf322841--


2020-01-21 11:58:45.317 [DefaultDispatcher-worker-2 @coroutine#6] INFO  io.ktor.client.HttpClient - BODY END
that's how the body is created https://gist.github.com/bitkid/e49c12c63cc4277a6139d3992a16ecb8 (the file is a .csv file)
the broken delimiter error log message from the server confuses me (it only happens when i use loglevel ALL)
e
It looks like form body doesn’t work well with logging, consumes the source twice and fail. Could you create an issue about?
b
ok!
does the consuming side look correct to you?
e
Yep
b
but back to my original question .. how can i find out why that call is not returning submitFormWithBinaryData without logging? 🙂
i can try with level=HEADER .. if that gives any information
e
Yep, could you show it headers?
b
ok that's weird .. that's all the output i get
Copy code
2020-01-21 12:37:33.731 [DefaultDispatcher-worker-1] INFO  io.ktor.client.HttpClient - REQUEST: <http://url/objectname>
2020-01-21 12:37:33.731 [DefaultDispatcher-worker-1] INFO  io.ktor.client.HttpClient - METHOD: HttpMethod(value=POST)
2020-01-21 12:37:33.732 [DefaultDispatcher-worker-1] INFO  io.ktor.client.HttpClient - COMMON HEADERS
2020-01-21 12:37:33.732 [DefaultDispatcher-worker-1] INFO  io.ktor.client.HttpClient - -> Authorization: Basic YWRtaW46YWRtaW4xMjM=
2020-01-21 12:37:33.732 [DefaultDispatcher-worker-1] INFO  io.ktor.client.HttpClient - -> Accept-Charset: UTF-8
2020-01-21 12:37:33.732 [DefaultDispatcher-worker-1] INFO  io.ktor.client.HttpClient - -> Accept: */*
2020-01-21 12:37:33.732 [DefaultDispatcher-worker-1] INFO  io.ktor.client.HttpClient - CONTENT HEADERS
and then it just stays there ... nothing more
does httpClient.submitFormWithBinaryData need an execute call or something like that?
e
Nope, it looks like they fail to send body
b
i see the request in the server logs
Copy code
file.inputStream().buffered().use
and then it.asInput() is correct?
👌 1
e
Could you file a github issue with reproducer?
b
i can't reproduce it in a unit/integration test .. that was my first try .. only when i let the whole thing run on our prod server
e
So next step is try to watch network request dump(from tool like wireshark) and clarify where is the problem in details
b
it's getting weirder and weirder ... i tried replacing the apache client with the jetty client (same code) and i see this weird exception .. which imho comes from the server, not the client 😮
Copy code
2020-01-21 14:31:32.774 [nioEventLoopGroup-4-3 @call-handler#34] ERROR Application - refCnt: 0, decrement: 1
io.netty.util.IllegalReferenceCountException: refCnt: 0, decrement: 1
	at io.netty.util.internal.ReferenceCountUpdater.toLiveRealRefCnt(ReferenceCountUpdater.java:74)
	at io.netty.util.internal.ReferenceCountUpdater.release(ReferenceCountUpdater.java:138)
	at io.netty.buffer.AbstractReferenceCountedByteBuf.release(AbstractReferenceCountedByteBuf.java:100)
	at io.netty.handler.codec.http.DefaultFullHttpRequest.release(DefaultFullHttpRequest.java:102)
	at io.netty.util.ReferenceCountUtil.release(ReferenceCountUtil.java:88)
	at io.ktor.server.netty.NettyApplicationCall.finishComplete(NettyApplicationCall.kt:51)
	at io.ktor.server.netty.NettyApplicationCall.finishSuspend(NettyApplicationCall.kt:44)
	at io.ktor.server.netty.NettyApplicationCall$finishSuspend$1.invokeSuspend(NettyApplicationCall.kt)
	(Coroutine boundary)
	at io.ktor.server.netty.NettyApplicationCallHandler$handleRequest$1.invokeSuspend(NettyApplicationCallHandler.kt:40)
Caused by: io.netty.util.IllegalReferenceCountException: refCnt: 0, decrement: 1
	at io.netty.util.internal.ReferenceCountUpdater.toLiveRealRefCnt(ReferenceCountUpdater.java:74)
	at io.netty.util.internal.ReferenceCountUpdater.release(ReferenceCountUpdater.java:138)
	at io.netty.buffer.AbstractReferenceCountedByteBuf.release(AbstractReferenceCountedByteBuf.java:100)
	at io.netty.handler.codec.http.DefaultFullHttpRequest.release(DefaultFullHttpRequest.java:102)
	at io.netty.util.ReferenceCountUtil.release(ReferenceCountUtil.java:88)
	at io.ktor.server.netty.NettyApplicationCall.finishComplete(NettyApplicationCall.kt:51)
	at io.ktor.server.netty.NettyApplicationCall.finishSuspend(NettyApplicationCall.kt:44)
	at io.ktor.server.netty.NettyApplicationCall$finishSuspend$1.invokeSuspend(NettyApplicationCall.kt)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:56)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:510)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:518)
	at io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1050)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:835)
@e5l i have no idea what that kind of error that is
i think i will switch back to 1.2.6 for the time being
ok downgrading to 1.2.6 works
but i see that as a personal defeat 😉
what i had to change was:
Copy code
httpClient.submitFormWithBinaryData<HttpResponse>
HttpResponse is in a different package .. and for the response i can use .use{} instead of .also{} (in 1.3.0) ... inputstream.asInput() seems to also be a different extension function in 1.3.0
this seems to match the 1.3.0 release notes
2 Views
Open in Slack
PreviousNext
Powered by