[Illniyar]

While I agree with some of it, I feel like there's a big gotcha here that isn't addressed. Having 1 single wide event, at the end of a request, means that if something unexpected happens in the middle (stack overflow, some bug that throws an error that bypasses your logging system, lambda times out etc...) you don't get any visibility into what happens.

You also most likely lose out on a lot of logging frameworks your language has that your dependencies might use.

I would say this is a good layer to put on top of your regular logs. Make sure you have a request/session wide id and aggregate all those in your clickhouse or whatever into a single "log".

[wesammikhail]

The way I have solved for this in my own framework in PHP is by having a Logging class with the following interface

  interface LoggerInterface {

    // calls $this->system(LEVEL_ERROR, ...);

    public function exception(Throwable $e): void;

    // Typical system logs

    public function system(string $level, string $message, ?string $category = null, mixed ...$extra): void;

    // User specific logs that can be seen in the user's "my history" 

    public function log(string $event, int|string|null $user_id = null, ?string $category = null, ?string $message = null, mixed ...$extra): void;
  }

I also have a global exception handler that is registered at application bootstrap time that takes any exception that happens at runtime and runs $logger->exception($e);

There is obviously a tiny bit more of boilerplating to this to ensure reliability, but it works so well that I can't live without it anymore. The logs are then inserted into a wide DB table with all the field one could ever want to examine thanks to the variadic parameter.

[hu3]

Nice. I guess you write logs on the "final" block of a global try/catch/final?

Something like:

  try {
    // handle request code
  } catch (...) {
    // add exceptions to log
  } final {
    // insert logs into DB
  }

[wesammikhail]

I used to do it like that and it worked really well but I changed the flow to where exceptions are actually part of the control flow of the app using PHP's set_exception_handler(), set_error_handler() and register_shutdown_function().

Example, lets say a user forgot to provide a password when authenticating, then I will throw a ClientSideException(400, "need password yada yada");

That exception will bubble up to the exception_handler that logs and outputs the proper message to the screen. Similarly if ANY exception is thrown, regardless of where it originated, the same will happen.

When you embrace exceptions as control flow rather than try to avoid them, suddenly everything gets 10x easier and I end up writing much less code overall.

[hu3]

I love Exceptions as control flow! Thanks for the suggestion.

I too use specialized exceptions. Some have friendly messages that can be displayed to the user, like "Please fill the password". But critical exceptions display a generic error to the user ("Ops, sorry something went wrong on our side...") but log specifics to devs, like database connection errors, for example.

[hansvm]

If that's an issue (visibility into middle layers) it just means your events aren't wide enough. There's no fundamental difference between log.error(data) and wide_event.attach(error, data), nor similar schemes using parameters rather that context/global-based state.

There are still use cases for one or the other strategy, but I'm not a fan of this explanation in either direction.

[yallpendantools]

> If that's an issue (visibility into middle layers) it just means your events aren't wide enough.

I hate this kind of No-True-Scotsman handwaves for how a certain approach is supposed to solve my problems. "If brute-force search is not solving all your problems, it just means your EC2 servers are not beefy enough."

I gotta admit, I don't quite "get" TFA's point and the one issue that jumped out at me while reading it and your comment is that sooner than later your wide events just become fat, supposedly-still-human-readable JSON dumps.

I think a machine-parseable log-line format is still better than wide events, each line hopefully correlated with a request id though in practice I find that user id + time correlation isn't that bad either.

>> [TFA] Wide Event: A single, context-rich log event emitted per request per service. Instead of 13 log lines for one request, you emit 1 line with 50+ fields containing everything you might need to debug.

I am not convinced this is supposed to help the poor soul who has to debug an incident at 2AM. Take for example a function that has to watch out for a special kind of user (`isUserFoo`) where "special kind" is defined as a metric on five user attributes. I.e.,

    lambda isUserFoo(u): u.isA && (u.isB || u.isC) && (u.isD || u.isE)

With usual logging I might find

    <timestamp> : <function> : {"level": "INFO", "requestID": "xxxaaa", "msg": "user is foo"}

Which immediately tells me that foo-ness is something I might want to pay attention to in this context.

With wide events, as I understand it, either you log the user in the wide event dump with attributes A to E (and potentially more!) or coalesce these into a boolean field `isUserFoo`. None of which tells me that foo-ness might be something that might be relevant in this context.

Multiply that with all the possible special-cases any logging unit might have to deal with. There's bar-ness which is also dependent on attributes A-E but with different logical connectives. There's baz-ness which is `isUserFoo(u) XOR (217828 < u.zCount < 3141592)`. The wide event is soooo context-rich I'm drowning.

[hansvm]

Your objection, as I understand it, is some combination of "no true Scotsman" combined with complaints about wide events themselves.

To the first point (no true Scotsman), I really don't think that applies in the slightest. The post I'm replying to said (paraphrasing) that middle-layer observability is hard with wide events and easy with logs. My counter is that the objection has nothing to do with wide events vs logs, since in both scenarios you can choose to include or omit more information with the same syntactic (and similar runtime overhead) ease. I think that's qualitatively different from other NTS arguments like TDD, in that their complaint is "I don't have enough information if I don't send it somewhere" and my objection is just "have you tried sending it somewhere?" There isn't an infinite stream of counter-arguments about holding the tool wrong; there's the very dumbest suggestion a rubber duck might possibly provide about their particular complaint, which is fully and easily compatible with wide events in every incarnation I've seen.

To the second point (wide events aren't especially useful and/or suck), I think a proper argument for them is a bit more nuanced (and I agree that they aren't a panacea and aren't without their drawbacks). I'll devote the rest of my (hopefully brief) comment to this idea.

1. Your counter-example falls prey to the same flaw as the post I responded to. If you want information then just send that information somewhere. Wide events don't stop you from gathering data you care about. If you need a requestID then it likely exists in the event already. If you need a message then _hopefully_ that's reasonably encoded in your choice of sub-field, and if it's not then you're free to tack on that sort of metadata as well.

2. Your next objection is about the wide event being so context-rich as to be a problem in its own right. I'm sympathetic to that issue, but normal logging doesn't avoid it. It takes exactly one production issue where you can't tie together related events (or else can tie them together but only via hacks which sometimes merge unrelated events with similar strings) for you to realize that completely disjoint log lines aren't exactly a safe fallback. If you have so much context-dependent complexity that a wide event is hard to interpret then linear logs are going to be a pain in the ass as well.

Mildly addressing the _actual_ pros and cons: Logs and wide events are both capapable of transmitting the same information. One reasonable frame of reference is viewing wide events as "pre-joined" with a side helping of compiler enforcement of the structure.

It's trivially possible to produce two log lines in unrelated parts of a code base which no possible parser can disambiguate. That's not (usually) possible when you have some data specification (your wide event) mediating the madness.

It's sometimes possible with normal logs to join on things which matter (as in your requestID example), but it's always possible with wide events since the relevant joins are executed by construction (also substantially more cheaply than a post-hoc join). Moreover, when you have to sub-sample, wide events give an easy strategy for ensuring your joins work (you sub-sample at a wide event level rather than a log-line level) -- it's not required; I've worked on systems with a "log seed" or whatever which manage that joinability in the face of sub-sampling, but it's more likely to "just work" with wide events.

The real argument in favor of wide events, IMO, is that it encourages returning information a caller is likely to care about at every level of the stack. You don't just get potentially slightly better logs; you're able to leverage the information in better tests and other hooks into the system in question. Parsing logs for every little one-off task sucks, and systems designed to be treated that way tend to suck and be nearly impossible to modify as desired if you actually have to interact with "logs" programatically.

It's still just one design choice in a sea of other tradeoffs (and one I'm only half-heartledly pursuing at $WORK since we definitely have some constraints which are solved by neither wide events nor traditional logging), BUT:

1. My argument against some random person's choice of counter-argument is perfectly sound. Nothing they said depended on wide events in the slightest, which was my core complaint, and I'm very mildly offended that anyone capable of writing something as otherwise sane and structured as your response would think otherwise.

2. Wide events do have a purpose, and your response doesn't seem to recognize that point in the design space. TFA wasn't the most enjoyable thing I've ever read, but I don't think the core ideas were that opaque, and I don't think a moment's consideration of carry-on implications would be out of the question either. I could be very wrong about the requisite background to understand the article or something, but I'm surprised to see responses of any nature which engage with irrelevant minutea rather than the subset of core benefits TFA chose to highlight (and I'm even more surprised to see anything in favor of or against wide events given my stated position that I care more about the faulty argument against them than whether they're good or bad)..

[cpill]

I wonder if one might solve this by using an accumulator that merges objects as they are emitted based on some ID (i.e. request ID say) and then ether emits the object on normal execution or a global exception handler emits it on error...?

[runeks]

I was going to say that. That definitely would be a solution (and ought to be the way it works).

[pastage]

Having logs in the format "connection X:Y accepted at Z ns for http request XXX" and then a "connection X:Y closed at Z ns for http response XXX" is rather nice when debugging issues on slow systems.