Hi,
I’ve recently run into some issues using Plex DVR where a show will occasionally not record, and Plex will present an unknown error. I’ve done a bit of digging before posting here, so I’ll do my best to present the issue I’m having.
My Setup:
I’m running Plex Server v1.7.6.4058 on Fedora 26, 64 bit version. I have three Silicon Dust tuners, the Dual (HDHR3-US), CONNECT (HDHR4-2US) and EXTEND (HDTC-2US). I have one library for recording movies and another for recording TV shows.
My Issue:
Occasionally a recording will fail, and Plex will show the recording (Recording Schedule view) with a yellow triangle with exclamation mark indicating an issue. This issue is thrown within only a few minutes after the recording should have started, and Plex will report the error “an unknown error occurred”. Other recordings will continue at the same time without issue. Pictures below:
Error shown in Recording Schedule
More specific details on Modern Family error
More specific details on Stargate SG1 error
My Investigation:
I know the original Plex DVR solution only supported the SiliconDust tuners with DLNA support, which the Dual does not have. Initially I removed the Dual from my available tuners leaving only the EXTEND and CONNECT for recording to see if it was related to DLNA support. The specific example and screen shots shown in this post are from the configuration of the EXTEND + CONNECT (no DUAL).
During the issue shown above, four programs were scheduled to be recorded simultaneously, which should require all available tuners. Two of the programs succeeded and two failed, so I immediately looked for a trend.
I first checked to make sure there weren’t any folder permission issues. All folders had the correct permissions, and I could see that Plex recently recorded an episode of each series successfully:
My next thought was to review tuner status. Plex presented this for tuner status:
It appears that 1 tuner from each device is used, but upon further investigation it appears this is inaccurate:
Each SiliconDust tuner has a built in web server which provides basic information, including the status of the tuners. Here it is clear that 1 device (192.168.2.55, EXTEND) has both tuners utilized while the other (192.168.2.56, CONNECT) is completely dormant. Interesting. I double checked the Plex status and it was still showing that 1 tuner from each device was used.
I tested the dormant tuner with the HDHomerun application on a Windows 10 machine and confirmed it was functional. Since both tuners are fully functional for other clients, onto the Plex logs.
The two programs that failed were the following:
Modern Family - E1 - A Tale of Three Cities
Stargate SG-1 - E15 - Paradise Lost
I was able to find both in the logs (see attached file) with some related error messages. Here are some short excerpts:
For the Stargate episode, I found the following:
Jul 19, 2017 21:02:00.915 [0x7fd8607f6700] ERROR - [Transcoder] http://192.168.2.55:5004/auto/v47.2: Server returned 5XX Server Error reply
Jul 19, 2017 21:02:00.916 [0x7fd8807ff700] ERROR - JobManager: child process returned: 1 (Operation not permitted)
Jul 19, 2017 21:02:00.916 [0x7fd8807ff700] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 4365 is 1
Jul 19, 2017 21:02:00.916 [0x7fd8647fe700] DEBUG - Using default transcode duration of 120 minutes
Jul 19, 2017 21:02:00.916 [0x7fd8647fe700] DEBUG - Started session successfully: 564e52fb-524e-4a5d-b5ac-19216736589e
Jul 19, 2017 21:02:00.916 [0x7fd8647fe700] DEBUG - DVR:Recorder: It took 0.0 sec to start the session for http://192.168.2.55:5004/auto/v47.2
Jul 19, 2017 21:02:00.916 [0x7fd8647fe700] ERROR - Unable to find title for item of type 5
Jul 19, 2017 21:02:00.916 [0x7fd8647fe700] DEBUG - MDE: analyzing media item -1
Jul 19, 2017 21:02:00.916 [0x7fd8647fe700] ERROR - MDE: video has neither a video stream nor an audio stream
Jul 19, 2017 21:02:00.916 [0x7fd8647fe700] DEBUG - MDE: ignoring media item -1
Jul 19, 2017 21:02:00.916 [0x7fd8647fe700] ERROR - MDE: no compatible media decisions are available
Jul 19, 2017 21:02:00.916 [0x7fd8647fe700] ERROR - DVR:Recorder: Unable to compute media decision.
Jul 19, 2017 21:02:00.917 [0x7fd8647fe700] ERROR - DVR:Recorder: Error 14 (An unknown error occurred) starting the record, shutting things down.
Jul 19, 2017 21:02:00.917 [0x7fd8647fe700] DEBUG - DVR:Recorder: Asked to stop recording ‘Stargate SG-1 - E15 - Paradise Lost’.
Jul 19, 2017 21:02:00.917 [0x7fd8647fe700] DEBUG - DVR:Recorder: Stopping transcode session.
Jul 19, 2017 21:02:00.917 [0x7fd8647fe700] DEBUG - Killing job.
Jul 19, 2017 21:02:00.917 [0x7fd8647fe700] DEBUG - Signalling job ID 4365 with 9
Jul 19, 2017 21:02:00.917 [0x7fd8647fe700] DEBUG - Job was already killed, not killing again.
Jul 19, 2017 21:02:00.917 [0x7fd8647fe700] DEBUG - Stopping transcode session 564e52fb-524e-4a5d-b5ac-19216736589e
Jul 19, 2017 21:02:00.917 [0x7fd8647fe700] DEBUG - DVR:Grabber: Freed a tuner (now 1 available)
Jul 19, 2017 21:02:00.917 [0x7fd8647fe700] DEBUG - DVR:Grabber: Operation for Stargate SG-1 - E15 - Paradise Lost completed with status error (An unknown error occurred)
For the Modern Family episode, the following:
Jul 19, 2017 21:02:00.755 [0x7fd864fff700] ERROR - [Transcoder] http://192.168.2.55:5004/auto/v8.1?transcode=heavy: Server returned 5XX Server Error reply
Jul 19, 2017 21:02:00.756 [0x7fd8807ff700] ERROR - JobManager: child process returned: 1 (Operation not permitted)
Jul 19, 2017 21:02:00.756 [0x7fd8807ff700] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 4362 is 1
Jul 19, 2017 21:02:00.756 [0x7fd8723fe700] DEBUG - Using default transcode duration of 120 minutes
Jul 19, 2017 21:02:00.757 [0x7fd8723fe700] DEBUG - Started session successfully: a175f7b6-8df8-4391-ac52-15e94f221a6c
Jul 19, 2017 21:02:00.757 [0x7fd8723fe700] DEBUG - DVR:Recorder: It took 0.1 sec to start the session for http://192.168.2.55:5004/auto/v8.1?transcode=heavy
Jul 19, 2017 21:02:00.757 [0x7fd8723fe700] ERROR - Unable to find title for item of type 5
Jul 19, 2017 21:02:00.757 [0x7fd8723fe700] DEBUG - MDE: analyzing media item -1
Jul 19, 2017 21:02:00.757 [0x7fd8723fe700] ERROR - MDE: video has neither a video stream nor an audio stream
Jul 19, 2017 21:02:00.757 [0x7fd8723fe700] DEBUG - MDE: ignoring media item -1
Jul 19, 2017 21:02:00.757 [0x7fd8723fe700] ERROR - MDE: no compatible media decisions are available
Jul 19, 2017 21:02:00.757 [0x7fd8723fe700] ERROR - DVR:Recorder: Unable to compute media decision.
Jul 19, 2017 21:02:00.757 [0x7fd8723fe700] ERROR - DVR:Recorder: Error 14 (An unknown error occurred) starting the record, shutting things down.
Jul 19, 2017 21:02:00.757 [0x7fd8723fe700] DEBUG - DVR:Recorder: Asked to stop recording ‘Modern Family - E1 - A Tale of Three Cities’.
Jul 19, 2017 21:02:00.757 [0x7fd8723fe700] DEBUG - DVR:Recorder: Stopping transcode session.
Jul 19, 2017 21:02:00.757 [0x7fd8723fe700] DEBUG - Killing job.
Jul 19, 2017 21:02:00.758 [0x7fd8723fe700] DEBUG - Signalling job ID 4362 with 9
Jul 19, 2017 21:02:00.758 [0x7fd8723fe700] DEBUG - Job was already killed, not killing again.
Jul 19, 2017 21:02:00.758 [0x7fd8723fe700] DEBUG - Stopping transcode session a175f7b6-8df8-4391-ac52-15e94f221a6c
Jul 19, 2017 21:02:00.758 [0x7fd8723fe700] DEBUG - DVR:Grabber: Freed a tuner (now 1 available)
Jul 19, 2017 21:02:00.758 [0x7fd8723fe700] DEBUG - DVR:Grabber: Operation for Modern Family - E1 - A Tale of Three Cities completed with status error (An unknown error occurred)
I notice two things immediately:
- The EXTEND tuner is being directed to transcode=heavy
- The failed tuning appears to be occurring on the EXTEND tuner only (192.168.2.55). This is the same tuner that is successfully recording my two other shows. The only action I see on the CONNECT tuner, which is dormant during the time that my shows failed to record, is a lineup.json request. I found this puzzling as the EXTEND tuner is obviously working for Plex (it’s successfully recording shows), and it seems like Plex never tried to utilize the CONNECT tuner which is sitting dormant.
I was able to confirm that the default setting for the EXTEND tuner is “Highest Quality”, not “Original Format”:
I’ve changed my EXTEND tuner transcode to “Original Format” to see if this has any impact.
My Ask/Question for the Plex Community:
Has anyone else experienced this issue? I’m not an expert on the Plex coding, but it appears Plex is attempting to over utilize the EXTEND device by utilizing a 3rd tuner (which is doesn’t have) while the CONNECT device remains dormant. (This may have nothing to do with the tuner type; this could be a device 1 vs. device 2 utilization issue). If Plex thought that both device 1 and device 2 still had an available tuner (as indicated above by the screen shot) when device 1 was actually fully loaded, I can see where there could be an issue.
Any assistance is greatly appreciated.
I’m happy to provide additional logs and information to expedite debugging this issue.
(Note: while writing this post I observed the same behavior again on another set of shows. Plex indicated that Device 1 and Device 2 were both using 1 tuner, but the EXTEND device was fully loaded. Two additional shows failed to record)
Thanks!