Hard to listen to all-test-results event #360

Closed
piuccio opened this Issue Apr 9, 2014 · 32 comments

Comments

Projects
None yet
9 participants
@piuccio

piuccio commented Apr 9, 2014

The code of testem client is

window.Testem = {
  emit: function(evt){
    var args = Array.prototype.slice.apply(arguments)
    socket.emit.apply(socket, circularSafe(args))
    if (this.evtHandlers && this.evtHandlers[evt]){
      var handlers = this.evtHandlers[evt]
      var args = Array.prototype.slice.call(arguments, 1)
      for (var i = 0; i < handlers.length; i++){
        var handler = handlers[i]
        handler.apply(this, args)
      }
    }
  },

Which means, first the socket then the callbacks. In case of all-test-results, the socket message tells testem ci to kill the browser, so depending on how quick this happen, the handler callback might not be called.

It would be good to move the socket.emit at the end of the method

@airportyh

This comment has been minimized.

Show comment Hide comment
@airportyh

airportyh Apr 9, 2014

Collaborator

Okay, PR welcome.

Collaborator

airportyh commented Apr 9, 2014

Okay, PR welcome.

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius May 8, 2014

This is an issue for me consistently on my VM, whereby the browser is closing before reporting the results to my coverage server. Needs a workaround today.

matteius commented May 8, 2014

This is an issue for me consistently on my VM, whereby the browser is closing before reporting the results to my coverage server. Needs a workaround today.

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius May 9, 2014

Well I tried to fork and alter the code path, I am not sure what I did because now the browser won't exit at all. I set it back to what it was, and the browser is still not exiting. I am not sure with mocha if it is actually using my included script., or the global testem. This is frustrating, I was just trying to add a delay at first but to no avail.

matteius commented May 9, 2014

Well I tried to fork and alter the code path, I am not sure what I did because now the browser won't exit at all. I set it back to what it was, and the browser is still not exiting. I am not sure with mocha if it is actually using my included script., or the global testem. This is frustrating, I was just trying to add a delay at first but to no avail.

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius May 9, 2014

Alright sorry, I think it was also importing stuff from the global testem install I have -- I added the testem_client.js code there and found that if I move the socket.emit to the end of the conditional, that the browser won't exit. If I move it back up front, it exits too soon.

matteius commented May 9, 2014

Alright sorry, I think it was also importing stuff from the global testem install I have -- I added the testem_client.js code there and found that if I move the socket.emit to the end of the conditional, that the browser won't exit. If I move it back up front, it exits too soon.

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius May 9, 2014

Just as I expected, ConnectStatus disconnected by the time the end of the loops hits. Hmmm ....

matteius commented May 9, 2014

Just as I expected, ConnectStatus disconnected by the time the end of the loops hits. Hmmm ....

@airportyh

This comment has been minimized.

Show comment Hide comment
@airportyh

airportyh May 9, 2014

Collaborator

What handler is needing to be called? I suspect this fix may have to be implemented on the server side. I haven't jumped in because I am not sure how to reproduce this problem. If you can provide a gist and steps to reproduce, then I can take a look into it.

Collaborator

airportyh commented May 9, 2014

What handler is needing to be called? I suspect this fix may have to be implemented on the server side. I haven't jumped in because I am not sure how to reproduce this problem. If you can provide a gist and steps to reproduce, then I can take a look into it.

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius May 9, 2014

So the issue for us and me especially (because mine runs on the slowness of VM, which is still fast at killing processes) is that we use the following code in our test boilerplate to have an event callback to this method that will register istanbul coverage results with our node coverage server.

Ex:
Testem.on('all-test-results', function(results){
console.log("Inside all-test-results");
var xhr = new XMLHttpRequest();
xhr.open('POST', 'http://localhost:7358/');
xhr.send(JSON.stringify(window.coverage));
return;
})

In my debugging I found that the connectStatus variable was always disconnected regardless of before or after the event loop, yet somehow if I moved the socket.emit.apply(socket, circularSafe(args)) below the conditional, that the browser wouldn't exit, and if I manually did so it caused the test runner to register it as a browser crash.

I don't get at all how the order of execution for the event loop and the socket call matters at all, but I totally believe that it does. Open to other ideas as you suggest, I am new to testem and .js and it is not the most documented code I work on so I am still coming up to speed on this.

I'd like to get back to focusing on learning to write my unit tests for .js and the biggest thing that would help me do that is to get consistent coverage reports without having to run in interactive mode, it is the ci mode that the browser issues occurs in.

Thank you much!

matteius commented May 9, 2014

So the issue for us and me especially (because mine runs on the slowness of VM, which is still fast at killing processes) is that we use the following code in our test boilerplate to have an event callback to this method that will register istanbul coverage results with our node coverage server.

Ex:
Testem.on('all-test-results', function(results){
console.log("Inside all-test-results");
var xhr = new XMLHttpRequest();
xhr.open('POST', 'http://localhost:7358/');
xhr.send(JSON.stringify(window.coverage));
return;
})

In my debugging I found that the connectStatus variable was always disconnected regardless of before or after the event loop, yet somehow if I moved the socket.emit.apply(socket, circularSafe(args)) below the conditional, that the browser wouldn't exit, and if I manually did so it caused the test runner to register it as a browser crash.

I don't get at all how the order of execution for the event loop and the socket call matters at all, but I totally believe that it does. Open to other ideas as you suggest, I am new to testem and .js and it is not the most documented code I work on so I am still coming up to speed on this.

I'd like to get back to focusing on learning to write my unit tests for .js and the biggest thing that would help me do that is to get consistent coverage reports without having to run in interactive mode, it is the ci mode that the browser issues occurs in.

Thank you much!

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius May 9, 2014

In reproducing also we had to take the coveage server example provided in testem and add quite a lot -- for one thing for this to ever work the server must handle CORs for cross origin requests. Myself and another guy at work that wrote the server wish to open source it, but I am unable to provide that example at this time until our company can review.

matteius commented May 9, 2014

In reproducing also we had to take the coveage server example provided in testem and add quite a lot -- for one thing for this to ever work the server must handle CORs for cross origin requests. Myself and another guy at work that wrote the server wish to open source it, but I am unable to provide that example at this time until our company can review.

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius May 9, 2014

Airportyh,

I found an interim solution that I have checked in to my fork: it adds an arbitrary 5 second delay before killing the browser in ci mode. I think this isn't ideal because it can be arbitrary long to send the coverage JSON -- it could be significantly bigger payload than I am seeing now.

I think the ideal solution is to have a hook back to shutdown the server once the final test results events have completed.

Anyway, here is my interim fix: https://github.com/matteius/testem/commit/17316282d4e3bfbe1d47c1036ba3dac4fdc0de01

matteius commented May 9, 2014

Airportyh,

I found an interim solution that I have checked in to my fork: it adds an arbitrary 5 second delay before killing the browser in ci mode. I think this isn't ideal because it can be arbitrary long to send the coverage JSON -- it could be significantly bigger payload than I am seeing now.

I think the ideal solution is to have a hook back to shutdown the server once the final test results events have completed.

Anyway, here is my interim fix: https://github.com/matteius/testem/commit/17316282d4e3bfbe1d47c1036ba3dac4fdc0de01

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius May 9, 2014

My fix only works if I install it globally and include /testem.js

If I reference my commit tarball in my package.json, install locally, and reference:
<script src="../../node_modules/testem/testem.js"></script>
then the browser doesn't exit. Same code.

matteius commented May 9, 2014

My fix only works if I install it globally and include /testem.js

If I reference my commit tarball in my package.json, install locally, and reference:
<script src="../../node_modules/testem/testem.js"></script>
then the browser doesn't exit. Same code.

@piuccio

This comment has been minimized.

Show comment Hide comment
@piuccio

piuccio May 10, 2014

I had the exact same problem, that's why I didn't open a pull request, but I didn't have time to figure out why it was behaving like this.

I also need this fix to have consistent coverage report, but for now I've fixed it with a time out, just like you did.
The code is somewhere on my fork of testem and is used by testem-multi and grunt-testem to write coverage reports, but now I wonder if it'll still work on a slow machine like yours.

Btw notice that /testem.js is different from node_modules/testem/testem.js there's a middleware that concatenates several files.

I'd suggest you to try with a synchronous xhr request

piuccio commented May 10, 2014

I had the exact same problem, that's why I didn't open a pull request, but I didn't have time to figure out why it was behaving like this.

I also need this fix to have consistent coverage report, but for now I've fixed it with a time out, just like you did.
The code is somewhere on my fork of testem and is used by testem-multi and grunt-testem to write coverage reports, but now I wonder if it'll still work on a slow machine like yours.

Btw notice that /testem.js is different from node_modules/testem/testem.js there's a middleware that concatenates several files.

I'd suggest you to try with a synchronous xhr request

@jwaggener

This comment has been minimized.

Show comment Hide comment
@jwaggener

jwaggener Jul 9, 2014

I have the same problem. My results for code coverage on hudson were sporadic - sometimes coverage was available, but usually not available. After much consternation, I arrived at this being the issue. I am using testem as a dependency of lineman.

I tried with a synchronous request, without any luck.

I have the same problem. My results for code coverage on hudson were sporadic - sometimes coverage was available, but usually not available. After much consternation, I arrived at this being the issue. I am using testem as a dependency of lineman.

I tried with a synchronous request, without any luck.

@tandrewnichols

This comment has been minimized.

Show comment Hide comment
@tandrewnichols

tandrewnichols Oct 24, 2014

Any update on this issue? Is anyone actively looking into/working on something? I just want to collect coverage reports without running dev (read, non-terminating) mode.

Any update on this issue? Is anyone actively looking into/working on something? I just want to collect coverage reports without running dev (read, non-terminating) mode.

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius Oct 25, 2014

Yes, this is important to solve the race condition of terminating the server prior to capturing all of the json being sent from the instance of the browser. Unlike many race conditions this one appears to be more easily solvable because its nature is that the hook to kill the browser is the completion of the unit tests, even though an event fires to send the coverage data from the .js run, the same event causes the browser to shutdown.

The right answer seems to be to break out the onAllTestResults code that kills the browser into another block such as onClientCompletionTerminate callback. How the callback gets triggered is another manner, but it must be similar to the way the browser reports back test failures to the testem CLI.

I am more of a Python guru than javascript, but maybe I'll pull together some more time to try and complete the fix. In the mean time I encourage anyone whom this makes sense to and finds the time to make a similar PR and I'll certainly help review it.

Yes, this is important to solve the race condition of terminating the server prior to capturing all of the json being sent from the instance of the browser. Unlike many race conditions this one appears to be more easily solvable because its nature is that the hook to kill the browser is the completion of the unit tests, even though an event fires to send the coverage data from the .js run, the same event causes the browser to shutdown.

The right answer seems to be to break out the onAllTestResults code that kills the browser into another block such as onClientCompletionTerminate callback. How the callback gets triggered is another manner, but it must be similar to the way the browser reports back test failures to the testem CLI.

I am more of a Python guru than javascript, but maybe I'll pull together some more time to try and complete the fix. In the mean time I encourage anyone whom this makes sense to and finds the time to make a similar PR and I'll certainly help review it.

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius Oct 25, 2014

Well I just started looking at the testem code base again, and one question I have is what is true purpose of setting the all variable to true when shutting down? I see this in a few places but I can't find the mechanism that response to all because it is a hard thing to grep for. You'll see what I mean if you grep for all-test-results.

Well I just started looking at the testem code base again, and one question I have is what is true purpose of setting the all variable to true when shutting down? I see this in a few places but I can't find the mechanism that response to all because it is a hard thing to grep for. You'll see what I mean if you grep for all-test-results.

@tandrewnichols

This comment has been minimized.

Show comment Hide comment
@tandrewnichols

tandrewnichols Oct 26, 2014

It basically looks impossible. I have no idea WHY this should be the case, but if you make your xhr request prior to emit('all-test-results') or you move the socket emit of the same AFTER the call to the evtHandler, the server just never closes . . . just hangs indefinitely. WHY would an entirely independent action on an event make the server stop working? There is no sane explanation.

It basically looks impossible. I have no idea WHY this should be the case, but if you make your xhr request prior to emit('all-test-results') or you move the socket emit of the same AFTER the call to the evtHandler, the server just never closes . . . just hangs indefinitely. WHY would an entirely independent action on an event make the server stop working? There is no sane explanation.

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius Oct 27, 2014

I think it hangs indefinitely because whatever change is made the analogous change has to be made in the tap_consumer.py or runner_tap_consumer or relevant tap implementation. I seem to recall making a change similar that would hang the server in the past and I had no idea why, it baffled me.

I think it hangs indefinitely because whatever change is made the analogous change has to be made in the tap_consumer.py or runner_tap_consumer or relevant tap implementation. I seem to recall making a change similar that would hang the server in the past and I had no idea why, it baffled me.

@tandrewnichols

This comment has been minimized.

Show comment Hide comment
@tandrewnichols

tandrewnichols Oct 27, 2014

Shouldn't that only matter if you're using tap? I'm using dot reporter in ci mode.

Shouldn't that only matter if you're using tap? I'm using dot reporter in ci mode.

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius Oct 27, 2014

In the tap_runner_consumer.py there is this block where it sets 'all' to be true, and I think it is causing havoc.

tapConsumer.on('all-test-results', function(){ runner.get('results').set('all', true) tapConsumer.removeAllListeners() runner.trigger('all-test-results', this.results) runner.trigger('tests-end') })

In all of my prior attempts I tried cheating by piggy backing on an existing event, but I think you have to run the full-monty and setup an entirely new event structure for post-tests .js boiler plate such as sending the coverage data, and it would require everyone to implement it, or have a default that would just pass immediately to 'all-test-results'.

In the tap_runner_consumer.py there is this block where it sets 'all' to be true, and I think it is causing havoc.

tapConsumer.on('all-test-results', function(){ runner.get('results').set('all', true) tapConsumer.removeAllListeners() runner.trigger('all-test-results', this.results) runner.trigger('tests-end') })

In all of my prior attempts I tried cheating by piggy backing on an existing event, but I think you have to run the full-monty and setup an entirely new event structure for post-tests .js boiler plate such as sending the coverage data, and it would require everyone to implement it, or have a default that would just pass immediately to 'all-test-results'.

@tandrewnichols

This comment has been minimized.

Show comment Hide comment
@tandrewnichols

tandrewnichols Jan 2, 2015

I was able to work around this by setting a timeout in lib/ci/browser_test_runner.js in the onAllTestResults handler. My changes look like this:

  onAllTestResults: function(results){
    var self = this
    setTimeout(function() {
      self.launcher.kill(null, function(){
        self.finish()
      })
    }, 50);
  },

As you can see, you don't need much of a timeout (maybe depending on how performant your coverage server is). I tried it down to 10, but at 10, it was sometimes inconsistent. At 50, it seemed to generate the report reliably for me (and that's still pretty fast - you don't notice the delay at all). @airportyh - Is this a viable fix that could be merged? It seems a bit hackish, and you might prefer something more legit, but this does solve the problem. You could always merge it as a temporary fix to be replaced later with something better.

I was able to work around this by setting a timeout in lib/ci/browser_test_runner.js in the onAllTestResults handler. My changes look like this:

  onAllTestResults: function(results){
    var self = this
    setTimeout(function() {
      self.launcher.kill(null, function(){
        self.finish()
      })
    }, 50);
  },

As you can see, you don't need much of a timeout (maybe depending on how performant your coverage server is). I tried it down to 10, but at 10, it was sometimes inconsistent. At 50, it seemed to generate the report reliably for me (and that's still pretty fast - you don't notice the delay at all). @airportyh - Is this a viable fix that could be merged? It seems a bit hackish, and you might prefer something more legit, but this does solve the problem. You could always merge it as a temporary fix to be replaced later with something better.

@piuccio

This comment has been minimized.

Show comment Hide comment
@piuccio

piuccio Jan 2, 2015

As a matter of facts, grunt-testem is also using a 50ms timeout.

piuccio commented Jan 2, 2015

As a matter of facts, grunt-testem is also using a 50ms timeout.

@tandrewnichols

This comment has been minimized.

Show comment Hide comment
@tandrewnichols

tandrewnichols Jan 22, 2015

Well . . . this still doesn't work in PhantomJS. Works with Chrome. I mean . . . the timeout happens (logging stuff tells me so), but it's hard to know if my script that sends coverage to the server is working. Adding console.log does nothing. Should I be seeing logs in the terminal when running under phantom?

Well . . . this still doesn't work in PhantomJS. Works with Chrome. I mean . . . the timeout happens (logging stuff tells me so), but it's hard to know if my script that sends coverage to the server is working. Adding console.log does nothing. Should I be seeing logs in the terminal when running under phantom?

@johanneswuerbach

This comment has been minimized.

Show comment Hide comment
@johanneswuerbach

johanneswuerbach Jan 22, 2015

Owner

Which testem and node version are you using?

Owner

johanneswuerbach commented Jan 22, 2015

Which testem and node version are you using?

@tandrewnichols

This comment has been minimized.

Show comment Hide comment
@tandrewnichols

tandrewnichols Jan 23, 2015

Node v0.10.33
Testem v0.6.24 from here

Node v0.10.33
Testem v0.6.24 from here

@matteius

This comment has been minimized.

Show comment Hide comment
@matteius

matteius Jan 27, 2015

Regardless of the question how effective is adding a timeout (from the answer book: not very, because it relays on an inherent race condition existing in the system) as a Computer Engineer I would not approve a timeout based solution--clearly anyone could add one.

Couldn't the author explain how to add an event that is capture the coverage results???

Regardless of the question how effective is adding a timeout (from the answer book: not very, because it relays on an inherent race condition existing in the system) as a Computer Engineer I would not approve a timeout based solution--clearly anyone could add one.

Couldn't the author explain how to add an event that is capture the coverage results???

@johanneswuerbach johanneswuerbach added the bug label Feb 3, 2015

@piuccio piuccio referenced this issue in sideroad/testem-multi Feb 16, 2015

Open

Remove internal patches #10

@tonylukasavage

This comment has been minimized.

Show comment Hide comment
@tonylukasavage

tonylukasavage Dec 28, 2015

I believe I'm encountering the same thing, specifically with the scenario of trying to deliver istanbul coverage results after testem finishes running phantomjs (chrome works fine). Any movement on this in terms of a solution or reliable workaround?

I believe I'm encountering the same thing, specifically with the scenario of trying to deliver istanbul coverage results after testem finishes running phantomjs (chrome works fine). Any movement on this in terms of a solution or reliable workaround?

@efx

This comment has been minimized.

Show comment Hide comment
@efx

efx Feb 9, 2016

Contributor

+1. Seeing this in an ember-cli app

Contributor

efx commented Feb 9, 2016

+1. Seeing this in an ember-cli app

@jreading

This comment has been minimized.

Show comment Hide comment
@jreading

jreading Mar 5, 2016

I'm seeing this too now.

jreading commented Mar 5, 2016

I'm seeing this too now.

@jreading

This comment has been minimized.

Show comment Hide comment
@jreading

jreading Mar 7, 2016

I have been thinking about this and wondering if it makes sense to implement a "sendCoverage" or similar functionality via a config. This seems like a very common use-case, it might sense to wrap the kill command that gets fired on "onAllTestResults" with a check for this flag and run kill on the updated readyState (done) from the ajax request. The URI and port can come from the config. Thoughts? This is a big issue in one of our apps that has a fairly large coverage file.

jreading commented Mar 7, 2016

I have been thinking about this and wondering if it makes sense to implement a "sendCoverage" or similar functionality via a config. This seems like a very common use-case, it might sense to wrap the kill command that gets fired on "onAllTestResults" with a check for this flag and run kill on the updated readyState (done) from the ajax request. The URI and port can come from the config. Thoughts? This is a big issue in one of our apps that has a fairly large coverage file.

@johanneswuerbach

This comment has been minimized.

Show comment Hide comment
@johanneswuerbach

johanneswuerbach Mar 7, 2016

Owner

I would prefer to have a more generic way to register async afterTests / beforeTests hooks, but would gladly accept a PR.

Owner

johanneswuerbach commented Mar 7, 2016

I would prefer to have a more generic way to register async afterTests / beforeTests hooks, but would gladly accept a PR.

@efx

This comment has been minimized.

Show comment Hide comment
@efx

efx Mar 7, 2016

Contributor

A generic way would be lovely. @jreading These lines shutdown the browser process: https://github.com/testem/testem/blob/master/lib/runners/browser_test_runner.js#L145-L149
As a demonstration you can remove this.finish() and your coverage sending should finish with the test server process never finishing :)
A simple approach would be to call this.finish after a callback as supplied by the configuration. If I get time I can try PRing something to this effect.

Contributor

efx commented Mar 7, 2016

A generic way would be lovely. @jreading These lines shutdown the browser process: https://github.com/testem/testem/blob/master/lib/runners/browser_test_runner.js#L145-L149
As a demonstration you can remove this.finish() and your coverage sending should finish with the test server process never finishing :)
A simple approach would be to call this.finish after a callback as supplied by the configuration. If I get time I can try PRing something to this effect.

@jreading

This comment has been minimized.

Show comment Hide comment
@jreading

jreading Mar 7, 2016

I'm working through an "afterTests" queue that handles async callbacks. PR later today and of course open for comments.

jreading commented Mar 7, 2016

I'm working through an "afterTests" queue that handles async callbacks. PR later today and of course open for comments.

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