impr: Add timeIntervalSince1970 to SDK log messages

CHANGELOG.md

@@ -10,6 +10,7 @@
 
 - Add more debug logs for SentryViewHierarchy (#4780)
 - Add `sample_rand` to baggage (#4751)
+- Add uptime to log messages (#4781)
 
 ## Fixes
 

Sources/Swift/Tools/SentryLog.swift

@@ -13,6 +13,7 @@ class SentryLog: NSObject {
     static let alwaysLevel = SentryLevel.fatal
     private static var logOutput = SentryLogOutput()
     private static var logConfigureLock = NSLock()
+    private static var dateProvider: SentryCurrentDateProvider = SentryDefaultCurrentDateProvider()
 
     @objc
     static func configure(_ isDebug: Bool, diagnosticLevel: SentryLevel) {
@@ -26,7 +27,14 @@ class SentryLog: NSObject {
     @objc
     static func log(message: String, andLevel level: SentryLevel) {
         guard willLog(atLevel: level) else { return }
-        logOutput.log("[Sentry] [\(level)] \(message)")
+
+        // We use the uptime because it's guaranteed to be linear even when the
+        // date time changes. Furthermore, initializing date objects and using the
+        // date format adds some overhead. The uptime shows the time difference
+        // between the logs. If we ever need the actual date and time, we can
+        // reconsider.
+        let uptime = nanosecondsToTimeInterval(self.dateProvider.systemTime())
+        logOutput.log("[Sentry] [\(level)] [uptime:\(uptime)] \(message)")
     }
 
     /**
@@ -54,6 +62,10 @@ class SentryLog: NSObject {
         return logOutput
     }
 
+    static func setDateProvider(_ dateProvider: SentryCurrentDateProvider) {
+        self.dateProvider = dateProvider
+    }
+
     #endif
 }
 

Tests/SentryTests/Helper/SentryLog.swift

@@ -21,4 +21,10 @@ extension Sentry.SentryLog {
         SentryLogOutput()
         #endif
     }
+
+    static func setCurrentDateProvider(_ dateProvider: SentryCurrentDateProvider) {
+        #if SENTRY_TEST || SENTRY_TEST_CI
+        SentryLog.setDateProvider(dateProvider)
+        #endif
+    }
 }

Tests/SentryTests/Helper/SentryLogTests.swift

@@ -6,18 +6,24 @@ class SentryLogTests: XCTestCase {
     private var oldDebug: Bool!
     private var oldLevel: SentryLevel!
     private var oldOutput: SentryLogOutput!
+    private let systemUptime: TimeInterval = 0.1234
 
     override func setUp() {
         super.setUp()
         oldDebug = SentryLog.isDebug
         oldLevel = SentryLog.diagnosticLevel
         oldOutput = SentryLog.getLogOutput()
+
+        let currentDateProvider = TestCurrentDateProvider()
+        currentDateProvider.advance(by: systemUptime)
+        SentryLog.setCurrentDateProvider(currentDateProvider)
     }
 
     override func tearDown() {
         super.tearDown()
         SentryLog.configure(oldDebug, diagnosticLevel: oldLevel)
         SentryLog.setLogOutput(oldOutput)
+        SentryLog.setCurrentDateProvider(SentryDefaultCurrentDateProvider())
     }
 
     func testDefault_PrintsFatalAndError() {
@@ -30,7 +36,7 @@ class SentryLogTests: XCTestCase {
         SentryLog.log(message: "2", andLevel: SentryLevel.warning)
         SentryLog.log(message: "3", andLevel: SentryLevel.none)
 
-        XCTAssertEqual(["[Sentry] [fatal] 0", "[Sentry] [error] 1"], logOutput.loggedMessages)
+        XCTAssertEqual(["[Sentry] [fatal] [uptime:\(systemUptime)] 0", "[Sentry] [error] [uptime:\(systemUptime)] 1"], logOutput.loggedMessages)
     }
 
     func testDefaultInitOfLogoutPut() {
@@ -53,7 +59,7 @@ class SentryLogTests: XCTestCase {
 
         // -- Assert --
         XCTAssertEqual(1, logOutput.loggedMessages.count)
-        XCTAssertEqual("[Sentry] [fatal] fatal", logOutput.loggedMessages.first)
+        XCTAssertEqual("[Sentry] [fatal] [uptime:\(systemUptime)] fatal", logOutput.loggedMessages.first)
     }
 
     func testLevelNone_PrintsEverythingExceptNone() {
@@ -68,11 +74,11 @@ class SentryLogTests: XCTestCase {
         SentryLog.log(message: "4", andLevel: SentryLevel.debug)
         SentryLog.log(message: "5", andLevel: SentryLevel.none)
 
-        XCTAssertEqual(["[Sentry] [fatal] 0",
-                        "[Sentry] [error] 1",
-                        "[Sentry] [warning] 2",
-                        "[Sentry] [info] 3",
-                        "[Sentry] [debug] 4"], logOutput.loggedMessages)
+        XCTAssertEqual(["[Sentry] [fatal] [uptime:\(systemUptime)] 0",
+                        "[Sentry] [error] [uptime:\(systemUptime)] 1",
+                        "[Sentry] [warning] [uptime:\(systemUptime)] 2",
+                        "[Sentry] [info] [uptime:\(systemUptime)] 3",
+                        "[Sentry] [debug] [uptime:\(systemUptime)] 4"], logOutput.loggedMessages)
     }
 
     func testMacroLogsErrorMessage() {
@@ -82,7 +88,7 @@ class SentryLogTests: XCTestCase {
 
         sentryLogErrorWithMacro("error")
 
-        XCTAssertEqual(["[Sentry] [error] [SentryLogTestHelper:21] error"], logOutput.loggedMessages)
+        XCTAssertEqual(["[Sentry] [error] [uptime:\(systemUptime)] [SentryLogTestHelper:21] error"], logOutput.loggedMessages)
     }
 
     func testMacroDoesNotEvaluateArgs_WhenNotMessageNotLogged() {
@@ -101,7 +107,7 @@ class SentryLogTests: XCTestCase {
         SentryLog.configure(true, diagnosticLevel: SentryLevel.debug)
         let line = #line + 1
         SentryLog.debug("Debug Log")
-        XCTAssertEqual(["[Sentry] [debug] [SentryLogTests:\(line)] Debug Log"], logOutput.loggedMessages)
+        XCTAssertEqual(["[Sentry] [debug] [uptime:\(systemUptime)] [SentryLogTests:\(line)] Debug Log"], logOutput.loggedMessages)
     }
 
 }