[squid-users] Squid TPROXY issues with Google sites

Sun May 28 11:40:31 UTC 2017

Hi Alex et al.,

Thank you very much for your analysis and help. I really appreciate it.

Please keep in mind that I'm basically an end-user, a sys-admin. I wish I had the time to study Squid's source code. All I can do for now is read the docs that so many people have kindly published.

In 99% of my use cases, I only need this:

ssl_bump stare all
ssl_bump bump all

However, some sites simply don't behave well when accessed with Squid TPROXY. This is an example I'm reporting regarding access to https://accounts.google.com.

The use case is simple. A client browser successfully connects to https://accounts.google.com and I can see this in the access log (there might be some garbage but I'm posting it all for completeness):

# tail -f /var/log/squid/access.log | grep 10.215.145.8
1495969366.990     90 10.215.145.8 TCP_MISS/302 870 GET https://accounts.google.com/ - ORIGINAL_DST/216.58.201.141 text/html
1495969367.089     91 10.215.145.8 TCP_MISS/302 1206 GET https://accounts.google.com/ManageAccount - ORIGINAL_DST/216.58.201.141 text/html
1495969367.165    165 10.215.145.8 TAG_NONE/200 0 CONNECT 216.58.201.141:443 - ORIGINAL_DST/216.58.201.141 -
1495969367.546    452 10.215.145.8 TCP_MISS/200 254275 GET https://accounts.google.com/ServiceLogin? - ORIGINAL_DST/216.58.201.141 text/html
1495969367.684     99 10.215.145.8 TCP_MISS/200 837 GET https://accounts.google.com/_/common/diagnostics/? - ORIGINAL_DST/216.58.201.141 application/json
1495969367.799    218 10.215.145.8 TAG_NONE/200 0 CONNECT 216.58.201.141:443 - ORIGINAL_DST/216.58.201.141 -
1495969368.341    356 10.215.145.8 TCP_MISS/200 9598 GET https://ssl.gstatic.com/accounts/static/_/js/k=gaia.gaiafe_glif.es.QCvs5i6XPsY.O/m=ZJkSm,ssIgD,GJkP8c,HUb4Ab,sy3j,DnoIKd,sy1a,sy1g,YKZpNb,sy19,VI9RTb,sy18,sy24,GEsPC/am=gggAAACgARcEwFGwAlAM/rt=j/rs=ABkqax2H2XpBhaGl4fmxx-IOq5MdI_K9yw - ORIGINAL_DST/172.217.9.227 text/javascript
1495969373.609    249 10.215.145.8 TCP_MISS/200 9598 GET https://ssl.gstatic.com/accounts/static/_/js/k=gaia.gaiafe_glif.es.QCvs5i6XPsY.O/m=ZJkSm,ssIgD,GJkP8c,HUb4Ab,sy3j,DnoIKd,sy1a,sy1g,YKZpNb,sy19,VI9RTb,sy18,sy24,GEsPC/am=gggAAACgARcEwFGwAlAM/rt=j/rs=ABkqax2H2XpBhaGl4fmxx-IOq5MdI_K9yw - ORIGINAL_DST/172.217.9.227 text/javascript
1495969393.879    248 10.215.145.8 TCP_MISS/200 9598 GET https://ssl.gstatic.com/accounts/static/_/js/k=gaia.gaiafe_glif.es.QCvs5i6XPsY.O/m=ZJkSm,ssIgD,GJkP8c,HUb4Ab,sy3j,DnoIKd,sy1a,sy1g,YKZpNb,sy19,VI9RTb,sy18,sy24,GEsPC/am=gggAAACgARcEwFGwAlAM/rt=j/rs=ABkqax2H2XpBhaGl4fmxx-IOq5MdI_K9yw - ORIGINAL_DST/172.217.9.227 text/javascript
1495969393.940    166 10.215.145.8 TCP_MISS/200 452 GET http://detectportal.firefox.com/success.txt - ORIGINAL_DST/23.219.93.219 text/plain
1495969394.116    225 10.215.145.8 TCP_MISS/200 1261 GET https://ssl.gstatic.com/accounts/static/_/js/k=gaia.gaiafe_glif.es.QCvs5i6XPsY.O/m=ZJkSm/am=gggAAACgARcEwFGwAlAM/rt=j/rs=ABkqax2H2XpBhaGl4fmxx-IOq5MdI_K9yw - ORIGINAL_DST/172.217.9.227 text/javascript
1495969394.204    873 10.215.145.8 TAG_NONE/200 0 CONNECT 54.148.190.222:443 - ORIGINAL_DST/54.148.190.222 -
1495969394.724    488 10.215.145.8 TCP_MISS/200 195 POST https://incoming.telemetry.mozilla.org/submit/telemetry/3474d8df-c0c5-454b-916f-20ad7f8cb3f3/main/Firefox/52.0.2/release/20170323105023? - ORIGINAL_DST/54.148.190.222 text/plain
1495969399.355    223 10.215.145.8 TCP_MISS/200 1261 GET https://ssl.gstatic.com/accounts/static/_/js/k=gaia.gaiafe_glif.es.QCvs5i6XPsY.O/m=ZJkSm/am=gggAAACgARcEwFGwAlAM/rt=j/rs=ABkqax2H2XpBhaGl4fmxx-IOq5MdI_K9yw - ORIGINAL_DST/172.217.9.227 text/javascript

The client browser successfully renders Google's log-in page where you enter a username. However, it is NOT possible to "click next" and enter a password.
No matter what the user does on that page, nothing is logged in /var/log/squid/access.log.

The cache log reports errors but they are not necessarily related to this client as there are many others actively browsing.

# grep -i error /var/log/squid/cache.log 
2017/05/28 12:55:48 kid1| Error negotiating SSL on FD 93: error:14090086:SSL routines:ssl3_get_server_certificate:certificate verify failed (1/-1/2)
2017/05/28 12:55:48 kid1| Error negotiating SSL connection on FD 90: error:14094412:SSL routines:ssl3_read_bytes:sslv3 alert bad certificate (1/0)
2017/05/28 12:55:49 kid1| Error negotiating SSL on FD 143: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:55:50 kid1| Error negotiating SSL on FD 172: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:55:55 kid1| Error negotiating SSL on FD 57: error:14090086:SSL routines:ssl3_get_server_certificate:certificate verify failed (1/-1/0)
2017/05/28 12:55:55 kid1| Error negotiating SSL connection on FD 27: error:1408A0C1:SSL routines:ssl3_get_client_hello:no shared cipher (1/-1)
2017/05/28 12:55:58 kid1| Error negotiating SSL on FD 57: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:55:58 kid1| Error negotiating SSL on FD 183: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:00 kid1| Error negotiating SSL on FD 82: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:01 kid1| Error negotiating SSL on FD 82: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:02 kid1| Error negotiating SSL on FD 82: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:02 kid1| Error negotiating SSL on FD 141: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:05 kid1| Error negotiating SSL on FD 81: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:05 kid1| Error negotiating SSL on FD 57: error:14090086:SSL routines:ssl3_get_server_certificate:certificate verify failed (1/-1/0)
2017/05/28 12:56:05 kid1| Error negotiating SSL connection on FD 52: error:1408A0C1:SSL routines:ssl3_get_client_hello:no shared cipher (1/-1)
2017/05/28 12:56:06 kid1| Error negotiating SSL on FD 47: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:08 kid1| Error negotiating SSL on FD 47: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:09 kid1| Error negotiating SSL on FD 47: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:11 kid1| Error negotiating SSL on FD 47: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:13 kid1| Error negotiating SSL on FD 38: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:16 kid1| Error negotiating SSL on FD 38: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:16 kid1| Error negotiating SSL on FD 38: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:16 kid1| Error negotiating SSL on FD 38: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:17 kid1| Error negotiating SSL on FD 17: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:19 kid1| Error negotiating SSL on FD 17: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:20 kid1| Error negotiating SSL on FD 17: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:21 kid1| Error negotiating SSL on FD 52: error:14090086:SSL routines:ssl3_get_server_certificate:certificate verify failed (1/-1/0)
2017/05/28 12:56:21 kid1| Error negotiating SSL connection on FD 49: error:1408A0C1:SSL routines:ssl3_get_client_hello:no shared cipher (1/-1)
2017/05/28 12:56:21 kid1| Error negotiating SSL on FD 17: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:22 kid1| Error negotiating SSL on FD 47: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:22 kid1| Error negotiating SSL on FD 17: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:24 kid1| Error negotiating SSL on FD 17: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:25 kid1| Error negotiating SSL on FD 17: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:27 kid1| Error negotiating SSL on FD 12: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:27 kid1| Error negotiating SSL on FD 12: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:30 kid1| Error negotiating SSL on FD 12: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:30 kid1| Error negotiating SSL on FD 12: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:32 kid1| Error negotiating SSL on FD 12: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:34 kid1| Error negotiating SSL on FD 12: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)
2017/05/28 12:56:35 kid1| Error negotiating SSL on FD 12: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry (1/-1/0)

As I said, if the client browses without Squid TPROXY in the middle, there are no issues and https://accounts.google.com behaves as expected. I haven't read Google's web page source code so I don't know yet which javascript call might be failing, etc.

Is it only me or can this issue be reproduced elsewhere?
Has anyone successfully logged into https://accounts.google.com when using the following config directives in Squid?

ssl_bump stare all
ssl_bump bump all

Anyway, as a workaround I'm willing to splice/tunnel traffic to accounts.google.com *ONLY*, and bump everything else (although I'd prefer to understand why bumping isn't "working" for this site).

I've tried this:

acl GoogleAccounts ssl::server_name accounts.google.com
#acl GoogleAccounts dstdomain accounts.google.com
acl step1 at_step SslBump1
ssl_bump peek step1
ssl_bump splice GoogleAccounts
ssl_bump bump all

However, traffic to accounts.google.com is not spliced, it's bumped like the rest.

Can FQDNs be used in ACLs as in the example above even when peeking at step 1?
If I need to peek at step 2 for GoogleAccounts to splice then I take it I won't be able to "bump all" (the rest).
Likewise, If I need to stare at step 2 then I'll never be able to splice GoogleAccounts.

Please let me know if I'm totally off course.

Thanks,

Vieri