Shield TV 4k Stutter/Buffering

[EricGRIT09 5]

Attempting to play my 4k rips on my Shield TV via the official Emby app and having issues with stuttering.  Stuttering meaning the file will begin playing for ~1-2 seconds, then pause for 2-5 seconds, then resume for maybe 1-10 seconds, repeat.  The file in question here is 53mbps 4k HDR/Atmos.  I've tried playing with different audio tracks with no success.  Direct playing and also may be worth noting this file direct plays perfectly on the Plex app on the same Shield TV (Plex running on the same server) - I can flip between apps and have 100% success on the Plex app but not the Emby app.  Refresh rate switching doesn't seem to make a difference either.

2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: session.RemoteEndPoint : 192.168.1.181
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : event_playing_id       = 67158f07324e6c022d92c4e256da7ee8
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : event_playing_id_int   = 53090
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : event_user_id          = 8e0e6a4c05e94908af9b98c69886bc31
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : event_user_id_int      = 1
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : session_playing_id     = 53090
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : session_playing_id_int = 53090
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : session_user_id_int    = 1
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : play_method            = DirectStream
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : e.ClientName           = AndroidTv
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : e.DeviceName           = Living Room TV
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : ItemName               = MovieName
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : ItemId                 = 67158f07324e6c022d92c4e256da7ee8
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : ItemType               = Movie
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : All matches, playback registered
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: Playback tracker found, adding playback info : 23b71e23c289c2a9-8e0e6a4c05e94908af9b98c69886bc31-67158f07324e6c022d92c4e256da7ee8
2018-11-29 13:56:50.018 Info PlaybackReporting - EventMonitorEntryPoint: Saving playback tracking activity in DB
2018-11-29 13:56:50.036 Info PlaybackReporting - EventMonitorEntryPoint: StartPlaybackTimer : Exited
2018-11-29 13:56:51.269 Info PlaybackReporting - EventMonitorEntryPoint: Processing playback tracker : 23b71e23c289c2a9-8e0e6a4c05e94908af9b98c69886bc31-67158f07324e6c022d92c4e256da7ee8
2018-11-29 13:56:51.269 Debug PlaybackReporting - EventMonitorEntryPoint: ProcessProgress : EventCount(2)Event(11/29/2018 1:56:30 PM,START)Event(11/29/2018 1:56:51 PM,STOP)Diff(21,21)Total(21)
2018-11-29 13:56:54.211 Info HttpServer: HTTP POST http://192.168.1.7:8096/emby/Sessions/Playing/Progress. UserAgent: Dalvik/2.1.0 (Linux; U; Android 8.0.0; SHIELD Android TV Build/OPR6.170623.010)
2018-11-29 13:56:54.217 Info HttpServer: HTTP Response 204 to 192.168.1.181. Time: 6ms. http://192.168.1.7:8096/emby/Sessions/Playing/Progress
2018-11-29 13:57:04.229 Info HttpServer: HTTP POST http://192.168.1.7:8096/emby/Sessions/Playing/Progress. UserAgent: Dalvik/2.1.0 (Linux; U; Android 8.0.0; SHIELD Android TV Build/OPR6.170623.010)
2018-11-29 13:57:04.232 Info HttpServer: HTTP Response 204 to 192.168.1.181. Time: 3ms. http://192.168.1.7:8096/emby/Sessions/Playing/Progress
2018-11-29 13:57:12.236 Info PlaybackReporting - EventMonitorEntryPoint: Processing playback tracker : 23b71e23c289c2a9-8e0e6a4c05e94908af9b98c69886bc31-67158f07324e6c022d92c4e256da7ee8
2018-11-29 13:57:12.236 Debug PlaybackReporting - EventMonitorEntryPoint: ProcessProgress : EventCount(2)Event(11/29/2018 1:56:30 PM,START)Event(11/29/2018 1:57:12 PM,STOP)Diff(42,42)Total(42)
2018-11-29 13:57:14.271 Info HttpServer: HTTP POST http://192.168.1.7:8096/emby/Sessions/Playing/Progress. UserAgent: Dalvik/2.1.0 (Linux; U; Android 8.0.0; SHIELD Android TV Build/OPR6.170623.010)
2018-11-29 13:57:14.273 Info HttpServer: HTTP Response 204 to 192.168.1.181. Time: 3ms. http://192.168.1.7:8096/emby/Sessions/Playing/Progress
2018-11-29 13:57:24.218 Info HttpServer: HTTP POST http://192.168.1.7:8096/emby/Sessions/Playing/Progress. UserAgent: Dalvik/2.1.0 (Linux; U; Android 8.0.0; SHIELD Android TV Build/OPR6.170623.010)
2018-11-29 13:57:24.221 Info HttpServer: HTTP Response 204 to 192.168.1.181. Time: 3ms. http://192.168.1.7:8096/emby/Sessions/Playing/Progress
2018-11-29 13:57:33.222 Info PlaybackReporting - EventMonitorEntryPoint: Processing playback tracker : 23b71e23c289c2a9-8e0e6a4c05e94908af9b98c69886bc31-67158f07324e6c022d92c4e256da7ee8
2018-11-29 13:57:33.222 Debug PlaybackReporting - EventMonitorEntryPoint: ProcessProgress : EventCount(2)Event(11/29/2018 1:56:30 PM,START)Event(11/29/2018 1:57:33 PM,STOP)Diff(63,63)Total(63)
2018-11-29 13:57:34.222 Info HttpServer: HTTP POST http://192.168.1.7:8096/emby/Sessions/Playing/Progress. UserAgent: Dalvik/2.1.0 (Linux; U; Android 8.0.0; SHIELD Android TV Build/OPR6.170623.010)
2018-11-29 13:57:34.224 Info HttpServer: HTTP Response 204 to 192.168.1.181. Time: 3ms. http://192.168.1.7:8096/emby/Sessions/Playing/Progress
2018-11-29 13:57:44.302 Info HttpServer: HTTP POST http://192.168.1.7:8096/emby/Sessions/Playing/Progress. UserAgent: Dalvik/2.1.0 (Linux; U; Android 8.0.0; SHIELD Android TV Build/OPR6.170623.010)
2018-11-29 13:57:44.305 Info HttpServer: HTTP Response 204 to 192.168.1.181. Time: 3ms. http://192.168.1.7:8096/emby/Sessions/Playing/Progress
2018-11-29 13:57:53.315 Info PlaybackReporting - EventMonitorEntryPoint: Processing playback tracker : 23b71e23c289c2a9-8e0e6a4c05e94908af9b98c69886bc31-67158f07324e6c022d92c4e256da7ee8
2018-11-29 13:57:53.315 Debug PlaybackReporting - EventMonitorEntryPoint: ProcessProgress : EventCount(2)Event(11/29/2018 1:56:30 PM,START)Event(11/29/2018 1:57:53 PM,STOP)Diff(83,83)Total(83)
2018-11-29 13:57:54.244 Info HttpServer: HTTP POST http://192.168.1.7:8096/emby/Sessions/Playing/Progress. UserAgent: Dalvik/2.1.0 (Linux; U; Android 8.0.0; SHIELD Android TV Build/OPR6.170623.010)
2018-11-29 13:57:54.247 Info HttpServer: HTTP Response 204 to 192.168.1.181. Time: 3ms. http://192.168.1.7:8096/emby/Sessions/Playing/Progress
2018-11-29 13:57:54.481 Info HttpServer: HTTP POST http://192.168.1.7:8096/emby/Sessions/Playing/Progress. UserAgent: Dalvik/2.1.0 (Linux; U; Android 8.0.0; SHIELD Android TV Build/OPR6.170623.010)
2018-11-29 13:57:54.483 Info HttpServer: HTTP Response 204 to 192.168.1.181. Time: 2ms. http://192.168.1.7:8096/emby/Sessions/Playing/Progress
2018-11-29 13:57:59.839 Info HttpServer: HTTP POST http://192.168.1.7:8096/emby/Sessions/Playing/Stopped. UserAgent: Dalvik/2.1.0 (Linux; U; Android 8.0.0; SHIELD Android TV Build/OPR6.170623.010)
2018-11-29 13:57:59.839 Info HttpServer: HTTP GET http://192.168.1.7:8096/emby/Users/8e0e6a4c05e94908af9b98c69886bc31/Items/53090?format=json. UserAgent: Dalvik/2.1.0 (Linux; U; Android 8.0.0; SHIELD Android TV Build/OPR6.170623.010)
2018-11-29 13:57:59.841 Debug App: ReportPlaybackStopped PlaySessionId: bd31d892346a4dfba098a5822a45c75f
2018-11-29 13:57:59.841 Info SessionManager: Playback stopped reported by app AndroidTv 1.6.56g playing MovieName. Stopped at 20915 ms
2018-11-29 13:57:59.843 Info PlaybackReporting - EventMonitorEntryPoint: Playback stop tracker found, processing stop : 23b71e23c289c2a9-8e0e6a4c05e94908af9b98c69886bc31-67158f07324e6c022d92c4e256da7ee8
2018-11-29 13:57:59.843 Info PlaybackReporting - EventMonitorEntryPoint: PlaybackTracker : Adding Stop Event : 11/29/2018 1:57:59 PM
2018-11-29 13:57:59.843 Debug PlaybackReporting - EventMonitorEntryPoint: ProcessProgress : EventCount(2)Event(11/29/2018 1:56:30 PM,START)Event(11/29/2018 1:57:59 PM,STOP)Diff(89,89)Total(89)
2018-11-29 13:57:59.843 Info PlaybackReporting - EventMonitorEntryPoint: Saving playback tracking activity in DB

Edited November 29, 2018 by EricGRIT09

[ebr 14904]

That's a very high bitrate.  Can you please follow the instructions to send a log from the app after reproducing this problem?

 

Thanks.

[EricGRIT09 5]

That's a very high bitrate.  Can you please follow the instructions to send a log from the app after reproducing this problem?

 

Thanks.

 

High bitrate for sure.

 

Submitted log.

Played Mission Impossible: Rogue Nation at ~3:33pm Eastern time.

Local user was Eric.

 

I'm also going to try hardwired but my WiFi should be able to handle this without issue, I would imagine (as other apps on the same device direct play without issue).  350-450mbps actual throughput as tested to the server.

Edited November 29, 2018 by EricGRIT09

[ebr 14904]

If you change the audio track does the problem go away?

 

There are a lot of these in your log (which I've never seen before):

11-29 15:35:05.984 12351 12447 D AudioTrack: correcting timestamp time for pause, currentTimeNanos: 503378440172871 < limitNs: 503382664940005 < mStartNs: 503382674940005
11-29 15:35:05.993 12351 12447 D AudioTrack: correcting timestamp time for pause, currentTimeNanos: 503378440172871 < limitNs: 503382664940005 < mStartNs: 503382674940005
11-29 15:35:06.004 12351 12447 D AudioTrack: correcting timestamp time for pause, currentTimeNanos: 503378440172871 < limitNs: 503382664940005 < mStartNs: 503382674940005
11-29 15:35:06.013 12351 12447 D AudioTrack: correcting timestamp time for pause, currentTimeNanos: 503378440172871 < limitNs: 503382664940005 < mStartNs: 503382674940005

[EricGRIT09 5]

 

If you change the audio track does the problem go away?

 

There are a lot of these in your log (which I've never seen before):

11-29 15:35:05.984 12351 12447 D AudioTrack: correcting timestamp time for pause, currentTimeNanos: 503378440172871 < limitNs: 503382664940005 < mStartNs: 503382674940005
11-29 15:35:05.993 12351 12447 D AudioTrack: correcting timestamp time for pause, currentTimeNanos: 503378440172871 < limitNs: 503382664940005 < mStartNs: 503382674940005
11-29 15:35:06.004 12351 12447 D AudioTrack: correcting timestamp time for pause, currentTimeNanos: 503378440172871 < limitNs: 503382664940005 < mStartNs: 503382674940005
11-29 15:35:06.013 12351 12447 D AudioTrack: correcting timestamp time for pause, currentTimeNanos: 503378440172871 < limitNs: 503382664940005 < mStartNs: 503382674940005

 

Interesting.  Behavior doesn't change with different audio tracks - just rotated through all four (Stereo, DD 5.1, TrueHD 7.1, DTS 7.1) and let them pause once or twice then I re-sent the logs in if that helps.