I had a working deployment of Hasura on Heroku. It did run for about 2 years. However, recently, when I startup the application, there's a timeout error, resulting in the app just not starting anymore (see logs below). The credentials, urls etc are correct, since the application has been working before. There were no changes in settings.
I already had Heroku increase the timeout from 60 seconds to 180 seconds, but that doesn't help, but it gives me the reason for the failure: the connection to the postgres db fails.
However, the postgres database is running fine: I can connect to it and read the schemas and tables using psql (using the DATABASE_URL
env variable from Heroku as URL). When I setup Hasura Cloud and connect to the postgres db on Heroku, it works fine (with the URL provided in the DATABASE_URL
env variable in Heroku). So, the db runs, and the connection string is the right one.
This is my Dockerfile (updated Hasura to version 2.9.0):
$ cat Dockerfile
FROM hasura/graphql-engine:v2.9.0
# Enable the console
ENV HASURA_GRAPHQL_ENABLE_CONSOLE=true
# Enable debugging mode. It should be disabled in production.
ENV HASURA_GRAPHQL_DEV_MODE=true
# Heroku hobby tier PG has few limitations including 20 max connections
# https://devcenter.heroku.com/articles/heroku-postgres-plans#hobby-tier
ENV HASURA_GRAPHQL_PG_CONNECTIONS=15
# Change $DATABASE_URL to your heroku postgres URL if you're not using
# the primary postgres instance in your app
CMD graphql-engine \
--database-url $DATABASE_URL \
serve \
--server-port $PORT
## Comment the command above and use the command below to
## enable an access-key and an auth-hook
## Recommended that you set the access-key as a environment variable in heroku
#CMD graphql-engine \
# --database-url $DATABASE_URL \
# serve \
# --server-port $PORT \
# --access-key XXXXX \
# --auth-hook https://myapp.com/hasura-webhook
#
# Console can be enable/disabled by the env var HASURA_GRAPHQL_ENABLE_CONSOLE
Any ideas how I can find out the exact issue/how to debug it/how to solve it?
Thanks.
Output logs:
2022-08-08T07:26:47.538883+00:00 heroku[web.1]: Starting process with command `/bin/sh -c graphql-engine\ \ \ \ \ --database-url\ \postgres://edxvzxubxqcanh:68eaaa545e7742497f656a43c3d2946f039fc90806a07d691e02202a2541263c@ec2-108-128-201-166.eu-west-1.compute.amazonaws.com:5432/d25u4bqll5rg1a\ \ \ \ \ serve\ \ \ \ \ --server-port\ \52293`
2022-08-08T07:26:49.672834+00:00 app[web.1]: {"detail":{"info":{"admin_secret_set":true,"auth_hook":null,"auth_hook_mode":null,"console_assets_dir":null,"cors_config":{"allowed_origins":"*","disabled":false,"ws_read_cookie":null},"enable_allowlist":false,"enable_console":true,"enable_maintenance_mode":false,"enable_metadata_query_logging":false,"enable_telemetry":true,"enabled_apis":["config","pgdump","graphql","metadata"],"enabled_log_types":["startup","webhook-log","websocket-log","http-log"],"events_fetch_batch_size":100,"experimental_features":[],"graceful_shutdown_timeout":60,"infer_function_permissions":true,"jwt_secret":[{"audience":null,"claims_format":"json","claims_namespace":"https://hasura.io/jwt/claims","header":null,"issuer":null,"key":"<JWK REDACTED>","type":"<TYPE REDACTED>"}],"live_query_options":{"batch_size":100,"refetch_delay":1},"log_level":"info","port":52293,"remote_schema_permissions":false,"server_host":"HostAny","stringify_numeric_types":false,"transaction_isolation":"ISOLATION LEVEL READ COMMITTED","unauth_role":"public","use_prepared_statements":true,"v1-boolean-null-collapse":false,"websocket_compression_options":"NoCompression","websocket_connection_init_timeout":"WSConnectionInitTimeout {unWSConnectionInitTimeout = Seconds {seconds = 3s}}","websocket_keep_alive":"KeepAliveDelay {unKeepAliveDelay = Seconds {seconds = 5s}}"},"kind":"server_configuration"},"level":"info","timestamp":"2022-08-08T07:26:49.667+0000","type":"startup"}
2022-08-08T07:26:50.680661+00:00 app[web.1]: {"detail":{"info":{"database_url":"postgres://edxvzxubxqcanh:...@ec2-108-128-201-166.eu-west-1.compute.amazonaws.com:5432/d25u4bqll5rg1a","retries":1},"kind":"postgres_connection"},"level":"info","timestamp":"2022-08-08T07:26:49.667+0000","type":"startup"}
2022-08-08T07:28:56.917452+00:00 app[web.1]: {"detail":{"message":"postgres connection failed, retrying(0)."},"level":"warn","timestamp":"2022-08-08T07:28:56.917+0000","type":"pg-client"}
2022-08-08T07:29:48.153244+00:00 heroku[web.1]: Error R10 (Boot timeout) -> Web process failed to bind to $PORT within 180 seconds of launch
2022-08-08T07:29:48.246481+00:00 heroku[web.1]: Stopping process with SIGKILL
2022-08-08T07:29:48.392887+00:00 heroku[web.1]: Process exited with status 137
2022-08-08T07:29:48.786085+00:00 heroku[web.1]: State changed from starting to crashed
== EDIT 15/08/2022
After updating to hasura to version:
FROM hasura/graphql-engine:v2.11.0-beta.1
# Heroku only allows to install extensions in the heroku_ext schema
ENV HASURA_GRAPHQL_DEFAULT_EXTENSIONS_SCHEMA=heroku_ext
# https://github.com/hasura/graphql-engine/issues/8734
ENV HASURA_GRAPHQL_METADATA_DATABASE_EXTENSIONS_SCHEMA=heroku_ext
ENV HASURA_GRAPHQL_ENABLE_CONSOLE=true
ENV HASURA_GRAPHQL_DEV_MODE=true
ENV HASURA_GRAPHQL_PG_CONNECTIONS=15
CMD graphql-engine \
--database-url $DATABASE_URL \
serve \
--server-port $PORT
I still have the same issue, the connection to postgres doesn't work:
Starting process with command `/bin/sh -c graphql-engine\ \ \ \ \ --database-url\ \postgres://edxvzxubxqcanh:...@ec2-108-128-201-166.eu-west-1.compute.amazonaws.com:5432/d25u4bqll5rg1a\ \ \ \ \ serve\ \ \ \ \ --server-port\ \7315`
2022-08-15T14:09:24.454749+00:00 app[web.1]: {"detail":{"info":{"admin_secret_set":true,"auth_hook":null,"auth_hook_mode":null,"console_assets_dir":null,"cors_config":{"allowed_origins":"*","disabled":false,"ws_read_cookie":null},"enable_allowlist":false,"enable_console":true,"enable_maintenance_mode":false,"enable_metadata_query_logging":false,"enable_telemetry":true,"enabled_apis":["config","pgdump","metadata","graphql"],"enabled_log_types":["startup","webhook-log","http-log","websocket-log"],"events_fetch_batch_size":100,"experimental_features":[],"graceful_shutdown_timeout":60,"infer_function_permissions":true,"jwt_secret":[{"audience":null,"claims_format":"json","claims_namespace":"https://hasura.io/jwt/claims","header":null,"issuer":null,"key":"<JWK REDACTED>","type":"<TYPE REDACTED>"}],"live_query_options":{"batch_size":100,"refetch_delay":1},"log_level":"info","port":7315,"remote_schema_permissions":false,"server_host":"HostAny","stringify_numeric_types":false,"transaction_isolation":"ISOLATION LEVEL READ COMMITTED","unauth_role":"public","use_prepared_statements":true,"v1-boolean-null-collapse":false,"websocket_compression_options":"NoCompression","websocket_connection_init_timeout":"WSConnectionInitTimeout {unWSConnectionInitTimeout = Seconds {seconds = 3s}}","websocket_keep_alive":"KeepAliveDelay {unKeepAliveDelay = Seconds {seconds = 5s}}"},"kind":"server_configuration"},"level":"info","timestamp":"2022-08-15T14:09:24.404+0000","type":"startup"}
2022-08-15T14:09:25.468623+00:00 app[web.1]: {"detail":{"info":{"database_url":"postgres://edxvzxubxqcanh:...@ec2-108-128-201-166.eu-west-1.compute.amazonaws.com:5432/d25u4bqll5rg1a","retries":1},"kind":"postgres_connection"},"level":"info","timestamp":"2022-08-15T14:09:24.404+0000","type":"startup"}
2022-08-15T14:11:29.990364+00:00 heroku[router]: at=error code=H20 desc="App boot timeout" method=OPTIONS path="/v1/graphql" host=systemic-nrr-store.herokuapp.com request_id=d4620807-2a79-468c-b658-be14fd31ec55 fwd="178.51.9.123" dyno= connect= service= status=503 bytes= protocol=https
2022-08-15T14:11:30.005688+00:00 heroku[router]: at=error code=H20 desc="App boot timeout" method=OPTIONS path="/v1/graphql" host=systemic-nrr-store.herokuapp.com request_id=2370dc41-749e-44f8-81c4-73052eec90fe fwd="178.51.9.123" dyno= connect= service= status=503 bytes= protocol=https
2022-08-15T14:11:30.109890+00:00 heroku[router]: at=error code=H20 desc="App boot timeout" method=OPTIONS path="/v1/graphql" host=systemic-nrr-store.herokuapp.com request_id=796a2090-79f4-4a3b-89a7-c00b55870af9 fwd="178.51.9.123" dyno= connect= service= status=503 bytes= protocol=https
2022-08-15T14:11:31.738877+00:00 app[web.1]: {"detail":{"message":"postgres connection failed, retrying(0)."},"level":"warn","timestamp":"2022-08-15T14:11:31.738+0000","type":"pg-client"}