Re: GIN improvements part 1: additional information - Mailing list pgsql-hackers

On 4.10.2013 10:28, Heikki Linnakangas wrote:
> Aside from the pg_upgrade discussion, here's an updated version of the
> patch, rebased over master. It also contains some other misc refactoring
> I've done while reading through the patch. I haven't tested this much, I
> may well have also broken something, but I wanted to post an update
> before the weekend.
>
> Thinking about the page format, I think we should start using the
> pd_lower/upper pointers in the data page format. For a non-leaf page,
> pd_upper would always point to the beginning of the special area, and
> pd_lower would indicate the end of PostingItems. For a leaf page,
> pd_lower would indicate the end of the compressed posting list, and
> pd_upper would point to the "leaf-index" at the end of the page. That
> matches the standard page layout in the sense that the space between
> pd_lower and pd_upper is free, although the data stored in the non-free
> areas would be quite different. That would allow us to mark full-page
> images with buffer_std, allowing the "gap" to be left out. I think that
> would be a more natural way to keep track of the used/unused space on
> the page, anyway, compared to the current maxoff/endoffset field in the
> special area.
>
> In the attached patch, I in fact already did that for data leaf pages,
> but didn't change the format of non-leaf pages yet. If we want to
> support pg_upgrade, we might want to refrain from changing the non-leaf
> format.
>
> - Heikki

Hi,

I've attempted to rerun the benchmarks tests I did a few weeks ago, but
I got repeated crashes when loading the data (into a table with
tsvector+gin index).

Right before a crash, theres this message in the log:

   PANIC:  not enough space in leaf page!

The exact crash varies though - for example this is the backtrace on the
first gdb attempt (second crash):

Program received signal SIGABRT, Aborted.
0x00007fb3c0b40b15 in raise () from /lib64/libc.so.6
(gdb) bt
#0  0x00007fb3c0b40b15 in raise () from /lib64/libc.so.6
#1  0x00007fb3c0b41f96 in abort () from /lib64/libc.so.6
#2  0x000000000072753b in errfinish ()
#3  0x0000000000729c1a in elog_finish ()
#4  0x00000000004721d6 in dataPlaceToPage ()
#5  0x0000000000473d51 in ginInsertValue ()
#6  0x0000000000473262 in ginInsertItemPointers ()
#7  0x000000000046d915 in ginEntryInsert ()
#8  0x00000000004792bf in ginInsertCleanup ()
#9  0x0000000000479b32 in ginHeapTupleFastInsert ()
#10 0x000000000046e0b4 in gininsert ()
#11 0x000000000072d733 in FunctionCall6Coll ()
#12 0x00000000004977bc in index_insert ()
#13 0x00000000005952ad in ExecInsertIndexTuples ()
#14 0x00000000005a235d in ExecModifyTable ()
#15 0x000000000058c4e8 in ExecProcNode ()
#16 0x0000000000589ab0 in standard_ExecutorRun ()
#17 0x00000000006603cf in ProcessQuery ()
#18 0x00000000006605fc in PortalRunMulti ()
#19 0x0000000000661142 in PortalRun ()
#20 0x000000000065e4c3 in PostgresMain ()
#21 0x0000000000465446 in ServerLoop ()
#22 0x000000000061f553 in PostmasterMain ()
#23 0x0000000000465cd5 in main ()

Then I recompiled the sources with "-ggdb" and I got this:

Program received signal SIGQUIT, Quit.
ResourceOwnerEnlargeSnapshots (owner=0x200000001) at resowner.c:1077
1077    {
(gdb) bt
#0  ResourceOwnerEnlargeSnapshots (owner=0x200000001) at resowner.c:1077
#1  0x0000000000872228 in RegisterSnapshotOnOwner (snapshot=0x1f9ac60,
snapshot@entry=<error reading variable: Cannot access memory at address
0x7fff6b6151c8>, owner=0x1e81960) at snapmgr.c:588

and then this:

Program received signal SIGQUIT, Quit.
0x00007f48d298b8f2 in recv () from /lib64/libc.so.6
(gdb) bt
#0  0x00007f48d298b8f2 in recv () from /lib64/libc.so.6
#1  0x000000000062ec6b in secure_read (port=0x1a110b0, ptr=0xc5f840
<PqRecvBuffer>, len=8192) at be-secure.c:304
#2  0x0000000000639e31 in pq_recvbuf () at pqcomm.c:854
#3  0x0000000000639ec9 in pq_getbyte () at pqcomm.c:895
#4  0x0000000000723743 in SocketBackend (inBuf=0x7fff3522f9f0) at
postgres.c:344
#5  0x0000000000723b22 in ReadCommand (inBuf=0x7fff3522f9f0) at
postgres.c:492
#6  0x0000000000728218 in PostgresMain (argc=1, argv=0x19f4b50,
dbname=0x19f4b38 "archie", username=0x19f4b20 "tomas") at postgres.c:3953
#7  0x00000000006d27ae in BackendRun (port=0x1a110b0) at postmaster.c:4083
#8  0x00000000006d1f84 in BackendStartup (port=0x1a110b0) at
postmaster.c:3772
#9  0x00000000006cea47 in ServerLoop () at postmaster.c:1583
#10 0x00000000006ce150 in PostmasterMain (argc=3, argv=0x19f2a10) at
postmaster.c:1239
#11 0x000000000063c0a8 in main (argc=3, argv=0x19f2a10) at main.c:196

So it crashes at various times, although now that I'm looking into the
log I see this:

LOG:  server process (PID 12326) was terminated by signal 6: Aborted
DETAIL:  Failed process was running: autovacuum: ANALYZE public.messages
LOG:  terminating any other active server processes

So in some cases it was autovacuum that crashed, and the other processes
were killed because of corrupted shared memory.

But in all cases there's 'not enough space in leaf page!' right before
the crash.

The behavior after the crash is pretty consistent too - I do get this:

LOG:  startup process (PID 26259) was terminated by signal 6: Aborted
LOG:  aborting startup due to startup process failure
LOG:  database system was interrupted while in recovery at 2013-10-06
01:26:48 CEST
HINT:  This probably means that some data is corrupted and you will have
to use the last backup for recovery.
LOG:  database system was not properly shut down; automatic recovery in
progress
LOG:  redo starts at 0/2B0094B0
LOG:  startup process (PID 12237) was terminated by signal 11:
Segmentation fault

or this:

LOG:  select() failed in postmaster: Nepřípustný argument
LOG:  database system was interrupted; last known up at 2013-10-06
01:39:38 CEST
LOG:  database system was not properly shut down; automatic recovery in
progress
LOG:  redo starts at 0/A013300
LOG:  startup process (PID 12441) was terminated by signal 11:
Segmentation fault
LOG:  aborting startup due to startup process failure

and then I have to reinit the whole cluster because the xlog is corrupted.

Attached is a log from the multiple runs (and crashes). The test
basically parses mailing list archives and inserts them into a table.
The unique constraint violations are OK (i.e. expected).

Tomas