cardano-foundation / cardano-graphql

GraphQL API for Cardano
Apache License 2.0
262 stars 104 forks source link

graphql server can not work #710

Closed liuyangc3 closed 2 years ago

liuyangc3 commented 2 years ago

Summary

API return RST

Steps to reproduce the bug

reference: https://github.com/input-output-hk/cardano-graphql#b-pull-and-run-via-docker-compose

start the stack

git clone https://github.com/input-output-hk/cardano-graphql.git \
  --single-branch \
  --branch 6.2.0 \
  --recurse-submodules

cd cardano-graphql

DOCKER_BUILDKIT=1 \
COMPOSE_DOCKER_CLI_BUILD=1 \
RESTORE_SNAPSHOT=https://update-cardano-mainnet.iohk.io/cardano-db-sync/12/db-sync-snapshot-schema-12-block-7230633-x86_64.tgz \
docker-compose up -d --build

the node is synced

docker-compose exec cardano-node-ogmios bash

# CARDANO_NODE_SOCKET_PATH=/ipc/node.socket ./cardano-cli query tip --mainnet
Warning: Local header state query unavailable. Falling back to chain sync query
{
    "era": "Alonzo",
    "epoch": 339,
    "hash": "40c09e14e6f2c1e985b44463d043b82bd1ef30264deca164dcb260db4586733b",
    "block": 7251734,
    "slot": 61095490,
    "syncProgress": "100.00"
}

cardano-db-sync logs looks well

cardano-db-sync-extended_1  | /run/secrets
cardano-db-sync-extended_1  | Generating PGPASS file
cardano-db-sync-extended_1  | Connecting to network: mainnet
cardano-db-sync-extended_1  | Downloading snapshot https://update-cardano-mainnet.iohk.io/cardano-db-sync/12/db-sync-snapshot-schema-12-block-7230633-x86_64.tgz ...
cardano-db-sync-extended_1  |   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
cardano-db-sync-extended_1  |                                  Dload  Upload   Total   Spent    Left  Speed
...
cardano-db-sync-extended_1  | All good!
cardano-db-sync-extended_1  | [db-sync-node:Info:6] [2022-05-12 05:05:31.26 UTC] Schema migration files validated
cardano-db-sync-extended_1  | [db-sync-node:Info:6] [2022-05-12 05:05:31.26 UTC] Running database migrations
cardano-db-sync-extended_1  | [db-sync-node:Info:6] [2022-05-12 05:05:31.26 UTC] Enviroment variable DbSyncAbortOnPanic: False
cardano-db-sync-extended_1  | [db-sync-node:Info:6] [2022-05-12 05:11:12.68 UTC] Using byron genesis file from: "/config/cardano-db-sync/../cardano-node/../genesis/byron.json"
cardano-db-sync-extended_1  | [db-sync-node:Info:6] [2022-05-12 05:11:12.68 UTC] Using shelley genesis file from: "/config/cardano-db-sync/../cardano-node/../genesis/shelley.json"
cardano-db-sync-extended_1  | [db-sync-node:Info:6] [2022-05-12 05:11:12.68 UTC] Using alonzo genesis file from: "/config/cardano-db-sync/../cardano-node/../genesis/alonzo.json"
cardano-db-sync-extended_1  | [db-sync-node:Info:6] [2022-05-12 05:11:13.08 UTC] NetworkMagic: 764824073
cardano-db-sync-extended_1  | [db-sync-node:Info:6] [2022-05-12 05:11:13.44 UTC] Initial genesis distribution present and correct
cardano-db-sync-extended_1  | [db-sync-node:Info:6] [2022-05-12 05:11:13.44 UTC] Total genesis supply of Ada: 31112484745.000000
cardano-db-sync-extended_1  | [db-sync-node:Info:6] [2022-05-12 05:11:13.44 UTC] Inserting Shelley Genesis distribution
cardano-db-sync-extended_1  | [db-sync-node:Info:6] [2022-05-12 05:11:13.44 UTC] epochPluginOnStartup: Checking
cardano-db-sync-extended_1  | [db-sync-node:Info:6] [2022-05-12 05:11:13.44 UTC] localInitiatorNetworkApplication: connecting to node via "/node-ipc/node.socket"
cardano-db-sync-extended_1  | [db-sync-node.Subscription:Notice:48] [2022-05-12 05:11:13.44 UTC] Identity Starting Subscription Worker, valency 1
cardano-db-sync-extended_1  | [db-sync-node.Subscription:Notice:49] [2022-05-12 05:11:13.44 UTC] Identity Connection Attempt Start, destination LocalAddress "/node-ipc/node.socket"
cardano-db-sync-extended_1  | [db-sync-node.Subscription:Notice:49] [2022-05-12 05:11:13.44 UTC] Identity Connection Attempt End, destination LocalAddress "/node-ipc/node.socket" outcome: ConnectSuccessLast
cardano-db-sync-extended_1  | [db-sync-node.Handshake:Info:49] [2022-05-12 05:11:13.45 UTC] WithMuxBearer (ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"}) Send (ClientAgency TokPropose,MsgProposeVersions (fromList [(NodeToClientV_1,TInt 764824073),(NodeToClientV_2,TInt 764824073),(NodeToClientV_3,TInt 764824073),(NodeToClientV_4,TInt 764824073),(NodeToClientV_5,TInt 764824073),(NodeToClientV_6,TInt 764824073),(NodeToClientV_7,TInt 764824073),(NodeToClientV_8,TInt 764824073),(NodeToClientV_9,TInt 764824073),(NodeToClientV_10,TInt 764824073)]))
cardano-db-sync-extended_1  | [db-sync-node.Handshake:Info:49] [2022-05-12 05:11:13.45 UTC] WithMuxBearer (ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"}) Recv (ServerAgency TokConfirm,MsgAcceptVersion NodeToClientV_9 (TInt 764824073))
cardano-db-sync-extended_1  | [db-sync-node.Mux:Info:49] [2022-05-12 05:11:13.45 UTC] Bearer on ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"} event: Handshake Client end, duration 0.009982313s
cardano-db-sync-extended_1  | [db-sync-node.Mux:Info:51] [2022-05-12 05:11:13.45 UTC] Bearer on ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"} event: State: Mature
cardano-db-sync-extended_1  | [db-sync-node:Info:54] [2022-05-12 05:11:13.46 UTC] Starting chainSyncClient
cardano-db-sync-extended_1  | [db-sync-node:Info:54] [2022-05-12 05:11:13.47 UTC] Cardano.Db tip is at slot 57041681, block 7059263
cardano-db-sync-extended_1  | [db-sync-node:Info:59] [2022-05-12 05:11:13.47 UTC] Running DB thread
cardano-db-sync-extended_1  | [db-sync-node.Subscription:Notice:48] [2022-05-12 05:11:13.47 UTC] Identity Required subscriptions started
cardano-db-sync-extended_1  | [db-sync-node:Info:59] [2022-05-12 05:11:13.51 UTC] Rolling back to genesis
cardano-db-sync-extended_1  | [db-sync-node:Info:59] [2022-05-12 05:12:24.62 UTC] Deleting 7059263 blocks up to slot 57041681

ogmios API looks well

curl -s http://localhost:1337/health | jq
{
  "startTime": "2022-05-12T04:20:29.506341498Z",
  "lastKnownTip": {
    "slot": 61121367,
    "hash": "469f41195c82116358bbbfadf2e4f54d1bae2b64c512f8dd9fb3302a1a699937",
    "blockNo": 7252931
  },
  "lastTipUpdate": "2022-05-16T07:54:18.291141201Z",
  "networkSynchronization": 1,
  "currentEra": "Alonzo",
  "metrics": {
    "activeConnections": 0,
    "totalConnections": 4,
    "totalUnrouted": 4,
    "sessionDurations": {
      "mean": 5404603,
      "min": 0,
      "max": 0
    },
    "runtimeStats": {
      "currentHeapSize": 1813,
      "gcCpuTime": 232449536631,
      "cpuTime": 295385133678,
      "maxHeapSize": 1814
    },
    "totalMessages": 9
  }
}

ogmios logs

cardano-node-ogmios_1       | [c03ebd47:cardano.node.LocalErrorPolicy:Error:2019] [2022-05-16 07:55:51.52 UTC] IP LocalAddress "" ErrorPolicyUnhandledApplicationException (MuxError MuxBearerClosed "<socket: 31> closed when reading data, waiting on next header True")
cardano-node-ogmios_1       | [c03ebd47:cardano.node.ChainDB:Notice:1988] [2022-05-16 07:56:06.30 UTC] Chain extended, new tip: ed0a59f6c3a9b3cd76844c81ff936f04a293d40a7c2ac6c801ce5abfcc4c9392 at slot 61121474
cardano-node-ogmios_1       | {"severity":"Info","timestamp":"2022-05-16T07:56:06.307655106Z","thread":"2432","message":{"tag":"OgmiosHealth","healthCheck":{"tag":"HealthTick","status":{"startTime":"2022-05-12T04:20:29.506341498Z","lastKnownTip":{"slot":61121474,"hash":"ed0a59f6c3a9b3cd76844c81ff936f04a293d40a7c2ac6c801ce5abfcc4c9392","blockNo":7252934},"lastTipUpdate":"2022-05-16T07:56:06.307451266Z","networkSynchronization":0.99999,"currentEra":"Alonzo","metrics":{"activeConnections":0,"totalConnections":5,"totalUnrouted":6,"sessionDurations":{"mean":4337568,"min":0,"max":0},"runtimeStats":{"currentHeapSize":1815,"gcCpuTime":232559961267,"cpuTime":295514346731,"maxHeapSize":1952},"totalMessages":13}}}},"version":"v4.1.0"}
cardano-node-ogmios_1       | [c03ebd47:cardano.node.ChainDB:Notice:1988] [2022-05-16 07:56:09.75 UTC] Chain extended, new tip: 815512454bd4198a2bff18797763ffe2f4ae8353c2042c0ca074090109a85bba at slot 61121478
cardano-node-ogmios_1       | {"severity":"Info","timestamp":"2022-05-16T07:56:09.757315862Z","thread":"2432","message":{"tag":"OgmiosHealth","healthCheck":{"tag":"HealthTick","status":{"startTime":"2022-05-12T04:20:29.506341498Z","lastKnownTip":{"slot":61121478,"hash":"815512454bd4198a2bff18797763ffe2f4ae8353c2042c0ca074090109a85bba","blockNo":7252935},"lastTipUpdate":"2022-05-16T07:56:09.757145723Z","networkSynchronization":0.99999,"currentEra":"Alonzo","metrics":{"activeConnections":0,"totalConnections":5,"totalUnrouted":6,"sessionDurations":{"mean":4337568,"min":0,"max":0},"runtimeStats":{"currentHeapSize":1815,"gcCpuTime":232566106226,"cpuTime":295522741527,"maxHeapSize":1952},"totalMessages":13}}}},"version":"v4.1.0"}
cardano-node-ogmios_1       | [c03ebd47:cardano.node.ChainDB:Notice:1988] [2022-05-16 07:56:11.27 UTC] Chain extended, new tip: 0c69e61489bf89e704158734f11d64a09e71821bd17a421378e4020b58b7cdda at slot 61121480

but the graphsql API doesn't response

curl -XPOST http://localhost:3100/graphql -H "Content-Type: application/json" \
-d  '{"query": "{ cardanoDbMeta { initialized syncPercentage }}"}'
curl: (56) Recv failure: Connection reset by peer

and the graphsql log

cardano-graphql_1           | {"name":"cardano-graphql","hostname":"5ef171d6de8c","pid":1,"level":30,"module":"Server","msg":"Initializing","time":"2022-05-16T07:57:06.131Z","v":0}
cardano-graphql_1           | {"name":"cardano-graphql","hostname":"5ef171d6de8c","pid":1,"level":30,"module":"HasuraClient","msg":"Initializing","time":"2022-05-16T07:57:06.375Z","v":0}
cardano-graphql_1           | {"name":"cardano-graphql","hostname":"5ef171d6de8c","pid":1,"level":30,"module":"ChainFollower","msg":"Initialized","time":"2022-05-12T04:54:54.355Z","v":0}
cardano-graphql_1           | (node:1) UnhandledPromiseRejectionWarning: Error: database query error: {"response":{"errors":[{"extensions":{"path":"$","code":"unexpected"},"message":"database query error"}],"status":200},"request":{"query":"query {\n          epochs (limit: 1, order_by: { number: desc }) {\n              adaPots {\n                  reserves\n              }\n          }\n          rewards_aggregate {\n              aggregate {\n                  sum {\n                      amount\n                  }\n              }\n          }\n          utxos_aggregate {\n              aggregate {\n                  sum {\n                      value\n                  }\n              }\n          }\n          withdrawals_aggregate {\n              aggregate {\n                  sum {\n                      amount\n                  }\n              }\n          }\n      }"}}
cardano-graphql_1           |     at GraphQLClient.<anonymous> (/app/node_modules/graphql-request/dist/index.js:170:35)
cardano-graphql_1           |     at step (/app/node_modules/graphql-request/dist/index.js:63:23)
cardano-graphql_1           |     at Object.next (/app/node_modules/graphql-request/dist/index.js:44:53)
cardano-graphql_1           |     at fulfilled (/app/node_modules/graphql-request/dist/index.js:35:58)
cardano-graphql_1           |     at runMicrotasks (<anonymous>)
cardano-graphql_1           |     at processTicksAndRejections (internal/process/task_queues.js:95:5)
cardano-graphql_1           | (Use `node --trace-warnings ...` to show where the warning was created)
cardano-graphql_1           | (node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 32)
cardano-graphql_1           | (node:1) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

Actual Result

curl: (56) Recv failure: Connection reset by peer

Expected Result

sync response

Environment

docker-compose

Platform

Platform version

No response

Runtime

Runtime version

No response

zlac116 commented 2 years ago

Did you manage to get this to work? I'm experiencing similar issues with 6.2.0...

taobo-ops commented 2 years ago

The same problem, my node is also synchronized, but the graphsql interface does not work. Did you solve it now?

yungtechboy1 commented 2 years ago

Funny I got 6.2.0 to work about a month ago and never took the stack down.. For good reasons,...

I upgraded my server and now Im having issues re-installing and syncing the whole stack... Heres my stack post from the last install https://cardano.stackexchange.com/questions/8297/amd64-error-warning-when-setting-up-grapgql-docker-in-mac-m1/8319#8319

yungtechboy1 commented 2 years ago

Funny I did a fresh restore of a Snapshot I downloaded locally from 13/ folder and I got the same message Deleting 7059263 blocks up to slot 57041681 after it said No Blocks needed to be deleted...

yungtechboy1 commented 2 years ago

:(


2022-06-29T06:13:40.952925680Z ALTER TABLE

2022-06-29T06:13:55.346845659Z ALTER TABLE

2022-06-29T06:13:55.930833402Z ALTER TABLE

2022-06-29T06:13:55.935190817Z ALTER TABLE

2022-06-29T06:14:06.344750715Z ALTER TABLE

2022-06-29T06:14:07.770900555Z ALTER TABLE

2022-06-29T06:14:07.772033337Z ALTER TABLE

2022-06-29T06:14:09.759893133Z ALTER TABLE

2022-06-29T06:14:11.727726685Z ALTER TABLE

2022-06-29T06:14:21.372749951Z ALTER TABLE

2022-06-29T06:14:22.452367765Z ALTER TABLE

2022-06-29T06:14:22.609672076Z ALTER TABLE

2022-06-29T06:14:41.736854203Z ALTER TABLE

2022-06-29T06:14:47.463960000Z ALTER TABLE

2022-06-29T06:15:21.612520608Z ALTER TABLE

2022-06-29T06:16:24.362984338Z ALTER TABLE

2022-06-29T06:16:43.582852563Z ALTER TABLE

2022-06-29T06:16:43.584873642Z ALTER TABLE

2022-06-29T06:16:43.586178322Z ALTER TABLE

2022-06-29T06:17:27.790991719Z ALTER TABLE

2022-06-29T06:18:15.245817388Z ALTER TABLE

2022-06-29T06:18:17.707528279Z ALTER TABLE

2022-06-29T06:18:17.709033874Z ALTER TABLE

2022-06-29T06:18:27.666888507Z ALTER TABLE

2022-06-29T06:18:28.951551538Z All good!

2022-06-29T06:18:29.012607212Z [db-sync-node:Info:6] [2022-06-29 06:18:29.01 UTC] Schema migration files validated

2022-06-29T06:18:29.012629337Z [db-sync-node:Info:6] [2022-06-29 06:18:29.01 UTC] Running database migrations

2022-06-29T06:18:29.012633414Z [db-sync-node:Info:6] [2022-06-29 06:18:29.01 UTC] Enviroment variable DbSyncAbortOnPanic: False

2022-06-29T06:18:29.302013494Z [db-sync-node:Info:6] [2022-06-29 06:18:29.29 UTC] Using byron genesis file from: "/config/cardano-db-sync/../cardano-node/../genesis/byron.json"

2022-06-29T06:18:29.302041847Z [db-sync-node:Info:6] [2022-06-29 06:18:29.29 UTC] Using shelley genesis file from: "/config/cardano-db-sync/../cardano-node/../genesis/shelley.json"

2022-06-29T06:18:29.302045742Z [db-sync-node:Info:6] [2022-06-29 06:18:29.29 UTC] Using alonzo genesis file from: "/config/cardano-db-sync/../cardano-node/../genesis/alonzo.json"

2022-06-29T06:18:29.901197612Z [db-sync-node:Info:6] [2022-06-29 06:18:29.65 UTC] NetworkMagic: 764824073

2022-06-29T06:18:29.946864272Z [db-sync-node:Info:6] [2022-06-29 06:18:29.94 UTC] Initial genesis distribution present and correct

2022-06-29T06:18:29.946878973Z [db-sync-node:Info:6] [2022-06-29 06:18:29.94 UTC] Total genesis supply of Ada: 31112484745.000000

2022-06-29T06:18:29.947703457Z [db-sync-node:Info:6] [2022-06-29 06:18:29.94 UTC] Inserting Shelley Genesis distribution

2022-06-29T06:18:29.947994990Z [db-sync-node:Info:6] [2022-06-29 06:18:29.94 UTC] epochPluginOnStartup: Checking

2022-06-29T06:18:29.949073855Z [db-sync-node:Info:6] [2022-06-29 06:18:29.94 UTC] localInitiatorNetworkApplication: connecting to node via "/node-ipc/node.socket"

2022-06-29T06:18:29.949120996Z [db-sync-node.Subscription:Notice:47] [2022-06-29 06:18:29.94 UTC] Identity Starting Subscription Worker, valency 1

2022-06-29T06:18:29.949208716Z [db-sync-node.Subscription:Notice:48] [2022-06-29 06:18:29.94 UTC] Identity Connection Attempt Start, destination LocalAddress "/node-ipc/node.socket"

2022-06-29T06:18:29.949270428Z [db-sync-node.Subscription:Notice:48] [2022-06-29 06:18:29.94 UTC] Identity Connection Attempt End, destination LocalAddress "/node-ipc/node.socket" outcome: ConnectSuccessLast

2022-06-29T06:18:29.949347159Z [db-sync-node.Handshake:Info:48] [2022-06-29 06:18:29.94 UTC] WithMuxBearer (ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"}) Send (ClientAgency TokPropose,MsgProposeVersions (fromList [(NodeToClientV_1,TInt 764824073),(NodeToClientV_2,TInt 764824073),(NodeToClientV_3,TInt 764824073),(NodeToClientV_4,TInt 764824073),(NodeToClientV_5,TInt 764824073),(NodeToClientV_6,TInt 764824073),(NodeToClientV_7,TInt 764824073),(NodeToClientV_8,TInt 764824073),(NodeToClientV_9,TInt 764824073),(NodeToClientV_10,TInt 764824073)]))

2022-06-29T06:18:29.949694235Z [db-sync-node.Handshake:Info:48] [2022-06-29 06:18:29.94 UTC] WithMuxBearer (ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"}) Recv (ServerAgency TokConfirm,MsgAcceptVersion NodeToClientV_10 (TInt 764824073))

2022-06-29T06:18:29.949709777Z [db-sync-node.Mux:Info:48] [2022-06-29 06:18:29.94 UTC] Bearer on ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"} event: Handshake Client end, duration 0.000503349s

2022-06-29T06:18:29.949834942Z [db-sync-node.Mux:Info:49] [2022-06-29 06:18:29.94 UTC] Bearer on ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"} event: State: Mature

2022-06-29T06:18:29.949849733Z [db-sync-node:Info:52] [2022-06-29 06:18:29.94 UTC] Starting chainSyncClient

2022-06-29T06:18:29.963029127Z [db-sync-node:Info:52] [2022-06-29 06:18:29.96 UTC] Cardano.Db tip is at slot 64540777, block 7417697

2022-06-29T06:18:29.963043520Z [db-sync-node:Info:57] [2022-06-29 06:18:29.96 UTC] Running DB thread

2022-06-29T06:18:29.970409386Z [db-sync-node:Info:57] [2022-06-29 06:18:29.97 UTC] Rolling back to slot 64540777, hash 106ba5f091ee1cca2c6aefbf30ec142be04c53095daee91c6b781fa0a5aef5e8

2022-06-29T06:18:31.598164539Z [db-sync-node:Info:57] [2022-06-29 06:18:29.97 UTC] No blocks need to be deleted

2022-06-29T06:18:31.598191637Z [db-sync-node.Subscription:Notice:47] [2022-06-29 06:18:29.97 UTC] Identity Required subscriptions started

2022-06-29T06:18:31.837659399Z [db-sync-node:Warning:57] [2022-06-29 06:18:31.60 UTC] Failed to parse ledger state file /var/lib/cdbsync/64540777-106ba5f091-346.lstate with error 'DecoderErrorDeserialiseFailure "Ledger state file" (DeserialiseFailure 214 "Size mismatch when decoding \nRecord RecD.\nExpected 7, but found 6.")'. Deleting it.

2022-06-29T06:18:31.837693479Z [db-sync-node:Warning:57] [2022-06-29 06:18:31.83 UTC] Rollback failed. No more ledger state files.

2022-06-29T06:18:31.973248307Z [db-sync-node:Info:57] [2022-06-29 06:18:31.97 UTC] Rolling back to genesis
2022-06-29T06:19:01.374315748Z [db-sync-node:Info:57] [2022-06-29 06:19:00.97 UTC] Deleting 7417697 blocks up to slot 64540777
rhyslbw commented 2 years ago

Deleting 7417697 blocks up to slot 64540777

This is an issue with the cardano-db-sync snapshot restoration. I would try removing the postgres and db-sync state volumes, then try restoring from the snapshot again. If you require further support, try asking over here

yungtechboy1 commented 2 years ago

Restoring from DB /12 folder fixed my issue... Along with mentioned volumes. NodeDB restored the latest snapshot from folder 12/, I downloaded it locally to restore. About 2 Hrs later, happy DB Sync, No Block needs to be deleted, and it starts catching up.

Its been ~6 Hrs for me and I'm almost at the current epoch (348) on DB Sync :)

Thanks for the link!