I’m having a problem where a scheduled recording was aborted for seemingly no reason. At the time this occurred another recording scheduled for a different channel started and completed successfully. The logs indicate that the recordings were scheduled on different tuners.
If anyone has any insight as to what is happening here I’d love to get this issue resolved. I’m including the relevant logs from both scheduled recordings, as well as the log from the HDHomerun Connect tuner.
I am running the following:
PMS 1.9.7.4441
Ubuntu 16.04.3 LTS
HDHomeRun Connect (Firmware 20170930)
Failed Recording:
Nov 15, 2017 19:00:00.546 [0x7fcdb23ff700] DEBUG - DVR:Grabber: Starting operation for 'Survivor - E8 - Playing With the Devil'.
Nov 15, 2017 19:00:00.555 [0x7fcdb23ff700] DEBUG - Activity: registered new activity 166ac809-defa-47df-b170-dd8aa8e1b475 - Recording
Nov 15, 2017 19:00:00.557 [0x7fcdb23ff700] DEBUG - DVR:Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/104D3D0E (Silicondust HDHomeRun CONNECT, supported) tuner 0.
Nov 15, 2017 19:00:00.561 [0x7fcdb23ff700] DEBUG - DVR:Subscription: Resolved subscription to library item 'Survivor' (24616)
Nov 15, 2017 19:00:00.571 [0x7fcdb23ff700] DEBUG - There were 1 top-level paths for Survivor.
Nov 15, 2017 19:00:00.709 [0x7fcdb23ff700] DEBUG - DVR:Grabber: Saving recording to /PLEX/TV/.grab/0899e038030dc6ce631b27d9b7dd0980f48074fb
Nov 15, 2017 19:00:00.852 [0x7fcdb23ff700] DEBUG - DVR:Grabber: Going to record for 3600 seconds, final URL is http://10.70.0.7:5004/auto/v48.3
Nov 15, 2017 19:00:00.856 [0x7fcdb23ff700] DEBUG - DVR:Grabber: Setting timer to stop grab of 'Survivor - E8 - Playing With the Devil' in 3600 seconds.
Nov 15, 2017 19:00:00.856 [0x7fcdb23ff700] ERROR - DVR:Recorder: Error 0 (Success) starting the record, shutting things down.
Nov 15, 2017 19:00:00.856 [0x7fcdb23ff700] DEBUG - DVR:Recorder: Stopping transcode session.
Nov 15, 2017 19:00:00.856 [0x7fcdb23ff700] DEBUG - Job was already killed, not killing again.
Nov 15, 2017 19:00:00.856 [0x7fcdb23ff700] DEBUG - Job was already killed, not killing again.
Nov 15, 2017 19:00:00.856 [0x7fcdb23ff700] DEBUG - DVR:Grabber: Freed a tuner (now 2 available)
Nov 15, 2017 19:00:00.856 [0x7fcdb23ff700] ERROR - DVR:Recorder: Error 0 (Success) starting the record, shutting things down.
Nov 15, 2017 19:00:00.857 [0x7fcdb23ff700] DEBUG - DVR:Grabber: Operation for Survivor - E8 - Playing With the Devil completed with status error (Success)
Nov 15, 2017 19:00:00.857 [0x7fcdb23ff700] DEBUG - Activity: Ended activity 166ac809-defa-47df-b170-dd8aa8e1b475.
Nov 15, 2017 19:00:00.857 [0x7fcdb23ff700] ERROR - DVR:Grabber: Starting media grab failed.
Successful Recording:
Nov 15, 2017 19:00:00.635 [0x7fcd9aff8700] DEBUG - DVR:Grabber: Starting operation for 'The Goldbergs - E7 - A Wall Street Thanksgiving'.
Nov 15, 2017 19:00:00.637 [0x7fcd9aff8700] DEBUG - Activity: registered new activity cb0f5021-7b45-4386-9d6a-81ae89a475df - Recording
Nov 15, 2017 19:00:00.639 [0x7fcd9aff8700] DEBUG - DVR:Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/104D3D0E (Silicondust HDHomeRun CONNECT, supported) tuner 1.
Nov 15, 2017 19:00:00.644 [0x7fcd9aff8700] DEBUG - DVR:Subscription: Resolved subscription to library item 'The Goldbergs (2013)' (22)
Nov 15, 2017 19:00:00.650 [0x7fcd9aff8700] DEBUG - There were 1 top-level paths for The Goldbergs (2013).
Nov 15, 2017 19:00:00.710 [0x7fcd9aff8700] DEBUG - DVR:Grabber: Saving recording to /PLEX/TV/.grab/160fd3eb5b01bd24767cb670719b4ff52ab7a865
Nov 15, 2017 19:00:00.852 [0x7fcd9aff8700] DEBUG - DVR:Grabber: Going to record for 1800 seconds, final URL is http://10.70.0.7:5004/auto/v7.1
Nov 15, 2017 19:00:00.856 [0x7fcd9aff8700] DEBUG - DVR:Grabber: Setting timer to stop grab of 'The Goldbergs - E7 - A Wall Street Thanksgiving' in 1800 seconds.
Nov 15, 2017 19:00:00.856 [0x7fcd9aff8700] DEBUG - DVR:Segmenter: Creating a new recorder for http://10.70.0.7:5004/auto/v7.1.
Nov 15, 2017 19:00:00.882 [0x7fcd9aff8700] DEBUG - DVR:Grabber: Waiting for a tuner (2 available).
Nov 15, 2017 19:00:00.882 [0x7fcd9aff8700] DEBUG - DVR:Grabber: Allocated a tuner (1 left)
Nov 15, 2017 19:00:00.936 [0x7fcd9aff8700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Nov 15, 2017 19:00:00.936 [0x7fcd9aff8700] DEBUG - Selecting best audio stream for part ID -1 (autoselect: 0 language: en)
Nov 15, 2017 19:00:00.937 [0x7fcd9aff8700] DEBUG - Audio Stream: -1, Subtitle Stream: -1
Nov 15, 2017 19:00:00.937 [0x7fcd9aff8700] ERROR - Unable to find title for item of type 5
Nov 15, 2017 19:00:00.944 [0x7fcd9aff8700] DEBUG - MDE: analyzing media item -1
Nov 15, 2017 19:00:00.945 [0x7fcd9aff8700] DEBUG - MDE: : no direct play video profile exists for http/mpegts/
Nov 15, 2017 19:00:00.945 [0x7fcd9aff8700] DEBUG - MDE: : no direct play video profile exists for http/mpegts//
Nov 15, 2017 19:00:00.945 [0x7fcd9aff8700] DEBUG - MDE: : codec is unavailable for analysis
Nov 15, 2017 19:00:00.945 [0x7fcd9aff8700] DEBUG - MDE: : codec is unavailable for analysis
Nov 15, 2017 19:00:00.955 [0x7fcd9aff8700] ERROR - Unable to find title for item of type 5
Nov 15, 2017 19:00:00.956 [0x7fcd9aff8700] DEBUG - MDE: : selected media 0 / -1
Nov 15, 2017 19:00:00.957 [0x7fcd9aff8700] DEBUG - Cleaning directory for session 9c99cef7-3428-416e-bc1b-3a892bf463d8 ()
Nov 15, 2017 19:00:00.998 [0x7fcd9aff8700] DEBUG - Starting a transcode session 9c99cef7-3428-416e-bc1b-3a892bf463d8 at offset -1.0 (state=3)
Nov 15, 2017 19:00:00.998 [0x7fcd9aff8700] DEBUG - Streaming Resource: Added session 0x7fcdac47a560:9c99cef7-3428-416e-bc1b-3a892bf463d8
Nov 15, 2017 19:00:01.003 [0x7fcd9aff8700] DEBUG - Job running: EAE_ROOT='/tmp/pms-900cbb5a-b553-4b5c-b56d-3f412a39d7a2/EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='/var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Codecs/a10855e-1258-linux-ubuntu-x86_64/' XDG_CACHE_HOME='/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/' XDG_DATA_HOME='/usr/lib/plexmediaserver/Resources/' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' '/usr/lib/plexmediaserver/Plex Transcoder' '-noaccurate_seek' '-ignore_unknown' '-scan_all_pmts' '-1' '-i' 'http://10.70.0.7:5004/auto/v7.1' '-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_copyts' '1' '-segment_time_delta' '0.0625' '-segment_list' 'http://127.0.0.1:32400/video/:/transcode/session/9c99cef7-3428-416e-bc1b-3a892bf463d8/46020fb7-0829-4a1b-bcb4-48f313124f93/seglist' '-segment_list_type' 'csv' '-segment_list_size' '2147483647' '-segment_list_separate_stream_times' '1' '-max_delay' '5000000' '-avoid_negative_ts' 'disabled' '-map_metadata' '-1' '-map_chapters' '-1' 'media-%05d.ts' '-start_at_zero' '-copyts' '-vsync' 'cfr' '-y' '-nostats' '-loglevel' 'quiet' '-loglevel_plex' 'error' '-progressurl' 'http://127.0.0.1:32400/video/:/transcode/session/9c99cef7-3428-416e-bc1b-3a892bf463d8/46020fb7-0829-4a1b-bcb4-48f313124f93/progress'
HDHomeRun Log:
20171116-01:00:01 Tuner: tuner0 tuning 7.1 WLS-HD (8vsb:653MHz-1)
20171116-01:00:01 Tuner: tuner0 streaming http to 10.70.0.14:47008
20171116-01:30:01 Tuner: tuner0 http stream ended (remote closed)
Please let me know if there is any additional information required from the logs and I would be happy to pull it up.
