kean / Pulse

Network logger for Apple platforms
https://pulselogger.com
MIT License
6.18k stars 294 forks source link

Crash accessing `URLSessionTask.currentRequest` and `URLRequest.allHTTPHeaderFields` #268

Open djtarazona opened 1 month ago

djtarazona commented 1 month ago

I'm fairly consistently getting a crash in NetworkLogger. It looks like Pulse may be accessing URLSessionTask.currentRequest and URLRequest.allHTTPHeaderFields in unsafe ways.

Screenshot 2024-06-24 at 19 51 06 Screenshot 2024-06-24 at 19 30 21

This issue is very similar to one I had with Datadog earlier. It appears URLSessionTask and URLRequest.allHTTPHeaderFields may not be thread-safe. See Datadog's solution for more info.

Reviewing NetworkLogger, it looks like Pulse is accessing URLSessionTask.currentRequest and URLRequest.allHTTPHeaderFields on a background NSManagedObjectContext queue.

Should a solution similar to Datadog's be used? Where the data needed is copied (see ImmutableRequest) before sending to the background queue?

kean commented 1 month ago

Thanks for reporting it!

Should a solution similar to Datadog's be used? Where the data needed is copied (see ImmutableRequest) before sending to the background queue?

I think that makes sense, yes.

ncreated commented 1 month ago

👋 Hi, 🐶 Datadog here. To add more context, the fix with capturing ImmutableRequest didn't seem to mute this problem entirely and we still got new reports. Ultimately we decided to avoid using request.allHTTPHeaderFields and instead we call request.value(forHTTPHeaderField:) to only read headers known by the SDK. Still waiting for users confirmation if this solves the problem.

Not sure how request.value(forHTTPHeaderField:) approach is relevant for general-purpose library like Pulse (I can imagine "reading all headers" is a requirement here). I'll watch this thread to see if you lead to interesting conclusions. We suspect this is Apple bug with allHTTPHeaderFields being not thread-safe, but we didn't manage to provide reproducible scenario to Apple.

kean commented 1 month ago

Hey, thanks for providing context, Maciek. Yeah, I kind of need to read allHTTPHeaderFields, so I'll probably have to look for other options.

djtarazona commented 1 month ago

I switched to using a URLSessionDelegate instead of an Alamofire EventMonitor to make most calls to NetworkLogger.

Because Alamofire only accepts an Alamofire SessionDelegate, I had to subclass SessionDelegate, adding in the calls to NetworkLogger:

class PulseSessionDelegate: SessionDelegate {

    let logger: NetworkLogger

    init(logger: NetworkLogger) {
        self.logger = logger

        super.init()
    }

    // MARK: URLSessionTaskDelegate

    func urlSession(_ session: URLSession, didCreateTask task: URLSessionTask) {
        logger.logTaskCreated(task)
    }

    override func urlSession(_ session: URLSession, task: URLSessionTask, didCompleteWithError error: Error?) {
        logger.logTask(task, didCompleteWithError: error)

        super.urlSession(session, task: task, didCompleteWithError: error)
    }

    override func urlSession(_ session: URLSession, task: URLSessionTask, didFinishCollecting metrics: URLSessionTaskMetrics) {
        logger.logTask(task, didFinishCollecting: metrics)

        super.urlSession(session, task: task, didFinishCollecting: metrics)
    }

    override func urlSession(_ session: URLSession, task: URLSessionTask, didSendBodyData bytesSent: Int64, totalBytesSent: Int64, totalBytesExpectedToSend: Int64) {
        if task is URLSessionUploadTask {
            logger.logTask(task, didUpdateProgress: (completed: totalBytesSent, total: totalBytesExpectedToSend))
        }

        super.urlSession(session, task: task, didSendBodyData: bytesSent, totalBytesSent: totalBytesSent, totalBytesExpectedToSend: totalBytesExpectedToSend)
    }

    // MARK: URLSessionDataDelegate

    override func urlSession(_ session: URLSession, dataTask: URLSessionDataTask, didReceive data: Data) {
        logger.logDataTask(dataTask, didReceive: data)

        super.urlSession(session, dataTask: dataTask, didReceive: data)
    }

    // MARK: URLSessionDownloadDelegate

    override func urlSession(_ session: URLSession, downloadTask: URLSessionDownloadTask, didWriteData bytesWritten: Int64, totalBytesWritten: Int64, totalBytesExpectedToWrite: Int64) {
        logger.logTask(downloadTask, didUpdateProgress: (completed: totalBytesWritten, total: totalBytesExpectedToWrite))

        super.urlSession(session, downloadTask: downloadTask, didWriteData: bytesWritten, totalBytesWritten: totalBytesWritten, totalBytesExpectedToWrite: totalBytesExpectedToWrite)
    }
}

I still use an EventMonitor to report parsing results:

class PulseEventMonitor: EventMonitor {

    let logger: NetworkLogger

    init(logger: NetworkLogger) {
        self.logger = logger
    }

    func request<Value>(_ request: DataStreamRequest, didParseStream result: Result<Value, AFError>) {
        guard let task = request.task else { return }

        let error: Error?
        switch result {
            case .success:
                error = nil
            case let .failure(failure):
                error = failure
        }

        logger.logTask(task, didFinishDecodingWithError: error)
    }

    func request(_ request: DataRequest, didParseResponse response: DataResponse<Data?, AFError>) {
        self.request(request, didFinishParsingWithError: response.error)
    }

    func request(_ request: DownloadRequest, didParseResponse response: DownloadResponse<URL?, AFError>) {
        self.request(request, didFinishParsingWithError: response.error)
    }

    func request<Value>(_ request: DataRequest, didParseResponse response: DataResponse<Value, AFError>) {
        self.request(request, didFinishParsingWithError: response.error)
    }

    func request<Value>(_ request: DownloadRequest, didParseResponse response: DownloadResponse<Value, AFError>) {
        self.request(request, didFinishParsingWithError: response.error)
    }

    func request(_ request: Request, didFinishParsingWithError error: Error?) {
        guard let task = request.task else { return }

        switch error {
            case .none:
                logger.logTask(task, didFinishDecodingWithError: nil)
            case let .some(AFError.responseSerializationFailed(reason: .decodingFailed(error: error))):
                logger.logTask(task, didFinishDecodingWithError: error)
            case let .some(error):
                logger.logTask(task, didFinishDecodingWithError: error)
        }
    }
}

Have not been crashing since. 🙂