hustle-gdpr-cleanup-logger

hustle-gdpr-cleanup-logger.php

<?php
/**
 * Plugin Name: Hustle GDPR Cleanup Logger
 * Description: Staging diagnostics for hustle_general_data_protection_cleanup. Logs settings, row counts, timings, and query progress.
 * Version: 1.0.0
 *
 * Install: copy this file to wp-content/mu-plugins/hustle-gdpr-cleanup-logger.php
 *
 * Log file: wp-content/hustle-gdpr-cleanup-debug.log
 *
 * Optional URL (logged-in admin):
 *   /wp-admin/?hustle_gdpr_debug=snapshot   — counts only, does not run cleanup
 *   /wp-admin/?hustle_gdpr_debug=run        — snapshot then fire the cron hook
 */

if ( ! defined( 'ABSPATH' ) ) {
	exit;
}

if ( ! defined( 'HUSTLE_GDPR_LOGGER_ENABLED' ) ) {
	define( 'HUSTLE_GDPR_LOGGER_ENABLED', true );
}

if ( ! defined( 'HUSTLE_GDPR_LOGGER_EXACT_COUNTS' ) ) {
	define( 'HUSTLE_GDPR_LOGGER_EXACT_COUNTS', true );
}

if ( ! defined( 'HUSTLE_GDPR_LOGGER_EXPLAIN' ) ) {
	define( 'HUSTLE_GDPR_LOGGER_EXPLAIN', true );
}

if ( ! defined( 'HUSTLE_GDPR_LOGGER_QUERY_EVERY' ) ) {
	define( 'HUSTLE_GDPR_LOGGER_QUERY_EVERY', 50 );
}

/**
 * Write a line to the dedicated log and to PHP error_log.
 *
 * @param string $message Message.
 * @param mixed  $data    Optional data to JSON-encode.
 */
function hustle_gdpr_debug_log( $message, $data = null ) {
	$elapsed = hustle_gdpr_debug_elapsed();
	$memory  = size_format( memory_get_usage( true ) );
	$line    = sprintf(
		'[%s] [+%ss] [%s] %s',
		gmdate( 'Y-m-d H:i:s' ),
		number_format( $elapsed, 3 ),
		$memory,
		$message
	);

	if ( null !== $data ) {
		$encoded = wp_json_encode( $data, JSON_UNESCAPED_SLASHES | JSON_UNESCAPED_UNICODE );
		if ( false !== $encoded ) {
			$line .= ' ' . $encoded;
		}
	}

	$line .= PHP_EOL;

	$file = WP_CONTENT_DIR . '/hustle-gdpr-cleanup-debug.log';
	// phpcs:ignore WordPress.PHP.DevelopmentFunctions.error_log_error_log,WordPress.WP.AlternativeFunctions.file_system_operations_file_put_contents
	file_put_contents( $file, $line, FILE_APPEND );
	// phpcs:ignore WordPress.PHP.DevelopmentFunctions.error_log_error_log
	error_log( trim( $line ) );
}

/**
 * Seconds since this request started watching the cleanup.
 *
 * @return float
 */
function hustle_gdpr_debug_elapsed() {
	$start = isset( $GLOBALS['hustle_gdpr_debug']['start'] ) ? $GLOBALS['hustle_gdpr_debug']['start'] : microtime( true );
	return microtime( true ) - $start;
}

/**
 * Table map.
 *
 * @return array<string,string>
 */
function hustle_gdpr_debug_tables() {
	global $wpdb;

	if ( class_exists( 'Hustle_Db' ) ) {
		return array(
			'modules'      => Hustle_Db::modules_table(),
			'modules_meta' => Hustle_Db::modules_meta_table(),
			'entries'      => Hustle_Db::entries_table(),
			'entries_meta' => Hustle_Db::entries_meta_table(),
			'tracking'     => Hustle_Db::tracking_table(),
		);
	}

	return array(
		'modules'      => $wpdb->prefix . 'hustle_modules',
		'modules_meta' => $wpdb->prefix . 'hustle_modules_meta',
		'entries'      => $wpdb->prefix . 'hustle_entries',
		'entries_meta' => $wpdb->prefix . 'hustle_entries_meta',
		'tracking'     => $wpdb->prefix . 'hustle_tracking',
	);
}

/**
 * Whether Hustle's own cleanup would skip a job (same strict checks as core).
 *
 * @param array  $settings Settings.
 * @param string $forever_key Forever option key.
 * @param string $number_key  Retention number key.
 * @param string $unit_key    Retention unit key.
 * @return array
 */
function hustle_gdpr_debug_job_status( $settings, $forever_key, $number_key, $unit_key ) {
	$forever_raw = isset( $settings[ $forever_key ] ) ? $settings[ $forever_key ] : null;
	$number_raw  = isset( $settings[ $number_key ] ) ? $settings[ $number_key ] : null;
	$unit        = isset( $settings[ $unit_key ] ) ? $settings[ $unit_key ] : null;

	$plugin_skips = ( '1' === $forever_raw ) || ( 0 === $number_raw );
	$safe_skips   = ( '1' === (string) $forever_raw ) || ( 0 === absint( $number_raw ) );

	$units        = array( 'days', 'weeks', 'months', 'years' );
	$unit_ok      = in_array( $unit, $units, true );
	$retain_time  = null;

	if ( $unit_ok && ! $plugin_skips ) {
		$retain_time = date_i18n( 'Y-m-d H:i:s', strtotime( '-' . $number_raw . ' ' . $unit ) );
	}

	return array(
		'forever_raw'          => $forever_raw,
		'forever_type'         => gettype( $forever_raw ),
		'number_raw'           => $number_raw,
		'number_type'          => gettype( $number_raw ),
		'unit'                 => $unit,
		'plugin_would_skip'    => $plugin_skips,
		'safe_logic_would_skip'=> $safe_skips,
		'plugin_would_run'     => ( ! $plugin_skips && $unit_ok ),
		'retain_time'          => $retain_time,
	);
}

/**
 * Timed COUNT(*).
 *
 * @param string $sql Prepared SQL.
 * @return array
 */
function hustle_gdpr_debug_count( $sql ) {
	global $wpdb;

	$started = microtime( true );
	$count   = $wpdb->get_var( $sql ); // phpcs:ignore WordPress.DB.DirectDatabaseQuery.DirectQuery,WordPress.DB.DirectDatabaseQuery.NoCaching,WordPress.DB.PreparedSQL.NotPrepared
	$error   = $wpdb->last_error;

	return array(
		'count'   => is_null( $count ) ? null : (int) $count,
		'seconds' => round( microtime( true ) - $started, 4 ),
		'error'   => $error ? $error : null,
	);
}

/**
 * Snapshot settings, table sizes, and how many rows each cleanup job would touch.
 */
function hustle_gdpr_debug_snapshot() {
	global $wpdb;

	hustle_gdpr_debug_log( '--- SNAPSHOT START ---' );
	hustle_gdpr_debug_log(
		'Runtime',
		array(
			'php'                 => PHP_VERSION,
			'wp_doing_cron'       => function_exists( 'wp_doing_cron' ) ? wp_doing_cron() : null,
			'is_admin'            => is_admin(),
			'max_execution_time'  => ini_get( 'max_execution_time' ),
			'memory_limit'        => ini_get( 'memory_limit' ),
			'fix_mu_plugin_loaded'=> function_exists( 'hustle_gdpr_fix_cleanup' ),
		)
	);

	if ( ! class_exists( 'Hustle_Settings_Admin' ) ) {
		hustle_gdpr_debug_log( 'Hustle is not loaded; aborting snapshot.' );
		return;
	}

	$settings = Hustle_Settings_Admin::get_privacy_settings();
	hustle_gdpr_debug_log( 'Privacy settings', $settings );

	$jobs = array(
		'submissions' => hustle_gdpr_debug_job_status( $settings, 'retain_submission_forever', 'submissions_retention_number', 'submissions_retention_number_unit' ),
		'ip'          => hustle_gdpr_debug_job_status( $settings, 'retain_ip_forever', 'ip_retention_number', 'ip_retention_number_unit' ),
		'tracking'    => hustle_gdpr_debug_job_status( $settings, 'retain_tracking_forever', 'tracking_retention_number', 'tracking_retention_number_unit' ),
	);
	hustle_gdpr_debug_log( 'Job skip/run vs plugin strict checks', $jobs );

	$tables = hustle_gdpr_debug_tables();
	$in     = "'" . implode( "','", array_map( 'esc_sql', array_values( $tables ) ) ) . "'";

	hustle_gdpr_debug_log( 'information_schema sizes (approximate table_rows)' );
	$schema = $wpdb->get_results( // phpcs:ignore WordPress.DB.DirectDatabaseQuery.DirectQuery,WordPress.DB.DirectDatabaseQuery.NoCaching
		$wpdb->prepare(
			"SELECT table_name, engine, table_rows, data_length, index_length
			FROM information_schema.tables
			WHERE table_schema = %s AND table_name IN ({$in})", // phpcs:ignore WordPress.DB.PreparedSQL.InterpolatedNotPrepared
			DB_NAME
		),
		ARRAY_A
	);
	hustle_gdpr_debug_log( 'information_schema', $schema );

	$indexes = $wpdb->get_results( "SHOW INDEX FROM `{$tables['tracking']}`", ARRAY_A ); // phpcs:ignore WordPress.DB.DirectDatabaseQuery.DirectQuery,WordPress.DB.DirectDatabaseQuery.NoCaching,WordPress.DB.PreparedSQL.InterpolatedNotPrepared
	hustle_gdpr_debug_log( 'tracking indexes', $indexes );

	if ( HUSTLE_GDPR_LOGGER_EXACT_COUNTS ) {
		hustle_gdpr_debug_log( 'Exact COUNT(*) starting (can be slow on large InnoDB tables)' );
		foreach ( $tables as $label => $table ) {
			hustle_gdpr_debug_log( "Starting COUNT(*) on {$label} ({$table})" );
			hustle_gdpr_debug_log( "COUNT {$label}", hustle_gdpr_debug_count( "SELECT COUNT(*) FROM `{$table}`" ) ); // phpcs:ignore WordPress.DB.PreparedSQL.InterpolatedNotPrepared
		}

		hustle_gdpr_debug_log(
			'tracking IP occupancy',
			array(
				'with_ip' => hustle_gdpr_debug_count(
					"SELECT COUNT(*) FROM `{$tables['tracking']}` WHERE ip IS NOT NULL AND ip <> '' AND ip <> '0.0.0.0'" // phpcs:ignore WordPress.DB.PreparedSQL.InterpolatedNotPrepared
				),
				'null_or_empty' => hustle_gdpr_debug_count(
					"SELECT COUNT(*) FROM `{$tables['tracking']}` WHERE ip IS NULL OR ip = '' OR ip = '0.0.0.0'" // phpcs:ignore WordPress.DB.PreparedSQL.InterpolatedNotPrepared
				),
			)
		);
	}

	foreach ( $jobs as $job => $status ) {
		if ( empty( $status['retain_time'] ) ) {
			hustle_gdpr_debug_log( "Matching rows for {$job}: skipped (no retain_time / plugin would not query)" );
			continue;
		}

		$retain = $status['retain_time'];
		hustle_gdpr_debug_log( "Matching rows for {$job} older than {$retain}" );

		if ( 'submissions' === $job || 'ip' === $job ) {
			hustle_gdpr_debug_log(
				"{$job} older entries",
				hustle_gdpr_debug_count(
					$wpdb->prepare(
						"SELECT COUNT(*) FROM `{$tables['entries']}` WHERE date_created < %s", // phpcs:ignore WordPress.DB.PreparedSQL.InterpolatedNotPrepared
						$retain
					)
				)
			);
		}

		if ( 'ip' === $job || 'tracking' === $job ) {
			hustle_gdpr_debug_log(
				"{$job} older tracking rows",
				hustle_gdpr_debug_count(
					$wpdb->prepare(
						"SELECT COUNT(*) FROM `{$tables['tracking']}` WHERE date_created < %s", // phpcs:ignore WordPress.DB.PreparedSQL.InterpolatedNotPrepared
						$retain
					)
				)
			);
		}

		if ( 'ip' === $job ) {
			hustle_gdpr_debug_log(
				'older tracking rows still holding an IP',
				hustle_gdpr_debug_count(
					$wpdb->prepare(
						"SELECT COUNT(*) FROM `{$tables['tracking']}`
						WHERE date_created < %s
						AND ip IS NOT NULL AND ip <> '' AND ip <> '0.0.0.0' AND ip <> '::'", // phpcs:ignore WordPress.DB.PreparedSQL.InterpolatedNotPrepared
						$retain
					)
				)
			);
		}
	}

	if ( HUSTLE_GDPR_LOGGER_EXPLAIN && ! empty( $jobs['ip']['retain_time'] ) ) {
		$retain = $jobs['ip']['retain_time'];
		$explain_ids = $wpdb->get_results( // phpcs:ignore WordPress.DB.DirectDatabaseQuery.DirectQuery,WordPress.DB.DirectDatabaseQuery.NoCaching
			$wpdb->prepare(
				"EXPLAIN SELECT tracking_id FROM `{$tables['tracking']}` WHERE date_created < %s", // phpcs:ignore WordPress.DB.PreparedSQL.InterpolatedNotPrepared
				$retain
			),
			ARRAY_A
		);
		hustle_gdpr_debug_log( 'EXPLAIN get_older_tracking_ids equivalent', $explain_ids );

		$max_id = (int) $wpdb->get_var( "SELECT MAX(tracking_id) FROM `{$tables['tracking']}`" ); // phpcs:ignore WordPress.DB.DirectDatabaseQuery.DirectQuery,WordPress.DB.DirectDatabaseQuery.NoCaching,WordPress.DB.PreparedSQL.InterpolatedNotPrepared
		if ( $max_id ) {
			$buggy = $wpdb->get_results( // phpcs:ignore WordPress.DB.DirectDatabaseQuery.DirectQuery,WordPress.DB.DirectDatabaseQuery.NoCaching
				$wpdb->prepare(
					"EXPLAIN SELECT ip FROM `{$tables['tracking']}` WHERE tracking_id < %s", // phpcs:ignore WordPress.DB.PreparedSQL.InterpolatedNotPrepared
					$max_id
				),
				ARRAY_A
			);
			hustle_gdpr_debug_log(
				'EXPLAIN buggy get_ip_from_tracking_id (tracking_id < MAX)',
				array(
					'sample_tracking_id' => $max_id,
					'explain'            => $buggy,
				)
			);

			$fixed = $wpdb->get_results( // phpcs:ignore WordPress.DB.DirectDatabaseQuery.DirectQuery,WordPress.DB.DirectDatabaseQuery.NoCaching
				$wpdb->prepare(
					"EXPLAIN SELECT ip FROM `{$tables['tracking']}` WHERE tracking_id = %d", // phpcs:ignore WordPress.DB.PreparedSQL.InterpolatedNotPrepared
					$max_id
				),
				ARRAY_A
			);
			hustle_gdpr_debug_log( 'EXPLAIN corrected get_ip_from_tracking_id (tracking_id = MAX)', $fixed );
		}
	}

	hustle_gdpr_debug_log( '--- SNAPSHOT END ---' );
}

/**
 * Start watching the cron hook.
 */
function hustle_gdpr_debug_on_cleanup_start() {
	if ( ! empty( $GLOBALS['hustle_gdpr_debug']['watching'] ) ) {
		return;
	}

	$GLOBALS['hustle_gdpr_debug'] = array(
		'watching'    => true,
		'start'       => microtime( true ),
		'queries'     => 0,
		'last_query'  => '',
		'buggy_query' => 0,
		'shutdown'    => true,
	);

	hustle_gdpr_debug_log( 'Cleanup hook started', array( 'hook' => 'hustle_general_data_protection_cleanup' ) );
	hustle_gdpr_debug_snapshot();
	hustle_gdpr_debug_log( 'Hustle cleanup callback (or fix mu-plugin) will run next' );

	add_filter( 'query', 'hustle_gdpr_debug_filter_query', 99 );
}

/**
 * Count and sample SQL while the cleanup is running.
 *
 * @param string $query SQL.
 * @return string
 */
function hustle_gdpr_debug_filter_query( $query ) {
	if ( empty( $GLOBALS['hustle_gdpr_debug']['watching'] ) ) {
		return $query;
	}

	$GLOBALS['hustle_gdpr_debug']['queries']++;
	$GLOBALS['hustle_gdpr_debug']['last_query'] = $query;

	if ( false !== stripos( $query, 'tracking_id <' ) ) {
		$GLOBALS['hustle_gdpr_debug']['buggy_query']++;
		if ( 1 === (int) $GLOBALS['hustle_gdpr_debug']['buggy_query'] ) {
			hustle_gdpr_debug_log( 'Detected buggy tracking_id < query', $query );
		}
	}

	$every = max( 1, (int) HUSTLE_GDPR_LOGGER_QUERY_EVERY );
	if ( 0 === $GLOBALS['hustle_gdpr_debug']['queries'] % $every ) {
		hustle_gdpr_debug_log(
			'Query progress',
			array(
				'queries'            => $GLOBALS['hustle_gdpr_debug']['queries'],
				'buggy_lt_queries'   => $GLOBALS['hustle_gdpr_debug']['buggy_query'],
				'last_query_preview' => substr( preg_replace( '/\s+/', ' ', $query ), 0, 300 ),
			)
		);
	}

	return $query;
}

/**
 * After the hook (only runs if PHP did not fatal).
 */
function hustle_gdpr_debug_on_cleanup_end() {
	if ( empty( $GLOBALS['hustle_gdpr_debug']['watching'] ) ) {
		return;
	}

	remove_filter( 'query', 'hustle_gdpr_debug_filter_query', 99 );
	hustle_gdpr_debug_log(
		'Cleanup hook finished without fatal',
		array(
			'queries'          => isset( $GLOBALS['hustle_gdpr_debug']['queries'] ) ? $GLOBALS['hustle_gdpr_debug']['queries'] : 0,
			'buggy_lt_queries' => isset( $GLOBALS['hustle_gdpr_debug']['buggy_query'] ) ? $GLOBALS['hustle_gdpr_debug']['buggy_query'] : 0,
			'peak_memory'      => size_format( memory_get_peak_usage( true ) ),
		)
	);
	$GLOBALS['hustle_gdpr_debug']['watching'] = false;
}

/**
 * Catch timeouts and other fatals.
 */
function hustle_gdpr_debug_shutdown() {
	if ( empty( $GLOBALS['hustle_gdpr_debug']['shutdown'] ) ) {
		return;
	}

	$error = error_get_last();
	if ( $error && in_array( $error['type'], array( E_ERROR, E_PARSE, E_CORE_ERROR, E_COMPILE_ERROR, E_USER_ERROR, E_RECOVERABLE_ERROR ), true ) ) {
		hustle_gdpr_debug_log(
			'Shutdown fatal',
			array(
				'type'       => $error['type'],
				'message'    => $error['message'],
				'file'       => $error['file'],
				'line'       => $error['line'],
				'queries'    => isset( $GLOBALS['hustle_gdpr_debug']['queries'] ) ? $GLOBALS['hustle_gdpr_debug']['queries'] : 0,
				'last_query' => isset( $GLOBALS['hustle_gdpr_debug']['last_query'] ) ? substr( $GLOBALS['hustle_gdpr_debug']['last_query'], 0, 500 ) : '',
				'peak_memory'=> size_format( memory_get_peak_usage( true ) ),
			)
		);
		return;
	}

	if ( ! empty( $GLOBALS['hustle_gdpr_debug']['watching'] ) ) {
		hustle_gdpr_debug_log(
			'Shutdown while cleanup was still marked running (likely timeout or exit)',
			array(
				'queries'    => isset( $GLOBALS['hustle_gdpr_debug']['queries'] ) ? $GLOBALS['hustle_gdpr_debug']['queries'] : 0,
				'last_query' => isset( $GLOBALS['hustle_gdpr_debug']['last_query'] ) ? substr( $GLOBALS['hustle_gdpr_debug']['last_query'], 0, 500 ) : '',
			)
		);
	}
}

/**
 * Manual snapshot / run from wp-admin.
 */
function hustle_gdpr_debug_admin_trigger() {
	if ( ! is_admin() || ! current_user_can( 'manage_options' ) ) {
		return;
	}

	if ( empty( $_GET['hustle_gdpr_debug'] ) ) { // phpcs:ignore WordPress.Security.NonceVerification.Recommended
		return;
	}

	$mode = sanitize_key( wp_unslash( $_GET['hustle_gdpr_debug'] ) ); // phpcs:ignore WordPress.Security.NonceVerification.Recommended
	if ( 'snapshot' === $mode ) {
		$GLOBALS['hustle_gdpr_debug']['start'] = microtime( true );
		hustle_gdpr_debug_snapshot();
		wp_die( esc_html( 'Hustle GDPR snapshot written to wp-content/hustle-gdpr-cleanup-debug.log' ) );
	}

	if ( 'run' === $mode ) {
		do_action( 'hustle_general_data_protection_cleanup' );
		wp_die( esc_html( 'Hustle GDPR cleanup hook fired. Check wp-content/hustle-gdpr-cleanup-debug.log' ) );
	}
}

if ( HUSTLE_GDPR_LOGGER_ENABLED ) {
	add_action( 'hustle_general_data_protection_cleanup', 'hustle_gdpr_debug_on_cleanup_start', 0 );
	add_action( 'hustle_general_data_protection_cleanup', 'hustle_gdpr_debug_on_cleanup_end', 9999 );
	add_action( 'shutdown', 'hustle_gdpr_debug_shutdown', 0 );
	add_action( 'admin_init', 'hustle_gdpr_debug_admin_trigger' );
}