graphprotocol / graph-node

Graph Node indexes data from blockchains such as Ethereum and serves it over GraphQL
https://thegraph.com
Apache License 2.0
2.89k stars 962 forks source link

SubstreamsBlockStream error #4422

Closed tw7613781 closed 1 year ago

tw7613781 commented 1 year ago

Hi. team, not sure where to report the bug, here or to https://github.com/streamingfast/substreams/issues, could you check it out and suggest? As the error message seems has no relation with substreams module (the event handler in graph-node), the module source code is not present yet. If necessary, can provide later.

Do you want to request a feature or report a bug? Bug

What is the current behavior? running a substreams module to sync pancakeSwap, it works well until block height 8259000. Keeping repeat following errors

graph-node-graph-node-1  | Mar 06 04:46:43.047 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220541, current_block_head: 26220540, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:46:45.108 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220542, current_block_head: 26220541, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:46:49.144 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220543, current_block_head: 26220542, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:46:51.202 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220544, current_block_head: 26220543, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:46:57.263 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220545, current_block_head: 26220544, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:46:58.356 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220546, current_block_head: 26220545, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:46:58.786 INFO Blockstreams disconnected, connecting, cursor: JvynIW3ITtkuKeMquIPtn6WwLpc_DFJtUAPsIxhLjdjx-SaTiJryBDQgPB3XkP-lixS4SVz_jN3NHXst95YDv9Drku4y5HJsRXN6xYy4_LS8LvL0aANJcLxhDb7dYdLTWTnfawPycLlT59yzbKbeM0ZnN5MmK2bl2mlR8YdSI_ETuXowlTmrIMzT0arAp4sSq-EtErKkwyyjVGN8Kh5Tb82FZKDL7D8=, start_block: 8259000, endpoint_uri: substreams-mainnet-0, sgd: 1, subgraph_id: QmQENou94EiD2c12tfDgfMCVBMtEwtCVK7RxtfxLqVV5YC, component: SubstreamsBlockStream
graph-node-graph-node-1  | Mar 06 04:46:58.845 INFO Blockstreams connected, sgd: 1, subgraph_id: QmQENou94EiD2c12tfDgfMCVBMtEwtCVK7RxtfxLqVV5YC, component: SubstreamsBlockStream
graph-node-graph-node-1  | Mar 06 04:47:00.404 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220547, current_block_head: 26220546, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:04.460 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220548, current_block_head: 26220547, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:06.542 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220549, current_block_head: 26220548, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:09.601 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220550, current_block_head: 26220549, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:12.653 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220551, current_block_head: 26220550, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:15.704 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220552, current_block_head: 26220551, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:18.755 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220553, current_block_head: 26220552, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:22.817 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220554, current_block_head: 26220553, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:24.860 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220555, current_block_head: 26220554, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:26.911 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220556, current_block_head: 26220555, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:30.953 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220557, current_block_head: 26220556, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:36.012 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220558, current_block_head: 26220557, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:38.133 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220559, current_block_head: 26220558, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:39.215 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220560, current_block_head: 26220559, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:43.268 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220561, current_block_head: 26220560, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:44.542 INFO received err, sgd: 1, subgraph_id: QmQENou94EiD2c12tfDgfMCVBMtEwtCVK7RxtfxLqVV5YC, component: SubstreamsBlockStream
graph-node-graph-node-1  | Mar 06 04:47:44.542 ERRO An error occurred while streaming blocks: status: Unknown, message: "error reading a body from connection: stream error received: unexpected internal error encountered", details: [], metadata: MetadataMap { headers: {} }, sgd: 1, subgraph_id: QmQENou94EiD2c12tfDgfMCVBMtEwtCVK7RxtfxLqVV5YC, component: SubstreamsBlockStream
graph-node-graph-node-1  | Mar 06 04:47:45.325 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220562, current_block_head: 26220561, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:48.373 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220563, current_block_head: 26220562, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:51.424 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220564, current_block_head: 26220563, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:55.460 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220565, current_block_head: 26220564, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:47:58.527 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220566, current_block_head: 26220565, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:48:00.617 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220567, current_block_head: 26220566, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:48:04.674 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220568, current_block_head: 26220567, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:48:08.729 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220569, current_block_head: 26220568, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:48:09.796 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220570, current_block_head: 26220569, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:48:11.849 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220571, current_block_head: 26220570, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:48:15.902 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220572, current_block_head: 26220571, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:48:18.956 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220573, current_block_head: 26220572, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:48:22.008 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220574, current_block_head: 26220573, provider: block-ingestor, component: BlockIngestor
graph-node-graph-node-1  | Mar 06 04:48:24.428 INFO Syncing 1 blocks from Ethereum, code: BlockIngestionStatus, blocks_needed: 1, blocks_behind: 1, latest_block_head: 26220575, current_block_head: 26220574, provider: block-ingestor, component: BlockIngestor

My subgraph.yaml is

specVersion: 0.0.4
description: PancakeSwap Subgraph powered by Substreams
repository:
schema:
  file: ./schema.graphql

dataSources:
  - kind: substreams
    name: pair
    network: bsc
    source:
      package:
        moduleName: graph_out
        file: pcs-ultra-v0.5.1.spkg
    mapping:
      kind: substreams/graph-entities
      apiVersion: 0.0.5

version graphprotocol/graph-node:c21487e

sduchesneau commented 1 year ago

The error seems to be that 'internal error'.

Does this specific line repeat ? graph-node-graph-node-1 | Mar 06 04:47:44.542 ERRO An error occurred while streaming blocks: status: Unknown, message: "error reading a body from connection: stream error received: unexpected internal error encountered", details: [], metadata: MetadataMap { headers: {} }, sgd: 1, subgraph_id: QmQENou94EiD2c12tfDgfMCVBMtEwtCVK7RxtfxLqVV5YC, component: SubstreamsBlockStream

The error seems to be graph-node getting an "internal error" response from substreams. It could simply be a retryable error. If the "internal error" keeps repeating, you should try running from the substreams CLI directly, using the same substreams.spkg and the same cursor, see if it gives you the same internal error (maybe with more details)

Note: you can skip all the BlockIngestionStatus lines from the logs, as they are not related to the specific subgraph and are noisy.

tw7613781 commented 1 year ago

thx sduchesneau

yes. the error line keep repeating. Tried run the same substreams.spkg with same cursor from substreams CLI, but found no errors.

sduchesneau commented 1 year ago

does it always show the same cursor and start_block ? (trying to figure out if it is progressing at all...)

Also, when trying to replicate with substreams run command, be sure to include the --production-mode flag to get the exact behavior as graph-node is getting. Let me know if you can make it fail without graph-node. Is the spkg file public ?

tw7613781 commented 1 year ago

thx. it show the same cursor, no progress at all. And I run the graph-node with the substreams module again, the error was not shown again when goes to block 8259000. Now it goes to 8786130 and keeping syncing well. thx for your response again. will close the issue.