Since the Bruins began pre-season games, every one of them is reporting "Interrupted". The last two are interrupted after 1hr2min exactly. All of them interrupted at (exactly?) 8pm EDT.
Diagnostics: 996698ad-f343-496d-a634-d090ce4b38fd
Are y'all seeing anything that might be the cause (and maybe something I can fix on this end?)
Thanks!
This exact same thing happened again today with tonight's Bruins game. I have not seen it with anything else.
Any thoughts?
2023/10/02 19:58:59.264819 [SNR] Buffer statistics for "TV/NHL Hockey/NHL Hockey Boston Bruins at Philadel 2023-10-02-1857.mpg": buf=0%-100% drop=0.05%
Seeing the buffer go to 100% indicates you were having issues with the drive being written to fast enough.
2023/10/02 19:58:59.677643 [DVR] Starting job 1696287420-1 NHL Hockey on ch=[6163]
2023/10/02 19:58:59.677698 [DVR] Waiting 22h58m0.322304878s until next job 1696373820-1 NHL Hockey
2023/10/02 19:59:00.297800 [ERR] Failed to start stream on channel 6163 via TVE-Fubo: TVE: Stream Not Available
2023/10/02 19:59:00.736658 [ERR] Failed to start stream on channel 6163 via TVE-ATTOTT: TVE: Stream Not Available
2023/10/02 19:59:00.736707 [DVR] Error running job 1696287420-1 NHL Hockey: could not start stream on channels=[6163]: TVE: Stream Not Available
This indicates the TVE stream wasn't available at that time.
THANK YOU!
Interesting. Seems NESN is "breaking" the stream at 8pm for some reason? Is that a fair interpretation of the data here?
And also...
Given that this is happening at exactly the same time... do we really think it's the drive? Or is that just the buffer getting upset because the stream stopped?
Thanks again!
And... if my assumptions/interpretations are correct, is there a way to tell Channels to re-try the stream, say, 60 seconds later? Or 300 seconds later?
I think this is a (recurring) temporary interruption, because if I go to the stream now, it shows up fine in Channels, but I have no way of telling Channels 'resume recording'.
Most kinds of errors are automatically retried, but this is one that means that we don't expect future tunes to succeed, so we don't retry unnecessary strain on the servers.
That makes sense. With this, in particular, is there a way to tell Channels, "no... trust me... it's coming back. Please try again."
It would be great to have this happen automatically (even with a declining frequency... every minute for 5 minutes, every 5 minutes for the next thirty, etc). But even if it has to happen manually, it would be nice to be able to say, "no... I literally just streamed it and it's working. Would you please retry?" 
Ok.. More data. I submitted logs 52481620-4391-46f6-ba67-cbb51a02db78 just now.
Tonight I decided to try something different. I let it record the Bruins game, as it usually would. I also told it to record the show after the Bruins game, "Bruins Overtime Live" and I set that to record 90 minutes early, meaning it should start at 8:00pm. I was, of course, expecting the Bruins game to fail at 7:59pm like all previous ones had.
And sure enough, the Bruins game stopped at 7:59pm:
2023/10/03 19:58:59.395619 [SNR] Buffer statistics for "TV/NHL Hockey/NHL Hockey Washington Capitals at Bo 2023-10-03-1857.mpg": buf=0% drop=0%
2023/10/03 19:58:59.414244 [SNR] Streaming statistics for "TV/NHL Hockey/NHL Hockey Washington Capitals at Bo 2023-10-03-1857.mpg": timeouts=0 segment_timeouts=0 playlist_timeouts=0
2023/10/03 19:58:59.662091 [MTS] Statistics for "TV/NHL Hockey/NHL Hockey Washington Capitals at Bo 2023-10-03-1857.mpg": discontinuity_detected=0 transport_errors=0 saw_pcr=true saw_pmt=true highest_pts=3721.634589
2023/10/03 19:59:00.036750 [ADS] Detected 2 commercial markers in file-5165: TV/NHL Hockey/NHL Hockey Washington Capitals at Bo 2023-10-03-1857.mpg
2023/10/03 19:59:00.240061 [TNR] Closed connection to TVE-Fubo for ch6163 NESN
2023/10/03 19:59:00.240107 [DVR] Job 1696373820-1 NHL Hockey ended prematurely: 3h0m59.759901414s
And then there was a lot of this as it retried a bit:
2023/10/03 19:59:00.340935 [DVR] Starting job 1696373820-1 NHL Hockey on ch=[6163]
2023/10/03 19:59:01.872437 [ERR] Failed to start stream on channel 6163 via TVE-Fubo: TVE: Stream Not Available
2023/10/03 19:59:04.214985 [ERR] Failed to start stream on channel 6163 via TVE-ATTOTT: TVE: Could not fetch playlist: : Get "": unsupported protocol scheme ""
2023/10/03 19:59:04.215028 [DVR] Error running job 1696373820-1 NHL Hockey: could not start stream on channels=[6163]: TVE: Could not fetch playlist: : Get "": unsupported protocol scheme ""
Interestingly, at 8pm, the start of the next show failed on that same channel, too:
2023/10/03 20:00:00.000526 [DVR] Starting job 1696377600-ch6163 Bruins Overtime Live on ch=[6163]
2023/10/03 20:00:00.288548 [ERR] Failed to start stream on channel 6163 via TVE-Fubo: TVE: Stream Not Available
2023/10/03 20:00:00.561464 [ERR] Failed to start stream on channel 6163 via TVE-ATTOTT: TVE: Could not fetch playlist: : Get "": unsupported protocol scheme ""
2023/10/03 20:00:00.561496 [DVR] Error running job 1696377600-ch6163 Bruins Overtime Live: could not start stream on channels=[6163]: TVE: Could not fetch playlist: : Get "": unsupported protocol scheme ""
But then, ten seconds later, it opened up... telling us that NESN, channel 6163, was down for 71 seconds, give or take:
2023/10/03 20:00:10.891074 [DVR] Starting job 1696377600-ch6163 Bruins Overtime Live on ch=[6163]
2023/10/03 20:00:11.183705 [TVE] stream timestamps: nesn: start_at=2023-10-03T20:00:00-04:00 end_at=2023-10-03T20:00:06-04:00 live_delay=3.14270146s
2023/10/03 20:00:11.183780 [TNR] Opened connection to TVE-Fubo for ch6163 NESN
2023/10/03 20:00:11.183896 [DVR] Recording for job 1696377600-ch6163 from TVE-Fubo ch6163 into "TV/Bruins Overtime Live/Bruins Overtime Live 2023-10-03-2000.mpg" for 2h29m49.108845418s
And then an interesting thing happened:
2023/10/03 20:00:11.764825 [DVR] Starting job 1696373820-1 NHL Hockey on ch=[6163]
2023/10/03 20:00:11.764988 [TNR] Sharing existing connection to TVE-Fubo for ch6163 NESN (clients=2, len=0)
2023/10/03 20:00:11.765037 [DVR] Recording for job 1696373820-1 from TVE-Fubo ch6163 into "TV/NHL Hockey/NHL Hockey Washington Capitals at Bo 2023-10-03-1857.mpg" for 2h59m48.235114934s
It seems like Channels also resumed the "actual" recording of the Bruins game, albeit with the one minute gap in there.
What I'm not sure of is whether it would have done this anyway, or if it only did it because there was a connection to share.
Thoughts?
And thanks!
I've made an improvement to the error codes when we get back this confusing response from NESN. I doubt it will give a better result in what you can record, but it should give more understandable error messages.
Could you update to the latest pre-release?
Sure thing! I'm currently on 2023.10.06.2303, which it reports as the latest.
The next Bruins game on NESN is Friday, the 13th, but I've queued up a recording tonight to test and see if this 8pm ET hiccup happens during non-Bruins shows. The show I'm recording tonight starts at 7:30pm and is only a 30-minute broadcast, but I set it to go 90-minutes extra, just to give it time to get past the (potential) 8pm glitch.
I'll report back here once I see the hiccup again. Thanks so much for your assistance!
Ok, tonight's test yielded the same thing: interrupted recording at 7:59pm local time. Logs submitted as ca90bdb1-9092-470b-9a13-48ba8fa2970b. Hopefully that helps begin to decipher things?
I've looked when this happened in the past, and indeed, the TVE stream for NESN is simply offline for ~70 seconds. I don't think there's any way to "force" it to retrieve a stream that's temporarily offline. And, assuming that's right, I'd just like to see it try again, knowing that this is a recurring issue (with that channel's TVE stream).
Okay, I've tried to make a change in the latest build that hopefully cause these errors to be retried for nesn.
Great! And thanks.
I've got another test queued up for that time slot on Monday. I'll report back once it has transpired.
Ok. It seems your new retry logic worked. Diags: 1be6e154-7082-4902-a6f5-8804ec6a76cc
The relevant parts:
2023/10/09 19:30:00.000890 [DVR] Starting job 1696894200-ch6163 Papi & Pedro Onstage on ch=[6163]
2023/10/09 19:30:05.835580 [TVE] stream timestamps: nesn: start_at=2023-10-09T19:30:15-04:00 end_at=2023-10-09T19:30:23-04:00 live_delay=9s
2023/10/09 19:30:05.835721 [TNR] Opened connection to TVE-Fubo for ch6163 NESN
2023/10/09 19:30:05.835905 [DVR] Recording for job 1696894200-ch6163 from TVE-Fubo ch6163 into "TV/Papi & Pedro Onstage/Papi & Pedro Onstage 2020-02-06 2023-10-09-1930.mpg" for 59m59.999030514s
2023/10/09 19:30:06.832101 [DVR] Refreshing metadata for Papi & Pedro Onstage (17913073)
2023/10/09 19:30:07.411817 [IDX] Generating video index for job 1696894200-ch6163
2023/10/09 19:59:00.022627 [SNR] Buffer statistics for "TV/Papi & Pedro Onstage/Papi & Pedro Onstage 2020-02-06 2023-10-09-1930.mpg": buf=0% drop=0%
2023/10/09 19:59:00.098108 [SNR] Streaming statistics for "TV/Papi & Pedro Onstage/Papi & Pedro Onstage 2020-02-06 2023-10-09-1930.mpg": timeouts=0 segment_timeouts=0 playlist_timeouts=0
2023/10/09 19:59:00.695092 [MTS] Statistics for "TV/Papi & Pedro Onstage/Papi & Pedro Onstage 2020-02-06 2023-10-09-1930.mpg": discontinuity_detected=0 transport_errors=0 saw_pcr=true saw_pmt=true highest_pts=1739.154089
2023/10/09 19:59:01.117834 [ADS] Detected 2 commercial markers in file-5178: TV/Papi & Pedro Onstage/Papi & Pedro Onstage 2020-02-06 2023-10-09-1930.mpg
2023/10/09 19:59:01.800406 [TNR] Closed connection to TVE-Fubo for ch6163 NESN
2023/10/09 19:59:01.945308 [DVR] Job 1696894200-ch6163 Papi & Pedro Onstage ended prematurely: 30m58.054701577s
2023/10/09 19:59:03.144565 [DVR] Starting job 1696894200-ch6163 Papi & Pedro Onstage on ch=[6163]
2023/10/09 19:59:04.786469 [ERR] Failed to start stream on channel 6163 via TVE-Fubo: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:05.775728 [ERR] Failed to start stream on channel 6163 via TVE-ATTOTT: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:05.775775 [DVR] Error running job 1696894200-ch6163 Papi & Pedro Onstage: could not start stream on channels=[6163]: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:07.373723 [DVR] Starting job 1696894200-ch6163 Papi & Pedro Onstage on ch=[6163]
2023/10/09 19:59:07.531881 [ERR] Failed to start stream on channel 6163 via TVE-Fubo: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:07.942020 [ERR] Failed to start stream on channel 6163 via TVE-ATTOTT: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:07.942051 [DVR] Error running job 1696894200-ch6163 Papi & Pedro Onstage: could not start stream on channels=[6163]: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:10.792036 [DVR] Starting job 1696894200-ch6163 Papi & Pedro Onstage on ch=[6163]
2023/10/09 19:59:10.972430 [ERR] Failed to start stream on channel 6163 via TVE-Fubo: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:11.771004 [ERR] Failed to start stream on channel 6163 via TVE-ATTOTT: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:11.771034 [DVR] Error running job 1696894200-ch6163 Papi & Pedro Onstage: could not start stream on channels=[6163]: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:17.257333 [DVR] Starting job 1696894200-ch6163 Papi & Pedro Onstage on ch=[6163]
2023/10/09 19:59:17.455981 [ERR] Failed to start stream on channel 6163 via TVE-Fubo: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:17.807769 [ERR] Failed to start stream on channel 6163 via TVE-ATTOTT: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:17.807805 [DVR] Error running job 1696894200-ch6163 Papi & Pedro Onstage: could not start stream on channels=[6163]: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:27.399941 [DVR] Starting job 1696894200-ch6163 Papi & Pedro Onstage on ch=[6163]
2023/10/09 19:59:27.901229 [ERR] Failed to start stream on channel 6163 via TVE-Fubo: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:28.222176 [ERR] Failed to start stream on channel 6163 via TVE-ATTOTT: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:28.222206 [DVR] Error running job 1696894200-ch6163 Papi & Pedro Onstage: could not start stream on channels=[6163]: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:44.454749 [DVR] Starting job 1696894200-ch6163 Papi & Pedro Onstage on ch=[6163]
2023/10/09 19:59:44.693947 [ERR] Failed to start stream on channel 6163 via TVE-Fubo: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:44.876061 [ERR] Failed to start stream on channel 6163 via TVE-ATTOTT: TVE: Stream Temporarily Unavailable
2023/10/09 19:59:44.876097 [DVR] Error running job 1696894200-ch6163 Papi & Pedro Onstage: could not start stream on channels=[6163]: TVE: Stream Temporarily Unavailable
2023/10/09 20:00:17.038991 [DVR] Starting job 1696894200-ch6163 Papi & Pedro Onstage on ch=[6163]
2023/10/09 20:00:17.300916 [TVE] stream timestamps: nesn: start_at=2023-10-09T20:02:03-04:00 end_at=2023-10-09T20:02:11-04:00 live_delay=9s
2023/10/09 20:00:17.301112 [TNR] Opened connection to TVE-Fubo for ch6163 NESN
2023/10/09 20:00:17.301195 [DVR] Recording for job 1696894200-ch6163 from TVE-Fubo ch6163 into "TV/Papi & Pedro Onstage/Papi & Pedro Onstage 2020-02-06 2023-10-09-1930.mpg" for 29m42.960912419s
2023/10/09 20:30:09.120433 [TNR] Closed connection to TVE-Fubo for ch6163 NESN
2023/10/09 20:30:10.364540 [SNR] Buffer statistics for "TV/Papi & Pedro Onstage/Papi & Pedro Onstage 2020-02-06 2023-10-09-1930.mpg": buf=0% drop=0%
2023/10/09 20:30:10.364585 [SNR] Streaming statistics for "TV/Papi & Pedro Onstage/Papi & Pedro Onstage 2020-02-06 2023-10-09-1930.mpg": timeouts=0 segment_timeouts=0 playlist_timeouts=0
2023/10/09 20:30:11.577759 [MTS] Statistics for "TV/Papi & Pedro Onstage/Papi & Pedro Onstage 2020-02-06 2023-10-09-1930.mpg": discontinuity_detected=0 transport_errors=0 saw_pcr=true saw_pmt=true highest_pts=3614.818400
2023/10/09 20:30:11.588599 [DVR] Finished job 1696894200-ch6163 Papi & Pedro Onstage
I'm going to set up a test tomorrow with (basically) the same thing on NESN and also NESN+ (just in case the latter is also affected). I'll keep you posted here, of course!
One thing I noticed. I played the recording back, just to see what happened at the inflection point (it just plays through, and jumps to the newly recorded part, no problem).
But the Status screen seems to get confused. I get this in the ~29 minutes leading up to the inflection point:
And then after the point, it just shows 0s forever:
To be clear: the client appears quite happy and so this isn't really an "issue" per se, but I figured I'd report it for you regardless.
Alright. NESN did fine (again), as expected.
And NESNPlus failed in the same way, and obviously channels isn't set to remedy that. I submitted logs 18e9e586-8382-4079-b298-8335bf9d8578.
But it's a clone of what we've seen with NESN, so I think the simple solution is to add NESNPLUS (ch6172) to the same logic, assuming that's doable?
As always, thank you!!
Testing NESNPlus with latest beta release. Will report back. DVR Pre-Release Notes - #1121 by fancybot
Confirming that NESNPlus now works with the retry just fine. Marking this answered/solved. Thank you!!
This is still an issue now. 7:59-8. Stream goes completely down, every single night like clockwork. The only channel we have these issues with.
Yep. It’s been happening all season. Clearly a NESN streaming issue.
But the fix/adjustment they made to Channels works around it, thankfully! 
