feat: add peer logger

Adds a `peerLogger` to `@libp2p/logger` that prefixes all log messages
with a truncated peer id.

When running multiple libp2p instances simultaneously it's often hard
to work out which log messages come from which instance. This will
solve this problem.

Refs #2105

packages/interface/src/index.ts

@@ -106,6 +106,23 @@ export interface IdentifyResult {
   connection: Connection
 }
 
+/**
+ * Logger component for libp2p
+ */
+export interface Logger {
+  (formatter: any, ...args: any[]): void
+  error(formatter: any, ...args: any[]): void
+  trace(formatter: any, ...args: any[]): void
+  enabled: boolean
+}
+
+/**
+ * Peer logger component for libp2p
+ */
+export interface PeerLogger {
+  forComponent(name: string): Logger
+}
+
 /**
  * Once you have a libp2p instance, you can listen to several events it emits,
  * so that you can be notified of relevant network events.
@@ -408,6 +425,8 @@ export interface Libp2p<T extends ServiceMap = ServiceMap> extends Startable, Ty
    */
   metrics?: Metrics
 
+  logger: PeerLogger
+
   /**
    * Get a deduplicated list of peer advertising multiaddrs by concatenating
    * the listen addresses used by transports with any configured

packages/libp2p/src/components.ts

@@ -1,6 +1,6 @@
 import { CodeError } from '@libp2p/interface/errors'
 import { isStartable, type Startable } from '@libp2p/interface/startable'
-import type { Libp2pEvents } from '@libp2p/interface'
+import type { Libp2pEvents, PeerLogger } from '@libp2p/interface'
 import type { ConnectionProtector } from '@libp2p/interface/connection'
 import type { ConnectionGater } from '@libp2p/interface/connection-gater'
 import type { ContentRouting } from '@libp2p/interface/content-routing'
@@ -18,6 +18,7 @@ import type { Datastore } from 'interface-datastore'
 
 export interface Components extends Record<string, any>, Startable {
   peerId: PeerId
+  logger: PeerLogger
   events: TypedEventTarget<Libp2pEvents>
   addressManager: AddressManager
   peerStore: PeerStore
@@ -35,6 +36,7 @@ export interface Components extends Record<string, any>, Startable {
 
 export interface ComponentsInit {
   peerId?: PeerId
+  logger?: PeerLogger
   events?: TypedEventTarget<Libp2pEvents>
   addressManager?: AddressManager
   peerStore?: PeerStore

packages/libp2p/src/libp2p.ts

@@ -5,7 +5,7 @@ import { TypedEventEmitter, CustomEvent, setMaxListeners } from '@libp2p/interfa
 import { peerDiscovery } from '@libp2p/interface/peer-discovery'
 import { type PeerRouting, peerRouting } from '@libp2p/interface/peer-routing'
 import { DefaultKeyChain } from '@libp2p/keychain'
-import { logger } from '@libp2p/logger'
+import { peerLogger } from '@libp2p/logger'
 import { PeerSet } from '@libp2p/peer-collections'
 import { peerIdFromString } from '@libp2p/peer-id'
 import { createEd25519PeerId } from '@libp2p/peer-id-factory'
@@ -28,7 +28,7 @@ import { DefaultTransportManager } from './transport-manager.js'
 import { DefaultUpgrader } from './upgrader.js'
 import type { Components } from './components.js'
 import type { Libp2p, Libp2pInit, Libp2pOptions } from './index.js'
-import type { Libp2pEvents, PendingDial, ServiceMap, AbortOptions } from '@libp2p/interface'
+import type { Libp2pEvents, PendingDial, ServiceMap, AbortOptions, PeerLogger, Logger } from '@libp2p/interface'
 import type { Connection, NewStreamOptions, Stream } from '@libp2p/interface/connection'
 import type { KeyChain } from '@libp2p/interface/keychain'
 import type { Metrics } from '@libp2p/interface/metrics'
@@ -39,8 +39,6 @@ import type { Topology } from '@libp2p/interface/topology'
 import type { StreamHandler, StreamHandlerOptions } from '@libp2p/interface-internal/registrar'
 import type { Datastore } from 'interface-datastore'
 
-const log = logger('libp2p')
-
 export class Libp2pNode<T extends ServiceMap = Record<string, unknown>> extends TypedEventEmitter<Libp2pEvents> implements Libp2p<T> {
   public peerId: PeerId
   public peerStore: PeerStore
@@ -49,9 +47,11 @@ export class Libp2pNode<T extends ServiceMap = Record<string, unknown>> extends
   public keychain: KeyChain
   public metrics?: Metrics
   public services: T
+  public logger: PeerLogger
 
   public components: Components
   #started: boolean
+  readonly #log: Logger
 
   constructor (init: Libp2pInit<T>) {
     super()
@@ -74,10 +74,13 @@ export class Libp2pNode<T extends ServiceMap = Record<string, unknown>> extends
 
     this.#started = false
     this.peerId = init.peerId
+    this.logger = peerLogger(this.peerId)
+    this.#log = this.logger.forComponent('libp2p')
     // @ts-expect-error {} may not be of type T
     this.services = {}
     const components = this.components = defaultComponents({
       peerId: init.peerId,
+      logger: this.logger,
       events,
       datastore: init.datastore ?? new MemoryDatastore(),
       connectionGater: connectionGater(init.connectionGater)
@@ -170,25 +173,25 @@ export class Libp2pNode<T extends ServiceMap = Record<string, unknown>> extends
         const service: any = createService(this.components)
 
         if (service == null) {
-          log.error('service factory %s returned null or undefined instance', name)
+          this.#log.error('service factory %s returned null or undefined instance', name)
           continue
         }
 
         this.services[name as keyof T] = service
         this.configureComponent(name, service)
 
         if (service[contentRouting] != null) {
-          log('registering service %s for content routing', name)
+          this.#log('registering service %s for content routing', name)
           contentRouters.push(service[contentRouting])
         }
 
         if (service[peerRouting] != null) {
-          log('registering service %s for peer routing', name)
+          this.#log('registering service %s for peer routing', name)
           peerRouters.push(service[peerRouting])
         }
 
         if (service[peerDiscovery] != null) {
-          log('registering service %s for peer discovery', name)
+          this.#log('registering service %s for peer discovery', name)
           service[peerDiscovery].addEventListener('peer', (evt: CustomEvent<PeerInfo>) => {
             this.#onDiscoveryPeer(evt)
           })
@@ -199,7 +202,7 @@ export class Libp2pNode<T extends ServiceMap = Record<string, unknown>> extends
 
   private configureComponent <T> (name: string, component: T): T {
     if (component == null) {
-      log.error('component %s was null or undefined', name)
+      this.#log.error('component %s was null or undefined', name)
     }
 
     this.components[name] = component
@@ -217,12 +220,12 @@ export class Libp2pNode<T extends ServiceMap = Record<string, unknown>> extends
 
     this.#started = true
 
-    log('libp2p is starting')
+    this.#log('libp2p is starting')
 
     const keys = await this.keychain.listKeys()
 
     if (keys.find(key => key.name === 'self') == null) {
-      log('importing self key into keychain')
+      this.#log('importing self key into keychain')
       await this.keychain.importPeer('self', this.components.peerId)
     }
 
@@ -232,9 +235,9 @@ export class Libp2pNode<T extends ServiceMap = Record<string, unknown>> extends
       await this.components.afterStart?.()
 
       this.safeDispatchEvent('start', { detail: this })
-      log('libp2p has started')
+      this.#log('libp2p has started')
     } catch (err: any) {
-      log.error('An error occurred starting libp2p', err)
+      this.#log.error('An error occurred starting libp2p', err)
       await this.stop()
       throw err
     }
@@ -248,7 +251,7 @@ export class Libp2pNode<T extends ServiceMap = Record<string, unknown>> extends
       return
     }
 
-    log('libp2p is stopping')
+    this.#log('libp2p is stopping')
 
     this.#started = false
 
@@ -257,7 +260,7 @@ export class Libp2pNode<T extends ServiceMap = Record<string, unknown>> extends
     await this.components.afterStop?.()
 
     this.safeDispatchEvent('stop', { detail: this })
-    log('libp2p has stopped')
+    this.#log('libp2p has stopped')
   }
 
   isStarted (): boolean {
@@ -322,7 +325,7 @@ export class Libp2pNode<T extends ServiceMap = Record<string, unknown>> extends
    * Get the public key for the given peer id
    */
   async getPublicKey (peer: PeerId, options: AbortOptions = {}): Promise<Uint8Array> {
-    log('getPublicKey %p', peer)
+    this.#log('getPublicKey %p', peer)
 
     if (peer.publicKey != null) {
       return peer.publicKey
@@ -391,15 +394,15 @@ export class Libp2pNode<T extends ServiceMap = Record<string, unknown>> extends
     const { detail: peer } = evt
 
     if (peer.id.toString() === this.peerId.toString()) {
-      log.error(new Error(codes.ERR_DISCOVERED_SELF))
+      this.#log.error(new Error(codes.ERR_DISCOVERED_SELF))
       return
     }
 
     void this.components.peerStore.merge(peer.id, {
       multiaddrs: peer.multiaddrs,
       protocols: peer.protocols
     })
-      .catch(err => { log.error(err) })
+      .catch(err => { this.#log.error(err) })
   }
 }
 

packages/logger/src/index.ts

@@ -1,9 +1,8 @@
 /**
  * @packageDocumentation
  *
- * A map that reports it's size to the libp2p [Metrics](https://github.com/libp2p/js-libp2p-interfaces/tree/master/packages/libp2p-interfaces/src/metrics#readme) system.
- *
- * If metrics are disabled a regular map is used.
+ * A logger for libp2p based on the venerable [debug](https://www.npmjs.com/package/debug)
+ * module.
  *
  * @example
  *
@@ -80,6 +79,10 @@ export interface Logger {
   enabled: boolean
 }
 
+export interface PeerLogger {
+  forComponent(name: string): Logger
+}
+
 function createDisabledLogger (namespace: string): debug.Debugger {
   const logger = (): void => {}
   logger.enabled = false
@@ -93,6 +96,58 @@ function createDisabledLogger (namespace: string): debug.Debugger {
   return logger
 }
 
+export interface PeerLoggerOptions {
+  prefixLength: number
+  suffixLength: number
+}
+
+/**
+ * Create a peer logger that will prefix any log messages with a truncated peer
+ * id.
+ *
+ * @example
+ *
+ * ```js
+ * import { peerLogger } from '@libp2p/logger'
+ * import { peerIdFromString } from '@libp2p/peer-id'
+ *
+ * const peerId = peerIdFromString('12D3FooBar')
+ * const logger = peerLogger(peerId)
+ *
+ * const log = logger.forComponent('my-component')
+ * log.info('hello world')
+ * // logs "12D3…oBar:my-component hello world"
+ * ```
+ */
+export function peerLogger (peerIdOrString: PeerId, options: Partial<PeerLoggerOptions> = {}): PeerLogger {
+  const prefixLength = options.prefixLength ?? 2
+  const suffixLength = options.suffixLength ?? 4
+
+  const peerIdString = peerIdOrString.toString()
+  const prefix = `${peerIdString.substring(0, prefixLength)}…${peerIdString.substring(peerIdString.length, peerIdString.length - suffixLength)}`
+
+  const peerLogger: PeerLogger = {
+    forComponent (name: string) {
+      return logger(`${prefix}:${name}`)
+    }
+  }
+
+  return peerLogger
+}
+
+/**
+ * Creates a logger for the passed component name.
+ *
+ * @example
+ *
+ * ```js
+ * import { logger } from '@libp2p/logger'
+ *
+ * const log = logger('my-component')
+ * log.info('hello world')
+ * // logs "my-component hello world"
+ * ```
+ */
 export function logger (name: string): Logger {
   // trace logging is a no-op by default
   let trace: debug.Debugger = createDisabledLogger(`${name}:trace`)

packages/logger/test/index.spec.ts

@@ -9,7 +9,7 @@ import { base64 } from 'multiformats/bases/base64'
 import sinon from 'sinon'
 import { fromString as uint8ArrayFromString } from 'uint8arrays/from-string'
 import { toString as unint8ArrayToString } from 'uint8arrays/to-string'
-import { logger } from '../src/index.js'
+import { logger, peerLogger } from '../src/index.js'
 
 describe('logger', () => {
   it('creates a logger', () => {
@@ -23,6 +23,19 @@ describe('logger', () => {
     expect(log).to.have.nested.property('trace.enabled').that.is.not.true()
   })
 
+  it('creates a peer logger', () => {
+    const peerId = peerIdFromString('12D3KooWLkHeUp6r5unBZKbYwV54CgKVxHuJDroFoigr8mF11CKW')
+    const logger = peerLogger(peerId)
+    const log = logger.forComponent('hello')
+
+    expect(log).to.be.a('function')
+    expect(log).to.a.property('enabled').that.is.not.true()
+    expect(log).to.have.property('error').that.is.a('function')
+    expect(log).to.have.nested.property('error.enabled').that.is.not.true()
+    expect(log).to.have.property('trace').that.is.a('function')
+    expect(log).to.have.nested.property('trace.enabled').that.is.not.true()
+  })
+
   it('creates a logger with logging enabled', () => {
     debug.enable('enabled-logger')