From 52ae80c40de68f97f535d718fbbc086d5698c870 Mon Sep 17 00:00:00 2001 From: "eroman@chromium.org" Date: Thu, 10 Sep 2009 21:27:00 +0000 Subject: Add trace points for the "dnsResolve()" and "myIpAddress()" PAC javascript bindings. This makes note of the calls in the request's LoadLog. Since the LoadLog is not thread-safe, SingleThreadedProxyResolver creates a private LoadLog for ProxyResolverV8 to write into, and then copies it into the mainLoadLog on completion (on the origin thread). BUG=http://crbug.com/14478 Review URL: http://codereview.chromium.org/193037 git-svn-id: svn://svn.chromium.org/chrome/trunk/src@25926 0039d316-1c4b-4281-b951-d872f2087c98 --- net/proxy/init_proxy_resolver_unittest.cc | 3 +- net/proxy/mock_proxy_resolver.h | 3 +- net/proxy/proxy_resolver.h | 4 +- net/proxy/proxy_resolver_mac.cc | 3 +- net/proxy/proxy_resolver_mac.h | 3 +- net/proxy/proxy_resolver_perftest.cc | 4 +- net/proxy/proxy_resolver_v8.cc | 30 +++- net/proxy/proxy_resolver_v8.h | 3 +- net/proxy/proxy_resolver_v8_unittest.cc | 171 +++++++++++++-------- net/proxy/proxy_resolver_winhttp.cc | 3 +- net/proxy/proxy_resolver_winhttp.h | 3 +- net/proxy/proxy_service.cc | 8 +- net/proxy/single_threaded_proxy_resolver.cc | 27 +++- net/proxy/single_threaded_proxy_resolver.h | 3 +- .../single_threaded_proxy_resolver_unittest.cc | 43 ++++-- 15 files changed, 205 insertions(+), 106 deletions(-) (limited to 'net/proxy') diff --git a/net/proxy/init_proxy_resolver_unittest.cc b/net/proxy/init_proxy_resolver_unittest.cc index b179ad1..e9d05a2 100644 --- a/net/proxy/init_proxy_resolver_unittest.cc +++ b/net/proxy/init_proxy_resolver_unittest.cc @@ -118,7 +118,8 @@ class RuleBasedProxyResolver : public ProxyResolver { virtual int GetProxyForURL(const GURL& /*url*/, ProxyInfo* /*results*/, CompletionCallback* /*callback*/, - RequestHandle* /*request_handle*/) { + RequestHandle* /*request_handle*/, + LoadLog* /*load_log*/) { NOTREACHED(); return ERR_UNEXPECTED; } diff --git a/net/proxy/mock_proxy_resolver.h b/net/proxy/mock_proxy_resolver.h index 47a557c..4c56124 100644 --- a/net/proxy/mock_proxy_resolver.h +++ b/net/proxy/mock_proxy_resolver.h @@ -92,7 +92,8 @@ class MockAsyncProxyResolverBase : public ProxyResolver { virtual int GetProxyForURL(const GURL& url, ProxyInfo* results, CompletionCallback* callback, - RequestHandle* request_handle) { + RequestHandle* request_handle, + LoadLog* /*load_log*/) { scoped_refptr request = new Request(this, url, results, callback); pending_requests_.push_back(request); diff --git a/net/proxy/proxy_resolver.h b/net/proxy/proxy_resolver.h index 89fffb1..3811be8 100644 --- a/net/proxy/proxy_resolver.h +++ b/net/proxy/proxy_resolver.h @@ -13,6 +13,7 @@ namespace net { +class LoadLog; class ProxyInfo; // Interface for "proxy resolvers". A ProxyResolver fills in a list of proxies @@ -39,7 +40,8 @@ class ProxyResolver { virtual int GetProxyForURL(const GURL& url, ProxyInfo* results, CompletionCallback* callback, - RequestHandle* request) = 0; + RequestHandle* request, + LoadLog* load_log) = 0; // Cancels |request|. virtual void CancelRequest(RequestHandle request) = 0; diff --git a/net/proxy/proxy_resolver_mac.cc b/net/proxy/proxy_resolver_mac.cc index b41e402..a57f840 100644 --- a/net/proxy/proxy_resolver_mac.cc +++ b/net/proxy/proxy_resolver_mac.cc @@ -245,7 +245,8 @@ int ProxyConfigServiceMac::GetProxyConfig(ProxyConfig* config) { int ProxyResolverMac::GetProxyForURL(const GURL& query_url, ProxyInfo* results, CompletionCallback* /*callback*/, - RequestHandle* /*request*/) { + RequestHandle* /*request*/, + LoadLog* load_log) { scoped_cftyperef query_ref( base::SysUTF8ToCFStringRef(query_url.spec())); scoped_cftyperef query_url_ref( diff --git a/net/proxy/proxy_resolver_mac.h b/net/proxy/proxy_resolver_mac.h index 6bad1d2..b96795a 100644 --- a/net/proxy/proxy_resolver_mac.h +++ b/net/proxy/proxy_resolver_mac.h @@ -24,7 +24,8 @@ class ProxyResolverMac : public ProxyResolver { virtual int GetProxyForURL(const GURL& url, ProxyInfo* results, CompletionCallback* callback, - RequestHandle* request); + RequestHandle* request, + LoadLog* load_log); virtual void CancelRequest(RequestHandle request) { NOTREACHED(); diff --git a/net/proxy/proxy_resolver_perftest.cc b/net/proxy/proxy_resolver_perftest.cc index efaf437..6e336e9 100644 --- a/net/proxy/proxy_resolver_perftest.cc +++ b/net/proxy/proxy_resolver_perftest.cc @@ -109,7 +109,7 @@ class PacPerfSuiteRunner { { net::ProxyInfo proxy_info; int result = resolver_->GetProxyForURL( - GURL("http://www.warmup.com"), &proxy_info, NULL, NULL); + GURL("http://www.warmup.com"), &proxy_info, NULL, NULL, NULL); ASSERT_EQ(net::OK, result); } @@ -124,7 +124,7 @@ class PacPerfSuiteRunner { // Resolve. net::ProxyInfo proxy_info; int result = resolver_->GetProxyForURL(GURL(query.query_url), - &proxy_info, NULL, NULL); + &proxy_info, NULL, NULL, NULL); // Check that the result was correct. Note that ToPacString() and // ASSERT_EQ() are fast, so they won't skew the results. diff --git a/net/proxy/proxy_resolver_v8.cc b/net/proxy/proxy_resolver_v8.cc index 8c40ecf..cb5eab1 100644 --- a/net/proxy/proxy_resolver_v8.cc +++ b/net/proxy/proxy_resolver_v8.cc @@ -7,6 +7,7 @@ #include "base/logging.h" #include "base/string_util.h" #include "googleurl/src/gurl.h" +#include "net/base/load_log.h" #include "net/base/net_errors.h" #include "net/proxy/proxy_info.h" #include "net/proxy/proxy_resolver_js_bindings.h" @@ -54,7 +55,7 @@ bool V8ObjectToString(v8::Handle object, std::string* result) { class ProxyResolverV8::Context { public: explicit Context(ProxyResolverJSBindings* js_bindings) - : js_bindings_(js_bindings) { + : js_bindings_(js_bindings), current_request_load_log_(NULL) { DCHECK(js_bindings != NULL); } @@ -156,6 +157,10 @@ class ProxyResolverV8::Context { return OK; } + void SetCurrentRequestLoadLog(LoadLog* load_log) { + current_request_load_log_ = load_log; + } + private: bool GetFindProxyForURL(v8::Local* function) { *function = v8_context_->Global()->Get(v8::String::New("FindProxyForURL")); @@ -198,9 +203,16 @@ class ProxyResolverV8::Context { Context* context = static_cast(v8::External::Cast(*args.Data())->Value()); + LoadLog::BeginEvent(context->current_request_load_log_, + LoadLog::TYPE_PROXY_RESOLVER_V8_MY_IP_ADDRESS); + // We shouldn't be called with any arguments, but will not complain if // we are. std::string result = context->js_bindings_->MyIpAddress(); + + LoadLog::EndEvent(context->current_request_load_log_, + LoadLog::TYPE_PROXY_RESOLVER_V8_MY_IP_ADDRESS); + if (result.empty()) result = "127.0.0.1"; return StdStringToV8String(result); @@ -220,13 +232,20 @@ class ProxyResolverV8::Context { return v8::Undefined(); } + LoadLog::BeginEvent(context->current_request_load_log_, + LoadLog::TYPE_PROXY_RESOLVER_V8_DNS_RESOLVE); + std::string result = context->js_bindings_->DnsResolve(host); + LoadLog::EndEvent(context->current_request_load_log_, + LoadLog::TYPE_PROXY_RESOLVER_V8_DNS_RESOLVE); + // DoDnsResolve() returns empty string on failure. return result.empty() ? v8::Null() : StdStringToV8String(result); } ProxyResolverJSBindings* js_bindings_; + LoadLog* current_request_load_log_; v8::Persistent v8_this_; v8::Persistent v8_context_; }; @@ -244,14 +263,19 @@ ProxyResolverV8::~ProxyResolverV8() {} int ProxyResolverV8::GetProxyForURL(const GURL& query_url, ProxyInfo* results, CompletionCallback* /*callback*/, - RequestHandle* /*request*/) { + RequestHandle* /*request*/, + LoadLog* load_log) { // If the V8 instance has not been initialized (either because // SetPacScript() wasn't called yet, or because it failed. if (!context_.get()) return ERR_FAILED; // Otherwise call into V8. - return context_->ResolveProxy(query_url, results); + context_->SetCurrentRequestLoadLog(load_log); + int rv = context_->ResolveProxy(query_url, results); + context_->SetCurrentRequestLoadLog(NULL); + + return rv; } void ProxyResolverV8::CancelRequest(RequestHandle request) { diff --git a/net/proxy/proxy_resolver_v8.h b/net/proxy/proxy_resolver_v8.h index f746ecb..3f024f2 100644 --- a/net/proxy/proxy_resolver_v8.h +++ b/net/proxy/proxy_resolver_v8.h @@ -48,7 +48,8 @@ class ProxyResolverV8 : public ProxyResolver { virtual int GetProxyForURL(const GURL& url, ProxyInfo* results, CompletionCallback* /*callback*/, - RequestHandle* /*request*/); + RequestHandle* /*request*/, + LoadLog* load_log); virtual void CancelRequest(RequestHandle request); ProxyResolverJSBindings* js_bindings() const { return js_bindings_.get(); } diff --git a/net/proxy/proxy_resolver_v8_unittest.cc b/net/proxy/proxy_resolver_v8_unittest.cc index 1aecb12..45e0459 100644 --- a/net/proxy/proxy_resolver_v8_unittest.cc +++ b/net/proxy/proxy_resolver_v8_unittest.cc @@ -6,18 +6,20 @@ #include "base/string_util.h" #include "base/path_service.h" #include "googleurl/src/gurl.h" +#include "net/base/load_log_unittest.h" #include "net/base/net_errors.h" #include "net/proxy/proxy_info.h" #include "net/proxy/proxy_resolver_js_bindings.h" #include "net/proxy/proxy_resolver_v8.h" #include "testing/gtest/include/gtest/gtest.h" +namespace net { namespace { // Javascript bindings for ProxyResolverV8, which returns mock values. // Each time one of the bindings is called into, we push the input into a // list, for later verification. -class MockJSBindings : public net::ProxyResolverJSBindings { +class MockJSBindings : public ProxyResolverJSBindings { public: MockJSBindings() : my_ip_address_count(0) {} @@ -59,7 +61,7 @@ class MockJSBindings : public net::ProxyResolverJSBindings { // This is the same as ProxyResolverV8, but it uses mock bindings in place of // the default bindings, and has a helper function to load PAC scripts from // disk. -class ProxyResolverV8WithMockBindings : public net::ProxyResolverV8 { +class ProxyResolverV8WithMockBindings : public ProxyResolverV8 { public: ProxyResolverV8WithMockBindings() : ProxyResolverV8(new MockJSBindings()) {} @@ -83,7 +85,7 @@ class ProxyResolverV8WithMockBindings : public net::ProxyResolverV8 { // If we can't load the file from disk, something is misconfigured. if (!ok) { LOG(ERROR) << "Failed to read file: " << path.value(); - return net::ERR_UNEXPECTED; + return ERR_UNEXPECTED; } // Load the PAC script into the ProxyResolver. @@ -95,32 +97,35 @@ class ProxyResolverV8WithMockBindings : public net::ProxyResolverV8 { const GURL kQueryUrl("http://www.google.com"); const GURL kPacUrl; -} TEST(ProxyResolverV8Test, Direct) { ProxyResolverV8WithMockBindings resolver; int result = resolver.SetPacScriptFromDisk("direct.js"); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); - net::ProxyInfo proxy_info; - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); + ProxyInfo proxy_info; + scoped_refptr log(new LoadLog); + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, log); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); EXPECT_TRUE(proxy_info.is_direct()); EXPECT_EQ(0U, resolver.mock_js_bindings()->alerts.size()); EXPECT_EQ(0U, resolver.mock_js_bindings()->errors.size()); + + // No bindings were called, so no log entries. + EXPECT_EQ(0u, log->events().size()); } TEST(ProxyResolverV8Test, ReturnEmptyString) { ProxyResolverV8WithMockBindings resolver; int result = resolver.SetPacScriptFromDisk("return_empty_string.js"); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); - net::ProxyInfo proxy_info; - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); + ProxyInfo proxy_info; + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); EXPECT_TRUE(proxy_info.is_direct()); EXPECT_EQ(0U, resolver.mock_js_bindings()->alerts.size()); @@ -130,24 +135,24 @@ TEST(ProxyResolverV8Test, ReturnEmptyString) { TEST(ProxyResolverV8Test, Basic) { ProxyResolverV8WithMockBindings resolver; int result = resolver.SetPacScriptFromDisk("passthrough.js"); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); // The "FindProxyForURL" of this PAC script simply concatenates all of the // arguments into a pseudo-host. The purpose of this test is to verify that // the correct arguments are being passed to FindProxyForURL(). { - net::ProxyInfo proxy_info; + ProxyInfo proxy_info; result = resolver.GetProxyForURL(GURL("http://query.com/path"), - &proxy_info, NULL, NULL); - EXPECT_EQ(net::OK, result); + &proxy_info, NULL, NULL, NULL); + EXPECT_EQ(OK, result); EXPECT_EQ("http.query.com.path.query.com:80", proxy_info.proxy_server().ToURI()); } { - net::ProxyInfo proxy_info; + ProxyInfo proxy_info; int result = resolver.GetProxyForURL(GURL("ftp://query.com:90/path"), - &proxy_info, NULL, NULL); - EXPECT_EQ(net::OK, result); + &proxy_info, NULL, NULL, NULL); + EXPECT_EQ(OK, result); // Note that FindProxyForURL(url, host) does not expect |host| to contain // the port number. EXPECT_EQ("ftp.query.com.90.path.query.com:80", @@ -174,12 +179,12 @@ TEST(ProxyResolverV8Test, BadReturnType) { for (size_t i = 0; i < arraysize(filenames); ++i) { ProxyResolverV8WithMockBindings resolver; int result = resolver.SetPacScriptFromDisk(filenames[i]); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); - net::ProxyInfo proxy_info; - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); + ProxyInfo proxy_info; + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); - EXPECT_EQ(net::ERR_PAC_SCRIPT_FAILED, result); + EXPECT_EQ(ERR_PAC_SCRIPT_FAILED, result); MockJSBindings* bindings = resolver.mock_js_bindings(); EXPECT_EQ(0U, bindings->alerts.size()); @@ -194,24 +199,24 @@ TEST(ProxyResolverV8Test, BadReturnType) { TEST(ProxyResolverV8Test, NoEntryPoint) { ProxyResolverV8WithMockBindings resolver; int result = resolver.SetPacScriptFromDisk("no_entrypoint.js"); - EXPECT_EQ(net::ERR_PAC_SCRIPT_FAILED, result); + EXPECT_EQ(ERR_PAC_SCRIPT_FAILED, result); - net::ProxyInfo proxy_info; - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); + ProxyInfo proxy_info; + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); - EXPECT_EQ(net::ERR_FAILED, result); + EXPECT_EQ(ERR_FAILED, result); } // Try loading a malformed PAC script. TEST(ProxyResolverV8Test, ParseError) { ProxyResolverV8WithMockBindings resolver; int result = resolver.SetPacScriptFromDisk("missing_close_brace.js"); - EXPECT_EQ(net::ERR_PAC_SCRIPT_FAILED, result); + EXPECT_EQ(ERR_PAC_SCRIPT_FAILED, result); - net::ProxyInfo proxy_info; - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); + ProxyInfo proxy_info; + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); - EXPECT_EQ(net::ERR_FAILED, result); + EXPECT_EQ(ERR_FAILED, result); MockJSBindings* bindings = resolver.mock_js_bindings(); EXPECT_EQ(0U, bindings->alerts.size()); @@ -231,9 +236,9 @@ TEST(ProxyResolverV8Test, SideEffects) { // The PAC script increments a counter each time we invoke it. for (int i = 0; i < 3; ++i) { - net::ProxyInfo proxy_info; - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); - EXPECT_EQ(net::OK, result); + ProxyInfo proxy_info; + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); + EXPECT_EQ(OK, result); EXPECT_EQ(StringPrintf("sideffect_%d:80", i), proxy_info.proxy_server().ToURI()); } @@ -241,12 +246,12 @@ TEST(ProxyResolverV8Test, SideEffects) { // Reload the script -- the javascript environment should be reset, hence // the counter starts over. result = resolver.SetPacScriptFromDisk("side_effects.js"); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); for (int i = 0; i < 3; ++i) { - net::ProxyInfo proxy_info; - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); - EXPECT_EQ(net::OK, result); + ProxyInfo proxy_info; + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); + EXPECT_EQ(OK, result); EXPECT_EQ(StringPrintf("sideffect_%d:80", i), proxy_info.proxy_server().ToURI()); } @@ -256,12 +261,12 @@ TEST(ProxyResolverV8Test, SideEffects) { TEST(ProxyResolverV8Test, UnhandledException) { ProxyResolverV8WithMockBindings resolver; int result = resolver.SetPacScriptFromDisk("unhandled_exception.js"); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); - net::ProxyInfo proxy_info; - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); + ProxyInfo proxy_info; + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); - EXPECT_EQ(net::ERR_PAC_SCRIPT_FAILED, result); + EXPECT_EQ(ERR_PAC_SCRIPT_FAILED, result); MockJSBindings* bindings = resolver.mock_js_bindings(); EXPECT_EQ(0U, bindings->alerts.size()); @@ -276,28 +281,28 @@ TEST(ProxyResolverV8Test, UnhandledException) { TEST(ProxyResolverV8Test, DISABLED_ReturnUnicode) { ProxyResolverV8WithMockBindings resolver; int result = resolver.SetPacScriptFromDisk("return_unicode.js"); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); - net::ProxyInfo proxy_info; - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); + ProxyInfo proxy_info; + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); // The result from this resolve was unparseable, because it // wasn't ascii. - EXPECT_EQ(net::ERR_PAC_SCRIPT_FAILED, result); + EXPECT_EQ(ERR_PAC_SCRIPT_FAILED, result); } // Test the PAC library functions that we expose in the JS environmnet. TEST(ProxyResolverV8Test, JavascriptLibrary) { ProxyResolverV8WithMockBindings resolver; int result = resolver.SetPacScriptFromDisk("pac_library_unittest.js"); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); - net::ProxyInfo proxy_info; - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); + ProxyInfo proxy_info; + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); // If the javascript side of this unit-test fails, it will throw a javascript // exception. Otherwise it will return "PROXY success:80". - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); EXPECT_EQ("success:80", proxy_info.proxy_server().ToURI()); EXPECT_EQ(0U, resolver.mock_js_bindings()->alerts.size()); @@ -308,32 +313,32 @@ TEST(ProxyResolverV8Test, JavascriptLibrary) { TEST(ProxyResolverV8Test, NoSetPacScript) { ProxyResolverV8WithMockBindings resolver; - net::ProxyInfo proxy_info; + ProxyInfo proxy_info; // Resolve should fail, as we are not yet initialized with a script. - int result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); - EXPECT_EQ(net::ERR_FAILED, result); + int result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); + EXPECT_EQ(ERR_FAILED, result); // Initialize it. result = resolver.SetPacScriptFromDisk("direct.js"); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); // Resolve should now succeed. - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); - EXPECT_EQ(net::OK, result); + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); + EXPECT_EQ(OK, result); // Clear it, by initializing with an empty string. resolver.SetPacScriptByData(std::string(), NULL); // Resolve should fail again now. - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); - EXPECT_EQ(net::ERR_FAILED, result); + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); + EXPECT_EQ(ERR_FAILED, result); // Load a good script once more. result = resolver.SetPacScriptFromDisk("direct.js"); - EXPECT_EQ(net::OK, result); - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); + EXPECT_EQ(OK, result); EXPECT_EQ(0U, resolver.mock_js_bindings()->alerts.size()); EXPECT_EQ(0U, resolver.mock_js_bindings()->errors.size()); @@ -343,12 +348,12 @@ TEST(ProxyResolverV8Test, NoSetPacScript) { TEST(ProxyResolverV8Test, V8Bindings) { ProxyResolverV8WithMockBindings resolver; int result = resolver.SetPacScriptFromDisk("bindings.js"); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); - net::ProxyInfo proxy_info; - result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL); + ProxyInfo proxy_info; + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, NULL); - EXPECT_EQ(net::OK, result); + EXPECT_EQ(OK, result); EXPECT_TRUE(proxy_info.is_direct()); MockJSBindings* bindings = resolver.mock_js_bindings(); @@ -381,3 +386,39 @@ TEST(ProxyResolverV8Test, V8Bindings) { EXPECT_EQ(2, bindings->my_ip_address_count); } +// Test that calls to the myIpAddress() and dnsResolve() bindings get +// logged to the LoadLog parameter. +TEST(ProxyResolverV8Test, LoadLog) { + ProxyResolverV8WithMockBindings resolver; + int result = resolver.SetPacScriptFromDisk("simple.js"); + EXPECT_EQ(OK, result); + + ProxyInfo proxy_info; + scoped_refptr log(new LoadLog); + result = resolver.GetProxyForURL(kQueryUrl, &proxy_info, NULL, NULL, log); + + EXPECT_EQ(OK, result); + EXPECT_FALSE(proxy_info.is_direct()); + EXPECT_EQ("c:100", proxy_info.proxy_server().ToURI()); + + // Note that dnsResolve() was never called directly, but it appears + // in the LoadLog. This is because it gets called indirectly by + // isInNet() and isResolvable(). + + EXPECT_EQ(6u, log->events().size()); + ExpectLogContains(log, 0, LoadLog::TYPE_PROXY_RESOLVER_V8_MY_IP_ADDRESS, + LoadLog::PHASE_BEGIN); + ExpectLogContains(log, 1, LoadLog::TYPE_PROXY_RESOLVER_V8_MY_IP_ADDRESS, + LoadLog::PHASE_END); + ExpectLogContains(log, 2, LoadLog::TYPE_PROXY_RESOLVER_V8_DNS_RESOLVE, + LoadLog::PHASE_BEGIN); + ExpectLogContains(log, 3, LoadLog::TYPE_PROXY_RESOLVER_V8_DNS_RESOLVE, + LoadLog::PHASE_END); + ExpectLogContains(log, 4, LoadLog::TYPE_PROXY_RESOLVER_V8_DNS_RESOLVE, + LoadLog::PHASE_BEGIN); + ExpectLogContains(log, 5, LoadLog::TYPE_PROXY_RESOLVER_V8_DNS_RESOLVE, + LoadLog::PHASE_END); +} + +} // namespace +} // namespace net diff --git a/net/proxy/proxy_resolver_winhttp.cc b/net/proxy/proxy_resolver_winhttp.cc index 4c0848d..fd9efe3 100644 --- a/net/proxy/proxy_resolver_winhttp.cc +++ b/net/proxy/proxy_resolver_winhttp.cc @@ -55,7 +55,8 @@ ProxyResolverWinHttp::~ProxyResolverWinHttp() { int ProxyResolverWinHttp::GetProxyForURL(const GURL& query_url, ProxyInfo* results, CompletionCallback* /*callback*/, - RequestHandle* /*request*/) { + RequestHandle* /*request*/, + LoadLog* /*load_log*/) { // If we don't have a WinHTTP session, then create a new one. if (!session_handle_ && !OpenWinHttpSession()) return ERR_FAILED; diff --git a/net/proxy/proxy_resolver_winhttp.h b/net/proxy/proxy_resolver_winhttp.h index 1d9a7e8..ab1df0f1 100644 --- a/net/proxy/proxy_resolver_winhttp.h +++ b/net/proxy/proxy_resolver_winhttp.h @@ -25,7 +25,8 @@ class ProxyResolverWinHttp : public ProxyResolver { virtual int GetProxyForURL(const GURL& url, ProxyInfo* results, CompletionCallback* /*callback*/, - RequestHandle* /*request*/); + RequestHandle* /*request*/, + LoadLog* /*load_log*/); virtual void CancelRequest(RequestHandle request); private: diff --git a/net/proxy/proxy_service.cc b/net/proxy/proxy_service.cc index 46509c2..637fbbd 100644 --- a/net/proxy/proxy_service.cc +++ b/net/proxy/proxy_service.cc @@ -54,7 +54,8 @@ class ProxyResolverNull : public ProxyResolver { virtual int GetProxyForURL(const GURL& url, ProxyInfo* results, CompletionCallback* callback, - RequestHandle* request) { + RequestHandle* request, + LoadLog* load_log) { return ERR_NOT_IMPLEMENTED; } @@ -99,11 +100,8 @@ class ProxyService::PacRequest config_id_ = service_->config_.id(); - // TODO(eroman): ProxyResolver::GetProxyForURL should take LoadLog*. - // Then we can pass in |load_log_| and understand how much time is - // spent in bindings like dnsResolve()! return resolver()->GetProxyForURL( - url_, results_, &io_callback_, &resolve_job_/*, load_log_*/); + url_, results_, &io_callback_, &resolve_job_, load_log_); } bool is_started() const { diff --git a/net/proxy/single_threaded_proxy_resolver.cc b/net/proxy/single_threaded_proxy_resolver.cc index 02658a6..01c35fa 100644 --- a/net/proxy/single_threaded_proxy_resolver.cc +++ b/net/proxy/single_threaded_proxy_resolver.cc @@ -5,6 +5,7 @@ #include "net/proxy/single_threaded_proxy_resolver.h" #include "base/thread.h" +#include "net/base/load_log.h" #include "net/base/net_errors.h" #include "net/proxy/proxy_info.h" @@ -94,10 +95,12 @@ class SingleThreadedProxyResolver::Job Job(SingleThreadedProxyResolver* coordinator, const GURL& url, ProxyInfo* results, - CompletionCallback* callback) + CompletionCallback* callback, + LoadLog* load_log) : coordinator_(coordinator), callback_(callback), results_(results), + load_log_(load_log), url_(url), is_started_(false), origin_loop_(MessageLoop::current()) { @@ -130,14 +133,24 @@ class SingleThreadedProxyResolver::Job private: // Runs on the worker thread. void DoQuery(ProxyResolver* resolver) { - int rv = resolver->GetProxyForURL(url_, &results_buf_, NULL, NULL); + scoped_refptr worker_log(new LoadLog); + int rv = resolver->GetProxyForURL(url_, &results_buf_, NULL, NULL, + worker_log); DCHECK_NE(rv, ERR_IO_PENDING); + + worker_log->AddRef(); // Balanced in QueryComplete. origin_loop_->PostTask(FROM_HERE, - NewRunnableMethod(this, &Job::QueryComplete, rv)); + NewRunnableMethod(this, &Job::QueryComplete, rv, worker_log)); } // Runs the completion callback on the origin thread. - void QueryComplete(int result_code) { + void QueryComplete(int result_code, LoadLog* worker_log) { + // Merge the load log that was generated on the worker thread, into the + // main log. + if (load_log_) + load_log_->Append(worker_log); + worker_log->Release(); + // The Job may have been cancelled after it was started. if (!was_cancelled()) { if (result_code >= OK) { // Note: unit-tests use values > 0. @@ -159,6 +172,7 @@ class SingleThreadedProxyResolver::Job SingleThreadedProxyResolver* coordinator_; CompletionCallback* callback_; ProxyInfo* results_; + scoped_refptr load_log_; GURL url_; bool is_started_; @@ -193,10 +207,11 @@ SingleThreadedProxyResolver::~SingleThreadedProxyResolver() { int SingleThreadedProxyResolver::GetProxyForURL(const GURL& url, ProxyInfo* results, CompletionCallback* callback, - RequestHandle* request) { + RequestHandle* request, + LoadLog* load_log) { DCHECK(callback); - scoped_refptr job = new Job(this, url, results, callback); + scoped_refptr job = new Job(this, url, results, callback, load_log); pending_jobs_.push_back(job); ProcessPendingJobs(); // Jobs can never finish synchronously. diff --git a/net/proxy/single_threaded_proxy_resolver.h b/net/proxy/single_threaded_proxy_resolver.h index fff23b8..46c95a2 100644 --- a/net/proxy/single_threaded_proxy_resolver.h +++ b/net/proxy/single_threaded_proxy_resolver.h @@ -35,7 +35,8 @@ class SingleThreadedProxyResolver : public ProxyResolver { virtual int GetProxyForURL(const GURL& url, ProxyInfo* results, CompletionCallback* callback, - RequestHandle* request); + RequestHandle* request, + LoadLog* load_log); virtual void CancelRequest(RequestHandle request); virtual void CancelSetPacScript(); diff --git a/net/proxy/single_threaded_proxy_resolver_unittest.cc b/net/proxy/single_threaded_proxy_resolver_unittest.cc index da21ff1..7718602 100644 --- a/net/proxy/single_threaded_proxy_resolver_unittest.cc +++ b/net/proxy/single_threaded_proxy_resolver_unittest.cc @@ -4,6 +4,7 @@ #include "base/waitable_event.h" #include "googleurl/src/gurl.h" +#include "net/base/load_log.h" #include "net/base/net_errors.h" #include "net/base/test_completion_callback.h" #include "net/proxy/proxy_info.h" @@ -28,7 +29,8 @@ class MockProxyResolver : public ProxyResolver { virtual int GetProxyForURL(const GURL& query_url, ProxyInfo* results, CompletionCallback* callback, - RequestHandle* request) { + RequestHandle* request, + LoadLog* load_log) { if (resolve_latency_ms_) PlatformThread::Sleep(resolve_latency_ms_); @@ -37,6 +39,9 @@ class MockProxyResolver : public ProxyResolver { EXPECT_EQ(NULL, callback); EXPECT_EQ(NULL, request); + // Write something into |load_log| (doesn't really have any meaning.) + LoadLog::BeginEvent(load_log, LoadLog::TYPE_PROXY_RESOLVER_V8_DNS_RESOLVE); + results->UseNamedProxy(query_url.host()); // Return a success code which represents the request's order. @@ -105,14 +110,15 @@ class BlockableProxyResolver : public MockProxyResolver { virtual int GetProxyForURL(const GURL& query_url, ProxyInfo* results, CompletionCallback* callback, - RequestHandle* request) { + RequestHandle* request, + LoadLog* load_log) { if (should_block_) { blocked_.Signal(); unblocked_.Wait(); } return MockProxyResolver::GetProxyForURL( - query_url, results, callback, request); + query_url, results, callback, request, load_log); } private: @@ -140,9 +146,10 @@ TEST(SingleThreadedProxyResolverTest, Basic) { // Start request 0. TestCompletionCallback callback0; + scoped_refptr log0(new LoadLog); ProxyInfo results0; rv = resolver->GetProxyForURL( - GURL("http://request0"), &results0, &callback0, NULL); + GURL("http://request0"), &results0, &callback0, NULL, log0); EXPECT_EQ(ERR_IO_PENDING, rv); // Wait for request 0 to finish. @@ -150,24 +157,28 @@ TEST(SingleThreadedProxyResolverTest, Basic) { EXPECT_EQ(0, rv); EXPECT_EQ("PROXY request0:80", results0.ToPacString()); + // The mock proxy resolver should have written 1 log entry. And + // on completion, this should have been copied into |log0|. + EXPECT_EQ(1u, log0->events().size()); + // Start 3 more requests (request1 to request3). TestCompletionCallback callback1; ProxyInfo results1; rv = resolver->GetProxyForURL( - GURL("http://request1"), &results1, &callback1, NULL); + GURL("http://request1"), &results1, &callback1, NULL, NULL); EXPECT_EQ(ERR_IO_PENDING, rv); TestCompletionCallback callback2; ProxyInfo results2; rv = resolver->GetProxyForURL( - GURL("http://request2"), &results2, &callback2, NULL); + GURL("http://request2"), &results2, &callback2, NULL, NULL); EXPECT_EQ(ERR_IO_PENDING, rv); TestCompletionCallback callback3; ProxyInfo results3; rv = resolver->GetProxyForURL( - GURL("http://request3"), &results3, &callback3, NULL); + GURL("http://request3"), &results3, &callback3, NULL, NULL); EXPECT_EQ(ERR_IO_PENDING, rv); // Wait for the requests to finish (they must finish in the order they were @@ -203,7 +214,7 @@ TEST(SingleThreadedProxyResolverTest, CancelRequest) { TestCompletionCallback callback0; ProxyInfo results0; rv = resolver->GetProxyForURL( - GURL("http://request0"), &results0, &callback0, &request0); + GURL("http://request0"), &results0, &callback0, &request0, NULL); EXPECT_EQ(ERR_IO_PENDING, rv); // Wait until requests 0 reaches the worker thread. @@ -214,20 +225,20 @@ TEST(SingleThreadedProxyResolverTest, CancelRequest) { TestCompletionCallback callback1; ProxyInfo results1; rv = resolver->GetProxyForURL( - GURL("http://request1"), &results1, &callback1, NULL); + GURL("http://request1"), &results1, &callback1, NULL, NULL); EXPECT_EQ(ERR_IO_PENDING, rv); ProxyResolver::RequestHandle request2; TestCompletionCallback callback2; ProxyInfo results2; rv = resolver->GetProxyForURL( - GURL("http://request2"), &results2, &callback2, &request2); + GURL("http://request2"), &results2, &callback2, &request2, NULL); EXPECT_EQ(ERR_IO_PENDING, rv); TestCompletionCallback callback3; ProxyInfo results3; rv = resolver->GetProxyForURL( - GURL("http://request3"), &results3, &callback3, NULL); + GURL("http://request3"), &results3, &callback3, NULL, NULL); EXPECT_EQ(ERR_IO_PENDING, rv); // Cancel request0 (inprogress) and request2 (pending). @@ -272,19 +283,19 @@ TEST(SingleThreadedProxyResolverTest, CancelRequestByDeleting) { TestCompletionCallback callback0; ProxyInfo results0; rv = resolver->GetProxyForURL( - GURL("http://request0"), &results0, &callback0, NULL); + GURL("http://request0"), &results0, &callback0, NULL, NULL); EXPECT_EQ(ERR_IO_PENDING, rv); TestCompletionCallback callback1; ProxyInfo results1; rv = resolver->GetProxyForURL( - GURL("http://request1"), &results1, &callback1, NULL); + GURL("http://request1"), &results1, &callback1, NULL, NULL); EXPECT_EQ(ERR_IO_PENDING, rv); TestCompletionCallback callback2; ProxyInfo results2; rv = resolver->GetProxyForURL( - GURL("http://request2"), &results2, &callback2, NULL); + GURL("http://request2"), &results2, &callback2, NULL, NULL); EXPECT_EQ(ERR_IO_PENDING, rv); // Wait until request 0 reaches the worker thread. @@ -327,7 +338,7 @@ TEST(SingleThreadedProxyResolverTest, CancelSetPacScript) { TestCompletionCallback callback0; ProxyInfo results0; rv = resolver->GetProxyForURL( - GURL("http://request0"), &results0, &callback0, &request0); + GURL("http://request0"), &results0, &callback0, &request0, NULL); EXPECT_EQ(ERR_IO_PENDING, rv); // Wait until requests 0 reaches the worker thread. @@ -346,7 +357,7 @@ TEST(SingleThreadedProxyResolverTest, CancelSetPacScript) { TestCompletionCallback callback1; ProxyInfo results1; rv = resolver->GetProxyForURL( - GURL("http://request1"), &results1, &callback1, NULL); + GURL("http://request1"), &results1, &callback1, NULL, NULL); EXPECT_EQ(ERR_IO_PENDING, rv); // Unblock the worker thread so the requests can continue running. -- cgit v1.1