DVR recordings are sometimes truncated, noisy, jumpy, and otherwise unplayable

Live TV & DVR
,
1

Sometimes my DVR recordings have problems when I try to playback. The problems range from noise, jumpiness, pixelation, and de-synced audio to flat out not playing back at all - sometimes from the beginning and sometimes partway through. This happens intermittently, but all of my recordings are for CBS (channel 9.1 in the Northern VA area). Sometimes the recording will be perfect, and sometimes it is unwatchable. Last night, it recorded 22 minutes and change of NCIS (just over 138MB, in HD) and 30 minutes of NCIS Hawaii (1.75GB, also in HD) - both shows should be 1 hour. Skipping through the video shows pixelation and audio cutout before the episode just ends. An episode of SEAL Team from a couple weeks ago seemed to be running at 1.5x speed but the audio wasn’t synced properly.

This happens on any player I try to play on, so it seems to be an issue with the recording itself rather than the player. I figured it was a problem with the antenna / tuner, but every time I pull up CBS in Live TV through Plex the signal comes in great. I don’t know what else to look for to even begin to troubleshoot.

I’m running Plex Media Server on my Win10 desktop, with the destination library on a NAS. I’ve set the DVR to mark commercials for skip but not to delete them. I’ve got an older i7-5820K and 32GB of RAM, which I think should be plenty for Plex. Chrome is the only other big thing running on the machine for the most part.

Server Version#: 1.24.5.5173
Player Version#: PlexWeb Version 4.63.0, though this occurs on other players as well
Tuner Make/Model: HDHomeRun CONNECT Quatro with a Mohu Leaf antenna
Guide/Lineup name:
Using XMLTV?:
Channel number/Name: CBS (9.1)

2

A couple shows exhibited problems again last night. I downloaded server logs, and this is what shows up at the beginning of one show (FBI). The recording only lasted about 2 minutes, but Plex shows the length of the file as almost 26.5 hours - but it’s only a tad over 100 MB. Is there anything in this log file which indicates what is going on?

Nov 09, 2021 20:00:00.867 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Subscription: No existing library item show ‘guid: plex://show/5fc6ac5b75bdc2002e9e4fb4 ratingKey: plex%3A%2F%2Fshow%2F5fc6ac5b75bdc2002e9e4fb4 thumb: https://metadata-static.plex.tv/a/gracenote/a6e221c7cae3fc63e61857b17f4916f9.jpg title: FBI type: 2 year: 2018’
Nov 09, 2021 20:00:00.868 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Starting operation for ‘FBI - E6 - Allegiance’ on channel 5fc76c77297361002dfabc36-5fc706004c4901002fec4380.
Nov 09, 2021 20:00:00.868 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Activity: registered new activity c2c3b178-8945-41c1-a311-ecc43dc0608f - “Recording”
Nov 09, 2021 20:00:00.869 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/1075B131 (Silicondust HDHomeRun CONNECT Quatro, supported) tuner 0.
Nov 09, 2021 20:00:00.869 [2396] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] HTTP requesting GET http://192.168.1.156:80/discover.json
Nov 09, 2021 20:00:00.873 [2396] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] HTTP/1.1 (0.0s) 200 response from GET http://192.168.1.156:80/discover.json
Nov 09, 2021 20:00:00.873 [2396] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] HTTP requesting GET http://192.168.1.156:80/lineup_status.json
Nov 09, 2021 20:00:00.874 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Subscription: No existing library item show ‘guid: plex://show/5fc6ac5b75bdc2002e9e4fb4 ratingKey: plex%3A%2F%2Fshow%2F5fc6ac5b75bdc2002e9e4fb4 thumb: https://metadata-static.plex.tv/a/gracenote/a6e221c7cae3fc63e61857b17f4916f9.jpg title: FBI type: 2 year: 2018’
Nov 09, 2021 20:00:00.875 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Grabber: checking for 8192 MB of available disk space in grab path and 100 MB in the transcode cache path
Nov 09, 2021 20:00:00.888 [2396] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] HTTP/1.1 (0.0s) 200 response from GET http://192.168.1.156:80/lineup_status.json
Nov 09, 2021 20:00:00.898 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Grabber: Saving recording to “M:\DVR.grab\50766bb4c1e6cece9cfdb946b6490552970aa8cd-fdd61eef7d6af2e5768e7de6f052911da4d06c55”
Nov 09, 2021 20:00:00.903 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] HTTP requesting GET http://192.168.1.156:80/lineup.json
Nov 09, 2021 20:00:00.908 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] HTTP/1.1 (0.0s) 200 response from GET http://192.168.1.156:80/lineup.json
Nov 09, 2021 20:00:00.908 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Grabber: Going to record for 3600 seconds, final URL is http://192.168.1.156:5004/auto/v9.1
Nov 09, 2021 20:00:00.909 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] MediaRecorderVirtual: setting stop time to 2021-11-09 21:00:00
Nov 09, 2021 20:00:00.909 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] DVR:Segmenter: Creating a new recorder for http://192.168.1.156:5004/auto/v9.1.
Nov 09, 2021 20:00:00.910 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Grabber: Waiting for a tuner on device://tv.plex.grabbers.hdhomerun/1075B131 (4 available) for at most 3600 seconds.
Nov 09, 2021 20:00:00.910 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Grabber: Allocated a tuner on device://tv.plex.grabbers.hdhomerun/1075B131 (3 left)
Nov 09, 2021 20:00:00.912 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] We’re going to try to auto-select an audio stream for account 1.
Nov 09, 2021 20:00:00.912 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Selecting best audio stream for part ID -1 (autoselect: 0 language: en)
Nov 09, 2021 20:00:00.912 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] We’re going to try to auto-select a subtitle.
Nov 09, 2021 20:00:00.912 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Audio Stream: -1, Subtitle Stream: -1
Nov 09, 2021 20:00:00.913 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] MDE: Selected protocol hls; container: mpegts
Nov 09, 2021 20:00:00.913 [6560] ERROR - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Unable to find title for item of type 5
Nov 09, 2021 20:00:00.913 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] MDE: analyzing media item -1
Nov 09, 2021 20:00:00.913 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] MDE: : no direct play video profile exists for http/mpegts/
Nov 09, 2021 20:00:00.913 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] MDE: : no direct play video profile exists for http/mpegts//
Nov 09, 2021 20:00:00.913 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] MDE: : codec is unavailable for analysis
Nov 09, 2021 20:00:00.913 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] MDE: : codec is unavailable for analysis
Nov 09, 2021 20:00:00.913 [6560] ERROR - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Unable to find title for item of type 5
Nov 09, 2021 20:00:00.913 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] MDE: : selected media 0 / -1
Nov 09, 2021 20:00:00.913 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Cleaning directory for session 58609eac-e1e4-42e3-8254-e89f64b9b31b ()
Nov 09, 2021 20:00:00.915 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Starting a transcode session 58609eac-e1e4-42e3-8254-e89f64b9b31b at offset -1.0 (state=3)
Nov 09, 2021 20:00:00.915 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Streaming Resource: Added session 0A052A60:58609eac-e1e4-42e3-8254-e89f64b9b31b
Nov 09, 2021 20:00:00.917 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd/JobRunner] Job running: set “FFMPEG_EXTERNAL_LIBS=\\?\C:\Users\Mark\AppData\Local\Plex\ Media\ Server\Codecs\be22e26-4019-windows-x86\” & set “X_PLEX_TOKEN=xxxxxxxxxxxxxxxxxxxx” & “C:\Program Files (x86)\Plex\Plex Media Server\Plex Transcoder.exe” -noaccurate_seek -ignore_unknown -scan_all_pmts -1 -rw_timeout 30000000 -reconnect 1 -reconnect_streamed 1 -reconnect_delay_max 30 -fflags +discardcorruptts+fillwallclockdts -probesize 20000000 -i http://192.168.1.156:5004/auto/v9.1 -map 0:V? -codec:V copy -map 0:a? -codec:a copy -map 0:s? -codec:s copy -break_non_keyframes 1 -segment_format mpegts -f ssegment -individual_header_trailer 0 -segment_time 1 -segment_start_number 0 -segment_time_delta 0.25 -segment_list http://127.0.0.1:32400/video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/manifest?X-Plex-Http-Pipeline=infinite -segment_list_type csv -segment_list_size 5 -segment_list_separate_stream_times 1 -segment_list_unfinished 1 -max_delay 5000000 -map_metadata -1 -map_chapters -1 media-%05d.ts -y -nostats -loglevel quiet -loglevel_plex error -xioerror -progressurl http://127.0.0.1:32400/video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress
Nov 09, 2021 20:00:00.922 [6560] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd/JobRunner] Jobs: Starting child process with pid 11632
Nov 09, 2021 20:00:01.036 [12516] DEBUG - Request: [127.0.0.1:55773 (Loopback)] PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress?status=startup (4 live) Signed-in Token (mandmmathis) (range: bytes=0-)
Nov 09, 2021 20:00:01.036 [14004] DEBUG - Completed: [127.0.0.1:55773] 204 PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress?status=startup (4 live) 0ms 203 bytes (pipelined: 1) (range: bytes=0-)
Nov 09, 2021 20:00:01.212 [15196] DEBUG - EPG[cloud]: Next thing to start/end is at 2021-11-10 01:15:00 GMT (in 900 seconds)
Nov 09, 2021 20:00:01.257 [12516] DEBUG - Request: [127.0.0.1:55773 (Loopback)] PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress?status=startup (4 live) Signed-in Token (mandmmathis) (range: bytes=0-)
Nov 09, 2021 20:00:01.257 [14004] DEBUG - Completed: [127.0.0.1:55773] 204 PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress?status=startup (4 live) 0ms 203 bytes (pipelined: 2) (range: bytes=0-)
Nov 09, 2021 20:00:01.257 [12516] DEBUG - Request: [127.0.0.1:55773 (Loopback)] PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress?status=opening (4 live) Signed-in Token (mandmmathis) (range: bytes=0-)
Nov 09, 2021 20:00:01.257 [14024] DEBUG - Completed: [127.0.0.1:55773] 204 PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress?status=opening (4 live) 0ms 203 bytes (pipelined: 3) (range: bytes=0-)
Nov 09, 2021 20:00:02.109 [12516] DEBUG - Request: [127.0.0.1:55773 (Loopback)] PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress?status=opened (4 live) Signed-in Token (mandmmathis) (range: bytes=0-)
Nov 09, 2021 20:00:02.109 [14024] DEBUG - Completed: [127.0.0.1:55773] 204 PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress?status=opened (4 live) 0ms 203 bytes (pipelined: 4) (range: bytes=0-)
Nov 09, 2021 20:00:02.109 [12516] DEBUG - Request: [127.0.0.1:55773 (Loopback)] PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress/stream?index=0&id=49&codec=mpeg2video&type=video (4 live) Signed-in Token (mandmmathis) (range: bytes=0-)
Nov 09, 2021 20:00:02.110 [14004] DEBUG - Completed: [127.0.0.1:55773] 200 PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress/stream?index=0&id=49&codec=mpeg2video&type=video (4 live) 0ms 195 bytes (pipelined: 5) (range: bytes=0-)
Nov 09, 2021 20:00:02.110 [12516] DEBUG - Request: [127.0.0.1:55773 (Loopback)] PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress/stream?index=1&id=52&codec=ac3&type=audio (4 live) Signed-in Token (mandmmathis) (range: bytes=0-)
Nov 09, 2021 20:00:02.111 [14004] DEBUG - Completed: [127.0.0.1:55773] 200 PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress/stream?index=1&id=52&codec=ac3&type=audio (4 live) 0ms 195 bytes (pipelined: 6) (range: bytes=0-)
Nov 09, 2021 20:00:02.111 [12516] DEBUG - Request: [127.0.0.1:55773 (Loopback)] PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress/stream?index=2&id=53&codec=ac3&type=audio (4 live) Signed-in Token (mandmmathis) (range: bytes=0-)
Nov 09, 2021 20:00:02.112 [14024] DEBUG - Completed: [127.0.0.1:55773] 200 PUT /video/:/transcode/session/58609eac-e1e4-42e3-8254-e89f64b9b31b/01fd8d62-a67a-4c2d-87fa-6a17baf8ac99/progress/stream?index=2&id=53&codec=ac3&type=audio (4 live) 0ms 195 bytes (pipelined: 7) (range: bytes=0-)
Nov 09, 2021 20:00:02.169 [12516] ERROR - [Transcoder] [mpeg2video @ 02b83d00] Invalid frame dimensions 0x0.
Nov 09, 2021 20:00:02.208 [12516] ERROR - [Transcoder] [mpeg2video @ 02b83d00] Invalid frame dimensions 0x0.
Nov 09, 2021 20:00:02.268 [12516] ERROR - [Transcoder] [mpeg2video @ 02b83d00] Invalid frame dimensions 0x0.

And then there’s a whole bunch more of those errors. There are also a few similar to

Nov 09, 2021 20:00:02.805 [12516] ERROR - [Transcoder] [mpeg2video @ 02b83d00] ignoring pic cod ext after 0

sprinkled in.

A few minutes later there are these entries:

Nov 09, 2021 20:02:07.936 [11380] DEBUG - [Transcode] Transcoder segment range: 0 - 240 (240)
Nov 09, 2021 20:02:07.938 [11380] DEBUG - [Transcode] Transcoder segment range: 0 - 241 (240)
Nov 09, 2021 20:02:09.067 [11380] DEBUG - [Transcode] Transcoder segment range: 0 - 241 (241)
Nov 09, 2021 20:02:09.083 [11380] DEBUG - [Transcode] Transcoder segment range: 0 - 242 (241)
Nov 09, 2021 20:02:09.223 [11380] DEBUG - [Transcode] Transcoder segment range: 0 - 242 (242)
Nov 09, 2021 20:02:09.238 [11380] DEBUG - [Transcode] Transcoder segment range: 0 - 243 (242)
Nov 09, 2021 20:02:09.254 [11380] DEBUG - [Live/58609eac-e1e4-42e3-8254-e89f64b9b31b/8c32d8ac-8eec-4f52-8719-44ee1766e2a8] buildLiveM3U8: min 0 max 242 ended 0
Nov 09, 2021 20:02:09.255 [11380] DEBUG - [Live/58609eac-e1e4-42e3-8254-e89f64b9b31b/8c32d8ac-8eec-4f52-8719-44ee1766e2a8] buildLiveM3U8: ended due to segment 95030.803167 past end time 2021-11-10 02:00:00.000000000 +0000
Nov 09, 2021 20:02:09.255 [11380] DEBUG - Request: [127.0.0.1:55789 (Loopback)] GET /livetv/sessions/58609eac-e1e4-42e3-8254-e89f64b9b31b/8c32d8ac-8eec-4f52-8719-44ee1766e2a8/00240.ts (13 live) Signed-in
Nov 09, 2021 20:02:09.256 [11380] DEBUG - Content-Length of C:\Users\Mark\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-58609eac-e1e4-42e3-8254-e89f64b9b31b\media-00240.ts is 1136272 (of total: 1136272).
Nov 09, 2021 20:02:09.259 [14004] DEBUG - Completed: [127.0.0.1:55789] 200 GET /livetv/sessions/58609eac-e1e4-42e3-8254-e89f64b9b31b/8c32d8ac-8eec-4f52-8719-44ee1766e2a8/00240.ts (13 live) 4ms 1136272 bytes (pipelined: 127)
Nov 09, 2021 20:02:09.259 [14004] DEBUG - Removed transcode data consumer, active count 241 => 241
Nov 09, 2021 20:02:09.301 [4440] DEBUG - Jobs: ‘C:\Program Files (x86)\Plex\Plex Media Server\Plex Transcoder.exe’ exit code for process 21688 is 0 (success)
Nov 09, 2021 20:02:09.302 [2396] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Recorder: No more consumers, stopping.
Nov 09, 2021 20:02:09.302 [2396] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Recorder: Asked to stop recording ‘FBI - E6 - Allegiance’ on channel 5fc76c77297361002dfabc36-5fc706004c4901002fec4380.
Nov 09, 2021 20:02:09.302 [2396] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Recorder: Stopping transcode session.
Nov 09, 2021 20:02:09.302 [2396] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Killing job.
Nov 09, 2021 20:02:09.302 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Recording for ‘FBI - E6 - Allegiance’ on channel 5fc76c77297361002dfabc36-5fc706004c4901002fec4380 stopped with status complete.
Nov 09, 2021 20:02:09.302 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Using recording status.
Nov 09, 2021 20:02:09.302 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Activity: updated activity c2c3b178-8945-41c1-a311-ecc43dc0608f - completed 100.0% - Recording
Nov 09, 2021 20:02:09.302 [8748] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Activity: updated activity 89d505dc-cbd2-4cca-8765-c5f31d7d23ab - completed 50.0% - Refreshing Sub
Nov 09, 2021 20:02:09.303 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Activity: updated activity c2c3b178-8945-41c1-a311-ecc43dc0608f - completed 100.0% - Recording
Nov 09, 2021 20:02:09.303 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [MI] Opening input file: “M:\DVR.grab\50766bb4c1e6cece9cfdb946b6490552970aa8cd-fdd61eef7d6af2e5768e7de6f052911da4d06c55\FBI (2018) - S04E06 - Allegiance.ts”
Nov 09, 2021 20:02:09.303 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - Opening ‘M:\DVR.grab\50766bb4c1e6cece9cfdb946b6490552970aa8cd-fdd61eef7d6af2e5768e7de6f052911da4d06c55\FBI (2018) - S04E06 - Allegiance.ts’ for reading
Nov 09, 2021 20:02:09.303 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - Setting default whitelist ‘file,crypto’
Nov 09, 2021 20:02:09.308 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - Format mpegts probed with size=2048 and score=50
Nov 09, 2021 20:02:09.308 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - stream=0 stream_type=2 pid=100 prog_reg_desc=
Nov 09, 2021 20:02:09.308 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - stream=1 stream_type=81 pid=101 prog_reg_desc=
Nov 09, 2021 20:02:09.308 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - stream=2 stream_type=81 pid=102 prog_reg_desc=
Nov 09, 2021 20:02:09.309 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - Before avformat_find_stream_info() pos: 0 bytes read:32768 seeks:0 nb_streams:3
Nov 09, 2021 20:02:09.309 [2396] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Job was already killed, not killing again.
Nov 09, 2021 20:02:09.309 [4440] DEBUG - Jobs: ‘C:\Program Files (x86)\Plex\Plex Media Server\Plex Transcoder.exe’ exit code for process 11632 is -1059143458 (intentional termination)
Nov 09, 2021 20:02:09.309 [2396] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Stopping transcode session 58609eac-e1e4-42e3-8254-e89f64b9b31b
Nov 09, 2021 20:02:09.309 [3400] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Cleaning directory for session 58609eac-e1e4-42e3-8254-e89f64b9b31b (C:\Users\Mark\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-58609eac-e1e4-42e3-8254-e89f64b9b31b)
…
Nov 09, 2021 20:02:09.347 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - invalid dts/pts combination 374018
Nov 09, 2021 20:02:09.347 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - Non-increasing DTS in stream 0: packet 158 with DTS 374017, packet 159 with DTS 371014
Nov 09, 2021 20:02:09.347 [7640] ERROR - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - Invalid frame dimensions 0x0.
Nov 09, 2021 20:02:09.347 [7640] ERROR - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - Invalid frame dimensions 0x0.
Nov 09, 2021 20:02:09.347 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - invalid dts/pts combination 377022
Nov 09, 2021 20:02:09.347 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - Non-increasing DTS in stream 0: packet 160 with DTS 377021, packet 161 with DTS 374018
Nov 09, 2021 20:02:09.347 [7640] ERROR - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - Invalid frame dimensions 0x0.
Nov 09, 2021 20:02:09.347 [7640] ERROR - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - ignoring pic cod ext after 0
Nov 09, 2021 20:02:09.347 [7640] ERROR - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - Invalid frame dimensions 0x0.
Nov 09, 2021 20:02:09.347 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - Format yuv420p chosen by get_format().
Nov 09, 2021 20:02:09.348 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - All info found
Nov 09, 2021 20:02:09.348 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - rfps: 60.000000 0.014371
Nov 09, 2021 20:02:09.348 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - rfps: 60.000000 0.014371
Nov 09, 2021 20:02:09.348 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - rfps: 59.940060 0.005681
Nov 09, 2021 20:02:09.366 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [FFMPEG] - After avformat_find_stream_info() pos: 0 bytes read:2478224 seeks:2 frames:370
Nov 09, 2021 20:02:09.367 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [MI] * [mpegts mpeg2video/ac3] Duration: 339731ms, 1920x1080 (1.777778) 29.970fps, bitrate=2593kbps, audio channels=6, optimizedForStreaming=0 (“M:\DVR.grab\50766bb4c1e6cece9cfdb946b6490552970aa8cd-fdd61eef7d6af2e5768e7de6f052911da4d06c55\FBI (2018) - S04E06 - Allegiance.ts”)
Nov 09, 2021 20:02:09.367 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [MI] Chapters had generic titles, clearing.
Nov 09, 2021 20:02:09.367 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] [MI] Closing input file: “M:\DVR.grab\50766bb4c1e6cece9cfdb946b6490552970aa8cd-fdd61eef7d6af2e5768e7de6f052911da4d06c55\FBI (2018) - S04E06 - Allegiance.ts”
Nov 09, 2021 20:02:09.367 [7640] DEBUG - [Grabber/50766bb4c1e6cece9cfdb946b6490552970aa8cd] Scheduling ‘FBI - E6 - Allegiance’ for assimilation.

3

@mandmmathis The i7-5820K doesn’t have any hardware transcoding, so what graphics card are you using for transcoding?

4

A GTX 970. I have the option in the DVR to convert video while recording set to Off rather than Transcode. Is there another setting I need to fiddle with? I don’t have problems playing media from my libraries, this is only with the DVR.

5

@mandmmathis I seem to remember that the GTX 970 has issues with transcoding, even a GT 1030 would be better. I usually have the transcoding while recording set to on as it does save disk space. Also I hope you aren’t trying to transcode straight from your NAS using 1gbe?

Quick note: Make sure you’ve got hardware transcoding enabled in your plex settings.

6

New video card isn’t possible right now unfortunately. I’m not too worried about disk space, as I only have 5-10 shows recording each week plus a ~6 TB NAS. I do record straight to the NAS (Synology 2-bay unit, with WD Red HDDs in it); I don’t even know what lgbe is, but if it’s running it is likely running straight from the NAS.

Looking at my Settings → Transcoder, I have the following options set: Transcoder quality is Automatic, Background preset is Very Fast, HDR tone mapping enabled, hardware-accelerated video encoding enabled. Are there other settings I should have enabled? Use hardware acceleration when available?

Some of these settings are probably leftover from when I was running an i3 and a Radeon 4840, which wasn’t able to keep up with real-time transcoding of Blu-Ray movies.

7

@mandmmathis The first problem is the fact you are transcoding straight to your NAS, that it your first bottleneck, the second bottleneck is the graphics card. The 1gbe is the speed at which your computer is connected to your NAS.

In regards to the transcoder settings

Background transcoding x264 preset Should be set to slow as possible
Use hardware acceleration when available Should be ticked
Use hardware-accelerated video encoding Should be ticked

8

Oh, I read that as El gbe, not One gbe…d’oh! Yes, the NAS is wired gigabit ethernet to the PMS machine. I’ll update those options and see what happens, as well as dig into saving the DVR streams to a local disk instead of hte NAS. Next recording isn’t until tomorrow evening…

9

@mandmmathis Hopefully it will work better, but I found the best way of testing is to create some test recordings, that way you don’t end up loosing out on more recordings that you actually want to watch.

10

Most of what you describe sounds like weak signal, with WUSA 9.1 being VHF the Mohu isn’t the best for reception. Plug your zip code into Antennaweb or Rabbitears.info to get your distance and direction to point the antenna.

Only a few clients direct play the mpeg2 streams from over the air. Do you regularly use Closed Captions? A browser will automatically cause a transcode for the audio and video. If your system has to transcode audio+video+subs then your looking at 3 concurrent live streams max based on your CPU. DVR recordings won’t be as limited unless you try to watch them at the same time. For troubleshooting, moving the storage location local will eliminate the NAS from possible issues.

If you want to watch your signal strength in real-time, start a live session then go to server settings > console and filter on “strength”. This should print out Signal Strength and Quality for the stream you are receiving.

If the logs you downloaded were from when the issue occurred you should upload the zip file by dragging and dropping on a reply so that they can be analyzed.

11

Antennaweb shows CBS is ~15 miles away to the NE, which should be well within the Mohu’s capabilities. I’ll play around with the antenna’s location a bit this weekend (it’s inside a west-facing window on the 2nd story now, which is not optimal given the signal direction). Filtering the Settings-> Console on “strength” doesn’t show any results when LiveTV is going. Full logs from a couple days ago are attached (two problematic recordings were from the 9th at 8pm and 9pm).

I don’t use CC, and normally watch via the Roku app. Most times I’m recording 1 show at a time, and maybe watching something from the DVR at the same time.

Plex Media Server Logs_2021-11-09_22-01-36.zip (6.4 MB)

12

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.