=multiplex #139 more properly handle logLevel in multiplex handler #140

ktoso · 2020-06-27T09:18:07Z

Motivation:

Log level handling is a bit too naive in the multiplex handler when underlying loggers have varying levels.

Modifications:

effective log level has to be the lowest of all passed in handlers / same on level modification
when dispatching, the multiplex handler has to filter again based on the specific handler.

Result:

resolves Issue setting different levels on log handlers in a MultiplexLogHandler #139

Tests/LoggingTests/LoggingTest.swift

ktoso · 2020-06-29T14:09:55Z

Tests/LoggingTests/LoggingTest.swift

+        logging2.history.assertExist(level: .debug, message: "debug")
+        logging2.history.assertExist(level: .info, message: "info")
+        logging2.history.assertExist(level: .warning, message: "warning")
+    }


this test explains the feature

Sources/Logging/Logging.swift

ktoso · 2020-06-30T01:15:38Z

I now realized the current behavior is documented:

/// The first `LogHandler` passed to the initialisation function of `MultiplexLogHandler` control the `logLevel` as
/// well as the `metadata` for this `LogHandler`. Any subsequent `LogHandler`s used to initialise a
/// `MultiplexLogHandler` are merely to emit the log message to another place.

but it's admittably a bit weird... not sure what to do here tbh.

The current behavior has some upsides (detailed control) but it is somewhat unexpected as witnessed by #139 as well as my going down this rabbit hole.

Do we have opinions what do do here @glbrntt @Lukasa (optionally, only if you have time and want to chime in @weissi) @tomerd ?

tomerd · 2020-06-30T01:28:56Z

Do we have opinions what do do here @glbrntt @Lukasa (optionally, only if you have time and want to chime in @weissi) @tomerd ?

for the log level, I think the semantics proposed by this PR is an improvement, but it does make the metadata story more murky since its still pinned to handler[0]

Lukasa · 2020-06-30T06:47:39Z

Yeah, I think this behavioural change needs to happen. The logical semantics of MultiplexLogHandler, in my mind, would be that its effective log level is the lowest of all log handlers it wraps, and that it only dispatches the messages to log handlers whose actual log level is lower than that of the message. This makes it maximally useful.

ktoso · 2020-06-30T07:12:41Z

The logical semantics of MultiplexLogHandler, in my mind, would be that its effective log level is the lowest of all log handlers it wraps, and that it only dispatches the messages to log handlers whose actual log level is lower than that of the message.

Cool, very much agreed, that's what the current PR brings it to 👍

I'll sanity check the metadata handling again here soon; I guess the semantics could be:

do not just expose any of the underlying ones
when set, set onto all underlying ones

or something like that; rather than the [0] based one

glbrntt · 2020-06-30T07:48:32Z

I agree with what's been said above: the current behaviour is weird; this change introduces the behaviour I would have expected.

ktoso · 2020-07-05T14:13:42Z

Sources/Logging/Logging.swift

+/// If the log level is _set_ on a `Logger` backed by an `MultiplexLogHandler` the log level will apply to *all*
+/// underlying log handlers. Allowing a logger to still select at what level it wants to log, regardless if the underlying
+/// handler is a multiplex or a normal one. If for some reason one might want to not allow changing a log level of a specific
+/// handled passed into the multiplex log handler, this is possible by wrapping it in a handler which ignores any log level changes.


docs and examples on how the log level works

ktoso · 2020-07-05T14:13:51Z

Sources/Logging/Logging.swift

+/// A query through the multiplex log handler the key `one` naturally returns `handler1`'s value, and a query for `two`
+/// naturally returns `handler2`'s value. Querying for the key `all` will return `handler1`'s value, as that handler was indicated
+/// "more important" than the second handler. The same rule applies when querying for the `metadata` property of the
+/// multiplex log handler - it constructs `Metadata` uniquing values


docs and examples how metadata works

I actually had a "smart and configurable" EffectiveMetadataMode based impl but I stepped back from it for a few hours to re-think and it was getting too complex IMO for what it is -- realistically this is not a "big problem that needs fancy solving" -- normally users just care about setting metadata on things and maybe some handlers have something specific to them, the conflicting cases should be rare and this simple rule is better than slamming more complexity into it.

// I even had an impl which would "collect all values if the same key is present in a few handlers into a logger metadata value Array etc... Way too fancy for what we're looking at I then realized.

ktoso · 2020-07-05T14:16:26Z

Sources/Logging/Logging.swift


    /// Create a `MultiplexLogHandler`.
    ///
    /// - parameters:
    ///    - handlers: An array of `LogHandler`s, each of which will receive the log messages sent to this `Logger`.
    ///                The array must not be empty.
    public init(_ handlers: [LogHandler]) {
-        assert(!handlers.isEmpty)
+        assert(!handlers.isEmpty, "MultiplexLogHandler.handlers MUST NOT be empty")


explicit messages always better IMO

ktoso · 2020-07-05T14:16:52Z

Sources/Logging/Logging.swift

        self.handlers = handlers
-        self.effectiveLogLevel = MultiplexLogHandler.effectiveLogLevel(handlers.map { $0.logLevel })
+        self.effectiveLogLevel = handlers.map({ $0.logLevel }).min() ?? .trace


the ?? will never trigger but it's semantically "aha makes sense, we take the lowest" so I prefer that to writing ! here

ktoso · 2020-07-05T14:22:40Z

Sources/Logging/Logging.swift

+            effectiveMetadata.reserveCapacity(self.handlers.first!.metadata.count) // !-safe, we always have at least one handler
+            return self.handlers.reduce(into: effectiveMetadata) { effectiveMetadata, handler in
+                effectiveMetadata.merge(handler.metadata, uniquingKeysWith: { l, _ in l })
+            }


We pick the "left" over any following ones "first handlers in the list are more important"

ktoso · 2020-07-05T14:23:00Z

Sources/Logging/Logging.swift

+                    return value
+                }
+            }
+            return nil


Again, implements the "first is most important"

ktoso · 2020-07-05T14:26:49Z

I poked at the metadata quite a bit over the weekend and think I've arrived at what is a good tradeoff here.

The metadata handling change is: cdb4869

And please see the comments in-line. Short version though: we should not magically rely on the first handler, but we should prefer more-first passed in handler metadata values over latter ones. This is simple to explain and implement without some crazy things (I had some advanced implementations with merge strategies and whatnot, but they ended up feeling wrong in their own ways, so I believe a simple rule like this (see added docs) is a good tradeoff, esp since we should not expect to be hitting this in reality much -- it is the underlying handlers doing their job, and barely anyone should be reading from the logger metadata to "just have a look at it" after all).

…write

tomerd

lgtm

Lukasa

One little grammar nit in a doc comment, otherwise this is a good change.

Sources/Logging/Logging.swift

glbrntt

Looks good aside from a couple of typos.

Sources/Logging/Logging.swift

Co-authored-by: Cory Benfield <[email protected]> Co-authored-by: George Barnett <[email protected]>

ktoso · 2020-07-06T09:08:30Z

Thanks for the review and cleanups folks 👍

ktoso marked this pull request as draft June 27, 2020 09:18

ktoso requested a review from tomerd June 29, 2020 13:09

ktoso added this to the 1.3.0 milestone Jun 29, 2020

ktoso force-pushed the wip-loglevel-handling-multiplex branch from e56b909 to e26592e Compare June 29, 2020 14:05

ktoso removed this from the 1.3.0 milestone Jun 29, 2020

ktoso force-pushed the wip-loglevel-handling-multiplex branch 2 times, most recently from 2a7153a to af24c58 Compare June 29, 2020 14:08

ktoso commented Jun 29, 2020

View reviewed changes

Tests/LoggingTests/LoggingTest.swift Show resolved Hide resolved

ktoso commented Jun 29, 2020

View reviewed changes

ktoso marked this pull request as ready for review June 29, 2020 14:11

tomerd reviewed Jun 29, 2020

View reviewed changes

Sources/Logging/Logging.swift Outdated Show resolved Hide resolved

tomerd reviewed Jun 29, 2020

View reviewed changes

Sources/Logging/Logging.swift Outdated Show resolved Hide resolved

tomerd reviewed Jun 29, 2020

View reviewed changes

Sources/Logging/Logging.swift Outdated Show resolved Hide resolved

tomerd reviewed Jun 29, 2020

View reviewed changes

Sources/Logging/Logging.swift Show resolved Hide resolved

tomerd added the 🔨 semver/patch No public API change. label Jun 30, 2020

ktoso marked this pull request as draft June 30, 2020 01:16

ktoso added this to the 1.2.1 milestone Jun 30, 2020

tomerd added 🆕 semver/minor Adds new public API. and removed 🔨 semver/patch No public API change. labels Jul 1, 2020

ktoso modified the milestones: 1.2.1, 1.3.0 Jul 4, 2020

ktoso force-pushed the wip-loglevel-handling-multiplex branch from a0e545a to d3164d6 Compare July 5, 2020 14:13

ktoso commented Jul 5, 2020

View reviewed changes

ktoso force-pushed the wip-loglevel-handling-multiplex branch from d3164d6 to 1974886 Compare July 5, 2020 14:22

ktoso commented Jul 5, 2020

View reviewed changes

Sources/Logging/Logging.swift

return value

}

}

return nil

Copy link

Member Author

ktoso Jul 5, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Again, implements the "first is most important"

ktoso force-pushed the wip-loglevel-handling-multiplex branch 2 times, most recently from 55f9711 to cdb4869 Compare July 5, 2020 14:24

ktoso and others added 4 commits July 5, 2020 23:27

=multiplex apple#139 more properly handle logLevel in multiplex handler

93c9b24

swift 5.0 needs explicit return

0ba64fa

no need to loop over the settings

ed22c99

=metadata MultiplexLogHandler now consistently handles metadata read/…

003a288

…write

ktoso force-pushed the wip-loglevel-handling-multiplex branch from cdb4869 to 003a288 Compare July 5, 2020 14:27

ktoso requested review from tomerd, Lukasa and glbrntt July 5, 2020 14:28

ktoso marked this pull request as ready for review July 5, 2020 14:28

tomerd approved these changes Jul 5, 2020

View reviewed changes

Lukasa approved these changes Jul 6, 2020

View reviewed changes

Sources/Logging/Logging.swift Outdated Show resolved Hide resolved

glbrntt approved these changes Jul 6, 2020

View reviewed changes

Sources/Logging/Logging.swift Outdated Show resolved Hide resolved

Sources/Logging/Logging.swift Outdated Show resolved Hide resolved

Sources/Logging/Logging.swift Outdated Show resolved Hide resolved

Apply suggestions from code review

fa767f4

Co-authored-by: Cory Benfield <[email protected]> Co-authored-by: George Barnett <[email protected]>

ktoso merged commit 0c61f36 into apple:master Jul 6, 2020

ktoso deleted the wip-loglevel-handling-multiplex branch July 6, 2020 09:34

ktoso removed this from the 1.3.0 milestone Jul 6, 2020

tomerd added this to the 1.3.0 milestone Jul 6, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

=multiplex #139 more properly handle logLevel in multiplex handler #140

=multiplex #139 more properly handle logLevel in multiplex handler #140

ktoso commented Jun 27, 2020 •

edited

Loading

ktoso Jun 29, 2020

ktoso commented Jun 30, 2020

tomerd commented Jun 30, 2020

Lukasa commented Jun 30, 2020

ktoso commented Jun 30, 2020

glbrntt commented Jun 30, 2020

ktoso Jul 5, 2020

ktoso Jul 5, 2020

ktoso Jul 5, 2020

ktoso Jul 5, 2020

ktoso Jul 5, 2020

ktoso Jul 5, 2020

ktoso Jul 5, 2020

ktoso commented Jul 5, 2020

tomerd left a comment

Lukasa left a comment

glbrntt left a comment

ktoso commented Jul 6, 2020

=multiplex #139 more properly handle logLevel in multiplex handler #140

=multiplex #139 more properly handle logLevel in multiplex handler #140

Conversation

ktoso commented Jun 27, 2020 • edited Loading

Motivation:

Modifications:

Result:

Choose a reason for hiding this comment

ktoso commented Jun 30, 2020

tomerd commented Jun 30, 2020

Lukasa commented Jun 30, 2020

ktoso commented Jun 30, 2020

glbrntt commented Jun 30, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ktoso commented Jul 5, 2020

tomerd left a comment

Choose a reason for hiding this comment

Lukasa left a comment

Choose a reason for hiding this comment

glbrntt left a comment

Choose a reason for hiding this comment

ktoso commented Jul 6, 2020

ktoso commented Jun 27, 2020 •

edited

Loading