apple/swift-log

Logging fails for non string literal, forcing extra var.

neilt opened this issue · 10 comments

neilt commented

Expected behavior

Expected to be able to log a string var without using string interpolation.

Actual behavior

Logging fails for non string literal, forcing extra var.

Steps to reproduce

For example:

let gLog = Logger(label: "com.fairwindsoft.logger")
let  logStr = "\nList All Events\n\(Report.logStringTextTable(stringTable: reportData, colDef: Event.reportColumns))\n"
gLog.info(logStr)

This fails with the error:
Cannot convert value of type 'String' to expected argument type 'Logger.Message'

This forces all code to be converted to:

gLog.info("\(logStr)")

Which should be unnecessary and is a waste of time and effort while coding.

Other syntax that fails:

gLog.info("\n" + categories.map({ "\($0.reportDescription)" }).joined(separator: "\n\n") )

These examples all work with XCGLogger.

IMO if you are going to design a standard logging API, it should be more swift like.

If possible, minimal yet complete reproducer code (or URL to code)

see above

SwiftLog version/commit hash

    "package": "swift-log",
    "repositoryURL": "https://github.com/apple/swift-log.git",
    "state": {
      "branch": null,
      "revision": "5d66f7ba25daf4f94100e7022febf3c75e37a6c7",
      "version": "1.4.2"
    }

[the SwiftLog tag/commit hash]

Swift & OS version (output of swift --version && uname -a)

swift-driver version: 1.26.9 Apple Swift version 5.5 (swiftlang-1300.0.31.1 clang-1300.0.29.1)
Target: x86_64-apple-macosx11.0
Darwin neils-iMac.local 20.6.0 Darwin Kernel Version 20.6.0: Mon Aug 30 06:12:21 PDT 2021; root:xnu-7195.141.6~3/RELEASE_X86_64 x86_64

0xTim commented
let gLog = Logger(label: "com.fairwindsoft.logger")
let logStr: Logger.Message = "\nList All Events\n\(Report.logStringTextTable(stringTable: reportData, colDef: Event.reportColumns))\n"
gLog.info(logStr)

should work

neilt commented

Well here is the most simple test case I can create and it fails to compile.

class testSwiftLog {
    func test() {
        let gLog = Logger(label: "com.fairwindsoft.logger")
        let str = ""
        gLog.error(str, metadata: nil)
    }
}

Compiling with Xcode 13 and iOS 15.
Error

Cannot convert value of type 'String' to expected argument type 'Logger.Message'

0xTim commented

Yes because the logger doesn't accept String types, it accepts Logger.Message types. But because it conforms to ExpressibleByStringLiteral the compiler can infer that when you gLog.error("something"), "something" in this case is Logger.Message, not String. When you define let str = "something", str is inferred to be String which is why you get a compiler mismatch. To use your simple test case, you just need to make the type of str explicit:

class testSwiftLog {
    func test() {
        let gLog = Logger(label: "com.fairwindsoft.logger")
        let str: Logger.Message = ""
        gLog.error(str, metadata: nil)
    }
}

(That use case is actual in the inline docs)

By accepting Logger.Message instead of String it allows things like the behaviour of string interpolation to be customised. This is pretty common for advanced String use-cases - e.g. in Fluent you have to do the same thing of defining the string to be SQLStatement so that any interpolation is passed in as an SQL bind parameter instead of just being inserted directly which would allow SQL injection attacks.

(I know technically the Logger functions take a closure that returns a Logger.Message but the effect is the same)

neilt commented

Ok, here is another example.

    func test2() {
        struct Cats {
            var name: String
            var size: String
        }
        let gLog = Logger(label: "com.fairwindsoft.logger")
        let categories: [Cats] = []

        // Works
        gLog.error( Logger.Message(stringLiteral: "\n" + categories.map({ $0.name }).joined(separator: "\n\n")))

        // Fails to compile: Cannot convert value of type 'String' to expected argument type 'Logger.Message'
        gLog.error("\n" + categories.map({ $0.name }).joined(separator: "\n\n"))
    }

So what you are saying is that I have to litter all of my code with
Logger.Message(stringLiteral: ....)

That seems suboptimal, IMO.

0xTim commented

If you're passing in stuff to the message that is of type String then yes. But you might want to consider passing things like the categories in as metadata etc.

In practice, I've found there are very few occasions where I've needed to actually specify a type

ktoso commented

This is by design, and is intended to have API similarity with OSLog.

All examples you are showing would, on our opinion, be better served as doing them as metadata; rather than constructing a very complex string like that. Manually constructing (and formatting 😱 ) complex log strings like that is not a good idea since you're going to allocate all this even if you are never going to log it.

Keep your log message simple, and use metadata to add information.

neilt commented

Got it. That is the reason I do NOT use OSLog. I do use XCGLogger, but that is no longer maintained.

As for allocating, but not using. In XCGLogger, for example:

gLog.info {
    var logStr = "\nMove back to beginning take of the day\n"
    logStr += "   Start Date: \(FWSDateFormatters.dateTimeDebugFormatterMilliSeconds.string(from: processingDate))\n"
    logStr += "   Check Date: \(FWSDateFormatters.dateTimeDebugFormatterMilliSeconds.string(from: checkDay))\n"
    logStr += " Time Between: \(MedTDate.timeBetweenWithUnits(hours: secondsBetween / Double(Date.secPerHr)))\n"
    logStr += "Loop End Date: \(FWSDateFormatters.dateTimeDebugFormatterMilliSeconds.string(from: loopDate1))\n"
    logStr += "Calc End Date: \(FWSDateFormatters.dateTimeDebugFormatterMilliSeconds.string(from: loopDate2))\n"
    return "\n\(logStr)\n"
}

Nothing in the closure gets executed or allocated unless it is going to be logged, which it won't unless the log level is info or above.

Accessing metadata sucks for development. I might see the value for production server installations, but it appears that swift-log is not for development, or at least not for me and my workflow.

If I am printing some complex stuff to the log, I want control of the format. Otherwise it is hard too hard to decode quickly. For development I don't care if it is slower, but I do want clarity. Single line strings do not often work for development. Most of this logging code gets ripped out before the code goes into production.

I don't usually use debugger, because it is not uncommon for the Apple's debugger to not work with anything more complex than Ints/Strings or multithreaded and again the formatting sucks.

Anyway, you can close this if you want. As it stands, I won't be adopting swift-log in my code.

Thanks for working on this. I hope someday we'll get a good logger that works for more than just Apple's narrow needs.

Thanks, for listening.

VaslD commented

I think the problem (or the difference between libraries), is that you are accustomed to having a separate log message variable for logging. The current design of swift-log actually reduces extra variables, as long as you don't have a habit of creating one. All you need to do is putting your "string" directly on the call to Logger.

In your first example:

let gLog = Logger(label: "com.fairwindsoft.logger")
let  logStr = "\nList All Events\n\(Report.logStringTextTable(stringTable: reportData, colDef: Event.reportColumns))\n"
gLog.info(logStr)

You just need:

let gLog = Logger(label: "com.fairwindsoft.logger")
gLog.info("\nList All Events\n\(Report.logStringTextTable(stringTable: reportData, colDef: Event.reportColumns))\n")

info(_:) takes a Logger.Message which is ExpressibleByStringInterpolation, and the compiler automatically constructs a message from your String.

And the next:

let gLog = Logger(label: "com.fairwindsoft.logger")
let categories: [Cats] = []

// This is bad.
// Documentation specifically says do not invoke this initializer by hand. It should be considered reserved for the compiler.
gLog.error( Logger.Message(stringLiteral: "\n" + categories.map({ $0.name }).joined(separator: "\n\n")))

// Just put it all together and not use +
// + is a call to an operator method, which String does have but Logger.Message may not.
gLog.error("\n\(categories.map({ $0.name }).joined(separator: "\n\n"))")

The same goes for the longest, last example. Write your entire message at once and do not rely on +, += and other String methods for constructing the message. You can include other variables and call methods/properties on these variables as long as you use \() to interpolate them. You just cannot operate on the message itself.

When the message gets too long for a single line of code, I think you can use Swift's multi-line string literal:

logger.error(
    """
    Something really bad has happened. \
    Oh my god. \(someVariable) is nil! \
    I found this out at \(formatter.string(from: date)).
    """
)

The \ at the end of each line of text (escapes) prevents the newline character, otherwise each line of text will appear separated by \n in the log message. This is multi-line string 101, nothing specific to the Logger.Message per-se.

As others suggested, you'd better use for metadata date formatting and other output behaviors. But as illustrated, you CAN do (almost) exactly the same with swift-log like with other libraries. The message (interpolation) you specified also delays execution until it's needed by say a LogHandler. The Logger API actually declares an @autoclosure in the position of log message, which is exactly logger.error { yourCode() } without you having to write curly brackets and function calls.

Edit: I think you may be able to use closures yourself (because @autoclosure should support regular closures, non-auto ones) if you need some complex fine-tuning and would like to put it in a really large block. The down side is you need to remember to return a Logger.Message, not String at the very end.

// I have never tried this. It should work judging from experience.
logger.debug({
    var var1 = ...
    var var2 = ...
    var1.doSomething()
    if var2.someProperty { ... }

    // Or if you'd rather somehow Logger.Message(...), I don't know.
    return "\(var1), \(var2)"
}())

Needless to say this is at least IMO bad code. If I need to write more code for logging than doing business logic, then something is definitely wrong.

neilt commented

Thanks for the suggestions.

ktoso commented

Thanks for the discussion folks, closing this as "as designed"