PostgreSQL Bugs

Collected from the PG bugs email list.

Bug ID16162
PG Version12.1
OSUbuntu 16.04
Opened2019-12-12 10:22:21+00
Reported byAndreas Kunert
StatusNew

Body of first available message related to this bug follows.

The following bug has been logged on the website:

Bug reference:      16162
Logged by:          Andreas Kunert
Email address:      (redacted)
PostgreSQL version: 12.1
Operating system:   Ubuntu 16.04
Description:        

Hello,

while testing an upcoming migration of our database server to a new hardware
including an update to a new postgres version I observed the following
behavior on the new server running a self-compiled Postgres 12.1 under
Ubuntu 16.04:

When importing a complete pg_dump, about one in three times a panic occurs
while trying to create a pg_trgm gist index and then the cluster restarts.
The according excerpt from the log:

2019-12-12 10:32:03.886 CET [36999] LOG:  statement: CREATE INDEX gist_idx
ON public.mytable USING gist (am_description public.gist_trgm_ops);
2019-12-12 10:32:04.370 CET [36999] PANIC:  invalid index offnum: 4
2019-12-12 10:32:04.370 CET [36999] STATEMENT:  CREATE INDEX gist_idx ON
public.mytable USING gist (am_description public.gist_trgm_ops);
2019-12-12 10:32:04.914 CET [31336] LOG:  server process (PID 36999) was
terminated by signal 6: Aborted
2019-12-12 10:32:04.914 CET [31336] DETAIL:  Failed process was running:
CREATE INDEX gist_idx ON public.mytable USING gist (am_description
public.gist_trgm_ops);
2019-12-12 10:32:04.914 CET [31336] LOG:  terminating any other active
server processes

I could successfully recreate the behaviour on another server (running a
default-configured packaged version of postgres 12 for ubuntu 16.04 on a
german locale) - the log look like this:

2019-12-11 17:15:00.735 CET [14959] test_gist_index@test_gist_index PANIK: 
invalid index offnum: 5
2019-12-11 17:15:00.735 CET [14959] test_gist_index@test_gist_index
ANWEISUNG:  CREATE INDEX gist_idx ON public.mytable USING
gist(am_description public.gist_trgm_ops);
2019-12-11 17:15:07.501 CET [7436] LOG:  Serverprozess (PID 14959) wurde von
Signal 6 beendet: Abgebrochen
2019-12-11 17:15:07.501 CET [7436] DETAIL:  Der fehlgeschlagene Prozess
führte aus: CREATE INDEX gist_idx ON public.mytable USING
gist(am_description public.gist_trgm_ops);
2019-12-11 17:15:07.501 CET [7436] LOG:  aktive Serverprozesse werden
abgebrochen
2019-12-11 17:15:07.515 CET [7436] LOG:  alle Serverprozesse beendet;
initialisiere neu


Unfortunately the database contains sensitive data but after a couple of
days and endless tests I managed to create a similarly built database
containing only random data which provokes the same behaviour (the log
messages above came from my test database). It consists of only on table
with two columns (serial, text) containing 200000 lines filled with random
strings of lengths varying from 1 to 1000.

A perl script creating the database, creating and filling the table and
finally iteratively creating and dropping the index is at the end of this
mail.

Since the error only occurs once in a while it can take a couple of
iterations (in my tests usually at least 7 attempts).

I hope I did not make a fundamental mistake and moreover I hope you can
reproduce the behavior.

Regards,
Andreas





----------------------------------------
Database creation
----------------------------------------

CREATE ROLE "test_gist_index" LOGIN PASSWORD 'XXXXX' NOINHERIT;
CREATE DATABASE "test_gist_index" OWNER "test_gist_index";
\c test_gist_index
CREATE EXTENSION IF NOT EXISTS pg_trgm;



---------------------------------------------------------------
Perl script creating and filling the table and running the test
---------------------------------------------------------------

#!/usr/bin/perl

use strict;
use warnings;
use DBI;
STDOUT->autoflush(1);


# generate alphabet similar to the one in the
# original error-prone database

my @alphabetstring;

for (my $j=0; $j<3; $j++) {
	for (my $i=65; $i<65+26; $i++) {
		push(@alphabetstring, chr($i));        # A-Z
		push(@alphabetstring, chr($i+97-65));  # a-z
	}
	for (my $i=0; $i<10; $i++) {
		push(@alphabetstring, chr($i+48));     # 0-9
		push(@alphabetstring, ' ');
	}
}

push(@alphabetstring, qw(ä ö ü Ä Ö Ü , ; : [ ] \( \) / - =));

# database connection

my $dbh = DBI->connect("DBI:Pg:dbname=test_gist_index;host=XXXXX",
"test_gist_index", "XXXXX", {'RaiseError' => 1});
$dbh->{pg_enable_utf8} = 0;

# (re)create test table

my $sth1 = $dbh->prepare("DROP TABLE IF EXISTS mytable; CREATE TABLE mytable
(am_id serial, am_description text); ");
$sth1->execute();

# fill table with random strings of arbitrary length

my $sth2 = $dbh->prepare("INSERT INTO mytable (am_description) VALUES
(?)");

for (my $i=1; $i<=200000; $i++) {

	my $stringlength = int(rand(1000));
	my $mystring = '';

	for (my $j=0; $j<=$stringlength; $j++) {

		my $randomchar = @alphabetstring[int(rand(scalar @alphabetstring))];
		$mystring .= $randomchar;

	}
	$sth2->execute($mystring);
	
	if ($i % 1000 == 0) { print "."; }
	if ($i % 10000 == 0) { print " - $i\n"; }
}

# test gist index creation

for (my $i=1; $i<=20; $i++) {
	print "\nbuilding gist $i\n";
	my $sth3 = $dbh->prepare("DROP INDEX IF EXISTS gist_idx;");
	print $sth3->execute();

	my $sth4 = $dbh->prepare("CREATE INDEX gist_idx ON public.mytable USING
gist (am_description public.gist_trgm_ops);");
	print $sth4->execute();

}

print "\n";

$dbh->disconnect();

Messages

DateAuthorSubject
2019-12-12 10:22:21+00PG Bug reporting formBUG #16162: create index using gist_trgm_ops leads to panic
2019-12-12 12:50:23+00Tomas VondraRe: BUG #16162: create index using gist_trgm_ops leads to panic
2019-12-12 13:44:22+00Tom LaneRe: BUG #16162: create index using gist_trgm_ops leads to panic
2019-12-13 00:05:53+00Jeff JanesRe: BUG #16162: create index using gist_trgm_ops leads to panic
2019-12-13 00:16:18+00Tomas VondraRe: BUG #16162: create index using gist_trgm_ops leads to panic
2019-12-13 17:09:20+00Heikki LinnakangasRe: BUG #16162: create index using gist_trgm_ops leads to panic
2019-12-13 22:02:52+00Heikki LinnakangasRe: BUG #16162: create index using gist_trgm_ops leads to panic
2019-12-14 03:03:40+00Jeff JanesRe: BUG #16162: create index using gist_trgm_ops leads to panic
2019-12-14 19:00:01+00Alexander LakhinRe: BUG #16162: create index using gist_trgm_ops leads to panic
2019-12-15 17:57:37+00Jeff JanesRe: BUG #16162: create index using gist_trgm_ops leads to panic
2019-12-15 18:19:58+00Heikki LinnakangasRe: BUG #16162: create index using gist_trgm_ops leads to panic
2019-12-16 12:02:15+00Heikki LinnakangasRe: BUG #16162: create index using gist_trgm_ops leads to panic
2019-12-16 19:00:00+00Alexander LakhinRe: BUG #16162: create index using gist_trgm_ops leads to panic