It's rare to see good test coverage of instrumentation logic. I don't often see automated tests that verify that an error is logged if an operation fails, or that an analytics event containing the correct fields is published when a conversion occurs. This is perhaps partially due to observability historically being regarded as less valuable, but it's also because it's a pain to write good tests for low-level instrumentation code.

Testing Instrumentation Code Is a Pain

To demonstrate, let's look at some instrumentation for a different part of our hypothetical e-commerce system and see how we might write some tests that verify the correctness of that instrumentation code.

ShoppingCart has an addToCart method, which is currently instrumented with direct calls to various observability systems (rather than using a Domain Probe):

class ShoppingCart…

addToCart(productId){ this.logger.log(`adding product '${productId}' to cart '${this.id}'`); const product = this.productService.lookupProduct(productId); this.products.push(product); this.recalculateTotals(); this.analytics.track( 'Product Added To Cart', {sku: product.sku} ); this.metrics.gauge( 'shopping-cart-total', this.totalPrice ); this.metrics.gauge( 'shopping-cart-size', this.products.length ); }

Let's look at how we might begin to test this instrumentation logic:

shoppingCart.test.js

const sinon = require('sinon'); describe('addToCart', () => { // ... it('logs that a product is being added to the cart', () => { const spyLogger = { log: sinon.spy() }; const shoppingCart = testableShoppingCart({ logger:spyLogger }); shoppingCart.addToCart('the-product-id'); expect(spyLogger.log) .calledWith(`adding product 'the-product-id' to cart '${shoppingCart.id}'`); }); });

In this test, we're setting up a shopping cart for test, wired up with a spy logger (a "spy" is a type of test double used to verify how our test subject is interacting with other objects). In case you're wondering, testableShoppingCart is just a little helper function that creates an instance of ShoppingCart with faked-out dependencies by default. With our spy in place, we call shoppingCart.addToCart(...) and then check that the shopping cart used the logger to log an appropriate message.

As written, this test does provide reasonable assurance that we are logging when products are added to a cart. However, it is very much coupled to the details of that logging. If we decided to change the format of the log message at some point in the future, we'd break this test for no good reason. This test shouldn't be concerned with the exact details of what was logged, just that something was logged with the correct contextual data.

We could try to reduce how tightly the test is coupled to the details of the log message format by matching against a regular expression (regex) instead of an exact string. However, this would make the validation a little opaque. Additionally, the effort required to craft a robust regex is usually a poor investment of time.

Moreover, this was just a simple example of testing how things are logged. More complex scenarios (e.g., logging exceptions) are even more of a pain—the APIs of logging frameworks and their ilk don't lend themselves to easy verification when they're being mocked out.

Let's move on and take a look at another test, this time verifying our analytics integration:

shoppingCart.test.js

const sinon = require('sinon'); describe('addToCart', () => { // ... it('publishes analytics event', () => { const theProduct = genericProduct(); const stubProductService = productServiceWhichAlwaysReturns(theProduct); ➋ const spyAnalytics = { track: sinon.spy() }; const shoppingCart = testableShoppingCart({ productService: stubProductService, ➊ analytics: spyAnalytics ➌ }); shoppingCart.addToCart('some-product-id'); expect(spyAnalytics.track).calledWith( ➍ 'Product Added To Cart', {sku: theProduct.sku} ); }); });

This test is a little more involved because we need to control the product that is passed back to the shopping cart from productService.lookupProduct(...) , which means that we need to inject a stub product service ① that is rigged to always return a specific product ② . We also inject a spy analytics ③ , just as we injected a spy logger in our previous test. After that's all set up, we call shoppingCart.addToCart(...) and then, finally, verify ④ that our analytics instrumentation was asked to create an event with the expected parameters.

I'm reasonably happy with this test. It's a bit of a pain to get that product sent into the cart as indirect input, but that's an acceptable trade-off in exchange for gaining confidence that we include that product's SKU in our analytics event. It's also a bit of a shame that our test is coupled to the exact format of that event: as with our logging test above, I'd prefer that this test didn't care about the details of how observability is achieved, just that it's being done using the correct data.