Merge pull request #137 from woocommerce/24-03/retry-after-429

Luc45 · web-flow · commit 72d145d9d1a1 · 2024-03-05T14:44:53.000-03:00
Retry after 429
diff --git a/_tests/QITSelfTests.php b/_tests/QITSelfTests.php
@@ -290,9 +290,6 @@ function run_test_runs( array $test_runs ) {
 
 	$qit_run_processes = [];
 
-	// If running a lot of tests, wait between any remote request to prevent 429.
-	$should_wait = array_sum( array_map( 'count', $test_runs ) ) > 3;
-
 	// Dispatch all tests in parallel using the qit binary.
 	foreach ( $test_runs as $test_type => &$test_type_test_runs ) {
 		foreach ( $test_type_test_runs as &$t ) {
@@ -376,10 +373,6 @@ function run_test_runs( array $test_runs ) {
 				'QIT_NON_JSON_OUTPUT'      => $t['non_json_output_file'],
 			];
 
-			if ( $should_wait ) {
-				$env['QIT_WAIT_BEFORE_REQUEST'] = 'yes';
-			}
-
 			$qit_process->setEnv( $env );
 
 			add_task_id_to_process( $qit_process, $t );
diff --git a/_tests/tests/__snapshots__/ActivationTest__test_activation_genericphp74wp62_woostable_php74_wprc_f236c472885ad1cea386db6a9f198c5e__1.php b/_tests/tests/__snapshots__/ActivationTest__test_activation_genericphp74wp62_woostable_php74_wprc_f236c472885ad1cea386db6a9f198c5e__1.php
@@ -97,7 +97,7 @@
                         },
                         {
                             "file": "\\/var\\/www\\/html\\/wp-settings.php",
-                            "line": 679,
+                            "line": 695,
                             "function": "do_action"
                         },
                         {
@@ -207,7 +207,7 @@
                         },
                         {
                             "file": "\\/var\\/www\\/html\\/wp-settings.php",
-                            "line": 679,
+                            "line": 695,
                             "function": "do_action"
                         },
                         {
@@ -279,7 +279,7 @@
                         },
                         {
                             "file": "\\/var\\/www\\/html\\/wp-settings.php",
-                            "line": 679,
+                            "line": 695,
                             "function": "do_action"
                         },
                         {
diff --git a/_tests/tests/__snapshots__/ActivationTest__test_activation_php81_woorc_php81_wprc_15d317e57322fe19f87aeeb57cad8452__1.php b/_tests/tests/__snapshots__/ActivationTest__test_activation_php81_woorc_php81_wprc_15d317e57322fe19f87aeeb57cad8452__1.php
@@ -90,7 +90,7 @@
                         },
                         {
                             "file": "\\/var\\/www\\/html\\/wp-settings.php",
-                            "line": 679,
+                            "line": 695,
                             "function": "do_action"
                         },
                         {
@@ -203,7 +203,7 @@
                         },
                         {
                             "file": "\\/var\\/www\\/html\\/wp-settings.php",
-                            "line": 679,
+                            "line": 695,
                             "function": "do_action"
                         },
                         {
@@ -316,7 +316,7 @@
                         },
                         {
                             "file": "\\/var\\/www\\/html\\/wp-settings.php",
-                            "line": 679,
+                            "line": 695,
                             "function": "do_action"
                         },
                         {
diff --git a/_tests/tests/__snapshots__/ActivationTest__test_activation_php81_woostable_php81_wprc_83dc095f2903767ea60c9a7e396dd4d0__1.php b/_tests/tests/__snapshots__/ActivationTest__test_activation_php81_woostable_php81_wprc_83dc095f2903767ea60c9a7e396dd4d0__1.php
@@ -90,7 +90,7 @@
                         },
                         {
                             "file": "\\/var\\/www\\/html\\/wp-settings.php",
-                            "line": 679,
+                            "line": 695,
                             "function": "do_action"
                         },
                         {
@@ -203,7 +203,7 @@
                         },
                         {
                             "file": "\\/var\\/www\\/html\\/wp-settings.php",
-                            "line": 679,
+                            "line": 695,
                             "function": "do_action"
                         },
                         {
@@ -316,7 +316,7 @@
                         },
                         {
                             "file": "\\/var\\/www\\/html\\/wp-settings.php",
-                            "line": 679,
+                            "line": 695,
                             "function": "do_action"
                         },
                         {
diff --git a/qit b/qit
diff --git a/src/src/RequestBuilder.php b/src/src/RequestBuilder.php
@@ -28,6 +28,9 @@ class RequestBuilder {
 	/** @var int */
 	protected $retry = 0;
 
+	/** @var int */
+	protected $retry_429 = 5;
+
 	/** @var int */
 	protected $timeout_in_seconds = 15;
 
@@ -145,14 +148,6 @@ public function request(): string {
 			throw new DoingAutocompleteException();
 		}
 
-		// Allow to wait from the outside to avoid 429 on parallel tests.
-		if ( getenv( 'QIT_WAIT_BEFORE_REQUEST' ) === 'yes' ) {
-			// Wait between 1 and 60 seconds.
-			$to_wait = rand( intval( 1 * 1e6 ), intval( 60 * 1e6 ) );
-			usleep( $to_wait );
-			App::make( Output::class )->writeln( sprintf( 'Waiting %d seconds before request...', number_format( $to_wait / 1e6, 2 ) ) );
-		}
-
 		$curl = curl_init();
 
 		$curl_parameters = [
@@ -162,6 +157,7 @@ public function request(): string {
 			CURLOPT_POSTREDIR      => CURL_REDIR_POST_ALL,
 			CURLOPT_CONNECTTIMEOUT => $this->timeout_in_seconds,
 			CURLOPT_TIMEOUT        => $this->timeout_in_seconds,
+			CURLOPT_HEADER         => 1,
 		];
 
 		if ( App::make( Output::class )->isVeryVerbose() ) {
@@ -231,34 +227,52 @@ public function request(): string {
 			App::make( Output::class )->writeln( sprintf( '[QIT DEBUG] Running external request: %s', json_encode( $request_in_logs, JSON_PRETTY_PRINT ) ) );
 		}
 
-		$result               = curl_exec( $curl );
-		$curl_error           = curl_error( $curl );
+		$result     = curl_exec( $curl );
+		$curl_error = curl_error( $curl );
+
+		// Extract header size and separate headers from body.
+		$header_size = curl_getinfo( $curl, CURLINFO_HEADER_SIZE );
+		$headers     = substr( $result, 0, $header_size );
+		$body        = substr( $result, $header_size );
+
 		$response_status_code = curl_getinfo( $curl, CURLINFO_HTTP_CODE );
 		curl_close( $curl );
 
 		if ( ! in_array( $response_status_code, $this->expected_status_codes, true ) ) {
-			if ( $proxied && $result === false ) {
-				$result = sprintf( 'Is the Automattic Proxy running and accessible through %s?', Config::get_proxy_url() );
+			if ( $proxied && $body === false ) {
+				$body = sprintf( 'Is the Automattic Proxy running and accessible through %s?', Config::get_proxy_url() );
 			}
 
 			if ( ! empty( $curl_error ) ) {
 				// Network error, such as a timeout, etc.
 				$error_message = $curl_error;
 			} else {
 				// Application error, such as invalid parameters, etc.
-				$error_message = $result;
+				$error_message = $body;
 				$json_response = json_decode( $error_message, true );
 
 				if ( is_array( $json_response ) && array_key_exists( 'message', $json_response ) ) {
 					$error_message = $json_response['message'];
 				}
 			}
 
-			if ( $this->retry > 0 ) {
-				$this->retry --;
-				App::make( Output::class )->writeln( '<comment>Request failed... Retrying.</comment>' );
-				usleep( rand( intval( 5 * 1e5 ), intval( 5 * 1e6 ) ) ); // Sleep between 0.5s and 5s.
-				goto retry_request; // phpcs:ignore Generic.PHP.DiscourageGoto.Found
+			if ( $response_status_code === 429 ) {
+				if ( $this->retry_429 > 0 ) {
+					$this->retry_429 --;
+					App::make( Output::class )->writeln( '<comment>Request failed... Retrying (429 Too many Requests)</comment>' );
+
+					sleep( $this->wait_after_429( $headers ) );
+					goto retry_request; // phpcs:ignore Generic.PHP.DiscourageGoto.Found
+				}
+			} else {
+				if ( $this->retry > 0 ) {
+					$this->retry --;
+					App::make( Output::class )->writeln( sprintf( '<comment>Request failed... Retrying (HTTP Status Code %s)</comment>', $response_status_code ) );
+
+					// Between 1 and 5s.
+					sleep( rand( 1, 5 ) );
+					goto retry_request; // phpcs:ignore Generic.PHP.DiscourageGoto.Found
+				}
 			}
 
 			throw new NetworkErrorException(
@@ -272,7 +286,67 @@ public function request(): string {
 			);
 		}
 
-		return $result;
+		return $body;
+	}
+
+	protected function wait_after_429( string $headers, int $max_wait = 60 ): int {
+		$retry_after = null;
+
+		// HTTP dates are always expressed in GMT, never in local time. (RFC 9110 5.6.7).
+		$gmt_timezone = new \DateTimeZone( 'GMT' );
+
+		// HTTP headers are case-insensitive according to RFC 7230.
+		$headers = strtolower( $headers );
+
+		foreach ( explode( "\r\n", $headers ) as $header ) {
+			/**
+			 * Retry-After header is specified by RFC 9110 10.2.3
+			 *
+			 * It can be formatted as http-date, or int (seconds).
+			 *
+			 * Retry-After: Fri, 31 Dec 1999 23:59:59 GMT
+			 * Retry-After: 120
+			 *
+			 * @link https://datatracker.ietf.org/doc/html/rfc9110#section-10.2.3
+			 */
+			if ( strpos( $header, 'retry-after:' ) !== false ) {
+				$retry_after_header = trim( substr( $header, strpos( $header, ':' ) + 1 ) );
+
+				// seconds.
+				if ( is_numeric( $retry_after_header ) ) {
+					$retry_after = intval( $retry_after_header );
+				} else {
+					// Parse as HTTP-date in GMT timezone.
+					try {
+						$retry_after = ( new \DateTime( $retry_after_header, $gmt_timezone ) )->getTimestamp() - ( new \DateTime( 'now', $gmt_timezone ) )->getTimestamp();
+					} catch ( \Exception $e ) {
+						$retry_after = null;
+					}
+					// http-date.
+					$retry_after_time = strtotime( $retry_after_header );
+					if ( $retry_after_time !== false ) {
+						$retry_after = $retry_after_time - time();
+					}
+				}
+
+				if ( ! defined( 'UNIT_TESTS' ) ) {
+					App::make( Output::class )->writeln( sprintf( 'Got 429. Retrying after %d seconds...', $retry_after ) );
+				}
+			}
+		}
+
+		// If no retry-after is specified, do a back-off.
+		if ( is_null( $retry_after ) ) {
+			$retry_after = 5 * pow( 2, abs( $this->retry_429 - 5 ) );
+		}
+
+		// Ensure we wait at least 1 second.
+		$retry_after = max( 1, $retry_after );
+
+		// And no longer than 60 seconds.
+		$retry_after = min( $max_wait, $retry_after );
+
+		return $retry_after;
 	}
 
 	/**
diff --git a/src/src/bootstrap.php b/src/src/bootstrap.php
@@ -99,6 +99,7 @@ public function filter( $in, $out, &$consumed, $closing ): int {
 	if ( ! stream_filter_register( 'qit_json', QIT_JSON_Filter::class ) ) {
 		exit( 151 );
 	}
+	/* @phan-suppress-next-line PhanUndeclaredMethod */
 	if ( ! stream_filter_append( App::make( Output::class )->getStream(), 'qit_json' ) ) {
 		exit( 152 );
 	}
diff --git a/src/tests/RequestBuilderTest.php b/src/tests/RequestBuilderTest.php
@@ -0,0 +1,68 @@
+<?php
+
+namespace QIT_CLI_Tests;
+
+use QIT_CLI\RequestBuilder;
+use PHPUnit\Framework\TestCase;
+
+class RequestBuilderTest extends TestCase {
+	/** @var RequestBuilder $this ->sut */
+	protected $sut;
+
+	protected function setUp(): void {
+		parent::setUp();
+		$this->sut = new class extends RequestBuilder {
+			public $retry_429 = 5;
+
+			public function wait_after_429( string $headers, int $max_wait = 60 ): int {
+				return parent::wait_after_429( $headers, $max_wait );
+			}
+		};
+	}
+
+	public function test_retry_after_seconds() {
+		$headers = "Retry-After: 59\r\nOther-Header: value";
+
+		$this->assertEquals( 59, $this->sut->wait_after_429( $headers ) );
+	}
+
+	public function test_retry_after_http_date() {
+		$dateTime = new \DateTime( '+120 seconds' );
+		$httpDate = $dateTime->format( \DateTimeInterface::RFC7231 );
+		$headers  = "Retry-After: $httpDate\r\nOther-Header: value";
+
+		// Since time will pass between the creation of the date and this calculation,
+		// allow a small margin in the assertion
+		$expected_delay = $dateTime->getTimestamp() - time();
+		$this->assertEqualsWithDelta( $expected_delay, $this->sut->wait_after_429( $headers, 130 ), 5 );
+	}
+
+	public function test_no_retry_after_header() {
+		$headers = "Other-Header: value";
+
+		$this->assertEquals( 5, $this->sut->wait_after_429( $headers ) );
+	}
+
+	public function test_invalid_retry_after_header() {
+		$headers = "Retry-After: invalid\r\nOther-Header: value";
+
+		$this->assertEquals( 5, $this->sut->wait_after_429( $headers ) );
+	}
+
+	public function test_exponential_backoff() {
+		$headers = "Retry-After: invalid\r\nOther-Header: value";
+
+		$this->assertEquals( 5, $this->sut->wait_after_429( $headers ) );
+		// Mimick integration-level test.
+		$this->sut->retry_429 --;
+		$this->assertEquals( 10, $this->sut->wait_after_429( $headers ) );
+		$this->sut->retry_429 --;
+		$this->assertEquals( 20, $this->sut->wait_after_429( $headers ) );
+		$this->sut->retry_429 --;
+		$this->assertEquals( 40, $this->sut->wait_after_429( $headers ) );
+		$this->sut->retry_429 --;
+		$this->assertEquals( 80, $this->sut->wait_after_429( $headers, 300 ) );
+		$this->sut->retry_429 --;
+		$this->assertEquals( 160, $this->sut->wait_after_429( $headers, 300 ) );
+	}
+}

Original file line number	Diff line number	Diff line change
`@@ -97,7 +97,7 @@`
`97`	`97`	`},`
`98`	`98`	`{`
`99`	`99`	`"file": "\\/var\\/www\\/html\\/wp-settings.php",`
`100`		`- "line": 679,`
	`100`	`+ "line": 695,`
`101`	`101`	`"function": "do_action"`
`102`	`102`	`},`
`103`	`103`	`{`
`@@ -207,7 +207,7 @@`
`207`	`207`	`},`
`208`	`208`	`{`
`209`	`209`	`"file": "\\/var\\/www\\/html\\/wp-settings.php",`
`210`		`- "line": 679,`
	`210`	`+ "line": 695,`
`211`	`211`	`"function": "do_action"`
`212`	`212`	`},`
`213`	`213`	`{`
`@@ -279,7 +279,7 @@`
`279`	`279`	`},`
`280`	`280`	`{`
`281`	`281`	`"file": "\\/var\\/www\\/html\\/wp-settings.php",`
`282`		`- "line": 679,`
	`282`	`+ "line": 695,`
`283`	`283`	`"function": "do_action"`
`284`	`284`	`},`
`285`	`285`	`{`
Original file line number	Diff line number	Diff line change
`@@ -90,7 +90,7 @@`
`90`	`90`	`},`
`91`	`91`	`{`
`92`	`92`	`"file": "\\/var\\/www\\/html\\/wp-settings.php",`
`93`		`- "line": 679,`
	`93`	`+ "line": 695,`
`94`	`94`	`"function": "do_action"`
`95`	`95`	`},`
`96`	`96`	`{`
`@@ -203,7 +203,7 @@`
`203`	`203`	`},`
`204`	`204`	`{`
`205`	`205`	`"file": "\\/var\\/www\\/html\\/wp-settings.php",`
`206`		`- "line": 679,`
	`206`	`+ "line": 695,`
`207`	`207`	`"function": "do_action"`
`208`	`208`	`},`
`209`	`209`	`{`
`@@ -316,7 +316,7 @@`
`316`	`316`	`},`
`317`	`317`	`{`
`318`	`318`	`"file": "\\/var\\/www\\/html\\/wp-settings.php",`
`319`		`- "line": 679,`
	`319`	`+ "line": 695,`
`320`	`320`	`"function": "do_action"`
`321`	`321`	`},`
`322`	`322`	`{`
Original file line number	Diff line number	Diff line change
`@@ -99,6 +99,7 @@ public function filter( $in, $out, &$consumed, $closing ): int {`
`99`	`99`	`if ( ! stream_filter_register( 'qit_json', QIT_JSON_Filter::class ) ) {`
`100`	`100`	`exit( 151 );`
`101`	`101`	`}`
	`102`	`+ /* @phan-suppress-next-line PhanUndeclaredMethod */`
`102`	`103`	`if ( ! stream_filter_append( App::make( Output::class )->getStream(), 'qit_json' ) ) {`
`103`	`104`	`exit( 152 );`
`104`	`105`	`}`