diff --git a/Sources/SwiftNetwork/Protocols/Frame.swift b/Sources/SwiftNetwork/Protocols/Frame.swift index 115c368d..9438d917 100644 --- a/Sources/SwiftNetwork/Protocols/Frame.swift +++ b/Sources/SwiftNetwork/Protocols/Frame.swift @@ -289,7 +289,7 @@ public struct Frame: ~Copyable { if adjustSingleIPAggregate && isSingleIPAggregate { guard fromEnd == 0 else { #if !DisableErrorLogging - Logger.proto.error("Trying to claim at the end \(fromEnd) bytes from a single-IP aggregate") + outlinedProtoLogError("Trying to claim bytes at the end of a single-IP aggregate", fromEnd) #endif return false } @@ -301,8 +301,11 @@ public struct Frame: ~Copyable { guard newStart <= effectiveBufferLength - newEnd else { let effectiveLength = effectiveBufferLength #if !DisableErrorLogging - Logger.proto.error( - "Claiming bytes failed because start (\(newStart)) is beyond end (\(effectiveLength) - \(newEnd))" + outlinedProtoLogError( + "Claiming bytes failed, start is beyond end; start, effective length, end", + newStart, + effectiveLength, + newEnd ) #endif return false @@ -322,7 +325,7 @@ public struct Frame: ~Copyable { if adjustSingleIPAggregate && isSingleIPAggregate { guard fromEnd == 0 else { #if !DisableErrorLogging - Logger.proto.error("Trying to unclaim at the end \(fromEnd) bytes from a single-IP aggregate") + outlinedProtoLogError("Trying to unclaim bytes at the end of a single-IP aggregate", fromEnd) #endif return false } @@ -332,7 +335,7 @@ public struct Frame: ~Copyable { guard fromStart <= startOffset else { let startOffset = startOffset #if !DisableErrorLogging - Logger.proto.error("Frame cannot unclaim \(fromStart) start bytes (has \(startOffset) left)") + outlinedProtoLogError("Frame cannot unclaim start bytes; requested, remaining", fromStart, startOffset) #endif return false } @@ -340,7 +343,7 @@ public struct Frame: ~Copyable { guard fromEnd <= endOffset else { let endOffset = endOffset #if !DisableErrorLogging - Logger.proto.error("Frame cannot unclaim \(fromEnd) end bytes (has \(endOffset) left)") + outlinedProtoLogError("Frame cannot unclaim end bytes; requested, remaining", fromEnd, endOffset) #endif return false } @@ -642,14 +645,14 @@ public struct Frame: ~Copyable { var packetChainTotalLength: Int { get { guard isSingleIPAggregate else { - Logger.proto.fault("Attempt to get aggregate buffer length on a non-single IP aggregate") + outlinedProtoLogFault("Attempt to get aggregate buffer length on a non-single IP aggregate") return 0 } return aggregateBufferLength } set { guard isSingleIPAggregate else { - Logger.proto.fault("Attempt to set aggregate buffer length on a non-single IP aggregate") + outlinedProtoLogFault("Attempt to set aggregate buffer length on a non-single IP aggregate") return } aggregateBufferLength = newValue @@ -667,7 +670,7 @@ public struct Frame: ~Copyable { } guard newValue < 64 else { #if !DisableErrorLogging - Logger.proto.error("Cannot set DSCP value of \(newValue)") + outlinedProtoLogError("Cannot set DSCP value", newValue) #endif return } @@ -856,7 +859,11 @@ public struct Frame: ~Copyable { guard length >= 0 else { return } guard length <= aggregateBufferLength else { let existingLength = aggregateBufferLength - Logger.proto.fault("Aggregate buffer length \(existingLength) cannot remove \(length)") + outlinedProtoLogFault( + "Aggregate buffer length cannot remove requested bytes; existing, requested", + existingLength, + length + ) aggregateBufferLength = 0 return } diff --git a/Sources/SwiftNetwork/QUIC/Ack.swift b/Sources/SwiftNetwork/QUIC/Ack.swift index fb92ccc6..706c31e7 100644 --- a/Sources/SwiftNetwork/QUIC/Ack.swift +++ b/Sources/SwiftNetwork/QUIC/Ack.swift @@ -1027,14 +1027,20 @@ struct AckBitstring: ~Copyable { // The connection will stall if these two conditions occur. let initialWord = initialWord if _slowPath(startWord < initialWord) { - Logger.proto.fault( - "Initial word \(initialWord) is lower than start \(startWord) (pn \(start))" + outlinedProtoLogFault( + "Initial word is lower than start; initial, start, packet number", + initialWord, + startWord, + start.value ) return false } if _slowPath(stopWord < initialWord) { - Logger.proto.fault( - "Initial word \(initialWord) is lower than stop \(stopWord) (pn \(stop))" + outlinedProtoLogFault( + "Initial word is lower than stop; initial, stop, packet number", + initialWord, + stopWord, + stop.value ) return false } @@ -1053,14 +1059,20 @@ struct AckBitstring: ~Copyable { let bitstringCount = UInt64(bitstring.count) let initialWord = initialWord if _slowPath(startWord > initialWord + bitstringCount) { - Logger.proto.fault( - "Size \(bitstringCount + initialWord) is lower than start \(startWord) (pn \(start))" + outlinedProtoLogFault( + "Bitstring size is lower than start; size, start, packet number", + bitstringCount + initialWord, + startWord, + start.value ) return false } if _slowPath(stopWord > initialWord + bitstringCount) { - Logger.proto.fault( - "Size \(bitstringCount + initialWord) is lower than start \(stopWord) (pn \(stop))" + outlinedProtoLogFault( + "Bitstring size is lower than stop; size, stop, packet number", + bitstringCount + initialWord, + stopWord, + stop.value ) return false } @@ -1078,7 +1090,7 @@ struct AckBitstring: ~Copyable { if stopWord >= size { guard _slowPath(stopWord < UInt32.max / 2) else { - Logger.proto.info("Refusing to grow bitstring further") + outlinedProtoLogInfo("Refusing to grow bitstring further") return } let targetSize = Int(stopWord) + 1 @@ -1124,7 +1136,7 @@ struct AckBitstring: ~Copyable { guard initialWord == other.initialWord else { let initialWord = self.initialWord let otherInitialWord = other.initialWord - Logger.proto.fault("Bitstring initial mismatch \(initialWord) != \(otherInitialWord)") + outlinedProtoLogFault("Bitstring initial mismatch; self, other", initialWord, otherInitialWord) return AckBitstringSequence.empty } if size > other.size { diff --git a/Sources/SwiftNetwork/QUIC/Packet.swift b/Sources/SwiftNetwork/QUIC/Packet.swift index 99d57750..21081fd2 100644 --- a/Sources/SwiftNetwork/QUIC/Packet.swift +++ b/Sources/SwiftNetwork/QUIC/Packet.swift @@ -307,9 +307,7 @@ struct Packet: ~Copyable { get { if let _overrideSentNumberSize { #if !DisableErrorLogging - Logger.proto.error( - "WARNING: Reading overrideSentNumberSize only be used for unit testing!" - ) + outlinedProtoLogError("WARNING: Reading overrideSentNumberSize only be used for unit testing!") #endif return _overrideSentNumberSize } @@ -318,9 +316,7 @@ struct Packet: ~Copyable { set(newValue) { if let newValue { #if !DisableErrorLogging - Logger.proto.error( - "WARNING: Setting overrideSentNumberSize only be used for unit testing!" - ) + outlinedProtoLogError("WARNING: Setting overrideSentNumberSize only be used for unit testing!") #endif _overrideSentNumberSize = newValue } else { diff --git a/Sources/SwiftNetwork/QUIC/PacketNumberSpace.swift b/Sources/SwiftNetwork/QUIC/PacketNumberSpace.swift index 822f8b33..0e9e10be 100644 --- a/Sources/SwiftNetwork/QUIC/PacketNumberSpace.swift +++ b/Sources/SwiftNetwork/QUIC/PacketNumberSpace.swift @@ -196,6 +196,7 @@ struct PacketNumber: Comparable, ExpressibleByIntegerLiteral, Hashable, CustomSt return (bits + 7) / 8 } + @inline(always) func encode( lastAcked: PacketNumber, fixedSize: EncodedPacketNumber.Size? = nil @@ -207,7 +208,7 @@ struct PacketNumber: Comparable, ExpressibleByIntegerLiteral, Hashable, CustomSt // check for packet number not greater than lastAcked. // If lastAcked == .none the peer has not yet acknowledged anything in this packet number space if lastAcked != .none, self <= lastAcked { - Logger.proto.error("Ack number underflow: \(self) <= \(lastAcked)") + outlinedProtoLogError("Ack number underflow; number, lastAcked", self.value, lastAcked.value) throw QUICError.packet(QUICPacketError.ackNumberUnderflow) } @@ -217,7 +218,7 @@ struct PacketNumber: Comparable, ExpressibleByIntegerLiteral, Hashable, CustomSt var truncatedPacketNumber = self.value var size: EncodedPacketNumber.Size if let fixedSize { - Logger.proto.error("WARNING: Use overrideSentNumberSize only for unit testing!") + outlinedProtoLogError("WARNING: Use overrideSentNumberSize only for unit testing!") size = fixedSize } else { if difference <= 0xff { diff --git a/Sources/SwiftNetwork/QUIC/Protector.swift b/Sources/SwiftNetwork/QUIC/Protector.swift index 649f5cbe..c23dfae0 100644 --- a/Sources/SwiftNetwork/QUIC/Protector.swift +++ b/Sources/SwiftNetwork/QUIC/Protector.swift @@ -845,14 +845,9 @@ struct Protector: ~Copyable, PrefixedLoggable { // Packet number offset must always be set, otherwise sampleRange doesn't work before we get here. packetNumberOffset = packet.packetNumberOffset! } else { - // When sealing/encrypting, the packet number is known but may be overridden - if let length = packet.overrideSentNumberSize?.rawValue { - packetNumberLength = length - } else { - // The packet number would not have been written if it doesn't encode - packetNumberLength = try! packet.number.encode(lastAcked: packet.lastAcked).size - .rawValue - } + // When sealing/encrypting, writing the header recorded the encoded length, including + // any override of the number of bytes it occupies. + packetNumberLength = Int(packet.packetNumberLength) packetNumberOffset = packet.packetNumberOffset! } diff --git a/Sources/SwiftNetwork/Utilities/Deserializer.swift b/Sources/SwiftNetwork/Utilities/Deserializer.swift index a4a29300..4ea91aea 100644 --- a/Sources/SwiftNetwork/Utilities/Deserializer.swift +++ b/Sources/SwiftNetwork/Utilities/Deserializer.swift @@ -194,7 +194,7 @@ public struct Deserializer(_ value: inout T) throws(DeserializationError) { let length = MemoryLayout.size precondition(length <= 16) @@ -715,6 +715,45 @@ public struct Deserializer= length else { + try invalidate(.bufferTooShort) + } + + var matched = 0 + while matched < length { + let available = min(remaining, length - matched) + if available > 0 { + let matches = value.withUnsafeBytes { expectedBytes in + let slice = UnsafeRawBufferPointer( + start: expectedBytes.baseAddress! + matched, + count: available + ) + return Deserializer.valueMatches( + lhs: slice, + rhs: currentSpan, + rhsOffset: cursor, + count: available + ) + } + guard matches else { + try invalidate(.validationFailed) + } + try moveCursor(available) + matched += available + } + if matched < length { + guard refill() else { + try invalidate(.bufferTooShort) + } + } + } + } + @inlinable @inline(always) public mutating func span(expect value: RawSpan) throws(DeserializationError) { @@ -724,40 +763,7 @@ public struct Deserializer= length else { - try invalidate(.bufferTooShort) - } - - // Compare across span boundaries - var matched = 0 - while matched < length { - let available = min(remaining, length - matched) - if available > 0 { - let matches = value.withUnsafeBytes { expectedBytes in - let slice = UnsafeRawBufferPointer( - start: expectedBytes.baseAddress! + matched, - count: available - ) - return Deserializer.valueMatches( - lhs: slice, - rhs: currentSpan, - rhsOffset: cursor, - count: available - ) - } - guard matches else { - try invalidate(.validationFailed) - } - try moveCursor(available) - matched += available - } - if matched < length { - guard refill() else { - try invalidate(.bufferTooShort) - } - } - } + try spanExpectFragmented(expect: value, length: length) return } @@ -771,6 +777,38 @@ public struct Deserializer, + lengthToCopy: Int + ) throws(DeserializationError) { + var filled = 0 + while filled < lengthToCopy { + let available = min(remaining, lengthToCopy - filled) + if available > 0 { + let source = currentSpan.extracting(unchecked: cursor..<(cursor &+ available)) + source.withUnsafeBytes { fromBuffer in + value.withUnsafeMutableBytes { toBuffer in + let dest = UnsafeMutableRawBufferPointer( + start: toBuffer.baseAddress! + filled, + count: available + ) + dest.copyMemory(from: fromBuffer) + } + } + try moveCursor(available) + filled += available + } + if filled < lengthToCopy { + guard refill() else { + try invalidate(.bufferTooShort) + } + } + } + } + @_optimize(speed) @inlinable @inline(always) @@ -790,30 +828,7 @@ public struct Deserializer 0 { - let source = currentSpan.extracting(unchecked: cursor..<(cursor &+ available)) - source.withUnsafeBytes { fromBuffer in - value.withUnsafeMutableBytes { toBuffer in - let dest = UnsafeMutableRawBufferPointer( - start: toBuffer.baseAddress! + filled, - count: available - ) - dest.copyMemory(from: fromBuffer) - } - } - try moveCursor(available) - filled += available - } - if filled < lengthToCopy { - guard refill() else { - try invalidate(.bufferTooShort) - } - } - } + try spanFragmented(&value, lengthToCopy: lengthToCopy) return } diff --git a/Sources/SwiftNetwork/Utilities/Logging.swift b/Sources/SwiftNetwork/Utilities/Logging.swift index b07f1700..73ac9365 100644 --- a/Sources/SwiftNetwork/Utilities/Logging.swift +++ b/Sources/SwiftNetwork/Utilities/Logging.swift @@ -86,3 +86,94 @@ extension Logger { static let migration = Logger(subsystem: "com.apple.network", category: "migration") } #endif + +// MARK: - Reporting from small functions + +// Building a log message is many times the size of the arithmetic a small function performs, and +// that code counts against the inliner's budget and occupies instruction footprint on the hot path +// whether or not the message is ever emitted. A function that reports an unexpected condition +// inline therefore stops being inlinable, and its callers pay for a diagnostic they never see. +// +// Reporting through these helpers keeps the message, and the logging metadata and +// once-initialisation with it, in one out-of-line place. Callers keep a compare and a branch. +// The names say so: being out of line is the point, not an implementation detail. They also +// name the category, because a helper that defaulted to one would quietly send a diagnostic +// from another subsystem to the wrong place. Passing the `Logger` instead would materialise it +// at the call site, which is the cost these helpers exist to avoid. +// +// The message is a `StaticString` so nothing is interpolated at the call site, and the values are +// parameters rather than an autoclosure, which would put the interpolation back in the caller. + +#if os(Linux) || (NETWORK_EMBEDDED && !NETWORK_DRIVERKIT) || canImport(os) || NETWORK_DRIVERKIT +@available(macOS 11, iOS 14, tvOS 14, watchOS 7, *) +@inline(never) +func outlinedProtoLogError(_ message: StaticString) { + Logger.proto.error("\(message)") +} + +@available(macOS 11, iOS 14, tvOS 14, watchOS 7, *) +@inline(never) +func outlinedProtoLogError(_ message: StaticString, _ value: Value) { + Logger.proto.error("\(message): \(value)") +} + +@available(macOS 11, iOS 14, tvOS 14, watchOS 7, *) +@inline(never) +func outlinedProtoLogError( + _ message: StaticString, + _ first: First, + _ second: Second +) { + Logger.proto.error("\(message): \(first), \(second)") +} + +@available(macOS 11, iOS 14, tvOS 14, watchOS 7, *) +@inline(never) +func outlinedProtoLogError( + _ message: StaticString, + _ first: First, + _ second: Second, + _ third: Third +) { + Logger.proto.error("\(message): \(first), \(second), \(third)") +} + +@available(macOS 11, iOS 14, tvOS 14, watchOS 7, *) +@inline(never) +func outlinedProtoLogFault(_ message: StaticString) { + Logger.proto.fault("\(message)") +} + +@available(macOS 11, iOS 14, tvOS 14, watchOS 7, *) +@inline(never) +func outlinedProtoLogFault(_ message: StaticString, _ value: Value) { + Logger.proto.fault("\(message): \(value)") +} + +@available(macOS 11, iOS 14, tvOS 14, watchOS 7, *) +@inline(never) +func outlinedProtoLogFault( + _ message: StaticString, + _ first: First, + _ second: Second +) { + Logger.proto.fault("\(message): \(first), \(second)") +} + +@available(macOS 11, iOS 14, tvOS 14, watchOS 7, *) +@inline(never) +func outlinedProtoLogFault( + _ message: StaticString, + _ first: First, + _ second: Second, + _ third: Third +) { + Logger.proto.fault("\(message): \(first), \(second), \(third)") +} + +@available(macOS 11, iOS 14, tvOS 14, watchOS 7, *) +@inline(never) +func outlinedProtoLogInfo(_ message: StaticString) { + Logger.proto.info("\(message)") +} +#endif diff --git a/Sources/SwiftNetwork/Utilities/Serializer.swift b/Sources/SwiftNetwork/Utilities/Serializer.swift index 5457d92b..832888d6 100644 --- a/Sources/SwiftNetwork/Utilities/Serializer.swift +++ b/Sources/SwiftNetwork/Utilities/Serializer.swift @@ -490,7 +490,7 @@ public struct InPlaceSerializer(_ value: T) throws(SerializationError) { let length = MemoryLayout.size precondition(length <= 16) @@ -648,6 +648,38 @@ public struct InPlaceSerializer 0 { + source.withUnsafeBytes { srcBuffer in + currentSpan.withUnsafeMutableBytes { dstBuffer in + let dst = UnsafeMutableRawBufferPointer( + start: dstBuffer.baseAddress! + cursor, + count: available + ) + let src = UnsafeRawBufferPointer( + start: srcBuffer.baseAddress! + written, + count: available + ) + dst.copyMemory(from: src) + } + } + try moveCursor(available) + written &+= available + } + if written < length { + guard refill() else { + try invalidate(.bufferTooShort) + } + } + } + } + @_optimize(speed) @inlinable @inline(always) @@ -658,34 +690,7 @@ public struct InPlaceSerializer 0 { - source.withUnsafeBytes { srcBuffer in - currentSpan.withUnsafeMutableBytes { dstBuffer in - let dst = UnsafeMutableRawBufferPointer( - start: dstBuffer.baseAddress! + cursor, - count: available - ) - let src = UnsafeRawBufferPointer( - start: srcBuffer.baseAddress! + written, - count: available - ) - dst.copyMemory(from: src) - } - } - try moveCursor(available) - written &+= available - } - if written < length { - guard refill() else { - try invalidate(.bufferTooShort) - } - } - } + try spanFragmented(source, length: length) return } // Fast path, only a single span diff --git a/Sources/SwiftNetwork/Utilities/UInt64+VLE.swift b/Sources/SwiftNetwork/Utilities/UInt64+VLE.swift index a5b2a928..06381067 100644 --- a/Sources/SwiftNetwork/Utilities/UInt64+VLE.swift +++ b/Sources/SwiftNetwork/Utilities/UInt64+VLE.swift @@ -41,7 +41,7 @@ extension FixedWidthInteger { @available(macOS 11, iOS 14, tvOS 14, watchOS 7, *) var variableLengthSize: Int { guard let size = self.safeVariableLengthSize else { - Logger.proto.error("Integer value too large to encode into a 8-byte VLE") + outlinedProtoLogError("Integer value too large to encode into a 8-byte VLE") return 8 } return size @@ -63,7 +63,7 @@ extension UInt64 { @inline(always) var variableLengthSize: Int { guard let size = self.safeVariableLengthSize else { - Logger.proto.error("Integer value too large to encode into a 8-byte VLE") + outlinedProtoLogError("Integer value too large to encode into a 8-byte VLE") return 8 } return size @@ -75,7 +75,7 @@ extension UInt64 { func variableLengthEncodeInto(_ buffer: inout [UInt8]) { guard let length = self.safeVariableLengthSize else { // Too big, encode the max UInt62 value instead - Logger.proto.error("Integer value too large to encode into a 8-byte VLE, setting to UInt62 max") + outlinedProtoLogError("Integer value too large to encode into a 8-byte VLE, setting to UInt62 max") UInt64(4_611_686_018_427_387_903).variableLengthEncodeInto(&buffer) return }