Node连接Postgres比.NET Core快20倍

8
我有两台服务器连接到托管在Azure上的PostgresSQL 9.6数据库。这两台服务器只做一件事,每5秒钟向Postgres db发送一个SELECT 1查询。

连接到db并获取数据的典型时间:

  • Node:25 MS
  • .NET Core 3.1使用Npsql 4.1.1(我也尝试了4.1.2,没有区别):500 MS

我的问题是,我的.NET Core应用程序在获取数据方面比Node慢20倍。我认为由于某些原因.NET Core未对连接进行池化。无论是在本地运行应用程序还是在Azure App Services上运行应用程序时,都会出现这种缓慢现象,没有任何区别。 我想解决.NET --> Postgres的速度慢的问题。

请仅浏览相关细节,不要阅读此点之后的全部内容 - 我认为只有.NET Core代码相关。

从我的机器(其中运行了Node和.NET Core应用程序)到数据库的PsPing:

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

为了完整起见,NODE 的示例如下所示(请注意,它建立连接的第一次也比较慢):

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 }

.NET Core的连接时间如下:

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 

请注意,初始连接时间非常缓慢,后续请求建立连接的时间也很长。
无论如何,由于我非常着急,现在我将发布所有代码,并进行解释。连接字符串看起来像这样:
public static string CONNECTION_STRING {
  get {
    return $"Server={HOST}; User Id={USER}; Database={DB_NAME}; Port={PORT}; Password={PWD}; SSLMode=Prefer";
  }
}

据我了解,如果使用这个连接字符串,我应该可以直接获取到连接池。请注意,我已经尝试关闭SSL并删除相关行,但这并没有起到帮助作用。

我的健康检查控制器如下:

// GET api/health/getdbhealthselectone
[HttpGet]
[Route("getdbhealthselectone")]
public async Task<IActionResult> GetDbHealthSelectOne()
{
  int testData = await _healthCheckRepo.RunHealthCheckSelectOne();
  return Ok(testData);
}

我的健康检查仓库方法看起来像这样:

 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;
    }

请注意这里的计时器 - await conn.OpenAsync(); 是远远占用大多数时间的部分,查询本身很快。另外,为了节省时间 - 我以前曾经运行过这段代码,没有使用 async,没有任何区别。
最后,如果有依赖注入问题,仓储库在一个类库中,API 项目引用它,并且: services.AddSingleton<IHealthCheckRepository, HealthCheckRepository>(); 这就是它看到的方式。
我相信这是所有相关信息 - 我一直在与 Azure 支持团队通话,他们没有发现数据库配置方面的任何问题。.NET Core 应用程序非常轻巧,所以不像它已经超载了,而且正在测试中,除了我的测试之外没有任何流量。
额外信息:为了完整起见,这里是我的整个 Node.js 应用程序,它连接到数据库并发布了性能结果(去掉了 conn 数据)。
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);

编辑:为了后人,以下是修复连接池超时后的.NET Core时间 - 它比node.js快,除了初始连接需要一段时间外,但我还没有检查一些默认值:

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

Node正在持有Pool,重新测试Node代码以确保在函数中包含Pool或修改NpgsqlConnection以具有类似的实现,它们之间差异很大,我不知道NpgsqlConnection是否可以使用,对于基线使用更多的ADO类型。还要确保结构相似。 - Seabizkit
即Node正在建立连接1的...方法RunHealthCheckSelectOne在每次调用时都会创建一个新的连接。 - Seabizkit
3
尝试设置最小池大小。每5秒钟进行一次调用并不多,池可能会决定关闭未使用的连接。 - JGH
1
@JGH 这就是它:Minimum Pool Size=5。我不明白为什么它在300秒之前关闭了池中的连接,但它确实这样做了。这使我的连接时间为0,没有间歇性问题。请写出答案,以便我可以授予您赏金。如果您想在此处解释文档中的池化部分https://www.npgsql.org/doc/connection-string-parameters.html,那就太好了,或者只需回答说“min pool size”=)再次感谢,虽然很小,但如果没有您,我就无法解决它。 - VSO
2
@VSO,只是为了好玩,你能否在你做出更改后更新一下新的时间表...因为我想看看它是否现在更倾向于C#,我认为应该是这样。 - Seabizkit
@Seabizkit 是的,已添加到帖子底部。看起来除了第一个请求外,速度快了约25%。 - VSO
3个回答

10

您需要设置一个最小连接池大小,这样做可以确保无论池的使用情况如何,此数量的连接都保持打开状态以供数据库使用。

默认情况下(至少对于 NPGSQL),最小值为0,因此如果连接一段时间不被使用,则会关闭它。

在您的测试中,您每5秒钟进行一次调用,这并不多,而且池可能会决定关闭未使用的连接。根据文档,它应该将其保持打开状态300秒,而不仅仅是15秒。


当奖励可用时,我会回来颁发赏金。 - VSO
再次阅读后,我的评论的意思是每次都建立了一个新连接,而Node则重用了池连接。这就是我的评论所指的。但这很好,因为我本来会写一些“花哨”的膨胀代码来实现同样的事情...所以感谢您的分享。 - Seabizkit
@Seabizkit 谢谢你的建议 - 你也帮了很多忙。说实话,我觉得文档可能需要更清晰一些,即使事后再阅读它们。 - VSO

3
第一次调用比其余时间长了约5秒钟。这看起来像是IP地址解析问题。它首先选择了一个不适合给定服务器的方法,然后在5秒后超时并选择一个不同的方法,该方法有效。然后它被缓存一段时间,因此继续工作良好,直到缓存条目过期。
为了确定这是否是问题,请将数据库主机的IP地址硬编码到您的“hosts”文件中,然后查看是否解决了问题。如果是这样,则根本原因成为您的网络工程师的问题。
在数据库方面,您可以打开慢查询日志,无论是log_min_duration_statement还是更好的auto_explain.log_min_duration。但是,如果我的理论是正确的,那么这将不会显示任何东西。数据库不知道你花费了多长时间来查找它的IP地址。

我假设你的回答是基于5秒钟这个数字是确定的。但实际上不是,有时候需要2或3秒钟,甚至6秒钟。5秒钟只是第一次调用的平均值,但并没有具体的数字。我会尝试查看日志,谢谢。 - VSO
当我遇到DNS问题时,它总是比正常等待时间多5.00秒加上一次迭代。由于这是您日志条目显示的内容,这让我怀疑这也是您的问题。但如果例如两个查询快速相继出现,那么可能会出现更少的时间,因此一个解决请求会跟随另一个解决请求。如果您的计算机和数据库之间有中间服务器(应用程序服务器或连接池),解析问题可能会发生在其中任何一个地方,因此您可能需要编辑两个主机文件以确保问题得到解决。 - jjanes
好的,谢谢。我已经按照你建议的打开了日志记录,神奇的是,这个调用只花费了我指定的日志时间(1500毫秒)以下。一旦我得到一个已记录的查询,我会立即添加日志。 - VSO
注意 - 这有点晚了,但由于我可以从节点快速完美地访问数据库,我猜这不是DNS问题。再次感谢您的建议。 - VSO

2

第一次查询可能需要从磁盘读取大量数据到内存中,而后续的执行会发现所有数据已经在共享缓冲区中。您可以通过运行以下命令来了解这一点:

EXPLAIN (ANALYZE, BUFFERS) <your query>

'读取'和'命中'的数量将告诉您从磁盘中读取了多少内容,以及有多少内容在RAM中被命中。


我添加了ANALYZE结果。请告诉我这是否对可能的解决方案或我应该查看什么有所帮助。我不太理解共享缓存是什么 - 是分配给缓存的内存吗? - VSO
能否提供“EXPLAIN(ANALYZE,BUFFERS)”输出的前28行?发布的行没有任何区别。此外,如果您可以检查跟在关键字“actual”后面的值,您就可以找出查询花费更多时间的位置。关于“shared_buffers”,是的,它作为缓存起作用。 - Tchorix bmejias

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接