devp2p: fix per-message debug logging (#1776)

* devp2p: fix debug logging

* move _version to protocol class

* move _send to protocol class

* simplify types, set null defaults in class rather than in constructor

Author: ryanio

packages/devp2p/src/protocol/eth.ts

@@ -1,36 +1,22 @@
 import assert from 'assert'
 import snappy from 'snappyjs'
-import { devp2pDebug } from '../util'
 import { BN, rlp } from 'ethereumjs-util'
 import { int2buffer, buffer2int, assertEq, formatLogId, formatLogData } from '../util'
 import { Peer } from '../rlpx/peer'
-import { Protocol } from './protocol'
-
-const DEBUG_BASE_NAME = 'eth'
-
-type SendMethod = (code: ETH.MESSAGE_CODES, data: Buffer) => any
+import { EthProtocol, Protocol, SendMethod } from './protocol'
 
 export class ETH extends Protocol {
-  _version: number
-  _status: ETH.StatusMsg | null
-  _peerStatus: ETH.StatusMsg | null
-  _send: SendMethod
+  _status: ETH.StatusMsg | null = null
+  _peerStatus: ETH.StatusMsg | null = null
 
   // Eth64
-  _hardfork: string = 'chainstart'
+  _hardfork = 'chainstart'
   _latestBlock = new BN(0)
-  _forkHash: string = ''
+  _forkHash = ''
   _nextForkBlock = new BN(0)
 
   constructor(version: number, peer: Peer, send: SendMethod) {
-    super(peer, ETH.MESSAGE_CODES, DEBUG_BASE_NAME)
-
-    this._version = version
-    this._peer = peer
-    this._send = send
-    this._debug = devp2pDebug.extend(DEBUG_BASE_NAME)
-    this._status = null
-    this._peerStatus = null
+    super(peer, send, EthProtocol.ETH, version, ETH.MESSAGE_CODES)
 
     // Set forkHash and nextForkBlock
     if (this._version >= 64) {

packages/devp2p/src/protocol/les.ts

@@ -1,32 +1,19 @@
 import ms from 'ms'
 import { rlp } from 'ethereumjs-util'
 import snappy from 'snappyjs'
-import { devp2pDebug } from '../util'
 import { int2buffer, buffer2int, assertEq, formatLogData } from '../util'
 import { Peer, DISCONNECT_REASONS } from '../rlpx/peer'
-import { Protocol } from './protocol'
-
-const DEBUG_BASE_NAME = 'les'
+import { EthProtocol, Protocol, SendMethod } from './protocol'
 
 export const DEFAULT_ANNOUNCE_TYPE = 1
 
-type SendMethod = (code: LES.MESSAGE_CODES, data: Buffer) => any
-
 export class LES extends Protocol {
-  _version: number
-  _send: SendMethod
-  _status: LES.Status | null
-  _peerStatus: LES.Status | null
+  _status: LES.Status | null = null
+  _peerStatus: LES.Status | null = null
 
   constructor(version: number, peer: Peer, send: SendMethod) {
-    super(peer, LES.MESSAGE_CODES, DEBUG_BASE_NAME)
-
-    this._version = version
-    this._peer = peer
-    this._send = send
-    this._debug = devp2pDebug
-    this._status = null
-    this._peerStatus = null
+    super(peer, send, EthProtocol.LES, version, LES.MESSAGE_CODES)
+
     this._statusTimeoutId = setTimeout(() => {
       this._peer.disconnect(DISCONNECT_REASONS.TIMEOUT)
     }, ms('5s'))

packages/devp2p/src/protocol/protocol.ts

@@ -1,12 +1,22 @@
 import ms from 'ms'
 import { debug as createDebugLogger, Debugger } from 'debug'
 import { EventEmitter } from 'events'
+import { devp2pDebug } from '../util'
 import { Peer, DISCONNECT_REASONS } from '../rlpx/peer'
 
+export enum EthProtocol {
+  ETH = 'eth',
+  LES = 'les',
+}
+
 type MessageCodes = { [key: number | string]: number | string }
 
+export type SendMethod = (code: number, data: Buffer) => any
+
 export class Protocol extends EventEmitter {
+  _version: number
   _peer: Peer
+  _send: SendMethod
   _statusTimeoutId: NodeJS.Timeout
   _messageCodes: MessageCodes
   _debug: Debugger
@@ -16,38 +26,45 @@ export class Protocol extends EventEmitter {
    * Will be set to the first successfully connected peer to allow for
    * debugging with the `devp2p:FIRST_PEER` debugger
    */
-  _firstPeer: string
+  _firstPeer = ''
 
   // Message debuggers (e.g. { 'GET_BLOCK_HEADERS': [debug Object], ...})
   protected msgDebuggers: { [key: string]: (debug: string) => void } = {}
 
-  constructor(peer: Peer, _messageCodes: MessageCodes, debugBaseName: string) {
+  constructor(
+    peer: Peer,
+    send: SendMethod,
+    protocol: EthProtocol,
+    version: number,
+    messageCodes: MessageCodes
+  ) {
     super()
 
-    this._firstPeer = ''
     this._peer = peer
-    this._messageCodes = _messageCodes
+    this._send = send
+    this._version = version
+    this._messageCodes = messageCodes
     this._statusTimeoutId = setTimeout(() => {
       this._peer.disconnect(DISCONNECT_REASONS.TIMEOUT)
     }, ms('5s'))
 
-    this._debug = createDebugLogger(debugBaseName)
+    this._debug = devp2pDebug.extend(protocol)
     this._verbose = createDebugLogger('verbose').enabled
-    this.initMsgDebuggers(debugBaseName)
+    this.initMsgDebuggers(protocol)
   }
 
-  private initMsgDebuggers(debugBaseName: string) {
+  private initMsgDebuggers(protocol: EthProtocol) {
     const MESSAGE_NAMES = Object.values(this._messageCodes).filter(
       (value) => typeof value === 'string'
     ) as string[]
     for (const name of MESSAGE_NAMES) {
-      this.msgDebuggers[name] = createDebugLogger(`${debugBaseName}:${name}`)
+      this.msgDebuggers[name] = devp2pDebug.extend(protocol).extend(name)
     }
 
     // Remote Peer IP logger
     const ip = this._peer._socket.remoteAddress
     if (ip) {
-      this.msgDebuggers[ip] = createDebugLogger(`devp2p:${ip}`)
+      this.msgDebuggers[ip] = devp2pDebug.extend(ip)
     }
   }
 
@@ -60,7 +77,7 @@ export class Protocol extends EventEmitter {
   _addFirstPeerDebugger() {
     const ip = this._peer._socket.remoteAddress
     if (ip) {
-      this.msgDebuggers[ip] = createDebugLogger(`devp2p:FIRST_PEER`)
+      this.msgDebuggers[ip] = devp2pDebug.extend('FIRST_PEER')
       this._peer._addFirstPeerDebugger()
       this._firstPeer = ip
     }