从redo日志分析数据库的profile

    xiaoxiao2025-12-30  10

    标签

    PostgreSQL , pg_xlogdump , 数据库profile


    背景

    在PostgreSQL中查看TOP SQL是比较方便的,如下:

    《PostgreSQL 如何查找TOP SQL (例如IO消耗最高的SQL)》

    而从另一个角度,比如REDO文件,我们也能分析出每个时间段数据库的操作类型,分析数据库资源消耗,以及提出优化建议。

    redo日志长什么样

    pg_xlogdump

    要查看redo日志,不得不提pg_xlogdump,原理和介绍详见如下

    《PostgreSQL xlog dump - pg_xlogdump 源码讲解》

    我们简单的看看某个REDO文件的内容:

    pg_xlogdump 000000050000159E00000095 000000050000159E00000099|less rmgr: Btree len (rec/tot): 42/ 74, tx: 891772656, lsn: 159E/95000CA0, prev 159E/94FFEC78, bkp: 0000, desc: insert: rel 1663/56867/10216768; tid 19180/150 rmgr: Btree len (rec/tot): 34/ 66, tx: 891772656, lsn: 159E/95000CF0, prev 159E/95000CA0, bkp: 0000, desc: insert: rel 1663/56867/10906168; tid 150019/337 rmgr: Transaction len (rec/tot): 12/ 44, tx: 891772656, lsn: 159E/95000D38, prev 159E/95000CF0, bkp: 0000, desc: commit: 2017-05-04 13:15:50.262106 CST rmgr: Heap2 len (rec/tot): 26/ 58, tx: 0, lsn: 159E/95000D68, prev 159E/95000D38, bkp: 0000, desc: clean: rel 1663/56867/10216762; blk 402406 remxid 891772032 rmgr: Heap len (rec/tot): 25/ 8065, tx: 891772657, lsn: 159E/95000DA8, prev 159E/95000D68, bkp: 1000, desc: lock 891772657: rel 1663/56867/10216770; tid 39310/2 LOCK_ONLY EXCL_LOCK rmgr: Heap len (rec/tot): 36/ 8116, tx: 891772657, lsn: 159E/95002D48, prev 159E/95000DA8, bkp: 0100, desc: update: rel 1663/56867/10216770; tid 39310/2 xmax 891772657 ; new tid 122748/1 xmax 0 rmgr: Btree len (rec/tot): 18/ 5238, tx: 891772657, lsn: 159E/95004D18, prev 159E/95002D48, bkp: 1000, desc: insert: rel 1663/56867/10216776; tid 15681/11 rmgr: Transaction len (rec/tot): 12/ 44, tx: 891772657, lsn: 159E/950061A8, prev 159E/95004D18, bkp: 0000, desc: commit: 2017-05-04 13:15:50.320538 CST

    rmgr是指这笔REDO RECORD的类别,后面是长度等信息。

    通过以下命令,可以统计每个资源有多少笔redo记录,描述是什么?

    pg_xlogdump 000000050000159E00000095 000000050000159E00000099|grep -v " lock "| awk '{print $2" "$16" "$17}'|sort |uniq -c|sort -n -r 178464 Gin Insert item, 39060 Gin Vacuum page, 30980 Heap2 clean: rel 23855 Gin Vacuum data 22240 Btree insert: rel 18068 Heap insert: rel 15650 Heap2 visible: rel 8516 Heap delete: rel 4057 Transaction commit: 2017-05-04 3727 XLOG full-page image: 3331 Gin Insert new 3026 Heap update: rel 1196 Transaction abort: 2017-05-04 1191 Gin Update metapage, 765 Btree vacuum: rel 755 Heap hot_update: rel 243 Gin Delete list 55 Btree insert_upper: rel 50 Btree split_r: rel 32 Btree unlink_page: rel 32 Btree mark_page_halfdead: rel 29 Btree reuse_page: rel 28 Heap2 freeze_page: rel 27 Standby running xacts: 27 Heap insert(init): rel 20 Heap inplace: rel 11 Btree delete: index 9 Heap2 cleanup info: 5 Standby AccessExclusive locks: 5 Btree split_l: rel 4 Gin Page split, 2 XLOG checkpoint: redo 2 Gin Create posting 1 Heap update(init): rel

    这个日志可以看出什么问题呢?

    比如我们可以看到Gin的REDO非常多,说明用户使用了GIN索引,同时这个索引的写入,更新非常频繁。

    对于这种情况,用户可以设置GIN索引的fastupdate特性,同时调大vacuum naptime,以及调大表的vacuum阈值,尽量的减少GIN的合并频率,(但是fastupdate会降低检索性能)。

    其他,

    如果你看到VACUUM非常多,说明这些REDO中包含大量的垃圾回收信息,用户可能产生了较多垃圾,正在被回收。

    如果是VACUUM FREEZE较多,说明冻结较多,用户可以修改一下冻结周期,减少这种REDO。

    参考

    《PostgreSQL 使用pg_xlogdump找到误操作事务号》

    《PostgreSQL xlog dump - pg_xlogdump 源码讲解》

    《PostgreSQL 如何查找TOP SQL (例如IO消耗最高的SQL)》

    最新回复(0)