NullPointerException at okio.OutputStreamSink.write

[Borutsky]

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

[yschimke]

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.

[Borutsky]

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() }
            ...
 }

[yschimke]

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]

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

[Borutsky]

@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>

[yschimke]

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.

[wylswz]

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:?]