Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1lzDOJ-0002Zd-Tv for pgsql-bugs@arkaria.postgresql.org; Fri, 02 Jul 2021 07:15:12 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1lzDOI-00078Q-RQ for pgsql-bugs@arkaria.postgresql.org; Fri, 02 Jul 2021 07:15:10 +0000 Received: from makus.postgresql.org ([2001:4800:3e1:1::229]) by malur.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1lzDOI-00078I-13 for pgsql-bugs@lists.postgresql.org; Fri, 02 Jul 2021 07:15:10 +0000 Received: from mail-ej1-x633.google.com ([2a00:1450:4864:20::633]) by makus.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.92) (envelope-from ) id 1lzDOD-0003UI-Tb for pgsql-bugs@lists.postgresql.org; Fri, 02 Jul 2021 07:15:08 +0000 Received: by mail-ej1-x633.google.com with SMTP id b2so14618842ejg.8 for ; Fri, 02 Jul 2021 00:15:05 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=splendiddata-com.20150623.gappssmtp.com; s=20150623; h=subject:to:references:from:message-id:date:user-agent:mime-version :in-reply-to:content-language; bh=/ofrrnpBciAgbXbOjzZ0ZVbEkEOIkmzBPscobwZne5Q=; b=QKUhWazvg9mReEKlm8vQlCF0pN6O6Fn3YvT9h94O0+brrOLiz8xcuNec8d2Ut+7tyZ bW7Uc3JC5PAim+0KjLvevB60jFACSZzND+VQIcMUSBll4f0eoCxwXvI/iJQXUJFSXH9I VWKym3W4mSI/PHepiemHYChbZQvNc0F9aiPxzU3uD6Frib+QKD0UU/9xRXUfldf6zwpd hcBHOILoByCy8YtKghAVAIvjla/TMN5IG8eQbOXJgKqeue1FE5CGN3TQCYdZaecQm/E0 N+Wp5tPSXgMBLVXLreZSw1yTYww4qCu2xVbVFSKCewz2MMlkvLsK1yNkarEdAii16CBG eFHg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:subject:to:references:from:message-id:date :user-agent:mime-version:in-reply-to:content-language; bh=/ofrrnpBciAgbXbOjzZ0ZVbEkEOIkmzBPscobwZne5Q=; b=pj5z69O3PJVWsiRTF/TdguJmdau7PyyO+r3DExSegTmUAFKb44W5IH0Edk3hprhERG KjuYdW0ZKGIQxxf6CqrZky1YfaShE0CutURZn/bkjko68yeRSxyeB7w6EWX4JuEUAPX9 iWeyzck0ZlzGjB0yneJFWnb8nAoefpZtPoSrfKkhnvH7spR9nqHCo6TtDRmA/TDG+9Qn 4YUDFuh0EqF8AWF6YnTQ3cp4n3LKtPoks5RiTirrBATqFSPqPIov+gyivx+D95U9ehpI 8uyW0l1+oWuUrLuYhmXntE4fQ4YJ+y5p1sgsmps1wk51rvsHZUJE4wa8rYWgupLxRw1B Mw/A== X-Gm-Message-State: AOAM533vFWnAASzp7qG+gAbQbV+slp2vtI6zxQhwo4kBNSQtznySwK8d 7Su5xj38kvBR8gwRy9qXjaIK8ZBSBkODtw== X-Google-Smtp-Source: ABdhPJzRAoBIaQk7JE0hGl2mgVAOeFe3TpBjUAZbVZ1a+TpU+M85yFlCl0JalZGVcVArdfsi0IppUQ== X-Received: by 2002:a17:907:c0f:: with SMTP id ga15mr3866898ejc.228.1625210104333; Fri, 02 Jul 2021 00:15:04 -0700 (PDT) Received: from localhost.localdomain (D57C1B83.static.ziggozakelijk.nl. [213.124.27.131]) by smtp.googlemail.com with ESMTPSA id de6sm890592edb.77.2021.07.02.00.15.03 for (version=TLS1_3 cipher=TLS_AES_128_GCM_SHA256 bits=128/128); Fri, 02 Jul 2021 00:15:03 -0700 (PDT) Subject: Re: BUG #17081: Segmentation fault on _PG_init() in a session_preload_library To: pgsql-bugs@lists.postgresql.org References: <17081-b5a83245fd4e64bb@postgresql.org> From: Martin Butter Message-ID: <5e9f75fd-2886-2b7d-0a8f-0b46049786f5@splendiddata.com> Date: Fri, 2 Jul 2021 09:15:02 +0200 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101 Thunderbird/78.11.0 MIME-Version: 1.0 In-Reply-To: <17081-b5a83245fd4e64bb@postgresql.org> Content-Type: multipart/mixed; boundary="------------73BFB29826BC0953AAFF6549" Content-Language: en-GB List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk This is a multi-part message in MIME format. --------------73BFB29826BC0953AAFF6549 Content-Type: multipart/alternative; boundary="------------A36185D8F3FF5A357D9B7BA0" --------------A36185D8F3FF5A357D9B7BA0 Content-Type: text/plain; charset=utf-8; format=flowed Content-Transfer-Encoding: 8bit In the attachement you will find the source of a database extension that I used to test this. Extension test_spi_in_preload_session just executes 'select 1' in its _PG_init() function. Until Postgres version 14beta1 this works fine, but in version 14beta2 the process dies. To compile: make make install In postgresql.conf set: log_min_messages = debug3 session_preload_libraries = 'test_spi_in_preload_session' To test: Just try to login to Postgres or execute make installcheck Regards, Martin. On 02/07/2021 09:10, PG Bug reporting form wrote: > The following bug has been logged on the website: > > Bug reference: 17081 > Logged by: Martin Butter > Email address: martin.butter@splendiddata.com > PostgreSQL version: 14beta2 > Operating system: Fedora 33 > Description: > > Code used: > #include "postgres.h" > #include "executor/spi.h" > #include "miscadmin.h" > #include "commands/dbcommands.h" > #include "access/xact.h" > > #ifdef PG_MODULE_MAGIC > PG_MODULE_MAGIC; > #endif > > void _PG_init(void); > /* Module entry point */ > void _PG_init(void) > { > char* dbName; > int startedATransaction = 0; > int spiStatus; > ErrorData *edata; > > elog(DEBUG3, > "_PG_init() in test_spi_in_preload_session.so, MyProcPid=%d, > MyDatabaseId=%d, IsBackgroundWorker=%d", > MyProcPid, MyDatabaseId, IsBackgroundWorker); > > /* > * If no database is selected, don't execute the code > * This may occur for example in a replication target database. > */ > if (!OidIsValid(MyDatabaseId)) { > elog(DEBUG1, "No database selected so test_spi_in_preload_session will > not execute"); > return; > } > > /* > * Don't try to execute in a parallel worker > */ > if (IsBackgroundWorker) > { > elog(DEBUG1, > "test_spi_in_preload_session did not do anything because we are in a > background worker"); > return; > } > > if (GetCurrentTransactionIdIfAny() == InvalidTransactionId) > { > /* > * If we're not in a transaction, start one. > */ > StartTransactionCommand(); > startedATransaction = 1; > } > > dbName = get_database_name(MyDatabaseId); > Assert(dbName); // warning: only active if kernel compiled with > --enable-cassert > > spiStatus = SPI_connect(); > if (spiStatus != SPI_OK_CONNECT) { > ereport(ERROR, > ( errmsg("SPI_connect returned %d for database %s", > spiStatus, > dbName))); > } > > > // if ones gets error in SPI_execute(), the function does not > return, unless protected by a PG_TRY / PG_CATCH > PG_TRY(); > { > elog(DEBUG3, > "test_spi_in_preload_session will execute 'select > 1' in database %s", > dbName); > spiStatus = SPI_execute("select 1", false, 1); > if (spiStatus < 0) { > ereport(ERROR, > ( errmsg("SPI_execute returned %d for query 'select > 1' in database %s", > spiStatus, > dbName))); > } > elog(DEBUG3, > "test_spi_in_preload_session is back from 'select 1' in > database %s", > dbName); > } > PG_CATCH(); > { > AbortCurrentTransaction(); > edata = CopyErrorData(); > ereport(WARNING, > ( errcode(edata->sqlerrcode), > errmsg("test_spi_in_preload_session failed to execute > 'select 1' in database %s", > dbName), > errhint("original message = %s", edata->message))); > } > PG_END_TRY(); > > SPI_finish(); > > if (startedATransaction) > { > /* > * commit the transaction we started > */ > CommitTransactionCommand(); > } > } > <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< > > Serverlog: > . > . > 2021-07-02 08:43:43.295 CEST [37478] LOG: database system is ready to > accept connections > 2021-07-02 08:43:43.295 CEST [37487] DEBUG: InitPostgres > 2021-07-02 08:43:43.295 CEST [37488] DEBUG: removing permanent stats file > "pg_stat/global.stat" > 2021-07-02 08:43:43.296 CEST [37489] DEBUG: logical replication launcher > started > 2021-07-02 08:43:43.296 CEST [37489] DEBUG: InitPostgres > 2021-07-02 08:43:43.300 CEST [37488] DEBUG: received inquiry for database > 0 > 2021-07-02 08:43:43.300 CEST [37488] DEBUG: writing stats file > "pg_stat_tmp/global.stat" > 2021-07-02 08:43:51.664 CEST [37478] DEBUG: forked new backend, pid=37558 > socket=9 > 2021-07-02 08:43:51.665 CEST [37558] DEBUG: InitPostgres > 2021-07-02 08:43:51.677 CEST [37558] DEBUG: find_in_dynamic_libpath: trying > "/usr/local/postgresql-14beta2/lib/test_spi_in_preload_session" > 2021-07-02 08:43:51.677 CEST [37558] DEBUG: find_in_dynamic_libpath: trying > "/usr/local/postgresql-14beta2/lib/test_spi_in_preload_session.so" > 2021-07-02 08:43:51.677 CEST [37558] DEBUG: _PG_init() in > test_spi_in_preload_session.so, MyProcPid=37558, MyDatabaseId=13977, > IsBackgroundWorker=0 > 2021-07-02 08:43:51.677 CEST [37558] DEBUG: test_spi_in_preload_session > will execute 'select 1' in database postgres > 2021-07-02 08:43:51.984 CEST [37478] DEBUG: server process (PID 37558) was > terminated by signal 11: Segmentation fault > 2021-07-02 08:43:51.984 CEST [37478] LOG: server process (PID 37558) was > terminated by signal 11: Segmentation fault > 2021-07-02 08:43:51.984 CEST [37478] LOG: terminating any other active > server processes > 2021-07-02 08:43:51.984 CEST [37478] DEBUG: sending SIGQUIT to process > 37489 > 2021-07-02 08:43:51.984 CEST [37478] DEBUG: sending SIGQUIT to process > 37485 > 2021-07-02 08:43:51.984 CEST [37478] DEBUG: sending SIGQUIT to process > 37484 > 2021-07-02 08:43:51.984 CEST [37478] DEBUG: sending SIGQUIT to process > 37486 > 2021-07-02 08:43:51.984 CEST [37478] DEBUG: sending SIGQUIT to process > 37487 > 2021-07-02 08:43:51.984 CEST [37478] DEBUG: sending SIGQUIT to process > 37488 > 2021-07-02 08:43:51.984 CEST [37488] DEBUG: writing stats file > "pg_stat/global.stat" > 2021-07-02 08:43:51.984 CEST [37488] DEBUG: shmem_exit(-1): 0 > before_shmem_exit callbacks to make > 2021-07-02 08:43:51.984 CEST [37488] DEBUG: shmem_exit(-1): 0 on_shmem_exit > callbacks to make > 2021-07-02 08:43:51.984 CEST [37488] DEBUG: proc_exit(-1): 0 callbacks to > make > 2021-07-02 08:43:51.985 CEST [37478] LOG: all server processes terminated; > reinitializing > 2021-07-02 08:43:51.985 CEST [37478] DEBUG: shmem_exit(1): 0 > before_shmem_exit callbacks to make > 2021-07-02 08:43:51.985 CEST [37478] DEBUG: shmem_exit(1): 5 on_shmem_exit > callbacks to make > 2021-07-02 08:43:51.985 CEST [37478] DEBUG: cleaning up dynamic shared > memory control segment with ID 2085192430 > 2021-07-02 08:43:51.997 CEST [37478] DEBUG: invoking > IpcMemoryCreate(size=148856832) > 2021-07-02 08:43:51.997 CEST [37478] DEBUG: mmap(148897792) with > MAP_HUGETLB failed, huge pages disabled: Cannot allocate memory > 2021-07-02 08:43:52.005 CEST [37478] DEBUG: dynamic shared memory system > will support 674 segments > 2021-07-02 08:43:52.005 CEST [37478] DEBUG: created dynamic shared memory > control segment 289087702 (26976 bytes) > 2021-07-02 08:43:52.006 CEST [37574] LOG: database system was interrupted; > last known up at 2021-07-02 08:43:43 CEST > 2021-07-02 08:43:52.006 CEST [37574] DEBUG: removing all temporary WAL > segments > 2021-07-02 08:43:52.174 CEST [37574] DEBUG: checkpoint record is at > 0/439D020 > 2021-07-02 08:43:52.174 CEST [37574] DEBUG: redo record is at 0/439D020; > shutdown true > 2021-07-02 08:43:52.174 CEST [37574] DEBUG: next transaction ID: 19078; > next OID: 111557 > 2021-07-02 08:43:52.174 CEST [37574] DEBUG: next MultiXactId: 1; next > MultiXactOffset: 0 > 2021-07-02 08:43:52.174 CEST [37574] DEBUG: oldest unfrozen transaction ID: > 726, in database 1 > 2021-07-02 08:43:52.174 CEST [37574] DEBUG: oldest MultiXactId: 1, in > database 1 > 2021-07-02 08:43:52.174 CEST [37574] DEBUG: commit timestamp Xid > oldest/newest: 0/0 > 2021-07-02 08:43:52.174 CEST [37574] DEBUG: transaction ID wrap limit is > 2147484373, limited by database with OID 1 > 2021-07-02 08:43:52.174 CEST [37574] DEBUG: MultiXactId wrap limit is > 2147483648, limited by database with OID 1 > 2021-07-02 08:43:52.174 CEST [37574] DEBUG: starting up replication slots > 2021-07-02 08:43:52.174 CEST [37574] DEBUG: starting up replication origin > progress state > 2021-07-02 08:43:52.174 CEST [37574] LOG: database system was not properly > shut down; automatic recovery in progress > 2021-07-02 08:43:52.176 CEST [37574] DEBUG: resetting unlogged relations: > cleanup 1 init 0 > 2021-07-02 08:43:52.176 CEST [37574] LOG: invalid record length at > 0/439D098: wanted 24, got 0 > 2021-07-02 08:43:52.176 CEST [37574] LOG: redo is not required > 2021-07-02 08:43:52.176 CEST [37574] DEBUG: resetting unlogged relations: > cleanup 0 init 1 > 2021-07-02 08:43:52.180 CEST [37574] DEBUG: performing replication slot > checkpoint > 2021-07-02 08:43:52.186 CEST [37574] DEBUG: attempting to remove WAL > segments older than log file 000000000000000000000003 > 2021-07-02 08:43:52.186 CEST [37574] DEBUG: MultiXactId wrap limit is > 2147483648, limited by database with OID 1 > 2021-07-02 08:43:52.186 CEST [37574] DEBUG: MultiXact member stop limit is > now 4294914944 based on MultiXact 1 > 2021-07-02 08:43:52.187 CEST [37574] DEBUG: shmem_exit(0): 1 > before_shmem_exit callbacks to make > 2021-07-02 08:43:52.187 CEST [37574] DEBUG: shmem_exit(0): 7 on_shmem_exit > callbacks to make > 2021-07-02 08:43:52.187 CEST [37574] DEBUG: proc_exit(0): 2 callbacks to > make > 2021-07-02 08:43:52.187 CEST [37574] DEBUG: exit(0) > 2021-07-02 08:43:52.187 CEST [37574] DEBUG: shmem_exit(-1): 0 > before_shmem_exit callbacks to make > 2021-07-02 08:43:52.187 CEST [37574] DEBUG: shmem_exit(-1): 0 on_shmem_exit > callbacks to make > 2021-07-02 08:43:52.187 CEST [37574] DEBUG: proc_exit(-1): 0 callbacks to > make > 2021-07-02 08:43:52.188 CEST [37575] DEBUG: checkpointer updated shared > memory configuration values > 2021-07-02 08:43:52.188 CEST [37478] DEBUG: starting background worker > process "logical replication launcher" > 2021-07-02 08:43:52.189 CEST [37578] DEBUG: autovacuum launcher started > 2021-07-02 08:43:52.189 CEST [37478] LOG: database system is ready to > accept connections > 2021-07-02 08:43:52.189 CEST [37578] DEBUG: InitPostgres > 2021-07-02 08:43:52.189 CEST [37580] DEBUG: logical replication launcher > started > 2021-07-02 08:43:52.189 CEST [37580] DEBUG: InitPostgres > 2021-07-02 08:43:52.189 CEST [37579] DEBUG: received inquiry for database > 0 > 2021-07-02 08:43:52.189 CEST [37579] DEBUG: writing stats file > "pg_stat_tmp/global.stat" > 2021-07-02 08:44:07.209 CEST [37576] DEBUG: snapshot of 0+0 running > transaction ids (lsn 0/439D148 oldest xid 19078 latest complete 19077 next > xid 19078) > <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< > > > Remarks: > Until version 14beta1 this worked fine, but in version 14beta2 the > SPI_execute() call fails > -- Martin Butter Developer Splendid Data Nederland B.V. Binnenhof 62A 1412 LC  NAARDEN T: +31 (0)85 773 19 99 M: +31 (0)6 226 946 62 E: martin.butter@splendiddata.com http://www.splendiddata.com/ --------------A36185D8F3FF5A357D9B7BA0 Content-Type: text/html; charset=utf-8 Content-Transfer-Encoding: 8bit

In the attachement you will find the source of a database extension that I used to test this.

Extension test_spi_in_preload_session just executes 'select 1' in its _PG_init() function.
Until Postgres version 14beta1 this works fine, but in version 14beta2 the process dies.

To compile:
make
make install

In postgresql.conf set:

log_min_messages = debug3
session_preload_libraries = 'test_spi_in_preload_session'

To test:
Just try to login to Postgres or execute
make installcheck

Regards,
Martin.

On 02/07/2021 09:10, PG Bug reporting form wrote:
The following bug has been logged on the website:

Bug reference:      17081
Logged by:          Martin Butter
Email address:      martin.butter@splendiddata.com
PostgreSQL version: 14beta2
Operating system:   Fedora 33
Description:        

Code used:

                                                          
#include "postgres.h"
#include "executor/spi.h"
#include "miscadmin.h"
#include "commands/dbcommands.h"
#include "access/xact.h"

#ifdef PG_MODULE_MAGIC
PG_MODULE_MAGIC;
#endif

void _PG_init(void);
/* Module entry point */
void _PG_init(void)
{
	char* dbName;
	int startedATransaction = 0;
	int spiStatus;
	ErrorData *edata;

	elog(DEBUG3,
	     "_PG_init() in test_spi_in_preload_session.so, MyProcPid=%d,
MyDatabaseId=%d, IsBackgroundWorker=%d",
	     MyProcPid, MyDatabaseId, IsBackgroundWorker);

	/*
	 * If no database is selected, don't execute the code
	 * This may occur for example in a replication target database.
	 */
	if (!OidIsValid(MyDatabaseId)) {
	    elog(DEBUG1, "No database selected so test_spi_in_preload_session will
not execute");
	    return;
	}

	/*
	 * Don't try to execute in a parallel worker
	 */
	if (IsBackgroundWorker)
	{
		elog(DEBUG1,
		     "test_spi_in_preload_session did not do anything because we are in a
background worker");
		return;
	}

	if (GetCurrentTransactionIdIfAny() == InvalidTransactionId)
	{
		/*
		 * If we're not in a transaction, start one.
		 */
		StartTransactionCommand();
		startedATransaction = 1;
	}

	dbName = get_database_name(MyDatabaseId);
	Assert(dbName); // warning: only active if kernel compiled with
--enable-cassert

        spiStatus = SPI_connect();
        if (spiStatus != SPI_OK_CONNECT) {
            ereport(ERROR,
                    ( errmsg("SPI_connect returned %d for database %s",
                            spiStatus,
                            dbName)));
        }


        // if ones gets error in SPI_execute(), the function does not
return, unless protected by a PG_TRY / PG_CATCH
        PG_TRY();
        {
            elog(DEBUG3,
                         "test_spi_in_preload_session will execute 'select
1' in database %s",
                         dbName);
            spiStatus = SPI_execute("select 1", false, 1);
            if (spiStatus < 0) {
                ereport(ERROR,
                        ( errmsg("SPI_execute returned %d for query 'select
1' in database %s",
                                spiStatus,
                                dbName)));
            }
            elog(DEBUG3,
                 "test_spi_in_preload_session is back from 'select 1' in
database %s",
                 dbName);
        }
        PG_CATCH();
        {
            AbortCurrentTransaction();
            edata = CopyErrorData();
            ereport(WARNING,
                ( errcode(edata->sqlerrcode),
                  errmsg("test_spi_in_preload_session failed to execute 
'select 1' in database %s",
                         dbName),
                  errhint("original message = %s", edata->message)));
        }
        PG_END_TRY();

        SPI_finish();

	if (startedATransaction)
	{
		/*
		 * commit the transaction we started
		 */
		CommitTransactionCommand();
	}
}
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

Serverlog:

                                                          
    .
    .
2021-07-02 08:43:43.295 CEST [37478] LOG:  database system is ready to
accept connections
2021-07-02 08:43:43.295 CEST [37487] DEBUG:  InitPostgres
2021-07-02 08:43:43.295 CEST [37488] DEBUG:  removing permanent stats file
"pg_stat/global.stat"
2021-07-02 08:43:43.296 CEST [37489] DEBUG:  logical replication launcher
started
2021-07-02 08:43:43.296 CEST [37489] DEBUG:  InitPostgres
2021-07-02 08:43:43.300 CEST [37488] DEBUG:  received inquiry for database
0
2021-07-02 08:43:43.300 CEST [37488] DEBUG:  writing stats file
"pg_stat_tmp/global.stat"
2021-07-02 08:43:51.664 CEST [37478] DEBUG:  forked new backend, pid=37558
socket=9
2021-07-02 08:43:51.665 CEST [37558] DEBUG:  InitPostgres
2021-07-02 08:43:51.677 CEST [37558] DEBUG:  find_in_dynamic_libpath: trying
"/usr/local/postgresql-14beta2/lib/test_spi_in_preload_session"
2021-07-02 08:43:51.677 CEST [37558] DEBUG:  find_in_dynamic_libpath: trying
"/usr/local/postgresql-14beta2/lib/test_spi_in_preload_session.so"
2021-07-02 08:43:51.677 CEST [37558] DEBUG:  _PG_init() in
test_spi_in_preload_session.so, MyProcPid=37558, MyDatabaseId=13977,
IsBackgroundWorker=0
2021-07-02 08:43:51.677 CEST [37558] DEBUG:  test_spi_in_preload_session
will execute 'select 1' in database postgres
2021-07-02 08:43:51.984 CEST [37478] DEBUG:  server process (PID 37558) was
terminated by signal 11: Segmentation fault
2021-07-02 08:43:51.984 CEST [37478] LOG:  server process (PID 37558) was
terminated by signal 11: Segmentation fault
2021-07-02 08:43:51.984 CEST [37478] LOG:  terminating any other active
server processes
2021-07-02 08:43:51.984 CEST [37478] DEBUG:  sending SIGQUIT to process
37489
2021-07-02 08:43:51.984 CEST [37478] DEBUG:  sending SIGQUIT to process
37485
2021-07-02 08:43:51.984 CEST [37478] DEBUG:  sending SIGQUIT to process
37484
2021-07-02 08:43:51.984 CEST [37478] DEBUG:  sending SIGQUIT to process
37486
2021-07-02 08:43:51.984 CEST [37478] DEBUG:  sending SIGQUIT to process
37487
2021-07-02 08:43:51.984 CEST [37478] DEBUG:  sending SIGQUIT to process
37488
2021-07-02 08:43:51.984 CEST [37488] DEBUG:  writing stats file
"pg_stat/global.stat"
2021-07-02 08:43:51.984 CEST [37488] DEBUG:  shmem_exit(-1): 0
before_shmem_exit callbacks to make
2021-07-02 08:43:51.984 CEST [37488] DEBUG:  shmem_exit(-1): 0 on_shmem_exit
callbacks to make
2021-07-02 08:43:51.984 CEST [37488] DEBUG:  proc_exit(-1): 0 callbacks to
make
2021-07-02 08:43:51.985 CEST [37478] LOG:  all server processes terminated;
reinitializing
2021-07-02 08:43:51.985 CEST [37478] DEBUG:  shmem_exit(1): 0
before_shmem_exit callbacks to make
2021-07-02 08:43:51.985 CEST [37478] DEBUG:  shmem_exit(1): 5 on_shmem_exit
callbacks to make
2021-07-02 08:43:51.985 CEST [37478] DEBUG:  cleaning up dynamic shared
memory control segment with ID 2085192430
2021-07-02 08:43:51.997 CEST [37478] DEBUG:  invoking
IpcMemoryCreate(size=148856832)
2021-07-02 08:43:51.997 CEST [37478] DEBUG:  mmap(148897792) with
MAP_HUGETLB failed, huge pages disabled: Cannot allocate memory
2021-07-02 08:43:52.005 CEST [37478] DEBUG:  dynamic shared memory system
will support 674 segments
2021-07-02 08:43:52.005 CEST [37478] DEBUG:  created dynamic shared memory
control segment 289087702 (26976 bytes)
2021-07-02 08:43:52.006 CEST [37574] LOG:  database system was interrupted;
last known up at 2021-07-02 08:43:43 CEST
2021-07-02 08:43:52.006 CEST [37574] DEBUG:  removing all temporary WAL
segments
2021-07-02 08:43:52.174 CEST [37574] DEBUG:  checkpoint record is at
0/439D020
2021-07-02 08:43:52.174 CEST [37574] DEBUG:  redo record is at 0/439D020;
shutdown true
2021-07-02 08:43:52.174 CEST [37574] DEBUG:  next transaction ID: 19078;
next OID: 111557
2021-07-02 08:43:52.174 CEST [37574] DEBUG:  next MultiXactId: 1; next
MultiXactOffset: 0
2021-07-02 08:43:52.174 CEST [37574] DEBUG:  oldest unfrozen transaction ID:
726, in database 1
2021-07-02 08:43:52.174 CEST [37574] DEBUG:  oldest MultiXactId: 1, in
database 1
2021-07-02 08:43:52.174 CEST [37574] DEBUG:  commit timestamp Xid
oldest/newest: 0/0
2021-07-02 08:43:52.174 CEST [37574] DEBUG:  transaction ID wrap limit is
2147484373, limited by database with OID 1
2021-07-02 08:43:52.174 CEST [37574] DEBUG:  MultiXactId wrap limit is
2147483648, limited by database with OID 1
2021-07-02 08:43:52.174 CEST [37574] DEBUG:  starting up replication slots
2021-07-02 08:43:52.174 CEST [37574] DEBUG:  starting up replication origin
progress state
2021-07-02 08:43:52.174 CEST [37574] LOG:  database system was not properly
shut down; automatic recovery in progress
2021-07-02 08:43:52.176 CEST [37574] DEBUG:  resetting unlogged relations:
cleanup 1 init 0
2021-07-02 08:43:52.176 CEST [37574] LOG:  invalid record length at
0/439D098: wanted 24, got 0
2021-07-02 08:43:52.176 CEST [37574] LOG:  redo is not required
2021-07-02 08:43:52.176 CEST [37574] DEBUG:  resetting unlogged relations:
cleanup 0 init 1
2021-07-02 08:43:52.180 CEST [37574] DEBUG:  performing replication slot
checkpoint
2021-07-02 08:43:52.186 CEST [37574] DEBUG:  attempting to remove WAL
segments older than log file 000000000000000000000003
2021-07-02 08:43:52.186 CEST [37574] DEBUG:  MultiXactId wrap limit is
2147483648, limited by database with OID 1
2021-07-02 08:43:52.186 CEST [37574] DEBUG:  MultiXact member stop limit is
now 4294914944 based on MultiXact 1
2021-07-02 08:43:52.187 CEST [37574] DEBUG:  shmem_exit(0): 1
before_shmem_exit callbacks to make
2021-07-02 08:43:52.187 CEST [37574] DEBUG:  shmem_exit(0): 7 on_shmem_exit
callbacks to make
2021-07-02 08:43:52.187 CEST [37574] DEBUG:  proc_exit(0): 2 callbacks to
make
2021-07-02 08:43:52.187 CEST [37574] DEBUG:  exit(0)
2021-07-02 08:43:52.187 CEST [37574] DEBUG:  shmem_exit(-1): 0
before_shmem_exit callbacks to make
2021-07-02 08:43:52.187 CEST [37574] DEBUG:  shmem_exit(-1): 0 on_shmem_exit
callbacks to make
2021-07-02 08:43:52.187 CEST [37574] DEBUG:  proc_exit(-1): 0 callbacks to
make
2021-07-02 08:43:52.188 CEST [37575] DEBUG:  checkpointer updated shared
memory configuration values
2021-07-02 08:43:52.188 CEST [37478] DEBUG:  starting background worker
process "logical replication launcher"
2021-07-02 08:43:52.189 CEST [37578] DEBUG:  autovacuum launcher started
2021-07-02 08:43:52.189 CEST [37478] LOG:  database system is ready to
accept connections
2021-07-02 08:43:52.189 CEST [37578] DEBUG:  InitPostgres
2021-07-02 08:43:52.189 CEST [37580] DEBUG:  logical replication launcher
started
2021-07-02 08:43:52.189 CEST [37580] DEBUG:  InitPostgres
2021-07-02 08:43:52.189 CEST [37579] DEBUG:  received inquiry for database
0
2021-07-02 08:43:52.189 CEST [37579] DEBUG:  writing stats file
"pg_stat_tmp/global.stat"
2021-07-02 08:44:07.209 CEST [37576] DEBUG:  snapshot of 0+0 running
transaction ids (lsn 0/439D148 oldest xid 19078 latest complete 19077 next
xid 19078)
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<


Remarks:
Until version 14beta1 this worked fine, but in version 14beta2 the
SPI_execute() call fails

--
Martin Butter
Developer

Splendid Data Nederland B.V.
Binnenhof 62A
1412 LC  NAARDEN

T: +31 (0)85 773 19 99
M: +31 (0)6 226 946 62
E: martin.butter@splendiddata.com

http://www.splendiddata.com/
--------------A36185D8F3FF5A357D9B7BA0-- --------------73BFB29826BC0953AAFF6549 Content-Type: application/x-xz; name="extension.tar.xz" Content-Transfer-Encoding: base64 Content-Disposition: attachment; filename="extension.tar.xz" /Td6WFoAAATm1rRGAgAhARYAAAB0L+Wj4D3/CkpdADKeCtBB2uo3WBSCEGk3fsV3twRcH/ew tWGJO0LRA4EgoF+TmKD8VFFcfS3VTmqb6qw+FySJqU+U5mkzgXC7aNDRttMPVB1hRPVhryga il4q3pbcGHr2EsGk+Csa/b4lEm6Ai4F4zVtUmTeSa2jQPz3UxfB/Qjuy79+hZ0onAs45TVAc +1c0smQ9uvQGJhRNsvLBMwfpA1bTh7erPGOgIKpt7TS0EWE/TRW5584tJ7SNNRTASpi2l3Kf 3b7QpJv/ZvQFlKooscyb0eqSDbJ9W7zjaobkMHzLEREUC/ThYldSBxYT1XUAyqHDKZ69JpUn DbChCTgAcNuZtGPjswVmk79SdTqblzfPUF+XqAatqNgHTovzgmKkNd5S58Po7J7gN5v0JnbF mOIrH1L7JQ46jJSEseTbogk62roQFyhOuoEIDapviGo8bIyQkizVcKRO1RPfdtsbl7qSKcKg 1NVdv/xxy7mQoh4Rv6cHsp9FpLfDkElQTqNHe0nPwR+wmjR07t+T7JevqoEcDJnhtUhXm1MT TJRTMBuQ38OV87QpQqyweiMM6DsGVzJfB35qput3FypdsFgCSjTMg+tnA2l9wY3oB5L8nOGq 8miX2lxaNiBo5Uy5I4/Q+K+co7TMuVsgil0RdZ/O6GVNz0HIF0u25zQJYEEcIjQjYYpo6Gmy oKP4UfB12awVsjQ4ty2rCaZPX64TCNvHRfwOmiaZlDGtycoN56EOwF1WX6lBMYDrCGjVC7h0 d8Cw2D9NrhxjX8ORLmNo6dnGPHFVx0u5iizfPDHp0KFErpSBNWpo3WDuzDbw+vIhwvECoikG uy0FVeS63LUC4haVv79LWbh05Rc8cJuaJGebmocFNa8gA2abT/arHUorUtavdD/sN975wKlh +x5ZFKq35AO876dHM/PnQjms8WlRcPbB1P86n3Z8yWCzrPpSTdRGmTJy7KJKT6sW5+ZLIvSI 4T0G5Y8UN1nHgkjG0SB91JundVxVU7Suu7YBBUaqsmoOleUaTqq4S6WeR8B5ElB06Gqk3y5m oCkDK5vles+zohQJHNUcsmpUvdYZiviDC7nqUY1hwZNTajvyZKVkWtqofQswO3PxWy6UU6b+ +bQrfyepSGiQxWfD5RsEL5N4DD7ui/RMq0/yoE3p8KZ2DodukWUJe9GrekLzfAp4jNdOEZ// Y1lMosQ6iaHSpnKH8K0nQEcDEV+90Krf5vxPred6dU3EJRok9lafKMhGWCgLjPYgSk1JrDCa XRVnnqQGAF7V0Ye1gtUKFubWYliinppdYKDR1pWMAosh5Z3CNOmKLxbjQrXpr8SY3hgY3H4Y sMRFY9k1Z2ye1LrOIQWGOnv4Q7+gKfOu9WchLO7e2yEZoZGkJ9xXWjQyGkwDq2Dv2vmeGqnL IrGljYLSPsuFdJZD35BsuEWp2WQNXfFkKA5aMuqxPftVBLGbcEAZo2TfPakf2lJifdl4vGn6 yNiJ4UCM+r7OT2hWPoXWrqd9Qrz87inTmwEG5iDHJUzwpBjClereaP3C9NFigKkepCX/wwfH pozLoq+ivVAWigSL3inICHMlP+zyf49jpoZefJvr7eGX9wDqkJUsWtaxi+ymlq03knmgHkU6 zXt6ngpM3nDRs6UHcLuOroNbrb323wrZk2v6//8UbhyfOA51OkYEiFHeo0h2rynQGDeBIlbh ExMGDPv1M/afyLR+90G+JOdHveNkHyi/OB9II82H4HXife83Au7p8JYxjCDlSOpalTtBDWab LzGLupaeDCr9DuqvZheZszgLhzve9K3wKas3R5S7Xn+PhlJRmC1QrKee9jF+Wemsc2q2CfOz i2IaZQ76FBKTeW2zMbR+DHvLHTOb78wRrpICJzM1gwnx+dqflUOdD9UwCWbM82GZu07gUZvh /FnSnNMUWVvCk6MbQKmaVOmIci/u3TB8ngys5YlnE3WdglXF3LtxvOz5F5GXWNNPRxqNZ7EL JbQvQ2qIOBiwTQ7TffNr7YeFvLLxYIhoWe+fxmCdQkzx0vAPYFWPYiIi4B5e5g+1pIg9CjeE ZQWjcQS5gOymolqQ6nTiz5BO5B3mJW0za+O9kxaRldFKXyk/yLi9QGygXCGQ4k1tnQsy77RM BocEO3ZqPixs0L1+0KWxQU4c34+DG98mSOfBu3JD7NJgan2pU3V1lkT2sI7+0J+JprdcvBUU 9HSV+a/Sp7bu5RYu2O9ECQILF0hUZQWN7tHUlQiMNIEBEb5nX2uL42TZ4ZEK6HOHG0UcVVPb ZUXSg/tfAuQRJ2Ad7xgiB083ogTaq18nvuk+M7jHe5MU4a99FN1NhMdgCky/3+7YqRPNFClO 66hRXscnBCLga6bHWTzWHzxc7YFOzNFjVEs3nJY42C+4SrLP4g/HgQlgc4hy7BOz41xiUUKh bQDAoell8a69QeoAIG/guYRNmWWIoB9fIbISsW5mbkMgAOrThbwmRlVc0LXgEYVoAUchH41a kHVAg2AyUdOmNgerNZO5vxgElIufZbTx8d8lhfvOOSANmp7GfFGmk65qd2SRDLT2wSqf0EBA GJG5BQePnAXHQPV007nkGAnoNtHzAaeLPxptQpfwLOZz7/cB88bNnI+aXRN/69XwCoxaw3e1 YWOSB7wXGNg07XM08nfsV+DUtxD9hI8Ezq5ZY+Wsltlyq0qYUXVdQ58A2AVzw+Usek3d89XY 6Tkul0yI3ABx84KaWvf/i2R6pJpdKsFCr2Yf33zvIzovVYrCcY4K+f0xfVE06/icWg20FImC xelYfOE0FsU+LmlD0Kke+U9+aiZb9skk1ZLxyXPywGcksLoQknDD6IWquIM1U8a3D3Y/KTKQ eWX4pDGzY9F0stNhedyBNsZBG8ZKUaQj0ye0CnwvqyVO3TQElAe2Qp8V1NhcQNA3JjbHO46b FYCQeYOoJIZ8hd/fM7GDP/4/BAhAyHXouc+DbnqT2ugAA21gc4/vYnUb5kT8r2sDMAxtkmq3 Kx26tfbPS0Bu4xYOx+qJjgeNmr+JTGwtd9kw4T1vid9MkMWydVYcRAV01Rg4xGzh5NvyLNHd /xZvximPyVJyPKzWlQg4xodIvEkT1EMhew7zzWsSvBIJJq4ZD8pzDvAqDq7PxmaJ1sDTOBXA V0WTW/THUgcJNUhn2N4z7QUr2SwSpuXMK/NfMotZ23kS2OE6VcfEBX7RuW+q2V6GSJawl+bC V8UIg4eWiCSlA/uVdVGU6QKUAvaDxfb7PZ9jZpm603YEtfIAgm2upbSl0/VmKY+q4TcqM6nO DT2dLGU8YfUVL2GRkS6UGg27joAd04u95PkSDvTmFI2EdMpEkRI+wOP016vmNnNXU/LUOUHu KPJRnffYzVdt/5AOYRxEOQHTae/HOvUaS5mKYpsW6WgIfC6nqdDMdBVJvHX44tr9ZkUGNqVu 3uxR3i+MwmrW8PRZB1/VQXZIl0+5y47lzocWRNhdQWnuLsLaBq2rvhuq4xdDtHhPqlY4inYO /xZ03NqndQ5ff7AU7HeTlQgKAAAAAIvq5uvGs9bnAAHmFIB8AAAPOpomscRn+wIAAAAABFla --------------73BFB29826BC0953AAFF6549--