DVR Bug - transcoder error until server restart

General Discussions Plex Features
,
1

Bug: transcoder error on scheduled recordings almost every second day - only server restart helps

Setting: one cable tuner, three PMS (2x QNAP, 1x Windows Storage Server 2012 R2, latest beta each), each of the PMS records only one show at a time to work around the one stream per IP address limitation of the tuner.

All is good on the QNAP PMS, they record and record and record.
For the Windows machine, recording works for a day, but something happens over night, so I need to restart the Windows server in order to get rid of the problem, that on the Windows PMS, recording or live TV is no longer working. After a server restart, all is good for a certain time - until it stops working again… very unnerving bug.

2

It happened again… I downloaded server logs and restarted the server…
After restart, the same recording is now underway as partial recording, so no tuner issue is the cause of this.

Whom can I send the server logs to? They contain information like IP addresses that I want to keep private.

This bug is really annoying. I would really appreciate some help from @sa2000 , @kinoCharlino @elan or anybody who can help…

In the Plex Media Server.log
I can find the following:

Nov 06, 2018 10:00:00.845 [1224] DEBUG - DVR:Grabber: Starting operation for 'Science of Crime - Eine Frage der Schrift'.
Nov 06, 2018 10:00:00.845 [1224] DEBUG - Activity: registered new activity 7ebdc3ed-2eeb-4baa-9b07-6ae69d9768b5 - Recording
Nov 06, 2018 10:00:00.845 [1224] DEBUG - DVR:Grabber: Remote starting a media grab on device device://tv.plex.grabbers.tunerservice/dvb%23sat2ip%23uuid%3a663d5d6c-f9f8-4bb4-84d4-C80E1466A4A8 (AVM Berlin FRITZ!Box 6490 Cable (kdg), supported) tuner 0.
Nov 06, 2018 10:00:00.860 [1224] DEBUG - DVR:Subscription: Resolved subscription to library item 'Science of Crime' (11910)
Nov 06, 2018 10:00:00.860 [1224] DEBUG - There were 1 top-level paths for Science of Crime.
Nov 06, 2018 10:00:00.860 [1224] DEBUG - DVR:Grabber: Saving recording to "D:\Aufnahmen\Serien\.grab\415b37a4514394691d1c6cc000105e1caf1aa039"
Nov 06, 2018 10:00:00.954 [1224] DEBUG - DVR:Grabber: Going to record for 2700 seconds, final URL is http://127.0.0.1:32600/devices/dvb%23sat2ip%230%23uuid%3a663d5d6c-f9f8-4bb4-84d4-C80E1466A4A8/media/triplet%3A%2F%2F1%3A1079%3A11170?param=%3C%3Fxml%20version%3D%221%2E0%22%20encoding%3D%22UTF-8%22%3F%3E%0A%3Ctunedata%3E%3Ctt%3E2%3C%2Ftt%3E%3Cdq%3E0%3C%2Fdq%3E%3Cdr%2F%3E%3Cfr%3E450000%3C%2Ffr%3E%3Cmd%3E0%3C%2Fmd%3E%3Csr%3E6900000%3C%2Fsr%3E%3Cpl%3E0%3C%2Fpl%3E%3Clf%3E5%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%3E1079%3C%2Ft%3E%3Cn%3E1%3C%2Fn%3E%3Cs%3E11170%3C%2Fs%3E%3Cen%3E0%3C%2Fen%3E%3C%2Ftunedata%3E%0A
Nov 06, 2018 10:00:00.954 [1224] DEBUG - MediaRecorderVirtual: setting stop time to 2018-11-06 10:45:00
Nov 06, 2018 10:00:00.954 [1224] DEBUG - DVR:Segmenter: Creating a new recorder for http://127.0.0.1:32600/devices/dvb%23sat2ip%230%23uuid%3a663d5d6c-f9f8-4bb4-84d4-C80E1466A4A8/media/triplet%3A%2F%2F1%3A1079%3A11170?param=%3C%3Fxml%20version%3D%221%2E0%22%20encoding%3D%22UTF-8%22%3F%3E%0A%3Ctunedata%3E%3Ctt%3E2%3C%2Ftt%3E%3Cdq%3E0%3C%2Fdq%3E%3Cdr%2F%3E%3Cfr%3E450000%3C%2Ffr%3E%3Cmd%3E0%3C%2Fmd%3E%3Csr%3E6900000%3C%2Fsr%3E%3Cpl%3E0%3C%2Fpl%3E%3Clf%3E5%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%3E1079%3C%2Ft%3E%3Cn%3E1%3C%2Fn%3E%3Cs%3E11170%3C%2Fs%3E%3Cen%3E0%3C%2Fen%3E%3C%2Ftunedata%3E%0A.
Nov 06, 2018 10:00:00.954 [1224] DEBUG - DVR:Grabber: Waiting for a tuner (2 available).
Nov 06, 2018 10:00:00.954 [1224] DEBUG - DVR:Grabber: Allocated a tuner (1 left)
Nov 06, 2018 10:00:00.985 [1224] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 06, 2018 10:00:00.985 [1224] DEBUG - Selecting best audio stream for part ID -1 (autoselect: 0 language: de)
Nov 06, 2018 10:00:00.985 [1224] DEBUG - Audio Stream: -1, Subtitle Stream: -1
Nov 06, 2018 10:00:00.985 [1224] DEBUG - MDE: Selected protocol hls; container: mpegts
Nov 06, 2018 10:00:00.985 [1224] ERROR - Unable to find title for item of type 5
Nov 06, 2018 10:00:00.985 [1224] DEBUG - MDE: analyzing media item -1
Nov 06, 2018 10:00:00.985 [1224] DEBUG - MDE: : no direct play video profile exists for http/mpegts/
Nov 06, 2018 10:00:00.985 [1224] DEBUG - MDE: : no direct play video profile exists for http/mpegts//
Nov 06, 2018 10:00:00.985 [1224] DEBUG - MDE: : codec is unavailable for analysis
Nov 06, 2018 10:00:00.985 [1224] DEBUG - MDE: : codec is unavailable for analysis
Nov 06, 2018 10:00:00.985 [1224] ERROR - Unable to find title for item of type 5
Nov 06, 2018 10:00:00.985 [1224] DEBUG - MDE: : selected media 0 / -1
Nov 06, 2018 10:00:00.985 [1224] DEBUG - Cleaning directory for session c71eb888-e8b2-4a61-a83a-5164eda0aa4e ()
Nov 06, 2018 10:00:00.985 [1224] DEBUG - Starting a transcode session c71eb888-e8b2-4a61-a83a-5164eda0aa4e at offset -1.0 (state=3)
Nov 06, 2018 10:00:00.985 [1224] DEBUG - Streaming Resource: Added session 0x7c60de0:c71eb888-e8b2-4a61-a83a-5164eda0aa4e
Nov 06, 2018 10:00:01.001 [1224] DEBUG - Job running: EAE_ROOT='\\?\C:\Users\Administrator\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='C\:\\Users\\Administrator\\AppData\\Local\\Plex\ Media\ Server\\Codecs\\531e313-1328-windows-i386\\' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' D:\Plex\PlexTranscoder.exe -noaccurate_seek -ignore_unknown -scan_all_pmts -1 -rw_timeout 15000000 -reconnect 1 -reconnect_streamed 1 -reconnect_delay_max 30 -fflags +discardcorruptts+fillwallclockdts -probesize 10000000 -i http://127.0.0.1:32600/devices/dvb%23sat2ip%230%23uuid%3a663d5d6c-f9f8-4bb4-84d4-C80E1466A4A8/media/triplet%3A%2F%2F1%3A1079%3A11170?param=%3C%3Fxml%20version%3D%221%2E0%22%20encoding%3D%22UTF-8%22%3F%3E%0A%3Ctunedata%3E%3Ctt%3E2%3C%2Ftt%3E%3Cdq%3E0%3C%2Fdq%3E%3Cdr%2F%3E%3Cfr%3E450000%3C%2Ffr%3E%3Cmd%3E0%3C%2Fmd%3E%3Csr%3E6900000%3C%2Fsr%3E%3Cpl%3E0%3C%2Fpl%3E%3Clf%3E5%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%3E1079%3C%2Ft%3E%3Cn%3E1%3C%2Fn%3E%3Cs%3E11170%3C%2Fs%3E%3Cen%3E0%3C%2Fen%3E%3C%2Ftunedata%3E%0A -map 0:V? -codec:V copy -map 0:a? -codec:a copy -copypriorss:a 0 -map 0:s? -codec:s copy -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/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/seglist -segment_list_type csv -segment_list_size 2147483647 -segment_list_separate_stream_times 1 -max_delay 5000000 -map_metadata -1 -map_chapters -1 media-%05d.ts -y -nostats -loglevel quiet -loglevel_plex error -progressurl http://127.0.0.1:32400/video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress 
Nov 06, 2018 10:00:02.110 [3936] DEBUG - EPG[onconnect]: Next thing to start/end is at 2018-11-06 09:10:00 GMT (in 599 seconds)
Nov 06, 2018 10:00:02.329 [1224] DEBUG - Jobs: Starting child process with pid 3456
Nov 06, 2018 10:00:02.798 [3936] DEBUG - Auth: Refreshing tokens inside the token-based authentication filter.
Nov 06, 2018 10:00:02.798 [3936] DEBUG - HTTP requesting GET https://plex.tv/servers/aa59e764fb49d1df247ff27b543d1f7d303219e3/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Nov 06, 2018 10:00:02.798 [2800] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress?status=startup (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:02.814 [2936] DEBUG - Completed: [127.0.0.1:51796] 204 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress?status=startup (5 live) 3ms 203 bytes (pipelined: 1) (range: bytes=0-) 
Nov 06, 2018 10:00:02.814 [3868] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress?status=opening (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:02.814 [2560] DEBUG - Completed: [127.0.0.1:51796] 204 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress?status=opening (5 live) 2ms 203 bytes (pipelined: 2) (range: bytes=0-) 
Nov 06, 2018 10:00:03.126 [3936] DEBUG - HTTP 200 response from GET https://plex.tv/servers/aa59e764fb49d1df247ff27b543d1f7d303219e3/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Nov 06, 2018 10:00:03.142 [3936] DEBUG - MyPlex: updating with 48 access tokens
Nov 06, 2018 10:00:03.142 [2380] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Nov 06, 2018 10:00:03.407 [2380] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Nov 06, 2018 10:00:04.267 [2800] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress?status=opened (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.267 [2936] DEBUG - Completed: [127.0.0.1:51796] 204 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress?status=opened (5 live) 2ms 203 bytes (pipelined: 3) (range: bytes=0-) 
Nov 06, 2018 10:00:04.267 [3868] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/stream?index=0&id=6710&codec=h264&type=video (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.267 [2936] DEBUG - Completed: [127.0.0.1:51796] 206 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/stream?index=0&id=6710&codec=h264&type=video (5 live) 1ms 256 bytes (pipelined: 4) (range: bytes=0-) 
Nov 06, 2018 10:00:04.267 [2800] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/stream?index=1&id=6720&codec=ac3&type=audio (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.267 [2936] DEBUG - Completed: [127.0.0.1:51796] 206 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/stream?index=1&id=6720&codec=ac3&type=audio (5 live) 1ms 256 bytes (pipelined: 5) (range: bytes=0-) 
Nov 06, 2018 10:00:04.267 [3868] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/stream?index=2&id=6721&codec=ac3&type=audio (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.267 [2936] DEBUG - Completed: [127.0.0.1:51796] 206 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/stream?index=2&id=6721&codec=ac3&type=audio (5 live) 2ms 256 bytes (pipelined: 6) (range: bytes=0-) 
Nov 06, 2018 10:00:04.282 [2800] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/stream?index=3&id=6723&codec=ac3&type=audio (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.282 [2936] DEBUG - Completed: [127.0.0.1:51796] 206 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/stream?index=3&id=6723&codec=ac3&type=audio (5 live) 2ms 256 bytes (pipelined: 7) (range: bytes=0-) 
Nov 06, 2018 10:00:04.314 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.314 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.314 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.314 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.314 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.329 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.329 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.329 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.329 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.329 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.329 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.345 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.345 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.345 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.345 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.345 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.345 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.361 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.361 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.361 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.361 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.361 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.361 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.376 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.376 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.376 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.376 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.376 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.376 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.392 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.392 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.392 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.392 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.392 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.392 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.407 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.407 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.407 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.407 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.407 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.407 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.423 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.423 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.423 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.423 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.423 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.439 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.439 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.439 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.439 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.439 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.439 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.454 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.454 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.454 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.454 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.454 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.454 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.470 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.470 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.470 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.470 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.470 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.470 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.486 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.486 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.486 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.486 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.486 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.486 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.501 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.501 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.501 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.501 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.501 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.501 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.517 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.517 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.517 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.517 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.517 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.517 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.532 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.532 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.532 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.532 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.532 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.548 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.548 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.548 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.548 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.548 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.548 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.564 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.564 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.564 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.564 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.564 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.564 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.579 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.579 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.579 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.579 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.579 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.579 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.595 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.595 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.595 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.595 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.595 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.595 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.611 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.611 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.611 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.611 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.611 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.611 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.626 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.626 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.626 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.626 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.626 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.626 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.642 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.642 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.642 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.642 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.642 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.642 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.657 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.657 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.657 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.657 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.657 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.657 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.673 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.673 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.673 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.673 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.673 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.673 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.689 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.689 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.689 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.689 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.689 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.689 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.704 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.704 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.704 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.704 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.704 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.704 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.720 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.720 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.720 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.720 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.720 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.720 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.736 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.736 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.736 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.782 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.782 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.782 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] SPS unavailable in decode_picture_timing
Nov 06, 2018 10:00:04.798 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] non-existing PPS 0 referenced
Nov 06, 2018 10:00:04.798 [3868] ERROR - [Transcoder] [h264 @ 0177ea40] decode_slice_header error
Nov 06, 2018 10:00:04.798 [2800] ERROR - [Transcoder] [h264 @ 0177ea40] no frame!
Nov 06, 2018 10:00:04.876 [3868] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/streamDetail?index=0&id=6710&codec=h264&type=video&profile=High&width=1280&height=720&interlaced=0&sar=1:1&level=40&frameRate=50.000 (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.876 [2560] DEBUG - Completed: [127.0.0.1:51796] 206 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/streamDetail?index=0&id=6710&codec=h264&type=video&profile=High&width=1280&height=720&interlaced=0&sar=1:1&level=40&frameRate=50.000 (5 live) 1ms 256 bytes (pipelined: 176) (range: bytes=0-) 
Nov 06, 2018 10:00:04.876 [2800] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/streamDetail?index=1&id=6720&codec=ac3&type=audio&bitrate=448000&language=deu&channels=2&layout=stereo&sampleRate=48000 (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.876 [2560] DEBUG - Completed: [127.0.0.1:51796] 206 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/streamDetail?index=1&id=6720&codec=ac3&type=audio&bitrate=448000&language=deu&channels=2&layout=stereo&sampleRate=48000 (5 live) 1ms 256 bytes (pipelined: 177) (range: bytes=0-) 
Nov 06, 2018 10:00:04.876 [3868] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/streamDetail?index=2&id=6721&codec=ac3&type=audio&bitrate=192000&language=deu&channels=2&layout=stereo&sampleRate=48000&disp_visual_impaired=1 (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.892 [2560] DEBUG - Completed: [127.0.0.1:51796] 206 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/streamDetail?index=2&id=6721&codec=ac3&type=audio&bitrate=192000&language=deu&channels=2&layout=stereo&sampleRate=48000&disp_visual_impaired=1 (5 live) 2ms 256 bytes (pipelined: 178) (range: bytes=0-) 
Nov 06, 2018 10:00:04.892 [2800] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/streamDetail?index=3&id=6723&codec=ac3&type=audio&bitrate=192000&language=mul&channels=2&layout=stereo&sampleRate=48000 (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.892 [2560] DEBUG - Completed: [127.0.0.1:51796] 206 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/streamDetail?index=3&id=6723&codec=ac3&type=audio&bitrate=192000&language=mul&channels=2&layout=stereo&sampleRate=48000 (5 live) 1ms 256 bytes (pipelined: 179) (range: bytes=0-) 
Nov 06, 2018 10:00:04.892 [3868] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/streamDetail?index=4&id=6730&codec=dvb_teletext&type=subtitle&language=deu (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.892 [2560] DEBUG - Completed: [127.0.0.1:51796] 206 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/streamDetail?index=4&id=6730&codec=dvb_teletext&type=subtitle&language=deu (5 live) 1ms 256 bytes (pipelined: 180) (range: bytes=0-) 
Nov 06, 2018 10:00:04.892 [2800] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/streamDetail?index=5&id=6731&codec=dvb_subtitle&type=subtitle&language=deu&disp_hearing_impaired=1 (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.892 [2560] DEBUG - Completed: [127.0.0.1:51796] 206 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress/streamDetail?index=5&id=6731&codec=dvb_subtitle&type=subtitle&language=deu&disp_hearing_impaired=1 (5 live) 1ms 256 bytes (pipelined: 181) (range: bytes=0-) 
Nov 06, 2018 10:00:04.907 [3868] DEBUG - Request: [127.0.0.1:51796 (Loopback)] PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress?duration=-1.000000 (5 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.907 [1224] DEBUG - Using default transcode duration of 120 minutes
Nov 06, 2018 10:00:04.907 [1224] DEBUG - Started session successfully: c71eb888-e8b2-4a61-a83a-5164eda0aa4e
Nov 06, 2018 10:00:04.907 [2936] DEBUG - Completed: [127.0.0.1:51796] 204 PUT /video/:/transcode/session/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/a77652a8-17da-4589-88b7-4207ee599d9a/progress?duration=-1.000000 (5 live) 2ms 203 bytes (pipelined: 182) (range: bytes=0-) 
Nov 06, 2018 10:00:04.907 [1224] DEBUG - DVR:Recorder: It took 3.9 sec to start the session for http://127.0.0.1:32600/devices/dvb%23sat2ip%230%23uuid%3a663d5d6c-f9f8-4bb4-84d4-C80E1466A4A8/media/triplet%3A%2F%2F1%3A1079%3A11170?param=%3C%3Fxml%20version%3D%221%2E0%22%20encoding%3D%22UTF-8%22%3F%3E%0A%3Ctunedata%3E%3Ctt%3E2%3C%2Ftt%3E%3Cdq%3E0%3C%2Fdq%3E%3Cdr%2F%3E%3Cfr%3E450000%3C%2Ffr%3E%3Cmd%3E0%3C%2Fmd%3E%3Csr%3E6900000%3C%2Fsr%3E%3Cpl%3E0%3C%2Fpl%3E%3Clf%3E5%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%3E1079%3C%2Ft%3E%3Cn%3E1%3C%2Fn%3E%3Cs%3E11170%3C%2Fs%3E%3Cen%3E0%3C%2Fen%3E%3C%2Ftunedata%3E%0A
3

Second part:

Nov 06, 2018 10:00:04.907 [1224] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 06, 2018 10:00:04.907 [1224] DEBUG - Selecting best audio stream for part ID -1 (autoselect: 0 language: de)
Nov 06, 2018 10:00:04.907 [1224] DEBUG - Audio Stream: -1, Subtitle Stream: -1
Nov 06, 2018 10:00:04.907 [1224] DEBUG - MDE: Selected protocol http; container: mpegts
Nov 06, 2018 10:00:04.907 [1224] ERROR - Unable to find title for item of type 5
Nov 06, 2018 10:00:04.907 [1224] DEBUG - MDE: analyzing media item -1
Nov 06, 2018 10:00:04.907 [1224] DEBUG - MDE: : no direct play video profile exists for hls/mpegts/h264
Nov 06, 2018 10:00:04.907 [1224] DEBUG - MDE: : no direct play video profile exists for hls/mpegts/h264/ac3
Nov 06, 2018 10:00:04.907 [1224] DEBUG - MDE: : non-selected embedded subtitle stream  cannot be direct-played
Nov 06, 2018 10:00:04.907 [1224] DEBUG - MDE: : non-selected embedded subtitle stream  cannot be direct-played
Nov 06, 2018 10:00:04.923 [1224] DEBUG - MDE: : no direct play video profile exists for hls/mpegts/h264/ac3
Nov 06, 2018 10:00:04.923 [1224] DEBUG - MDE: : non-selected embedded subtitle stream  cannot be direct-played
Nov 06, 2018 10:00:04.923 [1224] DEBUG - MDE: : non-selected embedded subtitle stream  cannot be direct-played
Nov 06, 2018 10:00:04.923 [1224] DEBUG - MDE: : no direct play video profile exists for hls/mpegts/h264/ac3
Nov 06, 2018 10:00:04.923 [1224] DEBUG - MDE: : non-selected embedded subtitle stream  cannot be direct-played
Nov 06, 2018 10:00:04.923 [1224] DEBUG - MDE: : non-selected embedded subtitle stream  cannot be direct-played
Nov 06, 2018 10:00:04.923 [2560] DEBUG - Auth: authenticated user 1 as rossinior
Nov 06, 2018 10:00:04.923 [2936] DEBUG - Auth: authenticated user 1 as rossinior
Nov 06, 2018 10:00:04.923 [1224] ERROR - Unable to find title for item of type 5
Nov 06, 2018 10:00:04.923 [1224] DEBUG - MDE: : selected media 0 / -1
Nov 06, 2018 10:00:04.923 [3868] DEBUG - Request: [192.168.94.124:56382 (Subnet)] GET /status/sessions/background (7 live) GZIP Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.923 [2800] DEBUG - Request: [192.168.94.124:56381 (Subnet)] GET /status/sessions/background (7 live) GZIP Signed-in Token (rossinior)
Nov 06, 2018 10:00:04.923 [1224] DEBUG - Cleaning directory for session 273a2f7c-e280-4452-b79c-f67ac22f0443 ()
Nov 06, 2018 10:00:04.923 [1224] DEBUG - Starting a transcode session 273a2f7c-e280-4452-b79c-f67ac22f0443 at offset -1.0 (state=3)
Nov 06, 2018 10:00:04.923 [1224] DEBUG - Streaming Resource: Added session 0x70b2828:273a2f7c-e280-4452-b79c-f67ac22f0443
Nov 06, 2018 10:00:04.923 [2560] DEBUG - Completed: [192.168.94.124:56381] 200 GET /status/sessions/background (7 live) GZIP 6ms 470 bytes (pipelined: 1)
Nov 06, 2018 10:00:04.923 [2936] DEBUG - Completed: [192.168.94.124:56382] 200 GET /status/sessions/background (7 live) GZIP 8ms 470 bytes (pipelined: 1)
Nov 06, 2018 10:00:04.954 [1224] DEBUG - Job running: EAE_ROOT='\\?\C:\Users\Administrator\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='C\:\\Users\\Administrator\\AppData\\Local\\Plex\ Media\ Server\\Codecs\\531e313-1328-windows-i386\\' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' D:\Plex\PlexTranscoder.exe -codec:0 h264 -noaccurate_seek -live_start_index 0 -probesize 10000000 -i http://127.0.0.1:32400/livetv/sessions/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/273a2f7c-e280-4452-b79c-f67ac22f0443/index.m3u8?offset=-1.000000&X-Plex-Token=xxxxxxxxxxxxxxxxxxxx -map 0:0 -codec:0 copy -map 0:1 -metadata:s:1 language=ger -codec:1 copy -copypriorss:1 0 -map 0:2 -metadata:s:2 language=ger -codec:2 copy -copypriorss:2 0 -map 0:3 -metadata:s:3 language=mul -codec:3 copy -copypriorss:3 0 -map 0:5 -metadata:s:4 language=ger -codec:4 copy -f mpegts -map_metadata -1 -map_chapters -1 "D:\Aufnahmen\Serien\.grab\415b37a4514394691d1c6cc000105e1caf1aa039\Science of Crime (2011) - 2018-11-06 10 00 00 - Eine Frage der Schrift.ts" -y -nostats -loglevel quiet -loglevel_plex error -progressurl http://127.0.0.1:32400/video/:/transcode/session/273a2f7c-e280-4452-b79c-f67ac22f0443/f5a9da5b-1983-49dc-9d2c-1f581b8296c6/progress 
Nov 06, 2018 10:00:04.954 [1224] DEBUG - Jobs: Starting child process with pid 548
Nov 06, 2018 10:00:05.064 [1144] DEBUG - Request: [127.0.0.1:51804 (Loopback)] PUT /video/:/transcode/session/273a2f7c-e280-4452-b79c-f67ac22f0443/f5a9da5b-1983-49dc-9d2c-1f581b8296c6/progress?status=startup (8 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:05.064 [2936] DEBUG - Completed: [127.0.0.1:51804] 204 PUT /video/:/transcode/session/273a2f7c-e280-4452-b79c-f67ac22f0443/f5a9da5b-1983-49dc-9d2c-1f581b8296c6/progress?status=startup (8 live) 2ms 203 bytes (pipelined: 1) (range: bytes=0-) 
Nov 06, 2018 10:00:05.064 [2800] DEBUG - Request: [127.0.0.1:51804 (Loopback)] PUT /video/:/transcode/session/273a2f7c-e280-4452-b79c-f67ac22f0443/f5a9da5b-1983-49dc-9d2c-1f581b8296c6/progress?status=opening (8 live) Signed-in Token (rossinior)
Nov 06, 2018 10:00:05.064 [2936] DEBUG - Completed: [127.0.0.1:51804] 204 PUT /video/:/transcode/session/273a2f7c-e280-4452-b79c-f67ac22f0443/f5a9da5b-1983-49dc-9d2c-1f581b8296c6/progress?status=opening (8 live) 1ms 203 bytes (pipelined: 2) (range: bytes=0-) 
Nov 06, 2018 10:00:09.767 [1296] DEBUG - NetworkServiceBrowser: SSDP departed after not being seen for 21.000820 seconds: 192.168.94.118 (Schlafzimmer)
Nov 06, 2018 10:00:10.908 [3352] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://192.168.94.118:60000/upnp/dev/8c42a0ba-0e99-7e6d-0000-000023f635d5/desc
Nov 06, 2018 10:00:10.923 [3352] DEBUG - HTTP requesting GET http://192.168.94.118:60000/upnp/dev/8c42a0ba-0e99-7e6d-0000-000023f635d5/desc
Nov 06, 2018 10:00:10.955 [3352] DEBUG - HTTP 200 response from GET http://192.168.94.118:60000/upnp/dev/8c42a0ba-0e99-7e6d-0000-000023f635d5/desc
Nov 06, 2018 10:00:10.955 [3352] DEBUG - NetworkServiceBrowser: found 1 SSDP devices via http://192.168.94.118:60000/upnp/dev/8c42a0ba-0e99-7e6d-0000-000023f635d5/desc
Nov 06, 2018 10:00:10.955 [3352] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.94.118 (Schlafzimmer)
Nov 06, 2018 10:00:27.846 [2380] DEBUG - Activity: updated activity 7ebdc3ed-2eeb-4baa-9b07-6ae69d9768b5 - completed 1% - Recording
Nov 06, 2018 10:00:35.831 [1224] DEBUG - Using default transcode duration of 120 minutes
Nov 06, 2018 10:00:35.831 [1224] DEBUG - Using default transcode duration of 120 minutes
Nov 06, 2018 10:00:35.831 [1224] DEBUG - Started session successfully: 273a2f7c-e280-4452-b79c-f67ac22f0443
Nov 06, 2018 10:00:35.831 [1224] DEBUG - DVR:Recorder: It took 30.9 sec to start the session for http://127.0.0.1:32600/devices/dvb%23sat2ip%230%23uuid%3a663d5d6c-f9f8-4bb4-84d4-C80E1466A4A8/media/triplet%3A%2F%2F1%3A1079%3A11170?param=%3C%3Fxml%20version%3D%221%2E0%22%20encoding%3D%22UTF-8%22%3F%3E%0A%3Ctunedata%3E%3Ctt%3E2%3C%2Ftt%3E%3Cdq%3E0%3C%2Fdq%3E%3Cdr%2F%3E%3Cfr%3E450000%3C%2Ffr%3E%3Cmd%3E0%3C%2Fmd%3E%3Csr%3E6900000%3C%2Fsr%3E%3Cpl%3E0%3C%2Fpl%3E%3Clf%3E5%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%3E1079%3C%2Ft%3E%3Cn%3E1%3C%2Fn%3E%3Cs%3E11170%3C%2Fs%3E%3Cen%3E0%3C%2Fen%3E%3C%2Ftunedata%3E%0A
Nov 06, 2018 10:00:35.831 [3644] INFO - Notification: Recording Science of Crime - Eine Frage der Schrift - 
Nov 06, 2018 10:00:35.846 [2936] DEBUG - Auth: authenticated user 1 as rossinior
Nov 06, 2018 10:00:35.846 [2560] DEBUG - Auth: authenticated user 1 as rossinior
Nov 06, 2018 10:00:35.846 [3868] DEBUG - Request: [192.168.94.124:56388 (Subnet)] GET /status/sessions/background (9 live) GZIP Signed-in Token (rossinior)
Nov 06, 2018 10:00:35.846 [3540] DEBUG - Request: [192.168.94.124:56389 (Subnet)] GET /status/sessions/background (9 live) GZIP Signed-in Token (rossinior)
Nov 06, 2018 10:00:35.846 [2936] DEBUG - Completed: [192.168.94.124:56388] 200 GET /status/sessions/background (9 live) GZIP 5ms 470 bytes (pipelined: 1)
Nov 06, 2018 10:00:35.846 [2936] DEBUG - Completed: [192.168.94.124:56389] 200 GET /status/sessions/background (9 live) GZIP 4ms 470 bytes (pipelined: 1)
Nov 06, 2018 10:00:37.893 [1144] WARN - buildLiveM3U8: no segment info available
Nov 06, 2018 10:00:37.893 [3260] ERROR - [Transcoder] http://127.0.0.1:32400/livetv/sessions/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/273a2f7c-e280-4452-b79c-f67ac22f0443/index.m3u8?offset=-1.000000&X-Plex-Token=xxxxxxxxxxxxxxxxxxxx: Server returned 5XX Server Error reply
Nov 06, 2018 10:00:37.909 [3868] ERROR - [Transcoder] http://127.0.0.1:32400/livetv/sessions/c71eb888-e8b2-4a61-a83a-5164eda0aa4e/273a2f7c-e280-4452-b79c-f67ac22f0443/index.m3u8?offset=-1.000000&X-Plex-Token=xxxxxxxxxxxxxxxxxxxx: Server returned 5XX Server Error reply
Nov 06, 2018 10:00:37.909 [2380] DEBUG - Jobs: 'D:\Plex\PlexTranscoder.exe' exit code for process 548 is 1 (failure)
Nov 06, 2018 10:00:37.909 [3784] DEBUG - DVR:Recorder: Asked to stop recording 'Science of Crime - Eine Frage der Schrift'.
Nov 06, 2018 10:00:37.909 [3784] DEBUG - DVR:Recorder: Stopping transcode session.
Nov 06, 2018 10:00:37.909 [3784] DEBUG - Killing job.
Nov 06, 2018 10:00:37.924 [3784] DEBUG - Job was already killed, not killing again.
Nov 06, 2018 10:00:37.924 [3420] DEBUG - Jobs: 'D:\Plex\PlexTranscoder.exe' exit code for process 3456 is -1059143458 (intentional termination)
Nov 06, 2018 10:00:37.924 [2560] DEBUG - Auth: authenticated user 1 as rossinior
Nov 06, 2018 10:00:37.924 [3784] DEBUG - Stopping transcode session c71eb888-e8b2-4a61-a83a-5164eda0aa4e
Nov 06, 2018 10:00:37.924 [1224] DEBUG - Cleaning directory for session c71eb888-e8b2-4a61-a83a-5164eda0aa4e (C:\Users\Administrator\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-c71eb888-e8b2-4a61-a83a-5164eda0aa4e)
Nov 06, 2018 10:00:37.924 [3540] DEBUG - Request: [192.168.94.124:56389 (Subnet)] GET /status/sessions/background (8 live) GZIP Signed-in Token (rossinior)
Nov 06, 2018 10:00:37.924 [2936] DEBUG - Auth: authenticated user 1 as rossinior
Nov 06, 2018 10:00:37.924 [1144] DEBUG - Request: [192.168.94.124:56388 (Subnet)] GET /status/sessions/background (7 live) GZIP Signed-in Token (rossinior)
Nov 06, 2018 10:00:37.940 [2560] DEBUG - Completed: [192.168.94.124:56389] 200 GET /status/sessions/background (7 live) GZIP 8ms 470 bytes (pipelined: 2)
Nov 06, 2018 10:00:37.940 [2560] DEBUG - Completed: [192.168.94.124:56388] 200 GET /status/sessions/background (7 live) GZIP 5ms 470 bytes (pipelined: 2)
Nov 06, 2018 10:00:37.940 [3784] DEBUG - DVR:Grabber: Freed a tuner (now 2 available)
Nov 06, 2018 10:00:37.956 [3784] DEBUG - DVR:Grabber: Recording for 'Science of Crime - Eine Frage der Schrift' stopped with status error.
Nov 06, 2018 10:00:37.956 [0900] DEBUG - DVR:Recorder: Asked to stop recording 'Science of Crime - Eine Frage der Schrift'.
Nov 06, 2018 10:00:37.956 [3784] DEBUG - DVR:Grabber: Using recording status.
Nov 06, 2018 10:00:37.956 [3784] DEBUG - Activity: updated activity 7ebdc3ed-2eeb-4baa-9b07-6ae69d9768b5 - completed 100% - Recording
Nov 06, 2018 10:00:37.956 [3784] DEBUG - [MI] Opening input file: "D:\Aufnahmen\Serien\.grab\415b37a4514394691d1c6cc000105e1caf1aa039\Science of Crime (2011) - 2018-11-06 10 00 00 - Eine Frage der Schrift.ts"
Nov 06, 2018 10:00:37.956 [3784] DEBUG - [FFMPEG] - Opening 'D:\Aufnahmen\Serien\.grab\415b37a4514394691d1c6cc000105e1caf1aa039\Science of Crime (2011) - 2018-11-06 10 00 00 - Eine Frage der Schrift.ts' for reading
Nov 06, 2018 10:00:37.956 [3784] DEBUG - [FFMPEG] - Setting default whitelist 'file,crypto'
Nov 06, 2018 10:00:38.128 [2560] DEBUG - Auth: authenticated user 1 as rossinior
Nov 06, 2018 10:00:38.128 [3868] DEBUG - Request: [192.168.94.124:56388 (Subnet)] GET /status/sessions/background (6 live) GZIP Signed-in Token (rossinior)
Nov 06, 2018 10:00:38.128 [2936] DEBUG - Completed: [192.168.94.124:56388] 200 GET /status/sessions/background (6 live) GZIP 3ms 470 bytes (pipelined: 3)
Nov 06, 2018 10:00:38.128 [2560] DEBUG - Auth: authenticated user 1 as rossinior
Nov 06, 2018 10:00:38.128 [3260] DEBUG - Request: [192.168.94.124:56389 (Subnet)] GET /status/sessions/background (6 live) GZIP Signed-in Token (rossinior)
Nov 06, 2018 10:00:38.143 [2936] DEBUG - Completed: [192.168.94.124:56389] 200 GET /status/sessions/background (6 live) GZIP 3ms 470 bytes (pipelined: 3)
Nov 06, 2018 10:00:39.221 [3784] ERROR - DVR:Grabber: Failed to inspect file: Could not parse D:\Aufnahmen\Serien\.grab\415b37a4514394691d1c6cc000105e1caf1aa039\Science of Crime (2011) - 2018-11-06 10 00 00 - Eine Frage der Schrift.ts (error=-2): No such file or directory
Nov 06, 2018 10:00:39.221 [3784] DEBUG - DVR:Grabber: Scheduling 'Science of Crime - Eine Frage der Schrift' for assimilation.
Nov 06, 2018 10:00:39.221 [3420] DEBUG - DVR:Subscription: Resolved subscription to library item 'Science of Crime' (11910)
Nov 06, 2018 10:00:39.221 [3420] DEBUG - There were 1 top-level paths for Science of Crime.
Nov 06, 2018 10:00:39.221 [3420] DEBUG - DVR:Grabber: Postprocessing, we're going to put `Science of Crime - Eine Frage der Schrift` in `D:\Aufnahmen\Serien\Science of Crime (2011)\Season 2018\Science of Crime (2011) - 2018-11-06 10 00 00 - Eine Frage der Schrift.ts`
Nov 06, 2018 10:00:39.221 [3420] DEBUG - DVR:Grabber: Operation for Science of Crime - Eine Frage der Schrift completed with status error (There was a transcoder error)
Nov 06, 2018 10:00:39.221 [3420] DEBUG - Activity: Ended activity 7ebdc3ed-2eeb-4baa-9b07-6ae69d9768b5.
4

Thanks for the log extract.

Would like to see the corresponding Plex Tuner Service log file please

If the problem is persistent, will probably need to capture the channel stream using curl and put that through to the transcoder to see why it crashes out.

This can be done using curl.exe in command line whilst the Plex Media Server is running with the tuner available.

Going to give you the details anyway,

Download curl.exe from https://curl.haxx.se/download.html - link for windows downloads https://curl.haxx.se/windows/
Download the curl project 64-bit - current version 7.62.0
unzip and pick the curl.exe from the bin folder and copy it to a test directory - eg
C:\Users\Administrator\AppData\Local\Plex Media Server\DVR-Curl-Tests

For the curl request you will need the server token to put in the curl request. To find a server token, see https://support.plex.tv/articles/200890058-require-authentication-for-local-network-access/

The test in curl would basically try to capture the stream from a channel from the tuner (whilst Plex Media Server is running - but not using any tuner)

So start a command line window

cd to the directory you saved curl.exe in
CD C:\Users\Administrator\AppData\Local\Plex Media Server\DVR-Curl-Tests

Then prepare this text to paste into the window

curl.exe "http://127.0.0.1:32600/devices/dvb%23sat2ip%230%23uuid%3a663d5d6c-f9f8-4bb4-84d4-C80E1466A4A8/media/triplet%3A%2F%2F1%3A1079%3A11170?param=%3C%3Fxml%20version%3D%221%2E0%22%20encoding%3D%22UTF-8%22%3F%3E%0A%3Ctunedata%3E%3Ctt%3E2%3C%2Ftt%3E%3Cdq%3E0%3C%2Fdq%3E%3Cdr%2F%3E%3Cfr%3E450000%3C%2Ffr%3E%3Cmd%3E0%3C%2Fmd%3E%3Csr%3E6900000%3C%2Fsr%3E%3Cpl%3E0%3C%2Fpl%3E%3Clf%3E5%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%3E1079%3C%2Ft%3E%3Cn%3E1%3C%2Fn%3E%3Cs%3E11170%3C%2Fs%3E%3Cen%3E0%3C%2Fen%3E%3C%2Ftunedata%3E%0A&X-Plex-Token=xxxxxxxxxxxxxxxxxx" > DVRChanGrab.ts
The xxxxxxxxxxxxxxxxxx at the end you need to replace with the server token string

When you have that text ready including the quotes - paste into the command line window and press Enter key

If it is successful, you will see the time and size incrementing as it writes the stream capture to the file DVRChanGrab.ts in that directory
You can break-in after few minutes and check the file with a video player

The above capture is for the specific channel that failed

5

You mentioned in the title that DVR Bug - transcoder error until server restart

Problems like this have been seen to arise due to previous use of tuner that did not get tidied up properly - eg watching a live tv channel beforehand. There it is very important to see all the log files - ideally since the last launch of Plex Media Server to see what previous actions were for the tuner and channel

So even though i asked for the curl test, i still want to see the whole set of logs. May be increase the number of log files, using LogNumFiles registry setting - see https://support.plex.tv/articles/201105343-advanced-hidden-server-settings/ and restart server and on next failure downloads the logs zip and attach with details of fail and time

6

Thank you for your help. Much aprrecieated.

I sent a message to you containing the logs from today before the regular server restart, a couple of minutes after I discovered, that the 10 am recording failed due to transcoder error

For the tests, I’d like to wait for you to have a look at the full logs, first, if that is okay…

7

I have been looking at the logs

You had three back to back recordings on the same channel - channel 601

Nov 05, 2018 20:15:00  channel 601. 1 hour to 21:15:00
Nov 05, 2018 21:15:00. channel 601. 55 mins to 22:10:00
Nov 05, 2018 22:10:00  channel 601. 1 hour to 23:10:00

and the one after these failed. It was scheduled for

Nov 06, 2018 10:00:00  channel 579. 45 mins

Can see this error

Nov 06, 2018 10:00:43.862 [3184] WARN - [E] http_streamer_t: http write error

There was a similar error at the end of the last element of the three back-to-back recordings

Nov 05, 2018 23:10:04.044 [3164] WARN - [E] http_streamer_t: http write error

This was after 1055 requests for the 3 recordings

Nov 05, 2018 23:09:56.825 [3324] DEBUG - [I] sat2ip_streamer::sat2ip_send_command. Request: OPTIONS rtsp://192.168.94.254/ RTSP/1.0
CSeq: 1055
Session: 537

You mentioned one stream allowed by the tuner. Do you have anything else that may be sending requests to 192.168.94.254 ?

I would like to offer you a development alpha build that had a number of fixes and improvements to see if it makes a difference

What is the actual tuner?

8

Unrelated to this - i have noticed lots of SQL errors in the log when attempting to view a TV Shows library with a sort of unwatched items

I believe it is a minor issue. Could you send me zip of the database by Private Message ?

Nov 06, 2018 10:23:24.212 [1328] DEBUG - Request: [192.168.94.124:56517 (Subnet)] GET /library/sections/3/firstCharacter?type=2&sort=unviewedLeafCount%3Adesc&includeCollections=1 (9 live) GZIP Signed-in Token (rossinior)
Nov 06, 2018 10:23:24.212 [1328] ERROR - SQLITE3:0xbbe3e096, 1, near ",": syntax error
Nov 06, 2018 10:23:24.212 [1328] ERROR - Soci Exception handled: sqlite3_statement_backend::prepare: near ",": syntax error for SQL: select upper(substr((select, 1, 1)) as c,count(distinct metadata_items.id) from metadata_items  left join metadata_item_settings on metadata_item_settings.guid=metadata_items.guid and metadata_item_settings.account_id= 1 where metadata_items.library_section_id=?  and metadata_items.library_section_id in (3) and metadata_items.metadata_type=2  group by c order by c
Nov 06, 2018 10:23:24.212 [2936] DEBUG - Completed: [192.168.94.124:56517] 500 GET /library/sections/3/firstCharacter?type=2&sort=unviewedLeafCount%3Adesc&includeCollections=1 (9 live) GZIP 5ms 405 bytes (pipelined: 3)
9

My tuner is: Fritz!Box 6490 Cable (community supported).

It can handle up to four streams, but only one per IP address.

What you see, is what I experience each day. After a fresh restart of the server system, I can record the whole day. But at some point overnight, there must something be happening (or I do it), so from that server - I get the transcoder error on EACH attempt of recording - whether or not I do recordings from my other two (QNAP Linux) PMS systems.

So, you are probably right that it has something to do with some other recording not being finished correctly, or some other transcoder task breaking its DVR functionality.

But I doubt, that it has something to do with other PMS recordings (three PMS with three different IP addresses in total - all of them carefully obeying the rule - only one recording at a time). Of course, I have seen spontaneous recording attempts of an episode, so I cannot be sure.

I’d prefer not to work with an alpha version of the PMS if the Plex Pass beta is around the corner. I do a nightly restart of the server each night by now. I am not totally against it, but I really fear that it breaks further functionality…

But I still would be happy to help you finding the root of this problem.

10

Just to say, I have just had the same error - everything has been working fine until now, but two recordings failed. I did a test recording and it failed immediately. Once I restarted the service, everything went back to normal.

The corresponding line from the tuner log:

Nov 09, 2018 09:19:04.561 [0x7f088af1f700] INFO - [I] device_manager_t::get_device_list. Device dualHD, id dvb#v4l#0#/sys/devices/pci0000:00/0000:00:15.0/usb1/1-3/1-3:1.0:0, tuners 1, state 2, standards 3
Nov 09, 2018 09:19:04.566 [0x7f088af1f700] INFO - [I] device_manager_t::get_device_list. Device dualHD, id dvb#v4l#0#/sys/devices/pci0000:00/0000:00:15.0/usb1/1-3/1-3:1.0:1, tuners 1, state 2, standards 3
Nov 09, 2018 09:19:04.670 [0x7f088af1f700] WARN - [E] web_service_t::process_start_channel. No available tuners found to start streaming channel triplet://9018:12293:12992 on device compound_device072dvb#v4l#/sys/devices/pci0000:00/0000:00:15.0/usb1/1-3/1-3:1.0:0014037372

I would guess that sa2000 is correct, that something is keeping the service open. The last thing to record succesfully, seemed to close down the tuner fine (as far as the logs are concerned);

Nov 07, 2018 22:55:01.805 [0x7f0842ffd700] INFO - [I] Stopping graph
Nov 07, 2018 22:55:01.834 [0x7f08437fe700] INFO - [I] Stop device request for tuner 1, frontend 0
Nov 07, 2018 22:55:01.842 [0x7f08597fa700] INFO - [I] Exiting streaming thread for tuner 1, frontend 0
Nov 07, 2018 22:55:05.023 [0x7f088bf21700] INFO - [I] device_manager_t::idle_timer_func. Device dvb#v4l#0#/sys/devices/pci0000:00/0000:00:15.0/usb1/1-3/1-3:1.0:1 is idle. Unloading it.
Nov 07, 2018 22:55:05.023 [0x7f088bf21700] INFO - [I] transponder_streamer::stop_idle_timer
Nov 07, 2018 22:55:05.023 [0x7f088bf21700] INFO - [I] CTVSStreamSource::Term. Waiting for streaming thread to stop
Nov 07, 2018 22:55:05.054 [0x7f08437fe700] INFO - [I] Stop device request for tuner 65535, frontend 0
Nov 07, 2018 22:55:05.055 [0x7f088bf21700] INFO - [I] CTVSStreamSource::Term. Streaming is stopped
Nov 07, 2018 22:55:05.055 [0x7f088bf21700] INFO - [I] CTVSStreamSource::Term. Stream source is stopped
Nov 07, 2018 22:55:05.843 [0x7f0842ffd700] INFO - [I] transponder_streamer::idle_thread_func finished

But the next one was unable to open the tuner service.

11

Plex Media Server logs please that go with that Plex Tuner Service log

Cannot investigate issues without the full logs zip

I suggest we wait until the next beta goes out which will be soon - there are some fixes to do with earlier live tv sessions impacting recordings later.

12

Sorry I did not come back to you on this. It does not appear to have an impact and this arises when viewing sort / filter is for Unplayed - as far as can be seen there is no impact. It has been raised a low severity issue with the development team

13

Thank you for catching up on this. I appreciate.

BTW, regarding transcoder errors… I know that the time limit for “switching” to a channel that is to be recorded has been raised. For my tuners and some channels (for HD channels mostly), the time still is not enough - sometimes by far.

Why there’s such a limit at all? If it takes a minute to start caching/recording… be it.

14

I presume you are referring to the initial timeout on tuning a channel which got increased from 5 seconds to 15 seconds

If there is evidence of it needing to be longer then i can raise this with the development team. Probably would need logs and if networked then probably wireshark capture of the tune action

15

Ok, perfect test:

I restarted the Windows 2012 Server (which is one of my Plex Media Servers) this morning…
I started PMS Software at 9:29 local time.

It started an automatic EPG update which had finished by around 9:34.

Today’s schedule:
10:30 - 11:13 channel 579 ZDFINHD (German HD channel)
12:00 - 13:28 channel 579 ZDFINHD
20:15 - 22:05 channel 202 TELE5GR (non-HD channel)
22:05 - 00:05 channel 202 TELE5GR

Today’s concurring recordings from OTHER PMS:
22:15 - 23:15 channel 503 DMAXD (non-HD channel) (other PMS, same tuner)
23:15 - 00:15 same channel (other PMS, same tuner)
–> no concurring recordings or TV uses in the morning.

I used Plex web to test Live TV on both channels (579 ZDFINHD, 202 TELE5GR) to see whether they are reachable.

They were… the results for Live TV test:
09:36 - 09:40 click on “Play channel 579” near the channel logo, watch Live TV for a couple of minutes… the channel pauses from time to time, the buffering wheel is shown on a number of occasions, but is viewable via Plex Web.
09:41 - 09:43 click on “Play channel 202” near the channel logo, no further stuttering, watch Live TV for a couple of minutes, seems okay.

Then left it alone till 10:40… just to see that the 10:30 scheduled recording failed due to a transcoder error:

schedule
schedule.jpg680×531 99.3 KB

Error
Error.jpg896×537 82.4 KB

I send the PMS Server logs to you @sa2000 via private message in a minute. - EDIT: Done.

16

… oh, the second recording failed with the same message. No time for server logs this time.

17

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