Thread: Server crashed with "TRAP: unrecognized TOAST vartag("1", File:"heaptuple.c", Line: 1490)"

Hi,

I am getting server crash with below test case, logfile message and core dump details in the mail.

postgres=# CREATE TABLE part_tbl (a INT, b TEXT, c INT) PARTITION BY RANGE(a);
CREATE TABLE
postgres=# CREATE TABLE part_tbl_p PARTITION OF part_tbl FOR VALUES FROM (minvalue) TO (maxvalue);
CREATE TABLE
postgres=# CREATE INDEX partidx_abc_idx ON part_tbl (a, b, c);
CREATE INDEX
postgres=# INSERT INTO part_tbl (a, b, c) SELECT i,i,i FROM generate_series(1,50)i;
INSERT 0 50
postgres=# ANALYZE part_tbl;
ANALYZE
postgres=# ALTER TABLE part_tbl ALTER COLUMN c TYPE numeric;
server closed the connection unexpectedly
    This probably means the server terminated abnormally
    before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
!>


--logfile
TRAP: unrecognized TOAST vartag("1", File: "heaptuple.c", Line: 1490)
2018-06-28 00:01:01.679 IST [97062] LOG:  server process (PID 97080) was terminated by signal 6: Aborted
2018-06-28 00:01:01.679 IST [97062] DETAIL:  Failed process was running: ALTER TABLE part_tbl ALTER COLUMN c TYPE numeric;

--corefile
Core was generated by `postgres: edb postgres [local] ALTER TABLE              '.
Program terminated with signal 6, Aborted.
#0  0x0000003dd2632495 in raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
64      return INLINE_SYSCALL (tgkill, 3, pid, selftid, sig);
Missing separate debuginfos, use: debuginfo-install keyutils-libs-1.4-5.el6.x86_64 krb5-libs-1.10.3-65.el6.x86_64 libcom_err-1.41.12-23.el6.x86_64 libselinux-2.0.94-7.el6.x86_64 openssl-1.0.1e-57.el6.x86_64 zlib-1.2.3-29.el6.x86_64
(gdb) bt
#0  0x0000003dd2632495 in raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1  0x0000003dd2633c75 in abort () at abort.c:92
#2  0x0000000000a337ee in ExceptionalCondition (conditionName=0xaa3290 "1", errorType=0xaa3276 "unrecognized TOAST vartag", fileName=0xaa31e0 "heaptuple.c", lineNumber=1490)
    at assert.c:54
#3  0x0000000000487c9c in slot_deform_tuple (slot=0x1fa2d68, natts=3) at heaptuple.c:1490
#4  0x0000000000487fc2 in slot_getattr (slot=0x1fa2d68, attnum=3, isnull=0x7ffea43368e7) at heaptuple.c:1595
#5  0x000000000057b10d in FormIndexDatum (indexInfo=0x1f91138, slot=0x1fa2d68, estate=0x1f95c98, values=0x7ffea4336be0, isnull=0x7ffea4336bc0) at index.c:2032
#6  0x000000000057c459 in IndexBuildHeapRangeScan (heapRelation=0x7f3944067c40, indexRelation=0x7f3944067a28, indexInfo=0x1f91138, allow_sync=true, anyvisible=false,
    start_blockno=0, numblocks=4294967295, callback=0x5123ab <_bt_build_callback>, callback_state=0x7ffea4336ea0, scan=0x1f91b80) at index.c:2876
#7  0x000000000057bac1 in IndexBuildHeapScan (heapRelation=0x7f3944067c40, indexRelation=0x7f3944067a28, indexInfo=0x1f91138, allow_sync=true,
    callback=0x5123ab <_bt_build_callback>, callback_state=0x7ffea4336ea0, scan=0x0) at index.c:2426
#8  0x0000000000512222 in _bt_spools_heapscan (heap=0x7f3944067c40, index=0x7f3944067a28, buildstate=0x7ffea4336ea0, indexInfo=0x1f91138) at nbtsort.c:472
#9  0x0000000000511f72 in btbuild (heap=0x7f3944067c40, index=0x7f3944067a28, indexInfo=0x1f91138) at nbtsort.c:324
#10 0x000000000057b6fb in index_build (heapRelation=0x7f3944067c40, indexRelation=0x7f3944067a28, indexInfo=0x1f91138, isprimary=false, isreindex=false, parallel=true)
    at index.c:2288
#11 0x0000000000579d49 in index_create (heapRelation=0x7f3944067c40, indexRelationName=0x1f9b370 "part_tbl_p_a_b_c_idx", indexRelationId=16396, parentIndexRelid=16395,
    parentConstraintId=0, relFileNode=0, indexInfo=0x1f91138, indexColNames=0x1f9b288, accessMethodObjectId=403, tableSpaceId=1663, collationObjectId=0x1f9b460,
    classObjectId=0x1f9b488, coloptions=0x1f9b4b0, reloptions=0, flags=0, constr_flags=0, allow_system_table_mods=false, is_internal=true, constraintId=0x7ffea433715c)
    at index.c:1187
#12 0x000000000066488d in DefineIndex (relationId=16387, stmt=0x1f90eb8, indexRelationId=0, parentIndexId=16395, parentConstraintId=0, is_alter_table=true, check_rights=false,
    check_not_in_use=false, skip_build=false, quiet=true) at indexcmds.c:850
#13 0x0000000000664e7f in DefineIndex (relationId=16384, stmt=0x1f79688, indexRelationId=16395, parentIndexId=0, parentConstraintId=0, is_alter_table=true, check_rights=false,
    check_not_in_use=false, skip_build=true, quiet=true) at indexcmds.c:1031
#14 0x000000000068ff68 in ATExecAddIndex (tab=0x1f744f8, rel=0x7f3944061b50, stmt=0x1f79688, is_rebuild=true, lockmode=8) at tablecmds.c:6958
#15 0x000000000068977f in ATExecCmd (wqueue=0x7ffea4337838, tab=0x1f744f8, rel=0x7f3944061b50, cmd=0x1f90e60, lockmode=8) at tablecmds.c:4090
#16 0x00000000006891a9 in ATRewriteCatalogs (wqueue=0x7ffea4337838, lockmode=8) at tablecmds.c:3989
#17 0x0000000000688880 in ATController (parsetree=0x1f81460, rel=0x7f3944061b50, cmds=0x1f74460, recurse=true, lockmode=8) at tablecmds.c:3639
#18 0x00000000006885a9 in AlterTable (relid=16384, lockmode=8, stmt=0x1f81460) at tablecmds.c:3312
#19 0x00000000008cea8e in ProcessUtilitySlow (pstate=0x1f81348, pstmt=0x1eb95a0, queryString=0x1eb8798 "ALTER TABLE part_tbl ALTER COLUMN c TYPE numeric;",
    context=PROCESS_UTILITY_TOPLEVEL, params=0x0, queryEnv=0x0, dest=0x1eb9890, completionTag=0x7ffea4337fd0 "") at utility.c:1117
#20 0x00000000008ce50e in standard_ProcessUtility (pstmt=0x1eb95a0, queryString=0x1eb8798 "ALTER TABLE part_tbl ALTER COLUMN c TYPE numeric;",
    context=PROCESS_UTILITY_TOPLEVEL, params=0x0, queryEnv=0x0, dest=0x1eb9890, completionTag=0x7ffea4337fd0 "") at utility.c:920
#21 0x00000000008cd530 in ProcessUtility (pstmt=0x1eb95a0, queryString=0x1eb8798 "ALTER TABLE part_tbl ALTER COLUMN c TYPE numeric;", context=PROCESS_UTILITY_TOPLEVEL,
    params=0x0, queryEnv=0x0, dest=0x1eb9890, completionTag=0x7ffea4337fd0 "") at utility.c:360
#22 0x00000000008cc4de in PortalRunUtility (portal=0x1f1dc28, pstmt=0x1eb95a0, isTopLevel=true, setHoldSnapshot=false, dest=0x1eb9890, completionTag=0x7ffea4337fd0 "")
    at pquery.c:1178
#23 0x00000000008cc706 in PortalRunMulti (portal=0x1f1dc28, isTopLevel=true, setHoldSnapshot=false, dest=0x1eb9890, altdest=0x1eb9890, completionTag=0x7ffea4337fd0 "")
    at pquery.c:1324
#24 0x00000000008cbbf3 in PortalRun (portal=0x1f1dc28, count=9223372036854775807, isTopLevel=true, run_once=true, dest=0x1eb9890, altdest=0x1eb9890,
    completionTag=0x7ffea4337fd0 "") at pquery.c:799
#25 0x00000000008c5afc in exec_simple_query (query_string=0x1eb8798 "ALTER TABLE part_tbl ALTER COLUMN c TYPE numeric;") at postgres.c:1122
#26 0x00000000008c9dd2 in PostgresMain (argc=1, argv=0x1ee22a0, dbname=0x1ee2100 "postgres", username=0x1eb5298 "edb") at postgres.c:4153
#27 0x0000000000827467 in BackendRun (port=0x1eda060) at postmaster.c:4361
Thanks & Regards,
Rajkumar Raghuwanshi
QMG, EnterpriseDB Corporation
Hi,

On 2018-06-28 16:08:31 +0530, Rajkumar Raghuwanshi wrote:
> I am getting server crash with below test case, logfile message and core
> dump details in the mail.

Which versions are affected here? Is this reproducible in postgres 10 or
just the current beta?


> postgres=# CREATE TABLE part_tbl (a INT, b TEXT, c INT) PARTITION BY
> RANGE(a);
> CREATE TABLE
> postgres=# CREATE TABLE part_tbl_p PARTITION OF part_tbl FOR VALUES FROM
> (minvalue) TO (maxvalue);
> CREATE TABLE
> postgres=# CREATE INDEX partidx_abc_idx ON part_tbl (a, b, c);
> CREATE INDEX
> postgres=# INSERT INTO part_tbl (a, b, c) SELECT i,i,i FROM
> generate_series(1,50)i;
> INSERT 0 50
> postgres=# ANALYZE part_tbl;
> ANALYZE
> postgres=# ALTER TABLE part_tbl ALTER COLUMN c TYPE numeric;
> server closed the connection unexpectedly
>     This probably means the server terminated abnormally
>     before or while processing the request.
> The connection to the server was lost. Attempting reset: Failed.
> !>
> 
> 
> --logfile
> TRAP: unrecognized TOAST vartag("1", File: "heaptuple.c", Line: 1490)
> 2018-06-28 00:01:01.679 IST [97062] LOG:  server process (PID 97080) was
> terminated by signal 6: Aborted
> 2018-06-28 00:01:01.679 IST [97062] DETAIL:  Failed process was running:
> ALTER TABLE part_tbl ALTER COLUMN c TYPE numeric;

Likely a memory lifetime issue or something like that.

Greetings,

Andres Freund


On Thu, Jun 28, 2018 at 9:45 PM, Andres Freund <andres@anarazel.de> wrote:
Hi,

On 2018-06-28 16:08:31 +0530, Rajkumar Raghuwanshi wrote:
> I am getting server crash with below test case, logfile message and core
> dump details in the mail.

Which versions are affected here? Is this reproducible in postgres 10 or
just the current beta?

This affected current beta only as this is not reproducible in postgres 10 because index create on
partitioned table is not supported in v10.
 

Hi,

On 2018-06-28 22:35:11 +0530, Rajkumar Raghuwanshi wrote:
> On Thu, Jun 28, 2018 at 9:45 PM, Andres Freund <andres@anarazel.de> wrote:
> > On 2018-06-28 16:08:31 +0530, Rajkumar Raghuwanshi wrote:
> > > I am getting server crash with below test case, logfile message and core
> > > dump details in the mail.
> >
> > Which versions are affected here? Is this reproducible in postgres 10 or
> > just the current beta?
> >
> 
> This affected current beta only as this is not reproducible in postgres 10
> because index create on
> partitioned table is not supported in v10.

Alvaro, sounds like it could be an open item assigned to you?

Greetings,

Andres Freund


On 2018-Jun-28, Andres Freund wrote:

> On 2018-06-28 22:35:11 +0530, Rajkumar Raghuwanshi wrote:
> > On Thu, Jun 28, 2018 at 9:45 PM, Andres Freund <andres@anarazel.de> wrote:
> > > On 2018-06-28 16:08:31 +0530, Rajkumar Raghuwanshi wrote:
> > > > I am getting server crash with below test case, logfile message and core
> > > > dump details in the mail.

> Alvaro, sounds like it could be an open item assigned to you?

You're right.  The attached patch seems to fix it.

I think I should add Rajkumar's test case too, though, so I'm not
pushing this evening.

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Attachment
On Fri, Jun 29, 2018 at 4:30 AM, Alvaro Herrera <alvherre@2ndquadrant.com> wrote:
On 2018-Jun-28, Andres Freund wrote:

> On 2018-06-28 22:35:11 +0530, Rajkumar Raghuwanshi wrote:
> > On Thu, Jun 28, 2018 at 9:45 PM, Andres Freund <andres@anarazel.de> wrote:
> > > On 2018-06-28 16:08:31 +0530, Rajkumar Raghuwanshi wrote:
> > > > I am getting server crash with below test case, logfile message and core
> > > > dump details in the mail.

> Alvaro, sounds like it could be an open item assigned to you?

You're right.  The attached patch seems to fix it.
Thanks for patch, It fixed the issue.
 

I think I should add Rajkumar's test case too, though, so I'm not
pushing this evening.

--
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On 2018-Jun-29, Rajkumar Raghuwanshi wrote:

> On Fri, Jun 29, 2018 at 4:30 AM, Alvaro Herrera <alvherre@2ndquadrant.com>
> wrote:
> 
> > On 2018-Jun-28, Andres Freund wrote:

> > > Alvaro, sounds like it could be an open item assigned to you?
> >
> > You're right.  The attached patch seems to fix it.
> >
> Thanks for patch, It fixed the issue.

Thanks for checking (and testing!).  Pushed.

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services