diff --git a/inc/spbc-settings.php b/inc/spbc-settings.php index 0c0a57d51..0ff909a5d 100644 --- a/inc/spbc-settings.php +++ b/inc/spbc-settings.php @@ -1284,8 +1284,8 @@ function spbc_field_scanner__prepare_data__analysis_log(&$table) $analysis_comment = __('Processing: new, preparing to queueing..', 'security-malware-firewall'); break; case 'ERROR': - $pscan_status = '' . __('Checked', 'security-malware-firewall') . ''; - $analysis_comment = '' . __('Files cause errors on execution.', 'security-malware-firewall') . ''; + $pscan_status = '' . __('Error', 'security-malware-firewall') . ''; + $analysis_comment = '' . __('Something went wrong. Please contact support team.', 'security-malware-firewall') . ''; break; case 'IN_SCANER': $pscan_status = __('Queued for inspection', 'security-malware-firewall'); @@ -1335,13 +1335,21 @@ function spbc_field_scanner__prepare_data__analysis_log(&$table) } if ( !is_null($row->pscan_estimated_execution_time) ) { - $estimated_execution_time = $row->pscan_estimated_execution_time . ' ' . __('second(s)', 'security-malware-firewall'); + if ( $row->pscan_estimated_execution_time === '0' ) { + $estimated_execution_time = __('Not available', 'security-malware-firewall'); + } else { + $estimated_execution_time = $row->pscan_estimated_execution_time . ' ' . __('second(s)', 'security-malware-firewall'); + } } else { $estimated_execution_time = $row->pscan_processing_status === 'DONE' ? 'Done' : 'Wait for assessing'; } // Filter actions for approved files - if ( in_array($row->pscan_status, array('SAFE','DANGEROUS')) || $curr_time - $row->last_sent < 500 ) { + if ( + $row->pscan_processing_status === 'ERROR' || + in_array($row->pscan_status, array('SAFE','DANGEROUS')) || + $curr_time - $row->last_sent < 500 + ) { unset($row->actions['check_analysis_status']); } diff --git a/lib/CleantalkSP/SpbctWP/Scanner/ScannerActions/CloudAnalysisActions.php b/lib/CleantalkSP/SpbctWP/Scanner/ScannerActions/CloudAnalysisActions.php index c7f66db90..41f203572 100644 --- a/lib/CleantalkSP/SpbctWP/Scanner/ScannerActions/CloudAnalysisActions.php +++ b/lib/CleantalkSP/SpbctWP/Scanner/ScannerActions/CloudAnalysisActions.php @@ -7,14 +7,19 @@ class CloudAnalysisActions { + /** + * Maximum polling period for checking file analysis status (in seconds) + * @var int + */ + private const MAX_POLLING_PERIOD_SECONDS = DAY_IN_SECONDS; // 24 hours /** * tested * @param array $response API Response - * @param bool $await_estimated_data Do await estimated data set on undone files check + * @param bool $polling_limit_reached Whether the polling limit has been reached * @return mixed API Response * @throws \Exception if validation failed */ - public static function validateAnalysisStatusResponse($response) + public static function validateAnalysisStatusResponse($response, $polling_limit_reached = false) { // Check if API error if ( !empty($response['error']) ) { @@ -56,18 +61,11 @@ public static function validateAnalysisStatusResponse($response) } } + $eta_required = !in_array($response['processing_status'], array('DONE', 'ERROR', 'UNKNOWN')) && !$polling_limit_reached; + //estimated time validation - if ( $response['processing_status'] !== 'DONE' ) { - if ( ! isset($response['estimated_execution_time'])) { - throw new \Exception('response provided no estimated scan time'); - } - //todo remove on business decision - //if ( ! isset($response['number_of_files'])) { - // throw new Exception('response provided no number of estimated files'); - //} - //if ( ! isset($response['number_of_files_scanned'])) { - // throw new Exception('response provided no number of already scanned files'); - //} + if ( $eta_required && ! isset($response['estimated_execution_time']) ) { + throw new \Exception('response provided no estimated scan time'); } return $response; @@ -87,6 +85,11 @@ public static function isStatusUpdaterExcludedFile(array $file_info) throw new \Exception('skipped'); } + //skip errored files + if (isset($file_info['pscan_processing_status']) && $file_info['pscan_processing_status'] === 'ERROR') { + throw new \Exception('skipped'); + } + // skip not queued files $pscan_pending_queue = isset($file_info['pscan_pending_queue']) && $file_info['pscan_pending_queue'] == '1'; if ($pscan_pending_queue) { @@ -239,12 +242,13 @@ public static function checkFilesAnalysisStatus($file_ids_input = '') continue; } + $polling_limit_reached = self::isPollingLimitReached($file_info); + // Perform API call $api_response = SpbcAPI::method__security_pscan_status($spbc->settings['spbc_key'], $file_info['pscan_file_id']); - // Validate API response try { - $api_response = CloudAnalysisActions::validateAnalysisStatusResponse($api_response); + $api_response = CloudAnalysisActions::validateAnalysisStatusResponse($api_response, $polling_limit_reached); } catch ( \Exception $exception ) { $out['error_detail'][] = array( 'file_path' => $file_info['path'], @@ -255,7 +259,7 @@ public static function checkFilesAnalysisStatus($file_ids_input = '') continue; } - $update_query = self::filesAnalysisStatusUpdateQuery($api_response, $file_info); + $update_query = self::filesAnalysisStatusUpdateQuery($api_response, $file_info, $polling_limit_reached); $update_result = $wpdb->query($update_query); if ( $update_result === false ) { @@ -279,7 +283,6 @@ public static function checkFilesAnalysisStatus($file_ids_input = '') // Fill counters $out['counters'] = $counters; - return $out; } @@ -289,17 +292,17 @@ public static function checkFilesAnalysisStatus($file_ids_input = '') * @param array $file_info * @return string */ - private static function filesAnalysisStatusUpdateQuery($api_response, $file_info) + private static function filesAnalysisStatusUpdateQuery($api_response, $file_info, $polling_limit_reached = false) { global $wpdb; - if ( $api_response['processing_status'] !== 'DONE' ) { + if ($api_response['processing_status'] !== 'DONE' ) { return $wpdb->prepare( 'UPDATE ' . SPBC_TBL_SCAN_FILES . ' SET pscan_pending_queue = 0, pscan_processing_status = %s, pscan_estimated_execution_time = %s' . ' WHERE pscan_file_id = %s', - $api_response['processing_status'], - $api_response['estimated_execution_time'], + $polling_limit_reached ? 'ERROR' : $api_response['processing_status'], + $api_response['estimated_execution_time'] ?? null, $file_info['pscan_file_id'] ); } @@ -315,7 +318,7 @@ private static function filesAnalysisStatusUpdateQuery($api_response, $file_info . ' status = "APPROVED_BY_CLOUD",' . ' pscan_estimated_execution_time = NULL' . ' WHERE pscan_file_id = %s', - isset($api_response['file_balls']) ? $api_response['file_balls'] : '{SAFE:0}', + $api_response['file_balls'] ?? '{SAFE:0}', $file_info['pscan_file_id'] ); } @@ -332,8 +335,20 @@ private static function filesAnalysisStatusUpdateQuery($api_response, $file_info . ' pscan_estimated_execution_time = NULL' . ' WHERE pscan_file_id = %s', $api_response['file_status'], - isset($api_response['file_balls']) ? $api_response['file_balls'] : '{DANGEROUS:0}', + $api_response['file_balls'] ?? '{DANGEROUS:0}', $file_info['pscan_file_id'] ); } + + /** + * Check if the polling limit has been reached for a file. + * @param array $file_info + * @return bool + */ + private static function isPollingLimitReached(array $file_info) + { + //limit the time of waiting for the analysis result to avoid infinite waiting + return isset($file_info['last_sent']) && + (current_time('timestamp') - $file_info['last_sent']) >= self::MAX_POLLING_PERIOD_SECONDS; + } } diff --git a/security-malware-firewall.php b/security-malware-firewall.php index 5b178e3f6..1ec1a2a02 100644 --- a/security-malware-firewall.php +++ b/security-malware-firewall.php @@ -1797,7 +1797,7 @@ function spbc_scanner_update_pscan_files_status() $undone_files_list = $wpdb->get_results( 'SELECT fast_hash' . ' FROM ' . SPBC_TBL_SCAN_FILES - . ' WHERE pscan_processing_status <> "DONE" AND pscan_processing_status IS NOT NULL', + . ' WHERE pscan_processing_status NOT IN ("DONE", "ERROR") AND pscan_processing_status IS NOT NULL', ARRAY_A ); diff --git a/tests/Inc/ScannerTest.php b/tests/Inc/ScannerTest.php index 379a4d8cb..990ead24b 100644 --- a/tests/Inc/ScannerTest.php +++ b/tests/Inc/ScannerTest.php @@ -102,6 +102,25 @@ public function testSpbcScannerPscanUpdateCheckExclusions() $result = CloudAnalysisActions::isStatusUpdaterExcludedFile(['pscan_processing_status' => 'NEW']); } + /** + * ERROR-marked files must be excluded from the pscan status updater, + * otherwise cron keeps polling the cloud API for them forever + * (they never turn into DONE, so the file is never skipped by any other check). + * + * @test + */ + public function testSpbcScannerPscanUpdateCheckExclusionsErrorStatusIsSkipped() + { + try { + CloudAnalysisActions::isStatusUpdaterExcludedFile( + ['pscan_processing_status' => 'ERROR', 'pscan_pending_queue' => 0] + ); + $this->fail('Expected exception not thrown for ERROR status'); + } catch (\Exception $e) { + $this->assertEquals('skipped', $e->getMessage()); + } + } + /** * function spbc_scanner_validate_pscan_status_response($response) * @test @@ -122,6 +141,182 @@ public function testSpbcScannerValidatePscanStatusResponse() } } + /** + * ERROR responses must be accepted even without "estimated_execution_time", + * since the cloud does not report an ETA for a failed analysis. + * + * @test + */ + public function testSpbcScannerValidatePscanStatusResponseErrorWithoutEstimatedTime() + { + $response = ['processing_status' => 'ERROR']; + + $result = CloudAnalysisActions::validateAnalysisStatusResponse($response); + + $this->assertEquals($response, $result); + } + + /** + * Regression guard: statuses that are still "in progress" (e.g. NEW) + * must keep requiring "estimated_execution_time". + * + * @test + */ + public function testSpbcScannerValidatePscanStatusResponseInProgressStillRequiresEstimatedTime() + { + $this->expectException(\Exception::class); + $this->expectExceptionMessage('response provided no estimated scan time'); + + CloudAnalysisActions::validateAnalysisStatusResponse(['processing_status' => 'NEW']); + } + + /** + * Once the polling limit is reached the file is about to be crunched to ERROR anyway, + * so a missing "estimated_execution_time" must no longer abort the update. + * + * @test + */ + public function testSpbcScannerValidatePscanStatusResponseSkipsEtaCheckWhenPollingLimitReached() + { + $response = ['processing_status' => 'NEW']; + + $result = CloudAnalysisActions::validateAnalysisStatusResponse($response, true); + + $this->assertEquals($response, $result); + } + + /** + * UNKNOWN is a state the cloud reports without any ETA, so it must not require one. + * + * @test + */ + public function testSpbcScannerValidatePscanStatusResponseUnknownDoesNotRequireEta() + { + $response = ['processing_status' => 'UNKNOWN']; + + $result = CloudAnalysisActions::validateAnalysisStatusResponse($response); + + $this->assertEquals($response, $result); + } + + /** + * Regression guard for the update query builder: an ERROR api response + * without "estimated_execution_time" must not trigger an "Undefined array key" notice + * (would be converted to an exception by the current phpunit configuration) + * and must still produce a valid UPDATE query. + * + * @test + */ + public function testSpbcScannerFilesAnalysisStatusUpdateQueryHandlesMissingEstimatedTimeOnError() + { + $method = new \ReflectionMethod(CloudAnalysisActions::class, 'filesAnalysisStatusUpdateQuery'); + $method->setAccessible(true); + + $api_response = ['processing_status' => 'ERROR']; + $file_info = ['pscan_file_id' => '123']; + + $query = $method->invoke(null, $api_response, $file_info); + + $this->assertIsString($query); + $this->assertStringContainsString('pscan_processing_status = \'ERROR\'', $query); + $this->assertStringContainsString('pscan_file_id = \'123\'', $query); + } + + /** + * A file that has been awaiting the analysis result for longer than the polling limit + * must be written to the DB as ERROR, so the status updater stops polling it. + * + * @test + */ + public function testSpbcScannerIsPollingLimitReachedDetectsStaleFile() + { + $method = new \ReflectionMethod(CloudAnalysisActions::class, 'isPollingLimitReached'); + $method->setAccessible(true); + + $stale = current_time('timestamp') - DAY_IN_SECONDS - 60; + $fresh = current_time('timestamp') - HOUR_IN_SECONDS; + + $this->assertTrue($method->invoke(null, ['last_sent' => $stale])); + $this->assertFalse($method->invoke(null, ['last_sent' => $fresh])); + } + + /** + * "last_sent" is stored in WP local time, so the comparison must use local time too. + * Using time() instead of current_time('timestamp') shifts the limit by the GMT offset: + * with a negative offset files expire too early, with a positive one they expire too late. + * + * @test + */ + public function testSpbcScannerIsPollingLimitReachedIsTimezoneSafe() + { + $original_offset = get_option('gmt_offset'); + $method = new \ReflectionMethod(CloudAnalysisActions::class, 'isPollingLimitReached'); + $method->setAccessible(true); + + try { + // negative offset: time() runs ahead of local time, a fresh file must not expire early + update_option('gmt_offset', -5); + $sent_20h_ago = current_time('timestamp') - (20 * HOUR_IN_SECONDS); + $this->assertFalse( + $method->invoke(null, ['last_sent' => $sent_20h_ago]), + 'A file sent 20 local hours ago must not be expired yet' + ); + + // positive offset: time() lags behind local time, a stale file must still expire + update_option('gmt_offset', 5); + $sent_25h_ago = current_time('timestamp') - (25 * HOUR_IN_SECONDS); + $this->assertTrue( + $method->invoke(null, ['last_sent' => $sent_25h_ago]), + 'A file sent 25 local hours ago must be expired' + ); + } finally { + update_option('gmt_offset', $original_offset); + } + } + + /** + * Reaching the polling limit must crunch any non-final status to ERROR in the update query. + * + * @test + */ + public function testSpbcScannerFilesAnalysisStatusUpdateQueryCrunchesStatusOnPollingLimit() + { + $method = new \ReflectionMethod(CloudAnalysisActions::class, 'filesAnalysisStatusUpdateQuery'); + $method->setAccessible(true); + + $api_response = ['processing_status' => 'UNKNOWN', 'estimated_execution_time' => 10]; + $file_info = ['pscan_file_id' => '789']; + + $crunched = $method->invoke(null, $api_response, $file_info, true); + $this->assertStringContainsString('pscan_processing_status = \'ERROR\'', $crunched); + $this->assertStringNotContainsString('\'UNKNOWN\'', $crunched); + + $not_crunched = $method->invoke(null, $api_response, $file_info, false); + $this->assertStringContainsString('pscan_processing_status = \'UNKNOWN\'', $not_crunched); + } + + /** + * The polling limit must never override a finished analysis: + * a DONE response has to keep its verdict-based query. + * + * @test + */ + public function testSpbcScannerFilesAnalysisStatusUpdateQueryKeepsDoneVerdictOnPollingLimit() + { + $method = new \ReflectionMethod(CloudAnalysisActions::class, 'filesAnalysisStatusUpdateQuery'); + $method->setAccessible(true); + + $query = $method->invoke( + null, + ['processing_status' => 'DONE', 'file_status' => 'SAFE'], + ['pscan_file_id' => '790'], + true + ); + + $this->assertStringContainsString('status = "APPROVED_BY_CLOUD"', $query); + $this->assertStringNotContainsString('\'ERROR\'', $query); + } + /** * function spbc_scanner_get_files_by_category($category, $count = false) * @test