Use mach_continuous_time() for calculating uptime (#708)

Author: kstenerud

platform/swift/source/shared/Uptime.swift

@@ -7,39 +7,22 @@
 
 import Foundation
 
+/// High resolution wall clock that continues ticking through device sleep and is unaffected by clock adjustments.
 struct Uptime {
-    private let uptime: TimeInterval
+    private static let timebase: mach_timebase_info_data_t = getTimebase()
 
-    /// Returns a high-resolution measurement of system uptime, that continues ticking through device sleep
-    /// *and* user- or system-generated clock adjustments. This allows for stable differences to be calculated
-    /// between timestamps.
-    ///
-    /// - returns: Expressed in seconds measurement of system uptime.
-    static func get() -> TimeInterval {
-        var mib: [Int32] = [CTL_KERN, KERN_BOOTTIME]
-        var size: size_t = MemoryLayout<timeval>.stride
-
-        var now = timeval()
-        let systemTimeError = gettimeofday(&now, nil) != 0
-        assert(!systemTimeError, "timing: system time unavailable")
-
-        var bootTime = timeval()
-        let bootTimeError = sysctl(&mib, 2, &bootTime, &size, nil, 0) != 0 || bootTime.tv_sec == 0
-        assert(!bootTimeError, "timing: kernel boot time unavailable")
-
-        let seconds = Double(now.tv_sec - bootTime.tv_sec)
-        assert(seconds >= 0, "timing: system time precedes boot time")
-
-        let microseconds = Double(now.tv_usec - bootTime.tv_usec)
-
-        return seconds + microseconds / 1_000_000
+    private static func getTimebase() -> mach_timebase_info_data_t {
+        var timebase: mach_timebase_info_data_t = mach_timebase_info_data_t()
+        let timebaseError = mach_timebase_info(&timebase) != KERN_SUCCESS
+        assert(!timebaseError, "Uptime: could not get timebase")
+        return timebase
     }
 
-    /// Captures the current uptime.
-    ///
-    /// - parameter uptime: The uptime.
-    init(uptime: TimeInterval = Uptime.get()) {
-        self.uptime = uptime
+    private let startTime: UInt64 = mach_continuous_time()
+
+    private func ticksToSeconds(_ ticks: UInt64) -> TimeInterval {
+        let elapsedNanos = ticks * UInt64(Uptime.timebase.numer) / UInt64(Uptime.timebase.denom)
+        return TimeInterval(elapsedNanos) / 1_000_000_000.0
     }
 
     /// Calculates the duration of time that passed between now and the provided timing.
@@ -48,6 +31,6 @@ struct Uptime {
     ///
     /// - returns: The duration of time.
     func timeIntervalSince(_ uptime: Uptime) -> TimeInterval {
-        return self.uptime - uptime.uptime
+        return ticksToSeconds(mach_continuous_time() - uptime.startTime)
     }
 }

test/platform/swift/unit_integration/core/logging/SpanTests.swift

@@ -11,6 +11,9 @@ import Foundation
 import XCTest
 
 final class SpanTests: XCTestCase {
+    // We need to allow a fair bit of variance due to potential CI load affecting the simulator
+    private let allowedTimeVarianceSeconds: TimeInterval = 0.200
+
     private func createSpan(logger: MockCoreLogging, timeProvider: TimeProvider = MockTimeProvider(),
                             start: TimeInterval? = nil, parent: UUID? = nil) -> Span
     {
@@ -31,6 +34,14 @@ final class SpanTests: XCTestCase {
         )
     }
 
+    private func assertTimeWithinRange(timeStringMS: String, intervalInSeconds: TimeInterval) {
+        let time = Double(timeStringMS)! / 1000.0
+        let minValue = (intervalInSeconds - allowedTimeVarianceSeconds) < 0 ? 0 : intervalInSeconds - allowedTimeVarianceSeconds
+        let maxValue = intervalInSeconds + allowedTimeVarianceSeconds
+        XCTAssertGreaterThanOrEqual(time, minValue)
+        XCTAssertLessThanOrEqual(time, maxValue)
+    }
+
     func testStartEndSpan() throws {
         let timeProvider = MockTimeProvider()
         let logger = MockCoreLogging()
@@ -50,7 +61,7 @@ final class SpanTests: XCTestCase {
                 "test_key": "test_value",
             ], emittedStartFields as? [String: String])
 
-            timeProvider.advanceBy(timeInterval: 1.0)
+            Thread.sleep(forTimeInterval: 1.0)
 
             span.end(
                 .success,
@@ -62,9 +73,10 @@ final class SpanTests: XCTestCase {
             XCTAssertEqual(2, logger.logs.count)
             let endLog = logger.logs[1]
 
-            let emittedEndFields = endLog.fields
+            var emittedEndFields = endLog.fields
+            assertTimeWithinRange(timeStringMS: emittedEndFields!["_duration_ms"] as! String, intervalInSeconds: 1.0)
+            emittedEndFields?.removeValue(forKey: "_duration_ms")
             XCTAssertEqual([
-                "_duration_ms": "1000.0",
                 "_span_id": span.id.uuidString,
                 "_span_type": "end",
                 "_span_name": "test",
@@ -84,16 +96,16 @@ final class SpanTests: XCTestCase {
         // ended manually and is deinited.
         let spanID: String = {
             let span = self.createSpan(logger: logger, timeProvider: timeProvider)
-            timeProvider.advanceBy(timeInterval: 1.0)
             return span.id.uuidString
         }()
 
         XCTAssertEqual(2, logger.logs.count)
         let endLog = logger.logs[1]
 
-        let emittedEndFields = endLog.fields
+        var emittedEndFields = endLog.fields
+        assertTimeWithinRange(timeStringMS: emittedEndFields!["_duration_ms"] as! String, intervalInSeconds: 0.0)
+        emittedEndFields?.removeValue(forKey: "_duration_ms")
         XCTAssertEqual([
-            "_duration_ms": "1000.0",
             "_span_id": spanID,
             "_span_type": "end",
             "_span_name": "test",
@@ -135,21 +147,21 @@ final class SpanTests: XCTestCase {
         // Test start with no end
         let timeProvider = MockTimeProvider()
         let spanOnlyStart = self.createSpan(logger: logger, timeProvider: timeProvider, start: 0)
-        timeProvider.advanceBy(timeInterval: 1337)
+        Thread.sleep(forTimeInterval: 1.0)
         spanOnlyStart.end(.success)
 
         XCTAssertEqual(4, logger.logs.count)
-        XCTAssertEqual("1337000.0", try XCTUnwrap(logger.logs[3].fields?["_duration_ms"] as? String))
+        assertTimeWithinRange(timeStringMS: (logger.logs[3].fields?["_duration_ms"] as? String)!, intervalInSeconds: 1.0)
         XCTAssertEqual(Date(timeIntervalSince1970: 0), logger.logs[2].occurredAtOverride)
         XCTAssertEqual(nil, logger.logs[3].occurredAtOverride)
 
         // Test end with no start
         let spanOnlyEnd = self.createSpan(logger: logger, timeProvider: timeProvider)
-        timeProvider.advanceBy(timeInterval: 1338)
+        Thread.sleep(forTimeInterval: 1.0)
         spanOnlyEnd.end(.success, endTimeInterval: 666)
 
         XCTAssertEqual(6, logger.logs.count)
-        XCTAssertEqual("1338000.0", try XCTUnwrap(logger.logs[5].fields?["_duration_ms"] as? String))
+        assertTimeWithinRange(timeStringMS: (logger.logs[5].fields?["_duration_ms"] as? String)!, intervalInSeconds: 1.0)
         XCTAssertEqual(nil, logger.logs[4].occurredAtOverride)
         XCTAssertEqual(Date(timeIntervalSince1970: 666), logger.logs[5].occurredAtOverride)
     }

test/platform/swift/unit_integration/mocks/MockTimingProvider.swift

@@ -21,7 +21,7 @@ public final class MockTimeProvider {
 }
 
 extension MockTimeProvider: TimeProvider {
-    public func uptime() -> Uptime { Uptime(uptime: self.timeIntervalSince1970) }
+    public func uptime() -> Uptime { Uptime() }
 
     public func now() -> Date { Date(timeIntervalSince1970: self.timeIntervalSince1970) }
 }