Commit 1f8c6499 authored by simonjam@chromium.org's avatar simonjam@chromium.org

Fix bug where Navigation Timing reports negative load time when redirecting to

a cached page.

The problem is that the same ResourceLoadTiming struct is re-used for each
redirect. So, we record the deltas for connect time, headers, send request, etc.,
for each redirect. But, after the last redirect, we simply have a cache hit. So,
the base_time is updated for that cache hit, but the deltas are still relative
to the old base_time value. When we apply the old deltas to the new base_time,
we end up with a time in the future.

To fix this, I clear ResourceLoadTimingInfo after each redirect.

I've added a UI test for this. I could've done a unit test, but we have no end-
to-end Navigation Timing tests and it'd be easy for this to be broken by some
unrelated change to NetLog and redirects, so I prefer having this test be a
safe guard.

On a related note, I noticed that LoadTimingObserver::OnAddURLRequestEntry() is
called at least twice for each source.id. Once for the normal URLRequest, and
once for the AppCacheURLRequest. Fortunately, they're only 100 ns apart, so it
doesn't screw up the times. But, it was a surprise to me. Perhaps we should
ignore the AppCache requests?

BUG=None
TEST=ui_tests


Review URL: http://codereview.chromium.org/8336012

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@107604 0039d316-1c4b-4281-b951-d872f2087c98
parent 6494823b
......@@ -150,6 +150,7 @@ void LoadTimingObserver::OnAddURLRequestEntry(
URLRequestRecord& record = url_request_to_record_[source.id];
record.base_ticks = time;
record.timing = ResourceLoadTimingInfo();
record.timing.base_time = TimeTicksToTime(time);
}
return;
......@@ -206,9 +207,9 @@ void LoadTimingObserver::OnAddURLRequestEntry(
break;
case net::NetLog::TYPE_HTTP_TRANSACTION_READ_HEADERS:
if (is_begin)
timing.receive_headers_start = TimeTicksToOffset(time, record);
timing.receive_headers_start = TimeTicksToOffset(time, record);
else if (is_end)
timing.receive_headers_end = TimeTicksToOffset(time, record);
timing.receive_headers_end = TimeTicksToOffset(time, record);
break;
default:
break;
......
// Copyright (c) 2011 The Chromium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#include "chrome/test/automation/tab_proxy.h"
#include "chrome/test/ui/ui_test.h"
#include "googleurl/src/gurl.h"
#include "net/test/test_server.h"
#include "testing/gtest/include/gtest/gtest.h"
class LoadTimingObserverUITest : public UITest {
public:
LoadTimingObserverUITest()
: http_server_(net::TestServer::TYPE_HTTP, FilePath()) {
dom_automation_enabled_ = true;
}
protected:
net::TestServer http_server_;
};
TEST_F(LoadTimingObserverUITest, CacheHitAfterRedirect) {
ASSERT_TRUE(http_server_.Start());
GURL cached_page = http_server_.GetURL("cachetime");
std::string redirect = "server-redirect?" + cached_page.spec();
NavigateToURL(cached_page);
NavigateToURL(http_server_.GetURL(redirect));
scoped_refptr<TabProxy> tab_proxy = GetActiveTab();
int response_start = 0;
int response_end = 0;
ASSERT_TRUE(tab_proxy->ExecuteAndExtractInt(
L"", L"window.domAutomationController.send("
L"window.performance.timing.responseStart - "
L"window.performance.timing.navigationStart)", &response_start));
ASSERT_TRUE(tab_proxy->ExecuteAndExtractInt(
L"", L"window.domAutomationController.send("
L"window.performance.timing.responseEnd - "
L"window.performance.timing.navigationStart)", &response_end));
EXPECT_LE(response_start, response_end);
}
......@@ -705,6 +705,7 @@
'browser/locale_tests_uitest.cc',
'browser/media_uitest.cc',
'browser/metrics/metrics_service_uitest.cc',
'browser/net/load_timing_observer_uitest.cc',
'browser/prefs/pref_service_uitest.cc',
'browser/printing/printing_layout_uitest.cc',
'browser/process_singleton_linux_uitest.cc',
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment