How to find out network connection error details

Hi,

When running my iOS app in Xcode, I got the following message in the console multiple times:

[connection] nw_read_request_report [C1] Receive failed with error "Operation timed out"

It seems not critical as my app still works, but how can I find out more details of the connection that printed this message? For example, the network request the caused this, or the URL?

Xcode: 15.3

iOS 17

SwiftUI app

Answered by DTS Engineer in 791742022

At the API level? Or while debugging?

If it’s at the API level, please explain more about what you’re trying to do and I’ll opine from there.

For debugging, the key thing in that log is this: [C1]. That uniquely identifies the connection (you’ll also see stuff like [C1.2], where this is the second sub-connection of [C1]). You can use that to search back through the log to find out more about the connection. In some cases that may require you to record private data, per Your Friend the System Log.

If you’re working at the URLSession level, one good trick is to log the local IP / local port / remote IP / remote port tuple of each request. You can this from the transactions available via URLSessionTaskMetrics class. You can then correlate that logging with the logging done by Network framework to work out which URLSession request is running over which Network framework connection.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

At the API level? Or while debugging?

If it’s at the API level, please explain more about what you’re trying to do and I’ll opine from there.

For debugging, the key thing in that log is this: [C1]. That uniquely identifies the connection (you’ll also see stuff like [C1.2], where this is the second sub-connection of [C1]). You can use that to search back through the log to find out more about the connection. In some cases that may require you to record private data, per Your Friend the System Log.

If you’re working at the URLSession level, one good trick is to log the local IP / local port / remote IP / remote port tuple of each request. You can this from the transactions available via URLSessionTaskMetrics class. You can then correlate that logging with the logging done by Network framework to work out which URLSession request is running over which Network framework connection.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

At the API level? Or while debugging?

Either would help. I am using URLSession (with QUIC only) and the app has multiple URLSession and many network requests.

My goal is to figure out which request (or connection) is causing these messages. Right now I am going through the app code and making a bit progress, but still don't have a reliable way to debug such messages quickly.

For debugging, the key thing in that log is this: [C1].

Is there a way for me to log this ID in my app log as well? How do I access this ID info given a URLSession ?

You can then correlate that logging with the logging done by Network framework to work out which URLSession request is...

I can log local IP / port / remote IP / port tuples, but how do I correlate to the message in this question? Maybe I missed something obvious?

Accepted Answer
How do I access this ID info given a URLSession ?

There isn’t a way to do that directly. Honestly, the ability to do that would be super useful and I encourage you to file an enhancement request for us to add it as a property to the task metrics API. Please post your bug number, just for the record.

The indirect way to do that is with the connection tuple, as I outlined earlier. To test this out I created a small Mac app that connects to port 80 on example.com. I then filtered the log for my app and the subsystem com.apple.network. The first log entry I saw was this:

type: info
time: 09:23:31.709387+0100
process: Test757473
subsystem: com.apple.network
category: connection
message: nw_connection_create_with_id [C2] create connection to example.com:80

That tells me the connection ID ([C2]) and the DNS name and port. I then saw this:

type: info
time: 09:23:31.711564+0100
process: Test757473
subsystem: com.apple.network
category: connection
message: nw_resolver_create_dns_getaddrinfo_locked_block_invoke [C2.1] Got 3 DNS results

type: info
time: 09:23:31.711576+0100
process: Test757473
subsystem: com.apple.network
category: connection
message: nw_resolver_create_dns_getaddrinfo_locked_block_invoke [C2.1] Got DNS result type ServiceBinding ifindex=0 example.com example.com. <NULL>

type: info
time: 09:23:31.711585+0100
process: Test757473
subsystem: com.apple.network
category: connection
message: nw_resolver_create_dns_getaddrinfo_locked_block_invoke [C2.1] Got DNS result type Add ifindex=0 example.com example.com. 2606:2800:21f:cb07:6820:80da:af6b:8b2c

type: info
time: 09:23:31.711592+0100
process: Test757473
subsystem: com.apple.network
category: connection
message: nw_resolver_create_dns_getaddrinfo_locked_block_invoke [C2.1] Got DNS result type Add ifindex=0 example.com example.com. 93.184.215.14

This is the DNS resolution results, telling me the inputs Network frameworks Happy Eyeballs algorithm. Note how the connection ID is shown as [C2.1], a ‘child’ of the [C2] we saw earlier.

Later on I saw this:

type: default
time: 09:23:32.064699+0100
process: Test757473
subsystem: com.apple.network
category: connection
message: nw_flow_connected [C2.1.2 93.184.215.14:80 in_progress channel-flow (satisfied (Path is satisfied), viable, interface: utun8, ipv4, ipv6, dns, uses wifi)] Output protocol connected (tcp)

indicating that the child flow is connected. Note that this is a grandchild of the original flow. There’s one of these for each of the connections that Happy Eyeballs ‘races’.

Finally, I saw this:

type: default
time: 09:23:32.066020+0100
process: Test757473
subsystem: com.apple.network
category: connection
message: nw_flow_connected [C2 93.184.215.14:80 in_progress parent-flow (satisfied (Path is satisfied), interface: utun8, ipv4, ipv6, dns, uses wifi)] Output protocol connected (endpoint_flow)

indicating that this caused the parent flow to be connected.

Keep in mind that I’m using TCP here. You’ll see different stuff for a QUIC connection.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

the ability to do that would be super useful and I encourage you to file an enhancement request for us to add it as a property to the task metrics API. Please post your bug number, just for the record.

Thank you for your suggestion! I've opened a ticket: FB14017046 .

And thanks a lot for your detailed example! It's helpful! (I finally realized that I should use Console app to view the system log). I can find the connection details now.

One thing I didn't understand is: why is there "parent" and "child" connection / flow? Are they the "connection" and "stream" in the context of HTTP2/3 ? But even then, how can there be 3 levels of connection ID like C2.1.2?

I've opened a ticket: FB14017046.

Thanks!

One thing I didn't understand is: why is there "parent" and "child" connection / flow?

I don’t fully understand this myself, but I am aware of two situations that produce this:

  • Happy Eyeballs — Network framework leans deep into this concept. So, at least during the connection phase, there’s a one-to-many mapping between the top-level NWConnection object you’re working with and the actual TCP connections (or UDP flows) on the ‘wire’.

  • QUIC — In this protocol, multiple streams are multiplexed over the same connection.

If you combine these you naturally get three levels. However, it’s not obvious why that’s happening in my example, because my use of HTTP (rather than HTTPS) means QUIC isn’t an option. It could be that this goes through a common bottleneck and hence you get the extra level even though it’s not necessary in this case.

One day I’ll have time to research this properly, but today is not that day (-:

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

How to find out network connection error details
 
 
Q