In this case the issue started earlier, when the cache first started dropping from 95s. Eventually it ran out and was not being refilled at all (probably because of network disconnect).
Okay well do you have any suggestions on a fix?
Also why is this only happening when the quality is set to original? The log doesn’t seem to suggest any kind of cause
Something isn't working correctly in your network. Could be a loose cable, a spanning loop, a firewall, VM nic driver, powerline, flow control, etc. I don't know how your network works or is setup. Other users with simple network setups are not running into this problem, which is quite extreme as the entire device is losing access to your LAN.
When you set to original streaming it is accessing the recording file directly and downloading it into the player. When you use 8mbps instead, the stream is usually re-encoded to use less packets/bandwidth on your network, and the transport mechanism is also slightly different (although they both use HTTP).
Do you have flow control disabled on the hypervisor's network adapter? That's been known to cause problems, as has "autotuning":
My Apple TV 4 is wired Ethernet. Tonight again it hiccups. This only happens on my non-4K Apple TV. I have a 4K and it’s smooth as silk. Ran a speed test:
Also took a video of the issue happening. This was a minor occurrence, two hiccups. Sometimes it’s worse.
Note that when I first started using Channels on this device it had no issues. It’s something that has appeared relatively recently, perhaps something in TVOS or Channels. Not sure. Next time I’ll see if I can also pull client logs when it happens. I have uploaded logs from the client in the past when it happened, don’t know if you are still able to see them.
1 Like
I will check all of that. As Macnbaish has also said, The issue only appears to happen on the Non-4k Apple TV and for me, at least it is a intermittent issue. If the issue is network related then surely it would be happening constantly.
Also if the issue was a network issue then surely we would see this happen when streaming is set to 8mbps.
I feel like we are going round in circles and would like a answer to what is going on.
8mbps is a lower bitrate. It is less bandwidth than the original signal. It is less bandwidth going through the network connection. Many users with network issues, especially those on WiFi, are able to compensate by lowering the bitrate being transferred.
Im aware of that. However the issue is when on wired or wireless.
So that eliminates the wifi access point. Leaving either a server configuration that is causing issue, a faulty device, or any of the cables/switches in-between.
Some troubleshooting steps:
- Try the ping loop from a third computer to see if either client or server stops responding completely when issue occurs. Or just open two different shells and do a continuous ping on each.
- Check the NIC settings in your VM, disable flow control.
- Check the VM settings for the network adapter. Try setting it to use the host network and not a separate bridged network.
- Ensure you aren't using anything like QoS or IDS/IPS on your switch/router.
- Ensure you don't have separate VLANs configured.
- Try a different switch.
- Try a different ethernet cable from the server.
- Try a different ethernet cable from the ATV.
- Try running the DVR on a different system, or even the same system, but not in a VM.
- Try a different Apple TV.
He’s not the only one experiencing this issue. I’ve tried many of the things you mentioned already. Speed test shows a solid 100Mbit connection. Later tonight I’ll try one of the recording using VLC instead of the Channels App and see how it does.
@Macnbaish Can you check your player logs and see if you're seeing any similar disconnect error messages?
Just played a recording and saw some minor hiccups. Here are the logs that seem relevant:
http://192.168.1.251:8089/dvr/files/1382/playback_time/5
2020-02-12 21:47:24.231 mpvstats: AV: 5.822 A-V: 0.000 Dropped: 7 Cache: 41.38s + 0KB
2020-02-12 21:47:24.630 LTHTTPClient: GET http://192.168.1.251:8089/dvr/files/1382
2020-02-12 21:47:24.660 LTHTTPClient: GET http://192.168.1.251:8089/dvr/groups/191277
2020-02-12 21:47:29.221 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/10
2020-02-12 21:47:29.224 mpvstats: AV: 10.827 A-V: 0.000 Dropped: 10 Cache: 41.92s + 0KB
2020-02-12 21:47:34.225 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/15
2020-02-12 21:47:34.230 mpvstats: AV: 15.832 A-V: 0.000 Dropped: 10 Cache: 41.89s + 0KB
2020-02-12 21:47:39.227 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/20
2020-02-12 21:47:39.233 mpvstats: AV: 20.820 A-V: 0.000 Dropped: 11 Cache: 42.02s + 0KB
2020-02-12 21:47:44.220 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/25
2020-02-12 21:47:44.221 mpvstats: AV: 25.825 A-V: 0.000 Dropped: 13 Cache: 40.90s + 0KB
2020-02-12 21:47:49.225 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/30
2020-02-12 21:47:49.227 mpvstats: AV: 30.830 A-V: 0.000 Dropped: 15 Cache: 40.70s + 0KB
2020-02-12 21:47:54.225 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/35
2020-02-12 21:47:54.232 mpvstats: AV: 35.818 A-V: 0.000 Dropped: 15 Cache: 40.77s + 0KB
2020-02-12 21:47:59.223 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/40
2020-02-12 21:47:59.224 mpvstats: AV: 40.823 A-V: 0.000 Dropped: 15 Cache: 40.83s + 0KB
2020-02-12 21:48:04.227 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/45
2020-02-12 21:48:04.235 mpvstats: AV: 45.828 A-V: 0.000 Dropped: 15 Cache: 40.90s + 0KB
2020-02-12 21:48:09.225 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/50
2020-02-12 21:48:09.231 mpvstats: AV: 50.800 A-V: 0.000 Dropped: 17 Cache: 41.18s + 0KB
2020-02-12 21:48:14.221 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/55
2020-02-12 21:48:14.222 mpvstats: AV: 55.822 A-V: 0.000 Dropped: 18 Cache: 41.31s + 0KB
2020-02-12 21:48:19.221 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/60
2020-02-12 21:48:19.222 mpvstats: AV: 60.827 A-V: 0.000 Dropped: 22 Cache: 41.38s + 0KB
2020-02-12 21:48:24.226 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/65
2020-02-12 21:48:24.227 mpvstats: AV: 65.832 A-V: 0.000 Dropped: 22 Cache: 41.38s + 0KB
2020-02-12 21:48:29.219 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/70
2020-02-12 21:48:29.231 mpvstats: AV: 70.820 A-V: 0.000 Dropped: 23 Cache: 41.41s + 0KB
2020-02-12 21:48:34.219 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/75
2020-02-12 21:48:34.219 mpvstats: AV: 75.825 A-V: 0.000 Dropped: 24 Cache: 41.34s + 0KB
2020-02-12 21:48:39.221 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/80
2020-02-12 21:48:39.227 mpvstats: AV: 80.830 A-V: 0.000 Dropped: 25 Cache: 41.63s + 0KB
2020-02-12 21:48:44.221 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/85
2020-02-12 21:48:44.222 mpvstats: AV: 85.802 A-V: 0.000 Dropped: 27 Cache: 41.60s + 0KB
2020-02-12 21:48:49.220 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/90
2020-02-12 21:48:49.221 mpvstats: AV: 90.823 A-V: 0.000 Dropped: 34 Cache: 41.38s + 0KB
2020-02-12 21:48:54.221 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/95
2020-02-12 21:48:54.222 mpvstats: AV: 95.812 A-V: 0.000 Dropped: 34 Cache: 41.38s + 0KB
2020-02-12 21:48:59.220 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1382/playback_time/100
2020-02-12 21:48:59.221 mpvstats: AV: 100.800 A-V: 0.000 Dropped: 35 Cache: 41.47s + 0KB
The cache looks pretty consistent, but I noticed it says “Dropped”. Could that be dropped video frames? If so, that’s exactly what this issue looks like. If you need more from the logs let me know.
Edit: Oops, I closed the app which kills the logs I think. It’s easy to reproduce so I can create new ones if you need more info.
Yes it looks like you're dropping frames, so your issue is different than what @Danny0239 is experiencing.
Is this happening on SD or HD recordings? On mpeg2 or h264?
Even if the issue is different, his cache isn’t at 95.02 and it drops lower as the playback continues.
In regards to the questions, mine happens on both SD and HD.
Yes but his cache is not hitting zero, and he's not seeing network disconnect errors like you are. The cache is also staying steady around 40 instead of decreasing all the way to zero, which means it continues to receive data in real time as playback is occurring. In your situation no data is received so the cache eventually runs out.
We just seem to be going round in circles.
Is there anything you guys can try to at least attempt to fix this or at least put more advanced logging on.
I'm sure that must be very frustrating having this issue with no resolution. Especially when you are as knowledgeable as you are in IT field.
With that said, I think the problem is the logs are telling a story, and that is you are having network issues of some sort. I know you don't agree, but just reading this as an outsider, it sure seems like that is what the data is saying.
You mentioned that this only happens on your non-4k apple tv. Have you tried switching locations with your 4k and non-4k apple tv to see if the issue follows the device, or if it stays with the location? I'm assuming they aren't connected to the same tv?
2 Likes
I agree I think these are two different issues. Feel free to split this into a separate thread. I’ll do some tests with recordings of different file types to see if it’s limited to one type. Stay tuned.
Here are the details of the recording logged above showing frame drops:
Duration
4 hrs 36 min
Bit Rate
11,973,109 bits/sec
File Size
24,709,319,832 bytes
File ID
1382
Streaming Index Up-to-date
Yes
Track #0: MPEG-2 video
1280x720 16:9 yuv420p progressive 59.94fps
Track #1: ATSC A/52A (AC-3)
5.1(side) eng 384kbps
Track #2: ATSC A/52A (AC-3)
mono spa 96kbps
Track #3: SCTE 35 Message Queue
———————-
Found an H264 recording:
Duration
2 hrs 41 min
Bit Rate
3,529,628 bits/sec
File Size
4,245,258,240 bytes
File ID
1035
Streaming Index Up-to-date
Yes
Track #0: AAC (Advanced Audio Coding)
stereo 121.687kbps
Track #1: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
1280x720 yuv420p progressive 29.97fps
Track #2: timed ID3 metadata
After watching for about 7 minutes, I only noticed one tiny hiccup, and 6 total dropped frames:
2020-02-13 22:34:21.407 mpvstats: AV: 461.304 A-V: 0.000 Dropped: 6 Cache: 95.02s + 0KB
So the issue seems to be impacting Mpeg2 playback. I also notice the Mpeg2 recording is 60 FPS, while the H264 is 30 FPS. I’ll see if I have any Mpeg2 at 30 FPS to test with.
Found one:
Duration
46 min
Bit Rate
7,679,117 bits/sec
File Size
2,601,587,240 bytes
File ID
1571
Streaming Index Up-to-date
Yes
Track #0: MPEG-2 video
1920x1080 16:9 yuv420p interlaced 29.97fps
Track #1: ATSC A/52A (AC-3)
5.1(side) eng 384kbps
Track #2: ATSC A/52A (AC-3)
stereo spa 192kbps
From the start it was dropping more frames than the H264 content, but it was fairly slow and not very noticeable. However, once I got about five minutes in, the rate started to increase and it was more noticeable visually as well. Here’s a snip from the end of the viewing period of about 7 minutes:
2020-02-13 23:08:45.778 mpvstats: AV: 400.958 A-V: 0.000 Dropped: 71 Cache: 68.70s + 0KB
2020-02-13 23:08:50.779 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1571/playback_time/405
2020-02-13 23:08:50.780 mpvstats: AV: 405.946 A-V: 0.000 Dropped: 71 Cache: 68.29s + 0KB
2020-02-13 23:08:55.780 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1571/playback_time/410
2020-02-13 23:08:55.793 mpvstats: AV: 410.984 A-V: 0.000 Dropped: 75 Cache: 67.14s + 0KB
2020-02-13 23:09:00.778 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1571/playback_time/415
2020-02-13 23:09:00.779 mpvstats: AV: 415.956 A-V: 0.000 Dropped: 75 Cache: 66.91s + 0KB
2020-02-13 23:09:05.772 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1571/playback_time/420
2020-02-13 23:09:05.776 mpvstats: AV: 420.828 A-V: 0.076 Dropped: 81 Cache: 67.33s + 0KB
2020-02-13 23:09:10.781 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1571/playback_time/425
2020-02-13 23:09:10.783 mpvstats: AV: 425.966 A-V: 0.000 Dropped: 86 Cache: 68.26s + 0KB
2020-02-13 23:09:15.780 LTHTTPClient: PUT http://192.168.1.251:8089/dvr/files/1571/playback_time/430
2020-02-13 23:09:15.793 mpvstats: AV: 430.938 A-V: 0.000 Dropped: 86 Cache: 67.10s + 0KB
Danny. I saw up the thread that you mentioned this only happens when viewing recordings. Is that still true? If so, in your client settings do you have tuner sharing enabled or disabled?
It's a bit maddening how everyone is so quick to continuously blame the network and not even consider the fact that it could be something within the app or tvOS itself.
Just because this isn't a widespread issue doesn't mean that there isn't a bug or something somewhere in Channels or tvOS causing these intermittent buffering issues for users with specific configurations.
Even if there is a temporary network glitch, Channels should be able to recover and resume the stream afterwards without having to fully reboot the ATV. As I mentioned earlier in the thread, the network activity from the DVR service on my server is virtually nil (Windows Resource Monitor shows about ~130,000 B/sec for channels-dvr.exe to the ATV) when the issue occurs.
I thought I'd found something promising, which is why I've held off on posting this week until now. I setup NIC teaming using the native Windows teaming capabilities on Tuesday night with my server's dual onboard NICs. I went almost three days before experiencing it again just a little while ago.
I looked at the logging as described earlier in the thread, and I'm seeing the same thing as Danny. My cache reaches 0 and bombs out.
Running the speed test from the DVR server, I regularly get between 875 Mbps and 950 Mbps download with less than 3 ms latency and jitter ranging from .3 ms to .75 ms.
What's interesting is that if I kick off the speed test when I'm experiencing the issue, Channels almost immediately resumes the stream, and it keeps working for a few minutes before the cache runs out again. I was able to reproduce this behavior consistently the 4 or 5 times I tried it.
I also had ping -t running from my desktop PC to the DVR server this last time when I kept running into the issue. 1365 packets sent, 0 dropped, max latency 12ms, and average latency 0ms.
But, ultimately, once the issue occurs, it keeps happening every few minutes until I reboot the ATV, where I might not see it for a day or three. If this issue had something to do with my network performance, why would it clear up for days at a time and only after the ATV was rebooted?
My configuration for Channels isn't super complex. I have a brand new HPE Microserver with a vanilla install of Windows on it that was purchased specifically for use as a DVR/storage server. There's absolutely nothing else on the server at the moment other than the Channels DVR software.
Everything is hardwired with CAT6 into a network that's comprised of three HPE managed gigabit switches, each of which are all interconnected with bonded gig trunks. I don't use any of the traffic manipulation features on the switch...no QoS, no flow control, no jumbo frames, no storm control, etc. I have loop protection and RSTP with the bridge priorities set appropriately on all switches.
I do have VLANs on my network, but those are all handled at the router. All the Channels/TV traffic is on the same default, untagged VLAN, so the router doesn't come into the equation at all.
I'm not experiencing stuttering issues with any other apps on my ATVs or anywhere else in my network, and the Channels DVR is able to record multiple TV streams simultaneously without missing a beat.
Speaking to that effect, last night, I had five streams recording simultaneously, was watching a recording on the ATV, and had another recording playing via the browser. Everything worked without issue.
These are the things that I've already tried...
- updated the BIOS
- installed the latest chipset drivers, graphics drivers, NIC drivers (tried both the HPE branded and Broadcom drivers), and NIC BIOS
- set the power policy in Windows to high performance
- adjusted multiple settings for the NIC, including changing the EEE profile, disabling EEE, adjusting the number of RSS queues, disabling flow control, and adjusting the receive and transmit buffer values
- put in AV scanning exclusions for Channels into Windows Defender and even disabled Windows Defender
- tried the production and multiple beta versions of both the DVR software and Channels apps
- unplugged the ethernet cables from both the ATV and the DVR server when the issue was occurring
- tried a different switch port, different cable, NIC teaming
What more can I do? And why isn't the app recovering the stream if there's some sort of temporary network glitch? The speed test and ping tests that I'm running when the issue occurs proves to me that there's not a line quality issue when the issue is occurring. All of the evidence I'm seeing is pointing me to the ATV or app itself.
We've definitely considered it could be within the app or tvOS. We just haven't found anything that pointed to any of that.
We have a few different people on this thread and so far have seen at least two distinct issues that have different behaviors in the logs.
To try to see if there is something strange going on with the network that we can work around, please try the tvOS TestFlight beta and scroll to the bottom of the Settings screen and enable Use HLS Streaming When Efficient.
You can join the TestFlight beta from an iPhone at https://getchannels.com/beta/ or you can email [email protected] with the email address you would like us to use to join the beta.