POI null after allocation closed despite full sync #186

hyperbot16 · 2021-01-06T02:47:31Z

I have closed an allocation after 10 days and have noticed that my POI was null despite ensuring that everything subgraph was synced to the latest block at the time of the closure. It seems that I have lost all the rewards for this period because of what is probably a bug.

Transaction Hash: 0x9c7e7429ccba712ae94e34656fa00375bdf32f0d0eeb139ac99304d7c712e033

{"level":30,"time":1609893313576,"pid":1,"hostname":"indexer-agent-8684f44768-6k94w","name":"IndexerAgent","component":"Network","indexer":"0xE0C1aF3235Ecee2c085eaD8e918cd394986d2303","operator":"0xA87c60067A47Cb1Ce79FecB2a6FdC2b4F3d01435","allocation":"0x9354Fd32Fe90D33936311D1D7BbFeCe76352497F","deployment":{"bytes32":"0x31edcacc9a53bc8ab4be2eeb0d873409da4c4228cb2d60e4243bd3b4e8af7500","ipfsHash":"QmRhYzT8HEZ9LziQhP6JfNfd4co9A7muUYQhPMJsMUojSF"},"createdAtEpoch":13,"poi":"0x0000000000000000000000000000000000000000000000000000000000000000","createdAtBlockHash":"0x5a340c71b5995c078adf5651a3f4ead963498ac4c0bccff8dda9f069d405c5f8","msg":"Successfully closed allocation"}

POI at time of allocation creation:

curl -X POST -H "Content-Type: application/json" --data '{"query": "query {proofOfIndexing(subgraph: \"QmRhYzT8HEZ9LziQhP6JfNfd4co9A7muUYQhPMJsMUojSF\",blockHash: \"0x5a340c71b5995c078adf5651a3f4ead963498ac4c0bccff8dda9f069d405c5f8\",indexer: \"0xe0c1af3235ecee2c085ead8e918cd394986d2303\")}"}'  http://localhost:8030/graphql
{"data":{"proofOfIndexing":null}}

I main changes I have performed during that period are:

Updating to the latest version of the indexer-{service,agent}
Changing the Ethereum archive node from an openethereum to a geth instance.

The text was updated successfully, but these errors were encountered:

Jannis · 2021-01-07T13:11:31Z

Thanks so much for the detailed report, @hyperbot16. I've root-caused it and now understand why this happens:

Right now, graph-node doesn't always have all block information available for creating POIs. In those cases it will return a null POI, which gets put on chain as 0x0...0 and leads to not receiving rewards.

We have to improvements planned:

Always have the block information ready in graph-node so that null is only returned if the subgraph is really behind.
If there is a 0x0 POI, don't close the allocation right away. Instead, track it in the agent database and provide a way for the indexer to manually close the allocation later when there may be a POI available. This part needs a bit of DX planning.

I'm actively working on 1 right now and should have a fix ready soon!

Jannis · 2021-01-07T13:15:32Z

For 1, this is what needs to get done. I'll track the progress here:

graph-node: Update proofOfIndexing API to take an optional block number argument. Use that in the POI computation. Addressed in *: Require a block number in proofOfIndexing queries graph-node#2100.
indexer: Pass the epoch start block number to proofOfIndexing in addition to the hash that we're passing to it already. Addressed in indexer-agent: Update to new proofOfIndexing API (#186) #191.

This is to avoid `null` POIs if the block hash isn't found in the block store (which could be the case on one indexer but not on another). This can lead to indexers losing rewards despite indexing a subgraph correctly. By requiring e.g. the indexer agent to always provide block number and hash in `proofOfIndexing` queries, we can compute the POI on any indexer, regardless of what is in their block store. This is easier than resolving the block hash -> number on-demand in the `proofOfIndexing` resolver. The agent already knows both values anyway. Part of fixing graphprotocol/indexer#186.

This adds passing the epoch start block number to the `proofOfIndexing` query, which is being added to graph-node in graphprotocol/graph-node#2100. This change is necessary so that we can reliably obtain a POI even if the graph-node block store doesn't have the Ethereum block in question. This fixes the main problem in #186. For another improvement (allowing indexers to deal with legitimate 0x0 POIs by closing allocations with manual intervention), we'll create a separate issue.

Jannis · 2021-01-07T14:20:12Z

The necessary changes are now in review. I'll create a new issue for the improvement of capturing potential 0x0 POIs and allowing indexers do deal with them manually in a bit.

This is to avoid `null` POIs if the block hash isn't found in the block store (which could be the case on one indexer but not on another). This can lead to indexers losing rewards despite indexing a subgraph correctly. By requiring e.g. the indexer agent to always provide block number and hash in `proofOfIndexing` queries, we can compute the POI on any indexer, regardless of what is in their block store. This is easier than resolving the block hash -> number on-demand in the `proofOfIndexing` resolver. The agent already knows both values anyway. Part of fixing graphprotocol/indexer#186.

This adds passing the epoch start block number to the `proofOfIndexing` query, which is being added to graph-node in graphprotocol/graph-node#2100. This change is necessary so that we can reliably obtain a POI even if the graph-node block store doesn't have the Ethereum block in question. This fixes the main problem in #186. For another improvement (allowing indexers to deal with legitimate 0x0 POIs by closing allocations with manual intervention), we'll create a separate issue.

Grom81 · 2021-01-13T07:15:46Z

I updated the agent, service and cli to version 0.9.3 and graph-node 0.21.1 and closed the allocation after 10 days. Subgraph was synced to the latest block at the time of the closure. It seems that I have lost all the rewards for this period because of what is probably a bug.

Transaction Hash: 0x6ea2554c3967c046783e2515a09739999ccd6babfa598a17dc67127eea89215f

Jan 12 22:42:23 GRom81 node[26054]: {"level":20,"time":1610520143729,"pid":26054,"hostname":"GRom81","name":"IndexerAgent","number":1,"deployments":[{"bytes32":"0x31edcacc9a53bc8ab4be2eeb0d873409da4c4228cb
2d60e4243bd3b4e8af7500","ipfsHash":"QmRhYzT8HEZ9LziQhP6JfNfd4co9A7muUYQhPMJsMUojSF"}],"msg":"Deployments to reconcile allocations for"}
Jan 12 22:42:23 GRom81 node[26054]: {"level":30,"time":1610520143729,"pid":26054,"hostname":"GRom81","name":"IndexerAgent","deployment":{"bytes32":"0x31edcacc9a53bc8ab4be2eeb0d873409da4c4228cb2d60e4243bd3b
4e8af7500","ipfsHash":"QmRhYzT8HEZ9LziQhP6JfNfd4co9A7muUYQhPMJsMUojSF"},"epoch":29,"allocationAmount":"0.01","totalActiveAllocationAmount":"1917268.0","desiredNumberOfAllocations":1,"activeNumberOfAllocati
ons":1,"activeAllocations":[{"id":"0x2869951317712E4dB51cdAC0B982908923976deF","createdAtEpoch":18,"amount":"1917268.0"}],"msg":"Reconcile deployment allocations"}
Jan 12 22:42:23 GRom81 node[26054]: {"level":30,"time":1610520143730,"pid":26054,"hostname":"GRom81","name":"IndexerAgent","deployment":{"bytes32":"0x31edcacc9a53bc8ab4be2eeb0d873409da4c4228cb2d60e4243bd3b
4e8af7500","ipfsHash":"QmRhYzT8HEZ9LziQhP6JfNfd4co9A7muUYQhPMJsMUojSF"},"epoch":29,"allocations":["0x2869951317712E4dB51cdAC0B982908923976deF"],"msg":"Deployment is not (or no longer) worth indexing, close
 all active allocations that are at least one epoch old"}
Jan 12 22:42:23 GRom81 node[26054]: {"level":50,"time":1610520143737,"pid":26054,"hostname":"GRom81","name":"IndexerAgent","subgraph":"QmRhYzT8HEZ9LziQhP6JfNfd4co9A7muUYQhPMJsMUojSF","blockHash":{"number":
11639502,"hash":"0x10fa9b6e64aa9edd68f7ed3f85ed25e6dbcebd12278de32e3dbc4e7d646df2ba"},"indexer":"0x55F3DCDaf0b73f7f0c761a9070d8865F37986e2C","err":{"type":"IndexerError","message":"Failed to query proof of
 indexing","stack":"IndexerError: Failed to query proof of indexing\n    at Object.indexerError (/root/.nvm/versions/node/v14.9.0/lib/node_modules/@graphprotocol/indexer-agent/node_modules/@graphprotocol/i
ndexer-common/dist/errors.js:97:12)\n    at Indexer.<anonymous> (/root/.nvm/versions/node/v14.9.0/lib/node_modules/@graphprotocol/indexer-agent/dist/indexer.js:123:46)\n    at Generator.next (<anonymous>)\
n    at fulfilled (/root/.nvm/versions/node/v14.9.0/lib/node_modules/@graphprotocol/indexer-agent/dist/indexer.js:5:58)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/proce
ss/task_queues.js:93:5)","code":"IE019","explanation":"https://github.com/graphprotocol/indexer/blob/master/docs/errors.md#ie019","cause":{"type":"b","message":"[GraphQL] Variable blockNumber must have a
n input type","name":"CombinedError","graphQLErrors":[{"message":"Variable blockNumber must have an input type","extensions":{}}],"response":{"size":0,"timeout":0}}},"msg":"Failed to query proof of index
ing"}
Jan 12 22:42:23 GRom81 node[26054]: {"level":30,"time":1610520143738,"pid":26054,"hostname":"GRom81","name":"IndexerAgent","component":"Network","indexer":"0x55F3DCDaf0b73f7f0c761a9070d8865F37986e2C","oper
ator":"0x07eB5c56Ee6d928fc5faAA89e74422c6c64bF786","allocation":"0x2869951317712E4dB51cdAC0B982908923976deF","deployment":{"bytes32":"0x31edcacc9a53bc8ab4be2eeb0d873409da4c4228cb2d60e4243bd3b4e8af7500","ip
fsHash":"QmRhYzT8HEZ9LziQhP6JfNfd4co9A7muUYQhPMJsMUojSF"},"createdAtEpoch":18,"poi":"0x0000000000000000000000000000000000000000000000000000000000000000","createdAtBlockHash":"0x7da8ad6133a5dfc8c795f8f7bc41
5c617ddc913ab65baa4e7e36e7f3f4681eea","msg":"Close allocation"}
Jan 12 22:42:24 GRom81 node[26054]: {"level":30,"time":1610520144288,"pid":26054,"hostname":"GRom81","name":"IndexerAgent","component":"Network","indexer":"0x55F3DCDaf0b73f7f0c761a9070d8865F37986e2C","oper
ator":"0x07eB5c56Ee6d928fc5faAA89e74422c6c64bF786","allocation":"0x2869951317712E4dB51cdAC0B982908923976deF","deployment":{"bytes32":"0x31edcacc9a53bc8ab4be2eeb0d873409da4c4228cb2d60e4243bd3b4e8af7500","ip
fsHash":"QmRhYzT8HEZ9LziQhP6JfNfd4co9A7muUYQhPMJsMUojSF"},"createdAtEpoch":18,"poi":"0x0000000000000000000000000000000000000000000000000000000000000000","createdAtBlockHash":"0x7da8ad6133a5dfc8c795f8f7bc41
5c617ddc913ab65baa4e7e36e7f3f4681eea","action":"close","tx":"0x6ea2554c3967c046783e2515a09739999ccd6babfa598a17dc67127eea89215f","msg":"Transaction pending"}
Jan 12 22:43:20 GRom81 node[26054]: {"level":30,"time":1610520200560,"pid":26054,"hostname":"GRom81","name":"IndexerAgent","component":"Network","indexer":"0x55F3DCDaf0b73f7f0c761a9070d8865F37986e2C","oper
ator":"0x07eB5c56Ee6d928fc5faAA89e74422c6c64bF786","allocation":"0x2869951317712E4dB51cdAC0B982908923976deF","deployment":{"bytes32":"0x31edcacc9a53bc8ab4be2eeb0d873409da4c4228cb2d60e4243bd3b4e8af7500","ip
fsHash":"QmRhYzT8HEZ9LziQhP6JfNfd4co9A7muUYQhPMJsMUojSF"},"createdAtEpoch":18,"poi":"0x0000000000000000000000000000000000000000000000000000000000000000","createdAtBlockHash":"0x7da8ad6133a5dfc8c795f8f7bc41
5c617ddc913ab65baa4e7e36e7f3f4681eea","action":"close","tx":"0x6ea2554c3967c046783e2515a09739999ccd6babfa598a17dc67127eea89215f","blockNumber":11645095,"blockHash":"0x3cd0654d57fc50f123bfbc4591d104dd7af5a8
05548ca4868cc4d71a29e3de18","msg":"Transaction successfully included in block"}
Jan 12 22:43:20 GRom81 node[26054]: {"level":30,"time":1610520200560,"pid":26054,"hostname":"GRom81","name":"IndexerAgent","component":"Network","indexer":"0x55F3DCDaf0b73f7f0c761a9070d8865F37986e2C","operator":"0x07eB5c56Ee6d928fc5faAA89e74422c6c64bF786","allocation":"0x2869951317712E4dB51cdAC0B982908923976deF","deployment":{"bytes32":"0x31edcacc9a53bc8ab4be2eeb0d873409da4c4228cb2d60e4243bd3b4e8af7500","ip
fsHash":"QmRhYzT8HEZ9LziQhP6JfNfd4co9A7muUYQhPMJsMUojSF"},"createdAtEpoch":18,"poi":"0x0000000000000000000000000000000000000000000000000000000000000000","createdAtBlockHash":"0x7da8ad6133a5dfc8c795f8f7bc41
5c617ddc913ab65baa4e7e36e7f3f4681eea","msg":"Successfully closed allocation"}

GitHub (https://github.com/graphprotocol/indexer/blob/master/docs/errors.md)

Bambarello · 2021-01-13T07:53:07Z

Just had the same issue with the allocation. All the indexer rewards lost

"blockHash":{"number":11639502,"hash":"0x10fa9b6e64aa9edd68f7ed3f85ed25e6dbcebd12278de32e3dbc4e7d646df2ba"},"indexer":"0x48b5687f0595E2A4d581DC72305fbae214345d07","err":{"type":"IndexerError",
"message":"Failed to query proof of indexing","stack":"IndexerError: Failed to query proof of indexing\n    at Object.indexerError (/root/.nvm/versions/node/v14.9.0/lib/node_modules/@graphprot
ocol/indexer-agent/node_modules/@graphprotocol/indexer-common/dist/errors.js:97:12)\n    at Indexer.<anonymous> (/root/.nvm/versions/node/v14.9.0/lib/node_modules/@graphprotocol/indexer-agent/
dist/indexer.js:123:46)\n    at Generator.next (<anonymous>)\n    at fulfilled (/root/.nvm/versions/node/v14.9.0/lib/node_modules/@graphprotocol/indexer-agent/dist/indexer.js:5:58)\n    at pro
cessTicksAndRejections (internal/process/task_queues.js:93:5)","code":"IE019","explanation":"https://github.com/graphprotocol/indexer/blob/master/docs/errors.md#ie019","cause":{"type":"b","mes
sage":"[GraphQL] Variable `blockNumber` must have an input type","name":"CombinedError","graphQLErrors":[{"message":"Variable `blockNumber` must have an input type","extensions":{}}],"response
":{"size":0,"timeout":0}}},"msg":"Failed to query proof of indexing"}```

here is the link to transaction with zero rewards:
https://etherscan.io/tx/0x300c88058f37b08c91abf0a0dec8fb8863185fe59308c0588b73491eb30e3740

Indexer was in full sync an dup to date.

Is there any way to reconcile and retrieve indexer rewards?

Bambarello · 2021-01-13T08:38:32Z

The graph node is latest, but build is with warning

warning: function is never used: `test_reorg`
   --> chain/ethereum/src/block_stream.rs:836:4
    |
836 | fn test_reorg(ptr: EthereumBlockPointer) -> bool {
    |    ^^^^^^^^^^
    |
    = note: `#[warn(dead_code)]` on by default

   Compiling graph-server-metrics v0.21.1 (/home/graf/graph-node/server/metrics)
   Compiling graph-server-websocket v0.21.1 (/home/graf/graph-node/server/websocket)
   Compiling wasmtime-profiling v0.21.0
   Compiling wasmtime-obj v0.21.0
   Compiling graph-server-index-node v0.21.1 (/home/graf/graph-node/server/index-node)
   Compiling graph-core v0.21.1 (/home/graf/graph-node/core)
   Compiling graph-server-http v0.21.1 (/home/graf/graph-node/server/http)
   Compiling graph-store-postgres v0.21.1 (/home/graf/graph-node/store/postgres)
   Compiling graph-mock v0.21.1 (/home/graf/graph-node/mock)
   Compiling wasmtime-jit v0.21.0
   Compiling wasmtime v0.21.0
   Compiling graph-runtime-wasm v0.21.1 (/home/graf/graph-node/runtime/wasm)
   Compiling graph-node v0.21.1 (/home/graf/graph-node/node)
warning: 1 warning emitted

   Compiling test-store v0.21.1 (/home/graf/graph-node/store/test-store)
    Finished release [optimized] target(s) in 3m 40s
graph-node v0.21.1 (8915fd15c 2021-01-11)

Jannis · 2021-01-13T11:54:58Z

@Grom81 @Bambarello Both of your errors mean that graph-node was not updated to 0.21.1.

The compilation warning is something you can ignore.

) This properly prevents #186. We'll still want to capture these cases and allow indexers to retry them later through `graph indexer` or resolve them manually.

This adds passing the epoch start block number to the `proofOfIndexing` query, which is being added to graph-node in graphprotocol/graph-node#2100. This change is necessary so that we can reliably obtain a POI even if the graph-node block store doesn't have the Ethereum block in question. This fixes the main problem in #186. For another improvement (allowing indexers to deal with legitimate 0x0 POIs by closing allocations with manual intervention), we'll create a separate issue.

) This properly prevents #186. We'll still want to capture these cases and allow indexers to retry them later through `graph indexer` or resolve them manually.

Jannis added bug Something isn't working indexer-agent labels Jan 6, 2021

Jannis mentioned this issue Jan 7, 2021

*: Require a block number in proofOfIndexing queries graphprotocol/graph-node#2100

Merged

Jannis mentioned this issue Jan 7, 2021

indexer-agent: Update to new proofOfIndexing API (#186) #191

Merged

Jannis mentioned this issue Jan 13, 2021

indexer-agent: Never close allocations on zero POI, retry 10 times (#186) #196

Merged

Jannis closed this as completed in #196 Jan 13, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

POI null after allocation closed despite full sync #186

POI null after allocation closed despite full sync #186

hyperbot16 commented Jan 6, 2021

Jannis commented Jan 7, 2021

Jannis commented Jan 7, 2021 •

edited

Jannis commented Jan 7, 2021

Grom81 commented Jan 13, 2021 •

edited

Bambarello commented Jan 13, 2021

Bambarello commented Jan 13, 2021

Jannis commented Jan 13, 2021 •

edited

POI null after allocation closed despite full sync #186

POI null after allocation closed despite full sync #186

Comments

hyperbot16 commented Jan 6, 2021

Jannis commented Jan 7, 2021

Jannis commented Jan 7, 2021 • edited

Jannis commented Jan 7, 2021

Grom81 commented Jan 13, 2021 • edited

Bambarello commented Jan 13, 2021

Bambarello commented Jan 13, 2021

Jannis commented Jan 13, 2021 • edited

Jannis commented Jan 7, 2021 •

edited

Grom81 commented Jan 13, 2021 •

edited

Jannis commented Jan 13, 2021 •

edited