在网络调用后追踪 ConcurrentModificationException 的原因

Tracking down cause of ConcurrentModificationException after network call

我已经创建了一个 Android SDK,我听到有关抛出 ConcurrentModificationExceptions 的报告,但我一直无法在我的设备上复制。不总是这样吗!

发生异常的 logcat 如下所示:

11-01 11:13:11.277 22956 22988 D OpenGLRenderer: createReliableSurface : 0xbe861ec0, 0xec295000
11-01 11:13:11.278 22956 22988 D mali_winsys: EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, EGLBoolean) returns 0x3000
11-01 11:13:11.279  3293  3293 W WindowManager: removeWindowToken: Attempted to remove non-existing token: android.os.Binder@6c754b3
11-01 11:13:11.280  2843  9611 D tfa_container: [NXP] tfaContWriteFile: end
11-01 11:13:11.280  2843  9611 D tfa98xxApp: [NXP] tfa_setvolumestep: tfa set volume successful
11-01 11:13:11.280  2843  9611 D tfa98xxApp: [NXP] tfa_setvolumestep: end
11-01 11:13:11.280  2843  9611 D tfa_dsp : [NXP] tfa98xx_set_forced_start: set force by 0 [0xf]
11-01 11:13:11.281  2843  9611 D tfa_usrdrv: [NXP] tfa_show_status_device: /dev/i2c-20 0x34, device = 0, status = 0xd05e, WDS = 0, ACS = 0, CHSA = 2, DCA = 1, CHS12 = 3, SWS = 1, PLLS = 1, SBSL = 1, RCV = 0, INPLVL = 0, PWDN = 0, re0 = 0x1848 (6.0703 ohm)
11-01 11:13:11.281  2843  9611 D tfa98xxApp: [NXP] tfa_enable: end
11-01 11:13:11.281  2843  9611 V audio_hw_primary: start_output_stream-
11-01 11:13:11.283  3014 25269 I Camera3-Status: markComponent: Component 1 is now idle - RequestThread
11-01 11:13:11.285 22956 22956 E DecorView: mWindow.mActivityCurrentConfig is null
11-01 11:13:11.293  3293  4829 D WindowManager: finishDrawingWindow: Window{87b2f1c u0 com.mycode.demo/com.mycode.mysdk.main.UIActivity} mDrawState=DRAW_PENDING
11-01 11:13:11.294 22956 22956 D CameraViewModel: response here: 
11-01 11:13:11.296 22956 23255 W System.err: java.util.ConcurrentModificationException
11-01 11:13:11.297  3293  3332 I WindowManager: Reparenting to leash, surface=Surface(name=87b2f1c com.mycode.demo/com.mycode.mysdk.main.UIActivity)/@0xce0b0a1
11-01 11:13:11.298  2873  4356 I SurfaceFlinger: createSurf start. lock debugging [Surface(name=87b2f1c com.mycode.demo/com.mycode.mysdk.main.UIActivity)/@0xce0b0a1 - animation-leash]
11-01 11:13:11.298  2873  4356 I SurfaceFlinger: id=1211 createSurf (0x0),-1 flag=80004, Surface(name=87b2f1c com.mycode.demo/com.mycode.mysdk.main.UIActivity)/@0xce0b0a1 - animation-leash#0
11-01 11:13:11.298  3293  3332 D WindowManager: makeSurface duration=1 leash=Surface(name=Surface(name=87b2f1c com.mycode.demo/com.mycode.mysdk.main.UIActivity)/@0xce0b0a1 - animation-leash)/@0xf0272c6
11-01 11:13:11.298 22956 23255 W System.err:    at java.util.ArrayList$Itr.next(ArrayList.java:860)
11-01 11:13:11.298 22956 23255 W System.err:    at com.google.gson.internal.bind.CollectionTypeAdapterFactory$Adapter.write(CollectionTypeAdapterFactory.java:96)
11-01 11:13:11.298 22956 23255 W System.err:    at com.google.gson.internal.bind.CollectionTypeAdapterFactory$Adapter.write(CollectionTypeAdapterFactory.java:61)
11-01 11:13:11.299 22956 23255 W System.err:    at com.google.gson.internal.bind.TypeAdapterRuntimeTypeWrapper.write(TypeAdapterRuntimeTypeWrapper.java:69)
11-01 11:13:11.299 22956 23255 W System.err:    at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory.write(ReflectiveTypeAdapterFactory.java:127)
11-01 11:13:11.299 22956 23255 W System.err:    at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$Adapter.write(ReflectiveTypeAdapterFactory.java:245)
11-01 11:13:11.299 22956 23255 W System.err:    at retrofit2.converter.gson.GsonRequestBodyConverter.convert(GsonRequestBodyConverter.java:47)
11-01 11:13:11.299 22956 23255 W System.err:    at retrofit2.converter.gson.GsonRequestBodyConverter.convert(GsonRequestBodyConverter.java:30)
11-01 11:13:11.299  2873  4356 I SurfaceFlinger: createSurf start. lock debugging [Dim Layer for - Task=5150]
11-01 11:13:11.299 22956 23255 W System.err:    at retrofit2.ParameterHandler$Body.apply(ParameterHandler.java:429)
11-01 11:13:11.299 22956 23255 W System.err:    at retrofit2.RequestFactory.create(RequestFactory.java:129)
11-01 11:13:11.299 22956 23255 W System.err:    at retrofit2.OkHttpCall.createRawCall(OkHttpCall.java:208)
11-01 11:13:11.299  2873  4356 I SurfaceFlinger: id=1212 createSurf (0x0),-1 flag=24004, Dim Layer for - Task=5150#0
11-01 11:13:11.299 22956 23255 W System.err:    at retrofit2.OkHttpCall.enqueue(OkHttpCall.java:130)
11-01 11:13:11.299 22956 23255 W System.err:    at retrofit2.KotlinExtensions.await(KotlinExtensions.kt:36)
11-01 11:13:11.299 22956 23255 W System.err:    at retrofit2.HttpServiceMethod$SuspendForBody.adapt(HttpServiceMethod.java:231)
11-01 11:13:11.299 22956 23255 W System.err:    at retrofit2.HttpServiceMethod.invoke(HttpServiceMethod.java:146)
11-01 11:13:11.299 22956 23255 W System.err:    at retrofit2.Retrofit.invoke(Retrofit.java:160)
11-01 11:13:11.299 22956 23255 W System.err:    at java.lang.reflect.Proxy.invoke(Proxy.java:1006)
11-01 11:13:11.299 22956 23255 W System.err:    at $Proxy1.postPartialMeasurementResults(Unknown Source)
11-01 11:13:11.299 22956 23255 W System.err:    at com.mycode.mysdk.data.repository.measurement.retrofit.RetrofitMeasurementsDataRepository$postPartialMeasurementResults.invokeSuspend(RetrofitMeasurementsDataRepository.kt:21)
11-01 11:13:11.300 22956 23255 W System.err:    at com.mycode.mysdk.data.repository.measurement.retrofit.RetrofitMeasurementsDataRepository$postPartialMeasurementResults.invoke(Unknown Source:8)
11-01 11:13:11.300 22956 23255 W System.err:    at com.mycode.mysdk.data.repository.measurement.retrofit.RetrofitMeasurementsDataRepository$postPartialMeasurementResults.invoke(Unknown Source:2)
11-01 11:13:11.300 22956 23255 W System.err:    at com.mycode.mysdk.data.network.datasource.NetworkDataSource.getResult$suspendImpl(NetworkDataSource.kt:16)
11-01 11:13:11.300 22956 23255 W System.err:    at com.mycode.mysdk.data.network.datasource.NetworkDataSource.getResult(Unknown Source:0)
11-01 11:13:11.300 22956 23255 W System.err:    at com.mycode.mysdk.data.repository.measurement.retrofit.RetrofitMeasurementsDataRepository.postPartialMeasurementResults(RetrofitMeasurementsDataRepository.kt:20)
11-01 11:13:11.300 22956 23255 W System.err:    at com.mycode.mysdk.data.repository.measurement.MeasurementsRepository$sendPartialMeasurements.invokeSuspend(MeasurementsRepository.kt:39)
11-01 11:13:11.300 22956 23255 W System.err:    at com.mycode.mysdk.data.repository.measurement.MeasurementsRepository$sendPartialMeasurements.invoke(Unknown Source:8)
11-01 11:13:11.300  2861 25701 I ExynosCameraMCPipe: [CAM_ID(1)][PIPE_3AA]-INFO(m_getBuffer[2254]):InternalFrame(5) frameCount(1230)                    : captureNodeCount == 0 || checkRet(0) != NO_ERROR.                    so, setFrameState(FRAME_STATE_SKIPPED)
11-01 11:13:11.302 22956 23255 W System.err:    at com.mycode.mysdk.data.repository.measurement.MeasurementsRepository$sendPartialMeasurements.invoke(Unknown Source:4)
11-01 11:13:11.302 22956 23255 W System.err:    at kotlinx.coroutines.flow.SafeFlow.collectSafely(Builders.kt:61)
11-01 11:13:11.302 22956 23255 W System.err:    at kotlinx.coroutines.flow.AbstractFlow.collect(Flow.kt:212)
11-01 11:13:11.302 22956 23255 W System.err:    at kotlinx.coroutines.flow.internal.ChannelFlowOperatorImpl.flowCollect(ChannelFlow.kt:207)
11-01 11:13:11.302  2870  2963 D AudioFlinger: mixer(0xe76d4500) Spend too much time to write: delta 220(effect 1, stage 0)
11-01 11:13:11.302  2870  2963 I SoundAlive_SRC384 arch32: SRC384 Destroy
11-01 11:13:11.302 22956 23255 W System.err:    at kotlinx.coroutines.flow.internal.ChannelFlowOperator.collectTo$suspendImpl(ChannelFlow.kt:169)
11-01 11:13:11.302  2870  2963 I SoundAlive_SRC384 arch32: ~SoundAlive_SRC384() 
11-01 11:13:11.302 22956 23255 W System.err:    at kotlinx.coroutines.flow.internal.ChannelFlowOperator.collectTo(Unknown Source:0)
11-01 11:13:11.302 22956 23255 W System.err:    at kotlinx.coroutines.flow.internal.ChannelFlow$collectToFun.invokeSuspend(ChannelFlow.kt:60)
11-01 11:13:11.302 22956 23255 W System.err:    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
11-01 11:13:11.302 22956 23255 W System.err:    at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
11-01 11:13:11.302 22956 23255 W System.err:    at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:571)
11-01 11:13:11.303 22956 23255 W System.err:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:738)
11-01 11:13:11.303 22956 23255 W System.err:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:678)
11-01 11:13:11.303 22956 23255 W System.err:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:665)
11-01 11:13:11.303  3293  3332 I WindowManager: Reparenting to leash, surface=Surface(name=Dim Layer for - Task=5150)/@0xe276287
11-01 11:13:11.304  2873  2944 I SurfaceFlinger: createSurf start. lock debugging [Surface(name=Dim Layer for - Task=5150)/@0xe276287 - animation-leash]
11-01 11:13:11.304  2873  2944 I SurfaceFlinger: id=1213 createSurf (0x0),-1 flag=80004, Surface(name=Dim Layer for - Task=5150)/@0xe276287 - animation-leash#0
11-01 11:13:11.304  3293  3332 D WindowManager: makeSurface duration=1 leash=Surface(name=Surface(name=Dim Layer for - Task=5150)/@0xe276287 - animation-leash)/@0x23445b4
11-01 11:13:11.311  3293  4829 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.sendBroadcast:1087 com.android.server.notification.DisplayToast.sendIntentForToastDumpLog:156 com.android.server.notification.DisplayToast.outFile:106 com.android.server.notification.DisplayToast.out:62 com.android.server.notification.NotificationManagerService.enqueueToastForLog:2664 
11-01 11:13:11.312  2873  2944 I SurfaceFlinger: createSurf start. lock debugging [WindowToken{122f552 android.os.Binder@ab6b5dd}]
11-01 11:13:11.312  2873  2944 I SurfaceFlinger: id=1214 createSurf (0x0),-1 flag=80004, WindowToken{122f552 android.os.Binder@ab6b5dd}#0
11-01 11:13:11.315 22956 22956 E Response: Response(...redacted...)

我很感激这个日志中有很多内容,但据我所知,CameraViewModel 从 API (CameraViewModel: response here: ) 获得响应,然后发生 ConcurrentModificationException,最后响应是实际记录 (Response: Response(...redacted...)).

任何人都可以帮助我了解我在这些日志中看到的其他内容吗?是否有关于可能导致异常的原因或可能发生的位置的任何线索?我知道在迭代时修改列表时会抛出它,但我看不到任何可能的情况。任何线索将不胜感激。

编辑

RetrofitMeasurementsDataRepository.kt:21 处的代码是:

    override suspend fun postResults(data: Data): RequestResult<Response?> {
        return networkDataSource.getResult {
            api.postResults(data)
        }
    }

此处的响应以某种方式(?)触发:

    private fun handleResult() {
        lifecycleOwner.lifecycleScope.launch {
            viewModel.getResponse(
                entries
            ).collect {
                it?.let {
                    listener.onResultReceived(it)
                }
            }
        }
    }

这里调用的函数如下所示:

    fun getResponse(data: Data): Flow<Result?> {
        return repository.send(data).map {
            Log.d(TAG, "partial response here: ")
            entries.clear()
        }
    }

可能 entries.clear() 在 gson 仍在另一个线程中处理它时被调用。在这里看起来像是竞争条件,这就是为什么它并不总是可重现的原因。我建议将 entries 的副本传递给改造而不是您正在修改的原始对象。

我认为 entries.clear() 是一个主要的危险信号,因为您正在并行处理一些事情。如果您在线程之间传递集合,请避免使用可变集合,并且如果您确实使用可变集合,则无论何时使用它们都必须同步某些内容。 ConcurrentModificationException 如果两个线程同时修改同一个集合,或者如果一个线程正在修改它而另一个线程正在迭代它。