Running a statement results in different prepared statements

[thomaschaaf]

Bug description

I am experiencing reaching the max_prepared_stmt_count limit in MySQL. I have found the reason to be that prisma is creating a lot of prepared statements.

We were getting information from the database and updating one field but were writing all data in the update statement. This is obviously not good and fixed on our side.

const sms = await this.prismaService.sms.findFirst({
  where: { externalId },
});

sms.status = 'delivered';

await this.prismaService.sms.update({
  data: sms,
  where: { externalId },
});

UPDATE `xxx`.`Sms` SET `body` = ?, `x` = ?, `campaignName` = ?, `p` = ?, `externalId` = ?, `sentAt` = ?, `id` = ?, `deliveredAt` = ?, `from` = ?, `bouncedAt` = ?, `updatedAt` = ?, `to` = ?, `isRestricted` = ?, `isDeleted` = ?, `y` = ?, `status` = ?, `deletedAt` = ?, `createdAt` = ? WHERE `xxx`.`Sms`.`id` IN (?)

or

UPDATE `xxx`.`Sms` SET `body` = ?, `x` = ?, `externalId` = ?, `deletedAt` = ?, `to` = ?, `y` = ?, `createdAt` = ?, `p` = ?, `bouncedAt` = ?, `deliveredAt` = ?, `from` = ?, `id` = ?, `updatedAt` = ?, `campaignName` = ?, `sentAt` = ?, `isRestricted` = ?, `status` = ?, `isDeleted` = ? WHERE `xxx`.`Sms`.`id` IN (?)

Interestingly the keys of the fetched object are not in the same order when getting them. This model has 17 fields resulting in 355.687.428.096.000 (17!) possible ways the prepared statement could be created.

How to reproduce

await this.prisma.sms.create({
  data: {
    from: 'yes',
    to: 'no',
    body: 'bla',
  },
})

await this.prisma.sms.create({
  data: {
    body: 'bla',
    from: 'yes',
    to: 'no',
  },
})

in MySQL look in performance_schema -> prepared_statements_instances and you will see two different prepared statements.

Expected behavior

I would expect that prisma normalizes this so that there is only one prepared statement. Reducing the number of prepared statements needed and thus not causing max_prepared_stmt_count errors.

Prisma information

model Sms {
  id           String    @id @default(uuid()) @db.Char(36)
  x   String?    @db.Char(36)
  from         String
  to           String
  y     String?    @db.Char(36)
  externalId   String?
  status       SmsStatus @default(initialized)
  createdAt    DateTime  @default(now())
  updatedAt    DateTime  @updatedAt
  sentAt       DateTime?
  deliveredAt  DateTime?
  bouncedAt    DateTime?
  body         String    @db.Text
  campaignName? String
  p     String?    @db.Char(36)
  isRestricted Boolean   @default(false)
  isDeleted    Boolean   @default(false)
  deletedAt    DateTime?
}

enum SmsStatus {
  initialized
  accepted
  scheduled
  queued
  sending
  sent
  delivered
  undelivered
  failed
}

Environment & setup

• OS: Mac OS
• Database: MySQL
• Node.js version: v14.16.0

Prisma Version

prisma               : 2.28.0
@prisma/client       : 2.28.0
Current platform     : darwin
Query Engine         : query-engine 89facabd0366f63911d089156a7a70125bfbcd27 (at node_modules/prisma/node_modules/@prisma/engines/query-engine-darwin)
Migration Engine     : migration-engine-cli 89facabd0366f63911d089156a7a70125bfbcd27 (at node_modules/prisma/node_modules/@prisma/engines/migration-engine-darwin)
Introspection Engine : introspection-core 89facabd0366f63911d089156a7a70125bfbcd27 (at node_modules/prisma/node_modules/@prisma/engines/introspection-engine-darwin)
Format Binary        : prisma-fmt 89facabd0366f63911d089156a7a70125bfbcd27 (at node_modules/prisma/node_modules/@prisma/engines/prisma-fmt-darwin)
Default Engines Hash : 89facabd0366f63911d089156a7a70125bfbcd27
Studio               : 0.417.0

[thomaschaaf]

Oh it is actually worse..

      await this.prismaService.sms.update({
        data: {
          status: sms.status,
          sentAt: sms.sentAt,
          deliveredAt: sms.deliveredAt,
          bouncedAt: sms.bouncedAt,
        },
        where: { id: sms.id },
      });

even if you do it like this it will still result in 24 (4!) prepared statements.

UPDATE `xxx`.`Sms` SET `deliveredAt` = ?, `status` = ?, `sentAt` = ?, `bouncedAt` = ?, `updatedAt` = ? WHERE `xxx`.`Sms`.`id` IN (?)

UPDATE `xxx`.`Sms` SET `deliveredAt` = ?, `status` = ?, `sentAt` = ?, `updatedAt` = ?, `bouncedAt` = ? WHERE `xxx`.`Sms`.`id` IN (?)

UPDATE `xxx`.`Sms` SET `deliveredAt` = ?, `bouncedAt` = ?, `updatedAt` = ?, `status` = ?, `sentAt` = ? WHERE `xxx`.`Sms`.`id` IN (?)

[...]

[thomaschaaf]

@janpio do you need any more info? We are running many thousand queries / minute at finanzcheck/smava and this is problematic for us. I'd be happy to help provide more data if needed.

[pimeys]

From my point of view, we render the statement in the order we get the values. And now I'm not talking about the JavaScript side or query engine, but the setup where we generate the query AST and then render the SQL.

I'm thinking of some cases where this might be a problem, and one of them is how we utilize JSON in the upper layers. This is converted to a vector of (column, statement) tuples, so when we iterate the JSON map, it comes out in random order.

Candidating this to the client team, but have you meanwhile tried to set statement_cache_size connection string parameter to something more reasonable? I'd go with low values for now, the team will then figure out the ordering when they have time.

[janpio]

Nope, all good - we are just a tad busy.

Oh it is actually worse..

Do you indicate here @thomaschaaf that running the same query creates different prepared statements when it is run multiple times?

In general I agree with you that we should try to minimize the number of prepared statements that are created. Sorting data of course has its own cost, so we will need to see if this "randomizing" is accidental in some way and can be "turned off" easily.

(And just to make sure: Did you already lower the statement_cache_size of Prisma so this does not really cause problems for you any more? Removing and adding statements from the cache is pretty cheap, so setting a low cache size should not hurt performance in a perceivable way but avoid getting crashes of course)

[pimeys]

Reproduction:

datasource db {
  provider = "mysql"
  url      = "mysql://root:prisma@localhost:3306/prisma"
}

model A {
  id Int           @id @default(autoincrement())
  a  Int
  b  Int
  c  Int
  d  Int
  e  Int
  f  Int
  g  Int
  h  Int
  i  Int
  j  Int
}

Directly communicating with the engine using GraphQL, create one item first:

mutation {
  createOneA(
    data: { a: 1, b: 2, c: 3, d: 4, e: 5, f: 6, g: 7, h: 8, i: 9, j: 10 }
  ) {
    id
    a
    b
    c
    d
    e
    f
    g
    h
    i
    j
  }
}

Then run a few updates with the id you got back, e.g.

mutation {
  updateOneA(
    where: { id: 2 }
    data: { a: 1, b: 2, c: 3, d: 4, e: 5, f: 6, g: 7, h: 8, i: 9, j: 10 }
  ) {
    id
    a
    b
    c
    d
    e
    f
    g
    h
    i
    j
  }
}

I did two queries, resulting in two SQL statements that have the ordering wrong:

UPDATE `prisma`.`A`
SET `a` = ?,
    `f` = ?,
    `h` = ?,
    `j` = ?,
    `i` = ?,
    `c` = ?,
    `e` = ?,
    `b` = ?,
    `g` = ?,
    `d` = ?
WHERE `prisma`.`A`.`id` IN (?);

and

UPDATE `prisma`.`A`
SET `h` = ?,
    `i` = ?,
    `f` = ?,
    `j` = ?,
    `a` = ?,
    `d` = ?,
    `c` = ?,
    `b` = ?,
    `e` = ?,
    `g` = ?
WHERE `prisma`.`A`.`id` IN (?)

[pimeys]

Position of the bug. HashMap doesn't keep the order of insertion. Needs an IndexMap.

https://github.com/prisma/prisma-engines/blob/master/query-engine/connectors/query-connector/src/write_args.rs#L14

[janpio]

Hey @thomaschaaf, as you can see above with the right information from you (thanks you! 💚) we could identify and fix the problem. This should be available in our next release on Sept 7th. I'll check if this already available in dev, so you could potentially confirm this is really fixed for you, and let you know here.

[janpio]

This should now be available via 2.31.0-dev.17. Would be awesome if you could try out if you can still reproduce your problem there @thomaschaaf, or if we indeed got it all and solved the problem. This code will be included in our next release.

[thomaschaaf]

I'm sorry I left for the holidays but I will try to get me colleagues to test it.

[pimeys]

I'm 22 hours late, but CAREFUL now. We just removed preview feature flags for the next release, so if you didn't use referentialActions feature before, it's now on by default and can lead to unexpected things if you use the dev versions!

Please read the feature docs or wait for the next version to get docs for updating.