Thread: auto_explain causes regression failures

With the following settings

    custom_variable_classes = 'auto_explain'
    auto_explain.log_min_duration = 0
    auto_explain.log_format = 'xml'
    auto_explain.log_analyze = on
    auto_explain.log_verbose = on
    shared_preload_libraries = 'auto_explain'

I am getting regression failures on the rowtypes, transactions and
arrays tests. Diff file is attached. I'm going to look into it, but if
anyone has a good idea what's going on please speak up ASAP.

cheers

andrew
*** /home/andrew/pgl/pgsql.expltry2/src/test/regress/expected/transactions.out    2009-08-09 19:29:31.000000000 -0400
--- /home/andrew/pgl/pgsql.expltry2/src/test/regress/results/transactions.out    2010-02-16 10:28:28.000000000 -0500
***************
*** 496,504 ****
  (1 row)

  rollback to x;
  -- should fail
  fetch from foo;
! ERROR:  cursor "foo" does not exist
  commit;
  begin;
  create table abc (a int);
--- 496,506 ----
  (1 row)

  rollback to x;
+ WARNING:  AbortSubTransaction while in ABORT state
+ ERROR:  cache lookup failed for attribute 1 of relation 28260
  -- should fail
  fetch from foo;
! ERROR:  current transaction is aborted, commands ignored until end of transaction block
  commit;
  begin;
  create table abc (a int);
***************
*** 527,532 ****
--- 529,536 ----
  (1 row)

  abort;
+ WARNING:  AbortTransaction while in ABORT state
+ ERROR:  cache lookup failed for attribute 1 of relation 28263
  -- tests for the "tid" type
  SELECT '(3, 3)'::tid = '(3, 4)'::tid;
   ?column?

======================================================================

*** /home/andrew/pgl/pgsql.expltry2/src/test/regress/expected/arrays.out    2009-08-09 19:29:31.000000000 -0400
--- /home/andrew/pgl/pgsql.expltry2/src/test/regress/results/arrays.out    2010-02-16 10:28:29.000000000 -0500
***************
*** 15,22 ****
--- 15,25 ----
  --
  INSERT INTO arrtest (a[1:5], b[1:1][1:2][1:2], c, d, f, g)
     VALUES ('{1,2,3,4,5}', '{{{0,0},{1,2}}}', '{}', '{}', '{}', '{}');
+ ERROR:  unexpected refassgnexpr
  UPDATE arrtest SET e[0] = '1.1';
+ ERROR:  unexpected refassgnexpr
  UPDATE arrtest SET e[1] = '2.2';
+ ERROR:  unexpected refassgnexpr
  INSERT INTO arrtest (f)
     VALUES ('{"too long"}');
  ERROR:  value too long for type character(5)
***************
*** 24,38 ****
     VALUES ('{11,12,23}', '{{3,4},{4,5}}', '{"foobar"}',
             '{{"elt1", "elt2"}}', '{"3.4", "6.7"}',
             '{"abc","abcde"}', '{"abc","abcde"}');
  INSERT INTO arrtest (a, b[1:2], c, d[1:2])
     VALUES ('{}', '{3,4}', '{foo,bar}', '{bar,foo}');
  SELECT * FROM arrtest;
!       a      |        b        |     c     |       d       |        e        |        f        |      g
! -------------+-----------------+-----------+---------------+-----------------+-----------------+-------------
!  {1,2,3,4,5} | {{{0,0},{1,2}}} | {}        | {}            | [0:1]={1.1,2.2} | {}              | {}
!  {11,12,23}  | {{3,4},{4,5}}   | {foobar}  | {{elt1,elt2}} | {3.4,6.7}       | {"abc  ",abcde} | {abc,abcde}
!  {}          | {3,4}           | {foo,bar} | {bar,foo}     |                 |                 |
! (3 rows)

  SELECT arrtest.a[1],
            arrtest.b[1][1][1],
--- 27,40 ----
     VALUES ('{11,12,23}', '{{3,4},{4,5}}', '{"foobar"}',
             '{{"elt1", "elt2"}}', '{"3.4", "6.7"}',
             '{"abc","abcde"}', '{"abc","abcde"}');
+ ERROR:  unexpected refassgnexpr
  INSERT INTO arrtest (a, b[1:2], c, d[1:2])
     VALUES ('{}', '{3,4}', '{foo,bar}', '{bar,foo}');
+ ERROR:  unexpected refassgnexpr
  SELECT * FROM arrtest;
!  a | b | c | d | e | f | g
! ---+---+---+---+---+---+---
! (0 rows)

  SELECT arrtest.a[1],
            arrtest.b[1][1][1],
***************
*** 40,90 ****
            arrtest.d[1][1],
            arrtest.e[0]
     FROM arrtest;
!  a  | b |   c    |  d   |  e
! ----+---+--------+------+-----
!   1 | 0 |        |      | 1.1
!  11 |   | foobar | elt1 |
!     |   | foo    |      |
! (3 rows)

  SELECT a[1], b[1][1][1], c[1], d[1][1], e[0]
     FROM arrtest;
!  a  | b |   c    |  d   |  e
! ----+---+--------+------+-----
!   1 | 0 |        |      | 1.1
!  11 |   | foobar | elt1 |
!     |   | foo    |      |
! (3 rows)

  SELECT a[1:3],
            b[1:1][1:2][1:2],
            c[1:2],
            d[1:1][1:2]
     FROM arrtest;
!      a      |        b        |     c     |       d
! ------------+-----------------+-----------+---------------
!  {1,2,3}    | {{{0,0},{1,2}}} | {}        | {}
!  {11,12,23} | {}              | {foobar}  | {{elt1,elt2}}
!  {}         | {}              | {foo,bar} | {}
! (3 rows)

  SELECT array_ndims(a) AS a,array_ndims(b) AS b,array_ndims(c) AS c
     FROM arrtest;
   a | b | c
  ---+---+---
!  1 | 3 |
!  1 | 2 | 1
!    | 1 | 1
! (3 rows)

  SELECT array_dims(a) AS a,array_dims(b) AS b,array_dims(c) AS c
     FROM arrtest;
!    a   |        b        |   c
! -------+-----------------+-------
!  [1:5] | [1:1][1:2][1:2] |
!  [1:3] | [1:2][1:2]      | [1:1]
!        | [1:2]           | [1:2]
! (3 rows)

  -- returns nothing
  SELECT *
--- 42,77 ----
            arrtest.d[1][1],
            arrtest.e[0]
     FROM arrtest;
!  a | b | c | d | e
! ---+---+---+---+---
! (0 rows)

  SELECT a[1], b[1][1][1], c[1], d[1][1], e[0]
     FROM arrtest;
!  a | b | c | d | e
! ---+---+---+---+---
! (0 rows)

  SELECT a[1:3],
            b[1:1][1:2][1:2],
            c[1:2],
            d[1:1][1:2]
     FROM arrtest;
!  a | b | c | d
! ---+---+---+---
! (0 rows)

  SELECT array_ndims(a) AS a,array_ndims(b) AS b,array_ndims(c) AS c
     FROM arrtest;
   a | b | c
  ---+---+---
! (0 rows)

  SELECT array_dims(a) AS a,array_dims(b) AS b,array_dims(c) AS c
     FROM arrtest;
!  a | b | c
! ---+---+---
! (0 rows)

  -- returns nothing
  SELECT *
***************
*** 98,156 ****
  UPDATE arrtest
    SET a[1:2] = '{16,25}'
    WHERE NOT a = '{}'::_int2;
  UPDATE arrtest
    SET b[1:1][1:1][1:2] = '{113, 117}',
        b[1:1][1:2][2:2] = '{142, 147}'
    WHERE array_dims(b) = '[1:1][1:2][1:2]';
  UPDATE arrtest
    SET c[2:2] = '{"new_word"}'
    WHERE array_dims(c) is not null;
  SELECT a,b,c FROM arrtest;
!        a       |           b           |         c
! ---------------+-----------------------+-------------------
!  {16,25,3,4,5} | {{{113,142},{1,147}}} | {}
!  {}            | {3,4}                 | {foo,new_word}
!  {16,25,23}    | {{3,4},{4,5}}         | {foobar,new_word}
! (3 rows)

  SELECT a[1:3],
            b[1:1][1:2][1:2],
            c[1:2],
            d[1:1][2:2]
     FROM arrtest;
!      a      |           b           |         c         |    d
! ------------+-----------------------+-------------------+----------
!  {16,25,3}  | {{{113,142},{1,147}}} | {}                | {}
!  {}         | {}                    | {foo,new_word}    | {}
!  {16,25,23} | {}                    | {foobar,new_word} | {{elt2}}
! (3 rows)

  INSERT INTO arrtest(a) VALUES('{1,null,3}');
  SELECT a FROM arrtest;
!        a
! ---------------
!  {16,25,3,4,5}
!  {}
!  {16,25,23}
   {1,NULL,3}
! (4 rows)

  UPDATE arrtest SET a[4] = NULL WHERE a[2] IS NULL;
  SELECT a FROM arrtest WHERE a[2] IS NULL;
!         a
! -----------------
!  [4:4]={NULL}
!  {1,NULL,3,NULL}
! (2 rows)

  DELETE FROM arrtest WHERE a[2] IS NULL AND b IS NULL;
  SELECT a,b,c FROM arrtest;
!        a       |           b           |         c
! ---------------+-----------------------+-------------------
!  {16,25,3,4,5} | {{{113,142},{1,147}}} | {}
!  {16,25,23}    | {{3,4},{4,5}}         | {foobar,new_word}
!  [4:4]={NULL}  | {3,4}                 | {foo,new_word}
! (3 rows)

  --
  -- test array extension
--- 85,134 ----
  UPDATE arrtest
    SET a[1:2] = '{16,25}'
    WHERE NOT a = '{}'::_int2;
+ ERROR:  unexpected refassgnexpr
  UPDATE arrtest
    SET b[1:1][1:1][1:2] = '{113, 117}',
        b[1:1][1:2][2:2] = '{142, 147}'
    WHERE array_dims(b) = '[1:1][1:2][1:2]';
+ ERROR:  unexpected refassgnexpr
  UPDATE arrtest
    SET c[2:2] = '{"new_word"}'
    WHERE array_dims(c) is not null;
+ ERROR:  unexpected refassgnexpr
  SELECT a,b,c FROM arrtest;
!  a | b | c
! ---+---+---
! (0 rows)

  SELECT a[1:3],
            b[1:1][1:2][1:2],
            c[1:2],
            d[1:1][2:2]
     FROM arrtest;
!  a | b | c | d
! ---+---+---+---
! (0 rows)

  INSERT INTO arrtest(a) VALUES('{1,null,3}');
  SELECT a FROM arrtest;
!      a
! ------------
   {1,NULL,3}
! (1 row)

  UPDATE arrtest SET a[4] = NULL WHERE a[2] IS NULL;
+ ERROR:  unexpected refassgnexpr
  SELECT a FROM arrtest WHERE a[2] IS NULL;
!      a
! ------------
!  {1,NULL,3}
! (1 row)

  DELETE FROM arrtest WHERE a[2] IS NULL AND b IS NULL;
  SELECT a,b,c FROM arrtest;
!  a | b | c
! ---+---+---
! (0 rows)

  --
  -- test array extension
***************
*** 164,250 ****
  (1 row)

  update arrtest1 set i[2] = 22, t[2] = 'twenty-two';
  select * from arrtest1;
!        i       |             t
! ---------------+----------------------------
!  {1,22,NULL,4} | {one,twenty-two,NULL,four}
  (1 row)

  update arrtest1 set i[5] = 5, t[5] = 'five';
  select * from arrtest1;
!         i        |                t
! -----------------+---------------------------------
!  {1,22,NULL,4,5} | {one,twenty-two,NULL,four,five}
  (1 row)

  update arrtest1 set i[8] = 8, t[8] = 'eight';
  select * from arrtest1;
!               i              |                        t
! -----------------------------+-------------------------------------------------
!  {1,22,NULL,4,5,NULL,NULL,8} | {one,twenty-two,NULL,four,five,NULL,NULL,eight}
  (1 row)

  update arrtest1 set i[0] = 0, t[0] = 'zero';
  select * from arrtest1;
!                   i                  |                             t
! -------------------------------------+------------------------------------------------------------
!  [0:8]={0,1,22,NULL,4,5,NULL,NULL,8} | [0:8]={zero,one,twenty-two,NULL,four,five,NULL,NULL,eight}
  (1 row)

  update arrtest1 set i[-3] = -3, t[-3] = 'minus-three';
  select * from arrtest1;
!                          i                         |                                         t
                 
!
---------------------------------------------------+-----------------------------------------------------------------------------------
!  [-3:8]={-3,NULL,NULL,0,1,22,NULL,4,5,NULL,NULL,8} |
[-3:8]={minus-three,NULL,NULL,zero,one,twenty-two,NULL,four,five,NULL,NULL,eight}
  (1 row)

  update arrtest1 set i[0:2] = array[10,11,12], t[0:2] = array['ten','eleven','twelve'];
  select * from arrtest1;
!                           i                          |                                        t
                 
!
-----------------------------------------------------+---------------------------------------------------------------------------------
!  [-3:8]={-3,NULL,NULL,10,11,12,NULL,4,5,NULL,NULL,8} |
[-3:8]={minus-three,NULL,NULL,ten,eleven,twelve,NULL,four,five,NULL,NULL,eight}
  (1 row)

  update arrtest1 set i[8:10] = array[18,null,20], t[8:10] = array['p18',null,'p20'];
  select * from arrtest1;
!                                i                               |                                            t
                                   
!
---------------------------------------------------------------+-----------------------------------------------------------------------------------------
!  [-3:10]={-3,NULL,NULL,10,11,12,NULL,4,5,NULL,NULL,18,NULL,20} |
[-3:10]={minus-three,NULL,NULL,ten,eleven,twelve,NULL,four,five,NULL,NULL,p18,NULL,p20}
  (1 row)

  update arrtest1 set i[11:12] = array[null,22], t[11:12] = array[null,'p22'];
  select * from arrtest1;
!                                    i                                   |
 t                                                  
!
-----------------------------------------------------------------------+--------------------------------------------------------------------------------------------------
!  [-3:12]={-3,NULL,NULL,10,11,12,NULL,4,5,NULL,NULL,18,NULL,20,NULL,22} |
[-3:12]={minus-three,NULL,NULL,ten,eleven,twelve,NULL,four,five,NULL,NULL,p18,NULL,p20,NULL,p22}
  (1 row)

  update arrtest1 set i[15:16] = array[null,26], t[15:16] = array[null,'p26'];
  select * from arrtest1;
!                                             i                                            |
                             t                                                           
!
-----------------------------------------------------------------------------------------+---------------------------------------------------------------------------------------------------------------------
!  [-3:16]={-3,NULL,NULL,10,11,12,NULL,4,5,NULL,NULL,18,NULL,20,NULL,22,NULL,NULL,NULL,26} |
[-3:16]={minus-three,NULL,NULL,ten,eleven,twelve,NULL,four,five,NULL,NULL,p18,NULL,p20,NULL,p22,NULL,NULL,NULL,p26}
  (1 row)

  update arrtest1 set i[-5:-3] = array[-15,-14,-13], t[-5:-3] = array['m15','m14','m13'];
  select * from arrtest1;
!                                                 i                                                 |
                                      t                                                           
!
--------------------------------------------------------------------------------------------------+---------------------------------------------------------------------------------------------------------------------
!  [-5:16]={-15,-14,-13,NULL,NULL,10,11,12,NULL,4,5,NULL,NULL,18,NULL,20,NULL,22,NULL,NULL,NULL,26} |
[-5:16]={m15,m14,m13,NULL,NULL,ten,eleven,twelve,NULL,four,five,NULL,NULL,p18,NULL,p20,NULL,p22,NULL,NULL,NULL,p26}
  (1 row)

  update arrtest1 set i[-7:-6] = array[-17,null], t[-7:-6] = array['m17',null];
  select * from arrtest1;
!                                                      i                                                     |
                                                   t                                                                
!
-----------------------------------------------------------------------------------------------------------+------------------------------------------------------------------------------------------------------------------------------
!  [-7:16]={-17,NULL,-15,-14,-13,NULL,NULL,10,11,12,NULL,4,5,NULL,NULL,18,NULL,20,NULL,22,NULL,NULL,NULL,26} |
[-7:16]={m17,NULL,m15,m14,m13,NULL,NULL,ten,eleven,twelve,NULL,four,five,NULL,NULL,p18,NULL,p20,NULL,p22,NULL,NULL,NULL,p26}
  (1 row)

  update arrtest1 set i[-12:-10] = array[-22,null,-20], t[-12:-10] = array['m22',null,'m20'];
  select * from arrtest1;
!                                                                  i
            |                                                                          t
                                           
!
-----------------------------------------------------------------------------------------------------------------------------------+------------------------------------------------------------------------------------------------------------------------------------------------------
!
[-12:16]={-22,NULL,-20,NULL,NULL,-17,NULL,-15,-14,-13,NULL,NULL,10,11,12,NULL,4,5,NULL,NULL,18,NULL,20,NULL,22,NULL,NULL,NULL,26}
|
[-12:16]={m22,NULL,m20,NULL,NULL,m17,NULL,m15,m14,m13,NULL,NULL,ten,eleven,twelve,NULL,four,five,NULL,NULL,p18,NULL,p20,NULL,p22,NULL,NULL,NULL,p26}
  (1 row)

  delete from arrtest1;
--- 142,240 ----
  (1 row)

  update arrtest1 set i[2] = 22, t[2] = 'twenty-two';
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  update arrtest1 set i[5] = 5, t[5] = 'five';
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  update arrtest1 set i[8] = 8, t[8] = 'eight';
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  update arrtest1 set i[0] = 0, t[0] = 'zero';
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  update arrtest1 set i[-3] = -3, t[-3] = 'minus-three';
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  update arrtest1 set i[0:2] = array[10,11,12], t[0:2] = array['ten','eleven','twelve'];
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  update arrtest1 set i[8:10] = array[18,null,20], t[8:10] = array['p18',null,'p20'];
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  update arrtest1 set i[11:12] = array[null,22], t[11:12] = array[null,'p22'];
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  update arrtest1 set i[15:16] = array[null,26], t[15:16] = array[null,'p26'];
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  update arrtest1 set i[-5:-3] = array[-15,-14,-13], t[-5:-3] = array['m15','m14','m13'];
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  update arrtest1 set i[-7:-6] = array[-17,null], t[-7:-6] = array['m17',null];
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  update arrtest1 set i[-12:-10] = array[-22,null,-20], t[-12:-10] = array['m22',null,'m20'];
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  delete from arrtest1;
***************
*** 256,265 ****
  (1 row)

  update arrtest1 set i[0:5] = array[0,1,2,null,4,5], t[0:5] = array['z','p1','p2',null,'p4','p5'];
  select * from arrtest1;
!            i            |             t
! ------------------------+----------------------------
!  [0:5]={0,1,2,NULL,4,5} | [0:5]={z,p1,p2,NULL,p4,p5}
  (1 row)

  --
--- 246,256 ----
  (1 row)

  update arrtest1 set i[0:5] = array[0,1,2,null,4,5], t[0:5] = array['z','p1','p2',null,'p4','p5'];
+ ERROR:  unexpected refassgnexpr
  select * from arrtest1;
!       i       |          t
! --------------+---------------------
!  {1,2,NULL,4} | {one,two,NULL,four}
  (1 row)

  --
***************
*** 368,377 ****

  -- operators
  SELECT a FROM arrtest WHERE b = ARRAY[[[113,142],[1,147]]];
!        a
! ---------------
!  {16,25,3,4,5}
! (1 row)

  SELECT NOT ARRAY[1.1,1.2,1.3] = ARRAY[1.1,1.2,1.3] AS "FALSE";
   FALSE
--- 359,367 ----

  -- operators
  SELECT a FROM arrtest WHERE b = ARRAY[[[113,142],[1,147]]];
!  a
! ---
! (0 rows)

  SELECT NOT ARRAY[1.1,1.2,1.3] = ARRAY[1.1,1.2,1.3] AS "FALSE";
   FALSE

======================================================================

*** /home/andrew/pgl/pgsql.expltry2/src/test/regress/expected/rowtypes.out    2009-12-09 09:49:39.000000000 -0500
--- /home/andrew/pgl/pgsql.expltry2/src/test/regress/results/rowtypes.out    2010-02-16 10:28:50.000000000 -0500
***************
*** 95,114 ****

  -- test insertion/updating of subfields
  update people set fn.suffix = 'Jr';
  select * from people;
!       fn       |     bd
! ---------------+------------
!  (Joe,Blow,Jr) | 01-10-1984
  (1 row)

  insert into quadtable (f1, q.c1.r, q.c2.i) values(44,55,66);
  select * from quadtable;
   f1 |             q
  ----+---------------------------
    1 | ("(3.3,4.4)","(5.5,6.6)")
    2 | ("(,4.4)","(5.5,6.6)")
!  44 | ("(55,)","(,66)")
! (3 rows)

  -- The object here is to ensure that toasted references inside
  -- composite values don't cause problems.  The large f1 value will
--- 95,115 ----

  -- test insertion/updating of subfields
  update people set fn.suffix = 'Jr';
+ ERROR:  unexpected FieldStore
  select * from people;
!      fn      |     bd
! -------------+------------
!  (Joe,Blow,) | 01-10-1984
  (1 row)

  insert into quadtable (f1, q.c1.r, q.c2.i) values(44,55,66);
+ ERROR:  unexpected FieldStore
  select * from quadtable;
   f1 |             q
  ----+---------------------------
    1 | ("(3.3,4.4)","(5.5,6.6)")
    2 | ("(,4.4)","(5.5,6.6)")
! (2 rows)

  -- The object here is to ensure that toasted references inside
  -- composite values don't cause problems.  The large f1 value will

======================================================================

Andrew Dunstan <andrew@dunslane.net> wrote:

> With the following settings
>
>     custom_variable_classes = 'auto_explain'
>     auto_explain.log_min_duration = 0
>     auto_explain.log_format = 'xml'
>     auto_explain.log_analyze = on
>     auto_explain.log_verbose = on
>     shared_preload_libraries = 'auto_explain'
>
> I am getting regression failures on the rowtypes, transactions and
> arrays tests. Diff file is attached. I'm going to look into it, but if
> anyone has a good idea what's going on please speak up ASAP.

Thank you for the bug report.  Auto_explan tries to explain the query
even if it is failed, but schema objects that are created in the same
transaction might not be available. "cache lookup failed" erros can be
avoided if auto_explain skips explaining queries in aborted transactions.

The attached patch will fix the bug, but I'm not sure whether this usage
of TransactionBlockStatusCode() is sane. Comments or better ideas?

Regards,
---
Takahiro Itagaki
NTT Open Source Software Center

Andrew Dunstan <andrew@dunslane.net> writes:
> I am getting regression failures on the rowtypes, transactions and 
> arrays tests. Diff file is attached. I'm going to look into it, but if 
> anyone has a good idea what's going on please speak up ASAP.

Hmm.  Didn't decipher the transactions-test failures yet, but the
errors about "unexpected refassgnexpr" and "unexpected FieldStore"
are a pre-existing bug that you can expose without auto_explain:

regression=# explain verbose INSERT INTO arrtest (a[1:5], b[1:1][1:2][1:2], c, d, f, g)VALUES ('{1,2,3,4,5}',
'{{{0,0},{1,2}}}','{}', '{}', '{}', '{}');
 
ERROR:  unexpected refassgnexpr

The problem is that get_rule_expr() expects any top-level assignment
nodes to have been stripped off by processIndirection(), and explain.c
is failing to cater to that.  It's not just a simple oversight ---
it's not exactly clear how such an expr tree should be printed without
any context.  Normally, we're decoding such things in the context
of reverse-listing a whole INSERT or UPDATE statement, and the upper
level ruleutils.c code takes care of putting the indirection annotation
on the target column name.  But for EXPLAIN we're just trying to treat
the plan target list as a list of standalone expressions.  What should
the display look like?

If you're lost about the point here, it's this: an ArrayExpr can
represent the result of an array assignment.  For example, given
UPDATE foo SET a[42] = x, what is generated is an ArrayExpr
with refexpr = a, refupperindexpr = 42, refassgnexpr = x.
On execution that generates the updated array value that needs to
get stored back into the "a" column.  How would you like to print
that in EXPLAIN?  Same deal for FieldStore: it can represent generating
the new value of a composite column after replacing one field.
        regards, tom lane

Andrew Dunstan <andrew@dunslane.net> writes:
> I am getting regression failures on the rowtypes, transactions and 
> arrays tests. Diff file is attached. I'm going to look into it, but if 
> anyone has a good idea what's going on please speak up ASAP.

And as for the transactions-test failures, a stack trace tells the tale:

#0  errfinish (dummy=0) at elog.c:366
#1  0x00000000006e2d3c in elog_finish (elevel=<value optimized out>,    fmt=<value optimized out>) at elog.c:1145
#2  0x00000000006dbf9a in get_relid_attribute_name (relid=64726,    attnum=<value optimized out>) at lsyscache.c:786
#3  0x0000000000685d94 in get_variable (var=0x0, levelsup=45293976,    showstar=<value optimized out>,
context=0x7fffb0e11440)at ruleutils.c:3693
 
#4  0x000000000068a35d in deparse_expression_pretty (expr=0x2b320c0,    dpcontext=0x2a962e0, forceprefix=0 '\0',
showimplicit=127'\177',    prettyFlags=0, startIndent=<value optimized out>) at ruleutils.c:2055
 
#5  0x000000000052552c in show_plan_tlist (es=<value optimized out>,    plan=<value optimized out>) at explain.c:1286
#6  ExplainNode (es=<value optimized out>, plan=<value optimized out>)   at explain.c:1001
#7  0x00007f85f70341a3 in explain_ExecutorEnd (queryDesc=0x2abb918)   at auto_explain.c:244
#8  0x0000000000535684 in PortalCleanup (portal=<value optimized out>)   at portalcmds.c:268
#9  0x00000000006ff82f in AtSubAbort_Portals (mySubid=2,    parentSubid=<value optimized out>, parentXactOwner=<value
optimizedout>)   at portalmem.c:825
 
#10 0x000000000048a5ea in AbortSubTransaction () at xact.c:4016

We're trying to EXPLAIN a plan that refers to a table that no longer
exists, because the subtransaction that created it is already rolled
back.  I think the proximate fault here is in PortalCleanup, which
claims it ain't gonna do this:
   /*    * Shut down executor, if still running.  We skip this during error abort,    * since other mechanisms will
takecare of releasing executor resources,    * and we can't be sure that ExecutorEnd itself wouldn't fail.    */
 

but the test it's actually using is
       if (portal->status != PORTAL_FAILED)

and this particular portal is not marked FAILED, because it wasn't
running when the abort happened.  I think maybe we should force
portals into FAILED state when aborting a (sub)transaction.
Or leave the state alone but add a check on the transaction state
in this test in PortalCleanup.  Thoughts?

(Again, I think this is a pre-existing bug that auto_explain is just
exposing to the world ...)
        regards, tom lane

Takahiro Itagaki <itagaki.takahiro@oss.ntt.co.jp> writes:
> Thank you for the bug report.  Auto_explan tries to explain the query
> even if it is failed, but schema objects that are created in the same
> transaction might not be available. "cache lookup failed" erros can be
> avoided if auto_explain skips explaining queries in aborted transactions.

I don't think this is auto_explain's fault.  ExecutorEnd() shouldn't
be getting run in an aborted xact --- there are too many other things
that are likely to fall over.  See my response to Andrew.
        regards, tom lane

I wrote:
> Andrew Dunstan <andrew@dunslane.net> writes:
>> I am getting regression failures on the rowtypes, transactions and 
>> arrays tests. Diff file is attached. I'm going to look into it, but if 
>> anyone has a good idea what's going on please speak up ASAP.

> And as for the transactions-test failures, a stack trace tells the tale:
> ...
> (Again, I think this is a pre-existing bug that auto_explain is just
> exposing to the world ...)

I've applied a patch for that one.
        regards, tom lane

I wrote:
> If you're lost about the point here, it's this: an ArrayExpr can
> represent the result of an array assignment.  For example, given
> UPDATE foo SET a[42] = x, what is generated is an ArrayExpr
> with refexpr = a, refupperindexpr = 42, refassgnexpr = x.
> On execution that generates the updated array value that needs to
> get stored back into the "a" column.  How would you like to print
> that in EXPLAIN?  Same deal for FieldStore: it can represent generating
> the new value of a composite column after replacing one field.

After thinking about this for awhile, the best representation I can
come up with is to let the EXPLAIN output look like an UPDATE
assignment.  That is, from something like
UPDATE foo SET arraycol[42] = x WHERE ...

an EXPLAIN VERBOSE would include this in the targetlist display:
Output: ... , arraycol[42] = x , ...

An alternative possibility is to strip the indirection node(s) and
just show "x"; but that seems to leave a good deal of information
hidden, especially if the subscript expressions are complicated.

Objections, better ideas?
        regards, tom lane

Andrew Dunstan <andrew@dunslane.net> writes:
> With the following settings

>     custom_variable_classes = 'auto_explain'
>     auto_explain.log_min_duration = 0
>     auto_explain.log_format = 'xml'
>     auto_explain.log_analyze = on
>     auto_explain.log_verbose = on
>     shared_preload_libraries = 'auto_explain'

> I am getting regression failures on the rowtypes, transactions and 
> arrays tests.

This seems to be fixed now in HEAD.  Somebody should try 8.4 as well.
        regards, tom lane

Tom Lane wrote:
> Andrew Dunstan <andrew@dunslane.net> writes:
>   
>> With the following settings
>>     
>
>   
>>     custom_variable_classes = 'auto_explain'
>>     auto_explain.log_min_duration = 0
>>     auto_explain.log_format = 'xml'
>>     auto_explain.log_analyze = on
>>     auto_explain.log_verbose = on
>>     shared_preload_libraries = 'auto_explain'
>>     
>
>   
>> I am getting regression failures on the rowtypes, transactions and 
>> arrays tests.
>>     
>
> This seems to be fixed now in HEAD.  Somebody should try 8.4 as well.
>
>             
>   

Done. All is good now. Thanks.

cheers

andrew