The first few lines of logs after the runtime upgrade (for the indexer) the RPC-CORE error which comes from polkadot-js/api immediately after upgrade.
Although the indexer is observed to make progress fetching additional blocks, the processor behaves correctly, ie it doesn't make progress. That is a good thing (we wouldn't get inconsistent state)
When indexer restarts, it continues processing from a couple of blocks before the runtime upgrade block, logging a few index-builder:indexer Block N has already been indexed lines, until it finally makes progress. The indexer can also be restarted manually (without resetting db) and it also "recovers" in the same way.
Some background about what type changes in the substrate runtime are possibly causing this.
Another changes in new substrate but not likely relevant, adding it just in-case:
I think it just affects the storage_info annotation and how benchmarks handle counting reading/writing to the storage key. The change in new substrate is that this is now an unbounded (git diff):
2023-04-14T22:05:43.608Z index-builder:indexer Done block #603
2023-04-14T22:05:43.609Z index-builder:indexer Saved 11 events
2023-04-14T22:05:43.611Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000597-000000-92ba5","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000597-000001-92ba5","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000597-000002-92ba5","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000597-000003-92ba5","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000597-000004-92ba5","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000597-000005-92ba5","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000597-000006-92ba5","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000597-000007-92ba5","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000597-000008-92ba5","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000597-000009-92ba5","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000597-000010-92ba5","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000597-000000-92ba5","name":"timestamp.set"}],"hash":"0x92ba5a9abcbb93af2e7a086b02972812eafbb9ade6fe4087605e3dc999cb1bec","parentHash":"0x17486fb3d778ef18494b1855787b6941e90f1b98b0de690ac4a4c0c30265887e","height":597,"runtimeVersion":{"specVersion":1001},"ts":1681509934000}
2023-04-14T22:05:43.611Z index-builder:indexer Done block #597
2023-04-14T22:05:44.689Z index-builder:indexer Processing block #604
2023-04-14T22:05:44.689Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":604}
2023-04-14T22:05:46.041Z index-builder:indexer Processing block #605
2023-04-14T22:05:46.103Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":605}
2023-04-14 22:05:49 API/INIT: Runtime version updated to spec=3000, tx=1
2023-04-14 22:05:50 RPC-CORE: getStorage(key: StorageKey, at?: BlockHash): StorageData:: Unable to decode storage system.events:: createType(Vec<FrameSystemEventRecord>):: Vec<FrameSystemEventRecord>:: Decoded input doesn't match input, received 0x0400000000000000d08ae10400000000020000 (19 bytes), created 0x0400000000000000d08ae10400000000 (16 bytes)
2023-04-14 22:05:50 RPC-CORE: getStorage(key: StorageKey, at?: BlockHash): StorageData:: Unable to decode storage system.events:: createType(Vec<FrameSystemEventRecord>):: Vec<FrameSystemEventRecord>:: Decoded input doesn't match input, received 0x0400000000000000d08ae10400000000020000 (19 bytes), created 0x0400000000000000d08ae10400000000 (16 bytes)
2023-04-14T22:05:50.197Z index-builder:indexer Processing block #606
2023-04-14T22:05:50.198Z index-builder:indexer Processing block #607
2023-04-14T22:05:50.199Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":606}
2023-04-14T22:05:50.199Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":607}
2023-04-14T22:05:51.208Z index-builder:indexer Saving block data
2023-04-14T22:05:51.305Z index-builder:indexer Saving block data
2023-04-14 22:05:51 RPC-CORE: getStorage(key: StorageKey, at?: BlockHash): StorageData:: Unable to decode storage system.events:: createType(Vec<FrameSystemEventRecord>):: Vec<FrameSystemEventRecord>:: Decoded input doesn't match input, received 0x0400000000000000d08ae10400000000020000 (19 bytes), created 0x0400000000000000d08ae10400000000 (16 bytes)
2023-04-14T22:05:51.309Z index-builder:indexer Saved block data
2023-04-14T22:05:51.309Z index-builder:indexer Saving extrinsics
2023-04-14T22:05:51.362Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:05:51.362Z index-builder:indexer Saving event entities
2023-04-14T22:05:51.362Z index-builder:indexer Read 5 events; saving in 1 batches
2023-04-14 22:05:51 RPC-CORE: getStorage(key: StorageKey, at?: BlockHash): StorageData:: Unable to decode storage system.events:: createType(SpRuntimeDigestDigestItem):: {"_enum":{"Other":"Bytes","__Unused1":"Null","__Unused2":"Null","__Unused3":"Null","Consensus":"([u8;4],Bytes)","Seal":"([u8;4],Bytes)","PreRuntime":"([u8;4],Bytes)","__Unused7":"Null","RuntimeEnvironmentUpdated":"Null"}}:: Decoded input doesn't match input, received 0x0400000000000000d08ae10400000000020000 (19 bytes), created 0x040000000000 (6 bytes)
2023-04-14T22:05:51.372Z index-builder:indexer Saved block data
2023-04-14T22:05:51.372Z index-builder:indexer Saving extrinsics
2023-04-14T22:05:51.375Z index-builder:indexer Saved 5 events
2023-04-14T22:05:51.378Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:05:51.378Z index-builder:indexer Saving event entities
2023-04-14T22:05:51.378Z index-builder:indexer Read 6 events; saving in 1 batches
2023-04-14T22:05:51.478Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000601-000000-acd49","name":"imOnline.AllGood","extrinsic":"none"},{"id":"0000000601-000001-acd49","name":"session.NewSession","extrinsic":"none"},{"id":"0000000601-000002-acd49","name":"council.BudgetRefill","extrinsic":"none"},{"id":"0000000601-000003-acd49","name":"council.BudgetRefillPlanned","extrinsic":"none"},{"id":"0000000601-000004-acd49","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000601-000000-acd49","name":"timestamp.set"}],"hash":"0xacd4999be4a3a9264655ea4da40d455b8ba417f36f14884935b5523e9097f464","parentHash":"0xd77460de4b59096588c475f1dbe4c051dd4cc5e572175c2bb6fd06bf477c41dc","height":601,"runtimeVersion":{"specVersion":1001},"ts":1681509938001}
2023-04-14T22:05:51.479Z index-builder:indexer Done block #601
2023-04-14T22:05:51.538Z index-builder:indexer Processing block #608
2023-04-14T22:05:51.539Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":608}
2023-04-14T22:05:51.651Z index-builder:indexer Saving block data
2023-04-14T22:05:51.654Z index-builder:indexer Saved block data
2023-04-14T22:05:51.654Z index-builder:indexer Saving extrinsics
2023-04-14T22:05:51.657Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:05:51.657Z index-builder:indexer Saving event entities
2023-04-14T22:05:51.657Z index-builder:indexer Read 2 events; saving in 1 batches
2023-04-14T22:05:51.660Z index-builder:indexer Saved 2 events
2023-04-14T22:05:51.662Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000608-000000-21d92","name":"proposalsEngine.ProposalDecisionMade","extrinsic":"none"},{"id":"0000000608-000001-21d92","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000608-000000-21d92","name":"timestamp.set"}],"hash":"0x21d92ec1d3b8d4b203fabf18797b63756b890caa5638cc4a64d30eaad5ec7aae","parentHash":"0x0c658aef5155ba84cb286e572148a14a63f34f9c19a6099ee9f9f01864b5176e","height":608,"runtimeVersion":{"specVersion":3000},"ts":1681509948786}
2023-04-14T22:05:51.662Z index-builder:indexer Done block #608
2023-04-14T22:05:51.800Z index-builder:indexer Saved 6 events
2023-04-14T22:05:51.807Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000607-000000-0c658","name":"council.BudgetRefill","extrinsic":"none"},{"id":"0000000607-000001-0c658","name":"council.BudgetRefillPlanned","extrinsic":"none"},{"id":"0000000607-000002-0c658","name":"system.CodeUpdated","extrinsic":"none"},{"id":"0000000607-000003-0c658","name":"joystreamUtility.RuntimeUpgraded","extrinsic":"none"},{"id":"0000000607-000004-0c658","name":"proposalsEngine.ProposalExecuted","extrinsic":"none"},{"id":"0000000607-000005-0c658","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000607-000000-0c658","name":"timestamp.set"}],"hash":"0x0c658aef5155ba84cb286e572148a14a63f34f9c19a6099ee9f9f01864b5176e","parentHash":"0x9a9e164faa430d9e28cbffe1ff18cfb9b383e4992c652b0210be8dd640cefe20","height":607,"runtimeVersion":{"specVersion":3000},"ts":1681509944000}
2023-04-14T22:05:51.807Z index-builder:indexer Done block #607
2023-04-14T22:05:52.733Z index-builder:indexer Processing block #609
2023-04-14T22:05:52.734Z index-builder:indexer Processing block #610
2023-04-14T22:05:52.735Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":609}
2023-04-14T22:05:52.735Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":610}
2023-04-14T22:05:52.854Z index-builder:indexer Saving block data
2023-04-14T22:05:52.857Z index-builder:indexer Saved block data
2023-04-14T22:05:52.857Z index-builder:indexer Saving extrinsics
2023-04-14T22:05:52.861Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:05:52.861Z index-builder:indexer Saving event entities
2023-04-14T22:05:52.862Z index-builder:indexer Read 1 events; saving in 1 batches
2023-04-14T22:05:52.864Z index-builder:indexer Saved 1 events
2023-04-14T22:05:52.866Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000610-000000-a1f37","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000610-000000-a1f37","name":"timestamp.set"}],"hash":"0xa1f37180ce8b2c0135b14056252450b56f0b55a088bdf54dcc1a30c4232764dd","parentHash":"0xab685922a2ef43d96231f69f8b022686b8701458fc293590fcc1706d93b32331","height":610,"runtimeVersion":{"specVersion":3000},"ts":1681509950004}
2023-04-14T22:05:52.866Z index-builder:indexer Done block #610
2023-04-14 22:05:53 RPC-CORE: getStorage(key: StorageKey, at?: BlockHash): StorageData:: Unable to decode storage system.events:: createType(SpRuntimeDigestDigestItem):: {"_enum":{"Other":"Bytes","__Unused1":"Null","__Unused2":"Null","__Unused3":"Null","Consensus":"([u8;4],Bytes)","Seal":"([u8;4],Bytes)","PreRuntime":"([u8;4],Bytes)","__Unused7":"Null","RuntimeEnvironmentUpdated":"Null"}}:: Decoded input doesn't match input, received 0x0400000000000000d08ae10400000000020000 (19 bytes), created 0x040000000000 (6 bytes)
2023-04-14 22:05:53 RPC-CORE: getStorage(key: StorageKey, at?: BlockHash): StorageData:: Unable to decode storage system.events:: createType(SpRuntimeDigestDigestItem):: {"_enum":{"Other":"Bytes","__Unused1":"Null","__Unused2":"Null","__Unused3":"Null","Consensus":"([u8;4],Bytes)","Seal":"([u8;4],Bytes)","PreRuntime":"([u8;4],Bytes)","__Unused7":"Null","RuntimeEnvironmentUpdated":"Null"}}:: Decoded input doesn't match input, received 0x0400000000000000d08ae10400000000020000 (19 bytes), created 0x040000000000 (6 bytes)
2023-04-14T22:05:54.067Z index-builder:indexer Processing block #611
2023-04-14T22:05:54.068Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":611}
2023-04-14T22:05:54.210Z index-builder:indexer Saving block data
2023-04-14T22:05:54.213Z index-builder:indexer Saved block data
2023-04-14T22:05:54.213Z index-builder:indexer Saving extrinsics
2023-04-14T22:05:54.216Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:05:54.217Z index-builder:indexer Saving event entities
2023-04-14T22:05:54.217Z index-builder:indexer Read 1 events; saving in 1 batches
2023-04-14T22:05:54.220Z index-builder:indexer Saved 1 events
2023-04-14T22:05:54.221Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000611-000000-e8dde","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000611-000000-e8dde","name":"timestamp.set"}],"hash":"0xe8ddef8d70c41ea247ff522e6119af84b40a67f98ef45a52d9e049c6d0219a4a","parentHash":"0xa1f37180ce8b2c0135b14056252450b56f0b55a088bdf54dcc1a30c4232764dd","height":611,"runtimeVersion":{"specVersion":3000},"ts":1681509951001}
2023-04-14T22:05:54.221Z index-builder:indexer Done block #611
2023-04-14T22:05:55.398Z index-builder:indexer Processing block #612
2023-04-14T22:05:55.399Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":612}
2023-04-14T22:05:55.626Z index-builder:indexer Saving block data
2023-04-14T22:05:55.631Z index-builder:indexer Saving block data
2023-04-14T22:05:55.632Z index-builder:indexer Saved block data
2023-04-14T22:05:55.632Z index-builder:indexer Saving extrinsics
2023-04-14T22:05:55.636Z index-builder:indexer Saved block data
2023-04-14T22:05:55.636Z index-builder:indexer Saving extrinsics
2023-04-14T22:05:55.637Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:05:55.637Z index-builder:indexer Saving event entities
2023-04-14T22:05:55.638Z index-builder:indexer Read 1 events; saving in 1 batches
2023-04-14T22:05:55.640Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:05:55.640Z index-builder:indexer Saving event entities
2023-04-14T22:05:55.640Z index-builder:indexer Read 1 events; saving in 1 batches
2023-04-14T22:05:55.642Z index-builder:indexer Saved 1 events
2023-04-14T22:05:55.643Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000612-000000-6ec11","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000612-000000-6ec11","name":"timestamp.set"}],"hash":"0x6ec11eb75b49af27ac6ab20f23db1689b0ffa8ff1949de56385b8312cf2a04f6","parentHash":"0xe8ddef8d70c41ea247ff522e6119af84b40a67f98ef45a52d9e049c6d0219a4a","height":612,"runtimeVersion":{"specVersion":3000},"ts":1681509952000}
2023-04-14T22:05:55.643Z index-builder:indexer Done block #612
2023-04-14T22:05:55.644Z index-builder:indexer Saved 1 events
2023-04-14T22:05:55.645Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000606-000000-9a9e1","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000606-000000-9a9e1","name":"timestamp.set"}],"hash":"0x9a9e164faa430d9e28cbffe1ff18cfb9b383e4992c652b0210be8dd640cefe20","parentHash":"0x760394b9a8d1b4d1b243b3ec52e025773af94c99f53bdc56716c4f29d503973b","height":606,"runtimeVersion":{"specVersion":1001},"ts":1681509943001}
2023-04-14T22:05:55.646Z index-builder:indexer Done block #606
2023-04-14T22:05:56.733Z index-builder:indexer Processing block #613
2023-04-14T22:05:56.733Z index-builder:indexer Processing block #614
2023-04-14T22:05:56.733Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":613}
2023-04-14T22:05:56.734Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":614}
2023-04-14T22:05:56.841Z index-builder:indexer Saving block data
2023-04-14T22:05:56.844Z index-builder:indexer Saved block data
2023-04-14T22:05:56.844Z index-builder:indexer Saving extrinsics
2023-04-14T22:05:56.848Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:05:56.848Z index-builder:indexer Saving event entities
2023-04-14T22:05:56.849Z index-builder:indexer Read 1 events; saving in 1 batches
2023-04-14T22:05:56.852Z index-builder:indexer Saved 1 events
2023-04-14T22:05:56.853Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000614-000000-79bc1","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000614-000000-79bc1","name":"timestamp.set"}],"hash":"0x79bc173aa2dd7e8fa75c3ecfa2cb827bed6784a87d566626ce51cb62848f5b71","parentHash":"0x19cbe5382a85b6f2afdf956a69497fde112b7aed1520feb4adbe8f1456434ba8","height":614,"runtimeVersion":{"specVersion":3000},"ts":1681509954000}
2023-04-14T22:05:56.854Z index-builder:indexer Done block #614
2023-04-14 22:05:57 RPC-CORE: getStorage(key: StorageKey, at?: BlockHash): StorageData:: Unable to decode storage system.events:: createType(SpRuntimeDigestDigestItem):: {"_enum":{"Other":"Bytes","__Unused1":"Null","__Unused2":"Null","__Unused3":"Null","Consensus":"([u8;4],Bytes)","Seal":"([u8;4],Bytes)","PreRuntime":"([u8;4],Bytes)","__Unused7":"Null","RuntimeEnvironmentUpdated":"Null"}}:: Decoded input doesn't match input, received 0x0400000000000000d08ae10400000000020000 (19 bytes), created 0x040000000000 (6 bytes)
2023-04-14 22:05:57 RPC-CORE: getStorage(key: StorageKey, at?: BlockHash): StorageData:: Unable to decode storage system.events:: createType(SpRuntimeDigestDigestItem):: {"_enum":{"Other":"Bytes","__Unused1":"Null","__Unused2":"Null","__Unused3":"Null","Consensus":"([u8;4],Bytes)","Seal":"([u8;4],Bytes)","PreRuntime":"([u8;4],Bytes)","__Unused7":"Null","RuntimeEnvironmentUpdated":"Null"}}:: Decoded input doesn't match input, received 0x0400000000000000d08ae10400000000020000 (19 bytes), created 0x040000000000 (6 bytes)
2023-04-14T22:05:58.075Z index-builder:indexer Processing block #615
2023-04-14T22:05:58.076Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":615}
2023-04-14T22:05:58.321Z index-builder:indexer Saving block data
2023-04-14T22:05:58.338Z index-builder:indexer Saved block data
2023-04-14T22:05:58.338Z index-builder:indexer Saving extrinsics
2023-04-14T22:05:58.340Z index-builder:indexer Saving block data
2023-04-14T22:05:58.343Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:05:58.343Z index-builder:indexer Saving event entities
2023-04-14T22:05:58.343Z index-builder:indexer Read 11 events; saving in 1 batches
2023-04-14T22:05:58.345Z index-builder:indexer Saved block data
2023-04-14T22:05:58.345Z index-builder:indexer Saving extrinsics
2023-04-14T22:05:58.351Z index-builder:indexer Saved 11 events
2023-04-14T22:05:58.352Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:05:58.352Z index-builder:indexer Saving event entities
2023-04-14T22:05:58.352Z index-builder:indexer Read 11 events; saving in 1 batches
2023-04-14T22:05:58.356Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000615-000000-681e8","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000615-000001-681e8","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000615-000002-681e8","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000615-000003-681e8","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000615-000004-681e8","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000615-000005-681e8","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000615-000006-681e8","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000615-000007-681e8","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000615-000008-681e8","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000615-000009-681e8","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000615-000010-681e8","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000615-000000-681e8","name":"timestamp.set"}],"hash":"0x681e8e29928435802f2bc57069e805da9ba10a497bdc96711edff8f19db396b8","parentHash":"0x79bc173aa2dd7e8fa75c3ecfa2cb827bed6784a87d566626ce51cb62848f5b71","height":615,"runtimeVersion":{"specVersion":3000},"ts":1681509955000}
2023-04-14T22:05:58.356Z index-builder:indexer Done block #615
2023-04-14T22:05:58.370Z index-builder:indexer Saved 11 events
2023-04-14T22:05:58.371Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000609-000000-ab685","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000609-000001-ab685","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000609-000002-ab685","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000609-000003-ab685","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000609-000004-ab685","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000609-000005-ab685","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000609-000006-ab685","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000609-000007-ab685","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000609-000008-ab685","name":"balances.Deposit","extrinsic":"none"},{"id":"0000000609-000009-ab685","name":"council.RewardPayment","extrinsic":"none"},{"id":"0000000609-000010-ab685","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000609-000000-ab685","name":"timestamp.set"}],"hash":"0xab685922a2ef43d96231f69f8b022686b8701458fc293590fcc1706d93b32331","parentHash":"0x21d92ec1d3b8d4b203fabf18797b63756b890caa5638cc4a64d30eaad5ec7aae","height":609,"runtimeVersion":{"specVersion":3000},"ts":1681509949286}
2023-04-14T22:05:58.372Z index-builder:indexer Done block #609
2023-04-14T22:06:00.038Z index-builder:indexer Processing block #616
2023-04-14T22:06:00.056Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":616}
2023-04-14T22:06:00.188Z index-builder:indexer Saving block data
2023-04-14T22:06:00.193Z index-builder:indexer Saved block data
2023-04-14T22:06:00.193Z index-builder:indexer Saving extrinsics
2023-04-14T22:06:00.199Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:06:00.199Z index-builder:indexer Saving event entities
2023-04-14T22:06:00.199Z index-builder:indexer Read 1 events; saving in 1 batches
2023-04-14T22:06:00.204Z index-builder:indexer Saved 1 events
2023-04-14T22:06:00.206Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000616-000000-a89e2","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000616-000000-a89e2","name":"timestamp.set"}],"hash":"0xa89e25b5f37c6fa7fa3507af00c113437f397a6e6e65d86d79de8e4741ac5551","parentHash":"0x681e8e29928435802f2bc57069e805da9ba10a497bdc96711edff8f19db396b8","height":616,"runtimeVersion":{"specVersion":3000},"ts":1681509956001}
2023-04-14T22:06:00.208Z index-builder:indexer Done block #616
2023-04-14T22:06:01.194Z index-builder:indexer Processing block #617
2023-04-14T22:06:01.195Z index-builder:indexer Processing block #618
2023-04-14T22:06:01.195Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":617}
2023-04-14T22:06:01.195Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":618}
2023-04-14T22:06:01.351Z index-builder:indexer Saving block data
2023-04-14T22:06:01.355Z index-builder:indexer Saved block data
2023-04-14T22:06:01.355Z index-builder:indexer Saving extrinsics
2023-04-14T22:06:01.359Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:06:01.359Z index-builder:indexer Saving event entities
2023-04-14T22:06:01.360Z index-builder:indexer Read 1 events; saving in 1 batches
2023-04-14T22:06:01.363Z index-builder:indexer Saved 1 events
2023-04-14T22:06:01.365Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000618-000000-750a0","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000618-000000-750a0","name":"timestamp.set"}],"hash":"0x750a04dc4c9d9068b1970e223eacaee1d752a6cbb91c57364cc5ab8b1ef3ea7f","parentHash":"0xfd470452ea35fcc4927d296f850aec5fc7a1c0f4779884ba782e3b7cf389de7a","height":618,"runtimeVersion":{"specVersion":3000},"ts":1681509958000}
2023-04-14T22:06:01.365Z index-builder:indexer Done block #618
2023-04-14T22:06:02.538Z index-builder:indexer Processing block #619
2023-04-14T22:06:02.539Z index-builder:redis-relayer Relaying to redis: hydra:indexer:started:block {"height":619}
2023-04-14T22:06:02.822Z index-builder:indexer Saving block data
2023-04-14T22:06:02.826Z index-builder:indexer Saving block data
2023-04-14T22:06:02.827Z index-builder:indexer Saved block data
2023-04-14T22:06:02.827Z index-builder:indexer Saving extrinsics
2023-04-14T22:06:02.831Z index-builder:indexer Saved block data
2023-04-14T22:06:02.831Z index-builder:indexer Saving extrinsics
2023-04-14T22:06:02.832Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:06:02.832Z index-builder:indexer Saving event entities
2023-04-14T22:06:02.832Z index-builder:indexer Read 3 events; saving in 1 batches
2023-04-14T22:06:02.835Z index-builder:indexer Saved 1 extrinsics
2023-04-14T22:06:02.835Z index-builder:indexer Saving event entities
2023-04-14T22:06:02.835Z index-builder:indexer Read 3 events; saving in 1 batches
2023-04-14T22:06:02.836Z index-builder:indexer Saved 3 events
2023-04-14T22:06:02.838Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000619-000000-5d2fc","name":"council.BudgetRefill","extrinsic":"none"},{"id":"0000000619-000001-5d2fc","name":"council.BudgetRefillPlanned","extrinsic":"none"},{"id":"0000000619-000002-5d2fc","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000619-000000-5d2fc","name":"timestamp.set"}],"hash":"0x5d2fc02345d16de49c67db5473536dc0015c7c7e4f90d162c904d7712f2949e9","parentHash":"0x750a04dc4c9d9068b1970e223eacaee1d752a6cbb91c57364cc5ab8b1ef3ea7f","height":619,"runtimeVersion":{"specVersion":3000},"ts":1681509959839}
2023-04-14T22:06:02.838Z index-builder:indexer Done block #619
2023-04-14T22:06:02.838Z index-builder:indexer Saved 3 events
2023-04-14T22:06:02.839Z index-builder:redis-relayer Relaying to redis: hydra:indexer:complete:block {"events":[{"id":"0000000613-000000-19cbe","name":"council.BudgetRefill","extrinsic":"none"},{"id":"0000000613-000001-19cbe","name":"council.BudgetRefillPlanned","extrinsic":"none"},{"id":"0000000613-000002-19cbe","name":"system.ExtrinsicSuccess","extrinsic":"timestamp.set"}],"extrinsics":[{"id":"0000000613-000000-19cbe","name":"timestamp.set"}],"hash":"0x19cbe5382a85b6f2afdf956a69497fde112b7aed1520feb4adbe8f1456434ba8","parentHash":"0x6ec11eb75b49af27ac6ab20f23db1689b0ffa8ff1949de56385b8312cf2a04f6","height":613,"runtimeVersion":{"specVersion":3000},"ts":1681509953000}
2023-04-14T22:06:02.839Z index-builder:indexer Done block #613
2023-04-14T22:06:03.865Z index-builder:indexer Processing block #620
2023-04-14T22:06:03.865Z index-builder:indexer Processing block #621
Problem
When running the runtime upgrade intergration tests, the runtime upgrade works successfully but the
test is failing at the step waiting for status of runtime upgrade proposal execution status to go from "ProposalStatusGracing" to "ProposalStatusExecuted" because the QN seems to not be properly processing the runtime upgrade block with the "ProposalExecuted" event in it. And processor altogether stops processing any events.
The first few lines of logs after the runtime upgrade (for the indexer) the RPC-CORE error which comes from polkadot-js/api immediately after upgrade.
If we allow indexer to keep running, eventually:
Recovery
Although the indexer is observed to make progress fetching additional blocks, the processor behaves correctly, ie it doesn't make progress. That is a good thing (we wouldn't get inconsistent state)
When indexer restarts, it continues processing from a couple of blocks before the runtime upgrade block, logging a few
index-builder:indexer Block N has already been indexedlines, until it finally makes progress. The indexer can also be restarted manually (without resetting db) and it also "recovers" in the same way.Some questions:
Relevant runtime type changes that are at the root cause of this behavior?
Some background about what type changes in the substrate runtime are possibly causing this.
Note that each block has a
timestamp.setextrinsic added by the block producer. Therefore each block produced will have asystem.extrinsicSuccessEvent, and therefore aDispatchInfotype.Before Upgrade

After Upgrade

Another changes in new substrate but not likely relevant, adding it just in-case:
I think it just affects the storage_info annotation and how benchmarks handle counting reading/writing to the storage key. The change in new substrate is that this is now an unbounded (git diff):
Indexer Logs
Runtime upgrade at block 607
┆Issue is synchronized with this Asana task by Unito