Skip to content

Commit 56c36f7

Browse files
tsctxtsctx
committed
Adding diagnostics channels to Fetch
1 parent 78a0c24 commit 56c36f7

5 files changed

Lines changed: 277 additions & 2 deletions

File tree

‎docs/docs/api/DiagnosticsChannel.md‎

Lines changed: 57 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -202,3 +202,60 @@ diagnosticsChannel.channel('undici:websocket:pong').subscribe(({ payload }) => {
202202
console.log(payload)
203203
})
204204
```
205+
The below channels collectively act as [`tracingChannel.tracePromise`](https://nodejs.org/api/diagnostics_channel.html#tracingchanneltracepromisefn-context-thisarg-args) on `fetch`. So all of them will publish the arguments passed to `fetch`.
206+
207+
## `tracing:undici:fetch:start`
208+
209+
This message is published when `fetch` is called, and will publish the arguments passed to `fetch`.
210+
211+
```js
212+
import diagnosticsChannel from 'diagnostics_channel'
213+
diagnosticsChannel.channel('tracing:undici:fetch:start').subscribe(({ req, input, init, }) => {
214+
console.log('input', input)
215+
console.log('init', init)
216+
})
217+
```
218+
219+
## `tracing:undici:fetch:end`
220+
221+
This message is published at the end of `fetch`'s execution, and will publish any `error` from the synchronous part of `fetch`. Since `fetch` is asynchronous, this should be empty. This channel will publish the same values as `undici:fetch:start`, but we are including it to track when `fetch` finishes execution and to be consistent with [`TracingChannel`](https://nodejs.org/api/diagnostics_channel.html#class-tracingchannel).
222+
```js
223+
import diagnosticsChannel from 'diagnostics_channel'
224+
diagnosticsChannel.channel('tracing:undici:fetch:end').subscribe(({ req, input, init, error }) => {
225+
console.log('input', input)
226+
console.log('init', init)
227+
console.log('error', error) // should be empty
228+
})
229+
```
230+
## `tracing:undici:fetch:asyncStart`
231+
This message is published after `fetch` resolves or rejects. If `fetch` resolves, it publishes the response in `result`. If it rejects, it publishes the error in `error`.
232+
```js
233+
import diagnosticsChannel from 'diagnostics_channel'
234+
diagnosticsChannel.channel('tracing:undici:fetch:asyncStart').subscribe(({ req, input, init, result, error }) => {
235+
console.log('input', input)
236+
console.log('init', init)
237+
console.log('response', result)
238+
console.log('error', error)
239+
})
240+
```
241+
## `tracing:undici:fetch:asyncEnd`
242+
This channel gets published the same values as and at the same time as `tracing:undici:fetch:asyncStart` in the case of [`tracingChannel.tracePromise`](https://nodejs.org/api/diagnostics_channel.html#tracingchanneltracepromisefn-context-thisarg-args)
243+
```js
244+
import diagnosticsChannel from 'diagnostics_channel'
245+
diagnosticsChannel.channel('tracing:undici:fetch:asyncEnd').subscribe(({ req, input, init, result, error }) => {
246+
console.log('input', input)
247+
console.log('init', init)
248+
console.log('response', result)
249+
console.log('error', error)
250+
})
251+
```
252+
## `tracing:undici:fetch:error`
253+
This message is published when an error is thrown or promise rejects while calling `fetch`.
254+
```js
255+
import diagnosticsChannel from 'diagnostics_channel'
256+
diagnosticsChannel.channel('tracing:undici:fetch:error').subscribe(({ req, input, init, error }) => {
257+
console.log('input', input)
258+
console.log('init', init)
259+
console.log('error', error)
260+
})
261+
```

‎lib/core/diagnostics.js‎

Lines changed: 78 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,12 @@ const undiciDebugLog = util.debuglog('undici')
66
const fetchDebuglog = util.debuglog('fetch')
77
const websocketDebuglog = util.debuglog('websocket')
88
let isClientSet = false
9+
let tracingChannel
10+
11+
if (diagnosticsChannel.tracingChannel) {
12+
tracingChannel = diagnosticsChannel.tracingChannel('undici:fetch')
13+
}
14+
915
const channels = {
1016
// Client
1117
beforeConnect: diagnosticsChannel.channel('undici:client:beforeConnect'),
@@ -23,7 +29,9 @@ const channels = {
2329
close: diagnosticsChannel.channel('undici:websocket:close'),
2430
socketError: diagnosticsChannel.channel('undici:websocket:socket_error'),
2531
ping: diagnosticsChannel.channel('undici:websocket:ping'),
26-
pong: diagnosticsChannel.channel('undici:websocket:pong')
32+
pong: diagnosticsChannel.channel('undici:websocket:pong'),
33+
// Fetch channels
34+
tracingChannel
2735
}
2836

2937
if (undiciDebugLog.enabled || fetchDebuglog.enabled) {
@@ -114,6 +122,75 @@ if (undiciDebugLog.enabled || fetchDebuglog.enabled) {
114122
isClientSet = true
115123
}
116124

125+
// Track fetch requests
126+
if (fetchDebuglog.enabled && diagnosticsChannel.tracingChannel) {
127+
const debuglog = fetchDebuglog
128+
129+
tracingChannel.start.subscribe(evt => {
130+
const {
131+
input
132+
} = evt
133+
debuglog(
134+
'fetch has started request to %s',
135+
input
136+
)
137+
})
138+
139+
tracingChannel.end.subscribe(evt => {
140+
const {
141+
input
142+
} = evt
143+
debuglog(
144+
'fetch has received response from %s',
145+
input
146+
)
147+
})
148+
149+
tracingChannel.asyncStart.subscribe(evt => {
150+
const {
151+
input,
152+
result,
153+
error
154+
} = evt
155+
if (result && error) {
156+
debuglog(
157+
'fetch has received response for %s - HTTP %d, error is %s',
158+
input,
159+
result.status,
160+
error.message
161+
)
162+
} else if (result) {
163+
debuglog(
164+
'fetch has received response for %s - HTTP %d',
165+
input,
166+
result.status
167+
)
168+
} else if (error) {
169+
debuglog(
170+
'fetch has errored for %s - %s',
171+
input,
172+
error.message
173+
)
174+
} else {
175+
debuglog(
176+
'fetch has started request to %s',
177+
input
178+
)
179+
}
180+
})
181+
182+
tracingChannel.error.subscribe(evt => {
183+
const {
184+
error
185+
} = evt
186+
debuglog(
187+
'fetch error event received response %s',
188+
error.message
189+
)
190+
})
191+
isClientSet = true
192+
}
193+
117194
if (websocketDebuglog.enabled) {
118195
if (!isClientSet) {
119196
const debuglog = undiciDebugLog.enabled ? undiciDebugLog : websocketDebuglog

‎lib/web/fetch/index.js‎

Lines changed: 32 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -70,6 +70,7 @@ const defaultUserAgent = typeof __UNDICI_IS_NODE__ !== 'undefined' || typeof esb
7070
? 'node'
7171
: 'undici'
7272

73+
const channels = require('../../core/diagnostics.js').channels.tracingChannel
7374
/** @type {import('buffer').resolveObjectURL} */
7475
let resolveObjectURL
7576

@@ -124,6 +125,16 @@ function handleFetchDone (response) {
124125
finalizeAndReportTiming(response, 'fetch')
125126
}
126127

128+
// subscribersCheck will be called at the beginning of the fetch call
129+
// and will check if we have subscribers
130+
function subscribersCheck () {
131+
return channels && (channels.start.hasSubscribers ||
132+
channels.end.hasSubscribers ||
133+
channels.asyncStart.hasSubscribers ||
134+
channels.asyncEnd.hasSubscribers ||
135+
channels.error.hasSubscribers)
136+
}
137+
127138
// https://fetch.spec.whatwg.org/#fetch-method
128139
function fetch (input, init = undefined) {
129140
webidl.argumentLengthCheck(arguments, 1, 'globalThis.fetch')
@@ -143,6 +154,27 @@ function fetch (input, init = undefined) {
143154
return p.promise
144155
}
145156

157+
// This will publish all diagnostic events only when we have subscribers.
158+
if (subscribersCheck()) {
159+
const context = { req: requestObject, input, init, result: null, error: null }
160+
const { resolve, reject } = p
161+
p.resolve = function (result) {
162+
context.result = result
163+
channels.asyncStart.publish(context)
164+
channels.asyncEnd.publish(context)
165+
resolve(result)
166+
}
167+
p.reject = function (error) {
168+
context.error = error
169+
channels.error.publish(context)
170+
channels.asyncStart.publish(context)
171+
channels.asyncEnd.publish(context)
172+
reject(error)
173+
}
174+
channels.start.publish(context)
175+
queueMicrotask(() => { channels.end.publish(context) })
176+
}
177+
146178
// 3. Let request be requestObject’s request.
147179
const request = requestObject[kState]
148180

‎test/node-test/debug.js‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -45,7 +45,7 @@ test('debug#websocket', { skip: !process.versions.icu }, async t => {
4545
})
4646

4747
test('debug#fetch', async t => {
48-
const assert = tspl(t, { plan: 7 })
48+
const assert = tspl(t, { plan: 10 })
4949
const child = spawn(
5050
process.execPath,
5151
[join(__dirname, '../fixtures/fetch.js')],
@@ -55,11 +55,14 @@ test('debug#fetch', async t => {
5555
)
5656
const chunks = []
5757
const assertions = [
58+
/(FETCH [0-9]+:) (fetch has started)/,
5859
/(FETCH [0-9]+:) (connecting to)/,
60+
/(FETCH [0-9]+:) (fetch has received)/,
5961
/(FETCH [0-9]+:) (connected to)/,
6062
/(FETCH [0-9]+:) (sending request)/,
6163
/(FETCH [0-9]+:) (received response)/,
6264
/(FETCH [0-9]+:) (trailers received)/,
65+
/(FETCH [0-9]+:) (fetch has received)/,
6366
/^$/
6467
]
6568

‎test/node-test/diagnostics-channel/fetch.js‎

Lines changed: 106 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,106 @@
1+
'use strict'
2+
3+
const { tspl } = require('@matteo.collina/tspl')
4+
const { describe, test, before, after } = require('node:test')
5+
const { fetch } = require('../../..')
6+
7+
let diagnosticsChannel
8+
let skip = false
9+
try {
10+
diagnosticsChannel = require('node:diagnostics_channel')
11+
} catch {
12+
skip = true
13+
}
14+
15+
const { createServer } = require('http')
16+
17+
describe('diagnosticsChannel for fetch', { skip }, () => {
18+
let server
19+
before(() => {
20+
server = createServer((req, res) => {
21+
res.setHeader('Content-Type', 'text/plain')
22+
res.setHeader('trailer', 'foo')
23+
res.write('hello')
24+
res.addTrailers({
25+
foo: 'oof'
26+
})
27+
res.end()
28+
})
29+
})
30+
31+
after(() => { server.close() })
32+
33+
test('fetch', async t => {
34+
t = tspl(t, { plan: 17 })
35+
36+
let startCalled = 0
37+
diagnosticsChannel.channel('tracing:undici:fetch:start').subscribe(({ req, input, init, result, error }) => {
38+
startCalled += 1
39+
if (input.redirect) {
40+
t.strictEqual(input, 'badrequest')
41+
t.deepStrictEqual(init, { redirect: 'error' })
42+
} else {
43+
t.strictEqual(input, `http://localhost:${server.address().port}`)
44+
t.deepStrictEqual(init, undefined)
45+
}
46+
})
47+
48+
let endCalled = 0
49+
diagnosticsChannel.channel('tracing:undici:fetch:end').subscribe(({ req, input, init, result, error }) => {
50+
endCalled += 1
51+
if (init && init.redirect) {
52+
t.strictEqual(input, 'badrequest')
53+
t.deepStrictEqual(init, { redirect: 'error' })
54+
} else {
55+
t.strictEqual(input, `http://localhost:${server.address().port}`)
56+
t.deepStrictEqual(init, undefined)
57+
}
58+
t.strictEqual(result, null)
59+
})
60+
61+
let asyncStartCalled = 0
62+
diagnosticsChannel.channel('tracing:undici:fetch:asyncStart').subscribe(({ req, input, init, result, error }) => {
63+
asyncStartCalled += 1
64+
if (init && init.redirect) {
65+
t.strictEqual(input, 'badrequest')
66+
t.deepStrictEqual(init, { redirect: 'error' })
67+
} else {
68+
t.strictEqual(input, `http://localhost:${server.address().port}`)
69+
t.deepStrictEqual(init, undefined)
70+
t.ok(result)
71+
}
72+
})
73+
74+
let asyncEndCalled = 0
75+
diagnosticsChannel.channel('tracing:undici:fetch:asyncEnd').subscribe(async ({ req, input, init, result, error }) => {
76+
asyncEndCalled += 1
77+
if (init && init.redirect) {
78+
t.strictEqual(input, 'badrequest')
79+
t.deepStrictEqual(init, { redirect: 'error' })
80+
t.strictEqual(result, null)
81+
t.ok(error)
82+
t.strictEqual(error.cause.code, 'ERR_INVALID_URL')
83+
} else {
84+
t.strictEqual(input, `http://localhost:${server.address().port}`)
85+
t.deepStrictEqual(init, undefined)
86+
t.ok(result)
87+
t.strictEqual(result.status, 200)
88+
t.strictEqual(error, null)
89+
}
90+
})
91+
92+
server.listen(0, async () => {
93+
await fetch(`http://localhost:${server.address().port}`)
94+
try {
95+
await fetch('badrequest', { redirect: 'error' })
96+
} catch (e) { }
97+
server.close()
98+
t.strictEqual(startCalled, 1)
99+
t.strictEqual(endCalled, 1)
100+
t.strictEqual(asyncStartCalled, 1)
101+
t.strictEqual(asyncEndCalled, 1)
102+
})
103+
104+
await t.completed
105+
})
106+
})

0 commit comments

Comments
 (0)