Performance problem when moving from 2.x to 3.x

[pst9354]

Hi,

We have a communication server that handles a lot of connections (to/from vehicles).
The server issues a lot of SQL commands, mostly SELECT and UPDATE.

When updating the server from version 2.x (2.6.2) to 3.x (3.2.0), we experience that the performance is less than 50% of what it was before.

I just did some really basic benchmarks, which should highligt the problem.
The test just run a simple SELECT 1000 times and measures how long it takes.

3.2.0:
Elapsed: execute() 634 ms.
Elapsed: execute(QueryMode.simple) 186 ms.

2.6.2:
Elapsed query(): 230 ms.
Elapsed execute(): 193 ms.

The tests are run against localhost.
The biggest problem seems to be the new execute() command.

Any comments/ideas?

---

Source 2.6.2:
`void test() async {
PostgreSQLConnection conn =
PostgreSQLConnection('127.0.0.1', 5433, 'postgres', username: 'postgres', password: 'xxxxx');
await conn.open();

String q = "SELECT 1,now(),'TEST'";
int nLoops = 1000;

Stopwatch s = Stopwatch();
s.start();

for (int i = 0; i < nLoops; i++) {
PostgreSQLResult res = await conn.query(q);
}
print('Elapsed query(): ${s.elapsedMilliseconds} ms.');

s.reset();

for (int i = 0; i < nLoops; i++) {
int n = await conn.execute(q);
}
print('Elapsed execute(): ${s.elapsedMilliseconds} ms.');
}`

Source 3.2.0:
`void test() async {
final ConnectionSettings connectionSettings =
ConnectionSettings(applicationName: 'vehicleservice_autodispatch', sslMode: SslMode.disable);
Connection conn = await Connection.open(
Endpoint(host: '127.0.0.1', database: 'postgres', port: 5433, username: 'postgres', password: 'xxxxx'),
settings: connectionSettings);

String q = "SELECT 1,now(),'TEST'";
int nLoops = 1000;

Stopwatch s = Stopwatch();
s.start();

for (int i = 0; i < nLoops; i++) {
Result res = await conn.execute(q);
}
print('Elapsed: execute() ${s.elapsedMilliseconds} ms.');

s.reset();

for (int i = 0; i < nLoops; i++) {
Result res = await conn.execute(q, queryMode: QueryMode.simple);
}
print('Elapsed: execute(QueryMode.simple) ${s.elapsedMilliseconds} ms.');
}
`

[isoos]

The biggest problem seems to be the new execute() command.
Any comments/ideas?

Re: your application performance changes: can you highlight a few real-world queries that are affected by the change?

Re: benchmarks: it seems that the new version with the simple query protocol is right in the same ballpark as it was before, so I'd just assume that difference comes from that vs. the extended protocol. If your application can use the simple protocol for your queries, feel free to specify it as such, and it will use that.

The previous implementation may have used inlined variables to create simple-protocol queries automatically, but we no longer consider that something we want to use or implement at the package level. Instead, we default on the safer side to prevent any kind of sql injection.

/cc @simolus3 for further comments

[simolus3]

The queries in the example posted here don't use variables. I thought we would use the simple protocol by default for that, but it seems like we only do that if it's been explicitly set to simple or if result rows are ignored. I'm not sure I remember why, I think it was something about result rows having a different format for some types in the simple protocol?

It's expected that the extended protocol takes longer (there are more roundtrips required), but some of the steps can be pipelined.

[pst9354]

Here is a sample query: (we are not using "variables" in queries).

SELECT (EXTRACT(epoch FROM now()-last_picking_list_time)/60)::int FROM _vehicle WHERE number='$vehicle' AND COALESCE(suti_id,0)=0;

Are there any risks/problems using the simple-protocol?
If not, then we will just change all execute() to use simple-protocol.

[pst9354]

But...

If there is no harm in using the simple-protocol, maybe the execute() method should default to simple-protocol if parameters is null?

[pst9354]

I added another test (create a table with 1000 random records and then updating them, 1 row at a time).
They are labeled "Elapsed UPDATE".
("Elapsed SELECT" is from the original SELECT test.)

3.2.0
Elapsed SELECT: execute() 658 ms.
Elapsed SELECT: execute(QueryMode.simple) 191 ms.
Elapsed UPDATE: update() 640 ms.
Elapsed UPDATE: update(ignoreRows: true) 350 ms.
Elapsed UPDATE: update(QueryMode.simple) 325 ms.

2.6.2.
Elapsed SELECT: query(): 245 ms.
Elapsed SELECT: execute(): 196 ms.
Elapsed UPDATE: query() 371 ms.
Elapsed UPDATE: execute() 375 ms.

[pst9354]

We just discovered that we can't use QueryMode.simple.
I don't know if it is a bug or not.

Example:
SELECT 1,now(),'TEST'
Returns ResultRows like:
ResultRow ([1, Instance of 'UndecodedBytes', TEST])

When running execute() without QueryMode.simple:
Returns ResultRows like:
ResultRow ([1, 2024-05-16 08:14:53.759141Z, TEST])

[pst9354]

There is also a problem with the "double precision" type:

Query: SELECT 1,now(),'TEST', 3::double precision"

When running execute() with QueryMode.simple:
ResultRow ([1, Instance of 'UndecodedBytes', TEST, 3])

When running execute() without QueryMode.simple:
ResultRow ([1, 2024-05-16 08:22:47.646683Z, TEST, 3.0])

QueryMode.simple converts the double precision value to an integer.

[isoos]

@pst9354: good points there, I think we should try to fix these issues with the simple query protocol's decoding. Not sure how much time I'll have for that this week, are you interested to look into and debug it a bit further? The best way would be to create a few test cases (for each missed type) and then check what is going on at the value decoding parts.

[pst9354]

Ok, I found that a lot of "conversions" are missing in PostgresTextDecoder.convert()

I will try to add the missing ones.

[pst9354]

Added a pull request for fixing some of the conversions.
#338

[pst9354]

After changing to QueryMode.simple, we still had significant performance issues, comparing v2 to v3.

That was caused by sslMode defaulting to SslMode.require.
The old version (v2) defaulted to: useSSL to false.

I don't know if that is documented?

Well, now we have ported some of our services to v3 and we have the same performance as with v2.

[isoos]

That was caused by sslMode defaulting to SslMode.require.
I don't know if that is documented?

Yeah, we had a long rewrite for v3, and documentation was not a strong part of that. I'm glad that we know the reason, but I'm a bit worried: how are you using the connections? Are you using connection pool? Because the overhead of the ssl protocol shouldn't be two-fold, but with frequent reconnects it may be.

[pst9354]

Understandable...

No connection pool.
We just open a connection at startup and reuses it.

I wonder if Darts SecureSocket is to blame.

[pst9354]

Our most busy servers, handles more than 50 messages / second.
Most of the messages involves one or more SQL queries.