search

moonlight-stream / moonlight-android

GameStream client for Android
GNU General Public License v3.0
3.95k stars 623 forks source link

[Issue]: Hwcomposer deliberately dropping 1/2 of all frames on new TVs with Mediatek Pentonic socs #1406

Open talespin-mathijs opened 1 month ago

talespin-mathijs commented 1 month ago

Describe the bug

When running Moonlight on a TV with a Mediatek Pentonic soc, the output video stream is displayed at half the refresh from what is intended. With Moonlights refresh rate set to 60/90/120, since Moonlights rendering framerate is capped at 60FPS on Google TV, this results in the video stream never outputting over 30Hz. On 30Hz refresh rate it outputs 15Hz. Note this issue only happens with Moonlight, other apps including Steam Link work fine.

These socs are the next generation soc introduced this year, and above is the only major issue experienced. All rendering stats are perfect, including latency and rendering frame rate. The decoding time is very low on this new soc (for a TV). But the actual video stream presented to the TV screen is only half the refresh rate of what is logged in the stat window.

image

Using the testufo frame skipping checker we can confirm the problem.

Photo of the host machine:

image

Photo of another Android client without any problems:

image

Photo of client affected by this issue:

image

As you can see on the last photo exactly half of the frames is skipped, resulting in the alternating pattern of the grey boxes.

Looking in the ADB logs, the issue is also revealed with this log:

I PqLink : frameRateControl : PqId[0] out_frame_rate 60000, in_frame_rate 120000, gcd 60000 => 1/2

And then a variation of the following outputted every other frame:

E PqLink : frameRateControl : PqId[0] Drop input index 4 with frm_idx 42003 by factor (1/2)

The offending process turns out to be:

system 578 1 226592 73676 0 0 S vendor.mediatek.hardware.hwcomposer.composer@2.5-service

The full ADB log of this process has been pasted in the relevant log output section of this issue.

My own understanding: it seems like there is a configuration mismatch or incorrect logic in determining input/output frame rates in the communication between Moonlight and the OS, resulting in the OS incorrectly thinking it needs to drop half of all frames to reach 60Hz.

Steps to reproduce

Run Moonlight on a recent Google TV that is equipped with a new generation Mediatek Pentonic soc.

It is highely likely a problem on all 2024 lineup Sony TVs + the Sony Bravia A95L (all Sonys with the Pentonic). There have also been reports on bad perceived performance on TVs from other brands running the Pentonic, this pertains to some Hisense, Philips, and TCL TVs.

Confirmed affected devices: (my own TV + reports I have received from other users having the same issue confirmed with logs) Sony Bravia 7 (Mediatek Pentonic 1000) TCL C805/C755 (Mediatek Pentonic 700)

Affected games

Any game

Other Moonlight clients

PC

Moonlight adjusted settings

Yes

Moonlight adjusted settings (please complete the following information)

This problem persists through any possible permutation of all possible Moonlight settings, even all the frame/refresh related settings.

Moonlight default settings

Yes

Gamepad-related connection issue

Yes

Gamepad-related input issue

Yes

Gamepad-related streaming issue

Yes

Android version

Google TV 12

Device model

Sony Bravia 7 K85XR70PAEP

Server PC OS version

Windows 10 Pro 22H2

Server PC GeForce Experience version

3.28.0.417

Server PC Nvidia GPU driver version

560.70

Server PC antivirus and firewall software

Windows Security

Screenshots

No response

Relevant log output

I PqLink  : frameRateControl : PqId[0] out_frame_rate 60000, in_frame_rate 120000, gcd 60000 => 1/2
D DispLink: [PERF][DISPLINK][225] [flipToPq] [0][performance] flip to PQ done fid 10 +0 (idx  8, PTS 519453113000    +0 cost 0, PqIn_AtPq_Cnt 1, cnt(1), interval 0)
I DispLink: [225] [checkFlipLogo] First 1, SDR -> SDR
E DispService: [logoThread][L1498] no DispServiceLogoListener
I DispLink: [225] [stepGetLatency] doConfig done
V <MI_PQ> : [mi_pq_cfd][error] [MI_PQ_ColorFormatDecision:4314] u8PreHdrType = 0, stInput.hdr_mode = 0,
I PQ_HIDL : PerStreamCallbackToRenderService
W DispLink: [225] [sendEventToRenderService] No callback to send event(0) to RenderService
I <MI_RENDER>: [INFO ]MI_RENDER_SetWindowPq_Sony[5909] [MI_RENDER_SetWindowPq_Sony:5909] hController: 0x0 pszWindowPqSetting:{
I <MI_RENDER>:     "HDR_type" : "SDR",
I <MI_RENDER>:     "Content_Sync_Frame_ID" : 0,
I <MI_RENDER>:     "Cine_Motion" : "Off"
I <MI_RENDER>: }
I <MI_RENDER>:
I <MI_RENDER>: [INFO ]MI_RENDER_SetWindowPq_Sony[5914] MI_RENDER_SetWindowPq_Sony Start
I <MI_RENDER>: [INFO ]MI_RENDER_SetWindowPq_Sony[5931] VideoNum:1
I <MI_RENDER>: [INFO ]MI_RENDER_SetWindowPq_Sony[5958] Registered success HDR Type: SDR
I <MI_RENDER>: [INFO ]MI_RENDER_SetContentSyncFrameId[9200] [DolbyMute]Found Content_Sync_Frame_ID in WindowPq
I <MI_RENDER>: [INFO ]MI_RENDER_SetContentSyncFrameId[9203] [DolbyMute]Conent_Sync_Frame_ID value = : 0,
I <MI_RENDER>:     "Cine_Motion" : "Off"
I <MI_RENDER>: }
I <MI_RENDER>:
I <MI_RENDER>: [INFO ]MI_RENDER_SetContentSyncFrameId[9215] [DolbyMute]WindowId:0 Receive New Content_Sync_Frame_ID:0 -> 0
I <MI_RENDER>: [INFO ]MI_RENDER_SetContentSyncFrameId[9221] [DolbyMute]WindowId:0 Set 1st Content_Sync_Frame_ID = 0 from MI_RENDER_Open
I <MI_RENDER>: [INFO ]MI_RENDER_SetWindowPq_Sony[5964] MI_RENDER_SetWindowPq_Sony End
I <MI_RENDER>: [INFO ]MI_RENDER_SetWindowPq_Sony[5909] [MI_RENDER_SetWindowPq_Sony:5909] hController: 0x0 pszWindowPqSetting:MJC_Demo:Off;MJC_Demo_Partition:Right;Gaming_MJC_Lvl:0;MJC_Deblur:0;MJC_Dejudder:0;Real_Cinema:Off;Cadence:Off;Cadence_Data1:0;Cadence_Data2:0;Cadence_Data3:0;MEMC_ONOFF:Off;MEMC_Level:[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0];
I <MI_RENDER>: [INFO ]MI_RENDER_SetWindowPq_Sony[5914] MI_RENDER_SetWindowPq_Sony Start
I <MI_RENDER>: [INFO ]MI_RENDER_SetWindowPq_Sony[5931] VideoNum:1
I <MI_RENDER>: [INFO ]MI_RENDER_SetWindowPq_Sony[5947] Not found HDR Type
I <MI_RENDER>: [INFO ]MI_RENDER_SetContentSyncFrameId[9197] [DolbyMute]WindowId:0 Not found Content_Frame_Sync_ID
I <MI_RENDER>: [INFO ]MI_RENDER_SetWindowPq_Sony[5964] MI_RENDER_SetWindowPq_Sony End
I <MI_RENDER>: [INFO ]MI_RENDER_MEMC_WindowPq[10349] Error before: MJC_Demo:Off;MJC_Demo_Partition:Right;Gaming_MJC_Lvl:0;MJC_Deblur:0;MJC_Dejudder:0;Real_Cinema:Off;Cadence:Off;Cadence_Data1:0;Cadence_Data2:0;Cadence_Data3:0;MEMC_ONOFF:Off;MEMC_Level:[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0];
I DispLink: [225] [cbPqCommonEvent] PQ_SETTING_TS_DOMAIN_GLOBAL
E <MI_PQ> : <ERR>MI_PQ_ApplyParams_WriteParamMeta[8968]: tag:327694, ver:0, size:4100, s32SMetaFd[0]
E <MI_PQ> : <ERR>MI_PQ_ApplyParams_WriteParamMeta[8968]: tag:327693, ver:1, size:3072, s32SMetaFd[0]
E PqLink  : frameRateControl : PqId[0] Drop input index 0 with frm_idx 11 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 1 with frm_idx 13 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D DispLink: [PERF][DISPLINK][225] [cbHandleOutBuf] [0][performance] PQ flip to syncQ fid 10 (idx: 0xb00000, pts 519453113000 sid 225, eos 0, byPassAv 0 PqIn_AtPq_Cnt 2, PqOut_AtPq_Cnt 2, interval: 0)
D DispLink: [PERF][DISPLINK][225] [flipToRender_internal][0][performance] flip to render done fid 10 pts 519453113000 (cost 0), frames to unmute/unfreeze 0 (Mute 1, UserMute 0, C2Mute 0, unstable 0, layer 0, PTC 0, TpcMute 0, dvrm 0, Freeze 0, UserFreeze 0, TpcFreeze 0, Ctrl NONE), RepeatCnt 0, FlipToRenderCnt : 1
I DispLink: [225] [flipToRender] SETMUTE false
I DispLink: [225] [renderSetMute] internal 0, user 0, C2 0, unstable 0, layer 0, PTC 0, tpc 0, ctrl NONE, dvrm 0
I DispLinkRender: [225] [setMute] 1 -> 0
I <MI_RENDER>: API trigger, no meta mute info
I <MI_RENDER>: [Win 0][CurTime:519453209559735][UserM:Un:Cur]=[257:129:0], [C2M:Un:Cur]=[0:2755430:0], [PqM:Un:Cur]=[0:2755430:0], [GlobalM:Un]=[2:2], [TxM:Un]=[2:2]
I DispLinkRender: [PERF][DISPLINK][225] [setMute] MI_RENDER_UnMuteWindow ok
I <MI_RENDER>: [Win 0][CurTime:519453211801152][UserM:Un:Cur]=[257:129:0], [C2M:Un:Cur]=[0:2755431:0], [PqM:Un:Cur]=[0:2755431:0], [GlobalM:Un]=[2:2], [TxM:Un]=[2:2]
V <MI3>   : <INFO>[PERF][MI_RENDER][DRM_Setting][PLAYBACK] Mute Status: pre_mute(0) -> current_mute(1), FREEZE(0), HW_FREEZE(0), Fake_Mute(0)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
I <MI_RENDER>: eFrameSyncMode=1
E PqLink  : frameRateControl : PqId[0] Drop input index 10 with frm_idx 15 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
V <MI3>   : <INFO>[PERF][MI_RENDER][DRM_Setting][PLAYBACK] Mute Status: pre_mute(1) -> current_mute(0), FREEZE(0), HW_FREEZE(0), Fake_Mute(0)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 4 with frm_idx 17 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 6 with frm_idx 19 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 0 with frm_idx 21 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 9 with frm_idx 23 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 2 with frm_idx 25 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 3 with frm_idx 27 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 5 with frm_idx 29 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 7 with frm_idx 31 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 8 with frm_idx 33 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 1 with frm_idx 35 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 10 with frm_idx 37 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 4 with frm_idx 39 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 6 with frm_idx 41 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 0 with frm_idx 43 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 9 with frm_idx 45 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 2 with frm_idx 47 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 3 with frm_idx 49 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 5 with frm_idx 51 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 7 with frm_idx 53 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 8 with frm_idx 55 by factor (1/2)
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
D hwcomposer: HWCDisplayDevicePrimary::getRefreshPeriod: set output fps(60).
E PqLink  : frameRateControl : PqId[0] Drop input index 1 with frm_idx 57 by factor (1/2)
I <MI_RENDER>: MI_RENDER_Open[25916][Output] Window ID = 0xf1000000
D hwcomposer: HWComposerDisplayHalMiRender::setShowFrameInfo: Plane[0]: Show!!!!
E PqLink  : frameRateControl : PqId[0] Drop input index 3 with frm_idx 60 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 5 with frm_idx 62 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 7 with frm_idx 64 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 8 with frm_idx 66 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 1 with frm_idx 68 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 2 with frm_idx 70 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 4 with frm_idx 72 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 6 with frm_idx 74 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 0 with frm_idx 76 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 9 with frm_idx 78 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 10 with frm_idx 80 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 3 with frm_idx 82 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 5 with frm_idx 84 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 7 with frm_idx 86 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 8 with frm_idx 88 by factor (1/2)
I <MI_RENDER>: [Win 0][CurTime:519454539654985]Mute:0, FlipInTime:519453292590819, FlipAvgfps:0, Flip2Atomic:1247
E PqLink  : frameRateControl : PqId[0] Drop input index 1 with frm_idx 90 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 2 with frm_idx 92 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 4 with frm_idx 94 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 6 with frm_idx 96 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 0 with frm_idx 98 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 9 with frm_idx 100 by factor (1/2)
E PqLink  : frameRateControl : PqId[0] Drop input index 10 with frm_idx 102 by factor (1/2)
...This pattern then repeats for as long as you run the app

Additional context

No response

talespin-mathijs commented 3 weeks ago

Adding a full log of a run of Moonlight, including all logs from all processes at the time to see the interaction between Moonlight and various OS systems logcat.txt