Ever since the Roku Beta version of Plex came out allowing for live stream I’ve run into an issue. After 60+ min of watching a single channel (and not changing channels at any point) the server will crash. I can reproduce this very easily as it’s happened now 5 times in the past 3 days. I’m in the process of testing to see if the web app version will do the same.
My initial guess is that since the DVR system has been so wonderfully built to auto record the live TV stream your watching so you can pause and rewind live TV, that there is a problem with the system truncating the temp file. Standard DVR’s only record your live channel for ~60 min before truncating the older stuff. I pulled logs and it looks like my theory is correct. The beginning of this log represents the last ~50 min or so of log. I’ve also had to truncate repeating errors in the log to fit it in the post.
Oct 15, 2017 18:48:15.962 [5256] WARN - Got a transcode session ping without a session GUID (or with an invalid one).
Oct 15, 2017 18:49:16.020 [5616] WARN - Got a transcode session ping without a session GUID (or with an invalid one).
Oct 15, 2017 18:50:16.076 [11872] WARN - Got a transcode session ping without a session GUID (or with an invalid one).
Oct 15, 2017 18:51:15.889 [5616] ERROR - Caught exception pruning transcoder directory on file 'media-00272.ts': boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts".
Oct 15, 2017 18:51:16.138 [4256] WARN - Got a transcode session ping without a session GUID (or with an invalid one).
Oct 15, 2017 18:51:18.282 [4336] ERROR - Caught exception pruning transcoder directory on file 'media-00272.ts': boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts".
Oct 15, 2017 18:53:44.176 [5256] ERROR - Caught exception pruning transcoder directory on file 'media-00272.ts': boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts".
Oct 15, 2017 18:53:44.368 [11836] WARN - Held transaction for too long (..\Sync\SyncItemGenerator.cpp:142): 0.953125 seconds
Oct 15, 2017 18:53:44.938 [11836] WARN - Held transaction for too long (..\Sync\SyncItemGenerator.cpp:142): 0.343750 seconds
Oct 15, 2017 18:53:45.482 [11836] WARN - Held transaction for too long (..\Sync\SyncItemGenerator.cpp:142): 0.406250 seconds
Oct 15, 2017 18:53:46.501 [11836] WARN - Held transaction for too long (..\Sync\SyncItemGenerator.cpp:142): 0.843750 seconds
Oct 15, 2017 18:53:47.994 [5616] ERROR - Caught exception pruning transcoder directory on file 'media-00272.ts': boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts".
Oct 15, 2017 18:53:48.431 [4336] ERROR - Caught exception pruning transcoder directory on file 'media-00272.ts': boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts".
Oct 15, 2017 18:53:50.227 [3308] ERROR - Caught exception pruning transcoder directory on file 'media-00272.ts': boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts".
Oct 15, 2017 18:53:51.785 [12000] ERROR - Caught exception pruning transcoder directory on file 'media-00272.ts': boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts".
Oct 15, 2017 18:53:53.816 [12000] ERROR - Caught exception pruning transcoder directory on file 'media-00272.ts': boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts".
Oct 15, 2017 18:53:56.286 [4256] ERROR - Caught exception pruning transcoder directory on file 'media-00272.ts': boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts".
Oct 15, 2017 18:53:58.435 [12000] ERROR - Caught exception pruning transcoder directory on file 'media-00272.ts': boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts".
Oct 15, 2017 18:54:00.977 [3308] ERROR - Caught exception pruning transcoder directory on file 'media-00272.ts': boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts".
Oct 15, 2017 18:54:03.678 [5616] ERROR - Caught exception pruning transcoder directory on file 'media-00272.ts': boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts".
Oct 15, 2017 18:54:16.313 [6576] WARN - Got a transcode session ping without a session GUID (or with an invalid one).
Oct 15, 2017 18:56:37.974 [0796] ERROR - Failed to delete session directory (boost::filesystem::remove: The process cannot access the file because it is being used by another process: "E:\Transcode\Sessions\plex-transcode-21a67b02-5dc6-46ea-aaa6-4ccffbef639f\media-00272.ts")
What do you mean by crashing the server? Does the Plex system tray icon disappear ? Does Plex Media Server.exe process disappear from Windows Task Manager process Detailed view?
By crash I mean the Plex service becomes completely unresponsive. No remote device, roku, firestick, xbox, or webapp can find it. As well as when locally on the server itself when I attempt to open up settings (127.0.0.1:32400) it is also unresponsive. So I go to close out of Plex entirely via the icon in system tray. However while the icon disappears when I select exit, none of the running Plex processes end or close out. I have to manually end the server process, transocoder process, and several relay processes. Only after I manually end these, can I restart plex and everything works fine again.
I have enabled debug logging and will attach the log within the next hour after it crashes.
So it hasn’t crashed yet, but I figured I’d post this anyways. My wife is the one at home helping me test right now by watching live TV on our Roku. About an hour after I turned debug on and restarted the server she told me that the channel she was watching kept going black/retrieving screen every 2-5 min. After a few min of this she changed the channel (sadly defeating my intention of running it until it crashed). However I have found something interesting since she has changed channel. Right before she changed, I had gone into my Transcode drive and found the folder and files related to the current live stream. At 65 min the original .ts file created when the stream first began (65 min ago) had not been deleted or truncated yet. Also, now that my wife has changed channel, the entire folder that was storing the files for the channel she had been watching, has yet to be deleted or removed from the drive.
I did a bit of digging myself in the Plex Server logs, and found what I thought to be some interesting warnings about delays in read/response from the transcode file. The file with the stream transcode is “plex-transcode-f7e6d2d3-fa7f-45c2-81d5-f30e1aa2a2a1”
What might also be a contributing factor in why it didn’t crash immediately at 60 min is I recently increase the drive space on my transcode drive. It happens to be a RAM drive on the VM that runs my Plex server. Originally only having 20GB of space on it, I’ve now doubled that to 40GB. Could be the crash was happening due to the transcode files not being truncated and then causing the transcode drive to fill up?
I will post the full zip file of the logs when I finally get it to crash, unless you’d like me to do that now, even before it’s technically crashed.
The transcode cache files should get purged on restart
Would not expect a crash if there is no space for transcode
Being not responsive and process still running in task manager could mean some deadlock issue / hang. A number of such issues were recently addressed. Logs would confirm if it is a deadlock and if it is then investigation would need logs plus porcess dump
Okay so, now I can’t seem to get it to crash anymore. Last time it crashed was over night Sunday/Monday. The only change I’ve made to my system since then was expanding my RAM drive. I do have the server set to auto update over night though, so unless a new update has come out in the past 48 hours…
However I’m still posting the logs here because it’s still acting up, just differently. Right around an hour of watching (10:38EDT) we start to see glitches where the video stream will drop for a few seconds, re buffer and continue. It will stream fine for 5-10 min, and then have 2-5 min of glitching. If we change channel to a different channel the glitching stops and works fine, until 60 min have passed watching that one channel.
As of the time of this post, it looks like none of the transcode files for the stream from the Roku have begun to truncate, which I’ve noticed will happen with a 60+ min stream off the Web Gui. So is truncation/deletion of 60 min old live transcode files a thing, or no?
What do you define as restart to have the transcode cache purge? Plex service restart? Server restart? Or simply transcode restart as it starts to work on a new channel or stream?
Okay, left for work this morning and left a roku running streaming a cable tv channel. Looks like it crashed like before. I restarted it and downloaded the logs. Will see if I can replicate and actually get an exact time as to when it crashes.
I’ve been running into this same issue with live TV through the Roku preview build. My wife forgets to stop the live TV stream after watching for some time and it causes the Plex server to freeze and become unresponsive. All the processes are still running but I can’t access Plex through the web interface or any player. I manually have to end all the Plex server tasks before I can restart it.
I haven’t been around the times when it seizes up so I’ve only come back a few hours later to find the server unresponsive. I’ll keep an eye on it closer to grab the logs when it happens again.
@silverdragon6687 said:
Okay, left for work this morning and left a roku running streaming a cable tv channel. Looks like it crashed like before. I restarted it and downloaded the logs. Will see if I can replicate and actually get an exact time as to when it crashes.
Thanks for the logs. This was a deadlock issue where requests started to build up around 09:14 am and failures and hangs started soon after that.
A deadlock fix was just identified from dump supplied by other user and the fix will be released soon
To confirm if it is the same issue, a process dump would be needed together with the logs.
I presume a process dump at the time of deadlock would be the most useful? Any recommendations on the easiest way of doing that?
Yes process dump at time of deadlock and after restart to get the logs zip
Two ways to try -
SysInternals Process Explorer - create full dump
Windows Task Manager - Dump Process
There have been a mixture of Process Explorer failing to create the dump and also had Windows Task manager create a dump that had no useful info on the threads)
So try first Process Explorer
Upload the zipped dump on dropbox/google drive etc and send me link by private message
You can upload logs zip here
Okay, got it to crash around 9:15 AM EDT. Sadly the process dump logs are ALL too big to attached (each one is 30-255MB) is there any other way I can get them to you? I took the dumps before I restarted the processes (when it had dead hung) and the plex log after I restarted the processes.
@silverdragon6687 said:
Okay, got it to crash around 9:15 AM EDT. Sadly the process dump logs are ALL too big to attached (each one is 30-255MB) is there any other way I can get them to you? I took the dumps before I restarted the processes (when it had dead hung) and the plex log after I restarted the processes.
Thank you very much for the logs and dumps.
I can confirm that this deadlock is one of two that are being fixed and I expect the fix to be released in either the next release or one after
Update 1.9.6.4385 came out yesterday and it appears to have fixed the issue. Not only does live stream from Roku last 2+ hours (and counting) but I can confirm that it is also actively truncating the temp files of the live stream.
@silverdragon6687 said:
Update 1.9.6.4385 came out yesterday and it appears to have fixed the issue. Not only does live stream from Roku last 2+ hours (and counting) but I can confirm that it is also actively truncating the temp files of the live stream.
Good to hear. May be there were several issues causing your streaming problems
Actually within a day after my last post I realized that it was still doing the same thing, don’t know why it didn’t freak out that one morning, but it continued to do so the next several days.
I just downloaded 1.9.6.4385 so here’s hoping it’s all working nicely now!
