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

Fix navigation span start #1421

Merged
merged 10 commits into from
Sep 12, 2024
8 changes: 8 additions & 0 deletions common/frame_manager.go
Original file line number Diff line number Diff line change
Expand Up @@ -577,6 +577,14 @@ func (m *FrameManager) setMainFrame(f *Frame) {
m.mainFrame = f
}

// MainFrameURL returns the main frame's url.
func (m *FrameManager) MainFrameURL() string {
m.mainFrameMu.RLock()
defer m.mainFrameMu.RUnlock()

return m.mainFrame.URL()
}

// NavigateFrame will navigate specified frame to specified URL.
//
//nolint:funlen,cyclop
Expand Down
53 changes: 42 additions & 11 deletions common/frame_session.go
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,11 @@ type FrameSession struct {
// Keep a reference to the main frame span so we can end it
// when FrameSession.ctx is Done
mainFrameSpan trace.Span
// The initial navigation when a new page is created navigates to about:blank.
// We want to make sure that the the navigation span is created for this in
// onFrameNavigated, but subsequent calls to onFrameNavigated in the same
// mainframe never again create a navigation span.
initialNavDone bool
inancgumus marked this conversation as resolved.
Show resolved Hide resolved
}

// NewFrameSession initializes and returns a new FrameSession.
Expand Down Expand Up @@ -237,6 +242,11 @@ func (fs *FrameSession) initEvents() {
// If there is an active span for main frame,
// end it before exiting so it can be flushed
if fs.mainFrameSpan != nil {
// The url needs to be added here instead of at the start of the span
// because at the start of the span we don't know the correct url for
// the page we're navigating to. At the end of the span we do have this
// information.
fs.mainFrameSpan.SetAttributes(attribute.String("navigation.url", fs.manager.MainFrameURL()))
fs.mainFrameSpan.End()
fs.mainFrameSpan = nil
}
Expand Down Expand Up @@ -782,25 +792,44 @@ func (fs *FrameSession) onFrameNavigated(frame *cdp.Frame, initial bool) {
frame.URL+frame.URLFragment, err)
}

// Only create a navigation span once from here, since a new page navigating
// to about:blank doesn't call onFrameStartedLoading. All subsequent
// navigations call onFrameStartedLoading.
if fs.initialNavDone {
return
}

fs.initialNavDone = true
fs.processNavigationSpan(frame.ID)
}

func (fs *FrameSession) processNavigationSpan(id cdp.FrameID) {
newFrame, ok := fs.manager.getFrameByID(id)
if !ok {
return
}

// Trace navigation only for the main frame.
// TODO: How will this affect sub frames such as iframes?
if isMainFrame := frame.ParentID == ""; !isMainFrame {
if newFrame.page.frameManager.MainFrame() != newFrame {
return
}

// End the navigation span if it is non-nil
if fs.mainFrameSpan != nil {
// The url needs to be added here instead of at the start of the span
// because at the start of the span we don't know the correct url for
// the page we're navigating to. At the end of the span we do have this
// information.
fs.mainFrameSpan.SetAttributes(attribute.String("navigation.url", fs.manager.MainFrameURL()))
fs.mainFrameSpan.End()
}

_, fs.mainFrameSpan = TraceNavigation(
fs.ctx, fs.targetID.String(), trace.WithAttributes(attribute.String("navigation.url", frame.URL)),
fs.ctx, fs.targetID.String(),
)

var (
spanID = fs.mainFrameSpan.SpanContext().SpanID().String()
newFrame, ok = fs.manager.getFrameByID(frame.ID)
)

// Only set the k6SpanId reference if it's a new frame.
if !ok {
return
}
spanID := fs.mainFrameSpan.SpanContext().SpanID().String()

// Set k6SpanId property in the page so it can be retrieved when pushing
// the Web Vitals events from the page execution context and used to
Expand Down Expand Up @@ -844,6 +873,8 @@ func (fs *FrameSession) onFrameStartedLoading(frameID cdp.FrameID) {
"sid:%v tid:%v fid:%v",
fs.session.ID(), fs.targetID, frameID)

fs.processNavigationSpan(frameID)

fs.manager.frameLoadingStarted(frameID)
}

Expand Down
171 changes: 169 additions & 2 deletions tests/tracing_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ import (
"time"

"github.com/grafana/sobek"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"go.opentelemetry.io/otel/trace"
"go.opentelemetry.io/otel/trace/embedded"
Expand All @@ -30,6 +31,7 @@ const html = `
</head>

<body>
<a id="top" href="#bottom">Go to bottom</a>
<div class="main">
<h3>Click Counter</h3>
<button id="clickme">Click me: 0</button>
Expand All @@ -44,6 +46,7 @@ const html = `
button.innerHTML = "Click me: " + count;
};
</script>
<div id="bottom"></div>
</body>

</html>
Expand Down Expand Up @@ -158,6 +161,152 @@ func TestTracing(t *testing.T) {
}
}

// This test is testing to ensure that correct number of navigation spans are created
// and they are created in the correct order.
func TestNavigationSpanCreation(t *testing.T) {
t.Parallel()

// Init tracing mocks
tracer := &mockTracer{
spans: make(map[string]struct{}),
}
tp := &mockTracerProvider{
tracer: tracer,
}
// Start test server
ts := httptest.NewServer(http.HandlerFunc(
func(w http.ResponseWriter, r *http.Request) {
fmt.Fprint(w, html)
},
))
defer ts.Close()

// Initialize VU and browser module
vu := k6test.NewVU(t, k6test.WithTracerProvider(tp))

rt := vu.Runtime()
root := browser.New()
mod := root.NewModuleInstance(vu)
jsMod, ok := mod.Exports().Default.(*browser.JSModule)
require.Truef(t, ok, "unexpected default mod export type %T", mod.Exports().Default)
require.NoError(t, rt.Set("browser", jsMod.Browser))
vu.ActivateVU()

testCases := []struct {
name string
js string
expected []string
}{
{
name: "goto",
js: fmt.Sprintf(`
page = await browser.newPage();
await page.goto('%s', {waitUntil:'networkidle'});
page.close();
`, ts.URL),
expected: []string{
"iteration",
"browser.newPage",
"browser.newContext",
"browserContext.newPage",
"navigation", // created when a new page is created
"page.goto",
"navigation", // created when a navigation occurs after goto
"page.close",
},
},
{
name: "reload",
ankur22 marked this conversation as resolved.
Show resolved Hide resolved
js: fmt.Sprintf(`
page = await browser.newPage();
await page.goto('%s', {waitUntil:'networkidle'});
await page.reload({waitUntil:'networkidle'});
page.close();
`, ts.URL),
expected: []string{
"iteration",
"browser.newPage",
"browser.newContext",
"browserContext.newPage",
"navigation", // created when a new page is created
"page.goto",
"navigation", // created when a navigation occurs after goto
"page.reload",
"navigation", // created when a navigation occurs after reload
"page.close",
},
},
{
name: "go_back",
js: fmt.Sprintf(`
page = await browser.newPage();
await page.goto('%s', {waitUntil:'networkidle'});
await Promise.all([
page.waitForNavigation(),
page.evaluate(() => window.history.back()),
]);
page.close();
`, ts.URL),
expected: []string{
"iteration",
"browser.newPage",
"browser.newContext",
"browserContext.newPage",
"navigation", // created when a new page is created
"page.goto",
"navigation", // created when a navigation occurs after goto
"page.waitForNavigation",
"navigation", // created when going back to the previous page
"page.close",
},
},
{
name: "same_page_navigation",
js: fmt.Sprintf(`
page = await browser.newPage();
await page.goto('%s', {waitUntil:'networkidle'});
await Promise.all([
page.waitForNavigation(),
page.locator('a[id=\"top\"]').click(),
]);
page.close();
`, ts.URL),
expected: []string{
"iteration",
"browser.newPage",
"browser.newContext",
"browserContext.newPage",
"navigation", // created when a new page is created
"page.goto",
"navigation", // created when a navigation occurs after goto
"page.waitForNavigation",
"locator.click",
"navigation", // created when navigating within the same page
"page.close",
},
},
}

for _, tc := range testCases {
// Cannot create new VUs that do not depend on each other due to the
// sync.Once in mod.NewModuleInstance, so we can't parallelize these
// subtests.
inancgumus marked this conversation as resolved.
Show resolved Hide resolved
func() {
// Run the test
vu.StartIteration(t)
defer vu.EndIteration(t)

assertJSInEventLoop(t, vu, tc.js)

got := tracer.cloneOrderedSpans()
// We can't use assert.Equal since the order of the span creation
// changes slightly on every test run. Instead we're going to make
// sure that the slice matches but not the order.
assert.ElementsMatch(t, tc.expected, got, fmt.Sprintf("%s failed", tc.name))
inancgumus marked this conversation as resolved.
Show resolved Hide resolved
}()
}
}

func setupTestTracing(t *testing.T, rt *sobek.Runtime) {
t.Helper()

Expand Down Expand Up @@ -210,8 +359,9 @@ func (m *mockTracerProvider) Tracer(
type mockTracer struct {
embedded.Tracer

mu sync.Mutex
spans map[string]struct{}
mu sync.Mutex
spans map[string]struct{}
orderedSpans []string
}

func (m *mockTracer) Start(
Expand All @@ -222,6 +372,11 @@ func (m *mockTracer) Start(

m.spans[spanName] = struct{}{}

// Ignore web_vital spans since they're non deterministic.
if spanName != "web_vital" {
m.orderedSpans = append(m.orderedSpans, spanName)
}

return ctx, browsertrace.NoopSpan{}
}

Expand All @@ -238,3 +393,15 @@ func (m *mockTracer) verifySpans(spanNames ...string) error {

return nil
}

func (m *mockTracer) cloneOrderedSpans() []string {
m.mu.Lock()
defer m.mu.Unlock()

c := make([]string, len(m.orderedSpans))
copy(c, m.orderedSpans)
inancgumus marked this conversation as resolved.
Show resolved Hide resolved

m.orderedSpans = []string{}

return c
}
Loading