[Bug]: Attribute number 7 exceeds number of columns 4

[MKrkkl]

What type of bug is this?

Unexpected error

What subsystems and features are affected?

Gapfill

What happened?

I have pg 14 ts 2.8 latest ha image running on docker. docker pull timescale/timescaledb-ha:pg14-ts2.8-latest

Please check below for details to generate test data set.

Using bucket_gapfill and case condition in the same query gives

Attribute number 7 exceeds number of columns 4 error

SELECT time_bucket_gapfill('1 hour', time) as time, CASE WHEN agg in (0,3) THEN max(value) ELSE null END as max, CASE WHEN agg in (0,2) THEN min(value) ELSE null END as min FROM hourly WHERE agg in (0,2,3) and signal in (2) AND level_a = 1 AND level_b = -1 AND time >= '2022-10-01T00:00:00Z' AND time < '2022-10-01T05:59:59Z' GROUP BY 1, agg order by 1;

But if I change last line to GROUP BY 1, agg, level_a, level_b, level_c order by 1; it will work. Why it needs those levels to be part of group by to get it working?

this works as well:

SELECT time_bucket_gapfill('1 hour', time) as time, max(value), min(value), agg FROM hourly WHERE agg in (0,2,3) and signal in (2) AND level_a = 1 AND level_b = -1 AND time >= '2022-10-01T00:00:00Z' AND time < '2022-10-01T05:59:59Z' GROUP BY 1, agg order by 1;

and this

SELECT time_bucket('1 hour', time) as time, CASE WHEN agg in (0,3) THEN max(value) ELSE null END as max, CASE WHEN agg in (0,2) THEN min(value) ELSE null END as min FROM hourly WHERE agg in (0,2,3) and signal in (2) AND level_a = 1 AND level_b = -1 AND time >= '2022-10-01T00:00:00Z' AND time < '2022-10-01T05:59:59Z' GROUP BY 1, agg order by 1;

TimescaleDB version affected

2.8 latest

PostgreSQL version used

14 (latest?)

What operating system did you use?

Ubuntu 20.04.4 LTS x64

What installation method did you use?

Docker

What platform did you run on?

On prem/Self-hosted

Relevant log output and stack trace

No response

How can we reproduce the bug?

CREATE TABLE hourly (
    time timestamptz NOT NULL,
    signal smallint NOT NULL,
    value real,
    level_a integer,
    level_b smallint,
    level_c smallint,
    agg smallint
);

SELECT create_hypertable('hourly', 'time');

INSERT into hourly(time, signal,value, level_a, level_b, level_c, agg) values 
('2022-10-01T00:00:00Z', 2, 685, 1, -1, -1, 2 ),
('2022-10-01T00:00:00Z', 2, 686, 1, -1, -1, 3 ),
('2022-10-01T02:00:00Z', 2, 686, 1, -1, -1, 2 ),
('2022-10-01T02:00:00Z', 2, 687, 1, -1, -1, 3 ),
('2022-10-01T03:00:00Z', 2, 687, 1, -1, -1, 2 ),
('2022-10-01T03:00:00Z', 2, 688, 1, -1, -1, 3 );

SELECT
 time_bucket_gapfill('1 hour', time) as time,
 CASE WHEN agg in (0,3) THEN max(value) ELSE null END as max,
 CASE WHEN agg in (0,2) THEN min(value) ELSE null END as min
 FROM hourly WHERE agg in (0,2,3) and signal in (2) AND level_a = 1 AND level_b = -1 AND time >= '2022-10-01T00:00:00Z' AND time < '2022-10-01T05:59:59Z' 
 GROUP BY 1,  agg order by 1;

[konskov]

Hi @MKrkkl , thank you for providing reproduction steps, I was able to reproduce the issue

[kgyrtkirk]

@konskov: I'm debugging/experimenting with this a bit...I'll assign it to myself for now; and see how far I could get with it :)

[kgyrtkirk]

I was writing some summary earlier about what's the issue here; but I guess I've not fully finished it (got an idea I guess)...

but anyway I'll write down so far what I know/think about this:

the issue is caused by the following:

• gapfill_plan copies the aggregations into itself - and thus copies all the expressions from the groupaggregate
• the logic which processes the output columns is adding the original expr for both of the operators here
  • by doing so the Aggregate will also make a projection on the columns
• in case the expr references some column which are not part of the query output but is being used; the projection in the Sort will not forward it
  • further more - there might be issues arising from the fact that the expr-s might change the output order of the columns - and even thru the query is processed; different data might be used

[...]
 Custom Scan (GapFill)  (cost=14.49..14.53 rows=1 width=50)
   Output: (time_bucket_gapfill('01:00:00'::interval, "time", NULL::timestamp with time zone, NULL::timestamp with time zone)), (CASE WHEN (agg = ANY ('{0,3}'::integer[])) THEN min(value) ELSE NULL::real END), (CASE WHEN (agg = ANY ('{0,3}'::integer[])) THEN '...'::text ELSE NULL::text END), 1, agg
   ->  GroupAggregate  (cost=14.49..14.52 rows=1 width=0)
         Output: (time_bucket_gapfill('01:00:00'::interval, _hyper_1_1_chunk."time", NULL::timestamp with time zone, NULL::timestamp with time zone)), CASE WHEN (_hyper_1_1_chunk.agg = ANY ('{0,3}'::integer[])) THEN min(_hyper_1_1_chunk.value) ELSE NULL::real END
[...]

I think the fix would be to process the incoming expr so that all basic aggregates are computed by the Aggregate; and the possible group column dependent aggregate is only evaluated during the Custom Scan projection evaluation

[kgyrtkirk]

my wip branch which iirc fixed this issue (and possibly others similar to this) is here:
https://github.com/timescale/timescaledb/compare/main...kgyrtkirk:timescaledb:gapfill?expand=0

wasn't had the chance to clean it up / finalize for months now

[akuzm]

Still fails with a slightly simplified query:

WITH hourly(time, signal, value, level_a, level_b, level_c, agg) AS (
  VALUES
    ('2022-10-01T00:00:00Z'::timestamptz, 2, 685::real, 1, -1, -1, 2),
    ('2022-10-01T00:00:00Z'::timestamptz, 2, 686::real, 1, -1, -1, 3),
    ('2022-10-01T02:00:00Z'::timestamptz, 2, 686::real, 1, -1, -1, 2),
    ('2022-10-01T02:00:00Z'::timestamptz, 2, 687::real, 1, -1, -1, 3),
    ('2022-10-01T03:00:00Z'::timestamptz, 2, 687::real, 1, -1, -1, 2),
    ('2022-10-01T03:00:00Z'::timestamptz, 2, 688::real, 1, -1, -1, 3)
)
SELECT
  time_bucket_gapfill('1 hour', time) AS time,
  CASE WHEN agg IN (0,3) THEN MAX(value) ELSE NULL END AS max
FROM hourly
WHERE
  time >= '2022-10-01T00:00:00Z'
  AND time <  '2022-10-01T05:59:59Z'
GROUP BY 1, agg;

Stack trace

gdb) bt
#0  errfinish (filename=0x59c8af3f84c2 "/home/akuzm/ts1/build-pg/../pg/src/backend/executor/execExprInterp.c", lineno=2012, funcname=0x59c8af38fbe1 "CheckVarSlotCompatibility") at /home/akuzm/ts1/build-pg/../pg/src/backend/utils/error/elog.c:481
#1  0x000059c8af88379d in CheckVarSlotCompatibility (slot=<optimized out>, attnum=<optimized out>, vartype=<optimized out>) at /home/akuzm/ts1/build-pg/../pg/src/backend/executor/execExprInterp.c:2023
#2  0x000059c8af8835f4 in CheckExprStillValid (state=0x59c8b146bab8, econtext=<optimized out>) at /home/akuzm/ts1/build-pg/../pg/src/backend/executor/execExprInterp.c:1945
#3  0x000059c8af881048 in ExecInterpExprStillValid (state=0x59c8af3f84c2, econtext=0x7dc, isNull=0x59c8af38fbe1) at /home/akuzm/ts1/build-pg/../pg/src/backend/executor/execExprInterp.c:1921
#4  0x000070f4a290c551 in ExecEvalExprSwitchContext (state=0x59c8b146bab8, econtext=0x59c8b14a17e0, isNull=0x7fffc63be577) at /home/akuzm/ts1/install/include/postgresql/server/executor/executor.h:356
#5  ExecProject (projInfo=0x59c8b146bab0) at /home/akuzm/ts1/install/include/postgresql/server/executor/executor.h:390
#6  gapfill_state_gaptuple_create (state=0x59c8b14a15d0, time=<optimized out>) at /home/akuzm/ts1/ts/tsl/src/nodes/gapfill/gapfill_exec.c:1047
#7  gapfill_exec (node=0x59c8b14a15d0) at /home/akuzm/ts1/ts/tsl/src/nodes/gapfill/gapfill_exec.c:897
#8  0x000059c8af88b46b in ExecProcNode (node=0x59c8b14a15d0) at /home/akuzm/ts1/build-pg/../pg/src/include/executor/executor.h:274
#9  ExecutePlan (queryDesc=0x59c8b14a33b0, operation=CMD_SELECT, sendTuples=true, numberTuples=0, direction=<optimized out>, dest=0x59c8b14b70c8) at /home/akuzm/ts1/build-pg/../pg/src/backend/executor/execMain.c:1649
#10 standard_ExecutorRun (queryDesc=0x59c8b14a33b0, direction=<optimized out>, count=0, execute_once=<optimized out>) at /home/akuzm/ts1/build-pg/../pg/src/backend/executor/execMain.c:361
#11 0x000059c8afa8ad98 in PortalRunSelect (portal=portal@entry=0x59c8b1418510, forward=<optimized out>, count=0, count@entry=9223372036854775807, dest=dest@entry=0x59c8b14b70c8) at /home/akuzm/ts1/build-pg/../pg/src/backend/tcop/pquery.c:927
#12 0x000059c8afa8a95d in PortalRun (portal=portal@entry=0x59c8b1418510, count=count@entry=9223372036854775807, isTopLevel=true, run_once=<optimized out>, dest=dest@entry=0x59c8b14b70c8, altdest=altdest@entry=0x59c8b14b70c8, qc=0x7fffc63be7c0) at /home/akuzm/ts1/build-pg/../pg/src/backend/tcop/pquery.c:769
#13 0x000059c8afa897e0 in exec_simple_query (query_string=query_string@entry=0x59c8b1391d80 "WITH hourly(time, signal, value, level_a, level_b, level_c, agg) AS (\n  VALUES\n    ('2022-10-01T00:00:00Z'::timestamptz, 2, 685::real, 1, -1, -1, 2),\n    ('2022-10-01T00:00:00Z'::timestamptz, 2, 686::"...) at /home/akuzm/ts1/build-pg/../pg/src/backend/tcop/postgres.c:2510
#14 0x000059c8afa8739d in PostgresMain (dbname=<optimized out>, username=<optimized out>) at /home/akuzm/ts1/build-pg/../pg/src/backend/tcop/postgres.c:6001
#15 0x000059c8afa7fce9 in BackendMain (startup_data=<optimized out>, startup_data_len=<optimized out>) at /home/akuzm/ts1/build-pg/../pg/src/backend/tcop/backend_startup.c:105
#16 0x000059c8af9d6be1 in postmaster_child_launch (child_type=child_type@entry=B_BACKEND, startup_data=startup_data@entry=0x7fffc63bf644 "", startup_data_len=startup_data_len@entry=4, client_sock=client_sock@entry=0x7fffc63bf598) at /home/akuzm/ts1/build-pg/../pg/src/backend/postmaster/launch_backend.c:277
#17 0x000059c8af9db523 in BackendStartup (client_sock=0x7fffc63bf598) at /home/akuzm/ts1/build-pg/../pg/src/backend/postmaster/postmaster.c:3594
#18 ServerLoop () at /home/akuzm/ts1/build-pg/../pg/src/backend/postmaster/postmaster.c:1676
#19 0x000059c8af9d8dc0 in PostmasterMain (argc=argc@entry=1, argv=argv@entry=0x59c8b12f9680) at /home/akuzm/ts1/build-pg/../pg/src/backend/postmaster/postmaster.c:1374
#20 0x000059c8af8ebc36 in main (argc=1, argv=0x59c8b12f9680) at /home/akuzm/ts1/build-pg/../pg/src/backend/main/main.c:199

[moodgorning]

I believe this is happening to me too, seems to be indeed a bug in the query planner. Same general setup, A CTE with data and then a time_bucket_gapfill that selects from the CTE. I also tried to use a CTE AS MATERIALIZED and even a temporary table instead, still getting the same error "Database internal error occurred: invalid attnum 8 for relation "m""
My query is being executed as part of a data import job that iterates over a time interval hour by hour. It can run fine for 20 minutes, importing hour after hour just fine and then at some point just decide to crash with the above error.
Is there a chance that this can be addressed anytime soon?

[moodgorning]

I can also confirm @akuzm 's query is failing on my side as well with "attribute number 7 exceeds number of columns 3"