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
Merged

Fix navigation span start #1421

merged 10 commits into from
Sep 12, 2024

Conversation

ankur22
Copy link
Collaborator

@ankur22 ankur22 commented Sep 10, 2024

What?

This fixes the navigation span so that the duration is longer than the duration of the child spans. This fix is to start the navigation span earlier in onFrameStartedLoading. It also required us to differ adding the url attribute to the navigation span to when it was ended since we don't have knowledge of the new url in onFrameStartedLoading.

Why?

This ensures that the child span values make sense with respect to the parent/navigation span they are part of.

Before the fix:
image

After the fix:
image

Checklist

  • I have performed a self-review of my code
  • I have added tests for my changes
  • I have commented on my code, particularly in hard-to-understand areas

Related PR(s)/Issue(s)

Updates: #1413

@ankur22 ankur22 force-pushed the fix/span-duration-web-vital branch 4 times, most recently from b0d1ef7 to 8dc3897 Compare September 10, 2024 10:28
@ankur22 ankur22 requested a review from inancgumus September 10, 2024 10:40
@ankur22 ankur22 force-pushed the fix/span-duration-web-vital branch from 8dc3897 to 792270b Compare September 10, 2024 11:15
common/frame_session.go Outdated Show resolved Hide resolved
@ankur22 ankur22 marked this pull request as draft September 10, 2024 12:48
@ankur22 ankur22 removed the request for review from inancgumus September 10, 2024 12:48
@ankur22 ankur22 force-pushed the fix/span-duration-web-vital branch 5 times, most recently from 7186973 to f9b4d51 Compare September 10, 2024 13:54
@ankur22 ankur22 marked this pull request as ready for review September 10, 2024 13:57
@ankur22 ankur22 requested a review from inancgumus September 10, 2024 13:57
@ankur22 ankur22 force-pushed the fix/span-duration-web-vital branch 2 times, most recently from b0d8b60 to 986f58a Compare September 10, 2024 16:00
@inancgumus
Copy link
Member

inancgumus commented Sep 10, 2024

@ankur22 Before reviewing, there's a data race on the test that this PR adds:

==================
WARNING: DATA RACE
Read at 0x00c006f7f498 by goroutine 17300:
  ...
  github.com/grafana/xk6-browser/browser.mapPage.func33.1()
      /home/runner/work/xk6-browser/xk6-browser/browser/page_mapping.go:241 +0x192
  github.com/grafana/xk6-browser/k6ext.promise.func1()
      /home/runner/work/xk6-browser/xk6-browser/k6ext/promise.go:41 +0x81

Previous write at 0x00c006f7f498 by goroutine 683:
  ...
  github.com/grafana/xk6-browser/tests.assertJSInEventLoop()
      /home/runner/work/xk6-browser/xk6-browser/tests/tracing_test.go:325 +0x1fa
  github.com/grafana/xk6-browser/tests.TestNavigationSpanCreation.func2()
      /home/runner/work/xk6-browser/xk6-browser/tests/tracing_test.go:287 +0x12c
  github.com/grafana/xk6-browser/tests.TestNavigationSpanCreation()

@ankur22
Copy link
Collaborator Author

ankur22 commented Sep 11, 2024

@ankur22 Before reviewing, there's a data race on the test that this PR adds:

==================
WARNING: DATA RACE
Read at 0x00c006f7f498 by goroutine 17300:
  ...
  github.com/grafana/xk6-browser/browser.mapPage.func33.1()
      /home/runner/work/xk6-browser/xk6-browser/browser/page_mapping.go:241 +0x192
  github.com/grafana/xk6-browser/k6ext.promise.func1()
      /home/runner/work/xk6-browser/xk6-browser/k6ext/promise.go:41 +0x81

Previous write at 0x00c006f7f498 by goroutine 683:
  ...
  github.com/grafana/xk6-browser/tests.assertJSInEventLoop()
      /home/runner/work/xk6-browser/xk6-browser/tests/tracing_test.go:325 +0x1fa
  github.com/grafana/xk6-browser/tests.TestNavigationSpanCreation.func2()
      /home/runner/work/xk6-browser/xk6-browser/tests/tracing_test.go:287 +0x12c
  github.com/grafana/xk6-browser/tests.TestNavigationSpanCreation()

I believe this is resolved in a new PR i created here. I've ran a race test with this fix and it seems to have solved it.

@ankur22 ankur22 force-pushed the fix/span-duration-web-vital branch from 986f58a to 11e5647 Compare September 11, 2024 08:04
@ankur22 ankur22 force-pushed the fix/span-duration-web-vital branch from af38da9 to d02e65c Compare September 11, 2024 15:42
Copy link
Member

@inancgumus inancgumus left a comment

Choose a reason for hiding this comment

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

LGTM 👍 Nice fix!

common/frame_session.go Show resolved Hide resolved
common/frame_session.go Outdated Show resolved Hide resolved
@ankur22 ankur22 requested a review from inancgumus September 12, 2024 09:06
This moves the navigation span starting into its own method since it
will likely be needed elsewhere.
It looks like we weren't ending the span when a new navigation span was
being started.
The navigation span was started a lot later than it should have. This
meant that child spans (such as web vitals) looked incorrect since
the values of those child spans were longer than the navigation span.

Now the navigation span is started a lot earlier, and this means that
the child span values are safely within the permitted navigation span.

We still have a navigation span start from onFrameNavigated which is
needed when the iteration starts on a new page, since
onFrameStartedLoading isn't called when a new page is called and it
navigates to about:blank.
When the navigation span is started, the new URL is not available to us
yet. We have to defer the adding of the url attribute to the span to
the end of the navigation span.
It was useful to have a test to ensure that the navigation spans were
created in the expected order before and after the fix.
This is to help mimic expected test structure. The page.close should
help determine when the test ends and whether there are any anomalies.
This also protects the retrieval of the url with the mutex.
Adding better ways of waiting for API to end with the use of waitUntil
and waitForNavigation. Now comparing the elements within the slices
and not worrying about the order since the order can change on every
test run.
@ankur22 ankur22 force-pushed the fix/span-duration-web-vital branch from 0f96ee8 to 0907ad5 Compare September 12, 2024 13:52
tests/tracing_test.go Show resolved Hide resolved
tests/tracing_test.go Outdated Show resolved Hide resolved
tests/tracing_test.go Show resolved Hide resolved
tests/tracing_test.go Show resolved Hide resolved
- Rename it to better represent what it is doing and the cost of the
action.
- Use clone instead of copy.
This isn't available in go <1.21 so reverting to copy for now.
@ankur22 ankur22 merged commit 2c70820 into main Sep 12, 2024
23 checks passed
@ankur22 ankur22 deleted the fix/span-duration-web-vital branch September 12, 2024 16:18
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants