serializeMessage should support format characters

[tripodsan]

serializeMessage should support string format characters, similar to console.log:

example:

info('creating %d tasks for %s', 42, 'test');

---

as a consequence, I think the messageFormatJson should be smart about how many parameters it consumes from the arguments during serializing the mesage, eg:

info('creating %d tasks for %s', 42, 'test', { 'taskId': 33));

would generate:

{
  message: 'creating 42 tasks for test',
  taskId: 33,
}

[koraa]

Hmmm. Even though I know quite a few people prefer the string interpolation notation, I never could understand why; guess it's a matter of taste (and you can't argue about that).

As for helix log, I decided at the very beginning, that supporting that style of string interpolation for the basic interface was a non-goal; there where a couple of reasons for this:

1. The fact this notation contains redundant type information (%d, %s – this could be remedied as has been done lot's of times by using '{}' as the replaceable character for any type)
2. The weirdness of mixing positional and interpolated parameters as I have often seen in helix log
3. The added weirdness in conjunction with the json data logging feature
4. The existence of two other string interpolation methods (positional + ${...})
5. Providing an interface familiar to the most devs by choosing one that is so similar to console.log
6. This style is only supported by bunyan and not winston (which I found more usages of in helix)

I mean, look at the weirdness of the following logging statement in bunyan:

> l.info("Hello World %o %d", "asd", "xxx", {})
{"name":"fnord","hostname":"castle","pid":1387770,"level":30,"msg":"Hello World 'asd' NaN {}","time":"2019-09-19T13:50:16.148Z","v":0}

In the end though it was my personal distaste for the interface that affected the decision the most and I guess it's bad style to expect other people to abide by my tastes; so, I suggest we create a StringInterpolationInterface (maybe with a much improved name) that features the usual logging functions and performs string interpolation before handing of the message to the rootLogger or any other logger (in a similar style as the Bunyan2HelixLog class).

If the feature turns out to be popular or if we find such an adapter to be too cumbersome I would also be open to an require('@adobe/helix-log/interpol') file that offers string interpolation for free functions; but I suspect you will prefer an adapter-object anyways.

[tripodsan]

2. The weirdness of mixing positional and interpolated parameters as I have often seen in helix log

true...

5. Providing an interface familiar to the most devs by choosing one that is so similar to console.log

well, console.log indeed supports string interpolation; otherwise it would not suggest it:

$ node -e "console.log('Hello %s. My Object is %j', 'world', { foo: 42 });"
Hello world. My Object is {"foo":42}

in the end, I would just rely on https://nodejs.org/api/util.html#util_util_format_format_args.
and either count the % and feed as many args into util.format as needed, or just use the lst object argument as log-data.

---

We could go with a special interface for this, but I don't see a benefit of not having string interpolation.

[koraa]

Jesus, you're right.
Urghs.
Let's think about this for a bit; my first idea is to implement this as part of logWithOpts so we don't taint the internal message format…

[koraa]

Do you want to take this and add it to logWithOpts?

[tripodsan]

it would be nice if you can take care of this...especially if you plan to refactor code for the data-logging.... :-)

[koraa]

I've looked at how hard implementing this (while preserving helix-log features such as exception-safety) would be, and unfortunately the answer is: Quite hard.

util.format is not really exception safe (I found ways to trigger exceptions on %j, %o, %O, %f, so we would have to implement formatting ourselves; probably by performing appropriate casting (e.g. jsonifyForLog for %j, Number(...) for %i and %f but in an exception safe way) and then reinjecting these values at the right position in the message field.

It can be done, but honestly I would not like to see in the core interface of helix-log. Since we now have the Interface concept, feel free to provide a BunyanLikeInterface and/or ConsoleLikeInterface.