Обсуждение: Query returns error "there is no parameter $1" but server logs that there are two parameters supplied

Поиск
Список
Период
Сортировка
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
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
basedconnection 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



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



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