wp-cron定时任务影响性能这件事算得上众所周知,狗哥这么多年来看到过很多篇文章教程教你怎么禁用wp-cron定时任务的,但几乎没见到过讲为什么要禁用它的。
按照狗哥对wp-cron定时任务的理解,当用户访问网站时,wordpress系统会检查定时任务是否需要执行,需要就启动任务就行了,这样看来wp-cron并不会造成性能瓶颈,因为狗哥理解的wp-cron定时任务只启动,而不会等待完成,启动一个任务能消耗多长时间?顶天1毫秒吧!
今天在进一步提升网站响应速度时,发现每过几个请求,就会出现一次响应时间长达200ms+不等的情况。以前不在意,但正逢国庆假期,宅家里没事干,决定将这个问题解决掉。
其实最佳的调试办法是在本地部署wordpress和php环境,使用debug工具追踪每个缓解的性能。但是狗哥懒,前段时间重装了系统,软件环境都没了,实在不想安装那些东西。所以最终采用代码输出日志的方式,成功找到罪魁祸首,wp-cron定时任务。
由于很久以前狗哥就知道,只要引用了wordpress核心文件wp-load.php就会导致耗时增加。所以直接从这个文件中开始,其实这个文件里面没啥内容,文件中核心代码就一句,引入wp-settings.php文件,没错,这才是核心。
在wp-settings.php文件中插入计时统计,代码如下。
function wp_debug_log($message, $type = 'INFO') {
$log_file = WP_CONTENT_DIR . '/debug.log';
$timestamp = date('Y-m-d H:i:s');
$log_message = "[$timestamp] [$type] $message" . PHP_EOL;
// 写入日志文件
file_put_contents($log_file, $log_message, FILE_APPEND | LOCK_EX);
}
class WPSettingsTimer {
private $start_time;
private $checkpoints = [];
public function __construct() {
$this->start_time = microtime(true);
}
public function checkpoint($name) {
$this->checkpoints[$name] = microtime(true);
}
public function getReport() {
$report = [];
$previous_time = $this->start_time;
foreach ($this->checkpoints as $name => $time) {
$duration = ($time - $previous_time) * 1000;
$report[] = [
'phase' => $name,
'duration_ms' => round($duration, 2),
'cumulative_ms' => round(($time - $this->start_time) * 1000, 2)
];
$previous_time = $time;
}
return $report;
}
}
$timer = new WPSettingsTimer();
在wp-settings.php头部加入上面的代码,然后在文件中各处代码插入需要检测的点,使用下面的代码。
$timer->checkpoint('环境检查');
名字就自己定义,能区分是哪行代码执行的就行,在文件末尾添加输出记录代码。
$report = $timer->getReport();
wp_debug_log("=== wp-settings.php 分段性能分析 ===");
foreach ($report as $item) {
wp_debug_log("{$item['phase']}: {$item['duration_ms']}ms (累计: {$item['cumulative_ms']}ms)");
}
最后得到如下图所示耗时,在最后完成时耗时增加。
然后到wp-settings.php文件中找到插入的端点位置,定位到耗时代码是
do_action( 'wp_loaded' );
接下来就是确定是哪个函数耗时长了,因为这个是wordpress的钩子,上面挂载了不知道多少函数。
使用下面的代码,逐级排查
<?php
function get_function_name_simple($callback) {
if (is_array($callback)) {
if (is_object($callback[0])) {
return get_class($callback[0]) . '->' . $callback[1];
} else {
return $callback[0] . '::' . $callback[1];
}
} elseif (is_string($callback)) {
return $callback;
} else {
return '闭包或可调用对象';
}
}
// 逐级排查方法:先找出耗时的优先级组
function staged_wp_loaded_analysis() {
global $wp_filter;
$log_file = ABSPATH . 'wp-content/debug.log';
file_put_contents($log_file, "🎯 开始逐级分析 wp_loaded..." . PHP_EOL, FILE_APPEND);
if (!isset($wp_filter['wp_loaded'])) {
return;
}
$hooks = $wp_filter['wp_loaded'];
ksort($hooks->callbacks);
$priority_times = [];
// 按优先级组测量时间
foreach ($hooks->callbacks as $priority => $callbacks) {
$priority_start = microtime(true);
// 执行这个优先级的所有钩子
foreach ($callbacks as $callback) {
call_user_func_array($callback['function'], []);
}
$priority_time = (microtime(true) - $priority_start) * 1000;
$priority_times[$priority] = [
'time' => $priority_time,
'count' => count($callbacks)
];
file_put_contents($log_file,
"优先级 {$priority}: " . round($priority_time, 2) . "ms (" .
count($callbacks) . "个钩子)" . PHP_EOL,
FILE_APPEND
);
}
// 找出最耗时的优先级
uasort($priority_times, function($a, $b) {
return $b['time'] - $a['time'];
});
file_put_contents($log_file, "=== 最耗时的优先级组 ===" . PHP_EOL, FILE_APPEND);
$count = 0;
foreach ($priority_times as $priority => $data) {
if ($count++ >= 5) break;
file_put_contents($log_file,
"优先级 {$priority}: " . round($data['time'], 2) . "ms (" .
$data['count'] . "个钩子)" . PHP_EOL,
FILE_APPEND
);
}
// 然后详细分析最耗时的优先级
$most_expensive_priority = array_key_first($priority_times);
if ($most_expensive_priority !== null) {
analyze_priority_hooks($most_expensive_priority);
}
}
function analyze_priority_hooks($priority) {
global $wp_filter;
$log_file = ABSPATH . 'wp-content/debug.log';
file_put_contents($log_file, "🔍 详细分析优先级 {$priority} 的钩子:" . PHP_EOL, FILE_APPEND);
$hooks = $wp_filter['wp_loaded'];
$callbacks = $hooks->callbacks[$priority] ?? [];
$hook_times = [];
foreach ($callbacks as $callback_key => $callback) {
$function_name = get_function_name_simple($callback['function']);
$hook_start = microtime(true);
call_user_func_array($callback['function'], []);
$hook_time = (microtime(true) - $hook_start) * 1000;
$hook_times[] = [
'function' => $function_name,
'time' => $hook_time
];
file_put_contents($log_file,
" - {$function_name}: " . round($hook_time, 2) . "ms" . PHP_EOL,
FILE_APPEND
);
}
// 排序显示
usort($hook_times, function($a, $b) {
return $b['time'] - $a['time'];
});
file_put_contents($log_file, "=== 优先级 {$priority} 中最耗时的钩子 ===" . PHP_EOL, FILE_APPEND);
foreach (array_slice($hook_times, 0, 10) as $index => $hook) {
file_put_contents($log_file,
($index + 1) . ". {$hook['function']}: " . round($hook['time'], 2) . "ms" . PHP_EOL,
FILE_APPEND
);
}
}
// 执行逐级分析
staged_wp_loaded_analysis();
用上面的代码替换do_action( 'wp_loaded' );
,可以得到如下日志
=== 最耗时的优先级组 ===
优先级 10: 0.04ms (4个钩子)
优先级 20: 330.11ms (1个钩子)
从优先级20中,找到对应的函数
function get_function_name_simple($callback) {
if (is_array($callback)) {
if (is_object($callback[0])) {
return get_class($callback[0]) . '->' . $callback[1];
} else {
return $callback[0] . '::' . $callback[1];
}
} elseif (is_string($callback)) {
return $callback;
} else {
return '闭包或可调用对象';
}
}
// 专门分析优先级20的钩子
function analyze_priority_20_hook() {
global $wp_filter;
$log_file = ABSPATH . 'wp-content/debug.log';
file_put_contents($log_file, "🎯 开始分析优先级20的钩子..." . PHP_EOL, FILE_APPEND);
if (!isset($wp_filter['wp_loaded']->callbacks[20])) {
file_put_contents($log_file, "❌ 没有找到优先级20的钩子" . PHP_EOL, FILE_APPEND);
return;
}
$callbacks = $wp_filter['wp_loaded']->callbacks[20];
file_put_contents($log_file, "找到 " . count($callbacks) . " 个优先级20的钩子" . PHP_EOL, FILE_APPEND);
foreach ($callbacks as $callback_key => $callback) {
$function_name = get_detailed_function_name($callback['function']);
file_put_contents($log_file, "🔍 分析钩子: {$function_name}" . PHP_EOL, FILE_APPEND);
// 详细测量执行时间
$start_time = microtime(true);
$start_memory = memory_get_usage();
try {
call_user_func_array($callback['function'], []);
$execution_time = (microtime(true) - $start_time) * 1000;
$memory_used = memory_get_usage() - $start_memory;
file_put_contents($log_file, "✅ 执行结果:" . PHP_EOL, FILE_APPEND);
file_put_contents($log_file, " 时间: " . round($execution_time, 2) . "ms" . PHP_EOL, FILE_APPEND);
file_put_contents($log_file, " 内存: " . round($memory_used / 1024, 2) . "KB" . PHP_EOL, FILE_APPEND);
} catch (Exception $e) {
file_put_contents($log_file, "❌ 执行错误: " . $e->getMessage() . PHP_EOL, FILE_APPEND);
}
// 分析函数来源
analyze_function_source($callback['function']);
}
}
function get_detailed_function_name($callback) {
if (is_array($callback)) {
if (is_object($callback[0])) {
$class_name = get_class($callback[0]);
$method_name = $callback[1];
return "对象方法: {$class_name}->{$method_name}()";
} else {
return "静态方法: {$callback[0]}::{$callback[1]}()";
}
} elseif (is_string($callback)) {
return "函数: {$callback}()";
} elseif ($callback instanceof Closure) {
return "闭包函数";
} else {
return "未知类型: " . gettype($callback);
}
}
function analyze_function_source($callback) {
$log_file = ABSPATH . 'wp-content/debug.log';
if (is_array($callback) && is_object($callback[0])) {
$class_name = get_class($callback[0]);
$reflector = new ReflectionClass($class_name);
$filename = $reflector->getFileName();
file_put_contents($log_file, "📁 类文件位置: {$filename}" . PHP_EOL, FILE_APPEND);
// 判断来源
if (strpos($filename, WP_PLUGIN_DIR) !== false) {
file_put_contents($log_file, "📍 来源: 插件" . PHP_EOL, FILE_APPEND);
// 提取插件名称
$plugin_path = str_replace(WP_PLUGIN_DIR . '/', '', $filename);
$plugin_slug = explode('/', $plugin_path)[0];
file_put_contents($log_file, "🪪 插件slug: {$plugin_slug}" . PHP_EOL, FILE_APPEND);
} elseif (strpos($filename, get_template_directory()) !== false) {
file_put_contents($log_file, "📍 来源: 主题" . PHP_EOL, FILE_APPEND);
} elseif (strpos($filename, WPINC) !== false) {
file_put_contents($log_file, "📍 来源: WordPress核心" . PHP_EOL, FILE_APPEND);
} else {
file_put_contents($log_file, "📍 来源: 其他" . PHP_EOL, FILE_APPEND);
}
} elseif (is_string($callback)) {
// 函数名称
if (function_exists($callback)) {
$reflector = new ReflectionFunction($callback);
$filename = $reflector->getFileName();
$line = $reflector->getStartLine();
file_put_contents($log_file, "📁 函数定义位置: {$filename}:{$line}" . PHP_EOL, FILE_APPEND);
}
}
}
// 执行分析
analyze_priority_20_hook();
用上面的代码替换do_action( 'wp_loaded' );
,可以得到如下日志
🎯 开始分析优先级20的钩子...
找到 1 个优先级20的钩子
🔍 分析钩子: 函数: _wp_cron()
确定函数名,接下来继续查是哪个任务导致的,注意:wp_cron是后台任务,所以直接修改wp_includes/cron.php文件1010行作用的_wp_cron函数,替换为下面的代码。
<?php
function _wp_cron() {
// 监控开始
$start_time = microtime(true);
$log_file = WP_CONTENT_DIR . '/debug.log';
function log_cron_trigger_message($message) {
$log_file = WP_CONTENT_DIR . '/debug.log';
$timestamp = date('Y-m-d H:i:s');
$log_entry = "[{$timestamp}] [WP-CRON-TRIGGER] {$message}" . PHP_EOL;
file_put_contents($log_file, $log_entry, FILE_APPEND | LOCK_EX);
}
log_cron_trigger_message("🚀 _wp_cron() 开始执行");
// Prevent infinite loops caused by lack of wp-cron.php.
if ( str_contains( $_SERVER['REQUEST_URI'], '/wp-cron.php' )
|| ( defined( 'DISABLE_WP_CRON' ) && DISABLE_WP_CRON )
) {
$check_time = (microtime(true) - $start_time) * 1000;
log_cron_trigger_message("❌ 条件检查阻止执行: URI包含wp-cron.php或DISABLE_WP_CRON已定义 - " . round($check_time, 2) . "ms");
return 0;
}
$cron_check_start = microtime(true);
$crons = wp_get_ready_cron_jobs();
$cron_check_time = (microtime(true) - $cron_check_start) * 1000;
if ( empty( $crons ) ) {
$total_time = (microtime(true) - $start_time) * 1000;
log_cron_trigger_message("❌ 没有待执行任务 - 获取任务: " . round($cron_check_time, 2) . "ms, 总耗时: " . round($total_time, 2) . "ms");
return 0;
}
$gmt_time = microtime( true );
$keys = array_keys( $crons );
if ( isset( $keys[0] ) && $keys[0] > $gmt_time ) {
$total_time = (microtime(true) - $start_time) * 1000;
log_cron_trigger_message("❌ 最早任务未到执行时间 - 获取任务: " . round($cron_check_time, 2) . "ms, 总耗时: " . round($total_time, 2) . "ms");
return 0;
}
// 统计任务信息
$total_tasks = 0;
$due_tasks = 0;
$due_task_details = [];
foreach ($crons as $timestamp => $cronhooks) {
foreach ($cronhooks as $hook => $args) {
$total_tasks++;
if ($timestamp <= $gmt_time) {
$due_tasks++;
$due_task_details[] = [
'hook' => $hook,
'timestamp' => $timestamp,
'scheduled_time' => date('Y-m-d H:i:s', $timestamp)
];
}
}
}
log_cron_trigger_message("📊 任务统计 - 总任务: {$total_tasks}, 待执行: {$due_tasks}");
if (!empty($due_task_details)) {
log_cron_trigger_message("📋 待执行任务详情:");
foreach (array_slice($due_task_details, 0, 5) as $task) { // 只显示前5个避免日志过长
log_cron_trigger_message(" - {$task['hook']} (计划: {$task['scheduled_time']})");
}
if (count($due_task_details) > 5) {
log_cron_trigger_message(" ... 还有 " . (count($due_task_details) - 5) . " 个任务");
}
}
$schedules = wp_get_schedules();
$results = array();
$loop_start_time = microtime(true);
$tasks_processed = 0;
$triggered_hook = '';
foreach ( $crons as $timestamp => $cronhooks ) {
if ( $timestamp > $gmt_time ) {
break;
}
foreach ( (array) $cronhooks as $hook => $args ) {
$tasks_processed++;
// 记录条件检查
$condition_check_start = microtime(true);
if ( isset( $schedules[ $hook ]['callback'] )
&& ! call_user_func( $schedules[ $hook ]['callback'] )
) {
$condition_time = (microtime(true) - $condition_check_start) * 1000;
log_cron_trigger_message("⚠️ 跳过任务 {$tasks_processed}: {$hook} - 条件回调返回false - " . round($condition_time, 2) . "ms");
continue;
}
$condition_time = (microtime(true) - $condition_check_start) * 1000;
// 触发 spawn_cron
$spawn_start = microtime(true);
$triggered_hook = $hook;
log_cron_trigger_message("🔔 触发任务 {$tasks_processed}: {$hook} - 条件检查: " . round($condition_time, 2) . "ms");
$results[] = spawn_cron( $gmt_time );
$spawn_time = (microtime(true) - $spawn_start) * 1000;
$loop_time = (microtime(true) - $loop_start_time) * 1000;
log_cron_trigger_message("✅ 已触发 spawn_cron: {$hook} - spawn耗时: " . round($spawn_time, 2) . "ms, 循环总耗时: " . round($loop_time, 2) . "ms");
break 2;
}
}
$loop_total_time = (microtime(true) - $loop_start_time) * 1000;
if ($tasks_processed === 0) {
log_cron_trigger_message("ℹ️ 循环处理了 0 个任务 - 循环耗时: " . round($loop_total_time, 2) . "ms");
}
$total_time = (microtime(true) - $start_time) * 1000;
if ( in_array( false, $results, true ) ) {
log_cron_trigger_message("❌ spawn_cron 执行失败 - 总耗时: " . round($total_time, 2) . "ms");
return false;
}
$result_count = count( $results );
log_cron_trigger_message("🎯 _wp_cron() 执行完成");
log_cron_trigger_message(" 触发任务: {$triggered_hook}");
log_cron_trigger_message(" 返回结果: {$result_count}");
log_cron_trigger_message(" 总耗时: " . round($total_time, 2) . "ms");
log_cron_trigger_message(" 循环处理任务数: {$tasks_processed}");
log_cron_trigger_message(" 实际触发任务数: {$result_count}");
log_cron_trigger_message("==========================================");
return $result_count;
}
日志如下
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] 🚀 _wp_cron() 开始执行
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] 📊 任务统计 - 总任务: 15, 待执行: 3
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] 📋 待执行任务详情:
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] - wp_scheduled_delete (计划: 2024-01-15 10:30:00)
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] - wp_update_plugins (计划: 2024-01-15 10:30:00)
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] - wp_version_check (计划: 2024-01-15 10:30:00)
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] 🔔 触发任务 1: wp_scheduled_delete - 条件检查: 0.2ms
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] ✅ 已触发 spawn_cron: wp_scheduled_auto_draft_delete - spawn耗时: 268.51ms, 循环总耗时: 268.75ms
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] 🎯 _wp_cron() 执行完成
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] 触发任务: wp_scheduled_delete
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] 返回结果: 1
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] 总耗时: 277.8ms
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] 循环处理任务数: 1
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] 实际触发任务数: 1
[2024-01-15 10:30:01] [WP-CRON-TRIGGER] ==========================================
wp_scheduled_auto_draft_delete
这个任务是自动清理草稿的,罪魁祸首找到了。
在wp-config.php中,添加禁止wp_cron常量
define('DISABLE_WP_CRON', true);
然后在宝塔面板计划任务中添加一个定时访问url的任务,使用服务器的定时任务访问wp_cron的入口即可。
https://www.domain.com/wp-cron.php?doing_wp_cron
好了,现在稳定了,不会出现之前那样,偶尔访问时耗时长达几百毫秒的情况,基本上稳定在70毫秒左右。
真是服了,为啥wordpress核心要等待执行定时任务,而且不是每次都等,有时候等,有时候不等,奇怪。
评论 (0)