Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
125 changes: 123 additions & 2 deletions inc/media_offload.php
Original file line number Diff line number Diff line change
Expand Up @@ -67,6 +67,17 @@ class Optml_Media_Offload extends Optml_App_Replacer {
*/
const TRANSFER_LOCK_TTL = 600;

/**
* Option counting the failed attempts of the current transfer step, and the steps skipped so far.
* It is an option rather than a transient so an object cache eviction can't reset the count.
*/
const STEP_FAILURES_OPTION = 'optml_transfer_step_failures';

/**
* How many times a failing transfer step is retried before the chain moves on.
*/
const MAX_STEP_RETRIES = 5;

/**
* Flag used inside wp_get_attachment url filter.
*
Expand Down Expand Up @@ -1988,6 +1999,7 @@ public static function move_images( $action, $refresh ) {
$lock_token = self::acquire_transfer_lock( $action );

if ( false !== $lock_token ) {
delete_option( self::STEP_FAILURES_OPTION );
$total = ceil( $count / $batch );
self::schedule_action(
time(),
Expand Down Expand Up @@ -2274,9 +2286,16 @@ public function start_processing_images( $action, $batch, $page, $total, $step,

self::$instance->settings->update( $option, 'disabled' );

self::$instance->settings->update( 'show_offload_finish_notice', $type );
// A transfer that skipped failing steps left images behind, so it does not report success.
$skipped = self::get_skipped_steps( $lock_token );
delete_option( self::STEP_FAILURES_OPTION );
if ( $skipped > 0 ) {
self::$instance->logger->add_log( $type, $skipped . ' step(s) were skipped after failing ' . self::MAX_STEP_RETRIES . ' times. Start the transfer again to move the images left behind.' );
} else {
self::$instance->settings->update( 'show_offload_finish_notice', $type );
}

// Transfer completed successfully: release the lock.
// Transfer finished: release the lock.
self::release_transfer_lock( $lock_token );

return;
Expand Down Expand Up @@ -2322,12 +2341,22 @@ public function start_processing_images( $action, $batch, $page, $total, $step,
$lock_token,
]
);
self::clear_step_failures( $lock_token );
} catch ( Exception $e ) {
// Reschedule the cron to run again after a delay. Sometimes memory limit is exausted.
// This is a retryable error, so the lock is kept rather than released.
$delay_in_seconds = 10;
self::$instance->logger->add_log( $type, $e->getMessage() );

// A step that keeps failing would be retried every few seconds forever, with the transfer
// shown as running. After a few attempts the chain moves on, so the transfer can finish
// and the images left behind can be retried.
if ( self::count_step_failure( $lock_token, $action, $step ) >= self::MAX_STEP_RETRIES ) {
self::record_skipped_step( $lock_token );
self::$instance->logger->add_log( $type, 'Step ' . $step . ' failed ' . self::MAX_STEP_RETRIES . ' times, moving on to the next one.' );
$step = $step + 1;
}

self::schedule_action(
time() + $delay_in_seconds,
'optml_start_processing_images',
Expand All @@ -2345,6 +2374,98 @@ public function start_processing_images( $action, $batch, $page, $total, $step,
}
}

/**
* Read the step failures record of a transfer chain.
*
* @param string $lock_token The transfer lock token of the chain.
*
* @return array{token: string, action: string, step: int, count: int, skipped: int} The record, empty for another chain.
*/
private static function get_step_failures( string $lock_token ): array {
$failures = get_option( self::STEP_FAILURES_OPTION );
$record = [
'token' => $lock_token,
'action' => '',
'step' => 0,
'count' => 0,
'skipped' => 0,
];
if ( ! is_array( $failures ) || ! isset( $failures['token'] ) || $failures['token'] !== $lock_token ) {
return $record;
}

return [
'token' => $lock_token,
'action' => isset( $failures['action'] ) ? (string) $failures['action'] : '',
'step' => isset( $failures['step'] ) ? (int) $failures['step'] : 0,
'count' => isset( $failures['count'] ) ? (int) $failures['count'] : 0,
'skipped' => isset( $failures['skipped'] ) ? (int) $failures['skipped'] : 0,
];
}

/**
* Count a failed attempt of a transfer step.
*
* @param string $lock_token The transfer lock token of the chain.
* @param string $action The transfer action.
* @param int $step The step that failed.
*
* @return int How many times in a row this step has failed.
*/
private static function count_step_failure( string $lock_token, string $action, int $step ): int {
$record = self::get_step_failures( $lock_token );
if ( $record['action'] !== $action || $record['step'] !== $step ) {
$record['count'] = 0;
}
$record['action'] = $action;
$record['step'] = $step;
++$record['count'];
update_option( self::STEP_FAILURES_OPTION, $record, false );

return $record['count'];
}

/**
* Remember that the chain skipped a step that kept failing.
*
* @param string $lock_token The transfer lock token of the chain.
*
* @return void
*/
private static function record_skipped_step( string $lock_token ): void {
$record = self::get_step_failures( $lock_token );
$record['count'] = 0;
++$record['skipped'];
update_option( self::STEP_FAILURES_OPTION, $record, false );
}

/**
* Clear the failed attempts after a step succeeds, keeping the count of skipped steps.
*
* @param string $lock_token The transfer lock token of the chain.
*
* @return void
*/
private static function clear_step_failures( string $lock_token ): void {
$record = self::get_step_failures( $lock_token );
if ( 0 === $record['count'] ) {
return;
}
$record['count'] = 0;
update_option( self::STEP_FAILURES_OPTION, $record, false );
}

/**
* How many steps the chain skipped after they kept failing.
*
* @param string $lock_token The transfer lock token of the chain.
*
* @return int
*/
public static function get_skipped_steps( string $lock_token ): int {
return self::get_step_failures( $lock_token )['skipped'];
}

/**
* Alter attachment image src for offloaded images.
*
Expand Down
133 changes: 133 additions & 0 deletions tests/test-media.php
Original file line number Diff line number Diff line change
Expand Up @@ -543,6 +543,139 @@ public function test_background_step_does_nothing_while_another_run_moves_images
$this->assert_moving_images_lock_is_free();
}

/**
* A step that throws every time is retried a few times, then the chain moves on to the next step
* instead of retrying it every few seconds forever.
*/
public function test_failing_step_moves_on_after_retries(): void {
( new Optml_Settings() )->update( 'rollback_status', 'enabled' );
delete_option( Optml_Media_Offload::STEP_FAILURES_OPTION );
$token = Optml_Media_Offload::acquire_transfer_lock( 'rollback_images' );
$fail = function () {
throw new Exception( 'cloud lookup failed' );
};
add_action( 'pre_get_posts', $fail );

$steps = [];
for ( $attempt = 1; $attempt <= Optml_Media_Offload::MAX_STEP_RETRIES; $attempt++ ) {
_set_cron_array( [] );
Optml_Media_Offload::instance()->start_processing_images( 'rollback_images', 10, 1, 5, 1, $token );
$steps[] = $this->scheduled_transfer_step();
}
remove_action( 'pre_get_posts', $fail );

$this->assertSame( array_merge( array_fill( 0, Optml_Media_Offload::MAX_STEP_RETRIES - 1, 1 ), [ 2 ] ), $steps );
$this->assertSame( 1, Optml_Media_Offload::get_skipped_steps( $token ) );
$this->assertSame( 0, get_option( Optml_Media_Offload::STEP_FAILURES_OPTION )['count'] );
delete_transient( Optml_Media_Offload::TRANSFER_LOCK_TRANSIENT );
}

/**
* A step that succeeds clears the failures of the one before it, but the skipped steps are kept.
*/
public function test_successful_step_clears_failures(): void {
( new Optml_Settings() )->update( 'rollback_status', 'enabled' );
$token = Optml_Media_Offload::acquire_transfer_lock( 'rollback_images' );
update_option( Optml_Media_Offload::STEP_FAILURES_OPTION, $this->step_failures( $token, Optml_Media_Offload::MAX_STEP_RETRIES - 1, 1 ), false );

_set_cron_array( [] );
Optml_Media_Offload::instance()->start_processing_images( 'rollback_images', 10, 1, 5, 1, $token );

$this->assertSame( 2, $this->scheduled_transfer_step() );
$this->assertSame( 0, get_option( Optml_Media_Offload::STEP_FAILURES_OPTION )['count'] );
$this->assertSame( 1, Optml_Media_Offload::get_skipped_steps( $token ) );
delete_transient( Optml_Media_Offload::TRANSFER_LOCK_TRANSIENT );
}

/**
* Failures left by an earlier transfer don't count toward the retries of a new one.
*/
public function test_failures_of_another_transfer_are_ignored(): void {
( new Optml_Settings() )->update( 'rollback_status', 'enabled' );
$token = Optml_Media_Offload::acquire_transfer_lock( 'rollback_images' );
update_option( Optml_Media_Offload::STEP_FAILURES_OPTION, $this->step_failures( 'old-transfer', Optml_Media_Offload::MAX_STEP_RETRIES - 1, 2 ), false );
$fail = function () {
throw new Exception( 'cloud lookup failed' );
};
add_action( 'pre_get_posts', $fail );

_set_cron_array( [] );
Optml_Media_Offload::instance()->start_processing_images( 'rollback_images', 10, 1, 5, 1, $token );
remove_action( 'pre_get_posts', $fail );

$this->assertSame( 1, $this->scheduled_transfer_step() );
$this->assertSame( 1, get_option( Optml_Media_Offload::STEP_FAILURES_OPTION )['count'] );
$this->assertSame( 0, Optml_Media_Offload::get_skipped_steps( $token ) );
delete_transient( Optml_Media_Offload::TRANSFER_LOCK_TRANSIENT );
}

/**
* A transfer that skipped steps does not show the "Transfer Complete" notice.
*/
public function test_transfer_with_skipped_steps_does_not_report_success(): void {
$settings = new Optml_Settings();
$settings->update( 'rollback_status', 'enabled' );
$settings->update( 'show_offload_finish_notice', '' );
$token = Optml_Media_Offload::acquire_transfer_lock( 'rollback_images' );
update_option( Optml_Media_Offload::STEP_FAILURES_OPTION, $this->step_failures( $token, 0, 1 ), false );

Optml_Media_Offload::instance()->start_processing_images( 'rollback_images', 10, 6, 5, 6, $token );

$settings = new Optml_Settings();
$this->assertSame( 'disabled', $settings->get( 'rollback_status' ) );
$this->assertSame( '', $settings->get( 'show_offload_finish_notice' ) );
$this->assertFalse( get_option( Optml_Media_Offload::STEP_FAILURES_OPTION ) );
}

/**
* A transfer that ran every step shows the "Transfer Complete" notice.
*/
public function test_transfer_without_skipped_steps_reports_success(): void {
$settings = new Optml_Settings();
$settings->update( 'rollback_status', 'enabled' );
$settings->update( 'show_offload_finish_notice', '' );
$token = Optml_Media_Offload::acquire_transfer_lock( 'rollback_images' );
update_option( Optml_Media_Offload::STEP_FAILURES_OPTION, $this->step_failures( 'old-transfer', 0, 3 ), false );

Optml_Media_Offload::instance()->start_processing_images( 'rollback_images', 10, 6, 5, 6, $token );

$this->assertSame( 'rollback', ( new Optml_Settings() )->get( 'show_offload_finish_notice' ) );
}

/**
* Build a step failures record.
*
* @param string $token The transfer lock token.
* @param int $count The failed attempts of step 1.
* @param int $skipped The skipped steps.
*
* @return array{token: string, action: string, step: int, count: int, skipped: int}
*/
private function step_failures( string $token, int $count, int $skipped ): array {
return [
'token' => $token,
'action' => 'rollback_images',
'step' => 1,
'count' => $count,
'skipped' => $skipped,
];
}

/**
* @return int|null The step of the background transfer step waiting in WP-Cron.
*/
private function scheduled_transfer_step(): ?int {
foreach ( (array) _get_cron_array() as $hooks ) {
if ( isset( $hooks['optml_start_processing_images'] ) ) {
$event = reset( $hooks['optml_start_processing_images'] );

return (int) $event['args'][4];
}
}

return null;
}

/**
* @return int The background transfer steps waiting in WP-Cron.
*/
Expand Down
Loading