I have been battling this intermittent error for some time. It is generally random and has been difficult to reproduce until yesterday when I stumbled across a way to reproduce it each time. I can cause the code to throw this error:
Task <70E3909F-8C30-4F34-A8B0-4AF3B41DD81B>.<1> finished with error [-1001] Error Domain=NSURLErrorDomain Code=-1001 "The request timed out." UserInfo={_kCFStreamErrorCodeKey=-2103, _NSURLErrorFailingURLSessionTaskErrorKey=BackgroundDownloadTask <70E3909F-8C30-4F34-A8B0-4AF3B41DD81B>.<1>, _NSURLErrorRelatedURLSessionTaskErrorKey=(
"BackgroundDownloadTask <70E3909F-8C30-4F34-A8B0-4AF3B41DD81B>.<1>",
"LocalDownloadTask <70E3909F-8C30-4F34-A8B0-4AF3B41DD81B>.<1>"
), NSLocalizedDescription=The request timed out., _kCFStreamErrorDomainKey=4, NSErrorFailingURLStringKey=https://redacted*, NSErrorFailingURLKey=https://redacted*}
*"redacted" is the backend URL, and it is the correct and same path for each
immediately after restarting an actual device. I have been over the following threads with no results:
What is kCFStreamErrorCodeKey=-4 (kCFStreamErrorDomainKey=4)
Request timed out with _kCFStreamErrorCodeKey=60
How to better diagnose -1001 "The request timed out." URLSession errors
Random timed out error on app start
Because I was able to reproduce it, I have been able to get the following logs:
Dec 29 13:53:17 device nsurlsessiond(Network)[119] : [C13] event: client:end_activity @155.620s, activity Dec 29 13:53:17 device nsurlsessiond(CFNetwork)[119] : Connection 13: cleaning up Dec 29 13:53:17 device nsurlsessiond(CFNetwork)[119] : Connection 0: summary for unused connection {protocol="(null)", domain_lookup_duration_ms=0, connect_duration_ms=0, secure_connection_duration_ms=0, private_relay=false, idle_duration_ms=0} Dec 29 13:53:17 device nsurlsessiond(CFNetwork)[119] : Task <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1> summary for task failure {transaction_duration_ms=15370, response_status=-1, connection=0, reused=1, reused_after_ms=0, request_start_ms=0, request_duration_ms=0, response_start_ms=0, response_duration_ms=0, request_bytes=0, request_throughput_kbps=0, response_bytes=0, response_throughput_kbps=0, cache_hit=false} Dec 29 13:53:17 device nsurlsessiond(Network)[119] : [C13 4775CE07-7B21-4C53-B50D-D90D2DF90C5C Hostname#3415e863:443 quic-connection, bundle id: BundleID, url hash: ba14aab5, traffic class: 100, attribution: developer] cancel Dec 29 13:53:17 device nsurlsessiond(Network)[119] : nw_connection_report_state_with_handler_on_nw_queue [C13] reporting state cancelled Dec 29 13:53:17 device nsurlsessiond(CFNetwork)[119] : Connection 13: activity(0xac432ad00) will be canceled Dec 29 13:53:17 device nsurlsessiond(CFNetwork)[119] : Task <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1> can retry(N) with reason(2) for error [1:89] Dec 29 13:53:17 device nsurlsessiond(CFNetwork)[119] : Task <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1> HTTP load canceled, 0/0 bytes (error code: -999 [1:89]) Dec 29 13:53:17 device nsurlsessiond(CFNetwork)[119] : Task <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1> finished with error [-1001] Error Domain=NSURLErrorDomain Code=-1001 UserInfo={_kCFStreamErrorCodeKey=-2103, _NSURLErrorFailingURLSessionTaskErrorKey=, _NSURLErrorRelatedURLSessionTaskErrorKey=, NSLocalizedDescription=, NSErrorFailingURLStringKey=, NSErrorFailingURLKey=, _kCFStreamErrorDomainKey=4} Dec 29 13:53:17 device dasd[85] : CANCELED: com.apple.CFNetwork-cc-119-12-Task <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1>:DE3ADB at priority 10 Dec 29 13:53:17 device dasd[85] : Activity not tracked as being started, ignoring it Dec 29 13:53:17 device dasd(Network)[85] : nw_path_evaluator_cancel [4DB7EF71-384D-4FD5-8DF6-D6BEB0CD3C8F] cancel Dec 29 13:53:17 device nsurlsessiond[119] : NDSession <2383110B-3A38-463C-AB6B-06833619A76F> Task <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1> completed with error Error Domain=NSURLErrorDomain Code=-1001 UserInfo={_kCFStreamErrorCodeKey=-2103, _NSURLErrorFailingURLSessionTaskErrorKey=, _NSURLErrorRelatedURLSessionTaskErrorKey=, NSLocalizedDescription=, NSErrorFailingURLStringKey=, NSErrorFailingURLKey=, _kCFStreamErrorDomainKey=4} [-1001]. C(U) Dec 29 13:53:17 device nsurlsessiond[119] : NDSession <2383110B-3A38-463C-AB6B-06833619A76F> Task <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1> for client completed with error - code: -1001 Dec 29 13:53:17 device nsurlsessiond[119] : NDSession <2383110B-3A38-463C-AB6B-06833619A76F> has 0 outstanding tasks Dec 29 13:53:17 device nsurlsessiond[119] : NDSession <2383110B-3A38-463C-AB6B-06833619A76F> client is active result (Y), XPC(Y) proxy(Y) for Dec 29 13:53:17 device nsurlsessiond(CFNetwork)[119] : {"_transactionUUID":"999D5D02-D913-435B-8A5F-2E773CA7F7B9","_taskUUID":"142B32FB-CA2F-48A3-A647-FB343E95DE52","serverIPAddress":"","startedDateTime":"2024-12-29T13:53:02.123-05:00","time":15370,"cache":{},"timings":{"connect":-1,"dns":-1,"send":-1,"wait":-1,"ssl":-1,"blocked":-1,"receive":-1},"_precisionPreservingTimings":{},"_sourceApplicationBundleIdentifier":"BundleID","connection":"0","request":{"method":"POST","bodySize":0,"headersSize":0,"cookies":[],"headers":[{"name":"Cookie","value":"mobile=Fd7Z48VbxqH9Cw1az2PMwYOaH5N9TJx0cNkYfkrhwj8txX%2Fp3YDFFUP9jlrExNDgAUkpaEPTD15nE2FKA8pxlCv6mE7kikaUqkBTQI4VEU%2F%2BC5njebZ%2FIXarSMpb%2BqiJRmRBB4TogP%2BMA25u0bGWTwaLICSFg%2Ff62RNzEQCl%2Fc65vhsEp3M6YoQrkXncM5EJLyx9vSVAcEMgVDqC384l6uvD0RytsoGA940OHMasVdt7AtNgsDPR8cBQMwGdVsfqyOsHLSSE%2FaGVx7i6fMxHPonEVwSVCw4vLcS8L9%2FBgc0%2BDwSQmS4UWwnlxiDanfhtQK7P%2Bc%2FHGHBSi8XwcOMcNJ%2B%2BkXkC%2BaflCkP3te5bOYqIkZarIgBqdwX0o1nVsdFXW7BDdbUzu1Gagg%2BfdvjpIhXBKyrcs5sD7RY5PPLJi%2FtJeGa2pG9zAU9NadvNarlgn6bRoIpaSh4bknG4JYO33Bzvrmo%3D--4CzBTkU2hdmgums2--%2BO8TFmvQ3dGr92tZ4FsWew%3D%3D"},{"name":"X-USER-EMAIL","value":"name@domain.com"},{"name":"Content-Type","value":"application\134/json"},{"name":"X-USER-CLIENT","value":"mobile"},{"name":"Accept","value":"*\134/*"},{"name":"Accept-Language","value":"en-US,en;q=0.9"},{"name":"User-Agent","value":"Redacted\134/1221 CFNetwork\134/3826.400.101 Darwin\134/24.3.0"},{"name":"Accept-Encoding","value":"gzip"}],"queryString":[],"httpVersion":"HTTP\134/1.1","url":"https:\134/\134/backendURL\134/app\134/v2\134/calendars\134/events"},"response":{"status":0,"content":{"size":0,"mimeType":"application\134/octet-stream"},"bodySize":0,"headersSize":0,"cookies":[],"statusText":"","headers":[],"httpVersion":"","redirectURL":""},"_fetchType":"Network Load"} Dec 29 13:53:17 device AppName(CFNetwork)[517] : Task <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1> finished with error [-1001] Error Domain=NSURLErrorDomain Code=-1001 "The request timed out." UserInfo={_kCFStreamErrorCodeKey=-2103, _NSURLErrorFailingURLSessionTaskErrorKey=BackgroundDownloadTask <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1>, _NSURLErrorRelatedURLSessionTaskErrorKey=( "BackgroundDownloadTask <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1>", "LocalDownloadTask <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1>" ), NSLocalizedDescription=The request timed out., _kCFStreamErrorDomainKey=4, NSErrorFailingURLStringKey=https://backendURL/app/v2/calendars/events, NSErrorFailingURLKey=https://backendURL/app/v2/calendars/events} Dec 29 13:53:17 device nsurlsessiond[119] : Task <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1> client acknowledged completion Dec 29 13:53:17 device nsurlsessiond[119] : NDSession <2383110B-3A38-463C-AB6B-06833619A76F> has 0 outstanding tasks Dec 29 13:53:17 device AppName(CFNetwork)[517] : Task <88BD8987-0FCE-4554-B7F8-C2BF3B4B00DE>.<151> resuming, timeouts(60.0, 604800.0) qos(0x9) voucher() activity(00000000-0000-0000-0000-000000000000) Dec 29 13:53:17 device AppName(AppName.debug.dylib)[517] : BackgroundEventsDownloadManager.urlSession_didCompleteWithError_error, a233e1b8e9aa1b80041c751ea149ac3e failed with error: Error Domain=NSURLErrorDomain Code=-1001 "The request timed out." UserInfo={_kCFStreamErrorCodeKey=-2103, _NSURLErrorFailingURLSessionTaskErrorKey=BackgroundDownloadTask <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1>, _NSURLErrorRelatedURLSessionTaskErrorKey=( "BackgroundDownloadTask <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1>", "LocalDownloadTask <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1>" ), NSLocalizedDescription=The request timed out., _kCFStreamErrorDomainKey=4, NSErrorFailingURLStringKey=https://backendURL/app/v2/calendars/events, NSErrorFailingURLKey=https://backendURL/app/v2/calendars/events} Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1950] 13:53:17.518 {LoaderWhatToDo: (null) Request: {string = https://backendURL/app/v1/metrics, encoding = 134217984, base = (null)} CachePolicy: 1 WhatToDo: originload CreateToNow: 0.00059s } [1:1950] Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1951] 13:53:17.520 {AddCookies Continue: request POST https://backendURL/app/v1/metrics HTTP/1.1 HTTPProtocol: Task: 0x1051bec00 } [1:1951] Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1952] 13:53:17.520 {Protocol Enqueue: request POST https://backendURL/app/v1/metrics HTTP/1.1 Request: request POST https://backendURL/app/v1/metrics HTTP/1.1 Message: POST https://backendURL/app/v1/metrics HTTP/1.1 } [1:1952] Dec 29 13:53:17 device AppName(Network)[517] : [C1] event: client:connection_reused @64.425s Dec 29 13:53:17 device AppName(CFNetwork)[517] : Task <88BD8987-0FCE-4554-B7F8-C2BF3B4B00DE>.<151> now using Connection 1 Dec 29 13:53:17 device AppName(CFNetwork)[517] : Task <88BD8987-0FCE-4554-B7F8-C2BF3B4B00DE>.<151> sent request, body S 979 Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1953] 13:53:17.523 { touchConnection: (null) Loader: request POST https://backendURL/app/v1/metrics HTTP/1.1 Timeout Interval: 60.000 seconds } [1:1953] Dec 29 13:53:17 device WirelessRadioManagerd[49] : Dec 29 13:53:17 device kernel()[0] : 000155.678674 wlan0.A[1172] [dk] parsePHYEcounterV3@31194:Version = 3, ChanSpec 40 5g 80MHz u, slice=0 phyWdg=112 noiseReq=76 noiseCrsbit=3 crsminPwrIdx=14 featureflag=0x0247 chanSwitchCnt=94 chipTemp=31 femTemp=36 ofdmDesense=0 bphyDesen Dec 29 13:53:17 device kernel()[0] : 000155.678749 wlan0.A[1173] [dk] parsePHYEcounterV3@31200:gbdBphySleepCnt=0 gbdOfdmSleepCnt=0 homeChan=0x2a scca_txstall_precondition=0, crsminPwrApplyCnt=67 edThreshold=-76 preemptStatus2=0x003f totalGlitch=19 bphyGlitch=0 badplcp=0 bphyB Dec 29 13:53:17 device kernel()[0] : 000155.678779 wlan0.A[1174] [dk] parsePHYEcounterV3@31205:ccaDurMS=1000 ccaEdDuration=0 crsminPwr0=-89 noiseLevelInst0=-90 crsminPwr1=-89 noiseLevelInst1=-90 Dec 29 13:53:17 device kernel()[0] : 000155.683404 wlan0.A[1175] [dk] updateChanSeqCommonStats@3603:P2P chan 40: dur 113609, entry 46, crsglitch 432, start 33066, badplcp 705, badfcs 379, f0ov 0, f1ov 0, anyerr 5704, resptout 1013, frmtooln 0, frmtoosh 106 Dec 29 13:53:17 device kernel()[0] : I [dk] @29318: DTIM missed count: p2p(21), iovar(0), scan(3), roam(0), homechan(70), sleep(10), misc(0) Dec 29 13:53:17 device AppName(CFNetwork)[517] : Task <88BD8987-0FCE-4554-B7F8-C2BF3B4B00DE>.<151> received response, status 200 content U Dec 29 13:53:17 device AppName(CFNetwork)[517] : Task <88BD8987-0FCE-4554-B7F8-C2BF3B4B00DE>.<151> done using Connection 1 Dec 29 13:53:17 device AppName(Network)[517] : [C1] event: client:connection_idle @64.476s Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1954] 13:53:17.572 {Protocol Received: request POST https://backendURL/app/v1/metrics HTTP/1.1 Response: HTTP/2.0 200 } [1:1954] Dec 29 13:53:17 device AppName(CFNetwork)[517] : Task <88BD8987-0FCE-4554-B7F8-C2BF3B4B00DE>.<151> response ended Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1955] 13:53:17.573 { touchConnection: (null) Loader: request POST https://backendURL/app/v1/metrics HTTP/1.1 Timeout Interval: 60.000 seconds } [1:1955] Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1956] 13:53:17.573 {destroyReadStream: request POST https://backendURL/app/v1/metrics HTTP/1.1 Request: request POST https://backendURL/app/v1/metrics HTTP/1.1 sent: 1031 received: 604 } [1:1956] Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1958] 13:53:17.573 {Response Complete: (null) Request: request POST https://backendURL/app/v1/metrics HTTP/1.1 } [1:1958] Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1957] 13:53:17.573 { touchConnection: (null) Loader: request POST https://backendURL/app/v1/metrics HTTP/1.1 Timeout Interval: 60.000 seconds } [1:1957] Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1959] 13:53:17.574 { Did Finish: (null) Loader: request POST https://backendURL/app/v1/metrics HTTP/1.1 init to origin load: 0.001544s total time: 0.055987s total bytes: 2 } [1:1959] Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1960] 13:53:17.574 { touchConnection: (null) Loader: request POST https://backendURL/app/v1/metrics HTTP/1.1 Timeout Interval: 60.000 seconds } [1:1960] Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1961] 13:53:17.575 {Vary Persistence: (null) Request: {string = https://backendURL/app/v1/metrics, encoding = 134217984, base = (null)} VaryHeader: Accept, Accept-Encoding, Origin VaryState: dict [2] { Accept-Encoding: gzip Accept: */* } } [1:1961] Dec 29 13:53:17 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1962] 13:53:17.575 {~HTTPProtocol: request POST https://backendURL/app/v1/metrics HTTP/1.1 Request: request POST https://backendURL/app/v1/metrics HTTP/1.1 sent: 1031 received: 604 } [1:1962] Dec 29 13:53:17 device AppName(CFNetwork)[517] : Task <88BD8987-0FCE-4554-B7F8-C2BF3B4B00DE>.<151> summary for task success {transaction_duration_ms=57, response_status=200, connection=1, reused=1, reused_after_ms=15348, request_start_ms=4, request_duration_ms=1, response_start_ms=53, response_duration_ms=2, request_bytes=1031, request_throughput_kbps=999, response_bytes=604, response_throughput_kbps=275, cache_hit=false} Dec 29 13:53:17 device AppName(CFNetwork)[517] : Task <88BD8987-0FCE-4554-B7F8-C2BF3B4B00DE>.<151> finished successfully Dec 29 13:53:17 device runningboardd(RunningBoard)[33] : Acquiring assertion targeting [app:517] from originator [app:517] with description , ]> Dec 29 13:53:17 device runningboardd(RunningBoard)[33] : Assertion 33-517-640 (target:[app:517]) will be created as inactive as start-time-defining assertions exist Dec 29 13:53:17 device AppName(CFNetwork)[517] : {"_transactionUUID":"C6B49E42-0AB9-41CE-AB46-D636FEBE1F84","_taskUUID":"88BD8987-0FCE-4554-B7F8-C2BF3B4B00DE","serverIPAddress":"104.26.14.159","startedDateTime":"2024-12-29T13:53:17.518-05:00","time":57,"cache":{},"timings":{"connect":-1,"dns":-1,"send":1,"wait":48,"ssl":-1,"blocked":4,"receive":2},"_precisionPreservingTimings":{"send":{"start":0.0042940378189086914,"end":0.0053009986877441406},"receive":{"start":0.053356051445007324,"end":0.055495023727416992}},"_sourceApplicationBundleIdentifier":null,"connection":"1","request":{"method":"POST","bodySize":988,"headersSize":43,"postData":{"text":"{\134"client\134":\134"iOS\134\134ndevice: iPhone14\134\134nconfig: Debug\134",\134"user_token\134":\134"9jivAXwJvmEacEYK\134",\134"version\134":\134"OS18.3, V1.0.199-1221\134",\134"category\134":\134"backgroundSync\134",\134"timestamp\134":\134"2024-12-29T18:53:17Z\134",\134"event_action\134":\134"urlSession_didCompleteWithError_error\134",\134"label\134":\134"time: 12\134\134\134/29\134\134\134/2024, 1:53:17\M-b\M^@\M-/PM EST, id: a233e1b8e9aa1b80041c751ea149ac3e failed with error: Error Domain=NSURLErrorDomain Code=-1001 \134\134\134"The request timed out.\134\134\134" UserInfo={_kCFStreamErrorCodeKey=-2103, _NSURLErrorFailingURLSessionTaskErrorKey=BackgroundDownloadTask <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1>, _NSURLErrorRelatedURLSessionTaskErrorKey=(\134\134n \134\134\134"BackgroundDownloadTask <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1>\134\134\134",\134\134n \134\134\134"LocalDownloadTask <142B32FB-CA2F-48A3-A647-FB343E95DE52>.<1>\134\134\134"\134\134n), NSLocalizedDescription=The request timed out., _kCFStreamErrorDomainKey=4, NSErrorFailingURLStringKey=https:\134\134\134/\134\134\134/backendURL\134\134\134/app\134\134\134/v2\134\134\134/calendars\134\134\134/events, NSErrorFailingURLKey=https:\134\134\134/\134\134\134/backendURL\134\134\134/app\134\134\134/v2\134\134\134/calendars\134\134\134/events}\134"}","mimeType" txX%2Fp3YDFFUP9jlrExNDgAUkpaEPTD15nE2FKA8pxlCv6mE7kikaUqkBTQI4VEU%2F%2BC5njebZ%2FIXarSMpb%2BqiJRmRBB4TogP%2BMA25u0bGWTwaLICSFg%2Ff62RNzEQCl%2Fc65vhsEp3M6YoQrkXncM5EJLyx9vSVAcEMgVDqC384l6uvD0RytsoGA940OHMasVdt7AtNgsDPR8cBQMwGdVsfqyOsHLSSE%2FaGVx7i6fMxHPonEVwSVCw4vLcS8L9%2FBgc0%2BDwSQmS4UWwnlxiDanfhtQK7P%2Bc%2FHGHBSi8XwcOMcNJ%2B%2BkXkC%2BaflCkP3te5bOYqIkZarIgBqdwX0o1nVsdFXW7BDdbUzu1Gagg%2BfdvjpIhXBKyrcs5sD7RY5PPLJi%2FtJeGa2pG9zAU9NadvNarlgn6bRoIpaSh4bknG4JYO33Bzvrmo%3D--4CzBTkU2hdmgums2--%2BO8TFmvQ3dGr92tZ4FsWew%3D%3D"}],"queryString":[],"httpVersion":"HTTP\134/2.0","url":"https:\134/\134/backendURL\134/app\134/v1\134/metrics"},"response":{"status":200,"content":{"size":2,"mimeType":"application\134/json","text":"{}"},"bodySize":46,"headersSize":558,"cookies":[],"statusText":"","headers":[{"name":"Content-Encoding","value":"gzip"},{"name":"x-runtime","value":"0.009342"},{"name":"x-content-type-options","value":"nosniff"},{"name":"content-security-policy","value":"default-src 'self' https:; font-src 'self' https: data:; img-src 'self' https: data:; object-src 'none'; script-src https:; style-src 'self' https: 'unsafe-inline'"},{"name":"Cache-Control","value":"no-cache"},{"name":"Strict-Transport-Security","value":"max-age=15552000"},{"name":"reporting-endpoints","value":"redacted-nel=https:\134/\134/nel.redacted.com\134/reports?ts=1735498397&sid=1b10b0ff-8a76-4548-befa-353fc6c6c045&s=E1XFeBhF5szfgPmz0md8zm3v0bYf7oyudc9IVwtaZYo%3D"},{"name":"Server","value":"cloudflare"},{"name":"x-download-options","value":"noopen"},{"name":"server-timing","value":"cfL4;desc=\134"?proto=TCP&rtt=14408&min_rtt=10175&rtt_var=1379&sent=568&recv=380&lost=0&retrans=1&sent_bytes=204807&recv_bytes=58911&delivery_rate=1771653&cwnd=252&unsent_bytes=0&cid=dc74be6ccdbbd64e&ts=64391&x=0\134""},{"name":"report-to","value":"{\134"group\134":\134"redacted-nel\134",\134"max_age\134":3600,\134"endpoints\134":[{\134"url\134":\134"https:\134/\134/nel.redacted.com\134/reports?ts=1735498397&sid=1b10b0ff-8a76-4548-befa-353fc6c6c045&s=E1XFeBhF5szfgPmz0md8zm3v 0bYf7oyudc9IVwtaZYo%3D\134"}]}"},{"name":"Via","value":"1.1 vegur"},{"name":"x-xss-protection","value":"1; mode=block"},{"name":"Date","value":"Sun, 29 Dec 2024 18:53:17 GMT"},{"name":"Vary","value":"Accept, Accept-Encoding, Origin"},{"name":"x-request-id","value":"c1a79808-3fd1-4aa7-aead-cbef40b1b2d8"},{"name":"nel","value":"{\134"report_to\134":\134"redacted-nel\134",\134"max_age\134":3600,\134"success_fraction\134":0.005,\134"failure_fraction\134":0.05,\134"response_headers\134":[\134"Via\134"]}"},{"name":"x-frame-options","value":"sameorigin"},{"name":"Content-Type","value":"application\134/json; charset=utf-8"},{"name":"cf-ray","value":"8f9bfdf888db4358-EWR"},{"name":"x-permitted-cross-domain-policies","value":"none"},{"name":"cf-cache-status","value":"DYNAMIC"}],"httpVersion":"HTTP\134/2.0","redirectURL":""},"_fetchType":"Network Load"} Dec 29 13:53:17 device backboardd(ColourSensorFilterPlugin)[71] : [ALS] ts=155.771 lux=86.374 xy=(0.446 0.397) chs=[764 1922 2272 3080 3109] CCT1=3187.789 gain=256x mode= subsamples=24 rawLux=106.058 nits=128 xTalk=[10 38 37 49 51] status=0x9B copyEvent=0 Dec 29 13:53:17 device locationd[79] : os_transaction created: () Dec 29 13:53:17 device locationd[79] : os_transaction released: () Dec 29 13:53:17 device kernel()[0] : wlan0:com.apple.p2p: isInfraRealtimePacketThresholdAllowed allowed:1 option:32 threshold:50 noRegistrations:1 cachedPeerCount:0 fastDiscoveryInactive:1 fastDiscoveryOnSince:156028 Dec 29 13:53:17 device kernel()[0] : wlan0:com.apple.p2p: currentInfraTrafficType:8976 checking if realtime upgrade required with inputPackets:7 outputPackets:5 packetThreshold:50 Dec 29 13:53:17 device backboardd(ColourSensorFilterPlugin)[71] : [ALS] ts=156.021 lux=86.584 xy=(0.446 0.397) chs=[764 1963 2259 3094 3122] CCT1=3189.286 gain=256x mode= subsamples=24 rawLux=106.268 nits=128 xTalk=[10 38 37 49 51] status=0x9B copyEvent=0 Dec 29 13:53:18 device identityservicesd(IMFoundation)[63] : -[IMDispatchTimer fired] {self: 0x58994e800} Dec 29 13:53:18 device identityservicesd(IMFoundation)[63] : -[IMDispatchTimer invalidate] {self: 0x58994e800, _timerSource: } Dec 29 13:53:18 device identityservicesd(IMFoundation)[63] : -[IMDispatchTimer invalidating] {self: 0x58994e800} Dec 29 13:53:18 device DTServiceHub(DVTInstrumentsFoundation)[382] : Checking a pid of -1, this shouldn't be happening Dec 29 13:53:18 device AppName(CFNetwork)[517] : Task <BC1A6931-A9E5-45B7-B07B-C6D99CF559E2>.<152> resuming, timeouts(60.0, 604800.0) qos(0x9) voucher() activity(00000000-0000-0000-0000-000000000000) Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1963] 13:53:18.111 {LoaderWhatToDo: (null) Request: {string = https://backendURL/app/v1/metrics, encoding = 134217984, base = (null)} CachePolicy: 1 WhatToDo: originload CreateToNow: 0.00024s } [1:1963] Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1964] 13:53:18.112 {AddCookies Continue: request POST https://backendURL/app/v1/metrics HTTP/1.1 HTTPProtocol: Task: 0x1051bec00 } [1:1964] Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1965] 13:53:18.113 {Protocol Enqueue: request POST https://backendURL/app/v1/metrics HTTP/1.1 Request: request POST https://backendURL/app/v1/metrics HTTP/1.1 Message: POST https://backendURL/app/v1/metrics HTTP/1.1 } [1:1965] Dec 29 13:53:18 device AppName(Network)[517] : [C1] event: client:connection_reused @65.017s Dec 29 13:53:18 device AppName(CFNetwork)[517] : Task <BC1A6931-A9E5-45B7-B07B-C6D99CF559E2>.<152> now using Connection 1 Dec 29 13:53:18 device AppName(UIKitCore)[517] : [0x3028dad10] [keyboardFocus] Recreation of event deferring records requested: removing recreation reason: detachedContext; for reason: _UIEventDeferringManager: 0x3028dad10: recreating keyboardFocus: context attached for window: 0x102958980; contextID: 0x5E1873B3 Dec 29 13:53:18 device AppName(CFNetwork)[517] : Task <BC1A6931-A9E5-45B7-B07B-C6D99CF559E2>.<152> sent request, body S 365 Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1966] 13:53:18.115 { touchConnection: (null) Loader: request POST https://backendURL/app/v1/metrics HTTP/1.1 Timeout Interval: 60.000 seconds } [1:1966] Dec 29 13:53:18 device AppName(BackBoardServices)[517] : flushing changes: ; deferringRules: [[517-2]; -> ; reason: UIWindowScene: 0x103aec800: Begin event deferring in keyboardFocus for window: 0x102958980]; keyCommandDispatchingRules: ; keyCommandsRegistrations: ; bufferingPredicates: ; activeUIResponders: > Dec 29 13:53:18 device backboardd(BackBoardHIDEventFoundation)[71] : new deferring rules for pid:517: [[517-2]; -> ; reason: UIWindowScene: 0x103aec800: Begin event deferring in keyboardFocus for window: 0x102958980] Dec 29 13:53:18 device backboardd(BackBoardHIDEventFoundation)[71] : cycle detected between [34-C] -> [34-3] Dec 29 13:53:18 device backboardd(ColourSensorFilterPlugin)[71] : [ALS] ts=156.271 lux=87.256 xy=(0.448 0.399) chs=[750 1949 2286 3121 3136] CCT1=3147.691 gain=256x mode= subsamples=24 rawLux=106.940 nits=128 xTalk=[10 38 37 49 51] status=0x9B copyEvent=0 Dec 29 13:53:18 device AppName(CFNetwork)[517] : Task <BC1A6931-A9E5-45B7-B07B-C6D99CF559E2>.<152> received response, status 200 content U Dec 29 13:53:18 device AppName(CFNetwork)[517] : Task <BC1A6931-A9E5-45B7-B07B-C6D99CF559E2>.<152> done using Connection 1 Dec 29 13:53:18 device AppName(Network)[517] : [C1] event: client:connection_idle @65.067s Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1967] 13:53:18.163 {Protocol Received: request POST https://backendURL/app/v1/metrics HTTP/1.1 Response: HTTP/2.0 200 } [1:1967] Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1968] 13:53:18.163 { touchConnection: (null) Loader: request POST https://backendURL/app/v1/metrics HTTP/1.1 Timeout Interval: 60.000 seconds } [1:1968] Dec 29 13:53:18 device AppName(CFNetwork)[517] : Task <BC1A6931-A9E5-45B7-B07B-C6D99CF559E2>.<152> response ended Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1969] 13:53:18.163 { touchConnection: (null) Loader: request POST https://backendURL/app/v1/metrics HTTP/1.1 Timeout Interval: 60.000 seconds } [1:1969] Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1970] 13:53:18.163 {destroyReadStream: request POST https://backendURL/app/v1/metrics HTTP/1.1 Request: request POST https://backendURL/app/v1/metrics HTTP/1.1 sent: 417 received: 585 } [1:1970] Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1971] 13:53:18.163 {Response Complete: (null) Request: request POST https://backendURL/app/v1/metrics HTTP/1.1 } [1:1971] Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1972] 13:53:18.163 { Did Finish: (null) Loader: request POST https://backendURL/app/v1/metrics HTTP/1.1 init to origin load: 0.000737071s total time: 0.0522151s total bytes: 2 } [1:1972] Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1973] 13:53:18.164 { touchConnection: (null) Loader: request POST https://backendURL/app/v1/metrics HTTP/1.1 Timeout Interval: 60.000 seconds } [1:1973] Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1974] 13:53:18.164 {Vary Persistence: (null) Request: {string = https://backendURL/app/v1/metrics, encoding = 134217984, base = (null)} VaryHeader: Accept, Accept-Encoding, Origin VaryState: dict [2] { Accept-Encoding: gzip Accept: */* } } [1:1974] Dec 29 13:53:18 device AppName(CFNetwork)[517] : Task <BC1A6931-A9E5-45B7-B07B-C6D99CF559E2>.<152> summary for task success {transaction_duration_ms=52, response_status=200, connection=1, reused=1, reused_after_ms=541, request_start_ms=2, request_duration_ms=0, response_start_ms=51, response_duration_ms=0, request_bytes=417, request_throughput_kbps=449, response_bytes=585, response_throughput_kbps=741, cache_hit=false} Dec 29 13:53:18 device AppName(CFNetwork)[517] : CFNetwork Diagnostics [1:1975] 13:53:18.164 {~HTTPProtocol: request POST https://backendURL/app/v1/metrics HTTP/1.1 Request: request POST https://backendURL/app/v1/metrics HTTP/1.1 sent: 417 received: 585 } [1:1975] Dec 29 13:53:18 device AppName(CFNetwork)[517] : Task <BC1A6931-A9E5-45B7-B07B-C6D99CF559E2>.<152> finished successfully nnection","value":"keep-alive"},{"name":"Host","value":"backendURL"},{"name":"Upload-Complete","value":"?1"},{"name":"Cookie","value":"mobile=Fd7Z48VbxqH9Cw1az2PMwYOaH5N9TJx0cNkYfkrhwj8txX%2Fp3YDFFUP9jlrExNDgAUkpaEPTD15nE2FKA8pxlCv6mE7kikaUqkBTQI4VEU%2F%2BC5njebZ%2FIXarSMpb%2BqiJRmRBB4TogP%2BMA25u0bGWTwaLICSFg%2Ff62RNzEQCl%2Fc65vhsEp3M6YoQrkXncM5EJLyx9vSVAcEMgVDqC384l6uvD0RytsoGA940OHMasVdt7AtNgsDPR8cBQMwGdVsfqyOsHLSSE%2FaGVx7i6fMxHPonEVwSVCw4vLcS8L9%2FBgc0%2BDwSQmS4UWwnlxiDanfhtQK7P%2Bc%2FHGHBSi8XwcOMcNJ%2B%2BkXkC%2BaflCkP3te5bOYqIkZarIgBqdwX0o1nVsdFXW7BDdbUzu1Gagg%2BfdvjpIhXBKyrcs5sD7RY5PPLJi%2FtJeGa2pG9zAU9NadvNarlgn6bRoIpaSh4bknG4JYO33Bzvrmo%3D--4CzBTkU2hdmgums2--%2BO8TFmvQ3dGr92tZ4FsWew%3D%3D"}],"queryString":[],"httpVersion":"HTTP\134/2.0","url":"https:\134/\134/backendURL\134/app\134/v1\134/metrics"},"response":{"status":200,"content":{"size":2,"mimeType":"application\134/json","text":"{}"},"bodySize":46,"headersSize":539,"cookies":[],"statusText":"","headers":[{"name":"Content-Encoding","val ue":"gzip"},{"name":"x-runtime","value":"0.010079"},{"name":"x-content-type-options","value":"nosniff"},{"name":"content-security-policy","value":"default-src 'self' https:; font-src 'self' https: data:; img-src 'self' https: data:; object-src 'none'; script-src https:; style-src 'self' https: 'unsafe-inline'"},{"name":"Cache-Control","value":"no-cache"},{"name":"Strict-Transport-Security","value":"max-age=15552000"},{"name":"reporting-endpoints","value":"redacted-nel=https:\134/\134/nel.redacted.com\134/reports?ts=1735498398&sid=1b10b0ff-8a76-4548-befa-353fc6c6c045&s=YuCNaHxnB1ny2BrQBbKr2%2Fz7u8f55emYOfPDAeD8Oao%3D"},{"name":"Server","value":"cloudflare"},{"name":"x-download-options","value":"noopen"},{"name":"server-timing","value":"cfL4;desc=\134"?proto=TCP&rtt=14153&min_rtt=10175&rtt_var=1400&sent=571&recv=383&lost=0&retrans=1&sent_bytes=205477&recv_bytes=59372&delivery_rate=1771653&cwnd=252&unsent_bytes=0&cid=dc74be6ccdbbd64e&ts=64981&x=0\134""},{"name":"report-to","value":"{\134"group\134":\134"redacted-nel\1 34",\134"max_age\134":3600,\134"endpoints\134":[{\134"url\134":\134"https:\134/\134/nel.redacted.com\134/reports?ts=1735498398&sid=1b10b0ff-8a76-4548-befa-353fc6c6c045&s=YuCNaHxnB1ny2BrQBbKr2%2Fz7u8f55emYOfPDAeD8Oao%3D\134"}]}"},{"name":"Via","value":"1.1 vegur"},{"name":"x-xss-protection","value":"1; mode=block"},{"name":"Date","value":"Sun, 29 Dec 2024 18:53:18 GMT"},{"name":"Vary","value":"Accept, Accept-Encoding, Origin"},{"name":"x-request-id","value":"fb540a81-4e98-47af-8e94-e2b25bf3b574"},{"name":"nel","value":"{\134"report_to\134":\134"redacted-nel\134",\134"max_age\134":3600,\134"success_fraction\134":0.005,\134"failure_fraction\134":0.05,\134"response_headers\134":[\134"Via\134"]}"},{"name":"x-frame-options","value":"sameorigin"},{"name":"Content-Type","value":"application\134/json; charset=utf-8"},{"name":"cf-ray","value":"8f9bfdfc3d704358-EWR"},{"name":"x-permitted-cross-domain-policies","value":"none"},{"name":"cf-cache-status","value":"DYNAMIC"}],"httpVersion":"HTTP\134/2.0","redirectURL":""},"_fetc hType":"Network Load"}
Last bit of information is that I had Network Instruments running, and when this error occurred, I found that the Connection ID was "No Connection" and it appears the request was never actually sent, though it waited the full time out for a backend response.
Any help would be appreciated. This data request is being used after sending a certain APNs to update necessary data in the background, and has been the source of many user complaints.
Thanks for the response. Originally, the timeoutIntervalForResource was set to 60 seconds, and the timeoutIntervalForRequest was default. We were still getting these errors in the wild. The only reason I implemented these times is because I implemented a retry once this specific error came in, and the server has a 15 second timeout. I am not opposed to increasing those times at all, but I am not sure this solves the root issue.
But yes, this data is pretty ephemeral, so "if you can't get me this data in the next <insert time> don't bother trying at all" is exactly what we were going for. We also have an app refresh we call that uses this same code that is called regularly throughout the day. That will also exhibit this error on occasion.
This slipped off my radar for awhile, but my answer here is actually really simple. Based on what you're describing, it sound like you should stop using the background URL session and just use the standard configuration. That is, you try to immediately download it while your app is awake in the background and if you can't download it, then you don't download it. Jumping back to what I said here:
"if you can't get me this data in the next <insert time> don't bother trying at all"
Putting some concrete numbers on that, when "<insert time>" is:
-
"a day or so"-> the background session is a great solution.
-
"12 hours"-> the background session might be worth "trying". That is, sometimes it will work, sometimes it won't, but something is better than nothing.
-
"60 minutes"-> the background session is largely irrelevant. There are times it might work but the results aren't going to be consistent enough to be useful
-
"a few minutes"-> the background session is probably a bad idea. To the extent it "works", that's almost certainly an artifact of your testing environment or some other distortion.
There are odd edge cases and exceptions to this, but the over arching point here is that as download size and resource timeout decrease, the background session makes less and less sense. If you need a 5k file in the next 30 min, then you should just download it directly instead of trying to use the background session.
__
Kevin Elliott
DTS Engineer, CoreOS/Hardware