标签
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找到误操作事务号》
