Thread: BUG #5548: ERROR: invalid attnum ## for rangetable entry on EXPLAIN VERBOSE, not on EXPLAIN
BUG #5548: ERROR: invalid attnum ## for rangetable entry on EXPLAIN VERBOSE, not on EXPLAIN
From
"Daniel Grace"
Date:
The following bug has been logged online:
Bug reference: 5548
Logged by: Daniel Grace
Email address: dgrace@wingsnw.com
PostgreSQL version: 9.0beta2
Operating system: Windows XP 32-bit
Description: ERROR: invalid attnum ## for rangetable entry on
EXPLAIN VERBOSE, not on EXPLAIN
Details:
I apologize for not including detailed schema information. It took a lot to
get this to reduce to the point it did, and hopefully this is enough
information to find a bug. If not, email me back and I'll see how much
schema information I can provide.
When using EXPLAIN [ANALYZE] VERBOSE on the below query:
SELECT t.*
FROM (
SELECT
TRUE AS is_enrolled,
acal.weight::REAL / (SELECT SUM(acal2.weight) FROM allocation_calendar AS
acal2 WHERE acal.year=acal2.year)::REAL AS calc_weight,
(
TRUNC(EXTRACT(EPOCH FROM LENGTH(
PERIOD(
GREATEST(FIRST(acal.daterange), acd.tstime),
LEAST(NEXT(acal.daterange), FIRST_VALUE(acd.tstime) OVER nextdate)
)
))) / TRUNC(EXTRACT(EPOCH FROM LENGTH(acal.daterange)))
) AS calc_duration,
NULL::integer AS group_id
FROM
allocation_calculated_dates AS acd
INNER JOIN allocation_calendar AS acal ON acd.acalid=acal.id
INNER JOIN log_status AS ls ON ls.sid=acd.sid AND ls.tsrange ~ acd.tstime
WINDOW
nextdate AS ( PARTITION BY acd.sid, acd.acalid ORDER BY acd.tstime ASC
ROWS BETWEEN 1 FOLLOWING AND 1 FOLLOWING )
) AS t
CROSS JOIN yearinfo AS yi -- ON t.year=yi.year
LEFT JOIN group_info AS gi ON gi.id=t.group_id
WHERE t.is_enrolled /* AND yi.allocation_lock=0 */
I receive the following result:
ERROR: invalid attnum 5 for rangetable entry t
This appears to be originating from get_rte_attribute_name() in
parse_relation.c (which might need to consider RTE_SUBQUERY?)
Stripping the final WHERE clause out (WHERE t.is_enrolled) causes the error
to go away, as do most modifications to joined tables.
When ran as a regular SELECT, the query runs fine and produces correct
outputs.
A regular EXPLAIN yields:
"Nested Loop (cost=1136.45..1146.96 rows=16 width=17)"
" -> Subquery Scan on t (cost=1136.45..1145.71 rows=4 width=17)"
" Filter: t.is_enrolled"
" -> WindowAgg (cost=1136.45..1145.63 rows=8 width=38)"
" -> Sort (cost=1136.45..1136.47 rows=8 width=38)"
" Sort Key: s.id, wings_demo.allocation_calendar.id,
(GREATEST(first(ls.tsrange), first(CASE WHEN
(wings_demo.allocation_calendar.countdate IS NULL) THEN
wings_demo.allocation_calendar.daterange ELSE
period_cc((wings_demo.allocation_calendar.countdate)::timestamp with time
zone, (wings_demo.allocation_calendar.countdate)::timestamp with time zone)
END)))"
" -> Hash Join (cost=1055.63..1136.33 rows=8
width=38)"
" Hash Cond: (ls.sid = s.id)"
" Join Filter: (ls.tsrange ~
(GREATEST(first(ls.tsrange), first(CASE WHEN
(wings_demo.allocation_calendar.countdate IS NULL) THEN
wings_demo.allocation_calendar.daterange ELSE
period_cc((wings_demo.allocation_calendar.countdate)::timestamp with time
zone, (wings_demo.allocation_calendar.countdate)::timestamp with time zone)
END))))"
" -> Seq Scan on log_status ls (cost=0.00..76.26
rows=1126 width=20)"
" -> Hash (cost=1055.56..1055.56 rows=6
width=38)"
" -> Hash Join (cost=1055.07..1055.56
rows=6 width=38)"
" Hash Cond:
(wings_demo.allocation_calendar.id = acal.id)"
" -> HashAggregate
(cost=1053.93..1054.11 rows=18 width=46)"
" -> Append
(cost=561.01..1053.75 rows=18 width=46)"
" -> Merge Left Join
(cost=561.01..596.61 rows=17 width=46)"
" Merge Cond: ((s.id
= ao.sid) AND (wings_demo.allocation_calendar.year = ao.year))"
" Filter: (ao.amount
IS NULL)"
" -> Sort
(cost=472.83..481.28 rows=3378 width=46)"
" Sort Key:
s.id, wings_demo.allocation_calendar.year"
" -> Nested
Loop (cost=30.02..274.85 rows=3378 width=46)"
" Join
Filter: (CASE WHEN (wings_demo.allocation_calendar.countdate IS NULL) THEN
wings_demo.allocation_calendar.daterange ELSE
period_cc((wings_demo.allocation_calendar.countdate)::timestamp with time
zone, (wings_demo.allocation_calendar.countdate)::timestamp with time zone)
END && ls.tsrange)"
" ->
Hash Join (cost=30.02..121.77 rows=1126 width=20)"
"
Hash Cond: (ls.sid = s.id)"
"
-> Seq Scan on log_status ls (cost=0.00..76.26 rows=1126 width=20)"
"
-> Hash (cost=25.01..25.01 rows=401 width=4)"
"
-> Seq Scan on student s (cost=0.00..25.01 rows=401 width=4)"
" ->
Materialize (cost=0.00..1.09 rows=6 width=26)"
"
-> Seq Scan on allocation_calendar (cost=0.00..1.06 rows=6 width=26)"
" -> Sort
(cost=88.17..91.35 rows=1270 width=19)"
" Sort Key:
ao.sid, ao.year"
" -> Seq Scan
on allocation_override ao (cost=0.00..22.70 rows=1270 width=19)"
" -> Hash Left Join
(cost=350.15..456.97 rows=1 width=54)"
" Hash Cond: (lg.sid
= lgprior.sid)"
" Join Filter:
((lgprior.id <> lg.id) AND (COALESCE(lgprior.allocation_priority,
giprior.allocation_priority) > COALESCE(lg.allocation_priority,
gi.allocation_priority)) AND (lgprior.tsrange ~ first(lg.tsrange)))"
" Filter: (((ao.sid
IS NULL) AND (lgprior.id IS NULL)) OR ((lgnext.id IS NULL) AND (NOT
lg.ignore_allocation_method) AND (gi.allocation_method_id IS NOT NULL)))"
" -> Hash Left Join
(cost=313.79..382.24 rows=963 width=75)"
" Hash Cond:
(lg.sid = lgnext.sid)"
" Join Filter:
((lgnext.id <> lg.id) AND (COALESCE(lgnext.allocation_priority,
ginext.allocation_priority) > COALESCE(lg.allocation_priority,
gi.allocation_priority)) AND (lgnext.tsrange ~ last(lg.tsrange)))"
" -> Hash Join
(cost=277.42..307.56 rows=963 width=71)"
" Hash
Cond: (lg.gid = gi.id)"
" ->
Merge Left Join (cost=276.33..293.23 rows=963 width=67)"
"
Merge Cond: ((s.id = ao.sid) AND (wings_demo.allocation_calendar.year =
ao.year))"
"
-> Sort (cost=188.16..190.57 rows=963 width=63)"
"
Sort Key: lg.sid, wings_demo.allocation_calendar.year"
"
-> Hash Join (cost=35.64..140.44 rows=963 width=63)"
"
Hash Cond: (lg.sid = s.id)"
"
-> Nested Loop (cost=5.61..97.17 rows=963 width=59)"
"
Join Filter: (NOT (lg.tsrange @> CASE WHEN
(wings_demo.allocation_calendar.countdate IS NULL) THEN
wings_demo.allocation_calendar.daterange ELSE
period_cc((wings_demo.allocation_calendar.countdate)::timestamp with time
zone, (wings_demo.allocation_calendar.countdate)::timestamp with time zone)
END))"
"
-> Seq Scan on allocation_calendar (cost=0.00..1.06 rows=6
width=26)"
"
-> Bitmap Heap Scan on log_group lg (cost=5.61..15.93
rows=3 width=33)"
"
Recheck Cond: (CASE WHEN
(wings_demo.allocation_calendar.countdate IS NULL) THEN
wings_demo.allocation_calendar.daterange ELSE
period_cc((wings_demo.allocation_calendar.countdate)::timestamp with time
zone, (wings_demo.allocation_calendar.countdate)::timestamp with time zone)
END && lg.tsrange)"
"
-> Bitmap Index Scan on log_group_gix_tsrange
(cost=0.00..5.61 rows=3 width=0)"
"
Index Cond: (CASE WHEN
(wings_demo.allocation_calendar.countdate IS NULL) THEN
wings_demo.allocation_calendar.daterange ELSE
period_cc((wings_demo.allocation_calendar.countdate)::timestamp with time
zone, (wings_demo.allocation_calendar.countdate)::timestamp with time zone)
END && lg.tsrange)"
"
-> Hash (cost=25.01..25.01 rows=401 width=4)"
"
-> Seq Scan on student s (cost=0.00..25.01 rows=401
width=4)"
"
-> Sort (cost=88.17..91.35 rows=1270 width=8)"
"
Sort Key: ao.sid, ao.year"
"
-> Seq Scan on allocation_override ao (cost=0.00..22.70 rows=1270
width=8)"
" ->
Hash (cost=1.04..1.04 rows=4 width=12)"
"
-> Seq Scan on group_info gi (cost=0.00..1.04 rows=4 width=12)"
" -> Hash
(cost=28.34..28.34 rows=642 width=32)"
" ->
Hash Join (cost=1.09..28.34 rows=642 width=32)"
"
Hash Cond: (lgnext.gid = ginext.id)"
"
-> Seq Scan on log_group lgnext (cost=0.00..18.42 rows=642 width=32)"
"
Filter: (NOT ignore_allocation_method)"
"
-> Hash (cost=1.04..1.04 rows=4 width=8)"
"
-> Seq Scan on group_info ginext (cost=0.00..1.04 rows=4 width=8)"
"
Filter: (allocation_method_id IS NOT NULL)"
" -> Hash
(cost=28.34..28.34 rows=642 width=32)"
" -> Hash Join
(cost=1.09..28.34 rows=642 width=32)"
" Hash
Cond: (lgprior.gid = giprior.id)"
" -> Seq
Scan on log_group lgprior (cost=0.00..18.42 rows=642 width=32)"
"
Filter: (NOT ignore_allocation_method)"
" ->
Hash (cost=1.04..1.04 rows=4 width=8)"
"
-> Seq Scan on group_info giprior (cost=0.00..1.04 rows=4 width=8)"
"
Filter: (allocation_method_id IS NOT NULL)"
" -> Hash (cost=1.06..1.06 rows=6
width=26)"
" -> Seq Scan on
allocation_calendar acal (cost=0.00..1.06 rows=6 width=26)"
" SubPlan 1"
" -> Aggregate (cost=1.08..1.09 rows=1 width=4)"
" -> Seq Scan on allocation_calendar acal2
(cost=0.00..1.08 rows=2 width=4)"
" Filter: ($0 = year)"
" -> Materialize (cost=0.00..1.06 rows=4 width=0)"
" -> Seq Scan on yearinfo yi (cost=0.00..1.04 rows=4 width=0)"
Re: BUG #5548: ERROR: invalid attnum ## for rangetable entry on EXPLAIN VERBOSE, not on EXPLAIN
From
Tom Lane
Date:
"Daniel Grace" <dgrace@wingsnw.com> writes:
> I apologize for not including detailed schema information. It took a lot to
> get this to reduce to the point it did, and hopefully this is enough
> information to find a bug.
It is not. You haven't provided anywhere near enough information
for someone else to reproduce the failure. We're not going to
guess at the tables or views that underlie your query ...
regards, tom lane
Re: BUG #5548: ERROR: invalid attnum ## for rangetable entry on EXPLAIN VERBOSE, not on EXPLAIN
From
Daniel Grace
Date:
On Thu, Jul 8, 2010 at 10:52 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> "Daniel Grace" <dgrace@wingsnw.com> writes:
>> I apologize for not including detailed schema information. =A0It took a =
lot to
>> get this to reduce to the point it did, and hopefully this is enough
>> information to find a bug.
>
> It is not. =A0You haven't provided anywhere near enough information
> for someone else to reproduce the failure. =A0We're not going to
> guess at the tables or views that underlie your query ...
>
> =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0regards, tom lane
>
So I've spent the greater portion of the last two hours trying to slim
down the schema and query enough to provide something that can
reproduce this.
While I can reproduce it 100% of the time with live data, I can't get
it to reproduce at all with test data -- though I've included a few
schemas below. It seems to be based on what plan ends up being
constructed for the query.
This doesn't really affect me at this point -- but my concern is that
it might cause actual problems when paired with the auto_explain
contrib module.
Basic stripped-down schema:
DROP SCHEMA IF EXISTS test CASCADE;
CREATE SCHEMA test;
SET SEARCH_PATH=3Dtest,public;
CREATE TABLE allocation_calendar
(
id serial NOT NULL,
"year" smallint NOT NULL,
"name" character varying(64) NOT NULL,
countdate date,
availabledate date NOT NULL,
weight integer NOT NULL,
daterange integer NOT NULL, -- Was a PERIOD, but not required to reproduce
CONSTRAINT allocation_calendar_pkey PRIMARY KEY (id),
CONSTRAINT allocation_calendar_ux_year UNIQUE (year, name)
);
CREATE INDEX allocation_calendar_ix_year_3 ON allocation_calendar
(year, countdate);
CREATE INDEX allocation_calendar_ix_year_4 ON allocation_calendar
(year, availabledate);
CREATE TABLE yearinfo (
id serial NOT NULL,
year smallint NOT NULL,
CONSTRAINT yearinfo_ux_year UNIQUE (year)
);
INSERT INTO yearinfo (year) SELECT * FROM GENERATE_SERIES(1000, 2000);
INSERT INTO allocation_calendar (year, name, countdate, availabledate,
weight, daterange) SELECT f.v, 'Year ' || f.v, NULL, '-infinity', 1, 2
FROM GENERATE_SERIES(1000, 5000) AS f(v);
ANALYZE allocation_calendar;
REINDEX TABLE yearinfo;
REINDEX TABLE allocation_calendar;
CREATE OR REPLACE VIEW allocation_calculated_dates AS
SELECT acal.id AS acalid, acal.year AS year, null::integer AS tstime
FROM
allocation_calendar AS acal
;
EXPLAIN ANALYZE SELECT t.*
FROM (
SELECT
FIRST_VALUE(acd.tstime) OVER nextdate AS foo
FROM
allocation_calculated_dates AS acd
INNER JOIN allocation_calendar AS acal ON acd.acalid=3Dacal.id
WINDOW
nextdate AS ( PARTITION BY acd.acalid ORDER BY acd.tstime ASC ROWS
BETWEEN 1 FOLLOWING AND 1 FOLLOWING )
) AS t
CROSS JOIN yearinfo AS yi -- ON t.year=3Dyi.year
WHERE t.foo IS NULL
Plan that fails on EXPLAIN VERBOSE:
"Nested Loop (cost=3D0.00..132.35 rows=3D24 width=3D4)"
" -> Subquery Scan on t (cost=3D0.00..131.00 rows=3D6 width=3D4)"
" Filter: (t.foo IS NULL)"
" -> WindowAgg (cost=3D0.00..119.50 rows=3D1150 width=3D4)"
" -> Merge Join (cost=3D0.00..102.25 rows=3D1150 width=3D4)"
" Merge Cond: (acal.id =3D acal.id)"
" -> Index Scan using allocation_calendar_pkey on
allocation_calendar acal (cost=3D0.00..42.50 rows=3D1150 width=3D4)"
" -> Index Scan using allocation_calendar_pkey on
allocation_calendar acal (cost=3D0.00..42.50 rows=3D1150 width=3D4)"
" -> Materialize (cost=3D0.00..1.06 rows=3D4 width=3D0)"
" -> Seq Scan on yearinfo yi (cost=3D0.00..1.04 rows=3D4 width=3D0=
)"
--> ERROR: invalid attnum 2 for rangetable entry t
Note: The attnum in question always seems to be 1 more than the number
of columns in t.
Plan that succeeds on EXPLAIN VERBOSE:
"Nested Loop (cost=3D0.00..827.88 rows=3D20020 width=3D4) (actual
time=3D0.036..2566.818 rows=3D4005001 loops=3D1)"
" -> Seq Scan on yearinfo yi (cost=3D0.00..15.01 rows=3D1001 width=3D0)
(actual time=3D0.007..0.429 rows=3D1001 loops=3D1)"
" -> Materialize (cost=3D0.00..562.67 rows=3D20 width=3D4) (actual
time=3D0.000..0.850 rows=3D4001 loops=3D1001)"
" -> Subquery Scan on t (cost=3D0.00..562.57 rows=3D20 width=3D4)
(actual time=3D0.026..14.731 rows=3D4001 loops=3D1)"
" Filter: (t.foo IS NULL)"
" -> WindowAgg (cost=3D0.00..522.56 rows=3D4001 width=3D4)
(actual time=3D0.025..12.637 rows=3D4001 loops=3D1)"
" -> Merge Join (cost=3D0.00..462.55 rows=3D4001
width=3D4) (actual time=3D0.016..7.715 rows=3D4001 loops=3D1)"
" Merge Cond: (acal.id =3D acal.id)"
" -> Index Scan using
allocation_calendar_pkey on allocation_calendar acal
(cost=3D0.00..201.27 rows=3D4001 width=3D4) (actual time=3D0.007..1.481
rows=3D4001 loops=3D1)"
" -> Index Scan using
allocation_calendar_pkey on allocation_calendar acal
(cost=3D0.00..201.27 rows=3D4001 width=3D4) (actual time=3D0.006..2.035
rows=3D4001 loops=3D1)"
"Total runtime: 3288.843 ms"
Hope this helps at least somewhat. I know it's not as clear cut as
I'd like. (Normally I'd like to send a 100% working reproduce case,
but I just can't seem to get one here)
--=20
Daniel Grace
Re: BUG #5548: ERROR: invalid attnum ## for rangetable entry on EXPLAIN VERBOSE, not on EXPLAIN
From
Tom Lane
Date:
Daniel Grace <dgrace@wingsnw.com> writes:
> So I've spent the greater portion of the last two hours trying to slim
> down the schema and query enough to provide something that can
> reproduce this.
> While I can reproduce it 100% of the time with live data, I can't get
> it to reproduce at all with test data -- though I've included a few
> schemas below. It seems to be based on what plan ends up being
> constructed for the query.
Maybe you could force it for the test data with some suitable
combination of the enable_plantype switches.
regards, tom lane
Re: BUG #5548: ERROR: invalid attnum ## for rangetable entry on EXPLAIN VERBOSE, not on EXPLAIN
From
Tom Lane
Date:
Daniel Grace <dgrace@wingsnw.com> writes:
> Plan that fails on EXPLAIN VERBOSE:
> "Nested Loop (cost=0.00..132.35 rows=24 width=4)"
> " -> Subquery Scan on t (cost=0.00..131.00 rows=6 width=4)"
> " Filter: (t.foo IS NULL)"
> " -> WindowAgg (cost=0.00..119.50 rows=1150 width=4)"
> " -> Merge Join (cost=0.00..102.25 rows=1150 width=4)"
> " Merge Cond: (acal.id = acal.id)"
> " -> Index Scan using allocation_calendar_pkey on
> allocation_calendar acal (cost=0.00..42.50 rows=1150 width=4)"
> " -> Index Scan using allocation_calendar_pkey on
> allocation_calendar acal (cost=0.00..42.50 rows=1150 width=4)"
> " -> Materialize (cost=0.00..1.06 rows=4 width=0)"
> " -> Seq Scan on yearinfo yi (cost=0.00..1.04 rows=4 width=0)"
> --> ERROR: invalid attnum 2 for rangetable entry t
I've applied a patch for this; it'll be in 9.0beta4. Thanks for the
report!
regards, tom lane