Stable Cable Connection: "no data was received for 6s"

#1

Does the "no data was received for 6s" always indicate a communication issue between the tuner and DVR? I'm seeing this happen periodically for local and remote viewing and trying to determine if there is a problem with my cable provider.

Multiple times I've seen two separate channels get kicked at the same time despite a stable signal (Cable provided via IP using a fiber OTN with cable output at the home).

Will submit diagnostics from the Apple TV when it happens again, submitting diagnostics from the sever now under user "dcleslie"...

2022/01/22 21:09:43.221630 [TNR] Cancelling stream 1323BD1F/1 ch1108 after no data was received for 6s
2022/01/22 21:09:43.221631 [TNR] Cancelling stream 13168F62/0 ch1105 after no data was received for 6s
2022/01/22 21:09:43.222171 [HLS] ffmpeg: ch1105-dANY-4b53c3499fa6-remux:  [mpegts @ 0x60fe6c0] Dropped corrupted packet (stream = 1)
2022/01/22 21:09:43.222202 [HLS] ffmpeg: ch1105-dANY-4b53c3499fa6-remux:  [mpegts @ 0x60fe6c0] Dropped corrupted packet (stream = 2)
2022/01/22 21:09:43.222193 [HLS] ffmpeg: ch1108-dANY-9606117f6c70-remux:  [mpegts @ 0x60fe6c0] Dropped corrupted packet (stream = 1)
2022/01/22 21:09:43.222304 [HLS] ffmpeg: ch1108-dANY-9606117f6c70-remux:  [mpegts @ 0x60fe6c0] Dropped corrupted packet (stream = 2)
2022/01/22 21:09:43.240052 [SNR] Statistics for ch1108 WJZYHD: ss=100% snq=100% seq=100% bps=18883534,5894176-19434688 pps=1615,0-1671
2022/01/22 21:09:43.251738 [TNR] Closed connection to 1323BD1F/1 for ch1108 WJZYHD
2022/01/22 21:09:43.257203 [TNR] Closed connection to 13168F62/0 for ch1105 CBSHD
2022/01/22 21:09:43.257302 [SNR] Statistics for ch1105 CBSHD: ss=100% snq=100% seq=100% bps=18946794,949024-19555008 pps=1621,0-1667
2022/01/22 21:09:43.288875 [SNR] Statistics for "TV/NFL Football/NFL Football San Francisco 49ers at Green Bay Packers 2022-01-22-2056.mpg": ss=100% snq=100% seq=100% bps=18883534,5894176-19434688 pps=1615,0-1671
2022/01/22 21:09:43.319604 [DVR] Job 1642899600-ch1108 NFL Football ended prematurely: 1h50m16.680399733s
Sockets in close-wait state
#2

I would check the system log in those prime tuners to see what it says.
Got to be something in common if two tuners fail at the same time.
I would think either cable signal or network from tuners to dvr.

#3

Yes, we have a read timeout on the local network connections to the HDHR. The data being sent by the HDHR is constant with very little buffer available on the HDHR, so if it isn't able to send data constantly, data will be dropped.

Because we know that the data is being sent consistently, we have a fairly short timeout (6 seconds) to close the connection if it's been that long since we received data.

I would guess that you're either having a hardware issue with the HDHR or you're having a momentary network issue causing all connections to hang at the same time.

#4

TL;DR: Are there any more robust logs on the DVR to help pinpoint this issue?

Following up on this... and even more confused. I assumed there may be a network issue since all streams were being dropped at the same time. I hooked up an OTA HDHR and had it streaming during the same time the streams below failed. The OTA streams didn't drop once, leaving me to believe the issue is not with network routing.

Next guess is that the cable feed is dropping out, but that is also confusing. My home is served with fiber, the ONT has a cable output, I've never seen low signal levels on the cable feed and there was no downtime on the network. In addition, the dropped channels open back up without issue immediately after the DVR reports no data for 6 seconds.

At this point I'm not sure how to narrow down the problem. It could be an issue with the ONT. Is there any more logging that the DVR does that could help pinpoint the issue? Has the 6s timeout been in place for more than 2 months (when this first started). The only logs showing in the tuner are: 20220214-01:33:36 Tuner: tuner0 http stream ended (remote closed)

DVR 1:

2022/02/13 20:33:36.821654 [TNR] Cancelling stream 13225028/0 ch1106 after no data was received for 6s
2022/02/13 20:33:36.831314 [TNR] Closed connection to 13225028/0 for ch1106 NBCHD
2022/02/13 20:33:36.840462 [HLS] ffmpeg: ch1106-dANY-53f102099cdd-remux:      Last message repeated 106 times
2022/02/13 20:33:37.029958 [SNR] Statistics for ch1106 NBCHD: ss=100% snq=100% seq=99%,0%-100% bps=18268248,0-19200064 pps=1563,0-1643
2022/02/13 20:33:38.002594 [HLS] Couldn't generate stream playlist for ch1106-dANY-53f102099cdd: Stream stopped
2022/02/13 20:33:38.002785 [HLS] Stopping transcoder session ch1106-dANY-53f102099cdd (out: 5h20m7.404989s, finished: true)

2022/02/13 22:08:25.653857 [TNR] Cancelling stream 13225028/0 ch1106 after no data was received for 6s
2022/02/13 22:08:25.653858 [TNR] Cancelling stream 13225028/1 ch1109 after no data was received for 6s
2022/02/13 22:08:25.672669 [HLS] ffmpeg: ch1106-dANY-53f102099cdd-remux:      Last message repeated 32 times
2022/02/13 22:08:25.673581 [TNR] Closed connection to 13225028/0 for ch1106 NBCHD
2022/02/13 22:08:25.673673 [TNR] Closed connection to 13225028/1 for ch1109 PBS-A H
2022/02/13 22:08:25.685456 [SNR] Statistics for "TV/Vienna Blood/Vienna Blood S02E00 Darkness Rising Part 2 2022-02-13-2200.mpg": ss=100% snq=100% seq=100% bps=10047979,1570176-19055680 pps=851,0-1631
2022/02/13 22:08:25.702592 [DVR] Job 1644807600-107 Vienna Blood ended prematurely: 51m34.297412439s
2022/02/13 22:08:25.775113 [DVR] Starting job 1644807600-107 Vienna Blood on ch=[1109 1107 113]
2022/02/13 22:08:25.775245 [DVR] Waiting 18h51m34.224757714s until next job 1644876000-35 The Five
2022/02/13 22:08:25.834726 [SNR] Statistics for ch1106 NBCHD: ss=100% snq=100% seq=100% bps=18671205,1186656-19183520 pps=1597,0-1641
2022/02/13 22:08:25.939985 [HLS] Couldn't generate stream playlist for ch1106-dANY-53f102099cdd: Stream stopped
2022/02/13 22:08:25.940153 [HLS] Stopping transcoder session ch1106-dANY-53f102099cdd (out: 1h33m43.383878s, finished: true)

DVR 2:

2022/02/13 20:33:36.823087 [TNR] Cancelling stream 1317E539/0 ch1106 after no data was received for 6s
2022/02/13 20:33:36.841581 [TNR] Closed connection to 1317E539/0 for ch1106 NBCHD
2022/02/13 20:33:36.846690 [HLS] ffmpeg: ch1106-dANY-6d4429b91688-remux:      Last message repeated 49 times
2022/02/13 20:33:37.040459 [SNR] Statistics for ch1106 NBCHD: ss=100% snq=100% seq=100% bps=18444571,112800-19172992 pps=1578,0-1641
2022/02/13 20:33:38.060885 [HLS] Couldn't generate stream playlist for ch1106-dANY-6d4429b91688: Stream stopped
2022/02/13 20:33:38.060932 [HLS] Stopping transcoder session ch1106-dANY-6d4429b91688 (out: 2h54m16.585s, finished: true)

2022/02/13 22:08:25.654119 [TNR] Cancelling stream 1317E539/0 ch1106 after no data was received for 6s
2022/02/13 22:08:25.676607 [TNR] Closed connection to 1317E539/0 for ch1106 NBCHD
2022/02/13 22:08:25.681514 [HLS] ffmpeg: ch1106-dANY-6d4429b91688-remux:      Last message repeated 32 times
2022/02/13 22:08:25.853966 [SNR] Statistics for ch1106 NBCHD: ss=100% snq=100% seq=100% bps=18674377,9303744-19157952 pps=1597,0-1641
2022/02/13 22:08:26.426006 [HLS] Couldn't generate stream playlist for ch1106-dANY-6d4429b91688: Stream stopped
2022/02/13 22:08:26.426109 [HLS] Stopping transcoder session ch1106-dANY-6d4429b91688 (out: 1h33m26.903378s, finished: true)

DVR 3:

2022/02/13 20:33:36.821914 [TNR] Cancelling stream 131C093A/0 ch1106 after no data was received for 6s
2022/02/13 20:33:36.822985 [TNR] Closed connection to 131C093A/0 for ch1106 NBCHD
2022/02/13 20:33:36.839695 [HLS] ffmpeg: ch1106-dANY-70c3cc511d48-remux:      Last message repeated 43 times
2022/02/13 20:33:37.031486 [SNR] Statistics for ch1106 NBCHD: ss=100% snq=100% seq=100% bps=18414741,9956480-19157952 pps=1575,0-1641
2022/02/13 20:33:38.012081 [HLS] Couldn't generate stream playlist for ch1106-dANY-70c3cc511d48: Stream stopped
2022/02/13 20:33:38.012131 [HLS] Stopping transcoder session ch1106-dANY-70c3cc511d48 (out: 2h30m18.782567s, finished: true)

2022/02/13 22:08:25.655118 [TNR] Cancelling stream 131C093A/0 ch1106 after no data was received for 6s
2022/02/13 22:08:25.681513 [TNR] Closed connection to 131C093A/0 for ch1106 NBCHD
2022/02/13 22:08:25.687912 [HLS] ffmpeg: ch1106-dANY-70c3cc511d48-remux:      Last message repeated 32 times
2022/02/13 22:08:25.739395 [HLS] Couldn't generate stream playlist for ch1106-dANY-70c3cc511d48: Stream stopped
2022/02/13 22:08:25.739708 [HLS] Stopping transcoder session ch1106-dANY-70c3cc511d48 (out: 1h34m17.944922s, finished: true)
2022/02/13 22:08:25.746580 [SNR] Statistics for ch1106 NBCHD: ss=100% snq=100% seq=99%,0%-100% bps=18675861,0-19157952 pps=1597,0-1641
#5

6s timeout has been in place for many years, since the first dvr release

The hdhomerun has more detailed diagnostics you can enable via the checkbox on the HDHR web UI. But they are sent directly to SiliconDust so you have to ask their support to look at them and tell you what it says.

1 Like
#6

you ever get anywhere with this? I'm curious what server you are using.

I've had my system up for years with no issues.

  • Channels running on Windows VM
  • Everything is hardwired (1g)
  • All ATV4k clients.

I changed from Windows VM to Docker container for Channels and I'm now seeing no data received after 6s multiple times a day. However when running the same channel at the same time using the HDHomerun App, only the channels client fails. The HDHomerun App does not throw an error or fail.

#7

I ran

grep -a 'after no data was received for 6s$' channels-dvr.log |cut -c-10|uniq -c

to see the number of 6s timeout events per day.

Here is the output:

      1 2022/08/22
      2 2022/09/02
      2 2022/09/14
     29 2022/09/18
      2 2022/10/11
      1 2022/10/30
      1 2022/10/31
     91 2022/11/13
      2 2022/11/14
     20 2022/11/18
     10 2022/11/19
      1 2022/11/25
      3 2022/11/28
      1 2022/12/25
      3 2023/01/24
      2 2023/02/02
      1 2023/02/12
      1 2023/02/28
      2 2023/03/04
     21 2023/03/06
      1 2023/03/21
      3 2023/03/28
      7 2023/03/31
      1 2023/04/01
    128 2023/04/03
      4 2023/04/04
     55 2023/04/14
     99 2023/04/18
      3 2023/04/22
      1 2023/05/02
      1 2023/05/07
      1 2023/05/15
     22 2023/06/10
      1 2023/06/13
     10 2023/06/15
     11 2023/06/16
     59 2023/06/17
      8 2023/06/19
    115 2023/06/20
      7 2023/06/21
      3 2023/06/22
      4 2023/06/23
      2 2023/06/24
      2 2023/06/26
      2 2023/06/27
     69 2023/06/28
    101 2023/06/29
     77 2023/06/30
     10 2023/07/01
     18 2023/07/03
      3 2023/07/10
      8 2023/07/14
     14 2023/07/15
    131 2023/07/17
      8 2023/07/18
     68 2023/07/19
     77 2023/07/20
     30 2023/07/21
      2 2023/07/26
     48 2023/07/27
      2 2023/07/28
      7 2023/07/29
      1 2023/08/01
     24 2023/08/03
      1 2023/08/05
      1 2023/08/07
     13 2023/08/08
      2 2023/08/09
      5 2023/08/10
     38 2023/08/11
     16 2023/08/13
     23 2023/08/14
     22 2023/08/18
     26 2023/09/22
      2 2023/09/24
      2 2023/10/01
     20 2023/10/22
      4 2023/11/08
      4 2023/11/12
      1 2023/11/27
      1 2023/12/01
      3 2023/12/04
      1 2023/12/16
      1 2023/12/17
      1 2023/12/24
      1 2023/12/30
     15 2024/01/07
      2 2024/01/30
     20 2024/02/21
     67 2024/02/26
     80 2024/02/27
      9 2024/03/02
     12 2024/03/05
      9 2024/03/07

it does not seem like the problem is with the tuner.

#8

Sounds like you should reach out to [email protected] to see if there are issues with your HDHomeRun.

#9

Let's wait what others find.

I also ran per hour stats to find times of day when it happens with per 10min break down
Here is the command

grep -a 'after no data was received for 6s$' channels-dvr.log | cut -c12-15 | sort | uniq -c

     12 01:0
      1 01:1
      5 01:2
     11 01:3
     12 01:4
     13 01:5
      7 02:0
      6 02:1
      5 02:2
      5 02:3
     12 02:4
      2 02:5
      3 03:0
      2 03:1
      1 03:2
      7 04:0
      7 04:1
     61 04:3
     66 04:4
     71 04:5
     68 05:0
     59 05:1
     69 05:2
     68 05:3
     49 05:4
     50 05:5
     74 06:0
     95 06:1
     64 06:2
     89 06:3
     66 06:4
     89 06:5
     14 07:0
      5 07:1
      5 07:2
     15 07:3
     17 07:4
     32 07:5
     48 08:0
     64 08:1
     47 08:2
     45 08:3
     18 08:4
     25 08:5
     28 09:0
     19 09:1
     15 09:2
     16 09:3
      7 09:4
      3 09:5
      1 10:0
      1 10:3
      1 10:5
      1 11:0
      6 11:1
      4 11:2
      3 11:3
      1 12:2
      1 12:5
      3 13:0
      2 13:2
      1 13:5
      1 15:4
      1 15:5
      1 16:0
      6 16:1
      1 16:2
      3 16:3
      1 16:5
      1 17:0
     10 17:2
      1 17:4
      1 17:5
      3 18:1
      1 19:1
      2 19:2
     13 20:0
      6 20:1
      6 20:2
      7 20:3
      5 20:4
      6 20:5
     26 21:0
      9 21:1
     14 21:2
     17 21:3
     13 21:4
     11 21:5
     17 22:0
      6 22:1
     25 22:2
     18 22:3
      5 22:4
      1 22:5
      1 23:0
      2 23:1
      4 23:2
      2 23:3
      2 23:5

There is a correlation between how busy the DVR is and the number of timeouts. Combined with the stats per day, where it does not occur every day .... it would be hard to pin it on the tuner.

1 Like
#10

Can somebody confirm. This only affects people with multiple HDHR devices? I suspect a bug in socket management closing a socket on a wrong tuner. Tracked separately in Sockets in close-wait state

#11

There are customers here that have been running half a dozen hdhomeruns for years without any such issue.

The problem is on the tuner side. The power supply for the hdhomerun is usually the first thing to fail.

#12

this produces false positives

$ grep -a -w 6s$ channels-dvr.log |cut -c-10|uniq -c
   1 2022/10/30
   1 2022/11/25
   1 2023/02/06
   1 2023/02/26
   1 2023/05/03
   3 2023/07/02
   1 2023/07/03
   1 2023/07/09
   1 2023/08/11
  10 2023/09/30
   1 2023/10/13
   1 2023/10/21
   1 2023/11/17
   2 2023/12/17
   1 2024/01/14
   1 2024/02/03
  11 2024/03/03


$ grep -a -w "for 6s" channels-dvr.log |cut -c-10|uniq -c
   1 2023/02/06
   1 2023/05/03
   1 2023/07/03
   1 2023/10/21
1 Like
#13

You are right.

$ diff <(grep -a -w 'for 6s' channels-dvr.log) <(grep -a -w 6s$ channels-dvr.log)

This does not amount to much in my case.

1615a1632
2023/11/01 17:00:09.183757 [IDX] Finished video index generation for file-24148 in 6s
1669a1687
2024/02/22 08:08:15.740543 [IDX] Finished video index generation for file-29417 in 6s
1729a1748
2024/02/26 22:34:08.202472 [IDX] Finished video index generation for file-29597 in 6s

#14

You are experiencing issues with your antenna. We can't do anything about that.

2024/03/07 05:10:25.791485 [TNR] Cancelling stream 10A12ADA/3 ch5.1 after no data was received for 6s
2024/03/07 05:10:25.867615 [SNR] Signal statistics for "TV/NBC 5 Today at 5AM/NBC 5 Today at 5AM 2024-03-07-0500.mpg": ss=71%,69%-76% snq=81%,0%-100% seq=96%,0%-100% bps=12825401,0-16476320 pps=1098,0-1411 sigerr=4%
2024/03/07 05:10:31.104467 [TNR] Cancelling stream 10A12ADA/2 ch8.8 after no data was received for 6s
2024/03/07 05:10:31.175980 [SNR] Signal statistics for "TV/News 8 Daybreak 500am/News 8 Daybreak 500am 2024-03-07-0500.mpg": ss=61%,60%-63% snq=75%,0%-92% seq=99%,0%-100% bps=7239599,0-12367392 pps=620,0-1059
2024/03/07 05:15:09.421078 [TNR] Cancelling stream 10A12ADA/3 ch8.8 after no data was received for 6s
2024/03/07 05:15:09.481441 [SNR] Signal statistics for "TV/News 8 Daybreak 500am/News 8 Daybreak 500am 2024-03-07-0500.mpg": ss=63%-64% snq=58%,0%-81% seq=84%,0%-100% bps=8459772,0-11385280 pps=724,0-975 sigerr=18%
2024/03/07 05:15:19.852297 [TNR] Cancelling stream 10A12ADA/2 ch5.1 after no data was received for 6s
2024/03/07 05:15:19.920185 [SNR] Signal statistics for "TV/NBC 5 Today at 5AM/NBC 5 Today at 5AM 2024-03-07-0500.mpg": ss=68%,66%-69% snq=56%,0%-75% seq=93%,0%-100% bps=12575499,0-15679200 pps=1076,0-1343 sigerr=6%
2024/03/07 05:18:31.563822 [TNR] Cancelling stream 10A12ADA/2 ch5.1 after no data was received for 6s
2024/03/07 05:18:31.631461 [SNR] Signal statistics for "TV/NBC 5 Today at 5AM/NBC 5 Today at 5AM 2024-03-07-0500.mpg": ss=67%,66%-69% snq=46%,0%-55% seq=76%,0%-100% bps=12189151,0-15983008 pps=1043,0-1369 sigerr=30%
2024/03/07 05:19:51.523380 [TNR] Cancelling stream 10A31D0C/2 ch5.1 after no data was received for 6s
2024/03/07 05:19:51.594615 [SNR] Signal statistics for "TV/NBC 5 Today at 5AM/NBC 5 Today at 5AM 2024-03-07-0500.mpg": ss=68%,66%-69% snq=42%,0%-49% seq=66%,0%-100% bps=11550380,0-15215968 pps=988,0-1303 sigerr=58%
2024/03/07 05:20:38.969476 [TNR] Cancelling stream 10A12ADA/2 ch5.1 after no data was received for 6s
2024/03/07 05:20:39.036176 [SNR] Signal statistics for "TV/NBC 5 Today at 5AM/NBC 5 Today at 5AM 2024-03-07-0500.mpg": ss=68% snq=11%,0%-44% seq=0% bps=4063808,0-8318624 pps=346,0-710 sigerr=100%

Talk to Silicon Dust if you want assistance on fixing this.

2 Likes
#15