gmdate( 'Y-m-d H:i:s' ), 'event' => (string) $event, ); foreach ( (array) $data as $key => $value ) { if ( is_scalar( $value ) || null === $value ) { $entry[ (string) $key ] = is_string( $value ) ? mb_substr( $value, 0, 300 ) : $value; } elseif ( is_array( $value ) ) { $entry[ (string) $key ] = mb_substr( (string) wp_json_encode( $value ), 0, 300 ); } } $log = get_option( self::OPTION, array() ); if ( ! is_array( $log ) ) { $log = array(); } $log[] = $entry; if ( count( $log ) > self::MAX_ENTRIES ) { $log = array_slice( $log, -self::MAX_ENTRIES ); } update_option( self::OPTION, $log, false ); if ( defined( 'WP_DEBUG' ) && WP_DEBUG ) { $mirrored = $entry; foreach ( self::$redact_from_error_log as $key ) { if ( isset( $mirrored[ $key ] ) ) { $mirrored[ $key ] = '[redacted - see wp_options wdkit_import_log]'; } } // phpcs:ignore WordPress.PHP.DevelopmentFunctions.error_log_error_log error_log( '[wdkit-import] ' . wp_json_encode( $mirrored ) ); } } /** * The whole log, oldest first. * * @return array[] */ public static function read() { $log = get_option( self::OPTION, array() ); return is_array( $log ) ? $log : array(); } /** * Human-readable timing breakdown for the last run. * * Answers "where did the time go" without anyone having to read raw JSON: * * wp eval 'echo Wdkit_Import_Log::report();' * * @return string */ public static function report() { $log = self::read(); if ( empty( $log ) ) { return "no import logged\n"; } $out = ''; $stages = array(); $tpl = array(); $fails = array(); foreach ( $log as $e ) { $event = isset( $e['event'] ) ? $e['event'] : ''; if ( 'stage' === $event ) { $name = isset( $e['stage'] ) ? $e['stage'] : '?'; if ( ! isset( $stages[ $name ] ) ) { $stages[ $name ] = array( 'ms' => 0, 'calls' => 0 ); } $stages[ $name ]['ms'] += isset( $e['ms'] ) ? (int) $e['ms'] : 0; ++$stages[ $name ]['calls']; } elseif ( 'template' === $event ) { $tpl[] = $e; } elseif ( 'failure' === $event ) { $fails[] = $e; } } $out .= "TEMPLATES (slowest first)\n"; $out .= sprintf( " %-24s %8s %8s %10s %8s %7s\n", 'title', 'total', 'fetch', 'transform', 'store', 'images' ); usort( $tpl, function ( $a, $b ) { return ( isset( $b['ms'] ) ? $b['ms'] : 0 ) <=> ( isset( $a['ms'] ) ? $a['ms'] : 0 ); } ); $sum = 0; foreach ( $tpl as $t ) { $sum += isset( $t['ms'] ) ? (int) $t['ms'] : 0; $out .= sprintf( " %-24s %7dms %7dms %9dms %7dms %7d\n", mb_substr( isset( $t['title'] ) ? $t['title'] : '?', 0, 24 ), isset( $t['ms'] ) ? $t['ms'] : 0, isset( $t['fetch_ms'] ) ? $t['fetch_ms'] : 0, isset( $t['transform_ms'] ) ? $t['transform_ms'] : 0, isset( $t['store_ms'] ) ? $t['store_ms'] : 0, isset( $t['images'] ) ? $t['images'] : 0 ); } $out .= sprintf( " %-24s %7dms across %d templates\n\n", 'TOTAL', $sum, count( $tpl ) ); $out .= "STAGES (server time only - excludes the browser's CSS passes)\n"; $stage_total = 0; foreach ( $stages as $name => $d ) { $stage_total += $d['ms']; $out .= sprintf( " %-28s %7dms over %d request(s)\n", $name, $d['ms'], $d['calls'] ); } $out .= sprintf( " %-28s %7dms\n", 'TOTAL', $stage_total ); if ( ! empty( $fails ) ) { $out .= sprintf( "\nFAILURES (%d)\n", count( $fails ) ); foreach ( array_slice( $fails, 0, 10 ) as $f ) { $out .= sprintf( " %-18s %-26s %s\n", isset( $f['step'] ) ? $f['step'] : '?', isset( $f['code'] ) ? $f['code'] : '?', mb_substr( isset( $f['message'] ) ? $f['message'] : '', 0, 70 ) ); } } return $out; } /** * Forget everything. Called when a run starts so one run's log is one run. * * @return void */ public static function clear() { delete_option( self::OPTION ); } } }