grafana / xk6-browser

k6 extension that adds support for browser automation and end-to-end web testing via the Chrome Devtools Protocol
https://grafana.com/docs/k6/latest/javascript-api/k6-experimental/browser/
GNU Affero General Public License v3.0
329 stars 42 forks source link

TestWebVitalMetric might be flaky #920

Open inancgumus opened 1 year ago

inancgumus commented 1 year ago

Brief summary

TestWebVitalMetric failed once in between dozens of test runs locally.

xk6-browser version

6ffa156

OS

macOS 13.1

Chrome version

110.0.5481.177 (Official Build) (arm64)

Steps to reproduce the problem

Run the test many times with different GOMAXPROC settings.

Expected behaviour

No flakiness.

Actual behaviour

time="2023-06-02T14:55:29+03:00" level=error msg="process with PID 61102 unexpectedly ended: exit status 1" category=browser elapsed="0 ms" goroutine=770
time="2023-06-02T14:55:30+03:00" level=error msg="communicating with browser: websocket: close 1006 (abnormal closure): unexpected EOF" category=cdp elapsed="0 ms" goroutine=892
time="2023-06-02T14:55:30+03:00" level=error msg="communicating with browser: websocket: close 1006 (abnormal closure): unexpected EOF" category=cdp elapsed="0 ms" goroutine=1108
time="2023-06-02T14:55:30+03:00" level=error msg="communicating with browser: websocket: close 1006 (abnormal closure): unexpected EOF" category=cdp elapsed="0 ms" goroutine=1309
time="2023-06-02T14:55:45+03:00" level=error msg="Failed to load resource: the server responded with a status of 401 (Unauthorized)" browser_source=network line_number=0 source=browser stacktrace="<nil>" url="http://127.0.0.1:54051/basic-auth/validuser/validpass"
time="2023-06-02T14:55:45+03:00" level=warning msg="url:http://127.0.0.1:54051/basic-auth/validuser/validpass method:GET err:fetching response body: context canceled" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=8466
time="2023-06-02T14:55:46+03:00" level=warning msg="url:http://127.0.0.1:54060/static/empty.html method:GET err:fetching response body: context canceled" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=8743
time="2023-06-02T14:55:48+03:00" level=warning msg="The specified value \"invalid date\" does not conform to the required format, \"yyyy-MM-dd\"." browser_source=rendering line_number=457 source=browser url=__xk6_browser_evaluation_script__
time="2023-06-02T14:55:50+03:00" level=error msg="communicating with browser: websocket: close 1006 (abnormal closure): unexpected EOF" category=cdp elapsed="0 ms" goroutine=10968
time="2023-06-02T14:55:50+03:00" level=error msg="process with PID 61475 unexpectedly ended: signal: killed" category=browser elapsed="1 ms" goroutine=10784
time="2023-06-02T14:55:51+03:00" level=error msg="process with PID 61499 unexpectedly ended: exit status 1" category=browser elapsed="0 ms" goroutine=11492
time="2023-06-02T14:55:51+03:00" level=warning msg="url:http://127.0.0.1:54108/static/web_vitals.html method:GET err:fetching response body: context canceled" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=11484
--- FAIL: TestWebVitalMetric (0.28s)
    webvital_test.go:52: 
                Error Trace:    /Users/inanc/grafana/k6browser/main/tests/webvital_test.go:52
                Error:          Expected value not to be nil.
                Test:           TestWebVitalMetric
time="2023-06-02T14:55:52+03:00" level=warning msg="Error with Permissions-Policy header: Unrecognized feature: 'ch-ua-form-factor'." browser_source=security line_number=0 source=browser url=
time="2023-06-02T14:55:52+03:00" level=warning msg="url:https://www.youtube.com/embed/gwO7k5RTE54?wmode=opaque&enablejsapi=1 method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:52+03:00" level=warning msg="url:https://www.youtube.com/s/player/f55759b8/www-player.css method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:52+03:00" level=warning msg="url:https://www.youtube.com/s/player/f55759b8/fetch-polyfill.vflset/fetch-polyfill.js method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:52+03:00" level=warning msg="url:https://www.youtube.com/s/player/f55759b8/www-embed-player.vflset/www-embed-player.js method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:52+03:00" level=warning msg="url:https://fonts.gstatic.com/s/roboto/v18/KFOmCnqEu92Fr1Mu4mxKKTU1Kg.woff2 method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:52+03:00" level=warning msg="url:https://fonts.gstatic.com/s/roboto/v18/KFOlCnqEu92Fr1MmEU9fBBc4AMP6lQ.woff2 method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://www.youtube.com/s/player/f55759b8/player_ias.vflset/en_US/base.js method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://www.youtube.com/s/player/f55759b8/player_ias.vflset/en_US/remote.js method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://www.youtube.com/s/player/f55759b8/player_ias.vflset/en_US/embed.js method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://static.doubleclick.net/instream/ad_status.js method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://www.google.com/js/th/eee_KjLo8HjJC2kczPWeD_UvQFOi_GikGCFFwzkCqeE.js method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://i.ytimg.com/vi_webp/gwO7k5RTE54/sddefault.webp method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://yt3.ggpht.com/9mD5UVq9v0F0JsJYQN-zMB8AfV2Wi4SOdF7B2AAxlfekZWgitfj9ewjXhvWmGYJe3RIff0gXWw=s68-c-k-c0x00ffffff-no-rj method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://googleads.g.doubleclick.net/pagead/id?slf_rd=1 method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://www.youtube.com/generate_204?hEkZ0w method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://jnn-pa.googleapis.com/$rpc/google.internal.waa.v1.Waa/Create method:POST err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://www.gstatic.com/cv/js/sender/v1/cast_sender.js method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://www.gstatic.com/eureka/clank/113/cast_sender.js method:GET err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:53+03:00" level=error msg="Failed to load resource: the server responded with a status of 404 (Not Found)" browser_source=network line_number=0 source=browser stacktrace="<nil>" url="http://127.0.0.1:54114/favicon.ico"
time="2023-06-02T14:55:53+03:00" level=warning msg="url:https://jnn-pa.googleapis.com/$rpc/google.internal.waa.v1.Waa/GenerateIT method:POST err:fetching response body: No resource with given identifier found (-32000)" category="Response:bodySize:fetchBody" elapsed="0 ms" goroutine=12275
time="2023-06-02T14:55:54+03:00" level=error msg="process with PID 61514 unexpectedly ended: signal: killed" category=browser elapsed="0 ms" goroutine=11653
FAIL
FAIL    github.com/grafana/xk6-browser/tests    26.980s
FAIL
inancgumus commented 4 months ago

This happens almost every other day (e.g.). We better look at this as it diminishes our trust with CI tests.

time="2024-03-04T06:11:15Z" level=error msg="process with PID 3335 unexpectedly ended: signal: killed" category=browser elapsed="2 ms" source=browser
--- FAIL: TestWebVitalMetricNoInteraction (1.16s)
    webvital_test.go:145: 
            Error Trace:    /home/runner/work/xk6-browser/xk6-browser/tests/webvital_test.go:1[45](https://github.com/grafana/xk6-browser/actions/runs/8136378756/job/22232567315#step:5:46)
            Error:          Should be true
            Test:           TestWebVitalMetricNoInteraction
            Messages:       expected browser_web_vital_lcp to have been measured and emitted
    webvital_test.go:145: 
            Error Trace:    /home/runner/work/xk6-browser/xk6-browser/tests/webvital_test.go:145
            Error:          Should be true
            Test:           TestWebVitalMetricNoInteraction
            Messages:       expected browser_web_vital_cls to have been measured and emitted