Repository navigation
Store connection issue prevents subgraph indexing until graph-node is restarted #4190
Description
BUG!
Current behavior:
- When the postgresql store is unavailable for a little while (ex: load is too high, server crashed or restarted)
- The resulting error is
store error: no connection to the server - This error halts the indexing of that subgraph for 30 minutes before retrying
- When it retries, even if the store is back and other subgraphs are correctly indexing, it leads to this error message:
ERRO Subgraph failed with non-deterministic error: Failed to transact block operations: subgraph writer poisoned by previous error, retry_delay_s: 1800, attempt: 27, sgd: 865, subgraph_id: (...), component: SubgraphInstanceManager - Then, it waits another 30 minutes before showing the same error about the connection being poisoned.
- If I restart the graph-node, this subgraph restarts indexing correctly.
How to reproduce:
I don't have a safe way to reproduce this on demand, unfortunately, but it happened to me on 3 different subgraphs at the same time (under heavy load)
Expected behavior:
- after these long 30 minutes of waiting, the graph-node should at least retry the connection and get back on its feet (instead of complaining about the writer being poisoned
- 30 minutes is a long wait time for something as trivial as "no connection to the server", it could easily be shorter for this kind of error.
Reacted by Paymahn Moghadasian and Andrew Dibble
Metadata
Metadata
Assignees
Labels
No labels
Activity
sduchesneau commentedon Nov 21, 2022
@evaporei ^ as we discussed earlier
azf20 commentedon Nov 23, 2022
thanks @sduchesneau - I think @fordN has also seen this error. Interesting that a restart fixes, while the regular retry does not. Will take a look
azf20 commentedon Nov 23, 2022
@sduchesneau is this from a recent build from source?
sduchesneau commentedon Nov 28, 2022
It was from a docker build of master,
graphprotocol/graph-node:013c2c9azf20 commentedon Nov 29, 2022
thanks @sduchesneau! This seems like it might be related to a failure to reset the subgraph on encountering this error:
(we see this log in all of the shared examples where we have seen this)
Which means it keeps using a store that has encountered an error, hence the recurring complaint about being poisoned (and thanks @lutter for the help with diagnosis).
balakhonoff commentedon Jan 27, 2023
Hey @sduchesneau and @azf20
Are there any solutions or workarounds?
paymog commentedon Feb 21, 2023
@sduchesneau did you see this while using RPC or Firehose providers? I started seeing this recently after adding a firehose provider and I'm not sure if it's because of the firehose provider (the provider being faulty or some bug in the graph node firehose code path).
paymog commentedon Feb 21, 2023
@balakhonoff have you encountered this issue as well? If so, were you using firehose providers?
SozinM commentedon Mar 16, 2023
@azf20 We did encounter this issue. Also, we can reproduce it reliably in our self-hosted environment.
Also, we could help with debugging using our indexer instances located in dev env.
lutter commentedon Mar 16, 2023
The issue is a mismatch between the subgraph runner and the store: because we write changes asynchronously, the store pretends to the subgraph runner that things have been written that aren't really in the database yet. That's all good when things are working. But if the async writer encounters an error when it is trying to write something, the subgraph runner's view will deviate from reality, and the store refuses to do anything more (that's what the
poisonederror says) Note that "database not available" here shouldn't count as an error, but I think there are cases where accesses to the block store (not the subgraph store) don't have the proper retry logic in place.What needs to happen at that point is that the subgraph runner tells the store explicitly "I got rid of all in-memory assumptions about what has been written" and reinitializes the store. That can either happen by calling
SubgraphStore.writablehere or we could add a method to theWritableto reinitialize itself.The retry loop in the subgraph runner here doesn't take that into account and continues with a poisoned store. The easiest fix for this might be to add a method
WritableStore.reinitialize()that does that and call it when restarting the subgraph here The newWritableStore.reinitialize()should be a noop for a non-poisoned store and return a new cleanWritableStorefor a poisoned store.azf20 commentedon Apr 12, 2023
Thanks @lutter! Is this fixed in #4533?
lutter commentedon Apr 13, 2023
Yes, that should fix these recurring errors