Right — I hadn’t thought of SNI and what-not. Is there a way I can identify 
those extensions from Squid’s logs?

I guess if it’s the client closing it, we’re not going to get much info from 
Squid’s end?

The in-app actions don’t hang per se, it pretty much instantly fails complete 
but leaves no error about it. In the App Store update case, you press “Update”, 
the button turns to the spinner for about 1 second and then changes back to the 
“Update” state as if nothing happened.

This is the cache.log output I get for one of these requests with the 
afore-mentioned debug_options (access.log has no record of it):

2014/04/07 15:21:55.454 kid1| Checklist.cc(62) preCheck: 0x30a86b8 checking 
slow rules
2014/04/07 15:21:55.454 kid1| Ip.cc(560) match: aclIpMatchIp: 
'10.0.1.175:56094' NOT found
2014/04/07 15:21:55.454 kid1| Acl.cc(177) matches: checked: localhost = 0
2014/04/07 15:21:55.454 kid1| Acl.cc(177) matches: checked: (ssl_bump rule) = 0
2014/04/07 15:21:55.454 kid1| Ip.cc(560) match: aclIpMatchIp: '23.73.114.217' 
NOT found
2014/04/07 15:21:55.454 kid1| Acl.cc(177) matches: checked: bump_bypass = 0
2014/04/07 15:21:55.454 kid1| Acl.cc(177) matches: checked: (ssl_bump rule) = 0
2014/04/07 15:21:55.454 kid1| Ip.cc(560) match: aclIpMatchIp: 
'10.0.1.175:56094' found
2014/04/07 15:21:55.454 kid1| Acl.cc(177) matches: checked: all = 1
2014/04/07 15:21:55.454 kid1| Acl.cc(177) matches: checked: (ssl_bump rule) = 1
2014/04/07 15:21:55.454 kid1| Acl.cc(177) matches: checked: (ssl_bump rules) = 1
2014/04/07 15:21:55.454 kid1| Checklist.cc(55) markFinished: 0x30a86b8 answer 
ALLOWED for match
2014/04/07 15:21:55.454 kid1| Checklist.cc(155) checkCallback: 
ACLChecklist::checkCallback: 0x30a86b8 answer=ALLOWED
2014/04/07 15:21:55.455 kid1| Checklist.cc(62) preCheck: 0x255fe98 checking 
slow rules
2014/04/07 15:21:55.455 kid1| Ip.cc(560) match: aclIpMatchIp: 
'23.73.114.217:443' NOT found
2014/04/07 15:21:55.455 kid1| Acl.cc(177) matches: checked: 
management_interface = 0
2014/04/07 15:21:55.455 kid1| Acl.cc(177) matches: checked: always_direct#1 = 0
2014/04/07 15:21:55.455 kid1| Acl.cc(177) matches: checked: upstream_bypass = 0
2014/04/07 15:21:55.455 kid1| Acl.cc(177) matches: checked: always_direct#2 = 0
2014/04/07 15:21:55.455 kid1| Acl.cc(177) matches: checked: always_direct = 0
2014/04/07 15:21:55.455 kid1| Checklist.cc(378) calcImplicitAnswer: 0x255fe98 
NO match found, last action ALLOWED so returning DENIED
2014/04/07 15:21:55.455 kid1| Checklist.cc(55) markFinished: 0x255fe98 answer 
DENIED for implicit rule won
2014/04/07 15:21:55.455 kid1| Checklist.cc(155) checkCallback: 
ACLChecklist::checkCallback: 0x255fe98 answer=DENIED
2014/04/07 15:21:56.279 kid1| Checklist.cc(62) preCheck: 0x7fff718578a0 
checking fast ACLs
2014/04/07 15:21:56.279 kid1| Acl.cc(177) matches: checked: ssl::certUntrusted 
= 0
2014/04/07 15:21:56.279 kid1| Acl.cc(177) matches: checked: (sslproxy_cert_sign 
signUntrusted line) = 0
2014/04/07 15:21:56.279 kid1| Acl.cc(177) matches: checked: sslproxy_cert_sign 
signUntrusted = 0
2014/04/07 15:21:56.279 kid1| Checklist.cc(55) markFinished: 0x7fff718578a0 
answer DENIED for ACLs failed to match
2014/04/07 15:21:56.279 kid1| Checklist.cc(62) preCheck: 0x7fff718578a0 
checking fast ACLs
2014/04/07 15:21:56.279 kid1| Acl.cc(177) matches: checked: ssl::certSelfSigned 
= 0
2014/04/07 15:21:56.279 kid1| Acl.cc(177) matches: checked: (sslproxy_cert_sign 
signSelf line) = 0
2014/04/07 15:21:56.279 kid1| Acl.cc(177) matches: checked: sslproxy_cert_sign 
signSelf = 0
2014/04/07 15:21:56.279 kid1| Checklist.cc(55) markFinished: 0x7fff718578a0 
answer DENIED for ACLs failed to match
2014/04/07 15:21:56.279 kid1| Checklist.cc(62) preCheck: 0x7fff718578a0 
checking fast ACLs
2014/04/07 15:21:56.279 kid1| Ip.cc(560) match: aclIpMatchIp: 
'10.0.1.175:56094' found
2014/04/07 15:21:56.279 kid1| Acl.cc(177) matches: checked: all = 1
2014/04/07 15:21:56.279 kid1| Acl.cc(177) matches: checked: (sslproxy_cert_sign 
signTrusted line) = 1
2014/04/07 15:21:56.279 kid1| Acl.cc(177) matches: checked: sslproxy_cert_sign 
signTrusted = 1
2014/04/07 15:21:56.279 kid1| Checklist.cc(55) markFinished: 0x7fff718578a0 
answer ALLOWED for match

On 7 Apr 2014, at 3:10 pm, Amos Jeffries <[email protected]> wrote:

> On 7/04/2014 4:58 p.m., Dan Charlesworth wrote:
>> This somewhat vague error comes up with relative frequency from iOS
>> apps when browsing via our Squid 3.4.4 intercepting proxy which is
>> performing server-first SSL Bumping.
>> 
>> The requests in question don’t make it as far as the access log, but
>> with debug_options 28,3 26,3, the dst IP can be identified and
>> allowed through with ssl_bump none.
> 
> Aha. So they hang? all requests that start should be logged.
> 
>> 
>> The device trusts Squid's CA, but apparently that’s not enough for
>> the Twitter iOS app and certain Akamai requests that App Store
>> updates use.
>> 
>> Can anyone suggest how one might debug this further? Or just an idea
>> of why the client might be closing the SSL connection in certain
>> cases?
> 
> Is there any SNI or NPN or ALPN extensions on those requests?
> It could be the clients are using new non-HTTP protocols whih cannot be
> bumped.
> 
> 
> Amos

Reply via email to