Bug revalidating or updating the query text of a plan with an explain clause

[arnoldsc]

I discovered a problem with pg_stat_plans_explain(planid).

The explain clause has the same plan as the original clause.
That's as expected.
So sometimes using pg_stat_plans_explain(planid) results in a substitution
of the sample query by the corresponding explain clause (when
revalidating/updating the query).

That's surprising, but the problem is, that you can no longer use
pg_stat_plans_explain on that entry, because it results in
an explain explain error.

This unwanted behaviour should be fixed by

• not updating or revalidating a plan with an explain query

or at least

• simply truncating the "explain" prefix when inserting the statement into the column.

or

• teaching pg_stat_plans_explain to truncate the explain prefix when evaluating

The actual behaviour has also to be called a BUG, because there are corner
cases
(see example below ) in which this behaviour leads to a syntax error of pg_stat_plans.

database1=# SELECT DISTINCT ON (UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS
VARCHAR(4000))) ,AGGREGATE.INFOOBJECT2ID) AGGREGATE.AUTORELATIONTYPE,
AGGREGATE.AUTORELATIONID
FROM (SELECT 'AUTOREL_AREA_HAS_PUBL_NAVIGATE'::TEXT AS AUTORELATIONTYPE,
AUTOREL_AREA_HAS_PUBL_NAVIGATE.ID AS AUTORELATIONID,
BNF_PUBLICATION.PUBLICATION_YEAR, BNF_PUBLICATION.ID AS INFOOBJECT2ID FROM
AUTOREL_AREA_HAS_PUBL_NAVIGATE,
BNF_PUBLICATION WHERE AUTOREL_AREA_HAS_PUBL_NAVIGATE.BNF_PUBLICATION =
BNF_PUBLICATION.ID AND BNF_PUBLICATION.C_STATUS_VISIBLE=TRUE ) AGGREGATE
ORDER BY UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) DESC NULLS
LAST , AGGREGATE.INFOOBJECT2ID LIMIT 10 OFFSET 0;

database1=# select *,pg_stat_plans_explain(planid) from pg_stat_plans where
query like 'SELECT D%';
-[ RECORD 1
]---------+----------------------------------------------------------------------------------------------------------------------------------------------------------------
planid | 2936400263
userid | 10
dbid | 16385
query | SELECT DISTINCT ON (UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) ,AGGREGATE.INFOOBJECT2ID) AGGREGATE.AUTORELATIONTYPE, AGGREGATE.AUTORELATIONID
| FROM (SELECT 'AUTOREL_AREA_HAS_PUBL_NAVIGATE'::TEXT AS AUTORELATIONTYPE,
| AUTOREL_AREA_HAS_PUBL_NAVIGATE.ID AS AUTORELATIONID, BNF_PUBLICATION.PUBLICATION_YEAR, BNF_PUBLICATION.ID AS INFOOBJECT2ID FROM AUTOREL_AREA_HAS_PUBL_NAVIGATE,
| BNF_PUBLICATION WHERE AUTOREL_AREA_HAS_PUBL_NAVIGATE.BNF_PUBLICATION = BNF_PUBLICATION.ID AND BNF_PUBLICATION.C_STATUS_VISIBLE=TRUE ) AGGREGATE
| ORDER BY UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) DESC NULLS LAST , AGGREGATE.INFOOBJECT2ID LIMIT 10 OFFSET 0;
had_our_search_path | t
from_our_database | t
query_explainable | t
calls | 5
total_time | 0.735
rows | 30
shared_blks_hit | 234
shared_blks_read | 0
shared_blks_written | 0
local_blks_hit | 0
local_blks_read | 0
local_blks_written | 0
temp_blks_read | 0
temp_blks_written | 0
blk_read_time | 0
blk_write_time | 0
last_startup_cost | 0
last_total_cost | 10.6211277959583
pg_stat_plans_explain | Limit (cost=0.00..10.62 rows=10 width=12)
| -> Unique (cost=0.00..62964.17 rows=59282 width=12)
| -> Nested Loop (cost=0.00..62418.30 rows=109173 width=12)
| -> Index Scan using arns_bnf_pub_2_idx on bnf_publication (cost=0.00..36002.73 rows=59282 width=8)
| Filter: c_status_visible
| -> Index Scan using idx_autorel_area_has_publ_navigate_bnf_publication on autorel_area_has_publ_navigate (cost=0.00..0.41 rows=2 width=8)
| Index Cond: (bnf_publication = bnf_publication.id)

database1=# set enable_indexscan=false;
SET
database1=# SELECT DISTINCT ON (UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) ,AGGREGATE.INFOOBJECT2ID) AGGREGATE.AUTORELATIONTYPE, AGGREGATE.AUTORELATIONID
FROM (SELECT 'AUTOREL_AREA_HAS_PUBL_NAVIGATE'::TEXT AS AUTORELATIONTYPE, AUTOREL_AREA_HAS_PUBL_NAVIGATE.ID AS AUTORELATIONID,
BNF_PUBLICATION.PUBLICATION_YEAR, BNF_PUBLICATION.ID AS INFOOBJECT2ID FROM
AUTOREL_AREA_HAS_PUBL_NAVIGATE, BNF_PUBLICATION WHERE AUTOREL_AREA_HAS_PUBL_NAVIGATE.BNF_PUBLICATION = BNF_PUBLICATION.ID AND BNF_PUBLICATION.C_STATUS_VISIBLE=TRUE ) AGGREGATE
ORDER BY UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) DESC NULLS
LAST , AGGREGATE.INFOOBJECT2ID LIMIT 10 OFFSET 0;

database1=# select *,pg_stat_plans_explain(planid) from pg_stat_plans where
query like 'SELECT D%';
WARNING: Existing pg_stat_plans entry planid (2936400263) differs from new
plan for query (1373001957).
-[ RECORD 1
]---------+----------------------------------------------------------------------------------------------------------------------------------------------------------------
planid | 1373001957
userid | 10
dbid | 16385
query | SELECT DISTINCT ON (UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) ,AGGREGATE.INFOOBJECT2ID) AGGREGATE.AUTORELATIONTYPE, AGGREGATE.AUTORELATIONID
| FROM (SELECT 'AUTOREL_AREA_HAS_PUBL_NAVIGATE'::TEXT AS AUTORELATIONTYPE,
| AUTOREL_AREA_HAS_PUBL_NAVIGATE.ID AS AUTORELATIONID, BNF_PUBLICATION.PUBLICATION_YEAR, BNF_PUBLICATION.ID AS INFOOBJECT2ID FROM AUTOREL_AREA_HAS_PUBL_NAVIGATE,
| BNF_PUBLICATION WHERE AUTOREL_AREA_HAS_PUBL_NAVIGATE.BNF_PUBLICATION = BNF_PUBLICATION.ID AND BNF_PUBLICATION.C_STATUS_VISIBLE=TRUE ) AGGREGATE
| ORDER BY UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) DESC NULLS LAST , AGGREGATE.INFOOBJECT2ID LIMIT 10 OFFSET 0;
had_our_search_path | t
from_our_database | t
query_explainable | t
calls | 1
total_time | 1677.555
rows | 10
shared_blks_hit | 9534
shared_blks_read | 0
shared_blks_written | 0
local_blks_hit | 0
local_blks_read | 0
local_blks_written | 0
temp_blks_read | 217
temp_blks_written | 860
blk_read_time | 0
blk_write_time | 0
last_startup_cost | 27218.575446009
last_total_cost | 27218.7135650839
pg_stat_plans_explain | Limit (cost=27218.58..27218.71 rows=10 width=12)
| -> Unique (cost=27218.58..28037.37 rows=59282 width=12)
| -> Sort (cost=27218.58..27491.51 rows=109173 width=12)
| Sort Key: (upper(((bnf_publication.publication_year)::character varying(4000))::text)), bnf_publication.id
| -> Hash Join (cost=9922.33..16213.84 rows=109173 width=12)
| Hash Cond: (autorel_area_has_publ_navigate.bnf_publication = bnf_publication.id)
| -> Seq Scan on autorel_area_has_publ_navigate (cost=0.00..2524.55 rows=140755 width=8)
| -> Hash (cost=9181.31..9181.31 rows=59282 width=8)
| -> Seq Scan on bnf_publication (cost=0.00..9181.31 rows=59282 width=8)
| Filter: c_status_visible
-[ RECORD 2
]---------+----------------------------------------------------------------------------------------------------------------------------------------------------------------
planid | 2936400263
userid | 10
dbid | 16385
query | SELECT DISTINCT ON (UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) ,AGGREGATE.INFOOBJECT2ID) AGGREGATE.AUTORELATIONTYPE, AGGREGATE.AUTORELATIONID
| FROM (SELECT 'AUTOREL_AREA_HAS_PUBL_NAVIGATE'::TEXT AS AUTORELATIONTYPE,
| AUTOREL_AREA_HAS_PUBL_NAVIGATE.ID AS AUTORELATIONID, BNF_PUBLICATION.PUBLICATION_YEAR, BNF_PUBLICATION.ID AS INFOOBJECT2ID FROM AUTOREL_AREA_HAS_PUBL_NAVIGATE,
| BNF_PUBLICATION WHERE AUTOREL_AREA_HAS_PUBL_NAVIGATE.BNF_PUBLICATION = BNF_PUBLICATION.ID AND BNF_PUBLICATION.C_STATUS_VISIBLE=TRUE ) AGGREGATE
| ORDER BY UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) DESC NULLS LAST , AGGREGATE.INFOOBJECT2ID LIMIT 10 OFFSET 0;
had_our_search_path | t
from_our_database | t
query_explainable | t
calls | 6
total_time | 0.735
rows | 30
shared_blks_hit | 234
shared_blks_read | 0
shared_blks_written | 0
local_blks_hit | 0
local_blks_read | 0
local_blks_written | 0
temp_blks_read | 0
temp_blks_written | 0
blk_read_time | 0
blk_write_time | 0
last_startup_cost | 0
last_total_cost | 10.6211277959583
pg_stat_plans_explain |

database1=# set enable_indexscan=true;
SET
database1=# select *,pg_stat_plans_explain(planid) from pg_stat_plans where
query like 'SELECT D%';
NOTICE: updated pg_stat_plans query string of entry 2936400263
CONTEXT: SQL statement "EXPLAIN SELECT DISTINCT ON (UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) ,AGGREGATE.INFOOBJECT2ID) AGGREGATE.AUTORELATIONTYPE, AGGREGATE.AUTORELATIONI
FROM (SELECT 'AUTOREL_AREA_HAS_PUBL_NAVIGATE'::TEXT AS AUTORELATIONTYPE, AUTOREL_AREA_HAS_PUBL_NAVIGATE.ID AS AUTORELATIONID,
BNF_PUBLICATION.PUBLICATION_YEAR, BNF_PUBLICATION.ID AS INFOOBJECT2ID FROM AUTOREL_AREA_HAS_PUBL_NAVIGATE, BNF_PUBLICATION WHERE AUTOREL_AREA_HAS_PUBL_NAVIGATE.BNF_PUBLICATION = BNF_PUBLIC
ORDER BY UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) DESC NULLS LAST , AGGREGATE.INFOOBJECT2ID LIMIT 10 OFFSET 0;"
WARNING: Existing pg_stat_plans entry planid (1373001957) differs from new plan for query (2936400263).
ERROR: syntax error at or near "EXPLAIN"
LINE 1: EXPLAIN EXPLAIN SELECT DISTINCT ON (UPPER(CAST (AGGREGATE.PU...
^
QUERY: EXPLAIN EXPLAIN SELECT DISTINCT ON (UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) ,AGGREGATE.INFOOBJECT2ID) AGGREGATE.AUTORELATIONTYPE, AGGREGATE.AUTORELATIONID
FROM (SELECT 'AUTOREL_AREA_HAS_PUBL_NAVIGATE'::TEXT AS AUTORELATIONTYPE, AUTOREL_AREA_HAS_PUBL_NAVIGATE.ID AS AUTORELATIONID,
BNF_PUBLICATION.PUBLICATION_YEAR, BNF_PUBLICATION.ID AS INFOOBJECT2ID FROM AUTOREL_AREA_HAS_PUBL_NAVIGATE,
BNF_PUBLICATION WHERE AUTOREL_AREA_HAS_PUBL_NAVIGATE.BNF_PUBLICATION = BNF_PUBLICATION.ID AND BNF_PUBLICATION.C_STATUS_VISIBLE=TRUE ) AGGREGATE
ORDER BY UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) DESC NULLS
LAST , AGGREGATE.INFOOBJECT2ID LIMIT 10 O
database1=# select *,pg_stat_plans_explain(planid) from pg_stat_plans where
query like 'SELECT D%';
-[ RECORD 1
]---------+----------------------------------------------------------------------------------------------------------------------------------------------------------------
planid | 1373001957
userid | 10
dbid | 16385
query | SELECT DISTINCT ON (UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) ,AGGREGATE.INFOOBJECT2ID) AGGREGATE.AUTORELATIONTYPE, AGGREGATE.AUTORELATIONID
| FROM (SELECT 'AUTOREL_AREA_HAS_PUBL_NAVIGATE'::TEXT AS AUTORELATIONTYPE,
| AUTOREL_AREA_HAS_PUBL_NAVIGATE.ID AS AUTORELATIONID, BNF_PUBLICATION.PUBLICATION_YEAR, BNF_PUBLICATION.ID AS INFOOBJECT2ID FROM AUTOREL_AREA_HAS_PUBL_NAVIGATE,
| BNF_PUBLICATION WHERE AUTOREL_AREA_HAS_PUBL_NAVIGATE.BNF_PUBLICATION = BNF_PUBLICATION.ID AND BNF_PUBLICATION.C_STATUS_VISIBLE=TRUE ) AGGREGATE
| ORDER BY UPPER(CAST (AGGREGATE.PUBLICATION_YEAR AS VARCHAR(4000))) DESC NULLS LAST , AGGREGATE.INFOOBJECT2ID LIMIT 10 OFFSET 0;
had_our_search_path | t
from_our_database | t
query_explainable | f
calls | 3
total_time | 1677.555
rows | 10
shared_blks_hit | 9534
shared_blks_read | 0
shared_blks_written | 0
local_blks_hit | 0
local_blks_read | 0
local_blks_written | 0
temp_blks_read | 217
temp_blks_written | 860
blk_read_time | 0
blk_write_time | 0
last_startup_cost | 27218.575446009
last_total_cost | 27218.7135650839
pg_stat_plans_explain |