Update sushiswap-subgraph stack to point to filecoin endpoint #509

Merged
prathamesh0 merged 16 commits from pm-sushigraph-filecoin into main 2023-08-30 10:35:16 +00:00
prathamesh0 commented 2023-08-18 07:00:43 +00:00 (Migrated from github.com)
Part of https://github.com/cerc-io/stack-orchestrator/issues/495
prathamesh0 commented 2023-08-21 13:50:50 +00:00 (Migrated from github.com)

After following log appears in the graph-node container, block entities created by the blocks subgraph can be checked using a GQL request to the subgraph endpoint:

$ docker logs -f sushigraph-graph-node-1
.
.
Aug 21 13:22:44.463 INFO Committed write batch, time_ms: 36, weight: 3063, entities: 2, block_count: 1, block_number: 2867000, sgd: 2, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager
.
.

Find out the mapped host port for the subgraph endpoint:

laconic-so --stack sushiswap-subgraph deploy --cluster sushigraph port graph-node 8000
# 0.0.0.0:HOST_PORT

Make following GQL request at the endpoint http://127.0.0.1:<HOST_PORT>/subgraphs/name/sushiswap/blocks/graphql:

query {
  blocks {
    number
    stateRoot
    parentHash
    timestamp
  }
}

# Expected output:
# {
#   "data": {
#     "blocks": [
#       {
#         "number": "2867000",
#         "stateRoot": "0x0000000000000000000000000000000000000000000000000000000000000000",
#         "parentHash": "0x84d5ad446e903c5f4ea53accc8a61c11956a4199d6c6a0d767afa9ed3af677a5",
#         "timestamp": "1684316400"
#       }
#     ]
#   }
# }
After following log appears in the `graph-node` container, block entities created by the `blocks` subgraph can be checked using a GQL request to the subgraph endpoint: ```bash $ docker logs -f sushigraph-graph-node-1 . . Aug 21 13:22:44.463 INFO Committed write batch, time_ms: 36, weight: 3063, entities: 2, block_count: 1, block_number: 2867000, sgd: 2, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager . . ``` Find out the mapped host port for the subgraph endpoint: ```bash laconic-so --stack sushiswap-subgraph deploy --cluster sushigraph port graph-node 8000 # 0.0.0.0:HOST_PORT ``` Make following GQL request at the endpoint `http://127.0.0.1:<HOST_PORT>/subgraphs/name/sushiswap/blocks/graphql`: ```gql query { blocks { number stateRoot parentHash timestamp } } # Expected output: # { # "data": { # "blocks": [ # { # "number": "2867000", # "stateRoot": "0x0000000000000000000000000000000000000000000000000000000000000000", # "parentHash": "0x84d5ad446e903c5f4ea53accc8a61c11956a4199d6c6a0d767afa9ed3af677a5", # "timestamp": "1684316400" # } # ] # } # } ```
prathamesh0 commented 2023-08-21 14:56:10 +00:00 (Migrated from github.com)

On running the v3 subgraph with startBlock set to 3143725 (skipping blocks to get to the first PoolCreated event at 3143728), getting the following error in graph-node:

$ docker logs -f sushigraph-graph-node-1
.
.
Aug 21 14:49:33.799 INFO Scanning blocks [3143725, 3143725], range_size: 1, sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: BlockStream
Aug 21 14:49:33.800 INFO [check skipped] getting hash for `to' block: block_hash_by_block_number(3143725), sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: BlockStream
Aug 21 14:49:34.763 INFO Syncing 42 blocks from Ethereum, code: BlockIngestionLagging, blocks_needed: 42, blocks_behind: 42, latest_block_head: 3144097, current_block_head: 3144055, provider: filecoin-rpc-0, component: EthereumPollingBlockIngestor
Aug 21 14:49:38.287 INFO Scanning blocks [3143726, 3143735], range_size: 10, sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: BlockStream
Aug 21 14:49:38.288 INFO [check skipped] getting hash for `to' block: block_hash_by_block_number(3143735), sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: BlockStream
Aug 21 14:49:54.337 INFO Done processing trigger, gas_used: 0, data_source: Factory, handler: handlePoolCreated, total_ms: 0, transaction: 0x66be…2053, address: 0xc35d…74c4, signature: PoolCreated(indexed address,indexed address,indexed uint24,int24,address), sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: SubgraphInstanceManager
Aug 21 14:49:54.345 ERRO Subgraph failed with non-deterministic error: failed to process trigger: block #3143728 (0x308e…bbae), transaction 66be068a8e85fbe83587627eaf302e647c8b522f57454ac168e6efaa16d22053: module instantiation failed: Failed to convert string to Address/H160: ''	wasm backtrace:	    0: 0x64aa - <unknown>!~start	: Invalid input length, retry_delay_s: 109, attempt: 0, sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: SubgraphInstanceManager
Aug 21 14:49:54.828 INFO Scanning blocks [3143736, 3143805], range_size: 100, sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: BlockStream
.
.
On running the `v3` subgraph with `startBlock` set to `3143725` (skipping blocks to get to the first `PoolCreated` event at ` 3143728`), getting the following error in `graph-node`: ```bash $ docker logs -f sushigraph-graph-node-1 . . Aug 21 14:49:33.799 INFO Scanning blocks [3143725, 3143725], range_size: 1, sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: BlockStream Aug 21 14:49:33.800 INFO [check skipped] getting hash for `to' block: block_hash_by_block_number(3143725), sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: BlockStream Aug 21 14:49:34.763 INFO Syncing 42 blocks from Ethereum, code: BlockIngestionLagging, blocks_needed: 42, blocks_behind: 42, latest_block_head: 3144097, current_block_head: 3144055, provider: filecoin-rpc-0, component: EthereumPollingBlockIngestor Aug 21 14:49:38.287 INFO Scanning blocks [3143726, 3143735], range_size: 10, sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: BlockStream Aug 21 14:49:38.288 INFO [check skipped] getting hash for `to' block: block_hash_by_block_number(3143735), sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: BlockStream Aug 21 14:49:54.337 INFO Done processing trigger, gas_used: 0, data_source: Factory, handler: handlePoolCreated, total_ms: 0, transaction: 0x66be…2053, address: 0xc35d…74c4, signature: PoolCreated(indexed address,indexed address,indexed uint24,int24,address), sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: SubgraphInstanceManager Aug 21 14:49:54.345 ERRO Subgraph failed with non-deterministic error: failed to process trigger: block #3143728 (0x308e…bbae), transaction 66be068a8e85fbe83587627eaf302e647c8b522f57454ac168e6efaa16d22053: module instantiation failed: Failed to convert string to Address/H160: '' wasm backtrace: 0: 0x64aa - <unknown>!~start : Invalid input length, retry_delay_s: 109, attempt: 0, sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: SubgraphInstanceManager Aug 21 14:49:54.828 INFO Scanning blocks [3143736, 3143805], range_size: 100, sgd: 1, subgraph_id: QmeUAP3i5LDzwo8THyHmFGNXx9f7wv1HX3WbJfZXsohRq1, component: BlockStream . . ```
prathamesh0 commented 2023-08-22 08:51:56 +00:00 (Migrated from github.com)

The blocks subgraph seems to be running fine for historic blocks (ran for >5000 blocks after startBlock):

# graph-node logs
.
.
Aug 22 12:09:30.977 DEBG Start processing block, triggers: 1, block_hash: 0x7d8ae13c8ecf8b33c14f41c60aeb7423defe382564ebac1499219e18d3eddcc3, block_number: 2871966, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager
Aug 22 12:09:30.986 INFO Done processing trigger, gas_used: 77171209, data_source: UniswapV2Factory, handler: onBlock, total_ms: 7, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager
Aug 22 12:09:30.987 DEBG Entity cache statistics, evict_time_ms: 0, accesses: 0, hit_rate: 100%, stale_update: false, evicted_count: 0, count: 4932, evicted_weight: 0, weight: 6415568, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager
Aug 22 12:09:30.988 INFO Applying 2 entity operation(s), block_hash: 0x7d8ae13c8ecf8b33c14f41c60aeb7423defe382564ebac1499219e18d3eddcc3, block_number: 2871966, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager
Aug 22 12:09:30.989 DEBG Start processing block, triggers: 1, block_hash: 0xe3e3e71a6af4956cd921da82ae19a598493fdabbb91228232f9a5aaeac292495, block_number: 2871967, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager
Aug 22 12:09:30.997 INFO Done processing trigger, gas_used: 77171209, data_source: UniswapV2Factory, handler: onBlock, total_ms: 7, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager
Aug 22 12:09:30.998 DEBG Entity cache statistics, evict_time_ms: 0, accesses: 0, hit_rate: 100%, stale_update: false, evicted_count: 0, count: 4933, evicted_weight: 0, weight: 6416869, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager
Aug 22 12:09:30.999 INFO Applying 2 entity operation(s), block_hash: 0xe3e3e71a6af4956cd921da82ae19a598493fdabbb91228232f9a5aaeac292495, block_number: 2871967, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager
.
.

On trying to run it near head by redeploying with startBlock set to 3145500 (head at 3146000), getting a recurring "non-fatal error" after some time with slowed down processing of blocks in graph-node:

# graph-node logs
.
.
Aug 22 12:23:21.198 DEBG Start processing block, triggers: 1, block_hash: 0x544d856b333c47346a10d43b6d8adc00e8cc5c58c0b72ad24698132a758222d4, block_number: 3145774, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager
Aug 22 12:23:21.203 INFO Done processing trigger, gas_used: 77171209, data_source: UniswapV2Factory, handler: onBlock, total_ms: 5, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager
Aug 22 12:23:21.205 DEBG Entity cache statistics, evict_time_ms: 0, accesses: 0, hit_rate: 100%, stale_update: false, evicted_count: 0, count: 273, evicted_weight: 0, weight: 354275, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager
Aug 22 12:23:21.205 INFO Applying 2 entity operation(s), block_hash: 0x544d856b333c47346a10d43b6d8adc00e8cc5c58c0b72ad24698132a758222d4, block_number: 3145774, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager
Aug 22 12:23:21.205 DEBG Start processing block, triggers: 1, block_hash: 0x68f97534eae4556ab751f3237cb2d178037cd907149d01321205fc90f807565a, block_number: 3145775, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager
Aug 22 12:23:21.212 INFO Done processing trigger, gas_used: 77171209, data_source: UniswapV2Factory, handler: onBlock, total_ms: 5, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager
Aug 22 12:23:21.213 DEBG Entity cache statistics, evict_time_ms: 0, accesses: 0, hit_rate: 100%, stale_update: false, evicted_count: 0, count: 274, evicted_weight: 0, weight: 355575, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager
Aug 22 12:23:21.214 INFO Applying 2 entity operation(s), block_hash: 0x68f97534eae4556ab751f3237cb2d178037cd907149d01321205fc90f807565a, block_number: 3145775, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager
Aug 22 12:23:21.214 DEBG Block stream produced a non-fatal error, error: store error: operator does not exist: bytea = character varying, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager
.
.

On running the v3 subgraph with startBlock set to 3143725 (skipping blocks to get to the first PoolCreated event at 3143728), getting the following error in graph-node when it tries to process the Transfer and IncreaseLiquidity events from the NonfungiblePositionManager contract:

# graph-node logs
.
.
Aug 22 11:01:11.874 INFO Scanned blocks [3143726, 3143735], range_size: 10, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: BlockStream
Aug 22 11:01:11.874 DEBG Processing 3 triggers, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: BlockStream
Aug 22 11:01:11.874 DEBG Start processing block, triggers: 3, block_hash: 0x308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, block_number: 3143728, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:11.896 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 95d89b41, address: 60e1773636cf5e4a227d9ac24f20feca034ee25a, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:11.899 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 06fdde03, address: 60e1773636cf5e4a227d9ac24f20feca034ee25a, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:11.900 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 18160ddd, address: 60e1773636cf5e4a227d9ac24f20feca034ee25a, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:11.903 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 313ce567, address: 60e1773636cf5e4a227d9ac24f20feca034ee25a, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:11.906 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 95d89b41, address: eb466342c4d449bc9f53a865d5cb90586f405215, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:11.908 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 06fdde03, address: eb466342c4d449bc9f53a865d5cb90586f405215, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:11.910 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 18160ddd, address: eb466342c4d449bc9f53a865d5cb90586f405215, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:11.912 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 313ce567, address: eb466342c4d449bc9f53a865d5cb90586f405215, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:11.921 INFO Create data source, params: 0x1d1375281265e4dd496d90455f7c82f4fbd85cc2, name: Pool, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:11.934 INFO Done processing trigger, gas_used: 40530732745, data_source: Factory, handler: handlePoolCreated, total_ms: 58, transaction: 0x66be…2053, address: 0xc35d…74c4, signature: PoolCreated(indexed address,indexed address,indexed uint24,int24,address), sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:11.939 DEBG calling getPosition, data_source: NonfungiblePositionManager, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager > UserMapping
Aug 22 11:01:11.946 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 99fbab880000000000000000000000000000000000000000000000000000000000000001, address: f4d73326c13a4fc5fd7a064217e12780e9bd62c3, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:12.334 INFO Contract call reverted, reason: message execution failed: exit 33, revert reason: Error(Invalid token ID), vm error: message failed with backtrace:
00: f02192757 (method 3844450837) -- contract reverted (33)
 (RetCode=33), sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:12.335 INFO Done processing trigger, gas_used: 5154428749, data_source: NonfungiblePositionManager, handler: handleTransfer, total_ms: 400, transaction: 0x66be…2053, address: 0xf4d7…62c3, signature: Transfer(indexed address,indexed address,indexed uint256), sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:12.341 INFO Scanning blocks [3143736, 3143835], target_range_size: 100, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: BlockStream
Aug 22 11:01:12.342 DEBG Finding nearest valid `to` block to 3143835, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: BlockStream
Aug 22 11:01:12.353 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 99fbab880000000000000000000000000000000000000000000000000000000000000001, address: f4d73326c13a4fc5fd7a064217e12780e9bd62c3, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:12.648 INFO Contract call reverted, reason: message execution failed: exit 33, revert reason: Error(Invalid token ID), vm error: message failed with backtrace:
00: f02192757 (method 3844450837) -- contract reverted (33)
 (RetCode=33), sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
Aug 22 11:01:12.650 INFO Done processing trigger, gas_used: 5048269122, data_source: NonfungiblePositionManager, handler: handleIncreaseLiquidity, total_ms: 313, transaction: 0x66be…2053, address: 0xf4d7…62c3, signature: IncreaseLiquidity(indexed uint256,uint128,uint256,uint256), sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager
.
.
The `blocks` subgraph seems to be running fine for historic blocks (ran for `>5000` blocks after `startBlock`): ```bash # graph-node logs . . Aug 22 12:09:30.977 DEBG Start processing block, triggers: 1, block_hash: 0x7d8ae13c8ecf8b33c14f41c60aeb7423defe382564ebac1499219e18d3eddcc3, block_number: 2871966, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager Aug 22 12:09:30.986 INFO Done processing trigger, gas_used: 77171209, data_source: UniswapV2Factory, handler: onBlock, total_ms: 7, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager Aug 22 12:09:30.987 DEBG Entity cache statistics, evict_time_ms: 0, accesses: 0, hit_rate: 100%, stale_update: false, evicted_count: 0, count: 4932, evicted_weight: 0, weight: 6415568, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager Aug 22 12:09:30.988 INFO Applying 2 entity operation(s), block_hash: 0x7d8ae13c8ecf8b33c14f41c60aeb7423defe382564ebac1499219e18d3eddcc3, block_number: 2871966, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager Aug 22 12:09:30.989 DEBG Start processing block, triggers: 1, block_hash: 0xe3e3e71a6af4956cd921da82ae19a598493fdabbb91228232f9a5aaeac292495, block_number: 2871967, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager Aug 22 12:09:30.997 INFO Done processing trigger, gas_used: 77171209, data_source: UniswapV2Factory, handler: onBlock, total_ms: 7, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager Aug 22 12:09:30.998 DEBG Entity cache statistics, evict_time_ms: 0, accesses: 0, hit_rate: 100%, stale_update: false, evicted_count: 0, count: 4933, evicted_weight: 0, weight: 6416869, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager Aug 22 12:09:30.999 INFO Applying 2 entity operation(s), block_hash: 0xe3e3e71a6af4956cd921da82ae19a598493fdabbb91228232f9a5aaeac292495, block_number: 2871967, sgd: 4, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: SubgraphInstanceManager . . ``` On trying to run it near head by redeploying with `startBlock` set to `3145500` (head at `3146000`), getting a recurring "non-fatal error" after some time with slowed down processing of blocks in `graph-node`: ```bash # graph-node logs . . Aug 22 12:23:21.198 DEBG Start processing block, triggers: 1, block_hash: 0x544d856b333c47346a10d43b6d8adc00e8cc5c58c0b72ad24698132a758222d4, block_number: 3145774, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager Aug 22 12:23:21.203 INFO Done processing trigger, gas_used: 77171209, data_source: UniswapV2Factory, handler: onBlock, total_ms: 5, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager Aug 22 12:23:21.205 DEBG Entity cache statistics, evict_time_ms: 0, accesses: 0, hit_rate: 100%, stale_update: false, evicted_count: 0, count: 273, evicted_weight: 0, weight: 354275, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager Aug 22 12:23:21.205 INFO Applying 2 entity operation(s), block_hash: 0x544d856b333c47346a10d43b6d8adc00e8cc5c58c0b72ad24698132a758222d4, block_number: 3145774, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager Aug 22 12:23:21.205 DEBG Start processing block, triggers: 1, block_hash: 0x68f97534eae4556ab751f3237cb2d178037cd907149d01321205fc90f807565a, block_number: 3145775, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager Aug 22 12:23:21.212 INFO Done processing trigger, gas_used: 77171209, data_source: UniswapV2Factory, handler: onBlock, total_ms: 5, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager Aug 22 12:23:21.213 DEBG Entity cache statistics, evict_time_ms: 0, accesses: 0, hit_rate: 100%, stale_update: false, evicted_count: 0, count: 274, evicted_weight: 0, weight: 355575, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager Aug 22 12:23:21.214 INFO Applying 2 entity operation(s), block_hash: 0x68f97534eae4556ab751f3237cb2d178037cd907149d01321205fc90f807565a, block_number: 3145775, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager Aug 22 12:23:21.214 DEBG Block stream produced a non-fatal error, error: store error: operator does not exist: bytea = character varying, sgd: 5, subgraph_id: QmUsViBkUEm2JtvkEqB56yvWcaocM2pbwBMWJSnRgeeLXL, component: SubgraphInstanceManager . . ``` On running the `v3` subgraph with `startBlock` set to `3143725` (skipping blocks to get to the first `PoolCreated` event at `3143728`), getting the following error in `graph-node` when it tries to process the `Transfer` and `IncreaseLiquidity` events from the `NonfungiblePositionManager` contract: ```bash # graph-node logs . . Aug 22 11:01:11.874 INFO Scanned blocks [3143726, 3143735], range_size: 10, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: BlockStream Aug 22 11:01:11.874 DEBG Processing 3 triggers, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: BlockStream Aug 22 11:01:11.874 DEBG Start processing block, triggers: 3, block_hash: 0x308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, block_number: 3143728, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:11.896 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 95d89b41, address: 60e1773636cf5e4a227d9ac24f20feca034ee25a, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:11.899 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 06fdde03, address: 60e1773636cf5e4a227d9ac24f20feca034ee25a, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:11.900 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 18160ddd, address: 60e1773636cf5e4a227d9ac24f20feca034ee25a, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:11.903 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 313ce567, address: 60e1773636cf5e4a227d9ac24f20feca034ee25a, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:11.906 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 95d89b41, address: eb466342c4d449bc9f53a865d5cb90586f405215, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:11.908 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 06fdde03, address: eb466342c4d449bc9f53a865d5cb90586f405215, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:11.910 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 18160ddd, address: eb466342c4d449bc9f53a865d5cb90586f405215, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:11.912 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 313ce567, address: eb466342c4d449bc9f53a865d5cb90586f405215, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:11.921 INFO Create data source, params: 0x1d1375281265e4dd496d90455f7c82f4fbd85cc2, name: Pool, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:11.934 INFO Done processing trigger, gas_used: 40530732745, data_source: Factory, handler: handlePoolCreated, total_ms: 58, transaction: 0x66be…2053, address: 0xc35d…74c4, signature: PoolCreated(indexed address,indexed address,indexed uint24,int24,address), sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:11.939 DEBG calling getPosition, data_source: NonfungiblePositionManager, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager > UserMapping Aug 22 11:01:11.946 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 99fbab880000000000000000000000000000000000000000000000000000000000000001, address: f4d73326c13a4fc5fd7a064217e12780e9bd62c3, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:12.334 INFO Contract call reverted, reason: message execution failed: exit 33, revert reason: Error(Invalid token ID), vm error: message failed with backtrace: 00: f02192757 (method 3844450837) -- contract reverted (33) (RetCode=33), sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:12.335 INFO Done processing trigger, gas_used: 5154428749, data_source: NonfungiblePositionManager, handler: handleTransfer, total_ms: 400, transaction: 0x66be…2053, address: 0xf4d7…62c3, signature: Transfer(indexed address,indexed address,indexed uint256), sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:12.341 INFO Scanning blocks [3143736, 3143835], target_range_size: 100, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: BlockStream Aug 22 11:01:12.342 DEBG Finding nearest valid `to` block to 3143835, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: BlockStream Aug 22 11:01:12.353 DEBG eth_call, block_number: 3143728, block_hash: 308e8ad67eef55d9ba76838c533e6358cc01c1b09c4844ea2829ffcbf7f8bbae, data: 99fbab880000000000000000000000000000000000000000000000000000000000000001, address: f4d73326c13a4fc5fd7a064217e12780e9bd62c3, sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:12.648 INFO Contract call reverted, reason: message execution failed: exit 33, revert reason: Error(Invalid token ID), vm error: message failed with backtrace: 00: f02192757 (method 3844450837) -- contract reverted (33) (RetCode=33), sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager Aug 22 11:01:12.650 INFO Done processing trigger, gas_used: 5048269122, data_source: NonfungiblePositionManager, handler: handleIncreaseLiquidity, total_ms: 313, transaction: 0x66be…2053, address: 0xf4d7…62c3, signature: IncreaseLiquidity(indexed uint256,uint128,uint256,uint256), sgd: 2, subgraph_id: QmdDQo9Zsy6f1wBRNFhFar5Xxt5KCFW5hhnFRPwh27MqDA, component: SubgraphInstanceManager . . ```
prathamesh0 commented 2023-08-22 11:17:54 +00:00 (Migrated from github.com)

Aug 22 11:01:12.334 INFO Contract call reverted, reason: message execution failed: exit 33, revert reason: Error(Invalid token ID), vm error: message failed with backtrace:
00: f02192757 (method 3844450837) -- contract reverted (33)

The above error from NonfungiblePositionManager contract seems to be occurring from the positions method:
https://github.com/sushiswap/v3-periphery/blob/master/contracts/NonfungiblePositionManager.sol#L100

In the v3 subgraph's Transfer event handler, a positions eth_call is made to the NFPM contract:
https://github.com/sushiswap/subgraphs/blob/master/subgraphs/v3/src/mappings/position-manager.ts#L205
https://github.com/sushiswap/subgraphs/blob/master/subgraphs/v3/src/mappings/position-manager.ts#L18

We get the same error on making the eth_call maually (using ethers) at the transaction height:

await contract.positions(ethers.BigNumber.from('0x01'), { blockTag: 3143728 });
# error: Error: message execution failed: exit 33, revert reason: Error(Invalid token ID), vm error: message failed with backtrace:
# 00: f02192757 (method 3844450837) -- contract reverted (33)

However, if we make the call at next block (3143729) or without a block tag (latest), the expected result is returned.

> Aug 22 11:01:12.334 INFO Contract call reverted, reason: message execution failed: exit 33, revert reason: Error(Invalid token ID), vm error: message failed with backtrace: 00: f02192757 (method 3844450837) -- contract reverted (33) The above error from `NonfungiblePositionManager` contract seems to be occurring from the `positions` method: https://github.com/sushiswap/v3-periphery/blob/master/contracts/NonfungiblePositionManager.sol#L100 In the `v3` subgraph's `Transfer` event handler, a `positions` eth_call is made to the NFPM contract: https://github.com/sushiswap/subgraphs/blob/master/subgraphs/v3/src/mappings/position-manager.ts#L205 https://github.com/sushiswap/subgraphs/blob/master/subgraphs/v3/src/mappings/position-manager.ts#L18 We get the same error on making the eth_call maually (using `ethers`) at the transaction height: ```bash await contract.positions(ethers.BigNumber.from('0x01'), { blockTag: 3143728 }); # error: Error: message execution failed: exit 33, revert reason: Error(Invalid token ID), vm error: message failed with backtrace: # 00: f02192757 (method 3844450837) -- contract reverted (33) ``` However, if we make the call at next block (`3143729`) or without a block tag (`latest`), the expected result is returned.
prathamesh0 commented 2023-08-23 12:24:29 +00:00 (Migrated from github.com)

After increasing the number of miners to 3 in the Lotus fixturenet, we see multiple blocks being included at some tipset heights (checked using Filecoin.ChainGetTipSetByHeight RPC call).

On doing transactions with a dummy ERC20 contract (transfers), the state change (balance) is reflected at height at which the transaction happened.
Same behaviour is seen regardless of whether or not there are multiple blocks at tipset height with the transaction.

After increasing the number of miners to 3 in the Lotus fixturenet, we see multiple blocks being included at some tipset heights (checked using `Filecoin.ChainGetTipSetByHeight` RPC call). On doing transactions with a dummy ERC20 contract (transfers), the state change (balance) is reflected at height at which the transaction happened. Same behaviour is seen regardless of whether or not there are multiple blocks at tipset height with the transaction.
prathamesh0 commented 2023-08-24 06:55:55 +00:00 (Migrated from github.com)

While running the subgraph against Lotus fixturenet, we get the following error in graph-node when it tries to process the PoolCreated event:

Aug 24 06:26:41.313 INFO Done processing trigger, gas_used: 0, data_source: Factory, handler: handlePoolCreated, total_ms: 11, transaction: 0x2264…12b1, address: 0xb8fe…25ff, signature: PoolCreated(indexed address,indexed address,indexed uint24,int24,address), sgd: 1, subgraph_id: QmY6syci6eV4oCpPjnPSFPcet5JHJ4LmXjAx8sxu5w6Xjr, component: SubgraphInstanceManager
Aug 24 06:26:41.322 ERRO Subgraph failed with non-deterministic error: failed to process trigger: block #79 (0x8e7a…cb7a), transaction 2264b5d139a17c119fae4cf4d3dc9b5749e783cf89c8d5f8db4829470cb512b1: module instantiation failed: Failed to convert string to Address/H160: ''	wasm backtrace:	    0: 0x64aa - <unknown>!~start	: Invalid input length, retry_delay_s: 131, attempt: 0, sgd: 1, subgraph_id: QmY6syci6eV4oCpPjnPSFPcet5JHJ4LmXjAx8sxu5w6Xjr, component: SubgraphInstanceManager

The error occurs because of nativePricePool being not set in the config used for subgraph deployment.
On an earlier run with the fixturenet (without the graph-node fix), it was running into the null block error even before reaching this point.

For Filecoin mainnet, the config had been updated with the required properties:
https://github.com/sushiswap/subgraphs/blob/master/config/filecoin.js

While running the subgraph against Lotus fixturenet, we get the following error in `graph-node` when it tries to process the `PoolCreated` event: ```bash Aug 24 06:26:41.313 INFO Done processing trigger, gas_used: 0, data_source: Factory, handler: handlePoolCreated, total_ms: 11, transaction: 0x2264…12b1, address: 0xb8fe…25ff, signature: PoolCreated(indexed address,indexed address,indexed uint24,int24,address), sgd: 1, subgraph_id: QmY6syci6eV4oCpPjnPSFPcet5JHJ4LmXjAx8sxu5w6Xjr, component: SubgraphInstanceManager Aug 24 06:26:41.322 ERRO Subgraph failed with non-deterministic error: failed to process trigger: block #79 (0x8e7a…cb7a), transaction 2264b5d139a17c119fae4cf4d3dc9b5749e783cf89c8d5f8db4829470cb512b1: module instantiation failed: Failed to convert string to Address/H160: '' wasm backtrace: 0: 0x64aa - <unknown>!~start : Invalid input length, retry_delay_s: 131, attempt: 0, sgd: 1, subgraph_id: QmY6syci6eV4oCpPjnPSFPcet5JHJ4LmXjAx8sxu5w6Xjr, component: SubgraphInstanceManager ``` The error occurs because of `nativePricePool` being not set in the config used for subgraph deployment. On an earlier run with the fixturenet (without the `graph-node` fix), it was running into the `null` block error even before reaching this point. For Filecoin mainnet, the config had been updated with the required properties: https://github.com/sushiswap/subgraphs/blob/master/config/filecoin.js
raulk commented 2023-08-24 12:34:08 +00:00 (Migrated from github.com)

This works against the latest tipset on the Glif API endpoint:

⟩ curl 'https://api.node.glif.io/rpc/v1' \
      -XPOST \
      -H "Content-Type: application/json" \
      --data-raw '{"id":"foo","jsonrpc":"2.0","method":"eth_call","params":[{"to":"0xF4d73326C13a4Fc5FD7A064217e12780e9Bd62c3","data":"0x99fbab880000000000000000000000000000000000000000000000000000000000000001"},"latest"]}'
{"jsonrpc":"2.0","result":"0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000060e1773636cf5e4a227d9ac24f20feca034ee25a000000000000000000000000eb466342c4d449bc9f53a865d5cb90586f4052150000000000000000000000000000000000000000000000000000000000000bb8fffffffffffffffffffffffffffffffffffffffffffffffffffffffffffbc8b4fffffffffffffffffffffffffffffffffffffffffffffffffffffffffffc0e8c00000000000000000000000000000000000000000000000000000012b4e8561a0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000","id":"foo"}

I suspect the issue is related to the way that Lotus applies tipset messages when performing the call on a specific height. In this particular case, it seems like the client is asking for height 3143728, which is where the first pool was created: https://filfox.info/en/address/f410f6tltgjwbhjh4l7l2azbbpyjhqdu32ywd2axlm6y.

I'd imagine that before that transaction, this assertion would've failed. After that transaction, the assertion likely passes.

So my theory is that eth_call is not applying the transaction before executing the call.

This works against the latest tipset on the Glif API endpoint: ``` ⟩ curl 'https://api.node.glif.io/rpc/v1' \ -XPOST \ -H "Content-Type: application/json" \ --data-raw '{"id":"foo","jsonrpc":"2.0","method":"eth_call","params":[{"to":"0xF4d73326C13a4Fc5FD7A064217e12780e9Bd62c3","data":"0x99fbab880000000000000000000000000000000000000000000000000000000000000001"},"latest"]}' {"jsonrpc":"2.0","result":"0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000060e1773636cf5e4a227d9ac24f20feca034ee25a000000000000000000000000eb466342c4d449bc9f53a865d5cb90586f4052150000000000000000000000000000000000000000000000000000000000000bb8fffffffffffffffffffffffffffffffffffffffffffffffffffffffffffbc8b4fffffffffffffffffffffffffffffffffffffffffffffffffffffffffffc0e8c00000000000000000000000000000000000000000000000000000012b4e8561a0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000","id":"foo"} ``` I suspect the issue is related to the way that Lotus applies tipset messages when performing the call on a specific height. In this particular case, it seems like the client is asking for height 3143728, which is where the first pool was created: https://filfox.info/en/address/f410f6tltgjwbhjh4l7l2azbbpyjhqdu32ywd2axlm6y. I'd imagine that _before_ that transaction, [this assertion](https://github.com/sushiswap/v3-periphery/blob/master/contracts/NonfungiblePositionManager.sol?rgh-link-date=2023-08-22T11%3A17%3A54Z#L100) would've failed. After that transaction, the assertion likely passes. So my theory is that `eth_call` is not applying the transaction _before_ executing the call.
raulk commented 2023-08-24 13:58:13 +00:00 (Migrated from github.com)

I was able to reproduce and confirm my hypothesis against the Vulcanize endpoint.

## epoch 3143728 (inclusion epoch)
⟩ curl '...' \
      -XPOST \
      -H "Content-Type: application/json" \
      --data-raw '{"id":"foo","jsonrpc":"2.0","method":"eth_call","params":[{"to":"0xF4d73326C13a4Fc5FD7A064217e12780e9Bd62c3","data":"0x99fbab880000000000000000000000000000000000000000000000000000000000000001"},"3143728"]}'
{"jsonrpc":"2.0","id":"foo","error":{"code":1,"message":"message execution failed: exit 33, revert reason: Error(Invalid token ID), vm error: message failed with backtrace:\n00: f02192757 (method 3844450837) -- contract reverted (33)\n (RetCode=33)"}}

## epoch 3143729 (execution epoch)
⟩ curl '...' \
      -XPOST \
      -H "Content-Type: application/json" \
      --data-raw '{"id":"foo","jsonrpc":"2.0","method":"eth_call","params":[{"to":"0xF4d73326C13a4Fc5FD7A064217e12780e9Bd62c3","data":"0x99fbab880000000000000000000000000000000000000000000000000000000000000001"},"3143729"]}'
{"jsonrpc":"2.0","result":"0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000060e1773636cf5e4a227d9ac24f20feca034ee25a000000000000000000000000eb466342c4d449bc9f53a865d5cb90586f4052150000000000000000000000000000000000000000000000000000000000000bb8fffffffffffffffffffffffffffffffffffffffffffffffffffffffffffbc8b4fffffffffffffffffffffffffffffffffffffffffffffffffffffffffffc0e8c00000000000000000000000000000000000000000000000000000012b4e8561a0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000","id":"foo"}

This observation implies that the deferred execution model is not being correctly reconciled for eth_call when requesting a concrete epoch number. You ask to perform a call on top of epoch 3143728. In Eth semantics, this means "apply this message on the output state after 3143728, which happens to be the state root specified in the block header". In Filecoin, this should translate to: "apply this message on the parent state root of the next epoch". In the Eth API, we ensure that what (Eth-assuming) clients see matches the expectations Ethereum's immediate execution model, but I suspect that's not being done correctly here.

Could you please check what the value of this env variable is in the Lotus nodes backing your endpoint? LOTUS_SKIP_APPLY_TS_MESSAGE_CALL_WITH_GAS. There is a rather nasty and bespoke optimization that might be interferring here.

I was able to reproduce and confirm my hypothesis against the Vulcanize endpoint. ```sh ## epoch 3143728 (inclusion epoch) ⟩ curl '...' \ -XPOST \ -H "Content-Type: application/json" \ --data-raw '{"id":"foo","jsonrpc":"2.0","method":"eth_call","params":[{"to":"0xF4d73326C13a4Fc5FD7A064217e12780e9Bd62c3","data":"0x99fbab880000000000000000000000000000000000000000000000000000000000000001"},"3143728"]}' {"jsonrpc":"2.0","id":"foo","error":{"code":1,"message":"message execution failed: exit 33, revert reason: Error(Invalid token ID), vm error: message failed with backtrace:\n00: f02192757 (method 3844450837) -- contract reverted (33)\n (RetCode=33)"}} ## epoch 3143729 (execution epoch) ⟩ curl '...' \ -XPOST \ -H "Content-Type: application/json" \ --data-raw '{"id":"foo","jsonrpc":"2.0","method":"eth_call","params":[{"to":"0xF4d73326C13a4Fc5FD7A064217e12780e9Bd62c3","data":"0x99fbab880000000000000000000000000000000000000000000000000000000000000001"},"3143729"]}' {"jsonrpc":"2.0","result":"0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000060e1773636cf5e4a227d9ac24f20feca034ee25a000000000000000000000000eb466342c4d449bc9f53a865d5cb90586f4052150000000000000000000000000000000000000000000000000000000000000bb8fffffffffffffffffffffffffffffffffffffffffffffffffffffffffffbc8b4fffffffffffffffffffffffffffffffffffffffffffffffffffffffffffc0e8c00000000000000000000000000000000000000000000000000000012b4e8561a0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000","id":"foo"} ``` This observation implies that the deferred execution model is not being correctly reconciled for `eth_call` when requesting a concrete epoch number. You ask to perform a call on top of epoch 3143728. In Eth semantics, this means "apply this message on the output state after 3143728, which happens to be the state root specified in the block header". In Filecoin, this should translate to: "apply this message on the **parent state root of the next epoch**". In the Eth API, we ensure that what (Eth-assuming) clients see matches the expectations Ethereum's immediate execution model, but I suspect that's not being done correctly here. Could you please check what the value of this env variable is in the Lotus nodes backing your endpoint? `LOTUS_SKIP_APPLY_TS_MESSAGE_CALL_WITH_GAS`. There is a rather [nasty and bespoke optimization](https://github.com/filecoin-project/lotus/blob/41fce94db48fbed79fe47549cc7b5a0c3c78c708/node/impl/full/eth.go#L892) that might be interferring here.
nikugogoi commented 2023-08-25 09:44:27 +00:00 (Migrated from github.com)

Subgraphs seem to be working now against the vulcanize endpoint
No errors are seen in graph-node container logs

Blocks subgraph seems to be processing blocks slower than v3 subgraph
v3 subgraph processed till 3,154,721 (head was at 3,154,983; ~250 blocks behind)
Also, subgraphs take some time to start processing after deployment: ~11 mins

Aug 25 08:59:47.629 DEBG Starting or restarting subgraph, sgd: 2, subgraph_id: QmVN8b4f1K2XbAh6onAMrGJZXGhxbRrzwXDcE7xw1DrN1D, component: SubgraphInstanceManager
Aug 25 08:59:47.629 DEBG subscribing to chain head updates, sgd: 2, subgraph_id: QmVN8b4f1K2XbAh6onAMrGJZXGhxbRrzwXDcE7xw1DrN1D, component: BlockStream
Aug 25 08:59:47.894 DEBG Starting block stream, sgd: 2, subgraph_id: QmVN8b4f1K2XbAh6onAMrGJZXGhxbRrzwXDcE7xw1DrN1D, component: SubgraphInstanceManager
Aug 25 08:59:52.673 DEBG no chain head update for 30 seconds, polling for update, sgd: 1, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: BlockStream
Aug 25 09:00:17.896 DEBG no chain head update for 30 seconds, polling for update, sgd: 2, subgraph_id: QmVN8b4f1K2XbAh6onAMrGJZXGhxbRrzwXDcE7xw1DrN1D, component: BlockStream
...
Aug 25 09:10:47.990 DEBG no chain head update for 30 seconds, polling for update, sgd: 2, subgraph_id: QmVN8b4f1K2XbAh6onAMrGJZXGhxbRrzwXDcE7xw1DrN1D, component: BlockStream
Aug 25 09:10:52.767 DEBG no chain head update for 30 seconds, polling for update, sgd: 1, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: BlockStream
Aug 25 09:10:58.731 INFO Scanning blocks [2867000, 2867000], target_range_size: 1, sgd: 1, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: BlockStream
Aug 25 09:10:58.731 DEBG Finding nearest valid `to` block to 2867000, sgd: 1, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: BlockStream

Blocks subgraph:
image
v3 subgraph:
image

Subgraphs seem to be working now against the vulcanize endpoint No errors are seen in graph-node container logs Blocks subgraph seems to be processing blocks slower than v3 subgraph v3 subgraph processed till `3,154,721` (head was at `3,154,983`; `~250` blocks behind) Also, subgraphs take some time to start processing after deployment: `~11 mins` ``` Aug 25 08:59:47.629 DEBG Starting or restarting subgraph, sgd: 2, subgraph_id: QmVN8b4f1K2XbAh6onAMrGJZXGhxbRrzwXDcE7xw1DrN1D, component: SubgraphInstanceManager Aug 25 08:59:47.629 DEBG subscribing to chain head updates, sgd: 2, subgraph_id: QmVN8b4f1K2XbAh6onAMrGJZXGhxbRrzwXDcE7xw1DrN1D, component: BlockStream Aug 25 08:59:47.894 DEBG Starting block stream, sgd: 2, subgraph_id: QmVN8b4f1K2XbAh6onAMrGJZXGhxbRrzwXDcE7xw1DrN1D, component: SubgraphInstanceManager Aug 25 08:59:52.673 DEBG no chain head update for 30 seconds, polling for update, sgd: 1, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: BlockStream Aug 25 09:00:17.896 DEBG no chain head update for 30 seconds, polling for update, sgd: 2, subgraph_id: QmVN8b4f1K2XbAh6onAMrGJZXGhxbRrzwXDcE7xw1DrN1D, component: BlockStream ... Aug 25 09:10:47.990 DEBG no chain head update for 30 seconds, polling for update, sgd: 2, subgraph_id: QmVN8b4f1K2XbAh6onAMrGJZXGhxbRrzwXDcE7xw1DrN1D, component: BlockStream Aug 25 09:10:52.767 DEBG no chain head update for 30 seconds, polling for update, sgd: 1, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: BlockStream Aug 25 09:10:58.731 INFO Scanning blocks [2867000, 2867000], target_range_size: 1, sgd: 1, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: BlockStream Aug 25 09:10:58.731 DEBG Finding nearest valid `to` block to 2867000, sgd: 1, subgraph_id: QmfBt5NbZdNhBoZS6MFj891YpNWQs8ysWkwVeEHF6rvscg, component: BlockStream ``` Blocks subgraph: ![image](https://github.com/cerc-io/stack-orchestrator/assets/20663182/83776754-96be-456c-b2b8-7eb767acbb20) v3 subgraph: ![image](https://github.com/cerc-io/stack-orchestrator/assets/20663182/eb975e9b-3a83-4cd6-b8de-cc602266fec6)
Sign in to join this conversation.
No reviewers
No Milestone
No project
No Assignees
1 Participants
Notifications
Due Date
The due date is invalid or out of range. Please use the format 'yyyy-mm-dd'.

No due date set.

Dependencies

No dependencies set.

Reference: cerc-io/stack-orchestrator#509
No description provided.