Stream error during commercial break TVE

[johnluber]

@tmm1

I’m not trying to say you haven’t tried to fix this. To be honest though I’m not aware of a half dozen attempts to fix; maybe that’s a part of my frustration with this. I update every day or so so I’ve got any fixes you tried. Let us know when a new attempt is in beta.

That said, I’ve been running 2143 for the past hour or so and so far so good. Longest I‘ve seen in the past has been about two hours without the error. One thing interesting I’ve seen tonight is we’re seeing more “real” commercials along with the PSA commercials.

Please don’t take my frustration as criticism. At least not as unconstructive criticism. We love your app and really enjoy using it and want it to succeed. If your making changes to help this problem then it would help if you let us know so that we understand that it is being worked on.

I remain 100% committed to this app and will always provide feedback and be willing to test any fix.

[chDVRuser]

Just wanted to add my 2 cents to the discussion, for what it's worth with inflation and all.

I don't watch or record either of these two "problem" TVE channels, although I did record a couple previously to help troubleshoot here

From what I've seen this only happens going into a commercial break or a commercial segment, correct?

If that's true they may be using targeted advertising and switching to another server/stream for the commercials.

Maybe based on demographics of the user (provider used to login to TVE/browser agent headers/zipcode/ip address, etc). And don't forget how Google gets their revenue.

Would it not be helpful if someone experiencing the issue used tuner sharing and while watching the live feed, they also recorded it?

That way you get log info from both the live viewing and the recording.

If it would help, I could do that, but I won't be watching the live stream, just running it in the background with the volume muted.

As long as the DVR web UI doing the live viewing logs the disconnect, I think it would be more data points.

Are there specific shows/times of day/etc. that are more likely to see the issue?

[johnluber]

FWIW, and fingers crossed, we’ve been watching for almost 3 hours and haven’t seen the issue. Probably premature to say it’s fixed but it does look good as of now.

[chDVRuser]

If you still have issues with the new version I can setup a test tomorrow.
Just let me know what shows/times to stream live and record. My TVE NAS is not busy tonight or tomorrow, so would be willing to help out by testing.

[chDVRuser]

Started early with v2019.09.15.0041 at 20:47:36 as I didn't see any responses.

Watching (in the background) two channels 6073(FNC) and 6074(FBN) via Channels DVR web UI while recording both those channels for 5+ hours (300 minute end-padding).

Apparently Lou Dobbs Tonight on ch6074(FBN) loses the battle to Watters' World on ch6073(FNC) tonight.

Not anything in the log after;

2019/09/14 21:52:33 [ERR] Error during stream TVE-Comcast_SSO ch6074 FBN: Failed to download file: https://foxvdms.akamaized.net/auso/slices/d73/4f59ea65df184a2580ad8fc80d3eaa32/d7319c379cec434198f1e1fbfcc9f33c/H00000004.ts?pbs=6452022af2604ced8eb5a818acaebd07&_jt=l&chid=0889265100704d178922db41fa6b6b91&oid=5b6fd7c6528d417e8bdad7f79754bb9e&si=65: 503 Service Unavailable
    Last message repeated 1 times

Other than it repeating trying to download again to the end with this message repeated...

2019/09/14 21:52:33 [MTS] Statistics for "TV/Lou Dobbs Tonight/Lou Dobbs Tonight 2003-06-16 2019-09-14-2051.mpg": skipped=8 unhandled_packets=0 discontinuity_detected=69 transport_errors=0 invalid_pts=0 invalid_dts=0 saw_pcr=false saw_pmt=true highest_pts=3750.198778
2019/09/14 21:52:33 [DVR] Job 1568516400-ch6074 Lou Dobbs Tonight ended prematurely: 4h7m26.037939258s
2019/09/14 21:52:34 [DVR] Starting job 1568516400-ch6074 Lou Dobbs Tonight on ch=[6074]
2019/09/14 21:52:34 [TNR] Sharing existing connection to TVE-Comcast_SSO for ch6074 FBN (clients=2, len=0)
2019/09/14 21:52:34 [DVR] Recording for job 1568516400-ch6074 from TVE-Comcast_SSO ch6074 into "TV/Lou Dobbs Tonight/Lou Dobbs Tonight 2003-06-16 2019-09-14-2051.mpg" for 4h7m25.926415771s

6073(FNC) is still displaying live tv, where 6074(FBN) is still frozen in the display showing this

Let me know if you want any logs before I delete the test recordings tomorrow night.

[chDVRuser]

Just knew I forgot to do something. Like get up at 2am to stop the live streams!

Although Lou Dobbs Tonight on FBN quit playing live 1 hour and 55 secs after I started to stream it, Watters' World on FNC was still streaming this morning almost 12 hrs after I started it.

The DVR log is large (984KB) and filled with disconnect errors (503 Service Unavailable) for Lou Dobbs Tonight on FBN.
about 20 of these repeated in the log

2019/09/14 21:53:41 [DVR] Starting job 1568516400-ch6074 Lou Dobbs Tonight on ch=[6074]
2019/09/14 21:53:42 [TNR] Opened connection to TVE-Comcast_SSO for ch6074 FBN
2019/09/14 21:53:42 [DVR] Recording for job 1568516400-ch6074 from TVE-Comcast_SSO ch6074 into "TV/Lou Dobbs Tonight/Lou Dobbs Tonight 2003-06-16 2019-09-14-2051.mpg" for 4h6m18.778760592s
2019/09/14 22:28:22 [ERR] Error during stream TVE-Comcast_SSO ch6074 FBN: Failed to download file: https://foxvdms.akamaized.net/ause/slices/040/5b6fd7c6528d417e8bdad7f79754bb9e/0406378abd5f4aa28229870832e622fb/H00000113.ts?pbs=3a913357639d4bbbb682527e7151657f&_jt=l&chid=0889265100704d178922db41fa6b6b91&si=9: 503 Service Unavailable
2019/09/14 22:28:22 [MTS] Statistics for "TV/Lou Dobbs Tonight/Lou Dobbs Tonight 2003-06-16 2019-09-14-2051.mpg": skipped=0 unhandled_packets=0 discontinuity_detected=40 transport_errors=0 invalid_pts=0 invalid_dts=0 saw_pcr=false saw_pmt=true highest_pts=8883.144844
2019/09/14 22:28:22 [TNR] Closed connection to TVE-Comcast_SSO for ch6074 FBN
2019/09/14 22:28:22 [DVR] Job 1568516400-ch6074 Lou Dobbs Tonight ended prematurely: 3h31m37.553568118s

Although no errors in the DVR log for Watters' World on FNC, there are 453 of the (503 Service Unavailable) errors in its recording log.

Both recordings finished.
Watters' World 05:08:34 duration, 12.5GB
Lou Dobbs Tonight 05:58:06 duration, 12.2GB

Let me know if you want me to email any logs to support and if so, which ones.

The recording log for Lou Dobbs Tonight http://127.0.0.1:8089/dvr/files/1573/log is 775MB
and contains 4,098 lines like this;

at=2019-09-14T20:52:01.065560562-07:00 tag="fbn" action="fetch" url="https://foxvdms.akamaized.net/ause/slices/e50/5b6fd7c6528d417e8bdad7f79754bb9e/e5076de44b204edea5b49253f46ef586/H00000218.ts?pbs=6452022af2604ced8eb5a818acaebd07&_jt=l&chid=0889265100704d178922db41fa6b6b91&si=2" content_length=175 failed="temporary" failed_while="requesting" status_code=503 status="503 Service Unavailable" body_time="101.937µs" time="93.084571ms" status="segmentTemporarilyFailed" 

[johnluber]

Ran FNC FOR 6 hours this morning with no issues. Looks promising.

[chDVRuser]

Appears the akamai CDN servers are unable to keep up with the Fox networks TVE streaming demand?
503 Service Unavailable - The server cannot handle the request (because it is overloaded or down for maintenance). Generally, this is a temporary state.

[johnluber]

FYI, I've only seen one occurrence of this issue since installing v2019.09.14.2143. Not sure if it's just a coincidence or a regression but it happened today after installing v2019.09.17.0401

2019/09/17 11:43:58 [ERR] Error during stream TVE-sony_auth-gateway_net ch6073 FNC: Failed to download file: https://x-live-fox-stgec.uplynk.com/ausc/slices/afd/4f59ea65df184a2580ad8fc80d3eaa32/afd76bf662454d8b870fd07499a57c8f/H0000000F.ts?pbs=ff0877e8335d43f79c8c0de450251fca&_jt=l&chid=1e298c9d65a245b3bd37f339cadcca58&oid=5b6fd7c6528d417e8bdad7f79754bb9e&si=38: 403 Forbidden

[scooter_scott]

I'm thinking that this has something to do with the commercials that are being played from the FNC stream. That's just me though. I've tried paying attention to see if it happens only after a certain commercial but I keep getting distracted

[johnluber]

I've thought the same and I've tried to track to see if it happens on the same commercial. Unfortunately, I have trouble remembering which it is as well. To be honest, with over 100 occurrences in the last month I think I'd remember by now if it is a particular commercial so I kind of doubt that it is.

The one common behavior I've recognized is that the stream pauses for 2-3 seconds before before reverting to the timeline. But, I don't think that tells a whole lot as it's probably just the player encountering the 403.

The really odd thing is that it's been a couple of days with no occurrences and then today it happened again.

[chDVRuser]

My suggestion is this whole topic be moved to Channels DVR TV Everywhere
With a thread Fox Networks (and whatever the issue is).

These type of issues appear to be specific to a TVE Network (ex:Fox), not a specific TVE channel.
The Network (ex:Fox) uses a CDN (Content Delivery Network) Provider to stream their content to you.
It doesn't matter who your TV provider is that you login with.

FNC and FBN and other Fox Network channels appear to be having issues.

Would assume they are overloaded with streams and their akamai CDN servers are having issues, not a Channels TVE DVR issue.

Anyone else having issues with Fox Network channels (I don't know as I don't watch or record any of them)?

[uclavic]

I'm on the latest update and was testing out Fox New Channel. It just locked up 3 minutes to 6pm PDT. The lock up occurred right at the end of a Susan G Komen ad. Don't know if that helps.

[chDVRuser]

Sounds like the devs are on it.

Let me know if you want me to email any logs to support and if so, which ones.

Deleted my recordings and logs as posted since no requests for them since my post on 9/15

[johnluber]

Here's an occurrence from last night. If it helps any it happened at the end of the YMCA commercial.

2019/09/17 21:50:08 [ERR] Error during stream TVE-sony_auth-gateway_net ch6073 FNC: Failed to download file: https://x-live-fox-stgec.uplynk.com/ausc/slices/afd/4f59ea65df184a2580ad8fc80d3eaa32/afd76bf662454d8b870fd07499a57c8f/H0000000F.ts?pbs=b01c03073ba344a7a0b8ecd2a6aed2dc&_jt=l&chid=1e298c9d65a245b3bd37f339cadcca58&oid=5b6fd7c6528d417e8bdad7f79754bb9e&si=28: 403 Forbidden

[tmm1]

Are you still seeing better ads than before?

The new errors seem to be from a different host name which is a good sign. Are they still happening less often? Is there a pattern to how long after you start streaming when the error occurs?

[uclavic]

I can corroborate that the YMCA ad will cause a lock up as will the Susan G Komen ad. I guess it's dependent on when you start watching and when they play the add as you can go an hour or 2 without an issue. I haven't paid attention to whether or not the system stays up after one of those 2 ads has played or if it happens every time they are played. I'll try to pay attention to that. Here's the log from around lunch today. I had to leave the office so I decided to start the stream and see how long it would last.

2019/09/18 11:30:00 [TNR] Opened connection to TVE-DTV for ch6073 FNC
2019/09/18 11:30:01 [HLS] Probed live stream in 687.084204ms: h264 1280x720 progressive 6233043bps
2019/09/18 11:30:01 [HLS] Starting transcoder for channel 6073 from 69.75.161.146 (encoder=h264_videotoolbox, resolution=720, deinterlacer=blend, bitrate=4000)
[h264_videotoolbox @ 0x7ffc96821400] Color range not set for yuv420p. Using MPEG range.
2019/09/18 11:30:13 [HLS] Stopping inactive session ch6051-dANY-07aedeb83a52 @ 2h44m57.528867s
[h264 @ 0x7f974382ce00] error while decoding MB 55 66, bytestream -6
2019/09/18 11:30:13 [TNR] Closed connection to TVE-DTV for ch6051 CNBC
[aac @ 0x7ffc9688f000] env_facs_q 252 is invalid
2019/09/18 11:38:15 [NAT] Successfully mapped port 8089 using natpmp
[aac @ 0x7ffc9688f000] env_facs_q 255 is invalid
2019/09/18 12:17:22 [ERR] Error during stream TVE-DTV ch6073 FNC: Failed to download file: https://x-live-fox-stgec.uplynk.com/ausc/slices/afd/4f59ea65df184a2580ad8fc80d3eaa32/afd76bf662454d8b870fd07499a57c8f/H0000000F.ts?pbs=3f7e125750f842fca4cc4ec07e4a5e5e&_jt=l&chid=1e298c9d65a245b3bd37f339cadcca58&oid=5b6fd7c6528d417e8bdad7f79754bb9e&si=33: 403 Forbidden
Last message repeated 2 times
2019/09/18 12:17:27 [HLS] Stopping transcoder session ch6073-dANY-07aedeb83a52 @ 47m10.439833s
2019/09/18 12:17:27 [TNR] Closed connection to TVE-DTV for ch6073 FNC

[johnluber]

@tmm1

I am still receiving regular commercials and the error does seem to happen less often than before. I think it’s happened 3 times in the last 2 days vs 3-4 before.

The ads for YMCA and Komen run fine most of the time so it’s inconsistent at best for me.

No pattern to the failure either. I did try to correlate my logs to those posted but could not find consistent failures with the limited data set.

Thanks for continuing to try to solve this.

[MadMax74]

I'm getting the same error on FS1 and Investigation Discovery. On ID it happens after every commercial and sometimes FS1 won't even open. Any solution? This just started happening after I upgraded to version 2020.03.10.1810

2020/03/13 10:53:44.846598 [TVE] stream timestamps: fs1: start_at=2020-03-13T10:53:43-05:00 current_at=2020-03-13T10:54:10-05:00 end_at=2020-03-13T10:54:13-05:00
2020/03/13 10:53:44.846684 [TNR] Opened connection to TVE-Fubo for ch6197 FS1
2020/03/13 10:54:00.923729 [TNR] Sharing existing connection to TVE-Fubo for ch6197 FS1 (clients=2, len=0)
2020/03/13 10:54:11.400496 [ERR] Error during stream TVE-Fubo ch6197 FS1: Failed to download file: https://x-live-fox-stgec.uplynk.com/ausw/slices/4c7/4f59ea65df184a2580ad8fc80d3eaa32/4c7689b197764322a2ea0b14a1f501fd/A0000000D.ts?pbs=52caf236d96c4e848650659ec3ea6d2f&_jt=l&chid=ab9513294ec74cc8affeeb95acd413ce&oid=06b4a36349624051a9ba52ac3a91d268&si=0: 403 Forbidden
2020/03/13 10:54:11.407152 [TNR] Closed connection to TVE-Fubo for ch6197 FS1
2020/03/13 10:54:15.806159 [TVE] stream timestamps: fs1: start_at=2020-03-13T10:54:15-05:00 current_at=2020-03-13T10:54:42-05:00 end_at=2020-03-13T10:54:45-05:00
2020/03/13 10:54:15.806215 [TNR] Opened connection to TVE-Fubo for ch6197 FS1
2020/03/13 10:54:34.044258 [TNR] Sharing existing connection to TVE-Fubo for ch6197 FS1 (clients=2, len=0)
2020/03/13 10:54:38.965430 [ERR] Error during stream TVE-Fubo ch6197 FS1: Failed to download file: https://x-live-fox-stgec.uplynk.com/ausw/slices/4c7/4f59ea65df184a2580ad8fc80d3eaa32/4c7689b197764322a2ea0b14a1f501fd/A00000000.ts?pbs=52caf236d96c4e848650659ec3ea6d2f&_jt=l&chid=ab9513294ec74cc8affeeb95acd413ce&oid=06b4a36349624051a9ba52ac3a91d268&si=2: 403 Forbidden
2020/03/13 10:54:38.967156 [TNR] Closed connection to TVE-Fubo for ch6197 FS1
2020/03/13 10:55:47.554212 [TVE] stream timestamps: hallmark: start_at=2020-03-13T10:55:11-05:00 current_at=2020-03-13T10:55:59-05:00 end_at=2020-03-13T10:56:07-05:00
2020/03/13 10:55:47.554267 [TNR] Opened connection to TVE-Fubo for ch6090 HALLMARK
2020/03/13 10:56:00.118240 [TVE] stream timestamps: investigation-discovery: start_at=2020-03-13T10:55:59-05:00 current_at=2020-03-13T10:56:20-05:00 end_at=2020-03-13T10:56:28-05:00
2020/03/13 10:56:00.118293 [TNR] Opened connection to TVE-Fubo for ch6107 INVESTIGATION-DISCOVERY
2020/03/13 10:56:00.122927 [TNR] Closed connection to TVE-Fubo for ch6090 HALLMARK
2020/03/13 11:37:34.210808 [ERR] Error during stream TVE-Fubo ch6107 INVESTIGATION-DISCOVERY: Failed to download file: https://x-default-stgec.uplynk.com/ausw/slices/ca2/4f59ea65df184a2580ad8fc80d3eaa32/ca26ad93241b4295b174d788e68c8b77/A00000000.ts?pbs=f5107e4a876744a8ae12b3ec3cd05235&_jt=l&chid=a6fe2dd55b3149a6a59154a93e348012&oid=e6cf0c55dac249f0a0f72e7c72e6f6cb&si=14: 403 Forbidden
2020/03/13 11:37:34.216224 [TNR] Closed connection to TVE-Fubo for ch6107 INVESTIGATION-DISCOVERY