Query returns error "there is no parameter $1" but server logs that there are two parameters supplied

Started by Paul De Audneyover 2 years ago4 messagesbugs
Jump to latest
#1Paul De Audney
paul.deaudney@safetyculture.io

Hello,

PostgreSQL slack suggested I submit this as a bug report as we are
supplying parameters but the server is saying we're missing 1. Even when we
supply 2 or more to our queries.

The following is the server logs & parameters supplied for a query that
returns an error message. This occurs around 2-10 times per hour on a
database with around 120-1000 queries per second. With around 300 users
connected, with roughly two thirds of those users idling due to connection
pools in the application code (node-pg).
We have other queries logging the same error on a different database on the
same server infrastructure using golang based connection pools/drivers
(jackc/pgx).

2023-07-17 01:39:20.265 UTC [1857486] user@db_name ERROR: there is no
parameter $1 at character 24
2023-07-17 01:39:20.265 UTC [1857486] user@db_name CONTEXT: unnamed portal
with parameters: $1 = 'template_31f98dcda25c482eb0b086a0081d28a8', $2 =
'template_31F98DCDA25C482EB0B086A0081D28A8'
2023-07-17 01:39:20.265 UTC [1857486] user@db_name STATEMENT:
SELECT templates.id, templates.rev, templates.json,
meta.template_data as meta_template_data, meta.date_draft_modified,
meta.draft_author_name
FROM templates
LEFT JOIN templates_meta as meta
ON templates.id = meta.id
WHERE (templates.id = $1 OR templates.id = $2)

This query does work when re-run exactly as shown there.

PostgreSQL version:

PostgreSQL 14.8 (Ubuntu 14.8-1.pgdg20.04+1) on x86_64-pc-linux-gnu,
compiled by gcc (Ubuntu 9.4.0-1ubuntu1~20.04.1) 9.4.0, 64-bit

Extensions loaded are:

postgres=# \dx
List of installed extensions
Name | Version | Schema |
Description
--------------------+---------+------------+------------------------------------------------------------------------
citus | 11.2-2 | pg_catalog | Citus distributed database
citus_columnar | 11.2-1 | pg_catalog | Citus Columnar extension
pg_stat_statements | 1.9 | public | track planning and execution
statistics of all SQL statements executed
pgaudit | 1.6.2 | public | provides auditing functionality
plpgsql | 1.0 | pg_catalog | PL/pgSQL procedural language
(5 rows)

Regards,

Paul De Audney

#2Laurenz Albe
laurenz.albe@cybertec.at
In reply to: Paul De Audney (#1)
Re: Query returns error "there is no parameter $1" but server logs that there are two parameters supplied

On Mon, 2023-07-17 at 12:25 +1000, Paul De Audney wrote:

We have other queries logging the same error on a different database on the same server infrastructure using golang based connection pools/drivers (jackc/pgx).

2023-07-17 01:39:20.265 UTC [1857486] user@db_name ERROR:  there is no parameter $1 at character 24
2023-07-17 01:39:20.265 UTC [1857486] user@db_name CONTEXT:  unnamed portal with parameters: $1 = 'template_31f98dcda25c482eb0b086a0081d28a8', $2 = 'template_31F98DCDA25C482EB0B086A0081D28A8'
2023-07-17 01:39:20.265 UTC [1857486] user@db_name STATEMENT:
              SELECT templates.id, templates.rev, templates.json, meta.template_data as meta_template_data, meta.date_draft_modified, meta.draft_author_name
              FROM templates
                     LEFT JOIN templates_meta as meta
                               ON templates.id = meta.id
              WHERE (templates.id = $1 OR templates.id = $2)

This query does work when re-run exactly as shown there.

To determine if that is a bug in PostgreSQL or the PostgreSQL driver, please reproduce
the problem on a test system with "log_min_duration_statement = 0" and show all relevant
parts of the log file.

Yours,
Laurenz Albe

#3Tom Lane
tgl@sss.pgh.pa.us
In reply to: Paul De Audney (#1)
Re: Query returns error "there is no parameter $1" but server logs that there are two parameters supplied

Paul De Audney <paul.deaudney@safetyculture.io> writes:

2023-07-17 01:39:20.265 UTC [1857486] user@db_name ERROR: there is no
parameter $1 at character 24
2023-07-17 01:39:20.265 UTC [1857486] user@db_name CONTEXT: unnamed portal
with parameters: $1 = 'template_31f98dcda25c482eb0b086a0081d28a8', $2 =
'template_31F98DCDA25C482EB0B086A0081D28A8'
2023-07-17 01:39:20.265 UTC [1857486] user@db_name STATEMENT:
SELECT templates.id, templates.rev, templates.json,
meta.template_data as meta_template_data, meta.date_draft_modified,
meta.draft_author_name
FROM templates
LEFT JOIN templates_meta as meta
ON templates.id = meta.id
WHERE (templates.id = $1 OR templates.id = $2)

"character 24" is not anywhere near where the $1 symbol is in that
query string, so I'm betting that this error does not refer to the
outer client-submitted query but to some plpgsql or sql function that
is getting invoked along the way. Since you've provided exactly no
context for this log snippet, it's hard to speculate further than
that.

(And yeah, if that is how such a problem gets logged then I agree
we could stand to work on providing better error context. But again,
without a reproducible test case it's hard to make any progress.)

regards, tom lane

#4Paul De Audney
paul.deaudney@safetyculture.io
In reply to: Tom Lane (#3)
Re: Query returns error "there is no parameter $1" but server logs that there are two parameters supplied

Hi Tom, Laurenz,

Thanks for your replies. Apologies for the sparse bug report.
I will work on collecting more details & hopefully a reproducible test case
as per the bug reporting guidelines. Along with sample data etc.

In the meantime here are some more details from another database (same
host/cluster & different database driver in use) that does not have any
triggers involved.
The first post was using node-pg (nodejs), this one querying
iot.device_reading is using jackc/pgx (golang).

The following pasted details are also located at
https://gist.github.com/pdeaudney/28d991c3831c2f5963461dd47669bedd for
potentially nicer formatting.

2023-07-17 01:30:37.418 UTC [1843972] iot_stats@iot_devicereadings
ERROR: there is no parameter $1 at character 24
2023-07-17 01:30:37.418 UTC [1843972] iot_stats@iot_devicereadings
CONTEXT: unnamed portal with parameters: $1 = '2023-07-16
01:30:37.329811Z', $2 = 'pixel', $3 = 'byo_monnit'
2023-07-17 01:30:37.418 UTC [1843972] iot_stats@iot_devicereadings STATEMENT:
SELECT r.vendor, COUNT(r.vendor_id) as "count"
FROM (
SELECT DISTINCT vendor, vendor_id
FROM iot.device_reading
WHERE created >= $1 AND vendor IN ($2, $3)
) r
GROUP BY r.vendor

iot_devicereadings=# \d+ iot.device_reading
Table
"iot.device_reading"
Column | Type | Collation | Nullable | Default |
Storage | Compression | Stats target | Description
-----------+-----------------------------+-----------+----------+---------+----------+-------------+--------------+-------------
asset_id | character varying(36) | | not null | |
extended | | |
vendor | character varying(36) | | not null | |
extended | | |
vendor_id | character varying(36) | | not null | |
extended | | |
type | character varying(36) | | not null | |
extended | | |
value | real | | not null | |
plain | | |
created | timestamp without time zone | | not null | |
plain | | |
Indexes:
"device_reading_pk" PRIMARY KEY, btree (asset_id, type, created)
"device_reading_asset_id_created_idx" btree (asset_id, created)
"device_reading_created_idx" btree (created)
Access method: heap

iot_devicereadings=# \dx
List of installed extensions
Name | Version | Schema |
Description
--------------------+---------+------------+------------------------------------------------------------------------
citus | 11.2-2 | pg_catalog | Citus distributed database
citus_columnar | 11.1-1 | pg_catalog | Citus Columnar extension
pg_buffercache | 1.3 | public | examine the shared buffer cache
pg_repack | 1.4.8 | public | Reorganize tables in
PostgreSQL databases with minimal locks
pg_stat_statements | 1.9 | public | track planning and execution
statistics of all SQL statements executed
pgaudit | 1.6.2 | public | provides auditing functionality
plpgsql | 1.0 | pg_catalog | PL/pgSQL procedural language
uuid-ossp | 1.1 | public | generate universally unique
identifiers (UUIDs)
(8 rows)

iot_devicereadings=# select version();
version
-----------------------------------------------------------------------------------------------------------------------------------
PostgreSQL 14.8 (Ubuntu 14.8-1.pgdg20.04+1) on x86_64-pc-linux-gnu,
compiled by gcc (Ubuntu 9.4.0-1ubuntu1~20.04.1) 9.4.0, 64-bit
(1 row)

Regards,

Paul De Audney

On Mon, Jul 17, 2023 at 11:45 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:

Paul De Audney <paul.deaudney@safetyculture.io> writes:

2023-07-17 01:39:20.265 UTC [1857486] user@db_name ERROR: there is no
parameter $1 at character 24
2023-07-17 01:39:20.265 UTC [1857486] user@db_name CONTEXT: unnamed

portal

with parameters: $1 = 'template_31f98dcda25c482eb0b086a0081d28a8', $2 =
'template_31F98DCDA25C482EB0B086A0081D28A8'
2023-07-17 01:39:20.265 UTC [1857486] user@db_name STATEMENT:
SELECT templates.id, templates.rev, templates.json,
meta.template_data as meta_template_data, meta.date_draft_modified,
meta.draft_author_name
FROM templates
LEFT JOIN templates_meta as meta
ON templates.id = meta.id
WHERE (templates.id = $1 OR templates.id = $2)

"character 24" is not anywhere near where the $1 symbol is in that
query string, so I'm betting that this error does not refer to the
outer client-submitted query but to some plpgsql or sql function that
is getting invoked along the way. Since you've provided exactly no
context for this log snippet, it's hard to speculate further than
that.

(And yeah, if that is how such a problem gets logged then I agree
we could stand to work on providing better error context. But again,
without a reproducible test case it's hard to make any progress.)

regards, tom lane

--

Paul De Audney

Senior Staff Engineer

72 Foveaux Street, Surry Hills NSW 2010
P +61 1300 984 245
E paul.deaudney@safetyculture.com | www.safetyculture.com
<http://safetyculture.com/&gt;