Hello,
Thank's for answer. I increased output level and get this :
2022/09/26 09:07:52.381| 44,3| peer_select.cc(163) peerSelect: CONNECT
2022/09/26 09:07:52.381| 44,3| peer_select.cc(472) peerSelectFoo: CONNECT
api.gouv.fr
2022/09/26 09:07:52.381| 44,3| peer_select.cc(485) peerSelectFoo:
peerSelectFoo: direct = DIRECT_UNKNOWN (never_direct to be checked)
2022/09/26 09:07:52.381| 28,3| Checklist.cc(70) preCheck: 0x5653abfc4b68
checking slow rules
2022/09/26 09:07:52.381| 28,3| Ip.cc(538) match: aclIpMatchIp:
'10.25.41.21:34896' found
2022/09/26 09:07:52.381| 28,3| Acl.cc(151) matches: checked: all = 1
2022/09/26 09:07:52.381| 28,3| Acl.cc(151) matches: checked: never_direct#1 = 1
2022/09/26 09:07:52.381| 28,3| Acl.cc(151) matches: checked: never_direct = 1
2022/09/26 09:07:52.381| 28,3| Checklist.cc(63) markFinished: 0x5653abfc4b68
answer ALLOWED for match
2022/09/26 09:07:52.381| 28,3| Checklist.cc(163) checkCallback:
ACLChecklist::checkCallback: 0x5653abfc4b68 answer=ALLOWED
2022/09/26 09:07:52.381| 44,3| peer_select.cc(195) peerCheckNeverDirectDone:
peerCheckNeverDirectDone: ALLOWED
2022/09/26 09:07:52.381| 44,3| peer_select.cc(201) peerCheckNeverDirectDone:
direct = DIRECT_NO (never_direct allow)
2022/09/26 09:07:52.381| 44,3| peer_select.cc(472) peerSelectFoo: CONNECT
api.gouv.fr
2022/09/26 09:07:52.381| 44,3| peer_select.cc(712) peerGetSomeParent: CONNECT
api.gouv.fr
2022/09/26 09:07:52.381| 15,3| neighbors.cc(332) getRoundRobinParent: returning
NULL
2022/09/26 09:07:52.381| 15,3| neighbors.cc(382) getWeightedRoundRobinParent:
getWeightedRoundRobinParent: returning NULL
2022/09/26 09:07:52.381| 28,3| Checklist.cc(70) preCheck: 0x7ffd6220f030
checking fast rules
2022/09/26 09:07:52.381| 28,3| Ip.cc(538) match: aclIpMatchIp:
'10.25.41.21:34896' found
2022/09/26 09:07:52.381| 28,3| Acl.cc(151) matches: checked: all = 1
2022/09/26 09:07:52.381| 28,3| Acl.cc(151) matches: checked: peer_access
squid-2.inf-proxy03-d01.dc02#1 = 1
2022/09/26 09:07:52.381| 28,3| Acl.cc(151) matches: checked: peer_access
squid-2.inf-proxy03-d01.dc02 = 1
2022/09/26 09:07:52.381| 28,3| Checklist.cc(63) markFinished: 0x7ffd6220f030
answer ALLOWED for match
2022/09/26 09:07:52.381| 15,3| neighbors.cc(294) getFirstUpParent:
getFirstUpParent: returning 10.26.8.10
2022/09/26 09:07:52.381| 44,3| peer_select.cc(978) peerAddFwdServer: adding
FIRSTUP_PARENT/10.26.8.10
2022/09/26 09:07:52.381| 28,3| Checklist.cc(70) preCheck: 0x7ffd6220f0d0
checking fast rules
2022/09/26 09:07:52.381| 28,3| Ip.cc(538) match: aclIpMatchIp:
'10.25.41.21:34896' found
2022/09/26 09:07:52.381| 28,3| Acl.cc(151) matches: checked: all = 1
2022/09/26 09:07:52.382| 28,3| Acl.cc(151) matches: checked: peer_access
squid-2.inf-proxy03-d01.dc02#1 = 1
2022/09/26 09:07:52.382| 28,3| Acl.cc(151) matches: checked: peer_access
squid-2.inf-proxy03-d01.dc02 = 1
2022/09/26 09:07:52.382| 28,3| Checklist.cc(63) markFinished: 0x7ffd6220f0d0
answer ALLOWED for match
2022/09/26 09:07:52.382| 44,3| peer_select.cc(971) peerAddFwdServer: skipping
ANY_OLD_PARENT/10.26.8.10; have FIRSTUP_PARENT/10.26.8.10
2022/09/26 09:07:52.382| 28,3| Checklist.cc(70) preCheck: 0x7ffd6220f0d0
checking fast rules
2022/09/26 09:07:52.382| 28,3| Ip.cc(538) match: aclIpMatchIp:
'10.25.41.21:34896' found
2022/09/26 09:07:52.382| 28,3| Acl.cc(151) matches: checked: all = 1
2022/09/26 09:07:52.382| 28,3| Acl.cc(151) matches: checked: peer_access
squid-2.inf-proxy03-d01.dc01#1 = 1
2022/09/26 09:07:52.382| 28,3| Acl.cc(151) matches: checked: peer_access
squid-2.inf-proxy03-d01.dc01 = 1
2022/09/26 09:07:52.382| 28,3| Checklist.cc(63) markFinished: 0x7ffd6220f0d0
answer ALLOWED for match
2022/09/26 09:07:52.382| 44,3| peer_select.cc(978) peerAddFwdServer: adding
ANY_OLD_PARENT/127.0.0.1
2022/09/26 09:07:52.382| 15,3| neighbors.cc(472) getDefaultParent:
getDefaultParent: returning NULL
2022/09/26 09:07:52.382| 44,2| peer_select.cc(295) peerSelectDnsPaths: Find IP
destination for: api.gouv.fr:443' via 10.26.8.10
2022/09/26 09:07:52.382| 44,2| peer_select.cc(295) peerSelectDnsPaths: Find IP
destination for: api.gouv.fr:443' via 127.0.0.1
2022/09/26 09:07:52.382| 44,2| peer_select.cc(316) peerSelectDnsPaths: Found
sources for 'api.gouv.fr:443'
2022/09/26 09:07:52.382| 44,2| peer_select.cc(317) peerSelectDnsPaths:
always_direct = DENIED
2022/09/26 09:07:52.382| 44,2| peer_select.cc(318) peerSelectDnsPaths:
never_direct = ALLOWED
2022/09/26 09:07:52.382| 44,2| peer_select.cc(328) peerSelectDnsPaths:
cache_peer = local=0.0.0.0 remote=10.26.8.10:3129 flags=1
2022/09/26 09:07:52.382| 44,2| peer_select.cc(328) peerSelectDnsPaths:
cache_peer = local=0.0.0.0 remote=127.0.0.1:3129 flags=1
2022/09/26 09:07:52.382| 44,2| peer_select.cc(331) peerSelectDnsPaths:
timedout = 0
2022/09/26 09:07:52.382| 26,3| tunnel.cc(1249) tunnelPeerSelectComplete:
paths=2, p[0]={local=0.0.0.0 remote=10.26.8.10:3129 flags=1},
serverDest[0]={local=0.0.0.0 remote=10.26.8.10:3129 flags=1}
2022/09/26 09:07:52.382| 17,3| FwdState.cc(1369) GetMarkingsToServer: from
0.0.0.0 netfilter mark 0
2022/09/26 09:07:52.382| 26,3| AsyncCall.cc(25) AsyncCall: The AsyncCall
tunnelConnectDone constructed, this=0x5653abf924a0 [call164]
2022/09/26 09:07:52.382| 5,3| ConnOpener.cc(43) ConnOpener: will connect to
local=0.0.0.0 remote=10.26.8.10:3129 flags=1 with 30 timeout
2022/09/26 09:07:52.382| 50,3| comm.cc(350) comm_openex: comm_openex: Attempt
open socket for: 0.0.0.0
2022/09/26 09:07:52.382| 50,3| comm.cc(393) comm_openex: comm_openex: Opened
socket local=0.0.0.0 remote=[::] FD 14 flags=1 : family=2, type=1, protocol=6
2022/09/26 09:07:52.382| 51,3| fd.cc(198) fd_open: fd_open() FD 14
api.gouv.fr:443
2022/09/26 09:07:52.382| 5,3| ConnOpener.cc(291) createFd: local=0.0.0.0
remote=10.26.8.10:3129 flags=1 will timeout in 30
2022/09/26 09:07:52.393| 26,3| AsyncCall.cc(92) ScheduleCall:
ConnOpener.cc(139) will call tunnelConnectDone(local=10.25.8.10:58500
remote=10.26.8.10:3129 FD 14 flags=1, data=0x5653abfa3598) [call164]
2022/09/26 09:07:52.393| 26,3| AsyncCallQueue.cc(55) fireNext: entering
tunnelConnectDone(local=10.25.8.10:58500 remote=10.26.8.10:3129 FD 14 flags=1,
data=0x5653abfa3598)
2022/09/26 09:07:52.393| 26,3| AsyncCall.cc(37) make: make call
tunnelConnectDone [call164]
2022/09/26 09:07:52.393| 14,3| Address.cc(382) lookupHostIP: Given Non-IP
'api.gouv.fr': Name or service not known
2022/09/26 09:07:52.393| 38,3| net_db.cc(355) netdbSendPing: netdbSendPing:
pinging api.gouv.fr
2022/09/26 09:07:52.393| 37,2| IcmpSquid.cc(59) SendEcho: Socket Closed.
Aborted send to 10.26.8.10, opcode 3, len 10
2022/09/26 09:07:52.393| 26,3| tunnel.cc(1163) tunnelRelayConnectRequest:
local=10.25.8.10:58500 remote=10.26.8.10:3129 FD 14 flags=1,
tunnelState=0x5653abfa3598
2022/09/26 09:07:52.393| 22,3| refresh.cc(648) getMaxAge: getMaxAge:
'api.gouv.fr:443'
2022/09/26 09:07:52.393| 11,2| tunnel.cc(1177) tunnelRelayConnectRequest:
Tunnel Server REQUEST: local=10.25.8.10:58500 remote=10.26.8.10:3129 FD 14
flags=1:
----------
CONNECT api.gouv.fr:443 HTTP/1.1
User-Agent: curl/7.52.1
Host: api.gouv.fr:443
X-Forwarded-For: unknown
Cache-Control: max-age=259200
Connection: close
----------
2022/09/26 09:07:52.393| 5,3| comm.cc(559) commSetConnTimeout:
local=10.25.8.10:58500 remote=10.26.8.10:3129 FD 14 flags=1 timeout 900
2022/09/26 09:07:52.393| 5,3| comm.cc(559) commSetConnTimeout:
local=10.25.8.10:58500 remote=10.26.8.10:3129 FD 14 flags=1 timeout 900
2022/09/26 09:07:52.393| 26,3| AsyncCallQueue.cc(57) fireNext: leaving
tunnelConnectDone(local=10.25.8.10:58500 remote=10.26.8.10:3129 FD 14 flags=1,
data=0x5653abfa3598)
2022/09/26 09:07:52.393| 5,3| IoCallback.cc(116) finish: called for
local=10.25.8.10:58500 remote=10.26.8.10:3129 FD 14 flags=1 (0, 0)
2022/09/26 09:07:52.393| 26,3| tunnel.cc(929) tunnelConnectReqWriteDone:
local=10.25.8.10:58500 remote=10.26.8.10:3129 FD 14 flags=1, flag=0
It seems peerGetSomeParent is called and this method never issue an ICP :
static void
peerGetSomeParent(ps_state * ps)
{
CachePeer *p;
HttpRequest *request = ps->request;
hier_code code = HIER_NONE;
debugs(44, 3, request->method << ' ' << request->url.host());
if (ps->direct == DIRECT_YES)
return;
if ((p = peerSourceHashSelectParent(request))) {
code = SOURCEHASH_PARENT;
#if USE_AUTH
} else if ((p = peerUserHashSelectParent(request))) {
code = USERHASH_PARENT;
#endif
} else if ((p = carpSelectParent(request))) {
code = CARP;
} else if ((p = getRoundRobinParent(request))) {
code = ROUNDROBIN_PARENT;
} else if ((p = getWeightedRoundRobinParent(request))) {
code = ROUNDROBIN_PARENT;
} else if ((p = getFirstUpParent(request))) {
code = FIRSTUP_PARENT;
} else if ((p = getDefaultParent(request))) {
code = DEFAULT_PARENT;
}
if (code != HIER_NONE) {
peerAddFwdServer(ps, p, code);
}
}
Instead of peerGetSomeNeighbor :
/**
* peerGetSomeNeighbor
*
* Selects a neighbor (parent or sibling) based on one of the
* following methods:
* Cache Digests
* CARP
* ICMP Netdb RTT estimates
* ICP/HTCP queries
*/
static void
peerGetSomeNeighbor(ps_state * ps)
{
StoreEntry *entry = ps->entry;
HttpRequest *request = ps->request;
CachePeer *p;
hier_code code = HIER_NONE;
assert(entry->ping_status == PING_NONE);
if (ps->direct == DIRECT_YES) {
entry->ping_status = PING_DONE;
return;
}
#if USE_CACHE_DIGESTS
if ((p = neighborsDigestSelect(request))) {
if (neighborType(p, request->url) == PEER_PARENT)
code = CD_PARENT_HIT;
else
code = CD_SIBLING_HIT;
} else
#endif
if ((p = netdbClosestParent(request))) {
code = CLOSEST_PARENT;
} else if (peerSelectIcpPing(request, ps->direct, entry)) {
debugs(44, 3, "peerSelect: Doing ICP pings");
ps->ping.start = current_time;
ps->ping.n_sent = neighborsUdpPing(request,
entry,
peerHandlePingReply,
ps,
&ps->ping.n_replies_expected,
&ps->ping.timeout);
if (ps->ping.n_sent == 0)
debugs(44, DBG_CRITICAL, "WARNING: neighborsUdpPing returned
0");
debugs(44, 3, "peerSelect: " << ps->ping.n_replies_expected <<
" ICP replies expected, RTT " << ps->ping.timeout <<
" msec");
if (ps->ping.n_replies_expected > 0) {
entry->ping_status = PING_WAITING;
eventAdd("peerPingTimeout",
peerPingTimeout,
ps,
0.001 * ps->ping.timeout,
0);
return;
}
}
if (code != HIER_NONE) {
assert(p);
peerAddFwdServer(ps, p, code);
}
entry->ping_status = PING_DONE;
}
These functions are called from peerSelectFoo :
static void
peerSelectFoo(ps_state * ps)
{
if (!cbdataReferenceValid(ps->callback_data)) {
debugs(44, 3, "Aborting peer selection. Parent Job went away.");
delete ps;
return;
}
StoreEntry *entry = ps->entry;
HttpRequest *request = ps->request;
debugs(44, 3, request->method << ' ' << request->url.host());
/** If we don't know whether DIRECT is permitted ... */
if (ps->direct == DIRECT_UNKNOWN) {
if (ps->always_direct == ACCESS_DUNNO) {
debugs(44, 3, "peerSelectFoo: direct = " << DirectStr[ps->direct]
<< " (always_direct to be checked)");
/** check always_direct; */
ACLFilledChecklist *ch = new
ACLFilledChecklist(Config.accessList.AlwaysDirect, request, NULL);
ch->al = ps->al;
ps->acl_checklist = ch;
ps->acl_checklist->nonBlockingCheck(peerCheckAlwaysDirectDone, ps);
return;
} else if (ps->never_direct == ACCESS_DUNNO) {
debugs(44, 3, "peerSelectFoo: direct = " << DirectStr[ps->direct]
<< " (never_direct to be checked)");
/** check never_direct; */
ACLFilledChecklist *ch = new
ACLFilledChecklist(Config.accessList.NeverDirect, request, NULL);
ch->al = ps->al;
ps->acl_checklist = ch;
ps->acl_checklist->nonBlockingCheck(peerCheckNeverDirectDone, ps);
return;
} else if (request->flags.noDirect) {
/** if we are accelerating, direct is not an option. */
ps->direct = DIRECT_NO;
debugs(44, 3, "peerSelectFoo: direct = " << DirectStr[ps->direct]
<< " (forced non-direct)");
} else if (request->flags.loopDetected) {
/** if we are in a forwarding-loop, direct is not an option. */
ps->direct = DIRECT_YES;
debugs(44, 3, "peerSelectFoo: direct = " << DirectStr[ps->direct]
<< " (forwarding loop detected)");
} else if (peerCheckNetdbDirect(ps)) {
ps->direct = DIRECT_YES;
debugs(44, 3, "peerSelectFoo: direct = " << DirectStr[ps->direct]
<< " (checkNetdbDirect)");
} else {
ps->direct = DIRECT_MAYBE;
debugs(44, 3, "peerSelectFoo: direct = " << DirectStr[ps->direct]
<< " (default)");
}
debugs(44, 3, "peerSelectFoo: direct = " << DirectStr[ps->direct]);
}
if (!entry || entry->ping_status == PING_NONE)
peerSelectPinned(ps);
if (entry == NULL) {
(void) 0;
} else if (entry->ping_status == PING_NONE) {
peerGetSomeNeighbor(ps);
if (entry->ping_status == PING_WAITING)
return;
} else if (entry->ping_status == PING_WAITING) {
peerGetSomeNeighborReplies(ps);
entry->ping_status = PING_DONE;
}
switch (ps->direct) {
case DIRECT_YES:
peerGetSomeDirect(ps);
break;
case DIRECT_NO:
peerGetSomeParent(ps);
peerGetAllParents(ps);
break;
default:
if (Config.onoff.prefer_direct)
peerGetSomeDirect(ps);
if (request->flags.hierarchical ||
!Config.onoff.nonhierarchical_direct) {
peerGetSomeParent(ps);
peerGetAllParents(ps);
}
if (!Config.onoff.prefer_direct)
peerGetSomeDirect(ps);
break;
}
// resolve the possible peers
peerSelectDnsPaths(ps);
}
entry is null so peerGetSomeNeighbor is never called :
if (entry == NULL) {
(void) 0;
} else if (entry->ping_status == PING_NONE) {
peerGetSomeNeighbor(ps);
if (entry->ping_status == PING_WAITING)
return;
} else if (entry->ping_status == PING_WAITING) {
peerGetSomeNeighborReplies(ps);
entry->ping_status = PING_DONE;
}
Because of tunnelStart method :
void
tunnelStart(ClientHttpRequest * http)
{
debugs(26, 3, HERE);
/* Create state structure. */
TunnelStateData *tunnelState = NULL;
ErrorState *err = NULL;
HttpRequest *request = http->request;
char *url = http->uri;
/*
* client_addr.isNoAddr() indicates this is an "internal" request
* from peer_digest.c, asn.c, netdb.c, etc and should always
* be allowed. yuck, I know.
*/
if (Config.accessList.miss && !request->client_addr.isNoAddr()) {
/*
* Check if this host is allowed to fetch MISSES from us (miss_access)
* default is to allow.
*/
ACLFilledChecklist ch(Config.accessList.miss, request, NULL);
ch.al = http->al;
ch.src_addr = request->client_addr;
ch.my_addr = request->my_addr;
ch.syncAle(request, http->log_uri);
if (ch.fastCheck().denied()) {
debugs(26, 4, HERE << "MISS access forbidden.");
err = new ErrorState(ERR_FORWARDING_DENIED, Http::scForbidden,
request);
http->al->http.code = Http::scForbidden;
errorSend(http->getConn()->clientConnection, err);
return;
}
}
debugs(26, 3, request->method << ' ' << url << ' ' << request->http_ver);
++statCounter.server.all.requests;
++statCounter.server.other.requests;
tunnelState = new TunnelStateData(http);
#if USE_DELAY_POOLS
//server.setDelayId called from tunnelConnectDone after server side
connection established
#endif
peerSelect(&(tunnelState->serverDestinations), request, http->al,
NULL,
tunnelPeerSelectComplete,
tunnelState);
}
Any ideas ?
Regards,
Théo BARRAGUÉ
_______________________________________________
squid-users mailing list
squid-users@lists.squid-cache.org
http://lists.squid-cache.org/listinfo/squid-users
