1772558 - Netflix live login failing intermittently and Facebook not fully loading (on Try)

Status: RESOLVED INVALID

(Testing :: Raptor, defect, P3)

Description

[Kash Shampur [:kshampur] ⌚EST]

As found in Bug 1754830 Try runs, netflix will sometimes be detected as a multi-page login rather than a single-page login and it will fail to properly log-in.

For example, it will run for a few iterations and successfully be classified as a single-page login, then it will be detected as a multi-page

[task 2022-06-02T21:14:20.686Z] 21:14:20     INFO -  raptor-browsertime Info: Skip setting default preferences for Firefox
[task 2022-06-02T21:14:22.660Z] 21:14:22     INFO -  raptor-browsertime Info: Starting a browsertime pageload
[task 2022-06-02T21:14:22.661Z] 21:14:22     INFO -  raptor-browsertime Info: Waiting for 1000 ms (post_startup_delay)
[task 2022-06-02T21:14:23.663Z] 21:14:23     INFO -  raptor-browsertime Info: Obtaining secrets for login...
[task 2022-06-02T21:14:23.720Z] 21:14:23     INFO -  raptor-browsertime Info: Secret status code: 200
[task 2022-06-02T21:14:23.721Z] 21:14:23     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 13
[task 2022-06-02T21:14:28.769Z] 21:14:28     INFO -  raptor-browsertime Info: Navigating to url https://www.netflix.com/login iteration 13
[task 2022-06-02T21:14:45.879Z] 21:14:45     INFO -  raptor-browsertime Info: Found a single-page login
[task 2022-06-02T21:14:56.280Z] 21:14:56     INFO -  raptor-browsertime Info: Ignoring 2FA error
[task 2022-06-02T21:14:56.281Z] 21:14:56     INFO -  raptor-browsertime Info: Can't find a button with the text: //a[contains(text(), 'skip')]
[task 2022-06-02T21:14:56.288Z] 21:14:56     INFO -  raptor-browsertime Info: Ignoring 2FA error
[task 2022-06-02T21:14:56.289Z] 21:14:56     INFO -  raptor-browsertime Info: Can't find a button with the text: //button[contains(text(), 'skip')]
[task 2022-06-02T21:14:56.295Z] 21:14:56     INFO -  raptor-browsertime Info: Ignoring 2FA error
[task 2022-06-02T21:14:56.296Z] 21:14:56     INFO -  raptor-browsertime Info: Can't find a button with the text: //input[contains(text(), 'skip')]
[task 2022-06-02T21:14:56.303Z] 21:14:56     INFO -  raptor-browsertime Info: Ignoring 2FA error
[task 2022-06-02T21:14:56.304Z] 21:14:56     INFO -  raptor-browsertime Info: Can't find a button with the text: //div[contains(text(), 'skip')]
[task 2022-06-02T21:14:56.305Z] 21:14:56     INFO -  raptor-browsertime Info: Navigating to about:blank, count: 0
[task 2022-06-02T21:14:56.306Z] 21:14:56     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 13
[task 2022-06-02T21:15:02.368Z] 21:15:02     INFO -  raptor-browsertime Info: Navigating to primary url:https://www.netflix.com/title/80117263
[task 2022-06-02T21:15:02.368Z] 21:15:02     INFO -  raptor-browsertime Info: Cycle 0, waiting for 5000 ms
[task 2022-06-02T21:15:07.374Z] 21:15:07     INFO -  raptor-browsertime Info: Cycle 0, starting the measure
[task 2022-06-02T21:15:07.375Z] 21:15:07     INFO -  raptor-browsertime Info: Testing url https://www.netflix.com/title/80117263 iteration 13
[task 2022-06-02T21:15:07.377Z] 21:15:07     INFO -  raptor-browsertime Info: Start firefox window recorder.
[task 2022-06-02T21:15:15.281Z] 21:15:15     INFO -  raptor-browsertime Info: Stop firefox window recorder.
[task 2022-06-02T21:15:17.252Z] 21:15:17     INFO -  raptor-browsertime Info: Navigating to secondary url:https://www.netflix.com/title/699257
[task 2022-06-02T21:15:17.252Z] 21:15:17     INFO -  raptor-browsertime Info: Navigating to url https://www.netflix.com/title/699257 iteration 13
[task 2022-06-02T21:15:28.329Z] 21:15:28     INFO -  raptor-browsertime Info: Navigating to primary url:https://www.netflix.com/title/80117263
[task 2022-06-02T21:15:28.330Z] 21:15:28     INFO -  raptor-browsertime Info: Cycle 1, waiting for 5000 ms
[task 2022-06-02T21:15:33.335Z] 21:15:33     INFO -  raptor-browsertime Info: Cycle 1, starting the measure
[task 2022-06-02T21:15:33.336Z] 21:15:33     INFO -  raptor-browsertime Info: Testing url https://www.netflix.com/title/80117263 iteration 13
[task 2022-06-02T21:15:33.336Z] 21:15:33     INFO -  raptor-browsertime Info: Start firefox window recorder.
[task 2022-06-02T21:15:41.243Z] 21:15:41     INFO -  raptor-browsertime Info: https://www.netflix.com/title/80117263 has been tested before within the same run, it will get an extra query parameter named browsertime_run. Make sure to use alias to keep track of the URLs
[task 2022-06-02T21:15:41.246Z] 21:15:41     INFO -  raptor-browsertime Info: Stop firefox window recorder.
[task 2022-06-02T21:15:43.372Z] 21:15:43     INFO -  raptor-browsertime Info: Browsertime pageload ended.
[task 2022-06-02T21:15:45.755Z] 21:15:45     INFO -  raptor-browsertime Info: Get visual metrics from the video
[task 2022-06-02T21:15:46.862Z] 21:15:46     INFO -  raptor-browsertime Info: Get visual metrics from the video
[task 2022-06-02T21:15:48.015Z] 21:15:48     INFO -  raptor-browsertime Info: https://www.netflix.com/title/80117263 TTFB: 467ms DOMContentLoaded: 893ms firstPaint: 869ms FCP: 857ms Load: 1.22s
[task 2022-06-02T21:15:48.016Z] 21:15:48     INFO -  raptor-browsertime Info: VisualMetrics: FirstVisualChange: 400ms SpeedIndex: 475ms PerceptualSpeedIndex: 473ms ContentfulSpeedIndex: 454ms VisualComplete85: 520ms LastVisualChange: 560ms
[task 2022-06-02T21:15:48.016Z] 21:15:48     INFO -  raptor-browsertime Info: https://www.netflix.com/title/80117263?browsertime_run=2 TTFB: 655ms DOMContentLoaded: 1.00s firstPaint: 999ms FCP: 994ms Load: 1.30s
[task 2022-06-02T21:15:48.017Z] 21:15:48     INFO -  raptor-browsertime Info: VisualMetrics: FirstVisualChange: 280ms SpeedIndex: 307ms PerceptualSpeedIndex: 318ms ContentfulSpeedIndex: 281ms VisualComplete85: 320ms LastVisualChange: 480ms
[task 2022-06-02T21:15:48.018Z] 21:15:48     INFO -  raptor-browsertime Info: Skip setting default preferences for Firefox
[task 2022-06-02T21:15:49.999Z] 21:15:49     INFO -  raptor-browsertime Info: Starting a browsertime pageload
[task 2022-06-02T21:15:50.000Z] 21:15:50     INFO -  raptor-browsertime Info: Waiting for 1000 ms (post_startup_delay)
[task 2022-06-02T21:15:51.002Z] 21:15:51     INFO -  raptor-browsertime Info: Obtaining secrets for login...
[task 2022-06-02T21:15:51.105Z] 21:15:51     INFO -  raptor-browsertime Info: Secret status code: 200
[task 2022-06-02T21:15:51.106Z] 21:15:51     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 14
[task 2022-06-02T21:15:56.151Z] 21:15:56     INFO -  raptor-browsertime Info: Navigating to url https://www.netflix.com/login iteration 14
[task 2022-06-02T21:16:12.253Z] 21:16:12     INFO -  raptor-browsertime Info: Found a multi-page login
[task 2022-06-02T21:16:12.261Z] 21:16:12    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2022-06-02T21:16:12.284Z] 21:16:12 CRITICAL -  raptor-browsertime Critical: No page that could be associated with the error:Could not setup login information: NoSuchElementError: Unable to locate element: input:not([type=hidden]):not([type=password])
[task 2022-06-02T21:16:12.284Z] 21:16:12     INFO -  raptor-perftest Info: Removing temporary directory: /tmp/tmpl0c_035p
[task 2022-06-02T21:16:12.290Z] 21:16:12    ERROR -  Traceback (most recent call last):
[task 2022-06-02T21:16:12.290Z] 21:16:12     INFO -    File "/home/cltbld/tasks/task_165420169886940/build/tests/raptor/raptor/raptor.py", line 215, in <module>
[task 2022-06-02T21:16:12.290Z] 21:16:12     INFO -      main()
[task 2022-06-02T21:16:12.290Z] 21:16:12     INFO -    File "/home/cltbld/tasks/task_165420169886940/build/tests/raptor/raptor/raptor.py", line 161, in main
[task 2022-06-02T21:16:12.291Z] 21:16:12     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2022-06-02T21:16:12.291Z] 21:16:12     INFO -    File "/home/cltbld/tasks/task_165420169886940/build/tests/raptor/raptor/perftest.py", line 462, in run_tests
[task 2022-06-02T21:16:12.291Z] 21:16:12     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2022-06-02T21:16:12.291Z] 21:16:12     INFO -    File "/home/cltbld/tasks/task_165420169886940/build/tests/raptor/raptor/browsertime/base.py", line 670, in run_test
[task 2022-06-02T21:16:12.291Z] 21:16:12     INFO -      raise Exception(self.browsertime_failure)
[task 2022-06-02T21:16:12.291Z] 21:16:12     INFO -  Exception: No page that could be associated with the error:Could not setup login information: NoSuchElementError: Unable to locate element: input:not([type=hidden]):not([type=password])
[task 2022-06-02T21:16:12.352Z] 21:16:12    ERROR - Return code: 1
[task 2022-06-02T21:16:12.352Z] 21:16:12  WARNING - setting return code to 1
[task 2022-06-02T21:16:12.353Z] 21:16:12     INFO - Copying Raptor results to upload dir:
[task 2022-06-02T21:16:12.353Z] 21:16:12     INFO - /home/cltbld/tasks/task_165420169886940/build/blobber_upload_dir/perfherder-data.json
[task 2022-06-02T21:16:12.353Z] 21:16:12     INFO - Copying raptor results from /home/cltbld/tasks/task_165420169886940/build/raptor.json to /home/cltbld/tasks/task_165420169886940/build/blobber_upload_dir/perfherder-data.json
[task 2022-06-02T21:16:12.353Z] 21:16:12 CRITICAL - Error copying results /home/cltbld/tasks/task_165420169886940/build/raptor.json to upload dir /home/cltbld/tasks/task_165420169886940/build/blobber_upload_dir/perfherder-data.json
[task 2022-06-02T21:16:12.353Z] 21:16:12     INFO - [Errno 2] No such file or directory: '/home/cltbld/tasks/task_165420169886940/build/raptor.json'
[task 2022-06-02T21:16:12.354Z] 21:16:12     INFO - Running post-action listener: _package_coverage_data
[task 2022-06-02T21:16:12.355Z] 21:16:12     INFO - Running post-action listener: _resource_record_post_action
[task 2022-06-02T21:16:12.355Z] 21:16:12     INFO - Running post-action listener: process_java_coverage_data
[task 2022-06-02T21:16:12.355Z] 21:16:12     INFO - Running post-action listener: stop_device
[task 2022-06-02T21:16:12.355Z] 21:16:12     INFO - [mozharness: 2022-06-02 21:16:12.355423Z] Finished run-tests step (success)
[task 2022-06-02T21:16:12.355Z] 21:16:12     INFO - Running post-run listener: _resource_record_post_run
[task 2022-06-02T21:16:12.463Z] 21:16:12     INFO - Total resource usage - Wall time: 1231s; CPU: 6%; Read bytes: 172843008; Write bytes: 5165723648; Read time: 2136; Write time: 61616
[task 2022-06-02T21:16:12.463Z] 21:16:12     INFO - TinderboxPrint: CPU usage<br/>5.6%
[task 2022-06-02T21:16:12.463Z] 21:16:12     INFO - TinderboxPrint: I/O read bytes / time<br/>172,843,008 / 2,136
[task 2022-06-02T21:16:12.463Z] 21:16:12     INFO - TinderboxPrint: I/O write bytes / time<br/>5,165,723,648 / 61,616
[task 2022-06-02T21:16:12.463Z] 21:16:12     INFO - TinderboxPrint: CPU idle<br/>9,266.4 (94.2%)
[task 2022-06-02T21:16:12.463Z] 21:16:12     INFO - TinderboxPrint: CPU system<br/>108.3 (1.1%)
[task 2022-06-02T21:16:12.463Z] 21:16:12     INFO - TinderboxPrint: CPU user<br/>393.7 (4.0%)
[task 2022-06-02T21:16:12.464Z] 21:16:12     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2022-06-02T21:16:12.464Z] 21:16:12     INFO - install-chromium-distribution - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2022-06-02T21:16:12.464Z] 21:16:12     INFO - install - Wall time: 9s; CPU: 13%; Read bytes: 32768; Write bytes: 404078592; Read time: 16; Write time: 2316
[task 2022-06-02T21:16:12.475Z] 21:16:12     INFO - run-tests - Wall time: 1222s; CPU: 6%; Read bytes: 171532288; Write bytes: 4757131264; Read time: 2104; Write time: 59260
[task 2022-06-02T21:16:12.692Z] 21:16:12  WARNING - returning nonzero exit status 1
[taskcluster 2022-06-02T21:16:12.717Z]    Exit Code: 1
[taskcluster 2022-06-02T21:16:12.717Z]    User Time: 7m45.984149s
[taskcluster 2022-06-02T21:16:12.717Z]  Kernel Time: 1m47.790149s
[taskcluster 2022-06-02T21:16:12.717Z]    Wall Time: 21m17.807224676s
[taskcluster 2022-06-02T21:16:12.717Z]       Result: FAILED
[taskcluster 2022-06-02T21:16:12.717Z] === Task Finished ===
[taskcluster 2022-06-02T21:16:12.717Z] Task Duration: 21m17.810123004s

I've been unsuccessful in reproducing this error locally.

A good starting point is looking at these 2 files with the login logic

https://searchfox.org/mozilla-central/source/testing/raptor/browsertime/browsertime_pageload.js

https://searchfox.org/mozilla-central/source/testing/performance/perftest_record.js

EDIT:
in addition, facebook sometimes blocks us when navigating to the secondary url or take a long time loading the page (see attached photos)

Comment 1

[Kash Shampur [:kshampur] ⌚EST]

Attachment: login_fail.png

Sometimes this error pops up when attempting a log-in. While this does not trigger a multi-page login, it might be related

Comment 2

[Kash Shampur [:kshampur] ⌚EST]

Attachment: fb_blocked.png

Comment 3

[Kash Shampur [:kshampur] ⌚EST]

Attachment: fb_loading.png

Comment 4

[Kash Shampur [:kshampur] ⌚EST]

Attachment: netflix_nav_no_login.png

Comment 5

[Florin Bilt]

This bug is quite old, and the website has changed since then. I am closing this ticket as invalid