diff --git a/bitchat/Noise/NoiseHandshakeCoordinator.swift b/bitchat/Noise/NoiseHandshakeCoordinator.swift new file mode 100644 index 00000000..5a2d5d9d --- /dev/null +++ b/bitchat/Noise/NoiseHandshakeCoordinator.swift @@ -0,0 +1,257 @@ +// +// NoiseHandshakeCoordinator.swift +// bitchat +// +// This is free and unencumbered software released into the public domain. +// For more information, see +// + +import Foundation + +/// Coordinates Noise handshakes to prevent race conditions and ensure reliable encryption establishment +class NoiseHandshakeCoordinator { + + // MARK: - Handshake State + + enum HandshakeState: Equatable { + case idle + case waitingToInitiate(since: Date) + case initiating(attempt: Int, lastAttempt: Date) + case responding + case waitingForResponse(messagesSent: [Data], timeout: Date) + case established(since: Date) + case failed(reason: String, canRetry: Bool, lastAttempt: Date) + + var isActive: Bool { + switch self { + case .idle, .established, .failed: + return false + default: + return true + } + } + } + + // MARK: - Properties + + private var handshakeStates: [String: HandshakeState] = [:] + private var handshakeQueue = DispatchQueue(label: "chat.bitchat.noise.handshake", attributes: .concurrent) + + // Configuration + private let maxHandshakeAttempts = 3 + private let handshakeTimeout: TimeInterval = 10.0 + private let retryDelay: TimeInterval = 2.0 + private let minTimeBetweenHandshakes: TimeInterval = 1.0 // Reduced from 5.0 for faster recovery + + // Track handshake messages to detect duplicates + private var processedHandshakeMessages: Set = [] + private let messageHistoryLimit = 100 + + // MARK: - Role Determination + + /// Deterministically determine who should initiate the handshake + /// Lower peer ID becomes the initiator to prevent simultaneous attempts + func determineHandshakeRole(myPeerID: String, remotePeerID: String) -> NoiseRole { + // Use simple string comparison for deterministic ordering + return myPeerID < remotePeerID ? .initiator : .responder + } + + /// Check if we should initiate handshake with a peer + func shouldInitiateHandshake(myPeerID: String, remotePeerID: String) -> Bool { + return handshakeQueue.sync { + // Check if we're already in an active handshake + if let state = handshakeStates[remotePeerID], state.isActive { + SecureLogger.log("Already in active handshake with \(remotePeerID), state: \(state)", + category: SecureLogger.handshake, level: .debug) + return false + } + + // Check role + let role = determineHandshakeRole(myPeerID: myPeerID, remotePeerID: remotePeerID) + if role != .initiator { + SecureLogger.log("Not initiator for handshake with \(remotePeerID) (my: \(myPeerID), their: \(remotePeerID))", + category: SecureLogger.handshake, level: .debug) + return false + } + + // Check if we've failed recently and can't retry yet + if case .failed(_, let canRetry, let lastAttempt) = handshakeStates[remotePeerID] { + if !canRetry { + return false + } + if Date().timeIntervalSince(lastAttempt) < retryDelay { + return false + } + } + + return true + } + } + + /// Record that we're initiating a handshake + func recordHandshakeInitiation(peerID: String) { + handshakeQueue.async(flags: .barrier) { + let attempt = self.getCurrentAttempt(for: peerID) + 1 + self.handshakeStates[peerID] = .initiating(attempt: attempt, lastAttempt: Date()) + SecureLogger.log("Recording handshake initiation with \(peerID), attempt \(attempt)", + category: SecureLogger.handshake, level: .info) + } + } + + /// Record that we're responding to a handshake + func recordHandshakeResponse(peerID: String) { + handshakeQueue.async(flags: .barrier) { + self.handshakeStates[peerID] = .responding + SecureLogger.log("Recording handshake response to \(peerID)", + category: SecureLogger.handshake, level: .info) + } + } + + /// Record successful handshake completion + func recordHandshakeSuccess(peerID: String) { + handshakeQueue.async(flags: .barrier) { + self.handshakeStates[peerID] = .established(since: Date()) + SecureLogger.log("Handshake successfully established with \(peerID)", + category: SecureLogger.handshake, level: .info) + } + } + + /// Record handshake failure + func recordHandshakeFailure(peerID: String, reason: String) { + handshakeQueue.async(flags: .barrier) { + let attempts = self.getCurrentAttempt(for: peerID) + let canRetry = attempts < self.maxHandshakeAttempts + self.handshakeStates[peerID] = .failed(reason: reason, canRetry: canRetry, lastAttempt: Date()) + SecureLogger.log("Handshake failed with \(peerID): \(reason), canRetry: \(canRetry)", + category: SecureLogger.handshake, level: .warning) + } + } + + /// Check if we should accept an incoming handshake initiation + func shouldAcceptHandshakeInitiation(myPeerID: String, remotePeerID: String) -> Bool { + return handshakeQueue.sync { + // If we're already established, reject new handshakes + if case .established = handshakeStates[remotePeerID] { + SecureLogger.log("Rejecting handshake from \(remotePeerID) - already established", + category: SecureLogger.handshake, level: .debug) + return false + } + + let role = determineHandshakeRole(myPeerID: myPeerID, remotePeerID: remotePeerID) + + // If we're the initiator and already initiating, this is a race condition + if role == .initiator { + if case .initiating = handshakeStates[remotePeerID] { + // They shouldn't be initiating, but accept it to recover from race condition + SecureLogger.log("Accepting handshake from \(remotePeerID) despite being initiator (race condition recovery)", + category: SecureLogger.handshake, level: .warning) + return true + } + } + + // If we're the responder, we should accept + return true + } + } + + /// Check if this is a duplicate handshake message + func isDuplicateHandshakeMessage(_ data: Data) -> Bool { + return handshakeQueue.sync { + if processedHandshakeMessages.contains(data) { + return true + } + + // Add to processed messages with size limit + if processedHandshakeMessages.count >= messageHistoryLimit { + processedHandshakeMessages.removeAll() + } + processedHandshakeMessages.insert(data) + return false + } + } + + /// Get time to wait before next handshake attempt + func getRetryDelay(for peerID: String) -> TimeInterval? { + return handshakeQueue.sync { + guard let state = handshakeStates[peerID] else { return nil } + + switch state { + case .failed(_, let canRetry, let lastAttempt): + if !canRetry { return nil } + let timeSinceFailure = Date().timeIntervalSince(lastAttempt) + if timeSinceFailure >= retryDelay { + return 0 + } + return retryDelay - timeSinceFailure + + case .initiating(_, let lastAttempt): + let timeSinceAttempt = Date().timeIntervalSince(lastAttempt) + if timeSinceAttempt >= minTimeBetweenHandshakes { + return 0 + } + return minTimeBetweenHandshakes - timeSinceAttempt + + default: + return nil + } + } + } + + /// Reset handshake state for a peer + func resetHandshakeState(for peerID: String) { + handshakeQueue.async(flags: .barrier) { + self.handshakeStates.removeValue(forKey: peerID) + SecureLogger.log("Reset handshake state for \(peerID)", + category: SecureLogger.handshake, level: .debug) + } + } + + /// Get current handshake state + func getHandshakeState(for peerID: String) -> HandshakeState { + return handshakeQueue.sync { + return handshakeStates[peerID] ?? .idle + } + } + + // MARK: - Private Helpers + + private func getCurrentAttempt(for peerID: String) -> Int { + switch handshakeStates[peerID] { + case .initiating(let attempt, _): + return attempt + case .failed(_, _, _): + // Count previous attempts + return 1 // Simplified for now + default: + return 0 + } + } + + /// Log current handshake states for debugging + func logHandshakeStates() { + handshakeQueue.sync { + SecureLogger.log("=== Handshake States ===", category: SecureLogger.handshake, level: .debug) + for (peerID, state) in handshakeStates { + let stateDesc: String + switch state { + case .idle: + stateDesc = "idle" + case .waitingToInitiate(let since): + stateDesc = "waiting to initiate (since \(since))" + case .initiating(let attempt, let lastAttempt): + stateDesc = "initiating (attempt \(attempt), last: \(lastAttempt))" + case .responding: + stateDesc = "responding" + case .waitingForResponse(let messages, let timeout): + stateDesc = "waiting for response (\(messages.count) messages, timeout: \(timeout))" + case .established(let since): + stateDesc = "established (since \(since))" + case .failed(let reason, let canRetry, let lastAttempt): + stateDesc = "failed: \(reason) (canRetry: \(canRetry), last: \(lastAttempt))" + } + SecureLogger.log(" \(peerID): \(stateDesc)", category: SecureLogger.handshake, level: .debug) + } + SecureLogger.log("========================", category: SecureLogger.handshake, level: .debug) + } + } +} \ No newline at end of file diff --git a/bitchat/Services/BluetoothMeshService.swift b/bitchat/Services/BluetoothMeshService.swift index 1c5639ef..3b20d30e 100644 --- a/bitchat/Services/BluetoothMeshService.swift +++ b/bitchat/Services/BluetoothMeshService.swift @@ -68,6 +68,7 @@ class BluetoothMeshService: NSObject { weak var delegate: BitchatDelegate? private let noiseService = NoiseEncryptionService() + private let handshakeCoordinator = NoiseHandshakeCoordinator() // Protocol version negotiation state private var versionNegotiationState: [String: VersionNegotiationState] = [:] @@ -519,6 +520,13 @@ class BluetoothMeshService: NSObject { self?.cleanupStalePeers() } + // Log handshake states periodically for debugging + #if DEBUG + Timer.scheduledTimer(withTimeInterval: 30.0, repeats: true) { [weak self] _ in + self?.handshakeCoordinator.logHandshakeStates() + } + #endif + // Schedule first peer ID rotation scheduleNextRotation() @@ -3276,16 +3284,27 @@ extension BluetoothMeshService: CBPeripheralManagerDelegate { SecureLogger.log("Already have established session with \(peerID)", category: SecureLogger.noise, level: .debug) // Clear any lingering handshake attempt time handshakeAttemptTimes.removeValue(forKey: peerID) + handshakeCoordinator.recordHandshakeSuccess(peerID: peerID) return } - // Check if we've recently tried to handshake with this peer - if let lastAttempt = handshakeAttemptTimes[peerID], - Date().timeIntervalSince(lastAttempt) < handshakeTimeout { - SecureLogger.log("Skipping handshake with \(peerID) - too recent", category: SecureLogger.noise, level: .debug) + // Check with coordinator if we should initiate + if !handshakeCoordinator.shouldInitiateHandshake(myPeerID: myPeerID, remotePeerID: peerID) { + SecureLogger.log("Coordinator says we should not initiate handshake with \(peerID)", category: SecureLogger.handshake, level: .debug) return } + // Check if there's a retry delay + if let retryDelay = handshakeCoordinator.getRetryDelay(for: peerID), retryDelay > 0 { + SecureLogger.log("Waiting \(retryDelay)s before retrying handshake with \(peerID)", category: SecureLogger.handshake, level: .debug) + DispatchQueue.main.asyncAfter(deadline: .now() + retryDelay) { [weak self] in + self?.initiateNoiseHandshake(with: peerID) + } + return + } + + // Record that we're initiating + handshakeCoordinator.recordHandshakeInitiation(peerID: peerID) handshakeAttemptTimes[peerID] = Date() @@ -3310,8 +3329,11 @@ extension BluetoothMeshService: CBPeripheralManagerDelegate { } catch NoiseSessionError.alreadyEstablished { // Session already established, no need to handshake + handshakeCoordinator.recordHandshakeSuccess(peerID: peerID) } catch { - // Failed to initiate handshake silently + // Failed to initiate handshake + handshakeCoordinator.recordHandshakeFailure(peerID: peerID, reason: error.localizedDescription) + SecureLogger.logSecurityEvent(.handshakeFailed(peerID: peerID, error: error.localizedDescription)) } } @@ -3319,6 +3341,22 @@ extension BluetoothMeshService: CBPeripheralManagerDelegate { // Use noiseService directly SecureLogger.logHandshake("processing \(isInitiation ? "init" : "response")", peerID: peerID, success: true) + // Check for duplicate handshake messages + if handshakeCoordinator.isDuplicateHandshakeMessage(message) { + SecureLogger.log("Duplicate handshake message from \(peerID), ignoring", category: SecureLogger.handshake, level: .debug) + return + } + + // If this is an initiation, check if we should accept it + if isInitiation { + if !handshakeCoordinator.shouldAcceptHandshakeInitiation(myPeerID: myPeerID, remotePeerID: peerID) { + SecureLogger.log("Coordinator says we should not accept handshake from \(peerID)", category: SecureLogger.handshake, level: .debug) + return + } + // Record that we're responding + handshakeCoordinator.recordHandshakeResponse(peerID: peerID) + } + do { // Process handshake message if let response = try noiseService.processHandshakeMessage(from: peerID, message: message) { @@ -3346,6 +3384,7 @@ extension BluetoothMeshService: CBPeripheralManagerDelegate { unlockRotation() // Session established successfully + handshakeCoordinator.recordHandshakeSuccess(peerID: peerID) // Clear handshake attempt time on success handshakeAttemptTimes.removeValue(forKey: peerID) @@ -3372,8 +3411,11 @@ extension BluetoothMeshService: CBPeripheralManagerDelegate { } catch NoiseSessionError.alreadyEstablished { // Session already established, ignore handshake SecureLogger.log("Handshake already established with \(peerID)", category: SecureLogger.noise, level: .info) + handshakeCoordinator.recordHandshakeSuccess(peerID: peerID) } catch { // Handshake failed + handshakeCoordinator.recordHandshakeFailure(peerID: peerID, reason: error.localizedDescription) + SecureLogger.logSecurityEvent(.handshakeFailed(peerID: peerID, error: error.localizedDescription)) SecureLogger.log("Handshake failed with \(peerID): \(error)", category: SecureLogger.noise, level: .error) } } @@ -3581,6 +3623,7 @@ extension BluetoothMeshService: CBPeripheralManagerDelegate { // Clean up any Noise session noiseService.removePeer(peerID) + handshakeCoordinator.resetHandshakeState(for: peerID) // Notify delegate about incompatible peer disconnection DispatchQueue.main.async { [weak self] in diff --git a/bitchat/Utils/SecureLogger.swift b/bitchat/Utils/SecureLogger.swift index 54deb50c..6938b78e 100644 --- a/bitchat/Utils/SecureLogger.swift +++ b/bitchat/Utils/SecureLogger.swift @@ -22,6 +22,16 @@ class SecureLogger { static let keychain = OSLog(subsystem: subsystem, category: "keychain") static let session = OSLog(subsystem: subsystem, category: "session") static let security = OSLog(subsystem: subsystem, category: "security") + static let handshake = OSLog(subsystem: subsystem, category: "handshake") + + // MARK: - Timestamp Formatter + + private static let timestampFormatter: DateFormatter = { + let formatter = DateFormatter() + formatter.dateFormat = "HH:mm:ss.SSS" + formatter.timeZone = TimeZone.current + return formatter + }() // MARK: - Cached Regex Patterns @@ -135,7 +145,8 @@ class SecureLogger { /// Format location information for logging private static func formatLocation(file: String, line: Int, function: String) -> String { let fileName = (file as NSString).lastPathComponent - return "[\(fileName):\(line) \(function)]" + let timestamp = timestampFormatter.string(from: Date()) + return "[\(timestamp)] [\(fileName):\(line) \(function)]" } /// Sanitize strings to remove potentially sensitive data