Nvidida Shield dropping frames/skipping while watching live TV

So far on my CCwGTV it's been flawless......
I watched SNL last night on NBC OTA 1080i and currently watching the Pats on CBS 720p.

Edit:
I'm on 111.11.2054?

1 Like

Yep that's the latest alpha. Great to hear results so far are good!

I'm praying this holds up. I've been wanting these results for 2 years now! Thank you for taking this extra effort. I'll test my 2018 SonyTV that still has Android TV (9) later but I've been using my CCwGTV exclusively for a few weeks now.

BTW I also have Tuner sharing enabled currently. Before it didn't matter if I had it enabled or not it would buffer.

Just imagine how I feel finally finding a fix after trying for three years :slight_smile:

I'm uploading alpha v2021.11.14.2205 now with some more upgrades to the audio/video handling code.

This latest alpha has support for DD+ passthrough on supported devices, and fixes an issue with captions getting distorted when going into PIP mode.

3 Likes

These changes are now part of beta starting with v2021.11.15.0054

1 Like

Nice :+1:

Alpha info bar is squished.

Edit:
Just checked new Beta.... It's the same

Nvidia related but let me know if this needs its own topic. I've also had these issue but something new has started for me. I'm running the latest beta btw ( Version
2021.11.15.2047)....but after watching a station for awhile, when the buffer fills up, the screen freezes and then kicks me back to the guide and I have to re-select the channel. This just started the last day or so and just happened a few mins ago - the 6:16 timestamp

2021/11/16 02:49:28.915300 http: TLS handshake error from 144.91.97.95:54583: tls: client offered only unsupported versions: [301]
2021/11/16 03:25:18.537327 [NAT] Successfully mapped port 8089 using upnp
2021/11/16 04:25:19.198309 [NAT] Successfully mapped port 8089 using upnp
2021/11/16 04:46:36.541125 [TVE] stream timestamps: fox: start_at=2021-11-16T04:45:42-05:00 current_at=2021-11-16T04:46:02-05:00 end_at=2021-11-16T04:46:10-05:00
2021/11/16 04:46:36.555343 [TNR] Opened connection to TVE-frontier_auth-gateway_net for ch6002 WTVT
2021/11/16 05:25:25.168177 [NAT] Successfully mapped port 8089 using upnp
2021/11/16 06:16:17.315860 [TNR] Closed connection to TVE-frontier_auth-gateway_net for ch6002 WTVT

You need to use the beta apk and check the android logs

Thanks and yes, using the beta apk via Nvidia. Though I've never tried to retrieve logs from the shield. I'll give it a shot and post

Anyone noticing picture quality issues in this beta?

@tmm1 Might not be the right place to post this.

I am on the beta watching live TV and I have had the screen go black and the video player just pauses. It has happened 3 times now. I thought first time I pushed a button on accident. lol I am able to fast forward and continue playing but it just pauses randomly. I just submitted video player data because I have no clue what it was in the logs.
(Also I haven't had this happen at all till I switched to beta couple days ago)

I will be watching a ton of TV today I will post if I find anything else!

Interesting thanks for the logs. If you find a recording where this happens please email it to support

1 Like

I did want to note, the screen does not always turn black. Sometimes the audio and video just pauses. I wonder if its possible the video is just black when its happening sometimes?
Also I tested it and sometimes if I rewind it will pause at the same spot other times it continues fine.

I am seeing a bunch of these at the top of logs and I don't remember seeing it before but might be completely irrelevant
JavaCPP Thread expire 1 line

This below logs are right after I rewound several times and then it paused at the same spot every time.
Not even sure its an error though, I seem to see these (or something similar) in the logs when like a commercial is not in dolby digital and it has to switch audio tracks (To be fair I could be skipping something specific in the logs). I think this does happen more during commercials where maybe its switching from non dolby digital to dolby digital. But it has happened sometimes in the middle of a football game as well, where I wouldn't think the audio would change.

11-20 18:31:35.865 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.8Mb/sec
11-20 18:31:38.866 24060 24060 V mpvstats: AV: 9848.195 A-V: 0.000 Dropped: 3 Cache: 5.656s video + 5.024s audio
11-20 18:31:38.866 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:31:41.866 24060 24060 V mpvstats: AV: 9851.198 A-V: 0.000 Dropped: 3 Cache: 5.656s video + 5.024s audio
11-20 18:31:41.866 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.6Mb/sec
11-20 18:31:42.095 24060 24093 V mpv     : [af] [in] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:31:42.095 24060 24093 V mpv     : [af] [userspeed] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:31:42.095 24060 24093 V mpv     : [af] [convert] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:31:42.576 24060 24093 W mpv     : [ao/audiotrack] getLatency: written=1440768 playhead=1440904 diff=4294967160 delay=178956.965000
11-20 18:31:44.867 24060 24060 V mpvstats: AV: 9851.915 A-V: -0.000 Dropped: 3 Cache: 5.239s video + 5.024s audio
11-20 18:31:44.867 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:31:47.868 24060 24060 V mpvstats: AV: 9851.915 A-V: -0.000 Dropped: 3 Cache: 5.239s video + 5.024s audio
11-20 18:31:47.868 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:31:48.384 24060 24060 V mpv     : seeking by -10.0 from 9851.915377777777
11-20 18:31:48.384 24060 24060 V mpv     : command: seek -10.0
11-20 18:31:48.387 24060 24093 V mpv     : [lavf] queuing seek to 94703.638000
11-20 18:31:48.387 24060 24093 V mpv     : [lavf] cached range 0: 94657.231689 <-> 94718.554600 (bof=0, eof=0)
11-20 18:31:48.387 24060 24093 V mpv     : [lavf] ...using this range for in-cache seek.
11-20 18:31:48.387 24060 24060 V PlayerActivity: state PLAYING -> SEEKING_BACK
11-20 18:31:48.387 24060 24093 V mpv     : [lavf] adjust seek target 94703.638000 -> 94703.511256
11-20 18:31:48.387 24060 24093 V mpv     : [lavf] seeking stream 0 (video) to packet 94703.544622/94703.494567
11-20 18:31:48.387 24060 24093 V mpv     : [lavf] seeking stream 1 (audio) to packet 94703.482600/94703.482600
11-20 18:31:48.387 24060 24093 V mpv     : [lavf] seeking stream 2 (audio) to nothing
11-20 18:31:48.388 24060 24093 V mpv     : [lavf] seeking stream 3 (sub) to nothing
11-20 18:31:48.392 24060 24093 V mpv     : event: seek
11-20 18:31:48.413 24060 24093 V mpv     : [vd] Decoder format: 1280x720 mediacodec auto/auto/auto/auto/auto CL=unknown
11-20 18:31:48.413 24060 24093 V mpv     : [cplayer] first video frame after restart shown
11-20 18:31:48.413 24060 24093 V mpv     : [af] [in] 48000Hz 5.1(side) 6ch raw-ac3 192kbps
11-20 18:31:48.413 24060 24093 V mpv     : [af] [userspeed] 48000Hz 5.1(side) 6ch raw-ac3 192kbps
11-20 18:31:48.413 24060 24093 V mpv     : [af] [convert] 48000Hz 5.1(side) 6ch raw-ac3 192kbps
11-20 18:31:48.413 24060 24093 V mpv     : [cplayer] audio ready
11-20 18:31:48.414 24060 24093 V mpv     : [cplayer] starting audio playback
11-20 18:31:48.435 24060 24093 V mpv     : event: playback-restart
11-20 18:31:48.435 24060 24093 V mpv     : [cplayer] playback restart complete @ 9841.822000, audio=playing, video=playing
11-20 18:31:48.443 24060 24060 V PlayerActivity: state SEEKING_BACK -> PLAYING
11-20 18:31:48.963 24060 24060 V mpvstats: AV: 9842.289 A-V: -0.002 Dropped: 0 Cache: 14.765s video + 14.176s audio
11-20 18:31:50.868 24060 24060 V mpvstats: AV: 9844.191 A-V: 0.000 Dropped: 0 Cache: 12.880s video + 12.256s audio
11-20 18:31:50.868 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:31:53.868 24060 24060 V mpvstats: AV: 9847.194 A-V: 0.000 Dropped: 0 Cache: 9.843s video + 9.280s audio
11-20 18:31:53.868 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.6Mb/sec
11-20 18:31:56.869 24060 24060 V mpvstats: AV: 9850.197 A-V: 0.000 Dropped: 0 Cache: 6.940s video + 6.272s audio
11-20 18:31:56.869 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:31:58.072 24060 24093 V mpv     : [af] [in] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:31:58.072 24060 24093 V mpv     : [af] [userspeed] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:31:58.073 24060 24093 V mpv     : [af] [convert] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:31:58.428 24060 24093 V mpv     : [ao/audiotrack] Underrun detected: 0 -> 1
11-20 18:31:58.431 24060 24093 V mpv     : event: audio-reconfig
11-20 18:31:58.431 24060 24093 V mpv     : [ao] Trying audio driver 'audiotrack'
11-20 18:31:58.431 24060 24093 V mpv     : [ao/audiotrack] requested format: 48000 Hz, 5.1(side) channels, raw-ac3
11-20 18:31:58.439 24060 24093 V mpv     : [ao/audiotrack] Setting bufferSize = 700 (driver=1540, min=0, max=0)
11-20 18:31:58.439 24060 24093 V mpv     : [ao/audiotrack] Using API21 initializer
11-20 18:31:58.445 24060 24093 V mpv     : [ao/audiotrack] AudioTrack.getBufferSizeInFrames = 700
11-20 18:31:58.445 24060 24093 V mpv     : [ao/audiotrack] device buffer: 700 samples.
11-20 18:31:58.445 24060 24093 V mpv     : [ao/audiotrack] using soft-buffer of 1568 samples.
11-20 18:31:58.445 24060 24093 I mpv     : [cplayer] AO: [audiotrack] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:31:58.445 24060 24093 V mpv     : [cplayer] AO: Description: Android AudioTrack audio output
11-20 18:31:58.451 24060 24093 V mpv     : event: audio-reconfig
11-20 18:31:58.451 24060 24093 V mpv     : [af] [out] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:31:58.451 24060 24093 V mpv     : [af] [in] 48000Hz 5.1(side) 6ch raw-ac3 448kbps
11-20 18:31:58.451 24060 24093 V mpv     : [af] [userspeed] 48000Hz 5.1(side) 6ch raw-ac3 448kbps
11-20 18:31:58.451 24060 24093 V mpv     : [af] [convert] 48000Hz 5.1(side) 6ch raw-ac3 448kbps
11-20 18:31:58.974 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 8 Cache: 5.088s video + 5.024s audio
11-20 18:31:59.870 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 8 Cache: 5.088s video + 5.024s audio
11-20 18:31:59.870 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:32:01.499 24060 24094 V libchannels: libchannels: creating new segment at idx=334
11-20 18:32:01.499 24060 24100 V libchannels: libchannels: pruning segment with idx=317
11-20 18:32:02.870 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 8 Cache: 5.088s video + 5.024s audio
11-20 18:32:02.871 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:32:04.998 24060 24060 V mpv     : seeking by -10.0 from 9851.982111111112
11-20 18:32:04.998 24060 24060 V mpv     : command: seek -10.0
11-20 18:32:04.999 24060 24093 V mpv     : [lavf] queuing seek to 94703.704733
11-20 18:32:04.999 24060 24093 V mpv     : [lavf] cached range 0: 94657.231689 <-> 94718.618600 (bof=0, eof=0)
11-20 18:32:04.999 24060 24093 V mpv     : [lavf] ...using this range for in-cache seek.
11-20 18:32:04.999 24060 24093 V mpv     : [lavf] adjust seek target 94703.704733 -> 94703.511256
11-20 18:32:04.999 24060 24093 V mpv     : [lavf] seeking stream 0 (video) to packet 94703.544622/94703.494567
11-20 18:32:04.999 24060 24093 V mpv     : [lavf] seeking stream 1 (audio) to packet 94703.482600/94703.482600
11-20 18:32:04.999 24060 24093 V mpv     : [lavf] seeking stream 2 (audio) to nothing
11-20 18:32:04.999 24060 24093 V mpv     : [lavf] seeking stream 3 (sub) to nothing
11-20 18:32:05.000 24060 24060 V PlayerActivity: state PLAYING -> SEEKING_BACK
11-20 18:32:05.005 24060 24093 V mpv     : event: seek
11-20 18:32:05.013 24060 24093 V mpv     : [vd] Decoder format: 1280x720 mediacodec auto/auto/auto/auto/auto CL=unknown
11-20 18:32:05.019 24060 24093 V mpv     : [cplayer] first video frame after restart shown
11-20 18:32:05.019 24060 24093 V mpv     : [af] [in] 48000Hz 5.1(side) 6ch raw-ac3 192kbps
11-20 18:32:05.019 24060 24093 V mpv     : [af] [userspeed] 48000Hz 5.1(side) 6ch raw-ac3 192kbps
11-20 18:32:05.019 24060 24093 V mpv     : [af] [convert] 48000Hz 5.1(side) 6ch raw-ac3 192kbps
11-20 18:32:05.023 24060 24093 V mpv     : event: audio-reconfig
11-20 18:32:05.023 24060 24093 V mpv     : [ao] Trying audio driver 'audiotrack'
11-20 18:32:05.023 24060 24093 V mpv     : [ao/audiotrack] requested format: 48000 Hz, 5.1(side) channels, raw-ac3
11-20 18:32:05.029 24060 24093 V mpv     : [ao/audiotrack] Setting bufferSize = 2400 (driver=1540, min=0, max=0)
11-20 18:32:05.029 24060 24093 V mpv     : [ao/audiotrack] Using API21 initializer
11-20 18:32:05.050 24060 24093 V mpv     : [ao/audiotrack] AudioTrack.getBufferSizeInFrames = 2400
11-20 18:32:05.050 24060 24093 V mpv     : event: audio-reconfig
11-20 18:32:05.050 24060 24093 V mpv     : [ao/audiotrack] device buffer: 2400 samples.
11-20 18:32:05.050 24060 24093 V mpv     : [ao/audiotrack] using soft-buffer of 5376 samples.
11-20 18:32:05.050 24060 24093 I mpv     : [cplayer] AO: [audiotrack] 48000Hz 5.1(side) 6ch raw-ac3 192kbps
11-20 18:32:05.050 24060 24093 V mpv     : [cplayer] AO: Description: Android AudioTrack audio output
11-20 18:32:05.050 24060 24093 V mpv     : [af] [out] 48000Hz 5.1(side) 6ch raw-ac3 192kbps
11-20 18:32:05.050 24060 24093 V mpv     : [cplayer] audio ready
11-20 18:32:05.050 24060 24093 V mpv     : [cplayer] starting audio playback
11-20 18:32:05.071 24060 24093 V mpv     : event: playback-restart
11-20 18:32:05.071 24060 24093 V mpv     : [cplayer] playback restart complete @ 9841.822000, audio=playing, video=playing
11-20 18:32:05.075 24060 24060 V PlayerActivity: state SEEKING_BACK -> PLAYING
11-20 18:32:05.881 24060 24060 V mpvstats: AV: 9842.539 A-V: -0.000 Dropped: 0 Cache: 14.481s video + 13.920s audio
11-20 18:32:05.881 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:32:05.981 24060 24060 V mpvstats: AV: 9842.690 A-V: -0.000 Dropped: 0 Cache: 14.481s video + 13.824s audio
11-20 18:32:08.882 24060 24060 V mpvstats: AV: 9845.592 A-V: 0.000 Dropped: 0 Cache: 11.562s video + 10.944s audio
11-20 18:32:08.882 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:32:11.887 24060 24060 V mpvstats: AV: 9848.545 A-V: 0.000 Dropped: 0 Cache: 8.475s video + 7.840s audio
11-20 18:32:11.887 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=13.6Mb/sec
11-20 18:32:14.722 24060 24093 V mpv     : [af] [in] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:32:14.722 24060 24093 V mpv     : [af] [userspeed] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:32:14.722 24060 24093 V mpv     : [af] [convert] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:32:14.890 24060 24060 V mpvstats: AV: 9851.548 A-V: 0.000 Dropped: 0 Cache: 5.472s video + 5.088s audio
11-20 18:32:14.891 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:32:15.053 24060 24093 V mpv     : [ao/audiotrack] Underrun detected: 0 -> 1
11-20 18:32:15.072 24060 24093 V mpv     : event: audio-reconfig
11-20 18:32:15.073 24060 24093 V mpv     : [ao] Trying audio driver 'audiotrack'
11-20 18:32:15.073 24060 24093 V mpv     : [ao/audiotrack] requested format: 48000 Hz, 5.1(side) channels, raw-ac3
11-20 18:32:15.078 24060 24093 V mpv     : [ao/audiotrack] Setting bufferSize = 700 (driver=1540, min=0, max=0)
11-20 18:32:15.078 24060 24093 V mpv     : [ao/audiotrack] Using API21 initializer
11-20 18:32:15.083 24060 24093 V mpv     : [ao/audiotrack] AudioTrack.getBufferSizeInFrames = 700
11-20 18:32:15.083 24060 24093 V mpv     : [ao/audiotrack] device buffer: 700 samples.
11-20 18:32:15.083 24060 24093 V mpv     : [ao/audiotrack] using soft-buffer of 1568 samples.
11-20 18:32:15.084 24060 24093 I mpv     : [cplayer] AO: [audiotrack] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:32:15.084 24060 24093 V mpv     : [cplayer] AO: Description: Android AudioTrack audio output
11-20 18:32:15.091 24060 24093 V mpv     : event: audio-reconfig
11-20 18:32:15.091 24060 24093 V mpv     : [af] [out] 48000Hz 5.1(side) 6ch raw-ac3 56kbps
11-20 18:32:15.107 24060 24093 V mpv     : [af] [in] 48000Hz 5.1(side) 6ch raw-ac3 448kbps
11-20 18:32:15.107 24060 24093 V mpv     : [af] [userspeed] 48000Hz 5.1(side) 6ch raw-ac3 448kbps
11-20 18:32:15.107 24060 24093 V mpv     : [af] [convert] 48000Hz 5.1(side) 6ch raw-ac3 448kbps
11-20 18:32:16.059 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 6 Cache: 5.105s video + 5.024s audio
11-20 18:32:17.891 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 6 Cache: 5.105s video + 5.024s audio
11-20 18:32:17.892 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.8Mb/sec
11-20 18:32:20.891 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 6 Cache: 5.105s video + 5.024s audio
11-20 18:32:20.892 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=16.1Mb/sec
11-20 18:32:23.892 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 6 Cache: 5.105s video + 5.024s audio
11-20 18:32:23.892 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.6Mb/sec
11-20 18:32:26.893 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 6 Cache: 5.105s video + 5.024s audio
11-20 18:32:26.893 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:32:29.894 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 6 Cache: 5.105s video + 5.024s audio
11-20 18:32:29.894 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:32:30.871 24060 24101 V libchannels: libchannels: creating new segment at idx=335
11-20 18:32:30.871 24060 24094 V libchannels: libchannels: pruning segment with idx=318
11-20 18:32:32.895 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 6 Cache: 5.105s video + 5.024s audio
11-20 18:32:32.895 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:32:35.895 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 6 Cache: 5.105s video + 5.024s audio
11-20 18:32:35.895 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:32:38.895 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 6 Cache: 5.105s video + 5.024s audio
11-20 18:32:38.896 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
11-20 18:32:41.896 24060 24060 V mpvstats: AV: 9851.982 A-V: -0.000 Dropped: 6 Cache: 5.105s video + 5.024s audio
11-20 18:32:41.896 24060 24060 V streamstats: strength=100% quality=100% symbol=100% rate=17.7Mb/sec
1 Like

I feel bad for saying this as I know you are doing a lot of work to help us out but for me(and my wife agrees) the beta 111.19.313 has had more issues than the alpha 111.11.2054.

We are now seeing skipping issues in recordings. Before never had any issues with recordings. The 3 logs below we got while watching a recording. All 3 seem to be different issues. I do have a recording now where at the 3 minutes mark I can replicate the "Audio/Video desynchronisation detected" issue (it is a very long recording). I don't know if I can export it to email it or if it will be too big.
Also becuase several mention it might be performance I did restart the shield in hopes that it would fix it. And it didn't :frowning:

// Example of desynchronisation
11-21 12:31:38.139  6961  6961 V mpvstats: AV: 43.183 A-V: 0.000 Dropped: 3 Cache: 30.030s video + 29.248s audio
11-21 12:31:41.140  6961  6961 V mpvstats: AV: 46.186 A-V: 0.000 Dropped: 3 Cache: 29.830s video + 29.248s audio
11-21 12:31:44.140  6961  6961 V mpvstats: AV: 49.189 A-V: 0.000 Dropped: 3 Cache: 29.913s video + 29.184s audio
11-21 12:31:47.142  6961  6961 V mpvstats: AV: 52.192 A-V: 0.000 Dropped: 3 Cache: 30.113s video + 29.344s audio
11-21 12:31:49.386  6961  7074 W mpv     : [ad] Invalid audio PTS: 54.877143 -> 56.416022
11-21 12:31:49.391  6961  7074 W mpv     : [cplayer] 
11-21 12:31:49.391  6961  7074 W mpv     : [cplayer] Audio/Video desynchronisation detected! Possible reasons include too slow
11-21 12:31:49.391  6961  7074 W mpv     : [cplayer] hardware, temporary CPU spikes, broken drivers, and broken files. Audio
11-21 12:31:49.391  6961  7074 W mpv     : [cplayer] position will not match to the video (see A-V status field).
11-21 12:31:49.391  6961  7074 W mpv     : [cplayer] 
11-21 12:31:50.143  6961  6961 V mpvstats: AV: 55.195 A-V: 1.232 Dropped: 3 Cache: 28.445s video + 27.744s audio
11-21 12:31:53.144  6961  6961 V mpvstats: AV: 59.499 A-V: 0.220 Dropped: 3 Cache: 28.428s video + 27.424s audio
11-21 12:31:56.144  6961  6961 V mpvstats: AV: 62.719 A-V: 0.000 Dropped: 3 Cache: 28.045s video + 27.360s audio
11-21 12:31:58.376  6961  9249 V ApiServer: REQUEST: GET /log
11-21 12:31:58.590  6961  6972 W System  : A resource failed to call end. 
11-21 12:31:59.146  6961  6961 V mpvstats: AV: 65.705 A-V: 0.000 Dropped: 3 Cache: 27.945s video + 27.424s audio
11-21 12:32:02.146  6961  6961 V mpvstats: AV: 68.725 A-V: 0.000 Dropped: 3 Cache: 28.078s video + 27.360s audio
11-21 12:32:05.146  6961  6961 V mpvstats: AV: 71.728 A-V: 0.000 Dropped: 3 Cache: 27.794s video + 27.104s audio
11-21 12:32:08.146  6961  6961 V mpvstats: AV: 74.731 A-V: 0.000 Dropped: 3 Cache: 28.045s video + 27.104s audio
11-21 12:32:11.147  6961  6961 V mpvstats: AV: 77.734 A-V: 0.000 Dropped: 3 Cache: 27.895s video + 27.104s audio
11-21 12:32:14.148  6961  6961 V mpvstats: AV: 80.737 A-V: 0.000 Dropped: 3 Cache: 28.028s video + 27.392s audio
11-21 12:32:17.149  6961  6961 V mpvstats: AV: 83.740 A-V: 0.000 Dropped: 3 Cache: 27.961s video + 27.200s audio
11-21 12:32:20.150  6961  6961 V mpvstats: AV: 86.726 A-V: 0.000 Dropped: 3 Cache: 28.028s video + 27.200s audio
11-21 12:32:23.150  6961  6961 V mpvstats: AV: 89.729 A-V: 0.000 Dropped: 3 Cache: 27.945s video + 27.200s audio
11-21 12:32:26.152  6961  6961 V mpvstats: AV: 92.732 A-V: 0.000 Dropped: 3 Cache: 27.945s video + 27.360s audio
11-21 12:32:29.152  6961  6961 V mpvstats: AV: 95.735 A-V: 0.000 Dropped: 3 Cache: 30.230s video + 29.536s audio
11-21 12:32:32.153  6961  6961 V mpvstats: AV: 98.738 A-V: 0.000 Dropped: 3 Cache: 44.061s video + 43.264s audio
11-21 12:32:35.154  6961  6961 V mpvstats: AV: 101.741 A-V: 0.000 Dropped: 3 Cache: 43.961s video + 43.264s audio
11-21 12:32:38.168  6961  6961 V mpvstats: AV: 104.744 A-V: 0.000 Dropped: 3 Cache: 43.961s video + 43.328s audio
11-21 12:32:41.170  6961  6961 V mpvstats: AV: 107.747 A-V: 0.000 Dropped: 3 Cache: 43.860s video + 43.200s audio
11-21 12:32:44.170  6961  6961 V mpvstats: AV: 110.750 A-V: 0.000 Dropped: 3 Cache: 43.927s video + 43.200s audio
11-21 12:32:47.170  6961  6961 V mpvstats: AV: 113.753 A-V: 0.000 Dropped: 3 Cache: 43.961s video + 43.232s audio
11-21 12:32:50.170  6961  6961 V mpvstats: AV: 116.756 A-V: 0.000 Dropped: 3 Cache: 44.027s video + 43.328s audio
11-21 12:32:53.184  6961  6961 V mpvstats: AV: 119.742 A-V: 0.000 Dropped: 3 Cache: 43.877s video + 43.232s audio
11-21 12:32:54.580  6961  7074 W mpv     : [ad] Invalid audio PTS: 121.630415 -> 123.968022
11-21 12:32:56.184  6961  6961 V mpvstats: AV: 121.895 A-V: 2.044 Dropped: 3 Cache: 41.792s video + 40.224s audio
11-21 12:32:57.028  6961  9271 V ApiServer: REQUEST: GET /log
11-21 12:32:57.653  6961  7074 W mpv     : [ad] Invalid audio PTS: 127.071129 -> 140.800022
11-21 12:32:57.653  6961  7074 W mpv     : [cplayer] Reset playback due to audio timestamp reset.
11-21 12:32:57.675  6961  9161 D ACodec  : REUSING read fence 185 as write fence in submitRegularOutputBuffers
11-21 12:32:57.675  6961  9161 D ACodec  : REUSING read fence 187 as write fence in submitRegularOutputBuffers
11-21 12:32:57.677  6961  7074 V mpv     : [cplayer] blocked, waiting for old audio to play
11-21 12:32:57.677  6961  7074 V mpv     : [cplayer] audio ready
11-21 12:32:57.705  6961  7074 V mpv     : [vd] Decoder format: 1280x720 mediacodec auto/auto/auto/auto/auto CL=unknown
11-21 12:32:57.706  6961  7074 V mpv     : [cplayer] first video frame after restart shown
11-21 12:32:57.706  6961  7074 V mpv     : event: playback-restart
11-21 12:32:57.706  6961  7074 V mpv     : [cplayer] starting audio playback
11-21 12:32:57.706  6961  7074 V mpv     : [cplayer] playback restart complete @ 125.481456, audio=playing, video=playing
11-21 12:32:58.185  6961  6961 V mpvstats: AV: 125.481 A-V: 0.000 Dropped: 0 Cache: 41.675s video + 25.568s audio
11-21 12:32:58.244  6961  7074 W mpv     : [cplayer] 
11-21 12:32:58.244  6961  7074 W mpv     : [cplayer] Audio/Video desynchronisation detected! Possible reasons include too slow
11-21 12:32:58.244  6961  7074 W mpv     : [cplayer] hardware, temporary CPU spikes, broken drivers, and broken files. Audio
11-21 12:32:58.245  6961  7074 W mpv     : [cplayer] position will not match to the video (see A-V status field).
11-21 12:32:58.245  6961  7074 W mpv     : [cplayer] 
11-21 12:32:59.186  6961  6961 V mpvstats: AV: 126.966 A-V: 14.827 Dropped: 0 Cache: 41.742s video + 26.208s audio
11-21 12:32:59.356  6961  7074 W mpv     : [cplayer] Invalid video timestamp: 127.283256 -> 141.130422 (13.847167 > 5.000000)

// Example of underrun skip
11-21 11:59:53.677 24060 24060 V mpvstats: AV: 4835.587 A-V: 0.000 Dropped: 0 Cache: 4.571s video + 3.776s audio
11-21 11:59:56.676 24060 24060 V mpvstats: AV: 4838.573 A-V: 0.000 Dropped: 0 Cache: 1.702s video + 0.896s audio
11-21 11:59:57.882 24060 24093 V mpv     : [ao/audiotrack] Underrun detected: 2 -> 3
11-21 11:59:57.897 24060 24093 W mpv     : [cplayer] Audio device underrun detected.
11-21 11:59:58.258 24060 24093 W mpv     : [ao/audiotrack] getLatency: written=265146352 playhead=265146757 diff=4294966891 delay=76695.837339
11-21 11:59:59.676 24060 24060 V mpvstats: AV: 4840.175 A-V: 0.000 Dropped: 0 Cache: 0.083s video + 0.000s audio
11-21 12:00:02.025 24060 24093 V mpv     : [cplayer] restarting audio after underrun
11-21 12:00:02.050 24060 22980 W AudioTrack: releaseBuffer() track 0x2f2b033400 disabled due to previous underrun, restarting
11-21 12:00:02.533 24060 22914 V HTTP    : Requesting GET http://192.168.0.100:8089/dvr/files/53?raw=false
11-21 12:00:02.677 24060 24060 V mpvstats: AV: 4840.442 A-V: 0.000 Dropped: 0 Cache: 6.356s video + 5.536s audio
11-21 12:00:03.583 24060 22914 V HTTP    : Requesting GET http://192.168.0.100:8089/dvr/files/53?raw=false
11-21 12:00:03.762 24060 24070 I ls.dvr.app.bet: Background concurrent copying GC freed 363068(12MB) AllocSpace objects, 16(1060KB) LOS objects, 50% free, 14MB/28MB, paused 112us total 169.667ms
11-21 12:00:03.769 24060 24068 W System  : A resource failed to call end. 
11-21 12:00:04.664 24060 22914 V HTTP    : Requesting GET http://192.168.0.100:8089/dvr/files/53?raw=false
11-21 12:00:05.214 24060 22914 V HTTP    : Requesting GET http://192.168.0.100:8089/dvr/files/53?raw=false
11-21 12:00:05.678 24060 24060 V mpvstats: AV: 4843.445 A-V: 0.000 Dropped: 0 Cache: 28.078s video + 27.136s audio
11-21 12:00:07.413 24060 24060 V mpv     : seeking by -10.0 from 4845.179777777778
11-21 12:00:07.414 24060 24060 V mpv     : command: seek -10.0
11-21 12:00:07.415 24060 24060 V PlayerActivity: state PLAYING -> SEEKING_BACK
11-21 12:00:07.422 24060 24093 V mpv     : [lavf] queuing seek to 55871.424845
11-21 12:00:07.422 24060 24093 V mpv     : [lavf] cached range 0: 55867.577678 <-> 55909.301067 (bof=0, eof=0)
11-21 12:00:07.422 24060 24093 V mpv     : [lavf] ...using this range for in-cache seek.
11-21 12:00:07.422 24060 24093 V mpv     : [lavf] adjust seek target 55871.424845 -> 55871.348111
11-21 12:00:07.422 24060 24093 V mpv     : [lavf] seeking stream 0 (video) to packet 55871.381478/55871.331422
11-21 12:00:07.422 24060 24093 V mpv     : [lavf] seeking stream 1 (audio) to packet 55871.317089/55871.317089
11-21 12:00:07.422 24060 24093 V mpv     : [lavf] seeking stream 2 (audio) to nothing
11-21 12:00:07.422 24060 24093 V mpv     : [lavf] seeking stream 3 (sub) to nothing
11-21 12:00:07.444 24060 24093 V mpv     : event: seek
11-21 12:00:07.471 24060 24093 V mpv     : [vd] Decoder format: 1280x720 mediacodec auto/auto/auto/auto/auto CL=unknown
11-21 12:00:07.472 24060 24093 V mpv     : [cplayer] first video frame after restart shown
11-21 12:00:07.473 24060 24093 V mpv     : [cplayer] audio ready
11-21 12:00:07.473 24060 24093 V mpv     : [cplayer] starting audio playback
11-21 12:00:07.497 24060 24093 V mpv     : event: playback-restart
11-21 12:00:07.497 24060 24093 V mpv     : [cplayer] playback restart complete @ 4835.136411, audio=playing, video=playing
11-21 12:00:07.632 24060 24060 V PlayerActivity: state SEEKING_BACK -> PLAYING
11-21 12:00:07.665 24060 24060 V mpvstats: AV: 4835.320 A-V: -0.000 Dropped: 1 Cache: 38.171s video + 37.344s audio
11-21 12:00:08.695 24060 24060 V mpvstats: AV: 4836.304 A-V: 0.000 Dropped: 1 Cache: 37.054s video + 36.352s audio
11-21 12:00:11.695 24060 24060 V mpvstats: AV: 4839.324 A-V: 0.000 Dropped: 1 Cache: 34.184s video + 33.344s audio

// Example of performance skip
11-21 12:15:30.484 24060 24060 V mpvstats: AV: 5758.125 A-V: 0.000 Dropped: 1 Cache: 31.865s video + 31.200s audio
11-21 12:15:31.243 24060 24093 W mpv     : [ad] Invalid audio PTS: 5759.275736 -> 5763.136022
11-21 12:15:31.250 24060 24093 W mpv     : [cplayer] 
11-21 12:15:31.250 24060 24093 W mpv     : [cplayer] Audio/Video desynchronisation detected! Possible reasons include too slow
11-21 12:15:31.250 24060 24093 W mpv     : [cplayer] hardware, temporary CPU spikes, broken drivers, and broken files. Audio
11-21 12:15:31.250 24060 24093 W mpv     : [cplayer] position will not match to the video (see A-V status field).
11-21 12:15:31.250 24060 24093 W mpv     : [cplayer] 
11-21 12:15:33.485 24060 24060 V mpvstats: AV: 5759.643 A-V: 3.553 Dropped: 1 Cache: 27.978s video + 25.792s audio
11-21 12:15:36.495 24060 24060 V mpvstats: AV: 5765.649 A-V: 2.304 Dropped: 1 Cache: 27.978s video + 25.024s audio
11-21 12:15:39.499 24060 24060 V mpvstats: AV: 5770.654 A-V: 0.302 Dropped: 1 Cache: 27.945s video + 27.008s audio
11-21 12:15:42.499 24060 24060 V mpvstats: AV: 5773.991 A-V: 0.001 Dropped: 1 Cache: 27.911s video + 27.232s audio

Again thanks for all the work. Sorry for the bad news :frowning: I also am sure this is a very difficult thing to track/down and fix so I do appreciate all the work.

Something strange is happening in this case where it thinks the audio is switching bitrates.

This issue would only happen with surround on.

This one generally means a blip in the recording. I would think the alpha build would react the same way with such a recording.

I did a ULTRA quick test of the repeatable section. And the alpha build with that recording and it did the same thing so you are absolutely correct! Sorry about that!
For the most part recording have been great! I will keep an eye on it, but maybe that recording was just bad! Because it had multiple issues throughout.

I can try surround sound off on the beta. To see if that resolved the weird pause issue. Because I do have surround sound on in that specific alpha build and it is almost perfect.

Also I know its a weekend :slight_smile: so thanks for the reply.

@tmm1 So I used beta all day today. Probably 4+ hours with surround sound off and no issues at all.
Then turned surround sound on and without planning my friend (who also uses channels came over) and we watched a football game. Absolutely ZERO pauses all day and if there were any skips I didn't notice it. (He mentioned 2 weeks ago he had pausing as well in channels) and during that time he noticed the signal on hd home run from verizon fios was bad.

So that might explain the bad recording and the pausing??? The dates don't line up exactly as they were different weekends but maybe they were doing upgrades in their neighborhood then mine? Either way I will 100% keep an eye on it. But I also wanted to let you know I might have blamed the beta for a possible fios issues and I do apologize!

Curious if you know if there is bad signal the video would pause? I don't care either way just curious if that could explain it?

Thanks again for all the solid work I will keep an eye on it!

It's just a bug. I'm working on tracking it down.

2 Likes

The pausing bug is fixed in v2021.11.29.2349 (uploading now)

1 Like