okhttp icon indicating copy to clipboard operation
okhttp copied to clipboard

NullPointerException at okio.OutputStreamSink.write

Open Borutsky opened this issue 2 years ago • 7 comments

Getting a lot of crash reports from production app with the following stacktraces:

Variant 1

Fatal Exception: java.lang.NullPointerException:
       at okio.OutputStreamSink.write(OutputStreamSink.java:55)
       at okio.AsyncTimeout$sink$1.write(AsyncTimeout.kt:102)
       at okio.RealBufferedSink.flush(RealBufferedSink.kt:267)
       at okhttp3.internal.http1.Http1ExchangeCodec.finishRequest(Http1ExchangeCodec.kt:155)
       at okhttp3.internal.connection.Exchange.finishRequest(Exchange.java:95)
       at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.kt:79)
       at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
       at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:34)
       at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
       at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
       at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
       at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
       at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
       at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
       at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
       at io.sentry.android.okhttp.SentryOkHttpInterceptor.intercept(SentryOkHttpInterceptor.kt:101)
       at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
       at okhttp3.logging.HttpLoggingInterceptor.intercept(HttpLoggingInterceptor.kt:154)
       at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
       at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
       at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:517)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1137)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637)
       at java.lang.Thread.run(Thread.java:1012)

Variant 2

Fatal Exception: java.lang.NullPointerException:
       at okio.OutputStreamSink.write(OutputStreamSink.java:55)
       at okio.AsyncTimeout$sink$1.write(AsyncTimeout.kt:102)
       at okio.RealBufferedSink.emit(RealBufferedSink.kt:261)
       at okhttp3.internal.ws.WebSocketWriter.writeMessageFrame(WebSocketWriter.kt:195)
       at okhttp3.internal.ws.RealWebSocket.writeOneFrame$okhttp(RealWebSocket.kt:527)
       at okhttp3.internal.ws.RealWebSocket$WriterTask.runOnce(RealWebSocket.kt:620)
       at okhttp3.internal.concurrent.TaskRunner.runTask(TaskRunner.kt:116)
       at okhttp3.internal.concurrent.TaskRunner.access$runTask(TaskRunner.kt:42)
       at okhttp3.internal.concurrent.TaskRunner$runnable$1.run(TaskRunner.kt:65)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1137)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637)
       at java.lang.Thread.run(Thread.java:1012)

We're using multiple instances of OkHttpClient for different cases. Some of them passed to Retrofit to make REST API calls. Another is used for web sockets.

I'm happy to provide any additional information if needed

Borutsky avatar Nov 03 '23 14:11 Borutsky

Likely a duplicate of https://github.com/square/okhttp/issues/7212

Buffer and BufferedSink are not safe for concurrent use. If you want to use it from multiple dispatchers, you need a coordination mechanism like a lock.

Can you check you aren't using multiple threads to process a request.

yschimke avatar Nov 05 '23 11:11 yschimke

Likely a duplicate of #7212

Buffer and BufferedSink are not safe for concurrent use. If you want to use it from multiple dispatchers, you need a coordination mechanism like a lock.

Can you check you aren't using multiple threads to process a request.

I found some code in the project that changes coroutine context, then takes error body from retrofit2.Response and transforms it to string using string() method from okhttp3.ResponseBody. However, I couldn't reproduce the crash by running this code. Do you think it still can cause that exception to be thrown in some scenarios?

if (response.code() == HttpURLConnection.HTTP_NOT_ACCEPTABLE) {
            val json =  withContext(Dispatchers.IO) { gson.toJson(response.errorBody()?.string()) }
           ...
 }
if (response.isSuccessful) {
           return if (response.code() == HttpURLConnection.HTTP_NO_CONTENT) {
               throw ApiException(getString(R.string.no_content))
           } else {
               response.body()!!
           }
       } else {
           val error = withContext(Dispatchers.IO) { response.errorBody()?.string() }
           ...
}

Borutsky avatar Nov 07 '23 17:11 Borutsky

It's not clear from that code sample. If these can't be happening at the same time, then no. It's not an issue to change threads and the withContext(Dispatchers.IO) looks correct. It's only a problem to interact with the response on two different threads concurrently.

yschimke avatar Nov 08 '23 03:11 yschimke

I would also suggest you put a use(response) or response.close before throwing exceptions. You don't want to leave responses open.

yschimke avatar Nov 08 '23 03:11 yschimke

@yschimke I got rid of those Gson calls on different threads and as you assumed that wasn't root cause of the issue (still getting same crashes in the new build). I've just added more logs to Crashlytics to see what exact requests are being made before the app crashes and, hopefully, will get some useful information. In the meantime, I've spotted a crash that has the full stacktrace and could be related.

Non-fatal Exception: java.lang.ArrayIndexOutOfBoundsException: src.length=8192 srcPos=90 dst.length=12 dstPos=0 length=-78
       at java.lang.System.arraycopy(System.java:527)
       at kotlin.collections.ArraysKt___ArraysJvmKt.copyInto(_ArraysJvm.kt:1270)
       at okio.Buffer.read(Buffer.kt:1090)
       at okio.Buffer.readFully(Buffer.kt:1081)
       at okio.Buffer.readByteArray(Buffer.kt:1076)
       at okio.Buffer.readString(Buffer.kt:313)
       at okio.Buffer.readUtf8(Buffer.kt:297)
       at okhttp3.HttpUrl$Companion.canonicalize$okhttp(HttpUrl.java:1806)
       at okhttp3.HttpUrl$Companion.canonicalize$okhttp$default(HttpUrl.java:1771)
       at okhttp3.HttpUrl$Builder.addQueryParameter(HttpUrl.java:1056)
       at retrofit2.RequestBuilder.addQueryParam(RequestBuilder.java:200)
       at retrofit2.ParameterHandler$Query.apply(ParameterHandler.java:138)
       at retrofit2.ParameterHandler$2.apply(ParameterHandler.java:51)
       at retrofit2.RequestFactory.create(RequestFactory.java:129)
       at retrofit2.OkHttpCall.createRawCall(OkHttpCall.java:208)
       at retrofit2.OkHttpCall.enqueue(OkHttpCall.java:130)
       at retrofit2.KotlinExtensions.await(KotlinExtensions.java:36)
       at retrofit2.HttpServiceMethod$SuspendForBody.adapt(HttpServiceMethod.java:231)
       at retrofit2.HttpServiceMethod.invoke(HttpServiceMethod.java:146)
       at retrofit2.Retrofit$1.invoke(Retrofit.java:160)
       at java.lang.reflect.Proxy.invoke(Proxy.java:1006)
       at $Proxy5.g1()
       at com.my.package.repository.UserRepository.getCounts(UserRepository.kt:252)
       at com.my.package.ui.MainViewModel$getNotificationsCount$1.invokeSuspend(MainViewModel.kt:168)
       at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
       at kotlinx.coroutines.internal.DispatchedContinuationKt.resumeCancellableWith(DispatchedContinuation.kt:365)
       at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:30)
       at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable$default(Cancellable.kt:25)
       at kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:110)
       at kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.java:126)
       at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch(BuildersKt__Builders_common.kt:56)
       at kotlinx.coroutines.BuildersKt.launch(Builders.kt:1)
       at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch$default(BuildersKt__Builders_common.kt:47)
       at kotlinx.coroutines.BuildersKt.launch$default(Builders.kt:1)
       at com.my.package.ui.MainViewModel.getNotificationsCount(MainViewModel.kt:166)
       at com.my.package.ui.MainActivity.reinitializeNotificationsCountHandler(MainActivity.java:962)
       at com.my.package.ui.MainActivity.reinitializeNotificationsCountHandler$lambda$8(MainActivity.java:964)
       at android.os.Handler.handleCallback(Handler.java:942)
       at android.os.Handler.dispatchMessage(Handler.java:99)
       at android.os.Looper.loopOnce(Looper.java:226)
       at android.os.Looper.loop(Looper.java:313)
       at android.app.ActivityThread.main(ActivityThread.java:8762)
       at java.lang.reflect.Method.invoke(Method.java)
       at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:604)
       at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1067)

Here is the code:

viewModelScope.launch() {
    try {
        val response = userRepository.getCounts(ConnectionEventType.NOTIFICATION_COUNT)
            .filter { countsResponse ->
                countsResponse.event == ConnectionEventType.NOTIFICATION_COUNT.key
            }.sumOf { it.numberValue ?: 0 }
        _notificationsCount.value = response
    } catch (e: IOException) {
        ...
    }
}

UserRepository:

suspend fun getCounts(vararg eventTypes: ConnectionEventType): List<CountsResponse> {
        val eventTypesKeys = eventTypes.map { it.key }.toTypedArray()
        return coreApi.getCounts(eventTypesKeys)
}

CoreApi:

@GET("counts")
    suspend fun getCounts(@Query("events[]") events: Array<String>): List<CountsResponse>

Borutsky avatar Dec 04 '23 10:12 Borutsky

That stack trace is really weird. canonicalize allocates a buffer, and then it's failing with an index error.

Non-fatal Exception: java.lang.ArrayIndexOutOfBoundsException: src.length=8192 srcPos=90 dst.length=12 dstPos=0 length=-78
       at java.lang.System.arraycopy(System.java:527)
       at kotlin.collections.ArraysKt___ArraysJvmKt.copyInto(_ArraysJvm.kt:1270)
       at okio.Buffer.read(Buffer.kt:1090)
       at okio.Buffer.readFully(Buffer.kt:1081)
       at okio.Buffer.readByteArray(Buffer.kt:1076)
       at okio.Buffer.readString(Buffer.kt:313)
       at okio.Buffer.readUtf8(Buffer.kt:297)
       at okhttp3.HttpUrl$Companion.canonicalize$okhttp(HttpUrl.java:1806)

Not sure how this is possible, outside of some abuse of the okio Buffers, but not even sure how that would work.

yschimke avatar Jan 20 '24 12:01 yschimke

I saw another version today. Didn't find an exactly same one after searching through the issues, but there is a same one under an influxdb topic, here's the stack trace (Copied from here, since I was not allowed to copy logs from customer's server).

2021-02-11 02:53:53.774 [ERROR] [org.influxdb.impl.BatchProcessor    ] - Batch could not be sent. Data will be lost
java.lang.NullPointerException: null
	at okio.Segment.push(Segment.java:111) ~[bundleFile:?]
	at okio.Buffer.writableSegment(Buffer.java:1307) ~[bundleFile:?]
	at okio.Buffer.writeUtf8(Buffer.java:980) ~[bundleFile:?]
	at okio.Buffer.writeUtf8(Buffer.java:961) ~[bundleFile:?]
	at okio.RealBufferedSink.writeUtf8(RealBufferedSink.java:53) ~[bundleFile:?]
	at okhttp3.internal.http1.Http1ExchangeCodec.writeRequest(Http1ExchangeCodec.java:196) ~[bundleFile:?]
	at okhttp3.internal.http1.Http1ExchangeCodec.writeRequestHeaders(Http1ExchangeCodec.java:141) ~[bundleFile:?]
	at okhttp3.internal.connection.Exchange.writeRequestHeaders(Exchange.java:72) ~[bundleFile:?]
	at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:43) ~[bundleFile:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142) ~[bundleFile:?]
	at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:43) ~[bundleFile:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142) ~[bundleFile:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117) ~[bundleFile:?]
	at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:94) ~[bundleFile:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142) ~[bundleFile:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117) ~[bundleFile:?]
	at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93) ~[bundleFile:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142) ~[bundleFile:?]
	at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:88) ~[bundleFile:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142) ~[bundleFile:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117) ~[bundleFile:?]

wylswz avatar Feb 21 '24 10:02 wylswz