Enabling face or iris unlock triggers log spam and high CPU usage

[HypermagiK]

Hi,

I am running stock N960FXXS3CSG1 AP firmware on a relatively fresh factory reset Exynos-based Note 9 device and I observed that when either face or iris is enabled as screen lock type, SystemUI is continuously generating warning logs as long as the screen is on. This can be seen by connecting the phone to a PC and running 'adb logcat' after enabling USB debugging or by using apps like CatLog. The warning logs are generated even if the phone is unlocked using the fingerprint sensor, without even showing the lock screen. I am not using any themes. 

The lines that are continuously written to the log by the SystemUI process are:

07-20 11:24:58.157 5439 5439 W View : requestLayout() improperly called by com.android.keyguard.biometric.KeyguardBiometricSmallIconView{c777788 V.E...... ......ID 0,84-1440,217 #7f0a0273 app:id/keyguard_iris_text_preview} during layout: running second layout pass
07-20 11:24:58.157 5439 5439 I ViewRootImpl@1208c5[StatusBar]: requestLayout is already in process
07-20 11:24:58.157 5439 5439 I ViewRootImpl@1208c5[StatusBar]: requestLayoutDuringLayout is already in process
07-20 11:24:58.157 5439 5439 I ViewRootImpl@1208c5[StatusBar]: requestLayoutDuringLayout is already in process
07-20 11:24:58.159 5439 5439 W View : requestLayout() improperly called by com.android.systemui.statusbar.phone.NotificationPanelView{5a9da25 V.E...... ........ 0,0-1440,2960 #7f0a0387 app:id/notification_panel} during second layout pass: posting in next frame
07-20 11:24:58.159 5439 5439 W View : requestLayout() improperly called by com.android.keyguard.biometric.KeyguardBiometricSmallIconView{c777788 V.E...... ........ 0,84-1440,217 #7f0a0273 app:id/keyguard_iris_text_preview} during second layout pass: posting in next frame

This behavior causes high CPU usage and battery drain when either iris or face unlock is enabled.

Here is a snapshot of top running after the phone was unlocked, with face unlock enabled:

800%cpu  80%user   7%nice 104%sys 608%idle   0%iow   0%irq   0%sirq   0%host

  PID USER         PR  NI VIRT  RES  SHR S[%CPU] %MEM     TIME+ ARGS
 5439 u0_a8        20   0 4.9G 380M 300M S 74.3   6.7   8:16.99 com.android.systemui
 4388 system       12  -8 3.0G  45M  37M S 31.6   0.7   5:07.57 surfaceflinger
 4261 logd         30  10  21M 4.7M 2.7M S 18.3   0.0   4:04.49 logd
 4366 system       20   0 166M 5.0M 4.3M S 16.0   0.0   2:03.32 android.hardware.graphics.composer@2.2-service
 2259 root         RT   0    0    0    0 S 11.0   0.0   2:49.27 [decon0]
20277 root         20   0    0    0    0 S  7.0   0.0   0:06.64 [kworker/0:0]
20228 root          0 -20    0    0    0 S  6.6   0.0   0:02.47 [kworker/u17:1]
15695 root          0 -20    0    0    0 S  6.0   0.0   0:19.06 [kworker/u17:4]
 4931 system       18  -2 5.4G 429M 318M S  5.6   7.6  32:10.51 system_server
21346 shell        20   0  12M 5.1M 3.9M R  3.6   0.0   0:00.35 top

This is how it looks when face and iris unlock are disabled (phone was restarted so different pids):

800%cpu  10%user   2%nice   9%sys 778%idle   0%iow   0%irq   0%sirq   0%host

  PID USER         PR  NI VIRT  RES  SHR S[%CPU] %MEM     TIME+ ARGS
 4927 system       18  -2 5.2G 502M 400M S 11.0   8.9   5:07.68 system_server
17742 shell        20   0  12M 5.0M 3.8M R  3.3   0.0   0:00.33 top
17650 root         20   0    0    0    0 S  1.6   0.0   0:01.89 [kworker/0:2]
 4569 wifi         20   0  19M 5.8M 5.5M S  1.6   0.1   0:08.97 wificond
 6128 u0_a15       20   0 3.7G 138M 120M S  1.0   2.4   0:12.86 android.process.acore
 6414 system       20   0 3.7G 132M 118M S  0.6   2.3   0:26.58 com.sec.android.sdhms
 4532 system       20   0  11M 3.3M 3.2M S  0.6   0.0   0:10.69 argosd
    7 root         20   0    0    0    0 S  0.6   0.0   0:09.04 [rcu_preempt]
 5406 u0_a8        20   0 4.5G 358M 286M S  0.3   6.3   0:42.20 com.android.systemui

Here is the logcat output for pid/tid 5439 (com.android.systemui), starting from when the power button was pressed, with face unlock enabled:
https://pastebin.com/zX77zHW8

The messages at the end keep repeating until the screen is turned off.

Here is the logcat output with face unlock disabled:
https://pastebin.com/1An2X6TJ

Has anyone else seen this behavior or knows how to get rid of these messages and make face and iris unlock usable again?

Thanks!

[BandOfBrothers]

I haven't gone to the lengths you have in regards to the logs @HypermagiK 

I'm using a Note 9 purchased directly from Samsung which is from launch day.

I typically get 3+ days usage and iris and facial recognition is On.

I'd suggest to use a Samsung Experience Store or Samsung Service Centre for them to run a diagnostic.

[HypermagiK]

Constant high CPU usage affects more than just battery life. It causes the phone to heat up more while the screen is on. The overall performance of the device is also affected as 2 out of the 8 cores are always busy crunching logs and refreshing the screen (you can see that idle time is only 600% out of the total 800% cpu time available).

According to this discussion on reddit, GPU performance is almost halved when face or iris unlock is enabled due to this issue:

https://www.reddit.com/r/GalaxyNote9/comments/chdl3j/disabling_face_unlock_improve_gpu_benchmark_by_...

In this discussion, more users confirmed that this issue exists on the Exynos-based Note 9 and also on the S9, all running the latest July firmware. Turning off face and iris unlock improves UI responsiveness, gaming performance and benchmark results.

[Alex_ArchQuest]

I have this exact same issue on my Samsung Galaxy S9 with an exynos5.
I started some Android app development yesterday and as I was troubleshooting with adb logcat I saw some extreme spam of these same messages and it was really hard to find the lines that were relevant for me.

I decided to search for the messages I was seeing being spammed and I ended up here and found your reddit threads. Great detective work! I have now disabled the intelligent scan, face scan and iris scan and I no longer see the spam with these messages.

I have also been a bit disappointed with the battery life of my device recently... Hopefully this will fix that but I would love to use the Face/Iris scan feature without killing the battery and performance of my phone.

[pemell]

Good find. This is a terrible bug and should be prioritized.

[h0tk3y]

I've encountered this behavior, too. Disabled face/iris unlock for now. I double the request for fixing this.

[HaukeRa]

Also flooding the logs on my Galaxy S9+, this needs a fix!

[TheChrisGlass]

Yeah. I'm getting this too. It disappeared once I unregistered my face and iris and rebooted.