Prisma-client-js: node script hanging after disconnect

[divyenduz]

Bug description

We observed this with some internal testing. The error log is like the following:

prisma-client TypeError: Cannot read property 'signalCode' of undefined
  prisma-client     at NodeEngine.handleRequestError (/Users/divyendusingh/Documents/prisma/system-behavior/pgbouncer-connection/node_modules/@prisma/client/runtime/index.js:1:111388)
  prisma-client     at /Users/divyendusingh/Documents/prisma/system-behavior/pgbouncer-connection/node_modules/@prisma/client/runtime/index.js:1:125748
  prisma-client     at runMicrotasks (<anonymous>)
  prisma-client     at processTicksAndRejections (internal/process/task_queues.js:97:5)
  prisma-client     at async PrismaClientFetcher.request (/Users/divyendusingh/Documents/prisma/system-behavior/pgbouncer-connection/node_modules/@prisma/client/runtime/index.js:1:222501)
  prisma-client     at async Promise.all (index 8) +1ms
  engine {
  engine   error: SocketError: other side closed
  engine       at Socket.onSocketEnd (/Users/divyendusingh/Documents/prisma/system-behavior/pgbouncer-connection/node_modules/@prisma/client/runtime/index.js:1:203556)
  engine       at Socket.emit (events.js:327:22)
  engine       at endReadableNT (_stream_readable.js:1221:12)
  engine       at processTicksAndRejections (internal/process/task_queues.js:84:21) {
  engine     code: 'UND_ERR_SOCKET'
  engine   }
  engine } +1ms

How to reproduce

Hunch: It happens when a lot of requests are running in parallel and a disconnect happens. While Prisma can reconnect if the connection is not available, it can happen that a certain request is already past that check and the async disconnect happens. In this case Prisma client gets stuck and these are the logs.

It thinks QE has crashed but that var is null. This can be reproduced by running many queries parallen and in loop and disconnecting async.

https://github.com/prisma/system-behavior/pull/6 (internal)

Expected behavior

It shouldn't hang.

Prisma information

Prisma CLI: 2.5.0-dev.61

Maybe related: https://github.com/prisma/prisma/issues/2917

[janpio]

👍 This needs a simpler reproduction with plain Node script that shows the behavior, without all the Postgres and PgBouncer container foo.

[mikecao]

I can confirm that I am also seeing this error if I explicitly call $disconnect. I am running a Next.js app with prisma and will see a bunch of these errors before it crashes the process.

TypeError: Cannot read property 'signalCode' of undefined
    at NodeEngine.handleRequestError (/var/www/umami.is/umami/node_modules/@prisma/client/runtime/index.js:1:115901)
    at async /var/www/umami.is/umami/node_modules/@prisma/client/runtime/index.js:1:129713
    at async PrismaClientFetcher.request (/var/www/umami.is/umami/node_modules/@prisma/client/runtime/index.js:1:210694)
    at async module.exports.FVZN.__webpack_exports__.default (/var/www/umami.is/umami/.next/server/pages/api/collect.js:173:5)
    at async apiResolver (/var/www/umami.is/umami/node_modules/next/dist/next-server/server/api-utils.js:8:1)
    at async Server.handleApiRequest (/var/www/umami.is/umami/node_modules/next/dist/next-server/server/next-server.js:48:397)
    at async Object.fn (/var/www/umami.is/umami/node_modules/next/dist/next-server/server/next-server.js:40:218)
    at async Router.execute (/var/www/umami.is/umami/node_modules/next/dist/next-server/server/router.js:38:67)
    at async Server.run (/var/www/umami.is/umami/node_modules/next/dist/next-server/server/next-server.js:49:494)
    at async Server.handleRequest (/var/www/umami.is/umami/node_modules/next/dist/next-server/server/next-server.js:18:101)
TypeError: Cannot read property 'signalCode' of undefined
    at NodeEngine.handleRequestError (/var/www/umami.is/umami/node_modules/@prisma/client/runtime/index.js:1:115901)
    at async /var/www/umami.is/umami/node_modules/@prisma/client/runtime/index.js:1:129713
events.js:291
      throw er; // Unhandled 'error' event
      ^

Error [ERR_STREAM_WRITE_AFTER_END]: write after end
    at writeAfterEnd (_http_outgoing.js:646:15)
    at ServerResponse.end (_http_outgoing.js:766:7)
    at ServerResponse.end (/var/www/umami.is/umami/node_modules/next/dist/compiled/compression/index.js:1:148805)
    at badRequest (/var/www/umami.is/umami/.next/server/pages/api/collect.js:1186:26)
    at /var/www/umami.is/umami/.next/server/pages/api/collect.js:427:50
Emitted 'error' event on ServerResponse instance at:
    at writeAfterEndNT (_http_outgoing.js:705:7)
    at processTicksAndRejections (internal/process/task_queues.js:81:21) {
  code: 'ERR_STREAM_WRITE_AFTER_END'
}
error Command failed with exit code 1.

[divyenduz]

@mikecao Thank you. Is it possible to share a small snippet/repro that we can use to debug this further?

I already plan to try and triage this today with just Prisma client without any frameworks/libraries but if a next.js repro is easily possible, that would help :)

[mikecao]

It's not a small repo, but it's the only thing I have running prisma at the moment

https://github.com/mikecao/umami

I can get it to consistently crash by adding a disconnect to the runQuery function under lib/db.js.

[divyenduz]

I have a reproduction - https://github.com/divyendu-test/prisma-client-js-839

[janpio]

Can you please confirm this change @divyenduz?

[divyenduz]

Exits correctly with 2.6.0-dev.44

[mikecao]

@janpio I am still getting this error whenever I call disconnect explicitly:

TypeError: Cannot read property 'signalCode' of undefined
    at NodeEngine.handleRequestError (E:\dev\umami\node_modules\@prisma\client\runtime\index.js:1:110757)
    at async E:\dev\umami\node_modules\@prisma\client\runtime\index.js:1:126324
    at async PrismaClientFetcher.request (E:\dev\umami\node_modules\@prisma\client\runtime\index.js:1:227215)
    at async Promise.all (index 0)
    at async module.exports../pages/api/website/[id]/pageviews.js.__webpack_exports__.default (E:\dev\umami\.next\server\pages\api\website\[id]\pageviews.js:957:32)
    at async apiResolver (E:\dev\umami\node_modules\next\dist\next-server\server\api-utils.js:8:1)
    at async DevServer.handleApiRequest (E:\dev\umami\node_modules\next\dist\next-server\server\next-server.js:47:397)
    at async Object.fn (E:\dev\umami\node_modules\next\dist\next-server\server\next-server.js:39:218)
    at async Router.execute (E:\dev\umami\node_modules\next\dist\next-server\server\router.js:23:67)
    at async DevServer.run (E:\dev\umami\node_modules\next\dist\next-server\server\next-server.js:49:494)

Using the latest prisma 2.6.0. Should I file a new issue?

[pantharshit00]

@mikecao Yes, please open a new issue with a minimal reproduction :)