Bluetooth Background Mode: Network-related errors and sporadic failures

Hi,

I've read over many of the helpful posts on background modes ([1], [2], and responses to my thread [3]) but am encountering something that doesn't quite line up with my understanding.

Background

My app is using Bluetooth background mode in order to receive data from a peripheral periodically and then perform a network request (eventually, this will involve two network requests, one of them being an upload of audio, which will be a much larger transfer of up to a couple hundred KB, possibly requiring m4a compression first).

In background mode, all the Bluetooth messages (currently a small string) are received reliably. The app is woken up and from my understanding, given some time to run in the background. I perform a POST request using URLSession.shared.dataTask(with: request).

Problem Encountered

These often succeed but sporadically fail with a timeout in background mode and with the error message "connection was lost". Furthermore, nearly every request in background mode is associated with some sort of connection error that appears in the log. Given that many of the requests still succeed, I'm not sure what to make of these. I see a variety of different ones. For example:

Case 1:

2023-05-23 16:33:49.428668-0700 ChatGPT for Monocle[4775:1088487] [connection] nw_read_request_report [C1] Receive failed with error "Socket is not connected"
2023-05-23 16:33:49.429633-0700 ChatGPT for Monocle[4775:1088487] [connection] nw_read_request_report [C1] Receive failed with error "Socket is not connected"
2023-05-23 16:33:49.431677-0700 ChatGPT for Monocle[4775:1088487] [connection] nw_read_request_report [C1] Receive failed with error "Socket is not connected"
2023-05-23 16:33:49.440358-0700 ChatGPT for Monocle[4775:1088487] [quic] quic_conn_send_frames_for_key_state_block_invoke [C1.1.1.1:2] [-0151a6eeef6cab8c6b53cceead6cada7cf118a4e] unable to request outbound data
2023-05-23 16:33:49.440528-0700 ChatGPT for Monocle[4775:1088487] [quic] quic_conn_send_frames_for_key_state_block_invoke [C1.1.1.1:2] [-0151a6eeef6cab8c6b53cceead6cada7cf118a4e] unable to request outbound data
2023-05-23 16:33:49.440640-0700 ChatGPT for Monocle[4775:1088487] [quic] quic_conn_send_frames_for_key_state_block_invoke [C1.1.1.1:2] [-0151a6eeef6cab8c6b53cceead6cada7cf118a4e] unable to request outbound data
2023-05-23 16:33:49.440784-0700 ChatGPT for Monocle[4775:1088487] [quic] quic_conn_send_frames_for_key_state_block_invoke [C1.1.1.1:2] [-0151a6eeef6cab8c6b53cceead6cada7cf118a4e] unable to request outbound data
2023-05-23 16:33:49.441459-0700 ChatGPT for Monocle[4775:1088487] [quic] quic_conn_send_frames_for_key_state_block_invoke [C1.1.1.1:2] [-0151a6eeef6cab8c6b53cceead6cada7cf118a4e] unable to request outbound data
2023-05-23 16:33:49.441684-0700 ChatGPT for Monocle[4775:1088487] [quic] quic_conn_send_frames_for_key_state_block_invoke [C1.1.1.1:2] [-0151a6eeef6cab8c6b53cceead6cada7cf118a4e] unable to request outbound data
2023-05-23 16:33:49.445598-0700 ChatGPT for Monocle[4775:1088487] [connection] nw_endpoint_handler_add_write_request [C1.1.1.1 104.18.6.192:443 failed channel-flow (satisfied (Path is satisfied), viable, interface: en0[802.11], ipv4, ipv6, dns)] Cannot send after flow table is released
2023-05-23 16:33:49.445773-0700 ChatGPT for Monocle[4775:1088487] [connection] nw_write_request_report [C1] Send failed with error "Socket is not connected"
2023-05-23 16:33:49.446925-0700 ChatGPT for Monocle[4775:1088487] Connection 1: received failure notification
2023-05-23 16:33:49.447348-0700 ChatGPT for Monocle[4775:1088487] Connection 1: write error 1:57
2023-05-23 16:33:49.464436-0700 ChatGPT for Monocle[4775:1088487] [connection] nw_endpoint_handler_unregister_context [C1.1.1.1 104.18.6.192:443 failed channel-flow (satisfied (Path is satisfied), viable, interface: en0[802.11], ipv4, ipv6, dns)] Cannot unregister after flow table is released
2023-05-23 16:33:49.464974-0700 ChatGPT for Monocle[4775:1088487] [] nw_endpoint_flow_fillout_data_transfer_snapshot copy_info() returned NULL

Case 2:

2023-05-23 16:34:09.422783-0700 ChatGPT for Monocle[4775:1088784] [connection] nw_read_request_report [C3] Receive failed with error "Socket is not connected"
2023-05-23 16:34:09.423511-0700 ChatGPT for Monocle[4775:1088784] [connection] nw_read_request_report [C3] Receive failed with error "Socket is not connected"
2023-05-23 16:34:09.425478-0700 ChatGPT for Monocle[4775:1088784] [connection] nw_read_request_report [C3] Receive failed with error "Socket is not connected"
2023-05-23 16:34:09.434263-0700 ChatGPT for Monocle[4775:1088784] [quic] quic_conn_send_frames_for_key_state_block_invoke [C3.1.1.1:2] [-01809801f02b5c3795812501322b6f9d3c91236f] unable to request outbound data

The code that is generating these requests is fairly straightforward:

public func send(query: String, apiKey: String, model: String, completion: @escaping (String, ChatGPTError?) -> Void) {
        let requestHeader = [
            "Authorization": "Bearer \(apiKey)",
            "Content-Type": "application/json"
        ]

        _payload["model"] = model

        if var messages = _payload["messages"] as? [[String: String]] {
            messages.append([ "role": "user", "content": "\(query)" ])
            _payload["messages"] = messages
        }

        let jsonPayload = try? JSONSerialization.data(withJSONObject: _payload)
        let url = URL(string: "https://api.openai.com/v1/chat/completions")!
        var request = URLRequest(url: url)
        request.httpMethod = "POST"
        request.allHTTPHeaderFields = requestHeader
        request.httpBody = jsonPayload
        _task = URLSession.shared.dataTask(with: request) { data, response, error in
            if let error = error {
                DispatchQueue.main.async { completion("", ChatGPTError.networkRequestFailed(error: error)) }
                return
            }

            if let data = data {
                let (contentError, response) = self.extractContent(from: data)
                if let contentError = contentError {
                    DispatchQueue.main.async { completion("", contentError) }
                } else if let response = response {
                    DispatchQueue.main.async { completion(response, nil) }
                }
                return
            }

            DispatchQueue.main.async { completion("", ChatGPTError.responsePayloadParseError) }
        }
        _task?.resume()
    }

Questions

  1. Is there any way to make this process more reliable? I assume the error messages are meaningful and should not be ignored.

  2. If not, will I end up encountering issues when trying to upload larger payloads?

Thank you! -- B.

Up vote post of trzy Down vote post of trzy
902 views
Posted by
trzy
Reply
Add a Comment

Replies

I was able to eliminate these errors by configuring a custom URLSession for background mode however there are is still an issue when I attempt to throw SFSpeech into the mix to perform a voice transcription request before uploading its results to the server. I get this error: Lost connection to background transfer service

This post mentions that dataTask isn't supposed to work with a background configuration, but for me it does. I don't think I can use downloadRequest because I'm making a POST request.

Why would using SFSpeech (and therefore starting the dataTask within one of its delegate calls) cause this issue?

Once again the sequence of events is:

  1. Bluetooth data received in background mode
  2. SFSpeech kicked off to convert speech to text
  3. POST request fired on a background URLSession in SFSpeech delegate handler

Here is how I configure the URLSession:

        let configuration = URLSessionConfiguration.background(withIdentifier: "ChatGPT")
        configuration.isDiscretionary = false
        configuration.shouldUseExtendedBackgroundIdleMode = true
        configuration.sessionSendsLaunchEvents = true
        configuration.allowsConstrainedNetworkAccess = true
        configuration.allowsExpensiveNetworkAccess = true
        _session = URLSession(configuration: configuration, delegate: self, delegateQueue: nil)

Thank you,

-- B.

Posted by
trzy
Up vote reply of trzy Down vote reply of trzy
Add a Comment

Are you doing anything to prevent your app from being suspended while the network request is in flight? If not, that’s probably what’s happening here, which would explain the weird behaviour you’re seeing.

There are numerous subsystems that can resume (or relaunch) your app in the background. Some give you a completion handler to call when you’re done. These prevent your app from suspending until you call that completion handler [1]. Others don’t, and the subsystem just grants you a small amount of background execution time (typically a few seconds). If you start a network request, there’s no guarantee that the request will complete in time. If not, your app gets suspended and weird things start happening.

There are two ways around this:

The first approach is best for low-latency requests. However, there’s no guarantee it’ll yield enough background execution time to complete your request, especially in adverse network conditions. If not, and the background task expires, you can at least cancel it cleanly. You could also choose to start a replacement request in a background session.

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

[1] Applying some sort of timeout to prevent unbounded background execution. The response to overrunning that timeout is usually that your app gets killed by the watchdog.

Posted by
eskimo
Up vote reply of eskimo Down vote reply of eskimo
Add a Comment