search

Genymobile / scrcpy

Display and control your Android device
Apache License 2.0
112.62k stars 10.77k forks source link

device crash or freeze when the display is turned off #5379

Open alberanid opened 1 month ago

alberanid commented 1 month ago

Environment

Describe the bug

The device crashes when the screen is turned off. Sometimes it will reboot, sometimes it will freeze.

It seems similar to #5121 but the log is not quite the same.

Logcat on the device:

10-15 13:44:59.759   564   600 I PowerManagerService: Going to sleep due to timeout (uid 1000)...
10-15 13:44:59.760   564   564 W UsageStatsService: Event reported without a package name, eventType:16
10-15 13:44:59.763   564   600 I PowerManagerService: Sleeping (uid 1000)...
10-15 13:44:59.767   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.768   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.788   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.788   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.801   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.801   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.819   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.819   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.832   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.832   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.843   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.843   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.857   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.857   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.872   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.872   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.888   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.889   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.899   348  2046 I mpp_enc : send header for codec/prep cfg change
10-15 13:44:59.899   348  2045 I vpu_api_legacy: setup encoder rate control config:
10-15 13:44:59.899   348  2045 I vpu_api_legacy: width 1280 height  800 format 10:0
10-15 13:44:59.899   348  2045 I vpu_api_legacy: rc_mode CBR qp 26 bps 8000000
10-15 13:44:59.899   348  2045 I vpu_api_legacy: fps in 60 fps out 60 gop 599
10-15 13:44:59.899   348  2045 I vpu_api_legacy: setup encoder stream feature config:
10-15 13:44:59.899   348  2045 I vpu_api_legacy: profile 66 level 31 cabac 0
10-15 13:44:59.900   348  2046 I h264e_sps: set level to 3.2
10-15 13:44:59.900   564   600 V DisplayPowerController: Brightness [120] reason changing to: 'manual', previous reason: 'manual [ dim ]'.
10-15 13:44:59.903   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.903   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.914   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.914   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.928   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.928   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.937   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.938   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:44:59.951   564   591 E memtrack: Couldn't load memtrack module
10-15 13:44:59.952   564   591 W android.os.Debug: failed to get memory consumption info: -1
10-15 13:45:00.006   722   722 D KeyguardClockSwitch: Updating clock: 1:45 PM
10-15 13:45:00.020   348  2046 I mpp_enc : send header for codec/prep cfg change
10-15 13:45:00.021   348  2045 I vpu_api_legacy: setup encoder rate control config:
10-15 13:45:00.022   348  2045 I vpu_api_legacy: width 1280 height  800 format 10:0
10-15 13:45:00.022   348  2045 I vpu_api_legacy: rc_mode CBR qp 26 bps 8000000
10-15 13:45:00.022   348  2045 I vpu_api_legacy: fps in 60 fps out 60 gop 599
10-15 13:45:00.022   348  2045 I vpu_api_legacy: setup encoder stream feature config:
10-15 13:45:00.022   348  2045 I vpu_api_legacy: profile 66 level 31 cabac 0
10-15 13:45:00.023   348  2046 I h264e_sps: set level to 3.2
10-15 13:45:00.149   348  2046 I mpp_enc : send header for codec/prep cfg change
10-15 13:45:00.149   348  2045 I vpu_api_legacy: setup encoder rate control config:
10-15 13:45:00.149   348  2045 I vpu_api_legacy: width 1280 height  800 format 10:0
10-15 13:45:00.150   348  2045 I vpu_api_legacy: rc_mode CBR qp 26 bps 8000000
10-15 13:45:00.150   348  2045 I vpu_api_legacy: fps in 60 fps out 60 gop 599
10-15 13:45:00.150   348  2045 I vpu_api_legacy: setup encoder stream feature config:
10-15 13:45:00.150   348  2045 I vpu_api_legacy: profile 66 level 31 cabac 0
10-15 13:45:00.150   348  2046 I h264e_sps: set level to 3.2
10-15 13:45:00.270   348  2046 I mpp_enc : send header for codec/prep cfg change
10-15 13:45:00.270   348  2045 I vpu_api_legacy: setup encoder rate control config:
10-15 13:45:00.270   348  2045 I vpu_api_legacy: width 1280 height  800 format 10:0
10-15 13:45:00.270   348  2045 I vpu_api_legacy: rc_mode CBR qp 26 bps 8000000
10-15 13:45:00.270   348  2045 I vpu_api_legacy: fps in 60 fps out 60 gop 599
10-15 13:45:00.270   348  2045 I vpu_api_legacy: setup encoder stream feature config:
10-15 13:45:00.270   348  2045 I vpu_api_legacy: profile 66 level 31 cabac 0
10-15 13:45:00.271   348  2046 I h264e_sps: set level to 3.2
10-15 13:45:00.322   564   600 I DisplayPowerController: Blocking screen off
10-15 13:45:00.322   564   600 I DisplayPowerController: Unblocked screen off after 1 ms
10-15 13:45:00.323   564   600 D ActivityTaskManager: Top Process State changed to PROCESS_STATE_TOP_SLEEPING
10-15 13:45:00.338   278   278 I SensorsHal: set active: handle = 0, enable = 0
10-15 13:45:00.346   278   278 I SensorsHal: set batch: handle = 3, period_ns = 200000000ns, timeout = 0ns
10-15 13:45:00.349   564   600 E Surface : getSlotFromBufferLocked: unknown buffer: 0x71cfe9f180
10-15 13:45:00.349   564   600 E IMGSRV  : android_ws.c:479: QueueCancelBufferWrapper: Failed to cancel buffer 0x7214d40410 (-22)
10-15 13:45:00.351   564   600 V DisplayPowerController: Brightness [0] reason changing to: 'screen_off', previous reason: 'manual'.
10-15 13:45:00.358   202   202 D SurfaceFlinger: Setting power mode 0 on display 0
10-15 13:45:00.364   564   586 I DisplayManagerService: Display device changed state: "Built-in Screen", OFF
10-15 13:45:00.451   348  2046 I mpp_enc : send header for codec/prep cfg change
10-15 13:45:00.451   348  2045 I vpu_api_legacy: setup encoder rate control config:
10-15 13:45:00.452   348  2045 I vpu_api_legacy: width 1280 height  800 format 10:0
10-15 13:45:00.452   348  2045 I vpu_api_legacy: rc_mode CBR qp 26 bps 8000000
10-15 13:45:00.452   348  2045 I vpu_api_legacy: fps in 60 fps out 60 gop 599
10-15 13:45:00.452   348  2045 I vpu_api_legacy: setup encoder stream feature config:
10-15 13:45:00.452   348  2045 I vpu_api_legacy: profile 66 level 31 cabac 0
10-15 13:45:00.452   348  2046 I h264e_sps: set level to 3.2
10-15 13:45:00.500   202   202 D SurfaceFlinger: Finished setting power mode 0 on display 0
10-15 13:45:00.501   564   694 D SurfaceControl: Excessive delay in setPowerMode()
10-15 13:45:00.512   564   663 E WifiClientModeImpl: getWifiLinkLayerStats called without an interface
10-15 13:45:00.516   265   316 D AudioHardwareTiny: adev_set_parameters: kvpairs = screen_state=off

dmesg output on the device:

[  840.367044] rockchip-vop ff930000.vop: [drm:vop_crtc_atomic_enable] Update mode to 800x1280p60, type: 16
[  840.368336] dw-mipi-dsi ff960000.dsi: [drm:dw_mipi_dsi_encoder_enable] final DSI-Link bandwidth: 450 x 4 Mbps
[  840.375644] binder_alloc: 1609: binder_alloc_buf, no vma
[  840.375673] binder: 567:589 transaction failed 29189/-3, size 120-0 line 3228
[  840.393495] gsensor_mxc6655 3-0015: set sensor poll time to 66ms
[  840.394806] gsensor_mxc6655 3-0015: sensor on: starting poll sensor data 62ms
[  840.403598] binder: undelivered transaction 51789, process died.
[  844.343050] type=1400 audit(1729001831.767:2220): avc: denied { read } for comm="busybox" name="drd-data" dev="dm-0" ino=27 scontext=u:object_r:vendor_file:s0 tcontext=u:object_r:rootfs:s0 tclass=lnk_file permissive=1
[  844.343094] type=1400 audit(1729001852.211:2221): avc: denied { read } for comm="omx_msg_hdl" name="version" dev="proc" ino=4026532061 scontext=u:r:mediacodec:s0 tcontext=u:object_r:proc_version:s0 tclass=file permissive=1
[  844.343273] type=1400 audit(1729001852.211:2221): avc: denied { read } for comm="omx_msg_hdl" name="version" dev="proc" ino=4026532061 scontext=u:r:mediacodec:s0 tcontext=u:object_r:proc_version:s0 tclass=file permissive=1
[  844.343292] type=1400 audit(1729001852.211:2222): avc: denied { open } for comm="omx_msg_hdl" path="/proc/version" dev="proc" ino=4026532061 scontext=u:r:mediacodec:s0 tcontext=u:object_r:proc_version:s0 tclass=file permissive=1
[  844.343383] type=1400 audit(1729001852.211:2222): avc: denied { open } for comm="omx_msg_hdl" path="/proc/version" dev="proc" ino=4026532061 scontext=u:r:mediacodec:s0 tcontext=u:object_r:proc_version:s0 tclass=file permissive=1
[  844.343400] type=1400 audit(1729001852.211:2223): avc: denied { getattr } for comm="omx_msg_hdl" path="/proc/version" dev="proc" ino=4026532061 scontext=u:r:mediacodec:s0 tcontext=u:object_r:proc_version:s0 tclass=file permissive=1
[  844.352662] selinux: avc:  denied  { set } for property=vendor.rga_api.version pid=352 uid=1046 gid=1006 scontext=u:r:mediacodec:s0 tcontext=u:object_r:vendor_default_prop:s0 tclass=property_service permissive=1\x0a
<<<<here display goes off>>>>
[  851.300239] healthd: battery l=100 v=3888 t=18.8 h=2 st=5 c=1000 fc=7536000 chg=au

scrpy on Windows (verbose logging enabled):

>.\scrcpy.exe -V verbose
scrcpy 2.7 <https://github.com/Genymobile/scrcpy>
INFO: ADB device found:
INFO:     --> (tcpip)  10.42.40.226:5555               device  CTP08_V3
DEBUG: Device serial: 10.42.40.226:5555
DEBUG: Using server (portable): C:\FlashTools\scrcpy-win64-v2.7\scrcpy-server
C:\FlashTools\scrcpy-win64-v2.7\scrcpy-server: 1 file pushed, 0 skipped. 52.8 MB/s (71200 bytes in 0.001s)
[server] INFO: Device: [DIVUS] DIVUS CTP08_V3 (Android 10)
[server] WARN: Audio disabled: it is not supported before Android 11
[server] DEBUG: Audio encoder stopped
[server] DEBUG: Using video encoder: 'OMX.rk.video_encoder.avc'
DEBUG: Server connected
DEBUG: Starting controller thread
DEBUG: Starting receiver thread
[server] DEBUG: Display: using SurfaceControl API
DEBUG: Using icon (portable): C:\FlashTools\scrcpy-win64-v2.7\icon.png
INFO: Renderer: direct3d
DEBUG: Trilinear filtering disabled (not an OpenGL renderer)
DEBUG: Demuxer 'video': starting thread
DEBUG: Demuxer 'audio': starting thread
INFO: Texture: 1280x800
WARN: Demuxer 'audio': stream explicitly disabled by the device
VERBOSE: input: touch [id=mouse] hover-move position=533,402 pressure=1.000000 action_button=000000 buttons=000000
[...]
VERBOSE: input: touch [id=mouse] hover-move position=1175,521 pressure=1.000000 action_button=000000 buttons=000000
DEBUG: Demuxer 'video': end of frames
DEBUG: Receiver stopped
DEBUG: Server disconnected
WARN: Device disconnected
DEBUG: Server terminated
DEBUG: quit...
DEBUG: Controller stopped

Notes

The issue is NOT present using the c2.android.avc.encoder or the OMX.google.h264.encoder video encoders, instead of the default OMX.rk.video_encoder.avc. The display mirroring is however quite slow, using those two codecs.

Another option to avoid the issue is to use the --stay-awake options.

Hope this helps; let me know if there are more information that can be useful to debug the problem.

rom1v commented 1 month ago

Looks like an encoder bug which does not handle properly the case where the display is off :man_shrugging: