情景:
最近,公司产品OpenSNS 3.2.0多次被人吐槽说:很卡,加载一个页面都要2~3s。
老板那边很关注这个问题,跑到我这和我说了这个现象,并让我找到原因,解决这个问题。
作为该产品的主要负责人,了解这一状况后,我也非常重视这个问题。
找问题:
作为主程之一,了解这一状况后,我着手寻找产生这一现象的原因。
首先,我随便打开一个简单的页面,发现耗时在1.5s左右。(由于是一个很简单的页面,1.5s是严重不能接受的)
其次,我找到了这个页面的后台程序,并用ThinkPHP自带的方法G()方法测试了后台程序的耗费时间。输出得到的结果是0.0035s,这个结果是可以接受的,于是得出的结论是,问题并非出在后台逻辑程序上面。
那么,问题只能是在之后的$this->display()上面。
作为浸淫ThinkPHP框架3年以上的老猿,我是非常不相信ThinkPHP框架会有这种耗时的问题的。但是,问题总要解决,所以,我还是深入到了display中。
我在display中做了各种时间点输出测试,以期检测出时间都耗费在哪个地方。于是就开始了漫长的4小时测试过程…………(此处省略10000字)
测试过程样例展示:
在TP的View.class.php的fetch中、Controller.class.php中调用fetch的位置display都做了多处时间点输出,其中a是调用Controller.class.php中display之前的时间点,也就是渲染html开始时间。
b是每个位置重置一次,也就是当前时间点。
从上面输出可以看出,fetch中代码在循环执行,甚至是fetch中的前半部分代码循环执行,并且不是外围重复调用,是其他位置调用的(这个设计到TP的机制,我也没看懂是在哪里调用的。有牛人的话,可以解释一个这个过程是什么样的,为什么会重复执行fetch中的部分代码)
从上图中可以看出,在第15~16个之间,时间从0.12s跳到了1.47s,并且没有执行我能跟踪到的代码。。。。。
经过这么多测试,得出的结论:莫名其妙执行了1.35s,不是道耗费在哪了,问题没有解决。。。
测试结果汇报:
经过近4个小时的测试,我把得出的结论汇报给了老板,并提供了证明材料。由于问题没法解决,所以征求了一下他的意见。他给出了一个很好的建议:从这些测试呢,确实看不出什么问题,但是TP的机制,根本不知道里面执行了多少东西,既然是渲染过程的问题,肯定跟渲染模板有关,肯定是模板中有些东西影响了时间,所以可以试着删除模板中某些部分,看看时间会不会明显缩短,如果缩短,说明是那部分模板有问题。
后续找问题:
得到建议后,感觉很棒,于是就去尝试,很快,找到了如下这段代码
删除代码前后,时间相差了1.3s左右,刚好是莫名其妙加上的时间。。。。问题找到,接下来是解决过程了。
如下图是删除前后的耗时:
到这,我就想到了一个故事:
一个农村姑娘误加入一个博士群里。有人提问:一滴水从很高很高的地方自由落体下来,砸到人会不会砸伤? 或砸死 ?群里一下就热闹起来,各种公式,各种假设,各种阻力,重力,加速度的计算,足足讨论了近一个小时 。
这时姑娘默默问了一句:你们没有淋过雨吗 ?群里突然死一般的寂静......
有文化真可怕 ..
启示:知识可以给你带来更多思考方式,但是经验可以让你更快的解决问题.
找问题过程总结:换个思路,问题很好找到。