Adopt swift-log

[ianpartridge]

https://github.com/apple/swift-log/tree/swift-log-0.0 supports Swift 4.1+

[djones6]

A simple implementation that allows a swift-log Logger to be attached to LoggerAPI: https://github.com/djones6/LoggerAPI/tree/swift-log

Sample project using the above: https://github.com/djones6/LoggingTest

Some considerations for use of swift-log with LoggerAPI and/or Kitura:

• Do we want LoggerAPI to log to a default swift-log Logger by default? Or should the user configure this explicitly? I'm leaning toward requiring explicit opt-in because:
  • by default, an otherwise unconfigured Logger will log to stdout, which may be undesirable
  • the logging level is defined on the Logger, rather than the backend (LogHandler), which is the opposite from LoggerAPI (where the logging level is configured on our 'backend' eg. HeliumLogger).
• How do we want to map the LoggerAPI logging levels (error, warning, info, verbose, debug, exit, entry) to the swift-log levels (critical, error, warning, notice, info, debug, trace), and do we want this to be hard-coded or user-configurable?
  • my example hard-codes the following (LoggerAPI -> swift-log):
    • error -> error
    • warning -> warning
    • info -> notice
    • verbose -> info
    • debug -> debug
    • entry / exit -> trace
    • (nothing sent to 'critical')

[djones6]

We may want to provide an API on Kitura itself to set up swift-log, eg: Kitura.logTo(logger: Logging.Logger) - doing this would eliminate the requirement to import / interact with LoggerAPI at all. I'll prototype what this would look like.

[djones6]

Example updated to use Kitura.logTo(logger: Logging.Logger) API which avoids users from needing to interact with LoggerAPI directly:
https://github.com/djones6/Kitura/tree/swift-log
(needs my corresponding fork of LoggerAPI)

Sample project updated using this: djones6/LoggingTest@40fdb1d

[ianpartridge]

@weissi ^^^ any thoughts?

[weissi]

@djones6 / @ianpartridge I'm not sure I understand the question fully. Is the question on where/how to configure the Logging.Logger that LoggerAPI should use?

[ianpartridge]

Sorry, no particular question, just thought you might be interested to see @djones6's current direction on this, and might have comments!

[weissi]

Thank you, that sounds great! I'll also have a look at the code now.

[weissi]

@djones6 Thanks, that all looks really good. I left some comments, mostly that LoggerAPI isn't (and never was) thread-safe and I think there are some extra branches (on the log level) that we don't need.

[djones6]

@weissi Thank you for your comments! I think it makes sense to address thread safety for both logging types. I'll work that up.

[djones6]

312c0c8 adds locking. I left the (otherwise superfluous) log level checks in for now, as otherwise we'll lock regardless of whether the logger is going to log a message or ignore it, which would increase contention.

That said, I haven't attempted to measure whether the cost of the check is less than the cost of (briefly) taking a lock - it feels like it should be.

[weissi]

@djones6 commented on the commit (312c0c8)

[djones6]

Thanks @weissi for your guidance on thread safety! I've reworked the locking changes to use computed properties incorporating NSLock in get/set operations: https://github.com/djones6/LoggerAPI/commit/2c1644454b8430afec4cff72412b70a7d4e5c1b1

As I was fearful of the performance overhead this might impose (as now, every LoggerAPI Log. call will go through a lock/unlock) I ran a Kitura hello-world test on Linux:

ITERATIONS: 10, DURATION: 30, CLIENT: 'localhost', CLIENTS: 128, URL: 'http://127.0.0.1:8080/plaintext', CPUS: '0,1,2,3'
PWD: /home/djones6/Kitura-Benchmarks/Bench-Kitura-Core
270_base: /home/djones6/Kitura-Benchmarks/Bench-Kitura-Core/log_270_base/.build/release/HelloWorld
270_nslock: /home/djones6/Kitura-Benchmarks/Bench-Kitura-Core/log_270_nslock/.build/release/HelloWorld
               | Throughput (req/s)      | CPU (%) | Mem (kb)     | Latency (ms)                   | good
Implementation | Average    | Max        | Average | Avg peak RSS | Average  | 99%      | Max      | iters
---------------|------------|------------|---------|--------------|----------|----------|----------|-------
      270_base |    79100.4 |    80764.0 |    97.4 |        29048 |      1.6 |      5.3 |    200.6 |    10
    270_nslock |    79822.0 |    81829.6 |    97.7 |        29216 |      1.6 |      6.2 |    201.1 |    10

This was Kitura 2.7, Swift 5.0.1, on Ubuntu 16.04 (bare metal, affinitized to 4 CPUs). No measurable degradation, which is a good start! Now, on closer inspection there is currently only one log entry generated in a simple request path such as this, so the numbers may not be a big surprise, but it means we can be thread safe without regressing.

[helenmasters]

Adding a reference to a newly created associated docs issue, so that we don't forget to update the docs once this is tagged in a release - Kitura/kitura.dev#367