Repeated failure to record Chicago PD

Live TV & DVR
1

Server Version#: 1.30.2.6563
Player Version#: (All)
Tuner Make/Model: HDHomerun Do
Guide/Lineup name:
Using XMLTV?: No
Channel number/Name: KFOR-DT 004-01

Looking for some guidance here. Recently setup an HDHomerun Duo (static IP on network) and Plex DVR. Overall, it is working very well.
However, the last two weeks, Chicago PD has failed to record and shows the “!” in Plex. Chicago Med and Fire record without an issue. This tells me the channel and the tuner are working fine. Nothing else is set to record on Wednesday evenings, so two tuners should be sufficient as 1 can be used for Med, 2 for Fire, and then 1 (or 2) again for PD.

This happened the first week and I didn’t think anything of it - growing pains. It happened again last week, so I deleted and recreated the timer. It is still failing this week.

I’m struggling to find any reason in Plex to indicate what is going on. Where is a good place to start to see why this continues to fail? The only error I have been able to find says “There was a transcoder error”

Thanks for any help on this. It’s the last issue I need to resolve before moving exclusively to Plex for OTA recordings.

2

Anyone have any suggestions here? It worked for a week or two and is now failing again and I have no idea where to start to figure out why.

Server version is now 1.31.1.6716

3

Your logs can be downloaded by following the directions here: https://support.plex.tv/articles/200250417-plex-media-server-log-files/

Attach them in a reply to be reviewed for problems.

Without seeing the logs, the most common problem is running out of transcoder temporary storage space. If you are using a ramdisk/memory for the transcoder you should reconsider pointing to a local drive since TV&DVR can use up to 6 GB per hour per concurrent show.

Most Plex help documents can be found by Googling “Plex Support + Thing you have a question on”

4

Thank you for the reply. Are there certain log files within the zip file needed - I would prefer not to attach all for security reasons. Alternatively, I am happy to send them privately to anyone who can take a look - just don’t want it posted on the web.

The server has a 5.5TB storage array specifically for live TV/DVR/Transcoding (yes, it is set to transcode there instead of the main OS drive) with 5.3+TB free at all times. System has 32gb of ram as well, so even that should be enough.

5

The primary file to inspect is Plex Media Server.log. As long as the storage array is direct attached and not networked then you should be good.

6

Thanks. Yes, the storage array is internal/not networked.

Here’s the extracts from the PMS.log file around the time of the start of the recording. It is set to start 1 minute early, so 20:59. Does this give any insight? I see stuff about a transcoder error, but no idea where to start with that (and still not sure why it is only this show that has this issue)

Feb 15, 2023 20:57:13.825 [13888] ERROR - Error parsing content.
Feb 15, 2023 20:57:13.825 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 20:57:13.825 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.148:9080
Feb 15, 2023 20:57:53.809 [13888] ERROR - XML: Entity: line 1:
Feb 15, 2023 20:57:53.809 [13888] ERROR - XML: parser
Feb 15, 2023 20:57:53.809 [13888] ERROR - XML: error :
Feb 15, 2023 20:57:53.809 [13888] ERROR - XML: Start tag expected, ‘<’ not found
Feb 15, 2023 20:57:53.809 [13888] ERROR - XML: status=ok
Feb 15, 2023 20:57:53.809 [13888] ERROR - XML: ^
Feb 15, 2023 20:57:53.809 [13888] ERROR - Error parsing content.
Feb 15, 2023 20:57:53.809 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 20:57:53.809 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.148:9080
Feb 15, 2023 20:58:31.350 [13888] ERROR - XML: Entity: line 1:
Feb 15, 2023 20:58:31.350 [13888] ERROR - XML: parser
Feb 15, 2023 20:58:31.350 [13888] ERROR - XML: error :
Feb 15, 2023 20:58:31.350 [13888] ERROR - XML: Start tag expected, ‘<’ not found
Feb 15, 2023 20:58:31.350 [13888] ERROR - XML: status=ok
Feb 15, 2023 20:58:31.350 [13888] ERROR - XML: ^
Feb 15, 2023 20:58:31.350 [13888] ERROR - Error parsing content.
Feb 15, 2023 20:58:31.350 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 20:58:31.350 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.133:9080
Feb 15, 2023 20:58:32.819 [13888] ERROR - XML: Entity: line 1:
Feb 15, 2023 20:58:32.819 [13888] ERROR - XML: parser
Feb 15, 2023 20:58:32.819 [13888] ERROR - XML: error :
Feb 15, 2023 20:58:32.819 [13888] ERROR - XML: Start tag expected, ‘<’ not found
Feb 15, 2023 20:58:32.819 [13888] ERROR - XML: status=ok
Feb 15, 2023 20:58:32.819 [13888] ERROR - XML: ^
Feb 15, 2023 20:58:32.819 [13888] ERROR - Error parsing content.
Feb 15, 2023 20:58:32.819 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 20:58:32.819 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.148:9080
Feb 15, 2023 20:59:00.257 [4012] ERROR - [Grabber/911f86bab9f76fa5f81ced2980368a771a6484bb] Unable to find title for item of type 5
Feb 15, 2023 20:59:00.258 [4012] ERROR - [Grabber/911f86bab9f76fa5f81ced2980368a771a6484bb] Unable to find title for item of type 5
**Feb 15, 2023 20:59:02.830 [13888] ERROR - XML: Entity: line 1: **
**Feb 15, 2023 20:59:02.830 [13888] ERROR - XML: parser **
**Feb 15, 2023 20:59:02.830 [13888] ERROR - XML: error : **
**Feb 15, 2023 20:59:02.830 [13888] ERROR - XML: Start tag expected, ‘<’ not found **
**Feb 15, 2023 20:59:02.830 [13888] ERROR - XML: status=ok **
**Feb 15, 2023 20:59:02.830 [13888] ERROR - XML: ^ **
Feb 15, 2023 20:59:02.830 [13888] ERROR - Error parsing content.
Feb 15, 2023 20:59:02.830 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 20:59:02.830 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.133:9080
**Feb 15, 2023 20:59:03.814 [13888] ERROR - XML: Entity: line 1: **
**Feb 15, 2023 20:59:03.814 [13888] ERROR - XML: parser **
**Feb 15, 2023 20:59:03.814 [13888] ERROR - XML: error : **
**Feb 15, 2023 20:59:03.814 [13888] ERROR - XML: Start tag expected, ‘<’ not found **
**Feb 15, 2023 20:59:03.814 [13888] ERROR - XML: status=ok **
**Feb 15, 2023 20:59:03.814 [13888] ERROR - XML: ^ **
Feb 15, 2023 20:59:03.814 [13888] ERROR - Error parsing content.
Feb 15, 2023 20:59:03.814 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 20:59:03.814 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.148:9080
Feb 15, 2023 20:59:10.363 [13264] ERROR - [Req#3a004/Transcode/d649f922-5f76-47dd-a5ea-ebc11bed858b/26ac010a-3133-4c27-b62b-41c90e77c9a6] Stream map ‘0:0’ matches no streams.
To ignore this, add a trailing ‘?’ to the map.
Feb 15, 2023 20:59:10.371 [4012] ERROR - [Grabber/911f86bab9f76fa5f81ced2980368a771a6484bb] Failed to start session.
Feb 15, 2023 20:59:10.371 [4012] ERROR - [Grabber/911f86bab9f76fa5f81ced2980368a771a6484bb] Recorder: Unable to create transcode session or session failed to start.
Feb 15, 2023 20:59:10.372 [4012] ERROR - [Grabber/911f86bab9f76fa5f81ced2980368a771a6484bb] Recorder: Error 12 (There was a transcoder error) starting the record, shutting things down.
Feb 15, 2023 20:59:10.372 [4012] ERROR - [Grabber/911f86bab9f76fa5f81ced2980368a771a6484bb] Starting media grab failed.
**Feb 15, 2023 20:59:35.849 [13888] ERROR - XML: Entity: line 1: **
**Feb 15, 2023 20:59:35.849 [13888] ERROR - XML: parser **
**Feb 15, 2023 20:59:35.849 [13888] ERROR - XML: error : **
**Feb 15, 2023 20:59:35.849 [13888] ERROR - XML: Start tag expected, ‘<’ not found **
**Feb 15, 2023 20:59:35.849 [13888] ERROR - XML: status=ok **
**Feb 15, 2023 20:59:35.849 [13888] ERROR - XML: ^ **
Feb 15, 2023 20:59:35.849 [13888] ERROR - Error parsing content.
Feb 15, 2023 20:59:35.849 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 20:59:35.849 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.133:9080
**Feb 15, 2023 20:59:41.824 [13888] ERROR - XML: Entity: line 1: **
**Feb 15, 2023 20:59:41.824 [13888] ERROR - XML: parser **
**Feb 15, 2023 20:59:41.824 [13888] ERROR - XML: error : **
**Feb 15, 2023 20:59:41.824 [13888] ERROR - XML: Start tag expected, ‘<’ not found **
**Feb 15, 2023 20:59:41.824 [13888] ERROR - XML: status=ok **
**Feb 15, 2023 20:59:41.824 [13888] ERROR - XML: ^ **
Feb 15, 2023 20:59:41.824 [13888] ERROR - Error parsing content.
Feb 15, 2023 20:59:41.824 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 20:59:41.824 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.148:9080
Feb 15, 2023 20:59:53.731 [13264] ERROR - Caught exception trying to stream file: Y:\Transcode_Temp\Transcode\Sessions\plex-transcode-6450c8a5-aeff-48ff-a19e-15aea1dc27d3\media-07222.ts: write: A request to send or receive data was disallowed because the socket had already been shut down in that direction with a previous shutdown call
**Feb 15, 2023 21:00:12.823 [13888] ERROR - XML: Entity: line 1: **
**Feb 15, 2023 21:00:12.823 [13888] ERROR - XML: parser **
**Feb 15, 2023 21:00:12.823 [13888] ERROR - XML: error : **
**Feb 15, 2023 21:00:12.823 [13888] ERROR - XML: Start tag expected, ‘<’ not found **
**Feb 15, 2023 21:00:12.823 [13888] ERROR - XML: status=ok **
**Feb 15, 2023 21:00:12.823 [13888] ERROR - XML: ^ **
Feb 15, 2023 21:00:12.823 [13888] ERROR - Error parsing content.
Feb 15, 2023 21:00:12.823 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 21:00:12.823 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.148:9080
Feb 15, 2023 21:00:15.857 [13888] ERROR - XML: Entity: line 1:
Feb 15, 2023 21:00:15.857 [13888] ERROR - XML: parser
Feb 15, 2023 21:00:15.857 [13888] ERROR - XML: error :
Feb 15, 2023 21:00:15.857 [13888] ERROR - XML: Start tag expected, ‘<’ not found
Feb 15, 2023 21:00:15.857 [13888] ERROR - XML: status=ok
Feb 15, 2023 21:00:15.857 [13888] ERROR - XML: ^
Feb 15, 2023 21:00:15.857 [13888] ERROR - Error parsing content.
Feb 15, 2023 21:00:15.857 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 21:00:15.857 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.133:9080
Feb 15, 2023 21:00:53.810 [13888] ERROR - XML: Entity: line 1:
Feb 15, 2023 21:00:53.810 [13888] ERROR - XML: parser
Feb 15, 2023 21:00:53.810 [13888] ERROR - XML: error :
Feb 15, 2023 21:00:53.810 [13888] ERROR - XML: Start tag expected, ‘<’ not found
Feb 15, 2023 21:00:53.810 [13888] ERROR - XML: status=ok
Feb 15, 2023 21:00:53.810 [13888] ERROR - XML: ^
Feb 15, 2023 21:00:53.810 [13888] ERROR - Error parsing content.
Feb 15, 2023 21:00:53.810 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 21:00:53.810 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.148:9080
Feb 15, 2023 21:00:53.890 [13888] ERROR - XML: Entity: line 1:
Feb 15, 2023 21:00:53.890 [13888] ERROR - XML: parser
Feb 15, 2023 21:00:53.890 [13888] ERROR - XML: error :
Feb 15, 2023 21:00:53.890 [13888] ERROR - XML: Start tag expected, ‘<’ not found
Feb 15, 2023 21:00:53.890 [13888] ERROR - XML: status=ok
Feb 15, 2023 21:00:53.890 [13888] ERROR - XML: ^
Feb 15, 2023 21:00:53.890 [13888] ERROR - Error parsing content.
Feb 15, 2023 21:00:53.890 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 21:00:53.890 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.133:9080
Feb 15, 2023 21:01:23.816 [13888] ERROR - XML: Entity: line 1:
Feb 15, 2023 21:01:23.816 [13888] ERROR - XML: parser
Feb 15, 2023 21:01:23.816 [13888] ERROR - XML: error :
Feb 15, 2023 21:01:23.816 [13888] ERROR - XML: Start tag expected, ‘<’ not found
Feb 15, 2023 21:01:23.816 [13888] ERROR - XML: status=ok
Feb 15, 2023 21:01:23.816 [13888] ERROR - XML: ^
Feb 15, 2023 21:01:23.816 [13888] ERROR - Error parsing content.
Feb 15, 2023 21:01:23.816 [13888] ERROR - Error parsing XML: Error parsing file.
Feb 15, 2023 21:01:23.816 [13888] ERROR - SSDP: Error parsing device schema for http://192.168.146.148:9080
Feb 15, 2023 21:01:32.852 [13888] ERROR - XML: Entity: line 1:
Feb 15, 2023 21:01:32.852 [13888] ERROR - XML: parser
Feb 15, 2023 21:01:32.852 [13888] ERROR - XML: error :
Feb 15, 2023 21:01:32.852 [13888] ERROR - XML: Start tag expected, ‘<’ not found
Feb 15, 2023 21:01:32.852 [13888] ERROR - XML: status=ok
Feb 15, 2023 21:01:32.852 [13888] ERROR - XML: ^

7

That’s why a full set of logs are requested, tough to make sense from an excerpt when many of the ERROR messages can be ignored.

Was this a DVR or Live TV session? From what little is here I would say the transcoder failed on memory access either trying to access the Y drive or video driver. What GPU do you have and what is this storage array?

8

This was a DVR scheduled recording. Aside from this one particular show, I have not had any other issues recording all other shows on the schedule. There are other times where two recordings overlap like this and neither of those have ever failed.

If there are other log files that are needed let me know and I would be happy to post that section (or send you the full files privately - just don’t want them floating on the interwebs)

What would cause that failure? The storage array is a Storage Spaces array spread over 3x 3TB drives (it is intended to just be the live recording/transcoding drive to reduce wear on a much bigger RAID array where videos are stored long term). GPU is the integrated Intel GPU on an i5-11600 CPU

9

Update: This worked fine last night, all 3 Chicago shows recorded properly. Nothing has changed in the environment.

10

I had problem around 3 weeks go which lasted for two weeks, Seems better in the last week

11

It has worked intermittently over the last few months, but failed more often than not. I still have no idea what is making it fail. At this point, just waiting to see what happens next week.

12

Was good for a few weeks and then failed again. I had it set to record two shows at 9:00PM, and both failed.

It sure seems like it has issues going immediately from 1 show to another without a gap between them. A 4 tuner HDHomerun would likely solve it, but I shouldn’t have to go to that because two should be fine as long as timers are not set to overlap and conflict. At this point, it seems that Plex DVR just isn’t reliable enough to become my sole DVR even though when it does work, it’s great.

13

Have you tried deleting your codecs? Plex will redownload them as needed. I’ve had this fix recording problems… Once specifically when I was having problems with back to back recordings.

  1. Stop your Plex server process.
  2. Delete everything from inside your Plex codec directory on your Plex server except for the .device_id file. I’m not sure what OS you are running.
    On debian based Linux OSes it is /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs. This directory isn’t large so I usually make a backup first to be safe, though I’ve never needed it.
  3. Start your Plex server process and try the recording again.
14

Thanks. Trying that right now, had not heard of this before.

15

Failed again tonight after trying the recommendation above.

Not sure why this is so difficult, but I can’t count on Plex DVR to be reasonably reliable at this point.

Log file from + / - a few minutes on each side of the start of the recording are below.


Apr 05, 2023 20:54:28.826 [15908] ERROR - Caught exception trying to stream file: Y:\Transcode_Temp\Transcode\Sessions\plex-transcode-671e3a8d-1621-4ccb-88cd-9e49cd4bf23c\media-03249.ts: write: A request to send or receive data was disallowed because the socket had already been shut down in that direction with a previous shutdown call [system:10058]
Apr 05, 2023 21:00:00.522 [1188] ERROR - [Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Grabber: found airing in the active list with an end time in the past. 'Chicago Fire - E18 - Danger Is All Around' on channel 5fc76b32a05ef8002e7a6907-5fc705e9a05ef8002e615c48 should have ended 0 seconds ago.
Apr 05, 2023 21:00:00.526 [23428] ERROR - [Grabber/3edab0bfa078d60c1b92d64bda0e88baee052c26] Grabber: found airing in the active list with an end time in the past. 'Chicago Fire - E18 - Danger Is All Around' on channel 5fc76b32a05ef8002e7a6907-5fc705e9a05ef8002e615c48 should have ended 0 seconds ago.
Apr 05, 2023 21:00:00.553 [1188] ERROR - [Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Unable to find title for item of type 5
Apr 05, 2023 21:00:00.553 [1188] ERROR - [Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Unable to find title for item of type 5
Apr 05, 2023 21:00:00.577 [23428] ERROR - [Grabber/3edab0bfa078d60c1b92d64bda0e88baee052c26] Unable to find title for item of type 5
Apr 05, 2023 21:00:00.577 [23428] ERROR - [Grabber/3edab0bfa078d60c1b92d64bda0e88baee052c26] Unable to find title for item of type 5
Apr 05, 2023 21:00:01.281 [17284] ERROR - [Req#629f5/Transcode/f43f9c7d-38b3-4bfe-9bf7-6f697c3a6d85/833618dd-2967-4ccb-90cf-368b141cbe08] [mpeg2video @ 00000296446d6e80] Invalid frame dimensions 0x0.
Apr 05, 2023 21:00:01.869 [23428] ERROR - [Grabber/3edab0bfa078d60c1b92d64bda0e88baee052c26] Unable to find title for item of type 5
Apr 05, 2023 21:00:01.870 [23428] ERROR - [Grabber/3edab0bfa078d60c1b92d64bda0e88baee052c26] Unable to find title for item of type 5
Apr 05, 2023 21:00:04.574 [23428] INFO - [Grabber/3edab0bfa078d60c1b92d64bda0e88baee052c26] Notification: Recording True Lies - E6 - Working Vacation - 
Apr 05, 2023 21:00:10.660 [15908] ERROR - [Req#62aef/Transcode/bac3b3b2-b159-4869-9388-ba5d4050383c/8241160d-6366-490a-9c23-c81fe2ceba58] Stream map '0:0' matches no streams.
To ignore this, add a trailing '?' to the map.
Apr 05, 2023 21:00:10.664 [1188] ERROR - [Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Failed to start session.
Apr 05, 2023 21:00:10.664 [1188] ERROR - [Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Recorder: Unable to create transcode session or session failed to start.
Apr 05, 2023 21:00:10.665 [1188] ERROR - [Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Recorder: Error 12 (There was a transcoder error) starting the record, shutting things down.
Apr 05, 2023 21:00:10.665 [1188] ERROR - [Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Starting media grab failed.
Apr 05, 2023 21:01:11.665 [17284] WARN - [Req#62fed] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:11.948 [17284] WARN - [Req#62ff1] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:18.487 [21104] INFO - Request: [192.168.146.148:33394 (Subnet)] DELETE /library/metadata/81531 (16 live) #63015 TLS GZIP Signed-in Token (<usernameredacted>) (AFTKA)
Apr 05, 2023 21:01:18.562 [8596] INFO - Completed: [192.168.146.148:33394] 200 DELETE /library/metadata/81531 (16 live) #63015 TLS GZIP 74ms 195 bytes (pipelined: 21)
Apr 05, 2023 21:01:18.600 [21104] ERROR - [Req#6309c] Unknown metadata type: folder
Apr 05, 2023 21:01:21.020 [15908] WARN - [Req#630a8] QueryParser: Invalid field 'IncludeExternalMedia' found, ignoring.
Apr 05, 2023 21:01:37.260 [15908] WARN - [Req#630d4] QueryParser: Invalid field 'IncludeExternalMedia' found, ignoring.
Apr 05, 2023 21:01:48.888 [15908] ERROR - [Req#632cd] Unknown metadata type: folder
Apr 05, 2023 21:01:49.195 [21104] INFO - [Req#631fb] AutoUpdate: no updates available
Apr 05, 2023 21:01:49.278 [21104] ERROR - [Req#632e6] Unknown metadata type: folder
Apr 05, 2023 21:01:49.298 [21104] WARN - [Req#632eb] QueryParser: Invalid field 'IncludeExternalMedia' found, ignoring.
Apr 05, 2023 21:01:56.210 [17284] WARN - [Req#63353] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:56.243 [17284] WARN - [Req#63353] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:56.246 [17284] WARN - [Req#63353] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:56.250 [17284] WARN - [Req#63353] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:58.013 [5708] WARN - [Req#63352] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:01:58.013 [5708] WARN - [Req#63352] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:58.013 [5708] WARN - [Req#63352] QueryParser: Invalid field 'sectionID' found, ignoring.
Apr 05, 2023 21:01:58.171 [17284] WARN - [Req#633c4] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:01:58.171 [17284] WARN - [Req#633c4] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:58.171 [17284] WARN - [Req#633c4] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Apr 05, 2023 21:01:58.430 [15908] WARN - [Req#633c2] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:01:58.430 [15908] WARN - [Req#633c2] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:58.430 [15908] WARN - [Req#633c2] QueryParser: Invalid field 'sectionID' found, ignoring.
Apr 05, 2023 21:01:58.620 [15908] WARN - [Req#633dd] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:01:58.620 [15908] WARN - [Req#633dd] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:58.620 [15908] WARN - [Req#633dd] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Apr 05, 2023 21:01:58.645 [15908] WARN - [Req#633dd] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:01:58.646 [15908] WARN - [Req#633dd] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:58.646 [15908] WARN - [Req#633dd] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Apr 05, 2023 21:01:58.649 [15908] WARN - [Req#633dd] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:01:58.649 [15908] WARN - [Req#633dd] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:58.649 [15908] WARN - [Req#633dd] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Apr 05, 2023 21:01:58.652 [15908] WARN - [Req#633dd] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:01:58.652 [15908] WARN - [Req#633dd] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:01:58.652 [15908] WARN - [Req#633dd] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Apr 05, 2023 21:02:00.440 [17528] ERROR - [Req#633fb] Unknown metadata type: folder
Apr 05, 2023 21:02:00.589 [17528] ERROR - [Req#63415] Unknown metadata type: folder
Apr 05, 2023 21:02:00.660 [17528] WARN - [Req#63416] QueryParser: Invalid field 'IncludeExternalMedia' found, ignoring.
Apr 05, 2023 21:02:22.048 [15908] ERROR - [Req#6355e] Missing required query parameter height
Apr 05, 2023 21:02:22.472 [15908] ERROR - [Req#63561] Missing required query parameter height
Apr 05, 2023 21:02:39.228 [23428] ERROR - [Req#635dd/Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Unable to find title for item of type 5
Apr 05, 2023 21:02:39.228 [23428] ERROR - [Req#635dd/Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Unable to find title for item of type 5
Apr 05, 2023 21:02:43.081 [9800] WARN - [Grabber/12788230c9aa007a349f5a0024c8b0d411481e6e] MDE: unable to find a working transcode profile for video stream
Apr 05, 2023 21:02:43.081 [9800] WARN - [Grabber/12788230c9aa007a349f5a0024c8b0d411481e6e] MDE: unable to find a working transcode profile for video stream
Apr 05, 2023 21:02:44.256 [5708] ERROR - [Req#63a4f/Transcode/c3bfb120-1fa7-457c-8a82-ef208e8331f1/e746e176-ff97-4a46-81ab-c579fa203b1b] [ac3 @ 000001c9605b2280] expacc 125 is out-of-range
Apr 05, 2023 21:02:44.256 [5708] ERROR - [Req#63b1f/Transcode/c3bfb120-1fa7-457c-8a82-ef208e8331f1/e746e176-ff97-4a46-81ab-c579fa203b1b] [ac3 @ 000001c9605b2280] error decoding the audio block
Apr 05, 2023 21:02:44.256 [5708] ERROR - [Req#63b20/Transcode/c3bfb120-1fa7-457c-8a82-ef208e8331f1/e746e176-ff97-4a46-81ab-c579fa203b1b] Error while decoding stream #0:1: Error number -16976906 occurred
Apr 05, 2023 21:02:49.334 [17284] ERROR - [Req#63de7/Transcode/787c31f6-365c-47b0-9419-19cdfc5bb95d/4737b551-6465-4924-8cbe-4d53b9bf5727] Stream map '0:0' matches no streams.
To ignore this, add a trailing '?' to the map.
Apr 05, 2023 21:02:49.338 [23428] ERROR - [Req#635dd/Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Failed to start session.
Apr 05, 2023 21:02:49.338 [23428] ERROR - [Req#635dd/Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Recorder: Unable to create transcode session or session failed to start.
Apr 05, 2023 21:02:49.338 [23428] ERROR - [Req#635dd/Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Recorder: Error 12 (There was a transcoder error) starting the record, shutting things down.
Apr 05, 2023 21:02:49.339 [23428] ERROR - [Req#635dd/Grabber/823514cfe493de6765e83c8b97130c64a86d5538] Starting media grab failed.
Apr 05, 2023 21:02:49.694 [5708] WARN - [Req#63e08] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:02:49.694 [5708] WARN - [Req#63e08] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:02:49.694 [5708] WARN - [Req#63e08] QueryParser: Invalid field 'sectionID' found, ignoring.
Apr 05, 2023 21:02:49.702 [17284] WARN - [Req#63d96] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:02:49.702 [17284] WARN - [Req#63d96] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:02:49.702 [17284] WARN - [Req#63d96] QueryParser: Invalid field 'sectionID' found, ignoring.
Apr 05, 2023 21:02:49.879 [13600] WARN - [Req#63e19] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:02:49.879 [13600] WARN - [Req#63e19] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:02:49.879 [13600] WARN - [Req#63e19] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Apr 05, 2023 21:02:50.148 [17284] WARN - [Req#63e1d] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:02:50.148 [17284] WARN - [Req#63e1d] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:02:50.148 [17284] WARN - [Req#63e1d] QueryParser: Invalid field 'sectionID' found, ignoring.
Apr 05, 2023 21:02:50.775 [13600] WARN - [Req#63e52] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:02:50.775 [13600] WARN - [Req#63e52] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:02:50.775 [13600] WARN - [Req#63e52] QueryParser: Invalid field 'onlyTransient' found, ignoring.
Apr 05, 2023 21:02:50.814 [13600] WARN - [Req#63e52] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:02:50.814 [13600] WARN - [Req#63e52] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:02:50.814 [13600] WARN - [Req#63e52] QueryParser: Invalid field 'onlyTransient' found, ignoring.
Apr 05, 2023 21:02:50.820 [13600] WARN - [Req#63e52] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:02:50.820 [13600] WARN - [Req#63e52] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:02:50.820 [13600] WARN - [Req#63e52] QueryParser: Invalid field 'onlyTransient' found, ignoring.
Apr 05, 2023 21:02:50.825 [13600] WARN - [Req#63e52] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:02:50.825 [13600] WARN - [Req#63e52] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:02:50.825 [13600] WARN - [Req#63e52] QueryParser: Invalid field 'onlyTransient' found, ignoring.
Apr 05, 2023 21:02:51.019 [13600] ERROR - [Req#63e60] Cannot find hub with identifier continueWatching.
Apr 05, 2023 21:02:56.335 [2364] ERROR - [Grabber/12788230c9aa007a349f5a0024c8b0d411481e6e/CreditsDetectionManager] PeekNamedPipe failed: 0x6d
Apr 05, 2023 21:02:56.335 [2364] ERROR - [Grabber/12788230c9aa007a349f5a0024c8b0d411481e6e/CreditsDetectionManager] BufferingLineReader: failed to read line (error: -1)
Apr 05, 2023 21:03:01.044 [17284] WARN - [Req#63e8e] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:03:01.044 [17284] WARN - [Req#63e8e] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:03:01.044 [17284] WARN - [Req#63e8e] QueryParser: Invalid field 'sectionID' found, ignoring.
Apr 05, 2023 21:03:01.061 [5708] WARN - [Req#63e6b] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:03:01.061 [5708] WARN - [Req#63e6b] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:03:01.061 [5708] WARN - [Req#63e6b] QueryParser: Invalid field 'sectionID' found, ignoring.
Apr 05, 2023 21:03:01.611 [13600] WARN - [Req#63f55] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Apr 05, 2023 21:03:01.611 [13600] WARN - [Req#63f55] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Apr 05, 2023 21:03:01.611 [13600] WARN - [Req#63f55] QueryParser: Invalid field 'sectionID' found, ignoring.
Apr 05, 2023 21:03:01.917 [17284] ERROR - [Req#63f81] Cannot find hub with identifier continueWatching.
Apr 05, 2023 21:03:05.066 [16820] ERROR - [Req#63f78] Unknown metadata type: folder
Apr 05, 2023 21:03:05.140 [16820] ERROR - [Req#63fbe] Unknown metadata type: folder
Apr 05, 2023 21:03:05.234 [17528] WARN - [Req#63fbf] QueryParser: Invalid field 'IncludeExternalMedia' found, ignoring.
Apr 05, 2023 21:03:05.448 [13600] INFO - [Req#63f85] AutoUpdate: no updates available
Apr 05, 2023 21:03:10.164 [23108] WARN - [HttpClient/HCl#6d2f] HTTP error requesting GET https://98-172-204-124.fd1fabc5ee2d4200a999e08d252e7366.plex.direct:28151/identity (7, Couldn't connect to server) (Failed to connect to 98-172-204-124.fd1fabc5ee2d4200a999e08d252e7366.plex.direct port 28151 after 2045 ms: Couldn't connect to server)
Apr 05, 2023 21:03:10.525 [16820] WARN - [Req#64170] QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
16

Bummer, I was hoping that would work, but making suggestions from log snippets is tough. An idea just occurred to me…

It appears from the logs that you have your transcoder temp directory set to Y:\Transcode_Temp. What is your Y: drive? (Local drive, network drive, etc?) If it is a network drive then that is likely the issue. Plex recommends not having the transcoder temp directory on a network drive. When I’ve seen it done it causes intermittent failures with the transcoder.

17

The Y drive is a local storage spaces array made up of 3x 3tb drives.

I had considered (if this solution had worked out) upgrading it to a 1TB SSD for better performance - I don’t envision ever needing more than 1TB for recordings.

18

Ok, drives should be fine but it’s failing when something with your transcoder isn’t happy. This message is coming back from FFMPEG:

This suggests that either the audio or video is missing or not being found. A few questions that may create some ideas:

  • I found cases of similar errors with both Plex and Emby (both use FFMEG), but typically this message is more in line with “0:a:0” or “0:v:0” to indicate either audio or video is missing, and I couldn’t find an example of just “0:0” so I’m not sure if this means the audio stream is missing, the video stream is missing, or both.

  • Is this issue specific to one channel or a specific set of channels?

  • When you tune this channel, then go into the web interface for your HDHR Duo. What is the signal strength and signal quality? Does this problem only occur at a specific time of day, or during bad weather that could impact the signal strength?

  • If you can catch a failed recording in real time when it happens, again try to check the signal strength and signal quality as close to the failure as you can.

  • Have you made any other changes (other than the transcoder temp directory) from the default values on the page Plex Web → Settings → Transcoder? If so, try changing back to the default.

19

That’s what is strange… it seems specific to this particular show. It has no issues recording the 2 shows immediately prior to it on the same channel, or other shows at other times from this channel.

Just tuned to that channel right now and here is what I am seeing:
Tuner 0 Status

Virtual Channel 4.1 KFOR-DT
Frequency 551.000 MHz
Program Number 1
Modulation Lock 8vsb
Signal Strength 70%
Signal Quality 85%
Symbol Quality 100%
Streaming Rate 6.612 Mbps

I will try to catch it during a failure in a few weeks when the next new episode airs. I did catch it fairly quickly this time. Still not sure how it records from 8-9pm just fine but suddenly fails repeatedly at 9pm

No other changes besides the transcoder, did not want it running on the OS drive.

20

This is a tricky one. Have you looked at your HDHR Duo logs at the timeframe of the failure to see if there is anything useful? Possibly it is not releasing the tuners fast enough from the previous recording so no tuner is available? I would expect to see something in the Plex logs as well, but with only a log snippets I can’t tell. The HDHR log should have a pretty clear message if it gets a tune request when no tuner is available.

I have an HDHR Extend that transcodes down for me so I’ve got a few differences. I don’t currently have anything recording the same channel back-to-back to see if Plex releases the tuner and then tunes again in this scenario.

Just to verify, no tune requests are going to your HDHR Duo except from Plex - correct? Plex expects to have exclusive access to tuner devices.

Edit: Do you have any record “minutes after” set on the 8-9, or “minutes before” on the 9:00 recording? I would expect Plex to flag this as a conflict, but thought it would be worth checking.