Whoops. Looks like yet another internal server error


#1

Last night, my application server suddenly started getting errors with every prisma request. I went to the GraphQL playground to test directly with my prisma server if I would also get errors there, and I did. They looked like this:

“message”: “Whoops. Looks like an internal server error. Search your server logs for request ID: local:cjueenue2001t0701jys8h26v”

To check the server logs on heroku, I did this:

$ heroku run bash -a

The errors look like this:

Apr 12, 2019 6:29:43 PM org.postgresql.Driver connect
SEVERE: Connection error:
org.postgresql.util.PSQLException: FATAL: permission denied for database “postgres”
Detail: User does not have CONNECT privilege.
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2433)
at org.postgresql.core.v3.QueryExecutorImpl.readStartupMessages(QueryExecutorImpl.java:2566)
at org.postgresql.core.v3.QueryExecutorImpl.<init>(QueryExecutorImpl.java:131)
at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:210)
at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49)
at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:195)
at org.postgresql.Driver.makeConnection(Driver.java:452)
at org.postgresql.Driver.connect(Driver.java:254)
at slick.jdbc.DriverDataSource.getConnection(DriverDataSource.scala:101)
at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:341)
at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:193)
at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:430)
at com.zaxxer.hikari.pool.HikariPool.access$500(HikariPool.java:64)
at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:570)
at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:563)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)

I searched for a solution to this problem, and I found this GitHub issue:

There was no solution to the problem there or anywhere else in my search results. The data in my database is not important, since the web app is in a prototype stage, but this was preventing the web app from working, so I decided to start completely from scratch, following the instructions in this video, as I did originally several months ago:

I thought for sure that this would fix the problem, since I started over completely, but unfortunately I still get the exact same errors with the brand new prisma server, service, and database.

My prisma version is:
prisma/1.30.1 (darwin-x64) node-v8.12.0

Please help. Thank you!


#2

I have reproduced this problem with the following datamodel.prisma:

type User {
id: ID! @unique
name: String!
}


#3

I was able to get past this problem by removing my Heroku account from “Heroku CONNECTED ACCOUNTS” in the Prisma console, and then recreating my Prisma server, database, and service from scratch. That’s definitely the nuclear option, which I would never want to do with a production web app, but in this case I just wanted to get my prototype web app back and running again ASAP.

I still have no idea why this problem randomly started happening when my prototype web app has successfully used Prisma with Heroku for several months.

If there is a less severe way of fixing this, please let me know, for future reference.


#4

This was the discussion that helped me get it working.


#5

I’m getting this issue again today after running a deleteMany___s mutation to delete a large number of objects. Every single query now fails with:

WARNING: SQLException occurred while connecting to ec2-50-19-127-115.compute-1.amazonaws.com:5432
org.postgresql.util.PSQLException: FATAL: permission denied for database “postgres”
Detail: User does not have CONNECT privilege.


#6

What is the proper way to unlink/relink a Heroku account from/to Prisma? I tried removing my Heroku account from “Heroku CONNECTED ACCOUNTS” in the Prisma console, and then reconnecting it using “CONNECT A HEROKU ACCOUNT”, but that did not solve the problem. Do I need to do anything to the server and service after I unlink/relink the Heroku account?

I even deleted cookies so that I’d be forced to enter my Heroku password when connecting the Heroku account to Prisma. It’s still broken.

The “User does not have CONNECT privilege” error is still occurring for every query.

Last time I got around this problem by recreating my Prisma server, database, and service from scratch. I would hate to have to do that again. Is there anyone who has advice on how to get past this problem?

My schema is fairly simple and I’m not doing anything unusual, so I’m puzzled as to why I keep hitting this problem. I do create millions of objects in the Prisma database, but I wouldn’t think that would be related to this error.


#7

The problems I experienced over the past couple of days seem to have been caused by running mutations or queries which involve a large number of objects (> 1,000,000). Such mutations/queries can send my Heroku dyno into a state where the Dyno Load increases, Memory Usage increases, and all requests time out. When testing, I’ve run queries that cause my Prisma server to get into this state for 30 minutes or more.

In Heroku Metrics, I even noticed some crashes, which in hindsight may have been related to my extended downtime a few weeks ago (described above), since Heroku’s “Dyno crash restart policy” means that a dyno can be offline for 320 minutes after multiple crashes.

Today, I changed my dyno from Hobby ($7) to Standard 2X ($50) with the hope that this would fix the behavior I just described. With the Hobby dyno, I was regularly getting R14 “Memory quota exceeded” errors because my Prisma server dyno was regularly exceeding the Hobby 512MB memory limit. The Standard 2X limit is 1GB. While Heroku seems to allow Hobby dynos to go up to 1GB before any consequences occur, I still thought this could be related to the Prisma server crashes.

Unfortunately, I can still easily reproduce the state I describe above where the Prisma server becomes unresponsive for 30+ minutes. I haven’t crashed it with the Standard 2X yet. I believe that the Hobby dyno was actually unresponsive for several hours last night after I ran the “deleteMany___s mutation to delete a large number of objects” yesterday. I’m not exactly sure how many objects would have been deleted by that mutation, perhaps a few million. I have done similar mutations before that seemed to only take a few minutes, so I’m not sure why it went into unresponsive mode for several hours last night.

Is what I’m describing expected behavior? That is, is the answer to this problem: “Don’t do that”? Don’t run a mutation or query that involves millions of objects, because your Prisma server might stop working for an hour, or even a day?


#8

My Prisma server went into constant error mode (“Whoops. Looks like an internal server error…”) again today for a couple of hours. The errors occurred when accessing the Prisma server either through my application server or through the GraphQL playground. Once I noticed the problem, I was able to fix it by restarting the Prisma server dyno on Heroku.

I’m getting better at working around this problem, but I hope that it can be fixed before my web app is officially released.


#9

My best guess right now is that the Prisma server crashes and unresponsiveness I’ve been plagued with over the past several weeks come down to the server not having enough memory. After bumping the memory up to 550MB using JAVA_OPTS -Xmx550m (the default set up by Prisma is -Xmx358m), the problem occurs slightly less, but still occurs. I can’t bump the memory higher than that without significantly going over the 1GB limit of my Standard 2x dyno, which costs $50/month. If I want more than 1GB of memory on Heroku, the next option up is $250/month. This seems excessive when I have less than 100 users a week, so I need to explore other provider options.

The instant Prisma server deployment to Heroku is a cool feature, but it would be nice to be warned in advance that Prisma can’t really do much with a 358MB Java memory limit. A simple query such as this from the Apollo client will break the Prisma server every time if there are over 1M transaction objects:

query {
  transactionsConnection {
    aggregate {
      count
    }
  }
}

The Apollo client adds __typename, so the query is actually like this:

query {
  transactionsConnection {
    aggregate {
      count
      __typename
    }
    __typename
  }
}

Still, one wouldn’t expect such a simple operation as getting a count of the number of objects of a certain type to break Prisma and require a restart of the server.

For anyone running Prisma successfully in a production app, how much memory are you giving the Prisma server?