User Details
- User Since
- Aug 17 2015, 6:48 PM (271 w, 10 h)
- Availability
- Available
- IRC Nick
- phedenskog
- LDAP User
- Unknown
- MediaWiki User
- PHedenskog (WMF) [ Global Accounts ]
Yesterday
Fri, Oct 23
Implemented start/clearing Firefox/Chrome before we start our tests.
Thu, Oct 22
A positive thing is that yesterdays fix handles when the browser hangs. The root issue is still there, but we handle that at least.
Kobiton is gonna change the setup for ZY2242HJDX and wire it in the Mac without the hub so we can exclude that the hub is the reason. If the problem still persist I'm gonna do a longer upstream issue.
Wed, Oct 21
At least there could be better error messages upstream. Also asked Kobiton about the setup between the Mac Mini and the phones, if there could be something special there.
Adding more logs for reference:
1603281834291 geckodriver::android DEBUG Launching org.mozilla.firefox/org.mozilla.fenix.IntentReceiverActivity
1603281834392 mozdevice DEBUG execute_host_command: >> "host:transport:ZY2242HJDX"
1603281834492 mozdevice DEBUG execute_host_command: << []
1603281834492 mozdevice DEBUG execute_host_command: >> "shell:am start -W -n org.mozilla.firefox/org.mozilla.fenix.IntentReceiverActivity -a android.intent.action.VIEW -d about:blank --es args --marionette\\ --
profile\\ /mnt/sdcard/org.mozilla.firefox-geckodriver-profile"
1603281838030 mozdevice DEBUG execute_host_command: << "Starting: Intent { act=android.intent.action.VIEW dat=about:blank cmp=org.mozilla.firefox/org.mozilla.fenix.IntentReceiverActivity (has extras) }\nStatus: ok\nActivity: org.mozilla.firefox/org.mozilla.fenix.HomeActivity\nThisTime: 1360\nTotalTime: 2284\nWaitTime: 2297\nComplete\n"
1603281838030 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1:64772
1603281838211 geckodriver::android DEBUG Force stopping the Android package: org.mozilla.firefox
1603281838211 mozdevice DEBUG Force stopping Android package: org.mozilla.firefox
1603281838311 mozdevice DEBUG execute_host_command: >> "host:transport:ZY2242HJDX"
1603281838411 mozdevice DEBUG execute_host_command: << []
1603281838411 mozdevice DEBUG execute_host_command: >> "shell:am force-stop org.mozilla.firefox"
1603281839918 mozdevice DEBUG execute_host_command: << ""
1603281839918 webdriver::server DEBUG <- 500 Internal Server Error {"value":{"error":"timeout","message":"Socket timeout reading Marionette handshake data: Resource temporarily unavailable (os error 35)","stacktrace":""}}I've pushed a changed where I added a timeout of two minutes when we try close the browser to avoid making tests hang. When I looked at the code, that was the only thing I could find. Best case that would at least make sure our tests continuous to run. The root cause will still be there (the browser freezes) but maybe we can live with that.
I think that's how WebPageTest choose to iterate over the object. Its alphabetically sorted where I created it.
I've added :/var/www/webpagetest/www/settings/custom_metrics/navigationTimings.js on the server.
Been running the tests though the night and suddenly the tests stopped. Look at the time difference between the last log line and the rotation of the log:
[2020-10-20 19:36:25] INFO: URL failed to load, trying 0 more time(s): Failed waiting on page https://en.m.wikipedia.org/wiki/Main_Page to finished loading, timed out after 300000 ms
[2020-10-20 19:36:25] ERROR: Could not load URL https://en.m.wikipedia.org/wiki/Main_Page UrlLoadError: Failed waiting on page https://en.m.wikipedia.org/wiki/Main_Page to finished loading, timed out after 300000 ms
at SeleniumRunner.wait (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/seleniumRunner.js:188:13)
[2020-10-20 19:36:25] ERROR: UrlLoadError: Failed to load https://en.m.wikipedia.org/wiki/Main_Page
at SeleniumRunner.loadAndWait (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/seleniumRunner.js:313:17)
Oct 21 00:30:04 Kobitons-Mac-mini-156 newsyslog[27602]: logfile turned overTue, Oct 20
My guess is that " TypeError: win is null" comes from RUMSpeedIndex, that's the only JS that we try to run that has "win" defined.
The new phone also gets errors:
[2020-10-20 16:33:29] INFO: firefox failed to start, trying 2 more time(s): Failed to start firefox in 60 seconds.
Let me pick this up again in a week or two.
This haven't happened again so close it.
Investigations happened in T263224
I've asked for access but they haven't got back yet.
Hit the right spot! Chrome looks like this:
I will try running Chrome on the same phone for a couple of days and see if we get the same problem there.
Latest from Mozilla is that its "some weird networking/port forwarding issue". We setup the wifi with proxy, I wonder if that somehow can have something to do with it? One way could be to just test with WebPageReplay and see what if we get the same problem.
Let me do summary of the status: I've enabled continuous testing on Kobiton for one phone last week. Test works for a while (a couple of URLs for X runs), then it starts to fail because the browser cannot be open. Then after some more time it starts to work again. I cannot reproduce this behavior when I test on my local phones.
Let look at the metrics. Focus on First Visual Change. For WebPageTest I can see that some pages are affected (Facebook/Obama):
Mon, Oct 19
Looking at the logs when Firefox can't start (INFO: Browser failed to start, trying 2 more time(s): Failed to start browser in 60 seconds.) using:
adb -s ZY322HX8RC logcat
Looks like this can be related:
"adbd : failed to connect to socket 'tcp:2829': Connection refused "
Looking at only Marionette logs only gives INFO logs with no help. I'm gonna turn on verbose logging and see if I can see something there.
For Browsertime it looks like this:
Here's what it looked like on WebPageTest before the change:
Hmm I was wrong, restarting the phone got the test to start running again (without restarting the tests), but I couldn't see anything that was stuck in the logs or using ps. Strange.
The last thing that happened on the phone was:
[2020-10-17 10:31:16] ERROR: Failed waiting on page https://en.m.wikipedia.org/wiki/Barack_Obama to finished loading, timed out after 300000 ms BrowserError: Running page complete check
return (function(waitTime) {
try {
var end = window.performance.timing.loadEventEnd;
var start= window.performance.timing.navigationStart;
return (end > 0) && (performance.now() > end - start + waitTime);
}
catch(e) {
return true;
}
})(arguments[arguments.length - 1]);
took too long
return (function(waitTime) {
try {
var end = window.performance.timing.loadEventEnd;
var start= window.performance.timing.navigationStart;
return (end > 0) && (performance.now() > end - start + waitTime);
}
catch(e) {
return true;
}
})(arguments[arguments.length - 1]);
took too long
at /usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/seleniumRunner.js:39:38
at new Promise (<anonymous>)
at timeout (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/seleniumRunner.js:38:5)
at SeleniumRunner.wait (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/seleniumRunner.js:169:13)
at SeleniumRunner.loadAndWait (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/seleniumRunner.js:259:20)
at async Measure.start (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/engine/command/measure.js:201:9)
at async /usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/engine/run.js:9:9
at async Iteration.run (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/engine/iteration.js:191:9)
at async Engine.runByScript (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/engine/index.js:215:20)
at async Object.analyzeUrl (/usr/local/lib/node_modules/sitespeed.io/lib/plugins/browsertime/analyzer.js:124:21)
at async Object.processMessage (/usr/local/lib/node_modules/sitespeed.io/lib/plugins/browsertime/index.js:134:24)
[2020-10-17 10:31:16] INFO: URL failed to load, trying 1 more time(s): Failed waiting on page https://en.m.wikipedia.org/wiki/Barack_Obama to finished loading, timed out after 300000 ms
[2020-10-17 10:36:17] ERROR: Failed waiting on page https://en.m.wikipedia.org/wiki/Barack_Obama to finished loading, timed out after 300000 ms BrowserError: Running page complete check
return (function(waitTime) {
try {
var end = window.performance.timing.loadEventEnd;
var start= window.performance.timing.navigationStart;
return (end > 0) && (performance.now() > end - start + waitTime);
}
catch(e) {
return true;
}
})(arguments[arguments.length - 1]);
took too long
return (function(waitTime) {
try {
var end = window.performance.timing.loadEventEnd;
var start= window.performance.timing.navigationStart;
return (end > 0) && (performance.now() > end - start + waitTime);
}
catch(e) {
return true;
}
})(arguments[arguments.length - 1]);
took too long
at /usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/seleniumRunner.js:39:38
at new Promise (<anonymous>)
at timeout (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/seleniumRunner.js:38:5)
at SeleniumRunner.wait (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/seleniumRunner.js:169:13)
at SeleniumRunner.loadAndWait (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/seleniumRunner.js:259:20)
at async Measure.start (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/engine/command/measure.js:201:9)
at async /usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/engine/run.js:9:9
at async Iteration.run (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/engine/iteration.js:191:9)
at async Engine.runByScript (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/engine/index.js:215:20)
at async Object.analyzeUrl (/usr/local/lib/node_modules/sitespeed.io/lib/plugins/browsertime/analyzer.js:124:21)
at async Object.processMessage (/usr/local/lib/node_modules/sitespeed.io/lib/plugins/browsertime/index.js:134:24)
[2020-10-17 10:36:17] INFO: URL failed to load, trying 0 more time(s): Failed waiting on page https://en.m.wikipedia.org/wiki/Barack_Obama to finished loading, timed out after 300000 ms
[2020-10-17 10:36:17] ERROR: Could not load URL https://en.m.wikipedia.org/wiki/Barack_Obama UrlLoadError: Failed waiting on page https://en.m.wikipedia.org/wiki/Barack_Obama to finished loading, timed out after 300000 ms
at SeleniumRunner.wait (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/seleniumRunner.js:186:13)
[2020-10-17 10:36:17] ERROR: UrlLoadError: Failed to load https://en.m.wikipedia.org/wiki/Barack_Obama
at SeleniumRunner.loadAndWait (/usr/local/lib/node_modules/sitespeed.io/node_modules/browsertime/lib/core/seleniumRunner.js:306:17)
Oct 18 00:30:04 Kobitons-Mac-mini-156 newsyslog[22220]: logfile turned overI've restarted WebPageTest to also use 1920x1080.
Fri, Oct 16
I've been trying to get Firefox to work better or rather understand what's wrong. I think there's multiple issues. One have been that there's already been running an instance. Since we running on a non root and shell am force-stop org.mozilla.firefox couldn't stop the device since we have multiple instances running(?) I've been restarting the instance to kill Firefox.
I configured for one of the test for WebPageReplay, push it on Monday to and let us see what changes.
I couldn't find that the WebPageTest API supports setting size, but you can configure it in the settings in /var/www/webpagetest/www/settings/settings.ini. I prepared for the change from 1024x768 to 1920x1080 in the settings, but I prefer pushing on Monday!
Thu, Oct 15
Wed, Oct 14
When we move the agent in-house we will use our own git copy.
Woho we do that now.
We will not fix this since with CLS its important that keep track of Speed Index alerts that fires.
For one off tests I think https://wikitech.wikimedia.org/wiki/Performance/WebPageTest/WPTBulkTester and Andy Davies spreadsheet is perfect. Adding it here for the next time we gonna do it.
Tue, Oct 13
The problem was the box that shared the wifi. Kobiton told me they couldn't connect to that wifi with desktop either. They restarted the box and it worked. They plan to replace it soon.
Mon, Oct 12
I updated Firefox on all phones today to run 81.1.2 but no luck when running tests. Now it always fail. Turned on the trace log for gecko driver:
Closing this since it was a Kobiton issue, fixed on Tuesday the coming week.
Sun, Oct 11
Fri, Oct 9
I think we should sync this, I see some moving parts (like WebPageTest auto update of code, update browsers etc) that we need to discuss, I'm not sure how it would work. I'll invite you for a start meeting on Monday @dpifke and then we can start by me going through the current setup and how it works. WebPageTest misses a lot of documentation and when I wrote our part it was mostly focused on making sure I would remember how set it up a second time.
Thu, Oct 8
Or actually I should try install Firefox beta on the phones and see if it works.
Haven't got this to work on the phones on Kobiton. Works on my machine though :) I think the version of Firefox will be released soon (in the middle of October) so lets wait for that + see if I can get a throttled wifi at home.
Yep I think we can try the wptserver-install, the image on AWS was created a couple of years before the official instructions so I've never looked into the dependencies for the server :)
Wed, Oct 7
Yep I added https://en.m.wikipedia.beta.wmflabs.org/wiki/Barack_Obama I think we only test one article there.
This has been fixed now. There reason was the configured proxy on the phone.
I talked to Kobiton: I back tracked when the temperature increased and they could see that they installed more phones at that time in the same cabinet. They gonna move the phones and let me know when they do it.
I asked Mozilla about there setups but the performance team doesn't do anything special, the phone host has fixed everything. I did some check for processes to try to find if something strange was running but couldn't find anything. Next step will be to restart the phone and let it rest for a couple of hours and check what kind of temperature we get then.
Created T264901 for documentation.
Metrics is slowly coming in:
All old jobs removed. Let me keep this task open until we see new data arriving and that I've added docs for error searching.
Yep the data storage is back to normal (6% usage on /data/). The problem is that all the tests that has been submitted during the downtime is being processed. To fix that I remove all jobs in /var/www/webpagetest/www/work/jobs/us-east and then we just get the new jobs.
It seems though that the tests don't run (I cannot see any new data in Graphite). Let me have look and if I cannot find it I'll ping you tonight @dpifke so we can work together on it so we get it going.
Tue, Oct 6
I'll add some new background: At the moment I'm not able to replicate our setup at Kobiton. I throttle the connection using gnirehtet to let the phone use the connection of my desktop. When testing out Firefox on Kobiton I've got problems where the first test works and the following tests do not work. I tested on multiple phones there and get the same result. But I can't reproduce on my own machine use gnirehtet, I get other problems/errors and I think the key issue here is that on my local all traffic + driving the device go though USB but at Kobiton we drive the device through USB and traffic through wifi.
I stopped the test for almost 4 hours and when starting again the temperature was 35 for ZY3222N2CZ and 33 for ZY2242HHQ8. So ZY3222N2CZ didn't come down at all. The temperature in the data center is 20.
FYI: Sometime ago I implemented the buffered flag in Browsertime but I needed to rollback to the old solution (inject the observer when the page start to load) because I could see that the buffered flag missed long tasks. Also see https://twitter.com/Joseph_Wynn/status/1310755139704074240 and https://bugs.chromium.org/p/chromium/issues/detail?id=1131385&q=long%20task%20buffered&can=2
Checking the nginx error logs in /var/log/nginx it looks like this: