一个PG主键重复的案例
👉 本文共约2370个字，系统预计阅读时间或需9分钟。
前言
昨天早上同事转了一封邮件过来，发现某张表的主键重复了！😵 印象中这是第二次遇到了，让我们一起分析下这个罕见的案例。根因很重要呀！耐心看完
分析
出问题的表结构不复杂，主要字段如下（部分信息做了脱敏）
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 | postgres=# \d fpp_xxx Table "public.fpp_xxx" Column | Type | Modifiers --------------------------+-----------------------------+------------------------ id_message_info | character varying(32) | not null ... ... date_created | timestamp without time zone | not null default now() updated_by | character varying(32) | not null date_updated | timestamp without time zone | not null default now() ... Indexes: "fpp_xxx_pkey" PRIMARY KEY, btree (id_message_info) ---主键 ... Foreign-key constraints: ... |
昨天开发反馈更新的时候提示主键重复，于是上去看了一下
1 2 3 4 5 6 7 8 | postgres=# select id_message_info from fpp_xxx where id_message_info='1E0443A700002A9F0000149948DA5E77'; id_message_info ---------------------------------- 1E0443A700002A9F0000149948DA5E77 1E0443A700002A9F0000149948DA5E77 (2 rows) Time: 206.009 ms |
果然主键重复了，DBA 表示惊呆了！主键的功能就是非空 + 唯一，那是哪里出了问题呢？
先看下这两条数据的事务状态，是否是可见性导致的
1 2 3 4 5 6 | postgres=# select xmin,xmax,id_message_info from fpp_xxx where id_message_info='1E0443A700002A9F0000149948DA5E77'; xmin | xmax | id_message_info ------------+------------+---------------------------------- 1837555476 | 1847923208 | 1E0443A700002A9F0000149948DA5E77 1837555517 | 0 | 1E0443A700002A9F0000149948DA5E77 (2 rows) |
第一条数据 xmax 字段有值，说明这条数据要么被更新过，要么获取过行锁，这点很好验证
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 | postgres=# create table t1(id int); CREATE TABLE postgres=# insert into t1 values(1); INSERT 0 1 postgres=# insert into t1 values(2); INSERT 0 1 postgres=# select id from t1 where id = 1 for update; id ---- 1 (1 row) postgres=# select xmin,xmax from t1; ---xmax + infomask 实现行锁 xmin | xmax -------+------- 18801 | 18803 18802 | 0 (2 rows) postgres=# begin; BEGIN postgres=*# update t1 set id = 10 where id = 2; UPDATE 1 postgres=*# rollback ; ROLLBACK postgres=# select xmin,xmax from t1; xmin | xmax -------+------- 18801 | 18803 18802 | 18804 (2 rows) |
再看看 ctid
1 2 3 4 5 6 7 8 9 10 11 12 13 | postgres=# select xmin,xmax,ctid,id_message_info from fpp_xxx where id_message_info='1E0443A700002A9F0000149948DA5E77'; -[ RECORD 1 ]---+--------------------------------- xmin | 1837555476 xmax | 1847923208 ctid | (9789,8) id_message_info | 1E0443A700002A9F0000149948DA5E77 -[ RECORD 2 ]---+--------------------------------- xmin | 1837555517 xmax | 0 ctid | (9790,3) id_message_info | 1E0443A700002A9F0000149948DA5E77 Time: 2.298 ms |
根据过往的一些经验，初步怀疑可能是索引出了问题，比如 index only scan 仅在索引中取数据，索引和存储上的数据不一致，这个是有具体的案例的，可以翻下之前的文章。看下执行计划：
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 | postgres=# set enable_indexscan to off; SET postgres=# set enable_indexonlyscan to off; SET postgres=# set enable_bitmapscan to off; SET postgres=# explain select xmin,xmax,ctid,id_message_info from fpp_xxx where id_message_info='1E0443A700002A9F0000149948DA5E77'; QUERY PLAN -------------------------------------------------------------------------------- Seq Scan on fpp_xxx (cost=0.00..595465.29 rows=1 width=47) Filter: ((id_message_info)::text = '1E0443A700002A9F0000149948DA5E77'::text) (2 rows) postgres=# select xmin,xmax,ctid,id_message_info from fpp_xxx where id_message_info='1E0443A700002A9F0000149948DA5E77'; xmin | xmax | ctid | id_message_info ------------+------------+----------+---------------------------------- 1837555476 | 1847923208 | (9789,8) | 1E0443A700002A9F0000149948DA5E77 1837555517 | 0 | (9790,3) | 1E0443A700002A9F0000149948DA5E77 (2 rows) Time: 124054.147 ms postgres=# set enable_indexscan to on; SET postgres=# explain select xmin,xmax,ctid,id_message_info from fpp_xxx where id_message_info='1E0443A700002A9F0000149948DA5E77'; QUERY PLAN ----------------------------------------------------------------------------------------------- Index Scan using fpp_xxx_pkey on fpp_xxx (cost=0.56..5.57 rows=1 width=47) Index Cond: ((id_message_info)::text = '1E0443A700002A9F0000149948DA5E77'::text) (2 rows) postgres=# select xmin,xmax,ctid,id_message_info from fpp_xxx where id_message_info='1E0443A700002A9F0000149948DA5E77'; xmin | xmax | ctid | id_message_info ------------+------------+----------+---------------------------------- 1837555476 | 1847923208 | (9789,8) | 1E0443A700002A9F0000149948DA5E77 1837555517 | 0 | (9790,3) | 1E0443A700002A9F0000149948DA5E77 (2 rows) Time: 0.384 ms |
顺序扫描和索引扫描返回的数据一致，那不是索引的问题。不过为了确保索引是正确的状态（属实踩雷踩多了），还是使用插件 amcheck 检查了一下。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 | postgres=# SELECT bt_index_check(index => c.oid, heapallindexed => i.indisunique), c.relname, c.relpages FROM pg_index i JOIN pg_opclass op ON i.indclass[0] = op.oid JOIN pg_am am ON op.opcmethod = am.oid JOIN pg_class c ON i.indexrelid = c.oid JOIN pg_namespace n ON c.relnamespace = n.oid WHERE am.amname = 'btree' AND n.nspname = 'public' -- Don't check temp tables, which may be from another session: AND c.relpersistence != 't' AND c.relname = 'fpp_xxx_pkey' -- Function may throw an error when this is omitted: AND c.relkind = 'i' AND i.indisready AND i.indisvalid ORDER BY c.relpages DESC LIMIT 10; bt_index_check | relname | relpages ----------------+-----------------------+---------- | fpp_xxx_pkey | 48302 (1 row) Time: 529784.373 ms |
em，索引也是正确的状态，说明有别于以往的案例。继续分析一下
1 2 3 4 5 6 7 8 9 10 11 | postgres=# select ctid,id_message_info from fpp_xxx where ctid='(9790,3)'; ctid | id_message_info ----------+---------------------------------- (9790,3) | 1E0443A700002A9F0000149948DA5E77 (1 row) postgres=# select ctid,id_message_info from fpp_xxx where ctid='(9789,8)'; ctid | id_message_info ----------+---------------------------------- (9789,8) | 1E0443A700002A9F0000149948DA5E77 (1 row) |
CTID 表示这两行数据分别位于 9789 和 9790 这两个数据块，使用 pageinspect 窥探一下底层文件
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 | postgres=# select lp, t_xmin, t_xmax, t_ctid, infomask(t_infomask, 1) as infomask, infomask(t_infomask2, 2) as infomask2 from heap_page_items(get_raw_page('fpp_xxx', 9789)) where lp = 8; lp | t_xmin | t_xmax | t_ctid | infomask | infomask2 ----+------------+------------+------------+----------------------------------------------------------------------+----------------- | 8 | 1837555476 | 1847923208 | (106234,2) | XMAX_INVALID|XMIN_INVALID|XMIN_COMMITTED|HASVARWIDTH|HASNULL | (1 row) [postgres:6635@xxx] [10-25.12:38:50]=# select lp, t_xmin, t_xmax, t_ctid, infomask(t_infomask, 1) as infomask, infomask(t_infomask2, 2) as infomask2 from heap_page_items(get_raw_page('fpp_xxx', 9790)) where lp = 3; lp | t_xmin | t_xmax | t_ctid | infomask | infomask2 ----+------------+--------+-----------+----------------------------------------------------------------------+----------------- 3 | 1837555517 | 0 | (9790,3) | UPDATED|XMAX_INVALID|XMIN_INVALID|XMIN_COMMITTED|HASVARWIDTH|HASNULL | (1 row) |
这里可以看到一些差别，第一行数据的 ctid 指向了 '(106234,2)'，同时表示该行已经冻结过了 XMIN_INVALID|XMIN_COMMITTED
1 2 3 4 5 6 7 8 9 | #define HEAP_XMIN_FROZEN (HEAP_XMIN_COMMITTED|HEAP_XMIN_INVALID) postgres=# select lp, t_xmin, t_xmax, t_ctid, infomask(t_infomask, 1) as infomask, infomask(t_infomask2, 2) as infomask2 from heap_page_items(get_raw_page('fpp_xxx', 106234)) where lp = 2; lp | t_xmin | t_xmax | t_ctid | infomask | infomask2 ----+------------+--------+------------+----------------------------------------------------------------------+----------- 2 | 1847923208 | 0 | (106234,2) | UPDATED|XMAX_INVALID|XMIN_INVALID|HASVARWIDTH|HASNULL | (1 row) |
通过 pageinspect 查看，发现有这行数据，但是通过指定查询是没有数据的
1 2 | postgres=# select ctid,id_message_info from fpp_xxx where ctid='(106234,2)'; (0 rows) |
假如查询的时候第一条数据通过 ctid '(9789,8)' 到 ctid '(106234,2)' 这个 ctid 链进行查找的话，数据的确无法可见，也就不会有第一条数据了，主键也就不会重复了。难道是数据不一致了？ctid 链出问题了？内存中的数据和底层的数据不一致？
后面仔细一想，发现是我想多了，这个其实是正常的机制，也是我最开始被绕进去的地方 👇🏻 做个小实验：
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 | postgres=# create table t1(id int); CREATE TABLE postgres=# insert into t1 values(1); INSERT 0 1 postgres=# select xmin,ctid from t1; xmin | ctid -------+------- 18807 | (0,1) (1 row) postgres=# begin; BEGIN postgres=*# update t1 set id = 99 where id = 1; UPDATE 1 postgres=*# rollback ; ROLLBACK postgres=# select xmin,ctid from t1; --- ctid是(0,1) xmin | ctid -------+------- 18807 | (0,1) (1 row) postgres=# select lp, t_xmin, t_xmax, t_ctid, t_data, --- ctid是(0,2) infomask(t_infomask, 1) as infomask, infomask(t_infomask2, 2) as infomask2 from heap_page_items(get_raw_page('t1', 0)); lp | t_xmin | t_xmax | t_ctid | t_data | infomask | infomask2 ----+--------+--------+--------+------------+-----------------------------------+----------------- 1 | 18807 | 18808 | (0,2) | \x01000000 | XMAX_INVALID|XMIN_COMMITTED | HOT_UPDATED 2 | 18808 | 0 | (0,2) | \x63000000 | UPDATED|XMAX_INVALID|XMIN_INVALID | HEAP_ONLY_TUPLE (2 rows) |
相信各位也看明白了，第一行数据依旧在哪里，但是通过 pageinspect 看的话，ctid 均是指向的第二行数据，即使第二行数据已经回滚了，通过 MVCC 和行上的 infomask（XMIN_INVALID） 来确保第二条数据不可见。所以，这个是正常的现象。这个不起眼的地方属实把我绕进去了，各种计算偏移量去看底层文件。
既然如此，说明是 1847923208 这个事务做了更新，然后更新失败了。既然如此，根据此事务 ID 去检索一下日志，日志中是包含具体的事务 ID 的
1 2 3 4 5 | [postgres@xiongcc log]$ grep fpp_xxx -rn ./* | grep -A 5 update | grep 1847923208 2022-10-24 18:21:21.722 CST,"xxx","xxx",271603,"xxx",63565783.424f3,10,"UPDATE",2022-10-24 17:14:43 CST,47/29729,1847923208,ERROR,23505,"duplicate key value violates unique constraint ""fpp_xxx_pkey""","Key (id_message_info)=(1E0443A700002A9F0000149948DA5E77) already exists.",,,,,"update fpp_xxx set message_status='SUCCESS', updated_by='TEST_TY' where message_type in ('2','20') and message_status='SENDING' and system_id not in ('xxx')^M ",,,"DBeaver 6.0.5 - Main" [postgres@xiongcc log]$ grep fpp_xxx -rn ./* | egrep '1837555476|1837555517' ---插入的事务未检索到 |
果然，昨天业务 18:21 通过 DBeaver 进行了更新，提示了唯一约束冲突，事务回滚。但是可惜的是没有在日志中检索到两条数据插入的日志
那难道是索引的状态不对，没有起到 unique 的功能？不过可能性微乎其微，举个栗子
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 | postgres=# create table test(id int primary key); CREATE TABLE postgres=# update pg_index set indisunique = 'f' where indexrelid = 'test_pkey'::regclass; UPDATE 1 postgres=# insert into test values(1); INSERT 0 1 postgres=# insert into test values(1); INSERT 0 1 postgres=# \d test ---主键是Invalid，只是无法起到唯一约束的作用了 Table "public.test" Column | Type | Collation | Nullable | Default --------+---------+-----------+----------+--------- id | integer | | not null | Indexes: "test_pkey" PRIMARY KEY, btree (id) postgres=# update pg_index set indisunique = 't' where indexrelid = 'test_pkey'::regclass; UPDATE 1 postgres=# insert into test values(1); ERROR: duplicate key value violates unique constraint "test_pkey" DETAIL: Key (id)=(1) already exists. postgres=# select * from test; id ---- 1 1 (2 rows) |
查询了一下系统表，这个索引的状态也是正确的。至此，貌似进入了死胡同不知道该从哪方面去分析。
但是可喜的是，发现这个表上有两个字段 date_created 和 date_updated ，分别是创建时间和更新时间，这就很方便了。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 | postgres=# \d fpp_xxx Table "public.fpp_xxx" Column | Type | Modifiers --------------------------+-----------------------------+------------------------ id_message_info | character varying(32) | not null ... ... date_created | timestamp without time zone | not null default now() updated_by | character varying(32) | not null date_updated | timestamp without time zone | not null default now() ... Indexes: "fpp_xxx_pkey" PRIMARY KEY, btree (id_message_info) ... Foreign-key constraints: ... |
通过查看，发现这两条数据插入的时间是在 10-09 09:37 左右，检索一下该段时间的日志
1 2 | 2022-10-09 09:37:03.648 CST,"xxx","xxx",431947,"30.4.171.124:46326",634213ed.6974b,472,"COMMIT",2022-10-09 08:21:01 CST,29/77078,1837555751,PANIC,53100,"could not write to file ""pg_xlog/xlogtemp.431947"": No space left on device",,,,,,"COMMIT",,,"PostgreSQL JDBC Driver" 2022-10-09 09:37:03.659 CST,,,31906,,6340e685.7ca2,3,,2022-10-08 10:55:01 CST,,0,LOG,00000,"server process (PID 431947) was terminated by signal 6: Aborted","Failed process was running: COMMIT",,,,,,,,"" |
原来这个时间点磁盘写爆了...数据库宕机了，发送了 signal 6！然后整个实例都重启了
1 2 3 | 2022-10-09 09:37:03.659 CST,,,31906,,6340e685.7ca2,4,,2022-10-08 10:55:01 CST,,0,LOG,00000,"terminating any other active server processes",,,,,,,,,"" 2022-10-09 09:37:03.659 CST,"xxx","xxx",364620,"30.4.171.124:52444",6342256e.5904c,17,"idle",2022-10-09 09:35:42 CST,74/0,0,WARNING,57P02,"terminating connection because of crash of another server process","The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.","In a moment you should be able to reconnect to the database and repeat your command.",,,,,,,"PostgreSQL JDBC Driver" 2022-10-09 09:37:03.659 CST,"xxx","xxx",364619,"30.4.171.124:52442",6342256e.5904b,5,"idle",2022-10-09 09:35:42 CST,79/0,0,WARNING,57P02,"terminating connection because of crash of another server process","The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.","In a moment you should be able to reconnect to the database and repeat your command.",,,,,,,"PostgreSQL JDBC Driver" |
后面经过了解，原来那个时间点有个失效的复制槽，WAL把磁盘打爆了。负责的 DBA 在 10:30 左右使用了 pg_resetxlog -x 1837553131 -o xxx -f $PGDATA，但是当恢复完成之后，日志一直在报奇奇怪怪的错误：could not access status of transaction 1837555746
本人提供Oracle(OCP、OCM)、MySQL(OCP)、PostgreSQL(PGCA、PGCE、PGCM)等数据库的培训和考证业务，私聊QQ646634621或微信db_bao，谢谢！
1 2 3 4 5 6 7 8 9 10 11 | 2022-10-09 10:31:28.079 CST,"xxx","xxx",205932,"30.4.171.124:55616",6342327f.3246c,3,"SELECT",2022-10-09 10:31:27 CST,21/5,0,ERROR,XX000,"could not access status of transaction 1837555746","Could not read from file ""pg_subtrans/6D86"" at offset 229376: Success.",,,,"while locking tuple (0,2) in relation ""xxx""","SELECT * FROM xxx",,,"PostgreSQL JDBC Driver" 2022-10-09 10:31:28.079 CST,"xxx","xxx",205935,"30.4.171.124:55618",6342327f.3246f,3,"SELECT",2022-10-09 10:31:27 CST,22/5,0,ERROR,XX000,"could not access status of transaction 1837555746","Could not read from file ""pg_subtrans/6D86"" at offset 229376: Success.",,,,"while locking tuple (0,2) in relation ""xxx""","SELECT * FROM xxx",,,"PostgreSQL JDBC Driver" 2022-10-09 10:31:28.080 CST,"xxx","xxx",205939,"30.4.171.124:42388",6342327f.32473,3,"SELECT",2022-10-09 10:31:27 CST,27/5,0,ERROR,XX000,"could not access status of transaction 1837555746","Could not read from file ""pg_subtrans/6D86"" at offset 229376: Success.",,,,"while locking tuple (0,2) in relation ""xxx""","SELECT * FROM xxx",,,"PostgreSQL JDBC Driver" 2022-10-09 10:31:28.080 CST,,,205971,"30.4.171.140:44506",63423280.32493,1,"",2022-10-09 10:31:28 CST,,0,LOG,00000,"connection received: host=30.4.171.140 port=44506",,,,,,,,,"" 2022-10-09 10:31:49.130 CST,"xxx","xxx",207786,"30.4.171.125:50528",63423288.32baa,52,"INSERT",2022-10-09 10:31:36 CST,183/212,1837553535,ERROR,XX000,"MultiXactId 5195804 has not been created yet -- apparent wraparound",,,,,"xxx""","INSERT INTO public.fpp_xxx (id_message_info, system_id, message_type, biz_unique_code, message_id, |
另外在生产中我们打开了 track_commit_timestamp 参数，因此可以查看事务提交的时间
1 2 3 4 5 6 7 8 | postgre=# select id_message_info,ctid,pg_xact_commit_timestamp(xmin),xmin,xmax from fpp_xxx where id_message_info='1E0443A700002A9F0000149948DA5E77' ; id_message_info | ctid | pg_xact_commit_timestamp | xmin | xmax ----------------------------------+----------+-------------------------------+------------+------------ 1E0443A700002A9F0000149948DA5E77 | (9789,8) | 2022-10-09 10:44:33.560093+08 | 1837555476 | 1847923208 1E0443A700002A9F0000149948DA5E77 | (9790,3) | 2022-10-09 10:44:43.254387+08 | 1837555517 | 0 (2 rows) Time: 4.159 ms |
由于版本是 9.6.6 的，在 10 以后才提供 txid_status() 查看事务的状态，本来还想通过计算偏移量的方式来去查看 CLOG 事务的状态，可惜元组由于已经被冻结过（前面的 infomask 已经证实），CLOG 也被会被清理。
可以看到，数据是在 09:37 分插入的，但是事务提交是 10:44 的，中间差了整整一个小时，日志中大量 CLOG 相关的错误，完全无法知晓事务的状态
1 2 3 4 5 6 7 8 9 10 | 2022-10-09 10:42:16.665 CST,"xxx","xxx",207773,"xxx:50522",63423288.32b9d,253,"INSERT",2022-10-09 10:31:36 CST,59/833,1837554116,ERROR,XX000,"could not access status of transaction 1837555749","Could not read from file ""pg_subtrans/6D86"" at offset 229376: Success.",,,,"while inserting index tuple (2416960,17) in relation ""ind_message_sys_type_unique""","INSERT INTO public.fpp_xxx (id_message_info, ... created_by, updated_by) SELECT $1, fs.system_id, ... FROM fpp_xxx fs WHERE fs.system_id = $10",,,"PostgreSQL JDBC Driver" |
因此此时数据库的状态已经不知道变成一个什么样的状态了，根据前面的分析，应该是第二条数据本不该可见的，但是通过 pg_resetxlog 重置了之后，导致第二条数据由于 MVCC 的判断机制，属于未来删除的事务了，复现一下
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 | postgres=# create table t1(id int primary key); CREATE TABLE postgres=# insert into t1 values(1); INSERT 0 1 postgres=# insert into t1 values(2); INSERT 0 1 postgres=# select xmin,id from t1; xmin | id -------+---- 18827 | 1 18828 | 2 (2 rows) postgres=# begin; BEGIN postgres=*# select txid_current(); txid_current -------------- 18829 (1 row) postgres=*# update t1 set id = 1 where id = 2; ERROR: duplicate key value violates unique constraint "t1_pkey" DETAIL: Key (id)=(1) already exists. postgres=!# rollback ; ROLLBACK postgres=# select lp, t_xmin, t_xmax, t_ctid, t_data, infomask(t_infomask, 1) as infomask, infomask(t_infomask2, 2) as infomask2 from heap_page_items(get_raw_page('t1', 0)); lp | t_xmin | t_xmax | t_ctid | t_data | infomask | infomask2 ----+--------+--------+--------+------------+-----------------------------+-------------------- 1 | 18827 | 0 | (0,1) | \x01000000 | XMAX_INVALID|XMIN_COMMITTED | 2 | 18828 | 18829 | (0,3) | \x02000000 | XMIN_COMMITTED | UPDATE_KEY_REVOKED 3 | 18829 | 0 | (0,3) | \x01000000 | UPDATED|XMAX_INVALID | (3 rows) |
可以看到我将第二行数据改为1，由于违反主键约束，事务报错回滚了。于是我使用pg_resetwal重置一下xid
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 | [postgres@xiongcc ~]$ pg_ctl -D pgdata stop waiting for server to shut down.... done server stopped [postgres@xiongcc ~]$ pg_resetwal -x 18828 pgdata Write-ahead log reset [postgres@xiongcc ~]$ pg_ctl -D pgdata start waiting for server to start....2022-10-26 10:34:43.323 CST [24139] LOG: redirecting log output to logging collector process 2022-10-26 10:34:43.323 CST [24139] HINT: Future log output will appear in directory "log". done server started [postgres@xiongcc ~]$ psql psql (14.2) Type "help" for help. postgres=# select * from t1; id ---- 1 (1 row) postgres=# select txid_current(); ---推进事务号 txid_current -------------- 18828 (1 row) postgres=# select * from t1; id ---- 1 2 (2 rows) postgres=# select txid_current(); ---推进事务号 txid_current -------------- 18829 (1 row) postgres=# select * from t1; id ---- 1 1 (2 rows) postgres=# \d t1 Table "public.t1" Column | Type | Collation | Nullable | Default --------+---------+-----------+----------+--------- id | integer | | not null | Indexes: "t1_pkey" PRIMARY KEY, btree (id) postgres=# insert into t1 values(2); INSERT 0 1 postgres=# select * from t1; id ---- 1 1 2 (3 rows) |
可以看到，主键重复了。这也是这次案例的根因。怎么样，是不是发现了新大陆？pg_resetwal 慎用，除非你知道自己在做什么。
小结
从根因分析的话，依旧是那句话，在 PostgreSQL 中，磁盘写满然后数据库宕机之后，你能做的十分有限，无非删除一些日志文件或一些其他无关的文件，运气好可能你删除了一些大的不影响可用性的表/索引等。但是大多数时候都没啥用，并且删除对象十分危险，因此一个可行的方式是提前创建一个占位文件，比如 dd/fallocate 等，关键时刻删除 Maybe 可以救命。另外，pg_resetxlog 要慎用，比如我的复现过程，主键重复都能出现，我个人也是能不用就不用，很容易将数据库搞到一个不知所以然的状态。
