Timeout loading EV websites because OCSP checks do not respect user's proxy settings |
|||||||
Issue descriptionChromeOS version: 67.0.3396.69 ChromeOS device model: HP Chromebook 13 G1 (chell) Case#: 14932204 Description: the customer is using a pac file to configure the proxy https://drive.google.com/open?id=16sfacTKwuFqUm9OwIr-iseKp1av7DGKW which returns: PROXY PROXY1:10117; PROXY PROXY2:10117; DIRECT when trying to connect to some site (example list in https://drive.google.com/open?id=1vLPtM4pyraTDYVSLgoh1sewR8BF5zzD-Xun0hV2AJ54 ) using the ethernet, they have timeout, instead using the wifi they don't have any issue. Steps to reproduce: connect to some site listed in ( https://drive.google.com/open?id=1vLPtM4pyraTDYVSLgoh1sewR8BF5zzD-Xun0hV2AJ54) Current Behavior / Reproduction: timeout Expected Behavior: being able to connect using a proxy Drive link to logs: https://drive.google.com/open?id=1dQl4_NNYSH8ZwTY_32yVWaplcjNVNeap net-export: https://drive.google.com/open?id=1bL7OltNXQdMVgZ0viAP9tRhGeBd82THf customer info: https://drive.google.com/open?id=1vLPtM4pyraTDYVSLgoh1sewR8BF5zzD-Xun0hV2AJ54 in the net-export log I see: 12317: URL_REQUEST http://adp.com/ Start Time: 2018-06-06 16:52:23.181 12319: HTTP_STREAM_JOB_CONTROLLER https://www.adp.com/ Start Time: 2018-06-06 16:52:23.198 t=121087 [st=13] PROXY_RESOLUTION_SERVICE_RESOLVED_PROXY_LIST --> pac_string = "PROXY PROXY1:10117;PROXY PROXY2:10117;DIRECT" t=121087 [st=13] PROXY_RESOLUTION_SERVICE_DEPRIORITIZED_BAD_PROXIES --> pac_string = "PROXY PROXY2:10117;DIRECT;PROXY PROXY1:10117" t=121087 [st=13] -PROXY_RESOLUTION_SERVICE t=121087 [st=13] HTTP_STREAM_JOB_CONTROLLER_PROXY_SERVER_RESOLVED --> proxy_server = "PROXY PROXY2:10117" so it's using the proxy to connect to the site, but for the 12358: CERT_VERIFIER_JOB Start Time: 2018-06-06 16:52:23.337 12359: URL_REQUEST http://ocsp.digicert.com/MHEwbzBNMEswSTAJBgUrDgMCGgUABBTfqhLjKLEJQZPin0KCzkdAQpVYowQUsT7DaQP4v0cB1JgmGggC72NkK8MCEAx5qUSwjBGVIJJhX%2BJrHYOiHjAcMBoGCSsGAQUFBzABBAQNMAsGCSsGAQUFBzABAQ%3D%3D Start Time: 2018-06-06 16:52:23.358 12360: HTTP_STREAM_JOB_CONTROLLER http://ocsp.digicert.com/MHEwbzBNMEswSTAJBgUrDgMCGgUABBTfqhLjKLEJQZPin0KCzkdAQpVYowQUsT7DaQP4v0cB1JgmGggC72NkK8MCEAx5qUSwjBGVIJJhX%2BJrHYOiHjAcMBoGCSsGAQUFBzABBAQNMAsGCSsGAQUFBzABAQ%3D%3D Start Time: 2018-06-06 16:52:23.358 t=121234 [st= 0] +PROXY_RESOLUTION_SERVICE [dt=0] t=121234 [st= 0] PROXY_RESOLUTION_SERVICE_RESOLVED_PROXY_LIST --> pac_string = "DIRECT" t=121234 [st= 0] -PROXY_RESOLUTION_SERVICE t=121234 [st= 0] HTTP_STREAM_JOB_CONTROLLER_PROXY_SERVER_RESOLVED --> proxy_server = "DIRECT" t=121234 [st= 0] HTTP_STREAM_REQUEST_STARTED_JOB --> source_dependency = 12361 (HTTP_STREAM_JOB) t=126207 [st=4973] -HTTP_STREAM_JOB_CONTROLLER it's using the direct connection. we asked the customer to try the beta release after crbug.com/680837 has been fixed.
,
Jun 11 2018
I've asked the customer to create the net-export using the wifi network: https://drive.google.com/open?id=18LotvfBzIulWem025r-qcwi2ICYU2cpK 72459: CERT_VERIFIER_JOB Start Time: 2018-06-11 16:41:38.857 72460: URL_REQUEST http://ocsp.digicert.com/MHEwbzBNMEswSTAJBgUrDgMCGgUABBRJ9L2KGL92BpjF3kAtaDtxauTmhgQUPdNQpdagre7zSmAKZdMh1Pj41g8CEAbhPrfZnsgJ0m579IMxiumiHjAcMBoGCSsGAQUFBzABBAQNMAsGCSsGAQUFBzABAQ%3D%3D Start Time: 2018-06-11 16:41:38.981 72461: HTTP_STREAM_JOB_CONTROLLER http://ocsp.digicert.com/MHEwbzBNMEswSTAJBgUrDgMCGgUABBRJ9L2KGL92BpjF3kAtaDtxauTmhgQUPdNQpdagre7zSmAKZdMh1Pj41g8CEAbhPrfZnsgJ0m579IMxiumiHjAcMBoGCSsGAQUFBzABBAQNMAsGCSsGAQUFBzABAQ%3D%3D Start Time: 2018-06-11 16:41:38.981 t=65430 [st= 0] +HTTP_STREAM_JOB_CONTROLLER [dt=20] --> is_preconnect = false --> url = "http://ocsp.digicert.com/MHEwbzBNMEswSTAJBgUrDgMCGgUABBRJ9L2KGL92BpjF3kAtaDtxauTmhgQUPdNQpdagre7zSmAKZdMh1Pj41g8CEAbhPrfZnsgJ0m579IMxiumiHjAcMBoGCSsGAQUFBzABBAQNMAsGCSsGAQUFBzABAQ%3D%3D" t=65430 [st= 0] HTTP_STREAM_JOB_CONTROLLER_BOUND --> source_dependency = 72460 (URL_REQUEST) t=65430 [st= 0] +PROXY_RESOLUTION_SERVICE [dt=12] t=65431 [st= 1] +HOST_RESOLVER_IMPL_REQUEST [dt=10] --> address_family = 1 --> allow_cached_response = true --> host = "ocsp.digicert.com:80" --> is_speculative = false t=65431 [st= 1] HOST_RESOLVER_IMPL_CREATE_JOB t=65431 [st= 1] HOST_RESOLVER_IMPL_JOB_ATTACH --> source_dependency = 72462 (HOST_RESOLVER_IMPL_JOB) t=65441 [st=11] -HOST_RESOLVER_IMPL_REQUEST t=65442 [st=12] PROXY_RESOLUTION_SERVICE_RESOLVED_PROXY_LIST --> pac_string = "PROXY PROXY1:10117;PROXY PROXY2:10117;DIRECT" t=65442 [st=12] -PROXY_RESOLUTION_SERVICE t=65442 [st=12] HTTP_STREAM_JOB_CONTROLLER_PROXY_SERVER_RESOLVED --> proxy_server = "PROXY PROXY1:10117" t=65442 [st=12] HTTP_STREAM_REQUEST_STARTED_JOB --> source_dependency = 72464 (HTTP_STREAM_JOB) t=65450 [st=20] -HTTP_STREAM_JOB_CONTROLLER as you can see, it's using the proxy.
,
Jun 12 2018
It looks like the user is getting timeouts when connecting to EV https:// sites. Presumably non-EV sites would not timeout. The log shows that 30 second are being spent in certificate verification, after which we time out the request. Certificate verification doesn't have many details logged, but I can see POST requests to http://ocsp.digicert.com/ in the log which timed out after 15 seconds. Perhaps on the wifi configuration connections to http://ocsp.digicert.com/ are doomed to fail unless they go through a proxy (and for NSS's OCSP they don't). I am not sure how we got from 15 second timeout to hitting the 30 seconds though. Perhaps there was a fallback attempt which hit the 15 second timeout a second time. I am not aware of changes in 67 that would have modified this behavior. Would it be possible to have the user try 66 and see if it is also affected? The 30 second timeout I believe is being controlled by an experiment Tarun is running. It used to be higher on desktop (3 minutes), which would have meant that this case would have worked, albeit painfully slowly.
,
Jun 12 2018
eroman: I am trying to determine the proxy timeout used in the first log. Where do you see the 30 second timeout?
,
Jun 13 2018
Try these filters: id:12340 id:12338 id:12342 id:12370 The first one is the PROXY_CLIENT_SOCKET_WRAPPER showing the slowness in cert verification, the rest show related dependencies, culminating with the URL_REQUEST to http://adp.com/ that failed.
,
Jun 13 2018
Thanks! Looking at id:12338, it seems that the 30 seconds timeout is coming from SSL_CONNECT_JOB::SOCKET_POOL_CONNECT_JOB_TIMED_OUT. That *I think* is coming from here: https://cs.chromium.org/chromium/src/net/socket/ssl_client_socket_pool.cc?rcl=486bced222f5d07b83b20857e40972d6caadf398&l=97
,
Jun 14 2018
@tbansal: Thanks for looking! Yes you are correct - the SSLClientSocketImpl handshake+certverification also has a timeout of 30 seconds. So this behavior is unaffected by your change (which coincidentally also sets a timeout of 30 seconds). Feel free to unsubscribe from this bug :)
,
Jun 18 2018
,
Jun 21 2018
As written in #c3 I've asked the customer to try with M66: M66.chrome-net-export-log_Wifi.json https://drive.google.com/open?id=1Pfp7g-DklPg98a33SH1C4BB9W-8XVd5h M66.chrome-net-export-log-Ethernet.json https://drive.google.com/open?id=1CfJIyP1lURayQ9SAf-LjB2o_oKxrQn0C Also M66 is affected.
,
Jun 21 2018
Thanks for the additional data! The root issue is that fetching http://ocsp.digicert.com/ DIRECT (i.e. no proxy) on the wired network is failing, due to a timeout in making a TCP connection. Whereas fetching it DIRECT from the wireless network is succeeding. Because fetches for OCSP are timing out, it is breaking the loading of EV https:// sites. This in turn is almost certainly a consequence of certificate verification not applying Chrome's proxy settings ( Issue 80722 and Issue 167742 ). This enterprise is configuring proxy settings via a PAC script. This PAC script in turn says that http://ocsp.digicert.com/ should be fetched via proxy, however Chrome is fetching it DIRECT. The workarounds on the enterprise side to address this are not great: (A) Make requests that don't go through proxy fail faster. Right now the DNS resolution is succeeding, however the TCP connection is hanging. Making either of these fail faster would avoid the catastrophic performance in Chrome. (B) Whitelist http://ocsp.digicert.com/ for DIRECT access on the network (to match the behavior from wireless network). This would solve the immediate problem, however would not be a general solution as there are other URLs that would also need to be whitelisted... (C) Launch Chrome with command line flags that blacklist host resolution for ocsp.digicert.com. Unfortunately I don't think this can be done on ChromeOS as changing the browser's command line flags is difficult. For other platforms you could launch with --host-resolver-rules="MAP ocsp.digicert.com ~NOTFOUND" On the Chrome end, we have had the issue of not applying proxy settings to OCSP/AIA/CRL for a long time, and I don't expect that will be fixed until we have switched to the builtin verifier for ChromeOS (roughly Issue 410574). Based on the resolution of Issue 80722 and Issue 167742 this is probably a WontFix. The 15 second timeout for opportunistic EV is quite punishing. Making Chrome use a lower threshold would also improve things.
,
Jun 21 2018
+Devon: Another example of why I want to remove the opportunistic EV checking :)
,
Jun 28 2018
,
Jun 28 2018
Hi, the customer confirmed they have the same configuration for the Wi-Fi and the wired network. I'm trying to reproduce, but with the network policy pushed at the device level, the OCSP is using the proxy. I've asked the customer to send me their configuration.
,
Jun 28 2018
> the customer confirmed they have the same configuration for the Wi-Fi and the wired network. The NetLog shows they are using the same proxy settings for wired vs wifi, so I don't expect this is something you will be able to reproduce on your end. OCSP requests are not using the proxy settings for either network ( Issue 80722 and Issue 167742 ). However the wifi network is seemingly letting them through when going direct, whereas the wired network does not. Having OCSP use the per-profile proxy settings is currently a WontFix on the Chrome side.
,
Jun 28 2018
One workaround for this is to configure the proxy settings via Policy [1] rather than on a per-profile basis.
The benefit of configuring via Policy is it will additional apply the proxy settings to the System Request Context, which is what NSS is using for its OCSP integration.
Specifically, add these two policy values:
{
"ProxyMode": "pac_script",
"ProxyPacUrl": "http://url-to-pac-file.pac"
}
I verified these steps using Chrome 69, and confirmed that OCSP requests made by NSS will pass through the desired PAC script in this case.
The better longterm solution is predicated on Issue 410574, after which we will have full control over how OCSP requests get issued by the certificate verifier and can make it use the per-profile context.
[1] https://www.chromium.org/administrators/policy-list-3
,
Jun 29 2018
another policy is possible to use is DeviceOpenNetworkConfiguration the user one OpenNetworkConfiguration it's not working. |
|||||||
►
Sign in to add a comment |
|||||||
Comment 1 by marcore@chromium.org
, Jun 11 2018