IntersectMBO / cardano-db-sync

A component that follows the Cardano chain and stores blocks and transactions in PostgreSQL
Apache License 2.0
290 stars 160 forks source link

db-sync-extended error cause sync very slow #832

Closed lcgogo closed 3 years ago

lcgogo commented 3 years ago

Environment

I have a 5.1.0-mainnet upgraded from 5.1.0-beta. However, the cardano-graphql_cardano-node-ogmios_1 is syncing OK, but tthe '{"query": "{ cardano { tip { number slotNo epoch { number } } } }"}' increases very slow. I think may caused by the cardano-graphql_cardano-db-sync-extended_1 shows followed error:

[db-sync-node.Subscription:Error:45959] [2021-09-08 03:51:09.55 UTC] Identity Application Exception: LocalAddress "/node-ipc/node.socket" DbInsertException "PoolOfflineData" (SqlError {sqlState = "42703", sqlExecStatus = FatalError, sqlErrorMsg = "column \"json\" of relation \"pool_offline_data\" does not exist", sqlErrorDetail = "", sqlErrorHint = ""})

Platform

Platform version:

Runtime

Steps to reproduce the bug

# docker logs -f --tail 20 cardano-graphql_cardano-node-ogmios_1
{"severity":"Info","timestamp":"2021-09-08T04:06:22.294629251Z","thread":"328","message":{"tag":"OgmiosHealth","healthCheck":{"tag":"HealthTick","status":{"startTime":"2021-09-06T06:01:52.268845241Z","lastKnownTip":{"slot":39507691,"hash":"6773f5f223429a83bbea66a7c48384cee6efbf8d514121f435c87699ddb7c52d","blockNo":6215967},"lastTipUpdate":"2021-09-08T04:06:22.294200582Z","networkSynchronization":1.00000,"currentEra":"Mary","metrics":{"activeConnections":3,"totalConnections":3,"totalUnrouted":0,"sessionDurations":{"mean":0,"min":0,"max":0},"runtimeStats":{"currentHeapSize":1673,"gcCpuTime":256674734281,"cpuTime":4279463529919,"maxHeapSize":8872},"totalMessages":6216482}}}},"version":"v4.0.0"}
[2767fd0a:cardano.node.ChainDB:Notice:894] [2021-09-08 04:07:13.61 UTC] Chain extended, new tip: 042d8071a91a49b60c29daf1235a1f70caa2ee94a21220f1267efbe4211f54ac at slot 39507742
{"severity":"Info","timestamp":"2021-09-08T04:07:13.62030908Z","thread":"328","message":{"tag":"OgmiosHealth","healthCheck":{"tag":"HealthTick","status":{"startTime":"2021-09-06T06:01:52.268845241Z","lastKnownTip":{"slot":39507742,"hash":"042d8071a91a49b60c29daf1235a1f70caa2ee94a21220f1267efbe4211f54ac","blockNo":6215968},"lastTipUpdate":"2021-09-08T04:07:13.61983308Z","networkSynchronization":0.99999,"currentEra":"Mary","metrics":{"activeConnections":3,"totalConnections":3,"totalUnrouted":0,"sessionDurations":{"mean":0,"min":0,"max":0},"runtimeStats":{"currentHeapSize":1677,"gcCpuTime":256739806865,"cpuTime":4279550274494,"maxHeapSize":8872},"totalMessages":6216483}}}},"version":"v4.0.0"}
{"severity":"Info","timestamp":"2021-09-08T04:07:14.349293282Z","thread":"328","message":{"tag":"OgmiosHealth","healthCheck":{"tag":"HealthTick","status":{"startTime":"2021-09-06T06:01:52.268845241Z","lastKnownTip":{"slot":39507743,"hash":"2f6360121266bd7e76d1a3791d4d96cbdfb75a4ecb5e99dc314a3aed15fde33e","blockNo":6215969},"lastTipUpdate":"2021-09-08T04:07:14.348990586Z","networkSynchronization":1.00000,"currentEra":"Mary","metrics":{"activeConnections":3,"totalConnections":3,"totalUnrouted":0,"sessionDurations":{"mean":0,"min":0,"max":0},"runtimeStats":{"currentHeapSize":1677,"gcCpuTime":256745628116,"cpuTime":4279566922199,"maxHeapSize":8872},"totalMessages":6216484}}}},"version":"v4.0.0"}
[2767fd0a:cardano.node.ChainDB:Notice:894] [2021-09-08 04:07:16.26 UTC] Chain extended, new tip: e5e71a852a4501478e821198fa7c06e19dfc53d9147f9660f860c5745725ae7f at slot 39507745
[2767fd0a:cardano.node.ChainDB:Notice:894] [2021-09-08 04:07:19.26 UTC] Chain extended, new tip: 2f37c0ec53ab3f4e3a5e5db87abf34ab9ccc07dc355cde83d80318f2b07adb29 at slot 39507748
[2767fd0a:cardano.node.ChainDB:Notice:894] [2021-09-08 04:08:20.50 UTC] Chain extended, new tip: c4e1c855b7a49fd6f07e6bc4578fff286a8cc6059ad563e19b7d92ee98ebcc3f at slot 39507809
{"severity":"Info","timestamp":"2021-09-08T04:08:20.511371047Z","thread":"328","message":{"tag":"OgmiosHealth","healthCheck":{"tag":"HealthTick","status":{"startTime":"2021-09-06T06:01:52.268845241Z","lastKnownTip":{"slot":39507809,"hash":"c4e1c855b7a49fd6f07e6bc4578fff286a8cc6059ad563e19b7d92ee98ebcc3f","blockNo":6215972},"lastTipUpdate":"2021-09-08T04:08:20.510858846Z","networkSynchronization":0.99999,"currentEra":"Mary","metrics":{"activeConnections":3,"totalConnections":3,"totalUnrouted":0,"sessionDurations":{"mean":0,"min":0,"max":0},"runtimeStats":{"currentHeapSize":1673,"gcCpuTime":256822979062,"cpuTime":4279670015612,"maxHeapSize":8872},"totalMessages":6216487}}}},"version":"v4.0.0"}
[2767fd0a:cardano.node.ChainDB:Notice:894] [2021-09-08 04:08:42.49 UTC] Chain extended, new tip: 4bbda29b594bfb993c156f6bb5196e6b075e9d695aadb1f44602b61cb482e05b at slot 39507831
{"severity":"Info","timestamp":"2021-09-08T04:08:42.499376002Z","thread":"328","message":{"tag":"OgmiosHealth","healthCheck":{"tag":"HealthTick","status":{"startTime":"2021-09-06T06:01:52.268845241Z","lastKnownTip":{"slot":39507831,"hash":"4bbda29b594bfb993c156f6bb5196e6b075e9d695aadb1f44602b61cb482e05b","blockNo":6215973},"lastTipUpdate":"2021-09-08T04:08:42.498936342Z","networkSynchronization":1.00000,"currentEra":"Mary","metrics":{"activeConnections":3,"totalConnections":3,"totalUnrouted":0,"sessionDurations":{"mean":0,"min":0,"max":0},"runtimeStats":{"currentHeapSize":1669,"gcCpuTime":256858019482,"cpuTime":4279730115693,"maxHeapSize":8872},"totalMessages":6216488}}}},"version":"v4.0.0"}
[2767fd0a:cardano.node.ChainDB:Notice:894] [2021-09-08 04:08:51.27 UTC] Chain extended, new tip: 1da44fdc55a01e58a46512f2996c60060db6906a5ccc93c02ce8d1c457510bf0 at slot 39507840
{"severity":"Info","timestamp":"2021-09-08T04:08:51.274488728Z","thread":"328","message":{"tag":"OgmiosHealth","healthCheck":{"tag":"HealthTick","status":{"startTime":"2021-09-06T06:01:52.268845241Z","lastKnownTip":{"slot":39507840,"hash":"1da44fdc55a01e58a46512f2996c60060db6906a5ccc93c02ce8d1c457510bf0","blockNo":6215974},"lastTipUpdate":"2021-09-08T04:08:51.274084929Z","networkSynchronization":1.00000,"currentEra":"Mary","metrics":{"activeConnections":3,"totalConnections":3,"totalUnrouted":0,"sessionDurations":{"mean":0,"min":0,"max":0},"runtimeStats":{"currentHeapSize":1669,"gcCpuTime":256865462218,"cpuTime":4279746928659,"maxHeapSize":8872},"totalMessages":6216489}}}},"version":"v4.0.0"}
[2767fd0a:cardano.node.ChainDB:Notice:894] [2021-09-08 04:08:53.35 UTC] Chain extended, new tip: 593b4d0d621f17f91ca509cd612666d46c4526329ebd3f2c5941db76387ba47b at slot 39507842
{"severity":"Info","timestamp":"2021-09-08T04:08:53.36115295Z","thread":"328","message":{"tag":"OgmiosHealth","healthCheck":{"tag":"HealthTick","status":{"startTime":"2021-09-06T06:01:52.268845241Z","lastKnownTip":{"slot":39507842,"hash":"593b4d0d621f17f91ca509cd612666d46c4526329ebd3f2c5941db76387ba47b","blockNo":6215975},"lastTipUpdate":"2021-09-08T04:08:53.360835883Z","networkSynchronization":1.00000,"currentEra":"Mary","metrics":{"activeConnections":3,"totalConnections":3,"totalUnrouted":0,"sessionDurations":{"mean":0,"min":0,"max":0},"runtimeStats":{"currentHeapSize":1673,"gcCpuTime":256875796274,"cpuTime":4279763927593,"maxHeapSize":8872},"totalMessages":6216490}}}},"version":"v4.0.0"}
[2767fd0a:cardano.node.ChainDB:Notice:894] [2021-09-08 04:09:19.63 UTC] Chain extended, new tip: a87425e6ea97e4480b0ea4052838ccfb4f1883c597c70df2517fec3f2c0d3ab3 at slot 39507868
{"severity":"Info","timestamp":"2021-09-08T04:09:19.640135289Z","thread":"328","message":{"tag":"OgmiosHealth","healthCheck":{"tag":"HealthTick","status":{"startTime":"2021-09-06T06:01:52.268845241Z","lastKnownTip":{"slot":39507868,"hash":"a87425e6ea97e4480b0ea4052838ccfb4f1883c597c70df2517fec3f2c0d3ab3","blockNo":6215976},"lastTipUpdate":"2021-09-08T04:09:19.637833118Z","networkSynchronization":0.99999,"currentEra":"Mary","metrics":{"activeConnections":3,"totalConnections":3,"totalUnrouted":0,"sessionDurations":{"mean":0,"min":0,"max":0},"runtimeStats":{"currentHeapSize":1673,"gcCpuTime":256918965057,"cpuTime":4279820597192,"maxHeapSize":8872},"totalMessages":6216491}}}},"version":"v4.0.0"}
[2767fd0a:cardano.node.ChainDB:Notice:894] [2021-09-08 04:09:24.36 UTC] Chain extended, new tip: f8c4b9538a199cf9150ac0f3a6b28184dc09e76016dbb7e80d584d162d627efd at slot 39507873
{"severity":"Info","timestamp":"2021-09-08T04:09:24.366550257Z","thread":"328","message":{"tag":"OgmiosHealth","healthCheck":{"tag":"HealthTick","status":{"startTime":"2021-09-06T06:01:52.268845241Z","lastKnownTip":{"slot":39507873,"hash":"f8c4b9538a199cf9150ac0f3a6b28184dc09e76016dbb7e80d584d162d627efd","blockNo":6215977},"lastTipUpdate":"2021-09-08T04:09:24.366177708Z","networkSynchronization":1.00000,"currentEra":"Mary","metrics":{"activeConnections":3,"totalConnections":3,"totalUnrouted":0,"sessionDurations":{"mean":0,"min":0,"max":0},"runtimeStats":{"currentHeapSize":1677,"gcCpuTime":256931206071,"cpuTime":4279845591570,"maxHeapSize":8872},"totalMessages":6216492}}}},"version":"v4.0.0"}
[2767fd0a:cardano.node.ChainDB:Notice:894] [2021-09-08 04:09:42.55 UTC] Chain extended, new tip: f9550e8f0f50a83e011df40a58bc9a399cab8c2d76feaf99108965ca52c5b35d at slot 39507891
{"severity":"Info","timestamp":"2021-09-08T04:09:42.560981976Z","thread":"328","message":{"tag":"OgmiosHealth","healthCheck":{"tag":"HealthTick","status":{"startTime":"2021-09-06T06:01:52.268845241Z","lastKnownTip":{"slot":39507891,"hash":"f9550e8f0f50a83e011df40a58bc9a399cab8c2d76feaf99108965ca52c5b35d","blockNo":6215978},"lastTipUpdate":"2021-09-08T04:09:42.56069968Z","networkSynchronization":0.99999,"currentEra":"Mary","metrics":{"activeConnections":3,"totalConnections":3,"totalUnrouted":0,"sessionDurations":{"mean":0,"min":0,"max":0},"runtimeStats":{"currentHeapSize":1673,"gcCpuTime":256978898763,"cpuTime":4279915672379,"maxHeapSize":8872},"totalMessages":6216493}}}},"version":"v4.0.0"}

# docker logs -f --tail 200 cardano-graphql_cardano-db-sync-extended_1
[db-sync-node:Info:45968] [2021-09-08 03:41:25.47 UTC] Found snapshot file for slot 39052794, hash 1693df35ad6cd02981ef2fe314078561e52bc61f5a8cd9d01012bde8fb663e6f
[db-sync-node:Info:45968] [2021-09-08 03:42:01.15 UTC] File /data/39052794-1693df35ad-287.lstate exists
[db-sync-node:Info:45968] [2021-09-08 03:47:29.31 UTC] insertShelleyBlock(Mary): epoch 288, slot 39078147, block 6195000, hash 8de101678a3d69f6c8b61a55f549d8cf91fa5be09a6f131588de0b1b72880a90
[db-sync-node:Info:45968] [2021-09-08 03:51:09.46 UTC] Offline pool metadata fetch: 44 results, 56 fetch errors
[db-sync-node:Error:45968] [2021-09-08 03:51:09.46 UTC] runDBThread: DbInsertException "PoolOfflineData" (SqlError {sqlState = "42703", sqlExecStatus = FatalError, sqlErrorMsg = "column \"json\" of relation \"pool_offline_data\" does not exist", sqlErrorDetail = "", sqlErrorHint = ""})
[db-sync-node:Error:45971] [2021-09-08 03:51:09.55 UTC] recvMsgRollForward: AsyncCancelled
[db-sync-node:Error:45963] [2021-09-08 03:51:09.55 UTC] ChainSyncWithBlocksPtcl: DbInsertException "PoolOfflineData" (SqlError {sqlState = "42703", sqlExecStatus = FatalError, sqlErrorMsg = "column \"json\" of relation \"pool_offline_data\" does not exist", sqlErrorDetail = "", sqlErrorHint = ""})
[db-sync-node.Mux:Info:45960] [2021-09-08 03:51:09.55 UTC] Bearer on ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"} event: State: Dead
[db-sync-node.Mux:Notice:45960] [2021-09-08 03:51:09.55 UTC] Bearer on ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"} event: Miniprotocol MiniProtocolNum 5 InitiatorDir terminated with exception DbInsertException "PoolOfflineData" (SqlError {sqlState = "42703", sqlExecStatus = FatalError, sqlErrorMsg = "column \"json\" of relation \"pool_offline_data\" does not exist", sqlErrorDetail = "", sqlErrorHint = ""})
[db-sync-node.Subscription:Error:45959] [2021-09-08 03:51:09.55 UTC] Identity Application Exception: LocalAddress "/node-ipc/node.socket" DbInsertException "PoolOfflineData" (SqlError {sqlState = "42703", sqlExecStatus = FatalError, sqlErrorMsg = "column \"json\" of relation \"pool_offline_data\" does not exist", sqlErrorDetail = "", sqlErrorHint = ""})
[db-sync-node.ErrorPolicy:Error:6] [2021-09-08 03:51:09.55 UTC] IP LocalAddress "/node-ipc/node.socket" ErrorPolicyUnhandledApplicationException (DbInsertException "PoolOfflineData" (SqlError {sqlState = "42703", sqlExecStatus = FatalError, sqlErrorMsg = "column \"json\" of relation \"pool_offline_data\" does not exist", sqlErrorDetail = "", sqlErrorHint = ""}))
[db-sync-node.Subscription:Notice:67] [2021-09-08 03:51:11.42 UTC] Identity Restarting Subscription after 624.465004361s desired valency 1 current valency 0
[db-sync-node.Subscription:Notice:67] [2021-09-08 03:51:11.42 UTC] Identity Starting Subscription Worker, valency 1
[db-sync-node.Subscription:Notice:46134] [2021-09-08 03:51:11.42 UTC] Identity Connection Attempt Start, destination LocalAddress "/node-ipc/node.socket"
[db-sync-node.Subscription:Notice:46134] [2021-09-08 03:51:11.42 UTC] Identity Connection Attempt End, destination LocalAddress "/node-ipc/node.socket" outcome: ConnectSuccessLast
[db-sync-node.Handshake:Info:46134] [2021-09-08 03:51:11.42 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)]))
[db-sync-node.Handshake:Info:46134] [2021-09-08 03:51:11.43 UTC] WithMuxBearer (ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"}) Recv (ServerAgency TokConfirm,MsgAcceptVersion NodeToClientV_9 (TInt 764824073))
[db-sync-node.Mux:Info:46134] [2021-09-08 03:51:11.43 UTC] Bearer on ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"} event: Handshake Client end, duration 0.013139756s
[db-sync-node.Mux:Info:46135] [2021-09-08 03:51:11.43 UTC] Bearer on ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"} event: State: Mature
[db-sync-node:Info:46138] [2021-09-08 03:51:11.43 UTC] Starting chainSyncClient
[db-sync-node.Subscription:Notice:67] [2021-09-08 03:51:11.44 UTC] Identity Required subscriptions started
[db-sync-node:Info:46138] [2021-09-08 03:51:11.46 UTC] Cardano.Db tip is at slot 39095924, block 6195882
[db-sync-node:Info:46143] [2021-09-08 03:51:11.46 UTC] Running DB thread
[db-sync-node:Info:46143] [2021-09-08 03:51:11.47 UTC] Rolling back to slot 39052794, hash 1693df35ad6cd02981ef2fe314078561e52bc61f5a8cd9d01012bde8fb663e6f
[db-sync-node:Info:46143] [2021-09-08 03:51:11.48 UTC] Deleting 2154 blocks up to slot 39095924
[db-sync-node:Info:46143] [2021-09-08 03:51:25.16 UTC] Blocks deleted
[db-sync-node:Info:46143] [2021-09-08 03:51:48.59 UTC] Found snapshot file for slot 39052794, hash 1693df35ad6cd02981ef2fe314078561e52bc61f5a8cd9d01012bde8fb663e6f
[db-sync-node:Info:46143] [2021-09-08 03:52:24.35 UTC] File /data/39052794-1693df35ad-287.lstate exists
[db-sync-node:Info:46143] [2021-09-08 03:57:40.07 UTC] insertShelleyBlock(Mary): epoch 288, slot 39078147, block 6195000, hash 8de101678a3d69f6c8b61a55f549d8cf91fa5be09a6f131588de0b1b72880a90
[db-sync-node:Info:46143] [2021-09-08 04:01:30.06 UTC] Offline pool metadata fetch: 44 results, 56 fetch errors
[db-sync-node:Error:46143] [2021-09-08 04:01:30.06 UTC] runDBThread: DbInsertException "PoolOfflineData" (SqlError {sqlState = "42703", sqlExecStatus = FatalError, sqlErrorMsg = "column \"json\" of relation \"pool_offline_data\" does not exist", sqlErrorDetail = "", sqlErrorHint = ""})
[db-sync-node:Error:46146] [2021-09-08 04:01:30.06 UTC] recvMsgRollForward: AsyncCancelled
[db-sync-node:Error:46138] [2021-09-08 04:01:30.06 UTC] ChainSyncWithBlocksPtcl: DbInsertException "PoolOfflineData" (SqlError {sqlState = "42703", sqlExecStatus = FatalError, sqlErrorMsg = "column \"json\" of relation \"pool_offline_data\" does not exist", sqlErrorDetail = "", sqlErrorHint = ""})
[db-sync-node.Mux:Info:46135] [2021-09-08 04:01:30.07 UTC] Bearer on ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"} event: State: Dead
[db-sync-node.Mux:Notice:46135] [2021-09-08 04:01:30.07 UTC] Bearer on ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"} event: Miniprotocol MiniProtocolNum 5 InitiatorDir terminated with exception DbInsertException "PoolOfflineData" (SqlError {sqlState = "42703", sqlExecStatus = FatalError, sqlErrorMsg = "column \"json\" of relation \"pool_offline_data\" does not exist", sqlErrorDetail = "", sqlErrorHint = ""})
[db-sync-node.Subscription:Error:46134] [2021-09-08 04:01:30.10 UTC] Identity Application Exception: LocalAddress "/node-ipc/node.socket" DbInsertException "PoolOfflineData" (SqlError {sqlState = "42703", sqlExecStatus = FatalError, sqlErrorMsg = "column \"json\" of relation \"pool_offline_data\" does not exist", sqlErrorDetail = "", sqlErrorHint = ""})
[db-sync-node.ErrorPolicy:Error:6] [2021-09-08 04:01:30.10 UTC] IP LocalAddress "/node-ipc/node.socket" ErrorPolicyUnhandledApplicationException (DbInsertException "PoolOfflineData" (SqlError {sqlState = "42703", sqlExecStatus = FatalError, sqlErrorMsg = "column \"json\" of relation \"pool_offline_data\" does not exist", sqlErrorDetail = "", sqlErrorHint = ""}))
[db-sync-node.Subscription:Notice:67] [2021-09-08 04:01:32.26 UTC] Identity Restarting Subscription after 620.84269761s desired valency 1 current valency 0
[db-sync-node.Subscription:Notice:67] [2021-09-08 04:01:32.26 UTC] Identity Starting Subscription Worker, valency 1
[db-sync-node.Subscription:Notice:46308] [2021-09-08 04:01:32.26 UTC] Identity Connection Attempt Start, destination LocalAddress "/node-ipc/node.socket"
[db-sync-node.Subscription:Notice:46308] [2021-09-08 04:01:32.26 UTC] Identity Connection Attempt End, destination LocalAddress "/node-ipc/node.socket" outcome: ConnectSuccessLast
[db-sync-node.Handshake:Info:46308] [2021-09-08 04:01:32.26 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)]))
[db-sync-node.Subscription:Notice:67] [2021-09-08 04:01:32.29 UTC] Identity Required subscriptions started
[db-sync-node.Handshake:Info:46308] [2021-09-08 04:01:32.32 UTC] WithMuxBearer (ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"}) Recv (ServerAgency TokConfirm,MsgAcceptVersion NodeToClientV_9 (TInt 764824073))
[db-sync-node.Mux:Info:46308] [2021-09-08 04:01:32.32 UTC] Bearer on ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"} event: Handshake Client end, duration 0.060127184s
[db-sync-node.Mux:Info:46309] [2021-09-08 04:01:32.32 UTC] Bearer on ConnectionId {localAddress = LocalAddress "", remoteAddress = LocalAddress "/ipc/node.socket"} event: State: Mature
[db-sync-node:Info:46312] [2021-09-08 04:01:32.32 UTC] Starting chainSyncClient
[db-sync-node:Info:46312] [2021-09-08 04:01:32.35 UTC] Cardano.Db tip is at slot 39096022, block 6195888
[db-sync-node:Info:46317] [2021-09-08 04:01:32.35 UTC] Running DB thread
[db-sync-node:Info:46317] [2021-09-08 04:01:32.38 UTC] Rolling back to slot 39052794, hash 1693df35ad6cd02981ef2fe314078561e52bc61f5a8cd9d01012bde8fb663e6f
[db-sync-node:Info:46317] [2021-09-08 04:01:32.41 UTC] Deleting 2160 blocks up to slot 39096022
[db-sync-node:Info:46317] [2021-09-08 04:01:45.46 UTC] Blocks deleted
[db-sync-node:Info:46317] [2021-09-08 04:02:13.37 UTC] Found snapshot file for slot 39052794, hash 1693df35ad6cd02981ef2fe314078561e52bc61f5a8cd9d01012bde8fb663e6f
[db-sync-node:Info:46317] [2021-09-08 04:02:49.01 UTC] File /data/39052794-1693df35ad-287.lstate exists

What is the expected behavior?

rhyslbw commented 3 years ago

It's out of scope for cardano-graphql, but did you get through this?

erikd commented 3 years ago

This:

DbInsertException "PoolOfflineData"
  ( SqlError
     { sqlState = "42703"
     , sqlExecStatus = FatalError
     , sqlErrorMsg = "column \"json\" of relation \"pool_offline_data\" does not exist"
     , sqlErrorDetail = ""
     , sqlErrorHint = ""
     }
   )

seems like a schema mismatch (the json field was added between the 10.0.x and the 11.0.x releases).

If db-sync did not abort on startup over a schema mismatch, then something is really messed up.

My only suggestion is to restore from a snapshot or sync from genesis.

erikd commented 3 years ago

Closing this. Seems like a stale ticket.