Logging with Decorators in TypeScript

Avoid tangled code by encapsulating cross-cutting concerns.

Image by snd63 from Pixabay

As codebases grow, so does the complex web of dependencies and concerns that individual modules rely on. Managing these can cause us headaches — even in the most well engineered applications.

Logging is a prime example of one such concern. We may have a logging functionality in one module, that is used across the application — cross-cutting it.

Consider the following example:

Two classes with an injected Logger dependency

On the face of it, there isn’t too much wrong here. We’re injecting implementations of Logger (which happens to be an interface, we’ll see it shortly) so that’s a tick in the SOLID box.

There are some improvements we can make though. The Logger is a cross-cutting concern. It weaves its way through our application like ivy. Yes, we’re injecting it but consider the maintenance burden. If the log method’s signature changes that is an awful lot of refactoring that needs to be handled.

Decorators to the Rescue

If you use Angular you’ll already be very familiar with decorators in TypeScript but if not, don’t worry — this article presumes exactly zero knowledge. So, we’ll start at the beginning.

A decorator “decorates” a class or method and provides some extra functionality at initialisation time, i.e. when a class is instantiated. In this example we’re going to implement a decorator that logs a message whenever a method is invoked, so that we can remove the injected Logger dependencies and calls to log.

In TypeScript decorators look like this:

@decorator()
public class Foo { ... }

Ok, before we dive into writing a decorator let’s do some setup. We’re going to need some logging functionality. This will be handled by two classes, ConsoleLogger and LoggerFactory and an interface Logger. Let’s take a look at them:

Logger Interface

The Logger interface has a single method, log, which takes a string. Simple.

ConsoleLogger class

The ConsoleLogger class implements the Logger interface and, well, logs a message to the console (this is a very simple example, after all).

LoggerFactory

The LoggerFactory is responsible for creating and returning a single instance of the ConsoleLogger. If you’re familiar with the singleton pattern, then you’ll recognise this. If not - this is a quick, crude, example of implementing the singleton pattern.

Right — that’s the setup done. We’ve got a means of logging to the console. Now let’s look at implementing a decorator.

If you’re thinking that this kind of meta-programming is going to be complex, think again. TypeScript makes it really quite simple to implement some powerful functionality.

A simple decorator

Ok, let’s step through this. Some of it is obvious but some requires a little explanation.

On line 3 we’re using the LoggerFactory to get an instance of Logger that we’ll be using to write messages to the console. So far, so straightforward.

The fun starts on line 5.

We’re creating a function that returns a function. The “outer” function, the one declared on line 5, is actually the decorator factory. This is a function which creates, and returns, the actual decorator. We can use a decorator factory to customise how a decorator is applied, but in this example we’re just returning the decorator.

So, the decorator itself. This is the function on lines 6, 7 and 8. As you can see all it does is call the log method. This type of decorator is a method decorator. It should only be applied to a class’s methods.

You can see that there are three arguments - target, propertyKey and descriptor. Let’s define what these are:

• target: The class that the member is part of
• propertyKey: The name of the member
• descriptor: This is, essentially, the object that you would pass to Object.defineProperty if you we’re writing this class in JavaScript

OK — that’s our decorator up and running. Let’s implement it in the Counter class we saw right at the start of the article.

A simple node app’s index.ts file

The code above is the entry point for a very simple node app. It creates a new instance of Counter and does a loop, and in each iteration it prints the current count and then increments.

On lines 7 and 12 we’ve implemented the simpleLog (remember the @ syntax for a decorator). We’ve also been able to remove the injected logger from the class (yay, no cross-cutting concerns) and the hard-coded calls to log from each of the methods.

This will perform the same as before, logging that we’re calling each method on each iteration.

Right?

Let’s look at the output…

❯ node index
Calling currentCount
Calling incrementCount
0
1
2
3
4
5
6
7
8
9

Hmm…

Well the correct method names have been logged, so that’s a start — but we’re not getting anything logged from the decorators on each iteration.

Remember at the start of the article we learned that decorators are called at instatiation time and not when their decorated methods are called. That’s what we’re seeing here. An instance of Counter is being instatiated so the decorator is called.

So, how can we replicate the functionality we had originally.

Let’s create a slightly more useful decorator…

A second decorator, this time a little more useful

So similar to before, we’re using a decorator factory which returns a function and the arguments target, propertyKey and descriptor are the same. The difference is in the guts of the decorator function itself.

On line 3 we’re creating a copy of the descriptor’s value property. This is the decorated method that will actually be executed.

We then set descriptor.value to a new function, one which wraps the original. You can see this on lines 5 to 8. On line 6 we call log and on line 7 we call the copy of the original method and return the result.

Let’s implement this in index.ts and see what the output looks like.

Refactored entry point using usefulLog

The only change is to use our new usefulLog decorator.

And the output…

Calling currentCount
0
Calling incrementCount
Calling currentCount
1
Calling incrementCount
Calling currentCount
2
Calling incrementCount
Calling currentCount
3
Calling incrementCount
Calling currentCount
4
Calling incrementCount
Calling currentCount
5
Calling incrementCount
Calling currentCount
6
Calling incrementCount
Calling currentCount
7
Calling incrementCount
Calling currentCount
8
Calling incrementCount
Calling currentCount
9
Calling incrementCount

Much better!

Conclusion

We’ve seen how we can implement a simple decorator to log whenever a method is called and how this helps to alleviate cross-cutting concerns. If we ever needed to change the method signature of log we would only need to refactor one place — the decorator.

This was, of course, a very simple example but it has hopefully given you an insight into what decorators are and how they work.

As of right now (June 2020) decorators in JavaScript, and therefore TypeScript, are still experimental. Their final implementation in JS hasn’t been formally agreed. Personally I’m happy using the in TypeScript — where the compiler does an awesome job of abstracting experimental features away — but I’m less happy using them in un-transpiled JavaScript applications.

That being said this is very powerful functionality available to us, familiar to those from the C# or Java worlds, and can really help solve some problems (such as cross-cutting concerns).