Intermittent instability (binds not corresponding, query strings being intermixed)

[mattadams]

When I was using Pgtcl release 2.7.5 everything was quite stable, however I have upgraded to 2.8.0 (comes out as 2.7.7 when compiled) and am encountering intermittent instability.

With 2.8.0, I will get curious errors like this:

postgres[73105]: [9-1] 2022-04-13 19:40:12.094 MDT [73105] ERROR:  bind message supplies 3 parameters, but prepared statement "" requires 7
postgres[73105]: [9-2] 2022-04-13 19:40:12.094 MDT [73105] STATEMENT:  
postgres[73105]: [9-3]            INSERT INTO logs (inserted_at, severity, log, creator, pid, tid, queue_id)
postgres[73105]: [9-4]            VALUES ($1, $2, $3, $4, $5, $6, $7)
postgres[73105]: [9-5]

and

postgres[73111]: [9-1] 2022-04-13 19:40:12.750 MDT [73111] ERROR:  syntax error at or near "NULextended" at character 88
postgres[73111]: [9-2] 2022-04-13 19:40:12.750 MDT [73111] STATEMENT:  UPDATE datasets SET imported_at = refreshed_at WHERE code = 'ABST' AND (imported_at IS NULextended ->> 'event' = 'appended_at'
postgres[73111]: [9-3]                

In the latter case it looks like two separate SQL statements are being intermixed because the actual SQL for the latter comes from:

UPDATE datasets SET ${event}_at = refreshed_at WHERE code = [::pg::quote $dataset_code] AND (${event}_at IS NULL OR refreshed_at > ${event}_at) RETURNING refreshed_at, ${event}_at

In this case the actual SQL error makes absolutely no sense, because the bit that reads extended ->> 'event' = 'appended_at' comes from another query entirely.

Thoughts?

[mattadams]

Both of these statements are run through pg::sqlexec (via Pg_exec in pgtclCmds.c).

Platform is FreeBSD 13.0-RELEASE-p10 with: tcl86-8.6.12 postgresql13-client-13.5 postgresql13-server-13.5

[resuna]

Can you provide the source code that is generating this SQL and error?

I suspect there's a problem in the UTF conversion code (2.7.6) in some code path I missed, so if you can produce a test case it would be extremely helpful.

[mattadams]

I will do my best to provide something that replicates it. Unfortunately it is very difficult to reproduce reliably in my environment. Either that, or I'll isolate it myself and provide a patch.

I did see ticket 1bd796d9c2 (multiple issues in Tcl_DString functions) in Tcl 8.6.12 and I am hoping that the problem doesn't stem from this.

I can confirm the problem originates in 2.7.6, and is present in the most current code. For now I've backported the listener fix to 2.7.5 and am using that, but I will keep this on my radar to do something about.

[resuna]

Can you at least provide the Tcl code that generated the errors you listed so I can get an idea of where to look?

The possibility of an underlying bug in Tcl_DString is scary.

[resuna]

Or the parameters to sqlexec?

[resuna]

@mattadams ^

[resuna]

The empty string in the bind error is apparently a PostgreSQL artifact. Which is a pity because I was hoping it would be a useful diagnostic. This stackoverflow article shows it happening with javascript bindings. :(

https://stackoverflow.com/questions/43755454/bind-message-supplies-1-parameters-but-prepared-statement-requires-2

[resuna]

@mattadams Try branch BCK-6946

[resuna]

Fixed in 3.1.0