Skip to content

Commit

Permalink
track and log storage and byetcode progress
Browse files Browse the repository at this point in the history
  • Loading branch information
@g11tech
g11tech committed Oct 13, 2023
1 parent 244ed3d commit 8408df7
Show file tree
Hide file tree
Showing 8 changed files with 183 additions and 78 deletions.
79 changes: 53 additions & 26 deletions packages/client/src/service/skeleton.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@ import {
import { short, timeDuration } from '../util'
import { DBKey, MetaDBManager } from '../util/metaDBManager'

import type { FetcherDoneFlags } from '../sync/fetcher'
import type { SnapFetcherDoneFlags } from '../sync/fetcher/types'
import type { MetaDBManagerOptions } from '../util/metaDBManager'
import type { BlockHeader } from '@ethereumjs/block'
import type { Hardfork } from '@ethereumjs/common'
Expand Down Expand Up @@ -1174,7 +1174,7 @@ export class Skeleton extends MetaDBManager {
lastStatus?: string
vmexecution?: { running: boolean; started: boolean }
fetching?: boolean
snapsync?: FetcherDoneFlags
snapsync?: SnapFetcherDoneFlags
peers?: number | string
} = {}
): string {
Expand Down Expand Up @@ -1265,8 +1265,17 @@ export class Skeleton extends MetaDBManager {
extraStatus = ` (${scenario} vm=${vmHead?.header.number} cl=el=${this.chain.blocks.height})`
break
case 'SYNCED':
scenario =
Date.now() - this.syncedchain > STALE_WINDOW ? 'execution stalled?' : 'awaiting execution'
if (vmexecution?.started === true) {
scenario =
Date.now() - this.syncedchain > STALE_WINDOW
? 'execution stalled?'
: 'awaiting execution'
} else if (snapsync !== undefined) {
// stall detection yet to be added
scenario = `snapsync height=${this.config.syncTargetHeight}`
} else {
scenario = 'execution none'
}
extraStatus = ` (${scenario} vm=${vmHead?.header.number} cl=el=${this.chain.blocks.height} )`
break
case 'SYNCING':
Expand Down Expand Up @@ -1324,52 +1333,65 @@ export class Skeleton extends MetaDBManager {
}
}

let logInfo
let vmlogInfo
let snapLogInfo
let subchainLog = ''
if (isValid) {
logInfo = `vm=cl=${chainHead}`
snapLogInfo = `vm=cl=${chainHead}`
} else {
const vmlogInfo = `vm=${vmHead?.header.number} hash=${short(
vmHead?.hash() ?? 'na'
)} started=${vmexecution?.started}`
vmlogInfo = `vm=${vmHead?.header.number} hash=${short(vmHead?.hash() ?? 'na')} started=${
vmexecution?.started
}`

if (vmexecution?.started === true) {
logInfo = `${vmlogInfo} executing=${vmexecution?.running}`
vmlogInfo = `${vmlogInfo} executing=${vmexecution?.running}`
} else {
logInfo = `snapsync=${snapsync !== undefined}`
snapLogInfo = `snapsync=${snapsync !== undefined}`
if (snapsync !== undefined) {
if (snapsync.fetchingDone === true) {
const { snapTargetHeight, snapTargetRoot, snapTargetHash } = this.config
logInfo = `${logInfo} synced height=${snapTargetHeight} hash=${short(
snapLogInfo = `${snapLogInfo} synced height=${snapTargetHeight} hash=${short(
snapTargetHash ?? 'na'
)} root=${short(snapTargetRoot ?? 'na')} vm-transition-by=${
(snapTargetHeight ?? BIGINT_0) + this.config.snapTransitionSafeDepth
}`
} else {
let stage = '??'
const accountrangesDone = formatBigDecimal(
snapsync.accountFetcher.first * BIGINT_100,
BIGINT_2EXP256,
BIGINT_100
)
const pendingStorageCodeReqs =
snapsync.storageFetcher.count -
snapsync.storageFetcher.first +
snapsync.byteCodeFetcher.count -
snapsync.byteCodeFetcher.first
const storagecodeReqsDone = formatBigDecimal(
(snapsync.storageFetcher.first + snapsync.byteCodeFetcher.first) * BIGINT_100,
snapsync.storageFetcher.count + snapsync.byteCodeFetcher.count,
BIGINT_100
)

let stage = `?? accounts=${accountrangesDone}% storage-and-codes=${storagecodeReqsDone}% of ${pendingStorageCodeReqs}`
if (snapsync.syncing) {
stage = `accountranges done=${formatBigDecimal(
snapsync.accountFetcher.first * BIGINT_100,
BIGINT_2EXP256,
BIGINT_100
)}%`
stage = `accounts=${accountrangesDone}% storage-and-codes=${storagecodeReqsDone}% of ${pendingStorageCodeReqs}`
}

// move the stage along
if (snapsync.accountFetcher.done === true) {
stage = 'storage and codes'
stage = `storage-and-codes done=${storagecodeReqsDone}% of ${pendingStorageCodeReqs} accounts=${accountrangesDone}%`
}

// move the stage along
if (snapsync.storageFetcherDone === true && snapsync.byteCodeFetcherDone === true) {
stage = 'trienodes'
if (snapsync.storageFetcher.done === true && snapsync.byteCodeFetcher.done === true) {
stage = `trienodes=true storage+codes=${storagecodeReqsDone}% of ${pendingStorageCodeReqs} accounts=${accountrangesDone}%`
}

logInfo = `${logInfo} syncing=${stage}`
snapLogInfo = `${snapLogInfo} ${stage} (hash=${short(
this.config.snapTargetHash ?? 'na'
)} root=${short(this.config.snapTargetRoot ?? 'na')})`
}
}

logInfo = `${logInfo} (${vmlogInfo})`
}

// if not synced add subchain info
Expand All @@ -1394,13 +1416,18 @@ export class Skeleton extends MetaDBManager {
// if valid then the status info is short and sweet
this.config.logger.info('')
if (isValid) {
this.config.logger.info(`${logPrefix} ${status}${extraStatus} ${logInfo} peers=${peers}`)
this.config.logger.info(`${logPrefix} ${status}${extraStatus} ${vmlogInfo} peers=${peers}`)
} else {
// else break into two
this.config.logger.info(
`${logPrefix} ${status}${extraStatus} synchronized=${this.config.synchronized} peers=${peers}`
)
this.config.logger.info(`${logPrefix} ${logInfo}`)
if (snapLogInfo !== undefined && snapLogInfo !== '') {
this.config.logger.info(`${logPrefix} ${snapLogInfo}`)
}
if (vmlogInfo !== undefined && vmlogInfo !== '') {
this.config.logger.info(`${logPrefix} ${vmlogInfo}`)
}
if (!isSynced) {
this.config.logger.info(`${logPrefix} ${subchainLog}`)
}
Expand Down
95 changes: 55 additions & 40 deletions packages/client/src/sync/fetcher/accountfetcher.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@ import { Trie } from '@ethereumjs/trie'
import {
BIGINT_0,
BIGINT_1,
BIGINT_100,
BIGINT_2EXP256,
KECCAK256_NULL,
KECCAK256_RLP,
Expand All @@ -11,6 +12,7 @@ import {
bytesToHex,
compareBytes,
equalsBytes,
formatBigDecimal,
setLengthLeft,
} from '@ethereumjs/util'
import debugDefault from 'debug'
Expand All @@ -25,32 +27,15 @@ import { TrieNodeFetcher } from './trienodefetcher'

import type { Peer } from '../../net/peer'
import type { AccountData } from '../../net/protocol/snapprotocol'
import type { EventBusType } from '../../types'
import type { FetcherOptions } from './fetcher'
import type { StorageRequest } from './storagefetcher'
import type { Job } from './types'
import type { Job, SnapFetcherDoneFlags } from './types'
import type { DefaultStateManager } from '@ethereumjs/statemanager'
import type { Debugger } from 'debug'
const { debug: createDebugLogger } = debugDefault

type AccountDataResponse = AccountData[] & { completed?: boolean }

export type FetcherDoneFlags = {
fetchingDone: boolean
syncing: boolean
accountFetcher: {
started: boolean
first: bigint
done: boolean
}
storageFetcherDone: boolean
byteCodeFetcherDone: boolean
trieNodeFetcherDone: boolean
eventBus?: EventBusType
stateManager?: DefaultStateManager
stateRoot?: Uint8Array
}

/**
* Implements an snap1 based account fetcher
* @memberof module:sync/fetcher
Expand All @@ -69,7 +54,7 @@ export interface AccountFetcherOptions extends FetcherOptions {

stateManager: DefaultStateManager

fetcherDoneFlags: FetcherDoneFlags
fetcherDoneFlags: SnapFetcherDoneFlags
}

// root comes from block?
Expand All @@ -96,7 +81,7 @@ export class AccountFetcher extends Fetcher<JobTask, AccountData[], AccountData>
storageFetcher: StorageFetcher
byteCodeFetcher: ByteCodeFetcher
trieNodeFetcher: TrieNodeFetcher
private readonly fetcherDoneFlags: FetcherDoneFlags
private readonly fetcherDoneFlags: SnapFetcherDoneFlags

/**
* Create new block fetcher
Expand All @@ -122,20 +107,23 @@ export class AccountFetcher extends Fetcher<JobTask, AccountData[], AccountData>
first: BIGINT_1,
destroyWhenDone: false,
stateManager: this.stateManager,
fetcherDoneFlags: this.fetcherDoneFlags,
})
this.byteCodeFetcher = new ByteCodeFetcher({
config: this.config,
pool: this.pool,
hashes: [],
destroyWhenDone: false,
stateManager: this.stateManager,
fetcherDoneFlags: this.fetcherDoneFlags,
})
this.trieNodeFetcher = new TrieNodeFetcher({
config: this.config,
pool: this.pool,
root: this.root,
stateManager: this.stateManager,
destroyWhenDone: false,
fetcherDoneFlags: this.fetcherDoneFlags,
})

const syncRange = { task: { first: this.first, count: this.count } } as Job<
Expand Down Expand Up @@ -164,11 +152,20 @@ export class AccountFetcher extends Fetcher<JobTask, AccountData[], AccountData>
await accountFetch
this.fetcherDoneFlags.accountFetcher.started = false
if (this.fetcherDoneFlags.accountFetcher.done !== true) {
// @scorbajio need to see the reason for this here
throw Error('accountFetcher finished without completing the sync')
}
if (this.fetcherDoneFlags.accountFetcher.first !== BIGINT_2EXP256) {
const fetcherProgress = formatBigDecimal(
this.fetcherDoneFlags.accountFetcher.first * BIGINT_100,
BIGINT_2EXP256,
BIGINT_100
)
this.config.logger.warn(
`accountFetcher completed with pending range done=${fetcherProgress}%`
)
}

const storageFetch = !this.fetcherDoneFlags.storageFetcherDone
const storageFetch = !this.fetcherDoneFlags.storageFetcher.done
? this.storageFetcher.fetch().then(
// we should not be doing this, fetcher itself should mark completion
// cc @scorbajio
Expand All @@ -178,7 +175,7 @@ export class AccountFetcher extends Fetcher<JobTask, AccountData[], AccountData>
}
)
: null
const codeFetch = !this.fetcherDoneFlags.byteCodeFetcherDone
const codeFetch = !this.fetcherDoneFlags.byteCodeFetcher.done
? this.byteCodeFetcher.fetch().then(
// we should not be doing this, fetcher itself should mark completion
// cc @scorbajio
Expand All @@ -195,11 +192,37 @@ export class AccountFetcher extends Fetcher<JobTask, AccountData[], AccountData>
await Promise.all([storageFetch, codeFetch])

if (
this.fetcherDoneFlags.storageFetcherDone !== true ||
this.fetcherDoneFlags.byteCodeFetcherDone !== true
this.fetcherDoneFlags.storageFetcher.first !== this.fetcherDoneFlags.storageFetcher.count
) {
const reqsDone = formatBigDecimal(
this.fetcherDoneFlags.storageFetcher.first * BIGINT_100,
this.fetcherDoneFlags.storageFetcher.count,
BIGINT_100
)
this.config.logger.warn(
`storageFetcher completed with pending tasks done=${reqsDone}% of ${this.fetcherDoneFlags.storageFetcher.count}`
)
}

if (
this.fetcherDoneFlags.byteCodeFetcher.first !== this.fetcherDoneFlags.byteCodeFetcher.count
) {
const reqsDone = formatBigDecimal(
this.fetcherDoneFlags.byteCodeFetcher.first * BIGINT_100,
this.fetcherDoneFlags.byteCodeFetcher.count,
BIGINT_100
)
this.config.logger.warn(
`storageFetcher completed with pending tasks done=${reqsDone}% of ${this.fetcherDoneFlags.byteCodeFetcher.count}`
)
}

if (
this.fetcherDoneFlags.storageFetcher.done !== true ||
this.fetcherDoneFlags.byteCodeFetcher.done !== true
) {
throw Error(
`storageFetch or codeFetch didn't complete storageFetcherDone=${this.fetcherDoneFlags.storageFetcherDone} byteCodeFetcherDone=${this.fetcherDoneFlags.byteCodeFetcherDone}`
`storageFetch or codeFetch didn't complete storageFetcherDone=${this.fetcherDoneFlags.storageFetcher.done} byteCodeFetcherDone=${this.fetcherDoneFlags.byteCodeFetcher.done}`
)
}

Expand Down Expand Up @@ -235,44 +258,36 @@ export class AccountFetcher extends Fetcher<JobTask, AccountData[], AccountData>

snapFetchersCompleted(fetcherType: Object, root?: Uint8Array): void {
const fetcherDoneFlags = this.fetcherDoneFlags
const eventBus = this.config.events
const stateManager = this.stateManager

switch (fetcherType) {
// eslint-disable-next-line @typescript-eslint/no-use-before-define
case AccountFetcher:
fetcherDoneFlags.accountFetcher.done = true
fetcherDoneFlags.accountFetcher.first = BIGINT_2EXP256
fetcherDoneFlags.stateRoot = root
fetcherDoneFlags.stateManager = stateManager
fetcherDoneFlags.eventBus = eventBus
break
case StorageFetcher:
fetcherDoneFlags.storageFetcherDone = true
fetcherDoneFlags.storageFetcher.done = true
break
case ByteCodeFetcher:
fetcherDoneFlags.byteCodeFetcherDone = true
fetcherDoneFlags.byteCodeFetcher.done = true
break
case TrieNodeFetcher:
fetcherDoneFlags.trieNodeFetcherDone = true
break
}

const { accountFetcher, storageFetcherDone, byteCodeFetcherDone, trieNodeFetcherDone } =
const { accountFetcher, storageFetcher, byteCodeFetcher, trieNodeFetcherDone } =
fetcherDoneFlags
this.fetcherDoneFlags.fetchingDone =
accountFetcher.done && storageFetcherDone && byteCodeFetcherDone && trieNodeFetcherDone
accountFetcher.done && storageFetcher.done && byteCodeFetcher.done && trieNodeFetcherDone

this.config.superMsg(
`snapFetchersCompletion status fetchingDone=${this.fetcherDoneFlags.fetchingDone} accountFetcherDone=${accountFetcher.done} storageFetcherDone=${storageFetcherDone} byteCodeFetcherDone=${byteCodeFetcherDone} trieNodeFetcherDone=${trieNodeFetcherDone}`
`snapFetchersCompletion status fetchingDone=${this.fetcherDoneFlags.fetchingDone} accountFetcherDone=${accountFetcher.done} storageFetcherDone=${storageFetcher.done} byteCodeFetcherDone=${byteCodeFetcher.done} trieNodeFetcherDone=${trieNodeFetcherDone}`
)

if (this.fetcherDoneFlags.fetchingDone) {
fetcherDoneFlags.eventBus!.emit(
Event.SYNC_SNAPSYNC_COMPLETE,
fetcherDoneFlags.stateRoot!,
fetcherDoneFlags.stateManager!
)
this.config.events.emit(Event.SYNC_SNAPSYNC_COMPLETE, this.root, this.stateManager)
}
}

Expand Down
Loading

0 comments on commit 8408df7

Please sign in to comment.