Type-safe logging with custom string interpolation

Type-safe logging with custom string interpolation

In an effort to improve observability of Lighthouse, I updated the logging infrastructure and switched from console.log to pino. That led me down the rabbit hole of typing the logging functions.

I wanted to create a function that takes a message string and data object, where the message string can reference values in the data object, and TypeScript verifies that all referenced values are in the data object.

log.info("Something happened %time", { time: new Date() }); // OK
log.info("Something happened %time", { }); // Property 'time' is missing in type '{}'

It looks simple, but took quite a lot of tinkering to make it work.

With the typing of the log function I want to ensure that changing log lines will never result in missing data in those log lines. Because, writing new code is relatively easy, and most unintended changes (aka mistakes) happen while editing.

Logging with pino

Pino is a logging library for JavaScript. It supports structured logging and writes log lines as JSON. The message is included as msg property, and its log functions accept an additional data parameter, which is merged into the logged JSON object.

It also supports string interpolation.

The signature is

logger.info([mergingObject], [message], [...interpolationValues])

This is an example with string interpolation:

logger.info({ property: "value" }, "hello %s", "world");
// {"property": "value","level":30,"time":1531257826880,"msg":"hello world","pid":55956,"hostname":"x"}

%s is replaced by "world" in the final msg property.

Motivation

I want the interpolated data also in the data object, not only in the message. Having to pass it twice, once in the data object and once for string interpolation seems like unnecessary effort.

logger.info("Something happened %time", { time: new Date() });

is cleaner than

logger.info({ time: new Date() }, "Something happened %s", new Date());

Implementation

The first step is to implement that behavior. Typing comes later.

It’s possible to pass a custom formatter to pino. This formatter receives the data object and can manipulate it. There it’s possible to replace the value references (e.g. %time) with the actual values.

const logger = pino({
  formatters: {
    // Make it possible to interpolate provided data into the log message
    log(data) {
      const message = data.msg as string;
      if (message == null) return data;

      const resultMessage = message.replace(/%(\w+)/g, (_, key) => {
        const value = data.hasOwnProperty(key) ? data[key] : `%${key}`;
        if (typeof value === "string") return value;
        if (value instanceof Date) return value.toISOString();
        if (value instanceof Error) return value.message;
        return JSON.stringify(value);
      });
      return {
        ...data,
        msg: resultMessage,
      };
    },
  },
});

This function implements custom formatting for Date and Error objects, the rest is converted to JSON strings.

The logger is used in a separate log function

function info(message: string, data?: Record<string, any>) {
  logger.info({ ...data, msg: message });
}

The log formatter function doesn’t receive the message text, but since it’s included in the resulting object as msg property, it’s possible to work around that by merging the message into the object directly.

Typing

The info function has message and data as parameters, but doesn’t yet verify that values referenced in message (e.g. %time) are part of the data parameter.

To reiterate, the goal is to type the log functions so that referencing a value which doesn’t exist in the data object leads to a TypeScript error.

log.info("Something happened %time", { time: new Date() }); // OK
log.info("Something happened %time", { }); // Property 'time' is missing in type '{}'

Solution

The full solution adds 5 helper types and changes the types of the info function:

type IsOnlyAlphabet<T extends string> = T extends `${infer F}${infer R}`
  ? Uppercase<F> extends Lowercase<F>
    ? false
    : IsOnlyAlphabet<R>
  : true;

type OnlyAlphabet<T extends string> = T extends string
  ? IsOnlyAlphabet<T> extends true
    ? T
    : never
  : never;

type ExtractPlaceholdersRaw<S extends string> = S extends
  | `${string}%${infer Key}${" " | "," | "."}${infer Rest}`
  | `${string}%${infer Key}`
  ? Key | ExtractPlaceholdersRaw<Rest>
  : never;

type ExtractPlaceholders<S extends string> = OnlyAlphabet<ExtractPlaceholdersRaw<S>>;

type PlaceholdersPresent<S extends string, P extends Record<string, any>> = {
  [K in ExtractPlaceholders<S>]: any;
} & P;

function info<S extends string, P extends Record<string, any>>(message: S, data?: PlaceholdersPresent<S, P>) {
  logger.info({ ...data, msg: message });
}

Explanation

The solution works in 2 steps

  1. Extract all words prefixed with % into a string union
  2. Ensure that the data parameter contains all strings of that union as key

IsOnlyAlphabet, OnlyAlphabet, ExtractPlaceholdersRaw, and ExtractPlaceholders are relevant for step 1.

PlaceholdersPresent is for step 2.

Extracting keys

ExtractPlaceholdersRaw is a recursive type that converts a string into a union of strings which includes every substring prefixed by a % sign.

type T1 = ExtractPlaceholdersRaw<"This %is a %test and %more">
// type T1 = "is" | "is a %test and %more" | "test" | "test and %more" | "more"

The most important part is the condition:

S extends
  | `${string}%${infer Key}${" " | "," | "."}${infer Rest}`
  | `${string}%${infer Key}`

If it matches, it extracts Key and recursively unions it with other keys extracted from Rest. If it doesn’t match, it returns the type never.

? ExtractPlaceholdersRaw<Rest>
: Key | ExtractPlaceholdersRaw<Rest>

The condition itself is a union. The first part of the union makes sure that Key is separated by a delimiter, in this case either a space (`” “`), colon (`,`), or dot (`.`). If the delimiter wasn’t there, then Key would only match one letter, and the result would be "t" instead of "test" for example.

The second part of the union ensures that interpolated values are extracted even if they are at the end of the string. In the example above that’d be "more".

The remaining problem is that the second part of the union also extracts "is a %test and %more" and "test and %more", because it matches any string that starts with %.

This is where the OnlyAlphabet type is relevant.

Checking if a key contains only letters

The type IsOnlyAlphabet converts a string type into true if it only contains letters, or false otherwise.

type IsOnlyAlphabet<T extends string> = T extends `${infer F}${infer R}`
  ? Uppercase<F> extends Lowercase<F>
    ? false
    : IsOnlyAlphabet<R>
  : true;

It’s also a recursive type, and extracts every character for the given string.

T extends `${infer F}${infer R}`

The condition works similar to the one of ExtractPlaceholdersRaw. It extracts the first letter into F, and the rest into R.

Uppercase<F> extends Lowercase<F>, checks if the character is the same as uppercase and lowercase. If that’s the case, it cannot be a letter.

Some letters in languages other than English are the same in upper- and lowercase, but in code that’s usually not an issue.

The result is

type A1 = IsOnlyAlphabet<"abcd">;
// type A1 = true
type A2 = IsOnlyAlphabet<"1234">;
// type A2 = false

Filtering a union of strings

As explained above, ExtractPlaceholdersRaw creates a union of strings which includes undesired values. They should be filtered to include only values that are letters-only.

"is" | "is a %test and %more" | "test" | "test and %more" | "more" should become "is" | "test" | "more".

This is what the OnlyAlphabet type does.

type OnlyAlphabet<T extends string> = T extends string
  ? IsOnlyAlphabet<T> extends true
    ? T
    : never
  : never;

It checks every part of the union, if IsOnlyAlphabet<T> is true. If so, it returns the string type, if not, returns never.

To understand how this type works it’s important to know that generic types expand unions. They are applied for every type of the union separately.

Applying it to the example above replaces "is a %test and %more" and "test and %more" with never.

OnlyAlphabet<"is" | "is a %test and %more" | "test" | "test and %more" | "more">
// "is" | never | "test" | never | "more"

The result is shortened to "is" | "test" | "more".

Combining it all

The type ExtractPlaceholders combines ExtractPlaceholdersRaw with OnlyAlphabet to only extract the keys we want.

type ExtractPlaceholders<S extends string> = OnlyAlphabet<ExtractPlaceholdersRaw<S>>;

ExtractPlaceholdersRaw extracts the list of keys, including some undesired keys, and OnlyAlphabet filters out the undesired keys to leave a clean list.

Ensuring the keys are present in the data parameter

The data parameter must have values corresponding to the keys from the message string, and it should be possible to add additional keys.

type PlaceholdersPresent<S extends string, P extends Record<string, any>> = {
  [K in ExtractPlaceholders<S>]: any;
} & P;

function info<S extends string, P extends Record<string, any>>(message: S, data?: PlaceholdersPresent<S, P>) {
  logger.info({ ...data, msg: message });
}

PlaceholdersPresent gets a string and record type as generic parameters. It creates one type with the extracted keys ([K in ExtractPlaceholders<S>\]: any;), and combines that with the record type.

To stick with the example from before, the resulting type would be

{
  is: any;
  test: any;
  more: any;
} & P

The result is that if a data parameter is passed to the info function, it must have values for is, test, and more properties.

A slight caveat is that, with the current function definition, the data parameter is optional. Consequently, if no data parameter is provided, TypeScript doesn’t show errors even if there are some mandatory keys.

info("This %is a %test and %more"); // No error
info("This %is a %test and %more", {}); // Type '{}' is missing the following properties from type '{ is: any; test: any; more: any; }': is, test, more

This can be solved with more conditional type magic, but it’s already complicated enough. I left it as a future improvement.

Final words

This must be one of the most complicated types I ever created. Even though this article only explains the final solution, it took many experiments and detours to finally get there.

I hope it helps others achieve the same.