wpsharks / comet-cache

An advanced WordPress® caching plugin inspired by simplicity.
https://cometcache.com
GNU General Public License v3.0
76 stars 17 forks source link

cron_zencache_cleanup never executing! #653

Open xberg opened 8 years ago

xberg commented 8 years ago

Hi Using Pro version 160103. The _cron_zencache_cleanup never executes. I use Crontrol to monitor the wp_cron and there's very strange behavior: The "next run" time keeps changing!!! I have it set to run every 3 hours, but the next run time is always in just 1 minute time! When I refresh the crontrol page I see your CRON is still schedule to run in a minute. and it NEVER NEVER runs. So this just fills my cache and I have several times a day to manually delete the cache! Same bahavior with _cron_zencache_auto_cache but I don't use this.

I tried deleting and reinstalling: same problem.

And you CRONs are the ONLY ones I cannot delete or edit with crontrol. It's like your system is continusouly deleting and recreating new ones!

Please help me fix this ASAP.

xberg commented 8 years ago

I do NOT have the Disable Cache Expiration If Server Load Average is High enabled, but it seems to behave like it is and that my server is high.

raamdev commented 8 years ago

@xberg I'm not able to reproduce this behavior. The cronjobs are behaving as expected for me:

40 seconds before running

2016-01-10_07-34-24

While running

2016-01-10_07-35-17

Just after running

2016-01-10_07-35-44


I suggest disabling deletion safeguards (ZenCache → Plugin Options → Plugin Deletion Safeguards) and then deactivating and deleting the ZenCache plugin. Then install it fresh and see if you still have issues.

(Note that if you have a custom plugin configuration that you want to backup, you can use ZenCache → Plugin Options → Import/Export Options.)

Also, it's normal for ZenCache to recreate the cron events if you delete them. ZenCache needs those events to be present for the plugin to work properly, so if ZenCache is active and it detects the events are missing, it will recreate them. If you don't want ZenCache to recreate the events, simply deactivate the plugin.

raamdev commented 8 years ago

@xberg Also, if you want to change the schedule at which the cache cleanup occurs, you can create a custom schedule with WP Crontrol (Dashboard → Settings → Cron Schedules) and then select that custom schedule in ZenCache → Plugin Options → Cache Expiration Time → Cache Cleanup Schedule:

2016-01-10_07-41-00

xberg commented 8 years ago

Raam, Just because you cannot reproduce the issue does not mean that the issue is not there. I am experienced with CRON jobs and I can tell you that there is a major problem on my setup with just your plugin, and this only started a few weeks ago (at least 2 releases ago). Yes, I can change the schedule to whatever I want, but your cleanup NEVER runs. It keeps reseting itself to run in a minute (but NEVER runs).

Let's try to find a temporary workaround: is there any code I could run thru a PHP to replicate the behavior of the cleanup? ie, I would be creating my own CRON?

Because I am using a 2 GB RAMDRIVE it fills in less than a day and then starts producing a massive number of errors. As such your plugin in unusable now.

xberg commented 8 years ago

http://prntscr.com/9oo1oz http://prntscr.com/9oo1t5 http://prntscr.com/9oo1wq http://prntscr.com/9oo1zu http://prntscr.com/9oo22i http://prntscr.com/9oo25s http://prntscr.com/9oo2b0

Here I am refreshing CRONTROL every 20 seconds. You can see that your CRONs are alway reset to run in 1 minute. In the meanwhile you can see that another cron, the NXS decrements correctly.

You have a problem and you need to acknowledge it.

raamdev commented 8 years ago

@xberg Have you reproduced this issue in a clean WordPress installation? See Testing ZenCache in a Clean WordPress Installation

If you have, then please provide me with a list of steps to reproduce this issue on my site.

xberg commented 8 years ago

Raamdev,

Do you have anything in your program that resets the counter to 1 minute? It would not surprise me at all that your "Disable Cache Expiration If Server Load Average is High" is creating the problem.

Otherwise is there any instruction I could run to replicate the behavior of your CRON?

Without this, what is your reimbursement policy as I can no longer use your caching with this bug.

xberg commented 8 years ago

Ah!! I found your code that was creating the bug. I cannot believe you did not immediately find it yourself after my description!

It's code you added 20151220 which resets the CRON to run in a minute: exactly the description I made initially!!!

It's in CronUtils.php and here it is:

/*

/*

xberg commented 8 years ago

Remving this line fixed your bug:

|| $self->options['crons_setup_on_wp_with_schedules'] !== sha1(serialize(wp_get_schedules()))

jaswrks commented 8 years ago

@xberg Watch it with the tone! Show some respect here, and we will do the same.

I cannot believe you did not immediately find it yourself after my description!

Please cleanup the code that you posted and I will review as well. So far it looks like you solved the problem, but I'm not clear on why you're calling this a :bug: yet. Please explain in greater details and we can work together at solving it.

xberg commented 8 years ago

Youi're right: I'm sorry about the tone.

raamdev commented 8 years ago

@xberg writes...

$self->options['crons_setup_on_wp_with_schedules'] !== sha1(serialize(wp_get_schedules()))`

The only reason that line would cause problems is if wp_get_schedules() changes on every page load (and that should never happen, which again, is why I asked you to reproduce this in a clean installation of WordPress to rule out issues with other plugins or custom code).

That line basically says, "if there has been a change to the WordPress Cron Schedules (i.e., you added/removed/changed a cron schedule), then set up the ZenCache cron events again". This is necessary because if you changed or delete a cron schedule that ZenCache was using, ZenCache must reconfigure its own cron events to make sure that it keeps working as expected.

I'm not seeing any bug in that code. I have tested it and it is working as expected.

xberg commented 8 years ago

Raamdev, I am not a developer so I cannot help you. I just know that removing this line fixed my problem. With the line there was a continuous loop which kept creating a new cron job that was to execute in a minute, but immediately got deleted and recreated.

I understand it's hard to debug without being able to replicate, but I am convinced I am not the only one who will have this problem so at least now you know what has helped me fix things. The only reason I noticed this problem is that I am using a 2 GB Ramdrive for zencache and this filled up fast. If I were using harddrive it could have been weeks before I noticed a problem. And I also have crontrol installed which allowed me to see this problem: most users will not have crontrol.

raamdev commented 8 years ago

@xberg Again, have you reproduced this in a clean WordPress environment? I'm guessing you did not, because if you did I have a strong feeling you'd see that there is no bug there. :-)

lkraav commented 8 years ago

@raamdev I'm seeing the same thing on my multisite installation subsites. This cron schedule gets bumped to 1min away on every page load. There doesn't seem to be anything that would be messing with cron schedules that would cause the hash to change. I'll investigate some more.

EDIT !wp_next_scheduled('_cron_'.GLOBAL_NS.'_auto_cache') always evaluates to true for me, causing the ever-reset symptom.

EDIT I'm just going to flat out return from $self->checkCronSetup() right now pending further instructions. This eliminates slow update queries on every page load.

xberg commented 8 years ago

Thanks ikraav for sharing your fix. Concretly, what file did you edit?

lkraav commented 8 years ago

Thanks ikraav for sharing your fix. Concretly, what file did you edit?

./src/includes/closures/Plugin/CronUtils.php the same thing you already found. It's not a fix, just a stopgap until people are able to figure out what's happening.

raamdev commented 8 years ago

@lkraav The wp_next_scheduled() function (see docs) just checks if a given action hook, in this case _cron_zencache_auto_cache, has been scheduled.

If the conditional where that check exists evaluates to true (i.e., the event has not been scheduled), then ZenCache schedules the event with this line:

wp_schedule_event(time() + 60, 'every15m', '_cron_'.GLOBAL_NS.'_auto_cache');

So once the event has been scheduled, !wp_next_scheduled('_cron_'.GLOBAL_NS.'_auto_cache') should return false, since the event has now been scheduled.

https://github.com/websharks/zencache-pro/blob/160103/src/includes/closures/Plugin/CronUtils.php#L23-L58

I can't explain why that's not working properly for you, but in all of our tests it works as expected.

lkraav commented 8 years ago

I will re-evaluate each of the conditions again. It may not be about just wp_next_scheduled() here.

xberg commented 8 years ago

Today I upgraded to V160222 Pro and the issue was back. I returned to /wp-content/plugins/zencache-pro/src/includes/closures/Plugin/CronUtils.php and commented out as I did before: || $self->options['crons_setup_on_wp_with_schedules'] !== sha1(serialize(wp_get_schedules()))

but this time it was not enough, and the CRON kept resetting itself to 1 minute.

But also commenting out: || $self->options['crons_setup_with_cache_cleanup_schedule'] !== $self->options['cache_cleanup_schedule'] worked and now the CRON is no longer reset.

Just FYI, as I have no time to dig further into this matter and that my fix solves the problem for me. Good luck.

raamdev commented 8 years ago

@xberg @lkraav I'm reopening this issue.

@lkraav reported in https://github.com/websharks/comet-cache/issues/667#issuecomment-187297229 that this issue occurred again with the Comet Cache update, which tells me this bug is most likely related to a certain combination of events that are not being considered in the checkCronSetup() routine, which is resulting in that routine updating the database repeatedly.

I have yet to figure out what combination of events is causing this, but since I have seen this happen during testing in the past (it happened to me once or twice, but then the problem disappeared and I was not able to reproduce it again at the time).

I'm going to reopen this GitHub issue so that we can continue tracking reports and so that it can be researched.

xberg commented 8 years ago

Hi: quick update. Today I upgraded from Zencache Pro to Comet cache Pro V 160227 and the problem re-appeared. So this time I had to comment out 3 conditions, as commenting out only 2 still continusouly resets the CRON to 60 seconds. The additional condition I had to comment out was: !wp_next_scheduled('_cron_'.GLOBAL_NS.'_cleanup')

in addition to:

  //|| $self->options['crons_setup_with_cache_cleanup_schedule'] !== $self->options['cache_cleanup_schedule']
        //|| $self->options['crons_setup_on_wp_with_schedules'] !== sha1(serialize(wp_get_schedules()))

Good luck, now that I know the "trick" it's not a big inconvenience to comment this out with each upgrade.

raamdev commented 8 years ago

@xberg Thank you for the update! Would you mind providing a list of active plugins on your site?

xberg commented 8 years ago

Sure @raamdev I have emailed this to you. Let me email this to you privately as a public list of plugins might be a security threat in case one gets exposed.

raamdev commented 8 years ago

@xberg Thank you. I received the email. That's quite a few plugins--I was hoping to review the code for those plugins to see if one of them might be causing problems, but that's too long of a list.

@lkraav Would you be able to provide a list of active plugins as well? That way I can see if there are any plugins you're both using and hopefully narrow this down.

xberg commented 8 years ago

@raamdev haha, I completely understand. And it might be another 100 things that are causing this such as server settings. Perhpas a better use of your time would be to simply have a geek option somewhere that allows users that see this behavior to simply tick that option which in turns comments out the whole "cron reset" function. Or simply like me tell them to edit the file: no big deal at all.

xberg commented 8 years ago

@raamdev Eventually I will set up a test platform and turn the plugins off one by one...

xberg commented 8 years ago

@raamdev I created a near clone from my production site and I was not able to reproduce the behavior. On the test platform Comet Cache worked normally. The biggest difference is no traffic on the test site :)

raamdev commented 8 years ago

@xberg Thanks for the follow-up. I can't imagine a difference in traffic affecting this issue... It must be something else...

xberg commented 8 years ago

Hi, Another follow up. Today I upgraded Comet Cache Pro to V160417 and the same problem occured. In this version you changed the directory structure, so for those facing the same problem as I have the file to modify is in: /wp-content/plugins/comet-cache-pro/src/includes/traits/Plugin

And this time I had to comment out these 4 lines for the cron to stop resetting: //|| $this->options['crons_setup_on_namespace'] !== __NAMESPACE__ //|| $this->options['crons_setup_with_cache_cleanup_schedule'] !== $this->options['cache_cleanup_schedule'] //|| $this->options['crons_setup_on_wp_with_schedules'] !== sha1(serialize(wp_get_schedules())) //|| !wp_next_scheduled('_cron_'.GLOBAL_NS.'_cleanup')

jaswrks commented 8 years ago

@xberg writes...

@raamdev I created a near clone from my production site and I was not able to reproduce the behavior. On the test platform Comet Cache worked normally. The biggest difference is no traffic on the test site :)

That seems to suggest that this is impacted by a race condition. It might help if we skip all of our CRON-related checks in this routine if CRON is currently in the middle of running a process where events are juggled around a bit and wp_next_scheduled() might return an unexpected value.

if(!get_transient('doing_cron')
   && $self->options['crons_setup'] < 1439005906
   ...

Referencing: https://github.com/WordPress/WordPress/blob/master/wp-cron.php#L78

raamdev commented 8 years ago

Next Release Changelog:

lkraav commented 8 years ago

Superb, looking forward to testing this in the next release!

lkraav commented 8 years ago

In my multisite, 160629-RC is still performing two UPDATE queries on every page load for cron entries. Yes, every single page load, it's easy to verify with plugins/query-monitor. As soon as I re-insert the early return into checkCronSetup() as described here earlier, these queries go away.

raamdev commented 8 years ago

@lkraav Thank you for the update. Would you mind posting those queries as reported by Query Monitor here?

raamdev commented 8 years ago

@lkraav I'm reviewing the database queries that you emailed to me and I noticed something odd about the value of one of the options being set in the update query.

In Comet Cache, the crons_setup_on_namespace Comet Cache option gets set to __NAMESPACE__ during the Comet Cache setup, which (for the past several versions) should be:

WebSharks\CometCache\Pro\Traits\Plugin

I confirmed that in my test installs, the crons_setup_on_namespace option is set to the above.

However, in the database query output that you sent me, it appears that it's getting set to:

WebSharks\\CometCache\\Pro\\Traits\\Plugin\

Could you check your database via PhpMyAdmin and tell me if the value of crons_setup_on_namespace on your site actually matches what is above? (I just want to make sure the query monitor plugin that you're running didn't change the query output.)

SELECT * FROM `wp_sitemeta` WHERE `meta_key` LIKE 'comet_cache_options'

Also, if you could create a PHP file on the site with the following and confirm that __NAMESPACE__ is not for some reason outputting the namespace with double-back-slashes, that would be great:

<?php
namespace something\somewhere\here;

echo __NAMESPACE__;

The output should be:

something\somewhere\here
raamdev commented 8 years ago

@lkraav Another thing: have you tried backing up your Comet Cache options, disabling Comet Cache → Plugin Options → Plugin Deletion Safeguards, disabling + deleting Comet Cache Pro, and then reinstalling?

These steps will clear out any existing Comet Cache Pro options in the database and allow you to reinstall with a fresh copy. (You can then restore the Comet Cache Pro options backup.) If there's corruption in the Comet Cache database options, that should resolve the issue.

@lkraav One other thing I noticed while analyzing the database queries you sent me: I noticed _cron_zencache_cleanup in one of the update queries that updates the cron option—that tells me you might have old ZenCache cron information in the database. I can't imagine how that would cause problems here, but you could you edit the wp_options table in question (the exact table name can be found in the queries you sent me) and then delete any ZenCache-related schedules if they exist.

raamdev commented 8 years ago

@lkraav Any update on the above? ↑

renzms commented 8 years ago

@raamdev

Was unable to reproduce issue. Tested in a clean install running WordPress 4.6.1 + Comet Cache™ Pro v160917, monitored Cron via WPX Cron Manager Light Version 2.0.4 plugin

42 Min before

screen shot 2016-10-05 at 7 28 21 am

While Running

screen shot 2016-10-05 at 7 53 08 am

After 23 Mins

screen shot 2016-10-05 at 8 15 09 am

raamdev commented 8 years ago

@renzms Thanks. I'm closing this for now and will reopen if we get any more information.

teknofilo commented 7 years ago

@raamdev, I am running Comet Cache v160917 and I am also seeing this behaviour

_cron_comet_cache_cleanup job is always to scheduled to run in 1 minute, but it never runs. If run it manually, files are properly deleted.

raamdev commented 7 years ago

@teknofilo Could you provide us with some information about your system? WordPress version, PHP version, web server type (Apache/Nginx), and a list of active plugins that you have in WordPress would be helpful.

teknofilo commented 7 years ago

@raamdev sure, this is the info:

Linux 4.4.0-36-generic #55-Ubuntu SMP x86_64 PHP Version 7.0.8-0ubuntu0.16.04.3 Apache/2.4.18 (Ubuntu)

Plugins:

raamdev commented 7 years ago

@teknofilo That's a lot of active plugins. Have you tried reproducing the issue in a clean WordPress installation?

Also, is this WP Multisite or just a standard single-site installation?

teknofilo commented 7 years ago

@raamdev

No, I have not tried to reproduce it, that is not easy.

It is a single-site installation.

I have been playing with the cleanup schedule and I have set it to 'hourly'. With this frequency, the cron job seems to be properly scheduled because now I see that the job will be executed in 60 mins, 40 mins, 20 mins etc. as time goes by.

However, the files in the directory are not deleted even though lots them are old (expiration time is 2 hours, so there should not be files >3 hours). It looks like the job is not executed or, if it is, it does not execute properly. Is there anything I can do to verify weather the clean up job gets executed?

lkraav commented 7 years ago

I can also confirm on multisite this issue is still there on v160917.

xberg commented 7 years ago

Hi team, I just wanted to let you know that this issue is still there. Every single version I need to comment out a few lines so that _cron_comet_cache_cleanup actually runs, otherwise it resets itself without ever running. I installed today V170220 and the bug is still there. Not sure if this is actively explored anymore... thanks

In this version I was able to get it working by commenting out a single line (perhaps this will allow you to narrow down root causes):

This line is: || $this->options['crons_setup_on_wp_with_schedules'] !== sha1(serialize(wp_get_schedules())) || !wp_next_scheduled('cron'.GLOBAL_NS.'_cleanup')

in: if ((!get_transient('doing_cron') && $this->options['crons_setup'] < 1439005906) || $this->options['crons_setup_on_namespace'] !== NAMESPACE || $this->options['crons_setup_with_cache_cleanup_schedule'] !== $this->options['cache_cleanup_schedule'] //|| $this->options['crons_setup_on_wp_with_schedules'] !== sha1(serialize(wp_get_schedules())) || !wp_next_scheduled('cron'.GLOBAL_NS.'_cleanup') /[pro strip-from="lite"]/ // Auto-cache engine. || !wp_next_scheduled('cron'.GLOBAL_NS.'_auto_cache') /[/pro]/ )

xberg commented 7 years ago

I only have 5 common plugins with tecnofilo above: Comet Cache MailPoet Newsletters NextScripts: Social Networks Auto-Poster TablePress WP Crontrol

raamdev commented 7 years ago

@xberg Thanks for the additional information. The problem I'm having is reproducing this issue consistently. Until I can reproduce it consistently, it's rather difficult to identify the cause.

@renzms Could you try installing the above plugins with the latest version of Comet Cache and see if you can reproduce the problem described in this issue?

renzms commented 7 years ago

@raamdev

Unable to reproduce bug

List of Plugins:

screen shot 2017-02-23 at 7 41 26 pm

Tested Using:

WordPress Version: 4.7.2 Current WordPress Theme: Twenty Seventeen version 1.1

PHP Version: 7.0.10-2+deb.sury.org~xenial+1 MySQL Version: 10.0.29-MariaDB-0ubuntu0.16.04.1

Active Plugins: Comet Cache Version 170220 MailPoet Newsletters Version 2.7.7 NextScripts: Social Networks Auto-Poster Version 3.7.16 TablePress Version 1.7 WP Crontrol Version 1.4

_for the purpose of multiple tests and time, the Cron: _cron_comet_cache_cleanup, was allowed to run on its own automatically set at 15 min intervals_

WP CRONTROL

1 Min before running

screen shot 2017-02-23 at 8 12 54 pm

While Running

screen shot 2017-02-23 at 8 13 46 pm

After Running

screen shot 2017-02-23 at 8 14 45 pm

Observations to consider

Manually Modifying the Cron Job via WP Crontrol does not necessarily update the Recurrence of the Cron Job until it actually runs the already in progress Cron Job (15min)

screen shot 2017-02-23 at 8 23 03 pm

screen shot 2017-02-23 at 8 23 26 pm

Executing the Cron Job Manually via WP Control does not reset the counter.

screen shot 2017-02-23 at 8 23 39 pm

Manually Modifying the Cron Job via the Comet Cache Plugin, (Dashboard → Plugin Options → Cache Expiration Time) does not necessarily update the Recurrence of the Cron Job until it actually runs the already in progress Cron Job (15min)

screen shot 2017-02-23 at 8 23 59 pm

screen shot 2017-02-23 at 8 28 31 pm


Alternate Test with: Advanced Crontrol Manager Plugin

Advanced Crontrol Manager Plugin

1 Min before running

screen shot 2017-02-23 at 7 58 04 pm

While Running

screen shot 2017-02-23 at 7 58 49 pm

After Running

screen shot 2017-02-23 at 7 59 09 pm