一、存儲
在將數據傳送到后台之前,已經做了一輪清洗工作,如果有需要還可以再做一次清洗。
日志表如下所示,自增的 id 直接偷懶使用了 bigint,沒有采用分表等其他技術。
CREATE TABLE `web_monitor` ( `id` bigint(20) NOT NULL AUTO_INCREMENT, `project` varchar(45) COLLATE utf8mb4_bin NOT NULL COMMENT '項目名稱', `digit` int(11) NOT NULL DEFAULT '1' COMMENT '出現次數', `message` text COLLATE utf8mb4_bin NOT NULL COMMENT '聚合信息', `ua` varchar(600) COLLATE utf8mb4_bin NOT NULL COMMENT '代理信息', `key` varchar(45) COLLATE utf8mb4_bin NOT NULL COMMENT '去重用的標記', `category` varchar(45) COLLATE utf8mb4_bin NOT NULL COMMENT '日志類型', `source` varchar(45) COLLATE utf8mb4_bin DEFAULT NULL COMMENT 'SourceMap映射文件的地址', `ctime` timestamp NULL DEFAULT CURRENT_TIMESTAMP, `identity` varchar(20) COLLATE utf8mb4_bin DEFAULT NULL COMMENT '身份,用於連貫日志上下文', `day` int(11) DEFAULT NULL COMMENT '格式化的天(冗余字段),用於排序,20210322', `hour` tinyint(2) DEFAULT NULL COMMENT '格式化的小時(冗余字段),用於分組,11', `minute` tinyint(2) DEFAULT NULL COMMENT '格式化的分鍾(冗余字段),用於分組,20', `message_status` int(11) DEFAULT NULL COMMENT 'message中的通信狀態碼', `message_path` varchar(45) COLLATE utf8mb4_bin DEFAULT NULL COMMENT 'message通信中的 path', `message_type` varchar(20) COLLATE utf8mb4_bin DEFAULT NULL COMMENT 'message中的類別字段', PRIMARY KEY (`id`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin COMMENT='前端監控日志';
在正式上線后,遇到了幾次慢查詢,阿里雲給出了相關索引建議,后面就直接加上了,效果立竿見影。
1)堆棧壓縮
對於數據量很大的公司,像下面這樣的堆棧內容消耗的存儲空間是非常可觀的,因此有必要做一次壓縮。
例如將重復的內容提取出來,用簡短的標識進行替代,把 URL 被替換成了 # 和數字組成的標識等。
{ "type": "runtime", "lineno": 1, "colno": 100, "desc": "Uncaught Error: Cannot find module \"./paramPathMap\" at http://localhost:8000/umi.js:248565:7", "stack": "Error: Cannot find module \"./paramPathMap\" at Object.<anonymous> (http://localhost:8000/umi.js:248565:7) at __webpack_require__ (http://localhost:8000/umi.js:679:30) at fn (http://localhost:8000/umi.js:89:20) at Object.<anonymous> (http://localhost:8000/umi.js:247749:77) at __webpack_require__ (http://localhost:8000/umi.js:679:30) at fn (http://localhost:8000/umi.js:89:20) at Object.<anonymous> (http://localhost:8000/umi.js:60008:18) at __webpack_require__ (http://localhost:8000/umi.js:679:30) at fn (http://localhost:8000/umi.js:89:20) at render (http://localhost:8000/umi.js:73018:200) at Object.<anonymous> (http://localhost:8000/umi.js:73021:1) at __webpack_require__ (http://localhost:8000/umi.js:679:30) at fn (http://localhost:8000/umi.js:89:20) at Object.<anonymous> (http://localhost:8000/umi.js:72970:18) at __webpack_require__ (http://localhost:8000/umi.js:679:30) at http://localhost:8000/umi.js:725:39 at http://localhost:8000/umi.js:728:10" }
考慮到我所在公司的數據量不會很大,人力資源也比較緊張,為了盡快上線,所以沒有使用壓縮,后期有時間了再來優化。
2)去除重復
雖然沒有做壓縮,但是對於相同的日志還是做了一次去重操作。
去重規則也很簡單,就是將項目 token、日志類別和日志內容拼接成一段字符串,再用MD5加密,下面是 Node.js 代碼。
const key = crypto.createHash("md5").update(token + category + message).digest("hex");
將 key 作為條件判斷數據庫中是否存在這條記錄,若存在就給 digit 字段加一。
在正式上線后,每次在添加日志時都要做這層判斷,一度將數據庫阻塞掉。因為每次在做 key 判斷時要全表查詢一次,舊的查詢還沒執行完,新的就來了。
為了解決此問題,就加上了一個基於 Redis 的隊列:Kue,將判斷、更新和插入的邏輯封裝到一個任務中,異步執行。注意,目前此庫已經不維護了,首頁上推薦了替代品:Bull。
再加上索引,雙重保障后,現在接收日志時未出現問題。
二、分析
目前的分析部分也比較簡單,只包括一個監控看板、趨勢分析、日志列表和定時任務等。
1)監控看板
在監控看板中包含今日數據和往期趨勢折線圖,本來想用 EChart.js 作圖,不過后面集成時出了點問題,並且該庫比較大,要500KB以上,於是換了另一個更小的庫:Chart.js,只有60KB。
今日數據有今日和昨日的日志總數、錯誤總數和影響人數,通信、事件、打印和跳轉等總數。
其中錯誤總數會按照 category:"error" 的 sum(digit) 來求和,而影響人數只會按照記錄的個數來計算。
今日的數量是實時計算的,在使用中發現查詢特別慢,要好幾分鍾才能得到結果,於是為幾個判斷條件中的字段加了個二級索引后(例如為 ctime 和 category 加索引),就能縮短到幾秒鍾響應。
ALTER TABLE `web_monitor` ADD INDEX `idx_category_ctime` (`category`, `ctime`); SELECT count(*) AS `count` FROM `web_monitor` WHERE (`ctime` >= '2021-03-25 16:00:00' AND `ctime` < '2021-03-26 16:00:00') AND `category` = 'ajax';
在往期趨勢中,會展示錯誤、500、502 和 504 錯誤、日志總數折線圖,這些數據會被保存在一張額外的統計表中,這樣就不必每次實時計算了。折線的顏色值取自 AntDesign。
計算了一下出現 504 的通信占全部的 0.2%,接下來需要將這個比例再往下降。
在看板中,展示的錯誤日志每天在七八千左右,為了減少到幾百甚至更低的范圍,可采取的措施有:
- 過濾掉無意義的錯誤,例如SyntaxError: Unexpected token ',',該錯誤占了 55%~60% 左右。
- 優化頁面和接口邏輯,504通信錯誤占了25%~30% 左右。
- 將這兩個大頭錯誤搞定,再針對性優化剩下的錯誤,就能將錯誤控制目標范圍內。
從日志中可以查看到具體的接口路徑,然后就能對其進行針對性的優化。
例如有一張活動頁面,在進行一個操作時會請求兩個接口,並且每個接口各自發送 3 次通信,這樣會很容易發生 504 錯誤(每天大約有1500個這樣的請求),因此需要改造該邏輯。
首先是給其中一張表加索引,然后是將兩個接口合並成一個,並且每次返回 20 條以上的數據,這樣就不用頻繁的發起請求了。
經過改造后,每日的 504 請求從 1500 個左右降低到 200 個左右,減少了整整 7.5 倍,效果立竿見影,大部分的 504 集中在 22 點到 0 點之間,這段時間的活躍度比較高。
還有一個令人意外的發現,那就是監控日志的量每天也減少了 50W 條。
2)日志列表
在日志列表中會包含幾個過濾條件:編號、關鍵字、日期范圍、項目、日志類型和身份標識等。
如果輸入了關鍵字,那么會在監控日志搜索結果列表中為其着色,這樣更便於查看,用正則加字符串的 replace() 方法配合實現的。
在數據量上去后,當對內容(MYSQL 中的類型是 TEXT)進行模糊查詢時,查詢非常慢,用 EXPLAIN 分析SQL語句時,發現在做全表查詢。
經過一番搜索后,發現了全文索引(match against 語法),在 5.7.6 之前的 MYSQL 不支持中文檢索,好在大部分情況要搜索的內容都是英文字符。
SELECT * FROM `web_monitor` WHERE MATCH(message) AGAINST('+*test*' IN BOOLEAN MODE)
在建完這個索引后,表的容量增加了 3G 多,當前表中包含 1400W 條數據。
CREATE FULLTEXT INDEX ft_message ON web_monitor(message)
有時候還是需要模糊匹配的,所以想了下加個下拉選項,來手動命令后台使用哪種方式的查詢,但如果是模糊匹配,必須選擇日期來縮小查找范圍。
在實際使用時,又發現缺張能直觀展示峰值的圖表,例如我想知道在哪個時間段某個特定錯誤的數量最多,於是又加了個按鈕和柱狀圖,支持跨天計算。
身份標識可以查詢到某個用戶的一系列操作,更容易鎖定錯誤發生時的情境。
每次查詢列表時,在后台就會通過Source Map文件映射位置,注意,必須得有列號才能還原,並且需要安裝 source-map 庫。
const sourceMap = require("source-map"); /** * 讀取指定的Source-Map文件 */ function readSourceMap(filePath) { let parsedData = null; try { parsedData = fs.readFileSync(filePath, "utf8"); parsedData = JSON.parse(parsedData); } catch (e) { logger.info(`sourceMap:error`); } return parsedData; } /** * 處理映射邏輯 */ async function getSourceMap(row) { // 拼接映射文件的地址 const filePath = path.resolve( __dirname, config.get("sourceMapPath"), process.env.NODE_ENV + "-" + row.project + "/" + row.source ); let { message } = row; message = JSON.parse(message); // 不存在行號或列號 if (!message.lineno || !message.colno) { return row; } // 打包后的sourceMap文件 const rawSourceMap = readSourceMap(filePath); if (!rawSourceMap) { return row; } const errorPos = { line: message.lineno, column: message.colno }; // 過傳入打包后的代碼位置來查詢源代碼的位置 const consumer = await new sourceMap.SourceMapConsumer(rawSourceMap); // 獲取出錯代碼在哪一個源文件及其對應位置 const originalPosition = consumer.originalPositionFor({ line: errorPos.line, column: errorPos.column }); // 根據源文件名尋找對應源文件 const sourceIndex = consumer.sources.findIndex( (item) => item === originalPosition.source ); const sourceCode = consumer.sourcesContent[sourceIndex]; if (sourceCode) { row.sourceInfo = { code: sourceCode, lineno: originalPosition.line, path: originalPosition.source }; } // 銷毀,否則會報內存訪問超出范圍 consumer.destroy(); return row; }
點擊詳情,就能在彈框中查看到代碼具體位置了,編碼着色采用了 highlight.js。
而每行代碼的行號使用了一個擴展的 highlight-line-numbers.js,柔和的淡紅色的色值是 #FFECEC。
圖中還有個上下文的 tab,這是一個很有用的功能,可以查詢到當前這條記錄前面和后面的所有日志。
本以為萬事大吉,但是沒想到在檢索時用模糊查詢,直接將數據庫跑掛了。
無奈,從服務器上將日志數據拉下來,導入本地數據庫中,在本地做查詢優化,2000W條數據倒了整整兩個小時。
和大數據的同事溝通后,他們說可以引入 ElasticSearch 做檢索功能。當他們看到我的 message 字段中的內容時,他們建議我先做關鍵字優化。
就是將我比較關心的內容放到單獨的字段中,提升命中率,而將一些可變的或不重要的數據再放到另一個字段中,單純的做存儲。
例如通信內容中,我比較關心的是 url 和 status,那么就將它們抽取出來,並且去除無關緊要的信息(例如錯誤的 stack、通信的 headers)給 message 字段瘦身,最多的能減少三分之二以上。
{ "type": "GET", "url": "/api/monitor/list?category=error&category=script&msg=", "status": 200, "endBytes": "0.15KB", "interval": "22.07ms", "network": { "bandwidth": 0, "type": "3G" }, }
最后決定報表統計的邏輯仍然用 MySQL,而檢索改成 ElasticSearch,由大數據組的同事提供接口,我們這邊傳數據給他們。
而之前的檢索方式也可以棄用了,MySQL中存儲的日志數據也從 14 天減少到 7 天。
在使用過程中遇到了幾個問題:
- 沒有將所有的數據傳遞到ES庫中,丟失了將近33%的數據,后面排查發現有些數據傳遞到了預發環境,而預發環境中有個參數沒配置導致無法推送。
- 在檢索時,返回的列表會漏幾條記錄,在一個可視化操作界面中輸入查詢條件可以得到連續的數據。經過排查發現,可能是在后台查詢時,由於異步隊列的原因,那幾條數據還未推送,這樣的話就會得不到那幾條記錄,導致不連續。
通過日志列表中的通信和點擊事件,可以計算出業務方日常工作的耗時,這個值可以作為指標,來驗證對業務優化后,前后的對比,這樣的量化能讓大家知道自己工作給業務方帶來了多少提升。
3)定時任務
每天的凌晨4點,統計昨天的日志信息,保存到 web_monitor_statis 表中。
CREATE TABLE `web_monitor_statis` ( `id` int(11) NOT NULL AUTO_INCREMENT, `date` int(11) NOT NULL COMMENT '日期,格式為20210318,一天只存一條記錄', `statis` text COLLATE utf8mb4_bin NOT NULL COMMENT '以JSON格式保存的統計信息', PRIMARY KEY (`id`), UNIQUE KEY `date_UNIQUE` (`date`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin COMMENT='前端監控日志統計信息表';
在 statis 字段中,保存的是一段JSON數據,類似於下面這樣,key 值是項目的 token。
{ "backend-app": {
allCount: 0, errorCount: 1, errorSum: 1, error500Count: 0, error502Count: 0, error504Count: 1, ajaxCount: 20, consoleCount: 0, eventCount: 0, redirectCount: 0 } }
還有個定時任務會在每天的凌晨3點,將一周前的數據清除(web_monitor),並將三周前的 map 文件刪除。
之所以有個時間差是為了避免一周內的數據中還有需要引用兩周前的 map 文件,當然這個時間差還可以更久。
注意,MySQL中表的數據通過 delete 命令刪除,如果使用的是 InnoDB 存儲引擎,那么是不會釋放磁盤空間的,需要執行 optimize 語句,例如:
optimize table `web_monitor`
原先每日的數據量在180W左右,每條數據在 800B 左右,每天占用空間 1.3G 左右。
后面優化了請求量,過濾掉重復和無意義的請求后(例如后台每次都要發的身份驗證的請求、活動頁面的埋點請求等),每天的日志量控制在 100W 左右。
而在經過上述活動的504優化后,請求量降到了 50W 左右,優化效果很喜人。
保存 map 文件的空間在100G,應該是妥妥夠的。
在未來會將監控拓展到小程序,並且會加上告警機制,在合適的時候用郵件、飛書、微信或短信等方式通知相關人員,后面還有很多擴展可做。
敘述的比較簡單,但過程還說蠻艱辛的,修修補補,加起來的代碼大概有4、5千行的樣子。
4)服務遷移
在使用時發現監控日志的服務比較占用CPU和內存,於是將其單獨抽取做來,獨立部署。
經過這波操作后,整體的504錯誤,從 800 多漸漸降到了 100 左右。其中有一半的請求是埋點通信,業務請求降到了有史以來的最低點。
但CPU和內存並沒有按預期下降,這部分涉及到了一次詳細的內存泄漏的摸查過程,在下文會詳細分析。
5)飛書告警
首先需要注冊飛書開放平台,並創建應用。
然后在開放平台找到憑證,記錄 app_id 和 app_secret。
接着在應用功能中,啟用機器人,由機器人來發送告警。
再獲取 tenant_access_token(需要 app_id 和 app_secret),最后通過另一個接口發送消息。
下一步就是制訂告警規則。
參考: