为什么用 URLSessionStreamTask 写会超时？

Question

我正在练习制作URLProtocol 子类。我正在使用URLSessionStreamTask 进行阅读和写作。在尝试子类时，我超时了。我以为我搞砸了我的阅读程序，但添加日志记录表明我没有通过最初的写入！

这是我的子类的简化版本：

import Foundation
import LoggerAPI

class GopherUrlProtocol: URLProtocol {

    enum Constants {
        static let schemeName = "gopher"
        static let defaultPort = 70
    }

    var innerSession: URLSession?
    var innerTask: URLSessionStreamTask?

    override class func canInit(with request: URLRequest) -> Bool { /*...*/ }
    override class func canonicalRequest(for request: URLRequest) -> URLRequest { /*...*/ }

    override func startLoading() {
        Log.entry("Starting up a download")
        defer { Log.exit("Started a download") }

        precondition(innerSession == nil)
        precondition(innerTask == nil)

        innerSession = URLSession(configuration: .ephemeral, delegate: self, delegateQueue: .current)
        innerTask = innerSession?.streamTask(withHostName: (request.url?.host)!, port: request.url?.port ?? Constants.defaultPort)
        innerTask!.resume()
        downloadGopher()
    }

    override func stopLoading() {
        Log.entry("Stopping a download")
        defer { Log.exit("Stopped a download") }

        innerTask?.cancel()
        innerTask = nil
        innerSession = nil
    }

}

extension GopherUrlProtocol {

    func downloadGopher() {
        Log.entry("Doing a gopher download")
        defer { Log.exit("Did a gopher download") }

        guard let task = innerTask, let url = request.url, let path = URLComponents(url: url, resolvingAgainstBaseURL: false)?.path else { return }

        let downloadAsText = determineTextDownload(path)
        task.write(determineRetrievalKey(path).data(using: .isoLatin1)!, timeout: innerSession?.configuration.timeoutIntervalForRequest ?? 60) {
            Log.entry("Responding to a write with error '\(String(describing: $0))'")
            defer { Log.exit("Responded to a write") }
            Log.info("Hi")

            if let error = $0 {
                self.client?.urlProtocol(self, didFailWithError: error)
                return
            }

            var hasSentClientData = false
            var endReadLoop = false
            let aMinute: TimeInterval = 60
            let bufferSize = 1024
            let noData = Data()
            var result = noData
            while !endReadLoop {
                task.readData(ofMinLength: 1, maxLength: bufferSize, timeout: self.innerSession?.configuration.timeoutIntervalForRequest ?? aMinute) { data, atEOF, error in
                    Log.entry("Responding to a read with data '\(String(describing: data))', at-EOF '\(atEOF)', and error '\(String(describing: error))'")
                    defer { Log.exit("Responded to a read") }
                    Log.info("Hello")

                    if let error = error {
                        self.client?.urlProtocol(self, didFailWithError: error)
                        endReadLoop = true
                        return
                    }
                    endReadLoop = atEOF
                    result.append(data ?? noData)
                    hasSentClientData = hasSentClientData || data != nil
                }
            }
            if hasSentClientData {
                self.client?.urlProtocol(self, didReceive: URLResponse(url: url, mimeType: downloadAsText ? "text/plain" : "application/octet-stream", expectedContentLength: result.count, textEncodingName: nil), cacheStoragePolicy: .notAllowed)  // To-do: Update cache policy
                self.client?.urlProtocol(self, didLoad: result)
            }
        }
    }

}

extension GopherUrlProtocol: URLSessionStreamDelegate {}

还有日志：

[2017-08-28T00:52:33.861-04:00] [ENTRY] [GopherUrlProtocol.swift:39 canInit(with:)] GopherUrlProtocol checks if it can 'init' gopher://gopher.floodgap.com/
[2017-08-28T00:52:33.863-04:00] [EXIT] [GopherUrlProtocol.swift:41 canInit(with:)] Returning true
[2017-08-28T00:52:33.863-04:00] [ENTRY] [GopherUrlProtocol.swift:39 canInit(with:)] GopherUrlProtocol checks if it can 'init' gopher://gopher.floodgap.com/
[2017-08-28T00:52:33.863-04:00] [EXIT] [GopherUrlProtocol.swift:41 canInit(with:)] Returning true
[2017-08-28T00:52:33.864-04:00] [ENTRY] [GopherUrlProtocol.swift:54 canonicalRequest(for:)] GopherUrlProtocol canonizes gopher://gopher.floodgap.com/
[2017-08-28T00:52:33.864-04:00] [EXIT] [GopherUrlProtocol.swift:56 canonicalRequest(for:)] Returning gopher://gopher.floodgap.com
[2017-08-28T00:52:33.867-04:00] [ENTRY] [GopherUrlProtocol.swift:82 startLoading()] Starting up a download
[2017-08-28T00:52:33.868-04:00] [ENTRY] [GopherUrlProtocol.swift:112 downloadGopher()] Doing a gopher download
[2017-08-28T00:52:33.868-04:00] [EXIT] [GopherUrlProtocol.swift:113 downloadGopher()] Did a gopher download
[2017-08-28T00:52:33.868-04:00] [EXIT] [GopherUrlProtocol.swift:83 startLoading()] Started a download
[2017-08-28T00:53:33.871-04:00] [ENTRY] [GopherUrlProtocol.swift:132 downloadGopher()] Responding to a write with error 'Optional(Error Domain=NSPOSIXErrorDomain Code=60 "Operation timed out" UserInfo={_kCFStreamErrorCodeKey=60, _kCFStreamErrorDomainKey=1})'
[2017-08-28T00:53:33.871-04:00] [INFO] [GopherUrlProtocol.swift:134 downloadGopher()] Hi
[2017-08-28T00:53:33.872-04:00] [EXIT] [GopherUrlProtocol.swift:133 downloadGopher()] Responded to a write
[2017-08-28T00:53:33.876-04:00] [ENTRY] [GopherUrlProtocol.swift:95 stopLoading()] Stopping a download
[2017-08-28T00:53:33.876-04:00] [ERROR] [main.swift:42 cget] Retrieval Error: Error Domain=NSURLErrorDomain Code=-1001 "The request timed out." UserInfo={NSUnderlyingError=0x100e01470 {Error Domain=kCFErrorDomainCFNetwork Code=-1001 "(null)" UserInfo={_kCFStreamErrorCodeKey=-2102, _kCFStreamErrorDomainKey=4}}, NSErrorFailingURLStringKey=gopher://gopher.floodgap.com, NSErrorFailingURLKey=gopher://gopher.floodgap.com, _kCFStreamErrorDomainKey=4, _kCFStreamErrorCodeKey=-2102, NSLocalizedDescription=The request timed out.}
[2017-08-28T00:53:33.876-04:00] [EXIT] [GopherUrlProtocol.swift:96 stopLoading()] Stopped a download
Program ended with exit code: 11

奇怪的是，写闭包的日志记录只是偶尔出现。也许这是某种线程/时间问题。 （在这里，我运行了两次程序。）

我使用URLSessionStreamTask 错了吗？还是URLProtocol 错了？或者，虽然不是 HTTP，但我是在触发 ATS 吗？

Answer 1

看起来您在 while 循环中排队了大量的读取回调，并通过从不从 while 循环返回来阻塞实际运行回调的线程。

读取调用是异步的，这意味着内部的回调将在稍后运行——可能很多更晚。因此，您的“while not EOF”事情将阻塞调用线程，确保它永远不会返回到运行循环的顶部以允许回调运行，从而确保回调永远无法设置 eof 标志终止while 循环。本质上，您使线程死锁了。

您几乎不应该在任何类型的循环中调用异步方法。而是：

• 创建一个方法，其唯一目的是返回该块/闭包（可能是getReadHandlerBlock）。
• 调用 read 方法，将调用返回的块传递给getReadHandlerBlock。

然后，读取处理程序块的底部：

• 查看是否需要阅读更多内容。
• 如果是这样，请在对 self 的弱引用上调用 getReadHandlerBlock 以获取对读取处理程序块的引用。
• 调用读取方法。

希望对您有所帮助。 （请注意，我并不是说这是代码的唯一问题；我没有仔细研究过它。这只是我注意到的第一件事。）

Answer 2

我正要在另一个论坛上问这个问题。在我的步骤中，我提到我发送了请求行......

线？有……结局？

[查阅 RFC 1436，第 2 节]

哦，我计算并发送来自 URL 的检索字符串，但我忘记用 CR-LF 结束请求。这使请求通过。

但是现在我的回读超时了....