Git-updater: Very long update of the Plugins page

[picasso]

After a long break, I went to the Plugins page. Updating the page took 27 seconds. Of these, 22 seconds occupy HTTP requests that were made by the github-updater. In total, github-updater requested information about 7 plugins and one theme. In total, it made 38 HTTP requests - for each object 4-6 requests. Each request is approximately 0.4-0.6 seconds.

For each object, github-updater requested GitHub, and then api.wordpress.org.
For 6 objects out of 8, the request for api.wordpress.org was unnecessary.
This is already saving for 3-4 seconds.

In any case, I wanted to draw attention to this situation. This workflow can be optimized. One of the obvious solutions is not to make requests for all plugins and themes right after the cache is expired. Just create a queue and take from there for 1-2 objects and put the rest on the next request to the Wordpress Admin.

[afragen]

I am well aware of this problem as I test with lots of plugins/themes. Each repo has about 5-6 API calls. You can skip many of these calls by using a filter and turning off branch switching if not needed.

https://github.com/afragen/github-updater/wiki/Developer-Hooks

I’m also trying to figure out a real asynchronous solution when I have the time.

[afragen]

I've gotten the remote updating working with wp-cron locally. I think you'll like the next release.

[picasso]

Thanks Andy!
Now it works much faster, almost unnoticeably.

[picasso]

I found a small problem in the new approach.
If I want to update a fresh plugin from the repository, I click "Refresh Cache" ... and nothing happens.
I understand that the cache is reset but the repository does not poll at the same time. In the end, you have to wait up to 12 hours to see that the new plugin is available.

I think that when you press "Refresh Cache" the effect should not be delayed.

[afragen]

The issue isn’t waiting 12 hours it’s waiting for WP-cron to run. Let me see if I can force it to run after the flush.

[afragen]

I added some code to call wp-cron.php. I hope that the next page load would then trigger the refreshing. LMK if this isn't sufficient.

[afragen]

I think this way is better. https://github.com/afragen/github-updater/commit/c0190d6ab21e5fb0024c40f9916edbd5dde0bf4d

[picasso]

I do not know why but there is almost one day passed and there is no sign of any updates from plugins.
I attach list of cron events which are still registered in my Wordpress because it looks very strange for me... a lot of non-repeating events which were not executed.. maybe this will help you...

Cron Events-WordPress.pdf

[afragen]

@picasso update to latest develop branch. I've added some code to clear the duplicate cron jobs when the cache is flushed.

Try flushing the cache afterwards. You will also have to load at least one other page to trigger WP-Cron.

[picasso]

Andy,

• duplicate cron jobs are now deleted.
• still nothing happens after the cache is flushed.
  And I still can see one ghu_get_remote_plugin task in the list of my cron events... which means it was not run.

You use wp_schedule_single_event( time(), to add this task...
I'm not an expert of wp_cron but maybe the problem with time() argument... maybe use something like time() + 60?

PS. and yes, I loaded many pages after flushing the cache.

[picasso]

I found in Wordpress docs:

_Note that scheduling an event to occur before 10 minutes after an existing event of the same name will be ignored,_

Maybe problem is related to existing event of the same name?

[afragen]

We only need one of those events to run. Extra events are very difficult to prevent and if it runs will have a negligible impact as everything will be cached already.

Can you confirm that the HTTP request to wp-cron.php is running?

[afragen]

Query Monitor plugin is excellent for viewing HTTP requests.

[picasso]

what I see in Call Stack on the page:

do_action('init')
wp-includes/plugin.php:453
wp_cron()
wp-includes/cron.php:367
spawn_cron()
wp-includes/cron.php:340
wp_remote_post()
wp-includes/http.php:187
WP_Http->post()
wp-includes/class-http.php:594
WP_Http->request()
wp-includes/class-http.php:223

I think it means that cron was running...

[picasso]

and the list of cron events is growing again:
Cron Events-WordPress.pdf

[afragen]

@picasso in reviewing the first log you sent in see all of the wp-cron events are scheduled to have run, some days earlier, yet none have run.

[afragen]

Query Monitor should show something like

(Non-blocking request: blocking=false)
(Certificate verification disabled: sslverify=false)
https://thefragens.net/wp-cron.php
?doing_wp_cron=1508082137.8453290462493896484375

under HTTP Requests.

[afragen]

Don’t worry about how many extra Cron events there are. When wp-cron runs they should clear or flushing cache will clear them.

[picasso]

I see 2 post requests:

(Non-blocking request: blocking=false)
(Certificate verification disabled: sslverify=false)
https://photosafari.wpengine.com/wp-cron.php
?doing_wp_cron=1508082342.5689079761505126953125

POST
(Certificate verification disabled: sslverify=false)
https://photosafari.wpengine.com/wp-cron.php
?doing_wp_cron=1508082342.7033898830413818359375

[afragen]

Can you set up a local development environment and test? Maybe WPEngine is doing something?

[afragen]

The way WP-Cron works is when that HTTP POST request is made all Cron jobs set to run will run.

It’s one of the reasons wp-Cron isn’t a _real_ Cron.

[picasso]

no, I could set up a local dev environment only in week... Now I have only remote control and limited time...
maybe WPEngine is doing something but all my cron jobs work...

[picasso]

But I can try to add some debug output to spawn_cron() to understand what's going on... I will try this evening.

[afragen]

From the first report you sent the earliest Cron jobs should have run more than 24 hours before.

[picasso]

And I will write to WPEngine support.

[afragen]

BTW, to disable the new cron updating and return to the old method you can use the following filter.

add_filter( 'github_updater_disable_wpcron', '__return_true' );

[afragen]

FYI, committed some code to avoid creating duplicate cron jobs. https://github.com/afragen/github-updater/commit/5e983cd4f9c71f68de5c995b94fe4c2b51cc5221

[picasso]

I found out that the file wp-cron.php was called, but then it was interrupted for an unclear reason. After I called it manually, everything worked and the list of events was cleared. I added debugging there and will watch if this situation occurs again.

[afragen]

Fascinating, if you can figure out what interrupted wp-cron.php that would be helpful.

[afragen]

Please reopen if the issue is in GHU.

[picasso]

Ok. I found the reason - it was because of SSL redirect on Wordpress Admin.

But I decided to write here because of 2 small things I found:

• the new update of GHU was installed in afragen-github-updater-d9cf712 folder instead of github-updater... not a big problem but I would like to let you know.

• there is PHP Notice:

Undefined index: Release Asset in /nas/content/live/photosafari/wp-content/plugins/github-updater/src/GitHub_Updater/Plugin.php on line 162, referer: http://photosafari.wpengine.com/wp-cron.php?doing_wp_cron=1508156403.9888849258422851562500

[afragen]

Try using the branch switch to reinstall GHU, that should take care of the naming issue or wait for next update. I haven’t seen naming issues in a while. I assume something short circuiting in the update process.

I’ll look into the PHP notice.

[afragen]

The header _Release Asset_ should be added automatically and be empty if none exists in the actual plugin headers. This is the same for all added headers.

See if it persists once the naming is corrected.

[afragen]

@picasso how did you figure out wp-cron.php was being interrupted. I think I'm having the same issue on a site but don't know where/how to debug.

Thanks.

[picasso]

Andy,

sorry for delay. I'm on a trip now and I have very limited access to the Internet.

To debug Wordpress sources, I use my class that implements some functions for writing debugging information to a log file. Then I include this file at the top of the Wordpress source and use these functions to understand the task flow or watch the value of variables. I can give you this file if you need it.

[afragen]

Thanks Dmitry.

In the latest develop I’ve committed some code that will temporarily revert back to the previous update method if the wp-cron event is over 12 hours old.

This doesn’t address the primary problem however, that wp-cron isn’t running.

I’ve looked at my htaccess file and don’t see anything odd. Anything that can help me figure out why WP-cron isn’t running would be very helpful, thanks.

[picasso]

My problem was not connected with htaccess file. It was connected with SSL. On WPEngine side was activated mu-plugin to force SSL on Wordpress Admin. Everything worked before I switched my site to SSL and added certificate. After that wp-cron stopped working but I did not realize it. Only when I got the problems with GHU - I understood that something was wrong. And then I started to debug it and with my debug function I found out that wp_remote_post (which should call wp-cron.php) returns 301 error. Something with redirect. After that I asked WPEngine support to help me to understand the reason of this error and together we found this conflict with forced SSL on admin part. Maybe this story will help you somehow.

[admecoach]

@picasso Can I ask what resolution you came to with wpengine and the ssl issue related to cron updates for the update check - did they or you make adjustments to the instance? (Note: i'm not having problems on my staging testing but want to be aware as I deploy to live sites)

[picasso]

@admecoach I started a "live chat" with their support, explained the problem to them, they checked the configuration files and corrected them.