From 8b62d0107b1a8d7241e05ae59a3c3ee027862374 Mon Sep 17 00:00:00 2001 From: Shunji Zhan Date: Fri, 17 May 2024 18:00:48 +0800 Subject: [PATCH] add heads check in health check (#998) * add heads check in health check * add test --- .../eth-providers/src/__tests__/utils.test.ts | 160 +++++++++++------- packages/eth-providers/src/base-provider.ts | 60 +++++-- packages/eth-providers/src/utils/utils.ts | 116 +++++++++---- .../eth-rpc-adapter/src/wrapped-provider.ts | 1 - 4 files changed, 224 insertions(+), 113 deletions(-) diff --git a/packages/eth-providers/src/__tests__/utils.test.ts b/packages/eth-providers/src/__tests__/utils.test.ts index e37d463ff..1ab23fd1c 100644 --- a/packages/eth-providers/src/__tests__/utils.test.ts +++ b/packages/eth-providers/src/__tests__/utils.test.ts @@ -1,3 +1,6 @@ +import { describe, expect, it, vi } from 'vitest'; +import { hexValue } from '@ethersproject/bytes'; + import { CacheInspect } from '../utils/BlockCache'; import { EthCallTimingResult, @@ -10,9 +13,8 @@ import { runWithTiming, sleep, } from '../utils'; +import { HeadsInfo } from '../base-provider'; import { _Metadata } from '../utils/gqlTypes'; -import { describe, expect, it, vi } from 'vitest'; -import { hexValue } from '@ethersproject/bytes'; describe('utils', () => { it('connect chain', async () => { @@ -136,17 +138,33 @@ describe('runwithTiming', () => { }); describe('getHealthResult', () => { - const indexerHealthy = true; + const isIndexerHealthy = true; const lastProcessedHeight = 2000; const lastProcessedTimestamp = Date.now() - 10000; const targetHeight = 2002; + const finalizedHeight = targetHeight; const indexerMeta: _Metadata = { - indexerHealthy, + indexerHealthy: isIndexerHealthy, lastProcessedHeight, lastProcessedTimestamp, targetHeight, }; + const headsInfo: HeadsInfo = { + internalState: { + curHeight: finalizedHeight + 2, + curHash: '0x34567', + finalizedHeight, + finalizedHash: '0x12321', + }, + chainState: { + curHeight: finalizedHeight + 2, + curHash: '0x34567', + finalizedHeight, + finalizedHash: '0x12321', + }, + }; + const maxCachedBlocks = 200; const cachedBlocksCount = 196; const cacheInfo: CacheInspect = { @@ -171,37 +189,52 @@ describe('getHealthResult', () => { const healthResult = { isHealthy: true, + isHeadsOK: true, isSubqlOK: true, isCacheOK: true, isRPCOK: true, msg: [], moreInfo: { - cachedBlocksCount, - maxCachedBlocksCount: maxCachedBlocks, - // subql - lastProcessedHeight, - targetHeight, - curFinalizedHeight, - lastProcessedTimestamp, - idleBlocks: curFinalizedHeight - lastProcessedHeight, - indexerHealthy, - // RPC + headsInfo, + cache: { + maxCachedBlocksCount: maxCachedBlocks, + cachedBlocksCount, + }, + subql: { + lastProcessedHeight, + targetHeight, + lastProcessedTimestamp, + idleBlocks: curFinalizedHeight - lastProcessedHeight, + isIndexerHealthy: indexerMeta.indexerHealthy!, + }, ethCallTiming, + listeners: { + newHead: 0, + newFinalizedHead: 0, + logs: 0, + }, }, }; + const healthyData = { + indexerMeta, + cacheInfo, + headsInfo, + ethCallTiming, + listenersCount: { newHead: 0, newFinalizedHead: 0, logs: 0 }, + }; + + const expectedSubql = expect.objectContaining(healthResult.moreInfo.subql); + it('return correct healthy data when healthy', () => { - const res = getHealthResult({ - indexerMeta, - cacheInfo, - curFinalizedHeight, - ethCallTiming, - listenersCount: { newHead: 0, newFinalizedHead: 0, logs: 0 }, - }); + const res = getHealthResult(healthyData); expect(res).toEqual(expect.objectContaining({ ...healthResult, - moreInfo: expect.objectContaining(healthResult.moreInfo), + moreInfo: expect.objectContaining({ + ...healthResult.moreInfo, + subql: expectedSubql, + }), })); }); @@ -211,15 +244,12 @@ describe('getHealthResult', () => { const lastProcessedTimestampBad = lastProcessedTimestamp - 35 * 60 * 1000; const res = getHealthResult({ + ...healthyData, indexerMeta: { ...indexerMeta, lastProcessedHeight: lastProcessedHeightBad, lastProcessedTimestamp: lastProcessedTimestampBad, }, - cacheInfo, - curFinalizedHeight, - ethCallTiming, - listenersCount: { newHead: 0, newFinalizedHead: 0, logs: 0 }, }); expect(res).toEqual(expect.objectContaining({ @@ -229,55 +259,63 @@ describe('getHealthResult', () => { msg: expect.any(Array), moreInfo: expect.objectContaining({ ...healthResult.moreInfo, - maxCachedBlocksCount: maxCachedBlocks, - lastProcessedHeight: lastProcessedHeightBad, - lastProcessedTimestamp: lastProcessedTimestampBad, - idleBlocks: curFinalizedHeight - lastProcessedHeightBad, + subql: expect.objectContaining({ + ...healthResult.moreInfo.subql, + lastProcessedHeight: lastProcessedHeightBad, + lastProcessedTimestamp: lastProcessedTimestampBad, + idleBlocks: curFinalizedHeight - lastProcessedHeightBad, + }), }), })); expect(res.msg.length).to.equal(2); }); - // this only happens when subql and rpc adapter are connecting to different node urls - it('when block production stopped', () => { - const idleBlocks = -100; - const curFinalizedHeightBad = lastProcessedHeight + idleBlocks; + it('when heads out of sync', () => { + const internalHeadsBad = { + curHeight: headsInfo.internalState.curHeight - 125, + curHash: '0xrrr', + finalizedHeight: headsInfo.internalState.finalizedHeight - 678, + finalizedHash: '0xhhh', + }; const res = getHealthResult({ - indexerMeta, - cacheInfo, - curFinalizedHeight: curFinalizedHeightBad, - ethCallTiming, - listenersCount: { newHead: 0, newFinalizedHead: 0, logs: 0 }, + ...healthyData, + headsInfo: { + ...headsInfo, + internalState: internalHeadsBad, + }, }); expect(res).toEqual(expect.objectContaining({ ...healthResult, isHealthy: false, - msg: expect.any(Array), + isHeadsOK: false, + msg: [ + `curHeight mismatch! chain: ${headsInfo.chainState.curHeight}, internal: ${internalHeadsBad.curHeight}`, + `finalizedHeight mismatch! chain: ${headsInfo.chainState.finalizedHeight}, internal: ${internalHeadsBad.finalizedHeight}`, + `curHash mismatch! chain: ${headsInfo.chainState.curHash}, internal: ${internalHeadsBad.curHash}`, + `finalizedHash mismatch! chain: ${headsInfo.chainState.finalizedHash}, internal: ${internalHeadsBad.finalizedHash}`, + ], moreInfo: expect.objectContaining({ ...healthResult.moreInfo, - idleBlocks: idleBlocks, - curFinalizedHeight: curFinalizedHeightBad, + subql: expectedSubql, + headsInfo: { + ...headsInfo, + internalState: internalHeadsBad, + }, }), })); - - expect(res.msg.length).to.equal(1); - expect(res.msg[0]).to.equal(`node production already idle for: ${-idleBlocks} blocks`); }); it('when cache unhealthy', () => { const cachedBlocksCountBad = cachedBlocksCount + 1300; const res = getHealthResult({ - indexerMeta, + ...healthyData, cacheInfo: { ...cacheInfo, cachedBlocksCount: cachedBlocksCountBad, }, - curFinalizedHeight, - ethCallTiming, - listenersCount: { newHead: 0, newFinalizedHead: 0, logs: 0 }, }); expect(res).toEqual(expect.objectContaining({ @@ -289,7 +327,11 @@ describe('getHealthResult', () => { ], moreInfo: expect.objectContaining({ ...healthResult.moreInfo, - cachedBlocksCount: cachedBlocksCountBad, + subql: expectedSubql, + cache: expect.objectContaining({ + ...healthResult.moreInfo.cache, + cachedBlocksCount: cachedBlocksCountBad, + }), }), })); }); @@ -300,11 +342,8 @@ describe('getHealthResult', () => { getFullBlockTime: 23000, }; const res = getHealthResult({ - indexerMeta, - cacheInfo, - curFinalizedHeight, + ...healthyData, ethCallTiming: ethCallTimingBad, - listenersCount: { newHead: 0, newFinalizedHead: 0, logs: 0 }, }); expect(res).toEqual(expect.objectContaining({ @@ -318,6 +357,7 @@ describe('getHealthResult', () => { ], moreInfo: expect.objectContaining({ ...healthResult.moreInfo, + subql: expectedSubql, ethCallTiming: ethCallTimingBad, }), })); @@ -329,11 +369,8 @@ describe('getHealthResult', () => { getFullBlockTime: -1, }; const res = getHealthResult({ - indexerMeta, - cacheInfo, - curFinalizedHeight, + ...healthyData, ethCallTiming: ethCallTimingBad, - listenersCount: { newHead: 0, newFinalizedHead: 0, logs: 0 }, }); expect(res).toEqual(expect.objectContaining({ @@ -343,6 +380,7 @@ describe('getHealthResult', () => { msg: [`an RPC is getting running errors. All timings: ${JSON.stringify(ethCallTimingBad)}`], moreInfo: expect.objectContaining({ ...healthResult.moreInfo, + subql: expectedSubql, ethCallTiming: ethCallTimingBad, }), })); @@ -354,11 +392,8 @@ describe('getHealthResult', () => { getFullBlockTime: -999, }; const res = getHealthResult({ - indexerMeta, - cacheInfo, - curFinalizedHeight, + ...healthyData, ethCallTiming: ethCallTimingBad, - listenersCount: { newHead: 0, newFinalizedHead: 0, logs: 0 }, }); expect(res).toEqual(expect.objectContaining({ @@ -368,6 +403,7 @@ describe('getHealthResult', () => { msg: [`an RPC is getting timeouts. All timings: ${JSON.stringify(ethCallTimingBad)}`], moreInfo: expect.objectContaining({ ...healthResult.moreInfo, + subql: expectedSubql, ethCallTiming: ethCallTimingBad, }), })); diff --git a/packages/eth-providers/src/base-provider.ts b/packages/eth-providers/src/base-provider.ts index 11784d5e4..838d3eb2c 100644 --- a/packages/eth-providers/src/base-provider.ts +++ b/packages/eth-providers/src/base-provider.ts @@ -23,6 +23,7 @@ import { Deferrable, defineReadOnly, resolveProperties } from '@ethersproject/pr import { EvmAccountInfo, EvmContractInfo } from '@acala-network/types/interfaces'; import { Formatter } from '@ethersproject/providers'; import { FrameSystemAccountInfo } from '@polkadot/types/lookup'; +import { ISubmittableResult } from '@polkadot/types/types'; import { Logger } from '@ethersproject/logger'; import { Network } from '@ethersproject/networks'; import { Observable, ReplaySubject, Subscription, firstValueFrom, throwError } from 'rxjs'; @@ -94,11 +95,25 @@ import { toBN, } from './utils'; import { BlockCache, CacheInspect } from './utils/BlockCache'; -import { ISubmittableResult } from '@polkadot/types/types'; import { MaxSizeSet } from './utils/MaxSizeSet'; import { SubqlProvider } from './utils/subqlProvider'; import { _Metadata } from './utils/gqlTypes'; +export interface HeadsInfo { + internalState: { + finalizedHeight: number; + finalizedHash: string; + curHeight: number; + curHash: string; + }; + chainState: { + curHeight: number; + curHash: string; + finalizedHeight: number; + finalizedHash: string; + }; +} + export type Eip1898BlockTag = { blockNumber: string | number; } | { @@ -746,18 +761,12 @@ export abstract class BaseProvider extends AbstractProvider { getTransactionCount = async ( addressOrName: string | Promise, - blockTag?: BlockTag | Promise | Eip1898BlockTag + _blockTag?: BlockTag | Promise | Eip1898BlockTag ): Promise => { - return this.getEvmTransactionCount(addressOrName, await parseBlockTag(blockTag)); - }; + const blockTag = await parseBlockTag(_blockTag); - // TODO: test pending - getEvmTransactionCount = async ( - addressOrName: string | Promise, - blockTag?: BlockTag | Promise - ): Promise => { let pendingNonce = 0; - if ((await blockTag) === 'pending') { + if (blockTag === 'pending') { const [substrateAddress, pendingExtrinsics] = await Promise.all([ this.getSubstrateAddress(await addressOrName), this.api.rpc.author.pendingExtrinsics(), @@ -1903,14 +1912,39 @@ export abstract class BaseProvider extends AbstractProvider { }; }; + _getHeadsInfo = async (): Promise => { + const internalState = { + curHeight: this.bestBlockNumber, + curHash: this.bestBlockHash, + finalizedHeight: await this.finalizedBlockNumber, + finalizedHash: await this.finalizedBlockHash, + }; + + const [header, finalizedHeader] = await Promise.all([ + this.api.rpc.chain.getHeader(), + this.api.rpc.chain.getFinalizedHead().then(hash => this.api.rpc.chain.getHeader(hash)), + ]); + + const chainState = { + curHeight: header.number.toNumber(), + curHash: header.hash.toHex(), + finalizedHeight: finalizedHeader.number.toNumber(), + finalizedHash: finalizedHeader.hash.toHex(), + }; + + return { internalState, chainState }; + }; + + // TODO: move the whole health check thing to a new class? healthCheck = async (): Promise => { - const [indexerMeta, ethCallTiming] = await Promise.all([ + const [indexerMeta, ethCallTiming, headsInfo] = await Promise.all([ this.getIndexerMetadata(), this._timeEthCalls(), + this._getHeadsInfo(), ]); const cacheInfo = this.getCachInfo(); - const curFinalizedHeight = await this.finalizedBlockNumber; + const listenersCount = { newHead: this.eventListeners[SubscriptionType.NewHeads]?.length || 0, newFinalizedHead: this.eventListeners[SubscriptionType.NewFinalizedHeads]?.length || 0, @@ -1920,7 +1954,7 @@ export abstract class BaseProvider extends AbstractProvider { return getHealthResult({ indexerMeta, cacheInfo, - curFinalizedHeight, + headsInfo, ethCallTiming, listenersCount, }); diff --git a/packages/eth-providers/src/utils/utils.ts b/packages/eth-providers/src/utils/utils.ts index 36ad4263f..2088b0a02 100644 --- a/packages/eth-providers/src/utils/utils.ts +++ b/packages/eth-providers/src/utils/utils.ts @@ -5,7 +5,7 @@ import { FrameSystemEventRecord } from '@polkadot/types/lookup'; import { hexToBn, hexToU8a, isHex, isU8a, u8aToBn } from '@polkadot/util'; import BN from 'bn.js'; -import { BlockTagish, CallReturnInfo, Eip1898BlockTag } from '../base-provider'; +import { BlockTagish, CallReturnInfo, Eip1898BlockTag, HeadsInfo } from '../base-provider'; import { CacheInspect } from './BlockCache'; import { _Metadata } from './gqlTypes'; @@ -21,24 +21,25 @@ export interface HealthResult { isSubqlOK: boolean; isCacheOK: boolean; isRPCOK: boolean; + isHeadsOK: boolean; msg: string[]; moreInfo: { - // cache - cachedBlocksCount: number; - maxCachedBlocksCount: number; - // subql - lastProcessedHeight: number; - targetHeight: number; - curFinalizedHeight: number; - lastProcessedTimestamp: number; - curTimestamp: number; - idleSeconds: number; - idleBlocks: number; - indexerHealthy: boolean; - // RPC + headsInfo: HeadsInfo; + cache: { + cachedBlocksCount: number; + maxCachedBlocksCount: number; + }; + subql: { + lastProcessedHeight: number; + targetHeight: number; + lastProcessedTimestamp: number; + curTimestamp: number; + idleSeconds: number; + idleBlocks: number; + isIndexerHealthy: boolean; + }; ethCallTiming: EthCallTimingResult; - // listeners - listenersCount: { + listeners: { newHead: number; newFinalizedHead: number; logs: number; @@ -49,7 +50,7 @@ export interface HealthResult { export interface HealthData { indexerMeta?: _Metadata; cacheInfo?: CacheInspect; - curFinalizedHeight: number; + headsInfo: HeadsInfo; ethCallTiming: EthCallTimingResult; listenersCount: { newHead: number; @@ -109,7 +110,7 @@ export const runWithRetries = async ( export const getHealthResult = ({ indexerMeta, cacheInfo, - curFinalizedHeight, + headsInfo, ethCallTiming, listenersCount, }: HealthData): HealthResult => { @@ -121,8 +122,35 @@ export const getHealthResult = ({ let isSubqlOK = true; let isCacheOK = true; let isRPCOK = true; + let isHeadsOK = true; const msg = []; + /* --------------- heads --------------- */ + const { chainState, internalState } = headsInfo; + if (chainState.curHeight !== internalState.curHeight) { + msg.push(`curHeight mismatch! chain: ${chainState.curHeight}, internal: ${internalState.curHeight}`); + isHealthy = false; + isHeadsOK = false; + } + + if (chainState.finalizedHeight !== internalState.finalizedHeight) { + msg.push(`finalizedHeight mismatch! chain: ${chainState.finalizedHeight}, internal: ${internalState.finalizedHeight}`); + isHealthy = false; + isHeadsOK = false; + } + + if (chainState.curHash !== internalState.curHash) { + msg.push(`curHash mismatch! chain: ${chainState.curHash}, internal: ${internalState.curHash}`); + isHealthy = false; + isHeadsOK = false; + } + + if (chainState.finalizedHash !== internalState.finalizedHash) { + msg.push(`finalizedHash mismatch! chain: ${chainState.finalizedHash}, internal: ${internalState.finalizedHash}`); + isHealthy = false; + isHeadsOK = false; + } + /* --------------- cache --------------- */ const maxCachedBlocks = cacheInfo?.maxCachedBlocks || 0; let cachedBlocksCount = 0; @@ -143,10 +171,12 @@ export const getHealthResult = ({ /* --------------- subql --------------- */ // lastProcessedTimestamp seems to be delayed for a little bit, but it's OK + const curFinalizedHeight = headsInfo.chainState.finalizedHeight; + const lastProcessedTimestamp = parseInt(indexerMeta?.lastProcessedTimestamp || '0'); const lastProcessedHeight = indexerMeta?.lastProcessedHeight || 0; const targetHeight = indexerMeta?.targetHeight || 0; - const indexerHealthy = indexerMeta?.indexerHealthy || false; + const isIndexerHealthy = indexerMeta?.indexerHealthy || false; const curTimestamp = Date.now(); const idleTime = (curTimestamp - lastProcessedTimestamp) / 1000; @@ -175,6 +205,12 @@ export const getHealthResult = ({ msg.push(`node production already idle for: ${-idleBlocks} blocks`); isHealthy = false; } + + if (!isIndexerHealthy) { + msg.push('subql self reported that indexer is not healthy'); + isHealthy = false; + isSubqlOK = false; + } } /* --------------- RPC --------------- */ @@ -202,31 +238,34 @@ export const getHealthResult = ({ } }); + /* --------------- listeners --------------- */ + // TODO: currently only print out info, no threshold check + /* --------------- result --------------- */ return { isHealthy, isSubqlOK, isCacheOK, isRPCOK, + isHeadsOK, msg, moreInfo: { - // cache - cachedBlocksCount, - maxCachedBlocksCount: maxCachedBlocks, - // subql - lastProcessedHeight, - targetHeight, - curFinalizedHeight, - lastProcessedTimestamp, - curTimestamp, - idleSeconds: idleTime, - idleBlocks, - indexerHealthy, - // RPC + headsInfo, + cache: { + cachedBlocksCount, + maxCachedBlocksCount: maxCachedBlocks, + }, + subql: { + lastProcessedHeight, + targetHeight, + lastProcessedTimestamp, + curTimestamp, + idleSeconds: idleTime, + idleBlocks, + isIndexerHealthy, + }, ethCallTiming, - // listeners - // TODO: currently only print out info, no threshold check - listenersCount, + listeners: listenersCount, }, }; }; @@ -276,10 +315,13 @@ export const nativeToEthDecimal = (value: any): BigNumber => export const ethToNativeDecimal = (value: any): BigNumber => BigNumber.from(value).div(10 ** (ETH_DECIMALS - NATIVE_DECIMALS)); -export const parseBlockTag = async (_blockTag: BlockTagish | Eip1898BlockTag): Promise => { +export const parseBlockTag = async ( + _blockTag: BlockTagish | Eip1898BlockTag | undefined +): Promise => { const blockTag = await _blockTag; - if (!blockTag || typeof blockTag !== 'object') return blockTag as any; + if (blockTag === undefined) return blockTag as undefined; + if (typeof blockTag !== 'object') return blockTag; return blockTag['blockHash'] || blockTag['blockNumber']; }; diff --git a/packages/eth-rpc-adapter/src/wrapped-provider.ts b/packages/eth-rpc-adapter/src/wrapped-provider.ts index 620c3c807..7c1793b00 100644 --- a/packages/eth-rpc-adapter/src/wrapped-provider.ts +++ b/packages/eth-rpc-adapter/src/wrapped-provider.ts @@ -14,7 +14,6 @@ const TRACE_METHODS = [ 'getBlockDataForHeader', 'getBalance', 'getTransactionCount', - 'getEvmTransactionCount', 'getCode', 'call', '_ethCall',