/* 記錄兩個(gè)在php7升級(jí)過(guò)程中踩的坑。*/
一、擴(kuò)展的不兼容
問(wèn)題現(xiàn)象：
1、升級(jí)完php7的機(jī)器中，有幾臺(tái)從曲線、指標(biāo)上看，性能反而不如php5
2、查看其中一臺(tái)，nginx access日志里大量502錯(cuò)誤
3、fpm產(chǎn)生大量慢日志，錯(cuò)誤日志里記錄著類(lèi)似：“WARNING: [pool www] child 31570 exited on signal 11 (SIGSEGV - core dumped) after 490.850482 seconds from start”
初步結(jié)論：
看起來(lái)問(wèn)題是出在fpm，并且間接性core dump了。遺憾的是，系統(tǒng)配置并沒(méi)有保留core文件。
復(fù)現(xiàn)問(wèn)題：
1、聯(lián)系運(yùn)維，摘掉有問(wèn)題的線上機(jī)流量
2、要一臺(tái)機(jī)器臨時(shí)root權(quán)限，修改機(jī)器配置，以保留core文件
3、重啟fpm，很快就有大量的core文件了。（改回配置，重啟fpm）
4、進(jìn)行g(shù)db調(diào)試，如下圖
從調(diào)用?？梢钥吹?，最后執(zhí)行Memcached::addServers，調(diào)用libmemcached時(shí)出錯(cuò)了。
可以基本判斷出是使用緩存出問(wèn)題了。
網(wǎng)上查相關(guān)資料，有解釋是這樣說(shuō)的：memcached長(zhǎng)連接的問(wèn)題 看來(lái)似乎還是得從業(yè)務(wù)入手。
定位問(wèn)題：
分析nginx access日志，發(fā)現(xiàn)主要集中在兩類(lèi)請(qǐng)求
1) xxxx/post/detail/?puid=2810963318
2) xxxx/xiaoqu/detail/?xiaoquId=1579&fields=public%2Cstat%2Cfacility
第一類(lèi)請(qǐng)求正常返回，第二類(lèi)請(qǐng)求有很多的502。配置host在摘掉流量的機(jī)器上調(diào)試，發(fā)現(xiàn)大量刷頁(yè)面時(shí)可以復(fù)現(xiàn)問(wèn)題。
追蹤代碼，發(fā)現(xiàn)該業(yè)務(wù)使用了公司的wcache服務(wù)（分布式緩存），而wcache使用memcached協(xié)議。將cache注釋?zhuān)l(fā)現(xiàn)問(wèn)題不再?gòu)?fù)現(xiàn)。即可確定是wcache的問(wèn)題。原因是，service的三臺(tái)機(jī)器wcache客戶(hù)端未更新為php7版本，更新后即解決問(wèn)題。水平有限，未徹底跟進(jìn)舊版本的問(wèn)題原因。
經(jīng)驗(yàn)總結(jié)：
1、擴(kuò)展的問(wèn)題，一般會(huì)導(dǎo)致fpm出錯(cuò)，甚至導(dǎo)致core。這時(shí)用gdb看一下，就可以知道是哪個(gè)擴(kuò)展出問(wèn)題了。網(wǎng)上查查這個(gè)擴(kuò)展相關(guān)的信息
2、從nginx access日志入手，則可以知道是哪類(lèi)業(yè)務(wù)出錯(cuò)多，便于復(fù)現(xiàn)問(wèn)題，斷點(diǎn)調(diào)試。
二、業(yè)務(wù)的問(wèn)題
問(wèn)題現(xiàn)象：
1、升級(jí)完php7的機(jī)器中，有幾臺(tái)從曲線、指標(biāo)上看，提升不大，感覺(jué)有異常
2、nginx access日志里大量499錯(cuò)誤
3、fpm大量慢日志，錯(cuò)誤日志里記錄著類(lèi)似：WARNING: [pool www] child 29682 exited on signal 15 (SIGTERM) after 58.730780 seconds from start
初步結(jié)論：
從fpm日志看，這是php進(jìn)程執(zhí)行過(guò)慢，超時(shí)導(dǎo)致fpm進(jìn)程終止。
定位問(wèn)題：
從nginx access日志里看，499錯(cuò)誤集中在類(lèi)似：xxx/fang5/2991994508x.htm的請(qǐng)求上，是房源詳情頁(yè)的展示。但是，php5的機(jī)器上access日志有499的錯(cuò)誤，但是fpm沒(méi)有SIGTERM的錯(cuò)誤。
通過(guò)打斷點(diǎn)的方式，發(fā)現(xiàn)在詳情頁(yè)里，有一處業(yè)務(wù)，在使用fsocketopen時(shí)，對(duì)應(yīng)服務(wù)已經(jīng)下線，超時(shí)設(shè)置為800ms，導(dǎo)致一定超時(shí)，并且重試1次。
但是，fpm配置里，進(jìn)程超時(shí)時(shí)間設(shè)置為30s，1.6s也遠(yuǎn)遠(yuǎn)達(dá)不到，最多是頁(yè)面卡。況且，業(yè)務(wù)代碼在php5和php7是一樣的，5下為何沒(méi)有問(wèn)題呢，解釋不通。
而且，fsocketopen本身實(shí)現(xiàn)是異步的。
ptrace
修改fpm配置，只啟動(dòng)2個(gè)子進(jìn)程進(jìn)行處理。ptrace跟蹤任務(wù)，看看一次請(qǐng)求php究竟做了些啥。狂刷頁(yè)面，終于問(wèn)題復(fù)現(xiàn)了。
分析日志發(fā)現(xiàn)，有大量的socket使用（連接、收發(fā)數(shù)據(jù)），和nanosleep()系統(tǒng)調(diào)用。并且nanosleep都是伴隨在socket不可用時(shí)產(chǎn)生的。
這樣就可以分析出，是底層建立網(wǎng)絡(luò)連接時(shí)，有很多連接不可用，調(diào)用epoll，并等待。最終導(dǎo)致進(jìn)程執(zhí)行時(shí)間過(guò)長(zhǎng)。這么看來(lái)，真的是前面斷點(diǎn)處使用fsocketopen問(wèn)題咯？但是30s超時(shí)真解釋不通。
分析ptrace日志，發(fā)現(xiàn)socket連接失敗，集中在某幾個(gè)ip和端口。grep業(yè)務(wù)代碼，沒(méi)找到ip和端口。這時(shí)就需要找運(yùn)維同學(xué)看了。
這些ip和端口對(duì)應(yīng)的服務(wù)，發(fā)現(xiàn)是session服務(wù)。
同時(shí)，在ptrace日志，也發(fā)現(xiàn)，確實(shí)寫(xiě)著mem.ses的字眼。那么基本可以確定，是session使用出問(wèn)題了。把業(yè)務(wù)底層的session使用注釋?zhuān)l(fā)現(xiàn)問(wèn)題不再?gòu)?fù)現(xiàn)。
問(wèn)題結(jié)論：
看了一下session的實(shí)現(xiàn)，使用的memcache分布式存儲(chǔ)，只在進(jìn)程執(zhí)行結(jié)束時(shí)，釋放session。那么，當(dāng)大量請(qǐng)求、進(jìn)程執(zhí)行慢時(shí)，session鎖競(jìng)爭(zhēng)會(huì)變得非常嚴(yán)重，最終導(dǎo)致php進(jìn)程的超時(shí)。
解決辦法是，減少業(yè)務(wù)上的超時(shí)接口，例如前面所述業(yè)務(wù)fsocketopen的1.6s。并建議使用session時(shí)，獲取完數(shù)據(jù)就手動(dòng)釋放，減少鎖。
經(jīng)驗(yàn)總結(jié)：
配置fpm，起一兩個(gè)進(jìn)程，用ptrace跟蹤定位問(wèn)題非常方便。
