Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add otel span for client component loading #62296

Merged
merged 4 commits into from
Feb 20, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
63 changes: 60 additions & 3 deletions packages/next/src/server/app-render/app-render.tsx
Original file line number Diff line number Diff line change
Expand Up @@ -51,7 +51,7 @@ import {
getRedirectStatusCodeFromError,
} from '../../client/components/redirect'
import { addImplicitTags } from '../lib/patch-fetch'
import { AppRenderSpan } from '../lib/trace/constants'
import { AppRenderSpan, NextNodeServerSpan } from '../lib/trace/constants'
import { getTracer } from '../lib/trace/tracer'
import { FlightRenderResult } from './flight-render-result'
import {
Expand Down Expand Up @@ -615,14 +615,71 @@ async function renderToHTMLOrFlightImpl(
enableTainting,
} = renderOpts

// Combined load times for loading client components
let clientComponentLoadStart = 0
let clientComponentLoadTimes = 0
let clientComponentLoadCount = 0

// We need to expose the bundled `require` API globally for
// react-server-dom-webpack. This is a hack until we find a better way.
if (ComponentMod.__next_app__) {
// @ts-ignore
globalThis.__next_require__ = ComponentMod.__next_app__.require
globalThis.__next_require__ = (...args: any[]) => {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do you know if this recursive? Or only top-level? If recursive - we need to expect 100s to 1000s of calls here.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yea should be ok as we're only tracking the total sum and not each individual call

if (clientComponentLoadStart === 0) {
clientComponentLoadStart = Date.now()
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why not performance.now()?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe there can be gaps in the timeline?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just followed prior art of Date.now() being used in lib/trace/tracer

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok. Let's follow then what they do.

}

const startTime = Date.now()
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One assumption that we are making here is that all of these require times are sequential. Is that true? Otherwise we will get bigger values than that it actually takes.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The span time time should be the duration of the sum of individual load times even if spread out over time

try {
clientComponentLoadCount += 1
return ComponentMod.__next_app__.require(...args)
} finally {
clientComponentLoadTimes += Date.now() - startTime
}
}

// @ts-ignore
globalThis.__next_chunk_load__ = ComponentMod.__next_app__.loadChunk
globalThis.__next_chunk_load__ = (...args: any[]) => {
const startTime = Date.now()
try {
clientComponentLoadCount += 1
return ComponentMod.__next_app__.loadChunk(...args)
} finally {
clientComponentLoadTimes += Date.now() - startTime
}
}
}

if (typeof req.on === 'function') {
req.on('end', () => {
const type = NextNodeServerSpan.clientComponentLoading
const startTime = clientComponentLoadStart
const endTime = clientComponentLoadStart + clientComponentLoadTimes
getTracer()
.startSpan(type, {
startTime,
attributes: {
'next.clientComponentLoadCount': clientComponentLoadCount,
},
})
.end(endTime)

if (
typeof performance !== 'undefined' &&
process.env.NEXT_OTEL_PERFORMANCE_PREFIX
) {
const { timeOrigin } = performance
performance.measure(
`${process.env.NEXT_OTEL_PERFORMANCE_PREFIX}:next-${(
type.split('.').pop() || ''
).replace(/[A-Z]/g, (match: string) => '-' + match.toLowerCase())}`,
{
start: startTime - timeOrigin,
end: endTime - timeOrigin,
}
)
}
})
}

const metadata: AppPageRenderResultMetadata = {}
Expand Down
3 changes: 3 additions & 0 deletions packages/next/src/server/lib/trace/constants.ts
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@ enum NextNodeServerSpan {
compression = 'NextNodeServer.compression',
getBuildId = 'NextNodeServer.getBuildId',
createComponentTree = 'NextNodeServer.createComponentTree',
clientComponentLoading = 'NextNodeServer.clientComponentLoading',
getLayoutOrPageModule = 'NextNodeServer.getLayoutOrPageModule',
generateStaticRoutes = 'NextNodeServer.generateStaticRoutes',
generateFsStaticRoutes = 'NextNodeServer.generateFsStaticRoutes',
Expand Down Expand Up @@ -134,13 +135,15 @@ export const NextVanillaSpanAllowlist = [
NextNodeServerSpan.findPageComponents,
NextNodeServerSpan.getLayoutOrPageModule,
NextNodeServerSpan.startResponse,
NextNodeServerSpan.clientComponentLoading,
]

// These Spans are allowed to be always logged
// when the otel log prefix env is set
export const LogSpanAllowList = [
NextNodeServerSpan.findPageComponents,
NextNodeServerSpan.createComponentTree,
NextNodeServerSpan.clientComponentLoading,
]

export {
Expand Down
1 change: 1 addition & 0 deletions packages/next/src/server/lib/trace/tracer.ts
Original file line number Diff line number Diff line change
Expand Up @@ -144,6 +144,7 @@ type NextAttributeNames =
| 'next.segment'
| 'next.span_name'
| 'next.span_type'
| 'next.clientComponentLoadCount'
type OTELAttributeNames = `http.${string}` | `net.${string}`
type AttributeNames = NextAttributeNames | OTELAttributeNames

Expand Down
13 changes: 13 additions & 0 deletions test/e2e/opentelemetry/opentelemetry.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -162,6 +162,16 @@ createNextDescribe(
kind: 0,
status: { code: 0 },
},
{
attributes: {
'next.clientComponentLoadCount': 4,
},
kind: 0,
name: 'NextNodeServer.clientComponentLoading',
status: {
code: 0,
},
},
{
name: 'start response',
attributes: {
Expand Down Expand Up @@ -771,6 +781,9 @@ createNextDescribe(
{
name: 'generateMetadata /app/[param]/rsc-fetch/page',
},
{
name: 'NextNodeServer.clientComponentLoading',
},
{
name: 'start response',
},
Expand Down