Handover log file management to Rust. (#2495)

* Handover log file management to Rust.

Fix all the tests, disabling the logging ones for now.

* Merge logging tests into a single case 😬

Not ideal but at least they're now running.

* Move TracingConfiguration into its own file.

* Split up the tests into smaller functions instead of writing code like a caveman.
This commit is contained in:
Doug
2024-02-23 18:29:13 +00:00
committed by GitHub
parent c573b7caa1
commit ff35688088
19 changed files with 379 additions and 772 deletions
+3 -31
View File
@@ -24,15 +24,6 @@ import MatrixRustSDK
enum MXLog {
private enum Constants {
static let target = "elementx"
// Avoid redirecting NSLogs to files if we are attached to a debugger.
static let redirectToFiles = isatty(STDERR_FILENO) == 0
/// the maximum number of log files to use before rolling. `10` by default.
static let maxLogFileCount: UInt = 10
/// the maximum total space to use for log files in bytes. `100MB` by default.
static let logFilesSizeLimit: UInt = 100 * 1024 * 1024 // 100MB
}
// Rust side crashes if invoking setupTracing multiple times
@@ -43,39 +34,20 @@ enum MXLog {
static func configure(target: String? = nil,
logLevel: TracingConfiguration.LogLevel,
otlpConfiguration: OTLPConfiguration? = nil,
redirectToFiles: Bool = Constants.redirectToFiles,
maxLogFileCount: UInt = Constants.maxLogFileCount,
logFileSizeLimit: UInt = Constants.logFilesSizeLimit) {
guard didConfigureOnce == false else {
if let target {
MXLogger.setSubLogName(target)
}
// SubLogName needs to be set before calling configure in order to be applied
MXLogger.configure(redirectToFiles: redirectToFiles,
maxLogFileCount: maxLogFileCount,
logFileSizeLimit: logFileSizeLimit)
return
}
otlpConfiguration: OTLPConfiguration? = nil) {
guard !didConfigureOnce else { return }
RustTracing.setup(configuration: .init(logLevel: logLevel), otlpConfiguration: otlpConfiguration)
RustTracing.setup(configuration: .init(logLevel: logLevel, target: target), otlpConfiguration: otlpConfiguration)
if let target {
self.target = target
MXLogger.setSubLogName(target)
} else {
self.target = Constants.target
}
rootSpan = Span(file: #file, line: #line, level: .info, target: self.target, name: "root")
rootSpan.enter()
MXLogger.configure(redirectToFiles: redirectToFiles,
maxLogFileCount: maxLogFileCount,
logFileSizeLimit: logFileSizeLimit)
didConfigureOnce = true
}
@@ -1,335 +0,0 @@
//
// Copyright 2022 New Vector Ltd
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
//
import UIKit
/// The `MXLogger` tool redirects NSLog output into a fixed pool of files.
/// Another log file is used every time `MXLogger redirectNSLog(toFiles: true)`
/// is called. The pool contains 3 files.
///
/// `MXLogger` can track and log uncaught exceptions or crashes.
enum MXLogger {
/// stderr so it can be restored.
static var stderrSave: Int32 = 0
private enum Constants {
/// The filename used for the crash log.
static let crashLogFileName = "crash.log"
}
/// Redirect NSLog output to MXLogger files.
///
/// It is advised to condition this redirection in `#if (!isatty(STDERR_FILENO))` block to enable
/// it only when the device is not attached to the debugger.
///
/// - Parameters:
/// - redirectToFiles: `true` to enable the redirection.
/// - maxLogFileCount: number of files to keep (default is 10).
/// - logFileSizeLimit: size limit of log files in bytes. 0 means no limitation, the default value for other methods
static func configure(redirectToFiles: Bool,
maxLogFileCount: UInt,
logFileSizeLimit: UInt) {
if redirectToFiles {
var tempLog = ""
// Do a circular buffer based on X files
for index in (0...(maxLogFileCount - 2)).reversed() {
rotateLog(at: index, tempLog: &tempLog)
}
// Save stderr so it can be restored.
stderrSave = dup(STDERR_FILENO)
let nsLogURL = logURL(for: "console\(subLogName).log")
freopen((nsLogURL as NSURL).fileSystemRepresentation, "w+", stderr)
MXLog.info("redirectNSLogToFiles: true")
if !tempLog.isEmpty {
// We can now log into files
MXLog.info(tempLog)
}
removeExtraFiles(from: maxLogFileCount)
if logFileSizeLimit > 0 {
removeFiles(after: logFileSizeLimit)
}
} else if stderrSave > 0 {
// Flush before restoring stderr
fflush(stderr)
// Now restore stderr, so new output goes to console.
dup2(stderrSave, STDERR_FILENO)
close(stderrSave)
}
}
private static func rotateLog(at index: UInt, tempLog: inout String) {
let fileManager = FileManager.default
let currentURL: URL
let newURL: URL
if index == 0 {
currentURL = logURL(for: String("console\(subLogName).log"))
newURL = logURL(for: String("console\(subLogName).1.log"))
} else {
currentURL = logURL(for: String("console\(subLogName).\(index).log"))
newURL = logURL(for: String("console\(subLogName).\(index + 1).log"))
}
guard fileManager.fileExists(atPath: currentURL.path()) else { return }
if fileManager.fileExists(atPath: newURL.path()) {
// Temp log
tempLog.append("removeItemAt: \(newURL)\n")
do {
try fileManager.removeItem(at: newURL)
} catch {
tempLog.append("removeItemAt: \(newURL). Error: \(error)\n")
}
}
// Temp log
tempLog.append("moveItemAt: \(currentURL) to: \(newURL)\n")
do {
try fileManager.moveItem(at: currentURL, to: newURL)
} catch {
tempLog.append("moveItemAt: \(currentURL) to: \(newURL). Error: \(error)\n")
}
}
private static func logURL(for fileName: String) -> URL {
MXLogger.logsFolderURL.appending(path: fileName)
}
/// Delete all log files.
static func deleteLogFiles() {
let fileManager = FileManager.default
for logFileURL in logFiles {
try? fileManager.removeItem(at: logFileURL)
}
}
/// The list of all log file URLs, sorted chronologically.
static var logFiles: [URL] {
var logFiles = [(url: URL, modificationDate: Date)]()
let fileManager = FileManager.default
let enumerator = fileManager.enumerator(at: logsFolderURL, includingPropertiesForKeys: [.contentModificationDateKey])
// Find all *.log files and their modification dates.
while let logURL = enumerator?.nextObject() as? URL {
guard let resourceValues = try? logURL.resourceValues(forKeys: [.contentModificationDateKey]),
let modificationDate = resourceValues.contentModificationDate
else { continue }
if logURL.pathExtension == "log" {
logFiles.append((logURL, modificationDate))
}
}
let sortedFiles = logFiles.sorted { $0.modificationDate > $1.modificationDate }.map(\.url)
MXLog.info("logFiles: \(sortedFiles.map(\.lastPathComponent))")
return sortedFiles
}
// MARK: - Exceptions and crashes
/// Exceptions uncaught by try catch block are handled here
static func handleUncaughtException(_ exception: NSException) {
MXLogger.logCrashes(false)
// Extract running app information
let app = InfoPlistReader.main.bundleExecutable
let appId = InfoPlistReader.main.bundleIdentifier
let appVersion = "\(InfoPlistReader.main.bundleShortVersionString) (r\(InfoPlistReader.main.bundleVersion))"
// Build the crash log
let model = UIDevice.current.model
let version = UIDevice.current.systemVersion
let backtrace = exception.callStackSymbols
let description = String(format: "%.0f - %@\n%@\nApplication: %@ (%@)\nApplication version: %@\nBuild: %@\n%@ %@\n\nMain thread: %@\n%@\n",
Date.now.timeIntervalSince1970,
NSDate(),
exception.description,
app, appId,
appVersion,
buildVersion ?? "Unknown",
model, version,
Thread.isMainThread ? "true" : "false",
backtrace)
// Write to the crash log file
MXLogger.deleteCrashLog()
let crashLog = crashLogURL
try? description.write(to: crashLog, atomically: false, encoding: .utf8)
MXLog.error("handleUncaughtException", context: ["description": description])
}
// Signals emitted by the app are handled here
private static func handleSignal(_ signalValue: Int32) {
// Throw a custom Objective-C exception
// The Objective-C runtime will then be able to build a readable call stack in handleUncaughtException
withVaList([signalValue]) { NSException.raise(.init("Signal detected"), format: "Signal detected: %d", arguments: $0) }
}
/// Make `MXLogger` catch and log unmanaged exceptions or application crashes.
///
/// When such error happens, `MXLogger` stores the application stack trace into a file
/// just before the application leaves. The path of this file is provided by `MXLogger.crashLog`.
///
/// - Parameter enabled: `true` to enable the catch.
static func logCrashes(_ enabled: Bool) {
if enabled {
// Handle not managed exceptions by ourselves
NSSetUncaughtExceptionHandler { exception in
MXLogger.handleUncaughtException(exception)
}
// Register signal event (seg fault & cie)
signal(SIGABRT) { MXLogger.handleSignal($0) }
signal(SIGILL) { MXLogger.handleSignal($0) }
signal(SIGSEGV) { MXLogger.handleSignal($0) }
signal(SIGFPE) { MXLogger.handleSignal($0) }
signal(SIGBUS) { MXLogger.handleSignal($0) }
signal(SIGABRT) { MXLogger.handleSignal($0) }
} else {
// Disable crash handling
NSSetUncaughtExceptionHandler(nil)
signal(SIGABRT, SIG_DFL)
signal(SIGILL, SIG_DFL)
signal(SIGSEGV, SIG_DFL)
signal(SIGFPE, SIG_DFL)
signal(SIGBUS, SIG_DFL)
}
}
/// Set the app build version.
/// It will be reported in crash report.
static var buildVersion: String?
/// Set a sub name for namespacing log files.
///
/// A sub name must be set when running from an app extension because extensions can
/// run in parallel to the app.
/// It must be called before `redirectNSLog(toFiles)`.
///
/// - Parameter name: the subname for log files. Files will be named as `console-[subLogName].log`
/// Default is nil.
static func setSubLogName(_ name: String) {
if name.isEmpty {
subLogName = ""
} else {
subLogName = "-\(name)"
}
}
private static var subLogName = ""
/// The URL used for a crash log file.
static var crashLogURL: URL {
MXLogger.logsFolderURL.appending(path: Constants.crashLogFileName)
}
/// The URL of the file containing the last application crash if one exists or `nil` if there is none.
///
/// Only one crash log is stored at a time. The best moment for the app to handle it is the
/// at its next startup.
static var crashLog: URL? {
let crashLogURL = MXLogger.crashLogURL
let fileManager = FileManager.default
guard fileManager.fileExists(atPath: crashLogURL.path()) else { return nil }
return crashLogURL
}
/// Delete the crash log file.
static func deleteCrashLog() {
let crashLog = MXLogger.crashLogURL
let fileManager = FileManager.default
if fileManager.fileExists(atPath: crashLog.path()) {
try? fileManager.removeItem(at: crashLog)
}
}
// MARK: - Private
/// The folder where logs are stored
private static var logsFolderURL: URL {
.appGroupContainerDirectory
}
/// If `self.redirectNSLog(toFiles:numberOfFiles:)` is called with a lower numberOfFiles we need to do some cleanup.
private static func removeExtraFiles(from count: UInt) {
let fileManager = FileManager.default
for index in count... {
let fileName = "console\(subLogName).\(index).log"
let logFile = logURL(for: fileName)
if fileManager.fileExists(atPath: logFile.path()) {
try? fileManager.removeItem(at: logFile)
MXLog.info("removeExtraFilesFromCount: \(count). removeItemAt: \(logFile)\n")
} else {
break
}
}
}
/// If `redirectNSLog(toFiles:sizeLimit:)` is called with a size limit, we may need to do some cleanup.
private static func removeFiles(after sizeLimit: UInt) {
var logSize: UInt = 0
var indexExceedingSizeLimit: Int?
let fileManager = FileManager.default
// Start from console.1.log. Do not consider console.log. It should be almost empty
for index in 1... {
let fileName = "console\(subLogName).\(index).log"
let logFile = logURL(for: fileName)
if fileManager.fileExists(atPath: logFile.path()) {
if let attributes = try? fileManager.attributesOfItem(atPath: logFile.path()), let fileSize = attributes[.size] as? UInt {
logSize += fileSize
}
if logSize >= sizeLimit {
indexExceedingSizeLimit = index
break
}
} else {
break
}
}
let logSizeString = logSize.formatted(.byteCount(style: .binary))
let sizeLimitString = sizeLimit.formatted(.byteCount(style: .binary))
if let indexExceedingSizeLimit {
MXLog.info("removeFilesAfterSizeLimit: Remove files from index \(indexExceedingSizeLimit) because logs are too large (\(logSizeString) for a limit of \(sizeLimitString)\n")
removeExtraFiles(from: UInt(indexExceedingSizeLimit))
} else {
MXLog.info("removeFilesAfterSizeLimit: No need: \(logSizeString) for a limit of \(sizeLimitString)\n")
}
}
}
+53 -126
View File
@@ -14,7 +14,7 @@
// limitations under the License.
//
import Collections
import Foundation
import MatrixRustSDK
struct OTLPConfiguration {
@@ -23,134 +23,21 @@ struct OTLPConfiguration {
let password: String
}
// This exposes the full Rust side tracing subscriber filter for more flexibility.
// We can filter by level, crate and even file. See more details here:
// https://docs.rs/tracing-subscriber/0.2.7/tracing_subscriber/filter/struct.EnvFilter.html#examples
struct TracingConfiguration {
enum LogLevel: Codable, Hashable {
case error, warn, info, debug, trace
case custom(String)
var title: String {
switch self {
case .error:
return "Error"
case .warn:
return "Warning"
case .info:
return "Info"
case .debug:
return "Debug"
case .trace:
return "Trace"
case .custom:
return "Custom"
}
}
fileprivate var rawValue: String {
switch self {
case .error:
return "error"
case .warn:
return "warn"
case .info:
return "info"
case .debug:
return "debug"
case .trace:
return "trace"
case .custom(let filter):
return filter
}
}
}
enum Target: String {
case common = ""
case elementx
case hyper, matrix_sdk_ffi, matrix_sdk_crypto
case matrix_sdk_client = "matrix_sdk::client"
case matrix_sdk_crypto_account = "matrix_sdk_crypto::olm::account"
case matrix_sdk_oidc = "matrix_sdk::oidc"
case matrix_sdk_http_client = "matrix_sdk::http_client"
case matrix_sdk_sliding_sync = "matrix_sdk::sliding_sync"
case matrix_sdk_base_sliding_sync = "matrix_sdk_base::sliding_sync"
case matrix_sdk_ui_timeline = "matrix_sdk_ui::timeline"
case matrix_sdk_base_read_receipts = "matrix_sdk_base::read_receipts"
}
static let targets: OrderedDictionary<Target, LogLevel> = [
.common: .info,
.elementx: .info,
.hyper: .warn,
.matrix_sdk_ffi: .info,
.matrix_sdk_client: .trace,
.matrix_sdk_crypto: .debug,
.matrix_sdk_crypto_account: .trace,
.matrix_sdk_oidc: .trace,
.matrix_sdk_http_client: .debug,
.matrix_sdk_sliding_sync: .info,
.matrix_sdk_base_sliding_sync: .info,
.matrix_sdk_ui_timeline: .info,
.matrix_sdk_base_read_receipts: .trace
]
let filter: String
/// Sets the same log level for all Targets
/// - Parameter logLevel: the desired log level
/// - Returns: a custom tracing configuration
init(logLevel: LogLevel) {
if case let .custom(filter) = logLevel {
self.filter = filter
return
}
let overrides = Self.targets.keys.reduce(into: [Target: LogLevel]()) { partialResult, target in
// Keep the defaults here
let ignoredTargets: [Target] = [.common,
.hyper,
.matrix_sdk_ffi,
.matrix_sdk_oidc,
.matrix_sdk_client,
.matrix_sdk_crypto,
.matrix_sdk_crypto_account,
.matrix_sdk_http_client,
.matrix_sdk_base_read_receipts]
if ignoredTargets.contains(target) {
return
}
partialResult[target] = logLevel
}
var newTargets = Self.targets
for (target, logLevel) in overrides {
newTargets.updateValue(logLevel, forKey: target)
}
let components = newTargets.map { (target: Target, logLevel: LogLevel) in
guard !target.rawValue.isEmpty else {
return logLevel.rawValue
}
return "\(target.rawValue)=\(logLevel.rawValue)"
}
filter = components.joined(separator: ",")
}
}
enum RustTracing {
private(set) static var currentTracingConfiguration: TracingConfiguration?
/// The base filename used for log files. This may be suffixed by the target
/// name and other log management metadata during rotation.
static let filePrefix = "console"
/// The directory that stores all of the log files.
static var logsDirectory: URL { .appGroupContainerDirectory }
private(set) static var currentTracingConfiguration: TracingConfiguration?
static func setup(configuration: TracingConfiguration, otlpConfiguration: OTLPConfiguration?) {
currentTracingConfiguration = configuration
// Keep a minimum of 1 week of log files. In reality it will be longer
// as the app is unlikely to be running continuously.
let maxFiles: UInt64 = 24 * 7
if let otlpConfiguration {
setupOtlpTracing(config: .init(clientName: "ElementX-iOS",
user: otlpConfiguration.username,
@@ -158,11 +45,51 @@ enum RustTracing {
otlpEndpoint: otlpConfiguration.url,
filter: configuration.filter,
writeToStdoutOrSystem: true,
writeToFiles: nil))
writeToFiles: .init(path: logsDirectory.path(),
filePrefix: configuration.fileName,
fileSuffix: configuration.fileExtension,
maxFiles: maxFiles)))
} else {
setupTracing(config: .init(filter: configuration.filter,
writeToStdoutOrSystem: true,
writeToFiles: nil))
writeToFiles: .init(path: logsDirectory.path(),
filePrefix: configuration.fileName,
fileSuffix: configuration.fileExtension,
maxFiles: maxFiles)))
}
}
/// A list of all log file URLs, sorted chronologically. This is only public for testing purposes, within
/// the app please use ``copyLogs(to:)`` so that the files are name appropriates for QuickLook.
static var logFiles: [URL] {
var logFiles = [(url: URL, modificationDate: Date)]()
let fileManager = FileManager.default
let enumerator = fileManager.enumerator(at: logsDirectory, includingPropertiesForKeys: [.contentModificationDateKey])
// Find all *.log files and their modification dates.
while let logURL = enumerator?.nextObject() as? URL {
guard let resourceValues = try? logURL.resourceValues(forKeys: [.contentModificationDateKey]),
let modificationDate = resourceValues.contentModificationDate
else { continue }
if logURL.lastPathComponent.hasPrefix(filePrefix) {
logFiles.append((logURL, modificationDate))
}
}
let sortedFiles = logFiles.sorted { $0.modificationDate > $1.modificationDate }.map(\.url)
MXLog.info("logFiles: \(sortedFiles.map(\.lastPathComponent))")
return sortedFiles
}
/// Delete all log files.
static func deleteLogFiles() {
let fileManager = FileManager.default
for logFileURL in logFiles {
try? fileManager.removeItem(at: logFileURL)
}
}
}
@@ -0,0 +1,151 @@
//
// Copyright 2024 New Vector Ltd
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
//
import Collections
// This exposes the full Rust side tracing subscriber filter for more flexibility.
// We can filter by level, crate and even file. See more details here:
// https://docs.rs/tracing-subscriber/0.2.7/tracing_subscriber/filter/struct.EnvFilter.html#examples
struct TracingConfiguration {
enum LogLevel: Codable, Hashable {
case error, warn, info, debug, trace
case custom(String)
var title: String {
switch self {
case .error:
return "Error"
case .warn:
return "Warning"
case .info:
return "Info"
case .debug:
return "Debug"
case .trace:
return "Trace"
case .custom:
return "Custom"
}
}
fileprivate var rawValue: String {
switch self {
case .error:
return "error"
case .warn:
return "warn"
case .info:
return "info"
case .debug:
return "debug"
case .trace:
return "trace"
case .custom(let filter):
return filter
}
}
}
enum Target: String {
case common = ""
case elementx
case hyper, matrix_sdk_ffi, matrix_sdk_crypto
case matrix_sdk_client = "matrix_sdk::client"
case matrix_sdk_crypto_account = "matrix_sdk_crypto::olm::account"
case matrix_sdk_oidc = "matrix_sdk::oidc"
case matrix_sdk_http_client = "matrix_sdk::http_client"
case matrix_sdk_sliding_sync = "matrix_sdk::sliding_sync"
case matrix_sdk_base_sliding_sync = "matrix_sdk_base::sliding_sync"
case matrix_sdk_ui_timeline = "matrix_sdk_ui::timeline"
case matrix_sdk_base_read_receipts = "matrix_sdk_base::read_receipts"
}
static let targets: OrderedDictionary<Target, LogLevel> = [
.common: .info,
.elementx: .info,
.hyper: .warn,
.matrix_sdk_ffi: .info,
.matrix_sdk_client: .trace,
.matrix_sdk_crypto: .debug,
.matrix_sdk_crypto_account: .trace,
.matrix_sdk_oidc: .trace,
.matrix_sdk_http_client: .debug,
.matrix_sdk_sliding_sync: .info,
.matrix_sdk_base_sliding_sync: .info,
.matrix_sdk_ui_timeline: .info,
.matrix_sdk_base_read_receipts: .trace
]
let filter: String
/// The filename that logs should be written to.
let fileName: String
/// The file extension to use for log files.
let fileExtension = "log"
/// Sets the same log level for all Targets
/// - Parameter logLevel: the desired log level
/// - Parameter target: the name of the target being configured
/// - Returns: a custom tracing configuration
init(logLevel: LogLevel, target: String?) {
fileName = if let target {
"\(RustTracing.filePrefix)-\(target)"
} else {
RustTracing.filePrefix
}
if case let .custom(filter) = logLevel {
self.filter = filter
return
}
let overrides = Self.targets.keys.reduce(into: [Target: LogLevel]()) { partialResult, target in
// Keep the defaults here
let ignoredTargets: [Target] = [.common,
.hyper,
.matrix_sdk_ffi,
.matrix_sdk_oidc,
.matrix_sdk_client,
.matrix_sdk_crypto,
.matrix_sdk_crypto_account,
.matrix_sdk_http_client,
.matrix_sdk_base_read_receipts]
if ignoredTargets.contains(target) {
return
}
partialResult[target] = logLevel
}
var newTargets = Self.targets
for (target, logLevel) in overrides {
newTargets.updateValue(logLevel, forKey: target)
}
let components = newTargets.map { (target: Target, logLevel: LogLevel) in
guard !target.rawValue.isEmpty else {
return logLevel.rawValue
}
return "\(target.rawValue)=\(logLevel.rawValue)"
}
filter = components.joined(separator: ",")
}
}