最近交接出去的代码，新人碰到个BUG。在测试同学的环境中，当索引不存在时进入某个后台页面，会报错404。以下新人简称A。
于是A尝试解决，既然404报错是因为索引不存在，就判定下索引，存在才继续后续逻辑。404的问题就这样解决了，到这里进展还算顺利。
然而，之后，进入后台页面，报错从404变为了502。由此开始，A踏上了一段曲折的定位历程。
其实我在这个版本的代码中，给后台内置了慢查询日志的查看功能，但是由于Docker挂载的php-fpm默认路径和代码的不同，所以慢查询日志在后台的查看功能就失效了。
而我第一时间给出了更正后的慢查询日志路径。希望A能以慢查询日志为基础，科学的定位问题根源。
很可惜，通过断点，A发现是执行到Elasticsearch的查询逻辑时，展现出了报错。所以推断是Elasticsearch慢查询造成的问题。
此时，慢查询日志展现内容为：
[10-Nov-2020 13:16:32] [pool www] pid 245
script_filename = /test/backend/web/index.php
[0x00007fa846a1d540] copy() /test/vendor/yiisoft/yii2/log/FileTarget.php:191
[0x00007fa846a1d4b0] rotateByCopy() /test/vendor/yiisoft/yii2/log/FileTarget.php:164
[0x00007fa846a1d3f0] rotateFiles() /test/vendor/yiisoft/yii2/log/FileTarget.php:118
[0x00007fa846a1d2f0] export() /test/vendor/yiisoft/yii2/log/Target.php:133
[0x00007fa846a1d230] collect() /test/vendor/yiisoft/yii2/log/Dispatcher.php:189
[0x00007fa846a1d150] dispatch() /test/vendor/yiisoft/yii2/log/Logger.php:177
[0x00007fa846a1d0c0] flush() /test/vendor/yiisoft/yii2/base/ErrorHandler.php:113
[0x00007fa846a1d030] handleException() unknown:0
[0x00007ffc55f2ce80] ???() unknown:0
[10-Nov-2020 13:16:52] [pool www] pid 246
script_filename = /test/backend/web/index.php
[0x00007fa846a1d4b0] unlink() /test/vendor/yiisoft/yii2/log/FileTarget.php:160
[0x00007fa846a1d3f0] rotateFiles() /test/vendor/yiisoft/yii2/log/FileTarget.php:118
[0x00007fa846a1d2f0] export() /test/vendor/yiisoft/yii2/log/Target.php:133
[0x00007fa846a1d230] collect() /test/vendor/yiisoft/yii2/log/Dispatcher.php:189
[0x00007fa846a1d150] dispatch() /test/vendor/yiisoft/yii2/log/Logger.php:177
[0x00007fa846a1d0c0] flush() /test/vendor/yiisoft/yii2/base/ErrorHandler.php:113
[0x00007fa846a1d030] handleException() unknown:0
[0x00007ffc55f2ce80] ???() unknown:0
A选择无视慢查询日志的报错，转而写了个逻辑判定，跳过了Elasticsearch的查询……然后反馈，BUG解决，原因是Elasticsearch触发慢查询。
Emmmm……后台确实能进入，问题看起来完美解决了。
虽然我反复提及，不是Elasticsearch的原因，并尝试引导A从慢查询日志入手寻找真实的原因，然而直到下班，A依旧抱着是某个查询条件造成了Elasticsearch慢查询的思路尝试在错误的方向挖掘出真相。
罢了，成长总是需要时间的，基于数据以科学的方法定位问题的习惯也不是一天两天或者一句话两句话就能养成的。
终于要回归主题了，你解决的BUG是表象还是本质？文中A同学，确实解决了“BUG”，至少是可以通过测试同学的验证的。但那根本不是造成问题的根源。毕竟我们应当尊重数据：慢查询日志根本没有涉及Elasticsearch相关代码的信息输出。
科学的方法是什么？根据慢查询的报错日志，可以明显看出，问题出在了什么文件滚动的操作上，而跟入框架的源码，可以推测这个日志文件大概率是框架自身的报错日志。继续跟进，进入错误日志的文件夹，查看文件，发现错误日志的文件基本上都是1.9G的样子。审阅滚动日志的源码，结合报错日志，应该是滚动过程中，文件过大，拷贝等操作用了太长时间，让整个脚本的执行超过了3秒的时限，触发了慢查询。
这个问题的重现是一件比较难的事情，主要原因是因为通常不会有那么大的错误日志文件存在。
现网会定时清理，仅有测试环境这种维护程度较低，并且没有其他定时任务触发框架的日志滚动逻辑，恰巧这个状态的时刻进入后台的一个调用框架内部方法的页面，才能触发。
如我所料，这个问题之后及时还原了代码，也不存在了。为什么呢？当然是因为日志滚完不再触发喽：
total 7.9G
-rw-r--r-- 1 test gtest 54M 11月 10 15:55 error.log
-rw-r--r-- 1 test gtest 1.1G 11月 10 13:30 error.log.4
-rw-r--r-- 1 test gtest 1.1G 11月 10 13:30 error.log.5
-rw-r--r-- 1 test gtest 1.9G 8月 26 09:27 error.log.1
-rw-r--r-- 1 test gtest 1.9G 8月 26 09:26 error.log.2
-rw-r--r-- 1 test gtest 1.9G 8月 26 09:26 error.log.3
程序员，会碰到很多BUG，而你尝试解决的那个BUG，是表象还是本质？这点，是对经验和内功的考验。只有抱着足够的好奇心和责任心，才有可能找到引发问题的起源，从而从本质上解决问题。
如果仅仅止步于解决表象问题，那么更深层次的坑，迟早会在未来的某天显现出来，而那时的你，将无能为力~
如您从本文得到了有价值的信息或帮助，请考虑扫描文末二维码捐赠和鼓励。
如本文对您有用，捐赠和留言 将是对我最好的支持~（捐赠可转为站内积分）
如愿意，请向朋友推荐本站，谢谢。
尊重他人劳动成果。转载请务必附上原文链接，我将感激不尽。