[Bug]: Crash in ON CONFLICT ... DO UPDATE query

[jnidzwetzki]

What type of bug is this?

Crash

What subsystems and features are affected?

Compression

What happened?

The PostgreSQL server crashes when a ON CONFLICT ... DO UPDATE query is executed:

Steps to reproduce

CREATE TABLE IF NOT EXISTS mytable (
	time TIMESTAMPTZ NOT NULL,
	source_id varchar(64) NOT NULL,
	label varchar NOT NULL,
  data jsonb,
  metadata jsonb
);

SELECT create_hypertable('mytable', 'time');
  
CREATE UNIQUE INDEX mytable_source_label_time_idx ON mytable(source_id, label, "time" DESC);

ALTER TABLE mytable SET (
  timescaledb.compress,
  timescaledb.compress_segmentby = 'source_id, label',
  timescaledb.compress_orderby = 'time'
);

INSERT INTO mytable
SELECT
time + (INTERVAL '1 minute' * random()) AS time,
source_id,
label,
'{}' AS data,
'{}' AS metadata
FROM
generate_series('1990-01-01'::date, '1990-01-15', INTERVAL '1 hour') AS g1(time),
generate_series(1, 10, 1 ) AS g2(source_id),
generate_series(1, 10, 1 ) AS g3(label)
ORDER BY
time;

SELECT compress_chunk(i, if_not_compressed => true)  FROM show_chunks('mytable') i;

EXPLAIN (ANALYZE, VERBOSE)
INSERT INTO mytable (time, source_id, label, data, metadata)
VALUES ('1990-01-01 00:00:00+00', 'test', 'test', '0'::jsonb, '{}'::jsonb)
ON CONFLICT (source_id, label, time) DO UPDATE SET data = '{"update": true}', metadata = '{"update": true}';

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.

Stacktrace

(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007fe110cfa537 in __GI_abort () at abort.c:79
#2  0x000056014b1d7a13 in ExceptionalCondition (conditionName=conditionName@entry=0x7fe10528a97c "OidIsValid(opr)", errorType=errorType@entry=0x7fe105280562 "FailedAssertion", 
    fileName=fileName@entry=0x7fe105289bb0 "/home/jan/timescaledb/tsl/src/compression/compression.c", lineNumber=lineNumber@entry=1965) at assert.c:69
#3  0x00007fe10520954e in create_segment_filter_scankey (decompressor=decompressor@entry=0x7ffdad002e40, segment_filter_col_name=segment_filter_col_name@entry=0x56014d220500 "source_id", strategy=strategy@entry=3, 
    scankeys=scankeys@entry=0x56014d2202e8, num_scankeys=num_scankeys@entry=2, null_columns=null_columns@entry=0x7ffdad002ec8, value=94563589157496, is_null_check=false) at /home/jan/timescaledb/tsl/src/compression/compression.c:1965
#4  0x00007fe105209724 in build_scankeys (hypertable_id=63, hypertable_relid=94524, decompressor=..., key_columns=key_columns@entry=0x56014d2202c0, null_columns=null_columns@entry=0x7ffdad002ec8, slot=slot@entry=0x56014d233d60, 
    num_scankeys=num_scankeys@entry=0x7ffdad002ec4) at /home/jan/timescaledb/tsl/src/compression/compression.c:1890
#5  0x00007fe10520e791 in decompress_batches_for_insert (cis=<optimized out>, chunk=0x56014d1be4e8, slot=0x56014d233d60) at /home/jan/timescaledb/tsl/src/compression/compression.c:2016
#6  0x00007fe105335286 in ts_chunk_dispatch_get_chunk_insert_state (dispatch=dispatch@entry=0x56014d2348c0, point=0x56014d1bd450, slot=slot@entry=0x56014d233d60, on_chunk_changed=on_chunk_changed@entry=0x7fe105334b11 <on_chunk_insert_state_changed>, 
    data=data@entry=0x56014d23e2b0) at /home/jan/timescaledb/src/nodes/chunk_dispatch/chunk_dispatch.c:174
#7  0x00007fe10533541e in chunk_dispatch_exec (node=0x56014d23e2b0) at /home/jan/timescaledb/src/nodes/chunk_dispatch/chunk_dispatch.c:422
#8  0x000056014aefffba in ExecCustomScan (pstate=0x56014d23e2b0) at nodeCustom.c:115
#9  0x000056014aeeaba7 in ExecProcNodeInstr (node=0x56014d23e2b0) at execProcnode.c:480
#10 0x000056014aeeab7e in ExecProcNodeFirst (node=0x56014d23e2b0) at execProcnode.c:464
#11 0x00007fe10532fb16 in ExecProcNode (node=0x56014d23e2b0) at /home/jan/postgresql-sandbox/bin/REL_14_9_DEBUG/include/server/executor/executor.h:260
#12 ExecModifyTable (cs_node=0x56014d23d4c8, pstate=0x56014d23d9c8) at /home/jan/timescaledb/src/nodes/hypertable_modify.c:833
#13 0x00007fe10532fe32 in hypertable_modify_exec (node=<optimized out>) at /home/jan/timescaledb/src/nodes/hypertable_modify.c:182
#14 0x000056014aefffba in ExecCustomScan (pstate=0x56014d23d4c8) at nodeCustom.c:115
#15 0x000056014aeeaba7 in ExecProcNodeInstr (node=0x56014d23d4c8) at execProcnode.c:480
#16 0x000056014aeeab7e in ExecProcNodeFirst (node=0x56014d23d4c8) at execProcnode.c:464
#17 0x000056014aee37ba in ExecProcNode (node=0x56014d23d4c8) at ../../../src/include/executor/executor.h:260
#18 ExecutePlan (estate=estate@entry=0x56014d23d240, planstate=0x56014d23d4c8, use_parallel_mode=<optimized out>, operation=operation@entry=CMD_INSERT, sendTuples=sendTuples@entry=false, numberTuples=numberTuples@entry=0, 
    direction=ForwardScanDirection, dest=0x56014b49e440 <donothingDR>, execute_once=true) at execMain.c:1551
#19 0x000056014aee398f in standard_ExecutorRun (queryDesc=0x56014d240c38, direction=ForwardScanDirection, count=0, execute_once=execute_once@entry=true) at execMain.c:361
#20 0x000056014aee3a55 in ExecutorRun (queryDesc=queryDesc@entry=0x56014d240c38, direction=<optimized out>, count=count@entry=0, execute_once=execute_once@entry=true) at execMain.c:305
#21 0x000056014ae692dd in ExplainOnePlan (plannedstmt=plannedstmt@entry=0x56014d240ba0, into=into@entry=0x0, es=es@entry=0x56014d2be6a8, 
    queryString=queryString@entry=0x56014d09a3e0 "EXPLAIN (ANALYZE, VERBOSE)\nINSERT INTO mytable (time, source_id, label, data, metadata)\nVALUES ('1990-01-01 00:00:00+00', 'test', 'test', '0'::jsonb, '{}'::jsonb)\nON CONFLICT (source_id, label, time) "..., params=params@entry=0x0, queryEnv=queryEnv@entry=0x0, planduration=0x7ffdad003360, bufusage=0x0) at explain.c:593
#22 0x000056014ae696db in ExplainOneQuery (query=<optimized out>, cursorOptions=cursorOptions@entry=2048, into=into@entry=0x0, es=es@entry=0x56014d2be6a8, 
    queryString=0x56014d09a3e0 "EXPLAIN (ANALYZE, VERBOSE)\nINSERT INTO mytable (time, source_id, label, data, metadata)\nVALUES ('1990-01-01 00:00:00+00', 'test', 'test', '0'::jsonb, '{}'::jsonb)\nON CONFLICT (source_id, label, time) "..., 
    params=params@entry=0x0, queryEnv=0x0) at explain.c:410
#23 0x000056014ae6a1f8 in ExplainQuery (pstate=pstate@entry=0x56014d2be800, stmt=stmt@entry=0x56014d09bf68, params=params@entry=0x0, dest=dest@entry=0x56014d2a1e78) at ../../../src/include/nodes/nodes.h:604
#24 0x000056014b0a53ef in standard_ProcessUtility (pstmt=0x56014d2a0c60, 
    queryString=0x56014d09a3e0 "EXPLAIN (ANALYZE, VERBOSE)\nINSERT INTO mytable (time, source_id, label, data, metadata)\nVALUES ('1990-01-01 00:00:00+00', 'test', 'test', '0'::jsonb, '{}'::jsonb)\nON CONFLICT (source_id, label, time) "..., 
    readOnlyTree=<optimized out>, context=PROCESS_UTILITY_TOPLEVEL, params=0x0, queryEnv=0x0, dest=0x56014d2a1e78, qc=0x7ffdad003740) at utility.c:862
#25 0x00007fe10ea15745 in loader_process_utility_hook (pstmt=0x56014d2a0c60, 
    query_string=0x56014d09a3e0 "EXPLAIN (ANALYZE, VERBOSE)\nINSERT INTO mytable (time, source_id, label, data, metadata)\nVALUES ('1990-01-01 00:00:00+00', 'test', 'test', '0'::jsonb, '{}'::jsonb)\nON CONFLICT (source_id, label, time) "..., 
    readonly_tree=<optimized out>, context=PROCESS_UTILITY_TOPLEVEL, params=0x0, queryEnv=0x0, dest=0x56014d2a1e78, completion_tag=0x7ffdad003740) at /home/jan/timescaledb/src/loader/loader.c:639
#26 0x00007fe105304e15 in prev_ProcessUtility (args=args@entry=0x7ffdad003620) at /home/jan/timescaledb/src/process_utility.c:100
#27 0x00007fe105309c70 in timescaledb_ddl_command_start (pstmt=0x56014d2a0c60, query_string=<optimized out>, readonly_tree=<optimized out>, context=PROCESS_UTILITY_TOPLEVEL, params=0x0, queryEnv=<optimized out>, dest=0x56014d2a1e78, 
    completion_tag=0x7ffdad003740) at /home/jan/timescaledb/src/process_utility.c:4538
#28 0x000056014b0a57f6 in ProcessUtility (pstmt=pstmt@entry=0x56014d2a0c60, queryString=<optimized out>, readOnlyTree=<optimized out>, context=context@entry=PROCESS_UTILITY_TOPLEVEL, params=<optimized out>, queryEnv=<optimized out>, 
    dest=0x56014d2a1e78, qc=0x7ffdad003740) at utility.c:523
#29 0x000056014b0a2d45 in PortalRunUtility (portal=portal@entry=0x56014d106160, pstmt=0x56014d2a0c60, isTopLevel=<optimized out>, setHoldSnapshot=setHoldSnapshot@entry=true, dest=dest@entry=0x56014d2a1e78, qc=qc@entry=0x7ffdad003740) at pquery.c:1155
#30 0x000056014b0a3220 in FillPortalStore (portal=portal@entry=0x56014d106160, isTopLevel=isTopLevel@entry=true) at ../../../src/include/nodes/nodes.h:604
#31 0x000056014b0a3617 in PortalRun (portal=portal@entry=0x56014d106160, count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=true, run_once=run_once@entry=true, dest=dest@entry=0x56014d2a0cf8, altdest=altdest@entry=0x56014d2a0cf8, 
    qc=0x7ffdad003940) at pquery.c:760
#32 0x000056014b09f58c in exec_simple_query (
    query_string=query_string@entry=0x56014d09a3e0 "EXPLAIN (ANALYZE, VERBOSE)\nINSERT INTO mytable (time, source_id, label, data, metadata)\nVALUES ('1990-01-01 00:00:00+00', 'test', 'test', '0'::jsonb, '{}'::jsonb)\nON CONFLICT (source_id, label, time) "...) at postgres.c:1213
#33 0x000056014b0a15a9 in PostgresMain (argc=argc@entry=1, argv=argv@entry=0x7ffdad003b10, dbname=<optimized out>, username=<optimized out>) at postgres.c:4513
#34 0x000056014affec47 in BackendRun (port=port@entry=0x56014d0c23f0) at postmaster.c:4537
#35 0x000056014b001ea9 in BackendStartup (port=port@entry=0x56014d0c23f0) at postmaster.c:4259
#36 0x000056014b0020c5 in ServerLoop () at postmaster.c:1745
#37 0x000056014b00360b in PostmasterMain (argc=argc@entry=3, argv=argv@entry=0x56014d093a50) at postmaster.c:1417
#38 0x000056014af44d7b in main (argc=3, argv=0x56014d093a50) at main.c:209

Seems to be fixed by #6061

test2=# EXPLAIN (ANALYZE, VERBOSE)
INSERT INTO mytable (time, source_id, label, data, metadata)
VALUES ('1990-01-01 00:00:00+00', 'test', 'test', '0'::jsonb, '{}'::jsonb)
ON CONFLICT (source_id, label, time) DO UPDATE SET data = '{"update": true}', metadata = '{"update": true}';
                                                                            QUERY PLAN                                                                             
-------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Custom Scan (HypertableModify)  (cost=0.00..0.01 rows=1 width=250) (actual time=4.659..4.661 rows=0 loops=1)
   ->  Insert on public.mytable  (cost=0.00..0.01 rows=1 width=250) (actual time=4.659..4.661 rows=0 loops=1)
         Conflict Resolution: UPDATE
         Conflict Arbiter Indexes: mytable_source_label_time_idx
         Tuples Inserted: 1
         Conflicting Tuples: 0
         ->  Custom Scan (ChunkDispatch)  (cost=0.00..0.01 rows=1 width=250) (actual time=4.222..4.224 rows=1 loops=1)
               Output: '1990-01-01 01:00:00+01'::timestamp with time zone, 'test'::character varying(64), 'test'::character varying, '0'::jsonb, '{}'::jsonb
               ->  Result  (cost=0.00..0.01 rows=1 width=250) (actual time=0.003..0.004 rows=1 loops=1)
                     Output: '1990-01-01 01:00:00+01'::timestamp with time zone, 'test'::character varying(64), 'test'::character varying, '0'::jsonb, '{}'::jsonb
 Planning Time: 1.698 ms
 Execution Time: 5.266 ms
(12 rows)

TimescaleDB version affected

2.11.2 / 2.12.0-dev

PostgreSQL version used

14.9

What operating system did you use?

Debian 12

What installation method did you use?

Source

What platform did you run on?

On prem/Self-hosted

Relevant log output and stack trace

No response

How can we reproduce the bug?

See steps above

[svenklemm]

This is just an assertion hit, removing the assertion or running this on a build without assertions enabled will succeed.