Skip to content

Commit 4db427d

Browse files
lodekeeperdozyio
andauthored
fix(metrics): avoid consuming protocol frames before app readers (libp2p#3394)
* fix(metrics): avoid consuming protocol frames before app readers --------- Co-authored-by: lodekeeper <lodekeeper@users.noreply.github.com> Co-authored-by: dozyio <37986489+dozyio@users.noreply.github.com>
1 parent 9f89098 commit 4db427d

4 files changed

Lines changed: 106 additions & 9 deletions

File tree

packages/metrics-opentelemetry/src/index.ts

Lines changed: 15 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -152,9 +152,21 @@ class OpenTelemetryMetrics implements Metrics {
152152
* in and out
153153
*/
154154
_track (stream: MessageStream, name: string): void {
155-
stream.addEventListener('message', (evt) => {
156-
this._incrementValue(`${name} received`, evt.data.byteLength)
157-
})
155+
// AbstractMessageStream dispatches buffered inbound data only when there is
156+
// at least one `message` listener. Adding a metrics listener too early can
157+
// consume the read buffer before protocol handlers attach their own readers
158+
// (e.g. identify), causing lost first frames.
159+
//
160+
// Instead, wrap dispatchEvent to observe already-dispatched message events
161+
// without increasing listenerCount('message').
162+
const dispatchEvent = stream.dispatchEvent.bind(stream)
163+
stream.dispatchEvent = (evt: Event): boolean => {
164+
if (evt.type === 'message') {
165+
this._incrementValue(`${name} received`, (evt as MessageEvent<{ byteLength: number }>).data.byteLength)
166+
}
167+
168+
return dispatchEvent(evt)
169+
}
158170

159171
const send = stream.send.bind(stream)
160172
stream.send = (buf) => {

packages/metrics-prometheus/src/index.ts

Lines changed: 17 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -236,9 +236,23 @@ class PrometheusMetrics implements Metrics {
236236
* in and out
237237
*/
238238
_track (stream: MessageStream, name: string): void {
239-
stream.addEventListener('message', (evt) => {
240-
this._incrementValue(`${name} received`, evt.data.byteLength)
241-
})
239+
// Do not attach a `message` listener here.
240+
//
241+
// AbstractMessageStream dispatches buffered inbound data only when there is
242+
// at least one `message` listener. Adding a metrics listener too early can
243+
// cause the read buffer to be consumed before protocol handlers attach their
244+
// own readers (e.g. identify), leading to lost first frames.
245+
//
246+
// Instead, wrap dispatchEvent to observe already-dispatched message events
247+
// without increasing listenerCount('message').
248+
const dispatchEvent = stream.dispatchEvent.bind(stream)
249+
stream.dispatchEvent = (evt: Event): boolean => {
250+
if (evt.type === 'message') {
251+
this._incrementValue(`${name} received`, (evt as MessageEvent<{ byteLength: number }>).data.byteLength)
252+
}
253+
254+
return dispatchEvent(evt)
255+
}
242256

243257
const send = stream.send.bind(stream)
244258
stream.send = (buf) => {

packages/metrics-prometheus/test/streams.spec.ts

Lines changed: 59 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -40,10 +40,21 @@ describe('streams', () => {
4040
// track incoming stream
4141
metrics.trackMultiaddrConnection(outbound)
4242

43+
// attach reader before data arrives so the stream dispatches message events
44+
const iterator = outbound[Symbol.asyncIterator]()
45+
4346
// send data to the remote over the tracked stream
4447
const data = Uint8Array.from([0, 1, 2, 3, 4])
4548
inbound.send(data)
4649

50+
const first = await Promise.race([
51+
iterator.next(),
52+
new Promise<never>((_resolve, reject) => setTimeout(() => reject(new Error('timed out waiting for first frame')), 200))
53+
])
54+
55+
expect(first.done).to.equal(false)
56+
expect(first.value?.byteLength).to.equal(data.length)
57+
4758
await Promise.all([
4859
pEvent(inbound, 'close'),
4960
outbound.close(),
@@ -78,6 +89,43 @@ describe('streams', () => {
7889
expect(scrapedMetrics).to.include(`libp2p_data_transfer_bytes_total{protocol="${outbound.protocol} sent"} ${data.length}`)
7990
})
8091

92+
it('should not consume early protocol data before app listeners are attached', async () => {
93+
const [outbound, inbound] = await streamPair()
94+
95+
const metrics = prometheusMetrics()({
96+
logger: defaultLogger()
97+
})
98+
99+
// Track stream before any app-level reader/listener is attached
100+
metrics.trackProtocolStream(outbound)
101+
102+
// Remote sends data first
103+
const data = Uint8Array.from([9, 8, 7, 6, 5])
104+
inbound.send(data)
105+
106+
// Allow data to arrive and be buffered
107+
await new Promise((resolve) => setTimeout(resolve, 25))
108+
109+
// App starts reading later - should still receive first frame
110+
const iterator = outbound[Symbol.asyncIterator]()
111+
const first = await Promise.race([
112+
iterator.next(),
113+
new Promise<never>((_resolve, reject) => setTimeout(() => reject(new Error('timed out waiting for first frame')), 200))
114+
])
115+
116+
expect(first.done).to.equal(false)
117+
expect(first.value?.byteLength).to.equal(data.length)
118+
119+
await Promise.all([
120+
pEvent(inbound, 'close'),
121+
outbound.close(),
122+
inbound.close()
123+
])
124+
125+
const scrapedMetrics = await client.register.metrics()
126+
expect(scrapedMetrics).to.include(`libp2p_data_transfer_bytes_total{protocol="${inbound.protocol} received"} ${data.length}`)
127+
})
128+
81129
it('should track bytes received over outbound streams', async () => {
82130
const [outbound, inbound] = await streamPair()
83131

@@ -88,10 +136,21 @@ describe('streams', () => {
88136
// track incoming stream
89137
metrics.trackProtocolStream(outbound)
90138

139+
// attach reader before data arrives so the stream dispatches message events
140+
const iterator = outbound[Symbol.asyncIterator]()
141+
91142
// send data from remote to local
92143
const data = Uint8Array.from([0, 1, 2, 3, 4])
93144
inbound.send(data)
94145

146+
const first = await Promise.race([
147+
iterator.next(),
148+
new Promise<never>((_resolve, reject) => setTimeout(() => reject(new Error('timed out waiting for first frame')), 200))
149+
])
150+
151+
expect(first.done).to.equal(false)
152+
expect(first.value?.byteLength).to.equal(data.length)
153+
95154
await Promise.all([
96155
pEvent(inbound, 'close'),
97156
outbound.close(),

packages/metrics-simple/src/index.ts

Lines changed: 15 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -416,9 +416,21 @@ class SimpleMetrics implements Metrics, Startable {
416416
* in and out
417417
*/
418418
_track (stream: MessageStream, name: string): void {
419-
stream.addEventListener('message', (evt) => {
420-
this._incrementValue(`${name} received`, evt.data.byteLength)
421-
})
419+
// AbstractMessageStream dispatches buffered inbound data only when there is
420+
// at least one `message` listener. Adding a metrics listener too early can
421+
// consume the read buffer before protocol handlers attach their own readers
422+
// (e.g. identify), causing lost first frames.
423+
//
424+
// Instead, wrap dispatchEvent to observe already-dispatched message events
425+
// without increasing listenerCount('message').
426+
const dispatchEvent = stream.dispatchEvent.bind(stream)
427+
stream.dispatchEvent = (evt: Event): boolean => {
428+
if (evt.type === 'message') {
429+
this._incrementValue(`${name} received`, (evt as MessageEvent<{ byteLength: number }>).data.byteLength)
430+
}
431+
432+
return dispatchEvent(evt)
433+
}
422434

423435
const send = stream.send.bind(stream)
424436
stream.send = (buf) => {

0 commit comments

Comments
 (0)