DVR recording failing

General Discussions Plex Features
1

I have Plex.TV running on a QNAP, with an HDHomeRun tuner. I can see live TV. Schedule programs, manually start recordings. But none of my recordings ever make it to my DVR directory (which I set up). Interestingly, I do see some in the .grab subfolder.

Looking at the log, the only problems I can see are that - DVR:Subscription: Failed to resolve subscription for 'grandparentGuid: com.gracenote.onconnect://show/10621776 - as you can see below.

But none of my scheduled recordings ever end up in the main folder. Permissions are all set, the folder is open to anyone to read and write.

Any thoughts?

Thanks!

ov 11, 2017 13:57:00.180 [0x7f93bf00d700] DEBUG - DVR:Grabber: Starting operation for ‘Weather World - Episode 11-11’.
Nov 11, 2017 13:57:00.183 [0x7f93bf00d700] DEBUG - Activity: registered new activity 5c3a06bf-d498-4a30-8b8d-f7c96a2359e9 - Recording
Nov 11, 2017 13:57:00.183 [0x7f93bf00d700] DEBUG - DVR:Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/1056FD08 (Silicondust HDHomeRun EXTEND, supported) tuner 1.
Nov 11, 2017 13:57:00.191 [0x7f93bf00d700] DEBUG - DVR:Subscription: Failed to resolve subscription for ‘grandparentGuid: com.gracenote.onconnect://show/10621776 grandparentThumb: http://tmsimg.plex.tv/assets/p10621776_i_v8_aa.jpg grandparentTitle: Weather World grandparentYear: 2014 guid: com.gracenote.onconnect://episode/10621776/2017-11-11 originallyAvailableAt: 2017-11-11 parentIndex: 2017 title: type: 4 year: 2017’ to library item
Nov 11, 2017 13:57:00.193 [0x7f93bf00d700] DEBUG - DVR:Grabber: Saving recording to /share/CACHEDEV1_DATA/Multimedia/videos/DVR/.grab/241b54f1c50398dd7e60e8059f96e4bfd46fc073
Nov 11, 2017 13:57:00.231 [0x7f93bf00d700] DEBUG - HTTP requesting GET http://192.168.2.133:80/lineup.json
Nov 11, 2017 13:57:00.268 [0x7f93bf00d700] DEBUG - HTTP 200 response from GET http://192.168.2.133:80/lineup.json
Nov 11, 2017 13:57:00.270 [0x7f93bf00d700] DEBUG - DVR:Grabber: Going to record for 180 seconds, final URL is http://192.168.2.133:5004/auto/v60.2?transcode=heavy
Nov 11, 2017 13:57:00.272 [0x7f93bf00d700] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘Weather World - Episode 11-11’ in 180 seconds.
Nov 11, 2017 13:57:00.272 [0x7f93bf00d700] DEBUG - DVR:Segmenter: Creating a new recorder for http://192.168.2.133:5004/auto/v60.2?transcode=heavy.
Nov 11, 2017 13:57:00.348 [0x7f93bf00d700] DEBUG - DVR:Grabber: Waiting for a tuner (0 available).
Nov 11, 2017 13:57:00.349 [0x7f93b7d59700] DEBUG - buildLiveM3U8: min 0 max 1234
Nov 11, 2017 13:57:00.779 [0x7f93bea31700] DEBUG - buildLiveM3U8: min 0 max 274
Nov 11, 2017 13:57:01.358 [0x7f93c1623700] DEBUG - buildLiveM3U8: min 0 max 1234
Nov 11, 2017 13:57:01.763 [0x7f93b03ff700] DEBUG - EPG[onconnect]: Next thing to start/end is at 2017-11-11 22:00:00 (in 180 seconds)
Nov 11, 2017 13:57:01.784 [0x7f93ae9a1700] DEBUG - buildLiveM3U8: min 0 max 274
Nov 11, 2017 13:57:02.367 [0x7f93b8911700] DEBUG - buildLiveM3U8: min 0 max 1234
Nov 11, 2017 13:57:02.788 [0x7f93b7a6b700] DEBUG - buildLiveM3U8: min 0 max 274
Nov 11, 2017 13:57:03.183 [0x7f93b8bff700] DEBUG - Activity: updated activity 5c3a06bf-d498-4a30-8b8d-f7c96a2359e9 - completed 1% - Recording
Nov 11, 2017 13:57:03.376 [0x7f93c01a1700] DEBUG - buildLiveM3U8: min 0 max 1234
Nov 11, 2017 13:57:03.792 [0x7f93c75e7700] DEBUG - buildLiveM3U8: min 0 max 274
Nov 11, 2017 13:57:04.160 [0x7f93c8bff700] DEBUG - handleStreamRead code 335544539: short read
Nov 11, 2017 13:57:04.173 [0x7f93c8bff700] DEBUG - Auth: authenticated user 1 as xxxxxx
Nov 11, 2017 13:57:04.174 [0x7f93c0d59700] DEBUG - Request: [192.168.2.35:49737 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (14 live) TLS GZIP Signed-in Token (xxxxxx)
Nov 11, 2017 13:57:04.175 [0x7f93c0d59700] DEBUG - Beginning read from two-way stream.

Nov 11, 2017 14:00:00.184 [0x7f93bfeb3700] DEBUG - Activity: registered new activity 9bccf80d-e019-4509-be31-7b4a46e1147e - Recording
Nov 11, 2017 14:00:00.184 [0x7f93bfeb3700] DEBUG - DVR:Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/1056FD08 (Silicondust HDHomeRun EXTEND, supported) tuner 1.
Nov 11, 2017 14:00:00.184 [0x7f93b8bff700] DEBUG - Activity: updated activity 5c3a06bf-d498-4a30-8b8d-f7c96a2359e9 - completed 100% - Recording
Nov 11, 2017 14:00:00.192 [0x7f93bfeb3700] DEBUG - DVR:Subscription: Failed to resolve subscription for ‘grandparentGuid: com.gracenote.onconnect://show/13532017 grandparentThumb: http://tmsimg.plex.tv/assets/p13532017_b_v8_aa.jpg grandparentTitle: Guitars & Swim-Up Bars grandparentYear: 2016 guid: com.gracenote.onconnect://episode/13532017/2017-11-11 originallyAvailableAt: 2017-11-11 parentIndex: 2017 title: type: 4 year: 2017’ to library item
Nov 11, 2017 14:00:00.193 [0x7f93bfeb3700] DEBUG - DVR:Grabber: Saving recording to /share/CACHEDEV1_DATA/Multimedia/videos/DVR/.grab/22c619486ba0fd526ba88093c9ce475c436a5447
Nov 11, 2017 14:00:00.194 [0x7f93bfeb3700] DEBUG - DVR:Grabber: Going to record for 3600 seconds, final URL is http://192.168.2.133:5004/auto/v28.15?transcode=heavy
Nov 11, 2017 14:00:00.196 [0x7f93bfeb3700] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘Guitars & Swim-Up Bars - Episode 11-11’ in 3600 seconds.
Nov 11, 2017 14:00:00.196 [0x7f93bfeb3700] DEBUG - DVR:Segmenter: Creating a new recorder for http://192.168.2.133:5004/auto/v28.15?transcode=heavy.
Nov 11, 2017 14:00:00.263 [0x7f93bfeb3700] DEBUG - DVR:Grabber: Waiting for a tuner (0 available).
Nov 11, 2017 14:00:00.272 [0x7f93c077d700] DEBUG - DVR:Grabber: Cancelling operation for ‘Weather World - Episode 11-11’ with status complete.
Nov 11, 2017 14:00:00.272 [0x7f93c077d700] DEBUG - DVR:Grabber: Operation was active, stopping recorder.
Nov 11, 2017 14:00:00.272 [0x7f93c077d700] DEBUG - DVR:Recorder: Asked to stop recording ‘Weather World - Episode 11-11’.
Nov 11, 2017 14:00:01.939 [0x7f93af847700] DEBUG - EPG[onconnect]: Next thing to start/end is at 2017-11-11 22:10:00 (in 600 seconds)
Nov 11, 2017 14:00:04.328 [0x7f93c8911700] DEBUG - handleStreamRead code 335544539: short read
Nov 11, 2017 14:00:04.335 [0x7f93c8911700] DEBUG - Auth: authenticated user 1 as xxxxxx
Nov 11, 2017 14:00:04.335 [0x7f93c1623700] DEBUG - Request: [192.168.2.35:49774 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (14 live) TLS GZIP Signed-in Token (xxxxxx)
Nov 11, 2017 14:00:04.336 [0x7f93c1623700] DEBUG - Beginning read from two-way stream.
Nov 11, 2017 14:00:18.186 [0x7f93b03ff700] DEBUG - Activity: updated activity a36b334e-6580-4f22-bb52-b9a8bd4292d8 - completed 43% - Recording
Nov 11, 2017 14:00:19.677 [0x7f93afb35700] DEBUG - Statistics: Flushing 2 expired bandwidth entries, 0 expired media entries.
Nov 11, 2017 14:00:24.336 [0x7f93c8bff700] DEBUG - handleStreamRead code 335544539: short read
Nov 11, 2017 14:00:24.709 [0x7f93c8bff700] DEBUG - Auth: authenticated user 1 as xxxxxx
Nov 11, 2017 14:00:24.710 [0x7f93bea31700] DEBUG - Request: [192.168.2.35:49777 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (7 live) TLS GZIP Signed-in Token (xxxxxx)
Nov 11, 2017 14:00:24.711 [0x7f93bea31700] DEBUG - Beginning read from two-way stream.
Nov 11, 2017 14:00:36.187 [0x7f93b8bff700] DEBUG - Activity: updated activity 9bccf80d-e019-4509-be31-7b4a46e1147e - completed 1% - Recording
Nov 11, 2017 14:00:44.711 [0x7f93c8911700] DEBUG - handleStreamRead code 335544539: short read
Nov 11, 2017 14:00:44.723 [0x7f93c8911700] DEBUG - Auth: authenticated user 1 as xxxxxx
Nov 11, 2017 14:00:44.724 [0x7f93bea31700] DEBUG - Request: [192.168.2.35:49782 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (7 live) TLS GZIP Signed-in Token (xxxxxx)

2

Hi there,

DVR:Subscription: Failed to resolve subscription for 'grandparentGuid: com.gracenote.onconnect://show/10621776

…is a standard error having to do with Gracenote that shouldn’t cause this to happen. Could you attach your full PMS logs (the zip file) ? Thank you.

3

Sure, here they are!

4

Interestingly, a movie recorded last night and went into the movie folder just fine. It’s just that TV Shows don’t end up in either the TV SHOW Folder or the new “DVR” folder I set up for TV Shows.

5

@jlouderb said:
Interestingly, a movie recorded last night and went into the movie folder just fine. It’s just that TV Shows don’t end up in either the TV SHOW Folder or the new “DVR” folder I set up for TV Shows.

It’s possible the issue you’re experiencing has already been fixed in an upcoming release of PMS. The fix is currently in testing and we’re hoping the release will go out very soon.

6

Thanks. Sounds like the bug I’ve seen reported here a few times. I will wait until the next release, thanks!

7

This morning’s Beta Channel version of PMS (1.10.0.4516) has several DVR fixes in it. While it doesn’t cover every scenario reported here, it does include the most commonly reported issue, the “100% stuck recording.” There are some additional issues covered in the forums related to failed DVR recordings and those continue to be actively investigated.