Nvidida Shield dropping frames/skipping while watching live TV

thors1982 · October 18, 2021, 11:36pm

I tried my phone and the Chromecast with Google TV
My phone I don't think is powerful enough it was buffering constantly but had very few dropped frames. However some (Still doesn't seem like a fair comparison).

The Chromecast with Google TV also was dropping frames about 340 in 5 minutes or so (I didn't time it). I noticed 1 dropped frame every once in a while but no change in video. Then after some time I could see the video skip and the dropped frames jump up by 10-30. Also the timeline didn't pop up on the chromecast when it dropped frames. The chromecast was also much more sporadic than with the shield(The shield almost always jumps up the dropped frames by exactly 17. Also FYI left all the settings default on the chromecast. It is on wifi and a much less powerful device.

Also if it wasn't clear all the dropped frames are on the output. The decoding never has any.

Is there a way to get more logging? I keep checking logs in the DVR but nothing about the video ever shows up its usually just channel changes and recordings.

tmm1 · October 18, 2021, 11:51pm

You can access the player logs via the IP of your client device http://x.x.x.x:57000/log

thors1982 · October 19, 2021, 12:45am

I did manage to grab the logs when it happened back to back in a short period of time. Looks like it goes into a buffering state randomly.

In the logs my strength, quality and symbol are all 100%. I did see strength drop to 98% earlier but didn't see any issues during that time.

10-18 20:36:36.144  9072  9072 V mpvstats: AV: 1187.619 A-V: 0.000 Dropped: 100 Cache: 0.416s + 0KB
10-18 20:36:36.144  9072  9072 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
10-18 20:36:37.220  9072  9104 V mpv     : event: unpause
10-18 20:36:37.223  9072  9104 V mpv     : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
10-18 20:36:37.224  9072  9104 V mpv     : property: buffering = true
10-18 20:36:37.224  9072  9072 V PlayerActivity: state PLAYING -> BUFFERING
10-18 20:36:37.229  9072  9104 V mpv     : [cplayer] Still buffering (buffer went from 0% -> 38%) [0.192000s].
10-18 20:36:37.229  9072  9072 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=1175.1062776666731, end=1189.3119998888942}], cache-end=1189.343977666671, reader-pts=1189.1519776666755, cache-duration=0.1919999999954598, eof=false, underrun=false, idle=false, total-bytes=33383600, fw-bytes=1893760, debug-low-level-seeks=0, debug-ts-last=57806.84566666667, ts-per-stream=[{type=video, duration=1.0010000000038417, reader=57806.2883, end=57807.289300000004}, {type=audio, duration=0.1919999999954598, reader=57806.65366666667, end=57806.84566666667}]}
10-18 20:36:37.245  9072  9104 V mpv     : [cplayer] Still buffering (buffer went from 38% -> 70%) [0.352022s].
10-18 20:36:37.370  9072  9104 V mpv     : [cplayer] Still buffering (buffer went from 70% -> 96%) [0.480022s].
10-18 20:36:37.482  9072  9104 V mpv     : event: unpause
10-18 20:36:37.482  9072  9104 V mpv     : [cplayer] End buffering (waited 0.243389 secs) [0.576022s].
10-18 20:36:37.491  9072  9104 V mpv     : property: buffering = false
10-18 20:36:37.491  9072  9072 V PlayerActivity: state BUFFERING -> PLAYING
10-18 20:36:37.491  9072  9072 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=1175.1062776666731, end=1189.6959998888924}], cache-end=1189.7279998888916, reader-pts=1189.1519776666755, cache-duration=0.5760222222161246, eof=false, underrun=false, idle=false, total-bytes=34306608, fw-bytes=2816768, debug-low-level-seeks=0, debug-ts-last=57806.271622333334, ts-per-stream=[{type=video, duration=1.3179888888917048, reader=57806.2883, end=57807.60628888889}, {type=audio, duration=0.5760222222161246, reader=57806.65366666667, end=57807.22968888889}]}
10-18 20:36:37.988  9072  9072 V mpvstats: AV: 1189.471 A-V: 0.000 Dropped: 114 Cache: 0.384s + 0KB
10-18 20:36:39.143  9072  9072 V mpvstats: AV: 1190.622 A-V: 0.000 Dropped: 114 Cache: 0.288s + 0KB
10-18 20:36:39.143  9072  9072 V streamstats: strength=100% quality=100% symbol=100% rate=17.8Mb/sec
10-18 20:36:41.579  9072 29089 V ApiServer: REQUEST: GET /log
10-18 20:36:42.144  9072  9072 V mpvstats: AV: 1193.625 A-V: 0.000 Dropped: 114 Cache: 0.288s + 0KB
10-18 20:36:42.144  9072  9072 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
10-18 20:36:45.145  9072  9072 V mpvstats: AV: 1196.628 A-V: 0.000 Dropped: 114 Cache: 0.384s + 0KB
10-18 20:36:45.146  9072  9072 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
10-18 20:36:45.990  9072  9108 V libchannels: libchannels: creating new segment at idx=40
10-18 20:36:45.991  9072  9109 V libchannels: libchannels: pruning segment with idx=15
10-18 20:36:46.074  9072  9108 V libchannels: libchannels: rolling over reader to segment with idx=40
10-18 20:36:47.245  9072  9104 V mpv     : event: unpause
10-18 20:36:47.245  9072  9104 V mpv     : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
10-18 20:36:47.245  9072  9104 V mpv     : property: buffering = true
10-18 20:36:47.245  9072  9072 V PlayerActivity: state PLAYING -> BUFFERING
10-18 20:36:47.246  9072  9072 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=1185.0995998888975, end=1199.103977666673}], cache-end=1199.1359776666723, reader-pts=1199.1359776666723, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=33099856, fw-bytes=1328400, debug-low-level-seeks=0, debug-ts-last=57816.23156677777, ts-per-stream=[{type=video, duration=0.6840222222162993, reader=57816.33166666667, end=57817.01568888889}, {type=audio, duration=0.0, reader=57816.63766666667, end=57816.63766666667}]}
10-18 20:36:47.609  9072  9104 V mpv     : [cplayer] Still buffering (buffer went from 0% -> 83%) [0.416022s].
10-18 20:36:47.609  9072  9104 V mpv     : [cplayer] Still buffering (buffer went from 83% -> 76%) [0.384022s].
10-18 20:36:47.638  9072  9104 V mpv     : event: unpause
10-18 20:36:47.638  9072  9104 V mpv     : [cplayer] End buffering (waited 0.372201 secs) [0.736022s].
10-18 20:36:47.639  9072  9104 V mpv     : property: buffering = false
10-18 20:36:47.640  9072  9072 V PlayerActivity: state BUFFERING -> PLAYING
10-18 20:36:47.652  9072  9072 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=1185.0995998888975, end=1199.8719998888919}], cache-end=1199.9039998888911, reader-pts=1199.2639998888917, cache-duration=0.6399999999994179, eof=false, underrun=false, idle=false, total-bytes=34837648, fw-bytes=3056528, debug-low-level-seeks=0, debug-ts-last=57816.26493344444, ts-per-stream=[{type=video, duration=1.401399999995192, reader=57816.33166666667, end=57817.73306666667}, {type=audio, duration=0.6399999999994179, reader=57816.76568888889, end=57817.40568888889}]}
10-18 20:36:48.024  9072  9072 V mpvstats: AV: 1199.364 A-V: 0.000 Dropped: 129 Cache: 0.416s + 0KB
10-18 20:36:48.146  9072  9072 V mpvstats: AV: 1199.481 A-V: 0.000 Dropped: 129 Cache: 0.544s + 0KB
10-18 20:36:48.146  9072  9072 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
10-18 20:36:51.146  9072  9072 V mpvstats: AV: 1202.484 A-V: 0.000 Dropped: 129 Cache: 0.416s + 0KB
10-18 20:36:51.147  9072  9072 V streamstats: strength=100% quality=100% symbol=100% rate=17.8Mb/sec

I will keep poking around the logs but wanted to post this as I have no clue why that would happen. Any thoughts?

racameron · October 19, 2021, 12:47am

Strength of 100% can mean strength of far over 100%, which can affect reception.

tmm1 · October 19, 2021, 1:13am

This is the cause of the buffering event.

Are you playing ac3 bitstream? Does the same thing happen with surround off?

thors1982 · October 19, 2021, 1:29am

Looks like it the current audio format according to the "Show stats" is raw-ac3 and "raw_ac3 (raw audio pass-through decoder)". Note I also recorded the same channel earlier and its raw-ac3 and seems to play fine on the recording(I will record a longer segment so that I can triple check)

@tmm1 do you want me to turn surround sound off on the shield or in the channels app, both, or one then the other???

I absolutely don't mind testing like that or tweaking some settings once we figure out what is wrong but I have a home theater and would definitely want surround sound going forward. I hope that is understandable.

tmm1 · October 19, 2021, 2:09am

Try turning off in the channels app. Just want to know if that changes behavior or not for troubleshooting.

thors1982 · October 19, 2021, 2:43am

Absolutely anything I can do to test/debug/help just let me know!

Watching with surround sound off the format changed to "floatp" and "ac3 (ATSC A/52A (AC-3))"

And it did happen again back to back as well however I did refresh log after first... as you can probably see, not sure if that caused second or not. But refreshing log, I don't think has messed it up before.

10-18 22:37:16.813 32546 32546 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
10-18 22:37:18.505 32546 32576 V mpv     : event: unpause
10-18 22:37:18.505 32546 32576 V mpv     : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
10-18 22:37:18.558 32546 32576 V mpv     : property: buffering = true
10-18 22:37:18.558 32546 32546 V PlayerActivity: state PLAYING -> BUFFERING
10-18 22:37:18.586 32546 32576 V mpv     : [cplayer] Still buffering (buffer went from 0% -> 76%) [0.384000s].
10-18 22:37:18.629 32546 32546 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=1054.8764110000047, end=1069.055999888893}], cache-end=1069.0879998888922, reader-pts=1069.0879998888922, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=33142224, fw-bytes=1376928, debug-low-level-seeks=0, debug-ts-last=65047.92263344445, ts-per-stream=[{type=video, duration=0.6172777777755982, reader=65047.956000000006, end=65048.57327777778}, {type=audio, duration=0.0, reader=65048.25368888889, end=65048.25368888889}]}
10-18 22:37:18.706 32546 32576 V mpv     : [cplayer] Still buffering (buffer went from 76% -> 95%) [0.480000s].
10-18 22:37:18.818 32546 32576 V mpv     : event: unpause
10-18 22:37:18.818 32546 32576 V mpv     : [cplayer] End buffering (waited 0.302853 secs) [0.607978s].
10-18 22:37:18.820 32546 32576 V mpv     : property: buffering = false
10-18 22:37:18.876 32546 32546 V PlayerActivity: state BUFFERING -> PLAYING
10-18 22:37:18.881 32546 32546 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=1055.1266554444446, end=1069.6639776666707}], cache-end=1069.69597766667, reader-pts=1069.247977666666, cache-duration=0.4480000000039581, eof=false, underrun=false, idle=false, total-bytes=34043200, fw-bytes=2206544, debug-low-level-seeks=0, debug-ts-last=65048.18956677778, ts-per-stream=[{type=video, duration=0.9509555555559928, reader=65048.206244444445, end=65049.1572}, {type=audio, duration=0.4480000000039581, reader=65048.41366666667, end=65048.86166666667}]}
10-18 22:37:19.534 32546 32546 V mpvstats: AV: 1069.574 A-V: 0.000 Dropped: 148 Cache: 0.576s + 0KB
10-18 22:37:19.814 32546 32546 V mpvstats: AV: 1069.858 A-V: 0.000 Dropped: 148 Cache: 0.480s + 0KB
10-18 22:37:19.814 32546 32546 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
10-18 22:37:22.814 32546 32546 V mpvstats: AV: 1072.861 A-V: 0.000 Dropped: 148 Cache: 0.480s + 0KB
10-18 22:37:22.815 32546 32546 V streamstats: strength=100% quality=100% symbol=100% rate=17.5Mb/sec
10-18 22:37:23.324 32546  1797 V ApiServer: REQUEST: GET /log
10-18 22:37:23.629 32546 32576 V mpv     : event: unpause
10-18 22:37:23.629 32546 32576 V mpv     : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
10-18 22:37:23.629 32546 32576 V mpv     : property: buffering = true
10-18 22:37:23.629 32546 32546 V PlayerActivity: state PLAYING -> BUFFERING
10-18 22:37:23.629 32546 32546 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=1059.914777666665, end=1074.0159776666696}], cache-end=1074.0479776666689, reader-pts=1074.0479776666689, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=32946912, fw-bytes=1581968, debug-low-level-seeks=0, debug-ts-last=65052.844211222226, ts-per-stream=[{type=video, duration=0.650655555560661, reader=65052.87757777778, end=65053.52823333334}, {type=audio, duration=0.0, reader=65053.21366666667, end=65053.21366666667}]}
10-18 22:37:24.030 32546 32576 V mpv     : [cplayer] Still buffering (buffer went from 0% -> 44%) [0.224022s].
10-18 22:37:24.092 32546 32576 V mpv     : event: unpause
10-18 22:37:24.092 32546 32576 V mpv     : [cplayer] End buffering (waited 0.454711 secs) [0.896000s].
10-18 22:37:24.092 32546 32576 V mpv     : property: buffering = false
10-18 22:37:24.093 32546 32546 V PlayerActivity: state BUFFERING -> PLAYING
10-18 22:37:24.099 32546 32546 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=1059.914777666665, end=1074.9119776666703}], cache-end=1074.9439776666695, reader-pts=1074.1759998888883, cache-duration=0.7679777777811978, eof=false, underrun=false, idle=false, total-bytes=34890064, fw-bytes=3515456, debug-low-level-seeks=0, debug-ts-last=65052.87757788889, ts-per-stream=[{type=video, duration=1.5015000000057626, reader=65052.87757777778, end=65054.37907777778}, {type=audio, duration=0.7679777777811978, reader=65053.34168888889, end=65054.10966666667}]}
10-18 22:37:24.542 32546 32546 V mpvstats: AV: 1074.262 A-V: 0.000 Dropped: 150 Cache: 0.800s + 0KB
10-18 22:37:25.823 32546 32546 V mpvstats: AV: 1075.530 A-V: 0.000 Dropped: 150 Cache: 0.768s + 0KB
10-18 22:37:25.823 32546 32546 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec

Also thank you so much for your incredibly quick responses and incredibly great support. I am trying to help in anyway I can but I am clearly not an expert in this stuff

tmm1 · October 19, 2021, 6:44pm

I would like to see what the line matching "Setting bufferSize =" looks like in both surround modes.

thors1982 · October 19, 2021, 9:39pm

For surround sound off
10-19 17:15:46.418 28483 28519 V mpv : [ao/audiotrack] Setting bufferSize = 28800 (driver=12320, min=28800, max=57600)
Tried another channel and exact same

For surround sound on
10-19 17:26:15.820 28483 28519 V mpv : [ao/audiotrack] Setting bufferSize = 4800 (driver=1540, min=0, max=0)
Tried another channel and bufferSize went up to 5600 but driver/min/max were the same.

*Note I did not see it error on these values as I was just trying to get you a response quickly and didn't wait for it to happen. I will keep testing random stuff though!

thors1982 · October 19, 2021, 10:52pm

I honestly don't know if I am making this worse or not.... yesterday I saw it drop the audio as you pointed out dozens and dozens of times. This time I see video drops not audio, if I am reading the
below correct It has happened at least 10 times. I wanted to make sure it would happen more before I posted something completely random.

ALSO I kept surround sound off for tests.

Very first few I saved

    10-19 18:17:57.177 28483 28519 V mpv     : event: unpause
    10-19 18:17:57.177 28483 28519 V mpv     : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
    10-19 18:17:57.177 28483 28519 V mpv     : property: buffering = true
    10-19 18:17:57.177 28483 28483 V PlayerActivity: state PLAYING -> BUFFERING
    10-19 18:17:57.178 28483 28483 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=2399.8986888888903, end=2413.8559999999998}], cache-end=2413.887999999999, reader-pts=2413.887999999999, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=32829680, fw-bytes=1114880, debug-low-level-seeks=0, debug-ts-last=40445.12438888889, ts-per-stream=[{type=video, duration=0.5171777777795796, reader=40445.25785555556, end=40445.77503333334}, {type=audio, duration=0.0, reader=40445.4, end=40445.4}]}
    10-19 18:17:57.200 28483 28519 V mpv     : event: unpause
    10-19 18:17:57.200 28483 28519 V mpv     : [cplayer] End buffering (waited 0.023098 secs) [0.671978s].
    10-19 18:17:57.203 28483 28519 V mpv     : property: buffering = false
    10-19 18:17:57.220 28483 28483 V PlayerActivity: state BUFFERING -> PLAYING
    10-19 18:17:57.221 28483 28483 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=2399.8986888888903, end=2414.527977777776}], cache-end=2414.559977777775, reader-pts=2414.0800000000017, cache-duration=0.4799777777734562, eof=false, underrun=false, idle=false, total-bytes=34565264, fw-bytes=2835968, debug-low-level-seeks=0, debug-ts-last=40445.157755555556, ts-per-stream=[{type=video, duration=1.2512444444437278, reader=40445.25785555556, end=40446.5091}, {type=audio, duration=0.4799777777734562, reader=40445.592000000004, end=40446.07197777778}]}
    10-19 18:17:58.058 28483 28483 V mpvstats: AV: 2414.563 A-V: 0.000 Dropped: 41 Cache: 0.512s + 0KB
    10-19 18:17:58.059 28483 28483 V streamstats: strength=100% quality=100% symbol=100% rate=17.5Mb/sec
    10-19 18:17:58.097 28483 28483 V mpvstats: AV: 2414.597 A-V: 0.000 Dropped: 41 Cache: 0.512s + 0KB
    10-19 18:18:01.059 28483 28483 V mpvstats: AV: 2417.566 A-V: 0.000 Dropped: 41 Cache: 0.480s + 0KB
    10-19 18:18:01.059 28483 28483 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
    10-19 18:18:03.277 28483 29994 V ApiServer: REQUEST: GET /log
    10-19 18:18:03.466 28483 28494 I hannels.dvr.ap: Background concurrent copying GC freed 325920(12MB) AllocSpace objects, 19(1172KB) LOS objects, 49% free, 16MB/32MB, paused 100us total 156.552ms
    10-19 18:18:03.469 28483 28492 W System  : A resource failed to call end. 
    10-19 18:18:04.061 28483 28483 V mpvstats: AV: 2420.553 A-V: 0.000 Dropped: 41 Cache: 0.448s + 0KB
    10-19 18:18:04.061 28483 28483 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
    10-19 18:18:07.033 28483 28519 V mpv     : event: unpause
    10-19 18:18:07.033 28483 28519 V mpv     : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
    10-19 18:18:07.034 28483 28519 V mpv     : property: buffering = true
    10-19 18:18:07.034 28483 28483 V PlayerActivity: state PLAYING -> BUFFERING
    10-19 18:18:07.034 28483 28483 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=2409.7918999999965, end=2423.872000000003}], cache-end=2423.9040000000023, reader-pts=2423.9040000000023, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=33144272, fw-bytes=1475232, debug-low-level-seeks=0, debug-ts-last=40455.05096666667, ts-per-stream=[{type=video, duration=0.5505444444497698, reader=40455.067655555555, end=40455.618200000004}, {type=audio, duration=0.0, reader=40455.416000000005, end=40455.416000000005}]}
    10-19 18:18:07.177 28483 28483 V mpvstats: AV: 2423.539 A-V: 0.000 Dropped: 41 Cache: 0.224s + 0KB
    10-19 18:18:07.177 28483 28483 V streamstats: strength=100% quality=100% symbol=100% rate=17.1Mb/sec
    10-19 18:18:07.181 28483 28519 V mpv     : [cplayer] Still buffering (buffer went from 0% -> 57%) [0.288000s].
    10-19 18:18:07.252 28483 28519 V mpv     : event: unpause
    10-19 18:18:07.252 28483 28519 V mpv     : [cplayer] End buffering (waited 0.198625 secs) [0.639978s].
    10-19 18:18:07.254 28483 28519 V mpv     : property: buffering = false
    10-19 18:18:07.264 28483 28483 V PlayerActivity: state BUFFERING -> PLAYING
    10-19 18:18:07.270 28483 28483 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=2409.7918999999965, end=2424.51197777778}], cache-end=2424.543977777779, reader-pts=2424.0319999999992, cache-duration=0.5119777777799754, eof=false, underrun=false, idle=false, total-bytes=34711312, fw-bytes=2901056, debug-low-level-seeks=0, debug-ts-last=40455.101022222225, ts-per-stream=[{type=video, duration=1.1010999999998603, reader=40455.1177, end=40456.2188}, {type=audio, duration=0.5119777777799754, reader=40455.544, end=40456.05597777778}]}
    10-19 18:18:08.190 28483 28483 V mpvstats: AV: 2424.590 A-V: 0.000 Dropped: 44 Cache: 0.544s + 0KB

Last one

    10-19 18:32:29.870 28483 28483 V streamstats: strength=100% quality=100% symbol=100% rate=17.8Mb/sec
    10-19 18:32:30.027 28483 28519 V mpv     : event: unpause
    10-19 18:32:30.027 28483 28519 V mpv     : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
    10-19 18:32:30.028 28483 28519 V mpv     : property: buffering = true
    10-19 18:32:30.028 28483 28483 V PlayerActivity: state PLAYING -> BUFFERING
    10-19 18:32:30.028 28483 28483 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=404.9752775555535, end=419.0399775555561}], cache-end=419.07197755555535, reader-pts=419.07197755555535, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=33051280, fw-bytes=1173840, debug-low-level-seeks=0, debug-ts-last=41317.92964466667, ts-per-stream=[{type=video, duration=0.533866666672111, reader=41318.04642222222, end=41318.580288888894}, {type=audio, duration=0.0, reader=41318.29595555556, end=41318.29595555556}]}
    10-19 18:32:30.129 28483 28519 V mpv     : event: unpause
    10-19 18:32:30.129 28483 28519 V mpv     : [cplayer] End buffering (waited 0.101319 secs) [0.736022s].
    10-19 18:32:30.129 28483 28519 V mpv     : property: buffering = false
    10-19 18:32:30.131 28483 28483 V PlayerActivity: state BUFFERING -> PLAYING
    10-19 18:32:30.134 28483 28483 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=404.9752775555535, end=419.7759997777757}], cache-end=419.80799977777497, reader-pts=419.2319997777813, cache-duration=0.5759999999936554, eof=false, underrun=false, idle=false, total-bytes=34784752, fw-bytes=2895232, debug-low-level-seeks=0, debug-ts-last=41317.96301133333, ts-per-stream=[{type=video, duration=1.2846222222215147, reader=41318.04642222222, end=41319.33104444444}, {type=audio, duration=0.5759999999936554, reader=41318.45597777778, end=41319.03197777778}]}
    10-19 18:32:30.915 28483 28483 V mpvstats: AV: 419.640 A-V: 0.000 Dropped: 48 Cache: 0.576s + 0KB
    10-19 18:32:32.871 28483 28483 V mpvstats: AV: 421.592 A-V: 0.000 Dropped: 48 Cache: 0.576s + 0KB
    10-19 18:32:32.871 28483 28483 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec

Lastly I saw what I purely guess to be a suggestion from a library? Probably meaningless but just in case
10-19 18:25:32.769 28483 28483 I ViewTarget: Glide treats LayoutParams.WRAP_CONTENT as a request for an image the size of this device's screen dimensions. If you want to load the original image and are ok with the corresponding memory cost and OOMs (depending on the input size), use override(Target.SIZE_ORIGINAL). Otherwise, use LayoutParams.MATCH_PARENT, set layout_width and layout_height to fixed dimension, or use .override() with fixed dimensions.

Finally I apologize I am making this worse by posting so much. I do just want to help but if especially this post is just noise I am sorry. Let me know and I can stop posting random things I find that you didn't ask for!

I am sure this is a very very difficult problem to isolate and track.

tmm1 · October 21, 2021, 1:43am

Thanks for the info. I have the details I need, and am looking into this issue.

I've put out a new alpha build of the app which has several audio related playback changes. It is currently not working correctly with surround sound, but I would like to know if it fixes the issue for you with surround off.

You will need to install the beta app via Settings > Support > Install Beta, then from the beta app select Install Alpha. Then turn off surround sound in that app and watch TV to see if it pauses to go into buffering or not.

thors1982 · October 21, 2021, 5:15pm

@tmm1
I did a few more tests on my own and am now running the latest alpha build now as well (without surround sound).

I do believe the latest alpha build has fixed it! However I don't know how to look at the logs to "prove" it. Because the stream still gets dropped frames, HOWEVER I think those are switching from like national to local or something? Because they were happening in some of my other tests when I wasn't having the issue. AND those drop frames aren't noticeable or bothersome, also the log message was different and wasn't about buffering. So I don't think they matter :-).

If there is a link I can poke at for the alpha logs I would love to take a look and prove its not the state changing from PLAYING to BUFFERING.

Also feel free to let me know when you think surround sound is fixed and I can help test that as well.

Thank you again I really do appreciate it!

tmm1 · October 21, 2021, 5:53pm

You should be able to load the alpha logs on 57000 as well, but you may need to force stop the other copies of the app first and restart the alpha so it can bind to that port.

Previously you were seeing the player pause and spinner icon come up on screen, right? Is that still happening?

thors1982 · October 21, 2021, 6:22pm

It used to stop for about 17 frames so I don't remember seeing the spinner, but the video did pause and the timeline popped up. That is NOT happening anymore so I am pretty sure its fixed!! I am happy with what I am seeing right now.

I just was going to poke around the logs and double check

tmm1 · October 21, 2021, 6:24pm

Yes please do and let me know if the logs look correct now. You can also click Settings > Support > Submit Diagnostics > Video Player and I can take a look.

tmm1 · October 21, 2021, 7:42pm

It would also be helpful if you can try with surround on and describe the results.

tmm1 · October 21, 2021, 8:46pm

I'm uploading a new alpha now with fixes to surround sound issues I was seeing on some channels. This build should work in both modes and hopefully not enter BUFFERING anymore during playback.

thors1982 · October 22, 2021, 12:13am

Without surround sound I think it looks GREAT!
I looked at logs quite a bit and did more test. I also submitted logs if you want to look at it.
I do (in logs see it drop a few frames when it switches from 5.1 to stereo then back to 5.1) However it is ONLY noticeable in logs. I don't notice it all just watching TV like a normal person. So in my opinion its perfect

Sorry I didn't get your message about surround sound till now :-p (I just updated alpha) and I will move on to that next. Thank you again! Amazingly fast bug fixes.

tmm1 · October 22, 2021, 6:18pm

Thanks! Very curious to hear your results with surround on.