On my setup it is easy to reproduce. It is enough to execute with wget: wget -S https://yandex.com/company/ access.log immediately shows 0 - TCP_DENIED/403 3574 GET http://repository.certum.pl/ca.cer - HIER_NONE/- text/html;charset=utf-8 before request to Yandex destination. However it executes: root @ khorne /patch # wget -S https://yandex.com/company/ --2017-01-25 02:37:52-- https://yandex.com/company/ Connecting to 127.0.0.1:3128... connected. Proxy request sent, awaiting response... HTTP/1.1 200 OK Date: Tue, 24 Jan 2017 20:37:54 GMT Content-Type: text/html; charset="UTF-8" Set-Cookie: yandexuid=15112434331485290274; Domain=.yandex.com; Path=/ Content-Security-Policy: default-src 'none'; frame-src 'self' yastatic.net yandex.st music.yandex.ru download.yandex.ru static.video.yandex.ru video.yandex.ru player.vimeo.com www.youtube.com *.cdn.yandex.net; script-src 'unsafe-eval' 'unsafe-inline' clck.yandex.ru pass.yandex.com yastatic.net mc.yandex.ru api-maps.yandex.ru social.yandex.com 'nonce-728706f8-8c12-4f25-a00f-27d1e8c36f6f'; style-src 'unsafe-inline' yastatic.net; connect-src 'self' yandex.st mail.yandex.com mc.yandex.ru mc.yandex.com; font-src yastatic.net; img-src 'self' data: avatars.yandex.net avatars.mds.yandex.net avatars.mdst.yandex.net http://avatars.mds.yandex.net jing.yandex-team.ru download.yandex.ru yandex.st mc.yandex.ru yastatic.net www.tns-counter.ru yandexgacom.hit.gemius.pl *.cdn.yandex.net api-maps.yandex.ru static-maps.yandex.ru *.maps.yandex.net i.ytimg.com company.yandex.com yandex.com http://img-fotki.yandex.ru img-fotki.yandex.ru; media-src *.cdn.yandex.net X-Content-Security-Policy: default-src 'none'; frame-src 'self' yastatic.net yandex.st music.yandex.ru download.yandex.ru static.video.yandex.ru video.yandex.ru player.vimeo.com www.youtube.com *.cdn.yandex.net; script-src 'unsafe-eval' 'unsafe-inline' clck.yandex.ru pass.yandex.com yastatic.net mc.yandex.ru api-maps.yandex.ru social.yandex.com 'nonce-728706f8-8c12-4f25-a00f-27d1e8c36f6f'; style-src 'unsafe-inline' yastatic.net; connect-src 'self' yandex.st mail.yandex.com mc.yandex.ru mc.yandex.com; font-src yastatic.net; img-src 'self' data: avatars.yandex.net avatars.mds.yandex.net avatars.mdst.yandex.net http://avatars.mds.yandex.net jing.yandex-team.ru download.yandex.ru yandex.st mc.yandex.ru yastatic.net www.tns-counter.ru yandexgacom.hit.gemius.pl *.cdn.yandex.net api-maps.yandex.ru static-maps.yandex.ru *.maps.yandex.net i.ytimg.com company.yandex.com yandex.com http://img-fotki.yandex.ru img-fotki.yandex.ru; media-src *.cdn.yandex.net X-WebKit-CSP: default-src 'none'; frame-src 'self' yastatic.net yandex.st music.yandex.ru download.yandex.ru static.video.yandex.ru video.yandex.ru player.vimeo.com www.youtube.com *.cdn.yandex.net; script-src 'unsafe-eval' 'unsafe-inline' clck.yandex.ru pass.yandex.com yastatic.net mc.yandex.ru api-maps.yandex.ru social.yandex.com 'nonce-728706f8-8c12-4f25-a00f-27d1e8c36f6f'; style-src 'unsafe-inline' yastatic.net; connect-src 'self' yandex.st mail.yandex.com mc.yandex.ru mc.yandex.com; font-src yastatic.net; img-src 'self' data: avatars.yandex.net avatars.mds.yandex.net avatars.mdst.yandex.net http://avatars.mds.yandex.net jing.yandex-team.ru download.yandex.ru yandex.st mc.yandex.ru yastatic.net www.tns-counter.ru yandexgacom.hit.gemius.pl *.cdn.yandex.net api-maps.yandex.ru static-maps.yandex.ru *.maps.yandex.net i.ytimg.com company.yandex.com yandex.com http://img-fotki.yandex.ru img-fotki.yandex.ru; media-src *.cdn.yandex.net Content-Encoding: gzip X-XSS-Protection: 1; mode=block X-Content-Type-Options: nosniff Strict-Transport-Security: max-age=0; includeSubDomains X-Cache: MISS from khorne X-Cache-Lookup: HIT from khorne:3128 Transfer-Encoding: chunked Connection: keep-alive Length: unspecified [text/html] Saving to: 'index.html' index.html [ <=> ] 3.60K --.-KB/s in 0s 2017-01-25 02:37:54 (7.44 MB/s) - 'index.html' saved [3688] because intermediate certificates file is exists and configured. 25.01.2017 2:09, Yuri Voinov пишет: > This is mentioned debug for this transaction. > > I see no anomalies. Just DENIED finally. > > > 25.01.2017 1:45, Yuri Voinov пишет: >> 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.
Attachment:
0x613DEC46.asc
Description: application/pgp-keys
Attachment:
signature.asc
Description: OpenPGP digital signature
_______________________________________________ squid-users mailing list squid-users@xxxxxxxxxxxxxxxxxxxxx http://lists.squid-cache.org/listinfo/squid-users
