Inconsistent compilation error

On Wed, Apr 18, 2018 at 9:02 PM, <raf@raf.org> wrote:

Hi,

postgresql-9.5.12 on debian-9

I have a stored function with code that looks like:

create or replace function tla_audit_delete_thing()
returns boolean stable language plpgsql as $$
declare
r record;
status boolean := 1;
begin
for r in select _.* from blah_history _ where _.original_id not in
(select id from blah)
loop
raise notice '% %', 'blah_history.original_id', r;
status := 0;
end loop;
[...]
end
$$
security definer
set search_path = public, pg_temp;
revoke all on function tla_audit_delete_thing() from public;
grant execute on function tla_audit_delete_thing() to staff;

And I have a program that loads stored functions from disk
when they are different to what's in the database and I have
just loaded a very old database backup, brought the schema up
to date, and tried to bring the stored functions up to date.

But I'm getting this compilation error when it tries to load this
function:

ERROR: too many parameters specified for RAISE
CONTEXT: compilation of PL/pgSQL function "tla_audit_delete_thing"
near line 9

Traceback (most recent call last):
File "lib/loadfunc.py", line 228, in main
db.cursor().execute(src)
File "/usr/lib/python2.7/dist-packages/pgdb.py", line 1026, in
execute
return self.executemany(operation, [parameters])
File "/usr/lib/python2.7/dist-packages/pgdb.py", line 1050, in
executemany
rows = self._src.execute(sql)
ProgrammingError: ERROR: too many parameters specified for RAISE
CONTEXT: compilation of PL/pgSQL function "tla_audit_delete_thing"
near line 9

The line in question is:

raise notice '% %', 'blah_history.original_id', r;

Which looks fine. The really wierd thing is that this happens when done on
a
debian9 host but when I load the function from another host (my macos
laptop)
with the same function into the same database, it works fine.

I've never encountered an inconsistency like this before.

Any suggestions as to what might be causing it?

The python versions are slightly different and the pgdb module versions
are different but I wouldn't have thought that that would affect the
compilation performed by the database server itself:

debian9: python-2.7.13 pgdb-5.0.3
macos-10.11.6: python-2.7.14 pgdb-4.2.2

And the sql sent to the database server is identical from both hosts.

And I don't think anything much has changed on the debian host recently.

And it's not just the old backup. The same is happening with other copies
of
essentially the same database.

And all the other stored functions were loaded fine. It's just this one
that
went wrong.

Thanks in advance for any insights you can share.

cheers,
raf

*>The line in question is:>> raise notice '% %',
'blah_history.original_id', r;>>Which looks fine. It is not fine. You have
specifed TWO percent signs (%) which requires TWO argumenrts,but you have
only provided ONE -> r.*

*Hence-> ERROR: too many parameters specified for RAISE *

*https://www.postgresql.org/docs/9.6/static/plpgsql-errors-and-messages.html#PLPGSQL-STATEMENTS-RAISE
<https://www.postgresql.org/docs/9.6/static/plpgsql-errors-and-messages.html#PLPGSQL-STATEMENTS-RAISE&gt;&quot;
Inside the format string, % is replaced by the string representation of the
next optional argument's value"*--
*Melvin Davidson*
*Maj. Database & Exploration Specialist*
*Universe Exploration Command – UXC*
Employment by invitation only!

On 19 April 2018 at 13:28, Melvin Davidson <melvin6925@gmail.com> wrote:

It is not fine. You have specifed TWO percent signs (%) which requires TWO
argumenrts,
but you have only provided ONE -> r.

I'm confused about this statement.

Did you perhaps overlook the fact that there are in fact two
arguments? I'm unsure why you're considering
'blah_history.original_id' not to be an argument here.

--
David Rowley http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

I'm unsure why you're considering
'blah_history.original_id' not to be an argument here.

On Wed, Apr 18, 2018 at 9:50 PM, David Rowley <david.rowley@2ndquadrant.com>
wrote:

On 19 April 2018 at 13:28, Melvin Davidson <melvin6925@gmail.com> wrote:

It is not fine. You have specifed TWO percent signs (%) which requires

TWO

argumenrts,
but you have only provided ONE -> r.

I'm confused about this statement.

Did you perhaps overlook the fact that there are in fact two
arguments? I'm unsure why you're considering
'blah_history.original_id' not to be an argument here.

--
David Rowley http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

There are two possibilities here.
1`. The compiler might be expecting a variable and not accepting a text
literal.
Normally, literals are inside the first quotes. IE: raise notice '
blah_history.original_id' %', r;
OR
2. since this is in a loop, r might be NULL

--
*Melvin Davidson*
*Maj. Database & Exploration Specialist*
*Universe Exploration Command – UXC*
Employment by invitation only!

raf@raf.org writes:

I have a stored function with code that looks like:

raise notice '% %', 'blah_history.original_id', r;

But I'm getting this compilation error when it tries to load this
function:

ERROR: too many parameters specified for RAISE

That is ... weird. The code is checking that the number of % symbols in
the string literal matches the number of comma-separated expressions after
the literal, and it sure looks like those match.

Which looks fine. The really wierd thing is that this happens when done on a
debian9 host but when I load the function from another host (my macos laptop)
with the same function into the same database, it works fine.

Weirder yet.

The only idea that comes to mind is that '%%', with nothing between the
percent signs, means a literal '%' character not two parameter markers.
If the contents of the string literal were '%%' then this is exactly
the error message you'd get.

So here's a long-shot theory: what's in your source code is not a plain
space but something weird like a no-break space, and when you transfer
that text from machine A to machine B, the no-break space is getting
dropped.

regards, tom lane

On Wed, Apr 18, 2018 at 7:04 PM, Melvin Davidson <melvin6925@gmail.com>
wrote:

Normally, literals are inside the first quotes. IE: raise notice '
blah_history.original_id' %', r;

​But a compiler doesn't care about human concepts like "normally" - it just
cares about "syntactically correct" and as David and Tom observe the
original post as visually observed is correct. Which leads one to think
that reality and the original post somehow don't match, or as Tom said what
the server sees and what is sent end up being different (client encoding
issues or some such).

And pretty sure "r" being NULL just puts an empty string where the % is.

David J.

On 04/18/2018 06:02 PM, raf@raf.org wrote:

Hi,

postgresql-9.5.12 on debian-9

I have a stored function with code that looks like:

create or replace function tla_audit_delete_thing()
returns boolean stable language plpgsql as $$
declare
r record;
status boolean := 1;
begin
for r in select _.* from blah_history _ where _.original_id not in (select id from blah)
loop
raise notice '% %', 'blah_history.original_id', r;
status := 0;
end loop;
[...]
end
$$
security definer
set search_path = public, pg_temp;
revoke all on function tla_audit_delete_thing() from public;
grant execute on function tla_audit_delete_thing() to staff;

So if you cut and paste the above directly into the database via psql on
the Debian host do you see the same issue?

And I have a program that loads stored functions from disk
when they are different to what's in the database and I have
just loaded a very old database backup, brought the schema up
to date, and tried to bring the stored functions up to date.

cheers,
raf

--
Adrian Klaver
adrian.klaver@aklaver.com

On 04/18/2018 06:02 PM, raf@raf.org wrote:

Hi,

But I'm getting this compilation error when it tries to load this
function:

ERROR: too many parameters specified for RAISE
CONTEXT: compilation of PL/pgSQL function "tla_audit_delete_thing" near line 9

Traceback (most recent call last):
File "lib/loadfunc.py", line 228, in main
db.cursor().execute(src)
File "/usr/lib/python2.7/dist-packages/pgdb.py", line 1026, in execute
return self.executemany(operation, [parameters])
File "/usr/lib/python2.7/dist-packages/pgdb.py", line 1050, in executemany
rows = self._src.execute(sql)
ProgrammingError: ERROR: too many parameters specified for RAISE
CONTEXT: compilation of PL/pgSQL function "tla_audit_delete_thing" near line 9

The line in question is:

raise notice '% %', 'blah_history.original_id', r;

Which looks fine. The really wierd thing is that this happens when done on a
debian9 host but when I load the function from another host (my macos laptop)
with the same function into the same database, it works fine.

I've never encountered an inconsistency like this before.

Any suggestions as to what might be causing it?

The python versions are slightly different and the pgdb module versions
are different but I wouldn't have thought that that would affect the
compilation performed by the database server itself:

debian9: python-2.7.13 pgdb-5.0.3

Hmm, wonder if there is an oops in the below:

http://www.pygresql.org/contents/changelog.html

Version 5.0 (2016-03-20)
Changes in the DB-API 2 module (pgdb):
"SQL commands are always handled as if they include parameters, i.e.
literal percent signs must always be doubled. This consistent behavior
is necessary for using pgdb with wrappers like SQLAlchemy."

macos-10.11.6: python-2.7.14 pgdb-4.2.2

And the sql sent to the database server is identical from both hosts.

And I don't think anything much has changed on the debian host recently.

And it's not just the old backup. The same is happening with other copies of
essentially the same database.

And all the other stored functions were loaded fine. It's just this one that
went wrong.

Thanks in advance for any insights you can share.

cheers,
raf

--
Adrian Klaver
adrian.klaver@aklaver.com

On Wednesday, April 18, 2018, Adrian Klaver <adrian.klaver@aklaver.com>
wrote:

Hmm, wonder if there is an oops in the below:

http://www.pygresql.org/contents/changelog.html

Version 5.0 (2016-03-20)
Changes in the DB-API 2 module (pgdb):
"SQL commands are always handled as if they include parameters, i.e.
literal percent signs must always be doubled. This consistent behavior is
necessary for using pgdb with wrappers like SQLAlchemy."

I'd hope not, as far as the driver is concerned the percent signs are text
content. It's plpgsql that is interpreting them directly in the server.

David J.

On Thu, Apr 19, 2018 at 8:13 AM, David G. Johnston <
david.g.johnston@gmail.com> wrote:

On Wednesday, April 18, 2018, Adrian Klaver <adrian.klaver@aklaver.com>
wrote:

Hmm, wonder if there is an oops in the below:

http://www.pygresql.org/contents/changelog.html

Version 5.0 (2016-03-20)
Changes in the DB-API 2 module (pgdb):
"SQL commands are always handled as if they include parameters, i.e.
literal percent signs must always be doubled. This consistent behavior is
necessary for using pgdb with wrappers like SQLAlchemy."

I'd hope not, as far as the driver is concerned the percent signs are text
content. It's plpgsql that is interpreting them directly in the server.

David J.

*Hmmm, looking at the code you provided us, it is obviously not what is
actually in production. So if you copy the actual function from the system
that works *

*and use that to frop and rebuild the function on the system that fails,
does that resolve the problem? I suspect there is an error in the failing
system that you have overlooked.*

--
*Melvin Davidson*
*Maj. Database & Exploration Specialist*
*Universe Exploration Command – UXC*
Employment by invitation only!

Tom Lane wrote:

raf@raf.org writes:

I have a stored function with code that looks like:

raise notice '% %', 'blah_history.original_id', r;

But I'm getting this compilation error when it tries to load this
function:

ERROR: too many parameters specified for RAISE

That is ... weird. The code is checking that the number of % symbols in
the string literal matches the number of comma-separated expressions after
the literal, and it sure looks like those match.

Which looks fine. The really wierd thing is that this happens when done on a
debian9 host but when I load the function from another host (my macos laptop)
with the same function into the same database, it works fine.

Weirder yet.

The only idea that comes to mind is that '%%', with nothing between the
percent signs, means a literal '%' character not two parameter markers.
If the contents of the string literal were '%%' then this is exactly
the error message you'd get.

So here's a long-shot theory: what's in your source code is not a plain
space but something weird like a no-break space, and when you transfer
that text from machine A to machine B, the no-break space is getting
dropped.

regards, tom lane

thanks but it is normal space character.

David G. Johnston wrote:

On Wed, Apr 18, 2018 at 7:04 PM, Melvin Davidson <melvin6925@gmail.com>
wrote:

Normally, literals are inside the first quotes. IE: raise notice '
blah_history.original_id' %', r;

​But a compiler doesn't care about human concepts like "normally" - it just
cares about "syntactically correct" and as David and Tom observe the
original post as visually observed is correct. Which leads one to think
that reality and the original post somehow don't match, or as Tom said what
the server sees and what is sent end up being different (client encoding
issues or some such).

And pretty sure "r" being NULL just puts an empty string where the % is.

David J.

passing a null value to raise notice outputs it as the string "NULL".

Adrian Klaver wrote:

On 04/18/2018 06:02 PM, raf@raf.org wrote:

Hi,

postgresql-9.5.12 on debian-9

I have a stored function with code that looks like:

create or replace function tla_audit_delete_thing()
returns boolean stable language plpgsql as $$
declare
r record;
status boolean := 1;
begin
for r in select _.* from blah_history _ where _.original_id not in (select id from blah)
loop
raise notice '% %', 'blah_history.original_id', r;
status := 0;
end loop;
[...]
end
$$
security definer
set search_path = public, pg_temp;
revoke all on function tla_audit_delete_thing() from public;
grant execute on function tla_audit_delete_thing() to staff;

So if you cut and paste the above directly into the database via psql on the
Debian host do you see the same issue?

No. Cutting and pasting the text into psql works fine.

Adrian Klaver wrote:

On 04/18/2018 06:02 PM, raf@raf.org wrote:

Hi,

But I'm getting this compilation error when it tries to load this
function:

ERROR: too many parameters specified for RAISE
CONTEXT: compilation of PL/pgSQL function "tla_audit_delete_thing" near line 9

Traceback (most recent call last):
File "lib/loadfunc.py", line 228, in main
db.cursor().execute(src)
File "/usr/lib/python2.7/dist-packages/pgdb.py", line 1026, in execute
return self.executemany(operation, [parameters])
File "/usr/lib/python2.7/dist-packages/pgdb.py", line 1050, in executemany
rows = self._src.execute(sql)
ProgrammingError: ERROR: too many parameters specified for RAISE
CONTEXT: compilation of PL/pgSQL function "tla_audit_delete_thing" near line 9

The line in question is:

raise notice '% %', 'blah_history.original_id', r;

Which looks fine. The really wierd thing is that this happens when done on a
debian9 host but when I load the function from another host (my macos laptop)
with the same function into the same database, it works fine.

I've never encountered an inconsistency like this before.

Any suggestions as to what might be causing it?

The python versions are slightly different and the pgdb module versions
are different but I wouldn't have thought that that would affect the
compilation performed by the database server itself:

debian9: python-2.7.13 pgdb-5.0.3

Hmm, wonder if there is an oops in the below:

http://www.pygresql.org/contents/changelog.html

Version 5.0 (2016-03-20)
Changes in the DB-API 2 module (pgdb):
"SQL commands are always handled as if they include parameters, i.e. literal
percent signs must always be doubled. This consistent behavior is necessary
for using pgdb with wrappers like SQLAlchemy."

well spotted! but i'm not sure. it depends on what they mean by
"literal percent signs". that might just mean percent signs that
appear in SQL string literals that need to be output ultimately
as actual percent signs but i thought that they always had to be
doubled. so i'm not sure what they are saying has changed in
that version. so maybe you are right.

but if they are suggesting that every single percent sign needs
to be doubled by the caller before passing sql to the pgdb
module, that sounds like an annoying change to have made.
but no doubt they have their reasons.

i've encountered other new behaviour with pygresql-5+ that i had
to find ways to disable/revert so it's not surprising that there
might be other oddities to encounter. i'm surprised it's only
become a problem now.

i think you're definitely right. when i change my function
loading program to duplicate all percent signs in all the source
code before passing it to pgdb, they all load successfully and a
subsequent audit of the code inside the database and on disk
still shows that they match, so pgdb must be de-duplicating all
the duplicated percent signs.

thanks so much for spotting this.

cheers,
raf

On 04/25/2018 05:33 AM, raf wrote:

Adrian Klaver wrote:

On 04/18/2018 06:02 PM, raf@raf.org wrote:

Hmm, wonder if there is an oops in the below:

http://www.pygresql.org/contents/changelog.html

Version 5.0 (2016-03-20)
Changes in the DB-API 2 module (pgdb):
"SQL commands are always handled as if they include parameters, i.e. literal
percent signs must always be doubled. This consistent behavior is necessary
for using pgdb with wrappers like SQLAlchemy."

well spotted! but i'm not sure. it depends on what they mean by
"literal percent signs". that might just mean percent signs that
appear in SQL string literals that need to be output ultimately
as actual percent signs but i thought that they always had to be
doubled. so i'm not sure what they are saying has changed in
that version. so maybe you are right.

but if they are suggesting that every single percent sign needs
to be doubled by the caller before passing sql to the pgdb
module, that sounds like an annoying change to have made.
but no doubt they have their reasons.

i've encountered other new behaviour with pygresql-5+ that i had
to find ways to disable/revert so it's not surprising that there
might be other oddities to encounter. i'm surprised it's only
become a problem now.

i think you're definitely right. when i change my function
loading program to duplicate all percent signs in all the source
code before passing it to pgdb, they all load successfully and a
subsequent audit of the code inside the database and on disk
still shows that they match, so pgdb must be de-duplicating all
the duplicated percent signs.

You might want to raise this on the PyGreSQL mailing list:

https://mail.vex.net/mailman/listinfo.cgi/pygresql

and see what they have to say.

thanks so much for spotting this.

cheers,
raf

--
Adrian Klaver
adrian.klaver@aklaver.com