Swift pthread read/write lock taking a while to release the lock

I am trying to implement a read/write lock in Swift with the pthread API's and I have come across a strange issue.

My implementation is largely based on the following with the addition of a timeout for attempted read locks.

http://swiftweb.johnholdsworth.com/Deferred/html/ReadWriteLock.html

Here is my implementation:

 public final class ReadWriteLock {

        private var lock = pthread_rwlock_t()

        public init() {
            let status = pthread_rwlock_init(&lock, nil)
            assert(status == 0)
        }

        deinit {
            let status = pthread_rwlock_destroy(&lock)
            assert(status == 0)
        }

        @discardableResult
        public func withReadLock<Result>(_ body: () throws -> Result) rethrows -> Result {
            pthread_rwlock_rdlock(&lock)
            defer { pthread_rwlock_unlock(&lock) }
            return try body()
        }

        @discardableResult
        public func withAttemptedReadLock<Result>(_ body: () throws -> Result) rethrows -> Result? {
            guard pthread_rwlock_tryrdlock(&lock) == 0 else { return nil }
            defer { pthread_rwlock_unlock(&lock) }
            return try body()
        }

        @discardableResult
        public func withAttemptedReadLock<Result>(_ timeout: Timeout = .now, body: () throws -> Result) rethrows -> Result? {
            guard timeout != .now else { return try withAttemptedReadLock(body) }

            let expiry = DispatchTime.now().uptimeNanoseconds + timeout.rawValue.uptimeNanoseconds
            var ts = Timeout.interval(1).timespec
            var result: Int32
            repeat {
                result = pthread_rwlock_tryrdlock(&lock)
                guard result != 0 else { break }
                nanosleep(&ts, nil)
            } while DispatchTime.now().uptimeNanoseconds < expiry

            // If the lock was not acquired
            if result != 0 {
                // Try to grab the lock once more
                result = pthread_rwlock_tryrdlock(&lock)
            }
            guard result == 0 else { return nil }
            defer { pthread_rwlock_unlock(&lock) }
            return try body()
        }

        @discardableResult
        public func withWriteLock<Return>(_ body: () throws -> Return) rethrows -> Return {
            pthread_rwlock_wrlock(&lock)
            defer { pthread_rwlock_unlock(&lock) }
            return try body()
        }
    }

/// An amount of time to wait for an event.
public enum Timeout {
    /// Do not wait at all.
    case now
    /// Wait indefinitely.
    case forever
    /// Wait for a given number of seconds.
    case interval(UInt64)
}

public extension Timeout {

    public var timespec: timespec {
        let nano = rawValue.uptimeNanoseconds
        return Darwin.timespec(tv_sec: Int(nano / NSEC_PER_SEC), tv_nsec: Int(nano % NSEC_PER_SEC))
    }

    public var rawValue: DispatchTime {
        switch self {
            case .now:
                return DispatchTime.now()
            case .forever:
                return DispatchTime.distantFuture
            case .interval(let milliseconds):
                return DispatchTime(uptimeNanoseconds: milliseconds * NSEC_PER_MSEC)
        }
    }
}

extension Timeout : Equatable { }

public func ==(lhs: Timeout, rhs: Timeout) -> Bool {
    switch (lhs, rhs) {
        case (.now, .now):
            return true
        case (.forever, .forever):
            return true
        case (let .interval(ms1), let .interval(ms2)):
            return ms1 == ms2
        default:
            return false
    }
}

Here is my unit test:

func testReadWrite() {
    let rwLock = PThreadReadWriteLock()
    let queue = OperationQueue()
    queue.maxConcurrentOperationCount = 2
    queue.qualityOfService = .userInteractive
    queue.isSuspended = true

    var enterWrite: Double = 0
    var exitWrite: Double = 0
    let writeWait: UInt64 = 500
    // Get write lock
    queue.addOperation {
        enterWrite = Double(Timeout.now.rawValue.uptimeNanoseconds) / Double(NSEC_PER_MSEC)
        rwLock.withWriteLock {
            // Sleep for 1 second
            var ts = Timeout.interval(writeWait).timespec
            var result: Int32
            repeat { result = nanosleep(&ts, &ts) } while result == -1
        }
        exitWrite = Double(Timeout.now.rawValue.uptimeNanoseconds) / Double(NSEC_PER_MSEC)
    }

    var entered = false
    var enterRead: Double = 0
    var exitRead: Double = 0
    let readWait = writeWait + 50
    // Get read lock
    queue.addOperation {
        enterRead = Double(Timeout.now.rawValue.uptimeNanoseconds) / Double(NSEC_PER_MSEC)
        rwLock.withAttemptedReadLock(.interval(readWait)) {
            print("**** Entered! ****")
            entered = true
        }
        exitRead = Double(Timeout.now.rawValue.uptimeNanoseconds) / Double(NSEC_PER_MSEC)
    }

    queue.isSuspended = false
    queue.waitUntilAllOperationsAreFinished()

    let startDifference = abs(enterWrite - enterRead)
    let totalWriteTime = abs(exitWrite - enterWrite)
    let totalReadTime = abs(exitRead - enterRead)
    print("Start Difference: \(startDifference)")
    print("Total Write Time: \(totalWriteTime)")
    print("Total Read Time: \(totalReadTime)")

    XCTAssert(totalWriteTime >= Double(writeWait))
    XCTAssert(totalReadTime >= Double(readWait))
    XCTAssert(totalReadTime >= totalWriteTime)
    XCTAssert(entered)
}

Finally, the output of my unit test is the following:

Start Difference: 0.00136399269104004
Total Write Time: 571.76081609726
Total Read Time: 554.105705976486

Of course, the test is failing because the write lock is not released in time. Given that my wait time is only half a second (500ms), why is it taking roughly 570ms for the write lock to execute and release?

I have tried executing with optimizations both on and off to no avail.

I was under the impression that nanosleep is high resolution sleep timer I would expect to have a resolution of at least 5-10 milliseconds here for the lock timeout.

Can anyone shed some light here?

Turns out foundation was performing some kind of optimization with the OperationQueue due to the long sleep in my unit test.

Replacing the sleep function with usleep and iterating with a 1ms sleep until the total time is exceed seems to have fixed the problem.

    // Get write lock
    queue.addOperation {
        enterWrite = Double(Timeout.now.rawValue.uptimeNanoseconds) / Double(NSEC_PER_MSEC)
        rwLock.withWriteLock {
            let expiry = DispatchTime.now().uptimeNanoseconds + Timeout.interval(writeWait).rawValue.uptimeNanoseconds
            let interval = Timeout.interval(1)
            repeat {
                interval.sleep()
            } while DispatchTime.now().uptimeNanoseconds < expiry
        }
        exitWrite = Double(Timeout.now.rawValue.uptimeNanoseconds) / Double(NSEC_PER_MSEC)
    }