diff --git a/TunnelKit/Sources/Core/ControlChannel.swift b/TunnelKit/Sources/Core/ControlChannel.swift index c1d105e..dd1bf81 100644 --- a/TunnelKit/Sources/Core/ControlChannel.swift +++ b/TunnelKit/Sources/Core/ControlChannel.swift @@ -42,7 +42,13 @@ class ControlChannel { private(set) var sessionId: Data? - var remoteSessionId: Data? + var remoteSessionId: Data? { + didSet { + if let id = remoteSessionId { + log.debug("Control: Remote sessionId is \(id.toHex())") + } + } + } private var queue: BidirectionalState<[ControlPacket]> @@ -138,9 +144,9 @@ class ControlChannel { // packet count let packetCount = currentPacketId.outbound - oldIdOut if (packetCount > 1) { - log.debug("Enqueued \(packetCount) control packets [\(oldIdOut)-\(currentPacketId.outbound - 1)]") + log.debug("Control: Enqueued \(packetCount) packets [\(oldIdOut)-\(currentPacketId.outbound - 1)]") } else { - log.debug("Enqueued 1 control packet [\(oldIdOut)]") + log.debug("Control: Enqueued 1 packet [\(oldIdOut)]") } } @@ -150,7 +156,7 @@ class ControlChannel { if let sentDate = packet.sentDate { let timeAgo = -sentDate.timeIntervalSinceNow guard (timeAgo >= CoreConfiguration.retransmissionLimit) else { - log.debug("Skip control packet with id \(packet.packetId) (sent on \(sentDate), \(timeAgo) seconds ago)") + log.debug("Control: Skip writing packet with packetId \(packet.packetId) (sent on \(sentDate), \(timeAgo) seconds ago)") continue } } @@ -178,7 +184,7 @@ class ControlChannel { throw SessionError.missingSessionId } guard acksRemoteSessionId == sessionId else { - log.error("Ack session mismatch (\(acksRemoteSessionId.toHex()) != \(sessionId.toHex()))") + log.error("Control: Ack session mismatch (\(acksRemoteSessionId.toHex()) != \(sessionId.toHex()))") throw SessionError.sessionMismatch } diff --git a/TunnelKit/Sources/Core/ControlChannelSerializer.swift b/TunnelKit/Sources/Core/ControlChannelSerializer.swift index 6067a57..4f9a39e 100644 --- a/TunnelKit/Sources/Core/ControlChannelSerializer.swift +++ b/TunnelKit/Sources/Core/ControlChannelSerializer.swift @@ -93,8 +93,6 @@ extension ControlChannel { let remoteSessionId = packet.subdata(offset: offset, count: PacketSessionIdLength) offset += PacketSessionIdLength - log.debug("Server acked packetIds \(ids) with remoteSessionId \(remoteSessionId.toHex())") - ackIds = ids ackRemoteSessionId = remoteSessionId } @@ -113,20 +111,11 @@ extension ControlChannel { throw ControlChannelError("Missing packetId") } let packetId = packet.networkUInt32Value(from: offset) - log.debug("Control packet has packetId \(packetId)") offset += PacketIdLength var payload: Data? if offset < end { payload = packet.subdata(in: offset.. \(payload.toHex())") + } else { + msg.append("[\(payload.count) bytes]") + } + } + return "{\(msg.joined(separator: ", "))}" + } +} + class DataPacket { static let pingString = Data(hex: "2a187bf3641eb4cb07ed2d0a981fc748") } + +/// :nodoc: +extension PacketCode: CustomStringConvertible { + public var description: String { + switch self { + case .softResetV1: return "SOFT_RESET_V1" + case .controlV1: return "CONTROL_V1" + case .ackV1: return "ACK_V1" + case .dataV1: return "DATA_V1" + case .hardResetClientV2: return "HARD_RESET_CLIENT_V2" + case .hardResetServerV2: return "HARD_RESET_SERVER_V2" + case .dataV2: return "DATA_V2" + case .unknown: return "UNKNOWN" + } + } +} diff --git a/TunnelKit/Sources/Core/SessionProxy.swift b/TunnelKit/Sources/Core/SessionProxy.swift index c22352e..0726a5c 100644 --- a/TunnelKit/Sources/Core/SessionProxy.swift +++ b/TunnelKit/Sources/Core/SessionProxy.swift @@ -426,7 +426,6 @@ public class SessionProxy { log.warning("Dropped malformed packet (unknown code: \(codeValue))") continue } - // log.verbose("Parsed packet with code \(code)") var offset = 1 @@ -454,7 +453,6 @@ public class SessionProxy { continue } - log.debug("Packet has code \(code.rawValue)") let controlPacket: ControlPacket do { let parsedPacket = try controlChannel.readInboundPacket(withData: packet, offset: 0) @@ -470,7 +468,6 @@ public class SessionProxy { // return } - log.debug("Packet has sessionId \(controlPacket.sessionId.toHex()) and \(controlPacket.ackIds?.count ?? 0) acks entries") sendAck(for: controlPacket) let pendingInboundQueue = controlChannel.enqueueInboundPacket(packet: controlPacket) @@ -663,8 +660,6 @@ public class SessionProxy { return } - log.debug("Handle control packet with code \(packet.code.rawValue) and id \(packet.packetId)") - if (((packet.code == .hardResetServerV2) && (negotiationKey.state == .hardReset)) || ((packet.code == .softResetV1) && (negotiationKey.state == .softReset))) { @@ -672,7 +667,7 @@ public class SessionProxy { controlChannel.remoteSessionId = packet.sessionId } guard let remoteSessionId = controlChannel.remoteSessionId else { - log.error("No remote session id (never set)") + log.error("No remote sessionId (never set)") deferStop(.shutdown, SessionError.missingSessionId) return } @@ -684,7 +679,6 @@ public class SessionProxy { negotiationKey.state = .tls - log.debug("Remote sessionId is \(remoteSessionId.toHex())") log.debug("Start TLS handshake") negotiationKey.tlsOptional = TLSBox( @@ -709,7 +703,7 @@ public class SessionProxy { } else if ((packet.code == .controlV1) && (negotiationKey.state == .tls)) { guard let remoteSessionId = controlChannel.remoteSessionId else { - log.error("No remote session id found in packet (control packets before server HARD_RESET)") + log.error("No remote sessionId found in packet (control packets before server HARD_RESET)") deferStop(.shutdown, SessionError.missingSessionId) return }