Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

restartOnFileChange doesn't work after run completes normally #1640

Closed
scottohara opened this issue Oct 19, 2015 · 5 comments · Fixed by karronoli/redpen#10 · May be fixed by Omrisnyk/npm-lockfiles#122 or Omrisnyk/npm-lockfiles#132
Closed

Comments

@scottohara
Copy link

I just upgraded to 0.13.11 and tried the restartOnFileChange option out for the first time.

An excerpt from my karma.conf.js is:

  autoWatch: true,
  singleRun: false,
  restartOnFileChange: true
}

When I kick off a test run, and then quickly edit/save a watched file; I see that the current run is cancelled and a new run starts, as per the docs.

I can repeat this process any number of times; with the same results each time (current run is cancelled, new run starts).

However, if I let the current run continue all the way through to completion; then make a change to a watched file, a new run will start, but it doesn't run any tests.

Example console output is below. It shows:

  1. the end of a successful run (Finished in 39.126 secs, 1325 tests completed)
  2. a change detected in the file foo.js
  3. another run triggered, but with 0 tests completed:
Finished in 39.136 secs / 1.009 secs

SUMMARY:
✔ 1325 tests completed
19 10 2015 16:42:45.754:INFO [watcher]: Changed file "foo.js".

Finished in 0.002 secs / 0 secs

SUMMARY:
✔ 0 tests completed
@Nr9
Copy link

Nr9 commented Nov 9, 2015

I have the same problem

@alexander-ossur
Copy link

Also got this issue. It does not seem random and reproduces every time then |restartOnFileChange| is true

gulp test-chrome-extension
(node:676) fs: re-evaluating native module sources is not supported. If you are using the graceful-fs module, please update it to a more recent version.
[07:49:33] Using gulpfile C:\Workspace\market\gulpfile.js
[07:49:33] Starting 'test-chrome-extension'...
03 07 2016 07:49:34.134:WARN [karma]: No captured browser, open http://localhost:9876/
03 07 2016 07:49:34.146:INFO [karma]: Karma v1.1.0 server started at http://localhost:9876/
03 07 2016 07:49:34.147:INFO [launcher]: Launching browser Chrome with unlimited concurrency
03 07 2016 07:49:34.174:INFO [launcher]: Starting browser Chrome
03 07 2016 07:49:35.591:INFO [Chrome 51.0.2704 (Windows 8.1 0.0.0)]: Connected on socket /#a7QsDyM3ifDa2XX5AAAA with id 25769336
Chrome 51.0.2704 (Windows 8.1 0.0.0): Executed 1 of 1 SUCCESS (0.01 secs / 0.001 secs)
03 07 2016 07:49:42.460:INFO [watcher]: Changed file "C:/Workspace/market/dist/chrome-extension/1.0.0/application/chrome/module/test-suite/tools.spec.js".
03 07 2016 07:52:29.802:INFO [watcher]: Changed file "C:/Workspace/market/dist/chrome-extension/1.0.0/application/chrome/module/test-suite/tools.spec.js".

... and no running tests

@levithomason
Copy link
Contributor

I have similar issues with this option. Tests run the first time, but when changing a file one of two things will happen, no tests will run, or no tests will run and the browser disconnects.

It looks like, after a file change, tests are being executed before any files are served. Here is a comparison with DEBUG logging and also logging all karma.Server events. I've added my own headers to help delineate successive file change and re-runs.

Test

I have a minimal test:

describe('restartOnFileChange', () => {
  it('skips tests after the first run', () => {
    (true).should.equal(true)
  })
})

With restartOnFileChange: true

I have enabled DEBUG logging here. I have also added karma.Server logs that simply log every event that karma.Server() is emitting (karma.Server: browser_start, etc):

#############################################################################
#                                                                           #
#                                 FIRST RUN                                 #
#              All is well, files are requested, then tests run.            #
#############################################################################
11 11 2016 11:52:56.658:DEBUG [config]: No config file specified.
11 11 2016 11:52:56.663:DEBUG [plugin]: Loading karma-* from /PROJECT/node_modules
11 11 2016 11:52:56.665:DEBUG [plugin]: Loading plugin /PROJECT/node_modules/karma-coverage.
11 11 2016 11:52:56.772:DEBUG [plugin]: Loading plugin /PROJECT/node_modules/karma-mocha.
11 11 2016 11:52:56.774:DEBUG [plugin]: Loading plugin /PROJECT/node_modules/karma-mocha-reporter.
11 11 2016 11:52:56.775:DEBUG [plugin]: Loading plugin /PROJECT/node_modules/karma-phantomjs-launcher.
11 11 2016 11:52:56.779:DEBUG [plugin]: Loading plugin /PROJECT/node_modules/karma-webpack-with-fast-source-maps.
11 11 2016 11:52:56.871:DEBUG [web-server]: Instantiating middleware
11 11 2016 11:52:56.872:DEBUG [reporter]: Trying to load reporter: mocha
11 11 2016 11:52:56.874:DEBUG [reporter]: Trying to load color-version of reporter: mocha (mocha_color)
11 11 2016 11:52:56.874:DEBUG [reporter]: Couldn't load color-version.
11 11 2016 11:52:56.874:DEBUG [reporter]: Trying to load reporter: coverage
11 11 2016 11:52:56.875:DEBUG [reporter]: Trying to load color-version of reporter: coverage (coverage_color)
11 11 2016 11:52:56.875:DEBUG [reporter]: Couldn't load color-version.
11 11 2016 11:53:02.088:DEBUG [karma]: List of files has changed, trying to execute
11 11 2016 11:53:02.089:WARN [karma]: No captured browser, open http://localhost:9876/
11 11 2016 11:53:02.092:DEBUG [watcher]: Watching "/PROJECT/lib/test/main.test.js"
11 11 2016 11:53:02.097:INFO [karma]: Karma v1.3.0 server started at http://localhost:9876/
karma.Server: listening
11 11 2016 11:53:02.097:INFO [launcher]: Launching browser PhantomJS with unlimited concurrency
11 11 2016 11:53:02.150:INFO [launcher]: Starting browser PhantomJS
11 11 2016 11:53:02.150:DEBUG [temp-dir]: Creating temp dir at /var/folders/sl/0sdljlvx2h54p0zfc6xwlq3r0000gn/T/karma-46680807
11 11 2016 11:53:02.153:DEBUG [launcher]: /PROJECT/node_modules/phantomjs-prebuilt/lib/phantom/bin/phantomjs /var/folders/sl/0sdljlvx2h54p0zfc6xwlq3r0000gn/T/karma-46680807/capture.js
11 11 2016 11:53:02.802:DEBUG [web-server]: serving: /PROJECT/node_modules/karma/static/client.html
11 11 2016 11:53:02.810:DEBUG [web-server]: serving: /PROJECT/node_modules/karma/static/karma.js
11 11 2016 11:53:02.844:DEBUG [karma]: A browser has connected on socket /#ngqKXJPyANov64juAAAA
11 11 2016 11:53:02.847:DEBUG [web-server]: upgrade /socket.io/?EIO=3&transport=websocket&sid=ngqKXJPyANov64juAAAA
11 11 2016 11:53:02.867:INFO [PhantomJS 2.1.1 (Mac OS X 0.0.0)]: Connected on socket /#ngqKXJPyANov64juAAAA with id 46680807
karma.Server: browser_register
11 11 2016 11:53:02.868:DEBUG [launcher]: PhantomJS (id 46680807) captured in 0.771 secs
11 11 2016 11:53:02.868:DEBUG [karma]: All browsers are ready, executing
11 11 2016 11:53:02.868:DEBUG [karma]: Captured 1 browsers
karma.Server: run_start

START:
11 11 2016 11:53:02.872:DEBUG [phantomjs.launcher]:

11 11 2016 11:53:02.873:DEBUG [middleware:karma]: custom files null null
11 11 2016 11:53:02.873:DEBUG [middleware:karma]: Serving static request /context.html
11 11 2016 11:53:02.874:DEBUG [web-server]: serving: /PROJECT/node_modules/karma/static/context.html
11 11 2016 11:53:02.876:DEBUG [middleware:source-files]: Requesting /absolute/PROJECT/node_modules/mocha/mocha.css?68699fe2e12cd4578e48892d46c27fe84ee09b09 /
11 11 2016 11:53:02.876:DEBUG [middleware:source-files]: Fetching /PROJECT/node_modules/mocha/mocha.css
11 11 2016 11:53:02.876:DEBUG [web-server]: serving (cached): /PROJECT/node_modules/mocha/mocha.css
11 11 2016 11:53:02.877:DEBUG [web-server]: serving: /PROJECT/node_modules/karma/static/context.js
11 11 2016 11:53:02.877:DEBUG [middleware:source-files]: Requesting /absolute/PROJECT/node_modules/mocha/mocha.js?bc2b9e2e7b386b405368c9247d419c9a1d2718c8 /
11 11 2016 11:53:02.877:DEBUG [middleware:source-files]: Fetching /PROJECT/node_modules/mocha/mocha.js
11 11 2016 11:53:02.878:DEBUG [middleware:source-files]: Requesting /absolute/PROJECT/node_modules/karma-mocha/lib/adapter.js?e8826109cf50b958ee4bd667517729ffdd4de363 /
11 11 2016 11:53:02.878:DEBUG [middleware:source-files]: Fetching /PROJECT/node_modules/karma-mocha/lib/adapter.js
11 11 2016 11:53:02.878:DEBUG [middleware:source-files]: Requesting /absolute/PROJECT/lib/test/main.test.js?28190b21b2bd15e90f78cc70ec7104bc4c32672c /
11 11 2016 11:53:02.878:DEBUG [middleware:source-files]: Fetching /PROJECT/lib/test/main.test.js
11 11 2016 11:53:02.878:DEBUG [web-server]: serving (cached): /PROJECT/node_modules/mocha/mocha.js
11 11 2016 11:53:02.881:DEBUG [web-server]: serving (cached): /PROJECT/node_modules/karma-mocha/lib/adapter.js
11 11 2016 11:53:02.881:DEBUG [web-server]: serving (cached): /PROJECT/lib/test/main.test.js
karma.Server: browser_start
  restartOnFileChange
    ✔ skips tests after the first run
karma.Server: browser_complete
karma.Server: run_complete

Finished in 0.01 secs / 0.004 secs

SUMMARY:
✔ 1 test completed

#############################################################################
#                                                                           #
#                         CHANGED FILE - SECOND RUN                         #
#           0 tests run immediately, without fetching any files.            #
#                                                                           #
#############################################################################
11 11 2016 11:53:14.344:DEBUG [karma]: List of files has changed, trying to execute
11 11 2016 11:53:14.344:DEBUG [karma]: All browsers are ready, executing
11 11 2016 11:53:14.344:DEBUG [karma]: Captured 1 browsers
karma.Server: run_start

================================================================================

START:
karma.Server: browser_complete
11 11 2016 11:53:14.346:DEBUG [phantomjs.launcher]:

karma.Server: run_complete

Finished in 0.001 secs / 0 secs

SUMMARY:
✔ 0 tests completed

#############################################################################
#                                                                           #
#                          CHANGED FILE - THIRD RUN                         #
#              0 tests run immediately, THEN, after run_complete,           #
#                web-server tries to fetch files and times out.             #
#                                                                           #
#############################################################################
11 11 2016 11:53:22.937:DEBUG [karma]: List of files has changed, trying to execute
11 11 2016 11:53:22.937:DEBUG [karma]: All browsers are ready, executing
11 11 2016 11:53:22.937:DEBUG [karma]: Captured 1 browsers
karma.Server: run_start

================================================================================

START:
karma.Server: browser_complete
11 11 2016 11:53:22.940:DEBUG [phantomjs.launcher]:

karma.Server: run_complete

Finished in 0.003 secs / 0 secs

SUMMARY:
✔ 0 tests completed

11 11 2016 11:53:22.942:DEBUG [middleware:karma]: Serving static request /context.html
11 11 2016 11:53:22.943:DEBUG [web-server]: serving (cached): /PROJECT/node_modules/karma/static/context.html
11 11 2016 11:53:22.943:DEBUG [coverage]: Writing coverage to /PROJECT/coverage/PhantomJS 2.1.1 (Mac OS X 0.0.0)
11 11 2016 11:53:22.946:DEBUG [web-server]: serving (cached): /PROJECT/node_modules/karma/static/context.js
11 11 2016 11:53:22.946:DEBUG [middleware:source-files]: Requesting /absolute/PROJECT/lib/test/main.test.js?a30b0747dc8cdfcc026c5f4713221372d6764ad7 /
11 11 2016 11:53:22.946:DEBUG [middleware:source-files]: Fetching /PROJECT/lib/test/main.test.js
11 11 2016 11:53:22.946:DEBUG [web-server]: serving (cached): /PROJECT/lib/test/main.test.js
karma.Server: browser_start
11 11 2016 11:53:33.110:WARN [PhantomJS 2.1.1 (Mac OS X 0.0.0)]: Disconnected (1 times), because no message in 10000 ms.
karma.Server: browser_error
PhantomJS 2.1.1 (Mac OS X 0.0.0) ERROR
    Disconnected, because no message in 10000 ms.
karma.Server: browser_complete

With restartOnFileChange: false

Notice on change that files are requested/fetched/served before tests are executed.

#############################################################################
#                                                                           #
#                                 FIRST RUN                                 #
#                                                                           #
#############################################################################
11 11 2016 12:01:09.610:DEBUG [config]: No config file specified.
11 11 2016 12:01:09.616:DEBUG [plugin]: Loading karma-* from /PROJECT/node_modules
11 11 2016 12:01:09.617:DEBUG [plugin]: Loading plugin /PROJECT/node_modules/karma-coverage.
11 11 2016 12:01:09.730:DEBUG [plugin]: Loading plugin /PROJECT/node_modules/karma-mocha.
11 11 2016 12:01:09.731:DEBUG [plugin]: Loading plugin /PROJECT/node_modules/karma-mocha-reporter.
11 11 2016 12:01:09.733:DEBUG [plugin]: Loading plugin /PROJECT/node_modules/karma-phantomjs-launcher.
11 11 2016 12:01:09.736:DEBUG [plugin]: Loading plugin /PROJECT/node_modules/karma-webpack-with-fast-source-maps.
11 11 2016 12:01:09.830:DEBUG [web-server]: Instantiating middleware
11 11 2016 12:01:09.831:DEBUG [reporter]: Trying to load reporter: mocha
11 11 2016 12:01:09.833:DEBUG [reporter]: Trying to load color-version of reporter: mocha (mocha_color)
11 11 2016 12:01:09.833:DEBUG [reporter]: Couldn't load color-version.
11 11 2016 12:01:09.833:DEBUG [reporter]: Trying to load reporter: coverage
11 11 2016 12:01:09.833:DEBUG [reporter]: Trying to load color-version of reporter: coverage (coverage_color)
11 11 2016 12:01:09.833:DEBUG [reporter]: Couldn't load color-version.
11 11 2016 12:01:15.095:DEBUG [karma]: List of files has changed, trying to execute
11 11 2016 12:01:15.095:WARN [karma]: No captured browser, open http://localhost:9876/
11 11 2016 12:01:15.098:DEBUG [watcher]: Watching "/PROJECT/lib/test/main.test.js"
11 11 2016 12:01:15.103:INFO [karma]: Karma v1.3.0 server started at http://localhost:9876/
karma.Server: listening
11 11 2016 12:01:15.103:INFO [launcher]: Launching browser PhantomJS with unlimited concurrency
11 11 2016 12:01:15.160:INFO [launcher]: Starting browser PhantomJS
11 11 2016 12:01:15.160:DEBUG [temp-dir]: Creating temp dir at /var/folders/sl/0sdljlvx2h54p0zfc6xwlq3r0000gn/T/karma-46312919
11 11 2016 12:01:15.162:DEBUG [launcher]: /PROJECT/node_modules/phantomjs-prebuilt/lib/phantom/bin/phantomjs /var/folders/sl/0sdljlvx2h54p0zfc6xwlq3r0000gn/T/karma-46312919/capture.js
11 11 2016 12:01:15.808:DEBUG [web-server]: serving: /PROJECT/node_modules/karma/static/client.html
11 11 2016 12:01:15.816:DEBUG [web-server]: serving: /PROJECT/node_modules/karma/static/karma.js
11 11 2016 12:01:15.852:DEBUG [karma]: A browser has connected on socket /#tIoQRCxsuT_SQOahAAAA
11 11 2016 12:01:15.855:DEBUG [web-server]: upgrade /socket.io/?EIO=3&transport=websocket&sid=tIoQRCxsuT_SQOahAAAA
11 11 2016 12:01:15.881:INFO [PhantomJS 2.1.1 (Mac OS X 0.0.0)]: Connected on socket /#tIoQRCxsuT_SQOahAAAA with id 46312919
karma.Server: browser_register
11 11 2016 12:01:15.881:DEBUG [launcher]: PhantomJS (id 46312919) captured in 0.777 secs
11 11 2016 12:01:15.882:DEBUG [karma]: All browsers are ready, executing
11 11 2016 12:01:15.882:DEBUG [karma]: Captured 1 browsers
karma.Server: run_start

START:
11 11 2016 12:01:15.886:DEBUG [phantomjs.launcher]:

11 11 2016 12:01:15.887:DEBUG [middleware:karma]: custom files null null
11 11 2016 12:01:15.887:DEBUG [middleware:karma]: Serving static request /context.html
11 11 2016 12:01:15.888:DEBUG [web-server]: serving: /PROJECT/node_modules/karma/static/context.html
11 11 2016 12:01:15.890:DEBUG [middleware:source-files]: Requesting /absolute/PROJECT/node_modules/mocha/mocha.css?68699fe2e12cd4578e48892d46c27fe84ee09b09 /
11 11 2016 12:01:15.890:DEBUG [middleware:source-files]: Fetching /PROJECT/node_modules/mocha/mocha.css
11 11 2016 12:01:15.891:DEBUG [web-server]: serving (cached): /PROJECT/node_modules/mocha/mocha.css
11 11 2016 12:01:15.891:DEBUG [web-server]: serving: /PROJECT/node_modules/karma/static/context.js
11 11 2016 12:01:15.892:DEBUG [middleware:source-files]: Requesting /absolute/PROJECT/node_modules/mocha/mocha.js?bc2b9e2e7b386b405368c9247d419c9a1d2718c8 /
11 11 2016 12:01:15.892:DEBUG [middleware:source-files]: Fetching /PROJECT/node_modules/mocha/mocha.js
11 11 2016 12:01:15.892:DEBUG [middleware:source-files]: Requesting /absolute/PROJECT/node_modules/karma-mocha/lib/adapter.js?e8826109cf50b958ee4bd667517729ffdd4de363 /
11 11 2016 12:01:15.892:DEBUG [middleware:source-files]: Fetching /PROJECT/node_modules/karma-mocha/lib/adapter.js
11 11 2016 12:01:15.893:DEBUG [middleware:source-files]: Requesting /absolute/PROJECT/lib/test/main.test.js?5e91226ec1f799a8de02c2be606edfde22e8089e /
11 11 2016 12:01:15.893:DEBUG [middleware:source-files]: Fetching /PROJECT/lib/test/main.test.js
11 11 2016 12:01:15.894:DEBUG [web-server]: serving (cached): /PROJECT/node_modules/mocha/mocha.js
11 11 2016 12:01:15.897:DEBUG [web-server]: serving (cached): /PROJECT/node_modules/karma-mocha/lib/adapter.js
11 11 2016 12:01:15.897:DEBUG [web-server]: serving (cached): /PROJECT/lib/test/main.test.js
karma.Server: browser_start
  restartOnFileChange
    ✔ skips tests after the first run
karma.Server: browser_complete
karma.Server: run_complete

Finished in 0.012 secs / 0.005 secs

SUMMARY:
✔ 1 test completed

#############################################################################
#                                                                           #
#                         CHANGED FILE - SECOND RUN                         #
#             Successfully executes tests, after fetching files.            #
#                                                                           #
#############################################################################
11 11 2016 12:01:21.555:DEBUG [karma]: List of files has changed, trying to execute
11 11 2016 12:01:21.555:DEBUG [karma]: All browsers are ready, executing
11 11 2016 12:01:21.555:DEBUG [karma]: Captured 1 browsers
karma.Server: run_start

================================================================================

START:
11 11 2016 12:01:21.556:DEBUG [phantomjs.launcher]:

11 11 2016 12:01:21.557:DEBUG [middleware:karma]: custom files null null
11 11 2016 12:01:21.557:DEBUG [middleware:karma]: Serving static request /context.html
11 11 2016 12:01:21.557:DEBUG [web-server]: serving (cached): /PROJECT/node_modules/karma/static/context.html
11 11 2016 12:01:21.559:DEBUG [web-server]: serving (cached): /PROJECT/node_modules/karma/static/context.js
11 11 2016 12:01:21.559:DEBUG [middleware:source-files]: Requesting /absolute/PROJECT/lib/test/main.test.js?eba96cf44a39ff7d29d003ec963558d0f4535ac6 /
11 11 2016 12:01:21.559:DEBUG [middleware:source-files]: Fetching /PROJECT/lib/test/main.test.js
11 11 2016 12:01:21.560:DEBUG [web-server]: serving (cached): /PROJECT/lib/test/main.test.js
karma.Server: browser_start
  restartOnFileChange
    ✔ skips tests after the first run
karma.Server: browser_complete
karma.Server: run_complete

Finished in 0.007 secs / 0.004 secs

SUMMARY:
✔ 1 test completed

@nobuti
Copy link

nobuti commented Aug 24, 2017

Still failing.

@solo-md
Copy link
Contributor

solo-md commented Jul 5, 2018

Let me put here a comment on how this issue happens.

Step by step what happens (karma 2.0.4) and why the issue appears:

  1. File changes.

  2. lib/server.js line 304 : file_list_modified event is handled

  3. lib/server.js line 306 : the handler checks config.restartOnFileChange (this one is true in our case)

  4. lib/server.js line 307 : Server emits STOP event

  5. lib/server.js line 309 : Server.executor.schedule() -> lib/executor.js line 34: capturedBrowsers.setAllToExecuting() -> lib/browser_collection.js line 36: set browser state to EXECUTING

  6. static/karma.js line 235 : STOP event (emitted in step 4) is handled

  7. static/karma.js line 236 : karma.complete method is called

  8. static/karma.js line 204: karma emits COMPLETE event to the socket

  9. lib/browser.js line 255 : COMPLETE event (emitted in step 8) is handled wtih onComplete function

  10. lib/browser.js line 117 : onComplete method set the browser state to READY

  11. Now the tests are started normally,lib/browser.js onStart method creates a new Result (line 101), and stores the total count of the specs to run....

  12. Each spec is completed and the lib/browser.js has a notification about it in onResult (line 185). But in case if the browser state is READY, the onResult method just ignores that result:
    see lib/browser.js lines 190-193 comment:

// ignore - probably results from last run (after server disconnecting)
    if (this.isReady()) {
      return
    }

So, once the restartOnFileChange config is set to TRUE, on the second run all the spec results are ignored, and the number of executed specs will be always 0.

johnjbarton pushed a commit that referenced this issue Jul 23, 2018
* fix(browser): ensure browser state is EXECUTING when tests start

Browser state is EXECUTING when it actually started to execute tests. This state change is triggered by client on actual tests execution start.

Introduced an additional browser state CONFIGURING

The CONFIGURING state means that the browser is not just CONNECTED for tests, but someone has requested tests execution (and provided a config file). But the provided config file is not yet processed, configuration is not applied or the tests execution is not yet started and we have not received the first event from the remote browser, so the browser object is not yet at EXECUTING state.

Refactored browser state names: renamed READY -> CONNECTED

Fixes #1640
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment