Emby, unknown remote behaviour

Kodi Add-ons
1

Hi,

I’m currently testing an AM6B+ with CoreELEC (21.1.1 stable), as a potential replacement for my Shield TV Pro (2019). Especially the DV profile 7 FEL support fascinated me. Great work of this team! Thanks!

Setup etc. was easy, with all the information you provide.

However, I did notice playback issues/glitches. So far, I’ve encountered these in 1080p *.mp4 files. Playback glitches (looks like something from the GUI shows for a fraction of a second, but hard to focus on and very easy to miss) usually once per file, but not at a specific spot. The files also do play fine on the Shield.

I’ve captured it (hopefully) in a debug log, using the default skin. However, log upload currently fails, and hastebin won’t accept the contents (“Something went wrong” error message… very helpful). Is there another way to provide the contents of the log file (which is unfortunately slightly over 12MB)?

Thank you!

Note: All my media files are sitting on a TrueNAS SCALE server, with emby server managing the library. Therefore, emby-for-kodi-next-gen (10.0.47 stable) is also installed on CE. Network is LAN, 1G, and both, server and client, are in the same subnet, so all traffic stays on the switches (HPE 1920S models). The emby server log is flawless during playback, everything’s in the 2-3ms range, except for a few 5-6ms “outliers”, no errors, nothing. This let’s me suspect something on the client end.

2

Seems there’s still no solution for uploading logs?

Well, I reproduced these glitches several times, and always do I find this in the logs:

2024-09-27 08:58:09.403 T:4169    debug <general>: CVideoPlayerVideo::OutputPicture - ttd:224ms pts:367.840 Clock:367.616 Level:6
2024-09-27 08:58:09.424 T:3889    debug <general>: ------ Window Init (custom_1134_PausedOverlay.xml) ------
2024-09-27 08:58:09.432 T:4169    debug <general>: CAMLCodec::SetSpeed, speed(0)
2024-09-27 08:58:09.443 T:4162    debug <general>: CVideoPlayer::ProcessVideoData size:8016 dts:485.120 pts:485.160 dur:20.000ms, clock:367.655 level:100
2024-09-27 08:58:09.443 T:4162    debug <general>: CVideoPlayer::ProcessVideoData size:1459 dts:485.140 pts:485.140 dur:20.000ms, clock:367.655 level:100
2024-09-27 08:58:09.443 T:4162    debug <general>: CVideoPlayer::ProcessVideoData size:1146 dts:485.160 pts:485.180 dur:20.000ms, clock:367.655 level:100
2024-09-27 08:58:09.445 T:4162    debug <general>: CVideoPlayer::ProcessVideoData size:33235 dts:485.180 pts:485.280 dur:20.000ms, clock:367.655 level:100
2024-09-27 08:58:09.450 T:4169    debug <general>: CVideoPlayerVideo::OutputPicture - ttd:205ms pts:367.860 Clock:367.655 Level:5
2024-09-27 08:58:09.460 T:4174    debug <general>: CDVDAudio::Pause - pausing audio stream
2024-09-27 08:58:09.469 T:4169    debug <general>: CVideoPlayerVideo::OutputPicture - ttd:225ms pts:367.880 Clock:367.655 Level:6
2024-09-27 08:58:09.476 T:4162    debug <general>: CVideoPlayer::ProcessVideoData size:7193 dts:485.200 pts:485.240 dur:20.000ms, clock:367.655 level:100
2024-09-27 08:58:09.476 T:4162    debug <general>: CVideoPlayer::ProcessVideoData size:1656 dts:485.220 pts:485.220 dur:20.000ms, clock:367.655 level:100
2024-09-27 08:58:09.476 T:4162    debug <general>: CVideoPlayer::ProcessVideoData size:1271 dts:485.240 pts:485.260 dur:20.000ms, clock:367.655 level:100
2024-09-27 08:58:09.477 T:4162    debug <general>: CVideoPlayer::ProcessVideoData size:31647 dts:485.260 pts:485.360 dur:20.000ms, clock:367.655 level:100
2024-09-27 08:58:09.540 T:3966    debug <general>: EMBY.hooks.player: playercommand received: ('pause',)
2024-09-27 08:58:09.541 T:3966     info <general>: EMBY.hooks.player: [ onPlayBackPaused ]
2024-09-27 08:58:09.541 T:3966    debug <general>: Emby.helper.utils: Json response: {"jsonrpc":"2.0","method":"Player.GetProperties","params":{"playerid":1,"properties": ["time"]},"id":1} / {'id': 1, 'jsonrpc': '2.0', 'result': {'time': {'hours': 0, 'milliseconds': 450, 'minutes': 6, 'seconds': 7}}}
2024-09-27 08:58:09.541 T:3966    debug <general>: EMBY.helper.playerops: --> [ remotecommand received: pause / [0, 0, 0, 0, 0] ]
2024-09-27 08:58:09.541 T:3966    debug <general>: EMBY.helper.playerops: --< [ remotecommand received: pause / [0, 0, 0, 0, 0] ]
2024-09-27 08:58:09.541 T:3966    debug <general>: EMBY.hooks.player: -->[ paused ]
2024-09-27 08:58:09.542 T:3987    debug <general>: EMBY.emby.http: Socket ASYNC opened
2024-09-27 08:58:09.568 T:4174    debug <general>: CDVDAudio::Resume - resume audio stream
2024-09-27 08:58:09.569 T:3919    debug <general>: ActiveAE - start sync of audio stream
2024-09-27 08:58:09.583 T:4185    debug <general>: Emby.helper.utils: Json response: {"jsonrpc":"2.0","method":"Player.GetProperties","params":{"playerid":1,"properties": ["time"]},"id":1} / {'id': 1, 'jsonrpc': '2.0', 'result': {'time': {'hours': 0, 'milliseconds': 450, 'minutes': 6, 'seconds': 7}}}
2024-09-27 08:58:09.583 T:4185    debug <general>: EMBY.hooks.player: PositionTracker: Position: 3674500000 / IntroStartPositionTicks: 0 / IntroEndPositionTicks: 0 / CreditsPositionTicks: 0 / SkipIntroJumpDone: False
2024-09-27 08:58:09.607 T:4169    debug <general>: CVideoPlayerVideo::OutputPicture - ttd:245ms pts:367.900 Clock:367.655 Level:6
2024-09-27 08:58:09.607 T:4169    debug <general>: CAMLCodec::SetSpeed, speed(1000)
2024-09-27 08:58:09.628 T:4169    debug <general>: CVideoPlayerVideo::OutputPicture - ttd:225ms pts:367.920 Clock:367.694 Level:6
2024-09-27 08:58:09.641 T:3966    debug <general>: EMBY.hooks.player: playercommand received: ('resume',)
2024-09-27 08:58:09.641 T:3966     info <general>: EMBY.hooks.player: [ onPlayBackResumed ]
2024-09-27 08:58:09.641 T:3966    debug <general>: EMBY.helper.playerops: --> [ remotecommand received: unpause / [0, 0, 0, 0, 0] ]
2024-09-27 08:58:09.641 T:3966    debug <general>: EMBY.helper.playerops: --< [ remotecommand received: unpause / [0, 0, 0, 0, 0] ]
2024-09-27 08:58:09.641 T:3966    debug <general>: EMBY.hooks.player: --<[ paused ]
2024-09-27 08:58:09.642 T:3987    debug <general>: EMBY.emby.http: Socket ASYNC opened
2024-09-27 08:58:09.647 T:4169    debug <general>: CVideoPlayerVideo::OutputPicture - ttd:223ms pts:367.940 Clock:367.717 Level:6
2024-09-27 08:58:09.670 T:4169    debug <general>: CVideoPlayerVideo::OutputPicture - ttd:202ms pts:367.960 Clock:367.758 Level:6
2024-09-27 08:58:09.689 T:4169    debug <general>: CVideoPlayerVideo::OutputPicture - ttd:221ms pts:367.980 Clock:367.759 Level:6
2024-09-27 08:58:09.699 T:4162    debug <general>: CVideoPlayer::ProcessVideoData size:7341 dts:485.280 pts:485.320 dur:20.000ms, clock:367.786 level:100
2024-09-27 08:58:09.699 T:4162    debug <general>: CVideoPlayer::ProcessVideoData size:1219 dts:485.300 pts:485.300 dur:20.000ms, clock:367.787 level:100
2024-09-27 08:58:09.700 T:4162    debug <general>: CVideoPlayer::ProcessVideoData size:1093 dts:485.320 pts:485.340 dur:20.000ms, clock:367.787 level:100
2024-09-27 08:58:09.709 T:3889    debug <general>: ------ Window Deinit (custom_1134_PausedOverlay.xml) ------
2024-09-27 08:58:09.711 T:3919    debug <general>: ActiveAE::SyncStream - average error of 268.710125, start adjusting
2024-09-27 08:58:09.720 T:4162    debug <general>: CVideoPlayer::ProcessVideoData size:29639 dts:485.340 pts:485.440 dur:20.000ms, clock:367.807 level:100
2024-09-27 08:58:09.751 T:4169    debug <general>: CVideoPlayerVideo::OutputPicture - ttd:161ms pts:368.000 Clock:367.838 Level:4

This seems very odd. No one is pausing the playback. The remote is just sitting on a desk, out of range. Also, this is happening within less than half a second. Impossible to achieve with any remote.