主页 SwiftLog 和 OSLog:选择、使用以及坑
Post
Cancel

SwiftLog 和 OSLog:选择、使用以及坑

如果你还在用 NSLog 或者 print 打 log,那也许这篇文章正适合你,可以帮你转型到新的 log 方式。如果你已经在使用 OSLog 的相关功能,那也许本文可以帮助你加深理解,以及找到一些“进阶”用法。

选择:SwiftLog 和 OSLog 的区别

两者都是 Swift 中与 log 有关的框架。在进行选择时,我们的首要任务就是理清它们的区别。“SwiftLog 和 OSLog 我应该选哪个”,也是我在参加一个聚会时经常听到的问题。

SwiftLog 是前端

SwiftLog 首次发布于 2019 年,是一个 Swift server 主导的项目。它的目的是提供一个统一的日志记录接口,让包括服务器 app、命令行工具以及 iOS 和 macOS app 等各种使用 Swift 语言的场合下 (但主要是 server!),能使用同样的方法记录日志。SwiftLog 本身是一个 log 前端框架,这意味着它需要搭配后端使用:例如将日志输出到控制台、文件、数据库或远程日志收集服务。SwiftLog 注重模块化,允许开发者通过更换后端来灵活调整日志记录的行为。

OSLog 是平台绑定的方案

OSLog 有着更长的历史,和 SwiftLog 只提供前端不同,它是一套绑定平台的完整的日志系统。OSLog 最初在 Objective-C 时代就已存在,它主要用于在 Apple 的各个平台上提供统一和高效的日志记录功能,特别强调了性能和隐私。随着 Swift 的发展,OSLog 也逐渐提供了更加 Swift 风格的 API,以减轻使用者的负担。OSLog 不仅支持日志的基本记录功能,还内置了对数据敏感性的处理、日志分类和过滤等高级功能。是更适合于一般 iOS / macOS 等 Apple 平台开发者的工具。

区分使用场景

综上,如果有下面需求时,我们可以使用 SwiftLog:

  • 跨平台应用或者服务器开发:对于那些不仅运行在 iOS 或 macOS,还需要在 Linux 或其他平台上运行的 Swift 应用,SwiftLog 提供了一个统一的日志记录接口,SwiftLog 搭配上合适的后端显然会成为最优先的的选择。

  • 需要高度定制的日志管理:如果你的项目需要将 log 输出到远程服务器、数据库或自定义格式的文件等,SwiftLog 的可扩展性可以满足要求。社区已经为 SwiftLog 提供了一些后端,你也可以通过实现自己的日志后端或利用现有的后端插件来满足这些需求。

而相对地,OSLog 更多地用在:

  • 专注于 Apple 平台的应用开发:OSLog 提供统一的 log 方式,并被搭载在系统中,所以对于只在 Apple 系统中运行的应用,OSLog 是更好的选择:容易集成,性能优秀,强大的日志筛选,以及隐私保护。
  • 希望尽量减少依赖:并不是说在 Apple 平台的开发中就不能使用 SwiftLog,但是这并没有必要。诚然我们可以使用 SwiftLog 作为前端,并接一个 OSLog 作为后端,来达到类似的效果,但是这引入了对 SwiftLog 的额外依赖。对于一般 app 可能影响不大 (大概几十 KB 的 binary size 增加),但是对于框架类型的项目来说,额外的依赖往往意味着额外的复杂度。以简单即美的设计哲学来说,除非有很强的理由 (比如确实需要在非 Apple 平台运行,或者需要多个 log 接收方),否则应该尽量避免引入 SwiftLog。

为什么应该避免使用 print

因为 print 根本不是为收集日志设计的:

  • SwiftLog 和 OSLog 都支持不同的日志级别(如 error、warning、info、debug 等)。Log 分级是最基础的功能,可以让开发者轻易地对 log 进行过滤并追踪问题。但是 print 只是简单地把字符串打印出来,出现问题时难以过滤。
  • SwiftLog 和 OSLog 尽量减少了日志记录对应用性能的影响。特别是 OSLog,它与系统日志数据库紧密集成,能够有效管理日志数据,即使在大量日志输出的情况下也能保持应用性能。而频繁调用 print 会严重影响性能。
  • SwiftLog 和 OSLog 自动记录必要的 metadata,比如进程、子系统和类别等。这使得在复杂系统中管理和检索日志成为可能,也可以让我们在设备外部通过别的工具查看和筛选日志。
  • SwiftLog 和 OSLog 可以通过在输出 log 时设定敏感信息和隐私保护,确保它们不会被无意间泄漏。另外,SwiftLog 提供了可扩展性,以对应不同的 log 后端。这些都是 print 不具备的。

我们应该让 print 回归它的本质:一个简单的将字符串打印到标准输出的语言特性,而不应该让它参与到 log 记录或者作为 debug 工具使用。

使用:OSLog 输出日志

在 Apple 平台开发,最经常接触和使用的日志系统应该还是 OSLog,因此在本文后面部分我们都会将重点放在 OSLog 上。

使用实例

和把大象放进冰箱类似,使用 OSLog 输出日志只有三步:

  1. 引入 OSLog 框架:

    1
    
     import OSLog
    
  2. 创建 Logger

    1
    2
    3
    4
    
     let logger = Logger(
       subsystem: "logger.onevcat.com", 
       category: "main"
     )
    
  3. 输出日志:

    1
    2
    3
    
     logger.info("This is an info")
     logger.warning("Ummm...seems not that good...")
     logger.fault("Something really BAD happens!!")
    

在 Xcode 的 Console 中,我们可以看到类似这样的效果:

打印出的 log 不仅包含了设定的信息,也包括了重要的 meta data,比如进程名 OSLogSample (不同于主 app 的 extension 的进程,或者是一些系统进程,也会打印日志。可以靠这个进程名进行筛选),子系统 (subsystem) 名 logger.onevcat.com (一般使用“逆域名”的形式,代表进程中的子系统),以及类别名 main 都可以显示出来。在 Console 的搜索栏内,我们也可以指定各类过滤器,通过 log 级别,子系统等进行查找,从而快速定位所需要的 log。

另外,当光标悬停在某一条输出时,在右下角还会显示这条输出对应的代码的位置,点击即可在编辑器中跳转到对应位置,十分方便。

如果你的输出看起来比这个简单得多,可以检查一下 Xcode Console 左下角的设置中,是否打开了对应的显示选项:

使用 Console.app 确认和过滤 log

使用 print 时,我们只能在连上 Xcode 调试期间用 Xcode 自带的 Console 来确认打印出的 log。使用 OSLog 则可以让我们在不依赖 Xcode 时,用系统的 Console.app 程序也可以看到打印出的内容。当我们在使用企业版或TestFlight进行测试分发等没有条件进行 debug 的情况下,OSLog 就非常实用了。

默认情况下 Console.app 可能只能输出警告和错误这样等级较高的日志,如果你希望让 Logger.info(_:)Logger.debug(_:) 这样的“低级别”日志也显示出来,你需要在 Action 菜单中勾选对应的选项。

在中文系统里,这两个选项被翻译成了“包括简介信息”和“包括调试信息”,虽然翻译没错,但是很难第一时间和它们实际所做的事情关联起来。

Console.app 的搜索框也十分强大,它也可以用来像 Xcode 的 console 搜索那样按照日志的 process 或者 subsystem 等信息进行过滤。比如在英文系统下,使用 s:logger.onevcat.com 就可以过滤对应 subsystem 的日志。

关于 Console.app 的搜索,有非常多的“隐藏小技巧”,比如组合多个 query,query 取非,使用简写,保存特定搜索以方便之后重用等。如果感兴趣,我建议您可以查看 Apple 提供的帮助文档以及属性简写,来帮助你提高效率。

上述两个文档也提供了中文版本的翻译。如果你使用中文版的系统,你应该参考的是中文版的属性简写文档:相较于英文版使用 p 代表 process,s 代表 subsystem,中文版要使用的是 (代表进程) 和 (代表子系统),使用 ps 的话都会被识别为 “Any”。

这种本地化的简化方式个人并不喜欢,在使用非英文系统时,我会选择在系统设置中的 通用 -> 语言与地区 -> 应用程序 选项中,把“控制台.app”设定为英文,以达到在不同语言环境下的统一。

代码读取

直接在 iOS 上读取当前进程

除了在 Xcode console 或者 Console.app 中确认外,我们还可以通过使用 OSLogStore 来读取这些日志。在 iOS 系统中,我们可以读取当前进程的日志信息:

1
2
3
4
let store = try OSLogStore(scope: .currentProcessIdentifier)
let predicate = NSPredicate(format: "subsystem == 'logger.onevcat.com'")

let logs = try store.getEntries(matching: predicate)

在获取 logs 时,我们使用 NSPredicate 来对海量 log 进行匹配。注意,我们应该直接使用 getEntriesmatching 来获取所需要的日志;先获取所有 log,然后再使用标准库中 Array.filter 的方法一般在性能上是不可行的。

通过在终端中输入 log help predicates,可以确认 NSPredicate 构建查询条件中能接受的关键字和它们的类型。它会给出类似这样的结果:

1
2
3
4
5
6
7
8
9
$ log help predicates
valid predicate fields:
    ...
    category                              (string)
    composedMessage                       (string)
    ...
    logType                               (log type)
    ...
    subsystem                             (string)

一些简单和常用的 predicate 例子:

1
2
3
4
5
NSPredicate(format: "subsystem == 'logger.onevcat.com'")
NSPredicate(format: "composedMessage CONTAINS 'BAD'")
NSPredicate(format: "category == 'main'")
NSPredicate(format: "logType >= error")
NSPredicate(format: "subsystem == 'logger.onevcat.com' AND logType >= error")

如果你对 NSPredicate 不熟悉,想要了解更多,可以参考这个总结得很好的 cheatsheet。

我们使用 Logger 打印出来的日志信息都是 OSLogEntryLog 类型,不过 getEntries 可能会包含其他更多类型的日志 (比如用于测量性能的 OSSignposter 等)。想要获取我们使用 Logger 的一般方式所打印的那些日志,可以进行类型转换:

1
2
3
4
5
6
for item in logs {
    guard let log = item as? OSLogEntryLog else {
        continue
    }
    print("[\(log.subsystem)]: \(log.level) \(log.composedMessage)")
}

导出 iOS 上的 log 并读取

除了上面看到的 OSLogStore(scope: .currentProcessIdentifier) 以外,OSLogStore 还提供了另一个初始化方法,它接受一个 url:OSLogStore.init(url:)。如果我们能给出一个指向有效 .logarchive bundle 的 URL,我们就可以用同样的 API 读取日志内容。

但不幸的是,当前 iOS 并没有提供直接把日志导出为 logarchive 的能力。我们只能通过将设备连接到一台 mac 上,然后使用类似下面的命令来将一段时间内的日志导出:

1
sudo log collect --device-name iPhone --last 1m --output logs.logarchive

导出后,我们便可以直接使用 Console.app 来打开并确认内容了。当然,有需要的话,我们也可以在 macOS 或者甚至 iOS 设备上使用 OSLogStore.init(url:) 来打开这个文件,并用代码读取日志内容。

坑:OSLog 的一些潜在问题

截止至本文发布时 (2024-04-09),OSLog 及其周边的配套设施或多或少存在一些问题。粗看起来,有一些是明显的 bug,应该会随着工具链的迭代逐渐得到修复;有些的话则是设计上的妥协甚至是“有意为之”。我们姑且都在这里列举一下。

框架中的 log 调用无法定位文件和行数

如前所述,在 Xcode console 中查看 log 时,将光标悬停在某个 log 上,该行右下角将会显示类似 “ViewController.swift 21:16” 这样的按钮,表明这条日志的输出来源。点击这个按钮,则会在编辑器中打开对应位置。

然而,如果这些 log 是由某个 package 或者 framework 输出的,即便我们有完整的调试信息甚至是源代码,在 log 过程中这些元数据也会丢失。比如,当我们创建一个本地 Swift Package 或 framework target,并在其中进行一些 log:

1
2
3
4
5
6
7
8
9
10
// In Framework A
public func hello() {
    let logger = Logger(subsystem: "com.onevcat.frameworkA", category: "main")
    logger.info("A message from framework")
}

// In main app bundle
import FrameworkA

hello()

虽然 “A message from framework” 能被打印出来,但是 Call Site 的符号信息和文件行数等都会丢失,你将无法直接定位到 Framework A 中的相关代码。这大大降低了 OSLog 在大型项目中的实用性。

OSLogStore 的选项和定位功能缺失

在 iOS 中使用 OSLogStore.getEntries(with:at:matching:) 时,获取 log 时本来可以指定一些选项,比如用 .reverse 来让 log 以逆序被检索,或者使用 OSLogPosition 来指定获取 log 的起始范围。但是这些选项在相当都不起作用。甚至在 macOS 时,如果指定了 .reverse,则可能什么 log 都获取不到。

这些问题在 radar://87622922 和 radar://87416514 中进行了追踪,但是至今还没有看到修复的迹象。

“捕获” self 的问题

Logger 的输出日志的各个方法 (Logger.info(_:), Logger.error(_:) 等),接受的都是一个 OSLogMessage 类型的值。文档指出,我们不应该手动创建一个 OSLogMessage 值,而是应该尽量使用插值的方式,把生成工作交给 Logging 框架。

You don’t create instances of OSLogMessage directly. Instead, the system creates them for you when writing messages to the unified logging system using a Logger.

OSLogMessage 在插值时实现了 OSLogInterpolation,后者负责处理日志输出时和普通字符串插值不同的独有特性,比如隐私 mask、数字或日期格式等。在最终调用插值时,它会将参数转换到一个 @escaping closure

1
2
3
internal mutating func append(_ value: @escaping () -> String) {
    // ...
}

这意味着,虽然在 Logger 使用时表面上并没有 closure,但实际上我们需要显式地将 self 写出来:

1
2
3
4
5
6
7
8
9
10
11
12
13
class A {
    var value = 100
    func hello() {
        let logger = Logger(
            subsystem: "logger.onevcat.com", 
            category: "main"
        )
        
        // 如果没有 self,报错。
        // Reference to property 'value' in closure requires explicit use of 'self' to make capture semantics explicit.
        logger.info("Test value: \(self.value)")
    }
}

这在大部分时候不构成问题,因为 logger 方法会马上结束,并且将 self 的引用计数减一。但是如果我们有一些异步代码时,这些 logger 语句就可能会在不经意间影响生命周期。比如:

1
2
3
4
5
6
7
8
9
10
11
12
13
class A {
    var value = 100
    func hello() {
        let logger = Logger(
            subsystem: "logger.onevcat.com", 
            category: "main"
        )
        
+       longLastingWorkShouldNotRetainSelf {
            logger.info("Test value: \(self.value)")
+       }
    }
}

上例中,简单地把 logger 移动到一个异步方法中时,由于 self 已经存在于原来的代码里了,因此这样的移动不会导致编译器再次报错,我们也就少了一次注意到 self 存在持有问题的机会。如果疏忽,将直接导致外界调用 A.hello() 时改变原来预想的生命周期。在处理涉及到 selfLogger,特别是在闭包里时,需要对是否应该持有 self 进行额外的思考。如果没有必要,可以用 [weak self] 的方式避免持有。

该博客文章由作者通过 CC BY 4.0 进行授权。

深入理解 Observation - 原理,back porting 和性能

-