add request duration metadata to network breadcrumbs

[yousif-bugsnag]

Goal

Adds a new metadata field duration to network breadcrumbs for JS and Electron - this is the elapsed time in milliseconds between the request start and completion or error

Design

• plugin-network-breadcrumbs

  • For XMLHttpRequest :
    • Override request object's send method in order to record the start time of the request, and get the duration in milliseconds when handleXHRLoad / handleXHRError are invoked
  • For fetch:
    • Record start of request when calling native fetch and get the duration in milliseconds whenhandleFetchSuccess / handleFetchError are invoked

• plugin-electron-net-breadcrumbs

  • Override request object's request.end method in order to record the start time of the request, and get the duration in milliseconds when the request / abort / error handlers are invoked

Testing

• Unit tests:

  • Extended existing unit tests to check for new metadata field

• e2e tests

  • Extended existing e2e tests to check for new metadata field
  • Added basic e2e tests for network breadcrumbs on Electron

[github-actions]

@bugsnag/browser bundle size diff

	Minified	Minfied + Gzipped
Before	43.90 kB	13.42 kB
After	44.11 kB	13.47 kB
±	⚠️ +208 bytes	⚠️ +51 bytes

code coverage diff

<temporarily disabled>

Generated by 🚫 dangerJS against 07fa693

[gingerbenw]

we save the requestStart date on request.end? if that's correct I think a comment here would be nice

[yousif-bugsnag]

Aah this is a good point actually - if the request is using chunked encoding that would only be the duration of the final chunk that was sent. Maybe it's better to set requestStart on the first write operation instead, or do something like this (cc @imjoehaines):

Suggested change

	request.end = (...args) => {
	requestStart = new Date()
	originalEnd.apply(request, args)
	}
	let requestStart
	// For chunked requests the request begins when the first chunk is written,
	// otherwise the request begins when the last chunk is written
	const originalWrite = request.write
	request.write = (...args) => {
	if (request.chunkedEncoding && !requestStart) requestStart = new Date()
	originalWrite.apply(request, args)
	}
	const originalEnd = request.end
	request.end = (...args) => {
	if (!requestStart) requestStart = new Date()
	originalEnd.apply(request, args)
	}

[imjoehaines]

request.end is what finalises the request, i.e. it makes sure that everything is actually sent. This is still a good point though — request.write can start the process of sending the request:

The first write operation may cause the request headers to be issued on the wire
https://www.electronjs.org/docs/latest/api/client-request#requestwritechunk-encoding-callback

So only using request.end means the duration may be wrong if we want to capture the duration from the point the request actually starts being sent — I doubt it will make a different most of the time in a real app TBH, especially with Date only having millisecond precision, but if there's a large request body it could take a non-trivial amount of time from writing it to the request with request.write and finishing the request with request.end

Maybe we need to use both request.write & request.end, recording the start time from whichever is called first? You have to call request.end but don't necessarily have to call request.write, so we can't just use request.write

[imjoehaines]

Replied at the same time as you @yousif-bugsnag!

What you suggested LGTM if it's only when using chunked encoding that write can start the request. Electron's docs aren't that specific so I'm not sure if there are other cases where write can start sending the request?

Edit: looks like write does only start sending when using chunked encoding: https://github.com/electron/electron/blob/ca3145a54716d864c2487f239f6ebd44989bb7ff/lib/browser/api/net.ts#L164

[yousif-bugsnag]

Cool, yep, looks that way - I've been doing some manual testing with a local http server and that tallies up with what I've observed (the connection is established on write only when request.chunkedEncoding = true)

Although looks like I could have just read the source! 😅

[yousif-bugsnag]

I've added some unit tests for the new duration logic but was finding that the unit tests for plugin-electron-net-breadcrumbs started flaking heavily again so I've reverted the previous change to reinstate these and updated the PR comment accordingly