Re: HEAD seems to generate larger WAL regarding GIN index - Mailing list pgsql-hackers

On Sun, Mar 16, 2014 at 7:15 AM, Alexander Korotkov
<aekorotkov@gmail.com> wrote:
> On Sat, Mar 15, 2014 at 11:27 PM, Heikki Linnakangas
> <hlinnakangas@vmware.com> wrote:
>>
>> On 03/15/2014 08:40 PM, Fujii Masao wrote:
>>>
>>> Hi,
>>>
>>> I executed the following statements in HEAD and 9.3, and compared
>>> the size of WAL which were generated by data insertion in GIN index.
>>>
>>> ---------------------
>>> CREATE EXTENSION pg_trgm;
>>> CREATE TABLE hoge (col1 text);
>>> CREATE INDEX hogeidx ON hoge USING gin (col1 gin_trgm_ops) WITH
>>> (FASTUPDATE = off);
>>>
>>> CHECKPOINT;
>>> SELECT pg_switch_xlog();
>>> SELECT pg_switch_xlog();
>>>
>>> SELECT pg_current_xlog_location();
>>> INSERT INTO hoge SELECT 'POSTGRESQL' FROM generate_series(1, 1000000);
>>> SELECT pg_current_xlog_location();
>>> ---------------------
>>>
>>> The results of WAL size are
>>>
>>>      960 MB (9.3)
>>>    2113 MB (HEAD)
>>>
>>> The WAL size in HEAD was more than two times bigger than that in 9.3.
>>> Recently the source code of GIN index has been changed dramatically.
>>> Is the increase in GIN-related WAL intentional or a bug?
>>
>>
>> It was somewhat expected. Updating individual items on the new-format GIN
>> pages requires decompressing and recompressing the page, and the
>> recompressed posting lists need to be WAL-logged. Which generates much
>> larger WAL records.
>>
>> That said, I didn't expect the difference to be quite that big when you're
>> appending to the end of the table. When the new entries go to the end of the
>> posting lists, you only need to recompress and WAL-log the last posting
>> list, which is max 256 bytes long. But I guess that's still a lot more WAL
>> than in the old format.

I ran "pg_xlogdump | grep Gin" and checked the size of GIN-related WAL,
and then found its max seems more than 256B. Am I missing something?

What I observed is

[In HEAD]
At first, the size of GIN-related WAL is gradually increasing up to about 1400B.
   rmgr: Gin         len (rec/tot):     48/    80, tx:       1813,
lsn: 0/020020D8, prev 0/02000070, bkp: 0000, desc: Insert item, node:
1663/12945/16441 blkno: 1 isdata: F isleaf: T isdelete: F   rmgr: Gin         len (rec/tot):     56/    88, tx:
1813,
lsn: 0/02002440, prev 0/020023F8, bkp: 0000, desc: Insert item, node:
1663/12945/16441 blkno: 1 isdata: F isleaf: T isdelete: T   rmgr: Gin         len (rec/tot):     64/    96, tx:
1813,
lsn: 0/020044D8, prev 0/02004490, bkp: 0000, desc: Insert item, node:
1663/12945/16441 blkno: 1 isdata: F isleaf: T isdelete: T   ...   rmgr: Gin         len (rec/tot):   1376/  1408, tx:
   1813,
 
lsn: 0/02A7EE90, prev 0/02A7E910, bkp: 0000, desc: Insert item, node:
1663/12945/16441 blkno: 2 isdata: F isleaf: T isdelete: T   rmgr: Gin         len (rec/tot):   1392/  1424, tx:
1813,
lsn: 0/02A7F458, prev 0/02A7F410, bkp: 0000, desc: Create posting
tree, node: 1663/12945/16441 blkno: 4

Then the size decreases to about 100B and is gradually increasing
again up to 320B.
   rmgr: Gin         len (rec/tot):    116/   148, tx:       1813,
lsn: 0/02A7F9E8, prev 0/02A7F458, bkp: 0000, desc: Insert item, node:
1663/12945/16441 blkno: 4 isdata: T isleaf: T unmodified: 1280 length:
1372 (compressed)   rmgr: Gin         len (rec/tot):     40/    72, tx:       1813,
lsn: 0/02A7FA80, prev 0/02A7F9E8, bkp: 0000, desc: Insert item, node:
1663/12945/16441 blkno: 3 isdata: F isleaf: T isdelete: T   ...   rmgr: Gin         len (rec/tot):    118/   150, tx:
   1813,
 
lsn: 0/02A83BA0, prev 0/02A83B58, bkp: 0000, desc: Insert item, node:
1663/12945/16441 blkno: 4 isdata: T isleaf: T unmodified: 1280 length:
1374 (compressed)   ...   rmgr: Gin         len (rec/tot):    288/   320, tx:       1813,
lsn: 0/02AEDE28, prev 0/02AEDCE8, bkp: 0000, desc: Insert item, node:
1663/12945/16441 blkno: 14 isdata: T isleaf: T unmodified: 1280
length: 1544 (compressed)

Then the size decreases to 66B and is gradually increasing again up to 320B.
This increase and decrease of WAL size seems to continue.

[In 9.3]
At first, the size of GIN-related WAL is gradually increasing up to about 2700B.
   rmgr: Gin         len (rec/tot):     52/    84, tx:       1812,
lsn: 0/02000430, prev 0/020003D8, bkp: 0000, desc: Insert item, node:
1663/12896/16441 blkno: 1 offset: 11 nitem: 1 isdata: F isleaf T
isdelete F updateBlkno:4294967295   rmgr: Gin         len (rec/tot):     60/    92, tx:       1812,
lsn: 0/020004D0, prev 0/02000488, bkp: 0000, desc: Insert item, node:
1663/12896/16441 blkno: 1 offset: 1 nitem: 1 isdata: F isleaf T
isdelete T updateBlkno:4294967295   ...   rmgr: Gin         len (rec/tot):   2740/  2772, tx:       1812,
lsn: 0/026D1670, prev 0/026D0B98, bkp: 0000, desc: Insert item, node:
1663/12896/16441 blkno: 5 offset: 2 nitem: 1 isdata: F isleaf T
isdelete T updateBlkno:4294967295   rmgr: Gin         len (rec/tot):   2714/  2746, tx:       1812,
lsn: 0/026D21A8, prev 0/026D2160, bkp: 0000, desc: Create posting
tree, node: 1663/12896/16441 blkno: 6

The size decreases to 66B and then is never changed.
   rmgr: Gin         len (rec/tot):     34/    66, tx:       1812,
lsn: 0/026D9F00, prev 0/026D9EB8, bkp: 0000, desc: Insert item, node:
1663/12896/16441 blkno: 6 offset: 451 nitem: 1 isdata: T isleaf T
isdelete F updateBlkno:4294967295   rmgr: Gin         len (rec/tot):     34/    66, tx:       1812,
lsn: 0/026D9F48, prev 0/026D9F00, bkp: 0000, desc: Insert item, node:
1663/12896/16441 blkno: 7 offset: 451 nitem: 1 isdata: T isleaf T
isdelete F updateBlkno:4294967295   rmgr: Gin         len (rec/tot):     34/    66, tx:       1812,
lsn: 0/026D9F90, prev 0/026D9F48, bkp: 0000, desc: Insert item, node:
1663/12896/16441 blkno: 8 offset: 451 nitem: 1 isdata: T isleaf T
isdelete F updateBlkno:4294967295   ...


This difference in GIN-related WAL size seems to cause HEAD to generate more
than two times bigger WAL. Unfortunately the gap of WAL size would be
continuously increasing :(


>>
>> That could be optimized, but I figured we can live with it, thanks to the
>> fastupdate feature. Fastupdate allows amortizing that cost over several
>> insertions. But of course, you explicitly disabled that...
>
>
> Let me know if you want me to write patch addressing this issue.

Yeah, I really want you to address this problem! That's definitely useful
for every users disabling FASTUPDATE option for some reasons.

Regards,

-- 
Fujii Masao