Thursday, 7 April 2016

Maintaining untested code, and mocking too much when backfilling test (with JavaScript & Jasmine)

G'day:
Here's another example of me doing something wrong. Well: there's a litany of wrongness in this exercise, and I'll show the whole thing from start to finish. But this all stems from me ballsing something up.

Caveat

Be warned: there's a lot of code in this one, but the main point is the volume of the code I found necessary to write to test and fix a tiny bug. You don't need to worry too much about the content of the code... the important part is the line number at the bottom of the file.

The background to this is that I was helping a former colleague with some CFML code ("just when I thought I was out..."), and it was whilst reconfiguring stuff, I got hit by a trivial bug... the resolution to which is the basis of this article. I could not use their actual code in the article here due to NDA reasons, but I also didn't want to be discussing CFML either. So I've undertaken to "refactor" the entire thing into JavaScript instead (I don't mean their code; I mean a version of their logic which I will discuss here). The JavaScript code closely resembles the actual code I was looking at, but obviously some of the approaches to doing things needed to change, and I've repurposed some of the elements of it to better suit what I'm discussing. The logic and "code distribution" is about a 95% match to the original case though, I think. Also I'm using Jasmine to do JavaScript testing in this example, and I was using a CFML-based solution for the original code. This is irrelevant to the situation as both work mostly the same way, and produce similar amounts of code for the equivalent testing and mocking tasks.

I will start by saying that the code is a product of its time and their coding policies at that time. I'm happy to say they've since revised their approach to things, and are fine-tuning it as they go. the code base - like all others - is an evolving beast. And indeed to be fair to them: it's a testament to their evolving coding process that I'm able to write this article.

Background

This code comes some a project which is built with an MVC framework: the details of which are irrelevant to this article. They also use a dependency injection container to handle their dependencies.

The code in this article is part of the TranslatorProvider, which creates a TranslationService, and loads it with translations originally stored in some (optionally cached) data repository. The implementation details of these are not relevant here. These translations are for on-screen labels and other text. The bit of code I'm focusing on in this article is the logic to load the translations from storage. They don't quite follow the service / repository model I have presented here, but it's the same beast by different names, and the service / repository model suits me better so that's how I've labelled things here.

My mate's organisation produces numerous small websites, all of which are multi-lingual, and all share this code.

New site

They're in the process of building a new site, which is where I came in. We'd been piggy-backing onto the translation dictionaries for one of the existing sites whilst we were protoyping. the onscreen-labels we need to translate follow the same general theme, so it's workable - during development - to use one site's translations for another site, to a point (some translations don't work, but that's OK). It took a while to prepare the dictionaries for the new site (a different team was doing that), but when they came back from the translator I switched the dictionary bundles over.

I did this, and the whole site broke. Switched the dictionary back to the older one: site worked again. Switch it forward: site broke. OK: there's something wrong with our translations. Oh, I switched the translations on another one of their test sites - one I knew in which all the work was sound (ie: not written by me) - and that site broke, Harrumph. What is it about some translation dictionaries that can break a site?

Bug

I dug into the translator code and quickly (well: it took a few hours) found the problem:

var translations;

// ...

for (var key in rawTranslations.primary){
    translations.primary = translations.primary || {};
    translations.primary[key] = rawTranslations.primary[key];
}

for (var key in rawTranslations.secondary){
    translations.secondary = translations.secondary || {};
    translations.secondary[key] = rawTranslations.secondary[key];
}

var ttl = config.ttl;

cacheService.put(cacheKeyPrimary, translations.primary, ttl);
cacheService.put(cacheKeySecondary, translations.secondary, ttl);


Can you see it?

What happens if - as it is in our case - one hasn't got any secondary translations? translations.secondary never gets created, so that last line will break.

The fix is simply to initialise that object outside of the loop:

translations = {primary : {}, secondary : {}};

Simple.

Well except for one thing. No test coverage. This code was written before they had a TDD policy, so it's got no tests at all. Note that this bug never would have happened had they used TDD when developing this code, because the very first test would have been with empty arrays. I made sure to point this out to them, but they rightfully pointed out when it was written and they now do have a full TDD policy. And that comes into play for my fix: I needed to use TDD for implementing my fix.

Back-fill

My policy with maintaining untested code using our new TDD approach is that I will not back-fill all missing tests. I will only implement the minimum testing needed for the case I'm fixing. if I have time I'll make shell tests with a "skip" in them so the missing coverage gets flagged in the test run, but I'll not bother too much other than that.

So in this case all I need to test is that if the secondary object is null, that null gets send to the cache. Simple.

Or is it?

Unclean code

Unfortunately this code was also written before the era of "write Clean Code", so the function itself is doing way too much. It's 50 lines long for a start, which is a red flag, but one can easily see different sections of processing in it too, so it violates the "functions should do one thing" rule. This becomes a problem because even to test my wee fix, I need to make sure the preceding 40-odd lines of code don't break or do the wrong thing before I get to my line of code. And as this code leverages a fair number of dependencies, there's a bunch of mocking work to do before I can even get to what I want to test. Note: the dependencies in the original code were handled differently in that they passed the DI container into this provider, and just plucked out whatever they need when they need it. I cannot bring myself to show code like that (even for a blog article), so I've broken them down into multiple dependencies with specific roles. The logic is the same, and it produces the same amount of code (both sample code and test code).

If the code was Clean and I was just looking at a function that map the source objects(s) into the target objects(s), then my test job would be easy. But no.

Let's look at what stands between me and where I can test the results of my line of code. I've highlighted what needs mocking:

if (!requestService.isTranslatorEnabled()){
    return;
}

var currentLocale = requestService.getLocale();

var cacheKeyPrimary = getCacheKey("primary", currentLocale);
var cacheKeySecondary = getCacheKey("secondary", currentLocale);

var okToGetFromCache = cacheService.isActive()
    && cacheService.exists(cacheKeyPrimary)
    && cacheService.exists(cacheKeySecondary);

var translations = {};
if (okToGetFromCache) {
    translations.primary = cacheService.get(cacheKeyPrimary);
    translations.secondary = cacheService.get(cacheKeySecondary);
}else{
    var rawTranslations = {
        primary : translationRepository.loadBundle("primary", currentLocale),
        secondary : translationRepository.loadBundle("secondary", currentLocale)
    };

    for (var key in rawTranslations.primary){
        translations.primary = translations.primary || {};
        translations.primary[key] = rawTranslations.primary[key];
    }

    for (var key in rawTranslations.secondary){
        translations.secondary = translations.secondary || {};
        translations.secondary[key] = rawTranslations.secondary[key];
    }

    var ttl = config.ttl;

    cacheService.put(cacheKeyPrimary, translations.primary, ttl);
    // [...]

  1. requestService.isTranslatorEnabled
  2. requestService.getLocale
  3. cacheService.isActive
  4. translationRepository.loadBundle
  5. config.ttl
  6. cacheService.put
But that's not all. The function has to complete without error. So I also need to mock this lot:

var translationService = translationFactory.getTranslator();
var arrayLoader = translationFactory.getArrayLoader();

translationService.load(arrayLoader.load(translations.primary), 'primary', currentLocale);
translationService.load(arrayLoader.load(translations.secondary), 'secondary', currentLocale);

  1. translationFactory.getTranslator
  2. translationFactory.getArrayLoader
  3. arrayLoader.load
  4. translationService.load

What a nightmare. If this code was written cleanly, I'd simply have to test a method that takes a coupla arguments and returns a value. Simple.



Mocking

Still, we do what we have to. A mocking solution for this is as follows. This is the bit I suggested you not to worry about following too closely (so I've made it infeasibly small so you'll be less inclined to read it...) what's important is the amount of code involved, not what the code is doing:

describe("Tests for TranslationProvider", function() {

    var mockedLocale = "MOCKED_LOCALE";

    beforeEach(function(){
        this.dependencies = getTestDependencies();

        spyOn(this.dependencies.requestService, "getLocale").and.returnValue(mockedLocale);
        spyOn(this.dependencies.requestService, "isTranslatorEnabled").and.returnValue(true);

        spyOn(this.dependencies.cacheService, "isActive").and.returnValue(false);

        spyOn(this.dependencies.cacheService, "put");

        spyOn(this.dependencies.mockedArrayLoader, "load").and.returnValue(this.dependencies.mockedArrayLoader);
        spyOn(this.dependencies.mockedTranslator, "load");
        spyOn(this.dependencies.translationFactory, "getArrayLoader").and.returnValue(this.dependencies.mockedArrayLoader);
        spyOn(this.dependencies.translationFactory, "getTranslator").and.returnValue(this.dependencies.mockedTranslator);

        this.translationProvider = getTestTranslationProvider(this.dependencies.mockedConfig);
    });

    describe("tests with fully-populated bundle", function(){
        beforeEach(function(){
            var mockedBundle = {mocked:"bundle"};
            spyOn(this.dependencies.translationRepository, "loadBundle").and.returnValue(mockedBundle);
            this.mockedBundle = mockedBundle;
        });

        it("sets the primary translations when the repository provides some", function(){

            var translationService = this.translationProvider.initialise(
                this.dependencies.mockedConfig.translation,
                this.dependencies.cacheService,
                this.dependencies.translationRepository,
                this.dependencies.requestService,
                this.dependencies.translationFactory
            );

            testDependencyExpectations(this.dependencies, this.mockedBundle, mockedLocale);

            expect(translationService).toEqual(this.dependencies.mockedTranslator);
        });
    });

});

var getTestDependencies = function(){
    var mockedConfig = getMockedConfig();
    var cacheService = getCacheService(mockedConfig);
    var translationRepository = getTranslationRepository();
    var requestService = getRequestService();
    var translationFactory = getTranslationFactory();
    var mockedArrayLoader = getMockedArrayLoader();
    var mockedTranslator = getMockedTranslator();

    return {
        mockedConfig : mockedConfig,
        cacheService : cacheService,
        translationRepository : translationRepository,
        requestService : requestService,
        translationFactory : translationFactory,
        mockedArrayLoader : mockedArrayLoader,
        mockedTranslator : mockedTranslator
    };
};

var getTestTranslationProvider = function(config){
    var TranslationProvider = require("../../src/provider/TranslationProvider.js");
    return new TranslationProvider(config.translation);
};

var getMockedConfig = function(){
    return {
        cache : {
            active : false
        },
        translation : {
            bundles : {
                primary : {cacheKey : "MOCKED_TRANSLATIONS_PRIMARY"},
                secondary : {cacheKey : "MOCKED_TRANSLATIONS_SECONDARY"}
            },
            enabled : true,
            ttl : "MOCKED_TTL"
        }
    };
};

var getCacheService = function(config){
    return {
        isActive : function(){},
        exists : function(key){},
        get : function(key){},
        put : function(key, value){}
    };
};

var getTranslationRepository = function(){
    return {loadBundle : function(bundle, locale){}};
};

var getRequestService = function(){
    return {
        isTranslatorEnabled : function(){},
        getLocale : function(){}
    };
};

var getTranslationFactory = function(){
    return {
        getArrayLoader : function(){},
        getTranslator : function(){}
    };
};

var getMockedCacheKeyForBundle = function(bundle, locale){
    return "MOCKED_TRANSLATIONS_" + bundle.toUpperCase() + "_" + locale;
};

var getMockedArrayLoader = function(){
    return {load:function(translations){}};
};

var getMockedTranslator = function(){
    return {load:function(loader, bundle, locale){}};
};

var testDependencyExpectations = function(dependencies, mockedBundle, mockedLocale){
    var expectedPrimaryKey = getMockedCacheKeyForBundle("primary", mockedLocale);
    var expectedSecondaryKey = getMockedCacheKeyForBundle("secondary", mockedLocale);

    expect(dependencies.requestService.isTranslatorEnabled.calls.count()).toEqual(1);
    expect(dependencies.requestService.getLocale.calls.count()).toEqual(1);

    expect(dependencies.cacheService.isActive.calls.count()).toEqual(1);

    expect(dependencies.translationRepository.loadBundle.calls.count()).toEqual(2);
    expect(dependencies.translationRepository.loadBundle.calls.argsFor(0)).toEqual([
        "primary",
        mockedLocale
    ]);
    expect(dependencies.translationRepository.loadBundle.calls.argsFor(1)).toEqual([
        "secondary",
        mockedLocale
    ]);

    expect(dependencies.cacheService.put.calls.count()).toEqual(2);
    expect(dependencies.cacheService.put.calls.argsFor(0)).toEqual([
        expectedPrimaryKey,
        mockedBundle,
        dependencies.mockedConfig.translation.ttl
    ]);
    expect(dependencies.cacheService.put.calls.argsFor(1)).toEqual([
        expectedSecondaryKey,
        mockedBundle,
        dependencies.mockedConfig.translation.ttl
    ]);

    expect(dependencies.translationFactory.getTranslator.calls.count()).toEqual(1);
    expect(dependencies.translationFactory.getArrayLoader.calls.count()).toEqual(1);


    expect(dependencies.mockedArrayLoader.load.calls.count()).toEqual(2);
    expect(dependencies.mockedArrayLoader.load.calls.argsFor(0)).toEqual([mockedBundle]);
    expect(dependencies.mockedArrayLoader.load.calls.argsFor(1)).toEqual([mockedBundle]);

    expect(dependencies.mockedTranslator.load.calls.count()).toEqual(2);
    expect(dependencies.mockedTranslator.load.calls.argsFor(0)).toEqual([
        dependencies.mockedArrayLoader,
        "primary",
        mockedLocale
    ]);
    expect(dependencies.mockedTranslator.load.calls.argsFor(1)).toEqual([
        dependencies.mockedArrayLoader,
        "secondary",
        mockedLocale
    ]);

};


Note the only bit testing the actual function is highlighted. The rest of it is mocking dependencies. For goodness sake.

It's important to note that had we followed TDD we'd end up with the same amount of code, but it would have been written piecemeal, and at the time the code was first solicited. So we would have budgeted time for it. Bear in mind all I'm trying to do is use this code, and my ticket was "change this string value to this other string value, in the translation config": from "[the old dictionary name]" to "[our new dictionary name]". So we budgeted 1h for that (1h is our minimum estimate for anything).

Also bear in mind that mocking someone else's code - especially when it's this complex and unfamiliar to me - is not a trivial undertaking. That might "only" be 180 lines of code, but it took me a day to write. And that is just the last iteration that I saw fit to put in a pull request.

This is not on.

Tests

Here's the actual test code in a more readable size. This is about the right amount of code to be wanting to do for this fix:

describe("tests with fully-populated bundle", function(){
    beforeEach(function(){
        var mockedBundle = {mocked:"bundle"};
        spyOn(this.dependencies.translationRepository, "loadBundle").and.returnValue(mockedBundle);
        this.mockedBundle = mockedBundle;
    });

    it("sets the primary translations when the repository provides some", function(){

        var translationService = this.translationProvider.initialise(
            this.dependencies.mockedConfig.translation,
            this.dependencies.cacheService,
            this.dependencies.translationRepository,
            this.dependencies.requestService,
            this.dependencies.translationFactory
        );

        testDependencyExpectations(this.dependencies, this.mockedBundle, mockedLocale);

        expect(translationService).toEqual(this.dependencies.mockedTranslator);
    });
});

var testDependencyExpectations = function(dependencies, mockedBundle, mockedLocale){
    // [...]
    expect(dependencies.cacheService.put.calls.count()).toEqual(2);
    expect(dependencies.cacheService.put.calls.argsFor(0)).toEqual([
        expectedPrimaryKey,
        mockedBundle,
        dependencies.mockedConfig.translation.ttl
    ]);
    // [...]


With this we have a nice failing test now. Perfect.

Oh... note I'm testing the primary translations here not the secondary ones which were giving me the issue in the first place. As the code is identical for both, I figured one expediency I'd allow myself is just test it against the earlier ones. It's still testing the issue.

Fix

And I add the fix:

var translations = {};
var translations = {primary:{},secondary:{}};


(actually the final fix was not this as I refactored some unnecessarily duplicated code, but at this stage of the process, that's the fix).

Now have passing tests. I could now do a pull request and be done with it.

Red... green...

However we have another in-house rule: never make bad code worse. In this case the code is "bad" because it's too long. And adding another line to it makes it worse. In the bigger scheme of things, not that much worse, but still: having assessed that the code does not meet our coding standards, I am kinda compelled to do something about it.

... Re-estimate...

One thing I ballsed up here is that I was keeping all this mess from my colleague, and I was being very vague as to how long this "simple" task was gonna take. I'd let them know we had a problem and I needed to fix it, and it would take "a while", but I should have assessed how long it would take and decide whether "now" is the right time. I just decided for myself that now was the right time, which was not great. Always be up-front with your estimations, and any variation in original estimations.

If I'd done this at work, I'd've been shot. And I'd probably have loaded the gun for my scrum master and handed it to him as I'd've deserved it.

...Refactor

Whilst doing my initial tests, I was taking pains in my mocking to make sure all the mocked methods were being called the appropriate amount of times (for my own case), and I let myself believe this was a suitable test bed for safely extracting some helper methods, to make that initialise method a more sensible size. Now I don't think that's strictly true, but I figured "well our coverage is not getting any worse if my tests still pass after I refactor". This is slightly naughty.

So I extracted a few methods, and was left with this:

TranslationProvider.prototype.initialise = function(config, cacheService, translationRepository, requestService, translationFactory){
    if (!requestService.isTranslatorEnabled()){
        return;
    }

    var locale = requestService.getLocale();
    var translations = getTranslations(cacheService, translationRepository, locale);
    var translationService = createTranslationService(translationFactory, translations, locale);

    return translationService;
};

var getTranslations = function(cacheService, translationRepository, locale){
    var cacheKeys = {
        primary : getCacheKey("primary", locale),
        secondary : getCacheKey("secondary", locale)
    };

    var okToGetFromCache = cacheService.isActive()
        && cacheService.exists(cacheKeys.primary)
        && cacheService.exists(cacheKeys.secondary);

    var translations;
    if (okToGetFromCache) {
        translations = {
            primary : cacheService.get(cacheKeys.primary),
            secondary:cacheService.get(cacheKeys.secondary)
        };
    }else{
        translations = loadTranslationsFromRepository(translationRepository, locale);
        cacheTranslations(config, cacheService, translations, cacheKeys);
    }

    return translations;
};

var loadTranslationsFromRepository = function(translationRepository, locale){
    var rawTranslations = {
        primary : translationRepository.loadBundle("primary", locale),
        secondary : translationRepository.loadBundle("secondary", locale)
    };

    var translations = {primary:{}, secondary:{}};

    for (var key in rawTranslations.primary){
        translations.primary = translations.primary || {};
        translations.primary[key] = rawTranslations.primary[key];
    }

    for (var key in rawTranslations.secondary){
        translations.secondary = translations.secondary || {};
        translations.secondary[key] = rawTranslations.secondary[key];
    }
    return translations;
};

var cacheTranslations = function(config, cacheService, translations, cacheKeys){
    var ttl = config.ttl;

    cacheService.put(cacheKeys.primary, translations.primary, ttl);
    cacheService.put(cacheKeys.secondary, translations.secondary, ttl);
};

var createTranslationService = function(translationFactory, translations, locale){
    var translationService = translationFactory.getTranslator();
    var arrayLoader = translationFactory.getArrayLoader();

    translationService.load(arrayLoader.load(translations.primary), 'primary', locale);
    translationService.load(arrayLoader.load(translations.secondary), 'secondary', locale);

    return translationService;
};



That's much cleaner, and easier to see what's going on. The good news is that having done that, all the tests still passed. Now note there are more / different refactoring opportunities there too, but remember I was on the clock and these ones could be made without changing any tests. This is by no means perfect code. But it's better, and it'll be easier for the next person who comes along to maintain it.

Commit

So I did a pull request on that, my mate approved it, and in it went.

Testing too much

This is where I had messed up. One of the other devs on the project eyeballed my pull request and made the observation that I was testing the code, not the logic variations. And as a result my tests were very fragile. And I fell into a pitfall that Ciaran covered in that video I pointed you to the other day: "Endorsement: Ciaran McNulty's "Why Your Test Suite Sucks" presentation is really good".

Have a look at this:


spyOn(this.dependencies.requestService, "getLocale").and.returnValue(mockedLocale);
spyOn(this.dependencies.requestService, "isTranslatorEnabled").and.returnValue(true);
// [...]
expect(dependencies.requestService.isTranslatorEnabled.calls.count()).toEqual(1);
expect(dependencies.requestService.getLocale.calls.count()).toEqual(1);


This is to mock out and test these calls:

if (!requestService.isTranslatorEnabled()){
    return;
}

var locale = requestService.getLocale();


I've basically gone through and eyeballed the existing code and mapped how it runs and what it needs to be mocked. Most of the mock code is right, except this bit:

.calls.count()).toEqual(1)

Whilst we should all expect the getLocale and isTranslatorEnabled methods to be called once, my mate made the very valid observation that the initialise process doesn't care about that. They can run one time, ten times or potentially never get run at all. I mean the current implementation of initialise() needs to run that once, it's not intrinsic to the initialise() requirements, and indeed it's not even one of the contingencies of any of the logic I'm testing.

What I need to mock here is that I need getLocale to return something (anything), and I need isTranslatorEnabled to return true. And this is only cos I need to get to code further down for my tests... not that I actually care about it. This is the mechanics of mocking, it's not part of the test. So the spyOn() calls are correct here, but the expectations are not. I ditched them.

There were a few of these, and most were wrong. There was only one I did need:

expect(dependencies.cacheService.put.calls.argsFor(0)).toEqual([
    expectedPrimaryKey,
    mockedBundle,
    dependencies.mockedConfig.translation.ttl
]);


This is to ensure this code runs:

cacheService.put(cacheKeys.primary, translations.primary, ttl);

I need to test that bit, because it's the first "exit point" that I can spy on the result of the translation building process. If I pass an empty result from the repository into my function, I want to ensure my processing still results in translations.primary being created. Remember my original issue was that the translation object to send to the translator were not being created if the there was no bundle data coming back from the repo.

Similarly I had been type-checking overly aggressively for what I was testing. The code above demonstrates this. The logic I'm testing is only regarding whether the value for the translations that are created are correct. But in that expectation above I'm also testing the cache-key and the TTL. There's really nothing wrong with enforcing them here, but what it does do is de-focus from what I am testing:


expect(dependencies.cacheService.put.calls.argsFor(0)[1]).toEqual(mockedBundle);


This gets rid of worrying about the key and the TTL, and just checks that the translations I'm caching (which are the ones I just created) are what I expected them to be. Job done.

Testing at the wrong time

My cock-ups there are down to testing at the wrong time. If I had been writing the tests when they should have been written, I'd not been surveying existing lines of code and testing them, I would instead of been testing my requirements and my variations on said requirements, rather than the implementation code. This hadn't occurred to me until I watched hat video of Ciaran's I mention above. He points this out. This is just one of the peril of back-filling unit tests that one should be aware of, I guess.

Outcome

The code is still not perfect, but no code ever is so that's fine. However now it's got a bit of test coverage, and the scene is set for the next person maintaining the code to face cleaner code, and the basis for adding in their own tests.

It's important to remember that yer not writing code for yerself: yer writing it for the next person (which coincidentally might be yourself, but that's not the point). Code quality is not about "now", it's about "next time". So if you write unclean, untested code? You're actually stitching-up yourself and your colleagues a bit. So don't do that.

The other outcome - for me - is that I learnt another coupla facets of unit testing and TDD that hadn't occurred to me before, so that's a win. I also learned a lot more about Jasmine, which is what I'm using for JavaScript testing here, and that's probably interesting enough for an article of its own.

Righto.

--
Adam