Channels DVR v2022.08.26.2245 Silently Failing to Record

9bd3bb1a-71da-46f0-a258-e74dacaf211b

Submitted

Try new build

Looks fixed. Nice work. Thanks

2 Likes

Recording continues to work on v2022.08.27.0519, thanks for the super quick fix!

However, one recording from this morning is still marked as "Recording" even though it has finished (and I cleared it from the Schedule view), and the details show the index is "out of date." Playing it in the web player required remuxing at first, until I ran "Regenerate Video Index," after which it plays fine without remuxing.

In the logs, there is an "unexpected end of file" error. Another recording on the same channel overlapped with the end of this one.

2022/08/27 12:33:27.279735 [SNR] Buffer statistics for "Movies/X-Men First Class (2011) 2022-08-27-0929.mpg": buf=0% drop=0%
2022/08/27 12:33:27.360001 [MTS] Statistics for "Movies/X-Men First Class (2011) 2022-08-27-0929.mpg": skipped=0 unhandled_packets=0 discontinuity_detected=23 transport_errors=0 invalid_pts=0 invalid_dts=0 saw_pcr=true saw_pmt=true highest_pts=11024.341878
2022/08/27 12:33:27.369057 [DVR] Error running job 1661606990-161 X-Men: First Class (2011): unexpected EOF

Diagnostics: 1774b6e3-83c2-450f-be47-590098554eec

Seeing the same thing here. Recording completed but marked as failed.
Status in manage shows says it's still recording.

2022/08/27 12:58:00.005698 [DVR] Starting job 1661630280-107 Yellowstone on ch=[9368]
2022/08/27 12:58:03.227903 [TNR] Opened connection to M3U-Pluto for ch9368 More TV Drama
2022/08/27 12:58:03.228370 [DVR] Recording for job 1661630280-107 from M3U-Pluto ch9368 into "TV/Yellowstone/Yellowstone S02E201 2019-06-19 A Thundering 2022-08-27-1258.mpg" for 1h3m59.993986533s
2022/08/27 12:58:03.962331 [IDX] Generating video index for job 1661630280-107
2022/08/27 14:02:15.003158 [SNR] Buffer statistics for "TV/Yellowstone/Yellowstone S02E201 2019-06-19 A Thundering 2022-08-27-1258.mpg": buf=0% drop=0%
2022/08/27 14:02:15.109602 [MTS] Statistics for "TV/Yellowstone/Yellowstone S02E201 2019-06-19 A Thundering 2022-08-27-1258.mpg": skipped=0 unhandled_packets=0 discontinuity_detected=32 transport_errors=0 invalid_pts=0 invalid_dts=0 saw_pcr=true saw_pmt=true highest_pts=3876.726667
2022/08/27 14:02:15.149002 [ADS] Detected 14 commercial markers in file-998: TV/Yellowstone/Yellowstone S02E201 2019-06-19 A Thundering 2022-08-27-1258.mpg
2022/08/27 14:02:15.278564 [DVR] Error running job 1661630280-107 Yellowstone: unexpected EOF

Logs have been submitted as 9ebd8e76-8777-4bdf-a9f6-33b48db9bdfb

Thanks for the reports. Checking them out.

2 Likes

Another DVR server same issue.

2022/08/27 15:30:01.000615 [DVR] Starting job 1661639401-ch6085 Canary SUNDANCE Recording on ch=[6085]
2022/08/27 15:30:02.961121 [TNR] Opened connection to TVE-Comcast_SSO for ch6085 SUNDANCE
2022/08/27 15:30:02.961404 [DVR] Recording for job 1661639401-ch6085 from TVE-Comcast_SSO ch6085 into "TV/Canary SUNDANCE Recording/Canary SUNDANCE Recording 2022-08-27-1530.mpg" for 9m59.999216775s
2022/08/27 15:30:03.297211 [IDX] Generating video index for job 1661639401-ch6085
2022/08/27 15:40:13.510335 [SNR] Buffer statistics for "TV/Canary SUNDANCE Recording/Canary SUNDANCE Recording 2022-08-27-1530.mpg": buf=0% drop=0%
2022/08/27 15:40:13.513387 [TNR] Closed connection to TVE-Comcast_SSO for ch6085 SUNDANCE
2022/08/27 15:40:13.740989 [MTS] Statistics for "TV/Canary SUNDANCE Recording/Canary SUNDANCE Recording 2022-08-27-1530.mpg": skipped=0 unhandled_packets=0 discontinuity_detected=0 transport_errors=0 invalid_pts=0 invalid_dts=0 saw_pcr=true saw_pmt=true highest_pts=627.492000
2022/08/27 15:40:13.744767 [DVR] Error running job 1661639401-ch6085 Canary SUNDANCE Recording: unexpected EOF

Logs have been submitted as df7190e6-f4dc-4bb3-ad58-65096201f25a

@chDVRuser Could you upload the recording.log for 998 to the dropbox?

Uploaded as 998-recording.log

Let's see if this helps out:

Fingers crossed :crossed_fingers:
My last recording before I updated ended strangely with the error Could not fetch playlist after the connection was closed.

2022/08/27 18:02:15.039200 [SNR] Buffer statistics for "TV/Yellowstone/Yellowstone S02E205 2019-07-24 Touching Your Enemy 2022-08-27-1658.mpg": buf=0% drop=0%
2022/08/27 18:02:15.046448 [TNR] Closed connection to M3U-Pluto for ch9368 More TV Drama
2022/08/27 18:02:15.308379 [MTS] Statistics for "TV/Yellowstone/Yellowstone S02E205 2019-07-24 Touching Your Enemy 2022-08-27-1658.mpg": skipped=0 unhandled_packets=0 discontinuity_detected=25 transport_errors=0 invalid_pts=0 invalid_dts=0 saw_pcr=true saw_pmt=true highest_pts=3876.954667
2022/08/27 18:02:15.381711 [ADS] Detected 12 commercial markers in file-1002: TV/Yellowstone/Yellowstone S02E205 2019-07-24 Touching Your Enemy 2022-08-27-1658.mpg
2022/08/27 18:02:15.521799 [DVR] Error running job 1661644680-107 Yellowstone: Could not fetch playlist: https://service-stitcher-ipv4.clusters.pluto.tv/stitch/hls/channel/613260e4bdb71c00070d63fa/3063648/playlist.m3u8?terminate=false&embedPartner=&serverSideAds=true&paln=&includeExtendedEvents=false&architecture=&deviceId=8d620d78-2642-11ed-994d-0242ac120004&deviceVersion=unknown&appVersion=unknown&deviceType=web&deviceMake=Chrome&sid=4c2a7f7f-1624-4bc1-a1d5-3b1fa8603bb6&advertisingId=&deviceLat=0&deviceLon=0&deviceDNT=0&deviceModel=web&userId=&appName=web: Get "https://service-stitcher-ipv4.clusters.pluto.tv/stitch/hls/channel/613260e4bdb71c00070d63fa/3063648/playlist.m3u8?terminate=false&embedPartner=&serverSideAds=true&paln=&includeExtendedEvents=false&architecture=&deviceId=8d620d78-2642-11ed-994d-0242ac120004&deviceVersion=unknown&appVersion=unknown&deviceType=web&deviceMake=Chrome&sid=4c2a7f7f-1624-4bc1-a1d5-3b1fa8603bb6&advertisingId=&deviceLat=0&deviceLon=0&deviceDNT=0&deviceModel=web&userId=&appName=web": context canceled

Any way to fix these completed recordings that still show recording?
I've updated to the new prerelease, tried refreshing metadata and regenerate video index on them.
Screenshot 2022-08-27 at 18-24-42 Channels Manage Recordings
Screenshot 2022-08-27 at 18-25-02 Channels Manage Recordings

These are recordings that were recording before the DVR restart? That's very unusual — we'll have to dig into how that could have happened.

First one shown is the one I reported here

Second one is this

Sorry, that last pre-release v2022.08.27.2357 didn't have the fix it intended to. The next one going out shortly will have it.

1 Like

Updated, but these are still showing as recording

Can you check the json for one of those. Does it say Completed:true?

Is it marked recording in /dvr/programs

Neither recording is marked "Completed": true or "Processed": true
Neither one appears in /dvr/programs

Because of all the issues starting with the crash, I have 2 marked interrupted (only one was), two marked delayed and these two marked recording still. The only recording with an issue is one of them marked as interrupted.

I could add them to /dvr/programs using curl, but not sure that would help

curl -XPUT 'http://192.168.1.3:8189/dvr/programs/pluto%2F5ec3040273354c001aa4e437%2FS1E201/recorded/998'
curl -XPUT 'http://192.168.1.3:8189/dvr/programs/pluto%2F5ec3040273354c001aa4e437%2FS2E205/recorded/1002'

UPDATE: added those using curl and it did nothing to help.

Don't want to jinx myself, but since updating to 2022.08.28.0235 last night and 2022.08.28.0324 this morning, I've had 7 successful recordings so far.

2 Likes

:+1:
22 recordings since updating to 2022.08.28.0235 last night across 4 servers and no issues.

1 Like