WordPress.org

Make WordPress Core

Opened 4 months ago

Last modified 2 weeks ago

#53705 new defect (bug)

Plugin upgrade deletes files from other in-progress upgrades

Reported by: bpayton Owned by:
Milestone: 6.0 Priority: normal
Severity: normal Version: 5.8
Component: Upgrade/Install Keywords:
Focuses: Cc:

Description

If two plugin upgrades are requested at the same time, the later upgrade can interfere with the earlier upgrade by deleting its source files while the earlier upgrade is still in progress.

This can lead to either disappearing plugins or plugins with missing files.

This is because Plugin_Upgrader::upgrade() calls WP_Upgrader::run() which calls WP_Upgrader::unpack_package() here, and WP_Upgrader::unpack_package() unconditionally deletes all files from the wp-content/upgrade/ directory here.

If plugin upgrade A is in progress with new plugin files under wp-content/upgrade/, plugin upgrade B will delete them as part of unpacking its zip file.

Plugin upgrade conflicts can cause a plugin to disappear with the following sequence:

  1. Plugin upgrade A downloads a zip for the new version here
  2. Plugin upgrade A calls WP_Upgrader::unpack_package() to unpack the zip to a unique subdirectory of wp-content/upgrade/ here
  3. Plugin upgrade A deletes the old version's plugin files here. This happens because Plugin_Upgrader::upgrade() sets the clear_destination flag to true here.
  4. Plugin upgrade B downloads a zip for its new version here
  5. Plugin upgrade B calls WP_Upgrader::unpack_package() to unpack its zip here, deleting all files of plugin upgrade A from wp-content/upgrade/ here
  6. Plugin upgrade A attempts to copy the new version into the plugins dir here, but the new version's files are completely gone.
  7. Plugin upgrade A has already deleted its old version's files, and it cannot copy the new files because they no longer exist.
  8. Plugin upgrade A encounters an error, and its plugin has completely disappeared.

This upgrade behavior can also lead to upgraded plugins with missing files, following a progression similar to the one above. The only difference is that, in case of missing plugin files, plugin upgrade A succeeded in copying some files before plugin upgrade B deleted the rest of them. Here, plugin upgrade A encounters an error, and the new plugin version only has some of its files.

At Automattic, we encountered this when WordPress.com attempted to request multiple, individual plugin updates for a standalone WP site all at once via Jetpack. We encountered frequent, reproducible plugin update corruption and tracked this down via error logging added to WP core source.

NOTE: Based on this WP_Upgrader code, it might be that simultaneous, mixed plugin and theme updates can also encounter this issue, but I have not tested it.

Attachments (3)

php-errors-plugin-corruption-20210720.txt (6.3 KB) - added by bpayton 4 months ago.
PHP error logs demonstrating this issue
wp-upgrader-error-logging.diff (3.1 KB) - added by bpayton 4 months ago.
Patch WP_Upgrader to error log and show concurrent upgrade issues
avoid-corrupting-concurrent-plugin-upgrades.diff (839 bytes) - added by bpayton 4 months ago.
Patch to avoid conflicts by only deleting older, leftover upgrade files

Download all attachments as: .zip

Change History (16)

#1 @bpayton
4 months ago

Instead of deleting old upgrade files on the fly, I think wp-content/upgrade/ cleanup should probably happen as part of a focused WP-Cron event, perhaps only deleting plugin dirs that are at least X hours old. I am working on a patch to propose this.

#2 @bpayton
4 months ago

This might be the cause of #51823. The experience and log messages there are similar to those found when reproducing missing and incomplete plugins with concurrent upgrade requests.

#3 @SergeyBiryukov
4 months ago

  • Milestone changed from Awaiting Review to 5.9

This ticket was mentioned in Slack in #core-auto-updates by desrosj. View the logs.


4 months ago

@bpayton
4 months ago

PHP error logs demonstrating this issue

#5 @bpayton
4 months ago

I went back and instrumented WordPress upgrade logic with error logging that is more readable than what I did privately for myself. The logs now attached here show the following:

  1. An update failure leading to a disappearing plugin (coblocks)
  2. An update failure caused by a target directory being deleted while a zip was being unpacked to that directory (wordpress-seo). In this case, nothing was left in a broken state because the previous version was not yet deleted.

Each line of the log has a REQUEST ID at the beginning. Use that to track which request is doing what.

If you search for "coblocks" in the logs, you can see that there are two different requests that do things to coblocks. One is downloading and unpacking (REQUEST 0059), and the other is deleting the unpacked files (REQUEST 0062). The coblocks upgrade errors before it can copy any new files but after it calls clear_destination() to delete its old files. After this, the coblocks plugin was no longer present on my site.

If you search for "wordpress-seo" in the logs, you can again see two different requests working with a plugin. One is downloading and unpacking wordpress-seo (REQUEST 0061), and the other is deleting the unpacked files (REQUEST 0063). In this case, REQUEST 0061 is still unpacking wordpress-seo files when REQUEST 0063 comes along to delete the unpack destination, and REQUEST 0061 errors because it can no longer put unpacked files into the deleted destination directory.

What these logs do not show is a broken plugin with only some of its files, but I think that is just a matter of timing. If a plugin gets to start copying its new files and another deletes those new files in the middle of copying, that could result in a plugin upgrade failure with a plugin directory containing only some of its files.

Last edited 4 months ago by bpayton (previous) (diff)

#6 @bpayton
4 months ago

Instead of deleting old upgrade files on the fly, I think wp-content/upgrade/ cleanup should probably happen as part of a focused WP-Cron event, perhaps only deleting plugin dirs that are at least X hours old. I am working on a patch to propose this.

Maybe it would be better to just add a condition so leftover wp-content/upgrade/ subdirectories are only removed if they are over X units of time old (maybe over a day old to be really conservative). It's kind of a hack, but it's also simpler than worrying about WP-Cron events for cleanup and seems very low risk.

Also, as mentioned in Slack, I will work to provide usable repro instructions for this for core as I am currently only using WordPress.com to generate concurrent plugin update requests.

#7 @bpayton
4 months ago

Here's how I am reproducing this issue with core WordPress. Thanks to @aristath for pointing out that updating inactive plugins doesn't enable maintenance mode, which might otherwise block concurrent update attempts.

First, create a script to force install out-of-date plugin versions:

#!/usr/bin/env bash

function wp_install() {
        wp --skip-plugins plugin install --force --version="$2" "$1"
}

wp_install 'amp' '2.1.2'
wp_install 'coblocks' '2.14.0'
wp_install 'layout-grid' '1.6'
wp_install 'page-optimize' '0.5.0'
wp_install 'wordpress-seo' '16.6'

# See that we have outdated plugins
wp plugin list

Then, to test:

  1. Start with a clean, default WordPress 5.8 installation and access to WP-CLI
  2. Apply the patch to add WP_Upgrader error logging
  3. Run the above script to install/downgrade outdated plugin versions
  4. Make sure those plugins are deactivated
  5. Open /wp-admin/plugins.php in your a modern web browser (I used latest Firefox)
  6. Open the browser dev tools Network tab so the browser starts collecting network requests
  7. Run this in the dev tools console to make sure plugin update links are found:
    $$('.inactive + .plugin-update-tr .update-link')
    
  8. If there are links found, run this in the dev tools console to request updates for the inactive plugins all at once:
    $$('.inactive + .plugin-update-tr .update-link')
      .map( a => a.href )
      .forEach( updateUrl => {
        fetch( updateUrl )
          .then( r => r.text() )
          .then( ( ...args ) => console.log( `${updateUrl} resolved`) )
          .catch( e => console.error( e ) )
    } )
    
  9. Examine the PHP error logs for failures
  10. When each request completes, a message should printed to the console. Once all the requests are done, you can examine each request's output for failures in the dev tools Network tab.
  11. Run wp plugin list to see if any of the plugins are still on old versions
  12. Check if any of the plugins disappeared after the upgrade attempt. This was not uncommon in my testing.

Repeat to see different outcomes. In my experience, something usually fails, but sometimes everything works OK.

If your testing goes like mine, you will see a mixture of failed upgrades, disappearing plugins, and maybe new plugin versions that are missing files.

I'm sorry these are so long. Testing this is kind of a pain. But I think these instructions should work with a default WordPress 5.8 installation.

If you're able to try this, I would love to hear how it went for you. Thanks!

Last edited 4 months ago by bpayton (previous) (diff)

@bpayton
4 months ago

Patch WP_Upgrader to error log and show concurrent upgrade issues

@bpayton
4 months ago

Patch to avoid conflicts by only deleting older, leftover upgrade files

#8 @bpayton
4 months ago

To make reproducing this easier, I added a patch to add error logging to WP_Upgrader and updated the repro instructions to use that. Each log message is prefixed with the request URI, and what is happening should be much clearer with the error logging.

I also uploaded a small patch to avoid this issue by deleting only older files from the upgrade directory.

#9 @bedas
4 months ago

Perhaps this is related https://core.trac.wordpress.org/ticket/50349

While the symptoms seem slightly different it seems rot have a similar background.

#10 @afragen
4 months ago

In unpatched WP 5.8 I ran in private browser window.

First pass got an error with AMP plugin and plugin missing at conclusion.
Second pass Yoast SEO didn't update, got a strange WP CLI error but plugin available fro update afterwards.
Third pass in new private browser window, no errors.

Sorry, not being able to get consistent errors doesn't make it easier to test. 🤨

This ticket was mentioned in Slack in #core by audrasjb. View the logs.


2 weeks ago

This ticket was mentioned in Slack in #core-auto-updates by audrasjb. View the logs.


2 weeks ago

#13 @audrasjb
2 weeks ago

  • Milestone changed from 5.9 to 6.0

Moving to milestone 6.0 as per today's bug scrub.

Note: See TracTickets for help on using tickets.