E_WARNING：发送STMT_PREPARE数据包时出错。 PID = *

Posted 2021-04-04

截至2019-01-30 14:52 UTC，您仍然可以赢得500分Bounty，因为没有一个答案有帮助！

我的Laravel 5.7网站遇到了一些我认为彼此相关的问题（但在不同时间发生）：

1. PDO::prepare(): mysql server has gone away
2. E_WARNING: Error while sending STMT_PREPARE packet. PID=10
3. PDOException: SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry（我的数据库似乎经常尝试在同一秒内写两次相同的记录。我一直无法弄清楚为什么或如何重现它;它似乎与用户行为无关。）
4. 不知何故，前两种类型的错误只出现在我的Rollbar日志中，而不是出现在服务器上或我的Slack通知中的文本日志上，因为所有错误应该是（和所有其他错误）。

几个月来，我一直看到这些可怕的日志消息，而且我完全无法重现这些错误（并且无法诊断和解决它们）。

我还没有发现任何实际症状或听到用户的任何抱怨，但错误消息似乎并非易事，所以我真的想了解并解决根本原因。

---

我已经尝试更改我的MySQL配置以使用max_allowed_packet=300M（而不是4M的default），但在我有超过几个访问者访问我的网站的日子里，我仍然经常得到这些例外。

由于this advice，我还设置了（从5M和10M改变）以下内容：

innodb_buffer_pool_chunk_size=218M
innodb_buffer_pool_size = 218M

---

作为进一步背景：

• 我的网站有一个运行作业的队列工作者（artisan queue:work --sleep=3 --tries=3 --daemon）。
• 根据访问者的注册时间，可以在同一时间安排一系列排队的作业。但我发现同时发生的最多是20。
• MySQL慢查询日志中没有条目。
• 我有几个cron工作，但我怀疑他们是有问题的。一分钟运行，但非常简单。另一个是每隔5分钟运行一次，如果有任何待处理的电子邮件，则会发另一个每30分钟运行一次报告。
• 我已经运行了各种mysqlslap查询（虽然我完全是新手）并且即使在模拟数百个并发客户端时也没有发现任何缓慢的问题。
• 我正在使用Laradock（Docker）。
• 我的服务器是DigitalOcean 1GB RAM，1个vCPU，25GB SSD。我也试过2GB内存没有区别。
• 来自SHOW VARIABLES;和SHOW GLOBAL STATUS; are here的结果。

我的my.cnf是：

[mysql]

[mysqld]
sql-mode="STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_ENGINE_SUBSTITUTION"
character-set-server=utf8
innodb_buffer_pool_chunk_size=218M
innodb_buffer_pool_size = 218M
max_allowed_packet=300M
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow_query_log.log
long_query_time = 10
log_queries_not_using_indexes = 0

关于我应该探索什么来诊断和解决这些问题的任何想法？谢谢。

---

答案

Re Slowlog：告诉我们你的my.cnf。 [mysqld]部分的变化是什么？通过SELECT SLEEP(12);测试它，然后查看文件和表格。

查找查询的替代方法：由于查询需要几分钟，因此当您认为它可能正在运行时请执行SHOW FULL PROCESSLIST;。

你有多少RAM？除非你有至少30GB的RAM，否则没有max_allowed_packet=300M。否则你冒着交换（甚至崩溃）的风险。将该设置保持在RAM的1％以下。

有关可调谐物的进一步分析，请提供（1）RAM大小，（2）SHOW VARIABLES;和（3）SHOW GLOBAL STATUS;。

Re deleted_at：你给的那个链接以“列deleted_at不是一个好的索引候选者”开头。你误解了它。它正在谈论单柱INDEX(deleted_at)。我建议像INDEX(contact_id, job_class_name, execute_at, deleted_at)这样的综合指数。

在小桌子上进行简单查询需要158秒？可能会有很多其他的事情发生。得到PROCESSLIST。

重新分离索引与复合：考虑两个索引：INDEX(last_name)和INDEX(first_name)。翻阅last_name索引找到“James”，然后你能做什么？翻阅“Rick”的其他索引不会帮助你找到我。

变量和全局状态分析

观察：

• 版本：5.7.22-log
• 1.00 GB的RAM
• 正常运行时间= 16d 10:30:19
• 你确定这是一个SHOW GLOBAL STATUS吗？
• 您没有在Windows上运行。
• 运行64位版本
• 您似乎完全（或大部分）运行InnoDB。

更重要的问题：

innodb_buffer_pool_size - 我以为你有213M，而不是10M。 10M太小了。另一方面，您似乎拥有的数据少于这么多。

由于RAM太小，我建议将tmp_table_size和max_heap_table_size以及max_allowed_pa​​cket丢弃到8M。并将table_open_cache，table_definition_cache和innodb_open_files降低到500。

是什么导致了这么多同时连接？

细节和其他观察：

( innodb_buffer_pool_size / _ram ) = 10M / 1024M = 0.98% - 用于InnoDB buffer_pool的RAM的百分比

( innodb_buffer_pool_size ) = 10M - InnoDB数据+索引缓存

( innodb_lru_scan_depth ) = 1,024 - “InnoDB：page_cleaner：1000ms意图循环花了...”可以通过降低lru_scan_depth来修复

( Innodb_buffer_pool_pages_free / Innodb_buffer_pool_pages_total ) = 375 / 638 = 58.8% - 当前未使用的buffer_pool的pct - innodb_buffer_pool_size比必要的大吗？

( Innodb_buffer_pool_bytes_data / innodb_buffer_pool_size ) = 4M / 10M = 40.0% - 数据占用的缓冲池百分比 - 一小部分可能表示buffer_pool不必要地大。

( innodb_log_buffer_size / _ram ) = 16M / 1024M = 1.6% - 用于缓冲InnoDB日志写入的RAM百分比。 - 太大的东西用于RAM的其他用途。

( innodb_log_file_size * innodb_log_files_in_group / innodb_buffer_pool_size ) = 48M * 2 / 10M = 960.0% - 日志大小与buffer_pool大小的比率。建议使用50％，但请参阅其他计算是否重要。 - 日志不需要大于缓冲池。

( innodb_flush_method ) = innodb_flush_method = - InnoDB应该如何要求操作系统编写块。建议使用O_DIRECT或O_ALL_DIRECT（Percona）以避免双重缓冲。 （至少对于Unix。）请参阅chrischandler关于O_ALL_DIRECT的警告

( innodb_flush_neighbors ) = 1 - 将块写入磁盘时的次要优化。 - 对于SSD驱动器使用0; 1用于HDD。

( innodb_io_capacity ) = 200 - 磁盘每秒I / O操作数。 100为慢速驱动器; 200用于旋转驱动器;固态硬盘1000-2000;乘以RAID因子。

( innodb_print_all_deadlocks ) = innodb_print_all_deadlocks = OFF - 是否记录所有死锁。 - 如果您遇到死锁，请启用此功能。警告：如果您有很多死锁，这可能会在磁盘上写下很多内容。

( min( tmp_table_size, max_heap_table_size ) / _ram ) = min( 16M, 16M ) / 1024M = 1.6% - 需要MEMORY表（每个表）时分配的RAM百分比，或SELECT内部的临时表（每个SELECT的每个临时表）。太高可能会导致交换。 - 将tmp_table_size和max_heap_table_size减少到比如ram的1％。

( net_buffer_length / max_allowed_packet ) = 16,384 / 16M = 0.10%

( local_infile ) = local_infile = ON - local_infile = ON是一个潜在的安全问题

( Select_scan / Com_select ) = 111,324 / 264144 = 42.1% - 选择进行全表扫描的百分比。 （可能被Stored Routines愚弄。） - 添加索引/优化查询

( long_query_time ) = 10 - 用于定义“慢”查询的截止（秒）。 - 建议2

( Max_used_connections / max_connections ) = 152 / 151 = 100.7% - 峰值连接百分比 - 增加max_connections和/或减少wait_timeout

您有半个查询缓存。您应该同时设置query_cache_type = OFF和query_cache_size = 0。 （根据谣言）QC代码中存在“错误”，除非您关闭这两个设置，否则会留下一些代码。

异常小：

( Innodb_pages_read + Innodb_pages_written ) / Uptime = 0.186
Created_tmp_files = 0.015 /HR
Handler_write = 0.21 /sec
Innodb_buffer_pool_bytes_data = 3 /sec
Innodb_buffer_pool_pages_data = 256
Innodb_buffer_pool_pages_total = 638
Key_reads+Key_writes + Innodb_pages_read+Innodb_pages_written+Innodb_dblwr_writes+Innodb_buffer_pool_pages_flushed = 0.25 /sec
Table_locks_immediate = 2.8 /HR
Table_open_cache_hits = 0.44 /sec
innodb_buffer_pool_chunk_size = 5MB

异常大：

Com_create_db = 0.41 /HR
Com_drop_db = 0.41 /HR
Connection_errors_peer_address = 2
Performance_schema_file_instances_lost = 9
Ssl_default_timeout = 500

异常字符串：

ft_boolean_syntax = + -><()~*:&
have_ssl = YES
have_symlink = DISABLED
innodb_fast_shutdown = 1
optimizer_trace = enabled=off,one_line=off
optimizer_trace_features = greedy_search=on, range_optimizer=on, dynamic_range=on, repeated_subselect=on
session_track_system_variables = time_zone, autocommit, character_set_client, character_set_results, character_set_connection
slave_rows_search_algorithms = TABLE_SCAN,INDEX_SCAN

另一答案

我在长时间运行的php CLI脚本上遇到了相同的情况（它在Redis列表上进行侦听;每个操作都很快，但脚本基本上都是运行的）。

我在开始时创建PDO对象和准备好的语句，然后重用它们。

我开始编写脚本后的第二天，我得到了完全相同的错误：

PHP Warning:  Error while sending STMT_EXECUTE packet. PID=9438 in /...redacted.../myscript.php on line 39

SQLSTATE[HY000]: General error: 2006 MySQL server has gone away

就我而言，它是一个开发服务器，没有负载，MySQL在同一个盒子上......所以它不太可能来自外部因素。这很可能与我使用相同的MySQL连接太久的事实有关，并且它超时了。并且PDO不会打扰，所以任何后续查询都会返回“MySQL服务器已经消失”。

检查MySQL中“wait_timeout”的值：

mysql> show variables like 'wait_timeout';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| wait_timeout  | 28800 |
+---------------+-------+
1 row in set (0.06 sec)

mysql> show local variables like 'wait_timeout';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| wait_timeout  | 28800 |
+---------------+-------+
1 row in set (0.00 sec)

我看到28800秒= 8小时，这似乎与我的错误时间一致。

在我的情况下，重新启动MySQL服务器，或将wait_timeout设置得非常低，同时保持相同的PHP工作程序运行，这使得重现问题变得非常容易。

总体：

• PDO不关心连接是否超时，并且不会自动重新连接。如果在PDO查询周围放置try / catch，脚本将永远不会崩溃并继续使用过时的PDO实例。
• STMT_EXECUTE警告可能是偶然的;只是因为连接超时的脚本使用了预准备语句，并且超时后的第一个查询恰好使用了预准备语句

回到你的案子

• 理论上，Laravel 5对这个问题免疫：https://blog.armen.im/en/laravel-4-and-stmt_prepare-error/;你是否使用Illuminate以外的东西，甚至是裸PDO？另外，我不确定Laravel在检测到连接丢失时会做什么（它是否重新连接并重建准备好的语句？），可能值得深入挖掘。
• 检查你的MySQL wait_timeout值，如果它太低则增加它
• 如果它没有一直发生，请查看错误是否与服务器/数据库负载相关。高负载可以使事情（尤其是大型SQL查询）慢几倍，达到其他一些MySQL超时，例如max_execution_time。
• 看看你是否在一个try / catch块中包装PDO查询并使用它来重试查询;它可能会阻止连接错误冒泡。

另一答案

如果您随机看到此消息，可能的原因：

1. 你的MySQL在代理后面，他们正在使用不同的timeout配置。
2. 您正在使用PHP的持久连接。

您可以尝试通过以下步骤深入研究问题：

1. 确保你与MySQL的连接有足够长的超时（在：代理设置，MySQL qazxsw poi / qazxsw poi）
2. 禁用PHP端的持久连接。
3. 如果你能看到收到错误信息后会发生什么，请做一些wait_timeout。