From dc32e92d9ae67e318aa58914abdb9049d2412afe Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Leon=20B=C3=B6ttger?= Date: Mon, 11 Aug 2025 09:06:19 +0200 Subject: [PATCH] Better logging --- .../Connection/InboundNearbyConnection.swift | 46 ++++++++-------- NearbyShare/Connection/NearbyConnection.swift | 52 +++++++++---------- .../Connection/NearbyConnectionManager.swift | 2 +- .../Connection/OutboundNearbyConnection.swift | 22 ++++---- 4 files changed, 61 insertions(+), 61 deletions(-) diff --git a/NearbyShare/Connection/InboundNearbyConnection.swift b/NearbyShare/Connection/InboundNearbyConnection.swift index 5b03344..0c858bb 100644 --- a/NearbyShare/Connection/InboundNearbyConnection.swift +++ b/NearbyShare/Connection/InboundNearbyConnection.swift @@ -57,7 +57,7 @@ class InboundNearbyConnection: NearbyConnection { override func processReceivedFrame(frameData: Data) { if currentState != .receivingFiles { - log("[InboundNearbyConnection] Received frame in state \(currentState)...") + log("[InboundNearbyConnection \(self.id)] Received frame in state \(currentState)...") } do { @@ -82,7 +82,7 @@ class InboundNearbyConnection: NearbyConnection { do { smsg = try Securemessage_SecureMessage(serializedBytes: frameData) } catch { - log("[InboundNearbyConnection] Error deserializing secure message (probably due to packet filter)") + log("[InboundNearbyConnection \(self.id)] Error deserializing secure message (probably due to packet filter)") lastError = NearbyError.packetFilterError protocolError() } @@ -93,7 +93,7 @@ class InboundNearbyConnection: NearbyConnection { } } catch { lastError = error - log("[InboundNearbyConnection] Error receiving frame: \(error) in state \(currentState).") + log("[InboundNearbyConnection \(self.id)] Error receiving frame: \(error) in state \(currentState).") protocolError() } } @@ -103,7 +103,7 @@ class InboundNearbyConnection: NearbyConnection { if frame.hasV1 && frame.v1.hasType, case .cancel = frame.v1.type { self.lastError = NearbyError.canceled(reason: .userCanceled) self.cancelled = true - log("[InboundNearbyConnection] Transfer canceled") + log("[InboundNearbyConnection \(self.id)] Transfer canceled") try sendDisconnectionAndDisconnect() return } @@ -115,7 +115,7 @@ class InboundNearbyConnection: NearbyConnection { case .receivedPairedKeyResult: try processIntroductionFrame(frame) default: - log("[InboundNearbyConnection] Unexpected connection state in processTransferSetupFrame: \(currentState)") + log("[InboundNearbyConnection \(self.id)] Unexpected connection state in processTransferSetupFrame: \(currentState)") log(frame.debugDescription) } } @@ -147,7 +147,7 @@ class InboundNearbyConnection: NearbyConnection { // only for logging self.bytesTransferred += Int64(frame.payloadChunk.body.count) } catch { - log("[InboundNearbyConnection] Error occurred during writing file: \(error.localizedDescription)") + log("[InboundNearbyConnection \(self.id)] Error occurred during writing file: \(error.localizedDescription)") throw NearbyError.protocolError(error.localizedDescription) } @@ -163,7 +163,7 @@ class InboundNearbyConnection: NearbyConnection { filesToBeReceived.removeValue(forKey: id) if filesToBeReceived.isEmpty { - log("[InboundNearbyConnection] All files received, sending disconnection frame and disconnecting.") + log("[InboundNearbyConnection \(self.id)] All files received, sending disconnection frame and disconnecting.") try sendDisconnectionAndDisconnect() } } @@ -199,7 +199,7 @@ class InboundNearbyConnection: NearbyConnection { } } - log("[InboundNearbyConnection] Received text payload. Disconnecting...") + log("[InboundNearbyConnection \(self.id)] Received text payload. Disconnecting...") try sendDisconnectionAndDisconnect() return true } @@ -215,7 +215,7 @@ class InboundNearbyConnection: NearbyConnection { filesToBeReceived.removeValue(forKey: id) SaveFilesManager.shared.registerFileFinishedDownloading(fileInfo.destinationURL) - log("[InboundNearbyConnection] Received file payload. Disconnecting...") + log("[InboundNearbyConnection \(self.id)] Received file payload. Disconnecting...") try sendDisconnectionAndDisconnect() return true } @@ -250,7 +250,7 @@ class InboundNearbyConnection: NearbyConnection { guard msg.hasMessageType, msg.hasMessageData else { throw NearbyError.requiredFieldMissing("clientInit ukey2message.type|data") } guard case .clientInit = msg.messageType else { sendUkey2Alert(type: .badMessageType) - log("[InboundNearbyConnection] Unsupported message type: \(msg.messageType)") + log("[InboundNearbyConnection \(self.id)] Unsupported message type: \(msg.messageType)") throw NearbyError.ukey2 } let clientInit: Securegcm_Ukey2ClientInit @@ -258,17 +258,17 @@ class InboundNearbyConnection: NearbyConnection { clientInit = try Securegcm_Ukey2ClientInit(serializedBytes: msg.messageData) } catch { sendUkey2Alert(type: .badMessageData) - log("[InboundNearbyConnection] Failed to parse clientInit: \(error)") + log("[InboundNearbyConnection \(self.id)] Failed to parse clientInit: \(error)") throw NearbyError.ukey2 } guard clientInit.version == 1 else { sendUkey2Alert(type: .badVersion) - log("[InboundNearbyConnection] Unsupported clientInit version: \(clientInit.version)") + log("[InboundNearbyConnection \(self.id)] Unsupported clientInit version: \(clientInit.version)") throw NearbyError.ukey2 } guard clientInit.random.count == 32 else { sendUkey2Alert(type: .badRandom) - log("[InboundNearbyConnection] Unsupported clientInit random: \(clientInit.random.count)") + log("[InboundNearbyConnection \(self.id)] Unsupported clientInit random: \(clientInit.random.count)") throw NearbyError.ukey2 } var found = false @@ -281,12 +281,12 @@ class InboundNearbyConnection: NearbyConnection { } guard found else { sendUkey2Alert(type: .badHandshakeCipher) - log("[InboundNearbyConnection] Unsupported clientInit handshakeCipher: \(clientInit.cipherCommitments)") + log("[InboundNearbyConnection \(self.id)] Unsupported clientInit handshakeCipher: \(clientInit.cipherCommitments)") throw NearbyError.ukey2 } guard clientInit.nextProtocol == "AES_256_CBC-HMAC_SHA256" else { sendUkey2Alert(type: .badNextProtocol) - log("[InboundNearbyConnection] Unsupported clientInit nextProtocol: \(clientInit.nextProtocol)") + log("[InboundNearbyConnection \(self.id)] Unsupported clientInit nextProtocol: \(clientInit.nextProtocol)") throw NearbyError.ukey2 } @@ -320,14 +320,14 @@ class InboundNearbyConnection: NearbyConnection { private func processUkey2ClientFinish(_ msg: Securegcm_Ukey2Message, raw: Data) throws { guard msg.hasMessageType, msg.hasMessageData else { throw NearbyError.requiredFieldMissing("clientFinish ukey2message.type|data") } guard case .clientFinish = msg.messageType else { - log("[InboundNearbyConnection] Unexpected message type \(msg.messageType)") + log("[InboundNearbyConnection \(self.id)] Unexpected message type \(msg.messageType)") throw NearbyError.ukey2 } var sha = SHA512() sha.update(data: raw) guard cipherCommitment == Data(sha.finalize()) else { - log("[InboundNearbyConnection] Invalid cipherCommitment in clientFinish") + log("[InboundNearbyConnection \(self.id)] Invalid cipherCommitment in clientFinish") throw NearbyError.ukey2 } @@ -368,7 +368,7 @@ class InboundNearbyConnection: NearbyConnection { try sendTransferSetupFrame(pairedEncryption) currentState = .sentConnectionResponse } else { - log("[InboundNearbyConnection] Unhandled offline frame plaintext: \(frame)") + log("[InboundNearbyConnection \(self.id)] Unhandled offline frame plaintext: \(frame)") } } @@ -459,7 +459,7 @@ class InboundNearbyConnection: NearbyConnection { func rejectDueToUnsupportedFileType(_ frame: Sharing_Nearby_Frame) { - log("[InboundNearbyConnection] Rejecting transfer due to unsupported file type. Frame is \(frame.debugDescription)") + log("[InboundNearbyConnection \(self.id)] Rejecting transfer due to unsupported file type. Frame is \(frame.debugDescription)") NearbyConnectionManager.shared.mainAppDelegate?.showUnsupportedFileAlert(for: remoteDeviceInfo) rejectTransfer(with: .unsupportedAttachmentType) @@ -479,7 +479,7 @@ class InboundNearbyConnection: NearbyConnection { private func acceptTransfer(storeInTemp: Bool) { if currentState == .disconnected { - log("[InboundNearbyConnection] Detected timeout, not accepting transfer") + log("[InboundNearbyConnection \(self.id)] Detected timeout, not accepting transfer") return } @@ -506,7 +506,7 @@ class InboundNearbyConnection: NearbyConnection { filesToBeReceived[id]!.progress = progress filesToBeReceived[id]!.created = true - log("[InboundNearbyConnection] Accepted file with size \(file.meta.size)") + log("[InboundNearbyConnection \(self.id)] Accepted file with size \(file.meta.size)") } var frame = Sharing_Nearby_Frame() @@ -527,7 +527,7 @@ class InboundNearbyConnection: NearbyConnection { self.wasRejected = true - log("[InboundNearbyConnection] Rejecting transfer because of \( reason)") + log("[InboundNearbyConnection \(self.id)] Rejecting transfer because of \( reason)") var frame = Sharing_Nearby_Frame() frame.version = .v1 @@ -537,7 +537,7 @@ class InboundNearbyConnection: NearbyConnection { try sendTransferSetupFrame(frame) try sendDisconnectionAndDisconnect() } catch { - log("[InboundNearbyConnection] Error \(error)") + log("[InboundNearbyConnection \(self.id)] Error \(error)") protocolError() } } diff --git a/NearbyShare/Connection/NearbyConnection.swift b/NearbyShare/Connection/NearbyConnection.swift index a849ab3..29eb49d 100644 --- a/NearbyShare/Connection/NearbyConnection.swift +++ b/NearbyShare/Connection/NearbyConnection.swift @@ -28,7 +28,7 @@ class NearbyConnection { var cancelled: Bool = false var isTransferring: Bool = false { didSet { - log("[NearbyConnection] Now transferring. Setting up data transfer inactivity timer.") + log("[NearbyConnection \(self.id)] Now transferring. Setting up data transfer inactivity timer.") startDataTransferTimer(previousBytesTransferred: bytesTransferred) } } @@ -76,7 +76,7 @@ class NearbyConnection { // If connection reset by peer, it could still be a valid file transfer that has not been processed yet. => Wait if err == .posix(.ECONNRESET) { - log("[NearbyConnection] Network connection reset error detected.") + log("[NearbyConnection \(self.id)] Network connection reset error detected.") self.connectionClosedByPeer { recordErrorAndDisconnect(err: err) } @@ -87,7 +87,7 @@ class NearbyConnection { } } else { - log("[NearbyConnection] Connection already closed, ignoring state update: \(state)") + log("[NearbyConnection \(self.id)] Connection already closed, ignoring state update: \(state)") } } @@ -95,18 +95,18 @@ class NearbyConnection { func recordErrorAndDisconnect(err: NWError) { self.lastError = err - log("[NearbyConnection] Connection Error: \(err)") + log("[NearbyConnection \(self.id)] Connection Error: \(err)") // If the error is a connection reset, it could be due to firewall issues. if err == .posix(.ENOTCONN) { - log("[NearbyConnection] Network not connected error detected.") + log("[NearbyConnection \(self.id)] Network not connected error detected.") ConnectionFailureTracker.shared.recordFailure { NearbyConnectionManager.shared.mainAppDelegate?.showFirewallAlert() } } if err == .posix(.ENETDOWN) { - log("[NearbyConnection] Network down error detected.") + log("[NearbyConnection \(self.id)] Network down error detected.") self.lastError = NearbyError.protocolError("Error.NetworkDown".localized()) } @@ -130,7 +130,7 @@ class NearbyConnection { func protocolError() { - log("[NearbyConnection] Protocol error: \(String(describing: lastError))") + log("[NearbyConnection \(self.id)] Protocol error: \(String(describing: lastError))") disconnect() } @@ -166,7 +166,7 @@ class NearbyConnection { return } if isComplete { - log("[NearbyConnection] Connection closed by peer during receiveFrameAsync()") + log("[NearbyConnection \(self.id)] Connection closed by peer during receiveFrameAsync()") self.connectionClosedByPeer { self.lastError = NearbyError.protocolError("Error.ClosedByPeer".localized()) self.disconnect() @@ -174,13 +174,13 @@ class NearbyConnection { return } if !(error == nil) { - log("[NearbyConnection] Error during receiveFrameAsync(): \(String(describing: error))") + log("[NearbyConnection \(self.id)] Error during receiveFrameAsync(): \(String(describing: error))") self.lastError = error self.protocolError() return } guard let content = content else { - log("[NearbyConnection] Received nil content during receiveFrameAsync(). IsComplete: \(isComplete)") + log("[NearbyConnection \(self.id)] Received nil content during receiveFrameAsync(). IsComplete: \(isComplete)") assertionFailure() return } @@ -198,19 +198,19 @@ class NearbyConnection { private func receiveFrameAsync(length: UInt32) { - connection.receive(minimumIncompleteLength: Int(length), maximumLength: Int(length)) { content, _, isComplete, _ in + connection.receive(minimumIncompleteLength: Int(length), maximumLength: Int(length)) { [self] content, _, isComplete, _ in if self.connectionClosed { return } if isComplete { - log("[NearbyConnection] Connection closed by peer during receiveFrameAsync(length:)") + log("[NearbyConnection \(self.id)] Connection closed by peer during receiveFrameAsync(length:)") if let content = content, !content.isEmpty { - log("[NearbyConnection] Connection closed by peer during receiveFrameAsync(length:), but trying to process the frame anyway. Frame length: \(content.count)") + log("[NearbyConnection \(self.id)] Connection closed by peer during receiveFrameAsync(length:), but trying to process the frame anyway. Frame length: \(content.count)") self.processReceivedFrame(frameData: content) } else { - log("[NearbyConnection] Connection closed by peer during receiveFrameAsync(length:), but no content received anymore (\(String(describing: content))).") + log("[NearbyConnection \(self.id)] Connection closed by peer during receiveFrameAsync(length:), but no content received anymore (\(String(describing: content))).") } self.connectionClosedByPeer { @@ -221,7 +221,7 @@ class NearbyConnection { return } guard let content = content else { - log("[NearbyConnection] Received nil content during receiveFrameAsync(length:). IsComplete: \(isComplete)") + log("[NearbyConnection \(self.id)] Received nil content during receiveFrameAsync(length:). IsComplete: \(isComplete)") self.protocolError() return } @@ -297,7 +297,7 @@ class NearbyConnection { func sendTransferSetupFrame(_ frame: Sharing_Nearby_Frame) throws { - log("[NearbyConnection] Sending transfer setup frame.") + log("[NearbyConnection \(self.id)] Sending transfer setup frame.") try sendBytesPayload(data: frame.serializedData(), id: Int64.random(in: Int64.min ... Int64.max)) } @@ -374,11 +374,11 @@ class NearbyConnection { guard payloadTransfer.hasPayloadChunk, chunk.hasOffset, chunk.hasFlags else { if payloadTransfer.controlMessage.event == .payloadCanceled { - log("[NearbyConnection] Cancel control frame received.") + log("[NearbyConnection \(self.id)] Cancel control frame received.") throw NearbyError.canceled(reason: .userCanceled) } - log("[NearbyConnection] Payload transfer chunk is missing offset or flags. Frame is \(payloadTransfer.debugDescription)") + log("[NearbyConnection \(self.id)] Payload transfer chunk is missing offset or flags. Frame is \(payloadTransfer.debugDescription)") throw NearbyError.requiredFieldMissing("payloadChunk.offset|flags") } @@ -423,11 +423,11 @@ class NearbyConnection { } else if offlineFrame.hasV1, offlineFrame.v1.hasType, case .keepAlive = offlineFrame.v1.type { - log("[NearbyConnection] Sent keep-alive, \(self.bytesTransferred) bytes sent") + log("[NearbyConnection \(self.id)] Sent keep-alive, \(self.bytesTransferred) bytes sent") sendKeepAlive(ack: true) } else { - log("[NearbyConnection] Unhandled offline frame encrypted: \(offlineFrame)") + log("[NearbyConnection \(self.id)] Unhandled offline frame encrypted: \(offlineFrame)") } } @@ -531,7 +531,7 @@ class NearbyConnection { func disconnect() { - log("[NearbyConnection] Disconnecting from connection.") + log("[NearbyConnection \(self.id)] Disconnecting from connection.") connection.stateUpdateHandler = nil inactivityTimer?.cancel() @@ -553,7 +553,7 @@ class NearbyConnection { try sendFrameAsync(offlineFrame.serializedData()) } - log("[NearbyConnection] Sent disconnection frame during sendDisconnectionAndDisconnect") + log("[NearbyConnection \(self.id)] Sent disconnection frame during sendDisconnectionAndDisconnect") disconnect() } @@ -566,7 +566,7 @@ class NearbyConnection { msg.messageData = try! alert.serializedData() sendFrameAsync(try! msg.serializedData()) - log("[NearbyConnection] Sent UKEY2 alert: \(type)") + log("[NearbyConnection \(self.id)] Sent UKEY2 alert: \(type)") disconnect() } @@ -584,7 +584,7 @@ class NearbyConnection { try sendFrameAsync(offlineFrame.serializedData()) } } catch { - log("[NearbyConnection] Error sending KEEP_ALIVE: \(error)") + log("[NearbyConnection \(self.id)] Error sending KEEP_ALIVE: \(error)") } } @@ -601,7 +601,7 @@ class NearbyConnection { guard let self = self else { return } if !self.connectionClosed { - log("[NearbyConnection] Connection timeout: No message received in \(self.timeoutInterval) seconds") + log("[NearbyConnection \(self.id)] Connection timeout: No message received in \(self.timeoutInterval) seconds") self.lastError = NearbyError.canceled(reason: .timedOut) self.disconnect() } @@ -621,7 +621,7 @@ class NearbyConnection { else { // connection stale, need to abort if !self.connectionClosed { - log("[NearbyConnection] Connection timeout: No more data received in \(self.timeoutInterval) seconds") + log("[NearbyConnection \(self.id)] Connection timeout: No more data received in \(self.timeoutInterval) seconds") self.lastError = NearbyError.canceled(reason: .timedOut) self.disconnect() } diff --git a/NearbyShare/Connection/NearbyConnectionManager.swift b/NearbyShare/Connection/NearbyConnectionManager.swift index 2ebfe39..0011235 100644 --- a/NearbyShare/Connection/NearbyConnectionManager.swift +++ b/NearbyShare/Connection/NearbyConnectionManager.swift @@ -135,7 +135,7 @@ public class NearbyConnectionManager: NSObject, NetServiceDelegate, InboundNearb public func submitUserConsent(transferID: String, accept: Bool, storeInTemp: Bool = false) { guard let conn = incomingConnections[transferID] else { return } - log("[NearbyConnectionManager] Submitting user consent for transfer, accepted: \(accept), store in temp: \(storeInTemp)") + log("[NearbyConnectionManager] Submitting user consent for transfer \(transferID), accepted: \(accept), store in temp: \(storeInTemp)") conn.submitUserConsent(accepted: accept, storeInTemp: storeInTemp) } diff --git a/NearbyShare/Connection/OutboundNearbyConnection.swift b/NearbyShare/Connection/OutboundNearbyConnection.swift index d6c1dd8..da57535 100644 --- a/NearbyShare/Connection/OutboundNearbyConnection.swift +++ b/NearbyShare/Connection/OutboundNearbyConnection.swift @@ -101,7 +101,7 @@ class OutboundNearbyConnection: NearbyConnection { override func processReceivedFrame(frameData: Data) { if currentState != .sendingFiles { - log("[OutboundNearbyConnection] Received frame in state \(currentState)...") + log("[OutboundNearbyConnection \(self.id)] Received frame in state \(currentState)...") } do { @@ -118,7 +118,7 @@ class OutboundNearbyConnection: NearbyConnection { } } catch { - log("[OutboundNearbyConnection] Error occured while processing frame with data \(frameData.hex): \(error)") + log("[OutboundNearbyConnection \(self.id)] Error occured while processing frame with data \(frameData.hex): \(error)") if case NearbyError.ukey2 = error { // do nothing @@ -137,7 +137,7 @@ class OutboundNearbyConnection: NearbyConnection { if frame.hasV1 && frame.v1.hasType, case .cancel = frame.v1.type { self.cancelled = true self.lastError = NearbyError.canceled(reason: .userCanceled) - log("[OutboundNearbyConnection] Transfer canceled") + log("[OutboundNearbyConnection \(self.id)] Transfer canceled") try sendDisconnectionAndDisconnect() delegate?.outboundConnection(connection: self, failedWithError: self.lastError!) return @@ -153,7 +153,7 @@ class OutboundNearbyConnection: NearbyConnection { case .sendingFiles: break default: - assertionFailure("[OutboundNearbyConnection] Unexpected state \(currentState)") + assertionFailure("[OutboundNearbyConnection \(self.id)] Unexpected state \(currentState)") } } @@ -224,23 +224,23 @@ class OutboundNearbyConnection: NearbyConnection { ukeyServerInitMsgData = raw guard frame.messageType == .serverInit else { sendUkey2Alert(type: .badMessageType) - log("[OutboundNearbyConnection] Invalid message type: \(frame.messageType)") + log("[OutboundNearbyConnection \(self.id)] Invalid message type: \(frame.messageType)") throw NearbyError.ukey2 } let serverInit = try Securegcm_Ukey2ServerInit(serializedBytes: frame.messageData) guard serverInit.version == 1 else { sendUkey2Alert(type: .badVersion) - log("[OutboundNearbyConnection] Invalid version: \(serverInit.version)") + log("[OutboundNearbyConnection \(self.id)] Invalid version: \(serverInit.version)") throw NearbyError.ukey2 } guard serverInit.random.count == 32 else { sendUkey2Alert(type: .badRandom) - log("[OutboundNearbyConnection] Invalid random: \(serverInit.random.count)") + log("[OutboundNearbyConnection \(self.id)] Invalid random: \(serverInit.random.count)") throw NearbyError.ukey2 } guard serverInit.handshakeCipher == .p256Sha512 else { sendUkey2Alert(type: .badHandshakeCipher) - log("[OutboundNearbyConnection] Invalid handshake cipher: \(serverInit.handshakeCipher)") + log("[OutboundNearbyConnection \(self.id)] Invalid handshake cipher: \(serverInit.handshakeCipher)") throw NearbyError.ukey2 } @@ -349,7 +349,7 @@ class OutboundNearbyConnection: NearbyConnection { introduction.v1.introduction.fileMetadata.append(meta) totalBytesToSend += meta.size - log("[OutboundNearbyConnection] Sending file with \(meta.size) bytes") + log("[OutboundNearbyConnection \(self.id)] Sending file with \(meta.size) bytes") } } try sendTransferSetupFrame(introduction) @@ -416,7 +416,7 @@ class OutboundNearbyConnection: NearbyConnection { try currentTransfer?.handle?.close() } if queue.isEmpty { - log("[OutboundNearbyConnection] Disconnecting because all files have been transferred") + log("[OutboundNearbyConnection \(self.id)] Disconnecting because all files have been transferred") try sendDisconnectionAndDisconnect() delegate?.outboundConnectionTransferFinished(connection: self) return @@ -479,7 +479,7 @@ class OutboundNearbyConnection: NearbyConnection { wrapper.v1.type = .payloadTransfer wrapper.v1.payloadTransfer = transfer try encryptAndSendOfflineFrame(wrapper) - log("[OutboundNearbyConnection] Sent EOF, current transfer: \(String(describing: currentTransfer))") + log("[OutboundNearbyConnection \(self.id)] Sent EOF, current transfer: \(String(describing: currentTransfer))") } }