First time using the Plex TV live feature, and I’m pulling my hair out trying to get this thing to stream. I’ve been able to add my tuner device and load channels/guide data, but every time I try to stream a channel it times out after exactly 30 seconds with an “unable to tune channel” error message. This occurs on multiple playback devices (web, nvidia shield tv, android).
Details:
- Latest Plex Media Server (1.13.5.5291)
- HDHomeRun Extend (HDTC-2US) running latest firmware (20180327), connected with antenna
I am able to capture and playback content from this tuner device using a desktop on the same network, so I know the video coming from the URL that Plex is pulling from (http://192.168.15.250:5004/auto/v3.1?transcode=heavy) is good.
The Plex Media Server logs seem to indicate that the failure is “DVR:Recorder: No part because session isn’t reporting one.” But I have no idea what this error message means.
Below are the debug error logs for the Plex Media Server during an attempted play. Can anyone help point me in the right direction for troubleshooting this issue?
Aug 17, 2018 08:36:27.776 [0x7f5ffd3fe700] DEBUG - Request came in with unrecognized domain / IP ‘XX.XXX.XX.XX’ in header Host; treating as non-local
Aug 17, 2018 08:36:27.776 [0x7f5ffd3fe700] DEBUG - Auth: authenticated user 1 as User
Aug 17, 2018 08:36:27.776 [0x7f5ffc3ff700] DEBUG - Request: [192.168.15.1:24788 (Allowed Network)] POST /livetv/dvrs/4/channels/3.1/tune (9 live) TLS GZIP Signed-in Token (User)
Aug 17, 2018 08:36:27.776 [0x7f5ffc3ff700] DEBUG - DVR:Subscription: Starting a new rolling subscription for session eqnahvnrjv6yld7c1ftozdsh channel 3.1.
Aug 17, 2018 08:36:27.892 [0x7f5ffc3ff700] DEBUG - Activity: registered new activity bee02d88-aded-4ba0-b8fc-20b926f361ce - Processing subscriptions
Aug 17, 2018 08:36:27.893 [0x7f5ffc3ff700] DEBUG - DVR:Subscription: Scheduling subscriptions.
Aug 17, 2018 08:36:27.895 [0x7f5ffc3ff700] DEBUG - DVR:Subscription: Initialized 1 schedulers.
Aug 17, 2018 08:36:27.895 [0x7f5ffc3ff700] DEBUG - DVR:Subscription: Starting with 0 grabs, scheduled 0 active ones preemptively.
Aug 17, 2018 08:36:27.895 [0x7f5ffc3ff700] DEBUG - DVR:Schedule: Attempting to schedule the item ‘Live TV - Session’.
Aug 17, 2018 08:36:27.895 [0x7f5ffc3ff700] DEBUG - DVR:Schedule: Trying airing at 2018-08-17 08:36:27 on channel 3.1.
Aug 17, 2018 08:36:27.895 [0x7f5ffc3ff700] DEBUG - DVR:Schedule: Device 0 tuner 0 scheduled recording between 2018-08-17 08:36:27 and 2018-08-17 08:41:27 on channel 3.1.
Aug 17, 2018 08:36:27.895 [0x7f5ffc3ff700] DEBUG - DVR:Grabber: Starting grab immediately for ‘Live TV - Session’ and we’re 0 seconds in already.
Aug 17, 2018 08:36:27.895 [0x7f5ffc3ff700] DEBUG - DVR:Subscription: Scheduled all subscriptions in 2 ms.
Aug 17, 2018 08:36:27.895 [0x7f5ffc3ff700] DEBUG - Activity: Ended activity bee02d88-aded-4ba0-b8fc-20b926f361ce.
Aug 17, 2018 08:36:27.895 [0x7f5ffc3ff700] DEBUG - DVR:Subscription: There are 1 grabs at the end.
Aug 17, 2018 08:36:27.895 [0x7f5ffc3ff700] DEBUG - DVR:Subscription: Waiting for media grab to start.
Aug 17, 2018 08:36:27.896 [0x7f5fecbff700] DEBUG - DVR:Grabber: Starting operation for ‘Live TV - Session’.
Aug 17, 2018 08:36:27.897 [0x7f5fecbff700] DEBUG - Activity: registered new activity 92d210fd-2b97-47be-8bc0-6611cae36b33 - Recording
Aug 17, 2018 08:36:27.898 [0x7f5fecbff700] DEBUG - DVR:Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/1056F0CB (Silicondust HDHomeRun EXTEND, supported) tuner 0.
Aug 17, 2018 08:36:27.898 [0x7f5fecbff700] DEBUG - DVR:Grabber: Creating custom segmented recorder for grab for channel 3.1
Aug 17, 2018 08:36:27.898 [0x7f5fecbff700] DEBUG - HTTP requesting GET http://192.168.15.250:80/lineup.json
Aug 17, 2018 08:36:27.930 [0x7f5fecbff700] DEBUG - HTTP 200 response from GET http://192.168.15.250:80/lineup.json
Aug 17, 2018 08:36:27.931 [0x7f5fecbff700] DEBUG - DVR:Segmenter: Creating a new recorder for http://192.168.15.250:5004/auto/v3.1?transcode=heavy.
Aug 17, 2018 08:36:27.934 [0x7f5fecbff700] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘Live TV - Session’ in 300 seconds.
Aug 17, 2018 08:36:27.934 [0x7f5fecbff700] DEBUG - DVR:Grabber: Waiting for a tuner (2 available).
Aug 17, 2018 08:36:27.934 [0x7f5fecbff700] DEBUG - DVR:Grabber: Allocated a tuner (1 left)
Aug 17, 2018 08:36:27.934 [0x7f5fecbff700] DEBUG - We’re going to try to auto-select an audio stream for account 1.
Aug 17, 2018 08:36:27.934 [0x7f5fecbff700] DEBUG - Selecting best audio stream for part ID -1 (autoselect: 1 language: en)
Aug 17, 2018 08:36:27.934 [0x7f5fecbff700] DEBUG - We’re going to try to auto-select a subtitle.
Aug 17, 2018 08:36:27.935 [0x7f5fecbff700] DEBUG - Audio Stream: -1, Subtitle Stream: -1
Aug 17, 2018 08:36:27.935 [0x7f5fecbff700] DEBUG - MDE: Selected protocol hls; container: mpegts
Aug 17, 2018 08:36:27.935 [0x7f5fecbff700] ERROR - Unable to find title for item of type 5
Aug 17, 2018 08:36:27.935 [0x7f5fecbff700] DEBUG - MDE: analyzing media item -1
Aug 17, 2018 08:36:27.935 [0x7f5fecbff700] DEBUG - MDE: : no direct play video profile exists for http/mpegts/
Aug 17, 2018 08:36:27.935 [0x7f5fecbff700] DEBUG - MDE: : no direct play video profile exists for http/mpegts//
Aug 17, 2018 08:36:27.935 [0x7f5fecbff700] DEBUG - MDE: : codec is unavailable for analysis
Aug 17, 2018 08:36:27.935 [0x7f5fecbff700] DEBUG - MDE: : codec is unavailable for analysis
Aug 17, 2018 08:36:27.935 [0x7f5fecbff700] ERROR - Unable to find title for item of type 5
Aug 17, 2018 08:36:27.935 [0x7f5fecbff700] DEBUG - MDE: : selected media 0 / -1
Aug 17, 2018 08:36:27.936 [0x7f5fecbff700] DEBUG - Cleaning directory for session 5b1ffcf0-4926-43f3-8e72-35b94cff728e ()
Aug 17, 2018 08:36:27.936 [0x7f5fecbff700] DEBUG - Starting a transcode session 5b1ffcf0-4926-43f3-8e72-35b94cff728e at offset -1.0 (state=3)
Aug 17, 2018 08:36:27.936 [0x7f5fecbff700] DEBUG - Streaming Resource: Added session 0x7f5feb621420:5b1ffcf0-4926-43f3-8e72-35b94cff728e
Aug 17, 2018 08:36:27.939 [0x7f5fecbff700] DEBUG - Job running: EAE_ROOT=’/tmp/pms-9ca934fc-0e1e-4430-84d9-7d44ed1b3f49/EasyAudioEncoder’ FFMPEG_EXTERNAL_LIBS=’/var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Codecs/e944d3a-1309-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’ ‘-rw_timeout’ ‘30000000’ ‘-fflags’ ‘+discardcorruptts+fillwallclockdts’ ‘-i’ ‘http://192.168.15.250:5004/auto/v3.1?transcode=heavy’ ‘-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.0625’ ‘-segment_list’ ‘http://127.0.0.1:32400/video/:/transcode/session/5b1ffcf0-4926-43f3-8e72-35b94cff728e/8b15d0b9-6751-489f-8fd3-7a163d6ba2c3/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/5b1ffcf0-4926-43f3-8e72-35b94cff728e/8b15d0b9-6751-489f-8fd3-7a163d6ba2c3/progress’
Aug 17, 2018 08:36:27.944 [0x7f5fecbff700] DEBUG - Jobs: Starting child process with pid 1742
Aug 17, 2018 08:36:30.898 [0x7f5fe07ff700] DEBUG - Activity: updated activity 92d210fd-2b97-47be-8bc0-6611cae36b33 - completed 1% - Recording
Aug 17, 2018 08:36:33.899 [0x7f5fe07ff700] DEBUG - Activity: updated activity 92d210fd-2b97-47be-8bc0-6611cae36b33 - completed 2% - Recording
Aug 17, 2018 08:36:36.899 [0x7f5fedbff700] DEBUG - Activity: updated activity 92d210fd-2b97-47be-8bc0-6611cae36b33 - completed 3% - Recording
Aug 17, 2018 08:36:39.900 [0x7f5fe07ff700] DEBUG - Activity: updated activity 92d210fd-2b97-47be-8bc0-6611cae36b33 - completed 4% - Recording
Aug 17, 2018 08:36:42.901 [0x7f5fe07ff700] DEBUG - Activity: updated activity 92d210fd-2b97-47be-8bc0-6611cae36b33 - completed 5% - Recording
Aug 17, 2018 08:36:45.901 [0x7f5fe07ff700] DEBUG - Activity: updated activity 92d210fd-2b97-47be-8bc0-6611cae36b33 - completed 6% - Recording
Aug 17, 2018 08:36:48.902 [0x7f5fe07ff700] DEBUG - Activity: updated activity 92d210fd-2b97-47be-8bc0-6611cae36b33 - completed 7% - Recording
Aug 17, 2018 08:36:51.902 [0x7f5fedbff700] DEBUG - Activity: updated activity 92d210fd-2b97-47be-8bc0-6611cae36b33 - completed 8% - Recording
Aug 17, 2018 08:36:54.903 [0x7f5fedbff700] DEBUG - Activity: updated activity 92d210fd-2b97-47be-8bc0-6611cae36b33 - completed 9% - Recording
Aug 17, 2018 08:36:57.201 [0x7f5ffb3ff700] DEBUG - Request: [34.244.6.8:35065 (WAN)] GET /identity (6 live) TLS Signed-in Token (User)
Aug 17, 2018 08:36:57.201 [0x7f5ffd3fe700] DEBUG - Completed: [34.244.6.8:35065] 200 GET /identity (6 live) TLS 1ms 357 bytes
Aug 17, 2018 08:36:57.903 [0x7f5fedbff700] DEBUG - Activity: updated activity 92d210fd-2b97-47be-8bc0-6611cae36b33 - completed 10% - Recording
Aug 17, 2018 08:36:57.948 [0x7f5fecbff700] DEBUG - Using default transcode duration of 120 minutes
Aug 17, 2018 08:36:57.948 [0x7f5fecbff700] DEBUG - Started session successfully: 5b1ffcf0-4926-43f3-8e72-35b94cff728e
Aug 17, 2018 08:36:57.948 [0x7f5fecbff700] DEBUG - DVR:Recorder: It took 30.0 sec to start the session for http://192.168.15.250:5004/auto/v3.1?transcode=heavy
Aug 17, 2018 08:36:57.949 [0x7f5fecbff700] DEBUG - DVR:Grabber: Merging EPG item with live item.
Aug 17, 2018 08:36:57.949 [0x7f5fecbff700] ERROR - DVR:Recorder: No part because session isn’t reporting one.
Aug 17, 2018 08:36:57.949 [0x7f5fecbff700] DEBUG - DVR:Grabber: Operation for Live TV - Session completed with status error (Could not start recording)
Aug 17, 2018 08:36:57.950 [0x7f5fecbff700] DEBUG - Activity: Ended activity 92d210fd-2b97-47be-8bc0-6611cae36b33.
Aug 17, 2018 08:36:57.950 [0x7f5fecbff700] DEBUG - DVR:Grabber: Cleaning up rolling grab for channel 3.1.
Aug 17, 2018 08:36:57.950 [0x7f5fecbff700] DEBUG - DVR:Recorder: Asked to stop recording ‘Live TV - Session’.
Aug 17, 2018 08:36:57.950 [0x7f5fecbff700] DEBUG - DVR:Recorder: Stopping transcode session.
Aug 17, 2018 08:36:57.950 [0x7f5fecbff700] DEBUG - Killing job.
Aug 17, 2018 08:36:57.950 [0x7f5fecbff700] DEBUG - Signalling job ID 1742 with 9
Aug 17, 2018 08:36:57.950 [0x7f5fecbff700] DEBUG - Job was already killed, not killing again.
Aug 17, 2018 08:36:57.950 [0x7f5fecbff700] DEBUG - Stopping transcode session 5b1ffcf0-4926-43f3-8e72-35b94cff728e
Aug 17, 2018 08:36:57.950 [0x7f5fedbff700] DEBUG - Cleaning directory for session 5b1ffcf0-4926-43f3-8e72-35b94cff728e (/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-5b1ffcf0-4926-43f3-8e72-35b94cff728e)
Aug 17, 2018 08:36:57.951 [0x7f5ff5bff700] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 1742 is -9 (signal: Killed)
Aug 17, 2018 08:36:57.952 [0x7f5fecbff700] DEBUG - DVR:Grabber: Freed a tuner (now 2 available)
Aug 17, 2018 08:36:57.952 [0x7f5ffc3ff700] ERROR - DVR:Subscription: Rolling media grab failed to start.
Aug 17, 2018 08:36:57.952 [0x7f5ffc3ff700] DEBUG - DVR:Grabber: Cancelling operation for ‘Live TV - Session’ with status cancelled.
Aug 17, 2018 08:36:57.952 [0x7f5ffc3ff700] DEBUG - DVR:Grabber: Operation was active, stopping recorder.
Aug 17, 2018 08:36:57.952 [0x7f5ffc3ff700] DEBUG - DVR:Grabber: We’ve cancelled the grab with 270 seconds remaining.
Aug 17, 2018 08:36:57.952 [0x7f5ffc3ff700] DEBUG - DVR:Grabber: Cleaning up rolling grab for channel 3.1.
Aug 17, 2018 08:36:57.952 [0x7f5ffc3ff700] DEBUG - DVR:Recorder: Asked to stop recording ‘Live TV - Session’.
Aug 17, 2018 08:36:57.954 [0x7f5ff9bff700] DEBUG - DVR:Grabber: Recording for ‘Live TV - Session’ stopped with status complete.
Aug 17, 2018 08:36:57.954 [0x7f5ff9bff700] DEBUG - DVR:Grabber: This was a rolling sub, not assimilating.
Aug 17, 2018 08:36:57.980 [0x7f5ffd3fe700] DEBUG - Request came in with unrecognized domain / IP ‘XX.XXX.XX.XX’ in header Host; treating as non-local
Aug 17, 2018 08:36:57.980 [0x7f5ffd3fe700] DEBUG - Auth: authenticated user 1 as User
Aug 17, 2018 08:36:57.981 [0x7f5fe63ff700] DEBUG - Request: [192.168.15.1:63099 (Allowed Network)] GET /status/sessions/background (7 live) TLS GZIP Signed-in Token (User)
Aug 17, 2018 08:36:57.983 [0x7f5ffd3fe700] DEBUG - Completed: [192.168.15.1:63099] 200 GET /status/sessions/background (6 live) TLS GZIP 3ms 470 bytes (pipelined: 1)
Aug 17, 2018 08:36:58.029 [0x7f5ffc3ff700] DEBUG - Activity: registered new activity cea156cb-b4a2-467a-8b3f-e1b9e9844614 - Processing subscriptions
Aug 17, 2018 08:36:58.029 [0x7f5ffc3ff700] DEBUG - DVR:Subscription: Scheduling subscriptions.
Aug 17, 2018 08:36:58.031 [0x7f5ffc3ff700] DEBUG - DVR:Subscription: Initialized 1 schedulers.
Aug 17, 2018 08:36:58.031 [0x7f5ffc3ff700] DEBUG - DVR:Subscription: Starting with 1 grabs, scheduled 0 active ones preemptively.
Aug 17, 2018 08:36:58.031 [0x7f5ffc3ff700] DEBUG - DVR:Subscription: Scheduled all subscriptions in 2 ms.
Aug 17, 2018 08:36:58.031 [0x7f5ffc3ff700] DEBUG - Activity: Ended activity cea156cb-b4a2-467a-8b3f-e1b9e9844614.
Aug 17, 2018 08:36:58.032 [0x7f5ffc3ff700] DEBUG - DVR:Subscription: There are 0 grabs at the end.
Aug 17, 2018 08:36:58.034 [0x7f5ffd3fe700] DEBUG - Completed: [192.168.15.1:24788] 200 POST /livetv/dvrs/4/channels/3.1/tune (6 live) TLS GZIP 30257ms 512 bytes (pipelined: 8)
Aug 17, 2018 08:36:58.039 [0x7f5ff9bff700] DEBUG - Activity: registered new activity 8392dba3-8750-4e63-b904-519812addaa4 - Processing subscriptions
Aug 17, 2018 08:36:58.039 [0x7f5ff9bff700] DEBUG - DVR:Subscription: Scheduling subscriptions.
Aug 17, 2018 08:36:58.041 [0x7f5ff9bff700] DEBUG - DVR:Subscription: Initialized 1 schedulers.
Aug 17, 2018 08:36:58.041 [0x7f5ff9bff700] DEBUG - DVR:Subscription: Starting with 0 grabs, scheduled 0 active ones preemptively.
Aug 17, 2018 08:36:58.041 [0x7f5ff9bff700] DEBUG - DVR:Subscription: Scheduled all subscriptions in 1 ms.
Aug 17, 2018 08:36:58.041 [0x7f5ff9bff700] DEBUG - Activity: Ended activity 8392dba3-8750-4e63-b904-519812addaa4.
Aug 17, 2018 08:36:58.041 [0x7f5ff9bff700] DEBUG - DVR:Subscription: There are 0 grabs at the end.
Aug 17, 2018 08:36:58.074 [0x7f5ffdbff700] DEBUG - EventSource: Got event [data] ‘’
Aug 17, 2018 08:36:58.074 [0x7f5ffd3fe700] DEBUG - EventSource: Got event [data] ‘’
Aug 17, 2018 08:36:58.075 [0x7f5ffdbff700] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (e26106fa-33b9-4042-a60f-06258e0931bf, expected )
Aug 17, 2018 08:36:58.075 [0x7f5ffdbff700] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (e26106fa-33b9-4042-a60f-06258e0931bf, expected 9adce917-d87a-419d-a6df-fd27d78b4df4)
Aug 17, 2018 08:36:58.075 [0x7f5ffd3fe700] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (e26106fa-33b9-4042-a60f-06258e0931bf, expected )
Aug 17, 2018 08:36:58.075 [0x7f5ffd3fe700] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (e26106fa-33b9-4042-a60f-06258e0931bf, expected 9adce917-d87a-419d-a6df-fd27d78b4df4)
Aug 17, 2018 08:36:58.934 [0x7f5ff7bff700] DEBUG - DVR:Recorder: Asked to stop recording ‘Live TV - Session’.
Aug 17, 2018 08:37:00.904 [0x7f5fe07ff700] DEBUG - Transcoder: Cleaning old transcode directories.
Aug 17, 2018 08:37:00.905 [0x7f5fe07ff700] DEBUG - Whacked session 5b1ffcf0-4926-43f3-8e72-35b94cff728e, 0 remaining.
Aug 17, 2018 08:37:00.906 [0x7f5fe07ff700] DEBUG - Streaming Resource: Terminated session 0x7f5feb621420:5b1ffcf0-4926-43f3-8e72-35b94cff728e with reason Client stopped playback.
Aug 17, 2018 08:37:00.906 [0x7f5fe07ff700] DEBUG - Streaming Resource: Removing session 0x7f5feb621420:5b1ffcf0-4926-43f3-8e72-35b94cff728e
Aug 17, 2018 08:37:00.906 [0x7f5fe07ff700] DEBUG - DVR:Subscription: Destroying rolling subscription for channel 3.1.