Add Debugging My Gemini NWProtocolFramer Implementation

site/css/main.scss

@@ -219,6 +219,15 @@ article {
 			background: var(--accent-color);
 		}
 
+		blockquote {
+			font-style: italic;
+			border-left: 3px solid var(--accent-color);
+			// use margin for vertical spacing so space is shared with elements that come before/after
+			// and padding for horizontal so that the space is between the border and the text
+			margin: 20px 0;
+			padding: 0 40px;
+		}
+
 		a::before, a::after,
 		p code {
 			word-break: break-all;
@@ -229,16 +238,8 @@ article {
 			border: 1px solid var(--aside-border);
 			padding: 15px;
 			font-size: 1rem;
-			left: 100%;
 			box-sizing: border-box;
 
-			&:not(.inline) {
-				width: 50%;
-				position: absolute;
-				margin-left: 15px;
-				transform: translateY(-50%);
-			}
-
 			p:first-child { margin-top: 0; }
 			p:last-child { margin-bottom: 0; }
 		}
@@ -734,11 +735,16 @@ table {
 	}
 }
 
-@media (max-width: 1455px) {
+// 720 + 30 + 720 + 15
-	article .article-content aside {
+// main content, l/r container padding, aside width (50% on each side), outer edge margin
-		position: initial;
+// inner edge margin overlaps with container padding
-		width: 100%;
+@media (min-width: 1485px) {
-		margin: 0;
+	article .article-content aside:not(.inline) {
-		transform: unset;
+		width: 50%;
+		position: absolute;
+		left: 100%;
+		margin-left: 15px;
+		margin-right: 15px;
+		transform: translateY(-50%);
 	}
 }

site/posts/2020-07-22-gemini-network-framework.md

@@ -135,7 +135,7 @@ Parsing input (i.e., the response from the server) is somewhat more complicated.
 
 First off is the status code (and the following space character). In the protocol implementation, there's a optional `Int` property used as temporary storage for the status code. If the `tempStatusCode` property is `nil`, the `parseInput` method is called on the framer. The length is always going to be 3 bytes (1 for each character of the status code, and 1 for the space). Inside the `parseInput` closure, if the buffer is not present or it's not of the expected length, the closure returns zero to indicate that no bytes were consumed. Otherwise, the contents of the buffer are converted to a String and then parsed into an integer^[If you were really building an implementation of the Gemini protocol, you would probably want to wrap the raw integer status code in something else to avoid dealing with magic numbers throughout your codebase. An enum backed by integer values, perhaps.] and stored in the temporary property (this is okay because the closure passed to `parseInput` is non-escaping, meaning it will be called before `parseInput` returns). Finally, the closure returns `3` to indicate that three bytes were consumed and should not be provided again as input.
 
-Outside the `if`, there's a `guard` that checks that there is a status code present, either from immediately prior or potentially from a previous iteration of the loop/method. If not, it returns `3` from the `handleInput` method, telling the framework that that it expects there to be at least 3 bytes available before it's called again. The reason the status code is stored in a class property, and why the code ensures that it's `nil` before trying to parse, is so that if some subsequent parse step fails and the method returns and has to be invoked again in the future, it doesn't try to re-parse the status code because the actual data for it has already been consumed.
+Outside the `if`, there's a `guard` that checks that there is a status code present, either from immediately prior or potentially from a previous invocation of the method. If not, it returns `3` from the `handleInput` method, telling the framework that that it expects there to be at least 3 bytes available before it's called again. The reason the status code is stored in a class property, and why the code ensures that it's `nil` before trying to parse, is so that if some subsequent parse step fails and the method returns and has to be invoked again in the future, it doesn't try to re-parse the status code because the actual data for it has already been consumed.
 
 ```swift
 class GeminiProtocol: NWProtocolFramerImplementation {
@@ -167,6 +167,8 @@ This time, the closure once again validates that there is enough data to at leas
 
 One key difference between parsing the meta string and parsing the status code is that if the status code couldn't be parsed, the exact number of bytes that must be available before it can be attempted again is always the same: 3. That's not true when parsing the meta text: the number of bytes necessary for a retry is depedent on the number of bytes that were unsuccessfully attempted to be parsed. For that reason, there's also an optional `Int` variable which stores the length of the buffer that the closure attempted to parse. When the closure executes, the variable is set to the length of the buffer. If, inside the closure, the code fails to find the carriage return and line feed characters anywhere, one of two things happens: If the buffer is shorter than 1026 bytes, the closure returns zero to indicate that nothing was consumed. Then, since there's no string, the `handleInput` will return 1 plus the attempted meta length, indicating to the framework that it should wait until there is at least 1 additional byte of data available before calling `handleInput` again. If no CRLF was found, and the buffer count is greater than or equal to 1026, the closure simply aborts with a `fatalError` because the protocol specifies that the cannot be longer than 1024 bytes (it would be better to set some sort of 'invalid' flag on the response object and then pass that along to be handled by higher-level code, but for the purposes of this blog post, that's not interesting code). In the final case, if parsing the meta failed and the `attemptedMetaLength` variable is `nil`, that means there wasn't enough data available, so we simply return 2.
 
+**Update July 7, 2021:** The eagle-eyed among you may notice that there's a flaw in the following implementation involving what happens when meta parsing has to be retried. I discovered this myself and discussed it in [this follow-up post](/2021/gemini-client-debugging/).
+
 ```swift
 class GeminiProtocol: NWProtocolFramerImplementation {
 	// ...
@@ -214,18 +216,16 @@ class GeminiProtocol: NWProtocolFramerImplementation {
 }
 ```
 
-With the entire header parsed, an object can be constructed to represent the response metadata and an `NWProtocolFramer.Message` created to contain it. Actually delivering the
+With the entire header parsed, an object can be constructed to represent the response metadata and an `NWProtocolFramer.Message` created to contain it.
 
 ```swift
 class GeminiProtocol: NWProtocolFramerImplementation {
 	// ...
 	func handleInput(framer: NWProtocolFramer.Instance) -> Int {
-		while true {
 		// ...
 		let header = GeminiResponseHeader(status: statusCode, meta: meta)
 		let message = NWProtocolFramer.Message(geminiResponseHeader: header)
 	}
-	}
 }
 ```
 
@@ -255,23 +255,22 @@ extension NWProtocolFramer.Message {
 }
 ```
 
-To actually pass the message off to the client of the protocol implementation, the `deliverInputNoCopy` method is used. Since the `handleInput` method has already parsed all of the data it needs to, and the response body is defined by the protocol to just be the rest of the response data, the `deliverInputNoCopy` method is a useful way of passing the data straight through to the protocol client, avoiding an extra memory copy. Since the Gemini protocol doesn't define any specific way of finding the end of a response, using `.max` as the length and specifying that the request is complete just delivers as much data to the protocol client as possible, stopping only when the connection closes.
+To actually pass the message off to the client of the protocol implementation, the `deliverInputNoCopy` method is used. Since the `handleInput` method has already parsed all of the data it needs to, and the response body is defined by the protocol to just be the rest of the response data, the `deliverInputNoCopy` method is a useful way of passing the data straight through to the protocol client, avoiding an extra memory copy. If the protocol had to transform the body of the response somehow, it could be read as above and then delivered to the protocol client with the `deliverInput(data:message:isComplete:)` method.
 
-If the protocol had to transform the body of the response somehow, it could be read as above and then delivered to the protocol client with the `deliverInput(data:message:isComplete:)` method.
+If the request was successful (i.e., the status code was in the 2x range), we try to receive as many bytes as possible, because the protocol doesn't specify a way of determining the length of a response. All other response codes are defined to never have response bodies, so we don't need to deliver any data. Using `.max` is a little bit weird, since we don't actually _need_ to receive that many bytes. But it seems to work perfectly fine in practice: once all the input is received and the other side closes the connection, the input is delivered without error.
 
-Here, it's also wrapped in an infinite loop, so that if the call to `deliverInputNoCopy` returns `true`, it loops and attempts it again. Unfortunately, the specific meaning of the deliver methods' return values as well the exact reason for the infinite retries is not specified in the docs. But this is what the sample project does and it doesn't seem to cause problems in practice, so ¯\\_(ツ)_/¯
+Annoyingly, the return value of the Swift function is entirely undocumented (even in the generated headers, where the parameters are). Fortunately, the C equivalent (`nw_framer_deliver_input_no_copy`) is more thoroughly documented and provides an answer: the function returns a boolean indicating whether the input was delivered immediately or whether the framework will wait for more bytes before delivering it. We don't care at all about this, so we just discard the return value.
+
+Finally, we return 0 from `handleInput`. Ordinarily, this would mean that there must be zero or more bytes available before the framework calls us again. But, because we've delivered all the available input, that will never happen.
 
 ```swift
 class GeminiProtocol: NWProtocolFramerImplementation {
 	// ...
 	func handleInput(framer: NWProtocolFramer.Instance) -> Int {
 		// ...
-		while true {
+		_ = framer.deliverInputNoCopy(length: statsCode.isSuccess ? .max : 0, message: message, isComplete: true)
-			if !framer.deliverInputNoCopy(length: .max, message: message, isComplete: true) {
 		return 0
 	}
-		}
-	}
 }
 ```
 

site/posts/2021-07-07-gemini-client-debugging.md

@@ -0,0 +1,91 @@
+```
+metadata.title = "Debugging My Gemini NWProtocolFramer Implementation"
+metadata.tags = ["swift", "gemini"]
+metadata.date = "2021-07-07 23:32:42 -0400"
+metadata.shortDesc = ""
+metadata.slug = "gemini-client-debugging"
+```
+
+I recently ran into an issue with the Network.framework Gemini client I'd [previously implemented](/2020/gemini-network-framework/) that turned out to be somewhat perplexing. So, I thought I'd write a brief post about it in case anyone finds it interesting or helpful.
+
+<!-- excerpt-end -->
+
+The gist of the issue is that when connecting to a certain host, the connection would hang indefinitely. The issue was 100% reproducible in my app, both in the simulator and on an actual device, in all manner of network conditions. What led me to believe that it was an issue with my implementation was that the problem only happened with a single host (I suspect the incompatibility was with whatever server software was being used) and the fact that I could not reproduce the issue with any other client.
+
+My initial attempts at debugging were fruitless. Every handler and callback I had was just never getting called. There was no error that was being swallowed or anything, just silence. Eventually I set a breakpoint in the `handleInput` method of my `NWProtocolFramerImplementation`.
+
+Stepping through[^1], I saw the status code get parsed successfully. Then it moved on to parsing the response meta, a string of up to 1024 bytes followed by a carriage return and line feed.
+
+[^1]: Debugging this is kind of painful because much of the actual work is done inside the closure passed to `NWProtocolFramer.Instance.parseInput`. It's invoked synchronously, so it does affect control flow, but if you click Step Over at the wrong time, you can accidentally skip a whole critical chunk of code.
+
+Next, I paused inside the `parseInput` closure that's responsible for parsing the meta string. The buffer that I received was 11 bytes long. I was immediately wary because I'd seen that number before in this context—it's the length of `text/gemini`. Indeed, printing out `String(bytes: buffer, encoding: .utf8)` revealed that it was indeed the meta string I was expecting. But it was just the meta string, not including the CR/LF pair that's supposed to follow it.
+
+Continuing to step through, I saw the closure return 0, indicating that no bytes were consumed, because the CRLF was missing. After that, the main body of the `handleInput` method would see that the meta wasn't found and would itself return the number of bytes it expected to receive before it should be invoked again. It does this by adding 1 to the length of the buffer from which meta parsing failed. So, the next time `handleInput` is called by the framework, there should be at least 12 bytes available.
+
+After hitting resume, the debugger trapped again in the `parseInput` closure for the meta. I checked `buffer.count` and found... 11 bytes. I know `handleInput` returned 12, so why did I still only have 11 bytes?
+
+The realization I came to, after puzzling over this for a couple days, is that `parseInput` behaves a little weirdly, though in a way that's technically correct. It seems that even if more data is available in some internal buffer of the framer's—which we know there must be because `handleInput` was invoked again after we returned 12 earlier—we won't receive all of it. It's not _wrong_, 11 bytes is indeed at least 2 and no more than 1026, but it's certainly unintuitive.
+
+
+To verify this behavior, I tweaked my code to call `parseInput` with a minimum length of 13 instead of 2 the second attempt to parse meta. Lo and behold, it worked. The buffer now had 13 bytes of data: the full meta string and the CR/LF.
+
+And that explains the user-facing issue that led to all this. A few attempts at parsing would fail, but then the server would stop sending data because there was nothing left, so `handleInput` would never be called, leaving the Gemini request in a waiting state forever.
+
+So, to properly fix the issue what needs to happen is we have to be smarter about the `minimumIncompleteLength` on subsequent attempts to parse the metadata. To do this, I saved the length of the last buffer for which meta parsing was attempted as an instance variable in the framer implementation. With that, we can determine how many bytes we _actually_ need before trying again.
+
+```swift
+class GeminiProtocol: NWProtocolFramerImplementation {
+	// ...
+	private var lastAttemptedMetaLength: Int? = nil
+	// ...
+
+	func handleInput(framer: NWProtocolFramer.Instance) -> Int {
+		// ...
+		if tempMeta == nil {
+			let min: Int
+			if let lastAttemptedMetaLength = lastAttemptedMetaLength {
+				min = lastAttemptedMetaLength + 1
+			} else {
+				min = 2
+			}
+			_ = framer.parseInput(minimumIncompleteLength: min, maximumLength: 1024 + 2) { (buffer, isComplete) -> Int in
+				guard let buffer = buffer else { return }
+				self.lastAttemptedMetaLength = buffer.count
+				// ...
+			}
+		}
+		guard let meta = tempMeta else {
+			if let attempted = self.lastAttemptedMetaLength {
+				return attempted + 1
+			} else {
+				return 2
+			}
+		}
+		// ...
+	}
+
+	// ...
+}
+```
+
+The minimum incomplete length still defaults to 2 because on the first attempt to parse, we don't have previous attempt info and the only thing we know is that there must be a carriage return and line feed (as best as I can interpret it, the Gemini spec doesn't say that there must be meta text, so it could be zero bytes).
+
+With that, the original issue is finally fixed and requests to the problematic server complete successfully.
+
+My best guess for why this was happening in the first place and only in such specific circumstances is this: the specific server software being used was sending the meta text over the wire separately from the CRLF. This could mean they arrive at my device separately and are thus stored by in two separate "chunks". Then, when `parseInput` is called, Network.framework simply starts looking through the stored chunks in order. And, since the first chunk is longer than `minimumIncompleteLength`, it's the only one that's returned.
+
+There's a note in the Network.framework header comments[^2] for `nw_framer_parse_input` that leads me to believe this. It says, with regard to the `temp_buffer` parameter:
+
+[^2]: Annoyingly it's not present in the Swift docs nor the Objective-C docs. Seriously, this is not good. There's a wealth of information in the header comments that's not present in the regular docs. If you feel so inclined, you can dupe FB9163518: "Many NWProtocolFramer.Instance methods are missing docs that are present in the generated headers".
+
+> If it is NULL, the buffer provided in the completion will not copy unless a copy is required to provide the minimum bytes as a contiguous buffer.
+
+The possibility of a copy being needed to form a contiguous buffer implies that there could be discontiguous data, which lines up with my "chunks" hypothesis and would explain the behavior I observed.
+
+<aside>
+
+Fun fact, the C function corresponding to this Swift API, `nw_framer_parse_input`, takes a maximum length, but it also lets to pass in your own temporary buffer, in the form of a `uint8_t*`. It's therefore up to the caller to ensure that the buffer that's pointed to is at least as long as the maximum length. This seems like a place ripe for buffer overruns in sloppily written protocol framer implementations.
+
+</aside>
+
+Anyhow, if you're interested, you can find the current version of my Gemini client implementation (as of this post) [here](https://git.shadowfacts.net/shadowfacts/Gemini/src/commit/3055cc339fccad99ab064f2daccdb65efa8024c0/GeminiProtocol/GeminiProtocol.swift).