G'day:
I faffed around on the computer - with ColdFusion and Railo and TestBox - all day today, and have concluded I have nothing interesting to show for it. Still... this is a log of what I've been up to with CFML, so you're gonna hear all about it anyhow. And what's "better"... I'm gonna spin it out to be two articles. I am the Peter Jackson of CFML blogs!
OK, so I got wind of something to investigate the other day, and to do the metrics, I needed to time some stuff. Normally I'd just use a getTickCount() before and after the code, but I thought I might need something more comprehensive this time, so I figured a wee stopwatch UDF was in order. I've also just installed TestBox and am in the process of seeing if I can migrate away from MXUnit, so decided to do another TDD exercise with it. Note: there is no great exposition in this article, or really much new about TDD etc. It's simply what I did today.
Note: I abandoned TesxtBox's MXUnit compatibility mode today, because of a show-stopper bug: "ADDASSERTDECORATOR not implemented". This is the function that allows the importing of custom assertions, which I am using here. On the basis of that, I decided to just go with TestBox syntax instead.
Let's have a quick look at the function, and the tests.
//makeStopwatch.cfm
struct function makeStopwatch(){
var timeline = [];
var lap = function(string message=""){
var ticksNow = getTickCount();
var lapCount = arrayLen(timeline);
var lap = {
currentClock = ticksNow,
lapDuration = lapCount > 0 ? ticksNow - timeLine[lapCount].currentClock : 0,
totalDuration = lapCount > 0 ? ticksNow - timeLine[1].currentClock : 0,
message = message
};
arrayAppend(timeline, lap);
return lap;
};
return {
start = function(string message="start"){
return lap(message);
},
lap = function(string message="lap"){
return lap(message);
},
stop = function(string message="stop"){
return lap(message);
},
getTimeline = function(){
return timeLine;
}
};
};
Not much interesting here. I enjoyed finding another reason / excuse to use function expressions and a wee bit of closure around the timeline which "sticks" with the start() / lap() / stop() / getTimeline() functions.
What this function does is to log a struct at start, each lap, and another on stop. Here's it in action:
// useStopwatch.cfm
include "makeStopwatch.cfm";
stopwatch = makeStopwatch();
stopwatch.start("Begin timing");
sleep(500);
stopwatch.lap();
sleep(1500);
secondLap = stopwatch.lap("after another 1500ms");
writeDump(var=secondLap, label="secondLap");
sleep(2000);
stopwatch.start("Stop timing");
writeDump(var=stopWatch.getTimeline());
Output:
| secondLap - struct | |
|---|---|
| CURRENTCLOCK | 1387658080067 |
| LAPDURATION | 1500 |
| MESSAGE | after another 1500ms |
| TOTALDURATION | 2000 |
| array | |||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|
| 1 |
| ||||||||||
| 2 |
| ||||||||||
| 3 |
| ||||||||||
| 4 |
| ||||||||||
This is the bumpf I usually need when I'm timing stuff. Well: some or all of it. It'll be quite handy, I reckon.
One interesting facet here is that initially I thought I'd need three separate functions for the start() / lap() / stop() functions, I was doing TDD (seriously, I knew you'd wonder, so everything I write on this blog uses full TDD now), and having knocked out the first few tests to verify the method signatures for the returned functions, it occurred to me that stop() was actually redundant. It doesn't do anything that lap() wouldn't already do. I mean all this "stopwatch" does is take time marks... there's no clock starting or stopping really (getTickCount() keeps on ticking, we simply start paying attention and then stop paying attention at some point).
So, anyway, I decided before I starting messing around with a redesign, I'd get the test coverage done, get it working, and then refactor. This is something one of my colleagues (Brian, I mean you) has been drumming into me recently: don't get halfway through something, decide to do it differently, start again, refactor, waste time, and not have anything to show for it if I get interrupted (or, in a work situation, we get to the end of the sprint and need to release). So I banged out the rest of the tests, got everything working, and looked at my code some more.
Here are the tests:
// TestMakeStopwatch.cfc
component extends="testbox.system.testing.BaseSpec" {
public void function beforeTests(){
addAssertions({
assertStructKeysCorrect = function(required string keys, required struct struct, string message){
var assertionArgs = {
expected = listSort(keys, "textnocase"),
actual = listSort(structKeyList(struct), "textnocase")
};
if (structKeyExists(arguments, "message")){
assertionArgs.message = message;
}
$assert.isEqual(argumentCollection=assertionArgs);
}
});
include "makeStopwatch.cfm";
}
public void function testBaseLine(){
makeStopwatch();
}
public void function testReturnValues(){
var stopwatch = makeStopwatch();
$assert.isTrue(isStruct(stopwatch), "Returned value should be a struct");
$assert.assertStructKeysCorrect(
"start,lap,stop,getTimeline",
stopwatch,
"Incorrect methods return for Stopwatch"
);
$assert.isTrue(
isClosure(stopwatch.start),
"The returned start() value should be a function"
);
$assert.isTrue(
isClosure(stopwatch.lap),
"The returned lap() value should be a function"
);
$assert.isTrue(
isClosure(stopwatch.stop),
"The returned stop() value should be a function"
);
$assert.isTrue(
isClosure(stopwatch.getTimeline),
"The returned getTimeline() value should be a function"
);
}
public void function testMethodSignatureOfStart(){
testMethodSignature("start");
}
public void function testMethodSignatureOfLap(){
testMethodSignature("lap");
}
public void function testMethodSignatureOfStop(){
testMethodSignature("stop");
}
private void function testMethodSignatureOfGetTimeline(){
var stopwatch = makeStopwatch();
var result = stopwatch.getTimeLine();
$assert.typeOf("array", result, "getTimeLine() should return an array");
}
public void function testCustomStartMessage(){
testCustomMessage("start");
}
public void function testCustomLapMessage(){
testCustomMessage("lap");
}
public void function testCustomStopMessage(){
testCustomMessage("stop");
}
public void function testDefaultStartMessage(){
testDefaultMessage("start");
}
public void function testDefaultLapMessage(){
testDefaultMessage("lap");
}
public void function testDefaultStopMessage(){
testDefaultMessage("stop");
}
public void function testGetTimelineRetunValueBeforeStart(){
var stopwatch = makeStopwatch();
var result = stopwatch.getTimeLine();
$assert.isEqual([], result, "getTimeLine() should return an empty array");
}
public void function testStartInitalises(){
var stopwatch = makeStopwatch();
var result = stopwatch.start();
$assert.closeTo(getTickCount(), result.currentClock, 16);
$assert.isEqual(0, result.lapDuration, "lapDuration incorrect");
$assert.isEqual(0, result.totalDuration, "lapDuration incorrect");
}
public void function testFirstLap(){
var sleepDuration = 500;
var stopwatch = makeStopwatch();
var start = stopwatch.start();
sleep(sleepDuration);
var lap = stopwatch.lap();
$assert.closeTo(getTickCount(), lap.currentClock, 16);
$assert.closeTo(sleepDuration, lap.lapDuration, 16);
$assert.closeTo(sleepDuration, lap.totalDuration, 16);
}
public void function testSecondLap(){
var sleepDuration = 500;
var stopwatch = makeStopwatch();
var start = stopwatch.start();
sleep(sleepDuration);
stopwatch.lap();
sleep(sleepDuration);
var lap = stopwatch.lap();
$assert.closeTo(getTickCount(), lap.currentClock, 16);
$assert.closeTo(sleepDuration, lap.lapDuration, 16);
$assert.closeTo(sleepDuration*2, lap.totalDuration, 16);
}
public void function testStop(){
var sleepDuration = 500;
var stopwatch = makeStopwatch();
var start = stopwatch.start();
sleep(sleepDuration);
var stop = stopwatch.stop();
$assert.closeTo(getTickCount(), stop.currentClock, 16);
$assert.closeTo(sleepDuration, stop.lapDuration, 16);
$assert.closeTo(sleepDuration, stop.totalDuration, 16);
}
private void function testMethodSignature(required string methodToTest){
var stopwatch = makeStopwatch();
var result = invoke(stopwatch, methodToTest);
$assert.typeOf("struct", result, "#methodToTest#() should return a struct");
$assert.assertStructKeysCorrect(
"currentClock,lapDuration,totalDuration,message",
result,
"Incorrect keys returned by #methodToTest#()"
);
var md = getMetadata(stopwatch[methodToTest]);
$assert.isEqual(
{name="message", type="string", required=false},
{name=md.parameters[1].name, type=md.parameters[1].type, required=md.parameters[1].required},
"#methodToTest#() should take an optional string argument 'message'"
);
}
private void function testCustomMessage(required string methodToTest){
var stopwatch = makeStopwatch();
var message = "TEST_MESSAGE_#methodToTest#";
var result = invoke(stopwatch, methodToTest, {message=message});
$assert.isEqual(message, result.message, "Incorrect message used for #methodToTest#()");
}
private void function testDefaultMessage(required string methodToTest){
var stopwatch = makeStopwatch();
var result = invoke(stopwatch, methodToTest);
$assert.isEqual(methodToTest, result.message, "Incorrect message used for #methodToTest#()");
}
}
Ignore the TestBox syntax for a bit, I'll get to that.
Here I'm testing the following:
- the function's return values: that all the functions are returned, and the method signatures are correct. Here I've refactored the individual method-signature tests to call a single private test. This is because the tests for all three of start(), lap() and stop().
- Test that the optionality on the message argument is correctly implemented for each of those functions too. These two use refactored test methods: testDefaultMessage() and testCustomMethod().
- From there I test that each of the start(), lap() and stop() methods all record the lap data correctly.
At this point in time I had three separate lapping functions (start / lap / stop) all doing much the same thing. I'm kicking myself now I didn't commit the code as I went, as me describing this isn't as good as actually showing you.
Anyway, here's unit test coverage at work. I refactored the code from the inline lap() function in the return statement to be a separate function within makeStopwatch(). And simply refactored the returned lap() function to call that. Re-ran the tests: all good. I've made a design change to my code, and I know I'm safe with it because I am happy my test coverage will show-up any significant problems. This is a trivial example, but hopefully you can see the benefit here: rather than rewriting some code and then trying to see if it works in your app, and hoping you think to test all the variations, you just click the "test it" button. We're saving time now.
Next I removed all the innards from stop(), and replaced it with a call to lap(). Re-ran the test code: still works. Excellent.
Next I looked hard at the start() function. It was pretty much the same as lap(), except it dealt with the edge-case of start() logging the first entry in the timeline array. Then I saw that all the difference in the logic was predicated on how many entries there were in the array, so I could revise lap() to be how it is now - checking the length of the array and setting / resusing values accordingly - and everything still worked. Tick. Then I put the code from lap() into start() to make sure the logic would also work there. All tests green. Tick. So now I replaced the code from start() with a simple call to lap(). Re-run the tests: all green. Cool.
It's slightly hollow without being able to show you the before and after versions of the code, but I really did pretty much change all the logic of the function(s) after finished my test coverage, and it was all fine afterwards: I knew the thing still worked. Well: another thing... a lot of my initial changes to the logic didn't work. I ran the tests and they failed. I was testing the wrong length for the array, and various assignments wrong and forgot about the message argument for a while. But the tests told me this. This isn't so much TDD here, but it's definitely a facet of unit testing in general.
TestBox progress
It went well today. As I said, I had to abandon using its MXUnit compatibility because it's got that bug with custom assertions (one of the links above). But that's cool. I need to start moving towards BDD, and one step here is to move away from MXUnit's syntax / approach and using more of TestBox's. The chief thing that's interesting is TestBox has a more OO approach to its assertions. Note how they're all methods of an object, not just a function:$assert.isEqual()
$assert.isTrue()
$assert.typeOf() // should be isTypeOf(), surely?
$assert.closeTo() // isCloseTo()?
typeOf() is cool. Instead of MXUnit's isStruct(), isQuery() etc, it checks for any type (it wraps up a call to isValid(), according to the docs.
closeTo() is also handy. One thing I've learned with getTickCount() is that it's not very accurate. If one has two consecutive calls to getTickCount(), then they'll either be zero or 16ms apart. So when testing the lap times, closeTo() allows me to give a degree of fuzziness to the test.
There are a tonne of xUnit style assertions, btw: "Class Assertion".
I'm not sure there's anything interesting in that lot... I've got a custom assertion in there - much the same as the one I used earlier, really - but I'll discuss that stuff once either the docs are clarified or a bug is fixed with them ("Docs for Assertion CFCs inadequate, or functionality just doesn't work?").
OK, so that's me stopwatch function written. As is my wont, I'll chuck it up on CFLib makeStopwatch()() in case it'll be of any use to anyone else (either functionality or just the code).
I'll also write up why I needed this (another less-than-exciting article), but I'm watching Broadchurch and I'm just up to the denouement, and I want to focus on the "whodunnit" bit. It's pleasing to see David Tennant in a proper role, btw.
Righto.
--
Adam