That looks like a different issue, unrelated to audio. Seems more like a regular buffering event not split-second pause.
It isn't any different, it is exactly the same, the log is exactly the same too.
type=audio, duration=0.0
Watch the video I posted earlier that shows the buffering and the time bar growing.
The split second pausing was fixed by using a different decoder.
As I said before, if I was recording the same program, the recording never experiences the same issue. It only happens watching live.
EDIT: Does using Transcoding on the server bypas the Live TV Buffer on the Client? I don't see any action in the Client log while transcoding.
No it's not. The "End buffering" lines show much longer wait times.
This doesn't matter anymore with the new beta because it does not pause when audio is 0.0, only when video packets run out.
I understand that. I don't have an explanation for how that's possible because live tv and recordings use the same player.
Yes.
It's really challenging to help you because you constantly keep switching devices. Can you please stick to one device and one bug at a time? Are you still having issues on the Sony TV, and if so what is happening?
1 Like
My fox news is back to buffering like crazy again today, dang made it almost 2 days.. diag submitted 1:25
OK I rebooted the SONY TV and started a new stream from Fox News TVE.
I've been following the LOG and I just had a pause event and saw this error.
**04-02 14:45:57.945 6854 6957 E mpv : [ffmpeg/video] h264: error while decoding MB 55 18, bytestream -11**
**04-02 14:45:57.947 6854 6957 V mpv : [ffmpeg/video] h264: concealing 2154 DC, 2154 AC, 2154 MV errors in P frame**
Could this be something?
Here is the LOG of the Event:
04-02 14:43:12.927 6854 6957 D mpv : [ffmpeg/video] h264: Reinit context to 1280x720, pix_fmt: yuv420p
04-02 14:43:13.060 6854 6957 V mpv : [vd] Decoder format: 1280x720 yuv420p auto/auto/auto/auto/auto CL=mpeg2/4/h264 (auto 0.000000/0.000000/0.000000)
04-02 14:43:13.061 6854 6957 V mpv : [vf] [in] 1280x720 yuv420p bt.709/bt.709/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
04-02 14:43:13.091 6854 6957 V mpv : [vf] [userdeint] 1280x720 yuv420p bt.709/bt.709/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
04-02 14:43:13.092 6854 6957 V mpv : [vf] [autorotate] 1280x720 yuv420p bt.709/bt.709/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
04-02 14:43:13.092 6854 6957 V mpv : [vf] [convert] 1280x720 yuv420p bt.709/bt.709/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
04-02 14:43:13.092 6854 6957 V mpv : [vf] [out] 1280x720 yuv420p bt.709/bt.709/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
04-02 14:43:13.092 6854 6957 I mpv : [cplayer] VO: [gpu] 1280x720 yuv420p
04-02 14:43:13.092 6854 6957 V mpv : event: video-reconfig
04-02 14:43:13.096 6854 6957 V mpv : event: video-reconfig
04-02 14:43:13.096 6854 6957 V mpv : [cplayer] VO: Description: Shader-based GPU Renderer
04-02 14:43:15.737 6854 6854 V mpvstats: AV: 1464.856 A-V: 0.000 Dropped: 0 Cache: 9.131s + 0KB
04-02 14:43:18.739 6854 6854 V mpvstats: AV: 1467.859 A-V: 0.000 Dropped: 0 Cache: 10.155s + 0KB
04-02 14:43:21.741 6854 6854 V mpvstats: AV: 1470.862 A-V: 0.000 Dropped: 0 Cache: 11.264s + 0KB
04-02 14:43:24.743 6854 6854 V mpvstats: AV: 1473.865 A-V: 0.000 Dropped: 0 Cache: 12.373s + 0KB
04-02 14:43:27.745 6854 6854 V mpvstats: AV: 1476.868 A-V: 0.000 Dropped: 0 Cache: 13.483s + 0KB
04-02 14:43:30.747 6854 6854 V mpvstats: AV: 1479.871 A-V: 0.000 Dropped: 0 Cache: 10.581s + 0KB
04-02 14:43:33.747 6854 6854 V mpvstats: AV: 1482.874 A-V: 0.001 Dropped: 0 Cache: 11.648s + 0KB
04-02 14:43:36.748 6854 6854 V mpvstats: AV: 1485.877 A-V: 0.000 Dropped: 0 Cache: 12.587s + 0KB
04-02 14:43:39.749 6854 6854 V mpvstats: AV: 1488.880 A-V: 0.000 Dropped: 0 Cache: 11.605s + 0KB
04-02 14:43:42.750 6854 6854 V mpvstats: AV: 1491.883 A-V: 0.000 Dropped: 0 Cache: 10.795s + 0KB
04-02 14:43:45.751 6854 6854 V mpvstats: AV: 1494.886 A-V: 0.000 Dropped: 0 Cache: 11.861s + 0KB
04-02 14:43:48.752 6854 6854 V mpvstats: AV: 1497.872 A-V: 0.000 Dropped: 0 Cache: 13.013s + 0KB
04-02 14:43:51.754 6854 6854 V mpvstats: AV: 1500.875 A-V: 0.000 Dropped: 0 Cache: 13.995s + 0KB
04-02 14:43:54.755 6854 6854 V mpvstats: AV: 1503.878 A-V: 0.000 Dropped: 0 Cache: 10.965s + 0KB
04-02 14:43:57.756 6854 6854 V mpvstats: AV: 1506.881 A-V: 0.000 Dropped: 0 Cache: 12.117s + 0KB
04-02 14:44:00.757 6854 6854 V mpvstats: AV: 1509.884 A-V: 0.000 Dropped: 0 Cache: 13.227s + 0KB
04-02 14:44:03.758 6854 6854 V mpvstats: AV: 1512.887 A-V: 0.000 Dropped: 0 Cache: 14.251s + 0KB
04-02 14:44:06.759 6854 6854 V mpvstats: AV: 1515.890 A-V: 0.000 Dropped: 0 Cache: 11.349s + 0KB
04-02 14:44:09.759 6854 6854 V mpvstats: AV: 1518.893 A-V: 0.000 Dropped: 0 Cache: 12.416s + 0KB
04-02 14:44:12.760 6854 6854 V mpvstats: AV: 1521.880 A-V: 0.000 Dropped: 0 Cache: 13.568s + 0KB
04-02 14:44:15.761 6854 6854 V mpvstats: AV: 1524.899 A-V: 0.000 Dropped: 0 Cache: 13.867s + 0KB
04-02 14:44:18.762 6854 6854 V mpvstats: AV: 1527.886 A-V: 0.000 Dropped: 0 Cache: 11.648s + 0KB
04-02 14:44:21.763 6854 6854 V mpvstats: AV: 1530.889 A-V: 0.000 Dropped: 0 Cache: 12.757s + 0KB
04-02 14:44:24.766 6854 6854 V mpvstats: AV: 1533.892 A-V: 0.000 Dropped: 0 Cache: 13.867s + 0KB
04-02 14:44:27.766 6854 6854 V mpvstats: AV: 1536.895 A-V: 0.000 Dropped: 0 Cache: 10.880s + 0KB
04-02 14:44:30.767 6854 6854 V mpvstats: AV: 1539.898 A-V: 0.000 Dropped: 0 Cache: 7.808s + 0KB
04-02 14:44:33.768 6854 6854 V mpvstats: AV: 1542.901 A-V: 0.000 Dropped: 0 Cache: 13.013s + 0KB
04-02 14:44:36.769 6854 6854 V mpvstats: AV: 1545.904 A-V: 0.000 Dropped: 0 Cache: 10.027s + 0KB
04-02 14:44:39.769 6854 6854 V mpvstats: AV: 1548.907 A-V: 0.000 Dropped: 0 Cache: 6.997s + 0KB
04-02 14:44:42.770 6854 6854 V mpvstats: AV: 1551.893 A-V: 0.000 Dropped: 0 Cache: 4.011s + 0KB
04-02 14:44:45.770 6854 6854 V mpvstats: AV: 1554.896 A-V: 0.000 Dropped: 0 Cache: 1.024s + 0KB
04-02 14:44:46.709 6854 6957 V mpv : event: unpause
04-02 14:44:46.709 6854 6957 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 46%) [0.467122s].
04-02 14:44:46.709 6854 6957 V mpv : property: buffering = true
04-02 14:44:46.709 6854 6854 V PlayerActivity: state PLAYING -> BUFFERING
04-02 14:44:46.712 6854 6854 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=1523.5978998888888, end=1556.3472887777777}], cache-end=1556.3806443333333, reader-pts=1555.9135221111112, cache-duration=0.46712222222208766, eof=false, underrun=true, idle=false, total-bytes=32547200, fw-bytes=592960, debug-low-level-seeks=0, debug-ts-last=1555.8134223333334, ts-per-stream=[{type=video, duration=0.46712222222208766, reader=1555.9302111111112, end=1556.3973333333333}, {type=audio, duration=0.0, reader=1556.4186333333334, end=1556.4186333333334}]}
04-02 14:44:48.770 6854 6854 V mpvstats: AV: 1555.847 A-V: 0.000 Dropped: 0 Cache: 0.467s + 0KB
04-02 14:44:51.771 6854 6854 V mpvstats: AV: 1555.847 A-V: 0.000 Dropped: 0 Cache: 0.467s + 0KB
04-02 14:44:54.772 6854 6854 V mpvstats: AV: 1555.847 A-V: 0.000 Dropped: 0 Cache: 0.467s + 0KB
04-02 14:44:55.079 6854 8919 V ApiServer: REQUEST: GET /log
04-02 14:44:55.079 6854 8919 I hls : goroutine 17 [running, locked to thread]:
04-02 14:44:55.079 6854 8919 I hls : main.FullStackTrace(0x8cc4c070, 0x8cc38f50)
04-02 14:44:55.079 6854 8919 I hls : /Users/fancybox/source/channels-android/vendor/libhls/channels-server/hls/libhls/hls_c.go:249 +0x80
04-02 14:44:55.079 6854 8919 I hls : main.hls_log_stack()
04-02 14:44:55.079 6854 8919 I hls : /Users/fancybox/source/channels-android/vendor/libhls/channels-server/hls/libhls/hls_c.go:259 +0x14
04-02 14:44:55.079 6854 8919 I hls : main._cgoexpwrap_277a0c6059f4_hls_log_stack()
04-02 14:44:55.079 6854 8919 I hls : _cgo_gotypes.go:299 +0x14
04-02 14:44:55.079 6854 8919 I hls :
04-02 14:44:55.079 6854 8919 I hls : goroutine 6 [syscall]:
04-02 14:44:55.079 6854 8919 I hls : os/signal.signal_recv(0x0)
04-02 14:44:55.079 6854 8919 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/runtime/sigqueue.go:147 +0x14c
04-02 14:44:55.079 6854 8919 I hls : os/signal.loop()
04-02 14:44:55.079 6854 8919 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/os/signal/signal_unix.go:23 +0x14
04-02 14:44:55.079 6854 8919 I hls : created by os/signal.Notify.func1
04-02 14:44:55.079 6854 8919 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/os/signal/signal.go:127 +0x38
04-02 14:44:55.079 6854 8919 I hls :
04-02 14:44:55.079 6854 8919 I hls : goroutine 19 [select]:
04-02 14:44:55.079 6854 8919 I hls : github.com/grafov/kiwi.processSink(0x8cd8e080)
04-02 14:44:55.079 6854 8919 I hls : /Users/fancybox/go/pkg/mod/github.com/grafov/kiwi@v0.3.1/sink.go:327 +0x90
04-02 14:44:55.079 6854 8919 I hls : created by github.com/grafov/kiwi.SinkTo
04-02 14:44:55.079 6854 8919 I hls : /Users/fancybox/go/pkg/mod/github.com/grafov/kiwi@v0.3.1/sink.go:111 +0x310
04-02 14:44:57.772 6854 6854 V mpvstats: AV: 1555.847 A-V: 0.000 Dropped: 0 Cache: 0.467s + 0KB
04-02 14:45:00.772 6854 6854 V mpvstats: AV: 1555.847 A-V: 0.000 Dropped: 0 Cache: 0.467s + 0KB
04-02 14:45:03.773 6854 6854 V mpvstats: AV: 1555.847 A-V: 0.000 Dropped: 0 Cache: 0.467s + 0KB
04-02 14:45:05.068 6854 8408 V Streamer: mpv read bytes:0 after retries:32000 (pos:1135542272)
04-02 14:45:06.774 6854 6854 V mpvstats: AV: 1555.847 A-V: 0.000 Dropped: 0 Cache: 0.484s + 0KB
04-02 14:45:09.775 6854 6854 V mpvstats: AV: 1555.847 A-V: 0.000 Dropped: 0 Cache: 0.484s + 0KB
04-02 14:45:12.776 6854 6854 V mpvstats: AV: 1555.847 A-V: 0.000 Dropped: 0 Cache: 0.484s + 0KB
04-02 14:45:15.777 6854 6854 V mpvstats: AV: 1555.847 A-V: 0.000 Dropped: 0 Cache: 0.484s + 0KB
04-02 14:45:18.777 6854 6854 V mpvstats: AV: 1555.847 A-V: 0.000 Dropped: 0 Cache: 0.469s + 0KB
04-02 14:45:18.921 6854 6957 V mpv : event: unpause
04-02 14:45:18.921 6854 6957 V mpv : [cplayer] End buffering (waited 32.207532 secs) [1.706667s].
04-02 14:45:18.930 6854 6957 V mpv : property: buffering = false
04-02 14:45:18.933 6854 6854 V PlayerActivity: state BUFFERING -> PLAYING
04-02 14:45:19.198 6854 6957 E mpv : [ffmpeg/video] h264: error while decoding MB 57 41, bytestream -6
04-02 14:45:19.200 6854 6957 V mpv : [ffmpeg/video] h264: concealing 312 DC, 312 AC, 312 MV errors in P frame
04-02 14:45:19.902 6854 6854 V mpvstats: AV: 1557.081 A-V: 0.000 Dropped: 19 Cache: 2.560s + 0KB
04-02 14:45:21.778 6854 6854 V mpvstats: AV: 1558.967 A-V: 0.000 Dropped: 19 Cache: 0.597s + 0KB
04-02 14:45:22.559 6854 6957 V mpv : event: unpause
04-02 14:45:22.559 6854 6957 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 23%) [0.233556s].
04-02 14:45:22.561 6854 6957 V mpv : property: buffering = true
04-02 14:45:22.561 6854 6854 V PlayerActivity: state PLAYING -> BUFFERING
04-02 14:45:22.562 6854 6854 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=1531.7894221111112, end=1558.432688777778}], cache-end=1560.0676665555557, reader-pts=1559.8341110000001, cache-duration=0.2335555555555402, eof=false, underrun=true, idle=false, total-bytes=31279296, fw-bytes=269632, debug-low-level-seeks=0, debug-ts-last=1559.7340001111113, ts-per-stream=[{type=video, duration=0.2335555555555402, reader=1559.8508000000002, end=1560.0843555555557}, {type=audio, duration=0.0, reader=1560.0879666666667, end=1560.0879666666667}]}
04-02 14:45:24.779 6854 6854 V mpvstats: AV: 1559.751 A-V: 0.000 Dropped: 19 Cache: 0.234s + 0KB
04-02 14:45:26.835 6854 8928 V ApiServer: REQUEST: GET /log
04-02 14:45:26.836 6854 8928 I hls : goroutine 17 [running, locked to thread]:
04-02 14:45:26.836 6854 8928 I hls : main.FullStackTrace(0x8cc4c070, 0x8cc38f50)
04-02 14:45:26.836 6854 8928 I hls : /Users/fancybox/source/channels-android/vendor/libhls/channels-server/hls/libhls/hls_c.go:249 +0x80
04-02 14:45:26.836 6854 8928 I hls : main.hls_log_stack()
04-02 14:45:26.836 6854 8928 I hls : /Users/fancybox/source/channels-android/vendor/libhls/channels-server/hls/libhls/hls_c.go:259 +0x14
04-02 14:45:26.836 6854 8928 I hls : main._cgoexpwrap_277a0c6059f4_hls_log_stack()
04-02 14:45:26.836 6854 8928 I hls : _cgo_gotypes.go:299 +0x14
04-02 14:45:26.836 6854 8928 I hls :
04-02 14:45:26.836 6854 8928 I hls : goroutine 6 [syscall]:
04-02 14:45:26.836 6854 8928 I hls : os/signal.signal_recv(0x0)
04-02 14:45:26.836 6854 8928 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/runtime/sigqueue.go:147 +0x14c
04-02 14:45:26.836 6854 8928 I hls : os/signal.loop()
04-02 14:45:26.836 6854 8928 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/os/signal/signal_unix.go:23 +0x14
04-02 14:45:26.836 6854 8928 I hls : created by os/signal.Notify.func1
04-02 14:45:26.836 6854 8928 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/os/signal/signal.go:127 +0x38
04-02 14:45:26.836 6854 8928 I hls :
04-02 14:45:26.836 6854 8928 I hls : goroutine 19 [select]:
04-02 14:45:26.836 6854 8928 I hls : github.com/grafov/kiwi.processSink(0x8cd8e080)
04-02 14:45:26.836 6854 8928 I hls : /Users/fancybox/go/pkg/mod/github.com/grafov/kiwi@v0.3.1/sink.go:327 +0x90
04-02 14:45:26.836 6854 8928 I hls : created by github.com/grafov/kiwi.SinkTo
04-02 14:45:26.836 6854 8928 I hls : /Users/fancybox/go/pkg/mod/github.com/grafov/kiwi@v0.3.1/sink.go:111 +0x310
04-02 14:45:27.779 6854 6854 V mpvstats: AV: 1559.751 A-V: 0.000 Dropped: 19 Cache: 0.234s + 0KB
04-02 14:45:30.780 6854 6854 V mpvstats: AV: 1559.751 A-V: 0.000 Dropped: 19 Cache: 0.234s + 0KB
04-02 14:45:33.781 6854 6854 V mpvstats: AV: 1559.751 A-V: 0.000 Dropped: 19 Cache: 0.234s + 0KB
04-02 14:45:36.781 6854 6854 I chatty : uid=10147(com.getchannels.dvr.app.beta) identical 1 line
04-02 14:45:39.782 6854 6854 V mpvstats: AV: 1559.751 A-V: 0.000 Dropped: 19 Cache: 0.234s + 0KB
04-02 14:45:42.783 6854 6854 V mpvstats: AV: 1559.751 A-V: 0.000 Dropped: 19 Cache: 0.234s + 0KB
04-02 14:45:45.784 6854 6854 V mpvstats: AV: 1559.751 A-V: 0.000 Dropped: 19 Cache: 0.234s + 0KB
04-02 14:45:48.784 6854 6854 V mpvstats: AV: 1559.751 A-V: 0.000 Dropped: 19 Cache: 0.234s + 0KB
04-02 14:45:50.213 6854 6862 W System : A resource failed to call end.
04-02 14:45:50.214 6854 6862 W System : A resource failed to call end.
04-02 14:45:51.549 6854 8408 V Streamer: mpv read bytes:0 after retries:32000 (pos:1140097024)
04-02 14:45:51.728 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 23% -> 25%) [0.250244s].
04-02 14:45:51.787 6854 6854 V mpvstats: AV: 1559.751 A-V: 0.000 Dropped: 19 Cache: 0.250s + 0KB
04-02 14:45:54.787 6854 6854 V mpvstats: AV: 1559.751 A-V: 0.000 Dropped: 19 Cache: 0.250s + 0KB
04-02 14:45:57.530 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 25% -> 4%) [0.042667s].
04-02 14:45:57.531 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 4% -> 26%) [0.266911s].
04-02 14:45:57.545 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 26% -> 28%) [0.283600s].
04-02 14:45:57.545 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 28% -> 8%) [0.085333s].
04-02 14:45:57.547 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 8% -> 41%) [0.417078s].
04-02 14:45:57.591 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 41% -> 29%) [0.298667s].
04-02 14:45:57.739 6854 6957 V mpv : event: unpause
04-02 14:45:57.740 6854 6957 V mpv : [cplayer] End buffering (waited 35.177989 secs) [1.536000s].
04-02 14:45:57.747 6854 6957 V mpv : property: buffering = false
04-02 14:45:57.748 6854 6854 V PlayerActivity: state BUFFERING -> PLAYING
04-02 14:45:57.799 6854 6854 V mpvstats: AV: 1559.767 A-V: 0.199 Dropped: 19 Cache: 1.963s + 0KB
04-02 14:45:57.945 6854 6957 E mpv : [ffmpeg/video] h264: error while decoding MB 55 18, bytestream -11
04-02 14:45:57.947 6854 6957 V mpv : [ffmpeg/video] h264: concealing 2154 DC, 2154 AC, 2154 MV errors in P frame
04-02 14:45:58.013 6854 6854 V mpvstats: AV: 1559.767 A-V: 0.042 Dropped: 36 Cache: 3.627s + 0KB
04-02 14:45:59.014 6854 6854 V mpvstats: AV: 1561.169 A-V: 0.000 Dropped: 40 Cache: 11.093s + 0KB
04-02 14:46:00.800 6854 6854 V mpvstats: AV: 1562.954 A-V: 0.000 Dropped: 40 Cache: 29.099s + 0KB
04-02 14:46:03.801 6854 6854 V mpvstats: AV: 1565.957 A-V: 0.000 Dropped: 40 Cache: 59.563s + 0KB
04-02 14:46:06.803 6854 6854 V mpvstats: AV: 1568.960 A-V: 0.000 Dropped: 40 Cache: 81.109s + 0KB
04-02 14:46:09.803 6854 6854 V mpvstats: AV: 1571.946 A-V: 0.000 Dropped: 40 Cache: 78.080s + 0KB
04-02 14:46:12.805 6854 6854 V mpvstats: AV: 1574.949 A-V: 0.000 Dropped: 40 Cache: 79.104s + 0KB
04-02 14:46:15.806 6854 6854 V mpvstats: AV: 1577.969 A-V: 0.000 Dropped: 40 Cache: 80.256s + 0KB
04-02 14:46:18.807 6854 6854 V mpvstats: AV: 1580.955 A-V: 0.000 Dropped: 40 Cache: 81.323s + 0KB
04-02 14:46:21.807 6854 6854 V mpvstats: AV: 1583.958 A-V: 0.000 Dropped: 40 Cache: 78.336s + 0KB
04-02 14:46:24.808 6854 6854 V mpvstats: AV: 1586.961 A-V: 0.000 Dropped: 40 Cache: 79.445s + 0KB
04-02 14:46:27.809 6854 6854 V mpvstats: AV: 1589.964 A-V: 0.000 Dropped: 40 Cache: 80.555s + 0KB
04-02 14:46:29.951 6854 8937 V ApiServer: REQUEST: GET /logThis message is showing the root cause. The streamer is waiting for 32s to receive data and no more data is coming from the DVR server for the channel. This indicates a network issue, a bug on the DVR side, or an issue with the feed itself.
This seems to match what you're seeing in the video. It waited 48s before resuming playback.
This is unexpected too, it's saying there's corrupted video packets which should not happen for a TVE stream.
That's interesting, is there any reason why that would show up after the stream pauses and during buffering?
Do you have a recommendation of the best way to test the network to rule that out?
The message shows up when the streamer gives up, after trying for the previous 32 seconds.
There's a speedtest button in the app. Did you try that?
Yes and it always seems to be fine.
100mbps, 1.91 Latency and 0.77 Jitter
Here is what I get pinging to the server with my Laptop:
Pinging 192.168.5.101 with 32 bytes of data:
Reply from 192.168.5.101: bytes=32 time=3ms TTL=64
Reply from 192.168.5.101: bytes=32 time=7ms TTL=64
Reply from 192.168.5.101: bytes=32 time=4ms TTL=64
Reply from 192.168.5.101: bytes=32 time=5ms TTL=64
Ping statistics for 192.168.5.101:
Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
Approximate round trip times in milli-seconds:
Minimum = 3ms, Maximum = 7ms, Average = 4ms
and here are Pings to my TV with my Laptop.
Pinging 192.168.5.10 with 32 bytes of data:
Reply from 192.168.5.10: bytes=32 time=7ms TTL=64
Reply from 192.168.5.10: bytes=32 time=3ms TTL=64
Reply from 192.168.5.10: bytes=32 time=4ms TTL=64
Reply from 192.168.5.10: bytes=32 time=5ms TTL=64
Ping statistics for 192.168.5.10:
Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
Approximate round trip times in milli-seconds:
Minimum = 3ms, Maximum = 7ms, Average = 4ms
Can you try playing some other channel for a while and see if it hits the same problem?
Since the issue is intermittent you should leave an infinite ping running and then you can see if there were disruptions that match the time when the video stalled.
1 Like
I just tried to go into another channels and it wouldn't let me because the DV was still showing I was streaming Fox even though I stopped it 10 minutes ago. It finally released after a few tries from Fox then the stream started.
I just turned on Discovery
This was on Discovery TVE on the SonyTV:
04-02 15:23:27.162 6854 6957 V mpv : event: unpause
04-02 15:23:27.162 6854 6957 V mpv : [cplayer] End buffering (waited 0.765094 secs) [4.053333s].
04-02 15:23:27.168 6854 6957 V mpv : property: buffering = false
04-02 15:23:27.169 6854 6854 V PlayerActivity: state BUFFERING -> PLAYING
04-02 15:23:27.886 6854 6854 V mpvstats: AV: 7.903 A-V: 0.000 Dropped: 6 Cache: 7.339s + 0KB
04-02 15:23:28.904 6854 6854 V mpvstats: AV: 8.937 A-V: 0.000 Dropped: 6 Cache: 6.315s + 0KB
04-02 15:23:31.905 6854 6854 V mpvstats: AV: 11.940 A-V: 0.000 Dropped: 6 Cache: 7.424s + 0KB
04-02 15:23:34.905 6854 6854 V mpvstats: AV: 14.943 A-V: 0.000 Dropped: 6 Cache: 6.400s + 0KB
04-02 15:23:37.906 6854 6854 V mpvstats: AV: 17.946 A-V: 0.000 Dropped: 6 Cache: 5.461s + 0KB
04-02 15:23:40.906 6854 6854 V mpvstats: AV: 20.949 A-V: 0.000 Dropped: 6 Cache: 6.528s + 0KB
04-02 15:23:43.907 6854 6854 V mpvstats: AV: 23.952 A-V: 0.000 Dropped: 6 Cache: 7.595s + 0KB
04-02 15:23:46.908 6854 6854 V mpvstats: AV: 26.955 A-V: 0.000 Dropped: 6 Cache: 4.608s + 0KB
04-02 15:23:49.908 6854 6854 V mpvstats: AV: 29.925 A-V: 0.000 Dropped: 6 Cache: 5.675s + 0KB
04-02 15:23:52.910 6854 6854 V mpvstats: AV: 32.961 A-V: 0.000 Dropped: 6 Cache: 6.784s + 0KB
04-02 15:23:55.911 6854 6854 V mpvstats: AV: 35.931 A-V: 0.000 Dropped: 6 Cache: 7.936s + 0KB
04-02 15:23:58.910 6854 6854 V mpvstats: AV: 38.934 A-V: 0.000 Dropped: 6 Cache: 4.949s + 0KB
04-02 15:24:01.911 6854 6854 V mpvstats: AV: 41.937 A-V: 0.000 Dropped: 6 Cache: 6.144s + 0KB
04-02 15:24:04.912 6854 6854 V mpvstats: AV: 44.940 A-V: 0.000 Dropped: 6 Cache: 7.253s + 0KB
04-02 15:24:07.913 6854 6854 V mpvstats: AV: 47.943 A-V: 0.000 Dropped: 6 Cache: 8.235s + 0KB
04-02 15:24:10.914 6854 6854 V mpvstats: AV: 50.946 A-V: 0.000 Dropped: 6 Cache: 5.248s + 0KB
04-02 15:24:13.915 6854 6854 V mpvstats: AV: 53.949 A-V: 0.000 Dropped: 6 Cache: 6.357s + 0KB
04-02 15:24:16.916 6854 6854 V mpvstats: AV: 56.952 A-V: 0.000 Dropped: 6 Cache: 7.467s + 0KB
04-02 15:24:19.917 6854 6854 V mpvstats: AV: 59.955 A-V: 0.000 Dropped: 6 Cache: 8.576s + 0KB
04-02 15:24:22.917 6854 6854 V mpvstats: AV: 62.958 A-V: 0.000 Dropped: 6 Cache: 5.504s + 0KB
04-02 15:24:25.918 6854 6854 V mpvstats: AV: 65.961 A-V: 0.000 Dropped: 6 Cache: 6.613s + 0KB
04-02 15:24:28.919 6854 6854 V mpvstats: AV: 68.964 A-V: 0.000 Dropped: 6 Cache: 7.680s + 0KB
04-02 15:24:31.920 6854 6854 V mpvstats: AV: 71.967 A-V: 0.000 Dropped: 6 Cache: 8.789s + 0KB
04-02 15:24:34.921 6854 6854 V mpvstats: AV: 74.970 A-V: 0.000 Dropped: 6 Cache: 5.803s + 0KB
04-02 15:24:37.925 6854 6854 V mpvstats: AV: 77.940 A-V: 0.000 Dropped: 6 Cache: 6.869s + 0KB
04-02 15:24:40.926 6854 6854 V mpvstats: AV: 80.976 A-V: 0.000 Dropped: 6 Cache: 7.893s + 0KB
04-02 15:24:43.927 6854 6854 V mpvstats: AV: 83.979 A-V: 0.000 Dropped: 6 Cache: 9.003s + 0KB
04-02 15:24:46.928 6854 6854 V mpvstats: AV: 86.949 A-V: 0.000 Dropped: 6 Cache: 6.101s + 0KB
04-02 15:24:49.929 6854 6854 V mpvstats: AV: 89.952 A-V: 0.000 Dropped: 6 Cache: 7.253s + 0KB
04-02 15:24:52.929 6854 6854 V mpvstats: AV: 92.955 A-V: 0.000 Dropped: 6 Cache: 8.363s + 0KB
04-02 15:24:55.930 6854 6854 V mpvstats: AV: 95.958 A-V: 0.000 Dropped: 6 Cache: 9.429s + 0KB
04-02 15:24:58.931 6854 6854 V mpvstats: AV: 98.961 A-V: 0.000 Dropped: 6 Cache: 7.680s + 0KB
04-02 15:25:01.934 6854 6854 V mpvstats: AV: 101.964 A-V: 0.000 Dropped: 6 Cache: 7.424s + 0KB
04-02 15:25:04.934 6854 6854 V mpvstats: AV: 104.967 A-V: 0.000 Dropped: 6 Cache: 8.576s + 0KB
04-02 15:25:07.935 6854 6854 V mpvstats: AV: 107.970 A-V: 0.000 Dropped: 6 Cache: 9.643s + 0KB
04-02 15:25:10.936 6854 6854 V mpvstats: AV: 110.973 A-V: 0.000 Dropped: 6 Cache: 6.656s + 0KB
04-02 15:25:13.938 6854 6854 V mpvstats: AV: 113.976 A-V: 0.000 Dropped: 6 Cache: 7.680s + 0KB
04-02 15:25:16.939 6854 6854 V mpvstats: AV: 116.979 A-V: 0.000 Dropped: 6 Cache: 8.789s + 0KB
04-02 15:25:19.940 6854 6854 V mpvstats: AV: 119.982 A-V: 0.000 Dropped: 6 Cache: 9.941s + 0KB
04-02 15:25:22.941 6854 6854 V mpvstats: AV: 122.985 A-V: 0.000 Dropped: 6 Cache: 6.912s + 0KB
04-02 15:25:25.941 6854 6854 V mpvstats: AV: 125.988 A-V: 0.000 Dropped: 6 Cache: 8.021s + 0KB
04-02 15:25:28.942 6854 6854 V mpvstats: AV: 128.991 A-V: 0.000 Dropped: 6 Cache: 9.173s + 0KB
04-02 15:25:31.943 6854 6854 V mpvstats: AV: 131.994 A-V: 0.000 Dropped: 6 Cache: 6.101s + 0KB
04-02 15:25:34.945 6854 6854 V mpvstats: AV: 134.963 A-V: 0.000 Dropped: 6 Cache: 7.211s + 0KB
04-02 15:25:37.946 6854 6854 V mpvstats: AV: 137.966 A-V: 0.000 Dropped: 6 Cache: 8.363s + 0KB
04-02 15:25:40.947 6854 6854 V mpvstats: AV: 140.969 A-V: 0.000 Dropped: 6 Cache: 5.376s + 0KB
04-02 15:25:43.948 6854 6854 V mpvstats: AV: 143.972 A-V: 0.000 Dropped: 6 Cache: 6.485s + 0KB
04-02 15:25:46.949 6854 6854 V mpvstats: AV: 146.975 A-V: 0.000 Dropped: 6 Cache: 7.552s + 0KB
04-02 15:25:49.950 6854 6854 V mpvstats: AV: 149.978 A-V: 0.000 Dropped: 6 Cache: 4.565s + 0KB
04-02 15:25:52.950 6854 6854 V mpvstats: AV: 152.981 A-V: 0.000 Dropped: 6 Cache: 5.504s + 0KB
04-02 15:25:55.951 6854 6854 V mpvstats: AV: 155.984 A-V: 0.000 Dropped: 6 Cache: 6.613s + 0KB
04-02 15:25:57.887 6854 6864 I ls.dvr.app.bet: Background concurrent copying GC freed 514575(19MB) AllocSpace objects, 10(2MB) LOS objects, 49% free, 14MB/28MB, paused 195us total 123.081ms
04-02 15:25:57.902 6854 6862 W System : A resource failed to call end.
04-02 15:25:58.951 6854 6854 V mpvstats: AV: 158.987 A-V: 0.000 Dropped: 6 Cache: 7.765s + 0KB
04-02 15:26:01.952 6854 6854 V mpvstats: AV: 161.990 A-V: 0.000 Dropped: 6 Cache: 7.296s + 0KB
04-02 15:26:04.954 6854 6854 V mpvstats: AV: 164.993 A-V: 0.000 Dropped: 6 Cache: 5.931s + 0KB
04-02 15:26:07.955 6854 6854 V mpvstats: AV: 167.996 A-V: 0.000 Dropped: 6 Cache: 6.869s + 0KB
04-02 15:26:10.956 6854 6854 V mpvstats: AV: 170.999 A-V: 0.000 Dropped: 6 Cache: 8.021s + 0KB
04-02 15:26:13.956 6854 6854 V mpvstats: AV: 174.002 A-V: 0.000 Dropped: 6 Cache: 9.131s + 0KB
04-02 15:26:16.958 6854 6854 V mpvstats: AV: 177.005 A-V: 0.000 Dropped: 6 Cache: 6.229s + 0KB
04-02 15:26:19.959 6854 6854 V mpvstats: AV: 180.008 A-V: 0.000 Dropped: 6 Cache: 7.339s + 0KB
04-02 15:26:22.960 6854 6854 V mpvstats: AV: 183.011 A-V: 0.000 Dropped: 6 Cache: 8.405s + 0KB
04-02 15:26:25.962 6854 6854 V mpvstats: AV: 185.981 A-V: 0.000 Dropped: 6 Cache: 6.187s + 0KB
04-02 15:26:28.964 6854 6854 V mpvstats: AV: 188.984 A-V: 0.000 Dropped: 6 Cache: 6.400s + 0KB
04-02 15:26:31.965 6854 6854 V mpvstats: AV: 191.987 A-V: 0.000 Dropped: 6 Cache: 7.509s + 0KB
04-02 15:26:34.965 6854 6854 V mpvstats: AV: 194.990 A-V: 0.000 Dropped: 6 Cache: 8.661s + 0KB
04-02 15:26:37.966 6854 6854 V mpvstats: AV: 197.993 A-V: 0.000 Dropped: 6 Cache: 6.443s + 0KB
04-02 15:26:40.967 6854 6854 V mpvstats: AV: 200.996 A-V: 0.000 Dropped: 6 Cache: 6.784s + 0KB
04-02 15:26:43.969 6854 6854 V mpvstats: AV: 203.999 A-V: 0.000 Dropped: 6 Cache: 7.893s + 0KB
04-02 15:26:46.970 6854 6854 V mpvstats: AV: 207.002 A-V: 0.000 Dropped: 6 Cache: 8.917s + 0KB
04-02 15:26:49.971 6854 6854 V mpvstats: AV: 210.005 A-V: 0.000 Dropped: 6 Cache: 5.888s + 0KB
04-02 15:26:52.972 6854 6854 V mpvstats: AV: 213.008 A-V: 0.000 Dropped: 6 Cache: 2.901s + 0KB
04-02 15:26:55.931 6854 6957 V mpv : event: unpause
04-02 15:26:55.931 6854 6957 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 23%) [0.233556s].
04-02 15:26:55.931 6854 6957 V mpv : property: buffering = true
04-02 15:26:55.932 6854 6854 V PlayerActivity: state PLAYING -> BUFFERING
04-02 15:26:55.934 6854 6854 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=171.46647744444445, end=212.3739996666667}], cache-end=216.37799966666668, reader-pts=216.1444441111111, cache-duration=0.23355555555556862, eof=false, underrun=true, idle=false, total-bytes=29860736, fw-bytes=107968, debug-low-level-seeks=0, debug-ts-last=216.04434477777778, ts-per-stream=[{type=video, duration=0.23355555555556862, reader=216.1778111111111, end=216.41136666666668}, {type=audio, duration=0.0, reader=216.48136666666667, end=216.48136666666667}]}
04-02 15:26:55.982 6854 6854 V mpvstats: AV: 215.978 A-V: 0.000 Dropped: 6 Cache: 0.234s + 0KB
04-02 15:26:57.163 6854 6957 V mpv : event: unpause
04-02 15:26:57.164 6854 6957 V mpv : [cplayer] End buffering (waited 1.232014 secs) [1.749333s].
04-02 15:26:57.164 6854 6957 V mpv : property: buffering = false
04-02 15:26:57.164 6854 6854 V PlayerActivity: state BUFFERING -> PLAYING
04-02 15:26:58.036 6854 6854 V mpvstats: AV: 216.979 A-V: 0.000 Dropped: 10 Cache: 3.029s + 0KB
04-02 15:26:58.983 6854 6854 V mpvstats: AV: 217.913 A-V: 0.000 Dropped: 10 Cache: 2.091s + 0KB
04-02 15:27:01.984 6854 6854 V mpvstats: AV: 220.916 A-V: 0.000 Dropped: 10 Cache: 11.392s + 0KB
04-02 15:27:04.985 6854 6854 V mpvstats: AV: 223.919 A-V: 0.000 Dropped: 10 Cache: 8.405s + 0KB
04-02 15:27:07.986 6854 6854 V mpvstats: AV: 226.922 A-V: 0.000 Dropped: 10 Cache: 9.557s + 0KB
04-02 15:27:10.987 6854 6854 V mpvstats: AV: 229.925 A-V: 0.000 Dropped: 10 Cache: 10.581s + 0KB
04-02 15:27:12.127 6854 9724 V ApiServer: REQUEST: GET /log
04-02 15:27:12.127 6854 9724 I hls : goroutine 17 [running, locked to thread]:
04-02 15:27:12.127 6854 9724 I hls : main.FullStackTrace(0x8cc4c070, 0x8cc38f50)
04-02 15:27:12.127 6854 9724 I hls : /Users/fancybox/source/channels-android/vendor/libhls/channels-server/hls/libhls/hls_c.go:249 +0x80
04-02 15:27:12.127 6854 9724 I hls : main.hls_log_stack()
04-02 15:27:12.127 6854 9724 I hls : /Users/fancybox/source/channels-android/vendor/libhls/channels-server/hls/libhls/hls_c.go:259 +0x14
04-02 15:27:12.127 6854 9724 I hls : main._cgoexpwrap_277a0c6059f4_hls_log_stack()
04-02 15:27:12.127 6854 9724 I hls : _cgo_gotypes.go:299 +0x14
04-02 15:27:12.127 6854 9724 I hls :
04-02 15:27:12.127 6854 9724 I hls : goroutine 6 [syscall]:
04-02 15:27:12.127 6854 9724 I hls : os/signal.signal_recv(0x0)
04-02 15:27:12.127 6854 9724 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/runtime/sigqueue.go:147 +0x14c
04-02 15:27:12.127 6854 9724 I hls : os/signal.loop()
04-02 15:27:12.127 6854 9724 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/os/signal/signal_unix.go:23 +0x14
04-02 15:27:12.127 6854 9724 I hls : created by os/signal.Notify.func1
04-02 15:27:12.127 6854 9724 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/os/signal/signal.go:127 +0x38
04-02 15:27:12.127 6854 9724 I hls :
04-02 15:27:12.127 6854 9724 I hls : goroutine 19 [select]:
04-02 15:27:12.127 6854 9724 I hls : github.com/grafov/kiwi.processSink(0x8cd8e080)
04-02 15:27:12.127 6854 9724 I hls : /Users/fancybox/go/pkg/mod/github.com/grafov/kiwi@v0.3.1/sink.go:327 +0x90
04-02 15:27:12.127 6854 9724 I hls : created by github.com/grafov/kiwi.SinkTo
04-02 15:27:12.127 6854 9724 I hls : /Users/fancybox/go/pkg/mod/github.com/grafov/kiwi@v0.3.1/sink.go:111 +0x310
04-02 15:27:13.988 6854 6854 V mpvstats: AV: 232.928 A-V: 0.000 Dropped: 10 Cache: 11.605s + 0KB
04-02 15:27:16.989 6854 6854 V mpvstats: AV: 235.931 A-V: 0.000 Dropped: 10 Cache: 8.619s + 0KB
04-02 15:27:19.990 6854 6854 V mpvstats: AV: 238.934 A-V: 0.000 Dropped: 10 Cache: 9.728s + 0KB
04-02 15:27:22.991 6854 6854 V mpvstats: AV: 241.904 A-V: 0.000 Dropped: 10 Cache: 10.837s + 0KB
04-02 15:27:25.993 6854 6854 V mpvstats: AV: 244.907 A-V: 0.000 Dropped: 10 Cache: 7.851s + 0KB
04-02 15:27:28.993 6854 6854 V mpvstats: AV: 247.910 A-V: 0.000 Dropped: 10 Cache: 8.960s + 0KB
04-02 15:27:31.993 6854 6854 V mpvstats: AV: 250.913 A-V: 0.000 Dropped: 10 Cache: 6.059s + 0KB
04-02 15:27:34.994 6854 6854 V mpvstats: AV: 253.916 A-V: 0.000 Dropped: 10 Cache: 7.083s + 0KB
04-02 15:27:37.995 6854 6854 V mpvstats: AV: 256.919 A-V: 0.000 Dropped: 10 Cache: 8.192s + 0KB
04-02 15:27:40.996 6854 6854 V mpvstats: AV: 259.922 A-V: 0.000 Dropped: 10 Cache: 5.205s + 0KB
04-02 15:27:43.997 6854 6854 V mpvstats: AV: 262.925 A-V: 0.000 Dropped: 10 Cache: 2.219s + 0KB
04-02 15:27:46.218 6854 6957 V mpv : event: unpause
04-02 15:27:46.218 6854 6957 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 23%) [0.233578s].
04-02 15:27:46.219 6854 6957 V mpv : property: buffering = true
04-02 15:27:46.219 6854 6854 V PlayerActivity: state PLAYING -> BUFFERING
04-02 15:27:46.221 6854 6854 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=220.61556633333333, end=261.5231107777778}], cache-end=265.5604774444445, reader-pts=265.3268996666667, cache-duration=0.2335777777777821, eof=false, underrun=true, idle=false, total-bytes=29895104, fw-bytes=113856, debug-low-level-seeks=0, debug-ts-last=264.359267, ts-per-stream=[{type=video, duration=0.2335777777777821, reader=265.3602666666667, end=265.59384444444447}, {type=audio, duration=0.0, reader=265.6333666666667, end=265.6333666666667}]}
04-02 15:27:46.919 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 23% -> 85%) [0.853333s].
04-02 15:27:46.976 6854 6957 V mpv : event: unpause
04-02 15:27:46.976 6854 6957 V mpv : [cplayer] End buffering (waited 0.757162 secs) [1.536000s].
04-02 15:27:46.977 6854 6957 V mpv : property: buffering = false
04-02 15:27:46.977 6854 6854 V PlayerActivity: state BUFFERING -> PLAYING
04-02 15:27:47.005 6854 6854 V mpvstats: AV: 265.227 A-V: 0.056 Dropped: 13 Cache: 1.792s + 0KB
04-02 15:27:47.074 6854 6854 V mpvstats: AV: 265.394 A-V: 0.000 Dropped: 14 Cache: 3.243s + 0KB
04-02 15:27:50.006 6854 6854 V mpvstats: AV: 268.297 A-V: 0.000 Dropped: 14 Cache: 9.088s + 0KB
04-02 15:27:52.154 6854 9732 V ApiServer: REQUEST: GET /log
04-02 15:27:52.155 6854 9732 I hls : goroutine 17 [running, locked to thread]:
04-02 15:27:52.155 6854 9732 I hls : main.FullStackTrace(0x8cc4c070, 0x8cc38f50)
04-02 15:27:52.155 6854 9732 I hls : /Users/fancybox/source/channels-android/vendor/libhls/channels-server/hls/libhls/hls_c.go:249 +0x80
04-02 15:27:52.155 6854 9732 I hls : main.hls_log_stack()
04-02 15:27:52.155 6854 9732 I hls : /Users/fancybox/source/channels-android/vendor/libhls/channels-server/hls/libhls/hls_c.go:259 +0x14
04-02 15:27:52.155 6854 9732 I hls : main._cgoexpwrap_277a0c6059f4_hls_log_stack()
04-02 15:27:52.155 6854 9732 I hls : _cgo_gotypes.go:299 +0x14
04-02 15:27:52.155 6854 9732 I hls :
04-02 15:27:52.155 6854 9732 I hls : goroutine 6 [syscall]:
04-02 15:27:52.155 6854 9732 I hls : os/signal.signal_recv(0x0)
04-02 15:27:52.155 6854 9732 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/runtime/sigqueue.go:147 +0x14c
04-02 15:27:52.155 6854 9732 I hls : os/signal.loop()
04-02 15:27:52.155 6854 9732 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/os/signal/signal_unix.go:23 +0x14
04-02 15:27:52.155 6854 9732 I hls : created by os/signal.Notify.func1
04-02 15:27:52.155 6854 9732 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/os/signal/signal.go:127 +0x38
04-02 15:27:52.155 6854 9732 I hls :
04-02 15:27:52.155 6854 9732 I hls : goroutine 19 [select]:
04-02 15:27:52.155 6854 9732 I hls : github.com/grafov/kiwi.processSink(0x8cd8e080)
04-02 15:27:52.155 6854 9732 I hls : /Users/fancybox/go/pkg/mod/github.com/grafov/kiwi@v0.3.1/sink.go:327 +0x90
04-02 15:27:52.155 6854 9732 I hls : created by github.com/grafov/kiwi.SinkTo
04-02 15:27:52.155 6854 9732 I hls : /Users/fancybox/go/pkg/mod/github.com/grafov/kiwi@v0.3.1/sink.go:111 +0x310
04-02 15:27:52.504 6854 6864 I ls.dvr.app.bet: Background concurrent copying GC freed 555578(16MB) AllocSpace objects, 18(5MB) LOS objects, 49% free, 14MB/28MB, paused 1.602ms total 100.335ms
04-02 15:27:52.505 6854 6862 W System : A resource failed to call end.
04-02 15:27:53.006 6854 6854 V mpvstats: AV: 271.300 A-V: 0.000 Dropped: 14 Cache: 10.240s + 0KB
04-02 15:27:56.009 6854 6854 V mpvstats: AV: 274.303 A-V: 0.000 Dropped: 14 Cache: 7.253s + 0KB
04-02 15:27:59.010 6854 6854 V mpvstats: AV: 277.306 A-V: 0.000 Dropped: 14 Cache: 8.235s + 0KB
04-02 15:28:02.011 6854 6854 V mpvstats: AV: 280.309 A-V: 0.000 Dropped: 14 Cache: 9.344s + 0KB
04-02 15:28:05.012 6854 6854 V mpvstats: AV: 283.312 A-V: 0.000 Dropped: 14 Cache: 10.411s + 0KB
04-02 15:28:08.013 6854 6854 V mpvstats: AV: 286.315 A-V: 0.000 Dropped: 14 Cache: 7.424s + 0KB
04-02 15:28:11.014 6854 6854 V mpvstats: AV: 289.318 A-V: 0.000 Dropped: 14 Cache: 8.576s + 0KB
04-02 15:28:14.018 6854 6854 V mpvstats: AV: 292.321 A-V: 0.000 Dropped: 14 Cache: 5.504s + 0KB
04-02 15:28:17.019 6854 6854 V mpvstats: AV: 295.324 A-V: 0.000 Dropped: 14 Cache: 10.709s + 0KB
04-02 15:28:20.021 6854 6854 V mpvstats: AV: 298.327 A-V: 0.000 Dropped: 14 Cache: 7.680s + 0KB
04-02 15:28:23.022 6854 6854 V mpvstats: AV: 301.330 A-V: 0.000 Dropped: 14 Cache: 8.832s + 0KB
04-02 15:28:26.023 6854 6854 V mpvstats: AV: 304.333 A-V: 0.000 Dropped: 14 Cache: 5.845s + 0KB
04-02 15:28:29.024 6854 6854 V mpvstats: AV: 307.336 A-V: 0.000 Dropped: 14 Cache: 6.869s + 0KB
04-02 15:28:32.026 6854 6854 V mpvstats: AV: 310.339 A-V: 0.000 Dropped: 14 Cache: 8.021s + 0KB
04-02 15:28:35.027 6854 6854 V mpvstats: AV: 313.342 A-V: 0.000 Dropped: 14 Cache: 9.131s + 0KB
04-02 15:28:38.028 6854 6854 V mpvstats: AV: 316.345 A-V: 0.000 Dropped: 14 Cache: 10.240s + 0KB
04-02 15:28:41.029 6854 6854 V mpvstats: AV: 319.348 A-V: 0.000 Dropped: 14 Cache: 11.307s + 0KB
04-02 15:28:44.030 6854 6854 V mpvstats: AV: 322.351 A-V: 0.000 Dropped: 14 Cache: 8.277s + 0KB
04-02 15:28:47.031 6854 6854 V mpvstats: AV: 325.354 A-V: 0.000 Dropped: 14 Cache: 9.429s + 0KB
04-02 15:28:50.032 6854 6854 V mpvstats: AV: 328.357 A-V: 0.000 Dropped: 14 Cache: 10.453s + 0KB
04-02 15:28:53.033 6854 6854 V mpvstats: AV: 331.360 A-V: 0.000 Dropped: 14 Cache: 11.563s + 0KB
04-02 15:28:56.034 6854 6854 V mpvstats: AV: 334.329 A-V: 0.000 Dropped: 14 Cache: 8.576s + 0KB
04-02 15:28:59.035 6854 6854 V mpvstats: AV: 337.332 A-V: 0.000 Dropped: 14 Cache: 9.643s + 0KB
04-02 15:29:02.037 6854 6854 V mpvstats: AV: 340.335 A-V: 0.000 Dropped: 14 Cache: 10.752s + 0KB
04-02 15:29:05.038 6854 6854 V mpvstats: AV: 343.338 A-V: 0.000 Dropped: 14 Cache: 11.861s + 0KB
04-02 15:29:08.040 6854 6854 V mpvstats: AV: 346.341 A-V: 0.000 Dropped: 14 Cache: 8.875s + 0KB
04-02 15:29:11.041 6854 6854 V mpvstats: AV: 349.344 A-V: 0.000 Dropped: 14 Cache: 9.941s + 0KB
04-02 15:29:14.042 6854 6854 V mpvstats: AV: 352.347 A-V: 0.000 Dropped: 14 Cache: 11.051s + 0KB
04-02 15:29:17.042 6854 6854 V mpvstats: AV: 355.350 A-V: 0.000 Dropped: 14 Cache: 8.064s + 0KB
04-02 15:29:20.043 6854 6854 V mpvstats: AV: 358.353 A-V: 0.000 Dropped: 14 Cache: 9.216s + 0KB
04-02 15:29:23.044 6854 6854 V mpvstats: AV: 361.356 A-V: 0.000 Dropped: 14 Cache: 6.229s + 0KB
04-02 15:29:26.045 6854 6854 V mpvstats: AV: 364.326 A-V: 0.000 Dropped: 14 Cache: 8.235s + 0KB
04-02 15:29:29.047 6854 6854 V mpvstats: AV: 367.362 A-V: 0.000 Dropped: 14 Cache: 9.344s + 0KB
04-02 15:29:32.050 6854 6854 V mpvstats: AV: 370.359 A-V: 0.000 Dropped: 14 Cache: 10.411s + 0KB
04-02 15:29:35.050 6854 6854 V mpvstats: AV: 373.362 A-V: 0.000 Dropped: 14 Cache: 7.424s + 0KB
04-02 15:29:38.051 6854 6854 V mpvstats: AV: 376.364 A-V: 0.000 Dropped: 14 Cache: 6.357s + 0KB
04-02 15:29:41.053 6854 6854 V mpvstats: AV: 379.367 A-V: 0.000 Dropped: 14 Cache: 3.499s + 0KB
04-02 15:29:44.054 6854 6854 V mpvstats: AV: 382.369 A-V: 0.000 Dropped: 14 Cache: 0.640s + 0KB
04-02 15:29:44.719 6854 6957 V mpv : event: unpause
04-02 15:29:44.720 6854 6957 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 20%) [0.208500s].
04-02 15:29:44.720 6854 6957 V mpv : property: buffering = true
04-02 15:29:44.720 6854 6854 V PlayerActivity: state PLAYING -> BUFFERING
04-02 15:29:44.721 6854 6854 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=335.2968107777778, end=383.3702218888889}], cache-end=383.45364411111115, reader-pts=383.24514411111113, cache-duration=0.208500000000015, eof=false, underrun=true, idle=false, total-bytes=31247552, fw-bytes=140032, debug-low-level-seeks=0, debug-ts-last=383.5640333333333, ts-per-stream=[{type=video, duration=0.208500000000015, reader=383.27851111111113, end=383.48701111111114}, {type=audio, duration=0.0, reader=383.5640333333333, end=383.5640333333333}]}
04-02 15:29:45.354 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 20% -> 34%) [0.341333s].
04-02 15:29:45.355 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 34% -> 55%) [0.554667s].
04-02 15:29:45.355 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 55% -> 59%) [0.597333s].
04-02 15:29:45.374 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 59% -> 98%) [0.981333s].
04-02 15:29:45.578 6854 6957 V mpv : event: unpause
04-02 15:29:45.578 6854 6957 V mpv : [cplayer] End buffering (waited 0.860866 secs) [4.608000s].
04-02 15:29:45.583 6854 6957 V mpv : property: buffering = false
04-02 15:29:45.583 6854 6854 V PlayerActivity: state BUFFERING -> PLAYING
04-02 15:29:46.135 6854 6854 V mpvstats: AV: 383.829 A-V: 0.000 Dropped: 19 Cache: 8.064s + 0KB
04-02 15:29:47.054 6854 6854 V mpvstats: AV: 384.738 A-V: 0.000 Dropped: 19 Cache: 8.149s + 0KB
04-02 15:29:50.055 6854 6854 V mpvstats: AV: 387.741 A-V: 0.000 Dropped: 19 Cache: 8.192s + 0KB
04-02 15:29:51.658 6854 9775 V ApiServer: REQUEST: GET /log
04-02 15:29:51.659 6854 9775 I hls : goroutine 17 [running, locked to thread]:
04-02 15:29:51.659 6854 9775 I hls : main.FullStackTrace(0x8cc4c070, 0x8cc38f50)
04-02 15:29:51.659 6854 9775 I hls : /Users/fancybox/source/channels-android/vendor/libhls/channels-server/hls/libhls/hls_c.go:249 +0x80
04-02 15:29:51.659 6854 9775 I hls : main.hls_log_stack()
04-02 15:29:51.659 6854 9775 I hls : /Users/fancybox/source/channels-android/vendor/libhls/channels-server/hls/libhls/hls_c.go:259 +0x14
04-02 15:29:51.659 6854 9775 I hls : main._cgoexpwrap_277a0c6059f4_hls_log_stack()
04-02 15:29:51.659 6854 9775 I hls : _cgo_gotypes.go:299 +0x14
04-02 15:29:51.659 6854 9775 I hls :
04-02 15:29:51.659 6854 9775 I hls : goroutine 6 [syscall]:
04-02 15:29:51.659 6854 9775 I hls : os/signal.signal_recv(0x0)
04-02 15:29:51.659 6854 9775 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/runtime/sigqueue.go:147 +0x14c
04-02 15:29:51.659 6854 9775 I hls : os/signal.loop()
04-02 15:29:51.659 6854 9775 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/os/signal/signal_unix.go:23 +0x14
04-02 15:29:51.659 6854 9775 I hls : created by os/signal.Notify.func1
04-02 15:29:51.659 6854 9775 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/os/signal/signal.go:127 +0x38
04-02 15:29:51.659 6854 9775 I hls :
04-02 15:29:51.659 6854 9775 I hls : goroutine 19 [select]:
04-02 15:29:51.659 6854 9775 I hls : github.com/grafov/kiwi.processSink(0x8cd8e080)
04-02 15:29:51.659 6854 9775 I hls : /Users/fancybox/go/pkg/mod/github.com/grafov/kiwi@v0.3.1/sink.go:327 +0x90
04-02 15:29:51.659 6854 9775 I hls : created by github.com/grafov/kiwi.SinkTo
04-02 15:29:51.659 6854 9775 I hls : /Users/fancybox/go/pkg/mod/github.com/grafov/kiwi@v0.3.1/sink.go:111 +0x310
I was running a continius ping during the show to the DVR and to the TV with zero packet drops.
EDIT: I don't see the problem with DVR'd programs or OTA so I can't imagine its my network anyway.
Please try with a channel between 6007-6062
Ok trying SyFy. Could be an hour or three before I see a problem.
What's the reason for the number range?
Also I was surprised at how quick it started happening to me with Discovery. Lately I've been having Fox News on most of the day when I'm not doing at home schooling with the kids.....
Ok just happened on SyFy channels 6054
04-02 17:08:36.445 6854 6854 V mpvstats: AV: 2627.057 A-V: 0.000 Dropped: 1 Cache: 16.300s + 0KB
04-02 17:08:39.447 6854 6854 V mpvstats: AV: 2630.060 A-V: 0.000 Dropped: 1 Cache: 13.305s + 0KB
04-02 17:08:42.448 6854 6854 V mpvstats: AV: 2633.063 A-V: 0.000 Dropped: 1 Cache: 20.317s + 0KB
04-02 17:08:45.448 6854 6854 V mpvstats: AV: 2636.066 A-V: 0.000 Dropped: 1 Cache: 17.229s + 0KB
04-02 17:08:48.449 6854 6854 V mpvstats: AV: 2639.069 A-V: 0.000 Dropped: 1 Cache: 14.234s + 0KB
04-02 17:08:51.449 6854 6854 V mpvstats: AV: 2642.072 A-V: 0.000 Dropped: 1 Cache: 11.262s + 0KB
04-02 17:08:54.450 6854 6854 V mpvstats: AV: 2645.075 A-V: 0.000 Dropped: 1 Cache: 8.266s + 0KB
04-02 17:08:57.452 6854 6854 V mpvstats: AV: 2648.078 A-V: 0.000 Dropped: 1 Cache: 5.271s + 0KB
04-02 17:09:00.453 6854 6854 V mpvstats: AV: 2651.081 A-V: 0.000 Dropped: 1 Cache: 2.276s + 0KB
04-02 17:09:02.691 6854 6957 V mpv : event: unpause
04-02 17:09:02.692 6854 6957 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 40%) [0.400000s].
04-02 17:09:02.693 6854 6957 V mpv : property: buffering = true
04-02 17:09:02.693 6854 6854 V PlayerActivity: state PLAYING -> BUFFERING
04-02 17:09:02.694 6854 6854 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=2593.991, end=2651.949}], cache-end=2653.851, reader-pts=2653.451, cache-duration=0.40000000000009095, eof=false, underrun=true, idle=false, total-bytes=31563584, fw-bytes=182848, debug-low-level-seeks=0, debug-ts-last=2654.05, ts-per-stream=[{type=video, duration=0.40000000000009095, reader=2654.184, end=2654.5840000000003}, {type=audio, duration=0.0, reader=2654.5665222222224, end=2654.5665222222224}]}
04-02 17:09:03.453 6854 6854 V mpvstats: AV: 2653.317 A-V: 0.000 Dropped: 1 Cache: 0.400s + 0KB
04-02 17:09:06.453 6854 6854 V mpvstats: AV: 2653.317 A-V: 0.000 Dropped: 1 Cache: 0.400s + 0KB
04-02 17:09:08.321 6854 6957 V mpv : event: unpause
04-02 17:09:08.321 6854 6957 V mpv : [cplayer] End buffering (waited 5.628183 secs) [1.091333s].
04-02 17:09:08.332 6854 6957 V mpv : property: buffering = false
04-02 17:09:08.342 6854 6854 V PlayerActivity: state BUFFERING -> PLAYING
04-02 17:09:09.064 6854 6854 V mpvstats: AV: 2654.251 A-V: 0.000 Dropped: 7 Cache: 1.463s + 0KB
04-02 17:09:09.454 6854 6854 V mpvstats: AV: 2654.652 A-V: 0.000 Dropped: 7 Cache: 1.022s + 0KB
04-02 17:09:10.738 6854 6957 V mpv : event: unpause
04-02 17:09:10.738 6854 6957 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 23%) [0.233000s].
04-02 17:09:10.738 6854 6957 V mpv : property: buffering = true
04-02 17:09:10.738 6854 6854 V PlayerActivity: state PLAYING -> BUFFERING
04-02 17:09:10.738 6854 6854 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=2595.993, end=2655.953}], cache-end=2656.353, reader-pts=2656.12, cache-duration=0.23300000000017462, eof=false, underrun=true, idle=false, total-bytes=32069504, fw-bytes=138432, debug-low-level-seeks=0, debug-ts-last=2656.7190000000005, ts-per-stream=[{type=video, duration=0.23300000000017462, reader=2656.853, end=2657.0860000000002}, {type=audio, duration=0.0, reader=2656.9117333333334, end=2656.9117333333334}]}
04-02 17:09:12.457 6854 6854 V mpvstats: AV: 2655.953 A-V: 0.000 Dropped: 7 Cache: 0.233s + 0KB
04-02 17:09:15.458 6854 6854 V mpvstats: AV: 2655.953 A-V: 0.000 Dropped: 7 Cache: 0.233s + 0KB
04-02 17:09:18.459 6854 6854 V mpvstats: AV: 2655.953 A-V: 0.000 Dropped: 7 Cache: 0.233s + 0KB
04-02 17:09:19.467 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 23% -> 2%) [0.023222s].
04-02 17:09:19.473 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 2% -> 36%) [0.367000s].
04-02 17:09:19.524 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 36% -> 99%) [0.998456s].
04-02 17:09:19.538 6854 6957 V mpv : event: unpause
04-02 17:09:19.539 6854 6957 V mpv : [cplayer] End buffering (waited 8.800246 secs) [1.253878s].
04-02 17:09:19.542 6854 6957 V mpv : property: buffering = false
04-02 17:09:19.543 6854 6854 V PlayerActivity: state BUFFERING -> PLAYING
04-02 17:09:20.077 6854 6854 V mpvstats: AV: 2656.620 A-V: 0.000 Dropped: 12 Cache: 2.113s + 0KB
04-02 17:09:21.459 6854 6854 V mpvstats: AV: 2658.022 A-V: 0.000 Dropped: 12 Cache: 0.743s + 0KB
04-02 17:09:22.311 6854 6957 V mpv : event: unpause
04-02 17:09:22.311 6854 6957 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 23%) [0.234000s].
04-02 17:09:22.313 6854 6957 V mpv : property: buffering = true
04-02 17:09:22.314 6854 6854 V PlayerActivity: state PLAYING -> BUFFERING
04-02 17:09:22.314 6854 6854 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=2599.997, end=2657.955}], cache-end=2659.29, reader-pts=2659.056, cache-duration=0.2339999999999236, eof=false, underrun=true, idle=false, total-bytes=31531328, fw-bytes=105600, debug-low-level-seeks=0, debug-ts-last=2659.6560000000004, ts-per-stream=[{type=video, duration=0.2339999999999236, reader=2659.789, end=2660.023}, {type=audio, duration=0.0, reader=2659.9535444444446, end=2659.9535444444446}]}
04-02 17:09:24.460 6854 6854 V mpvstats: AV: 2658.889 A-V: 0.000 Dropped: 12 Cache: 0.234s + 0KB
04-02 17:09:27.461 6854 6854 V mpvstats: AV: 2658.889 A-V: 0.000 Dropped: 12 Cache: 0.234s + 0KB
04-02 17:09:29.645 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 23% -> 11%) [0.116100s].
04-02 17:09:29.700 6854 6957 V mpv : event: unpause
04-02 17:09:29.702 6854 6957 V mpv : [cplayer] End buffering (waited 7.386153 secs) [1.323544s].
04-02 17:09:29.704 6854 6957 V mpv : property: buffering = false
04-02 17:09:29.704 6854 6854 V PlayerActivity: state BUFFERING -> PLAYING
04-02 17:09:30.086 6854 6854 V mpvstats: AV: 2659.390 A-V: 0.000 Dropped: 16 Cache: 2.345s + 0KB
04-02 17:09:30.462 6854 6854 V mpvstats: AV: 2659.757 A-V: 0.000 Dropped: 16 Cache: 1.997s + 0KB
04-02 17:09:32.604 6854 6957 V mpv : event: unpause
04-02 17:09:32.604 6854 6957 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 23%) [0.234000s].
04-02 17:09:32.605 6854 6957 V mpv : property: buffering = true
04-02 17:09:32.606 6854 6854 V PlayerActivity: state PLAYING -> BUFFERING
04-02 17:09:32.608 6854 6854 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=2601.999, end=2661.959}], cache-end=2662.326, reader-pts=2662.092, cache-duration=0.2339999999999236, eof=false, underrun=true, idle=false, total-bytes=32041728, fw-bytes=97280, debug-low-level-seeks=0, debug-ts-last=2662.6920000000005, ts-per-stream=[{type=video, duration=0.2339999999999236, reader=2662.8250000000003, end=2663.059}, {type=audio, duration=0.0, reader=2662.9257000000002, end=2662.9257000000002}]}
04-02 17:09:33.463 6854 6854 V mpvstats: AV: 2661.926 A-V: 0.000 Dropped: 16 Cache: 0.234s + 0KB
04-02 17:09:36.464 6854 6854 V mpvstats: AV: 2661.926 A-V: 0.000 Dropped: 16 Cache: 0.234s + 0KB
04-02 17:09:39.465 6854 6854 V mpvstats: AV: 2661.926 A-V: 0.000 Dropped: 16 Cache: 0.234s + 0KB
04-02 17:09:40.552 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 23% -> 50%) [0.501000s].
04-02 17:09:40.759 6854 6957 V mpv : event: unpause
04-02 17:09:40.759 6854 6957 V mpv : [cplayer] End buffering (waited 8.155303 secs) [2.530978s].
04-02 17:09:40.766 6854 6957 V mpv : property: buffering = false
04-02 17:09:40.767 6854 6854 V PlayerActivity: state BUFFERING -> PLAYING
04-02 17:09:41.097 6854 6854 V mpvstats: AV: 2662.393 A-V: 0.000 Dropped: 21 Cache: 2.020s + 0KB
04-02 17:09:42.466 6854 6854 V mpvstats: AV: 2663.761 A-V: 0.000 Dropped: 21 Cache: 0.650s + 0KB
04-02 17:09:43.193 6854 6957 V mpv : event: unpause
04-02 17:09:43.194 6854 6957 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 23%) [0.233000s].
04-02 17:09:43.194 6854 6957 V mpv : property: buffering = true
04-02 17:09:43.195 6854 6854 V PlayerActivity: state PLAYING -> BUFFERING
04-02 17:09:43.197 6854 6854 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=2605.97, end=2663.961}], cache-end=2664.895, reader-pts=2664.662, cache-duration=0.23300000000017462, eof=false, underrun=true, idle=false, total-bytes=31290752, fw-bytes=131072, debug-low-level-seeks=0, debug-ts-last=2665.2610000000004, ts-per-stream=[{type=video, duration=0.23300000000017462, reader=2665.395, end=2665.628}, {type=audio, duration=0.0, reader=2665.688877777778, end=2665.688877777778}]}
04-02 17:09:45.467 6854 6854 V mpvstats: AV: 2664.495 A-V: 0.000 Dropped: 21 Cache: 0.233s + 0KB
04-02 17:09:48.467 6854 6854 V mpvstats: AV: 2664.495 A-V: 0.000 Dropped: 21 Cache: 0.233s + 0KB
04-02 17:09:50.780 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 23% -> 2%) [0.023222s].
04-02 17:09:50.782 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 2% -> 11%) [0.116100s].
04-02 17:09:50.807 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 11% -> 60%) [0.603722s].
04-02 17:09:50.833 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 60% -> 85%) [0.859144s].
04-02 17:09:51.035 6854 6957 V mpv : event: unpause
04-02 17:09:51.035 6854 6957 V mpv : [cplayer] End buffering (waited 7.841262 secs) [2.902489s].
04-02 17:09:51.036 6854 6957 V mpv : property: buffering = false
04-02 17:09:51.036 6854 6854 V PlayerActivity: state BUFFERING -> PLAYING
04-02 17:09:51.142 6854 6854 V mpvstats: AV: 2664.728 A-V: 0.058 Dropped: 27 Cache: 2.647s + 0KB
04-02 17:09:51.468 6854 6854 V mpvstats: AV: 2665.196 A-V: 0.000 Dropped: 29 Cache: 2.299s + 0KB
04-02 17:09:52.144 6854 6854 V mpvstats: AV: 2665.863 A-V: 0.000 Dropped: 29 Cache: 1.625s + 0KB
04-02 17:09:53.980 6854 6957 V mpv : event: unpause
04-02 17:09:53.980 6854 6957 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 23%) [0.234000s].
04-02 17:09:53.981 6854 6957 V mpv : property: buffering = true
04-02 17:09:53.981 6854 6854 V PlayerActivity: state PLAYING -> BUFFERING
04-02 17:09:53.981 6854 6854 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=2607.9719999999998, end=2667.9512555555557}], cache-end=2668.132, reader-pts=2667.898, cache-duration=0.2339999999999236, eof=false, underrun=true, idle=false, total-bytes=32102336, fw-bytes=172864, debug-low-level-seeks=0, debug-ts-last=2668.4980000000005, ts-per-stream=[{type=video, duration=0.2339999999999236, reader=2668.6310000000003, end=2668.8650000000002}, {type=audio, duration=0.0, reader=2668.7074666666667, end=2668.7074666666667}]}
04-02 17:09:54.469 6854 6854 V mpvstats: AV: 2667.731 A-V: 0.002 Dropped: 29 Cache: 0.234s + 0KB
04-02 17:09:57.470 6854 6854 V mpvstats: AV: 2667.731 A-V: 0.002 Dropped: 29 Cache: 0.234s + 0KB
04-02 17:10:00.471 6854 6854 V mpvstats: AV: 2667.731 A-V: 0.002 Dropped: 29 Cache: 0.234s + 0KB
04-02 17:10:03.473 6854 6854 V mpvstats: AV: 2667.731 A-V: 0.002 Dropped: 29 Cache: 0.234s + 0KB
04-02 17:10:05.552 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 23% -> 25%) [0.255422s].
04-02 17:10:05.560 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 25% -> 33%) [0.334000s].
04-02 17:10:05.569 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 33% -> 25%) [0.255422s].
04-02 17:10:05.585 6854 6957 V mpv : [cplayer] Still buffering (buffer went from 25% -> 78%) [0.789478s].
04-02 17:10:05.790 6854 6957 V mpv : event: unpause
04-02 17:10:05.790 6854 6957 V mpv : [cplayer] End buffering (waited 11.807353 secs) [5.572789s].
04-02 17:10:05.792 6854 6957 V mpv : property: buffering = false
04-02 17:10:05.793 6854 6854 V PlayerActivity: state BUFFERING -> PLAYING
04-02 17:10:06.186 6854 6854 V mpvstats: AV: 2668.299 A-V: 0.000 Dropped: 36 Cache: 12.678s + 0KB
04-02 17:10:06.474 6854 6854 V mpvstats: AV: 2668.566 A-V: 0.000 Dropped: 36 Cache: 15.859s + 0KB
04-02 17:10:09.475 6854 6854 V mpvstats: AV: 2671.569 A-V: 0.000 Dropped: 36 Cache: 68.592s + 0KB
04-02 17:10:12.481 6854 6854 V mpvstats: AV: 2674.605 A-V: 0.000 Dropped: 36 Cache: 68.638s + 0KB
04-02 17:10:15.481 6854 6854 V mpvstats: AV: 2677.575 A-V: 0.000 Dropped: 36 Cache: 65.666s + 0KB
04-02 17:10:18.482 6854 6854 V mpvstats: AV: 2680.578 A-V: 0.000 Dropped: 36 Cache: 62.671s + 0KB
04-02 17:10:21.483 6854 6854 V mpvstats: AV: 2683.581 A-V: 0.000 Dropped: 36 Cache: 69.799s + 0KB
04-02 17:10:24.485 6854 6854 V mpvstats: AV: 2686.584 A-V: 0.000 Dropped: 36 Cache: 66.804s + 0KB
04-02 17:10:27.486 6854 6854 V mpvstats: AV: 2689.587 A-V: 0.000 Dropped: 36 Cache: 63.716s + 0KB
04-02 17:10:30.487 6854 6854 V mpvstats: AV: 2692.590 A-V: 0.000 Dropped: 36 Cache: 70.635s + 0KB
04-02 17:10:32.111 6854 12160 V ApiServer: REQUEST: GET /log
04-02 17:10:32.112 6854 12160 I hls : goroutine 17 [running, locked to thread]:
04-02 17:10:32.112 6854 12160 I hls : main.FullStackTrace(0x8cc4c070, 0x8cc38f50)
04-02 17:10:32.112 6854 12160 I hls : /Users/fancybox/source/channels-android/vendor/libhls/channels-server/hls/libhls/hls_c.go:249 +0x80
04-02 17:10:32.112 6854 12160 I hls : main.hls_log_stack()
04-02 17:10:32.112 6854 12160 I hls : /Users/fancybox/source/channels-android/vendor/libhls/channels-server/hls/libhls/hls_c.go:259 +0x14
04-02 17:10:32.112 6854 12160 I hls : main._cgoexpwrap_277a0c6059f4_hls_log_stack()
04-02 17:10:32.112 6854 12160 I hls : _cgo_gotypes.go:299 +0x14
04-02 17:10:32.112 6854 12160 I hls :
04-02 17:10:32.112 6854 12160 I hls : goroutine 6 [syscall]:
04-02 17:10:32.112 6854 12160 I hls : os/signal.signal_recv(0x0)
04-02 17:10:32.112 6854 12160 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/runtime/sigqueue.go:147 +0x14c
04-02 17:10:32.112 6854 12160 I hls : os/signal.loop()
04-02 17:10:32.112 6854 12160 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/os/signal/signal_unix.go:23 +0x14
04-02 17:10:32.112 6854 12160 I hls : created by os/signal.Notify.func1
04-02 17:10:32.112 6854 12160 I hls : /usr/local/Cellar/go/HEAD-612ef03/libexec/src/os/signal/signal.go:127 +0x38
04-02 17:10:32.112 6854 12160 I hls :
04-02 17:10:32.112 6854 12160 I hls : goroutine 19 [select]:
04-02 17:10:32.112 6854 12160 I hls : github.com/grafov/kiwi.processSink(0x8cd8e080)
04-02 17:10:32.112 6854 12160 I hls : /Users/fancybox/go/pkg/mod/github.com/grafov/kiwi@v0.3.1/sink.go:327 +0x90
04-02 17:10:32.112 6854 12160 I hls : created by github.com/grafov/kiwi.SinkTo
04-02 17:10:32.112 6854 12160 I hls : /Users/fancybox/go/pkg/mod/github.com/grafov/kiwi@v0.3.1/sink.go:111 +0x310
04-02 17:10:32.282 6854 6864 I ls.dvr.app.bet: Background concurrent copying GC freed 292239(11MB) AllocSpace objects, 10(1628KB) LOS objects, 50% free, 17MB/34MB, paused 302us total 118.038ms
04-02 17:10:33.488 6854 6854 V mpvstats: AV: 2695.593 A-V: 0.000 Dropped: 36 Cache: 67.663s + 0KB
04-02 17:10:36.489 6854 6854 V mpvstats: AV: 2698.596 A-V: 0.000 Dropped: 36 Cache: 64.668s + 0KB
04-02 17:10:39.490 6854 6854 V mpvstats: AV: 2701.599 A-V: 0.000 Dropped: 36 Cache: 71.843s + 0KB
04-02 17:10:42.491 6854 6854 V mpvstats: AV: 2704.602 A-V: 0.000 Dropped: 36 Cache: 68.847s + 0KB
04-02 17:10:45.492 6854 6854 V mpvstats: AV: 2707.605 A-V: 0.000 Dropped: 36 Cache: 65.852s + 0KB
04-02 17:10:48.493 6854 6854 V mpvstats: AV: 2710.608 A-V: 0.000 Dropped: 36 Cache: 62.856s + 0KB
04-02 17:10:51.494 6854 6854 V mpvstats: AV: 2713.611 A-V: 0.000 Dropped: 36 Cache: 59.861s + 0KB
04-02 17:10:54.495 6854 6854 V mpvstats: AV: 2716.614 A-V: 0.000 Dropped: 36 Cache: 66.781s + 0KB
04-02 17:10:57.496 6854 6854 V mpvstats: AV: 2719.617 A-V: 0.000 Dropped: 36 Cache: 63.785s + 0KB
04-02 17:11:00.497 6854 6854 V mpvstats: AV: 2722.620 A-V: 0.000 Dropped: 36 Cache: 70.798s + 0KB
04-02 17:11:03.498 6854 6854 V mpvstats: AV: 2725.623 A-V: 0.000 Dropped: 36 Cache: 67.802s + 0KB
04-02 17:11:06.499 6854 6854 V mpvstats: AV: 2728.592 A-V: 0.000 Dropped: 36 Cache: 64.807s + 0KB
04-02 17:11:09.500 6854 6854 V mpvstats: AV: 2731.595 A-V: 0.000 Dropped: 36 Cache: 61.812s + 0KB
04-02 17:11:12.220 6854 6854 V mpvstats: AV: 2734.331 A-V: 0.000 Dropped: 37 Cache: 64.342s + 0KB
04-02 17:11:12.501 6854 6854 V mpvstats: AV: 2734.598 A-V: 0.000 Dropped: 37 Cache: 68.615s + 0KB
04-02 17:11:15.501 6854 6854 V mpvstats: AV: 2737.601 A-V: 0.000 Dropped: 37 Cache: 65.527s + 0KB
04-02 17:11:18.502 6854 6854 V mpvstats: AV: 2740.604 A-V: 0.000 Dropped: 37 Cache: 62.531s + 0KB
04-02 17:11:21.501 6854 6854 V mpvstats: AV: 2743.607 A-V: 0.000 Dropped: 37 Cache: 69.544s + 0KB
04-02 17:11:24.502 6854 6854 V mpvstats: AV: 2746.610 A-V: 0.000 Dropped: 37 Cache: 66.641s + 0KB
04-02 17:11:27.503 6854 6854 V mpvstats: AV: 2749.613 A-V: 0.000 Dropped: 37 Cache: 63.646s + 0KB
04-02 17:11:30.504 6854 6854 V mpvstats: AV: 2752.616 A-V: 0.000 Dropped: 37 Cache: 70.240s + 0KB
04-02 17:11:33.505 6854 6854 V mpvstats: AV: 2755.619 A-V: 0.000 Dropped: 37 Cache: 67.686s + 0KB
04-02 17:11:36.506 6854 6854 V mpvstats: AV: 2758.622 A-V: 0.000 Dropped: 37 Cache: 64.691s + 0KB
04-02 17:11:39.508 6854 6854 V mpvstats: AV: 2761.625 A-V: 0.000 Dropped: 37 Cache: 61.695s + 0KB
04-02 17:11:42.511 6854 6854 V mpvstats: AV: 2764.628 A-V: 0.000 Dropped: 37 Cache: 58.700s + 0KB
04-02 17:11:45.512 6854 6854 V mpvstats: AV: 2767.631 A-V: 0.000 Dropped: 37 Cache: 65.596s + 0KB
04-02 17:11:48.513 6854 6854 V mpvstats: AV: 2770.634 A-V: 0.000 Dropped: 37 Cache: 62.531s + 0KB
04-02 17:11:51.515 6854 6854 V mpvstats: AV: 2773.604 A-V: 0.000 Dropped: 37 Cache: 59.536s + 0KB
04-02 17:11:54.516 6854 6854 V mpvstats: AV: 2776.640 A-V: 0.000 Dropped: 37 Cache: 66.548s + 0KB
04-02 17:11:57.517 6854 6854 V mpvstats: AV: 2779.610 A-V: 0.000 Dropped: 37 Cache: 63.553s + 0KB
04-02 17:12:00.517 6854 6854 V mpvstats: AV: 2782.613 A-V: 0.000 Dropped: 37 Cache: 60.558s + 0KB
04-02 17:12:03.518 6854 6854 V mpvstats: AV: 2785.616 A-V: 0.000 Dropped: 37 Cache: 67.756s + 0KB
04-02 17:12:06.519 6854 6854 V mpvstats: AV: 2788.619 A-V: 0.000 Dropped: 37 Cache: 64.853s + 0KB
04-02 17:12:09.520 6854 6854 V mpvstats: AV: 2791.622 A-V: 0.000 Dropped: 37 Cache: 61.858s + 0KB
04-02 17:12:12.522 6854 6854 V mpvstats: AV: 2794.625 A-V: 0.000 Dropped: 37 Cache: 58.793s + 0KB
04-02 17:12:15.522 6854 6854 V mpvstats: AV: 2797.628 A-V: 0.000 Dropped: 37 Cache: 65.852s + 0KB
04-02 17:12:18.523 6854 6854 V mpvstats: AV: 2800.631 A-V: 0.000 Dropped: 37 Cache: 62.856s + 0KB
04-02 17:12:21.523 6854 6854 V mpvstats: AV: 2803.634 A-V: 0.000 Dropped: 37 Cache: 59.861s + 0KB
04-02 17:12:24.523 6854 6854 V mpvstats: AV: 2806.637 A-V: 0.000 Dropped: 37 Cache: 65.364s + 0KB
04-02 17:12:27.524 6854 6854 V mpvstats: AV: 2809.640 A-V: 0.000 Dropped: 37 Cache: 63.576s + 0KB
04-02 17:12:30.525 6854 6854 V mpvstats: AV: 2812.643 A-V: 0.000 Dropped: 37 Cache: 60.581s + 0KB
04-02 17:12:33.526 6854 6854 V mpvstats: AV: 2815.646 A-V: 0.000 Dropped: 37 Cache: 67.570s + 0KB
04-02 17:12:36.527 6854 6854 V mpvstats: AV: 2818.649 A-V: 0.000 Dropped: 37 Cache: 64.575s + 0KB
04-02 17:12:37.678 6854 8365 W ExifInterface: Stop reading file since a wrong offset may cause an infinite loop: 0
04-02 17:12:39.529 6854 6854 V mpvstats: AV: 2821.652 A-V: 0.000 Dropped: 37 Cache: 61.579s + 0KB
04-02 17:12:42.532 6854 6854 V mpvstats: AV: 2824.622 A-V: 0.000 Dropped: 37 Cache: 58.491s + 0KB
04-02 17:12:45.533 6854 6854 V mpvstats: AV: 2827.625 A-V: 0.000 Dropped: 37 Cache: 55.519s + 0KB
04-02 17:12:48.535 6854 6854 V mpvstats: AV: 2830.661 A-V: 0.000 Dropped: 37 Cache: 52.524s + 0KB
04-02 17:12:51.537 6854 6854 V mpvstats: AV: 2833.631 A-V: 0.000 Dropped: 37 Cache: 57.655s + 0KB
04-02 17:12:54.537 6854 6854 V mpvstats: AV: 2836.634 A-V: 0.000 Dropped: 37 Cache: 56.610s + 0KB
04-02 17:12:57.538 6854 6854 V mpvstats: AV: 2839.637 A-V: 0.000 Dropped: 37 Cache: 53.615s + 0KB
04-02 17:13:00.539 6854 6854 V mpvstats: AV: 2842.640 A-V: 0.000 Dropped: 37 Cache: 50.620s + 0KB
04-02 17:13:03.539 6854 6854 V mpvstats: AV: 2845.643 A-V: 0.000 Dropped: 37 Cache: 57.655s + 0KB
04-02 17:13:06.540 6854 6854 V mpvstats: AV: 2848.646 A-V: 0.000 Dropped: 37 Cache: 64.714s + 0KB
04-02 17:13:09.541 6854 6854 V mpvstats: AV: 2851.649 A-V: 0.000 Dropped: 37 Cache: 61.742s + 0KB
04-02 17:13:12.542 6854 6854 V mpvstats: AV: 2854.652 A-V: 0.000 Dropped: 37 Cache: 58.746s + 0KB
04-02 17:13:15.543 6854 6854 V mpvstats: AV: 2857.655 A-V: 0.000 Dropped: 37 Cache: 65.643s + 0KB
04-02 17:13:18.545 6854 6854 V mpvstats: AV: 2860.658 A-V: 0.000 Dropped: 37 Cache: 62.555s + 0KB
04-02 17:13:21.545 6854 6854 V mpvstats: AV: 2863.661 A-V: 0.000 Dropped: 37 Cache: 59.559s + 0KB
04-02 17:13:24.546 6854 6854 V mpvstats: AV: 2866.664 A-V: 0.000 Dropped: 37 Cache: 56.587s + 0KB
04-02 17:13:27.547 6854 6854 V mpvstats: AV: 2869.667 A-V: 0.000 Dropped: 37 Cache: 63.507s + 0KB
04-02 17:13:30.548 6854 6854 V mpvstats: AV: 2872.670 A-V: 0.000 Dropped: 37 Cache: 60.511s + 0KB
04-02 17:13:33.550 6854 6854 V mpvstats: AV: 2875.639 A-V: 0.000 Dropped: 37 Cache: 57.423s + 0KB
04-02 17:13:36.552 6854 6854 V mpvstats: AV: 2878.642 A-V: 0.000 Dropped: 37 Cache: 64.760s + 0KB
04-02 17:13:39.554 6854 6854 V mpvstats: AV: 2881.645 A-V: 0.000 Dropped: 37 Cache: 61.765s + 0KB
04-02 17:13:42.556 6854 6854 V mpvstats: AV: 2884.648 A-V: 0.000 Dropped: 37 Cache: 58.770s + 0KB
04-02 17:13:45.560 6854 6854 V mpvstats: AV: 2887.685 A-V: 0.000 Dropped: 37 Cache: 65.643s + 0KB
04-02 17:13:46.311 6854 6862 W System : A resource failed to call end.
04-02 17:13:48.561 6854 6854 V mpvstats: AV: 2890.654 A-V: 0.000 Dropped: 37 Cache: 62.671s + 0KB
04-02 17:13:51.563 6854 6854 V mpvstats: AV: 2893.657 A-V: 0.000 Dropped: 37 Cache: 59.675s + 0KB
04-02 17:13:54.564 6854 6854 V mpvstats: AV: 2896.660 A-V: 0.000 Dropped: 37 Cache: 56.587s + 0KB
04-02 17:13:57.297 6854 6854 V mpvstats: AV: 2899.430 A-V: 0.000 Dropped: 38 Cache: 63.019s + 0KB
04-02 17:13:57.565 6854 6854 V mpvstats: AV: 2899.663 A-V: 0.000 Dropped: 38 Cache: 63.739s + 0KB
04-02 17:14:00.566 6854 6854 V mpvstats: AV: 2902.666 A-V: 0.000 Dropped: 38 Cache: 60.743s + 0KB
04-02 17:14:03.567 6854 6854 V mpvstats: AV: 2905.669 A-V: 0.000 Dropped: 38 Cache: 57.748s + 0KB
04-02 17:14:06.568 6854 6854 V mpvstats: AV: 2908.672 A-V: 0.000 Dropped: 38 Cache: 64.575s + 0KB
04-02 17:14:09.569 6854 6854 V mpvstats: AV: 2911.675 A-V: 0.000 Dropped: 38 Cache: 61.579sVery interesting. Are you able to try using your SHIELD as a client. It would be interesting to know if the same thing can be replicated on that device.
I can't because my Server is on it. That is why I have previously mentioned that I experience the same issues on my FireTV 4k stick which is Android based.
Now with that said, I have tried the MPV Android Player and experience the same problem. I have also tried the VLC Player and have not experienced the same problem.
The server and client can run on the same shield. The shield is the best android client hardware available and the one we are most familiar with. If the same issue occurs on the shield, then it helps us narrow down where the problem is originating.
Doesn't have them on the same device remove the network pipe from the equation so you are not just changing one thing?
What about that other change you mentioned you were thinking about?