Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

"Healthcheck failed!" error when deploying on Railway #683

Closed
Destiner opened this issue Mar 1, 2024 · 1 comment
Closed

"Healthcheck failed!" error when deploying on Railway #683

Destiner opened this issue Mar 1, 2024 · 1 comment

Comments

@Destiner
Copy link
Contributor

Destiner commented Mar 1, 2024

Sometimes, when you deploy or redeploy Ponder on Railway, the healthcheck fails.

Here's an example:

Build Log 
Path: /health
Retry window: 5m0s
 
Attempt #1 failed with service unavailable. Continuing to retry for 4m59s
Attempt #2 failed with service unavailable. Continuing to retry for 4m58s
Attempt #3 failed with service unavailable. Continuing to retry for 4m56s
Attempt #4 failed with service unavailable. Continuing to retry for 4m52s
Attempt #5 failed with service unavailable. Continuing to retry for 4m44s
Attempt #6 failed with status 503. Continuing to retry for 4m27s
Attempt #7 failed with status 503. Continuing to retry for 3m57s
Attempt #8 failed with status 503. Continuing to retry for 3m27s
Attempt #9 failed with status 503. Continuing to retry for 2m56s
Attempt #10 failed with status 503. Continuing to retry for 2m25s
Attempt #11 failed with status 503. Continuing to retry for 1m54s
Attempt #12 failed with status 503. Continuing to retry for 1m24s
Attempt #13 failed with status 503. Continuing to retry for 54s
Attempt #14 failed with status 503. Continuing to retry for 23s
 
1/1 replicas never became healthy!
Healthcheck failed!
Deploy Logs 
$ ponder start
Attention: Ponder collects anonymous telemetry data to identify issues and prioritize features. See https://ponder.sh/advanced/telemetry for more information.
6:06:10 AM INFO  database   Using Postgres database postgres.railway.internal:5432/railway (from DATABASE_PRIVATE_URL env var)
/app/node_modules/pg-pool/index.js:45
Error.captureStackTrace(err);
^
Error: getaddrinfo ENOTFOUND postgres.railway.internal
at /app/node_modules/pg-pool/index.js:45:11
at processTicksAndRejections (node:internal/process/task_queues:95:5)
at PostgresDriver.acquireConnection (file:///app/node_modules/kysely/dist/esm/dialect/postgres/postgres-driver.js:19:24)
at RuntimeDriver.acquireConnection (file:///app/node_modules/kysely/dist/esm/driver/runtime-driver.js:44:28)
at DefaultConnectionProvider.provideConnection (file:///app/node_modules/kysely/dist/esm/driver/default-connection-provider.js:8:28)
at DefaultQueryExecutor.executeQuery (file:///app/node_modules/kysely/dist/esm/query-executor/query-executor-base.js:34:16)
at SelectQueryBuilderImpl.execute (file:///app/node_modules/kysely/dist/esm/query-builder/select-query-builder.js:293:24)
at PostgresIntrospector.getSchemas (file:///app/node_modules/kysely/dist/esm/dialect/postgres/postgres-introspector.js:11:26)
at Migrator.#doesSchemaExists (file:///app/node_modules/kysely/dist/esm/migration/migrator.js:303:25)
at Migrator.#ensureMigrationTableSchemaExists (file:///app/node_modules/kysely/dist/esm/migration/migrator.js:219:15) {
  errno: -3008,
code: 'ENOTFOUND',
syscall: 'getaddrinfo',
hostname: 'postgres.railway.internal'
}
Node.js v18.18.2
error: script "start" exited with code 1 (SIGHUP)
$ ponder start
6:06:17 AM INFO  database   Using Postgres database postgres.railway.internal:5432/railway (from DATABASE_PRIVATE_URL env var)
^
Error: getaddrinfo ENOTFOUND postgres.railway.internal
at /app/node_modules/pg-pool/index.js:45:11
at processTicksAndRejections (node:internal/process/task_queues:95:5)
at PostgresDriver.acquireConnection (file:///app/node_modules/kysely/dist/esm/dialect/postgres/postgres-driver.js:19:24)
at RuntimeDriver.acquireConnection (file:///app/node_modules/kysely/dist/esm/driver/runtime-driver.js:44:28)
at DefaultConnectionProvider.provideConnection (file:///app/node_modules/kysely/dist/esm/driver/default-connection-provider.js:8:28)
at DefaultQueryExecutor.executeQuery (file:///app/node_modules/kysely/dist/esm/query-executor/query-executor-base.js:34:16)
at SelectQueryBuilderImpl.execute (file:///app/node_modules/kysely/dist/esm/query-builder/select-query-builder.js:293:24)
at PostgresIntrospector.getSchemas (file:///app/node_modules/kysely/dist/esm/dialect/postgres/postgres-introspector.js:11:26)
at Migrator.#doesSchemaExists (file:///app/node_modules/kysely/dist/esm/migration/migrator.js:303:25)
at Migrator.#ensureMigrationTableSchemaExists (file:///app/node_modules/kysely/dist/esm/migration/migrator.js:219:15) {
  errno: -3008,
code: 'ENOTFOUND',
syscall: 'getaddrinfo',
hostname: 'postgres.railway.internal'
}
Node.js v18.18.2
error: script "start" exited with code 1 (SIGHUP)
$ ponder start
6:06:25 AM INFO  database   Using Postgres database postgres.railway.internal:5432/railway (from DATABASE_PRIVATE_URL env var)
6:06:25 AM INFO  server     Started listening on port 7284
6:06:26 AM INFO  realtime   Fetched latest block at 46521820 (network=polygonMumbai)
6:06:26 AM INFO  historical Started sync with 100% cached (contract=EntryPoint 0.6 network=polygonMumbai)
6:06:26 AM INFO  historical Started sync with 100% cached (contract=EntryPoint 0.7 network=polygonMumbai)
6:06:26 AM INFO  historical Started sync with 100% cached (contract=BiconomyAccountFactory 2 network=polygonMumbai)
6:06:26 AM INFO  historical Started sync with 100% cached (contract=BiconomyAccount2 network=polygonMumbai)
6:06:29 AM INFO  realtime   Synced 2 matched logs from block 46521730 (network=polygonMumbai)
6:06:29 AM INFO  realtime   Synced 2 matched logs from block 46521767 (network=polygonMumbai)
6:06:29 AM INFO  realtime   Synced 2 matched logs from block 46521777 (network=polygonMumbai)
6:06:29 AM INFO  realtime   Synced 2 matched logs from block 46521786 (network=polygonMumbai)
6:06:29 AM INFO  realtime   Synced 2 matched logs from block 46521794 (network=polygonMumbai)
6:06:29 AM INFO  realtime   Synced 2 matched logs from block 46521804 (network=polygonMumbai)
6:06:29 AM INFO  realtime   Synced 2 matched logs from block 46521806 (network=polygonMumbai)
6:06:29 AM INFO  realtime   Synced 2 matched logs from block 46521810 (network=polygonMumbai)
6:06:29 AM INFO  realtime   Synced 2 matched logs from block 46521813 (network=polygonMumbai)
6:06:29 AM INFO  realtime   Synced 4 matched logs from block 46521819 (network=polygonMumbai)
6:06:31 AM INFO  realtime   Synced 2 matched logs from block 46521822 (network=polygonMumbai)
6:06:31 AM INFO  indexing   Indexed 37 EntryPoint 0.6:UserOperationEvent events (chainId=80001 block=45000552 logIndex=46)
6:06:31 AM INFO  indexing   Indexed 1 BiconomyAccountFactory 2:AccountCreation event (chainId=80001 block=45000552 logIndex=40)
6:06:36 AM INFO  historical Sync is 100% complete (contract=EntryPoint 0.6)
6:06:36 AM INFO  historical Sync is 100% complete (contract=EntryPoint 0.7)
6:06:36 AM INFO  historical Sync is 100% complete (contract=BiconomyAccount2)
6:06:36 AM INFO  historical Sync is 100% complete (contract=BiconomyAccountFactory 2)
fun(...args);
^
TypeError: args is not iterable (cannot read property undefined)
at Timeout._onTimeout (file:///app/node_modules/@ponder/core/src/utils/debounce.ts:26:13)
at listOnTimeout (node:internal/timers:569:17)
at processTimers (node:internal/timers:512:7)
Node.js v18.18.2
error: script "start" exited with code 1 (SIGHUP)
$ ponder start
6:06:46 AM INFO  database   Using Postgres database postgres.railway.internal:5432/railway (from DATABASE_PRIVATE_URL env var)
6:06:46 AM INFO  server     Started listening on port 7284
6:06:47 AM INFO  realtime   Fetched latest block at 46521830 (network=polygonMumbai)
6:06:47 AM INFO  historical Started sync with 100% cached (contract=EntryPoint 0.7 network=polygonMumbai)
6:06:47 AM INFO  historical Started sync with 100% cached (contract=BiconomyAccountFactory 2 network=polygonMumbai)
6:06:47 AM INFO  historical Started sync with 100% cached (contract=EntryPoint 0.6 network=polygonMumbai)
6:06:47 AM INFO  historical Started sync with 100% cached (contract=BiconomyAccount2 network=polygonMumbai)
6:06:49 AM INFO  historical Completed sync in 1s (network=polygonMumbai)
6:06:49 AM INFO  realtime   Synced 2 matched logs from block 46521767 (network=polygonMumbai)
6:06:49 AM INFO  realtime   Synced 2 matched logs from block 46521777 (network=polygonMumbai)
6:06:49 AM INFO  realtime   Synced 2 matched logs from block 46521786 (network=polygonMumbai)
6:06:49 AM INFO  realtime   Synced 2 matched logs from block 46521794 (network=polygonMumbai)
6:06:49 AM INFO  realtime   Synced 2 matched logs from block 46521804 (network=polygonMumbai)
6:06:49 AM INFO  realtime   Synced 2 matched logs from block 46521806 (network=polygonMumbai)
6:06:49 AM INFO  realtime   Synced 2 matched logs from block 46521810 (network=polygonMumbai)
6:06:49 AM INFO  realtime   Synced 2 matched logs from block 46521813 (network=polygonMumbai)
6:06:49 AM INFO  realtime   Synced 4 matched logs from block 46521819 (network=polygonMumbai)
6:06:49 AM INFO  realtime   Synced 2 matched logs from block 46521822 (network=polygonMumbai)
6:06:49 AM INFO  realtime   Synced 2 matched logs from block 46521829 (network=polygonMumbai)
6:07:06 AM INFO  realtime   Synced 2 matched logs from block 46521839 (network=polygonMumbai)
6:07:26 AM INFO  realtime   Synced 7 matched logs from block 46521848 (network=polygonMumbai)
6:07:48 AM INFO  realtime   Synced 2 matched logs from block 46521858 (network=polygonMumbai)
6:07:49 AM INFO  realtime   Synced 3 matched logs from block 46521859 (network=polygonMumbai)
6:08:02 AM INFO  realtime   Synced 3 matched logs from block 46521865 (network=polygonMumbai)
6:08:08 AM INFO  realtime   Synced 2 matched logs from block 46521868 (network=polygonMumbai)
6:08:24 AM INFO  realtime   Synced 2 matched logs from block 46521875 (network=polygonMumbai)
6:08:42 AM INFO  realtime   Synced 2 matched logs from block 46521884 (network=polygonMumbai)
6:08:44 AM INFO  realtime   Synced 2 matched logs from block 46521885 (network=polygonMumbai)
6:08:59 AM INFO  realtime   Synced 6 matched logs from block 46521892 (network=polygonMumbai)
6:09:05 AM INFO  realtime   Synced 2 matched logs from block 46521895 (network=polygonMumbai)
6:09:11 AM INFO  realtime   Synced 2 matched logs from block 46521898 (network=polygonMumbai)
6:09:19 AM INFO  realtime   Synced 2 matched logs from block 46521902 (network=polygonMumbai)
6:09:26 AM INFO  realtime   Synced 4 matched logs from block 46521904 (network=polygonMumbai)
6:09:27 AM INFO  realtime   Synced 2 matched logs from block 46521905 (network=polygonMumbai)
6:09:47 AM INFO  realtime   Synced 2 matched logs from block 46521915 (network=polygonMumbai)
6:10:09 AM INFO  realtime   Synced 2 matched logs from block 46521924 (network=polygonMumbai)
6:10:14 AM INFO  realtime   Synced 5 matched logs from block 46521927 (network=polygonMumbai)
6:10:16 AM INFO  indexing   Indexed 2000 EntryPoint 0.6:UserOperationEvent events (chainId=80001 block=45019458 logIndex=10)
6:10:18 AM INFO  indexing   Indexed 2000 BiconomyAccountFactory 2:AccountCreation events (chainId=80001 block=46451295 logIndex=1)
6:10:22 AM INFO  indexing   Indexed 3330 EntryPoint 0.6:UserOperationEvent events (chainId=80001 block=45042366 logIndex=66)
6:10:24 AM INFO  indexing   Indexed 1146 BiconomyAccountFactory 2:AccountCreation events (chainId=80001 block=46521122 logIndex=3)
6:10:29 AM INFO  indexing   Indexed 3330 EntryPoint 0.6:UserOperationEvent events (chainId=80001 block=45060870 logIndex=20)
6:10:33 AM INFO  realtime   Synced 2 matched logs from block 46521936 (network=polygonMumbai)
6:10:36 AM INFO  indexing   Indexed 4995 EntryPoint 0.6:UserOperationEvent events (chainId=80001 block=45084412 logIndex=39)
6:10:37 AM INFO  realtime   Synced 3 matched logs from block 46521937 (network=polygonMumbai)
6:10:40 AM INFO  realtime   Synced 3 matched logs from block 46521939 (network=polygonMumbai)
6:10:40 AM INFO  indexing   Indexed 2000 EntryPoint 0.6:UserOperationEvent events (chainId=80001 block=45097983 logIndex=20)
6:10:46 AM INFO  indexing   Indexed 4995 EntryPoint 0.6:UserOperationEvent events (chainId=80001 block=45127677 logIndex=22)

I think the ultimate root issue is Ponder restarting multiple times due to Error: getaddrinfo ENOTFOUND postgres.railway.internal which I assume is Railway's internal issue. Each subsequent restart resets the 240 second limit, and if the instance kept restarting for more than 1 minute, Railway's heath check will timeout.

Reproduction

Deploy any Ponder graph to Railway (might require a few tries).

Workaround

Redeploying failed instance usually fixes the issue
@kyscott18
Copy link
Collaborator

I fixed a race condition in @ponder/core@0.2.15 which should resolve this issue. Thanks for reporting

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@Destiner @kyscott18