Skip to content

Commit

Permalink
Ensure log file sizes stay below a certain threshold
Browse files Browse the repository at this point in the history
  • Loading branch information
Jon Petersson committed Apr 19, 2024
1 parent 0819505 commit ee04640
Show file tree
Hide file tree
Showing 16 changed files with 157 additions and 62 deletions.
10 changes: 1 addition & 9 deletions ios/MullvadLogging/CustomFormatLogHandler.swift
Original file line number Diff line number Diff line change
Expand Up @@ -16,14 +16,6 @@ public struct CustomFormatLogHandler: LogHandler {
private let label: String
private let streams: [TextOutputStream]

private let dateFormatter = Self.makeDateFormatter()

public static func makeDateFormatter() -> DateFormatter {
let dateFormatter = DateFormatter()
dateFormatter.dateFormat = "YYYY-MM-dd HH:mm:ss.SSS"
return dateFormatter
}

public init(label: String, streams: [TextOutputStream]) {
self.label = label
self.streams = streams
Expand Down Expand Up @@ -54,7 +46,7 @@ public struct CustomFormatLogHandler: LogHandler {
}
let prettyMetadata = Self.formatMetadata(mergedMetadata)
let metadataOutput = prettyMetadata.isEmpty ? "" : " \(prettyMetadata)"
let timestamp = dateFormatter.string(from: Date())
let timestamp = Date().logFormatted
let formattedMessage = "[\(timestamp)][\(label)][\(level)]\(metadataOutput) \(message)\n"

for var stream in streams {
Expand Down
10 changes: 8 additions & 2 deletions ios/MullvadLogging/Date+LogFormat.swift
Original file line number Diff line number Diff line change
Expand Up @@ -9,16 +9,22 @@
import Foundation

extension Date {
public func logFormatDate() -> String {
public var logFormatted: String {
let formatter = DateFormatter()

formatter.dateFormat = "dd/MM/yyyy @ HH:mm:ss"
formatter.locale = Locale(identifier: "en_US_POSIX")
formatter.timeZone = TimeZone(abbreviation: "UTC")

return formatter.string(from: self)
}

public func logFormatFilename() -> String {
public var logFileFormatted: String {
let formatter = DateFormatter()

formatter.dateFormat = "dd-MM-yyyy'T'HH:mm:ss"
formatter.locale = Locale(identifier: "en_US_POSIX")
formatter.timeZone = TimeZone(abbreviation: "UTC")

return formatter.string(from: self)
}
Expand Down
58 changes: 48 additions & 10 deletions ios/MullvadLogging/LogFileOutputStream.swift
Original file line number Diff line number Diff line change
Expand Up @@ -16,10 +16,14 @@ private let reopenFileLogInterval: Duration = .seconds(5)
class LogFileOutputStream: TextOutputStream {
private let queue = DispatchQueue(label: "LogFileOutputStreamQueue", qos: .utility)

private let fileURL: URL
private let baseFileURL: URL
private var fileURL: URL
private let encoding: String.Encoding
private let maxBufferCapacity: Int
private let maximumBufferCapacity: Int
private let fileHeader: String
private let fileSizeLimit: UInt64
private var partialFileSizeCounter: UInt64 = 0
private var partialFileNameCounter = 1

private var state: State = .closed {
didSet {
Expand All @@ -45,11 +49,20 @@ class LogFileOutputStream: TextOutputStream {
case waitingToReopen
}

init(fileURL: URL, header: String, encoding: String.Encoding = .utf8, maxBufferCapacity: Int = 16 * 1024) {
init(
fileURL: URL,
header: String,
fileSizeLimit: UInt64 = ApplicationConfiguration.logMaximumFileSize,
encoding: String.Encoding = .utf8,
maxBufferCapacity: Int = 16 * 1024
) {
self.fileURL = fileURL
self.encoding = encoding
self.maxBufferCapacity = maxBufferCapacity
self.fileHeader = header
self.fileSizeLimit = fileSizeLimit
self.encoding = encoding
self.maximumBufferCapacity = maxBufferCapacity

baseFileURL = fileURL.deletingPathExtension()
}

deinit {
Expand Down Expand Up @@ -89,7 +102,16 @@ class LogFileOutputStream: TextOutputStream {
}
}

@discardableResult private func write(fileHandle: FileHandle, data: Data) throws -> Int {
private func write(fileHandle: FileHandle, data: Data) throws {
partialFileSizeCounter += UInt64(data.count)

// Rotate file if threshold has been met. Then rerun the write operation.
guard partialFileSizeCounter <= fileSizeLimit else {
try rotateFile(handle: fileHandle, data: data)
write(String(data: data, encoding: encoding) ?? "")
return
}

let bytesWritten = data.withUnsafeBytes { buffer -> Int in
guard let ptr = buffer.baseAddress else { return 0 }

Expand All @@ -99,11 +121,17 @@ class LogFileOutputStream: TextOutputStream {
if bytesWritten == -1 {
let code = POSIXErrorCode(rawValue: errno)!
throw POSIXError(code)
} else {
return bytesWritten
}
}

fileprivate func rotateFile(handle: FileHandle, data: Data) throws {
try handle.close()

state = .closed
partialFileSizeCounter = 0
fileURL = try incrementFileName()
}

private func openFile() throws -> FileHandle {
let oflag: Int32 = O_WRONLY | O_CREAT
let mode: mode_t = S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH
Expand Down Expand Up @@ -171,8 +199,18 @@ class LogFileOutputStream: TextOutputStream {
private func bufferData(_ data: Data) {
buffer.append(data)

if buffer.count > maxBufferCapacity {
buffer.removeFirst(buffer.count - maxBufferCapacity)
if buffer.count > maximumBufferCapacity {
buffer.removeFirst(buffer.count - maximumBufferCapacity)
}
}

private func incrementFileName() throws -> URL {
partialFileNameCounter += 1

if let url = URL(string: baseFileURL.relativePath + "_\(partialFileNameCounter).log") {
return url
} else {
throw POSIXError(POSIXErrorCode(rawValue: 2)!) // "No such file or directory"
}
}
}
21 changes: 7 additions & 14 deletions ios/MullvadLogging/LogRotation.swift
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,7 @@ public enum LogRotation {
public var errorDescription: String? {
switch self {
case .rotateLogFiles:
return "Failure to rotate the source log file to backup."
return "Failure to rotate logs"
}
}

Expand Down Expand Up @@ -74,30 +74,23 @@ public enum LogRotation {
log1.creationDate > log2.creationDate
}

try deleteLogsOlderThan(options.oldestAllowedDate, in: logs)
try deleteLogsWithCombinedSizeLargerThan(options.storageSizeLimit, in: logs)
try deleteLogs(dateThreshold: options.oldestAllowedDate, sizeThreshold: options.storageSizeLimit, in: logs)
} catch {
throw Error.rotateLogFiles(error)
}
}

private static func deleteLogsOlderThan(_ dateThreshold: Date, in logs: [LogData]) throws {
private static func deleteLogs(dateThreshold: Date, sizeThreshold: Int, in logs: [LogData]) throws {
let fileManager = FileManager.default

for log in logs where log.creationDate < dateThreshold {
try fileManager.removeItem(at: log.path)
}
}

private static func deleteLogsWithCombinedSizeLargerThan(_ sizeThreshold: Int, in logs: [LogData]) throws {
let fileManager = FileManager.default

// Delete all logs outside maximum capacity (ordered newest to oldest).
var fileSizes = UInt64.zero
for log in logs {
fileSizes += log.size

if fileSizes > sizeThreshold {
let logIsTooOld = log.creationDate < dateThreshold
let logCapacityIsExceeded = fileSizes > sizeThreshold

if logIsTooOld || logCapacityIsExceeded {
try fileManager.removeItem(at: log.path)
}
}
Expand Down
2 changes: 1 addition & 1 deletion ios/MullvadLogging/Logging.swift
Original file line number Diff line number Diff line change
Expand Up @@ -78,7 +78,7 @@ public struct LoggerBuilder {
let rotationLogger = Logger(label: "LogRotation")

for error in logRotationErrors {
rotationLogger.error(error: error, message: "Failed to rotate log")
rotationLogger.error(error: error, message: error.localizedDescription)
}
}
}
Expand Down
8 changes: 8 additions & 0 deletions ios/MullvadVPN.xcodeproj/project.pbxproj
Original file line number Diff line number Diff line change
Expand Up @@ -603,6 +603,8 @@
7ADCB2D82B6A6EB300C88F89 /* AnyRelay.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7ADCB2D72B6A6EB300C88F89 /* AnyRelay.swift */; };
7ADCB2DA2B6A730400C88F89 /* IPOverrideRepositoryStub.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7ADCB2D92B6A730400C88F89 /* IPOverrideRepositoryStub.swift */; };
7AE044BB2A935726003915D8 /* Routing.h in Headers */ = {isa = PBXBuildFile; fileRef = 7A88DCD02A8FABBE00D2FF0E /* Routing.h */; settings = {ATTRIBUTES = (Public, ); }; };
7AED35CC2BD13F60002A67D1 /* ApplicationConfiguration.swift in Sources */ = {isa = PBXBuildFile; fileRef = 58BFA5CB22A7CE1F00A6173D /* ApplicationConfiguration.swift */; };
7AED35CD2BD13FC4002A67D1 /* ApplicationTarget.swift in Sources */ = {isa = PBXBuildFile; fileRef = 58C76A072A33850E00100D75 /* ApplicationTarget.swift */; };
7AEF7F1A2AD00F52006FE45D /* AppMessageHandler.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7AEF7F192AD00F52006FE45D /* AppMessageHandler.swift */; };
7AF10EB22ADE859200C090B9 /* AlertViewController.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7AF10EB12ADE859200C090B9 /* AlertViewController.swift */; };
7AF10EB42ADE85BC00C090B9 /* RelayFilterCoordinator.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7AF10EB32ADE85BC00C090B9 /* RelayFilterCoordinator.swift */; };
Expand Down Expand Up @@ -5584,6 +5586,8 @@
isa = PBXSourcesBuildPhase;
buildActionMask = 2147483647;
files = (
7AED35CC2BD13F60002A67D1 /* ApplicationConfiguration.swift in Sources */,
7AED35CD2BD13FC4002A67D1 /* ApplicationTarget.swift in Sources */,
58D22402294C90050029F5F8 /* Logger+Errors.swift in Sources */,
58D22404294C90050029F5F8 /* Date+LogFormat.swift in Sources */,
58D22403294C90050029F5F8 /* Logging.swift in Sources */,
Expand Down Expand Up @@ -6497,6 +6501,7 @@
PRODUCT_BUNDLE_IDENTIFIER = "$(APPLICATION_IDENTIFIER)";
PRODUCT_NAME = "$(TARGET_NAME)";
SWIFT_OPTIMIZATION_LEVEL = "-Onone";
SWIFT_STRICT_CONCURRENCY = minimal;
SWIFT_VERSION = 5.0;
};
name = Debug;
Expand All @@ -6517,6 +6522,7 @@
);
PRODUCT_BUNDLE_IDENTIFIER = "$(APPLICATION_IDENTIFIER)";
PRODUCT_NAME = "$(TARGET_NAME)";
SWIFT_STRICT_CONCURRENCY = minimal;
SWIFT_VERSION = 5.0;
};
name = Release;
Expand Down Expand Up @@ -7166,6 +7172,7 @@
PRODUCT_NAME = "$(TARGET_NAME)";
"PROVISIONING_PROFILE_SPECIFIER[sdk=iphoneos*]" = "Mullvad VPN Development";
SWIFT_OPTIMIZATION_LEVEL = "-Onone";
SWIFT_STRICT_CONCURRENCY = minimal;
SWIFT_VERSION = 5.0;
};
name = Staging;
Expand Down Expand Up @@ -7778,6 +7785,7 @@
PRODUCT_BUNDLE_IDENTIFIER = "$(APPLICATION_IDENTIFIER)";
PRODUCT_NAME = "$(TARGET_NAME)";
"PROVISIONING_PROFILE_SPECIFIER[sdk=iphoneos*]" = "Mullvad VPN Development";
SWIFT_STRICT_CONCURRENCY = minimal;
SWIFT_VERSION = 5.0;
};
name = MockRelease;
Expand Down
4 changes: 2 additions & 2 deletions ios/MullvadVPN/AddressCacheTracker/AddressCacheTracker.swift
Original file line number Diff line number Diff line change
Expand Up @@ -65,7 +65,7 @@ final class AddressCacheTracker {

let scheduleDate = _nextScheduleDate()

logger.debug("Schedule address cache update at \(scheduleDate.logFormatDate()).")
logger.debug("Schedule address cache update at \(scheduleDate.logFormatted).")

scheduleEndpointsUpdate(startTime: .now() + scheduleDate.timeIntervalSinceNow)
}
Expand Down Expand Up @@ -165,7 +165,7 @@ final class AddressCacheTracker {
let scheduleDate = self._nextScheduleDate()

self.logger
.debug("Schedule next address cache update at \(scheduleDate.logFormatDate()).")
.debug("Schedule next address cache update at \(scheduleDate.logFormatted).")

self.scheduleEndpointsUpdate(startTime: .now() + scheduleDate.timeIntervalSinceNow)
}
Expand Down
6 changes: 3 additions & 3 deletions ios/MullvadVPN/AppDelegate.swift
Original file line number Diff line number Diff line change
Expand Up @@ -307,7 +307,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD
let request = BGAppRefreshTaskRequest(identifier: BackgroundTask.appRefresh.identifier)
request.earliestBeginDate = date

logger.debug("Schedule app refresh task at \(date.logFormatDate()).")
logger.debug("Schedule app refresh task at \(date.logFormatted).")

try BGTaskScheduler.shared.submit(request)
} catch {
Expand All @@ -325,7 +325,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD
request.requiresNetworkConnectivity = true
request.earliestBeginDate = date

logger.debug("Schedule key rotation task at \(date.logFormatDate()).")
logger.debug("Schedule key rotation task at \(date.logFormatted).")

try BGTaskScheduler.shared.submit(request)
} catch {
Expand All @@ -341,7 +341,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate, UNUserNotificationCenterD
request.requiresNetworkConnectivity = true
request.earliestBeginDate = date

logger.debug("Schedule address cache update task at \(date.logFormatDate()).")
logger.debug("Schedule address cache update task at \(date.logFormatted).")

try BGTaskScheduler.shared.submit(request)
} catch {
Expand Down
5 changes: 2 additions & 3 deletions ios/MullvadVPN/Classes/ConsolidatedApplicationLog.swift
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,6 @@

import Foundation

private let kLogMaxReadBytes: UInt64 = 128 * 1024
private let kLogDelimiter = "===================="
private let kRedactedPlaceholder = "[REDACTED]"
private let kRedactedAccountPlaceholder = "[REDACTED ACCOUNT NUMBER]"
Expand Down Expand Up @@ -93,7 +92,7 @@ class ConsolidatedApplicationLog: TextOutputStreamable {
let path = fileURL.path
let redactedPath = redact(string: path)

if let lossyString = Self.readFileLossy(path: path, maxBytes: kLogMaxReadBytes) {
if let lossyString = Self.readFileLossy(path: path, maxBytes: ApplicationConfiguration.logMaximumFileSize) {
let redactedString = redact(string: lossyString)

logs.append(LogAttachment(label: redactedPath, content: redactedString))
Expand Down Expand Up @@ -126,7 +125,7 @@ class ConsolidatedApplicationLog: TextOutputStreamable {
fileHandle.seek(toFileOffset: 0)
}

let data = fileHandle.readData(ofLength: Int(kLogMaxReadBytes))
let data = fileHandle.readData(ofLength: Int(ApplicationConfiguration.logMaximumFileSize))
let replacementCharacter = Character(UTF8.decode(UTF8.encodedReplacementCharacter))
let lossyString = String(
String(decoding: data, as: UTF8.self)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -140,7 +140,7 @@ class SendStoreReceiptOperation: ResultOperation<REST.CreateApplePaymentResponse
"""
AppStore receipt was processed. \
Time added: \(response.timeAdded), \
New expiry: \(response.newExpiry.logFormatDate())
New expiry: \(response.newExpiry.logFormatted)
"""
)
self.finish(result: .success(response))
Expand Down
2 changes: 1 addition & 1 deletion ios/MullvadVPN/TunnelManager/TunnelManager.swift
Original file line number Diff line number Diff line change
Expand Up @@ -172,7 +172,7 @@ final class TunnelManager: StorePaymentObserver {

privateKeyRotationTimer = timer

logger.debug("Schedule next private key rotation at \(scheduleDate.logFormatDate()).")
logger.debug("Schedule next private key rotation at \(scheduleDate.logFormatted).")
}

// MARK: - Public methods
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -30,6 +30,10 @@ final class ProblemReportInteractor {
return report
}()

var reportString: String {
consolidatedLog.string
}

init(apiProxy: APIQuerying, tunnelManager: TunnelManager) {
self.apiProxy = apiProxy
self.tunnelManager = tunnelManager
Expand All @@ -55,8 +59,4 @@ final class ProblemReportInteractor {
completionHandler: completion
)
}

var reportString: String {
consolidatedLog.string
}
}
Loading

0 comments on commit ee04640

Please sign in to comment.