diff --git a/netwerk/base/src/nsSocketTransport2.cpp b/netwerk/base/src/nsSocketTransport2.cpp index 7e37bbbd726..bfa2e9e2494 100644 --- a/netwerk/base/src/nsSocketTransport2.cpp +++ b/netwerk/base/src/nsSocketTransport2.cpp @@ -972,7 +972,10 @@ nsSocketTransport::SendStatus(nsresult status) nsresult nsSocketTransport::ResolveHost() { - SOCKET_LOG(("nsSocketTransport::ResolveHost [this=%p]\n", this)); + SOCKET_LOG(("nsSocketTransport::ResolveHost [this=%p %s:%d%s]\n", + this, SocketHost().get(), SocketPort(), + mConnectionFlags & nsSocketTransport::BYPASS_CACHE ? + " bypass cache" : "")); nsresult rv; diff --git a/netwerk/dns/nsHostResolver.cpp b/netwerk/dns/nsHostResolver.cpp index a104e150451..0921c7996e9 100644 --- a/netwerk/dns/nsHostResolver.cpp +++ b/netwerk/dns/nsHostResolver.cpp @@ -517,7 +517,8 @@ nsHostResolver::ResolveHost(const char *host, { NS_ENSURE_TRUE(host && *host, NS_ERROR_UNEXPECTED); - LOG(("Resolving host [%s].\n", host)); + LOG(("Resolving host [%s]%s.\n", + host, flags & RES_BYPASS_CACHE ? " - bypassing cache" : "")); // ensure that we are working with a valid hostname before proceeding. see // bug 304904 for details. @@ -552,13 +553,15 @@ nsHostResolver::ResolveHost(const char *host, (PL_DHashTableOperate(&mDB, &key, PL_DHASH_ADD)); // if the record is null, then HostDB_InitEntry failed. - if (!he || !he->rec) + if (!he || !he->rec) { + LOG((" Out of memory: no cache entry for [%s].\n", host)); rv = NS_ERROR_OUT_OF_MEMORY; + } // do we have a cached result that we can reuse? else if (!(flags & RES_BYPASS_CACHE) && he->rec->HasUsableResult(flags) && TimeStamp::NowLoRes() <= (he->rec->expiration + TimeDuration::FromSeconds(mGracePeriod * 60))) { - LOG(("Using cached record for host [%s].\n", host)); + LOG((" Using cached record for host [%s].\n", host)); // put reference to host record on stack... result = he->rec; Telemetry::Accumulate(Telemetry::DNS_LOOKUP_METHOD2, METHOD_HIT); @@ -569,6 +572,7 @@ nsHostResolver::ResolveHost(const char *host, ConditionallyRefreshRecord(he->rec, host); if (he->rec->negative) { + LOG((" Negative cache entry for[%s].\n", host)); Telemetry::Accumulate(Telemetry::DNS_LOOKUP_METHOD2, METHOD_NEGATIVE_HIT); status = NS_ERROR_UNKNOWN_HOST; @@ -577,6 +581,7 @@ nsHostResolver::ResolveHost(const char *host, // if the host name is an IP address literal and has been parsed, // go ahead and use it. else if (he->rec->addr) { + LOG((" Using cached address for IP Literal [%s].\n", host)); Telemetry::Accumulate(Telemetry::DNS_LOOKUP_METHOD2, METHOD_LITERAL); result = he->rec; @@ -585,6 +590,7 @@ nsHostResolver::ResolveHost(const char *host, // circuit full host resolution. (this is necessary on some // platforms like Win9x. see bug 219376 for more details.) else if (PR_StringToNetAddr(host, &tempAddr) == PR_SUCCESS) { + LOG((" Host is IP Literal [%s].\n", host)); // ok, just copy the result into the host record, and be done // with it! ;-) he->rec->addr = new NetAddr(); @@ -597,12 +603,16 @@ nsHostResolver::ResolveHost(const char *host, else if (mPendingCount >= MAX_NON_PRIORITY_REQUESTS && !IsHighPriority(flags) && !he->rec->resolving) { + LOG((" Lookup queue full: dropping %s priority request for " + "[%s].\n", + IsMediumPriority(flags) ? "medium" : "low", host)); Telemetry::Accumulate(Telemetry::DNS_LOOKUP_METHOD2, METHOD_OVERFLOW); // This is a lower priority request and we are swamped, so refuse it. rv = NS_ERROR_DNS_LOOKUP_QUEUE_FULL; } else if (flags & RES_OFFLINE) { + LOG((" Offline request for [%s]; ignoring.\n", host)); rv = NS_ERROR_OFFLINE; } @@ -624,9 +634,8 @@ nsHostResolver::ResolveHost(const char *host, unspecHe->rec->HasUsableResult(flags) && TimeStamp::NowLoRes() <= (he->rec->expiration + TimeDuration::FromSeconds(mGracePeriod * 60))) { - LOG(("Specific DNS request (%s) for an unspecified " - "cached record", - (af == PR_AF_INET) ? "AF_INET" : "AF_INET6")); + LOG((" Trying AF_UNSPEC entry for [%s] af: %s.\n", + host, (af == PR_AF_INET) ? "AF_INET" : "AF_INET6")); // Search for any valid address in the AF_UNSPEC entry // in the cache (not blacklisted and from the right @@ -658,6 +667,8 @@ nsHostResolver::ResolveHost(const char *host, // AF_UNSPEC addresses, so we mark this record as // negative. else if (af == PR_AF_INET6) { + LOG((" No AF_INET6 in AF_UNSPEC entry: " + "[%s] unknown host", host)); result = he->rec; he->rec->negative = true; status = NS_ERROR_UNKNOWN_HOST; @@ -669,25 +680,26 @@ nsHostResolver::ResolveHost(const char *host, // If no valid address was found in the cache or this is an // AF_UNSPEC request, then start a new lookup. if (!result) { - LOG(("No valid address was found in the cache for the " - "requested IP family")); + LOG((" No usable address in cache for [%s]", host)); // Add callback to the list of pending callbacks. PR_APPEND_LINK(callback, &he->rec->callbacks); he->rec->flags = flags; - IssueLookup(he->rec); + rv = IssueLookup(he->rec); Telemetry::Accumulate(Telemetry::DNS_LOOKUP_METHOD2, METHOD_NETWORK_FIRST); if (NS_FAILED(rv)) { PR_REMOVE_AND_INIT_LINK(callback); } else { - LOG(("DNS lookup for host [%s] blocking pending " - "'getaddrinfo' query.", host)); + LOG((" DNS lookup for host [%s] blocking pending " + "'getaddrinfo' query: callback [%p]", + host, callback)); } } } else { - // The record is being resolved. Append our callback. + LOG((" Host [%s] is being resolved. Appending callback [%p].", + host, callback)); PR_APPEND_LINK(callback, &he->rec->callbacks); if (he->rec->onQueue) { Telemetry::Accumulate(Telemetry::DNS_LOOKUP_METHOD2, @@ -782,7 +794,7 @@ nsHostResolver::ConditionallyCreateThread(nsHostRecord *rec) } #if defined(PR_LOGGING) else - LOG(("Unable to find a thread for looking up host [%s].\n", rec->host)); + LOG((" Unable to find a thread for looking up host [%s].\n", rec->host)); #endif return NS_OK; } @@ -818,7 +830,7 @@ nsHostResolver::IssueLookup(nsHostRecord *rec) rv = ConditionallyCreateThread(rec); - LOG (("DNS thread counters: total=%d any-live=%d idle=%d pending=%d\n", + LOG ((" DNS thread counters: total=%d any-live=%d idle=%d pending=%d\n", mThreadCount, mActiveAnyThreadCount, mNumIdleThreads, @@ -833,7 +845,7 @@ nsHostResolver::ConditionallyRefreshRecord(nsHostRecord *rec, const char *host) if ((((TimeStamp::NowLoRes() > rec->expiration) && rec->mBlacklistedItems.Length()) || rec->negative) && !rec->resolving) { - LOG(("Using %s cache entry for host [%s] but starting async renewal.", + LOG((" Using %s cache entry for host [%s] but starting async renewal.", rec->negative ? "negative" :"positive", host)); IssueLookup(rec); @@ -1053,7 +1065,7 @@ nsHostResolver::CancelAsyncRequest(const char *host, void nsHostResolver::ThreadFunc(void *arg) { - LOG(("DNS lookup thread starting execution.\n")); + LOG(("DNS lookup thread - starting execution.\n")); static nsThreadPoolNaming naming; naming.SetThreadPoolName(NS_LITERAL_CSTRING("DNS Resolver")); @@ -1065,7 +1077,8 @@ nsHostResolver::ThreadFunc(void *arg) nsHostRecord *rec; PRAddrInfo *prai = nullptr; while (resolver->GetHostToLookup(&rec)) { - LOG(("Calling getaddrinfo for host [%s].\n", rec->host)); + LOG(("DNS lookup thread - Calling getaddrinfo for host [%s].\n", + rec->host)); int flags = PR_AI_ADDRCONFIG; if (!(rec->flags & RES_CANON_NAME)) @@ -1115,11 +1128,12 @@ nsHostResolver::ThreadFunc(void *arg) } // OnLookupComplete may release "rec", log before we lose it. - LOG(("Lookup completed for host [%s].\n", rec->host)); + LOG(("DNS lookup thread - lookup completed for host [%s]: %s.\n", + rec->host, ai ? "success" : "failure: unknown host")); resolver->OnLookupComplete(rec, status, ai); } NS_RELEASE(resolver); - LOG(("DNS lookup thread ending execution.\n")); + LOG(("DNS lookup thread - queue empty, thread finished.\n")); } nsresult diff --git a/netwerk/protocol/http/nsHttpChannel.cpp b/netwerk/protocol/http/nsHttpChannel.cpp index 37d1ab7a690..6cd213f173e 100644 --- a/netwerk/protocol/http/nsHttpChannel.cpp +++ b/netwerk/protocol/http/nsHttpChannel.cpp @@ -4526,6 +4526,7 @@ nsHttpChannel::BeginConnect() // be correct, and even when it isn't, the timing still represents _a_ // valid DNS lookup timing for the site, even if it is not _the_ // timing we used. + LOG(("nsHttpChannel::BeginConnect [this=%p] prefetching\n", this)); mDNSPrefetch = new nsDNSPrefetch(mURI, mTimingEnabled); mDNSPrefetch->PrefetchHigh(); }