Debug logger namespace standardization

packages/blockchain/README.md

@@ -247,7 +247,7 @@ The following initial logger is currently available:
 
 | Logger              | Description                                                              |
 | ------------------- | ------------------------------------------------------------------------ |
-| `blockchain`        | Core blockchain operations like when a block or header is put or deleted |
+| `blockchain:#`      | Core blockchain operations like when a block or header is put or deleted |
 | `blockchain:clique` | Clique consensus operations like updating the vote and/or signer list    |
 | `blockchain:ethash` | Ethash consensus operations like PoW block or header validation          |
 

packages/blockchain/src/blockchain.ts

@@ -107,7 +107,7 @@ export class Blockchain implements BlockchainInterface {
   constructor(opts: BlockchainOptions = {}) {
     this.DEBUG =
       typeof window === 'undefined' ? (process?.env?.DEBUG?.includes('ethjs') ?? false) : false
-    this._debug = debugDefault('blockchain')
+    this._debug = debugDefault('blockchain:#')
 
     if (opts.common) {
       this.common = opts.common
@@ -327,7 +327,10 @@ export class Blockchain implements BlockchainInterface {
 
   async resetCanonicalHead(canonicalHead: bigint) {
     let hash: Uint8Array | undefined
-    const canonicalHeadHash = (await this.getCanonicalHeadHeader()).hash()
+    let canonicalHeadHash: Uint8Array | undefined
+    if (this.DEBUG) {
+      canonicalHeadHash = (await this.getCanonicalHeadHeader()).hash()
+    }
     await this.runWithLock<void>(async () => {
       hash = await this.dbManager.numberToHash(canonicalHead)
       if (hash === undefined) {
@@ -352,7 +355,7 @@ export class Blockchain implements BlockchainInterface {
 
       this.DEBUG &&
         this._debug(
-          `Canonical head set from ${bytesToHex(canonicalHeadHash)} to ${bytesToHex(hash!)} (number ${bigIntToHex(canonicalHead)})`,
+          `Canonical head set from ${bytesToHex(canonicalHeadHash!)} to ${bytesToHex(hash!)} (number ${bigIntToHex(canonicalHead)})`,
         )
 
       this._deletedBlocks = []

packages/blockchain/src/constructors.ts

@@ -17,7 +17,7 @@ import type { Chain } from '@ethereumjs/common'
 
 const DEBUG =
   typeof window === 'undefined' ? (process?.env?.DEBUG?.includes('ethjs') ?? false) : false
-const debug = debugDefault('blockchain')
+const debug = debugDefault('blockchain:#')
 
 export async function createBlockchain(opts: BlockchainOptions = {}) {
   const blockchain = new Blockchain(opts)

packages/client/README.md

@@ -466,7 +466,7 @@ The following options are available:
 
 | Logger              | Description                                      |
 | ------------------- | ------------------------------------------------ |
-| `client:fetcher`            | This option enables logging for all fetchers      |
+| `client:fetcher:#`            | This option enables logging for core fetcher operations such as job scheduling   |
 | `client:fetcher:bytecode`   | This option enables logging for the snap sync bytecode fetcher         |
 | `client:fetcher:storage`    | This option enables logging for the snap sync storage fetcher  |
 | `client:fetcher:trienode`   | This option enables logging for the snap sync trienode fetcher      |

packages/client/src/sync/fetcher/fetcher.ts

@@ -82,7 +82,7 @@ export abstract class Fetcher<JobTask, JobResult, StorageItem> extends Readable
       typeof window === 'undefined' ? (process?.env?.DEBUG?.includes('ethjs') ?? false) : false
 
     this.config = options.config
-    this.debug = debug('client:fetcher')
+    this.debug = debug('client:fetcher:#')
 
     this.pool = options.pool
     this.timeout = options.timeout ?? 8000

packages/devp2p/src/util.ts

@@ -7,7 +7,7 @@ import { secp256k1 } from 'ethereum-cryptography/secp256k1.js'
 import type { ETH } from './protocol/eth.js'
 import type { LES } from './protocol/les.js'
 
-export const devp2pDebug = debug('devp2p')
+export const devp2pDebug = debug('devp2p:#')
 
 export function genPrivateKey(): Uint8Array {
   const privateKey = secp256k1.utils.randomPrivateKey()

packages/trie/README.md

@@ -341,12 +341,26 @@ The `Trie` class features optional debug logging. Individual debug selections ca
 
 The following options are available:
 
-| Logger            | Description                                    |
-| ----------------- | ---------------------------------------------- |
-| `trie`            | minimal info logging for all trie methods      |
-| `trie:<METHOD>`   | debug logging for specific trie method         |
-| `trie:<METHOD>:*` | verbose debug logging for specific trie method |
-| `trie:*`          | verbose debug logging for all trie methods     |
+| Logger                            | Description                                                          |
+| --------------------------------- | -------------------------------------------------------------------- |
+| `trie:#`                          | minimal info logging for all trie methods                            |
+| `trie:#:put`                      | a trie put operation has occurred                                    |
+| `trie:#:get`                      | a trie get operation has occurred                                    |
+| `trie:#:del`                      | a trie del operation has occurred                                    |
+| `trie:#:find_path`                | a node is being searched for                                         |
+| `trie:#:find_path:branch_node`    | a branch node has been found during a node search                    |
+| `trie:#:find_path:extension_node` | an extension node has been found during a node search                |
+| `trie:#:lookup_node`              | node lookup operations                                               |
+| `trie:#:lookup_node:raw_node`     | node lookup operations that have hit a raw node                      |
+| `trie:#:lookup_node:by_hash`      | node lookup operations that have hit a node hash                     |
+| `trie:#:persist_root`             | operations writing the state root to the disk                        |
+| `trie:#:checkpoint`               | checkpoint operations                                                |
+| `trie:#:commit`                   | operations committing checkpoints to the disk                        |
+| `trie:#:revert:before`            | the stateRoot before reverting committed checkpoints                 |
+| `trie:#:revert:after`             | the stateRoot after reverting committed checkpoints                  |
+| `trie:#:flush_checkpoints`        | checkpoints are being flushed                                        |
+| `trie:#:from_proof`               | a trie has been updated from a proof using updateTrieFromMerkleProof |
+| `trie:#:create_proof`             | a merkle proof has been created using updateTrieFromMerkleProof      |
 
 To observe the logging in action at different levels:
 
@@ -359,25 +373,25 @@ DEBUG=ethjs,trie npx vitest test/util/log.spec.ts
 Run with **put** method logging:
 
 ```shell
-DEBUG=ethjs,trie:PUT npx vitest test/util/log.spec.ts
+DEBUG=ethjs,trie:put npx vitest test/util/log.spec.ts
 ```
 
 Run with **trie** + **put**/**get**/**del** logging:
 
 ```shell
-DEBUG=ethjs,trie,trie:PUT,trie:GET,trie:DEL npx vitest test/util/log.spec.ts
+DEBUG=ethjs,trie,trie:put,trie:get,trie:del npx vitest test/util/log.spec.ts
 ```
 
 Run with **findPath** debug logging:
 
 ```shell
-DEBUG=ethjs,trie:FIND_PATH npx vitest test/util/log.spec.ts
+DEBUG=ethjs,trie:find_path npx vitest test/util/log.spec.ts
 ```
 
 Run with **findPath** verbose logging:
 
 ```shell
-DEBUG=ethjs,trie:FIND_PATH:* npx vitest test/util/log.spec.ts
+DEBUG=ethjs,trie:find_path:* npx vitest test/util/log.spec.ts
 ```
 
 Run with max logging:
@@ -389,7 +403,7 @@ DEBUG=ethjs,trie:* npx vitest test/util/log.spec.ts
 `ethjs` **must** be included in the `DEBUG` environment variables to enable **any** logs.
 Additional log selections can be added with a comma separated list (no spaces). Logs with extensions can be enabled with a colon `:`, and `*` can be used to include all extensions.
 
-`DEBUG=ethjs,tie:PUT,trie:FIND_PATH:* npx vitest test/proof.spec.ts`
+`DEBUG=ethjs,trie:put,trie:find_path:* npx vitest test/proof.spec.ts`
 
 ## References
 

packages/trie/src/proof/index.ts

@@ -72,12 +72,12 @@ export function verifyTrieRangeProof(
  * @param key key to create a proof for
  */
 export async function createMerkleProof(trie: Trie, key: Uint8Array): Promise<Proof> {
-  trie['DEBUG'] && trie['debug'](`Creating Proof for Key: ${bytesToHex(key)}`, ['CREATE_PROOF'])
+  trie['DEBUG'] && trie['debug'](`Creating Proof for Key: ${bytesToHex(key)}`, ['create_proof'])
   const { stack } = await trie.findPath(trie['appliedKey'](key))
   const p = stack.map((stackElem) => {
     return stackElem.serialize()
   })
-  trie['DEBUG'] && trie['debug'](`Proof created with (${stack.length}) nodes`, ['CREATE_PROOF'])
+  trie['DEBUG'] && trie['debug'](`Proof created with (${stack.length}) nodes`, ['create_proof'])
   return p
 }
 
@@ -94,7 +94,7 @@ export async function updateTrieFromMerkleProof(
   proof: Proof,
   shouldVerifyRoot: boolean = false,
 ) {
-  trie['DEBUG'] && trie['debug'](`Saving (${proof.length}) proof nodes in DB`, ['FROM_PROOF'])
+  trie['DEBUG'] && trie['debug'](`Saving (${proof.length}) proof nodes in DB`, ['from_proof'])
   const opStack = proof.map((nodeValue) => {
     let key = Uint8Array.from(trie['hash'](nodeValue))
     key = trie['_opts'].keyPrefix ? concatBytes(trie['_opts'].keyPrefix, key) : key

packages/trie/src/trie.ts

@@ -72,7 +72,7 @@ export class Trie {
 
   /** Debug logging */
   protected DEBUG: boolean
-  protected _debug: Debugger = debug('trie')
+  protected _debug: Debugger = debug('trie:#')
   protected debug: (...args: any) => void
 
   /**
@@ -187,13 +187,13 @@ export class Trie {
    * @returns A Promise that resolves to `Uint8Array` if a value was found or `null` if no value was found.
    */
   async get(key: Uint8Array, throwIfMissing = false): Promise<Uint8Array | null> {
-    this.DEBUG && this.debug(`Key: ${bytesToHex(key)}`, ['GET'])
+    this.DEBUG && this.debug(`Key: ${bytesToHex(key)}`, ['get'])
     const { node, remaining } = await this.findPath(this.appliedKey(key), throwIfMissing)
     let value: Uint8Array | null = null
     if (node && remaining.length === 0) {
       value = node.value()
     }
-    this.DEBUG && this.debug(`Value: ${value === null ? 'null' : bytesToHex(value)}`, ['GET'])
+    this.DEBUG && this.debug(`Value: ${value === null ? 'null' : bytesToHex(value)}`, ['get'])
     return value
   }
 
@@ -209,8 +209,8 @@ export class Trie {
     value: Uint8Array | null,
     skipKeyTransform: boolean = false,
   ): Promise<void> {
-    this.DEBUG && this.debug(`Key: ${bytesToHex(key)}`, ['PUT'])
-    this.DEBUG && this.debug(`Value: ${value === null ? 'null' : bytesToHex(key)}`, ['PUT'])
+    this.DEBUG && this.debug(`Key: ${bytesToHex(key)}`, ['put'])
+    this.DEBUG && this.debug(`Value: ${value === null ? 'null' : bytesToHex(key)}`, ['put'])
     if (this._opts.useRootPersistence && equalsBytes(key, ROOT_DB_KEY) === true) {
       throw new Error(`Attempted to set '${bytesToUtf8(ROOT_DB_KEY)}' key but it is not allowed.`)
     }
@@ -272,7 +272,7 @@ export class Trie {
    * @returns A Promise that resolves once value is deleted.
    */
   async del(key: Uint8Array, skipKeyTransform: boolean = false): Promise<void> {
-    this.DEBUG && this.debug(`Key: ${bytesToHex(key)}`, ['DEL'])
+    this.DEBUG && this.debug(`Key: ${bytesToHex(key)}`, ['del'])
     await this._lock.acquire()
     const appliedKey = skipKeyTransform ? key : this.appliedKey(key)
     const { node, stack } = await this.findPath(appliedKey)
@@ -331,7 +331,7 @@ export class Trie {
       stack[i] = partialPath.stack[i]
       progress += stack[i] instanceof BranchNode ? 1 : (<ExtensionNode>stack[i]).keyLength()
     }
-    this.DEBUG && this.debug(`Target (${targetKey.length}): [${targetKey}]`, ['FIND_PATH'])
+    this.DEBUG && this.debug(`Target (${targetKey.length}): [${targetKey}]`, ['find_path'])
     let result: Path | null = null
 
     const onFound: FoundNodeFunction = async (_, node, keyProgress, walkController) => {
@@ -343,19 +343,25 @@ export class Trie {
           const branchIndex = targetKey[progress]
           this.DEBUG &&
             this.debug(`Looking for node on branch index: [${branchIndex}]`, [
-              'FIND_PATH',
-              'BranchNode',
+              'find_path',
+              'branch_node',
             ])
           const branchNode = node.getBranch(branchIndex)
-          this.DEBUG &&
-            this.debug(
-              branchNode === null
-                ? 'NULL'
-                : branchNode instanceof Uint8Array
+
+          if (this.DEBUG) {
+            let debugString: string
+            if (branchNode === null) {
+              debugString = 'NULL'
+            } else {
+              debugString = `Branch index: ${branchIndex.toString()} - `
+              debugString +=
+                branchNode instanceof Uint8Array
                   ? `NodeHash: ${bytesToHex(branchNode)}`
-                  : `Raw_Node: ${branchNode.toString()}`,
-              ['FIND_PATH', 'BranchNode', branchIndex.toString()],
-            )
+                  : `Raw_Node: ${branchNode!.toString()}`
+            }
+
+            this.debug(debugString, ['find_path', 'branch_node'])
+          }
           if (!branchNode) {
             result = { node: null, remaining: targetKey.slice(progress), stack }
           } else {
@@ -388,11 +394,11 @@ export class Trie {
               node.key().toString()
             }]
             `,
-            ['FIND_PATH', 'ExtensionNode'],
+            ['find_path', 'extension_node'],
           )
         const _progress = progress
         for (const k of node.key()) {
-          this.DEBUG && this.debug(`NextNode: ${node.value()}`, ['FIND_PATH', 'ExtensionNode'])
+          this.DEBUG && this.debug(`NextNode: ${node.value()}`, ['find_path', 'extension_node'])
           if (k !== targetKey[progress]) {
             result = { node: null, remaining: targetKey.slice(_progress), stack }
             return
@@ -408,7 +414,7 @@ export class Trie {
       this.DEBUG &&
         this.debug(
           `Walking trie from ${startingNode === undefined ? 'ROOT' : 'NODE'}: ${bytesToHex(start)}`,
-          ['FIND_PATH'],
+          ['find_path'],
         )
       await this.walkTrie(start, onFound)
     } catch (error: any) {
@@ -425,7 +431,7 @@ export class Trie {
         result.node !== null
           ? `Target Node FOUND for ${bytesToNibbles(key)}`
           : `Target Node NOT FOUND`,
-        ['FIND_PATH'],
+        ['find_path'],
       )
 
     result.stack = result.stack.filter((e) => e !== undefined)
@@ -436,7 +442,7 @@ export class Trie {
         || Remaining: [${result.remaining}]\n|| Stack: ${result.stack
           .map((e) => e.constructor.name)
           .join(', ')}`,
-        ['FIND_PATH'],
+        ['find_path'],
       )
     return result
   }
@@ -503,10 +509,10 @@ export class Trie {
   async lookupNode(node: Uint8Array | Uint8Array[]): Promise<TrieNode> {
     if (isRawNode(node)) {
       const decoded = decodeRawNode(node)
-      this.DEBUG && this.debug(`${decoded.constructor.name}`, ['LOOKUP_NODE', 'RAW_NODE'])
+      this.DEBUG && this.debug(`${decoded.constructor.name}`, ['lookup_node', 'raw_node'])
       return decoded
     }
-    this.DEBUG && this.debug(`${`${bytesToHex(node)}`}`, ['LOOKUP_NODE', 'BY_HASH'])
+    this.DEBUG && this.debug(`${`${bytesToHex(node)}`}`, ['lookup_node', 'by_hash'])
     const key = this._opts.keyPrefix ? concatBytes(this._opts.keyPrefix, node) : node
     const value = (await this._db.get(key)) ?? null
 
@@ -516,7 +522,7 @@ export class Trie {
     }
 
     const decoded = decodeNode(value)
-    this.DEBUG && this.debug(`${decoded.constructor.name} found in DB`, ['LOOKUP_NODE', 'BY_HASH'])
+    this.DEBUG && this.debug(`${decoded.constructor.name} found in DB`, ['lookup_node', 'by_hash'])
     return decoded
   }
 
@@ -965,7 +971,7 @@ export class Trie {
           `Persisting root: \n|| RootHash: ${bytesToHex(this.root())}\n|| RootKey: ${bytesToHex(
             this.appliedKey(ROOT_DB_KEY),
           )}`,
-          ['PERSIST_ROOT'],
+          ['persist_root'],
         )
       let key = this.appliedKey(ROOT_DB_KEY)
       key = this._opts.keyPrefix ? concatBytes(this._opts.keyPrefix, key) : key
@@ -1020,7 +1026,7 @@ export class Trie {
    * After this is called, all changes can be reverted until `commit` is called.
    */
   checkpoint() {
-    this.DEBUG && this.debug(`${bytesToHex(this.root())}`, ['CHECKPOINT'])
+    this.DEBUG && this.debug(`${bytesToHex(this.root())}`, ['checkpoint'])
     this._db.checkpoint(this.root())
   }
 
@@ -1033,7 +1039,7 @@ export class Trie {
     if (!this.hasCheckpoints()) {
       throw new Error('trying to commit when not checkpointed')
     }
-    this.DEBUG && this.debug(`${bytesToHex(this.root())}`, ['COMMIT'])
+    this.DEBUG && this.debug(`${bytesToHex(this.root())}`, ['commit'])
     await this._lock.acquire()
     await this._db.commit()
     await this.persistRoot()
@@ -1050,20 +1056,20 @@ export class Trie {
       throw new Error('trying to revert when not checkpointed')
     }
 
-    this.DEBUG && this.debug(`${bytesToHex(this.root())}`, ['REVERT', 'BEFORE'])
+    this.DEBUG && this.debug(`${bytesToHex(this.root())}`, ['revert', 'before'])
     await this._lock.acquire()
     this.root(await this._db.revert())
     await this.persistRoot()
     this._lock.release()
-    this.DEBUG && this.debug(`${bytesToHex(this.root())}`, ['REVERT', 'AFTER'])
+    this.DEBUG && this.debug(`${bytesToHex(this.root())}`, ['revert', 'after'])
   }
 
   /**
    * Flushes all checkpoints, restoring the initial checkpoint state.
    */
   flushCheckpoints() {
     this.DEBUG &&
-      this.debug(`Deleting ${this._db.checkpoints.length} checkpoints.`, ['FLUSH_CHECKPOINTS'])
+      this.debug(`Deleting ${this._db.checkpoints.length} checkpoints.`, ['flush_checkpoints'])
     this._db.checkpoints = []
   }