Search squid archive

Re: Use ICP RTT with HTTPS request

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 

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@xxxxxxxxxxxxxxxxxxxxx
http://lists.squid-cache.org/listinfo/squid-users
[Index of Archives]     [Linux Audio Users]     [Samba]     [Big List of Linux Books]     [Linux USB]     [Yosemite News]

  Powered by Linux