timescaledb [Bug]: assertion failure in get_appendrel

[Bug]: assertion failure in get_appendrel_parampathinfo

Open svenklemm opened this issue 2 years ago • 3 comments

What type of bug is this?

Other

What subsystems and features are affected?

Query planner

What happened?

sqlsmith failed with an assertion failure

Link to failed run: https://github.com/timescale/timescaledb/runs/5608836995?check_suite_focus=true

TimescaleDB version affected

master

PostgreSQL version used

14.2

What operating system did you use?

Ubuntu 20.04

What installation method did you use?

Source

What platform did you run on?

On prem/Self-hosted

Relevant log output and stack trace

#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
(gdb) #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
        set = {__val = {4194304, 0, 0, 0, 0, 94835184952096, 
            4611686018427387904, 0, 0, 140028848755930, 0, 94835184952142, 
            128, 0, 140724912339648, 140028842829120}}
        pid = <optimized out>
        tid = <optimized out>
        ret = <optimized out>
#1  0x00007f5b015b9859 in __GI_abort () at abort.c:79
        save_stage = 1
        act = {__sigaction_handler = {sa_handler = 0x7f5b0174cbf7, 
            sa_sigaction = 0x7f5b0174cbf7}, sa_mask = {__val = {1, 
              140028843188254, 3, 140724912339828, 12, 140028843188258, 2, 
              3473460813870661632, 7292510206346934584, 140724912339936, 
              7291948136861554232, 94835309690808, 8248173052380786944, 
              140724912339920, 1596, 20}}, sa_flags = 308886496, 
          sa_restorer = 0x564089e05638}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x0000564089ca8fb8 in ExceptionalCondition (
    conditionName=conditionName@entry=0x564089e05638 "bms_is_subset(appendrel->lateral_relids, required_outer)", 
    errorType=errorType@entry=0x564089cff00b "FailedAssertion", 
    fileName=fileName@entry=0x564089e056a8 "relnode.c", 
    lineNumber=lineNumber@entry=1596) at assert.c:69
No locals.
#3  0x0000564089ad58aa in get_appendrel_parampathinfo (
    appendrel=appendrel@entry=0x564090f23fb8, 
    required_outer=required_outer@entry=0x0) at relnode.c:1596
        ppi = <optimized out>
#4  0x0000564089ac93ab in create_append_path (root=root@entry=0x56408aacd988, 
    rel=rel@entry=0x564090f23fb8, subpaths=0x56408f1b7f40, 
    partial_subpaths=partial_subpaths@entry=0x0, pathkeys=pathkeys@entry=0x0, 
    required_outer=required_outer@entry=0x0, parallel_workers=0, 
    parallel_aware=false, rows=rows@entry=-1) at pathnode.c:1274
        pathnode = 0x56408f1b8210
        l = <optimized out>
#5  0x0000564089a8166e in add_paths_to_append_rel (
    root=root@entry=0x56408aacd988, rel=rel@entry=0x564090f23fb8, 
    live_childrels=live_childrels@entry=0x56408f19c790) at allpaths.c:1457
        subpaths = 0x56408f1b7f40
        subpaths_valid = <optimized out>
        partial_subpaths = 0x56408f1b7f98
        pa_partial_subpaths = 0x56408f1b7ff0
        pa_nonpartial_subpaths = 0x0
        partial_subpaths_valid = <optimized out>
        pa_subpaths_valid = <optimized out>
        all_child_pathkeys = <optimized out>
        all_child_outers = <optimized out>
        l = <optimized out>
        partial_rows = -1
#6  0x0000564089a82066 in set_append_rel_pathlist (rte=0x56408daf8840, 
    rti=12, rel=0x564090f23fb8, root=0x56408aacd988) at allpaths.c:1269
        parentRTindex = 12
        live_childrels = <optimized out>
        l = <optimized out>
        parentRTindex = <optimized out>
        live_childrels = <optimized out>
        l = <optimized out>
        l__state = {l = <optimized out>, i = <optimized out>}
        appinfo = <optimized out>
        childRTindex = <optimized out>
        childRTE = <optimized out>
        childrel = <optimized out>
#7  set_rel_pathlist (root=0x56408aacd988, rel=0x564090f23fb8, rti=12, 
    rte=0x56408daf8840) at allpaths.c:481
        __func__ = "set_rel_pathlist"
#8  0x0000564089a828e1 in set_base_rel_pathlists (root=0x56408aacd988)
    at allpaths.c:353
        rel = <optimized out>
        rti = 12
        rti = <optimized out>
        rel = <optimized out>
#9  make_one_rel (root=root@entry=0x56408aacd988, 
    joinlist=joinlist@entry=0x564090f25158) at allpaths.c:223
        rel = <optimized out>
        rti = <optimized out>
        total_pages = <optimized out>
#10 0x0000564089aa8366 in query_planner (root=root@entry=0x56408aacd988, 
    qp_callback=qp_callback@entry=0x564089aa9060 <standard_qp_callback>, 
    qp_extra=qp_extra@entry=0x7ffd12694280) at planmain.c:276
        parse = 0x56408bf7c6e0
        joinlist = 0x564090f25158
        final_rel = <optimized out>
        __func__ = "query_planner"
#11 0x0000564089aad777 in grouping_planner (root=<optimized out>, 
    tuple_fraction=<optimized out>) at planner.c:1442
        sort_input_targets = 0x564090f209c0
        sort_input_target_parallel_safe = <optimized out>

        grouping_target = <optimized out>
warning: Can't open file /dev/shm/PostgreSQL.421526852 during file-backed mapping note processing
        scanjoin_target = <optimized out>

        activeWindows = <optimized out>
warning: Can't open file /dev/shm/PostgreSQL.3505831422 during file-backed mapping note processing
        qp_extra = {activeWindows = 0x0, groupClause = 0x0}

        sort_input_targets_contain_srfs = 0x0
warning: Can't open file /dev/shm/PostgreSQL.417915192 during file-backed mapping note processing
        have_grouping = <optimized out>

        wflists = <optimized out>
warning: Can't open file /dev/zero (deleted) during file-backed mapping note processing
        gset_data = 0x0

        sort_input_target = <optimized out>
warning: Can't open file /SYSV001486d9 (deleted) during file-backed mapping note processing
        grouping_targets = 0x564089aba387 <reduce_outer_joins_pass2+1127>
50	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
        grouping_target_parallel_safe = <optimized out>
        scanjoin_targets = 0x0
        scanjoin_target_parallel_safe = <optimized out>
        grouping_targets_contain_srfs = 0x564090f21030
        scanjoin_targets_contain_srfs = 0x0
        scanjoin_target_same_exprs = <optimized out>
        parse = 0x56408bf7c6e0
        offset_est = 0
        count_est = 53
        limit_tuples = 53
        have_postponed_srfs = false
        final_target = <optimized out>
        final_targets = 0x56408aacd988
        final_targets_contain_srfs = 0x56408daf8288
        final_target_parallel_safe = <optimized out>
        current_rel = <optimized out>
        final_rel = <optimized out>
        extra = {limit_needed = 48, limit_tuples = 0, count_est = 0, 
          offset_est = 94835187244605}
        lc = <optimized out>
        __func__ = "grouping_planner"
#12 0x0000564089ab0569 in subquery_planner (glob=glob@entry=0x56408eca0198, 
    parse=parse@entry=0x56408bf7c6e0, parent_root=parent_root@entry=0x0, 
    hasRecursion=hasRecursion@entry=false, 
    tuple_fraction=tuple_fraction@entry=0) at planner.c:1019
        root = 0x56408aacd988
        newWithCheckOptions = <optimized out>
        newHaving = <optimized out>
        hasOuterJoins = <optimized out>
        hasResultRTEs = <optimized out>
        final_rel = <optimized out>
        l = <optimized out>
#13 0x0000564089ab09d3 in standard_planner (parse=0x56408bf7c6e0, 
    query_string=<optimized out>, cursorOptions=2048, 
    boundParams=<optimized out>) at planner.c:400
        result = <optimized out>
        glob = 0x56408eca0198
        tuple_fraction = 0
        root = <optimized out>
        final_rel = <optimized out>
        best_path = <optimized out>
        top_plan = <optimized out>
        lp = <optimized out>
        lr = <optimized out>
#14 0x00007f5af7881f05 in timescaledb_planner (parse=0x56408bf7c6e0, 
    query_string=0x56408aacdda0 "select  \n  subq_2.c4 as c0, \n  subq_0.c0 as c1, \n  subq_2.c6 as c2, \n  subq_2.c1 as c3, \n  subq_0.c1 as c4, \n  subq_0.c0 as c5, \n  subq_0.c3 as c6\nfrom \n  (select  \n        sample_0.id as c0, \n       "..., cursor_opts=2048, bound_params=0x0)
    at /home/runner/work/timescaledb/timescaledb/src/planner.c:415
        context = {rootquery = 0x56408bf7c6e0, num_distributed_tables = 4}
        _save_exception_stack = 0x7ffd12694920
        _save_context_stack = 0x0
        _local_sigjmp_buf = {{__jmpbuf = {0, -5117897507948843286, 
              94835204480416, 2048, 0, 0, -5117897507938357526, 
              -5064763322679677206}, __mask_was_saved = 0, __saved_mask = {
              __val = {0, 0, 8248173052380786944, 2551, 2, 1, 94835226167008, 
                94835226180480, 1, 0, 94835188148940, 140724912342405, 208, 
                94835204480416, 94835204478032, 64}}}}
        _do_rethrow = <optimized out>
        stmt = <optimized out>
        lc = <optimized out>
        reset_fetcher_type = false
        __func__ = "timescaledb_planner"
#15 0x0000564089b8852c in pg_plan_query (querytree=0x56408bf7c6e0, 
    query_string=0x56408aacdda0 "select  \n  subq_2.c4 as c0, \n  subq_0.c0 as c1, \n  subq_2.c6 as c2, \n  subq_2.c1 as c3, \n  subq_0.c1 as c4, \n  subq_0.c0 as c5, \n  subq_0.c3 as c6\nfrom \n  (select  \n        sample_0.id as c0, \n       "..., cursorOptions=2048, boundParams=0x0) at postgres.c:847
        plan = <optimized out>
#16 0x0000564089b88621 in pg_plan_queries (querytrees=0x56408ec990e8, 
    query_string=query_string@entry=0x56408aacdda0 "select  \n  subq_2.c4 as c0, \n  subq_0.c0 as c1, \n  subq_2.c6 as c2, \n  subq_2.c1 as c3, \n  subq_0.c1 as c4, \n  subq_0.c0 as c5, \n  subq_0.c3 as c6\nfrom \n  (select  \n        sample_0.id as c0, \n       "..., cursorOptions=cursorOptions@entry=2048, 
    boundParams=boundParams@entry=0x0) at postgres.c:939
        query = <optimized out>
        stmt = <optimized out>
        query_list__state = {l = 0x56408ec990e8, i = 0}
        stmt_list = 0x0
        query_list = <optimized out>
#17 0x0000564089b88a22 in exec_simple_query (
    query_string=0x56408aacdda0 "select  \n  subq_2.c4 as c0, \n  subq_0.c0 as c1, \n  subq_2.c6 as c2, \n  subq_2.c1 as c3, \n  subq_0.c1 as c4, \n  subq_0.c0 as c5, \n  subq_0.c3 as c6\nfrom \n  (select  \n        sample_0.id as c0, \n       "...) at postgres.c:1133
        snapshot_set = true
        per_parsetree_context = 0x0
        plantree_list = <optimized out>
        parsetree = <optimized out>
        commandTag = CMDTAG_SELECT
        qc = {commandTag = CMDTAG_UNKNOWN, nprocessed = 94832877895690}
        querytree_list = <optimized out>
        portal = <optimized out>
        receiver = <optimized out>
        format = 0
        parsetree_item__state = {l = 0x56408bf7c570, i = 0}
        dest = DestRemote
        oldcontext = 0x56408ab6e360
        parsetree_list = 0x56408bf7c570
        parsetree_item = <optimized out>
        save_log_statement_stats = false
        was_logged = false
        use_implicit_block = false
        msec_str = "\000\000\000\000\000\000\000\000\000\061\033\301\260ewr\000\000\000\000\000\000\000\000{\313ˉ@V\000"
        __func__ = "exec_simple_query"
#18 0x0000564089b8a63d in PostgresMain (argc=argc@entry=1, 
    argv=argv@entry=0x7ffd12694b00, dbname=<optimized out>, 
    username=<optimized out>) at postgres.c:4486
        query_string = 0x56408aacdda0 "select  \n  subq_2.c4 as c0, \n  subq_0.c0 as c1, \n  subq_2.c6 as c2, \n  subq_2.c1 as c3, \n  subq_0.c1 as c4, \n  subq_0.c0 as c5, \n  subq_0.c3 as c6\nfrom \n  (select  \n        sample_0.id as c0, \n       "...
        firstchar = <optimized out>
        input_message = {
          data = 0x56408aacdda0 "select  \n  subq_2.c4 as c0, \n  subq_0.c0 as c1, \n  subq_2.c6 as c2, \n  subq_2.c1 as c3, \n  subq_0.c1 as c4, \n  subq_0.c0 as c5, \n  subq_0.c3 as c6\nfrom \n  (select  \n        sample_0.id as c0, \n       "..., len = 2552, maxlen = 4096, cursor = 2552}
        local_sigjmp_buf = {{__jmpbuf = {0, -5117897508053700886, 2618534318, 
              94835204670864, 3, 94835192890888, -5117897507902705942, 
              -1476436348204339478}, __mask_was_saved = 1, __saved_mask = {
              __val = {4194304, 140724912353233, 0, 0, 140724912343776, 
                140028841379520, 8248173052380786944, 206158430232, 
                94835189993811, 206158430240, 140724912343696, 
                140724912343504, 8248173052380786944, 94835204633904, 0, 6}}}}
        send_ready_for_query = false
        idle_in_transaction_timeout_enabled = false
        idle_session_timeout_enabled = false
        __func__ = "PostgresMain"
#19 0x0000564089af7df3 in BackendRun (port=<optimized out>, 
    port=<optimized out>) at postmaster.c:4530
        av = {0x564089d0e7b2 "postgres", 0x0}
        ac = 1
        av = {<optimized out>, <optimized out>}
        ac = <optimized out>
#20 BackendStartup (port=<optimized out>) at postmaster.c:4252
        bn = <optimized out>
        pid = <optimized out>
        bn = <optimized out>
        pid = <optimized out>
        __func__ = "BackendStartup"
        __errno_location = <optimized out>
        __errno_location = <optimized out>
        save_errno = <optimized out>
        __errno_location = <optimized out>
        __errno_location = <optimized out>
#21 ServerLoop () at postmaster.c:1745
        port = <optimized out>
        i = <optimized out>
        rmask = {fds_bits = {128, 0 <repeats 15 times>}}
        selres = <optimized out>
        now = <optimized out>
        readmask = {fds_bits = {224, 0 <repeats 15 times>}}
        nSockets = 8
        last_lockfile_recheck_time = 1647657676
        last_touch_time = 1647656834
        __func__ = "ServerLoop"
#22 0x0000564089af8d79 in PostmasterMain (argc=argc@entry=6, 
    argv=argv@entry=0x56408aac5bb0) at postmaster.c:1417
        opt = <optimized out>
        status = <optimized out>
        userDoption = <optimized out>
        listen_addr_saved = true
        i = <optimized out>
        output_config_variable = <optimized out>
        __func__ = "PostmasterMain"
#23 0x000056408982e2a2 in main (argc=6, argv=0x56408aac5bb0) at main.c:209
        do_check_root = <optimized out>
(gdb) quit
           PID: 14440 (postgres)
           UID: 1001 (runner)
           GID: 121 (docker)
        Signal: 6 (ABRT)
     Timestamp: Sat 2022-03-19 02:44:46 UTC (19min ago)
  Command Line: postgres: runner smith [local] SELECT
    Executable: /home/runner/postgresql/bin/postgres
 Control Group: /system.slice/runner-provisioner.service
          Unit: runner-provisioner.service
         Slice: system.slice
       Boot ID: 05574c07d10b4e328f5a43cbe501c110
    Machine ID: 6fe698402f044602bf038833560abb94
      Hostname: fv-az213-324
       Storage: /var/lib/systemd/coredump/core.postgres.1001.05574c07d10b4e328f5a43cbe501c110.14440.1647657886000000000000.lz4
       Message: Process 14440 (postgres) of user 1001 dumped core.
                
                Stack trace of thread 14440:
                #0  0x00007f5b015da03b __GI_raise (libc.so.6 + 0x4303b)
                #1  0x00007f5b015b9859 __GI_abort (libc.so.6 + 0x22859)
                #2  0x0000564089ca8fb8 n/a (/home/runner/postgresql/bin/postgres + 0x5d3fb8)

How can we reproduce the bug?

Link to failed run: https://github.com/timescale/timescaledb/runs/5608836995?check_suite_focus=true

Mar 20 '22 05:03 svenklemm

Not seen again, hence closing.

Jul 26 '22 11:07 RafiaSabih

Still happening: https://github.com/timescale/timescaledb/runs/7552425996?check_suite_focus=true

Jul 28 '22 05:07 svenklemm

Another one: https://github.com/timescale/timescaledb/runs/7816309184?check_suite_focus=true

Aug 13 '22 07:08 svenklemm

timescaledb timescaledb copied to clipboard

[Bug]: assertion failure in get_appendrel_parampathinfo

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?

timescaledb
timescaledb copied to clipboard