RE: [squid-users] tcp_outgoing_mark + https

From: Sébastien WENSKE <sebastien_at_wenske.fr>
Date: Thu, 13 Dec 2012 08:29:15 +0000

Hi Eliezer,

I made the tests, and first, there is no IP in the CONNECT request:

13/Dec/2012:07:30:13.508 240535 10.4.10.25 TCP_MISS/200 14882 CONNECT www.kernel.org:443 - HIER_DIRECT/www.kernel.org -

Now the debug:
In HTTP, I see the ACL;
2012/12/13 08:45:03.434 kid1| ACLList::matches: checking fibre
2012/12/13 08:45:03.434 kid1| ACL::checklistMatches: checking 'fibre'
2012/12/13 08:45:03.434 kid1| aclMatchDomainList: checking 'www.kernel.org'
2012/12/13 08:45:03.434 kid1| aclMatchDomainList: 'www.kernel.org' found
2012/12/13 08:45:03.434 kid1| ACL::ChecklistMatches: result for 'fibre' is 1
2012/12/13 08:45:03.434 kid1| aclmatchAclList: 0x7fff52f3eab0 returning true (AND list satisfied)
2012/12/13 08:45:03.434 kid1| ACLChecklist::markFinished: 0x7fff52f3eab0 checklist processing finished

But in HTTPS, nothing. Below, the complete log for a request to https://www.kernel.org:
2012/12/13 09:09:49.255 kid1| Acl.cc(321) matches: ACLList::matches: checking all
2012/12/13 09:09:49.255 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'all'
2012/12/13 09:09:49.255 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' found
2012/12/13 09:09:49.255 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'all' is 1
2012/12/13 09:09:49.255 kid1| Checklist.cc(251) matchAclList: aclmatchAclList: 0x7ffff2c159e0 returning true (AND list satisfied)
2012/12/13 09:09:49.255 kid1| Checklist.cc(156) markFinished: ACLChecklist::markFinished: 0x7ffff2c159e0 checklist processing finished
2012/12/13 09:09:49.255 kid1| Acl.cc(321) matches: ACLList::matches: checking all
2012/12/13 09:09:49.255 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'all'
2012/12/13 09:09:49.255 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52321' found
2012/12/13 09:09:49.255 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'all' is 1
2012/12/13 09:09:49.255 kid1| Checklist.cc(251) matchAclList: aclmatchAclList: 0x7ffff2c159e0 returning true (AND list satisfied)
2012/12/13 09:09:49.255 kid1| Checklist.cc(156) markFinished: ACLChecklist::markFinished: 0x7ffff2c159e0 checklist processing finished
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow swe'
2012/12/13 09:09:49.256 kid1| Acl.cc(321) matches: ACLList::matches: checking swe
2012/12/13 09:09:49.256 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'swe'
2012/12/13 09:09:49.256 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.256 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'swe' is 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow localhost'
2012/12/13 09:09:49.256 kid1| Acl.cc(321) matches: ACLList::matches: checking localhost
2012/12/13 09:09:49.256 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'localhost'
2012/12/13 09:09:49.256 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.256 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'localhost' is 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow manager localhost'
2012/12/13 09:09:49.256 kid1| Acl.cc(321) matches: ACLList::matches: checking manager
2012/12/13 09:09:49.256 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'manager'
2012/12/13 09:09:49.256 kid1| RegexData.cc(70) match: aclRegexData::match: checking 'www.kernel.org:443'
2012/12/13 09:09:49.256 kid1| RegexData.cc(81) match: aclRegexData::match: looking for '(^cache_object://)'
2012/12/13 09:09:49.256 kid1| RegexData.cc(81) match: aclRegexData::match: looking for '(^https?://[^/]+/squid-internal-mgr/)'
2012/12/13 09:09:49.256 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'manager' is 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access deny manager'
2012/12/13 09:09:49.256 kid1| Acl.cc(321) matches: ACLList::matches: checking manager
2012/12/13 09:09:49.256 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'manager'
2012/12/13 09:09:49.256 kid1| RegexData.cc(70) match: aclRegexData::match: checking 'www.kernel.org:443'
2012/12/13 09:09:49.256 kid1| RegexData.cc(81) match: aclRegexData::match: looking for '(^cache_object://)'
2012/12/13 09:09:49.256 kid1| RegexData.cc(81) match: aclRegexData::match: looking for '(^https?://[^/]+/squid-internal-mgr/)'
2012/12/13 09:09:49.256 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'manager' is 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow airpad_test auth to_th2'
2012/12/13 09:09:49.256 kid1| Acl.cc(321) matches: ACLList::matches: checking airpad_test
2012/12/13 09:09:49.256 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'airpad_test'
2012/12/13 09:09:49.256 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.256 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'airpad_test' is 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow airpad_test auth CONNECT SSH_ports to_th2'
2012/12/13 09:09:49.256 kid1| Acl.cc(321) matches: ACLList::matches: checking airpad_test
2012/12/13 09:09:49.256 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'airpad_test'
2012/12/13 09:09:49.256 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.256 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'airpad_test' is 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow airpad_test auth to_localdomain'
2012/12/13 09:09:49.256 kid1| Acl.cc(321) matches: ACLList::matches: checking airpad_test
2012/12/13 09:09:49.256 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'airpad_test'
2012/12/13 09:09:49.256 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.256 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'airpad_test' is 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow airpad_test auth CONNECT SSH_ports to_localdomain'
2012/12/13 09:09:49.256 kid1| Acl.cc(321) matches: ACLList::matches: checking airpad_test
2012/12/13 09:09:49.256 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'airpad_test'
2012/12/13 09:09:49.256 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.256 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'airpad_test' is 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access deny airpad_test'
2012/12/13 09:09:49.256 kid1| Acl.cc(321) matches: ACLList::matches: checking airpad_test
2012/12/13 09:09:49.256 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'airpad_test'
2012/12/13 09:09:49.256 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.256 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'airpad_test' is 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow ouest-express to_th2'
2012/12/13 09:09:49.256 kid1| Acl.cc(321) matches: ACLList::matches: checking ouest-express
2012/12/13 09:09:49.256 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'ouest-express'
2012/12/13 09:09:49.256 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.256 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'ouest-express' is 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow ouest-express CONNECT SSH_ports to_th2'
2012/12/13 09:09:49.256 kid1| Acl.cc(321) matches: ACLList::matches: checking ouest-express
2012/12/13 09:09:49.256 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'ouest-express'
2012/12/13 09:09:49.256 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.256 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'ouest-express' is 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow ouest-express to_localdomain'
2012/12/13 09:09:49.256 kid1| Acl.cc(321) matches: ACLList::matches: checking ouest-express
2012/12/13 09:09:49.256 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'ouest-express'
2012/12/13 09:09:49.256 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.256 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'ouest-express' is 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.256 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.256 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow ouest-express CONNECT SSH_ports to_localdomain'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking ouest-express
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'ouest-express'
2012/12/13 09:09:49.257 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'ouest-express' is 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access deny ouest-express'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking ouest-express
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'ouest-express'
2012/12/13 09:09:49.257 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'ouest-express' is 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow to_localdomain'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking to_localdomain
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'to_localdomain'
2012/12/13 09:09:49.257 kid1| DomainData.cc(131) match: aclMatchDomainList: checking 'www.kernel.org'
2012/12/13 09:09:49.257 kid1| DomainData.cc(135) match: aclMatchDomainList: 'www.kernel.org' NOT found
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'to_localdomain' is 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow to_localnet'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking to_localnet
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'to_localnet'
2012/12/13 09:09:49.257 kid1| Ip.cc(571) match: aclIpMatchIp: '149.20.4.69' NOT found
2012/12/13 09:09:49.257 kid1| Ip.cc(571) match: aclIpMatchIp: '149.20.20.133' NOT found
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'to_localnet' is 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow to_th2'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking to_th2
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'to_th2'
2012/12/13 09:09:49.257 kid1| Ip.cc(571) match: aclIpMatchIp: '149.20.4.69' NOT found
2012/12/13 09:09:49.257 kid1| Ip.cc(571) match: aclIpMatchIp: '149.20.20.133' NOT found
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'to_th2' is 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow to_hq0_ext'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking to_hq0_ext
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'to_hq0_ext'
2012/12/13 09:09:49.257 kid1| Ip.cc(571) match: aclIpMatchIp: '149.20.4.69' NOT found
2012/12/13 09:09:49.257 kid1| Ip.cc(571) match: aclIpMatchIp: '149.20.20.133' NOT found
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'to_hq0_ext' is 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow CONNECT XMPP_Ports chat'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking CONNECT
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'CONNECT'
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'CONNECT' is 1
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking XMPP_Ports
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'XMPP_Ports'
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'XMPP_Ports' is 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access deny !Safe_ports'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking !Safe_ports
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'Safe_ports'
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'Safe_ports' is 1
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow CONNECT FTP_ports'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking CONNECT
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'CONNECT'
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'CONNECT' is 1
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking FTP_ports
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'FTP_ports'
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'FTP_ports' is 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access deny CONNECT !SSL_ports'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking CONNECT
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'CONNECT'
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'CONNECT' is 1
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking !SSL_ports
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'SSL_ports'
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'SSL_ports' is 1
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access deny numeric_url'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking numeric_url
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'numeric_url'
2012/12/13 09:09:49.257 kid1| RegexData.cc(70) match: aclRegexData::match: checking 'www.kernel.org:443'
2012/12/13 09:09:49.257 kid1| RegexData.cc(81) match: aclRegexData::match: looking for '(^[^:]*://([^/@]*@)?[0-9\.]*(:|/|$|\?))|(^[0-9\.:]*$)'
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'numeric_url' is 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow vlan30'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking vlan30
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'vlan30'
2012/12/13 09:09:49.257 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'vlan30' is 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x54fde78 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x54fde78 checking 'http_access allow vlan20'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking vlan20
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'vlan20'
2012/12/13 09:09:49.257 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' found
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'vlan20' is 1
2012/12/13 09:09:49.257 kid1| Checklist.cc(251) matchAclList: aclmatchAclList: 0x54fde78 returning true (AND list satisfied)
2012/12/13 09:09:49.257 kid1| Checklist.cc(156) markFinished: ACLChecklist::markFinished: 0x54fde78 checklist processing finished
2012/12/13 09:09:49.257 kid1| Checklist.cc(103) matchNonBlocking: ACLChecklist::check: 0x54fde78 match found, calling back with 1
2012/12/13 09:09:49.257 kid1| Checklist.cc(188) checkCallback: ACLChecklist::checkCallback: 0x54fde78 answer=1
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x4945528 checking 'always_direct allow airpad_test'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking airpad_test
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'airpad_test'
2012/12/13 09:09:49.257 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'airpad_test' is 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x4945528 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(162) preCheck: ACLChecklist::preCheck: 0x4945528 checking 'always_direct allow ouest-express'
2012/12/13 09:09:49.257 kid1| Acl.cc(321) matches: ACLList::matches: checking ouest-express
2012/12/13 09:09:49.257 kid1| Acl.cc(310) checklistMatches: ACL::checklistMatches: checking 'ouest-express'
2012/12/13 09:09:49.257 kid1| Ip.cc(571) match: aclIpMatchIp: '10.4.10.76:52320' NOT found
2012/12/13 09:09:49.257 kid1| Acl.cc(312) checklistMatches: ACL::ChecklistMatches: result for 'ouest-express' is 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(229) matchAclList: aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(243) matchAclList: aclmatchAclList: 0x4945528 returning (AND list entry awaiting an async lookup)
2012/12/13 09:09:49.257 kid1| Checklist.cc(124) matchNonBlocking: 0x4945528 NO match found, returning 0
2012/12/13 09:09:49.257 kid1| Checklist.cc(188) checkCallback: ACLChecklist::checkCallback: 0x4945528 answer=0

Note that I now running squid 3.2.5.

Best Regards,
Sébastien

-----Message d'origine-----
De : Eliezer Croitoru [mailto:eliezer_at_ngtech.co.il]
Envoyé : mercredi 12 décembre 2012 16:33
À : squid-users_at_squid-cache.org
Cc : Sébastien WENSKE
Objet : Re: [squid-users] tcp_outgoing_mark + https

On 12/12/2012 09:44 AM, Sébastien WENSKE wrote:
> Eliezer,
>
> I'm running Debian 6 with a 3.6.9 kernel, Shorewall is v4.5.9.3 and
> Squid 3.2.3 (I had some troubles to compile 3.2.4)
>
> Indeed, "just these to 100Mbit connection" is what I need:)
Hey Sébastien,

It seems like a bug to me but just to make sure we need to check couple things.
When these requests are being made make sure that in the CONNECT there is no IP in the log but the actual domain name such as:
CONNECT www.google.com
and not CONNECT ip.address.what.so

The next step is to verify that the acls recognize the request dstdomain.
You can either use the acls debug_options which suppose to be 28.
debug_options ALL,1 28,3
will be basic to make sure the requests are being verified by the acl.
If you can use 28,6 it can help with even more details but in most cases not needed.
The above will provide a lot output in production machines so make sure to run small instance for testing or another machine.

When you have the above information please do two things:
File a bug in the squid bugzilla with as much details you can get on the bug and notice that logs can be attached as txt files.
Send the basic description to the squid-dev mailing list.

All the above will help to speed up the a bug fix and bug tracing.
Maybe even one of the developers knows about it already or can give you a test patch.

Regards,
Eliezer
Received on Thu Dec 13 2012 - 08:31:45 MST

This archive was generated by hypermail 2.2.0 : Thu Dec 13 2012 - 12:00:04 MST