需求
日誌對於線上排查問題是非常重要的,很多問題其實是很偶現的,同樣的系統版本,同樣的裝置,可能就是使用者的復現,而開發通過相同的操作和裝置就是不復現。但是這個問題也不能一直不解決,所以可以通過日誌的方式排查問題。可能是後臺導致的問題,也可能是客戶端邏輯問題,在關鍵點記錄日誌可以快速定位問題。
假設我們的使用者量是一百萬日活,其中有1%
的使用者使用出現問題,即使這個問題並不是崩潰,就是業務上或播放出現問題。那這部分使用者就是一萬的使用者,一萬的使用者數量是很龐大的。而且大多數使用者在遇到問題後,並不會主動去聯絡客服,而是轉到其他平臺上。
雖然我們現在有Kibana
網路監控,但是隻能排查網路請求是否有問題,使用者是否在某個時間請求了伺服器,伺服器下發的資料是否正確,但是如果定位業務邏輯的問題,還是要客戶端記錄日誌。
現狀
我們專案中之前有日誌系統,但是從業務和技術的角度來說,存在兩個問題。現有的日誌系統從業務層角度,需要使用者手動匯出併發給客服,對使用者有不必要的打擾。而且大多數使用者並不會答應客服的請求,不會匯出日誌給客服。從技術的角度,現有的日誌系統程式碼很亂,而且效能很差,導致線上不敢持續記錄日誌,會導致播放器卡頓。
而且現有的日誌系統僅限於debug
環境開啟主動記錄,線上是不開啟的,線上出問題後需要使用者手動開啟,並且記錄時長只有三分鐘。正是由於現在存在的諸多問題,所以大家對日誌的使用並不是很積極,線上排查問題就比較困難。
方案設計
思路
正是針對現在存在的問題,我準備做一套新的日誌系統,來替代現有的日誌系統。新的日誌系統定位很簡單,就是純粹的記錄業務日誌。Crash
、埋點這些,我們都不記錄在裡面,這些可以當做以後的擴充套件。日誌系統就記錄三種日誌,業務日誌、網路日誌、播放器日誌。
日誌收集我們採用的主動回撈策略,在日誌平臺上填寫使用者的uid
,通過uid
對指定裝置下發回撈指令,回撈指令通過長連線的方式下發。客戶端收到回撈指令後,根據篩選條件對日誌進行篩選,隨後以天為單位寫入到不同的檔案中,壓縮後上傳到後端。
在日誌平臺可以根據指定的條件進行搜尋,並下載檔案檢視日誌。為了便於開發者檢視日誌,從資料庫取出的日誌都會寫成.txt
形式,並上傳此檔案。
API設計
對於呼叫的API
設計,應該足夠簡單,業務層使用時就像呼叫NSLog
一樣。所以對於API
的設計方案,我採用的是巨集定義的方式,呼叫方法和NSLog
一樣,呼叫很簡單。
#if DEBUG
#define SVLogDebug(frmt, ...) [[SVLogManager sharedInstance] mobileLogContent:(frmt), ##__VA_ARGS__]
#else
#define SVLogDebug(frmt, ...) NSLog(frmt, ...)
#endif
日誌總共分為三種型別,業務日誌、播放器日誌、網路日誌,對於三種日誌分別對應著不同的巨集定義。不同的巨集定義,寫入資料庫的型別也不一樣,可以使用者日誌篩選。
- 業務日誌:
SVLogDebug
。 - 播放器日誌:
SVLogDebugPlayer
。 - 網路日子:
SVLogDebugQUIC
。
淘汰策略
不光是要往資料庫裡寫,還需要考慮淘汰策略。淘汰策略需要平衡記錄的日誌數量,以及時效性的問題,日誌數量儘量夠排查問題,並且還不會佔用過多的磁碟空間。所以,在日誌上傳之後會將已上傳日誌刪除掉,除此之外日誌淘汰策略有以下兩種。
- 日誌最多隻儲存三天,三天以前的日誌都會被刪掉。在應用啟動後進行檢查,並後臺執行緒執行這個過程。
- 日誌增加一個最大閾值,超過閾值的日誌部分,以時間為序,從前往後刪除。我們定義的閾值大小為
200MB
,一般不會超過這個大小。
記錄基礎資訊
在排查問題時一些關鍵資訊也很重要,例如使用者當時的網路環境,以及一些配置項,這些因素對程式碼的執行都會有一些影響。對於這個問題,我們也會記錄一些使用者的配置資訊及網路環境,方便排查問題,但不會涉及使用者經緯度等隱私資訊。
資料庫
舊方案
之前的日誌方案是通過DDLog
實現的,這種方案有很嚴重的效能問題。其寫入日誌的方式,是通過NSData
來實現的,在沙盒建立一個txt
檔案,通過一個控制程式碼來向本地寫檔案,每次寫完之後把控制程式碼seek
到檔案末尾,下次直接在檔案末尾繼續寫入日誌。日誌是以NSData
的方式進行處理的,相當於一直在頻繁的進行本地檔案寫入操作,還要在記憶體中維持一個或者多個控制程式碼物件。
這種方式還有個問題在於,因為是直接進行二進位制寫入,在本地儲存的是txt
檔案。這種方式是沒有辦法做篩選之類的操作的,擴充套件性很差,所以新的日誌方案我們打算採用資料庫來實現。
方案選擇
我對比了一下iOS
平臺主流的資料庫,發現WCDB
是綜合效能最好的,某些方面比FMDB
都要好,而且由於是C++
實現的程式碼,所以從程式碼執行的層面來講,也不會有OC
的訊息傳送和轉發的額外消耗。
根據WCDB
官網的統計資料,WCDB
和FMDB
進行對比,FMDB
是對SQLite
進行簡單封裝的框架,和直接用SQLite
差別不是很大。而WCDB
則在sqlcipher
的基礎上進行的深度優化,綜合效能比FMDB
要高,以下是效能對比,資料來自WCDB
官方文件。
單次讀操作WCDB
要比FMDB
慢5%
左右,在for
迴圈內一直讀。
單次寫操作WCDB
要比FMDB
快28%
,一個for
迴圈一直寫。
批量寫操作比較明顯,WCDB
要比FMDB
快180%
,一個批量任務寫入一批資料。
從資料可以看出,WCDB
在寫操作這塊效能要比FMDB
要快很多,而本地日誌最頻繁的就是寫操作,所以這正好符合我們的需求,所以選擇WCDB
作為新的資料庫方案是最合適的。而且專案中曝光模組已經用過WCDB
,證明這個方案是可行並且效能很好的。
表設計
我們資料庫的表設計很簡單,就下面四個欄位,不同型別的日誌用type
做區分。如果想增加新的日誌型別,也可以在專案中擴充套件。因為使用的是資料庫,所以擴充套件性很好。
- index:主鍵,用來做索引。
- content:日誌內容,記錄日誌內容。
- createTime:建立時間,日誌入庫的時間。
- type:日誌型別,用來區分三種型別。
資料庫優化
我們是視訊類應用,會涉及播放、下載、上傳等主要功能,這些功能都會大量記錄日誌,來方便排查線上問題。所以,避免資料庫太大就成了我在設計日誌系統時,比較看重的一點。
根據日誌規模,我對播放、下載、上傳三個模組進行了大量測試,播放一天兩夜、下載40集電視劇、上傳多個高清視訊,累計記錄的日誌數量大概五萬多條。我發現資料庫資料夾已經到200MB+
的大小,這個大小已經是比較大的,所以需要對資料庫進行優化。
我觀察了一下資料庫資料夾,有三個檔案,db
、shm
、wal
,主要是資料庫的日誌檔案太大,db
檔案反而並不大。所以需要呼叫sqlite3_wal_checkpoint
將wal
內容寫入到資料庫中,這樣可以減少wal
和shm
檔案的大小。但WCDB
並沒有提供直接checkpoint
的方法,所以經過調研發現,執行database
的關閉操作時,可以觸發checkpoint
。
我在應用程式退出時,監聽了terminal
通知,並且把處理實際儘量靠後。這樣可以保證日誌不被遺漏,而且還可以在程式退出時關閉資料庫。經過驗證,優化後的資料庫磁碟佔用很小。143,987
條資料庫,資料庫檔案大小為34.8MB
,壓縮後的日誌大小為1.4MB
,解壓後的日誌大小為13.6MB
。
wal模式
這裡順帶講一下wal
模式,以方便對資料庫有更深入的瞭解。SQLite
在3.7
版本加入了wal
模式,但預設是不開啟的,iOS
版的WCDB
將wal
模式自動開啟,並且做了一些優化。
wal
檔案負責優化多執行緒下的併發操作,如果沒有wal
檔案,在傳統的delete
模式下,資料庫的讀寫操作是互斥的,為了防止寫到一半的資料被讀到,會等到寫操作執行完成後,再執行讀操作。而wal
檔案就是為了解決併發讀寫的情況,shm
檔案是對wal
檔案進行索引的。
SQLite
比較常用的delete
和wal
兩種模式,這兩種模式各有優勢。delete
是直接讀寫db-page
,讀寫操作的都是同一份檔案,所以讀寫是互斥的,不支援併發操作。而wal
是append
新的db-page
,這樣寫入速度比較快,而且可以支援併發操作,在寫入的同時不讀取正在操作的db-page
即可。
由於delete
模式操作的db-page
是離散的,所以在執行批量寫操作時,delete
模式的效能會差很多,這也就是為什麼WCDB
的批量寫入效能比較好的原因。而wal
模式讀操作會讀取db
和wal
兩個檔案,這樣會一定程度影響讀資料的效能,所以wal
的查詢效能相對delete
模式要差。
使用wal
模式需要控制wal
檔案的db-page
數量,如果page
數量太大,會導致檔案大小不受控制。wal
檔案並不是一直增加的,根據SQLite
的設計,通過checkpoint
操作可以將wal
檔案合併到db
檔案中。但同步的時機會導致查詢操作被阻塞,所以不能頻繁執行checkpoint
。在WCDB
中設定了一個1000
的閾值,當page
達到1000
後才會執行一次checkpoint
。
這個1000
是微信團隊的一個經驗值,太大會影響讀寫效能,而且佔用過多的磁碟空間。太小會頻繁執行checkpoint
,導致讀寫受阻。
# define SQLITE_DEFAULT_WAL_AUTOCHECKPOINT 1000
sqlite3_wal_autocheckpoint(db, SQLITE_DEFAULT_WAL_AUTOCHECKPOINT);
int sqlite3_wal_autocheckpoint(sqlite3 *db, int nFrame){
#ifdef SQLITE_OMIT_WAL
UNUSED_PARAMETER(db);
UNUSED_PARAMETER(nFrame);
#else
#ifdef SQLITE_ENABLE_API_ARMOR
if( !sqlite3SafetyCheckOk(db) ) return SQLITE_MISUSE_BKPT;
#endif
if( nFrame>0 ){
sqlite3_wal_hook(db, sqlite3WalDefaultHook, SQLITE_INT_TO_PTR(nFrame));
}else{
sqlite3_wal_hook(db, 0, 0);
}
#endif
return SQLITE_OK;
}
也可以設定日誌檔案的大小限制,預設是-1
,也就是沒限制,journalSizeLimit
的意思是,超出的部分會被覆寫。儘量不要修改這個檔案,可能會導致wal
檔案損壞。
i64 sqlite3PagerJournalSizeLimit(Pager *pPager, i64 iLimit){
if( iLimit>=-1 ){
pPager->journalSizeLimit = iLimit;
sqlite3WalLimit(pPager->pWal, iLimit);
}
return pPager->journalSizeLimit;
}
下發指令
日誌平臺
日誌上報應該做到使用者無感知,不需要使用者主動配合即可進行日誌的自動上傳。而且並不是所有的使用者日誌都需要上報,只有出問題的使用者日誌才是我們需要的,這樣也可以避免服務端的儲存資源浪費。對於這些問題,我們開發了日誌平臺,通過下發上傳指令的方式告知客戶端上傳日誌。
我們的日誌平臺做的比較簡單,輸入uid
對指定的使用者下發上傳指令,客戶端上傳日誌之後,也可以通過uid
進行查詢。如上圖,下發指令時可以選擇下面的日誌型別和時間區間,客戶端收到指令後會根據這些引數做篩選,如果沒選擇則是預設引數。搜尋時也可以使用這三個引數。
日誌平臺對應一個服務,點選按鈕下發上傳指令時,服務會給長連線通道下發一個json
,json
中包含上面的引數,以後也可以用來擴充套件其他欄位。上傳日誌是以天為單位的,所以在這裡可以根據天為單位進行搜尋,點選下載可以直接預覽日誌內容。
長連線通道
指令下發這塊我們利用了現有的長連線,當使用者反饋問題後,我們會記錄下使用者的uid
,如果技術需要日誌進行排查問題時,我們會通過日誌平臺下發指令。
指令會傳送到公共的長連線服務後臺,服務會通過長連線通道下發指令,如果指令下發到客戶端之後,客戶端會回覆一個ack
訊息回覆,告知通道已經收到指令,通道會將這條指令從佇列中移除。如果此時使用者未開啟App
,則這條指令會在下次使用者開啟App
,和長連線通道建立連線時重新下發。
未完成的上傳指令會在佇列中,但最多不超過三天,因為超過三天的指令就已經失去其時效性,問題當時可能已經通過其他途徑解決。
靜默push
使用者如果開啟App
時,日誌指令的下發可以通過長連線通道下發。還有一種場景,也是最多的一種場景,使用者未開啟App
怎麼解決日誌上報的問題,這塊我們還在探索中。
當時也調研了美團的日誌回撈,美團的方案中包含了靜默push
的策略,但是經過我們調研之後,發現靜默push
基本意義不大,只能覆蓋一些很小的場景。例如使用者App
被系統kill
掉,或者在後臺被掛起等,這種場景對於我們來說並不多見。另外和push
組的人也溝通了一下,push
組反饋說靜默push
的到達率有些問題,所以就沒采用靜默push
的策略。
日誌上傳
分片上傳
進行方案設計的時候,由於後端不支援直接展示日誌,只能以檔案的方式下載下來。所以當時和後端約定的是以天為單位上傳日誌檔案,例如回撈的時間點是,開始時間4月21日19:00,結束時間4月23日21:00。對於這種情況會被分割為三個檔案,即每天為一個檔案,第一天的檔案只包含19:00開始的日誌,最後一天的檔案只包含到21:00的日誌。
這種方案也是分片上傳的一種策略,上傳時以每個日誌檔案壓縮一個zip
檔案後上傳。這樣一方面是保證上傳成功率,檔案太大會導致成功率下降,另一方面是為了做檔案分割。經過觀察,每個檔案壓縮成zip
後,檔案大小可以控制在500kb
以內,500kb
這個是我們之前做視訊切片上傳時的一個經驗值,這個經驗值是上傳成功率和分片數量的一個平衡點。
日誌命名使用時間戳為組合,時間單位應該精確到分鐘,以方便服務端做時間篩選操作。上傳以表單的方式進行提交,上傳完成後會刪除對應的本地日誌。如果上傳失敗則使用重試策略,每個分片最多上傳三次,如果三次都上傳失敗,則這次上傳失敗,在其他時機再重新上傳。
安全性
為了保證日誌的資料安全性,日誌上傳的請求我們通過https
進行傳輸,但這還是不夠的,https
依然可以通過其他方式獲取到SSL
管道的明文資訊。所以對於傳輸的內容,也需要進行加密,選擇加密策略時,考慮到效能問題,加密方式採用的對稱加密策略。
但對稱加密的祕鑰是通過非對稱加密的方式下發的,並且每個上傳指令對應一個唯一的祕鑰。客戶端先對檔案進行壓縮,對壓縮後的檔案進行加密,加密後分片再上傳。服務端收到加密檔案後,通過祕鑰解密得到zip
並解壓縮。
主動上報
新的日誌系統上線後,我們發現回撈成功率只有40%
,因為有的使用者反饋問題後就失去聯絡,或者反饋問題後一直沒有開啟App
。對於這個問題,我分析使用者反饋問題的途徑主要有兩大類,一種是使用者從系統設定裡進去反饋問題,並且和客服溝通後,技術介入排查問題。另一種是使用者發生問題後,通過反饋群、App Store
評論區、運營等渠道反饋的問題。
這兩種方式都適用於日誌回撈,但第一種由於有特定的觸發條件,也就是使用者點選進入反饋介面。所以,對於這種場景反饋問題的使用者,我們增加了主動上報的方式。即使用者點選反饋時,主動上報以當前時間為結束點,三天內的日誌。這樣可以把日誌上報的成功率提升到90%
左右,成功率上來後也會推動更多人接入日誌模組,方便排查線上問題。
手動匯出
日誌上傳的方式還包含手動匯出,手動匯出就是通過某種方式進入除錯頁面,在除錯頁面選擇對應的日誌分享,並且調起系統分享皮膚,通過對應的渠道分享出去。在新的日誌系統之前,就是通過這種方式讓使用者手動匯出日誌給客服的,可想而知對使用者的打擾有多嚴重吧。
現在手動匯出的方式依然存在,但只用於debug
階段測試和開發同學,手動匯出日誌來排查問題,線上是不需要使用者手動操作的。