ANR using scope in WearableListenerService

[akrulec]

If I use this similar sample adding a scope in WearableListenerService causes the Wear OS Small API Round API 30 to ANR after 56 seconds. Removing having the scope, removes the ANR.

https://github.com/android/wear-os-samples/blob/7ab9ef187bd02f167797c0d510b566b5c58e4f23/DataLayer/Wearable/src/main/java/com/example/android/wearable/datalayer/DataLayerListenerService.kt#L47

Error I see:

ANR in com.myxxx.xxxapp
PID: 7209
Reason: executing service com.myxxx.xxxapp/.wearOs.database.service.WearableDataService
Load: 0.05 / 0.24 / 0.44
----- Output from /proc/pressure/memory -----
some avg10=0.00 avg60=0.00 avg300=0.00 total=2036194
full avg10=0.00 avg60=0.00 avg300=0.00 total=578656
----- End output from /proc/pressure/memory -----

CPU usage from 153639ms to 0ms ago (2023-02-23 10:41:56.315 to 2023-02-23 10:44:29.954):
  5.7% 248/android.hardware.bluetooth@1.1-service.sim: 0.1% user + 5.6% kernel
  1.7% 257/android.hardware.graphics.composer@2.3-service: 0% user + 1.6% kernel
  1.2% 332/adbd: 0.1% user + 1.1% kernel / faults: 4182 minor
  0.8% 502/system_server: 0.3% user + 0.4% kernel / faults: 2777 minor
  0.8% 7209/com.myxxx.xxxapp: 0.3% user + 0.4% kernel / faults: 1732 minor
  0.7% 4462/com.google.android.wearable.healthservices: 0.3% user + 0.4% kernel / faults: 4738 minor
  0.4% 1920/kworker/u8:3-events_unbound: 0% user + 0.4% kernel
  0.3% 10/rcu_preempt: 0% user + 0.3% kernel
  0.3% 98/kworker/u8:1-events_unbound: 0% user + 0.3% kernel
  0.3% 6966/kworker/u8:0-events_unbound: 0% user + 0.3% kernel
  0.3% 277/android.hardware.sensors@2.1-service.multihal: 0% user + 0.3% kernel
  0.2% 21/ksoftirqd/2: 0% user + 0.2% kernel
  0.2% 9/ksoftirqd/0: 0% user + 0.2% kernel
  0.1% 16/ksoftirqd/1: 0% user + 0.1% kernel
  0.1% 877/com.google.android.gms.persistent: 0% user + 0% kernel / faults: 800 minor
  0.1% 26/ksoftirqd/3: 0% user + 0.1% kernel
  0.1% 1521/com.google.android.inputmethod.latin: 0% user + 0% kernel / faults: 1 minor
  0% 286/android.hardware.wifi@1.0-service: 0% user + 0% kernel
  0% 159/logd: 0% user + 0% kernel / faults: 3 minor
  0% 206/android.system.suspend@1.0-service: 0% user + 0% kernel
  0% 235/statsd: 0% user + 0% kernel / faults: 11 minor
  0% 986/android.hardware.gnss@2.0-service.ranchu: 0% user + 0% kernel
  0% 158/kworker/1:2-ipv6_addrconf: 0% user + 0% kernel
  0% 202/jbd2/dm-4-8: 0% user + 0% kernel
  0% 161/servicemanager: 0% user + 0% kernel
  0% 236/netd: 0% user + 0% kernel / faults: 2 minor
  0% 1697/com.google.android.wearable.app: 0% user + 0% kernel / faults: 29 minor
  0% 2369/com.google.android.gms.unstable: 0% user + 0% kernel / faults: 344 minor 2 major
  0% 6185/com.android.vending: 0% user + 0% kernel / faults: 2 minor
  0% 147/ueventd: 0% user + 0% kernel
  0% 380/wificond: 0% user + 0% kernel
  0% 126/kworker/0:3-memcg_kmem_cache: 0% user + 0% kernel
  0% 472/hostapd_nohidl: 0% user + 0% kernel
  0% 780/com.android.bluetooth: 0% user + 0% kernel / faults: 4 minor
  0% 790/com.google.android.wearable.sysui: 0% user + 0% kernel / faults: 10 minor
  0% 2139/androidx.wear.watchface.samples.app: 0% user + 0% kernel / faults: 23 minor
  0% 5901/kworker/3:0-sock_diag_events: 0% user + 0% kernel
  0% 7065/kworker/2:2-mm_percpu_wq: 0% user + 0% kernel
  0% 11/migration/0: 0% user + 0% kernel
  0% 20/migration/2: 0% user + 0% kernel
  0% 25/migration/3: 0% user + 0% kernel
  0% 160/lmkd: 0% user + 0% kernel
  0% 163/hwservicemanager: 0% user + 0% kernel
  0% 171/qemu-props: 0% user + 0% kernel
  0% 258/android.hardware.health@2.1-service: 0% user + 0% kernel
  0% 305/surfaceflinger: 0% user + 0% kernel
  0% 345/logcat: 0% user + 0% kernel
  0% 361/traced: 0% user + 0% kernel
  0% 383/libgoldfish-rild: 0% user + 0% kernel
  0% 400/android.hardware.biometrics.fingerprint@2.1-service: 0% user + 0% kernel
  0% 444/wifi_forwarder: 0% user + 0% kernel
  0% 449/logcat: 0% user + 0% kernel
  0% 776/wpa_supplicant: 0% user + 0% kernel
  0% 1048/com.android.phone: 0% user + 0% kernel
  0% 7247/logcat: 0% user + 0% kernel
1.2% TOTAL: 0.3% user + 0.9% kernel + 0% iowait + 0% softirq
CPU usage from 16ms to 358ms later (2023-02-23 10:44:29.970 to 2023-02-23 10:44:30.312):
  46% 502/system_server: 16% user + 30% kernel / faults: 431 minor
    26% 7762/AnrConsumer: 3.3% user + 23% kernel
    13% 512/HeapTaskDaemon: 13% user + 0% kernel

My code:

class WearableDataService : WearableListenerService() {
    private val scope = CoroutineScope(SupervisorJob() + Dispatchers.IO)

    private val dataServiceRepository: DataServiceRepository by inject()
    private val healthServicesRepository: HealthServicesRepository by inject()

    override fun onDataChanged(dataEvents: DataEventBuffer) {
        super.onDataChanged(dataEvents)

        Timber.d("$dataEvents")
        dataEvents.forEach { dataEvent ->
            val uri = dataEvent.dataItem.uri
            Timber.e("$dataEvent : $uri")
            when (uri.path) {
                WORKOUT_STATUS_PATH -> {
                    val item = DataMapItem.fromDataItem(dataEvent.dataItem)
                    item.dataMap.getByteArray(WORKOUT_STATUS_DATA)?.let {
                        it.toWorkoutStatusUpdate().let { workoutStatusUpdate ->
                            Timber.d("Received: $uri $workoutStatusUpdate")

                            scope.launch {
                                dataServiceRepository.setWorkoutStatusUpdate(workoutStatusUpdate)
                                if (workoutStatusUpdate.workoutStartTimeMs > 0) {
                                    healthServicesRepository.setSessionStartTime(
                                        workoutStatusUpdate.workoutStartTimeMs)
                                }
                            }
                        }
                    }
                }
            }
        }
    }

    override fun onMessageReceived(messageEvent: MessageEvent) {
        super.onMessageReceived(messageEvent)

        when (messageEvent.path) {
            START_ACTIVITY_PATH -> {
                Timber.d("Received: ${messageEvent.path}")
                startActivity(
                    Intent(this, MainActivity::class.java).addFlags(
                        // Keep this as is. Make sure to clear other tasks, and only keep one
                        // going.
                        Intent.FLAG_ACTIVITY_NEW_TASK or Intent.FLAG_ACTIVITY_CLEAR_TASK
                    or Intent.FLAG_ACTIVITY_SINGLE_TOP))
            }
            WORKOUT_STATUS_PATH -> {
                messageEvent.data.let {
                    it.toWorkoutStatusUpdate().let { workoutStatusUpdate ->
                        Timber.d("Received: ${messageEvent.path} $workoutStatusUpdate")

                        scope.launch {
                            dataServiceRepository.setWorkoutStatusUpdate(workoutStatusUpdate)
                            if (workoutStatusUpdate.workoutStartTimeMs > 0) {
                                healthServicesRepository.setSessionStartTime(
                                    workoutStatusUpdate.workoutStartTimeMs
                                )
                            }
                        }
                    }
                }
            }
        }
    }

    override fun onDestroy() {
        Timber.d("onDestroy")
        super.onDestroy()
        scope.cancel()
    }

    companion object {
        private const val START_ACTIVITY_PATH = "/start-activity"
        private const val WORKOUT_STATUS_PATH = "/workout-status"
        private const val WORKOUT_STATUS_DATA = "/workout_status_data"
        private const val WORKOUT_STATS_DATA_MESSAGE_PATH = "/workout_stats_data"
    }
}

Thank you

[yschimke]

This project isn't an active support forum for general wear problems. If it's a problem with the sample then it's a different matter.

You might get an answer, but I can't guarantee who will look at it and when.

If you think its a real bug you should file a bug report on the wear project.

If you think its just incorrect usage, maybe stackoverflow.

[yschimke]

It's probably a bug in the sample, but passing because it's using Dispatchers.Main.immediate

I don't think it's safe to process incoming data events in WearableListenerService by launching on a scope that is destroyed when the service exits.

The onDataChanged should complete the work, or alternatively schedule the work for later, with work manager or a forground service.