DVR Recordings stops after 24 seconds

themaacks · August 28, 2019, 5:42am

I’ve been trying to work through issues with all my recordings stoping early. Mostly I’ve had shows stop recording after 20-40 minutes but here’s an example that stops after only 24 seconds. I notice there is a lot of (basically nonstop) chatter in the logs about EPG updates. Is it possible the scheduler is just getting confused and intentionally stopping recordings?

Plex Media Server Logs_2019-08-27_21-58-22.zip (2.4 MB)

Here’s a small relevant excerpt from the Logs

Server Version#: 1.16.5.1488
Player Version#:

Aug 27, 2019 19:00:00.288 [0x80c968100] DEBUG - DVR:Grabber: Starting operation for 'Bachelor in Paradise - E8 - Episode 604b' on channel 15.1.
Aug 27, 2019 19:00:00.288 [0x80c968100] DEBUG - Activity: registered new activity 2ad7818b-525a-4dfb-8e96-8b4f7df4200e - Recording
Aug 27, 2019 19:00:00.288 [0x80c968100] DEBUG - DVR:Grabber: Remote starting a media grab on device device://tv.plex.grabbers.tunerservice/dvb%23hdhr%2310385F9A (Silicondust HDHomeRun DUAL, supported) tuner 1.
Aug 27, 2019 19:00:00.288 [0x80c5a2700] DEBUG - HTTP requesting GET http://127.0.0.1:32600/devices/dvb%23hdhr%230%23272129946
Aug 27, 2019 19:00:00.289 [0x80c968100] DEBUG - DVR:Subscription: Resolved subscription to library item 'Bachelor in Paradise' (501)
Aug 27, 2019 19:00:00.289 [0x80c968100] DEBUG - There were 1 top-level paths for Bachelor in Paradise.
Aug 27, 2019 19:00:00.290 [0x80c968100] DEBUG - DVR:Grabber: checking for 16384 MB of available disk space in grab path and transcode cache path
Aug 27, 2019 19:00:00.290 [0x80c968100] DEBUG - DVR:Grabber: Saving recording to "/mnt/shows/.grab/336e2fc20fd72af4ad258de65d1647f85e6e8863"
Aug 27, 2019 19:00:00.291 [0x80c968100] DEBUG - DVR:Grabber: Going to record for 7200 seconds, final URL is http://127.0.0.1:32600/devices/dvb%23hdhr%231%23272129946/media/triplet%3A%2F%2F0%3A195%3A1?param=%3C%3Fxml%20version%3D%221%2E0%22%20encoding%3D%22UTF-8%22%3F%3E%0A%3Ctunedata%3E%3Ctt%3E8%3C%2Ftt%3E%3Cdq%3E0%3C%2Fdq%3E%3Cfr%3E15%3C%2Ffr%3E%3Cmd%3E0%3C%2Fmd%3E%3Csr%3E0%3C%2Fsr%3E%3Cpl%3E0%3C%2Fpl%3E%3Clf%3E0%3C%2Flf%3E%3Cl1%3E0%3C%2Fl1%3E%3Cl2%3E0%3C%2Fl2%3E%3Cls%3E0%3C%2Fls%3E%3Cpp%3E0%3C%2Fpp%3E%3Chz%3E0%3C%2Fhz%3E%3Cin%3E0%3C%2Fin%3E%3Cfc%3E0%3C%2Ffc%3E%3Ct%3E195%3C%2Ft%3E%3Cn%3E0%3C%2Fn%3E%3Cs%3E1%3C%2Fs%3E%3Cen%3E0%3C%2Fen%3E%3C%2Ftunedata%3E%0A
Aug 27, 2019 19:00:00.291 [0x80c968100] DEBUG - MediaRecorderVirtual: setting stop time to 2019-08-27 21:00:00
Aug 27, 2019 19:00:00.292 [0x80c968100] DEBUG - DVR:Segmenter: Creating a new recorder for http://127.0.0.1:32600/devices/dvb%23hdhr%231%23272129946/media/triplet%3A%2F%2F0%3A195%3A1?param=%3C%3Fxml%20version%3D%221%2E0%22%20encoding%3D%22UTF-8%22%3F%3E%0A%3Ctunedata%3E%3Ctt%3E8%3C%2Ftt%3E%3Cdq%3E0%3C%2Fdq%3E%3Cfr%3E15%3C%2Ffr%3E%3Cmd%3E0%3C%2Fmd%3E%3Csr%3E0%3C%2Fsr%3E%3Cpl%3E0%3C%2Fpl%3E%3Clf%3E0%3C%2Flf%3E%3Cl1%3E0%3C%2Fl1%3E%3Cl2%3E0%3C%2Fl2%3E%3Cls%3E0%3C%2Fls%3E%3Cpp%3E0%3C%2Fpp%3E%3Chz%3E0%3C%2Fhz%3E%3Cin%3E0%3C%2Fin%3E%3Cfc%3E0%3C%2Ffc%3E%3Ct%3E195%3C%2Ft%3E%3Cn%3E0%3C%2Fn%3E%3Cs%3E1%3C%2Fs%3E%3Cen%3E0%3C%2Fen%3E%3C%2Ftunedata%3E%0A.
Aug 27, 2019 19:00:00.292 [0x80c968100] DEBUG - DVR:Grabber: Waiting for a tuner on device://tv.plex.grabbers.tunerservice/dvb%23hdhr%2310385F9A (2 available) for at most 7200 seconds.
Aug 27, 2019 19:00:00.292 [0x80c968100] DEBUG - DVR:Grabber: Allocated a tuner on device://tv.plex.grabbers.tunerservice/dvb%23hdhr%2310385F9A (1 left)
Aug 27, 2019 19:00:00.292 [0x80c968100] DEBUG - We're going to try to auto-select an audio stream for account 1.
Aug 27, 2019 19:00:00.292 [0x80c968100] DEBUG - Selecting best audio stream for part ID -1 (autoselect: 0 language: en)
Aug 27, 2019 19:00:00.292 [0x80c968100] DEBUG - Audio Stream: -1, Subtitle Stream: -1
Aug 27, 2019 19:00:00.296 [0x80c968100] DEBUG - MDE: Selected protocol hls; container: mpegts
Aug 27, 2019 19:00:00.296 [0x80c968100] ERROR - Unable to find title for item of type 5
Aug 27, 2019 19:00:00.296 [0x80c968100] DEBUG - MDE: analyzing media item -1
Aug 27, 2019 19:00:00.296 [0x80c968100] DEBUG - MDE: : no direct play video profile exists for http/mpegts/
Aug 27, 2019 19:00:00.296 [0x80c968100] DEBUG - MDE: : no direct play video profile exists for http/mpegts//
Aug 27, 2019 19:00:00.296 [0x80c968100] DEBUG - MDE: : codec is unavailable for analysis
Aug 27, 2019 19:00:00.296 [0x80c968100] DEBUG - MDE: : codec is unavailable for analysis
Aug 27, 2019 19:00:00.296 [0x80c968100] ERROR - Unable to find title for item of type 5
Aug 27, 2019 19:00:00.296 [0x80c968100] DEBUG - MDE: : selected media 0 / -1
Aug 27, 2019 19:00:00.296 [0x80c968100] DEBUG - Cleaning directory for session cd227a94-1279-4efd-9af4-807699553eec ()
Aug 27, 2019 19:00:00.296 [0x80c968100] DEBUG - Starting a transcode session cd227a94-1279-4efd-9af4-807699553eec at offset -1.0 (state=3)
Aug 27, 2019 19:00:00.296 [0x80c968100] DEBUG - Streaming Resource: Added session 0x80cd6d3e0:cd227a94-1279-4efd-9af4-807699553eec
Aug 27, 2019 19:00:00.297 [0x80c968100] DEBUG - Job running: EAE_ROOT='/tmp/pms-a72d0860-c7d3-47d7-b3ce-dacd4682f90a/EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='/usr/local/plexdata-plexpass/Plex\ Media\ Server/Codecs/dd95667-2434-freebsd-x86_64/' XDG_CACHE_HOME='/usr/local/plexdata-plexpass/Plex Media Server/Cache' XDG_DATA_HOME='/usr/local/share/plexmediaserver-plexpass/Resources' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' '/usr/local/share/plexmediaserver-plexpass/Plex Transcoder' '-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://127.0.0.1:32600/devices/dvb%23hdhr%231%23272129946/media/triplet%3A%2F%2F0%3A195%3A1?param=%3C%3Fxml%20version%3D%221%2E0%22%20encoding%3D%22UTF-8%22%3F%3E%0A%3Ctunedata%3E%3Ctt%3E8%3C%2Ftt%3E%3Cdq%3E0%3C%2Fdq%3E%3Cfr%3E15%3C%2Ffr%3E%3Cmd%3E0%3C%2Fmd%3E%3Csr%3E0%3C%2Fsr%3E%3Cpl%3E0%3C%2Fpl%3E%3Clf%3E0%3C%2Flf%3E%3Cl1%3E0%3C%2Fl1%3E%3Cl2%3E0%3C%2Fl2%3E%3Cls%3E0%3C%2Fls%3E%3Cpp%3E0%3C%2Fpp%3E%3Chz%3E0%3C%2Fhz%3E%3Cin%3E0%3C%2Fin%3E%3Cfc%3E0%3C%2Ffc%3E%3Ct%3E195%3C%2Ft%3E%3Cn%3E0%3C%2Fn%3E%3Cs%3E1%3C%2Fs%3E%3Cen%3E0%3C%2Fen%3E%3C%2Ftunedata%3E%0A' '-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/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/seglist' '-segment_list_type' 'csv' '-segment_list_size' '2147483647' '-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/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress'
Aug 27, 2019 19:00:00.297 [0x80c968100] DEBUG - Jobs: Starting child process with pid 99772
Aug 27, 2019 19:00:00.305 [0x80c968600] DEBUG - Request: [127.0.0.1:53397 (Loopback)] PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress?status=startup (4 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:00.305 [0x80c59ff00] DEBUG - Completed: [127.0.0.1:53397] 204 PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress?status=startup (4 live) 0ms 203 bytes (pipelined: 1) (range: bytes=0-) 
Aug 27, 2019 19:00:00.306 [0x80deebf00] DEBUG - Request: [127.0.0.1:53397 (Loopback)] PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress?status=opening (4 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:00.306 [0x80c59fa00] DEBUG - Completed: [127.0.0.1:53397] 204 PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress?status=opening (4 live) 0ms 203 bytes (pipelined: 2) (range: bytes=0-) 
Aug 27, 2019 19:00:00.712 [0x80c5a2700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32600/devices/dvb%23hdhr%230%23272129946
Aug 27, 2019 19:00:01.237 [0x80c59ff00] DEBUG - Auth: authenticated user 1 as themaacks
Aug 27, 2019 19:00:01.237 [0x80c968600] DEBUG - Request: [192.168.1.92:64162 (Subnet)] GET /statistics/bandwidth?timespan=6 (4 live) TLS GZIP Signed-in Token (themaacks)
Aug 27, 2019 19:00:01.239 [0x80c59ff00] DEBUG - Completed: [192.168.1.92:64162] 200 GET /statistics/bandwidth?timespan=6 (4 live) TLS GZIP 2ms 1660 bytes (pipelined: 686)
Aug 27, 2019 19:00:01.400 [0x80c67cd00] DEBUG - EPG[cloud]: Next thing to start/end is at 2019-08-28 02:30:00 GMT (in 1800 seconds)
Aug 27, 2019 19:00:02.249 [0x80c59ff00] DEBUG - Auth: authenticated user 1 as themaacks
Aug 27, 2019 19:00:02.249 [0x80deebf00] DEBUG - Request: [192.168.1.92:64162 (Subnet)] GET /statistics/bandwidth?timespan=6 (4 live) TLS GZIP Signed-in Token (themaacks)
Aug 27, 2019 19:00:02.251 [0x80c59ff00] DEBUG - Completed: [192.168.1.92:64162] 200 GET /statistics/bandwidth?timespan=6 (4 live) TLS GZIP 2ms 1670 bytes (pipelined: 687)
Aug 27, 2019 19:00:03.261 [0x80c59fa00] DEBUG - Auth: authenticated user 1 as themaacks
Aug 27, 2019 19:00:03.262 [0x80deebf00] DEBUG - Request: [192.168.1.92:64162 (Subnet)] GET /statistics/bandwidth?timespan=6 (4 live) TLS GZIP Signed-in Token (themaacks)
Aug 27, 2019 19:00:03.264 [0x80c59fa00] DEBUG - Completed: [192.168.1.92:64162] 200 GET /statistics/bandwidth?timespan=6 (4 live) TLS GZIP 2ms 1676 bytes (pipelined: 688)
Aug 27, 2019 19:00:03.563 [0x80c968600] DEBUG - Request: [127.0.0.1:53397 (Loopback)] PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress?status=opened (4 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:03.563 [0x80c59ff00] DEBUG - Completed: [127.0.0.1:53397] 204 PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress?status=opened (4 live) 0ms 203 bytes (pipelined: 3) (range: bytes=0-) 
Aug 27, 2019 19:00:03.716 [0x80c67cd00] DEBUG - HTTP requesting GET http://127.0.0.1:32600/devices/dvb%23hdhr%230%23272129946
Aug 27, 2019 19:00:03.805 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.805 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.806 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.806 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.806 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.806 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.807 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.807 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.807 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.807 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.808 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.808 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.808 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.838 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.838 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.839 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.871 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.871 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.872 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.872 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.904 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.904 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.936 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.937 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.970 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:03.970 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.003 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.003 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.004 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.036 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.060 [0x80d842f00] DEBUG - Statistics: Flushing 2 expired bandwidth entries, 0 expired media entries.
Aug 27, 2019 19:00:04.069 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.069 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.091 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.091 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.123 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.124 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.134 [0x80c67cd00] DEBUG - HTTP 200 response from GET http://127.0.0.1:32600/devices/dvb%23hdhr%230%23272129946
Aug 27, 2019 19:00:04.157 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.157 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.190 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.190 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.234 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.234 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.267 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.267 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.274 [0x80c59fa00] DEBUG - Auth: authenticated user 1 as themaacks
Aug 27, 2019 19:00:04.275 [0x80c968600] DEBUG - Request: [192.168.1.92:64162 (Subnet)] GET /statistics/bandwidth?timespan=6 (4 live) TLS GZIP Signed-in Token (themaacks)
Aug 27, 2019 19:00:04.277 [0x80c59fa00] DEBUG - Completed: [192.168.1.92:64162] 200 GET /statistics/bandwidth?timespan=6 (4 live) TLS GZIP 2ms 1495 bytes (pipelined: 689)
Aug 27, 2019 19:00:04.300 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.300 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.332 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.332 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.377 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.377 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.378 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.421 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.421 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.454 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.454 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.498 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.498 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.499 [0x80deebf00] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.663 [0x80c968600] ERROR - [Transcoder] [mpeg2video @ 0x803c17400] Invalid frame dimensions 0x0.
Aug 27, 2019 19:00:04.663 [0x80deebf00] DEBUG - Request: [127.0.0.1:53397 (Loopback)] PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress/stream?index=1&id=49&codec=mpeg2video&type=video&profile=Main (4 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:04.664 [0x80c59fa00] DEBUG - Completed: [127.0.0.1:53397] 200 PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress/stream?index=1&id=49&codec=mpeg2video&type=video&profile=Main (4 live) 0ms 195 bytes (pipelined: 63) (range: bytes=0-) 
Aug 27, 2019 19:00:04.664 [0x80deebf00] DEBUG - Request: [127.0.0.1:53397 (Loopback)] PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress/stream?index=2&id=52&codec=ac3&type=audio (4 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:04.664 [0x80c59fa00] DEBUG - Completed: [127.0.0.1:53397] 200 PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress/stream?index=2&id=52&codec=ac3&type=audio (4 live) 0ms 195 bytes (pipelined: 64) (range: bytes=0-) 
Aug 27, 2019 19:00:04.664 [0x80deebf00] DEBUG - Request: [127.0.0.1:53397 (Loopback)] PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress/streamDetail?index=0&id=53&codec=ac3&type=audio&bitrate=192000&language=spa&channels=2&layout=stereo&sampleRate=48000&disp_visual_impaired=1 (4 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:04.664 [0x80c59ff00] DEBUG - Completed: [127.0.0.1:53397] 200 PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress/streamDetail?index=0&id=53&codec=ac3&type=audio&bitrate=192000&language=spa&channels=2&layout=stereo&sampleRate=48000&disp_visual_impaired=1 (4 live) 0ms 195 bytes (pipelined: 65) (range: bytes=0-) 
Aug 27, 2019 19:00:04.665 [0x80deebf00] DEBUG - Request: [127.0.0.1:53397 (Loopback)] PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress/streamDetail?index=1&id=49&codec=mpeg2video&type=video&profile=Main&width=1280&height=720&interlaced=0&sar=1:1&level=4&frameRate=59.940&closedCaptions=1 (4 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:04.665 [0x80c59ff00] DEBUG - Completed: [127.0.0.1:53397] 200 PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress/streamDetail?index=1&id=49&codec=mpeg2video&type=video&profile=Main&width=1280&height=720&interlaced=0&sar=1:1&level=4&frameRate=59.940&closedCaptions=1 (4 live) 0ms 195 bytes (pipelined: 66) (range: bytes=0-) 
Aug 27, 2019 19:00:04.665 [0x80deebf00] DEBUG - Request: [127.0.0.1:53397 (Loopback)] PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress/streamDetail?index=2&id=52&codec=ac3&type=audio&bitrate=384000&language=eng&channels=6&layout=5.1%28side%29&sampleRate=48000 (4 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:04.665 [0x80c59ff00] DEBUG - Completed: [127.0.0.1:53397] 200 PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress/streamDetail?index=2&id=52&codec=ac3&type=audio&bitrate=384000&language=eng&channels=6&layout=5.1%28side%29&sampleRate=48000 (4 live) 0ms 195 bytes (pipelined: 67) (range: bytes=0-) 
Aug 27, 2019 19:00:04.665 [0x80deebf00] DEBUG - Request: [127.0.0.1:53397 (Loopback)] PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress?duration=-1.000000 (4 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:04.666 [0x80c968100] DEBUG - Using default transcode duration of 120 minutes
Aug 27, 2019 19:00:04.666 [0x80c968100] DEBUG - Started session successfully: cd227a94-1279-4efd-9af4-807699553eec
Aug 27, 2019 19:00:04.666 [0x80c59fa00] DEBUG - Completed: [127.0.0.1:53397] 204 PUT /video/:/transcode/session/cd227a94-1279-4efd-9af4-807699553eec/21c3c039-0289-4367-88c9-e0a6700beeda/progress?duration=-1.000000 (4 live) 0ms 203 bytes (pipelined: 68) (range: bytes=0-) 
Aug 27, 2019 19:00:04.666 [0x80c968100] DEBUG - DVR:Recorder: It took 4.4 sec to start the session for http://127.0.0.1:32600/devices/dvb%23hdhr%231%23272129946/media/triplet%3A%2F%2F0%3A195%3A1?param=%3C%3Fxml%20version%3D%221%2E0%22%20encoding%3D%22UTF-8%22%3F%3E%0A%3Ctunedata%3E%3Ctt%3E8%3C%2Ftt%3E%3Cdq%3E0%3C%2Fdq%3E%3Cfr%3E15%3C%2Ffr%3E%3Cmd%3E0%3C%2Fmd%3E%3Csr%3E0%3C%2Fsr%3E%3Cpl%3E0%3C%2Fpl%3E%3Clf%3E0%3C%2Flf%3E%3Cl1%3E0%3C%2Fl1%3E%3Cl2%3E0%3C%2Fl2%3E%3Cls%3E0%3C%2Fls%3E%3Cpp%3E0%3C%2Fpp%3E%3Chz%3E0%3C%2Fhz%3E%3Cin%3E0%3C%2Fin%3E%3Cfc%3E0%3C%2Ffc%3E%3Ct%3E195%3C%2Ft%3E%3Cn%3E0%3C%2Fn%3E%3Cs%3E1%3C%2Fs%3E%3Cen%3E0%3C%2Fen%3E%3C%2Ftunedata%3E%0A
Aug 27, 2019 19:00:04.666 [0x80c968100] DEBUG - We're going to try to auto-select an audio stream for account 1.
Aug 27, 2019 19:00:04.666 [0x80c968100] DEBUG - Selecting best audio stream for part ID -1 (autoselect: 0 language: en)
Aug 27, 2019 19:00:04.666 [0x80c968100] DEBUG - Audio Stream: -1, Subtitle Stream: -1
Aug 27, 2019 19:00:04.666 [0x80deebf00] DEBUG - Transcoder segment range: 0 - 0 (-1)
Aug 27, 2019 19:00:04.667 [0x80c968100] DEBUG - MDE: Selected protocol http; container: mpegts
Aug 27, 2019 19:00:04.667 [0x80c968100] ERROR - Unable to find title for item of type 5
Aug 27, 2019 19:00:04.667 [0x80c968100] DEBUG - MDE: analyzing media item -1
Aug 27, 2019 19:00:04.667 [0x80c968100] DEBUG - MDE: : no direct play video profile exists for hls/mpegts/mpeg2video
Aug 27, 2019 19:00:04.667 [0x80c968100] DEBUG - MDE: : no direct play video profile exists for hls/mpegts/mpeg2video/ac3
Aug 27, 2019 19:00:04.667 [0x80c968100] DEBUG - MDE: : non-selected embedded subtitle stream  cannot be direct-played
Aug 27, 2019 19:00:04.667 [0x80c968100] DEBUG - MDE: : no direct play video profile exists for hls/mpegts/mpeg2video/ac3
Aug 27, 2019 19:00:04.667 [0x80c968100] DEBUG - MDE: : non-selected embedded subtitle stream  cannot be direct-played
Aug 27, 2019 19:00:04.667 [0x80c968100] ERROR - Unable to find title for item of type 5
Aug 27, 2019 19:00:04.667 [0x80c968100] DEBUG - MDE: : selected media 0 / -1
Aug 27, 2019 19:00:04.667 [0x80c968100] DEBUG - Cleaning directory for session 46de062d-0787-4d70-b2c4-23e366a21d7b ()
Aug 27, 2019 19:00:04.667 [0x80c968100] DEBUG - Starting a transcode session 46de062d-0787-4d70-b2c4-23e366a21d7b at offset -1.0 (state=3)
Aug 27, 2019 19:00:04.667 [0x80c968100] DEBUG - Streaming Resource: Added session 0x80cd6db60:46de062d-0787-4d70-b2c4-23e366a21d7b
Aug 27, 2019 19:00:04.668 [0x80c968100] DEBUG - Job running: EAE_ROOT='/tmp/pms-a72d0860-c7d3-47d7-b3ce-dacd4682f90a/EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='/usr/local/plexdata-plexpass/Plex\ Media\ Server/Codecs/dd95667-2434-freebsd-x86_64/' XDG_CACHE_HOME='/usr/local/plexdata-plexpass/Plex Media Server/Cache' XDG_DATA_HOME='/usr/local/share/plexmediaserver-plexpass/Resources' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' '/usr/local/share/plexmediaserver-plexpass/Plex Transcoder' '-codec:0' 'mpeg2video' '-noaccurate_seek' '-live_start_index' '0' '-probesize' '20000000' '-i' 'http://127.0.0.1:32400/livetv/sessions/cd227a94-1279-4efd-9af4-807699553eec/46de062d-0787-4d70-b2c4-23e366a21d7b/index.m3u8?offset=-1.000000&X-Plex-Token=xxxxxxxxxxxxxxxxxxxx' '-map' '0:0' '-codec:0' 'copy' '-map' '0:1' '-metadata:s:1' 'language=spa' '-codec:1' 'copy' '-map' '0:2' '-metadata:s:2' 'language=eng' '-codec:2' 'copy' '-f' 'mpegts' '-map_metadata' '-1' '-map_chapters' '-1' '/mnt/shows/.grab/336e2fc20fd72af4ad258de65d1647f85e6e8863/Bachelor in Paradise (2019) - S06E08 - Episode 604b.ts' '-y' '-nostats' '-loglevel' 'quiet' '-loglevel_plex' 'error' '-xioerror' '-progressurl' 'http://127.0.0.1:32400/video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress'
Aug 27, 2019 19:00:04.668 [0x80c968100] DEBUG - Jobs: Starting child process with pid 99773
Aug 27, 2019 19:00:04.673 [0x80c968600] DEBUG - Request: [127.0.0.1:20740 (Loopback)] PUT /video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress?status=startup (5 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:04.673 [0x80c59fa00] DEBUG - Completed: [127.0.0.1:20740] 204 PUT /video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress?status=startup (5 live) 0ms 203 bytes (pipelined: 1) (range: bytes=0-) 
Aug 27, 2019 19:00:04.673 [0x80c968600] DEBUG - Request: [127.0.0.1:20740 (Loopback)] PUT /video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress?status=opening (5 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:04.674 [0x80c59ff00] DEBUG - Completed: [127.0.0.1:20740] 204 PUT /video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress?status=opening (5 live) 0ms 203 bytes (pipelined: 2) (range: bytes=0-) 
Aug 27, 2019 19:00:04.689 [0x80c59ff00] DEBUG - Auth: authenticated user 1 as themaacks
Aug 27, 2019 19:00:04.689 [0x80c67d200] DEBUG - Request: [192.168.1.92:64162 (Subnet)] GET /status/sessions/background (6 live) TLS GZIP Signed-in Token (themaacks)
Aug 27, 2019 19:00:04.690 [0x80c59ff00] DEBUG - Completed: [192.168.1.92:64162] 200 GET /status/sessions/background (6 live) TLS GZIP 0ms 476 bytes (pipelined: 690)
Aug 27, 2019 19:00:05.285 [0x80c59ff00] DEBUG - Auth: authenticated user 1 as themaacks
Aug 27, 2019 19:00:05.285 [0x80c67d200] DEBUG - Request: [192.168.1.92:64162 (Subnet)] GET /statistics/bandwidth?timespan=6 (6 live) TLS GZIP Signed-in Token (themaacks)
Aug 27, 2019 19:00:05.287 [0x80c59ff00] DEBUG - Completed: [192.168.1.92:64162] 200 GET /statistics/bandwidth?timespan=6 (6 live) TLS GZIP 1ms 1509 bytes (pipelined: 691)
Aug 27, 2019 19:00:05.630 [0x80c968600] DEBUG - Transcoder segment range: 0 - 0 (0)
Aug 27, 2019 19:00:05.631 [0x80c67d200] DEBUG - Transcoder segment range: 0 - 1 (0)
Aug 27, 2019 19:00:05.631 [0x80c5a3100] DEBUG - Transcoder segment range: 0 - 1 (1)
Aug 27, 2019 19:00:05.631 [0x80c968600] DEBUG - Transcoder segment range: 0 - 2 (1)
Aug 27, 2019 19:00:05.713 [0x80c59ff00] DEBUG - Auth: authenticated user 1 as themaacks
Aug 27, 2019 19:00:05.713 [0x80c968600] DEBUG - Request: [192.168.1.92:64162 (Subnet)] GET /status/sessions/background (7 live) TLS GZIP Signed-in Token (themaacks)
Aug 27, 2019 19:00:05.713 [0x80c59ff00] DEBUG - Completed: [192.168.1.92:64162] 200 GET /status/sessions/background (7 live) TLS GZIP 0ms 476 bytes (pipelined: 692)
Aug 27, 2019 19:00:05.718 [0x80deebf00] DEBUG - buildLiveM3U8: min 0 max 1 ended 0
Aug 27, 2019 19:00:05.719 [0x80c67d200] DEBUG - buildLiveM3U8: min 0 max 1 ended 0
Aug 27, 2019 19:00:05.719 [0x80c968600] DEBUG - Request: [127.0.0.1:54181 (Loopback)] GET /livetv/sessions/cd227a94-1279-4efd-9af4-807699553eec/46de062d-0787-4d70-b2c4-23e366a21d7b/00000.ts (9 live) Signed-in
Aug 27, 2019 19:00:05.719 [0x80c968600] DEBUG - Content-Length of /mnt/transcode/Transcode/Sessions/plex-transcode-cd227a94-1279-4efd-9af4-807699553eec/media-00000.ts is 225976.
Aug 27, 2019 19:00:05.720 [0x80c968600] DEBUG - Request: [127.0.0.1:59158 (Loopback)] GET /livetv/sessions/cd227a94-1279-4efd-9af4-807699553eec/46de062d-0787-4d70-b2c4-23e366a21d7b/00001.ts (10 live) Signed-in
Aug 27, 2019 19:00:05.720 [0x80c968600] DEBUG - Content-Length of /mnt/transcode/Transcode/Sessions/plex-transcode-cd227a94-1279-4efd-9af4-807699553eec/media-00001.ts is 6956.
Aug 27, 2019 19:00:05.720 [0x80c968600] DEBUG - Request: [127.0.0.1:20740 (Loopback)] PUT /video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress?status=opened (10 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:05.721 [0x80c59ff00] DEBUG - Completed: [127.0.0.1:20740] 204 PUT /video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress?status=opened (10 live) 0ms 203 bytes (pipelined: 3) (range: bytes=0-) 
Aug 27, 2019 19:00:05.721 [0x80c968600] DEBUG - Request: [127.0.0.1:20740 (Loopback)] PUT /video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress/stream?index=0&id=0&codec=mpeg2video&type=video (10 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:05.721 [0x80c59ff00] DEBUG - Completed: [127.0.0.1:20740] 200 PUT /video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress/stream?index=0&id=0&codec=mpeg2video&type=video (10 live) 0ms 195 bytes (pipelined: 4) (range: bytes=0-) 
Aug 27, 2019 19:00:05.721 [0x80c968600] DEBUG - Request: [127.0.0.1:20740 (Loopback)] PUT /video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress/stream?index=1&id=0&codec=ac3&type=audio (10 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:05.721 [0x80c59ff00] DEBUG - Completed: [127.0.0.1:20740] 200 PUT /video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress/stream?index=1&id=0&codec=ac3&type=audio (10 live) 0ms 195 bytes (pipelined: 5) (range: bytes=0-) 
Aug 27, 2019 19:00:05.721 [0x80c968600] DEBUG - Request: [127.0.0.1:20740 (Loopback)] PUT /video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress/stream?index=2&id=0&codec=ac3&type=audio (10 live) Signed-in Token (themaacks)
Aug 27, 2019 19:00:05.721 [0x80c59ff00] DEBUG - Completed: [127.0.0.1:20740] 200 PUT /video/:/transcode/session/46de062d-0787-4d70-b2c4-23e366a21d7b/af4e95ad-9b3e-45c9-a13b-a9519814d08c/progress/stream?index=2&id=0&codec=ac3&type=audio (10 live) 0ms 195 bytes (pipelined: 6) (range: bytes=0-) 
Aug 27, 2019 19:00:05.722 [0x80c59fa00] DEBUG - Completed: [127.0.0.1:54181] 200 GET /livetv/sessions/cd227a94-1279-4efd-9af4-807699553eec/46de062d-0787-4d70-b2c4-23e366a21d7b/00000.ts (10 live) 2ms 225976 bytes (pipelined: 1)
Aug 27, 2019 19:00:05.722 [0x80c59fa00] DEBUG - Removed transcode data consumer, active count 2 => 1
Aug 27, 2019 19:00:05.723 [0x80c968600] DEBUG - buildLiveM3U8: min 0 max 1 ended 0
Aug 27, 2019 19:00:06.296 [0x80c59fa00] DEBUG - Auth: authenticated user 1 as themaacks
Aug 27, 2019 19:00:06.296 [0x80c968600] DEBUG - Request: [192.168.1.92:64162 (Subnet)] GET /statistics/bandwidth?timespan=6 (10 live) TLS GZIP Signed-in Token (themaacks)
Aug 27, 2019 19:00:06.298 [0x80c59fa00] DEBUG - Completed: [192.168.1.92:64162] 200 GET /statistics/bandwidth?timespan=6 (10 live) TLS GZIP 2ms 1523 bytes (pipelined: 693)
Aug 27, 2019 19:00:06.555 [0x80c968600] DEBUG - Transcoder segment range: 0 - 2 (2)
Aug 27, 2019 19:00:06.555 [0x80c67d200] DEBUG - Transcoder segment range: 0 - 3 (2)
Aug 27, 2019 19:00:06.555 [0x80c59fa00] DEBUG - Completed: [127.0.0.1:59158] 200 GET /livetv/sessions/cd227a94-1279-4efd-9af4-807699553eec/46de062d-0787-4d70-b2c4-23e366a21d7b/00001.ts (11 live) 835ms 6956 bytes (pipelined: 1)
Aug 27, 2019 19:00:06.555 [0x80c59fa00] DEBUG - Removed transcode data consumer, active count 1 => 0
Aug 27, 2019 19:00:07.138 [0x80d843900] DEBUG - HTTP requesting GET http://127.0.0.1:32600/devices/dvb%23hdhr%230%23272129946
Aug 27, 2019 19:00:07.310 [0x80c59ff00] DEBUG - Auth: authenticated user 1 as themaacks
Aug 27, 2019 19:00:07.310 [0x80c67d200] DEBUG - Request: [192.168.1.92:64162 (Subnet)] GET /statistics/bandwidth?timespan=6 (10 live) TLS GZIP Signed-in Token (themaacks)
Aug 27, 2019 19:00:07.312 [0x80c59ff00] DEBUG - Completed: [192.168.1.92:64162] 200 GET /statistics/bandwidth?timespan=6 (10 live) TLS GZIP 2ms 1530 bytes (pipelined: 694)
Aug 27, 2019 19:00:07.512 [0x80c67d200] DEBUG - Transcoder segment range: 0 - 3 (3)
Aug 27, 2019 19:00:07.512 [0x80c5a3100] DEBUG - Transcoder segment range: 0 - 4 (3)
Aug 27, 2019 19:00:07.557 [0x80d843900] DEBUG - HTTP 200 response from GET http://127.0.0.1:32600/devices/dvb%23hdhr%230%23272129946
Aug 27, 2019 19:00:08.321 [0x80c59ff00] DEBUG - Auth: authenticated user 1 as themaacks
Aug 27, 2019 19:00:08.321 [0x80c968600] DEBUG - Request: [192.168.1.92:64162 (Subnet)] GET /statistics/bandwidth?timespan=6 (10 live) TLS GZIP Signed-in Token (themaacks)
Aug 27, 2019 19:00:08.323 [0x80c59fa00] DEBUG - Completed: [192.168.1.92:64162] 200 GET /statistics/bandwidth?timespan=6 (10 live) TLS GZIP 2ms 1535 bytes (pipelined: 695)
Aug 27, 2019 19:00:08.469 [0x80c968600] DEBUG - Transcoder segment range: 0 - 4 (4)
Aug 27, 2019 19:00:08.469 [0x80c5a3100] DEBUG - Transcoder segment range: 0 - 5 (4)
Aug 27, 2019 19:00:09.333 [0x80c59ff00] DEBUG - Auth: authenticated user 1 as themaacks
Aug 27, 2019 19:00:09.333 [0x80deebf00] DEBUG - Request: [192.168.1.92:64162 (Subnet)] GET /statistics/bandwidth?timespan=6 (10 live) TLS GZIP Signed-in Token (themaacks)
Aug 27, 2019 19:00:09.335 [0x80c59ff00] DEBUG - Completed: [192.168.1.92:64162] 200 GET /statistics/bandwidth?timespan=6 (10 live) TLS GZIP 2ms 1541 bytes (pipelined: 696)
Aug 27, 2019 19:00:09.590 [0x80deebf00] DEBUG - Transcoder segment range: 0 - 5 (5)
Aug 27, 2019 19:00:09.590 [0x80c968600] DEBUG - Transcoder segment range: 0 - 6 (5)
Aug 27, 2019 19:00:10.346 [0x80c59ff00] DEBUG - Auth: authenticated user 1 as themaacks
Aug 27, 2019 19:00:10.346 [0x80c968600] DEBUG - Request: [192.168.1.92:64162 (Subnet)] GET /statistics/bandwidth?timespan=6 (10 live) TLS GZIP Signed-in Token (themaacks)
Aug 27, 2019 19:00:10.348 [0x80c59ff00] DEBUG - Completed: [192.168.1.92:64162] 200 GET /statistics/bandwidth?timespan=6 (10 live) TLS GZIP 2ms 1547 bytes (pipelined: 697)
Aug 27, 2019 19:00:10.548 [0x80c968600] DEBUG - Transcoder segment range: 0 - 6 (6)
Aug 27, 2019 19:00:10.548 [0x80c5a3100] DEBUG - Transcoder segment range: 0 - 7 (6)
Aug 27, 2019 19:00:10.558 [0x80d842f00] DEBUG - HTTP requesting GET http://127.0.0.1:32600/devices/dvb%23hdhr%230%23272129946
Aug 27, 2019 19:00:10.613 [0x80c964a00] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://192.168.1.116:49152/upnpdevicedesc.xml
Aug 27, 2019 19:00:10.613 [0x80c964a00] DEBUG - HTTP requesting GET http://192.168.1.116:49152/upnpdevicedesc.xml
Aug 27, 2019 19:00:10.621 [0x80c964a00] DEBUG - HTTP 200 response from GET http://192.168.1.116:49152/upnpdevicedesc.xml
Aug 27, 2019 19:00:10.621 [0x80c964a00] ERROR - XML: Entity: line 1:

pl_5309 · August 28, 2019, 9:35am

Is this an old HDHR Dual and do you have an antenna connected to both inputs?

Sounds like the checking for signal strength issue that was supposed to be resolved.

jwrober · August 28, 2019, 1:24pm

There can be issues with recording and having an EPG update occurring at the same time. I ran into it and had to develop a workaround on my end (I use zap2xml.pl file to build a custom xmltv.xml file). It looks like in your logs that you are getting transcoding errors in recording so the DVR is killing the process.

themaacks · September 3, 2019, 5:42pm

Yes. It is an old HDHR Dual and an antenna is connected to both inputs. I updated to 1.16.6.1592 and have the same problem still.

pl_5309 · September 3, 2019, 6:27pm

If you changed where you point to for transcoding. The location needs 16GB free space and plus Read, Write and Execute.
You can re-initialize the epg by shutting down Plex and deleting 3 files " tv.plex.providers.epg*" and then restart.
Looks like you are running on FreeNas in a docker and have been for a while. Your data is under /usr/local instead of /var/lib, not sure if that is an issue or not.
Did you rescan the channel list with the HDHR setup app to pick up any frequency changes that have been happening with the repacks?

When they added signal level checking I started having problems with my Dual and stopped using it.

themaacks · September 11, 2019, 11:49pm

Yeah, I’m running under FreeNAS but am just doing a manual install in a jail so it really shouldn’t be an issue. I’m open to doing any research/testing to determine if it is. I’ve set my transcoding directory to a mount on my filesystem that has plenty of space but I wonder if there’s anything hardcoded to other directories. I have just about 16GB free on the jail disk. I might try symlinking the entire plex data directory to a mount that has lots of space and see if that resolves it.

I did a channel scan when I installed the latest version of Plex Media Server so I don’t think that would be the issue.

Recordings fail every time. Pretty consistent issue, should be easy to recreate.

elverado · December 8, 2019, 3:52am

So I too am having a similar issue. I have two older HDHomeRun tuners that I used to use with MythTV DVR without issue. I saw that they’d ‘plug and play’ with PLEX and have spent half a day trying to figure out why they won’t record via the DVR, despite playing live and writing to all transcode folders without issue. I believe I figured it out - the channel change is slow on these older devices. So the transcoder starts trying to process on a 0kb file, since the MPEG2 stream hasn’t started yet. And it dies. There was a forum post that mentioned this 10 second delay being fixed in an earlier build in 2018 but seems it’s it’s back.

I finally figured out that if I’m playing live TV on a certain channel before the recording begins it works. So pretty sure that the tuner delay is the issue. Looking for some options to increase this timeout now.

system · March 7, 2020, 3:52am

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

Topic		Replies	Views
DVR failed to record Live TV & DVR livetv-dvr , server-linux	7	201	July 11, 2021
DVR Recordings Not Finishing Plex Features livetv-dvr	289	942	January 9, 2020
Recording showing in progress and 100% complete. Plex Features livetv-dvr	41	810	January 9, 2020
DVR recordings almost never complete Plex Features livetv-dvr	41	291	January 9, 2020
Recording started 15mins after scheduled (5 mins after show started airing) Live TV & DVR livetv-dvr , server-qnap	51	623	August 30, 2021

DVR Recordings stops after 24 seconds

Related topics