TearDown Asynchronous Tests in Dart

Bah! I almost had my ridiculous, pseudo-stubbing solution working last night. And then I tried it one too many times.

Dart is a fantastic language that mixes aspects of both dynamic languages and static languages. One of the places that static wins is the ability to replace methods at runtime—it won't work in Dart. It is still possible to vary runtime behavior (with noSuchMethod() or assigning a property to a function). But once a method is declared, there is nothing that can change it.

What this means for me in my recent quest is that there is no way to stub HttpRequest actions in my tests. I either need to use something that is HttpRequest-like (e.g. a subclass) or use a real server. Lately, I have been focusing on the latter. I even got the bright idea to run a test server that accepted POSTs to the /stub resource so that subsequent requests would return a specified response. In effect I would be stubbing HttpRequest in the most roundabout way possible.

And it worked. Kind of.

With a bit of browser and server code, I was able to write a “stub” test as:

    group("HTTP get", (){
      setUp((){
        return HttpRequestX.respondWith('{"foo": 42}');
      });

      test("it can parse responses", (){
        var model = new FakeModel();
        HipsterSync.
          call('get', model).
          then(
            expectAsync1((response) {
              expect(response, {'foo': 42});
            })
          );
      });
    });

Most of the time, that passes. But every now and then I will get a 404/Not Found response in the actual test.

To track this down, I add some logging to my Dart server:

main() {
  HttpServer.bind('127.0.0.1', 31337).then((app) {
    app.listen((HttpRequest req) {
      log(req);
      // handle actual requests below...
    });
  });
}

I will not be interfering with the response in the log() function. Instead, I wait for the response to be done, at which point I log a some pertinent information:

log(req) {
  req.response.done.then((res){
    var now = new DateTime.now();
    print('[${now}] "${req.method} ${req.uri.path}" ${res.statusCode}');
  });
}

I love me some good Dart code. In there, I get to make use of a Future, sane date objects, and string interpolation. That's just pretty. The done property on the response is a future—the callback that I supply in then() is invoked when the response is… done. The now() factory constructor gives me the current time in an object that supports a sane toString(). That comes in handy when I interpolate a bunch of values into the logged string.

With that, I see that my normal activity looks like:

[2013-07-16 22:55:02.292] "DELETE /widgets/ALL" 204
[2013-07-16 22:55:02.294] "POST /stub" 204
[2013-07-16 22:55:02.301] "GET /test" 200
[2013-07-16 22:55:02.305] "DELETE /widgets/ALL" 204

The POST to /stub specifies the stubbed response that I am going to get back on the next request. The subsequent GET of /test returns the data POSTed to /stub. The DELETEs before and after are teardown functions being executed in between tests (they clear the DB for tests that use them).

One thing that strikes me in the log output is that the first DELETE and the POST to /stub are only 2 milliseconds apart. My tests are asynchronous. If there is a tiny delay when connecting for the first DELETE, but no delay when connecting for the POST to /stub, what happens?

It turns out that I can make that happen on the very next test run:

[2013-07-16 22:55:06.017] "POST /stub" 204
[2013-07-16 22:55:06.020] "DELETE /widgets/ALL" 200
[2013-07-16 22:55:06.034] "GET /test" 404

Since the POST to /stub arrives before the DELETE teardown, the response to the DELETE request is the stubbed data. When the test that expects a stubbed response finally hits the server, the stub is gone (currently, it is a one-time only stub), resulting in a 404 and a failing test.

So culprit identified, but how do I fix it? The fix is something that I have been wanting to do for a while: return a future from a test's teardown function. I already figured out the benefit of returning futures in setup blocks—the test will block until the setup future completes. I knew that I could return a Future from unittest tearDown() functions, but until tonight, I lacked a good use-case.

The tearDown() function in this case is “fixed” by simply adding a return statement to my Hipster MVC test. HipsterSync.call() returns a future, so returning it will return a future from tearDown():

    tearDown(() {
      // ...
      return HipsterSync.call('delete', model);
    });

The use-case seems to be that other tests in the same group will not start running until the previous teardown is complete. And this seems to be the case. Despite repeated efforts, I cannot get the timing issue to reappear even though the first DELETE and the stub are often a single millisecond apart:

[2013-07-16 23:47:47.178] "DELETE /widgets/ALL" 204
[2013-07-16 23:47:47.179] "POST /stub" 204
[2013-07-16 23:47:47.187] "GET /test" 200
[2013-07-16 23:47:47.193] "DELETE /widgets/ALL" 204

This even seems to work cross-test groups. I make a duplicate of the test that had been failing—the stubbing test—in a separate group. And it still works despite repeated test runs. The second stub always occurs at the very end—after the previous group has run.

[2013-07-16 23:57:50.904] "DELETE /widgets/ALL" 204
[2013-07-16 23:57:50.905] "POST /stub" 204
[2013-07-16 23:57:50.911] "GET /test" 200
[2013-07-16 23:57:50.916] "DELETE /widgets/ALL" 204
... other test activity ...
[2013-07-16 23:57:50.972] "DELETE /widgets/ALL" 204
[2013-07-16 23:57:50.975] "POST /stub" 204
[2013-07-16 23:57:50.978] "GET /test" 200
[2013-07-16 23:57:50.981] "DELETE /widgets/ALL" 204

So maybe this will work after all. This whole pseudo-stubbing exercise still feels a bit daft. Still, it may prove useful in certain circumstances so I will probably explore it a bit more. But it just might work.


Day #814

‹prev | My Chain | next›