Re: Too many files in pg_replslot folder

On 03/11/2016 11:16 AM, Dmitriy Sarafannikov wrote:
>
>> Well, the files are all different in what you reported, so I would say
>> it's not a loop but a very long sequence.
> Yes, i have noticed this, sorry for bad explanation.
>
>> This can happen if you have a very long transaction while the snapshot
>> for the slot is being built, and a million other transactions happen
>> before the long transaction commits. One way in which this would go on
>> and on until it fills the disk is that you have a prepared transaction
>> that you forgot about (See select * from pg_prepared_xacts to diagnose
>> this one). Or you could just have a very long transaction (see select *
>> from pg_stat_activity).
> Thanks for explanation. Where was a long autovacuum on big table.
> What will happen when he finished?
> Wal sender will remove all of this files together and will utilze disk on 100% again?
>
>
> Regards,
> Dmitriy Sarafannikov

Sorry, autovacuum not involved in this.
I took several xids from this files and found them in WAL with pg_xlogdump:
rmgr: Heap len (rec/tot): 67/ 99, tx: 2918822231, lsn:
4983/D8FF8388, prev 4983/D8FF8338, bkp: 0000, desc: insert: rel
1663/16428/133587958; tid 5737/114
rmgr: Btree len (rec/tot): 34/ 66, tx: 2918822231, lsn:
4983/D8FF83F0, prev 4983/D8FF8388, bkp: 0000, desc: insert: rel
1663/16428/133587964; tid 6560/2
rmgr: Btree len (rec/tot): 50/ 82, tx: 2918822231, lsn:
4983/D8FF8438, prev 4983/D8FF83F0, bkp: 0000, desc: insert: rel
1663/16428/133926198; tid 27418/14
rmgr: Btree len (rec/tot): 50/ 82, tx: 2918822231, lsn:
4983/D8FF8490, prev 4983/D8FF8438, bkp: 0000, desc: insert: rel
1663/16428/148286684; tid 14048/2

i noticed that they are points to table, that filled by trigger
functions with upsert.

I have reproduced this case on clean instance (9.4.6):

create tables:

postgres=# create table test (id int primary key);
CREATE TABLE
postgres=# create table test2 (id int primary key);
CREATE TABLE

fill test2 table:
postgres=# insert into test2 (id) select generate_series(1,10000);
INSERT 0 10000

create upsert trigger:

postgres=# \sf tg_test
CREATE OR REPLACE FUNCTION public.tg_test()
RETURNS trigger
LANGUAGE plpgsql
AS $function$
begin
loop
update test2 set id = new.id where id = new.id;
exit when found;
begin
insert into test2 values (new.*);
exit;
exception when unique_violation then
end;
end loop;
return new;
end
$function$

postgres=# create trigger test_trigger after insert or update on test
for each row execute procedure tg_test();
CREATE TRIGGER

create slot:

postgres=# select * from pg_create_logical_replication_slot('test_slot',
'test_decoding');
slot_name | xlog_position
-----------+---------------
test_slot | 0/227DFE18
(1 row)

start pg_recvlogical:

$ pg_recvlogical --start -S test_slot -d postgres -hlocalhost -p5433 -f
/tmp/test_logical

postgres=# select * from pg_replication_slots ;
slot_name | plugin | slot_type | datoid | database | active |
xmin | catalog_xmin | restart_lsn
-----------+---------------+-----------+--------+----------+--------+------+--------------+-------------
test_slot | test_decoding | logical | 12141 | postgres | t
| | 330838 | 0/227DFE18
(1 row)

There are 1 file in slot folder (state file):

$ find ./testdata_9.4/pg_replslot/test_slot/ -type f | wc -l
1

Then start transaction and insert data into test table:
postgres=# begin ;
BEGIN
postgres=# insert into test (id) select generate_series(1,10000);
INSERT 0 10000

Now we have 2 files on slot folder:
$ find ./testdata_9.4/pg_replslot/test_slot/ -type f
./testdata_9.4/pg_replslot/test_slot/xid-330839-lsn-0-22000000.snap
./testdata_9.4/pg_replslot/test_slot/state

Then commit:
postgres=# commit ;
COMMIT

And now we have only state file on folder:
$ find ./testdata_9.4/pg_replslot/test_slot/ -type f
./testdata_9.4/pg_replslot/test_slot/state

Ok.

Then lets truncate both tables test and test2
and repeat:
postgres=# truncate test;
TRUNCATE TABLE
postgres=# truncate test2;
TRUNCATE TABLE

postgres=# begin ;
BEGIN
postgres=# insert into test (id) select generate_series(1,10000);
INSERT 0 10000

there are 2 files:
$ find ./testdata_9.4/pg_replslot/test_slot/ -type f
./testdata_9.4/pg_replslot/test_slot/xid-330842-lsn-0-22000000.snap
./testdata_9.4/pg_replslot/test_slot/state

postgres=# commit ;
COMMIT

and there are 10001 files:
$ find ./testdata_9.4/pg_replslot/test_slot/ -type f | wc -l
10001

$ find ./testdata_9.4/pg_replslot/test_slot/ -type f | head
./testdata_9.4/pg_replslot/test_slot/xid-332964-lsn-0-22000000.snap
./testdata_9.4/pg_replslot/test_slot/xid-336489-lsn-0-22000000.snap
./testdata_9.4/pg_replslot/test_slot/xid-331289-lsn-0-22000000.snap
./testdata_9.4/pg_replslot/test_slot/xid-339354-lsn-0-22000000.snap
./testdata_9.4/pg_replslot/test_slot/xid-337343-lsn-0-22000000.snap
./testdata_9.4/pg_replslot/test_slot/xid-336479-lsn-0-22000000.snap
./testdata_9.4/pg_replslot/test_slot/xid-332975-lsn-0-22000000.snap
./testdata_9.4/pg_replslot/test_slot/xid-331320-lsn-0-22000000.snap
./testdata_9.4/pg_replslot/test_slot/xid-331664-lsn-0-22000000.snap
./testdata_9.4/pg_replslot/test_slot/xid-334975-lsn-0-22000000.snap

there are 1 file per xid:
$ find ./testdata_9.4/pg_replslot/test_slot/ -type f -name '*.snap' |
cut -d'-' -f2 | sort | uniq -c | sort -nr | head
1 340842
1 340841
1 340840
1 340839
1 340838
1 340837
1 340836
1 340835
1 340834
1 340833

$ find ./testdata_9.4/pg_replslot/test_slot/ -type f -name '*.snap' |
cut -d'-' -f4,5 | sort | uniq -c | sort -nr | head
10000 0-22000000.snap

in test_logical file we see, that pg_recvlogical received this transaction:

$ tail /tmp/test_logical
table public.test2: INSERT: id[integer]:9996
table public.test2: INSERT: id[integer]:9997
table public.test2: INSERT: id[integer]:9998
table public.test2: INSERT: id[integer]:9999
table public.test2: INSERT: id[integer]:10000
COMMIT 330842
BEGIN 340843
COMMIT 340843
BEGIN 340844
COMMIT 340844

postgres=# select * from pg_replication_slots ;
slot_name | plugin | slot_type | datoid | database | active |
xmin | catalog_xmin | restart_lsn
-----------+---------------+-----------+--------+----------+--------+------+--------------+-------------
test_slot | test_decoding | logical | 12141 | postgres | t
| | 340845 | 0/22D97140
(1 row)

files are not deleted. They will be deleted if you will drop replication
slot.

It turns out that, if rows are updated in function, it's ok. But if rows
are inserted inside BEGIN..END block in function,
we get forgotten files in slot folder.

--
Best Regards,
Dmitriy Sarafannikov