[Bug]: Segfault when trying to insert into multiple compressed chunks at once #4778

antekresic · 2022-09-30T09:40:17Z

What type of bug is this?

Crash

What subsystems and features are affected?

Data ingestion

What happened?

While trying to insert into a hypertable where all the chunks were already compressed, I get a segfault. Interestingly, this only happens if there is a lot of compressed chunks in which you are trying to insert to.

Expected an error that I cannot insert into compressed chunks or something similar.

TimescaleDB version affected

2.8.0

PostgreSQL version used

14.2

What operating system did you use?

Arch

What installation method did you use?

Source

What platform did you run on?

On prem/Self-hosted

Relevant log output and stack trace

Program received signal SIGSEGV, Segmentation fault.
ExecCopySlot (dstslot=0x563beb070058, srcslot=0x563bebfcd7c0) at /usr/local/pgsql/include/server/executor/tuptable.h:480
480		dstslot->tts_ops->copyslot(dstslot, srcslot);

bt full:
#0  ExecCopySlot (dstslot=0x563beb070058, srcslot=0x563bebfcd7c0) at /usr/local/pgsql/include/server/executor/tuptable.h:480
No locals.
#1  0x00007f7e509b9af7 in ExecGetInsertNewTuple (relinfo=0x563beafcb1f0, planSlot=0x563bebfcd7c0) at /home/ante/go/src/github.com/timescale/timescaledb/src/nodes/hypertable_modify.c:1304
        newProj = 0x0
        econtext = 0x563beafcb6b0
#2  0x00007f7e509b8d91 in ExecModifyTable (pstate=0x563beafcafd8) at /home/ante/go/src/github.com/timescale/timescaledb/src/nodes/hypertable_modify.c:887
        node = 0x563beafcafd8
        estate = 0x563beafca830
        operation = CMD_INSERT
        resultRelInfo = 0x563beafcb1f0
        subplanstate = 0x563beafcb6b0
        slot = 0x563bebfcd7c0
        planSlot = 0x563bebfcd7c0
        oldSlot = 0x7ffcd115b950
        tupleid = 0x0
        tuple_ctid = {ip_blkid = {bi_hi = 60156, bi_lo = 22075}, ip_posid = 0}
        oldtupdata = {t_len = 3507861840, t_self = {ip_blkid = {bi_hi = 32764, bi_lo = 0}, ip_posid = 19640}, t_tableOid = 32638, t_data = 0x563beafcafd8}
        oldtuple = 0x0
        relinfos = 0x0
        lc = 0xe700000001
        cds = 0x563beafcb6b0
        __func__ = "ExecModifyTable"
#3  0x00007f7e509b78cc in hypertable_modify_exec (node=0x563beafcaad8) at /home/ante/go/src/github.com/timescale/timescaledb/src/nodes/hypertable_modify.c:181
        mtstate = 0x563beafcafd8
#4  0x0000563be914e72f in ExecCustomScan (pstate=0x563beafcaad8) at nodeCustom.c:115
        node = 0x563beafcaad8
#5  0x0000563be912f9cf in ExecProcNodeFirst (node=0x563beafcaad8) at execProcnode.c:463
No locals.
#6  0x0000563be91235ff in ExecProcNode (node=0x563beafcaad8) at ../../../src/include/executor/executor.h:257
No locals.
#7  0x0000563be91261bf in ExecutePlan (estate=0x563beafca830, planstate=0x563beafcaad8, use_parallel_mode=false, operation=CMD_INSERT, sendTuples=false, numberTuples=0, direction=ForwardScanDirection, dest=0x563beaf6dac0, execute_once=true) at execMain.c:1551
        slot = 0x7ffcd115ba90
        current_tuple_count = 0
#8  0x0000563be9123d26 in standard_ExecutorRun (queryDesc=0x563beafd74b0, direction=ForwardScanDirection, count=0, execute_once=true) at execMain.c:361
        estate = 0x563beafca830
        operation = CMD_INSERT
        dest = 0x563beaf6dac0
        sendTuples = false
        oldcontext = 0x563beafd7390
        __func__ = "standard_ExecutorRun"
#9  0x00007f7e5a369e45 in pgss_ExecutorRun (queryDesc=0x563beafd74b0, direction=ForwardScanDirection, count=0, execute_once=true) at pg_stat_statements.c:1003
        _save_exception_stack = 0x7ffcd115bd40
        _save_context_stack = 0x0
        _local_sigjmp_buf = {{__jmpbuf = {140723816350872, 8122572234603318003, 0, 140723816350944, 94815321035288, 140180658040832, 8122572234622192371, 8195489398898641651}, __mask_was_saved = 0, __saved_mask = {__val = {384, 3507862368, 94815345701632, 94815345485584, 
                94815345701248, 384, 94815345701632, 140723816348576, 94815313454806, 94561942467472, 94815345537936, 4311810352, 94815345485584, 140723816348624, 140180656135506, 0}}}}
        _do_rethrow = false
#10 0x0000563be9123afc in ExecutorRun (queryDesc=0x563beafd74b0, direction=ForwardScanDirection, count=0, execute_once=true) at execMain.c:303
No locals.
#11 0x0000563be939de34 in ProcessQuery (plan=0x563beaf6da28, sourceText=0x563beae99ae0 "insert into metric_5m (time, series_id, value) select t, s,1 from generate_series(NOW(), NOW() + interval '1 day', '10s') t cross join generate_series(1,100, 1) s;", params=0x0, 
    queryEnv=0x0, dest=0x563beaf6dac0, qc=0x7ffcd115bec0) at pquery.c:160
        queryDesc = 0x563beafd74b0
#12 0x0000563be939f9bf in PortalRunMulti (portal=0x563beaf07ac0, isTopLevel=true, setHoldSnapshot=false, dest=0x563beaf6dac0, altdest=0x563beaf6dac0, qc=0x7ffcd115bec0) at pquery.c:1274
        pstmt = 0x563beaf6da28
        stmtlist_item__state = {l = 0x563beafd5a50, i = 0}
        active_snapshot_set = true
        stmtlist_item = 0x563beafd5a68
#13 0x0000563be939eeb9 in PortalRun (portal=0x563beaf07ac0, count=9223372036854775807, isTopLevel=true, run_once=true, dest=0x563beaf6dac0, altdest=0x563beaf6dac0, qc=0x7ffcd115bec0) at pquery.c:788
        _save_exception_stack = 0x7ffcd115bfd0
        _save_context_stack = 0x0
        _local_sigjmp_buf = {{__jmpbuf = {140723816350872, 8122572234743827187, 0, 140723816350944, 94815321035288, 140180658040832, 8122572234838199027, 2537598281310227187}, __mask_was_saved = 0, __saved_mask = {__val = {94815318016269, 13, 112, 3914756389, 
                94815345105712, 94815344236992, 94815345105600, 112, 94815345105712, 140723816349184, 94815310333270, 140723816349216, 12504895625, 0, 94815345105600, 94815344687808}}}}
        _do_rethrow = false
        result = false
        nprocessed = 19499010803
        saveTopTransactionResourceOwner = 0x563beaed2dc0
        saveTopTransactionContext = 0x563beafbeeb0
        saveActivePortal = 0x0
        saveResourceOwner = 0x563beaed2dc0
        savePortalContext = 0x0
        saveMemoryContext = 0x563beafbeeb0
        __func__ = "PortalRun"
#14 0x0000563be9397dd1 in exec_simple_query (query_string=0x563beae99ae0 "insert into metric_5m (time, series_id, value) select t, s,1 from generate_series(NOW(), NOW() + interval '1 day', '10s') t cross join generate_series(1,100, 1) s;") at postgres.c:1214
        snapshot_set = true
        per_parsetree_context = 0x0
        plantree_list = 0x563beafd5a50
        parsetree = 0x563beae9b908
        commandTag = CMDTAG_INSERT
        qc = {commandTag = CMDTAG_UNKNOWN, nprocessed = 0}
        querytree_list = 0x563beafd59a8
        portal = 0x563beaf07ac0
        receiver = 0x563beaf6dac0
        format = 0
        parsetree_item__state = {l = 0x563beae9b940, i = 0}
        dest = DestRemote
        oldcontext = 0x563beafbeeb0
        parsetree_list = 0x563beae9b940
        parsetree_item = 0x563beae9b958
        save_log_statement_stats = false
        was_logged = false
        use_implicit_block = false
        msec_str = "\000\277\025\321\374\177\000\000\215\271\032\351;V\000\000\000\000\000\000\000\000\000\000\220\277\025\321\374\177\000"
        __func__ = "exec_simple_query"
#15 0x0000563be939cc2c in PostgresMain (argc=1, argv=0x7ffcd115c0e0, dbname=0x563beaecb9a0 "postgres", username=0x563beaecb978 "postgres") at postgres.c:4486
        query_string = 0x563beae99ae0 "insert into metric_5m (time, series_id, value) select t, s,1 from generate_series(NOW(), NOW() + interval '1 day', '10s') t cross join generate_series(1,100, 1) s;"
        firstchar = 81
        input_message = {data = 0x563beae99ae0 "insert into metric_5m (time, series_id, value) select t, s,1 from generate_series(NOW(), NOW() + interval '1 day', '10s') t cross join generate_series(1,100, 1) s;", len = 164, maxlen = 1024, cursor = 164}
        local_sigjmp_buf = {{__jmpbuf = {140723816350872, 8122572234420865779, 0, 140723816350944, 94815321035288, 140180658040832, 8122572234710272755, 2537598282608626419}, __mask_was_saved = 1, __saved_mask = {__val = {4194304, 94815344210272, 94815344217352, 0, 0, 
                94815315035466, 67108864, 140180650793472, 18446744066192964103, 0, 0, 0, 0, 24, 140723816349920, 140723816349856}}}}
        send_ready_for_query = false
        idle_in_transaction_timeout_enabled = false
        idle_session_timeout_enabled = false
        __func__ = "PostgresMain"
#16 0x0000563be92c3436 in BackendRun (port=0x563beaec4610) at postmaster.c:4530
        av = {0x563be9708527 "postgres", 0x0}
        ac = 1
#17 0x0000563be92c2c9d in BackendStartup (port=0x563beaec4610) at postmaster.c:4252
        bn = 0x563beaec2d00
        pid = 0
        __func__ = "BackendStartup"
#18 0x0000563be92bea26 in ServerLoop () at postmaster.c:1745
        port = 0x563beaec4610
        i = 0
        rmask = {fds_bits = {32, 0 <repeats 15 times>}}
        selres = 1
        now = 1664530216
        readmask = {fds_bits = {96, 0 <repeats 15 times>}}
        nSockets = 7
        last_lockfile_recheck_time = 1664530179
        last_touch_time = 1664530107
        __func__ = "ServerLoop"
#19 0x0000563be92be19b in PostmasterMain (argc=8, argv=0x563beae92fd0) at postmaster.c:1417
        opt = -1
        status = 0
        userDoption = 0x563beaeb69f0 "/tmp/tsdb"
        listen_addr_saved = true
        i = 64
        output_config_variable = 0x0
        __func__ = "PostmasterMain"
#20 0x0000563be91afc81 in main (argc=8, argv=0x563beae92fd0) at main.c:209
        do_check_root = true
Detaching from program: /usr/local/pgsql/bin/postgres, process 77680
[Inferior 1 (process 77680) detached]

How can we reproduce the bug?

postgres=# create extension timescaledb ;
postgres=# create table metric_5m (time TIMESTAMPTZ NOT NULL, value DOUBLE PRECISION NOT NULL, series_id BIGINT NOT NULL);
postgres=# select create_hypertable('metric_5m'::regclass, 'time'::name, chunk_time_interval=>interval '5m', create_default_indexes=> false);
postgres=# alter table metric_5m set (timescaledb.compress,
                timescaledb.compress_segmentby = 'series_id',
                timescaledb.compress_orderby = 'time, value');
postgres=# insert into metric_5m (time, series_id, value) select t, s,1 from generate_series(NOW(), NOW() + interval '1 day', '10s') t cross join generate_series(1,100, 1) s;
postgres=# SELECT compress_chunk(i, true) from show_chunks('metric_5m') i;
postgres=# insert into metric_5m (time, series_id, value) select t, s,1 from generate_series(NOW(), NOW() + interval '1 day', '10s') t cross join generate_series(1,100, 1) s;
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.
!?>

sb230132 · 2022-10-06T12:32:55Z

Hi @antekresic
Segmentation fault is happening because there seems to be a memory corruption.
Increasing work_mem possibly resolves the issue.

Let me try to understand more on what and where the corruption is.

INSERT into compressed hypertable with number of open chunks greater than ts_guc_max_open_chunks_per_insert causes segementation fault. New row which needs to be inserted into compressed chunk has to be compressed. Memory required as part of compressing a row is allocated from RowCompressor::per_row_ctx memory context. Once row is compressed, ExecInsert() is called, where memory from same context is used to allocate and free it instead of using "Executor State". This causes a corruption in memory. Fixes: timescale#4778

INSERT into compressed hypertable with number of open chunks greater than ts_guc_max_open_chunks_per_insert causes segementation fault. New row which needs to be inserted into compressed chunk has to be compressed. Memory required as part of compressing a row is allocated from RowCompressor::per_row_ctx memory context. Once row is compressed, ExecInsert() is called, where memory from same context is used to allocate and free it instead of using "Executor State". This causes a corruption in memory. Fixes: #4778

antekresic added the bug label Sep 30, 2022

svenklemm added the segfault Segmentation fault label Sep 30, 2022

sb230132 self-assigned this Oct 6, 2022

sb230132 mentioned this issue Oct 10, 2022

Fix segmentation fault during INSERT into compressed hypertable. #4807

Merged

sb230132 closed this as completed in #4807 Oct 13, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Bug]: Segfault when trying to insert into multiple compressed chunks at once #4778

[Bug]: Segfault when trying to insert into multiple compressed chunks at once #4778

antekresic commented Sep 30, 2022 •

edited

Loading

sb230132 commented Oct 6, 2022

[Bug]: Segfault when trying to insert into multiple compressed chunks at once #4778

[Bug]: Segfault when trying to insert into multiple compressed chunks at once #4778

Comments

antekresic commented Sep 30, 2022 • edited Loading

What type of bug is this?

What subsystems and features are affected?

What happened?

TimescaleDB version affected

PostgreSQL version used

What operating system did you use?

What installation method did you use?

What platform did you run on?

Relevant log output and stack trace

How can we reproduce the bug?

sb230132 commented Oct 6, 2022

antekresic commented Sep 30, 2022 •

edited

Loading