Server Version#: 1.22.3.4392
For the second time in approximately the last 2-3 weeks, the guide has failed to refresh automatically and I lost two days of recorded content (because it never recorded). I have already upgraded to the current server version of 1.23.1.4602, but both of these failures occurred on the version listed above.
The release notes for the 1.23.1.4602 version mention a fix in the Networking functions to address “some” systems that may have DNS failures, but there is nothing beyond that.
Does anyone know how to track this issue down -definitively-? I have a total of three servers, two running this version of Linux AND server and a third running this version of the server but a different version of linux. It was only one of the two ‘identical’ systems that failed to update and missed a LOT of content recordings. It’s 100% frustrating when you get ZERO warning about an issue that has clearly been going on for up to two full weeks!
From what I’ve seen on the forums the DNS issue is with eero wifi systems. There are a couple of threads on the topic, but this one suggests a workaround has been implemented in Plex in the interrim though the real problem needs to be fixed in the eero firmware.
A good place to start would be to look at your Plex Server logs, preferably at debug level. The automatic guide refresh is supposed to happen nightly, initiated by the butler during the window you have set in Plex Web under Settings → Scheduled Tasks. If you have given the butler a small window to run it could be a problem. If you look in the logs (the logs roll, so “Plex Media Server.log”, “Plex Media Server.1.log”, etc.) starting at your set schedule start time you should see where the butler schedules the EPG refresh with a line something like “Butler: Scheduling randomized task ‘RefreshEpgGuides’ in 237 minutes.”. Figure out when this would be and go to that time in the logs and look for EPG guide refresh activity starting, such as “Activity: registered new activity xxxxxx-xxxxxxx-xxxx-xxxxx - Refreshing guide data” (and look for errors.)
Also in Plex Web go to Settings → Manage → Live TV & DVR, and click on “DVR Settings”. Scroll to the bottom of the window that pops up and make sure “Perform Refresh of Guide Data” is checked. Just under the “DVR Settings” link is a “Refresh Guide” link where you can manually initiate a refresh, which can be helpful while troubleshooting if that successfully works, or if it fails you can note the time and then the EPG refresh error will be near the end of the “Plex Media Server.log” file if you go and download logs a couple minutes after the error.
Thanks.
I don’t have the eero stuff, so that would seemingly not apply.
The DVR is configured to refresh the guide data. I have Scheduled Tasks configured to run between 2AM and 7AM with basically everything checked. Manually refreshing the guide data takes “around” five minutes.
In looking at the logs, the only references I am finding in the main server logs for EPG are loads of the following lines:
WARN - Subscription: No container available for /tv.plex.providers.epg.cloud:7/metadata/plex
I see similar warnings in my logs about the EPG container not being available, but I’m not having EPG refresh problems. Since it is just a warning I’m leaning toward this not being the root of the problem though we should keep it in mind. Since your manual EPG refresh works I’m thinking to focus on the butler to see if it is actually initiating.
Do you see the butler waking up an starting at 2AM in your logs? My window is 1AM-6AM, and I see the following:
May 29, 2021 01:00:01.569 [0x7f9dd3ba1b38] DEBUG - EPG[cloud]: Next thing to start/end is at 2021-05-29 05:01:00 GMT (in 60 seconds)
May 29, 2021 01:00:11.053 [0x7f9dd3ba1b38] DEBUG - Statistics: Flushing 1 expired bandwidth entries, 0 expired media entries.
May 29, 2021 01:01:01.580 [0x7f9dd3415b38] DEBUG - EPG[cloud]: Next thing to start/end is at 2021-05-29 05:30:00 GMT (in 1740 seconds)
May 29, 2021 01:04:41.555 [0x7f9dd3ba1b38] DEBUG - Butler: we're in the window, starting.
May 29, 2021 01:04:41.555 [0x7f9dd3ba1b38] DEBUG - Butler: Waking up!
May 29, 2021 01:04:41.555 [0x7f9dd3ba1b38] DEBUG - Butler: Scheduling randomized task 'RefreshEpgGuides' in 237 minutes.
Also, I notice you are a bit behind on your PMS server version with the most recent public release being 1.23.1.4602. It would be worth trying the update to see if it resolves the problem, though the only relevant release note in the versions between I see is regarding guide refreshes not cancelling immediately.
The server version that I listed for this thread is/was the version that was installed and running both times that the complete lack of refresh led to losing recorded content. I did include a comment that I have since upgraded to 1.23.1.4602 (but have no viable feedback regarding that version as of yet because it was done in the last few days).
To find potentially relevant log entries, I did the following:
cd "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Logs"
grep -i EPG *.log
The outputs are limited to the one I posted. Zero other entries related to EPG. If I instead look for anything about the butler in all of those log files:
grep -i butler *.log
I get this:
Plex Tuner Service.1.log:May 29, 2021 08:27:21.958 [0x7fdce2387808] INFO - [I] tvbutler_aux_t::init
Plex Tuner Service.2.log:Apr 25, 2021 12:27:24.781 [0x7fb0bc416740] INFO - [I] tvbutler_aux_t::init
Plex Tuner Service.2.log:May 29, 2021 08:26:32.961 [0x7fb0bc416740] INFO - [I] tvbutler_aux_t::term
Plex Tuner Service.3.log:Apr 15, 2021 09:11:13.570 [0x7f556addc740] INFO - [I] tvbutler_aux_t::init
Plex Tuner Service.3.log:Apr 25, 2021 12:26:25.407 [0x7f556addc740] INFO - [I] tvbutler_aux_t::term
Plex Tuner Service.4.log:Apr 02, 2021 14:41:54.933 [0x7f8f377fc740] INFO - [I] tvbutler_aux_t::init
Plex Tuner Service.4.log:Apr 15, 2021 09:09:19.822 [0x7f8f377fc740] INFO - [I] tvbutler_aux_t::term
Plex Tuner Service.5.log:Mar 30, 2021 15:59:41.203 [0x7f9a4a507740] INFO - [I] tvbutler_aux_t::init
Plex Tuner Service.log:May 29, 2021 09:47:09.690 [0x7f946d2b2808] INFO - [I] tvbutler_aux_t::init
That’s it. Nothing more.
Are your logs set at debug level? The grep statement output you are seeing is consistent with what you would get if debug level logging is off.
To check, go in Plex Web and go to Settings → General. Make sure you have selected the “General” under Settings on the left, not the “General” under “Plex Web” on the left. Once on the “General” screen make sure the “Show Advanced” button has been clicked. Ensure “Enable Plex Media Server debug logging” is checked, but “Enable Plex Media Server verbose logging” is off. Click the “Save Changes” button, and restart your Plex Media Server service.
No, it wasn’t set for Debug. I have enabled it and expect that I’ll need to wait overnight for the Butler process to hopefully fire up and run.
I checked the logs again today and all of the log files have been overwritten. My scheduled maint window is 2AM, and the absolute earliest entry I can find that contains “Butler” is in the “.4” log file and it shows a timestamp of about 2:15AM.
The “.5” file was totally overwritten as well. The beginning of it starts around 1:15AM, but there’s no instance of “Butler” in the file that I can find. Weird.
There are a TON of entries about scanning intro’s… And I do have a rather large library of media. Don’t really see it get past about 98%. Maybe it’s trying to do those first and the guide refresh is just never occurring?
Just confirming, you just turned on debug logging, and not verbose? (If you logs have fully rolled, then grep for verbose in all of your logs should return nothing.)
If only debug is on, then for it to roll all your Plex logs so quickly does indicate that your server is very busy during your maint window. Intro detect isn’t dissimilar to commercial skip, and can create significant CPU demand. I can’t speak to how the butler prioritizes, but it is possible for it to simply run out of time to do everything that could be scheduled in the maint window, and it isn’t getting to the EPG refresh.
Is it viable for you to significantly expand your maint window, at least for a while? If you recently turned on intro detection and have a large library it would help it work through that demand.
Verbose logging is not enabled, just Debug.
I have four libraries that have Intro Detection enabled. One is very small in terms of total content and nothing has been added to it in over five months.
A second item routinely gets about 20 shows added to it per week.
A third item routinely gets about 10 shows added to it per week.
The fourth item gets about 50-60 items added per week.
The fourth library mentioned above is also shared at the disk level with another Plex server that records into this directory as well. The second server does NOT have Intro Detection enabled for its library access.
While I understand the premise of increasing the time allotted for the maintenance work, these settings have been in place for quite some time. I would not expect there to be a need to allow more time for it to complete because the majority of the shows that are recorded into the folders have been there for months and this problem only recently occurred.
I don’t have nearly the volume added as you, but I’ll look to see if I can find a night where several items are added in the near future see if intro detect is taking longer, though recently my number of recorded shows dropped significantly just due to season breaks. I’m on v1.23.2.4600/linux and last night only had one new item. The intro detect seems to have take less than a minute during the maint window.
Maybe someone else with a similar issue here can jump in? There is always the possibility that there’s an issue in the Plex release, though I didn’t pick up on a similar trend just quickly scanning the forum.
Just throwing out ideas to see if something pops: any possibility that something else is running during this window on that computer that is using significant CPU or disk? (e.g. timeshift, media backup jobs/rsync, etc.) It’s probably a tough window to directly monitor - worth a simple cron job running multiple times during your Plex maint window, executing top in batch mode to a file so you could look at CPU use and wait?
I appreciate the exploration of ideas…
I do have a few different cron jobs that run somewhat frequently on that box. They are predominantly focused on cleaning up the filesystem from bad files left behind on SAMBA shares by Mac’s and ensuring that the libraries and media are correctly owned by the Plex user. Since these both have the potential to be disk-intesive, it’s possible that they are slowing down the maintenance tasks. I will update the schedule so that they will run OUTSIDE of the Plex maintenance schedule and see what happens.
That’s definitely worth a shot since there is some evidence of your Plex butler doing a lot of work during the window. It would still be good to be able to see the logs at the beginning of your maintenance window to see if the butler is even attempting to schedule the EPG refresh!
Ok… Seems I have gotten two new entries that I hadn’t seen before:
Plex Media Server.1.log:Jun 02, 2021 02:21:21.204 [0x7f559d82ab38] DEBUG - Butler: Scheduling randomized task 'RefreshEpgGuides' in 77 minutes.
Plex Media Server.2.log:Jun 02, 2021 02:14:10.478 [0x7f33eb0f5b38] DEBUG - Butler: Starting delayed task RefreshEpgGuides.
Is there anywhere that will show me the date of the last guide refresh or how far out the guide data goes besides the log files? I can only easily see the next 7 days in the Live TV & DVR section. Going beyond that means moving ahead one half hour at a time which is painful.
Wow, date of last EPG refresh would be a great feature! It is probably already a feature request, but if it isn’t it should be. The easiest way I know isn’t great - look at your DVR schedule and go right as far as possible. If you see a recording scheduled for a date then you know you have EPG data at least through that date. Unfortunately that only an indicator, and doesn’t really tell you when your EPG was last refreshed.
The fact that your logs show the EPG refresh task starting at 02:14, and then 7 minutes later it schedules another EPG refresh - this looks odd to me. I’d suggest manually looking at the logs between these two entries to see if you can see the EPG actually refresh. I may have made a choice to not run it for some reason, or errored, and so it rescheduled.
Two different log files, too…
Ok… It’s getting worse / more interesting.
I have been using a combination of a HDHR Extend and HDHR Quatro. I removed the Extend and added a second Quatro.
I attempted to add the second Quatro to my existing DVR setup and it simply refuses to add it. I set the country to United States and input my correct ZIP code as I did with the original two devices. It throws an error stating
Unsupported location
This location isnt covered by Plex DVR guide data. Because you already set up a tuner using Plex DVR guide data, we are unable to offer the option to use a XMLTV guide. Please select a different location.
If I go to my other server, I can add the new Quatro without issue.
Just upgraded to 1.23.2.4656 and the results are the same.
And more frustration… the schedule of recording that has been in place for months now shows all future shows as being on channels not tuned by the device I have linked. Something has apparently gone very awry with the Guide… It wasn’t refreshing, now I can’t add a tuner device because it claims my guide is associated to a different area, and it won’t record anything going forward.
I have had a similar issue for months. I have found that the only way to get the EPG to refresh correctly is to manually restart the PMS service. I find if I do this on a Friday, the EPG for the following week will get updated correctly. The second week out though remains incorrect, so the service restart is a weekly occurrence.
