Server Version#: 1.21.3.4021
Player Version#: 4.52.1
Tuner Make/Model: HDHomeRun Quatro
Guide/Lineup name:
Using XMLTV?:
Channel number/Name:
I’ve been recording 10-20 shows per day and am getting 1-3 (seemingly) random partial recordings every day. I think I’ve narrowed it down to a “End of File” transcoding failure as shown below. However, I’m not sure why the Transcoder is being called during recording in the first place. Shouldn’t Plex DVR be capturing the raw stream in the .ts file? Why the need for transcoding?
Feb 11, 2021 20:30:00.791 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : no direct play video profile exists for hls/mpegts/mpeg2video
Feb 11, 2021 20:30:00.791 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : no direct play video profile exists for hls/mpegts/mpeg2video/ac3
Feb 11, 2021 20:30:00.791 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : no direct play video profile exists for hls/mpegts/mpeg2video/ac3
Feb 11, 2021 20:30:00.791 [6852] ERROR - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Unable to find title for item of type 5
Feb 11, 2021 20:30:00.884 [6476] ERROR - [Transcoder] http://127.0.0.1:32400/livetv/sessions/ba4c5fc9-af3a-48ab-9efa-82726f69d68c/134bb310-65dc-42e1-9881-aaa963c04e9a/index.m3u8?offset=1798.794902&X-Plex-Token=xxxxxxxxxxxxxxxxxxxx: End of file
Feb 11, 2021 20:30:00.887 [7784] DEBUG - Jobs: 'C:\Program Files (x86)\Plex\Plex Media Server\Plex Transcoder.exe' exit code for process 6128 is 1 (failure)
Here’s the full snip of the recording that fails:
Feb 11, 2021 20:30:00.768 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Starting operation for 'Superstore - E9 - Conspiracy' on channel 4.1.
Feb 11, 2021 20:30:00.768 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Activity: registered new activity 6a980e2b-39bd-4edf-9af0-b281520894a1 - Recording
Feb 11, 2021 20:30:00.768 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/10758467 (Silicondust HDHomeRun CONNECT QUATRO, supported) tuner 0.
Feb 11, 2021 20:30:00.769 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Subscription: Resolved subscription to library item 'Superstore' (19111)
Feb 11, 2021 20:30:00.769 [2012] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] HTTP requesting GET http://192.168.1.110:80/discover.json
Feb 11, 2021 20:30:00.773 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] There were 1 top-level paths for Superstore.
Feb 11, 2021 20:30:00.775 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] HTTP requesting GET http://192.168.1.110:80/lineup.json
Feb 11, 2021 20:30:00.776 [2012] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] HTTP 200 response from GET http://192.168.1.110:80/discover.json
Feb 11, 2021 20:30:00.776 [2012] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] HTTP requesting GET http://192.168.1.110:80/lineup_status.json
Feb 11, 2021 20:30:00.788 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] HTTP 200 response from GET http://192.168.1.110:80/lineup.json
Feb 11, 2021 20:30:00.789 [2012] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] HTTP 200 response from GET http://192.168.1.110:80/lineup_status.json
Feb 11, 2021 20:30:00.789 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Grabber: Going to record for 1800 seconds, final URL is http://192.168.1.110:5004/auto/v4.1
Feb 11, 2021 20:30:00.789 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MediaRecorderVirtual: setting stop time to 2021-02-11 21:00:00
Feb 11, 2021 20:30:00.789 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] DVR:Segmenter: Consumer for 'http://192.168.1.110:5004/auto/v4.1' successfully added to existing recorder 'ba4c5fc9-af3a-48ab-9efa-82726f69d68c'.
Feb 11, 2021 20:30:00.789 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] DVR:Segmenter: Stopping idle session: http://192.168.1.110:5004/auto/v7.1.
Feb 11, 2021 20:30:00.790 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] We're going to try to auto-select an audio stream for account 1.
Feb 11, 2021 20:30:00.790 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Selecting best audio stream for part ID -1 (autoselect: 1 language: en)
Feb 11, 2021 20:30:00.790 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] We're going to try to auto-select a subtitle.
Feb 11, 2021 20:30:00.790 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Subtitles: Found a candidate subtitle language [] for a foreign film
Feb 11, 2021 20:30:00.790 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Audio Stream: -1, Subtitle Stream: -1
Feb 11, 2021 20:30:00.791 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: Selected protocol http; container: mpegts
Feb 11, 2021 20:30:00.791 [6852] ERROR - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Unable to find title for item of type 5
Feb 11, 2021 20:30:00.791 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: analyzing media item -1
Feb 11, 2021 20:30:00.791 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : no direct play video profile exists for hls/mpegts/mpeg2video
Feb 11, 2021 20:30:00.791 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : no direct play video profile exists for hls/mpegts/mpeg2video/ac3
Feb 11, 2021 20:30:00.791 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : no direct play video profile exists for hls/mpegts/mpeg2video/ac3
Feb 11, 2021 20:30:00.791 [6852] ERROR - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Unable to find title for item of type 5
Feb 11, 2021 20:30:00.791 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : selected media 0 / -1
Feb 11, 2021 20:30:00.791 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Cleaning directory for session 134bb310-65dc-42e1-9881-aaa963c04e9a ()
Feb 11, 2021 20:30:00.791 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Starting a transcode session 134bb310-65dc-42e1-9881-aaa963c04e9a at offset -1.0 (state=3)
Feb 11, 2021 20:30:00.791 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Streaming Resource: Added session 0x55bcde8:134bb310-65dc-42e1-9881-aaa963c04e9a
Feb 11, 2021 20:30:00.793 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] TPU: hardware transcoding: enabled, but no hardware decode accelerator found
Feb 11, 2021 20:30:00.793 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] TPU: hardware transcoding: final decoder: , final encoder:
Feb 11, 2021 20:30:00.800 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Job running: set "FFMPEG_EXTERNAL_LIBS=\\\\?\\C\:\\Users\\lat-htpc\\AppData\\Local\\Plex\ Media\ Server\\Codecs\\367b3d4-3673-windows-x86\\" & set "X_PLEX_TOKEN=xxxxxxxxxxxxxxxxxxxx" & "C:\Program Files (x86)\Plex\Plex Media Server\Plex Transcoder.exe" -codec:0 mpeg2video -noaccurate_seek -live_start_index 0 -probesize 20000000 -i http://127.0.0.1:32400/livetv/sessions/ba4c5fc9-af3a-48ab-9efa-82726f69d68c/134bb310-65dc-42e1-9881-aaa963c04e9a/index.m3u8?offset=1798.794902&X-Plex-Token=xxxxxxxxxxxxxxxxxxxx -map 0:0 -codec:0 copy -map 0:1 -metadata:s:1 language=eng -codec:1 copy -map 0:2 -metadata:s:2 language=spa -codec:2 copy -f mpegts -map_metadata -1 -map_chapters -1 "E:\Recorded TV\.grab\b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069-ae2696be43c0098c5647d6d562e31c2ed6f3cfd6\Superstore (2015) - S06E09 - Conspiracy.ts" -y -nostats -loglevel quiet -loglevel_plex error -xioerror -progressurl http://127.0.0.1:32400/video/:/transcode/session/134bb310-65dc-42e1-9881-aaa963c04e9a/ef36853c-20a7-46a9-a9e7-b079843a0454/progress
Feb 11, 2021 20:30:00.806 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Jobs: Starting child process with pid 6128
Feb 11, 2021 20:30:00.884 [6476] ERROR - [Transcoder] http://127.0.0.1:32400/livetv/sessions/ba4c5fc9-af3a-48ab-9efa-82726f69d68c/134bb310-65dc-42e1-9881-aaa963c04e9a/index.m3u8?offset=1798.794902&X-Plex-Token=xxxxxxxxxxxxxxxxxxxx: End of file
Feb 11, 2021 20:30:00.887 [7784] DEBUG - Jobs: 'C:\Program Files (x86)\Plex\Plex Media Server\Plex Transcoder.exe' exit code for process 6128 is 1 (failure)
Feb 11, 2021 20:30:00.888 [6852] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] TranscodeSession: session failed while waiting for duration
Feb 11, 2021 20:30:00.888 [6852] ERROR - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Failed to start session.
Feb 11, 2021 20:30:00.888 [2012] DEBUG - Streaming Resource: Terminated session 0x55bcde8:134bb310-65dc-42e1-9881-aaa963c04e9a with reason Recording failed. Please check your tuner or antenna.
Feb 11, 2021 20:30:00.888 [3780] DEBUG - Killing job.
Feb 11, 2021 20:30:00.888 [6852] ERROR - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Recorder: Unable to create transcode session or session failed to start.
Feb 11, 2021 20:30:00.888 [3780] DEBUG - Job was already killed, not killing again.
And then Plex DVR records the last last 21 minutes successfully after the DVR Scheduler finds it again 9 minutes into the show:
Feb 11, 2021 20:38:49.352 [1828] DEBUG - Subscription: Resolved subscription to library item 'Superstore' (19111)
Feb 11, 2021 20:38:49.880 [1828] DEBUG - Subscription: No match in the library for 'Superstore - E9 - Conspiracy', grabbing.
Feb 11, 2021 20:38:56.433 [2768] DEBUG - DVR:NewSchedule: Between 2021-02-11 20:30:00 and 2021-02-11 21:00:00 on channel 4.1: 'Superstore - E9 - Conspiracy'
Feb 11, 2021 20:38:56.441 [2768] DEBUG - DVR:NewSchedule: Between 2021-02-11 20:30:00 and 2021-02-11 21:00:00 on channel 4.1: 'Superstore - E9 - Conspiracy'
Feb 11, 2021 20:38:56.975 [2768] DEBUG - DVR:NewSchedule: device 0 tuner 2 airing 0 between 2021-02-11 20:30:00 and 2021-02-11 21:00:00 on channel 4.1: 'Superstore - E9 - Conspiracy'
Feb 11, 2021 20:38:56.979 [2768] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Starting grab immediately for 'Superstore - E9 - Conspiracy' on channel 4.1 and we're 536 seconds in already.
Feb 11, 2021 20:38:56.980 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Subscription: Resolved subscription to library item 'Superstore' (19111)
Feb 11, 2021 20:38:56.984 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Starting operation for 'Superstore - E9 - Conspiracy' on channel 4.1.
Feb 11, 2021 20:38:56.984 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Activity: registered new activity 70d3faa1-a9b9-4acd-a1b2-6efab6394449 - Recording
Feb 11, 2021 20:38:56.984 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/10758467 (Silicondust HDHomeRun CONNECT QUATRO, supported) tuner 2.
Feb 11, 2021 20:38:56.988 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] There were 1 top-level paths for Superstore.
Feb 11, 2021 20:38:56.988 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Grabber: checking for 11068 MB of available disk space in grab path and 100 MB in the transcode cache path
Feb 11, 2021 20:38:56.990 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Grabber: Saving recording to "E:\Recorded TV\.grab\b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069-ae2696be43c0098c5647d6d562e31c2ed6f3cfd6"
Feb 11, 2021 20:38:57.004 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] DVR:Segmenter: Creating a new recorder for http://192.168.1.110:5004/auto/v4.1.
Feb 11, 2021 20:38:57.005 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Grabber: Waiting for a tuner on device://tv.plex.grabbers.hdhomerun/10758467 (3 available) for at most 1264 seconds.
Feb 11, 2021 20:38:57.005 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Grabber: Allocated a tuner on device://tv.plex.grabbers.hdhomerun/10758467 (2 left)
Feb 11, 2021 20:38:57.005 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] We're going to try to auto-select an audio stream for account 1.
Feb 11, 2021 20:38:57.005 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Selecting best audio stream for part ID -1 (autoselect: 1 language: en)
Feb 11, 2021 20:38:57.005 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] We're going to try to auto-select a subtitle.
Feb 11, 2021 20:38:57.005 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Subtitles: Found a candidate subtitle language [] for a foreign film
Feb 11, 2021 20:38:57.005 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Audio Stream: -1, Subtitle Stream: -1
Feb 11, 2021 20:38:57.006 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: Selected protocol hls; container: mpegts
Feb 11, 2021 20:38:57.006 [8212] ERROR - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Unable to find title for item of type 5
Feb 11, 2021 20:38:57.006 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: analyzing media item -1
Feb 11, 2021 20:38:57.006 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : no direct play video profile exists for http/mpegts/
Feb 11, 2021 20:38:57.006 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : no direct play video profile exists for http/mpegts//
Feb 11, 2021 20:38:57.006 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : selected subtitle stream has no codec
Feb 11, 2021 20:38:57.006 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : codec is unavailable for analysis
Feb 11, 2021 20:38:57.006 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : codec is unavailable for analysis
Feb 11, 2021 20:38:57.006 [8212] ERROR - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Unable to find title for item of type 5
Feb 11, 2021 20:38:57.006 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] MDE: : selected media 0 / -1
Feb 11, 2021 20:38:57.006 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Cleaning directory for session a69a210f-96b5-4d83-b75a-c40945af7e19 ()
Feb 11, 2021 20:38:57.007 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Starting a transcode session a69a210f-96b5-4d83-b75a-c40945af7e19 at offset -1.0 (state=3)
Feb 11, 2021 20:38:57.007 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Streaming Resource: Added session 0x56e53f0:a69a210f-96b5-4d83-b75a-c40945af7e19
Feb 11, 2021 20:38:57.007 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] TPU: hardware transcoding: enabled, but no hardware decode accelerator found
Feb 11, 2021 20:38:57.007 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] TPU: hardware transcoding: final decoder: , final encoder:
Feb 11, 2021 20:38:57.008 [8212] DEBUG - [Grabber/b486e1d71b12b91ebc72bc4f8c2e91c3a53c7069] Job running: set "FFMPEG_EXTERNAL_LIBS=\\\\?\\C\:\\Users\\lat-htpc\\AppData\\Local\\Plex\ Media\ Server\\Codecs\\367b3d4-3673-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.110:5004/auto/v4.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/a69a210f-96b5-4d83-b75a-c40945af7e19/529f4d05-5eb6-428b-8909-d5af35ddfeff/seglist?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/a69a210f-96b5-4d83-b75a-c40945af7e19/529f4d05-5eb6-428b-8909-d5af35ddfeff/progress
