Closed Bug 1565030 Opened 5 years ago Closed 4 years ago

mach browsertime throws exception when collecting visual metrics on Linux and OSX

Categories

(Firefox Build System :: General, defect, P2)

Product:
Firefox Build System
Component:
General
Platform:
Unspecified
Linux
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED WORKSFORME

People

(Reporter: denispal, Assigned: tarek)

References

(Blocks 1 open bug, Regression)

Details

(Keywords: regression)

When invoking browsertime without the mach system, everything works as expected:

$ node tools/browsertime/node_modules/browsertime/bin/browsertime.js --skipHar -b firefox -n 1 --firefox.binaryPath ~/nightly/firefox/firefox-bin --video true --visualMetrics true https://www.youtube.com
[2019-07-10 16:22:04] INFO: Running tests using Firefox - 1 iteration(s)
[2019-07-10 16:22:06] INFO: Testing url https://www.youtube.com iteration 1
[2019-07-10 16:22:28] INFO: https://www.youtube.com 0, backEndTime: 334ms, firstPaint: 466ms, firstVisualChange: 680ms, DOMContentLoaded: 1.54s, Load: 2.33s, speedIndex: 1186, perceptualSpeedIndex: 1275, contentfulSpeedIndex: 1230, visualComplete85: 1.84s, lastVisualChange: 3.12s, rumSpeedIndex: 334
[2019-07-10 16:22:28] INFO: Wrote data to browsertime-results/www.youtube.com/2019-07-10T162204-0400

However, with mach browsertime we are hitting quite a few errors:

denis@denis-xps:~/src/trunk$ ./mach browsertime --skipHar -b firefox -n 1 --firefox.binaryPath ~/nightly/firefox/firefox-bin --video true --visualMetrics true https://www.youtube.com
0:00.63 /home/denis/.mozbuild/node/bin/node /home/denis/src/trunk/tools/browsertime/node_modules/browsertime/bin/browsertime.js --skipHar -b firefox -n 1 --firefox.binaryPath /home/denis/nightly/firefox/firefox-bin --video true --visualMetrics true https://www.youtube.com
[2019-07-10 16:19:47] INFO: Running tests using Firefox - 1 iteration(s)
[2019-07-10 16:19:49] INFO: Testing url https://www.youtube.com iteration 1
[2019-07-10 16:20:07] ERROR: Visual Metrics failed to analyse the video Error: Command failed: /home/denis/src/trunk/obj-debug/_virtualenvs/init/bin/python /home/denis/src/trunk/tools/browsertime/node_modules/browsertime/vendor/visualmetrics.py --dir /home/denis/src/trunk/browsertime-results/www.youtube.com/2019-07-10T161947-0400/pages/www.youtube.com/data/video/images/1 --video /home/denis/src/trunk/browsertime-results/www.youtube.com/2019-07-10T161947-0400/pages/www.youtube.com/data/video/1.mp4 --orange --perceptual --contentful --force --renderignore 5 --json --viewport -q 75
ffmpeg version 4.0.3-static https://johnvansickle.com/ffmpeg/ Copyright (c) 2000-2018 the FFmpeg developers
built with gcc 6.3.0 (Debian 6.3.0-18+deb9u1) 20170516
configuration: --enable-gpl --enable-version3 --enable-static --disable-debug --disable-ffplay --disable-indev=sndio --disable-outdev=sndio --cc=gcc-6 --enable-fontconfig --enable-frei0r --enable-gnutls --enable-gray --enable-libaom --enable-libfribidi --enable-libass --enable-libvmaf --enable-libfreetype --enable-libmp3lame --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-librubberband --enable-libsoxr --enable-libspeex --enable-libvorbis --enable-libopus --enable-libtheora --enable-libvidstab --enable-libvo-amrwbenc --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzimg
libavutil 56. 14.100 / 56. 14.100
libavcodec 58. 18.100 / 58. 18.100
libavformat 58. 12.100 / 58. 12.100
libavdevice 58. 3.100 / 58. 3.100
libavfilter 7. 16.100 / 7. 16.100
libswscale 5. 1.100 / 5. 1.100
libswresample 3. 1.100 / 3. 1.100
libpostproc 55. 1.100 / 55. 1.100
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from '/home/denis/src/trunk/browsertime-results/www.youtube.com/2019-07-10T161947-0400/pages/www.youtube.com/data/video/1.mp4':
Metadata:
major_brand : isom
minor_version : 512
compatible_brands: isomiso2avc1mp41
encoder : Lavf58.12.100
Duration: 00:00:04.52, start: 0.000000, bitrate: 771 kb/s
Stream #0:0(und): Video: h264 (High) (avc1 / 0x31637661), yuv420p, 2732x1536, 768 kb/s, 7.96 fps, 25 tbr, 12800 tbn, 50 tbc (default)
Metadata:
handler_name : VideoHandler
Stream mapping:
Stream #0:0 -> #0:0 (h264 (native) -> png (native))
Press [q] to stop, [?] for help
Output #0, image2, to '/home/denis/src/trunk/browsertime-results/www.youtube.com/2019-07-10T161947-0400/pages/www.youtube.com/data/video/images/1/viewport.png':
Metadata:
major_brand : isom
minor_version : 512
compatible_brands: isomiso2avc1mp41
encoder : Lavf58.12.100
Stream #0:0(und): Video: png, rgb24, 2732x1536, q=2-31, 200 kb/s, 25 fps, 25 tbn, 25 tbc (default)
Metadata:
handler_name : VideoHandler
encoder : Lavc58.18.100 png
frame= 1 fps=0.0 q=-0.0 Lsize=N/A time=00:00:00.04 bitrate=N/A speed=0.334x
video:12kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: unknown

ffmpeg version 4.0.3-static https://johnvansickle.com/ffmpeg/ Copyright (c) 2000-2018 the FFmpeg developers
built with gcc 6.3.0 (Debian 6.3.0-18+deb9u1) 20170516
configuration: --enable-gpl --enable-version3 --enable-static --disable-debug --disable-ffplay --disable-indev=sndio --disable-outdev=sndio --cc=gcc-6 --enable-fontconfig --enable-frei0r --enable-gnutls --enable-gray --enable-libaom --enable-libfribidi --enable-libass --enable-libvmaf --enable-libfreetype --enable-libmp3lame --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-librubberband --enable-libsoxr --enable-libspeex --enable-libvorbis --enable-libopus --enable-libtheora --enable-libvidstab --enable-libvo-amrwbenc --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzimg
libavutil 56. 14.100 / 56. 14.100
libavcodec 58. 18.100 / 58. 18.100
libavformat 58. 12.100 / 58. 12.100
libavdevice 58. 3.100 / 58. 3.100
libavfilter 7. 16.100 / 7. 16.100
libswscale 5. 1.100 / 5. 1.100
libswresample 3. 1.100 / 3. 1.100
libpostproc 55. 1.100 / 55. 1.100
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from '/home/denis/src/trunk/browsertime-results/www.youtube.com/2019-07-10T161947-0400/pages/www.youtube.com/data/video/1.mp4':
Metadata:
major_brand : isom
minor_version : 512
compatible_brands: isomiso2avc1mp41
encoder : Lavf58.12.100
Duration: 00:00:04.52, start: 0.000000, bitrate: 771 kb/s
Stream #0:0(und): Video: h264 (High) (avc1 / 0x31637661), yuv420p, 2732x1536, 768 kb/s, 7.96 fps, 25 tbr, 12800 tbn, 50 tbc (default)
Metadata:
handler_name : VideoHandler
Stream mapping:
Stream #0:0 -> #0:0 (h264 (native) -> png (native))
Press [q] to stop, [?] for help
Output #0, image2, to '/home/denis/src/trunk/browsertime-results/www.youtube.com/2019-07-10T161947-0400/pages/www.youtube.com/data/video/images/1/viewport.png':
Metadata:
major_brand : isom
minor_version : 512
compatible_brands: isomiso2avc1mp41
encoder : Lavf58.12.100
Stream #0:0(und): Video: png, rgb24, 2732x1536, q=2-31, 200 kb/s, 25 fps, 25 tbn, 25 tbc (default)
Metadata:
handler_name : VideoHandler
encoder : Lavc58.18.100 png
frame= 1 fps=0.0 q=-0.0 Lsize=N/A time=00:00:00.04 bitrate=N/A speed=0.334x
video:12kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: unknown

at makeError (/home/denis/src/trunk/tools/browsertime/node_modules/browsertime/node_modules/execa/index.js:174:9)
at Promise.all.then.arr (/home/denis/src/trunk/tools/browsertime/node_modules/browsertime/node_modules/execa/index.js:278:16)
at <anonymous>
at process._tickCallback (internal/process/next_tick.js:188:7)

[2019-07-10 16:20:07] INFO: https://www.youtube.com 0, backEndTime: 321ms, firstPaint: 449ms, DOMContentLoaded: 1.49s, Load: 2.06s, rumSpeedIndex: 540
[2019-07-10 16:20:07] INFO: Wrote data to browsertime-results/www.youtube.com/2019-07-10T161947-0400

Hmm... an error in execa. This looks like Bug 1560193: do you have that patch applied?

Flags: needinfo?(dpalmeiro)

Yeah, I should. This is using c4b20b18bf97 from Wed Jul 10 22:14:41 2019.

Flags: needinfo?(dpalmeiro)

brennie: any thoughts here?

Flags: needinfo?(brennie)
Regressed by: 1560193

Just being pedantry here, could it be you have required python package installed in the global python, but don't have them installed in the virtualenv? I think ./mach browsertime starts to use the python inside the virtualenv.

The execa error just means that the executable it ran exited with a non-zero exit status.

:denispal, could you run the python in the virtualenv and confirm that the packages are installed?

If you run /home/denis/src/trunk/obj-debug/_virtualenvs/init/bin/pip list, you will get the list of packages available to the virtualenv.

If ssim and pillow (or PIL) are listed, then running the python in the virtualenv (/home/denis/src/trunk/obj-debug/_virtualenvs/init/bin/python) and attempting to import them should work:

>>> import ssim
>>> import PIL
Flags: needinfo?(brennie) → needinfo?(dpalmeiro)

(In reply to Barret Rennie [:barret] (he/him) from comment #5)

Yes, this seems to be caused by pyssim 0.4 refusing to install on my system for some reason. However, if I manually install it with /home/denis/src/trunk/obj-x86_64-pc-linux-gnu/_virtualenvs/init/bin/pip install pyssim everything works fine for me.

Flags: needinfo?(dpalmeiro)
Regressed by: 1543247
No longer regressed by: 1560193

I'm also seeing this on OSX:

Roberts-MacBook-Pro-1927:~ rwood$ ./mach browsertime --browser firefox --firefox.binaryPath /Users/rwood/mozilla-central/obj-ff-dbg/dist/NightlyDebug.app/Contents/MacOS/firefox --verbose -n 1 https://www.mozilla.org --video
....
[2019-11-20 10:17:27] INFO: Running tests using Firefox - 1 iteration(s)
[2019-11-20 10:17:34] INFO: Testing url https://www.mozilla.org iteration 1
[2019-11-20 10:17:34] INFO: Start firefox window recorder.
[2019-11-20 10:17:41] INFO: Stop firefox window recorder.
[2019-11-20 10:17:49] ERROR: Visual Metrics failed to analyse the video TypeError: Cannot read property 'visualMetrics' of undefined
at Iteration.run (/Users/rwood/mozilla-central/tools/browsertime/node_modules/browsertime/lib/core/engine/iteration.js:207:28)
at <anonymous>
at process._tickCallback (internal/process/next_tick.js:188:7)

Priority: -- → P2
Summary: mach browsertime throws exception when collecting visual metrics on Linux → mach browsertime throws exception when collecting visual metrics on Linux and OSX
See Also: → 1601284
Assignee: nobody → tarek

FYI, I cannot reproduce this issue anymore, working great for me now on OSX (Catalina 10.15.2).

Rob and I can't reproduce this anymore. Feel free to reopen in case you get the issue again

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → WORKSFORME
Has Regression Range: --- → yes
You need to log in before you can comment on or make changes to this bug.