Hi - My Plex DVR was working fine last week, but it suddenly stopped storing recordings.
If I try to watch Live TV, that works - so, I know that my cable box is working fine.
However, the Plex desktop will properly show when a recording is in progress, and then when the recording time is over … there is no recording stored on my NAS drive.
What can I look for in my settings or logs that will give me a clue on what the problem is?
Thanks,
AzJazz
Server Version#: 1.16.1.1273
Player Version#: N/A
Do you happen to have a “Keep” only a certain number of episodes set for the recording(s) in question? For me, when I went to 1.16.1.x, I could see in the logs that it would record, move the file from .grab to the appropriate location, and then delete it because it thought that the “new” episode just recorded was the oldest episode. Individual recordings and series recordings without a “Keep” set seem to be working.
My workaround was to delete all of the shows where I had a Keep set, then recording worked for those series.
It could be a problem with shows being recorded under both the old and the new EPG. I haven’t gotten enough recordings in those series yet to see if the “Keep” will work correctly once all of the shows have been recorded under the new EPG.
PS In the web interface, go to Settings -> Troubleshooting -> click on “Download Logs”. Unzip the file that downloads, and look in the “Plex Media Server.log” file.
Some stuff was being recorded with Keep limits, some stuff was not. It didn’t seem to matter: Nothing is actually being saved after the recording time ends.
What should I look at regarding the EPG? Plex seems to try recording at the proper time, but it doesn’t get saved.
Also, I downloaded the logs … There are a gazillion files! What can I search for in there to track down the problem(s)?
Are you running comskip or any post processing? There is a known bug that when there is more than one file in the recording directory, only one file will be moved to the proper location after recording.
I would look in the Plex Media Server.log files and see if you don’t have any errors like the ones discussed in the below post.
I think I might have isolated the source of the problem (though, not the reason).
I recently made a change to a setting, thinking that it would make Plex run more efficiently.
Under Server >> Manage >> Live TV & DVR >> Device >> Device Settings, I recently enabled Convert Video while Recording >> Transcode.
Recordings worked fine, but it seemed like that sucked up more CPU than I would like.
So, I reverted the setting from Transcode back to Off (The original, default setting) … and that is apparently when my recording problems started.
When I changed it back to Transcode last night, my recordings were being stored normally again.
This looks like a bug.
Is there anything I can review in the logs to confirm? How do I report this back to the Plex developers?
Thanks,
AzJazz
I’m not an expert on Plex log analysis, but generally speaking I’ve found the “Plex Media Server.log” file in the zip that downloads is the most useful log file to start investigation - and also the only log file I’ve needed to look at in most cases. It will be easiest if you grab your logs shortly after the recording (should have) finished since Plex does rotate the logs. This log file has a date/time stamp on each line entry in the log, so typically look at the time that the recording started and ended. If you are using comskip you will have to look later also when comskip finished running. My Plex is on Linux, but if you are Win and the log file looks like one continuous run on line in Notepad then try Wordpad instead. It’s caused by a difference with end of line characters that Notepad can’t handle.
If this log file has rotated you may need to look at the older logs in the zip, that will be named “Plex Media Server.1.log”, “Plex Media Server.2.log”,etc to get to the right timeframe.
Generally speaking, while recording is in progress Plex puts the file in a “.grab” directory that is a subdirectory of where you have set your recordings to be placed. Then at the end of the recording, or after comskip finishes running if you are using it, Plex will move the file from .grab to the final location for the recording.
I’ve found searching for “.grab” in the logs is useful because it generally is referenced at the start of a recording and at the final file move for the recording. Also search for the name of the show you are focusing on analyzing. I’m not good enough at Plex log analysis to be more specific, but I’ve always been able to get to the root of my problems in the logs with a little patience.
I do transcoding on my HDHomeRun Extend tuner while watching live TV/recording without issues, and appreciate the file size reduction, but in device settings my transcoding is described as “Transcoder Quality”. Since yours is labeled “Convert Video While Recording” I think you must have a different tuner. I’d suggest also posting what tuner model you are using.
Also, look at your tuner’s logs (on your tuner device if it has this capability, not the Plex logs) to make sure it is showing the tuner changing to the right station, and that it is maintaining the connection and tuning for the expected period of time. For my HDHomeRun Extend I can get to the logs by pointing a web browser at the IP address for my Extend, and then navigating the Extend’s web interface.
If a Plex employee sees this stream they may investigate, and 99.99% of the time will ask you to post logs. Click here to get info on posting logs. and here for reporting issues.
Sorry for the long post. Hope this helps…
I looked in the logs, and I am seeing errors like this when trying to record to my QNAP NAS or a local HDD:
Jun 30, 2019 17:24:51.066 [7000] ERROR - Caught exception trying to stream file: P:\Video Conversion\Transcode\Sessions\plex-transcode-e4f58440-6c88-411d-96b5-00aa83bc2b5c\media-00044.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
Is this the problem?
I believe you have found the problem, and this is consistent with your finding that you can record with the transcode option off, but not when on. The error is saying that Plex can’t write to the transcode directory that is on the P: drive.
The thing is that this doesn’t look like it is actually a Plex error, but may instead be a Windows error that Plex is passing through to it’s logs as the reason for the failure. You are running some flavor of Windows, correct? I’m a bit in the dark also because I don’t have your TV tuner, and that is where you are describing the transcode setting, so I can’t be sure about corresponding settings and implications.
What I can say is that Plex is trying to use your P: drive for transcoding in the example you provided, and Windows (if that is where you are running PMS) is having trouble writing to this location. This transcode location may be independent of where you are trying to store the recording. Please review articles on transcode storage locations here and here.
If P: is a mounted drive in Windows to your QNAP, note that in the first article Plex says your transcode directory SHOULD NOT be on a network share/disk. If this is the case you need to move your transcode directory to a local drive on your Windows computer.
I’d also suggest looking in your Windows event viewer at your windows sytem logs to see if you can get any more information on the error. See the Microsoft docuement on this error here, look for error 10058 in this doc - it is the error you are getting.
If my suppositions are correct, this could be a problem between your Windows instance and your mounted P: drive, and may not specifically be a Plex issue. I have my recordings placed on a NAS without issues (though I run PMS on Linux), but my transcode directory is local on the server.
If it’s Windows, have you tried rebooting? You probably have, but the first rule of Windows troubleshooting is to see if a reboot fixes the problem.
Hope this helps…
I did some more digging to isolate the source of the failure, and I now know that it is related to my QNAP NAS storage device.
If I try recording TV onto a local hard drive on my PC, I can record tv shows just fine. My P: drive was a hard disk, not a mapped Windows drive.
However, if I try to record to my QNAP \<qnap_ip_address>\Multimedia\tv shared folder, the recording doesn’t get saved. I read and write to the \<qnap_ip_address>\Multimedia\tv folder fine with Windows Explorer, but Plex apparently fails during the recording process.
Note that I don’t use a Windows mapped drive to the QNAP, I always use the UNC path to the QNAP folder.
I can see that Plex is able to write the thousands of .ts files to the \<qnap_ip_address>\Video Conversion\Transcode\Sessions\plex-transcode-xxxxxx during the recording, so Plex has some sort of access to the NAS working.
Here is an edited list from my Plex Media Server.log file:
Search "error" (133 hits in 1 file)
C:\Users\AzJazz\AppData\Local\Temp\7zOC156DB40\Plex Media Server.log (133 hits)
Line 174: Jul 07, 2019 13:01:19.350 [22624] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-00044.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
Line 406: Jul 07, 2019 13:01:46.429 [22228] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-00071.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
Line 425: Jul 07, 2019 13:01:47.618 [9056] DEBUG - NotificationStream: Removing because of error
Line 577: Jul 07, 2019 13:02:08.356 [22624] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-00093.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
Line 775: Jul 07, 2019 13:02:34.454 [22228] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-00119.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
...
Line 2528: Jul 07, 2019 13:06:31.380 [22544] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-00356.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
Line 2698: Jul 07, 2019 13:06:54.433 [29284] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-00379.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
Line 2884: Jul 07, 2019 13:07:19.429 [22624] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-00404.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
Line 3157: Jul 07, 2019 13:07:29.026 [24304] ERROR - PlexClient::downloadContainer: expected MediaContainer element, found html
Line 5289: Jul 07, 2019 13:11:46.434 [22544] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-00671.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
Line 5454: Jul 07, 2019 13:12:08.389 [22624] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-00693.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
Line 5781: Jul 07, 2019 13:12:27.354 [24952] ERROR - PlexClient::downloadContainer: expected MediaContainer element, found html
Line 5929: Jul 07, 2019 13:12:31.365 [22544] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-00716.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
Line 5973: Jul 07, 2019 13:12:37.006 [23232] WARN - NAT: PMP, got an error: NATPMP_ERR_RECVFROM.
Line 6134: Jul 07, 2019 13:12:58.424 [29284] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-00743.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
Line 6314: Jul 07, 2019 13:13:22.393 [22228] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-00767.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
...
Line 19362: Jul 07, 2019 13:38:56.342 [29320] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-02301.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
Line 19535: Jul 07, 2019 13:39:19.363 [12172] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-02324.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
Line 19760: Jul 07, 2019 13:39:40.320 [22228] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-02345.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
Line 19778: Jul 07, 2019 13:39:40.704 [9056] DEBUG - NotificationStream: Removing because of error
Line 20043: Jul 07, 2019 13:40:05.366 [29132] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-02370.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
Line 20235: Jul 07, 2019 13:40:27.274 [22544] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-02392.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
...
Line 31699: Jul 07, 2019 13:58:58.316 [12172] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-03503.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
Line 31918: Jul 07, 2019 13:59:23.302 [29132] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-03528.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
Line 32132: Jul 07, 2019 13:59:47.338 [12172] ERROR - Caught exception trying to stream file: \\172.16.1.200\Video Conversion\Transcode\Sessions\plex-transcode-5a740b3c-0719-4484-91b8-0ce3f75c5006\media-03552.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
Line 32641: Jul 07, 2019 14:04:11.923 [24764] DEBUG - Job running: EAE_ROOT='\\?\P:\Video Conversion\Transcode\Sessions\EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='C\:\\Users\\AzJazz\\AppData\\Local\\Plex\ Media\ Server\\Codecs\\2144ff1-2376-windows-x86\\' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' C:\Program Files (x86)\Plex\Plex Media Server\Plex Transcoder.exe -y -safe 0 -skip_before_video_key 1 -skip_before_inpoint 1 -offset_inout 1 -i \\172.16.1.200\Multimedia\tv\.grab\73f8988d1f5ad59d8af7f89a062ed471c8d98a28\segment-list.txt -map 0 -c copy -loglevel quiet -loglevel_plex error "\\172.16.1.200\Multimedia\tv\.grab\73f8988d1f5ad59d8af7f89a062ed471c8d98a28\NOVA (1974) - S46E11 - Black Hole Universe-comskipped.ts"
Line 32737: Jul 07, 2019 14:05:13.501 [24096] ERROR - Error creating directory "\\172.16.1.200\Multimedia\tv\NOVA (1974)\Season 46": boost::filesystem::create_directories: Access is denied: "\\172.16.1.200\Multimedia\tv\NOVA (1974)"
Line 32737: Jul 07, 2019 14:05:13.501 [24096] ERROR - Error creating directory "\\172.16.1.200\Multimedia\tv\NOVA (1974)\Season 46": boost::filesystem::create_directories: Access is denied: "\\172.16.1.200\Multimedia\tv\NOVA (1974)"
Line 32739: Jul 07, 2019 14:05:13.509 [24096] ERROR - Couldn't rename file "\\172.16.1.200\Multimedia\tv\.grab\73f8988d1f5ad59d8af7f89a062ed471c8d98a28\NOVA (1974) - S46E11 - Black Hole Universe.ts" to "\\172.16.1.200\Multimedia\tv\NOVA (1974)\Season 46\NOVA (1974) - S46E11 - Black Hole Universe.ts": The system cannot find the path specified
Line 33024: Jul 07, 2019 14:05:17.906 [23920] ERROR - PlexClient::downloadContainer: expected MediaContainer element, found html
Line 33204: Jul 07, 2019 14:05:18.023 [23920] ERROR - PlexClient::downloadContainer: expected MediaContainer element, found html
Line 33875: Jul 07, 2019 14:07:29.157 [25564] ERROR - PlexClient::downloadContainer: expected MediaContainer element, found html
Line 34307: Jul 07, 2019 14:12:28.906 [20356] ERROR - PlexClient::downloadContainer: expected MediaContainer element, found html
Line 34426: Jul 07, 2019 14:12:37.930 [23212] WARN - NAT: PMP, got an error: NATPMP_ERR_RECVFROM.
Line 34872: Jul 07, 2019 14:27:31.644 [16996] ERROR - PlexClient::downloadContainer: expected MediaContainer element, found html
Line 35311: Jul 07, 2019 14:32:27.385 [4932] ERROR - PlexClient::downloadContainer: expected MediaContainer element, found html```This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.
