Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ensure that non-deterministic failures are cleared when a subgraph restarts after shutting down the writer too early #5452

Open
azf20 opened this issue Jun 3, 2024 · 0 comments
Assignees

Comments

@azf20
Copy link
Contributor

azf20 commented Jun 3, 2024

I think this is an issue with how subgraphs shut down, the messages around this error are these:

2024-05-22T17:47:46.525708734Z stderr F May 22 17:47:46.525 INFO Received session init, session: SessionInit { trace_id: "c76c0a6c84af586be40b9f91882d6188", resolved_start_block: 19927007, linear_handoff_block: 19926000, max_parallel_workers: 40 }, provider: mainnet-substreams-pinax, deployment: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubstreamsBlockStream
2024-05-22T17:47:46.525643885Z stderr F May 22 17:47:46.525 INFO Blockstreams connected, provider: mainnet-substreams-pinax, deployment: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubstreamsBlockStream
2024-05-22T17:47:46.263421648Z stderr F May 22 17:47:46.262 DEBG Starting block stream, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubgraphInstanceManager
2024-05-22T17:47:46.261160639Z stderr F May 22 17:47:46.260 DEBG Starting or restarting subgraph, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubgraphInstanceManager
2024-05-22T17:47:46.147887874Z stderr F May 22 17:47:46.144 INFO Data source count at start: 1, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubgraphInstanceManager
2024-05-22T17:47:46.086656158Z stderr F May 22 17:47:46.086 INFO Starting subgraph writer, queue_size: 5, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubgraphInstanceManager
2024-05-22T17:47:46.002721632Z stderr F May 22 17:47:46.002 INFO Successfully resolved subgraph files using IPFS, features: ø, n_templates: 0, n_data_sources: 1, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubgraphInstanceManager
2024-05-22T17:47:45.998172113Z stderr F May 22 17:47:45.997 DEBG Subgraph started, start_ms: 18, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubgraphRegistrar
2024-05-22T17:47:45.987948153Z stderr F May 22 17:47:45.987 INFO Resolve subgraph files using IPFS, n_templates: 0, n_data_sources: 1, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubgraphInstanceManager

2024-05-22T17:47:26.189685172Z stderr F May 22 17:47:26.189 ERRO Subgraph failed with non-deterministic error: Failed to transact block operations: internal constraint violated: Subgraph writer for QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8[sgd596884] is not running, retry_delay_s: 133, attempt: 0, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubgraphInstanceManager

2024-05-22T17:47:26.148660025Z stderr F May 22 17:47:26.148 INFO Applying 116 entity operation(s), block_hash: 0x34623436623366353135313632303565346537623636363839646338396137356162633036333665316166643136366337326537653266333564396139356136, block_number: 19927007, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubgraphInstanceManager
2024-05-22T17:47:25.780281074Z stderr F May 22 17:47:25.780 INFO Stopped subgraph, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubgraphInstanceManager
2024-05-22T17:47:25.780248134Z stderr F May 22 17:47:25.780 DEBG Stopped subgraph writer, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubgraphInstanceManager
2024-05-22T17:47:25.584168495Z stderr F May 22 17:47:25.584 DEBG Substreams backend graph_out last block is 19927007, Stages: [#7 up to 19926000 (store_protocol_cumulative_fields +2), #6 up to 19926000 (store_daily_and_hourly_fields +3), #5 up to 19926000 (store_pool_tvl +3), #4 up to 19926000 (store_usd_prices), #3 up to 19926000 (store_native_prices), #2 up to 19926000 (store_volume_by_token_amount +2), #1 up to 19926000 (store_output_token_supply), #0 up to 19926000 (store_pools +1)], trace_id: 50d17a44cbd62663e0a590c326c064e3, provider: mainnet-substreams-pinax, deployment: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, sgd: 596884, subgraph_id: QmPskkt9UNrjpPVz453pq6m5u4wsjZKdHhNqqqjCztswR8, component: SubstreamsBlockStream

Unclear why the subgraph shut down in the first place, but what happens is that when the subgraph shuts down, it shuts down the writer too early, and processing still tries to write some lingering data.
That write then fails with that error, but it doesn’t do any real damage since we just restart from where the error happened (the error is caused by the Applying .. at block 19927007 and the Received session start message at the top of the log says resolved_start_block: 19927007 which means that’s where we resume syncing)

@fordN fordN assigned mangas and unassigned lutter Jun 6, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants