Skip to content

Improve debug logging and add tests that it is not evaluated when disabled #26

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Nov 23, 2023
Merged

Improve debug logging and add tests that it is not evaluated when disabled #26

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
12 changes: 10 additions & 2 deletions Sources/OpenAPIURLSession/URLSessionTransport.swift
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ import Foundation
@preconcurrency import struct Foundation.URLComponents
@preconcurrency import struct Foundation.Data
@preconcurrency import protocol Foundation.LocalizedError
@preconcurrency import class Foundation.FileHandle
#if canImport(FoundationNetworking)
@preconcurrency import struct FoundationNetworking.URLRequest
@preconcurrency import class FoundationNetworking.URLSession
Expand Down Expand Up @@ -230,10 +231,17 @@ var debugLoggingEnabled: Bool {
get { _debugLoggingEnabled.withLockedValue { $0 } }
set { _debugLoggingEnabled.withLockedValue { $0 = newValue } }
}
func debug(_ items: Any..., separator: String = " ", terminator: String = "\n") {
private let _standardErrorLock = LockStorage.create(value: FileHandle.standardError)
func debug(_ message: @autoclosure () -> String, function: String = #function, file: String = #file, line: UInt = #line)
{
assert(
{
if debugLoggingEnabled { print(items, separator: separator, terminator: terminator) }
if debugLoggingEnabled {
_standardErrorLock.withLockedValue {
let logLine = "[\(function) \(file.split(separator: "/").last!):\(line)] \(message())\n"
$0.write(Data((logLine).utf8))
}
}
return true
}()
)
Expand Down
14 changes: 7 additions & 7 deletions .../OpenAPIURLSessionTests/AsyncBackpressuredStreamTests/AsyncBackpressuredStreamTests.swift
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -51,7 +51,7 @@ final class AsyncBackpressuredStreamTests: XCTestCase {
group.addTask {
while true {
backPressureEventContinuation.yield(())
print("Yielding")
debug("Yielding")
try await source.asyncWrite(contentsOf: [1])
}
}
Expand All @@ -64,12 +64,12 @@ final class AsyncBackpressuredStreamTests: XCTestCase {
await backPressureEventIterator.next()
await backPressureEventIterator.next()

print("Waited 4 times")
debug("Waited 4 times")

_ = try await iterator.next()
_ = try await iterator.next()
_ = try await iterator.next()
print("Consumed three")
debug("Consumed three")

await backPressureEventIterator.next()
await backPressureEventIterator.next()
Expand All @@ -91,12 +91,12 @@ final class AsyncBackpressuredStreamTests: XCTestCase {
group.addTask {
@Sendable func yield() {
backPressureEventContinuation.yield(())
print("Yielding")
debug("Yielding")
source.write(contentsOf: [1]) { result in
switch result {
case .success: yield()

case .failure: print("Stopping to yield")
case .failure: debug("Stopping to yield")
}
}
}
Expand All @@ -112,12 +112,12 @@ final class AsyncBackpressuredStreamTests: XCTestCase {
await backPressureEventIterator.next()
await backPressureEventIterator.next()

print("Waited 4 times")
debug("Waited 4 times")

_ = try await iterator.next()
_ = try await iterator.next()
_ = try await iterator.next()
print("Consumed three")
debug("Consumed three")

await backPressureEventIterator.next()
await backPressureEventIterator.next()
Expand Down
7 changes: 4 additions & 3 deletions Tests/OpenAPIURLSessionTests/NIOAsyncHTTP1TestServer.swift
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@
import NIOCore
import NIOPosix
import NIOHTTP1
@testable import OpenAPIURLSession

final class AsyncTestHTTP1Server {

Expand Down Expand Up @@ -58,10 +59,10 @@ final class AsyncTestHTTP1Server {
for try await connectionChannel in inbound {
group.addTask {
do {
print("Sevrer handling new connection")
debug("Sevrer handling new connection")
try await connectionHandler(connectionChannel)
print("Server done handling connection")
} catch { print("Server error handling connection: \(error)") }
debug("Server done handling connection")
} catch { debug("Server error handling connection: \(error)") }
}
}
}
Expand Down
2 changes: 1 addition & 1 deletion ...nAPIURLSessionTests/URLSessionBidirectionalStreamingTests/HTTPBodyOutputStreamTests.swift
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@ import XCTest

// swift-format-ignore: AllPublicDeclarationsHaveDocumentation
class HTTPBodyOutputStreamBridgeTests: XCTestCase {
static override func setUp() { OpenAPIURLSession.debugLoggingEnabled = true }
static override func setUp() { OpenAPIURLSession.debugLoggingEnabled = false }

func testHTTPBodyOutputStreamInputOutput() async throws {
let chunkSize = 71
Expand Down
13 changes: 7 additions & 6 deletions ...penAPIURLSessionTests/URLSessionBidirectionalStreamingTests/MockInputStreamDelegate.swift
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@
#if canImport(Darwin)

import Foundation
@testable import OpenAPIURLSession

/// Reads one byte at a time from the stream, regardless of how many bytes are available.
///
Expand All @@ -39,7 +40,7 @@ final class MockInputStreamDelegate: NSObject, StreamDelegate {
self.inputStream.open()
}

deinit { print("Input stream delegate deinit") }
deinit { debug("Input stream delegate deinit") }

private func readAndResumeContinuation() {
dispatchPrecondition(condition: .onQueue(Self.streamQueue))
Expand All @@ -52,15 +53,15 @@ final class MockInputStreamDelegate: NSObject, StreamDelegate {
}
switch buffer.count {
case -1:
print("Input stream delegate error reading from stream: \(inputStream.streamError!)")
debug("Input stream delegate error reading from stream: \(inputStream.streamError!)")
inputStream.close()
continuation.resume(throwing: inputStream.streamError!)
case 0:
print("Input stream delegate reached end of stream; will close stream")
debug("Input stream delegate reached end of stream; will close stream")
self.close()
continuation.resume(returning: nil)
case let numBytesRead where numBytesRead > 0:
print("Input stream delegate read \(numBytesRead) bytes from stream: \(buffer)")
debug("Input stream delegate read \(numBytesRead) bytes from stream: \(buffer)")
continuation.resume(returning: buffer)
default: preconditionFailure()
}
Expand All @@ -85,12 +86,12 @@ final class MockInputStreamDelegate: NSObject, StreamDelegate {
func close(withError error: (any Error)? = nil) {
self.inputStream.close()
Self.streamQueue.async { self.state = .closed(error) }
print("Input stream delegate closed stream with error: \(String(describing: error))")
debug("Input stream delegate closed stream with error: \(String(describing: error))")
}

func stream(_ stream: Stream, handle event: Stream.Event) {
dispatchPrecondition(condition: .onQueue(Self.streamQueue))
print("Input stream delegate received event: \(event)")
debug("Input stream delegate received event: \(event)")
switch event {
case .hasBytesAvailable:
switch state {
Expand Down
24 changes: 12 additions & 12 deletions ...onTests/URLSessionBidirectionalStreamingTests/URLSessionBidirectionalStreamingTests.swift
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@ import XCTest

class URLSessionBidirectionalStreamingTests: XCTestCase {
// swift-format-ignore: AllPublicDeclarationsHaveDocumentation
static override func setUp() { OpenAPIURLSession.debugLoggingEnabled = true }
static override func setUp() { OpenAPIURLSession.debugLoggingEnabled = false }

func testBidirectionalEcho_PerChunkRatchet_1BChunk_1Chunks_1BUploadBuffer_1BDownloadWatermark() async throws {
try await testBidirectionalEchoPerChunkRatchet(
Expand Down Expand Up @@ -329,31 +329,31 @@ class URLSessionBidirectionalStreamingTests: XCTestCase {
)
)
)
print("Server sent response head")
debug("Server sent response head")
for i in 1...numResponseChunks {
try await outbound.write(.body(ByteBuffer(bytes: responseChunk)))
print("Server sent body chunk \(i)/\(numResponseChunks) of \(responseChunk.count)")
debug("Server sent body chunk \(i)/\(numResponseChunks) of \(responseChunk.count)")
}
case .body: preconditionFailure()
case .end:
try await outbound.write(.end(nil))
print("Server sent response end")
debug("Server sent response end")
}
}
}
}
print("Server running on 127.0.0.1:\(serverPort)")
debug("Server running on 127.0.0.1:\(serverPort)")

// Send the request.
print("Client starting request")
debug("Client starting request")
let (response, responseBody) = try await URLSession.shared.bidirectionalStreamingRequest(
for: HTTPRequest(method: .get, scheme: nil, authority: nil, path: "/"),
baseURL: URL(string: "http://127.0.0.1:\(serverPort)")!,
requestBody: nil,
requestStreamBufferSize: 16 * 1024 * 1024,
responseStreamWatermarks: responseStreamWatermarks
)
print("Client received response head: \(response)")
debug("Client received response head: \(response)")
XCTAssertEqual(response.status, .ok)

switch verification {
Expand All @@ -362,10 +362,10 @@ class URLSessionBidirectionalStreamingTests: XCTestCase {
var unprocessedBytes = ByteBuffer()
var numProcessedChunks = 0
for try await receivedResponseChunk in responseBody! {
print("Client received some response body bytes (numBytes: \(receivedResponseChunk.count))")
debug("Client received some response body bytes (numBytes: \(receivedResponseChunk.count))")
unprocessedBytes.writeBytes(receivedResponseChunk)
while unprocessedBytes.readableBytes >= responseChunk.count {
print("Client reconstructing and verifying chunk \(numProcessedChunks+1)/\(numResponseChunks)")
debug("Client reconstructing and verifying chunk \(numProcessedChunks+1)/\(numResponseChunks)")
XCTAssertEqual(
ArraySlice(unprocessedBytes.readBytes(length: responseChunk.count)!),
responseChunk
Expand All @@ -379,14 +379,14 @@ class URLSessionBidirectionalStreamingTests: XCTestCase {
case .count:
var numBytesReceived = 0
for try await receivedResponseChunk in responseBody! {
print("Client received some response body bytes (numBytes: \(receivedResponseChunk.count))")
debug("Client received some response body bytes (numBytes: \(receivedResponseChunk.count))")
numBytesReceived += receivedResponseChunk.count
}
XCTAssertEqual(numBytesReceived, responseChunk.count * numResponseChunks)
case .delay(let delay):
for try await receivedResponseChunk in responseBody! {
print("Client received some response body bytes (numBytes: \(receivedResponseChunk.count))")
print("Client doing fake work for \(delay)s")
debug("Client received some response body bytes (numBytes: \(receivedResponseChunk.count))")
debug("Client doing fake work for \(delay)s")
try await Task.sleep(nanoseconds: UInt64(delay.nanoseconds))
}
}
Expand Down
Loading