I have two servers connecting to a PostgresSQL 9.6 db hosted on Azure. The servers are doing one thing - hitting the Postgres db with a SELECT 1 query every 5 seconds.
Typical time to connect to db and get data:
- Node:
25 MS - .NET Core 3.1 using Npsql 4.1.1(I have tried 4.1.2 too, no diff):
500 MS
My problem is that my .NET Core app is 20x slower than Node in getting data. I believe .NET Core is not pooling connections for some reason. This slowness occurs with both running the app locally and while running it on Azure App Services - no difference. I want to solve the .NET --> Postgres slowness.
Please only skim the relevant details and don't read the whole thing past this point - I believe only the .NET Core code is relevant.
A PsPing to the db from my machine (on which both the Node and the .NET Core apps are running:
Connecting to foobarPostGres:5432 (warmup): from someIp: 19.98ms
Connecting to foobarPostGres:5432: from someIp: 1.65ms
Connecting to foobarPostGres:5432 from someIp: 1.18ms
Connecting to foobarPostGres:5432: from someIp: 1.23ms
Connecting to foobarPostGres:5432: from someIp: 1.06ms
For sake of completeness, a sample of NODE times look like this (note that the first time it establishes a connection, it is also "slow"):
Attempting to establish a connection...
Elapsed ms: 644.1334999799728
RESP: { '?column?': 1 }
Elapsed ms: 22.76109904050827
RESP: { '?column?': 1 }
Elapsed ms: 21.984400033950806
RESP: { '?column?': 1 }
Elapsed ms: 26.043799996376038
RESP: { '?column?': 1 }
Elapsed ms: 22.538798987865448
RESP: { '?column?': 1 }
Connection times for .NET Core look like this:
5:13:32 PM: SLOW QUERY, CONN TIME: 4153, QUERY TIME: 18
5:13:53 PM: SLOW QUERY, CONN TIME: 707, QUERY TIME: 17
5:14:14 PM: SLOW QUERY, CONN TIME: 589, QUERY TIME: 16
5:14:35 PM: SLOW QUERY, CONN TIME: 663, QUERY TIME: 18
5:14:56 PM: SLOW QUERY, CONN TIME: 705, QUERY TIME: 16
Note the super-slow initial connection time and a long time to establish a connection on subsequent requests.
Anyway, because I am desperate, I am going to dump all my code now, with explanations. The connection string looks like this:
public static string CONNECTION_STRING {
get {
return $"Server={HOST}; User Id={USER}; Database={DB_NAME}; Port={PORT}; Password={PWD}; SSLMode=Prefer";
}
}
It is my understanding that I should get connection pooling out of the box if I use this connection string. Note that I have tried turning of SSL on both the db and taking that line out - it did not help.
My health check controller looks like this:
// GET api/health/getdbhealthselectone
[HttpGet]
[Route("getdbhealthselectone")]
public async Task<IActionResult> GetDbHealthSelectOne()
{
int testData = await _healthCheckRepo.RunHealthCheckSelectOne();
return Ok(testData);
}
My health check repo method looks like this:
public async Task<int> RunHealthCheckSelectOne()
{
await using var conn = new NpgsqlConnection(AzureDbConnectionInfo.CONNECTION_STRING);
var connTimer = System.Diagnostics.Stopwatch.StartNew(); // TODO: Remove this testing line
await conn.OpenAsync();
connTimer.Stop(); // TODO: Remove this testing line
var msToConnect = connTimer.ElapsedMilliseconds; // TODO: Remove this testing line
int testData = 999;
var jobsQueryTimer = System.Diagnostics.Stopwatch.StartNew(); // TODO: Remove this testing line0
await using (var cmd = new NpgsqlCommand("SELECT 1", conn))
await using (var reader = await cmd.ExecuteReaderAsync())
while (await reader.ReadAsync()) {
testData = reader.GetInt32(0);
};
jobsQueryTimer.Stop(); // TODO: Remove this testing line
var msToQuery = jobsQueryTimer.ElapsedMilliseconds; // TODO: Remove this testing line
LogQueryIfSlow(msToConnect, msToQuery, _logger); // TODO: Remove this testing line
return testData;
}
Note the timers here - await conn.OpenAsync(); is what takes the bulk of the time by far, the queries themselves are fast. Also, for sake of saving time - I have run this code WITHOUT async before, no difference.
Finally, in case there are dependency injection concerns, the repository is in a class library, the API project references it, and:
services.AddSingleton<IHealthCheckRepository, HealthCheckRepository>();
This is how it sees it.
I believe this is all the relevant information - I have been on the phone with Azure support and they found no issues with the db config. The .NET Core app is super light, so it's not like it's overloaded and it's in testing, so no traffic besides my tests.
Extra: For the sake of completeness, here is my WHOLE node app which hits the db and gets the performance posted (conn data taken out).
const { Pool, Client } = require('pg');
const { performance } = require('perf_hooks');
const pool = new Pool({
user: 'SECRET',
host: 'SECRET',
database: 'SECRET',
password: 'SECRET',
port: 5432,
})
function runQuery(pool) {
var t0 = performance.now();
pool.query('SELECT 1', (err, res) => {
if (err) {
console.log('ERROR: ', err.stack)
} else {
console.log('RESP: ', res.rows[0])
}
var t1 = performance.now();
console.log('Elapsed ms: ', t1-t0);
//pool.end()
});
}
setInterval(() => {runQuery(pool)}, 5000);
EDIT: For posterity, here are the times in .NET Core after fixing the connection pool timeout - it's faster than node, except on that initial connection, which seems to take a while, but I haven't checked some defaults:
CONN: 1710 QUERY: 18
CONN: 0 QUERY: 16
CONN: 0 QUERY: 16
CONN: 0 QUERY: 17
CONN: 0 QUERY: 16
CONN: 0 QUERY: 23
CONN: 0 QUERY: 16
CONN: 0 QUERY: 16
CONN: 0 QUERY: 23
CONN: 0 QUERY: 16
CONN: 0 QUERY: 16
Minimum Pool Size=5. I don't understand why it closed the connections in the pool before the 300 seconds were up, but it did. This takes my connection times to 0, without intermittent issues. Please write up the answer so I can award you the bounty. If you want to explain the pooling section of the docs here npgsql.org/doc/connection-string-parameters.html that would be cool, or just make an answer saying "min pool size" =) Thank you again, minor but I wouldn't have solved it without you. – Tourer