Skip to content

Commit

Permalink
feat: add component logger (#2198)
Browse files Browse the repository at this point in the history
Adds a `ComponentLogger` to `@libp2p/logger` with implementations that
prefixes all log messages with a truncated peer id or an arbitrary
string.

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
  • Loading branch information
achingbrain authored Nov 7, 2023
1 parent 4f2a41d commit fb8a6f1
Show file tree
Hide file tree
Showing 22 changed files with 407 additions and 229 deletions.
26 changes: 26 additions & 0 deletions packages/interface/src/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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 ComponentLogger {
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.
Expand Down Expand Up @@ -408,6 +425,8 @@ export interface Libp2p<T extends ServiceMap = ServiceMap> extends Startable, Ty
*/
metrics?: Metrics

logger: ComponentLogger

/**
* Get a deduplicated list of peer advertising multiaddrs by concatenating
* the listen addresses used by transports with any configured
Expand Down Expand Up @@ -626,6 +645,13 @@ export interface AbortOptions {
signal?: AbortSignal
}

/**
* An object that contains a Logger as the `log` property.
*/
export interface LoggerOptions {
log: Logger
}

/**
* Returns a new type with all fields marked optional.
*
Expand Down
9 changes: 8 additions & 1 deletion packages/libp2p/src/components.ts
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
import { CodeError } from '@libp2p/interface/errors'
import { isStartable, type Startable } from '@libp2p/interface/startable'
import type { Libp2pEvents } from '@libp2p/interface'
import { defaultLogger } from '@libp2p/logger'
import type { Libp2pEvents, ComponentLogger } 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'
Expand All @@ -18,6 +19,7 @@ import type { Datastore } from 'interface-datastore'

export interface Components extends Record<string, any>, Startable {
peerId: PeerId
logger: ComponentLogger
events: TypedEventTarget<Libp2pEvents>
addressManager: AddressManager
peerStore: PeerStore
Expand All @@ -35,6 +37,7 @@ export interface Components extends Record<string, any>, Startable {

export interface ComponentsInit {
peerId?: PeerId
logger?: ComponentLogger
events?: TypedEventTarget<Libp2pEvents>
addressManager?: AddressManager
peerStore?: PeerStore
Expand All @@ -60,6 +63,10 @@ class DefaultComponents implements Startable {
for (const [key, value] of Object.entries(init)) {
this.components[key] = value
}

if (this.components.logger == null) {
this.components.logger = defaultLogger()
}
}

isStarted (): boolean {
Expand Down
44 changes: 22 additions & 22 deletions packages/libp2p/src/connection-manager/auto-dial.ts
Original file line number Diff line number Diff line change
@@ -1,16 +1,13 @@
import { logger } from '@libp2p/logger'
import { PeerMap, PeerSet } from '@libp2p/peer-collections'
import { toString as uint8ArrayToString } from 'uint8arrays/to-string'
import { PeerJobQueue } from '../utils/peer-job-queue.js'
import { AUTO_DIAL_CONCURRENCY, AUTO_DIAL_DISCOVERED_PEERS_DEBOUNCE, AUTO_DIAL_INTERVAL, AUTO_DIAL_MAX_QUEUE_LENGTH, AUTO_DIAL_PEER_RETRY_THRESHOLD, AUTO_DIAL_PRIORITY, LAST_DIAL_FAILURE_KEY, MIN_CONNECTIONS } from './constants.js'
import type { Libp2pEvents } from '@libp2p/interface'
import type { Libp2pEvents, Logger, ComponentLogger } from '@libp2p/interface'
import type { TypedEventTarget } from '@libp2p/interface/events'
import type { PeerStore } from '@libp2p/interface/peer-store'
import type { Startable } from '@libp2p/interface/startable'
import type { ConnectionManager } from '@libp2p/interface-internal/connection-manager'

const log = logger('libp2p:connection-manager:auto-dial')

interface AutoDialInit {
minConnections?: number
maxQueueLength?: number
Expand All @@ -25,6 +22,7 @@ interface AutoDialComponents {
connectionManager: ConnectionManager
peerStore: PeerStore
events: TypedEventTarget<Libp2pEvents>
logger: ComponentLogger
}

const defaultOptions = {
Expand All @@ -50,6 +48,7 @@ export class AutoDial implements Startable {
private autoDialInterval?: ReturnType<typeof setInterval>
private started: boolean
private running: boolean
readonly #log: Logger

/**
* Proactively tries to connect to known peers stored in the PeerStore.
Expand All @@ -65,20 +64,21 @@ export class AutoDial implements Startable {
this.autoDialMaxQueueLength = init.maxQueueLength ?? defaultOptions.maxQueueLength
this.autoDialPeerRetryThresholdMs = init.autoDialPeerRetryThreshold ?? defaultOptions.autoDialPeerRetryThreshold
this.autoDialDiscoveredPeersDebounce = init.autoDialDiscoveredPeersDebounce ?? defaultOptions.autoDialDiscoveredPeersDebounce
this.#log = components.logger.forComponent('libp2p:connection-manager:auto-dial')
this.started = false
this.running = false
this.queue = new PeerJobQueue({
concurrency: init.autoDialConcurrency ?? defaultOptions.autoDialConcurrency
})
this.queue.addListener('error', (err) => {
log.error('error during auto-dial', err)
this.#log.error('error during auto-dial', err)
})

// check the min connection limit whenever a peer disconnects
components.events.addEventListener('connection:close', () => {
this.autoDial()
.catch(err => {
log.error(err)
this.#log.error(err)
})
})

Expand All @@ -93,7 +93,7 @@ export class AutoDial implements Startable {
debounce = setTimeout(() => {
this.autoDial()
.catch(err => {
log.error(err)
this.#log.error(err)
})
}, this.autoDialDiscoveredPeersDebounce)
})
Expand All @@ -107,7 +107,7 @@ export class AutoDial implements Startable {
this.autoDialInterval = setTimeout(() => {
this.autoDial()
.catch(err => {
log.error('error while autodialing', err)
this.#log.error('error while autodialing', err)
})
}, this.autoDialIntervalMs)
this.started = true
Expand All @@ -116,7 +116,7 @@ export class AutoDial implements Startable {
afterStart (): void {
this.autoDial()
.catch(err => {
log.error('error while autodialing', err)
this.#log.error('error while autodialing', err)
})
}

Expand All @@ -139,24 +139,24 @@ export class AutoDial implements Startable {
// Already has enough connections
if (numConnections >= this.minConnections) {
if (this.minConnections > 0) {
log.trace('have enough connections %d/%d', numConnections, this.minConnections)
this.#log.trace('have enough connections %d/%d', numConnections, this.minConnections)
}
return
}

if (this.queue.size > this.autoDialMaxQueueLength) {
log('not enough connections %d/%d but auto dial queue is full', numConnections, this.minConnections)
this.#log('not enough connections %d/%d but auto dial queue is full', numConnections, this.minConnections)
return
}

if (this.running) {
log('not enough connections %d/%d - but skipping autodial as it is already running', numConnections, this.minConnections)
this.#log('not enough connections %d/%d - but skipping autodial as it is already running', numConnections, this.minConnections)
return
}

this.running = true

log('not enough connections %d/%d - will dial peers to increase the number of connections', numConnections, this.minConnections)
this.#log('not enough connections %d/%d - will dial peers to increase the number of connections', numConnections, this.minConnections)

const dialQueue = new PeerSet(
// @ts-expect-error boolean filter removes falsy peer IDs
Expand All @@ -172,25 +172,25 @@ export class AutoDial implements Startable {
(peer) => {
// Remove peers without addresses
if (peer.addresses.length === 0) {
log.trace('not autodialing %p because they have no addresses', peer.id)
this.#log.trace('not autodialing %p because they have no addresses', peer.id)
return false
}

// remove peers we are already connected to
if (connections.has(peer.id)) {
log.trace('not autodialing %p because they are already connected', peer.id)
this.#log.trace('not autodialing %p because they are already connected', peer.id)
return false
}

// remove peers we are already dialling
if (dialQueue.has(peer.id)) {
log.trace('not autodialing %p because they are already being dialed', peer.id)
this.#log.trace('not autodialing %p because they are already being dialed', peer.id)
return false
}

// remove peers already in the autodial queue
if (this.queue.hasJob(peer.id)) {
log.trace('not autodialing %p because they are already being autodialed', peer.id)
this.#log.trace('not autodialing %p because they are already being autodialed', peer.id)
return false
}

Expand Down Expand Up @@ -249,27 +249,27 @@ export class AutoDial implements Startable {
return Date.now() - lastDialFailureTimestamp > this.autoDialPeerRetryThresholdMs
})

log('selected %d/%d peers to dial', peersThatHaveNotFailed.length, peers.length)
this.#log('selected %d/%d peers to dial', peersThatHaveNotFailed.length, peers.length)

for (const peer of peersThatHaveNotFailed) {
this.queue.add(async () => {
const numConnections = this.connectionManager.getConnectionsMap().size

// Check to see if we still need to auto dial
if (numConnections >= this.minConnections) {
log('got enough connections now %d/%d', numConnections, this.minConnections)
this.#log('got enough connections now %d/%d', numConnections, this.minConnections)
this.queue.clear()
return
}

log('connecting to a peerStore stored peer %p', peer.id)
this.#log('connecting to a peerStore stored peer %p', peer.id)
await this.connectionManager.openConnection(peer.id, {
priority: this.autoDialPriority
})
}, {
peerId: peer.id
}).catch(err => {
log.error('could not connect to peerStore stored peer', err)
this.#log.error('could not connect to peerStore stored peer', err)
})
}

Expand All @@ -279,7 +279,7 @@ export class AutoDial implements Startable {
this.autoDialInterval = setTimeout(() => {
this.autoDial()
.catch(err => {
log.error('error while autodialing', err)
this.#log.error('error while autodialing', err)
})
}, this.autoDialIntervalMs)
}
Expand Down
20 changes: 10 additions & 10 deletions packages/libp2p/src/connection-manager/connection-pruner.ts
Original file line number Diff line number Diff line change
@@ -1,14 +1,11 @@
import { logger } from '@libp2p/logger'
import { PeerMap } from '@libp2p/peer-collections'
import { MAX_CONNECTIONS } from './constants.js'
import type { Libp2pEvents } from '@libp2p/interface'
import type { Libp2pEvents, Logger, ComponentLogger } from '@libp2p/interface'
import type { TypedEventTarget } from '@libp2p/interface/events'
import type { PeerStore } from '@libp2p/interface/peer-store'
import type { ConnectionManager } from '@libp2p/interface-internal/connection-manager'
import type { Multiaddr } from '@multiformats/multiaddr'

const log = logger('libp2p:connection-manager:connection-pruner')

interface ConnectionPrunerInit {
maxConnections?: number
allow?: Multiaddr[]
Expand All @@ -18,6 +15,7 @@ interface ConnectionPrunerComponents {
connectionManager: ConnectionManager
peerStore: PeerStore
events: TypedEventTarget<Libp2pEvents>
logger: ComponentLogger
}

const defaultOptions = {
Expand All @@ -34,19 +32,21 @@ export class ConnectionPruner {
private readonly peerStore: PeerStore
private readonly allow: Multiaddr[]
private readonly events: TypedEventTarget<Libp2pEvents>
readonly #log: Logger

constructor (components: ConnectionPrunerComponents, init: ConnectionPrunerInit = {}) {
this.maxConnections = init.maxConnections ?? defaultOptions.maxConnections
this.allow = init.allow ?? defaultOptions.allow
this.connectionManager = components.connectionManager
this.peerStore = components.peerStore
this.events = components.events
this.#log = components.logger.forComponent('libp2p:connection-manager:connection-pruner')

// check the max connection limit whenever a peer connects
components.events.addEventListener('connection:open', () => {
this.maybePruneConnections()
.catch(err => {
log.error(err)
this.#log.error(err)
})
})
}
Expand All @@ -60,12 +60,12 @@ export class ConnectionPruner {
const numConnections = connections.length
const toPrune = Math.max(numConnections - this.maxConnections, 0)

log('checking max connections limit %d/%d', numConnections, this.maxConnections)
this.#log('checking max connections limit %d/%d', numConnections, this.maxConnections)
if (numConnections <= this.maxConnections) {
return
}

log('max connections limit exceeded %d/%d, pruning %d connection(s)', numConnections, this.maxConnections, toPrune)
this.#log('max connections limit exceeded %d/%d, pruning %d connection(s)', numConnections, this.maxConnections, toPrune)
const peerValues = new PeerMap<number>()

// work out peer values
Expand All @@ -87,7 +87,7 @@ export class ConnectionPruner {
}, 0))
} catch (err: any) {
if (err.code !== 'ERR_NOT_FOUND') {
log.error('error loading peer tags', err)
this.#log.error('error loading peer tags', err)
}
}
}
Expand Down Expand Up @@ -124,7 +124,7 @@ export class ConnectionPruner {
const toClose = []

for (const connection of sortedConnections) {
log('too many connections open - closing a connection to %p', connection.remotePeer)
this.#log('too many connections open - closing a connection to %p', connection.remotePeer)
// check allow list
const connectionInAllowList = this.allow.some((ma) => {
return connection.remoteAddr.toString().startsWith(ma.toString())
Expand All @@ -146,7 +146,7 @@ export class ConnectionPruner {
try {
await connection.close()
} catch (err) {
log.error(err)
this.#log.error(err)
}
})
)
Expand Down
Loading

0 comments on commit fb8a6f1

Please sign in to comment.