OrderLogsCleanupHelper.php
3 weeks ago
OrderLogsDeletionProcessor.php
3 months ago
RemoteLogger.php
10 months ago
SafeGlobalFunctionProxy.php
2 weeks ago
OrderLogsCleanupHelper.php
330 lines
| 1 | <?php |
| 2 | |
| 3 | declare( strict_types=1 ); |
| 4 | |
| 5 | namespace Automattic\WooCommerce\Internal\Logging; |
| 6 | |
| 7 | use Automattic\WooCommerce\Internal\Admin\Logging\FileV2\FileController; |
| 8 | use Automattic\WooCommerce\Internal\Admin\Logging\LogHandlerFileV2; |
| 9 | use Automattic\WooCommerce\Internal\DataStores\Orders\DataSynchronizer; |
| 10 | use Automattic\WooCommerce\Utilities\LoggingUtil; |
| 11 | use Automattic\WooCommerce\Utilities\OrderUtil; |
| 12 | use WC_Logger; |
| 13 | |
| 14 | /** |
| 15 | * Handles cleanup of place-order debug log files and associated order meta. |
| 16 | * |
| 17 | * @since 10.7.0 |
| 18 | */ |
| 19 | class OrderLogsCleanupHelper { |
| 20 | |
| 21 | /** |
| 22 | * Maximum number of log files to delete per run. |
| 23 | */ |
| 24 | public const MAX_FILES_PER_RUN = 1000; |
| 25 | |
| 26 | /** |
| 27 | * Maximum number of orders to clean up per run. |
| 28 | */ |
| 29 | public const MAX_ORDERS_PER_RUN = 100; |
| 30 | |
| 31 | /** |
| 32 | * Hook of the action scheduled to continue a cleanup that didn't drain the backlog. |
| 33 | */ |
| 34 | public const EXTENDED_CLEANUP_HOOK = 'woocommerce_cleanup_logs_extended'; |
| 35 | |
| 36 | /** |
| 37 | * Delay, in seconds, before a follow-up cleanup run. |
| 38 | */ |
| 39 | private const EXTENDED_CLEANUP_DELAY = 5 * MINUTE_IN_SECONDS; |
| 40 | |
| 41 | /** |
| 42 | * The instance of DataSynchronizer to use. |
| 43 | * |
| 44 | * @var DataSynchronizer |
| 45 | */ |
| 46 | private DataSynchronizer $data_synchronizer; |
| 47 | |
| 48 | /** |
| 49 | * Initialize the instance and register hooks. |
| 50 | * This is invoked by the dependency injection container. |
| 51 | * |
| 52 | * @internal |
| 53 | * |
| 54 | * @param DataSynchronizer $data_synchronizer The instance of DataSynchronizer to use. |
| 55 | * |
| 56 | * @return void |
| 57 | */ |
| 58 | final public function init( DataSynchronizer $data_synchronizer ): void { |
| 59 | $this->data_synchronizer = $data_synchronizer; |
| 60 | |
| 61 | add_action( self::EXTENDED_CLEANUP_HOOK, array( $this, 'cleanup' ) ); |
| 62 | } |
| 63 | |
| 64 | /** |
| 65 | * Get the maximum age for debug logs before cleanup, in seconds. |
| 66 | * Returns 0 if cleanup is disabled via filter. |
| 67 | * |
| 68 | * @return int |
| 69 | */ |
| 70 | private function get_max_age_in_seconds(): int { |
| 71 | /** |
| 72 | * Filter the retention period for place-order debug logs cleanup. |
| 73 | * Return 0 to disable cleanup entirely. |
| 74 | * |
| 75 | * @param int $max_age_in_seconds The maximum age in seconds before cleanup. Default 3 days. |
| 76 | * |
| 77 | * @since 10.7.0 |
| 78 | */ |
| 79 | return absint( apply_filters( 'woocommerce_cleanup_order_debug_logs_max_age', 3 * DAY_IN_SECONDS ) ); |
| 80 | } |
| 81 | |
| 82 | /** |
| 83 | * Run all cleanup tasks: dangling order meta and old log files. |
| 84 | * |
| 85 | * Also the callback for the extended cleanup action. |
| 86 | * |
| 87 | * @since 10.7.0 |
| 88 | */ |
| 89 | public function cleanup(): void { |
| 90 | $max_age = $this->get_max_age_in_seconds(); |
| 91 | |
| 92 | if ( 0 === $max_age ) { |
| 93 | return; |
| 94 | } |
| 95 | |
| 96 | $files_swept_in_bulk = LogHandlerFileV2::class === LoggingUtil::get_default_handler(); |
| 97 | |
| 98 | $more_files = $files_swept_in_bulk && $this->cleanup_old_log_files( $max_age ); |
| 99 | $more_orders = $this->cleanup_dangling_orders( $max_age, $files_swept_in_bulk ); |
| 100 | |
| 101 | // Each run handles a single batch, so that it can't grow unbounded on a large |
| 102 | // backlog. Anything left over is picked up by a follow-up run a few minutes later. |
| 103 | if ( $more_files || $more_orders ) { |
| 104 | $this->schedule_extended_cleanup(); |
| 105 | } |
| 106 | } |
| 107 | |
| 108 | /** |
| 109 | * Clean up a batch of orders with dangling debug log meta. |
| 110 | * |
| 111 | * Dangling orders have `_debug_log_source` meta but no `_debug_log_source_pending_deletion`. |
| 112 | * |
| 113 | * @param int $max_age Maximum age in seconds before an order's debug log meta is eligible for cleanup. |
| 114 | * @param bool $files_swept_in_bulk True if the file sweep is already deleting these orders' log files. |
| 115 | * |
| 116 | * @return bool True if there may be more orders left to clean up. |
| 117 | */ |
| 118 | private function cleanup_dangling_orders( int $max_age, bool $files_swept_in_bulk ): bool { |
| 119 | $dangling_orders = $this->get_dangling_orders( $max_age ); |
| 120 | |
| 121 | if ( empty( $dangling_orders ) ) { |
| 122 | return false; |
| 123 | } |
| 124 | |
| 125 | // Clearing each order's log source individually scans the log directory once per |
| 126 | // order, so it's only worth doing when the bulk sweep isn't deleting the files. |
| 127 | $deleted = $files_swept_in_bulk |
| 128 | ? $this->delete_debug_log_meta_entries( array_keys( $dangling_orders ) ) |
| 129 | : $this->clear_logs_and_delete_meta_entries( $dangling_orders ); |
| 130 | |
| 131 | return $deleted && self::MAX_ORDERS_PER_RUN === count( $dangling_orders ); |
| 132 | } |
| 133 | |
| 134 | /** |
| 135 | * Delete a batch of place-order-debug-* log files from the filesystem. |
| 136 | * |
| 137 | * @param int $max_age Maximum age in seconds before a file is eligible for deletion. |
| 138 | * |
| 139 | * @return bool True if there may be more files left to delete. |
| 140 | */ |
| 141 | private function cleanup_old_log_files( int $max_age ): bool { |
| 142 | $deleted = wc_get_container()->get( FileController::class )->delete_stale_files( |
| 143 | 'place-order-debug', |
| 144 | time() - $max_age, |
| 145 | self::MAX_FILES_PER_RUN |
| 146 | ); |
| 147 | |
| 148 | return self::MAX_FILES_PER_RUN === $deleted; |
| 149 | } |
| 150 | |
| 151 | /** |
| 152 | * Schedule a follow-up cleanup run to continue draining the backlog. |
| 153 | */ |
| 154 | private function schedule_extended_cleanup(): void { |
| 155 | if ( ! function_exists( 'as_schedule_single_action' ) || ! function_exists( 'as_get_scheduled_actions' ) ) { |
| 156 | return; |
| 157 | } |
| 158 | |
| 159 | // Only pending actions count: when this runs as the extended cleanup callback, the |
| 160 | // current action is in-progress and would otherwise match, blocking the follow-up. |
| 161 | $pending = as_get_scheduled_actions( |
| 162 | array( |
| 163 | 'hook' => self::EXTENDED_CLEANUP_HOOK, |
| 164 | 'args' => array(), |
| 165 | 'group' => 'woocommerce', |
| 166 | 'status' => \ActionScheduler_Store::STATUS_PENDING, |
| 167 | 'per_page' => 1, |
| 168 | 'orderby' => 'none', |
| 169 | ), |
| 170 | 'ids' |
| 171 | ); |
| 172 | |
| 173 | if ( $pending ) { |
| 174 | return; |
| 175 | } |
| 176 | |
| 177 | as_schedule_single_action( time() + self::EXTENDED_CLEANUP_DELAY, self::EXTENDED_CLEANUP_HOOK, array(), 'woocommerce' ); |
| 178 | } |
| 179 | |
| 180 | /** |
| 181 | * Clear debug log files and delete associated order meta for the given items. |
| 182 | * Deletes both `_debug_log_source` and `_debug_log_source_pending_deletion` meta. |
| 183 | * |
| 184 | * @since 10.7.0 |
| 185 | * |
| 186 | * @param array $items Associative array of order ID => log source name. |
| 187 | * |
| 188 | * @return void |
| 189 | */ |
| 190 | public function clear_logs_and_delete_meta( array $items ): void { |
| 191 | $this->clear_logs_and_delete_meta_entries( $items ); |
| 192 | } |
| 193 | |
| 194 | /** |
| 195 | * Clear debug log files and delete associated order meta for the given items, reporting whether anything |
| 196 | * was deleted. |
| 197 | * |
| 198 | * This backs the public clear_logs_and_delete_meta(), whose `void` return type is kept for compatibility. |
| 199 | * |
| 200 | * @param array $items Associative array of order ID => log source name. |
| 201 | * |
| 202 | * @return bool True if any meta entries were deleted. |
| 203 | */ |
| 204 | private function clear_logs_and_delete_meta_entries( array $items ): bool { |
| 205 | if ( empty( $items ) ) { |
| 206 | return false; |
| 207 | } |
| 208 | |
| 209 | $logger = wc_get_logger(); |
| 210 | if ( $logger instanceof WC_Logger ) { |
| 211 | foreach ( $items as $source ) { |
| 212 | $logger->clear( $source ); |
| 213 | } |
| 214 | } |
| 215 | |
| 216 | return $this->delete_debug_log_meta_entries( array_keys( $items ) ); |
| 217 | } |
| 218 | |
| 219 | /** |
| 220 | * Get orders with `_debug_log_source` meta older than the given max age. |
| 221 | * |
| 222 | * Orders that also have `_debug_log_source_pending_deletion` will be handled |
| 223 | * by the batch processor, but cleaning them up here too is harmless. |
| 224 | * |
| 225 | * @param int $max_age Maximum age in seconds. |
| 226 | * |
| 227 | * @return array Associative array of order ID => log source name. |
| 228 | */ |
| 229 | private function get_dangling_orders( int $max_age ): array { |
| 230 | if ( OrderUtil::unknown_orders_data_store_in_use() ) { |
| 231 | return array(); |
| 232 | } |
| 233 | |
| 234 | global $wpdb; |
| 235 | |
| 236 | $hpos_in_use = OrderUtil::custom_orders_table_usage_is_enabled(); |
| 237 | $cutoff_date = gmdate( 'Y-m-d H:i:s', time() - $max_age ); |
| 238 | |
| 239 | $meta_table = $hpos_in_use ? "{$wpdb->prefix}wc_orders_meta" : $wpdb->postmeta; |
| 240 | $order_table = $hpos_in_use ? "{$wpdb->prefix}wc_orders" : $wpdb->posts; |
| 241 | $id_column = $hpos_in_use ? 'order_id' : 'post_id'; |
| 242 | $type_column = $hpos_in_use ? 'type' : 'post_type'; |
| 243 | $date_column = $hpos_in_use ? 'date_created_gmt' : 'post_date_gmt'; |
| 244 | |
| 245 | // phpcs:disable WordPress.DB.PreparedSQL.InterpolatedNotPrepared |
| 246 | $rows = $wpdb->get_results( |
| 247 | $wpdb->prepare( |
| 248 | "SELECT m.{$id_column} as order_id, m.meta_value |
| 249 | FROM {$meta_table} m |
| 250 | INNER JOIN {$order_table} o ON m.{$id_column} = o.id |
| 251 | WHERE m.meta_key = %s |
| 252 | AND o.{$type_column} = %s |
| 253 | AND o.{$date_column} < %s |
| 254 | LIMIT %d", |
| 255 | '_debug_log_source', |
| 256 | 'shop_order', |
| 257 | $cutoff_date, |
| 258 | self::MAX_ORDERS_PER_RUN |
| 259 | ), |
| 260 | ARRAY_A |
| 261 | ); |
| 262 | // phpcs:enable WordPress.DB.PreparedSQL.InterpolatedNotPrepared |
| 263 | |
| 264 | return array_column( $rows, 'meta_value', 'order_id' ); |
| 265 | } |
| 266 | |
| 267 | /** |
| 268 | * Delete `_debug_log_source` and `_debug_log_source_pending_deletion` meta entries for the given order IDs |
| 269 | * from the authoritative table and the backup table (when data sync is enabled). |
| 270 | * |
| 271 | * @param array $order_ids Array of order IDs to delete meta for. |
| 272 | * |
| 273 | * @return bool True if any meta entries were deleted. |
| 274 | */ |
| 275 | private function delete_debug_log_meta_entries( array $order_ids ): bool { |
| 276 | global $wpdb; |
| 277 | |
| 278 | $hpos_in_use = OrderUtil::custom_orders_table_usage_is_enabled(); |
| 279 | |
| 280 | $tables = array( |
| 281 | array( |
| 282 | 'table' => $hpos_in_use ? "{$wpdb->prefix}wc_orders_meta" : $wpdb->postmeta, |
| 283 | 'id_column' => $hpos_in_use ? 'order_id' : 'post_id', |
| 284 | ), |
| 285 | ); |
| 286 | |
| 287 | if ( $this->data_synchronizer->data_sync_is_enabled() ) { |
| 288 | $tables[] = array( |
| 289 | 'table' => $hpos_in_use ? $wpdb->postmeta : "{$wpdb->prefix}wc_orders_meta", |
| 290 | 'id_column' => $hpos_in_use ? 'post_id' : 'order_id', |
| 291 | ); |
| 292 | } |
| 293 | |
| 294 | $id_placeholders = implode( ',', array_fill( 0, count( $order_ids ), '%d' ) ); |
| 295 | |
| 296 | $deleted = false; |
| 297 | |
| 298 | foreach ( $tables as $table_config ) { |
| 299 | // phpcs:disable WordPress.DB.PreparedSQL.InterpolatedNotPrepared, WordPress.DB.PreparedSQLPlaceholders.ReplacementsWrongNumber |
| 300 | $result = $wpdb->query( |
| 301 | $wpdb->prepare( |
| 302 | "DELETE FROM {$table_config['table']} |
| 303 | WHERE {$table_config['id_column']} IN ({$id_placeholders}) |
| 304 | AND meta_key IN (%s, %s)", |
| 305 | array_merge( $order_ids, array( '_debug_log_source', '_debug_log_source_pending_deletion' ) ) |
| 306 | ) |
| 307 | ); |
| 308 | // phpcs:enable WordPress.DB.PreparedSQL.InterpolatedNotPrepared, WordPress.DB.PreparedSQLPlaceholders.ReplacementsWrongNumber |
| 309 | |
| 310 | if ( is_int( $result ) && $result > 0 ) { |
| 311 | $deleted = true; |
| 312 | } |
| 313 | } |
| 314 | |
| 315 | if ( ! $deleted ) { |
| 316 | // These IDs came from a query that just matched them on `_debug_log_source`, so deleting nothing |
| 317 | // means either another process got there first or the writes are failing. Worth surfacing either way. |
| 318 | wc_get_logger()->warning( |
| 319 | sprintf( |
| 320 | 'Expected to delete debug log meta for %d order(s), but no rows were removed.', |
| 321 | count( $order_ids ) |
| 322 | ), |
| 323 | array( 'source' => 'wc-logs-cleanup' ) |
| 324 | ); |
| 325 | } |
| 326 | |
| 327 | return $deleted; |
| 328 | } |
| 329 | } |
| 330 |