日誌中每段程式碼執行時間的和不等於整段程式碼執行的總時間
阿新 • • 發佈:2018-11-23
程式碼邏輯:
def getInlink()
A -> B -> C -> D
在tornado中呼叫getInlink
@tornado.gen.coroutine def get(self): start2 = int(time.time()*1000) error, errReason, lstSummary = yield self.getInlink(utfQuery) print 'total use %d' % (int(time.time()*1000)-start2)
實踐中,分別記錄了上面四個步驟執行的時間, 假設為At, Bt, Ct, Dt,並且記錄了getInlink總的時間,假設為ADt(呼叫getInlink方法到返回的時間)
發現4個程式碼片段的時間的和不等於總的時間, 也就是:
ADt > At+Bt+Ct+Dt
原因是什麼呢?
之前分析過的錯誤的原因:
A->D這個步驟中應該還有CPU排程的等待時間,這段程式碼並不是一直都在執行
尤其,這4步如果有IO的話,假設B中有IO,那麼在B執行IO的過程中,該程序會被掛起,而當IO執行完後,也不一定馬上就可以被CPU排程執行,很可能還要等待一段時間
正確的原因:
其實上面分析的原因不對,因為B中的IO雖然會等待被排程,但是Bt的時間其實已經包含了那段等待被呼叫的時間了
真實的原因應該是呼叫getInlink方法用了yield,所以它所在的get方法就變成了迭代器,這個方法需要等待被tornado的空閒的執行緒來呼叫,所以應該是:
ADt = At+Bt+Ct+Dt + getInlink方法等待被執行的時間