fix: re-use helia's logger (#283)

Do not create top-level loggers for verified fetch components, instead
re-use the existing logger and create new scopes from it.

This lets us configure helia and verified fetch together.

Author: achingbrain

packages/verified-fetch/package.json

@@ -177,7 +177,6 @@
     "@ipld/dag-pb": "^4.1.5",
     "@libp2p/interface": "^3.0.0",
     "@libp2p/kad-dht": "^16.0.0",
-    "@libp2p/logger": "^6.0.0",
     "@libp2p/peer-id": "^6.0.0",
     "@libp2p/utils": "^7.0.5",
     "@libp2p/webrtc": "^6.0.0",
@@ -206,6 +205,7 @@
     "@helia/json": "^5.0.0",
     "@ipld/car": "^5.4.2",
     "@libp2p/crypto": "^5.1.3",
+    "@libp2p/logger": "^6.0.0",
     "@types/sinon": "^17.0.4",
     "aegir": "^47.0.24",
     "browser-readablestream-to-it": "^2.0.9",

packages/verified-fetch/src/plugins/plugin-base.ts

@@ -17,9 +17,10 @@ export abstract class BasePlugin implements VerifiedFetchPlugin {
   protected _log?: Logger
 
   get log (): Logger {
-    // instantiate the logger lazily because it depends on the id, which is not set until after the constructor is called
+    // instantiate the logger lazily because it depends on the id, which is not
+    // set until after the constructor is called
     if (this._log == null) {
-      this._log = this.pluginOptions.logger.forComponent(this.id)
+      this._log = this.pluginOptions.logger.newScope(this.id)
     }
     return this._log
   }

packages/verified-fetch/src/plugins/types.ts

@@ -4,7 +4,7 @@ import type { AcceptHeader } from '../utils/select-output-type.ts'
 import type { ServerTiming } from '../utils/server-timing.ts'
 import type { PathWalkerResponse } from '../utils/walk-path.js'
 import type { IPNSResolver } from '@helia/ipns'
-import type { AbortOptions, ComponentLogger, Logger } from '@libp2p/interface'
+import type { AbortOptions, Logger } from '@libp2p/interface'
 import type { Helia } from 'helia'
 import type { Blockstore } from 'interface-blockstore'
 import type { UnixFSEntry } from 'ipfs-unixfs-exporter'
@@ -17,7 +17,7 @@ import type { CustomProgressEvent } from 'progress-events'
  * - Persistent: Relevant even after the request completes (e.g., logging or metrics).
  */
 export interface PluginOptions {
-  logger: ComponentLogger
+  logger: Logger
   getBlockstore(cid: CID, resource: string | CID, useSession?: boolean, options?: AbortOptions): Blockstore
   contentTypeParser?: ContentTypeParser
   helia: Helia

packages/verified-fetch/src/utils/byte-range-context.ts

@@ -3,7 +3,7 @@ import { InvalidRangeError } from '../errors.js'
 import { calculateByteRangeIndexes, getHeader } from './request-headers.js'
 import { getContentRangeHeader } from './response-headers.js'
 import type { SupportedBodyTypes } from '../index.js'
-import type { ComponentLogger, Logger } from '@libp2p/interface'
+import type { Logger } from '@libp2p/interface'
 
 type SliceableBody = Exclude<SupportedBodyTypes, ReadableStream<Uint8Array> | null>
 
@@ -90,8 +90,8 @@ export class ByteRangeContext {
   // to be set by isValidRangeRequest so that we don't need to re-check the byteRanges
   private _isValidRangeRequest: boolean = false
 
-  constructor (logger: ComponentLogger, private readonly headers?: HeadersInit) {
-    this.log = logger.forComponent('helia:verified-fetch:byte-range-context')
+  constructor (logger: Logger, private readonly headers?: HeadersInit) {
+    this.log = logger.newScope('byte-range-context')
     this.rangeRequestHeader = getHeader(this.headers, 'Range')
 
     if (this.rangeRequestHeader != null) {

packages/verified-fetch/src/utils/content-type-parser.ts

@@ -1,28 +1,22 @@
-import { logger } from '@libp2p/logger'
 import { fileTypeFromBuffer } from 'file-type'
 
-const log = logger('helia:verified-fetch:content-type-parser')
-
 export const defaultMimeType = 'application/octet-stream'
 function checkForSvg (text: string): boolean {
-  log('checking for svg')
   return /^(<\?xml[^>]+>)?[^<^\w]+<svg/ig.test(text)
 }
 
 async function checkForJson (text: string): Promise<boolean> {
-  log('checking for json')
   try {
     JSON.parse(text)
     return true
   } catch (err) {
-    log('failed to parse as json', err)
     return false
   }
 }
 
 function getText (bytes: Uint8Array): string | null {
-  log('checking for text')
   const decoder = new TextDecoder('utf-8', { fatal: true })
+
   try {
     return decoder.decode(bytes)
   } catch (err) {
@@ -31,25 +25,24 @@ function getText (bytes: Uint8Array): string | null {
 }
 
 async function checkForHtml (text: string): Promise<boolean> {
-  log('checking for html')
   return /^\s*<(?:!doctype\s+html|html|head|body)\b/i.test(text)
 }
 
 export async function contentTypeParser (bytes: Uint8Array, fileName?: string): Promise<string> {
-  log('contentTypeParser called for fileName: %s, byte size=%s', fileName, bytes.length)
   const detectedType = (await fileTypeFromBuffer(bytes))?.mime
+
   if (detectedType != null) {
-    log('detectedType: %s', detectedType)
     if (detectedType === 'application/xml' && fileName?.toLowerCase().endsWith('.svg')) {
       return 'image/svg+xml'
     }
+
     return detectedType
   }
-  log('no detectedType')
 
   if (fileName == null) {
     // it's likely text... no other way to determine file-type.
     const text = getText(bytes)
+
     if (text != null) {
       // check for svg, json, html, or it's plain text.
       if (checkForSvg(text)) {
@@ -62,6 +55,7 @@ export async function contentTypeParser (bytes: Uint8Array, fileName?: string):
         return 'text/plain; charset=utf-8'
       }
     }
+
     return defaultMimeType
   }
 

packages/verified-fetch/src/utils/get-stream-from-async-iterable.ts

@@ -2,28 +2,18 @@ import { AbortError } from '@libp2p/interface'
 import { CustomProgressEvent } from 'progress-events'
 import { NoContentError } from '../errors.js'
 import type { VerifiedFetchInit } from '../index.js'
-import type { ComponentLogger } from '@libp2p/interface'
+import type { Logger } from '@libp2p/interface'
 
 /**
  * Converts an async iterator of Uint8Array bytes to a stream and returns the first chunk of bytes
  */
-export async function getStreamFromAsyncIterable (iterator: AsyncIterable<Uint8Array>, path: string, logger: ComponentLogger, options?: Pick<VerifiedFetchInit, 'onProgress' | 'signal'>): Promise<{ stream: ReadableStream<Uint8Array>, firstChunk: Uint8Array }> {
-  const log = logger.forComponent('helia:verified-fetch:get-stream-from-async-iterable')
+export async function getStreamFromAsyncIterable (iterator: AsyncIterable<Uint8Array>, path: string, logger: Logger, options?: Pick<VerifiedFetchInit, 'onProgress' | 'signal'>): Promise<{ stream: ReadableStream<Uint8Array>, firstChunk: Uint8Array }> {
+  const log = logger.newScope('get-stream-from-async-iterable')
   const reader = iterator[Symbol.asyncIterator]()
   const { value: firstChunk, done } = await reader.next()
 
   if (done === true) {
     log.error('no content found for path "%s"', path)
-    /*
-    return {
-      stream: new ReadableStream({
-        start (controller) {
-          controller.close()
-        }
-      }),
-      firstChunk: new Uint8Array()
-    }
-*/
     throw new NoContentError()
   }
 

packages/verified-fetch/src/utils/walk-path.ts

@@ -52,7 +52,7 @@ export function isObjectNode (node: UnixFSEntry): node is ObjectNode {
  */
 export async function handlePathWalking ({ cid, path, resource, options, blockstore, log }: PluginContext & { blockstore: Blockstore, log: Logger }): Promise<PathWalkerResponse | Response> {
   try {
-    return await walkPath(blockstore, `${cid.toString()}/${path}`, options)
+    return await walkPath(blockstore, `${cid}/${path}`, options)
   } catch (err: any) {
     if (options?.signal?.aborted) {
       throw new AbortError(options?.signal?.reason)

packages/verified-fetch/src/verified-fetch.ts

@@ -1,7 +1,6 @@
 import { dnsLink } from '@helia/dnslink'
 import { ipnsResolver } from '@helia/ipns'
 import { AbortError } from '@libp2p/interface'
-import { prefixLogger } from '@libp2p/logger'
 import { CustomProgressEvent } from 'progress-events'
 import QuickLRU from 'quick-lru'
 import { ByteRangeContextPlugin } from './plugins/plugin-handle-byte-range-context.js'
@@ -84,7 +83,7 @@ export class VerifiedFetch {
 
     const pluginOptions: PluginOptions = {
       ...init,
-      logger: prefixLogger('helia:verified-fetch'),
+      logger: helia.logger.forComponent('verified-fetch'),
       getBlockstore: (cid, resource, useSession, options) => this.getBlockstore(cid, resource, useSession, options),
       helia,
       contentTypeParser: this.contentTypeParser,
@@ -276,6 +275,8 @@ export class VerifiedFetch {
 
           const maybeResponse = await plugin.handle(context)
 
+          this.log('plugin response %s %o', plugin.id, maybeResponse)
+
           if (maybeResponse != null) {
             // if a plugin returns a final Response, short-circuit
             finalResponse = maybeResponse

packages/verified-fetch/test/get-stream-from-async-iterable.spec.ts

@@ -2,23 +2,26 @@ import { defaultLogger } from '@libp2p/logger'
 import { expect } from 'aegir/chai'
 import sinon from 'sinon'
 import { getStreamFromAsyncIterable } from '../src/utils/get-stream-from-async-iterable.js'
+import type { Logger } from '@libp2p/logger'
 
 describe('getStreamFromAsyncIterable', () => {
   let onProgressSpy: sinon.SinonSpy
+  let log: Logger
 
   beforeEach(() => {
     onProgressSpy = sinon.spy()
+    log = defaultLogger().forComponent('test')
   })
 
   it('should throw an error if no content is found', async () => {
     const iterator = (async function * () { })()
-    await expect(getStreamFromAsyncIterable(iterator, 'test', defaultLogger())).to.be.rejectedWith('No content found')
+    await expect(getStreamFromAsyncIterable(iterator, 'test', log)).to.be.rejectedWith('No content found')
   })
 
   it('should return the correct content type and a readable stream', async () => {
     const chunks = new TextEncoder().encode('Hello, world!')
     const iterator = (async function * () { yield chunks })()
-    const { firstChunk, stream } = await getStreamFromAsyncIterable(iterator, 'test.txt', defaultLogger(), { onProgress: onProgressSpy })
+    const { firstChunk, stream } = await getStreamFromAsyncIterable(iterator, 'test.txt', log, { onProgress: onProgressSpy })
     expect(firstChunk).to.equal(chunks)
     const reader = stream.getReader()
     const { value } = await reader.read()
@@ -30,7 +33,7 @@ describe('getStreamFromAsyncIterable', () => {
     const textEncoder = new TextEncoder()
     const chunks = ['Hello,', ' world!'].map((txt) => textEncoder.encode(txt))
     const iterator = (async function * () { yield chunks[0]; yield chunks[1] })()
-    const { firstChunk, stream } = await getStreamFromAsyncIterable(iterator, 'test.txt', defaultLogger(), { onProgress: onProgressSpy })
+    const { firstChunk, stream } = await getStreamFromAsyncIterable(iterator, 'test.txt', log, { onProgress: onProgressSpy })
     expect(firstChunk).to.equal(chunks[0])
     const reader = stream.getReader()
     let result = ''
@@ -59,7 +62,7 @@ describe('getStreamFromAsyncIterable', () => {
         }
       }
     }
-    const { firstChunk, stream } = await getStreamFromAsyncIterable(iterator, 'test.txt', defaultLogger(), { onProgress: onProgressSpy })
+    const { firstChunk, stream } = await getStreamFromAsyncIterable(iterator, 'test.txt', log, { onProgress: onProgressSpy })
     // @ts-expect-error - actualFirstChunk is not used before set, because the await above.
     expect(firstChunk).to.equal(actualFirstChunk)
     const reader = stream.getReader()

packages/verified-fetch/test/utils/byte-range-context.spec.ts

@@ -12,7 +12,7 @@ import type { Helia } from 'helia'
 import type { CID } from 'multiformats/cid'
 
 describe('ByteRangeContext', () => {
-  const logger = prefixLogger('test')
+  const logger = prefixLogger('test').forComponent('test')
 
   it('should correctly detect range request', () => {
     const context = new ByteRangeContext(logger, { Range: 'bytes=0-2' })
@@ -166,7 +166,7 @@ describe('ByteRangeContext', () => {
     let cid: CID
     const getBodyStream = async (offset?: number, length?: number): Promise<ReadableStream<Uint8Array>> => {
       const iter = fs.cat(cid, { offset, length })
-      const { stream } = await getStreamFromAsyncIterable(iter, 'test.txt', defaultLogger())
+      const { stream } = await getStreamFromAsyncIterable(iter, 'test.txt', defaultLogger().forComponent('test'))
       return stream
     }