Possible Node API performance regression with concurrency

[janpio]

After testing 1000 queries with 100 currency (), I'm seeing a big perf regression:

with napi: 420ms (findMany) 200ms (queryRaw)
without napi: 178ms (findMany) 100ms (queryRaw)

Using sample database and .

Originally posted by @vjpr in #6301 (comment)

[janpio]

@williamluke4 Thanks, works.

With latest version, with high concurrency (see #6301 (comment)) it's still twice as slow per query compared to without napi.

I will look at publishing my ORM benchmarking repo today if you want to see.

Originally posted by @vjpr in #6301 (comment)

[janpio]

How do you measure. I just did a tight loop:

import { PrismaClient } from '@prisma/client'

const metrics = require('metrics');
const prisma = new PrismaClient();

function now() {
  var hrTime = process.hrtime();
  return hrTime[0] * 1000000 + hrTime[1] / 1000;
}

async function main() {
  let histogram = new metrics.Histogram();

  var report = new metrics.Report();
  report.addMetric('queryTime', histogram);

  var reporter = new metrics.ConsoleReporter(report);
  reporter.start(1000);

  while (true) {
    var start = now();
    const all = await prisma.a.findMany({
      include: {
        bs: true,
      },
    });
    histogram.update(now() - start);
  }
}

main()
  .catch((e) => {
    throw e;
  })
  .finally(async () => {
    await prisma.$disconnect();
  })

And results:

With N-API ---------------------------------------------------------------------
queryTime
             count = 99550
               min = 261.12
               max = 72612.98
              mean = 319.68
            stddev = 241.98
              50% <= 310.25
              75% <= 326.76
              95% <= 368.96
              98% <= 378.14
              99% <= 389.39
            99.9% <= 1219.91

Without N-API ---------------------------------------------------------------------
queryTime
             count = 4336
               min = 499.38
               max = 107903.64
              mean = 7600.22
            stddev = 15235.63
              50% <= 667.22
              75% <= 785.09
              95% <= 40940.40
              98% <= 40997.68
              99% <= 41613.17
            99.9% <= 42778.98

Numbers are in microseconds. If there is a specific query that is slow, file an issue. I also must underline here that our priority with N-API is not performance, but simplifying the codebase and closing that extra TCP port the engine binary opens up.

Originally posted by @pimeys in #6301 (comment)

[janpio]

@pimeys Your example is only testing sequential runs. I'm using to run concurrent queries.

Originally posted by @vjpr in #6301 (comment)

[janpio]

@vjpr I am getting the following results with concurrency via p-times:

import { PrismaClient } from "@prisma/client";
import { performance } from "perf_hooks";
import metrics from "metrics";
import pTimes from "p-times";

const prisma = new PrismaClient();
async function main() {
  let start, finish;
  let histogram = new metrics.Histogram();
  let report = new metrics.Report();
  report.addMetric("queryTime", histogram);
  let reporter = new metrics.ConsoleReporter(report);
  reporter.start(1000);

  while (true) {
    start = performance.now();
    await pTimes(1000, () =>
      prisma.test.findUnique({
        select: {
          id: true,
          name: true,
        },
        where: {
          id: 1,
        },
      })
    );
    finish = performance.now();
    histogram.update(finish - start);
  }
}

main();

Results:

without NAPI---------------------------------------------------------------------
queryTime
             count = 575
               min = 34.03
               max = 222.30
              mean = 80.25
            stddev =  7.58
              50% <= 79.95
              75% <= 80.22
              95% <= 81.05
              98% <= 89.62
              99% <= 90.25
            99.9% <= 222.30
NAPI---------------------------------------------------------------------
queryTime
             count = 566
               min = 29.16
               max = 115.68
              mean = 76.30
            stddev =  7.10
              50% <= 79.59
              75% <= 80.06
              95% <= 80.95
              98% <= 89.92
              99% <= 90.32
            99.9% <= 115.68

This doesn't indicate a regression. Can you try this test out?

Version used:

Environment variables loaded from prisma\.env
prisma               : 2.24.0-dev.34
@prisma/client       : 2.24.0-dev.34
Current platform     : windows
Query Engine         : query-engine 3e7fd9395fd522da21025ecfd731803bae72fd2f (at node_modules\@prisma\engines\query-engine-windows.exe)
Migration Engine     : migration-engine-cli 3e7fd9395fd522da21025ecfd731803bae72fd2f (at node_modules\@prisma\engines\migration-engine-windows.exe)
Introspection Engine : introspection-core 3e7fd9395fd522da21025ecfd731803bae72fd2f (at node_modules\@prisma\engines\introspection-engine-windows.exe)
Format Binary        : prisma-fmt 3e7fd9395fd522da21025ecfd731803bae72fd2f (at node_modules\@prisma\engines\prisma-fmt-windows.exe)
Default Engines Hash : 3e7fd9395fd522da21025ecfd731803bae72fd2f
Studio               : 0.397.0

Schema:

generator client {
  provider = "prisma-client-js"
}

datasource db {
  provider = "postgresql"
  url      = env("DATABASE_URL")
}

model test {
  id   Int    @id @default(autoincrement()) @db.Integer
  name String @db.Text
}

So can you please try this once again or maybe share the benchmark code which detects the regression.

Originally posted by @pantharshit00 in #6301 (comment)

[janpio]

After testing 1000 queries with 100 currency (), I'm seeing a big perf regression:

with napi: 420ms (findMany) 200ms (queryRaw)
without napi: 178ms (findMany) 100ms (queryRaw)

Using sample database and .

@pantharshit00 he said that above, I will check myself today. My guess would be the issue is related to the size of the dataset and how NAPI handles findMany with many hundred (maybe thousand) objects.

Originally posted by @Sytten in #6301 (comment)

[janpio]

@pantharshit00 Will try your benchmark script to see I can replicate.

@Sytten I am running on https://github.com/lerocha/chinook-database (see morenoh149/postgresDBSamples#1 (comment) for an error that you need to work around when importing it)

Originally posted by @vjpr in #6301 (comment)

[janpio]

@pantharshit00 You need to add option with .

await pTimes(async () => {
  await ...
}, {concurrency: 100})

Originally posted by @vjpr in #6301 (comment)

[janpio]

Out of interest, what is the when your is 100? If much less than that, you're basically just measuring the waiting time to get a connection from the database. I'd try lowering the to the same value as the is (default: number of logical cores + 1).

Originally posted by @pimeys in #6301 (comment)

[janpio]

max_connections is 100.

Other ORMs using pg and pg-native don't have this issue when I benchmarked them.

Originally posted by @vjpr in #6301 (comment)

[vjpr]

See: #7404

[pimeys]

Duplicate of #7404 and fixed in prisma/prisma-engines#1986