[squid-users] Squid 4.x: Intermediate certificates downloader

Tue Jan 24 19:45:23 UTC 2017

Under detailed ACL debug got this transaction:

2017/01/25 01:36:35.772 kid1| 28,3| DomainData.cc(110) match:
aclMatchDomainList: checking 'repository.certum.pl'
2017/01/25 01:36:35.772 kid1| 28,3| DomainData.cc(115) match:
aclMatchDomainList: 'repository.certum.pl' NOT found
2017/01/25 01:36:35.772 kid1| 28,3| Acl.cc(290) matches: checked:
block_tld = 0
2017/01/25 01:36:35.772 kid1| 28,3| Acl.cc(290) matches: checked:
http_access#11 = 0
2017/01/25 01:36:35.772 kid1| 28,5| Checklist.cc(397) bannedAction:
Action 'ALLOWED/0' is not banned
2017/01/25 01:36:35.772 kid1| 28,5| Acl.cc(263) matches: checking
http_access#12
2017/01/25 01:36:35.772 kid1| 28,5| Acl.cc(263) matches: checking CONNECT
2017/01/25 01:36:35.772 kid1| 28,3| Acl.cc(290) matches: checked:
CONNECT = 0
2017/01/25 01:36:35.772 kid1| 28,3| Acl.cc(290) matches: checked:
http_access#12 = 0
2017/01/25 01:36:35.772 kid1| 28,5| Checklist.cc(397) bannedAction:
Action 'ALLOWED/0' is not banned
2017/01/25 01:36:35.772 kid1| 28,5| Acl.cc(263) matches: checking
http_access#13
2017/01/25 01:36:35.772 kid1| 28,5| Acl.cc(263) matches: checking CONNECT
2017/01/25 01:36:35.772 kid1| 28,3| Acl.cc(290) matches: checked:
CONNECT = 0
2017/01/25 01:36:35.772 kid1| 28,3| Acl.cc(290) matches: checked:
http_access#13 = 0
2017/01/25 01:36:35.772 kid1| 28,5| Checklist.cc(397) bannedAction:
Action 'ALLOWED/0' is not banned
2017/01/25 01:36:35.772 kid1| 28,5| Acl.cc(263) matches: checking
http_access#14
2017/01/25 01:36:35.772 kid1| 28,5| Acl.cc(263) matches: checking
windowsupdate
2017/01/25 01:36:35.772 kid1| 28,3| DomainData.cc(110) match:
aclMatchDomainList: checking 'repository.certum.pl'
2017/01/25 01:36:35.772 kid1| 28,3| DomainData.cc(115) match:
aclMatchDomainList: 'repository.certum.pl' NOT found
2017/01/25 01:36:35.772 kid1| 28,3| Acl.cc(290) matches: checked:
windowsupdate = 0
2017/01/25 01:36:35.772 kid1| 28,3| Acl.cc(290) matches: checked:
http_access#14 = 0
2017/01/25 01:36:35.772 kid1| 28,5| Checklist.cc(397) bannedAction:
Action 'ALLOWED/0' is not banned
2017/01/25 01:36:35.772 kid1| 28,5| Acl.cc(263) matches: checking
http_access#15
2017/01/25 01:36:35.772 kid1| 28,5| Acl.cc(263) matches: checking
windowsupdate
2017/01/25 01:36:35.773 kid1| 28,3| DomainData.cc(110) match:
aclMatchDomainList: checking 'repository.certum.pl'
2017/01/25 01:36:35.773 kid1| 28,3| DomainData.cc(115) match:
aclMatchDomainList: 'repository.certum.pl' NOT found
2017/01/25 01:36:35.773 kid1| 28,3| Acl.cc(290) matches: checked:
windowsupdate = 0
2017/01/25 01:36:35.773 kid1| 28,3| Acl.cc(290) matches: checked:
http_access#15 = 0
2017/01/25 01:36:35.773 kid1| 28,5| Checklist.cc(397) bannedAction:
Action 'ALLOWED/0' is not banned
2017/01/25 01:36:35.773 kid1| 28,5| Acl.cc(263) matches: checking
http_access#16
2017/01/25 01:36:35.773 kid1| 28,5| Acl.cc(263) matches: checking localnet
2017/01/25 01:36:35.773 kid1| 28,9| Ip.cc(96) aclIpAddrNetworkCompare:
aclIpAddrNetworkCompare: compare:
[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]/[ffff:ffff:ffff:ffff:ffff:ffff:ffc0:0]
([ffff:ffff:ffff:ffff:ffff:ffff:ffc0:0])  vs
100.64.0.0-[::]/[ffff:ffff:ffff:ffff:ffff:ffff:ffc0:0]
2017/01/25 01:36:35.773 kid1| 28,9| Ip.cc(96) aclIpAddrNetworkCompare:
aclIpAddrNetworkCompare: compare:
[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]/[ffff:ffff:ffff:ffff:ffff:ffff:fff0:0]
([ffff:ffff:ffff:ffff:ffff:ffff:fff0:0])  vs
172.16.0.0-[::]/[ffff:ffff:ffff:ffff:ffff:ffff:fff0:0]
2017/01/25 01:36:35.773 kid1| 28,9| Ip.cc(96) aclIpAddrNetworkCompare:
aclIpAddrNetworkCompare: compare:
[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:0]
([ffff:ffff:ffff:ffff:ffff:ffff:ffff:0])  vs
192.168.0.0-[::]/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:0]
2017/01/25 01:36:35.773 kid1| 28,3| Ip.cc(540) match: aclIpMatchIp:
'[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]' NOT found
2017/01/25 01:36:35.773 kid1| 28,3| Acl.cc(290) matches: checked:
localnet = 0
2017/01/25 01:36:35.773 kid1| 28,3| Acl.cc(290) matches: checked:
http_access#16 = 0
2017/01/25 01:36:35.773 kid1| 28,5| Checklist.cc(397) bannedAction:
Action 'ALLOWED/0' is not banned
2017/01/25 01:36:35.773 kid1| 28,5| Acl.cc(263) matches: checking
http_access#17
2017/01/25 01:36:35.773 kid1| 28,5| Acl.cc(263) matches: checking localhost
2017/01/25 01:36:35.773 kid1| 28,9| Ip.cc(96) aclIpAddrNetworkCompare:
aclIpAddrNetworkCompare: compare:
[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]
([ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff])  vs
127.0.0.1-[::]/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]
2017/01/25 01:36:35.773 kid1| 28,3| Ip.cc(540) match: aclIpMatchIp:
'[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]' NOT found
2017/01/25 01:36:35.773 kid1| 28,3| Acl.cc(290) matches: checked:
localhost = 0
2017/01/25 01:36:35.773 kid1| 28,3| Acl.cc(290) matches: checked:
http_access#17 = 0
2017/01/25 01:36:35.773 kid1| 28,5| Checklist.cc(397) bannedAction:
Action 'DENIED/0' is not banned
2017/01/25 01:36:35.773 kid1| 28,5| Acl.cc(263) matches: checking
http_access#18
2017/01/25 01:36:35.773 kid1| 28,5| Acl.cc(263) matches: checking all
2017/01/25 01:36:35.773 kid1| 28,9| Ip.cc(96) aclIpAddrNetworkCompare:
aclIpAddrNetworkCompare: compare:
[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]/[::] ([::])  vs [::]-[::]/[::]
2017/01/25 01:36:35.773 kid1| 28,3| Ip.cc(540) match: aclIpMatchIp:
'[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]' found
2017/01/25 01:36:35.773 kid1| 28,3| Acl.cc(290) matches: checked: all = 1
2017/01/25 01:36:35.773 kid1| 28,3| Acl.cc(290) matches: checked:
http_access#18 = 1
2017/01/25 01:36:35.773 kid1| 28,3| Acl.cc(290) matches: checked:
http_access = 1
2017/01/25 01:36:35.773 kid1| 28,3| Checklist.cc(63) markFinished:
0x4b781938 answer DENIED for match
2017/01/25 01:36:35.773 kid1| 28,3| Checklist.cc(163) checkCallback:
ACLChecklist::checkCallback: 0x4b781938 answer=DENIED

It seems like bug.

25.01.2017 1:10, Alex Rousskov пишет:
> On 01/24/2017 11:33 AM, Yuri Voinov wrote:
>
>>> 1485279884.648      0 - TCP_DENIED/403 3574 GET
>>> http://repository.certum.pl/ca.cer - HIER_NONE/- text/html;charset=utf-8
>
>> http_access deny !Safe_ports
> Probably does not match -- 80 is a safe port.
>
>
>> # Instant messengers include
>> include "/usr/local/squid/etc/acl.im.include"
> I am guessing these do not match or are irrelevant.
>
>
>> # Deny CONNECT to other than SSL ports
>> http_access deny CONNECT !SSL_ports
> Does not match. This is a GET request.
>
>
>> # Only allow cachemgr access from localhost
>> http_access allow localhost manager
>> http_access deny manager
> Probably do not match. This is not a cache manager request although I
> have not checked how Squid identifies those exactly.
>
>
>> http_access deny to_localhost
> Does not match. The destination is not localhost.
>
>
>> # Allow purge from localhost
>> http_access allow PURGE localhost
>> http_access deny PURGE
> Do not match. This is a GET request, not PURGE.
>
>
>> # Block torrent files
>> acl TorrentFiles rep_mime_type mime-type application/x-bittorrent
>> http_reply_access deny TorrentFiles
> Does not match. There was no response [with an application/x-bittorrent
> MIME type].
>
>
>> # Windows updates rules
>> http_access allow CONNECT wuCONNECT localnet
>> http_access allow CONNECT wuCONNECT localhost
> Do not match. This is a GET request, not CONNECT.
>
>
>> http_access allow windowsupdate localnet
>> http_access allow windowsupdate localhost
> Probably do not match. The internal transaction is not associated with a
> to-Squid connection coming from localnet or localhost.
>
>
>> # Rule allowing access from local networks
>> http_access allow localnet
>> http_access allow localhost
> Probably do not match. The internal transaction is not associated with a
> to-Squid connection coming from localnet or localhost.
>
>
>> # And finally deny all other access to this proxy
>> http_access deny all
> Matches!
>
>
>> I have no idea, what can block access.
> That much was clear from the time you asked the question. I bet your
> last http_access rule that denies all other connection matches, but I
> would still ask Squid. Squid knows why it blocks (or does not allow)
> access. There are several ways to ask Squid, including increasing
> debugging verbosity when reproducing the problem, adding the matching
> ACL to the error message, using custom error messages for different
> http_access deny lines, etc.
>
> These methods are not easy, pleasant, quick, or human-friendly,
> unfortunately, but you are a very capable sysadmin with more than enough
> Squid knowledge to find the blocking directive/ACL, especially for a
> problem that can be isolated to two HTTP transactions.
>
> Once we know what directive/ACL blocks, we may be able to figure out a
> workaround, propose a bug fix, etc. For example, if my guess is correct
> -- the "deny all" rule has matched -- then you would need to add a rule
> to allow internal requests, including the ones that fetch those missing
> certificates.
>
>
> HTH,
>
> Alex.
>
>
>> 25.01.2017 0:27, Alex Rousskov пишет:
>>> On 01/24/2017 11:19 AM, Yuri Voinov wrote:
>>>
>>>> It is downloads directly via proxy from localhost:
>>>> As I understand, downloader also access via localhost, right? 
>>> This is incorrect. Downloader does not have a concept of an HTTP client
>>> which sends the request to Squid so "via localhost" or "via any client
>>> source address" does not apply to Downloader transactions. In other
>>> words, there is no client [source address] for Downloader requests.
>>>
>>> Unfortunately, I do not know exactly what effect that lack of info has
>>> on what ACLs (in part because there are too many of them and because
>>> lack of info is often treated inconsistently by various ACLs). Thus, I
>>> continue to recommend finding out which directive/ACL denied Downloader
>>> access as the first step.
>>>
>>> Alex.
>>>
>>>
>>>> 25.01.2017 0:16, Alex Rousskov пишет:
>>>>> On 01/24/2017 10:48 AM, Yuri Voinov wrote:
>>>>>
>>>>>> It seems 4.0.17 tries to download certs but gives deny somewhere.
>>>>>> However, same URL with wget via same proxy works
>>>>>> Why?
>>>>> Most likely, your http_access or similar rules deny internal download
>>>>> transactions but allow external ones. This is possible, for example, if
>>>>> your access rules use client information. Internal transactions (ESI,
>>>>> missing certificate fetching, Cache Digests, etc.) do not have an
>>>>> associated client.
>>>>>
>>>>> The standard denial troubleshooting procedure applies here: Start with
>>>>> finding out which directive/ACL denies access. I am _not_ implying that
>>>>> this is easy to do.

-------------- next part --------------
A non-text attachment was scrubbed...
Name: 0x613DEC46.asc
Type: application/pgp-keys
Size: 2437 bytes
Desc: not available
URL: <http://lists.squid-cache.org/pipermail/squid-users/attachments/20170125/8ba51f13/attachment.key>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 473 bytes
Desc: OpenPGP digital signature
URL: <http://lists.squid-cache.org/pipermail/squid-users/attachments/20170125/8ba51f13/attachment.sig>