karma-firefox-launcher icon indicating copy to clipboard operation
karma-firefox-launcher copied to clipboard

Firefox 68.x won't run (from inside docker)

Open davidkarlsen opened this issue 6 years ago • 48 comments

I've used FirefoxHeadless inside docker just fine for a long time - but with v68 of ffox it just won't work.

19:02:46 [32m09 08 2019 17:02:44.991:INFO [launcher]: [39mStarting browser FirefoxHeadless
19:03:54 [33m09 08 2019 17:03:45.123:WARN [launcher]: [39mFirefoxHeadless have not captured in 60000 ms, killing.
19:03:54 [32m09 08 2019 17:03:45.598:INFO [launcher]: [39mTrying to start FirefoxHeadless again (1/2).
19:04:54 [33m09 08 2019 17:04:45.602:WARN [launcher]: [39mFirefoxHeadless have not captured in 60000 ms, killing.
19:04:54 [32m09 08 2019 17:04:45.724:INFO [launcher]: [39mTrying to start FirefoxHeadless again (2/2).
19:05:50 [33m09 08 2019 17:05:45.855:WARN [launcher]: [39mFirefoxHeadless have not captured in 60000 ms, killing.
19:05:50 [91m09 08 2019 17:05:47.109:ERROR [launcher]: [39mFirefoxHeadless failed 2 times (timeout). Giving up.

Karma config:

// Karma configuration file, see link for more information
// https://karma-runner.github.io/0.13/config/configuration-file.html

//https://hackernoon.com/running-karma-tests-with-headless-chrome-inside-docker-ae4aceb06ed3
const isDocker = require('is-docker')();


module.exports = function (config) {
  config.set({
    concurrency: 1, // avoid clash when ffox and chrome run at the same time
    customLaunchers: {
      ChromeCustom: {
        base: 'ChromeHeadless',
        // We must disable the Chrome sandbox when running Chrome inside Docker (Chrome's sandbox needs
        // more permissions than Docker allows by default)
        flags: isDocker ? ['--no-sandbox'] : []
      }
    },
    basePath: '',
    frameworks: ['jasmine', '@angular-devkit/build-angular'],
    plugins: [
      require('karma-jasmine'),
      require('karma-coverage'),
      require('karma-coverage-istanbul-reporter'),
      require('karma-chrome-launcher'),
      require('karma-firefox-launcher'),
      require('karma-junit-reporter'),
      //require('karma-remap-istanbul'),
      require('@angular-devkit/build-angular/plugins/karma')
    ],
    files: [
    ],
    preprocessors: {
      './src/app/**/*.ts': ['coverage']
    },
    coverageReporter: {
      type:'lcov',
      dir:'target/coverage'
    },
    mime: {
      'text/x-typescript': ['ts','tsx']
    },
    angularCli: {
      config: './angular-cli.json',
      environment: 'dev'
    },
    reporters: config.angularCli && config.angularCli.codeCoverage
              ? ['progress', 'junit','coverage-istanbul','coverage']
              : ['progress', 'junit'],
    junitReporter: {
      outputDir: 'target/junit-reports'
      //outputDir: 'target/junit-dir: require('path').join(__dirname, 'coverage'), reports'
    },
    port: 9876,
    colors: true,
    autoWatch: true,
    browsers: ['FirefoxHeadless','ChromeCustom'],
    singleRun: false
  });
};

Image I am using: https://hub.docker.com/r/evryfs/node-dev-docker/ (node12 tag)

davidkarlsen avatar Aug 09 '19 17:08 davidkarlsen

I'll have to try that image later to see what's going on.

There's no problem with docker, per se, however. See https://github.com/karma-runner/karma-firefox-launcher/issues/93#issuecomment-519333245 for an example of some steps to run karma-firefox-launcher in docker that worked for me recently with Firefox 68.

birtles avatar Aug 10 '19 01:08 birtles

In issue #93 it runs with xvfb instead of headless. Here is some more logging:

20:49:46 [36m09 08 2019 18:49:45.541:DEBUG [web-server]: [39mserving: /app/node_modules/karma/static/karma.js
20:49:46 [36m09 08 2019 18:49:46.165:DEBUG [web-server]: [39mserving: /app/node_modules/karma/static/favicon.ico
20:50:25 [33m09 08 2019 18:50:19.098:WARN [launcher]: [39mFirefoxHeadless have not captured in 60000 ms, killing.
20:50:25 [36m09 08 2019 18:50:19.104:DEBUG [launcher]: [39mBEING_CAPTURED -> BEING_KILLED
20:50:25 [36m09 08 2019 18:50:19.427:DEBUG [launcher]: [39mProcess FirefoxHeadless exited with code null and signal SIGTERM
20:50:25 [36m09 08 2019 18:50:19.427:DEBUG [temp-dir]: [39mCleaning temp dir /tmp/karma-92895928
20:50:25 [32m09 08 2019 18:50:19.450:INFO [launcher]: [39mTrying to start FirefoxHeadless again (1/2).
20:50:25 [36m09 08 2019 18:50:19.450:DEBUG [launcher]: [39mBEING_KILLED -> RESTARTING
20:50:25 [36m09 08 2019 18:50:19.450:DEBUG [launcher]: [39mRESTARTING -> FINISHED
20:50:25 [36m09 08 2019 18:50:19.450:DEBUG [launcher]: [39mFINISHED -> FINISHED
20:50:25 [36m09 08 2019 18:50:19.451:DEBUG [launcher]: [39mRestarting FirefoxHeadless
20:50:25 [36m09 08 2019 18:50:19.451:DEBUG [launcher]: [39mFINISHED -> BEING_CAPTURED
20:50:25 [36m09 08 2019 18:50:19.451:DEBUG [temp-dir]: [39mCreating temp dir at /tmp/karma-92895928
20:50:25 [36m09 08 2019 18:50:19.452:DEBUG [launcher]: [39mfirefox http://localhost:9876/?id=92895928 -profile /tmp/karma-92895928 -no-remote -wait-for-browser -headless --start-debugger-server 6000
20:50:40 [36m09 08 2019 18:50:38.522:DEBUG [web-server]: [39mserving (cached): /app/node_modules/karma/static/client.html
20:51:27 [33m09 08 2019 18:51:20.007:WARN [launcher]: [39mFirefoxHeadless have not captured in 60000 ms, killing.
20:51:27 [36m09 08 2019 18:51:20.071:DEBUG [launcher]: [39mBEING_CAPTURED -> BEING_KILLED
20:51:27 [36m09 08 2019 18:51:20.430:DEBUG [launcher]: [39mProcess FirefoxHeadless exited with code null and signal SIGTERM
20:51:27 [36m09 08 2019 18:51:20.437:DEBUG [temp-dir]: [39mCleaning temp dir /tmp/karma-92895928
20:51:27 [32m09 08 2019 18:51:20.447:INFO [launcher]: [39mTrying to start FirefoxHeadless again (2/2).
20:51:27 [36m09 08 2019 18:51:20.447:DEBUG [launcher]: [39mBEING_KILLED -> RESTARTING
20:51:27 [36m09 08 2019 18:51:20.447:DEBUG [launcher]: [39mRESTARTING -> FINISHED
20:51:27 [36m09 08 2019 18:51:20.448:DEBUG [launcher]: [39mFINISHED -> FINISHED
20:51:27 [36m09 08 2019 18:51:20.448:DEBUG [launcher]: [39mRestarting FirefoxHeadless
20:51:27 [36m09 08 2019 18:51:20.448:DEBUG [launcher]: [39mFINISHED -> BEING_CAPTURED
20:51:27 [36m09 08 2019 18:51:20.448:DEBUG [temp-dir]: [39mCreating temp dir at /tmp/karma-92895928
20:51:27 [36m09 08 2019 18:51:20.448:DEBUG [launcher]: [39mfirefox http://localhost:9876/?id=92895928 -profile /tmp/karma-92895928 -no-remote -wait-for-browser -headless --start-debugger-server 6000
20:51:27 [36m09 08 2019 18:51:25.934:DEBUG [web-server]: [39mserving (cached): /app/node_modules/karma/static/client.html
20:51:49 [36m09 08 2019 18:51:45.751:DEBUG [web-server]: [39mserving (cached): /app/node_modules/karma/static/karma.js
20:51:49 [36m09 08 2019 18:51:46.379:DEBUG [web-server]: [39mserving (cached): /app/node_modules/karma/static/favicon.ico
20:52:21 [33m09 08 2019 18:52:20.447:WARN [launcher]: [39mFirefoxHeadless have not captured in 60000 ms, killing.
20:52:21 [36m09 08 2019 18:52:20.448:DEBUG [launcher]: [39mBEING_CAPTURED -> BEING_KILLED
20:52:21 [36m09 08 2019 18:52:20.593:DEBUG [launcher]: [39mProcess FirefoxHeadless exited with code null and signal SIGTERM
20:52:21 [36m09 08 2019 18:52:20.594:DEBUG [temp-dir]: [39mCleaning temp dir /tmp/karma-92895928
20:52:21 [91m09 08 2019 18:52:20.605:ERROR [launcher]: [39mFirefoxHeadless failed 2 times (timeout). Giving up.
20:52:21 [36m09 08 2019 18:52:20.615:DEBUG [launcher]: [39mBEING_KILLED -> FINISHED
20:52:21 [36m09 08 2019 18:52:20.615:DEBUG [launcher]: [39mFINISHED -> FINISHED
Cancelling nested steps due to timeout

what is odd is that the same test runs fine on my mac (e.g. not in docker)

davidkarlsen avatar Aug 10 '19 10:08 davidkarlsen

@birtles Same image just ffox 67 works: https://github.com/evryfs/node-dev-docker/compare/test - exact same code & setup running - this must be directly tied to ffox version and the fact it's running in docker.

davidkarlsen avatar Aug 10 '19 11:08 davidkarlsen

There were a few changes to startup discussed on dev-platform in March but most of those seemed to land in Firefox 67 (e.g. bug 1535144 and bug 1535021).

The next step is probably to look through bugs in the Startup and Profile System component that landed in the 68 timeframe. Maybe @mossop might have some pointers about where to start.

birtles avatar Aug 12 '19 09:08 birtles

@birtles but why does it work fine outside of docker on my Mac?

davidkarlsen avatar Aug 12 '19 15:08 davidkarlsen

If it is working with xvfb but not headless then this is likely a headless widget issue, probably accidentally depending on a windowing system existing somwhere. @brendandahl might have ideas.

@birtles but why does it work fine outside of docker on my Mac?

Inside docker you have no windowing system and are presumably running the linux version of Firefox. Outside you have a windowing system and are running the osx version. Those are two very different situations.

Mossop avatar Aug 12 '19 15:08 Mossop

I'm not familiar with karma-runner, but is there a way to capture the startup output of Firefox in the docker image? That would probably tells us where it's crashing.

Alternatively, you could just try to start firefox inside your docker image in headless mode firefox --headless --profile <some empty folder>.

brendandahl avatar Aug 12 '19 18:08 brendandahl

@brendandahl see comment above for debug log output

davidkarlsen avatar Aug 12 '19 18:08 davidkarlsen

It doesn't look like that is capturing all of stdout/stderr from Firefox. There should hopefully be a message You are running in headless mode. I suppose it's possible it's crashing even before that though.

brendandahl avatar Aug 12 '19 20:08 brendandahl

@davidkarlsen I tried debugging your image today but it seems to work for me (had to disable the proxy however).

Steps I ran:

> docker pull evryfs/node-dev-docker:node12
> docker run -i -t evryfs/node-dev-docker:node12 /bin/bash
docker> firefox --headless --profile /tmp
*** You are running in headless mode.
(No errors show. Let's try with arguments more similar to what karma-firefox-launcher uses.)
^C
docker> firefox -headless -profile /tmp -no-remote -wait-for-browser --start-debugger-server 6000
*** You are running in headless mode.
(No errors show)
^C
docker> git clone https://github.com/karma-runner/karma-firefox-launcher.git
Cloning into 'karma-firefox-launcher'...
fatal: unable to access 'https://github.com/karma-runner/karma-firefox-launcher.git/': Failed to connect to proxy.evry.com port 8080: Connection refused
docker> unset HTTP_PROXY
docker> unset HTTPS_PROXY
docker> unset http_proxy
docker> unset https_proxy
docker> git clone https://github.com/karma-runner/karma-firefox-launcher.git
docker> cd karma-firefox-launcher
docker> yarn install
docker> apt-get install nano
docker> nano karma.conf.js
(Remove 'Firefox' entry, leaving only 'FirefoxHeadless')
docker> yarn test
yarn run v1.17.3
$ karma start --single-run
13 08 2019 03:18:45.457:INFO [karma-server]: Karma v4.2.0 server started at http://0.0.0.0:9876/
13 08 2019 03:18:45.460:INFO [launcher]: Launching browsers FirefoxHeadless with concurrency unlimited
13 08 2019 03:18:45.464:INFO [launcher]: Starting browser FirefoxHeadless
13 08 2019 03:18:47.679:INFO [Firefox 68.0.0 (Linux 0.0.0)]: Connected on socket lH-3IYR2_YaEygz1AAAA with id 93797292
.
Firefox 68.0.0 (Linux 0.0.0): Executed 1 of 1 SUCCESS (0.003 secs / 0.001 secs)
Done in 3.39s.

birtles avatar Aug 13 '19 03:08 birtles

How strange - I'll do some other testing myself. Linking a similar issue: https://github.com/DevExpress/testcafe/issues/4031

davidkarlsen avatar Aug 13 '19 05:08 davidkarlsen

OK, on my desktop (MacOS) in runs fine, on CI server it stalls at:

yarn test
yarn run v1.17.3
$ karma start --single-run
14 08 2019 21:45:39.178:INFO [karma-server]: Karma v4.2.0 server started at http://0.0.0.0:9876/
14 08 2019 21:45:39.180:INFO [launcher]: Launching browsers FirefoxHeadless with concurrency unlimited
14 08 2019 21:45:39.186:INFO [launcher]: Starting browser FirefoxHeadless

it runs docker:

docker version
Client:
 Version:         1.13.1
 API version:     1.26
 Package version: docker-1.13.1-94.gitb2f74b2.el7.x86_64
 Go version:      go1.10.8
 Git commit:      b2f74b2/1.13.1
 Built:           Mon Feb 25 14:45:39 2019
 OS/Arch:         linux/amd64

Server:
 Version:         1.13.1
 API version:     1.26 (minimum version 1.12)
 Package version: docker-1.13.1-94.gitb2f74b2.el7.x86_64
 Go version:      go1.10.8
 Git commit:      b2f74b2/1.13.1
 Built:           Mon Feb 25 14:45:39 2019
 OS/Arch:         linux/amd64
 Experimental:    false

davidkarlsen avatar Aug 14 '19 21:08 davidkarlsen

A bit impatient, it got further but eventually failed:

yarn test
yarn run v1.17.3
$ karma start --single-run
14 08 2019 21:45:39.178:INFO [karma-server]: Karma v4.2.0 server started at http://0.0.0.0:9876/
14 08 2019 21:45:39.180:INFO [launcher]: Launching browsers FirefoxHeadless with concurrency unlimited
14 08 2019 21:45:39.186:INFO [launcher]: Starting browser FirefoxHeadless
14 08 2019 21:46:39.326:WARN [launcher]: FirefoxHeadless have not captured in 60000 ms, killing.
14 08 2019 21:46:40.099:INFO [launcher]: Trying to start FirefoxHeadless again (1/2).
14 08 2019 21:47:23.907:INFO [Firefox 68.0.0 (Linux 0.0.0)]: Connected on socket n4o2_4kwR-_xm8J-AAAA with id 4482926
14 08 2019 21:47:56.170:WARN [Firefox 68.0.0 (Linux 0.0.0)]: Disconnected (0 times)reconnect failed before timeout of 2000ms (ping timeout)
Firefox 68.0.0 (Linux 0.0.0) ERROR
  Disconnectedreconnect failed before timeout of 2000ms (ping timeout)
Firefox 68.0.0 (Linux 0.0.0): Executed 0 of 0 DISCONNECTED (32.25 secs / 0 secs)
error Command failed with exit code 1.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.

davidkarlsen avatar Aug 14 '19 21:08 davidkarlsen

So, just to check, on your desktop you're also running it inside docker, right? I thought docker was supposed to help creating a reproducible environment ;)

That's certainly an older version of docker but I wonder if CI is setting environment variables or otherwise interacting with the container in a way that might affect the runtime environment.

I've seen karma-firefox-launcher just not respond and timeout when it can't find the firefox binary so if CI is clobbering your PATH or something in a manner that affects 68 but not 67, I guess that's possible.

birtles avatar Aug 15 '19 00:08 birtles

I had the same problem with Firefox 68.0.1, but 68.0.2 seems to work.

Edit: I should mention that I already had the shm set to 2gb. 68.0.1 failed to launch, 68.0.2 seems to be ok.

stevenhair avatar Aug 15 '19 20:08 stevenhair

@birtles yes, docker on desktop too, CI does not alter env.

davidkarlsen avatar Aug 15 '19 21:08 davidkarlsen

If the same image running the same steps is producing different results, then there must be something different about the environment, even if it's the docker version, network speed, etc. but without access to your CI setup I'm not sure there's much I can do to help other than dig through changes made in 68.

If 68.0.2 is indeed working then that might provide a clue. Digging through the changes since 68.0.1, the most obvious candidate is Bug 1567614 but that should only affect Windows as far as I can tell.

birtles avatar Aug 15 '19 23:08 birtles

68.0.2 fails as well, 67.0.4 works fine - it is definitely tied to ffox version.

davidkarlsen avatar Aug 15 '19 23:08 davidkarlsen

Note for anyone testing the images: the master / node12 tag is now on a downgraded ffox version, while the tag ffoxbroken tag points at latest ffox (which is malfunctioning).

davidkarlsen avatar Aug 15 '19 23:08 davidkarlsen

@glandium Are you aware of any changes to launching Firefox on Debian introduced in 68?

This is about karma-firefox-launcher which apparently has stopped working for various folks using it in Docker in CI as of Firefox 68. In this particular instance, the docker image appears to be Debian-based (based on node:12.8-stretch).

birtles avatar Aug 16 '19 00:08 birtles

Not aware of anything.

glandium avatar Aug 16 '19 02:08 glandium

The thing I notice is that it just seems incredibly slow - it hogs CPU and runs on close to 100% CPU but still takes an age to get running - and fails due to this it seems. Was anything changed in use of libraries, or other capabilities docker might slow down?

davidkarlsen avatar Aug 16 '19 08:08 davidkarlsen

I am also seeing this:

16 08 2019 08:01:24.483:INFO [launcher]: Starting browser FirefoxHeadless

16 08 2019 08:04:51.187:ERROR [launcher]: Cannot start FirefoxHeadless

	*** You are running in headless mode.

[Parent 134, Gecko_IOThread] WARNING: pipe error: Broken pipe: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 727



16 08 2019 08:04:51.342:ERROR [launcher]: FirefoxHeadless stdout: 

16 08 2019 08:04:51.344:ERROR [launcher]: FirefoxHeadless stderr: *** You are running in headless mode.

[Parent 134, Gecko_IOThread] WARNING: pipe error: Broken pipe: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 727



16 08 2019 08:04:51.905:INFO [launcher]: Trying to start FirefoxHeadless again (1/2).

16 08 2019 08:05:24.194:INFO [Firefox 68.0.0 (Linux 0.0.0)]: Connected on socket c8jqifCmOpVt7xaUAAAB with id 54449045

16 08 2019 08:05:55.838:WARN [Firefox 68.0.0 (Linux 0.0.0)]: Disconnected (0 times)reconnect failed before timeout of 2000ms (ping timeout)

Firefox 68.0.0 (Linux 0.0.0) ERROR

  Disconnectedreconnect failed before timeout of 2000ms (ping timeout)





16 08 2019 08:05:56.128:INFO [launcher]: Starting browser ChromeHeadless

16 08 2019 08:05:57.057:INFO [HeadlessChrome 76.0.3809 (Linux 0.0.0)]: Connected on socket NCI_VirZUOQzr0S3AAAC with id 92170417

davidkarlsen avatar Aug 16 '19 08:08 davidkarlsen

I am also seeing this:

16 08 2019 08:01:24.483:INFO [launcher]: Starting browser FirefoxHeadless

16 08 2019 08:04:51.187:ERROR [launcher]: Cannot start FirefoxHeadless

	*** You are running in headless mode.

[Parent 134, Gecko_IOThread] WARNING: pipe error: Broken pipe: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 727

Oh, that's super helpful. So know we now that at least it is finding the binary.

Digging into related issues, this seems really promising:

  • https://bugzilla.mozilla.org/show_bug.cgi?id=1567168#c9

Specifically, it points to problems with shared memory affecting firefox running in docker containers and includes:

Why did this happen in the move from FF 67 to FF 68? Because I did disable SHM usage in FF by disabling E10s using user_pref("browser.tabs.remote.autostart", false);, but as this bug (https://bugzilla.mozilla.org/show_bug.cgi?id=1548941) says, support for this flag was removed in FF 68.

karma-firefox-launcher likewise includes user_pref("browser.tabs.remote.autostart", false) (and user_pref("browser.tabs.remote.autostart.2", false)).

The solution seems to be running docker with --shm-size 2g or mounting -v /dev/shm:/dev/shm.

See:

  • https://bugzilla.mozilla.org/show_bug.cgi?id=1245239
  • https://github.com/SeleniumHQ/docker-selenium/issues/388
  • https://github.com/SeleniumHQ/docker-selenium/issues/397
  • https://github.com/mozilla/geckodriver/issues/285
  • https://github.com/SeleniumHQ/docker-selenium/blob/master/README.md#running-the-images

Ultimately, though it seems like this is tracked by:

  • https://bugzilla.mozilla.org/show_bug.cgi?id=1464690

birtles avatar Aug 19 '19 00:08 birtles

I have also seen those issues and tried running with shm_size 2g but the problem persist

davidkarlsen avatar Aug 19 '19 06:08 davidkarlsen

Ok, I suggest trying some of those other solutions. I don't think there's anything more we can do here for now.

birtles avatar Aug 19 '19 06:08 birtles

Would someone be able to try a debug build of Firefox?

brendandahl avatar Aug 19 '19 18:08 brendandahl

@brendandahl

20:55:12 [32m19 08 2019 18:55:11.424:INFO [karma-server]: [39mKarma v4.2.0 server started at http://0.0.0.0:9876/
20:55:12 [32m19 08 2019 18:55:11.428:INFO [launcher]: [39mLaunching browsers FirefoxHeadless, ChromeCustom with concurrency 1
20:55:12 [32m19 08 2019 18:55:11.431:INFO [launcher]: [39mStarting browser FirefoxHeadless
20:55:39 [32m19 08 2019 18:55:36.666:INFO [Firefox 68.0.0 (Linux 0.0.0)]: [39mConnected on socket OOa9F7ZjnZljlxFWAAAA with id 35543876
20:56:11 [33m19 08 2019 18:56:06.686:WARN [Firefox 68.0.0 (Linux 0.0.0)]: [39mDisconnected (0 times), because no message in 30000 ms.
20:56:11 Firefox 68.0.0 (Linux 0.0.0) ERROR
20:56:11   Disconnected, because no message in 30000 ms.
20:56:11 
20:56:11 

davidkarlsen avatar Aug 19 '19 18:08 davidkarlsen

hang on! That actually got further. I had some bad config. It might actually fail on a bad test.

davidkarlsen avatar Aug 19 '19 19:08 davidkarlsen

Yes - that version consistently works OK! https://github.com/evryfs/node-dev-docker/blob/ffoxbroken/Dockerfile

davidkarlsen avatar Aug 19 '19 19:08 davidkarlsen