Category

general development

Machine Readable Logs in PHP

I’m a big believer that log files should be easy for machines to read and ingest. Structured logging opens up the door for using tools like the ELK stack or Splunk to aggregate, search, monitor, and alert on application activity.

The most common format for structured logging seems to be JSON. There are, of course, a lot of logging libraries for PHP, but I’ve been using log4php forever and don’t have any plans to switch. Like most logging libraries, log4php logs straight up strings.

There is no built in appender for JSON log formatting, though. The good news is that it’s easy to get properly formatted JSON logs using the standard LoggerAppenderDailyFile.

Here’s what I did.

First, I updated my log4php.config.xml file to write a JSON structure for the LoggerLayoutPattern. My updated appender looks like this. (For reference, all of log4php’s conversion parameters can be found here)

<appender name="jsonAppender" class="LoggerAppenderDailyFile">
   <layout class="LoggerLayoutPattern">
      <param name="conversionPattern" value="{&quot;timestamp&quot;:&quot;%d&quot;, &quot;level&quot;:&quot;%p&quot;, &quot;ip&quot;:&quot;%server{REMOTE_ADDR}&quot;, &quot;details&quot;:%m}%n"/>
   </layout>
   <param name="file" value="/tmp/application_json_%s.log"/>
   <param name="append" value="true"/>
</appender>

Let’s break the conversion pattern down.

We open it with a bracket { and close it with another bracket followed by a newline }%n

This is just the basic JSON data structure.

Next we add a timestamp. This is where it gets a little funky. We have to encode the quotes because the config file is XML. %d the parameter is the standard ISO8601 datetime format.

&quot;timestamp&quot;:&quot;%d&quot;

This is equivalent to a JSON object that looks like {“timestamp”:”%d”}

The rest is pretty much the same.

{&quot;timestamp&quot;:&quot;%d&quot;, &quot;level&quot;:&quot;%p&quot;, &quot;ip&quot;:&quot;%server{REMOTE_ADDR}&quot;, &quot;details&quot;:%m}%n

This creates a JSON object that looks like this

{“timestamp”:”%d”, “level”:”%p”, “ip”:”%server{REMOTE_ADDR}”, “details”:%m}%n

Next we need to make sure that the log information is written as JSON instead of plain text. I have a standard static Log class that I use for all logging.

class Log
{
    /**
     * @var Log
     */
    protected static $_instance;

    /**
     * @var Logger
     */
    protected $logger;

    protected function __construct()
    {
        Logger::configure("log4php.config.xml");
        $this->logger = Logger::getLogger('default');
    }

    /**
     * @return Log
     */
    private static function &GetInstance()
    {
        if (is_null(self::$_instance)) {
            self::$_instance = new Log();
        }

        return self::$_instance;
    }

    /**
     * @param string $message
     * @param array $args
     * @return LogMessage
     */
    private static function EnrichLog($message, $args)
    {
        $logMessage = new LogMessage($message, $args);
        $debug = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
        if (is_array($debug)) {
            $debugInfo = $debug[1];
        }
        else {
            $debugInfo = array('file' => null, 'line' => null);
        }

        $logMessage->userId = $_SESSION['userId'];
        $logMessage->file = $debugInfo['file'];
        $logMessage->line = $debugInfo['line'];
        return $logMessage;
    }

    /**
     * @param string $message
     * @param array $args
     */
    public static function Debug($message, $args = array())
    {
        if (!self::GetInstance()->logger->isDebugEnabled()) {
            return;
        }

        try {
            $log = json_encode(self::EnrichLog($message, $args));
            self::GetInstance()->logger->debug($log);
        } catch (Exception $ex) {
            echo $ex;
        }
    }

    /**
     * @param string $message
     * @param array $args
     */
    public static function Info($message, $args = array())
    {
        if (!self::GetInstance()->logger->isInfoEnabled()) {
            return;
        }

        try {
            $log = json_encode(self::EnrichLog($message, $args));
            self::GetInstance()->logger->info($log);
        } catch (Exception $ex) {
            echo $ex;
        }
    }

    /**
     * @param string $message
     * @param array $args
     */
    public static function Warn($message, $args = array())
    {
        if (!self::GetInstance()->logger->isWarnEnabled()) {
            return;
        }

        try {
            $log = json_encode(self::EnrichLog($message, $args));
            self::GetInstance()->logger->warn($log);
        } catch (Exception $ex) {
            echo $ex;
        }
    }

    /**
     * @param string $message
     * @param array $args
     * @param Exception|null $exception
     */
    public static function Error($message, $args = array(), $exception = null)
    {
        if (!self::GetInstance()->logger->isErrorEnabled()) {
            return;
        }

        try {
            $logMessage = self::EnrichLog($message, $args);
            $logMessage->exception = $exception;
            $log = json_encode($logMessage);
            self::GetInstance()->logger->error($log);
        } catch (Exception $ex) {
            echo $ex;
        }
    }

    /**
     * @param string $message
     * @param array $args
     * @param Exception|null $exception
     */
    public static function Fatal($message, $args = array(), $exception = null)
    {
        if (!self::GetInstance()->logger->isFatalEnabled()) {
            return;
        }

        try {
            $logMessage = self::EnrichLog($message, $args);
            $logMessage->exception = $exception;
            $log = json_encode($logMessage);
            self::GetInstance()->logger->fatal($log, $args);
        } catch (Exception $ex) {
            echo $ex;
        }
    }

    public static function SetInstance($logger)
    {
        self::$_instance = $logger;
    }
}

class LogMessage
{
    /**
     * @var string
     */
    public $message;

    /**
     * @var int|null
     */
    public $userId;

    /**
     * @var string|null
     */
    public $file;

    /**
     * @var string|null
     */
    public $line;

    /**
     * @var array|null
     */
    public $args;
	
    /**
     * @var Exception|null
     */
    public $exception;

    public function __construct($message, $args = null)
    {
        $this->message = $message;
        $this->args = $args;
    }
}

Using this is pretty simple, we just need to make sure we pass in any variables we want in a format that converts to JSON easily. I use an array because it’s readable and lightweight.

Log::Debug('This is a log message', ['param1' => 'value1', 'param2' => 123]);

Would end up writing a log message that looks like this

{"timestamp":"2020-09-18T10:17:16-04:00", "details":"{"message":"This is a log message","userId":1,"file":"/var/www/app/test-logger.php","line":71,"args":{"param1":"value1", "param2": 123},"exception":null}", "level": "DEBUG"}

This log can easily be parsed and searched using ElasticSearch now. This makes it trivial to find specific log events and look at trends.

To take it a step further, I could create a correlationId that is stored in the session at the beginning of a web request and added to every log entry. Now I can connect all the log events for every request.

Node – Get Named Command Line Arguments

I am writing a small command line utility using Node and needed to get named arguments from the command line. A quick Google search led me down crazy complicated rabbit holes and (of course) a bunch of recommendations to just install npm modules.

There ain’t no way I’m installing an npm module to READ COMMAND LINE ARGUMENTS!

So I wrote a tiny function that gets command line arguments and turns them into an object. 10 lines is all you need in ES6.

function getArgs() {
  const args = process.argv.slice(2);
  let params = {};

  args.forEach(a => {
    const nameValue = a.split("=");
    params[nameValue[0]] = nameValue[1];
  });

  return params;
}

Easy enough. Now if I call the script from the command line like this:

node myapp.js arg1=foo arg2=bar

I can transform the arguments to an object by calling:

const args = getArgs();

Which will give me the following object:

{
arg1: "foo",
arg2: "bar"
}

So now I can just do this:

// called using node myapp.js name=nick role="master of node"

const args = getArgs();
console.log(`${args.name} is the ${args.role}`);

// which outputs "nick is the master of node"

I mean, that’s all there is to it. I’ll save my rant about the wasteland that is npm for another post.

Configuring Sonar with a Create React App in TypeScript

There are a ton of posts on StackOverflow and Medium and the rest of the internet on setting up SonarQube, but I couldn’t find a definitive guide on configuring it with a React web application (using react-scripts/create react app) written in TypeScript. Turns out that it’s not that hard once you know all the pieces that need to be pulled together.

This article was written in February, 2020. These are the versions of the different components I’m using. Your mileage may vary.

  • Yarn 1.2.1
  • Node 12.4.1
  • React 16.12.0
  • Sonar 7.9.2
  • TypeScript 3.7.5
  • Docker Desktop (Windows) 2.2.0.0
  • Docker 19.03.5
  • react-scripts 3.3.0
  • sonarqube-scanner 2.5.0
  • jest-sonar-reporter 2.0.0

First of all, I’m going to assume nothing is ejected from the CRA configuration and that you have a working application written in TypeScript. For example if you cannot successfully run npm test or yarn test then this guide will not work. I’m also assuming you’re comfortable with Docker.

SonarQube

Get SonarQube up. I used Docker for this because it was the quickest way.

First, set your memory allocation for Docker to at least 4GB for the Sonar container to be able to run correctly. ElasticSearch needs this, I guess.

Next, I used this docker-compose file from https://github.com/SonarSource/docker-sonarqube/blob/master/example-compose-files/sq-with-postgres/docker-compose.yml. Just docker-compose up. This will start a SonarQube instance using Postgres on http://localhost:9000

Open that URL in a browser, log in with admin/admin, and make sure everything is looking good. There should be a wizard that guides you through creating a security token for your user. If not, you can always do so in Administration > Security and creating a Sonar user just for project analysis (this is probably a good idea anyway).

Analyzing your React application with Sonar

Tools

You’ll need a couple tools to simplify this process. Install sonarqube-scanner and jest-sonar-reporter into your React project using either yarn or npm. Save it as a development dependency.

yarn add -D sonarqube-scanner
yarn add -D jest-sonar-reporter

Sonar Configuration

I was expecting to do a bunch of configuration within Sonar itself, but it can all be contained within your React project. In the root of your project (at the same level as your package.json) create a file named sonar-project.js with the following contents. I’ll go over the details next.

const sonarqubeScanner = require("sonarqube-scanner");
sonarqubeScanner(
  {
    serverUrl: "http://localhost:9000",
    token: "YOUR-TOKEN-HERE",
    options: {
      "sonar.sources": "./src",
      "sonar.exclusions": "**/__tests__/**",
      "sonar.tests": "./src/__tests__",
      "sonar.test.inclusions": "./src/__tests__/**/*.test.tsx,./src/__tests__/**/*.test.ts",
      "sonar.typescript.lcov.reportPaths": "coverage/lcov.info",
      "sonar.testExecutionReportPaths": "reports/test-report.xml",
    },
  },
  () => {},
);

Each of these settings is a standard Sonar configuration property, but they weren’t immediately clear to me.

  • serverUrl is the URL to your SonarQube instance
  • token is the security token assigned to your Sonar user
  • sonar.sources is the base directory for all of your code. This is where your React application lives (in my case the *.tsx files). By default, CRA puts __tests__ within the src directory. We’ll deal with that next.
  • sonar.exclusions is everything you do not want Sonar to analyze. The most important one for me is that we don’t want to be analysis on our tests. In fact, if there is overlap between sonar.sources and sonar.tests then Sonar will throw an indexing error. So I exclude anything in any __tests__ folder.
  • sonar.tests is the location of all of your tests. By default, CRA puts this in /src/__tests__
  • sonar.test.inclusions is a comma separated list of all files that should be treated as test files. I have a mix of .tsx and .ts tests, but they all follow the standard jest pattern of testname.test.ts*
  • sonar.typescript.lcov.reportPaths is the path to the test coverage output file from jest. By default this will be coverage/lcov.info
  • sonar.testExecutionReportPaths is the path to the jest-sonar-reporter output file. We’ll configure this next.

Test Coverage Configuration

The first thing to note is that we use the sonar.typescript.lcov.reportPaths property in our sonar-project.js configuration, not the javascript property.

By default jest-sonar-reporter outputs a file called test-report.xml to the root directory. I don’t like littering that directory with unrelated files, so I added this to the end of my package.json file in order to put the report in a reports directory.

"jestSonar": {
  "reportPath": "reports",
  "reportFile": "test-report.xml",
  "indent": 4
}

The last thing you need to do is tell react-scripts to use this test report generator rather than the default. I assume you have something like this in your package.json scripts definition.

"test": "react-scripts test --silent --env=jsdom"

We need to change that so we process the results in a Sonar-friendly format

"test": "react-scripts test --silent --env=jsdom --coverage --testResultsProcessor jest-sonar-reporter"

To be honest, I do one more thing so that we’re not watching tests, so my test script is, which tells react-scripts that we’re running in a continuous integration mode and should not watch.

"test": "cross-env CI=true react-scripts test --silent --env=jsdom --coverage --testResultsProcessor jest-sonar-reporter",

Running Sonar Analysis

We’ll add another script to our package.json file to initiate the Sonar analysis.

"sonar": "node sonar-project.js"

At this point we have all of our configuration done and just need to run everything.

First run your tests

yarn test

This should run all of your tests with coverage. You’ll have files in /coverage and /reports.

Next, run your sonar analysis

yarn sonar

This will take a couple minutes, depending on the size of your project. But when it’s complete, refresh your Sonar projects and you should see your project show up. By default, it will use the name defined in your package.json file.

Continuous Integration

If you wanted to (and why wouldn’t you) integrate this into your CI environment so every push triggers a Sonar analysis, you can just add a build step that invokes yarn sonar after your test stage.

Other Projects

I’m using this base set of instructions for all of my TypeScript based projects. The only thing that really changes is the location of source, tests, and the inclusion/exclusion list. For example, in my api, where I have __tests_ at the same level as src (instead of nested within), my sonar-project.js looks like this.

const sonarqubeScanner = require("sonarqube-scanner");

sonarqubeScanner(
  {
    serverUrl: "http://localhost:9000",
    token: "MY-TOKEN",
    options: {
      "sonar.sources": "./src",
      "sonar.tests": "./__tests__",
      "sonar.test.inclusions": "./__tests__/**/*.test.ts",
      "sonar.typescript.lcov.reportPaths": "coverage/lcov.info",
      "sonar.testExecutionReportPaths": "reports/test-report.xml",
    },
  },
  () => {},
);

Some Cleanup

This whole thing will create some cruft in your project. You want to ignore /.scannerwork, /coverage, /reports from Git.

Learning how to modern web dev

I’m neck deep in learning ES6, React, Typescript, Node and all the billions of pieces that are a part of this “ecosystem”. I think I’m going to post some of the things that I learn along the way here.

Most of it will probably be obvious if you’ve been working with these technologies for a while, though I assumed a lot of what I was trying to do would be easily discoverable online. Maybe I just need to take some Google lessons.

My Lessons

Lessons to write about…

  • Using Sequelize CLI (and probably a rant about all ORMs, but especially this one)
  • Avoiding Redux and test driving React apps using hooks
  • Dockerizing a dev database
  • Writing integration tests with Sequelize without losing my mind

Packaging a Node Express App

I’m not sure how most of the JavaScript world is building, packaging, and deploying their applications. We’re using Yarn instead of npm, but neither tool provides a simple way to zip up and version your app (unless you’re publishing to npm, that is).

Here’s what worked for me (based on Yarn 1.15.2). As with everything I post, If there are better ways, please tell me.

Install cross-var to support consistent variable usage in package.json across Windows and Mac.

yarn add cross-var

Install bestzip to support cross-platform packaging.

yarn add bestzip

Install copyfiles to support cross-platform, configurable file copying.

yarn add copyfiles

Create a script in package.json for compiling TypeScript to JavaScript

"build:ts": "tsc"

Create a script in package.json for copying the compiled files to a /dist directory

"copy": "copyfiles -a -e \"**/*.ts\" -u 1 \"src/**/*.*\" dist"

Create a script in package.json for packing up the source and dependent node_modules

"package": "cross-var bestzip $npm_package_name-$npm_package_version.zip dist/* node_modules/* package.json"

Notice the $npm_* variables? Apparently you can use any variable defined in package.json within package.json. You just need cross-var to consistently access them.

That ended up being it. Here is a redacted package.json that I’m using:

{
"name": "Nick Korbel Demo",
"version": "0.1.0",
"description": "The demo for packaging",
"private": true,
"main": "dist/index.js",
"scripts": {
"build:ts": "tsc",
"copy": "copyfiles -a -e \"/.ts\" -e \"/.spec.js\" -e \"/.log\" -u 1 \"src//.\" dist", "start": "node ./dist/index.js", "package": "cross-var bestzip $npm_package_name-$npm_package_version.zip dist/ node_modules/* package.json"
},
… more stuff here like dependencies

This post is part of a series I’m writing to share what I’m learning

Oh no… GitFlow

It seems like every team I’ve worked with in the past few years follows some form of GitFlow. At the very least, they use feature branches and pull requests to perform code reviews.

How we got here

The creation of distributed source control systems made the pull request model possible. Distributed source control systems emerged from the open source community, where there is typically a group of independent people working on a shared system and there is a need for trusted reviewers to gate changes to the code. With previous tools like CVS or Subversion, the cost of accepting a contribution to open source projects was high. Unless the author was already a trusted contributor, it usually involved submitting a patch.

Context is king

I view code as the end result of a series of decisions made by the code’s author. When the author was writing the code, they likely evaluated a series of approaches, tried a few of them, and found one to be the best solution to the problem. The final code can’t possibly capture the all decisions that were made or all of the trade-offs that were considered, though.

I was using Subversion for version control for Booked for many years. When other people had changes they wanted to contribute I asked them to commit directly to trunk or to create a branch. I’d often have to revert commits or make non-trivial changes to ensure the commit didn’t break the application. I moved to Git a couple of years back and being able to review/accept pull requests has certainly made it easier to incorporate contributions to the source from external developers.

Unfortunately, I still don’t have the author’s context which led to the decision to change or write a certain line of code. Collaboration tools make the discussion easier by being able to point to specific changes. Pull requests certainly enable a technically simpler process for accepting changes to the source, but they do not provide any other benefits over methods like patch submission.

Wait, what are we doing?

Using pull requests on a team all working on the same project is so strange to me. It’s a process designed for highly-distributed, loosely-coupled developers to contribute to the same codebase. If the team is co-located, there is no physical separation that forces an asynchronous process. There is very rarely a risk of a change being submitted that isn’t part of an agreed upon team strategy.

Yet, I see pull request comments and iterations of changes fly back and forth over the course of hours, days, or even weeks. Often, the resulting changes only take a few hours of hands-on work in culmination, but take orders of magnitude longer due to the asynchronous nature of the pull request process. During each passing minute the author’s memory of their decision making process fades. This is compounded if the author moves on to work on something new – but work in progress abuse is a topic for another blog post.

At my first real job in the early 2000s we did side by side code reviews. I would sit down with another developer (there was only one other person, so I guess I should say that I’d sit down with THE other developer) and talk through the changes I made to enable a new feature.

Unless the review was happening within a few minutes of finishing the feature, it’s very likely that I didn’t remember the specific context which led to the decision to write a specific line of code. Side by side code reviews encourage discussion and are a drastic improvement over pull requests, but I think we can do better.

We can do better

The most productive team I’ve ever been a part of adopted pair-programming for all production code. Two people, two monitors, two keyboards, one computer. There is no way to lose the context of each line of code being written when practicing pair-programming. This is a real-time collaborative decision making and code review process.

Our team had no need for a separate review step, because we already had the multiplicative brain power of two people involved in the creation of the code. Even without the “formal” review and merge process, we had incredibly high quality with almost zero knowledge gaps throughout the team.

One more gripe, that’s it, I promise

Here’s my last gripe with code reviews and pull requests as commonly practiced – they defer continuous integration.

Continuous integration is the process of continually integrating the whole team’s set of changes at a regular cadence. The purpose is simple – regularly integrating, compiling, and testing outstanding changes minimizes the time between the code working on one person’s machine and validation that it works once combined with the rest of the team’s changes.

Pull requests (more specifically feature branches, I suppose) defer integration. Sure, if you’re a diligent developer you may pull master into your branch a few times a day. But since everyone on the team is committing to their own branch, master is missing the majority of the outstanding changes and full integration is being deferred.

When I talk to teams about this, I regularly hear the opinion that it’s a good thing.

There is an impression that feature branching and pull requests help keep master stable. I agree with the spirit of this approach. I agree with always-releaseable code. But let’s be honest, if a team can’t keep trunk stable, why would maintaining X number of branches will be stable?

Branches are a security blanket. Sure, they make you feel safe, but provide little to actually provide safety. It’s just an illusion.

Always-releasable doesn’t mean change should be avoided or isolated. While it is true that not changing the code is the easiest way to keep it from breaking, building up large batches of changes that all get merged once “complete” is far more risky than committing small changes to a single branch daily. When the time between writing a line of code and knowing if it causes unexpected issues is short, it becomes very simple to identify and correct it.

Issues have nowhere to hide in a small change set.

The sales pitch

So I guess my pitch here is to try different approaches.

Try trunk based development as an alternative to feature branches. Try pair-programming as an alternative to pull requests.

If you’re absolutely not going to budge from feature branches, impose a rule that a branch cannot live longer than 24 hours. If you’re absolutely not going to budge from pull requests, impose a rule that all reviews must be complete within a few hours.

Tighten the feedback loop and see what good comes from it.

These things may not be for every team, but it may work for your team.

Loss Aversion and Tech Debt

Humans are loss-adverse. We place an irrationally high value on losing something over gaining an identical item. So for example, I’d be more upset about losing $10 than the happiness I’d feel by gaining $10. If I buy a meal and hate it, I’ll likely finish it anyway.

In general, people would rather gamble on a 50% chance of losing $1000 rather than giving up $500. Down $50 at the blackjack table? Odds are most people will want to try to win that back rather than take the loss. Curiously, most people would rather accept a guaranteed $500 rather than accept a 50% chance of making $1000. Irrational? Yup, but extremely predictable.

Loss Aversion is the fancy name for the phenomenon. People prefer avoiding losses to acquiring gains, which drives them to become more-risk tolerant in the face of loss. I think it can help explain how we build up and continue to live with technical debt in software development.

Tech debt is a useful metaphor describing the long term consequences inflicted upon a code base by deferring work. Similar to financial debt, we often choose to avoid doing the “right thing” now in favor of a faster path to the end result. The interest accrued by the debt adds up over time and can cause major problems.

There are lots of reasons that software engineers knowingly take on tech debt – deadlines, lack of knowledge or skills, too much work in progress – the list goes on. Sometimes it is unavoidable, sometimes not. Every project has some level of debt, though.

Paying off accumulated technical debt is where I see the ties into loss aversion. The time spent fixing a hastily implemented data access strategy, for example, is time not spent implementing a cool new feature. There is rarely any directly visible customer value delivered by paying off technical debt. In most people’s eyes, this is a loss of time, opportunity, and resources.

We are irrationally risk-tolerant in the face of this loss. Instead of spending $500 to pay off the debt, we’ll flip the coin, let the problems grow, and take the risk of losing $1000. Who knows, maybe the problems won’t surface for a long time. Maybe never. Maybe tomorrow, though.

So how do we fix this if the human mind is hardwired to avoid losses?

Shift the mindset of technical debt. Knowingly taking on technical debt is a loss, not a gain. We are losing the ability to easily respond to future requirements; we are not gaining a new feature in a shorter time frame. And existing tech debt should be seen as a sunk cost – it’s lost, and it’s better to forget the past.

If we accept the current state rather than treating tech debt as an incurred loss we will be less likely to gamble with the possibility of future losses. And hopefully our minds will start to blast warning sirens as we consider taking on new technical debt in the future.

TDD: Back to Hand Rolled Stubs

I’m unashamedly an Agile practitioner and self-proclaimed enthusiast. It’s not a perfect way to build software, but I haven’t found anything better. And until I do, this is the approach I’m taking.

Building Quality In

One of the core principles of Agile is the focus of building quality in from the start, not asserting quality after the product is built. At first this is counter-intuitive, right? How can you ensure the quality of something which is in the process of being built? This is where TDD saves the day. Write your tests first – set the expectations of what the code is supposed to do – then write the production code.

When I rewrote Booked for the 2.0 release I did it all test-first. In fact, there are thousands of assertions covering the majority of the code base. This is super important for a dynamic language like PHP where it is very easy to shoot yourself in the foot. Lots of tests = high confidence that my change didn’t break something. Of course, unit tests in a statically typed language are also critical.

The Unit Testing Approach

I use PHPUnit in Booked and it works great. Aside from providing your typical unit testing functionality, PHPUnit also includes test doubles. Mocks and stubs are great for substituting behavior and isolating components in your tests. It’s a technique I rely on heavily and it leads to loosely coupled code and more focused tests.

Martin Fowler has a great writeup comparing mocks, stubs and other substitution patterns.

Death By Over-Specification

When I first starting practicing TDD there weren’t a lot of mocking frameworks or libraries available. We wrote our stubs and mocks by hand and used a plain assertion framework (nUnit in the .NET space). It takes some time to write this code – you’re building new objects to stand in for existing objects. The interfaces need to match, the return types need to match, and in some cases the return object needs to be set up in a certain way. It can be a decent amount of work. My laziness is what led me to mocking frameworks.

Mocking libraries gained a lot of traction around 2006/2007. Mocks, and mocking frameworks in particular, work by setting up expectations and then returning appropriate responses when you exercise the code. This awesome because you can quickly substitute behavior of specific methods without building up a whole object.

Great! Look how fast I’m going!

So Super Fast

One problem with mocks is that they want to know everything about your code. For example, given you pass parameters x, y, z to this function then return this specific result. This is great when you care about how you execute a function – and there are valid reasons to care about that. This is not great when all you want to do is return a canned response and move on. One of the most frequent arguments I hear against unit testing and TDD is that the tests are fragile and difficult to maintain. Over-specification is generally the real cause of these problems.

An Example

Here’s a test pulled straight from the Booked test suite.

public function testBindsDefaultScheduleByMonthWhenNothingSelected()
{
	$this->page = $this->getMock('ICalendarPage');
	$this->repository = $this->getMock('IReservationViewRepository');
	$this->scheduleRepository = $this->getMock('IScheduleRepository');
	$this->calendarFactory = $this->getMock('ICalendarFactory');
	$this->resourceService = $this->getMock('IResourceService');
	$this->subscriptionService = $this->getMock('ICalendarSubscriptionService');
	$this->privacyFilter = new FakePrivacyFilter();

	$this->presenter = new CalendarPresenter(
		$this->page,
		$this->calendarFactory,
		$this->repository,
		$this->scheduleRepository,
		$this->resourceService,
		$this->subscriptionService,
		$this->privacyFilter);

	$showInaccessible = true;
	$this->fakeConfig->SetSectionKey(ConfigSection::SCHEDULE, ConfigKeys::SCHEDULE_SHOW_INACCESSIBLE_RESOURCES, 'true');

	$userId = $this->fakeUser->UserId;
	$defaultScheduleId = 10;
	$userTimezone = "America/New_York";

	$calendarType = CalendarTypes::Month;

	$requestedDay = 4;
	$requestedMonth = 3;
	$requestedYear = 2011;

	$month = new CalendarMonth($requestedMonth, $requestedYear, $userTimezone);

	$startDate = Date::Parse('2011-01-01', 'UTC');
	$endDate = Date::Parse('2011-01-02', 'UTC');
	$summary = 'foo summary';
	$resourceId = 3;
	$fname = 'fname';
	$lname = 'lname';
	$referenceNumber = 'refnum';
	$resourceName = 'resource name';

	$res = new ReservationItemView($referenceNumber, $startDate, $endDate, 'resource name', $resourceId, 1, null, null, $summary, null, $fname, $lname, $userId);

	$r1 = new FakeBookableResource(1, 'dude1');
	$r2 = new FakeBookableResource($resourceId, $resourceName);

	$reservations = array($res);
	$resources = array($r1, $r2);
	/** @var Schedule[] $schedules */
	$schedules = array(new Schedule(1, null, false, 2, null), new Schedule($defaultScheduleId, null, true, 3, null),);

	$this->scheduleRepository
			->expects($this->atLeastOnce())
			->method('GetAll')
			->will($this->returnValue($schedules));

	$this->resourceService
			->expects($this->atLeastOnce())
			->method('GetAllResources')
			->with($this->equalTo($showInaccessible), $this->equalTo($this->fakeUser))
			->will($this->returnValue($resources));

	$this->resourceService
			->expects($this->atLeastOnce())
			->method('GetResourceGroups')
			->with($this->equalTo(null), $this->equalTo($this->fakeUser))
			->will($this->returnValue(new ResourceGroupTree()));

	$this->page
			->expects($this->atLeastOnce())
			->method('GetScheduleId')
			->will($this->returnValue(null));

	$this->page
			->expects($this->atLeastOnce())
			->method('GetResourceId')
			->will($this->returnValue(null));

	$this->repository
			->expects($this->atLeastOnce())
			->method('GetReservationList')
			->with($this->equalTo($month->FirstDay()),
				   $this->equalTo($month->LastDay()->AddDays(1)),
				   $this->equalTo(null), $this->equalTo(null),
				   $this->equalTo(null), $this->equalTo(null))
			->will($this->returnValue($reservations));

	$this->page
			->expects($this->atLeastOnce())
			->method('GetCalendarType')
			->will($this->returnValue($calendarType));

	$this->page
			->expects($this->atLeastOnce())
			->method('GetDay')
			->will($this->returnValue($requestedDay));

	$this->page
			->expects($this->atLeastOnce())
			->method('GetMonth')
			->will($this->returnValue($requestedMonth));

	$this->page
			->expects($this->atLeastOnce())
			->method('GetYear')
			->will($this->returnValue($requestedYear));

	$this->page
			->expects($this->atLeastOnce())
			->method('SetFirstDay')
			->with($this->equalTo($schedules[1]->GetWeekdayStart()));

	$this->calendarFactory
			->expects($this->atLeastOnce())
			->method('Create')
			->with($this->equalTo($calendarType),
				   $this->equalTo($requestedYear), $this->equalTo($requestedMonth), $this->equalTo($requestedDay),
				   $this->equalTo($userTimezone))
			->will($this->returnValue($month));

	$this->page->expects($this->atLeastOnce())->method('BindCalendar')->with($this->equalTo($month));

	$details = new CalendarSubscriptionDetails(true);
	$this->subscriptionService->expects($this->once())->method('ForSchedule')->with($this->equalTo($defaultScheduleId))->will($this->returnValue($details));

	$this->page->expects($this->atLeastOnce())->method('BindSubscription')->with($this->equalTo($details));

	$calendarFilters = new CalendarFilters($schedules, $resources, null, null, new ResourceGroupTree());
	$this->page->expects($this->atLeastOnce())->method('BindFilters')->with($this->equalTo($calendarFilters));

	$this->presenter->PageLoad($this->fakeUser, $userTimezone);

	$actualReservations = $month->Reservations();

	$expectedReservations = CalendarReservation::FromScheduleReservationList($reservations,
																			 $resources,
																			 $this->fakeUser,
																			 $this->privacyFilter);

	$this->assertEquals($expectedReservations, $actualReservations);
}

This is 75 lines of mock setup code! We’re expecting specific parameters and have mock objects being returned all over. Let’s take a look at this same test with stubs.

public function testBindsDefaultScheduleByMonthWhenNothingSelected()
{
	$this->page = new StubCalendarPage();
	$this->repository = new StubReservationViewRepository();
	$this->scheduleRepository = new StubScheduleRepository();
	$this->calendarFactory = new StubCalendarFactory();
	$this->resourceService = new StubResourceService();
	$this->subscriptionService = new StubCalendarSubscriptionService();
	$this->privacyFilter = new FakePrivacyFilter();

	$this->presenter = new CalendarPresenter(
		$this->page,
		$this->calendarFactory,
		$this->repository,
		$this->scheduleRepository,
		$this->resourceService,
		$this->subscriptionService,
		$this->privacyFilter);

	$showInaccessible = true;
	$this->fakeConfig->SetSectionKey(ConfigSection::SCHEDULE, ConfigKeys::SCHEDULE_SHOW_INACCESSIBLE_RESOURCES, 'true');

	$userId = $this->fakeUser->UserId;
	$defaultScheduleId = 10;
	$userTimezone = "America/New_York";

	$calendarType = CalendarTypes::Month;

	$requestedDay = 4;
	$requestedMonth = 3;
	$requestedYear = 2011;

	$month = new CalendarMonth($requestedMonth, $requestedYear, $userTimezone);

	$startDate = Date::Parse('2011-01-01', 'UTC');
	$endDate = Date::Parse('2011-01-02', 'UTC');
	$summary = 'foo summary';
	$resourceId = 3;
	$fname = 'fname';
	$lname = 'lname';
	$referenceNumber = 'refnum';
	$resourceName = 'resource name';

	$res = new ReservationItemView($referenceNumber, $startDate, $endDate, 'resource name', $resourceId, 1, null, null, $summary, null, $fname, $lname, $userId);

	$r1 = new FakeBookableResource(1, 'dude1');
	$r2 = new FakeBookableResource($resourceId, $resourceName);

	$reservations = array($res);
	$resources = array($r1, $r2);
	/** @var Schedule[] $schedules */
	$schedules = array(new Schedule(1, null, false, 2, null), new Schedule($defaultScheduleId, null, true, 3, null),);

	$this->scheduleRepository->SetSchedules($schedules);

	$this->resourceService->SetResources($resources);

	$this->page->SetScheduleId(null);

	$this->page->SetResourceId(null);

	$this->repository->SetReservaions($reservations);

	$this->page->SetCalendarType($calendarType);

	$this->page->SetDate($requestedDay, $requestedMonth, $requestedYear);

	$this->page->SetFirstDayStart($schedules[1]->GetWeekdayStart());

	$this->calendarFactory->SetCalendarMonth($month);

	$details = new CalendarSubscriptionDetails(true);
	$this->subscriptionService->SetDetails($details);

	$this->presenter->PageLoad($this->fakeUser, $userTimezone);

	$actualReservations = $month->Reservations();

	$expectedReservations = CalendarReservation::FromScheduleReservationList($reservations,
																			 $resources,
																			 $this->fakeUser,
																			 $this->privacyFilter);

	$this->assertEquals($expectedReservations, $actualReservations);
	$this->assertEquals($month->FirstDay(), $this->repository->_SearchStart);
	$this->assertEquals($month->LastDay()->AddDays(1), $this->repository->_SearchEnd);
	$this->assertEquals($calendarType, $this->calendarFactory->_CalendarType);
	$this->assertEquals($requestedYear, $this->calendarFactory->_CreateYear);
	$this->assertEquals($requestedMonth, $this->calendarFactory->_CreateMonth);
	$this->assertEquals($requestedDay, $this->calendarFactory->_CreateDay);
	$this->assertEquals($userTimezone, $this->calendarFactory->_CreateTimezone);
	$this->assertEquals($month, $this->page->_BoundMonth);
	$this->assertEquals($details, $this->page->_BoundSubscription);
	$calendarFilters = new CalendarFilters($schedules, $resources, null, null, new ResourceGroupTree());
	$this->assertEquals($calendarFilters, $this->page->_BoundFlters);
	$this->assertEquals($this->subscriptionService, $this->subscriptionService->_ScheduleId);
}

This is still a huge test (that’s a problem for another post). Here the stub setup code gets cut down to about 15 lines. What I also love is that I don’t have expectations set in the mock specification. Any assertions around parameters have been moved down with the rest of the assertions. This is wonderful for a few reasons.

1 – This follows the Arrange-Act-Assert model that helps us in writing clean tests.
2 – Most of the time I don’t care about what parameters I pass to a method.
3 – Mocks will typically not return anything if you don’t pass the right value to a mocked-out function. When you pass the wrong value null is returned, causing a null reference exception in your code. This is very frustrating and difficult to trace, especially when you changed the parameters intentionally.

I don’t care which method is called (most of the time). Often times I don’t care about the data that we’re feeding to a collaborating object, either. I just want to test this specific object’s functionality and assume that everything else is tested elsewhere and works as it should.

The Stub Library

One of the biggest ancillary benefits I’ve found to hand writing my stubs is that I’ve built up a pretty solid library of reusable objects. I have stub objects ready to go for different pages, for reservations, data access and so on. I can pull in an existing stub and continue on with my test. I don’t need to set up the same stub expectation or response over and over. I don’t even have to think about how this collaborating object works. And if I apply an automated refactor to a method signature I don’t have to worry about breaking a ton of tests – the refactoring would apply to the stub object, as well.

Looking Forward

I’ve come full circle on stubs since my early days of TDD. I used to view them as a productivity killer, but my opinion now is that they actually save me time. Sure, there’s a little upfront investment, but the return on that investment is high. Who knows, maybe I’ll venture back into the land of mocks again one day. Until then, I’m happy with my well-tested, easy to maintain production code base.

Software Development is Expensive

This is a bit of a rant, so I apologize ahead of time.

Software development is a crazy blend of art, science and luck. I’ve compared it to painting in the past and I still think that’s one of the better comparisons out there. It is difficult to build a software application that solves a problem, addresses technical challenges, and is intuitive and simple to use.

It shouldn’t be a surprise that software development is expensive. And the higher the skill level of the developer, the more well-known the developer, or the more specialized the skill set, the more expensive it will be. Art follows a similar cost pattern. A Picasso is going to cost more than something by a local art student. Fair or not, that’s the world we live in.

Booked is free and open source and will continue to be. I choose to release it free of charge because I enjoy giving back to a community that has given me so much. I also do a fair amount of custom software development for Booked. This development is not free, but I make every attempt to charge a reasonable fee for my expertise and time.

In some ways open source has spoiled us. It can give the perception that software development is easy and cheap. Most software developers – open source or not – are highly skilled experts in their field.

If you have a custom table built by and expert carpenter it will cost more than the particle board table that you pull off the shelf at the local Ikea. If you reach out a developer for custom software development be prepared for it to be costly. After all, you’re getting a solution expertly crafted to solve your problem. I know I’ll pay a premium for that.

Are You Mentoring or Lecturing?

Great team leaders raise the skill level of people around them. There are so many ways to do this – team presentations, sharing articles, demonstrations, etc. Mentoring is one of the most personal and powerful ways of developing individuals on your teams. Unfortunately, this term gets tossed around freely without really understanding it.

To the Wikipedia!

Here’s what Wikipedia says:

Mentoring is a process for the informal transmission of knowledge, social capital, and the psychosocial support perceived by the recipient as relevant to work, career, or professional development; mentoring entails informal communication, usually face-to-face and during a sustained period of time, between a person who is perceived to have greater relevant knowledge, wisdom, or experience (the mentor) and a person who is perceived to have less (the protégé)”

Knowledge. Social Capital. Psychosocial Support. Mentoring is not just teaching. It’s not lecturing or demonstrating.

Let’s just be frank

You are not mentoring if you’re: criticizing, doing, judging, scolding, arguing. The goal is not to claim your throne as supreme master of knowledge and make others feel bad. The goal is not to make others do things “your way.”

As a mentor you should be asking questions and guiding others to answers. You’re building skills as well as the inherent desire to apply those skills. You should want this person to become a mentor themselves – to grow others on your team.

Ask yourself this

Are the individuals that you are mentoring only doing what you want because they are scared of you or want to avoid confrontation? If you left today, would the process or behavior cease? If you answered yes to either of these then you’re not mentoring.

Empower others

People want to be great. If you’re in a leadership position – and let’s be honest, we’re all leaders – make the time and emotional investments to help others be great. I guarantee you’ll also grow as part of the experience.

There’s a place for mentoring and there’s a place for lecturing or instructing. Be aware of which role you’re playing.

Update Jan 28 2015
Harvard Business Review has a great article with advice on how to avoid some common mentoring mistakes