karma-runner / karma

Spectacular Test Runner for JavaScript
http://karma-runner.github.io
MIT License
11.96k stars 1.71k forks source link

0.5.6 doesn't exit cleanly on Windows in once mode #254

Closed Iristyle closed 11 years ago

Iristyle commented 11 years ago

0.5.5 exits properly with an exit code based on failing tests.

Something in the 0.5.6 codebase has broken that.... instead of exiting, it just hangs up. I let it run a while locally, and it didn't seem to ever exit. I could Ctrl+C to exit the process locally. I let it run overnight on the build server (14 hours or something) and it never exited either.

So something in here did it ;0 https://github.com/vojtajina/testacular/compare/f574ff6d59676157d3457f31a35b708faa406e9d...985114f825d7fcd1782a37fdd8442792feecdbdb

I will try and track this down a little later, but wanted to get this filed now.

vojtajina commented 11 years ago

Can you bisect (http://www.kernel.org/pub/software/scm/git/docs/git-bisect.html) to figure out which commit did it ?

I'd like to push current canary to stable release, so I'm gonna wait for this.

Iristyle commented 11 years ago

Yeah, as long as the test suite exhibits the same behavior.. hang on.

Iristyle commented 11 years ago

I see Gruntfile.coffee ... so I assume you're on Grunt 0.4.0rc4? Nvm... that appears to be the case ;0 Should have grunt in devDependencies of package.json IMHO

dignifiedquire commented 11 years ago

Yes latest I tested with though was 0.4.0.rc2 but I don't think there should be problems with rc4.

Iristyle commented 11 years ago

Getting a bail in test:client ... I'm guessing these haven't been run on Windows recently?

Running "test:unit" (test) task
Verifying property test.unit exists in config...OK

Running "jasmine_node" task
........................................................................................................................................................................................................................................

Finished in 1.758 seconds
232 tests, 492 assertions, 0 failures

Running "test:client" (test) task
Verifying property test.client exists in config...OK
[Error]
Fatal error: Client unit tests failed.
dignifiedquire commented 11 years ago

Sorry but F*\ Windows. Now to the problem at hand. Can you try with grunt@0.4.0.rc2 ? I looked at their changelog and they did some stuff to grunt.spawn for windows.

Iristyle commented 11 years ago

No dice on RC2 either... I am running grunt in verbose btw... unfortunately [Error] isn't giving me a lot to go on :(

Iristyle commented 11 years ago

Also tried -d and --stack to see if I can get a little more info on where to fix this... but nada.

I guess I have to go old school and instrument the code with some console.log statements or similar -- haha.

dignifiedquire commented 11 years ago

Yeah true story [Error] tells us everything -.-

Iristyle commented 11 years ago

I'm also on Node v0.8.14 -- bumping that up to v0.8.16 just to rule that out... hang on.

vojtajina commented 11 years ago

Yep, fucking Windows :-)

Just bisect the commits in 0.5.6 and do a single run, to see whether it exits or not. testacular start test/client/testacular.conf.js --single-run

vojtajina commented 11 years ago

I mean, you don't need grunt for it...

Iristyle commented 11 years ago

Nothing going with v0.8.16 ... will skip the suite and go for the single run.. hold tight :8ball:

dignifiedquire commented 11 years ago

For the future I'll create an issue to switch from grunt.spawn to something more robust. Or at least to try-catch the hell out of it so that we get at least some error messages when this stuff breaks.

Iristyle commented 11 years ago

I bisected all the way back.. and they all hung on --single-run (including v0.5.5, which I know works).. so I have to be doing something wrong with how I'm firing up Testacular.

I assumed the script I was supposed to run was in .\bin\testacular ... and since Windows doesn't do shebangs, I was using node to start it from Powershell.

± node .\bin\testacular start .\test\client\testacular.conf.js --single-run
info: Testacular server started at http://localhost:9876/

Server would fire... node is hanging out in my process list. Nothing seems to be happening though.

Just to rule out Powershell arg parsing, and the shebang bit, I launched from Git bash as well.... same deal.

EPS@EPSHQ-DEVIMAGE /c/source/testacular ((v0.5.5))
$ ./bin/testacular start ./test/client/testacular.conf.js --single-run
info: Testacular server started at http://localhost:9876/

Am I kicking off the wrong script or something?

Iristyle commented 11 years ago

Ok, I can work with the e2e basic tests.. those launch. New plan of attack... hang on ;0

± node .\bin\testacular start .\test\e2e\basic\testacular.conf.js --single-run
info: Testacular server started at http://localhost:9876/
info (launcher): Starting browser Chrome
info (Chrome 25.0 (Windows)): Connected on socket id iswnsMi_nHx3WdQA3qwO
Chrome 25.0 (Windows): Executed 2 of 2 SUCCESS (0.091 secs / 0.001 secs)
eps@epshq-devimage: C:\S\testacular [(v0.5.4)]                                    ▶▶▶▶▶▶▶▶▶▶
Iristyle commented 11 years ago

Whoops -- goofed that last one up because I forgot to NPM install ;0

Ok... so up to e7c3830 the E2E basic tests run.

After that... they all seem to run fine. So I guess I need another suite of tests to run against to verify this :frowning:

7d62cdc

± git reset --hard 7d62cdc
HEAD is now at 7d62cdc Refactor FileList to use promises and batch changes
eps@epshq-devimage: C:\S\testacular [(7d62cdc...)|BISECTING]                      ▶▶▶▶▶▶▶▶▶▶

± node .\bin\testacular start .\test\e2e\basic\testacular.conf.js --single-run
info: Testacular server started at http://localhost:9876/
info (launcher): Starting browser Chrome
info (Chrome 25.0 (Windows)): Connected on socket id lQB1VQIfP11r_AOO5nw3
error: TypeError: Object [object Object] has no method 'getIncludedFiles'
eps@epshq-devimage: C:\S\testacular [(7d62cdc...)|BISECTING]                      ▶▶▶▶▶▶▶▶▶▶

af8086b

± node .\bin\testacular start .\test\e2e\basic\testacular.conf.js --single-run
info: Testacular server started at http://localhost:9876/
info (launcher): Starting browser Chrome
info (Chrome 25.0 (Windows)): Connected on socket id QQlGnaSyX5xYSZrR56C9
Chrome 25.0 (Windows): Executed 2 of 2 SUCCESS (0.117 secs / 0.002 secs)

dd20a29

± node .\bin\testacular start .\test\e2e\basic\testacular.conf.js --single-run
info: Testacular server started at http://localhost:9876/
info (launcher): Starting browser Chrome
[Error: Error while sending request to "localhost:23053"]
info (Chrome 25.0 (Windows)): Connected on socket id v17m5yC3AXo4tAym6XIL
Chrome 25.0 (Windows): Executed 2 of 2 SUCCESS (0.158 secs / 0.003 secs)

74f04dd

eps@epshq-devimage: C:\S\testacular [(74f04dd...)|BISECTING]                      ▶▶▶▶▶▶▶▶▶▶
± node .\bin\testacular start .\test\e2e\basic\testacular.conf.js --single-run
info: Testacular server started at http://localhost:9876/
info (launcher): Starting browser Chrome
info (Chrome 25.0 (Windows)): Connected on socket id NL9i3mhjGDSkQAuU6hHZ
Chrome 25.0 (Windows): Executed 2 of 2 SUCCESS (0.111 secs / 0.008 secs)

985114f

eps@epshq-devimage: C:\S\testacular [(74f04dd...)|BISECTING]                      ▶▶▶▶▶▶▶▶▶▶
± git reset --hard 985114f
HEAD is now at 985114f Fix web server proxying (pause request)
eps@epshq-devimage: C:\S\testacular [(985114f...)|BISECTING]                      ▶▶▶▶▶▶▶▶▶▶
± npm install
npm http GET https://github.com/Dignifiedquire/grunt-jasmine-node/tarball/upgrade-jasmine
npm http GET https://registry.npmjs.org/pause
npm http 200 https://github.com/Dignifiedquire/grunt-jasmine-node/tarball/upgrade-jasmine
npm http 304 https://registry.npmjs.org/pause
npm WARN prefer global grunt-cli@0.1.6 should be installed with -g
pause@0.0.1 node_modules\pause
eps@epshq-devimage: C:\S\testacular [(985114f...)|BISECTING]                      ▶▶▶▶▶▶▶▶▶▶
± node .\bin\testacular start .\test\e2e\basic\testacular.conf.js --single-run
info: Testacular server started at http://localhost:9876/
info (launcher): Starting browser Chrome
info (Chrome 25.0 (Windows)): Connected on socket id lqBAm6d0L2vXssYY6uBi
Chrome 25.0 (Windows): Executed 2 of 2 SUCCESS (0.114 secs / 0.003 secs)
Iristyle commented 11 years ago

Also, this is the variation I get in output from 0.5.5 to 0.5.6 in my real build.

0.5.5

info: Testacular server started at http://localhost:9876/
info (launcher): Starting browser PhantomJS
debug (launcher): Creating temp dir at C:\Users\EPS\AppData\Local\Temp\testacular-64484880
debug (launcher): C:\tools\PhantomJS\phantomjs.exe C:\Users\EPS\AppData\Local\Temp\testacular-64484880/capture.js
debug (preprocess.coverage): Processing "C:/Source/Osiris/generated/app.js".
debug (watcher): Resolved files:
        C:/Source/Osiris/generated/lib/chai.js
        C:/Source/Osiris/generated/test/chai-adapter.js
        C:/Source/Osiris/generated/lib/mocha.js
        C:/Source/Osiris/node_modules/testacular/adapter/mocha.js
        C:/Source/Osiris/generated/lib/require.js
        C:/Source/Osiris/generated/app.js
        C:/Source/Osiris/generated/specs.js
debug (web server): serving: C:/Source/Osiris/node_modules/testacular/static/client.html
debug (web server): serving: C:/Source/Osiris/node_modules/testacular/static/testacular.js
debug: New browser has connected on socket 9BkxeUUuRcf829o_80ks
info (PhantomJS 1.7 (Windows)): Connected on socket id 9BkxeUUuRcf829o_80ks
debug: All browsers are ready, executing
debug (web server): serving: C:/Source/Osiris/node_modules/testacular/static/context.html
debug (web server): serving: C:/Source/Osiris/generated/lib/chai.js
debug (web server): serving: C:/Source/Osiris/generated/test/chai-adapter.js
debug (web server): serving: C:/Source/Osiris/generated/lib/mocha.js
debug (web server): serving: C:/Source/Osiris/node_modules/testacular/adapter/mocha.js
debug (web server): serving: C:/Source/Osiris/generated/lib/require.js
debug (web server): serving: C:\Users\EPS\AppData\Local\Temp/ef37c46705a212fd4ed33ae854a95dac96e84986.js
debug (web server): serving: C:/Source/Osiris/generated/specs.js
debug (launcher): Disconnecting all browsers
debug (launcher): Killing PhantomJS
debug (launcher): Process PhantomJS exitted with code 0
debug (launcher): Cleaning temp dir C:\Users\EPS\AppData\Local\Temp\testacular-64484880
debug (reporter): JUnit results written to "C:/Source/Osiris/dist/test-results.xml".
Warning: Spec execution failed with exit code 1 Use --force to continue.

Aborted due to warnings.

0.5.6

info: Testacular server started at http://localhost:9876/
info (launcher): Starting browser PhantomJS
debug (launcher): Creating temp dir at C:\Users\EPS\AppData\Local\Temp\testacular-19663057
debug (launcher): C:\tools\PhantomJS\phantomjs.exe C:\Users\EPS\AppData\Local\Temp\testacular-19663057/capture.js
debug (preprocess.coverage): Processing "C:/Source/Osiris/generated/app.js".
debug (watcher): Resolved files:
        C:/Source/Osiris/generated/lib/chai.js
        C:/Source/Osiris/generated/test/chai-adapter.js
        C:/Source/Osiris/generated/lib/mocha.js
        C:/Source/Osiris/node_modules/testacular/adapter/mocha.js
        C:/Source/Osiris/generated/lib/require.js
        C:/Source/Osiris/generated/app.js
        C:/Source/Osiris/generated/specs.js
debug (web server): serving: C:/Source/Osiris/node_modules/testacular/static/client.html
debug (web server): serving: C:/Source/Osiris/node_modules/testacular/static/testacular.js
debug: New browser has connected on socket m4RNCmEuwa0B-VOt8aGF
info (PhantomJS 1.7 (Windows)): Connected on socket id m4RNCmEuwa0B-VOt8aGF
debug: All browsers are ready, executing
debug (web server): serving: C:/Source/Osiris/node_modules/testacular/static/context.html
debug (web server): serving: C:/Source/Osiris/generated/lib/chai.js
debug (web server): serving: C:/Source/Osiris/generated/test/chai-adapter.js
debug (web server): serving: C:/Source/Osiris/generated/lib/mocha.js
debug (web server): serving: C:/Source/Osiris/node_modules/testacular/adapter/mocha.js
debug (web server): serving: C:/Source/Osiris/generated/lib/require.js
debug (web server): serving: C:\Users\EPS\AppData\Local\Temp/ef37c46705a212fd4ed33ae854a95dac96e84986.js
debug (web server): serving: C:/Source/Osiris/generated/specs.js
debug (launcher): Disconnecting all browsers
debug (launcher): Killing PhantomJS
debug (launcher): Process PhantomJS exitted with code 0
debug (launcher): Cleaning temp dir C:\Users\EPS\AppData\Local\Temp\testacular-19663057
debug (reporter): JUnit results written to "C:/Source/Osiris/dist/test-results.xml".
dignifiedquire commented 11 years ago

Are all your tests passing?

Warning: Spec execution failed with exit code 1 Use --force to continue.

Sounds like they aren't.

Iristyle commented 11 years ago

No, they aren't... and that's fine. At least Node / Testacular wraps up at that point and exits with an exitcode. In 0.5.6, it just sits there.

dignifiedquire commented 11 years ago

I'm guessing but maybe 32838ad is the problem. Just try commenting it out maybe it helps.

vojtajina commented 11 years ago

This code should be only called once exception happens, so I don't think so. Although, one never knows on this great OS...

dignifiedquire commented 11 years ago

I know..it should be but I've seen much stranger behavior than this on windows..

Iristyle commented 11 years ago

I was thinking it might be here -> https://github.com/vojtajina/testacular/commit/14dcc77abe683215ef679d5d4b748f2eec94c813#L1R199

Testing my theory... if done is in the wrong scope, it won't get closed on, right?

dignifiedquire commented 11 years ago

There are just three commits in there that change anything about the exiting and spawning process as far as I can see.

dignifiedquire commented 11 years ago

Yes but I hope that the scope is the same on all OSes and it works fine on my machine :/

Iristyle commented 11 years ago

Ok, so I instrumented the code (and added the util = require('util') to server.js)

globalEmitter.emitAsync('exit').then(function() {
      log.info('calling exit function ' + util.inspect(done));
      done(code || 0);
    });

My output is

debug (launcher): Cleaning temp dir C:\Users\EPS\AppData\Local\Temp\testacular-35565596
debug (reporter): JUnit results written to "C:/Source/Osiris/dist/test-results.xml".
info: calling exit function undefined

util.inspect should be '[Function]'

Unless I've made an error here...

Let me just hardcode process.exit back in.

Iristyle commented 11 years ago

Yup, that fixed it... so done is not defined there.

    globalEmitter.emitAsync('exit').then(function() {
      process.exit(code || 0);
    });
Iristyle commented 11 years ago

You know what... I bet this has something do with how Testacular is being launched from Grunt on my end as well.

dignifiedquire commented 11 years ago

Could be..Are you using grunt-testacular or something else to spawn Testacular?

Iristyle commented 11 years ago

Yeah, I hand rolled some stuff a while back, before your plugin existed. I've been meaning to switch, but have been tied up with other build-y stuff lately.

I can see in your grunt plugin (which I've been meaning to switch to), that this is handled -- https://github.com/Dignifiedquire/grunt-testacular/blob/canary/tasks/testacularServer.js#L27

Pretty sure I'm doing it wrong, since I didn't realize this had changed.

So in the end, this looks like user error... but is something that should probably go in the docs.

dignifiedquire commented 11 years ago

Oh yes. It should go in the docs. Like so many things ;)

Iristyle commented 11 years ago

For ref, this is how I was starting Testacular (forking server.js)... since it was soooo long ago that it was it put together, it didn't even occur to me that I had something goofed up there.

util = require('util');
util.log('Starting testacular with arguments:' + util.inspect(process.argv[2]));

require('testacular').server.start(JSON.parse(process.argv[2]));

Hopefully you guys don't want to totally :punch: me now ;0

dignifiedquire commented 11 years ago

:laughing: No problem happens to the best of us.

I think we should switch the interface so that it is

server.start(options, [callback])

with implementation being

if (! _.isFunction(done)) {
  done = process.exit;
}

For ref also I've started a wiki page for the public api here.

Iristyle commented 11 years ago

Yeah, I think that a fail-safe fallback is a good idea. It was entertaining seeing the F Windows cries in any event -- haha. And I did uncover some test run issues, so at least something positive came out of this.

BTW -- In my attempt to find a set of tests that were working on one tag, but failing on the other... I tried all of the E2E tests. Most ran fine, but a couple of them hung. I know that requirejs hung for instance.

dignifiedquire commented 11 years ago

I've switched it so it's now optional. See f945131.