With the release of iPadOS 17 we began noticing that the AssetCacheLocator service on iOS/iPadOS was reliably returning a "no caching server" response even when we had active caching servers on the network.
default 2023-09-27 18:40:17.970429 +1000 AssetCacheLocatorService #11553fbd [AssetCacheLocatorService.queue] found no caching servers
This behaviour was also apparent during the beta releases of iPadOS 17 but vanished around beta 8 before returning during the production release.
For a bit of back story our network environment makes use of proxy servers which devices are configured to use via PAC discovery methods. Either via specifying a pac url in config payload or via auto-discovery means via DHCP option 252 or dns. We have been compliant with https PAC file delivery since it was first brought in for the iPadOS 15 release.
After continued testing the behaviour was being cause by a failure in the trust daemon to validate certificates used in SSL handshakes for the AssetCacheLocatorService. This would result in NSURLNetworkError = -999 being reported for network tasks started from the AssetCacheLocatorService.
default 2023-09-27 18:40:17.961617 +1000 AssetCacheLocatorService Task <027E06F3-3994-4BE1-9F3C-EA3C22110ACA>.<1> finished with error [-999] Error Domain=NSURLErrorDomain Code=-999 UserInfo={NSErrorFailingURLStringKey=<private>, NSErrorFailingURLKey=<private>, _NSURLErrorRelatedURLSessionTaskErrorKey=<private>, _NSURLErrorFailingURLSessionTaskErrorKey=<private>, NSLocalizedDescription=<private>}
I initially thought these trust failures were directly related to ocsp and crl requests needed to validate the "https://lcdn-locator.apple.com/lcdn/locate" api. However, when testing was performed utilising no PAC url or via using manual proxy settings AssetCacheLocatorservice would correctly find caching servers on the network.
Puzzled by this response continued analysis of the logs generated from the trust daemon pointed in the direction of HTTPS pac file delivery. It seems that the AssetCacheLocatorService enforces certificate validation for all SSL sessions it establishes. Should a validation fail the entire process is cancelled and a "no caching server" response is returned. The problem is that this is also applying to the PAC file retrieval over HTTPS. I suspect may be causing a loop where it's unable to validate the certificate used for HTTPS pac file retrieval without having the pac file.
After disabling HTTPS pac file support on our network we then observed that the AssetCacheLocatorService completed successfully:
HTTPS PAC File
default 2023-09-27 18:40:17.661202 +1000 AssetCacheLocatorService CFNetwork Diagnostics [3:6] 18:40:17.660 {
Authentication Challenge: (null)
Loader: request POST https://lcdn-locator.apple.com/<redacted>
Challenge: challenge space https://lcdn-locator.apple.com:443/, ServerTrustEvaluationRequested (Hash 91283047ef00ae3c)
} [3:6]
default 2023-09-27 18:40:17.662336 +1000 AssetCacheLocatorService [0x974b0e130] activating connection: mach=true listener=false peer=false name=com.apple.trustd
default 2023-09-27 18:40:17.664988 +1000 AssetCacheLocatorService user sessions enabled, targeting 501
default 2023-09-27 18:40:17.665056 +1000 AssetCacheLocatorService [0x974a255e0] activating connection: mach=true listener=false peer=false name=com.apple.trustd
default 2023-09-27 18:40:17.928484 +1000 AssetCacheLocatorService cleaning up unpooled xpc conn to trustd 0x974a255e0
default 2023-09-27 18:40:17.928567 +1000 AssetCacheLocatorService [0x974a255e0] invalidated on xpc_connection_cancel()
error 2023-09-27 18:40:17.928972 +1000 AssetCacheLocatorService #11553fbd [NSOperationQueue 0x97490ac50 (QOS: UNSPECIFIED)] LocateURL https://lcdn-locator.apple.com/lcdn/locate untrusted: EV=(null) organization=(null)
default 2023-09-27 18:40:17.929114 +1000 AssetCacheLocatorService got event: Connection invalid
default 2023-09-27 18:40:17.929167 +1000 AssetCacheLocatorService Task <027E06F3-3994-4BE1-9F3C-EA3C22110ACA>.<1> auth completion disp=2 cred=0x0
default 2023-09-27 18:40:17.957367 +1000 AssetCacheLocatorService Task <027E06F3-3994-4BE1-9F3C-EA3C22110ACA>.<1> summary for task failure {transaction_duration_ms=3211, response_status=-1, connection=1, reused=1, request_start_ms=0, request_duration_ms=0, response_start_ms=0, response_duration_ms=0, request_bytes=0, response_bytes=0, cache_hit=false}
HTTP Pac File (no https support)
default 2023-09-29 16:30:02.452153 +1000 AssetCacheLocatorService CFNetwork Diagnostics [3:6] 16:30:02.452 {
Authentication Challenge: (null)
Loader: request POST https://lcdn-locator.apple.com/<redacted>
Challenge: challenge space https://lcdn-locator.apple.com:443/, ServerTrustEvaluationRequested (Hash 91283047ef00ae3c)
} [3:6]
default 2023-09-29 16:30:02.454355 +1000 AssetCacheLocatorService [0x81691bab0] activating connection: mach=true listener=false peer=false name=com.apple.trustd
default 2023-09-29 16:30:02.455334 +1000 AssetCacheLocatorService user sessions enabled, targeting 501
default 2023-09-29 16:30:02.455436 +1000 AssetCacheLocatorService [0x816b12dc0] activating connection: mach=true listener=false peer=false name=com.apple.trustd
default 2023-09-29 16:30:02.630496 +1000 AssetCacheLocatorService cleaning up unpooled xpc conn to trustd 0x816b12dc0
default 2023-09-29 16:30:02.630672 +1000 AssetCacheLocatorService [0x816b12dc0] invalidated on xpc_connection_cancel()
default 2023-09-29 16:30:02.631720 +1000 AssetCacheLocatorService got event: Connection invalid
default 2023-09-29 16:30:02.631788 +1000 AssetCacheLocatorService Task <44EC5539-7E06-4BC5-AD2D-F40E43C947B6>.<1> auth completion disp=0 cred=0x816a14490
default 2023-09-29 16:30:02.632041 +1000 AssetCacheLocatorService CFNetwork Diagnostics [3:7] 16:30:02.631 {
Use Credential: (null)
Loader: request POST https://lcdn-locator.apple.com/<redacted>
Credential: Name: iswlocator.apple.com, Persistence: session
} [3:7]
default 2023-09-29 16:30:02.632267 +1000 AssetCacheLocatorService CFNetwork Diagnostics [3:8] 16:30:02.632 {
touchConnection: (null)
Loader: request POST https://lcdn-locator.apple.com/<redacted>
Timeout Interval: 59.739 seconds
} [3:8]
default 2023-09-29 16:30:02.636661 +1000 AssetCacheLocatorService Connection 1: TLS Trust result 0
default 2023-09-29 16:30:02.636774 +1000 AssetCacheLocatorService boringssl_context_evaluate_trust_async_external_block_invoke_3(1631) [C1.1.1.1.1:2][0x816918590] Returning from external verify block with result: true
default 2023-09-29 16:30:02.636935 +1000 AssetCacheLocatorService boringssl_context_certificate_verify_callback(1852) [C1.1.1.1.1:2][0x816918590] Certificate verification result: OK
Can the trust mechanism for this process be adjusted to enforce certificate validation to allow for HTTPS pac file delivery.
Post
Replies
Boosts
Views
Activity
Since the release of iPadOS 15 we have noticed some apps as well as com.apple.webkit will bypass a proxy server for nested NSURLSession requests if the first request receives a 403 response.
Additionally the behaviour seems to be restricted to device configured with automatic proxy settings for a given network. If proxy settings are set to manual the behaviour doesn't occur.
Is this an issue with the new feature added to iPadOS 15:
URLSession now includes async functions. (68890254)
error 11:41:38.747890 +1000 Hello_World nw_http_connect_process_response http connect Proxy received status: HTTP/1.1 403 Forbidden
default 11:41:38.752065 +1000 Hello_World [C5.1.1 192.168.0.10:3128 failed resolver (satisfied (Path is satisfied), interface: en0, ipv4, dns, proxy)] event: resolver:children_failed @0.091s
info 11:41:38.752232 +1000 Hello_World nw_endpoint_handler_start [C5.1.2 Hostname#fc891996:443 initial path ((null))]
default 11:41:38.752582 +1000 Hello_World [C5.1.2 Hostname#fc891996:443 initial path ((null))] event: path:start @0.091s
default 11:41:38.753731 +1000 Hello_World [C5.1.2 Hostname#fc891996:443 waiting path (satisfied (Path is satisfied), interface: en0, ipv4, dns, proxy)] event: path:satisfied @0.092s, uuid: 35A79C08-A4E5-4EC9-A784-78C4F560AC42
default 11:41:38.754288 +1000 Hello_World [C5.1.2 Hostname#fc891996:443 in_progress resolver (satisfied (Path is satisfied), interface: en0, ipv4, dns, proxy)] event: resolver:start_dns @0.093s
info 11:41:38.754532 +1000 Hello_World nw_resolver_create_dns_getaddrinfo_locked [C5.1.2] Starting host resolution Hostname#fc891996:443, flags 0xc000d000 proto 0 using hostname: <redacted hostname>
info 11:41:38.757527 +1000 Hello_World nw_resolver_create_dns_getaddrinfo_locked_block_invoke [C5.1.2] Got 3 DNS results
info 11:41:38.757615 +1000 Hello_World nw_resolver_create_dns_getaddrinfo_locked_block_invoke [C5.1.2] Got DNS result type NoAddress ifindex=0 <private> <private> IN6ADDR_ANY
info 11:41:38.757702 +1000 Hello_World nw_resolver_create_dns_getaddrinfo_locked_block_invoke [C5.1.2] Got DNS result type ServiceBinding ifindex=0 <private> <private> <NULL>
info 11:41:38.757751 +1000 Hello_World nw_resolver_create_dns_getaddrinfo_locked_block_invoke [C5.1.2] Got DNS result type Add ifindex=0 <private> <private> IPv4#2535179d
info 11:41:38.757792 +1000 Hello_World nw_resolver_create_dns_getaddrinfo_locked_block_invoke [C5.1.2] Got DNS negative reason: query suppressed
info 11:41:38.757837 +1000 Hello_World nw_resolver_create_dns_getaddrinfo_locked_block_invoke [C5.1.2] SVCB queries are complete
default 11:41:38.758300 +1000 Hello_World nw_endpoint_resolver_update [C5.1.2 Hostname#fc891996:443 in_progress resolver (satisfied (Path is satisfied), interface: en0, ipv4, dns, proxy)] Adding endpoint handler for IPv4#2535179d:443
default 11:41:38.758851 +1000 Hello_World [C5.1.2 Hostname#fc891996:443 in_progress resolver (satisfied (Path is satisfied), interface: en0, ipv4, dns, proxy)] event: resolver:receive_dns @0.098s
info 11:41:38.758905 +1000 Hello_World nw_resolver_create_dns_getaddrinfo_locked_block_invoke [C5.1.2] Invalidating getaddrinfo DNS object
info 11:41:38.759032 +1000 Hello_World nw_endpoint_resolver_start_next_child [C5.1.2 Hostname#fc891996:443 in_progress resolver (satisfied (Path is satisfied), interface: en0, ipv4, dns, proxy)] starting child endpoint IPv4#2535179d:443
info 11:41:38.759130 +1000 Hello_World nw_endpoint_handler_start [C5.1.2.1 IPv4#2535179d:443 initial path ((null))]
default 11:41:38.759490 +1000 Hello_World [C5.1.2.1 IPv4#2535179d:443 initial path ((null))] event: path:start @0.098s
default 11:41:38.760370 +1000 Hello_World [C5.1.2.1 IPv4#2535179d:443 waiting path (satisfied (Path is satisfied), interface: en0, ipv4, dns, proxy)] event: path:satisfied @0.099s, uuid: 13B361F5-6CC9-4A72-AEB8-35655515FBBB