| OLD | NEW |
| 1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. | 1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. |
| 2 // Use of this source code is governed by a BSD-style license that can be | 2 // Use of this source code is governed by a BSD-style license that can be |
| 3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
| 4 | 4 |
| 5 #include "chrome/renderer/page_load_histograms.h" | 5 #include "chrome/renderer/page_load_histograms.h" |
| 6 | 6 |
| 7 #include <stddef.h> | 7 #include <stddef.h> |
| 8 | 8 |
| 9 #include <string> | 9 #include <string> |
| 10 | 10 |
| 11 #include "base/bind.h" | |
| 12 #include "base/command_line.h" | 11 #include "base/command_line.h" |
| 13 #include "base/logging.h" | 12 #include "base/logging.h" |
| 14 #include "base/metrics/field_trial.h" | 13 #include "base/metrics/field_trial.h" |
| 15 #include "base/metrics/histogram.h" | 14 #include "base/metrics/histogram.h" |
| 16 #include "base/strings/string_number_conversions.h" | 15 #include "base/strings/string_number_conversions.h" |
| 17 #include "base/strings/string_split.h" | 16 #include "base/strings/string_split.h" |
| 18 #include "base/strings/string_util.h" | 17 #include "base/strings/string_util.h" |
| 19 #include "base/strings/stringprintf.h" | 18 #include "base/strings/stringprintf.h" |
| 20 #include "base/strings/utf_string_conversions.h" | 19 #include "base/strings/utf_string_conversions.h" |
| 21 #include "base/time/time.h" | 20 #include "base/time/time.h" |
| (...skipping 824 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 846 break; | 845 break; |
| 847 default: | 846 default: |
| 848 break; | 847 break; |
| 849 } | 848 } |
| 850 } | 849 } |
| 851 } | 850 } |
| 852 | 851 |
| 853 } // namespace | 852 } // namespace |
| 854 | 853 |
| 855 PageLoadHistograms::PageLoadHistograms(content::RenderView* render_view) | 854 PageLoadHistograms::PageLoadHistograms(content::RenderView* render_view) |
| 856 : content::RenderViewObserver(render_view), | 855 : content::RenderViewObserver(render_view) { |
| 857 dumped_first_layout_histograms_(false), | |
| 858 weak_factory_(this) { | |
| 859 } | 856 } |
| 860 | 857 |
| 861 PageLoadHistograms::~PageLoadHistograms() { | 858 PageLoadHistograms::~PageLoadHistograms() { |
| 862 } | 859 } |
| 863 | 860 |
| 864 bool PageLoadHistograms::ShouldDump(WebFrame* frame) { | 861 void PageLoadHistograms::Dump(WebFrame* frame) { |
| 865 // We only dump histograms for main frames. | 862 // We only dump histograms for main frames. |
| 866 // In the future, it may be interesting to tag subframes and dump them too. | 863 // In the future, it may be interesting to tag subframes and dump them too. |
| 867 if (!frame || frame->parent()) | 864 if (!frame || frame->parent()) |
| 868 return false; | 865 return; |
| 869 | 866 |
| 870 // If the main frame lives in a different process, don't do anything. | 867 // If the main frame lives in a different process, don't do anything. |
| 871 // Histogram data will be recorded by the real main frame. | 868 // Histogram data will be recorded by the real main frame. |
| 872 if (frame->isWebRemoteFrame()) | 869 if (frame->isWebRemoteFrame()) |
| 873 return false; | 870 return; |
| 874 | 871 |
| 875 // Only dump for supported schemes. | 872 // Only dump for supported schemes. |
| 876 URLPattern::SchemeMasks scheme_type = | 873 URLPattern::SchemeMasks scheme_type = |
| 877 GetSupportedSchemeType(frame->document().url()); | 874 GetSupportedSchemeType(frame->document().url()); |
| 878 if (scheme_type == 0) | 875 if (scheme_type == 0) |
| 879 return false; | 876 return; |
| 880 | 877 |
| 881 // Don't dump stats for the NTP, as PageLoadHistograms should only be recorded | 878 // Don't dump stats for the NTP, as PageLoadHistograms should only be recorded |
| 882 // for pages visited due to an explicit user navigation. | 879 // for pages visited due to an explicit user navigation. |
| 883 if (SearchBouncer::GetInstance()->IsNewTabPage(frame->document().url())) { | 880 if (SearchBouncer::GetInstance()->IsNewTabPage(frame->document().url())) { |
| 884 return false; | 881 return; |
| 885 } | 882 } |
| 886 | 883 |
| 887 // Ignore multipart requests. | 884 // Ignore multipart requests. |
| 888 if (frame->dataSource()->response().isMultipartPayload()) | 885 if (frame->dataSource()->response().isMultipartPayload()) |
| 889 return false; | |
| 890 | |
| 891 return true; | |
| 892 } | |
| 893 | |
| 894 void PageLoadHistograms::Dump(WebFrame* frame) { | |
| 895 if (!ShouldDump(frame)) | |
| 896 return; | 886 return; |
| 897 | 887 |
| 898 URLPattern::SchemeMasks scheme_type = | |
| 899 GetSupportedSchemeType(frame->document().url()); | |
| 900 | |
| 901 DocumentState* document_state = | 888 DocumentState* document_state = |
| 902 DocumentState::FromDataSource(frame->dataSource()); | 889 DocumentState::FromDataSource(frame->dataSource()); |
| 903 | 890 |
| 904 bool data_reduction_proxy_was_used = false; | 891 bool data_reduction_proxy_was_used = false; |
| 905 if (!document_state->proxy_server().IsEmpty()) { | 892 if (!document_state->proxy_server().IsEmpty()) { |
| 906 bool handled = | 893 bool handled = |
| 907 Send(new DataReductionProxyViewHostMsg_IsDataReductionProxy( | 894 Send(new DataReductionProxyViewHostMsg_IsDataReductionProxy( |
| 908 document_state->proxy_server(), &data_reduction_proxy_was_used)); | 895 document_state->proxy_server(), &data_reduction_proxy_was_used)); |
| 909 // If the IPC call is not handled, then |data_reduction_proxy_was_used| | 896 // If the IPC call is not handled, then |data_reduction_proxy_was_used| |
| 910 // should remain |false|. | 897 // should remain |false|. |
| 911 DCHECK(handled || !data_reduction_proxy_was_used); | 898 DCHECK(handled || !data_reduction_proxy_was_used); |
| 912 } | 899 } |
| 913 | 900 |
| 914 bool came_from_websearch = IsFromGoogleSearchResult( | 901 bool came_from_websearch = IsFromGoogleSearchResult( |
| 915 frame->document().url(), | 902 frame->document().url(), |
| 916 blink::WebStringToGURL(frame->document().referrer())); | 903 blink::WebStringToGURL(frame->document().referrer())); |
| 917 int websearch_chrome_joint_experiment_id = kNoExperiment; | 904 int websearch_chrome_joint_experiment_id = kNoExperiment; |
| 918 bool is_preview = false; | 905 bool is_preview = false; |
| 919 if (came_from_websearch) { | 906 if (came_from_websearch) { |
| 920 websearch_chrome_joint_experiment_id = GetQueryStringBasedExperiment( | 907 websearch_chrome_joint_experiment_id = GetQueryStringBasedExperiment( |
| 921 blink::WebStringToGURL(frame->document().referrer())); | 908 blink::WebStringToGURL(frame->document().referrer())); |
| 922 is_preview = ViaHeaderContains(frame, "1.1 Google Instant Proxy Preview"); | 909 is_preview = ViaHeaderContains(frame, "1.1 Google Instant Proxy Preview"); |
| 923 } | 910 } |
| 924 | 911 |
| 925 MaybeDumpFirstLayoutHistograms(); | |
| 926 | |
| 927 content::RenderFrame* render_frame = | 912 content::RenderFrame* render_frame = |
| 928 content::RenderFrame::FromWebFrame(frame); | 913 content::RenderFrame::FromWebFrame(frame); |
| 929 | 914 |
| 930 // Metrics based on the timing information recorded for the Navigation Timing | 915 // Metrics based on the timing information recorded for the Navigation Timing |
| 931 // API - http://www.w3.org/TR/navigation-timing/. | 916 // API - http://www.w3.org/TR/navigation-timing/. |
| 932 DumpHistograms( | 917 DumpHistograms( |
| 933 frame->performance(), document_state, data_reduction_proxy_was_used, | 918 frame->performance(), document_state, data_reduction_proxy_was_used, |
| 934 render_frame && render_frame->IsUsingLoFi(), came_from_websearch, | 919 render_frame && render_frame->IsUsingLoFi(), came_from_websearch, |
| 935 websearch_chrome_joint_experiment_id, is_preview, scheme_type); | 920 websearch_chrome_joint_experiment_id, is_preview, scheme_type); |
| 936 | 921 |
| (...skipping 14 matching lines...) Expand all Loading... |
| 951 // the histograms we generated. Without this call, pages that don't have an | 936 // the histograms we generated. Without this call, pages that don't have an |
| 952 // on-close-handler might generate data that is lost when the renderer is | 937 // on-close-handler might generate data that is lost when the renderer is |
| 953 // shutdown abruptly (perchance because the user closed the tab). | 938 // shutdown abruptly (perchance because the user closed the tab). |
| 954 // TODO(jar) BUG=33233: This needs to be moved to a PostDelayedTask, and it | 939 // TODO(jar) BUG=33233: This needs to be moved to a PostDelayedTask, and it |
| 955 // should post when the onload is complete, so that it doesn't interfere with | 940 // should post when the onload is complete, so that it doesn't interfere with |
| 956 // the next load. | 941 // the next load. |
| 957 content::RenderThread::Get()->UpdateHistograms( | 942 content::RenderThread::Get()->UpdateHistograms( |
| 958 content::kHistogramSynchronizerReservedSequenceNumber); | 943 content::kHistogramSynchronizerReservedSequenceNumber); |
| 959 } | 944 } |
| 960 | 945 |
| 961 void PageLoadHistograms::MaybeDumpFirstLayoutHistograms() { | |
| 962 if (dumped_first_layout_histograms_) | |
| 963 return; | |
| 964 | |
| 965 const WebPerformance& performance = | |
| 966 render_view()->GetWebView()->mainFrame()->performance(); | |
| 967 Time first_layout = Time::FromDoubleT(performance.firstLayout()); | |
| 968 if (first_layout.is_null()) | |
| 969 return; | |
| 970 | |
| 971 Time navigation_start = Time::FromDoubleT(performance.navigationStart()); | |
| 972 if (!navigation_start.is_null()) | |
| 973 PLT_HISTOGRAM("PLT.PT.NavigationStartToFirstLayout", | |
| 974 first_layout - navigation_start); | |
| 975 | |
| 976 Time response_start = Time::FromDoubleT(performance.responseStart()); | |
| 977 if (!response_start.is_null()) | |
| 978 PLT_HISTOGRAM("PLT.PT.ResponseStartToFirstLayout", | |
| 979 first_layout - response_start); | |
| 980 | |
| 981 dumped_first_layout_histograms_ = true; | |
| 982 } | |
| 983 | |
| 984 void PageLoadHistograms::FrameWillClose(WebFrame* frame) { | 946 void PageLoadHistograms::FrameWillClose(WebFrame* frame) { |
| 985 Dump(frame); | 947 Dump(frame); |
| 986 } | 948 } |
| 987 | 949 |
| 988 void PageLoadHistograms::ClosePage() { | 950 void PageLoadHistograms::ClosePage() { |
| 989 // TODO(davemoore) This code should be removed once willClose() gets | 951 // TODO(davemoore) This code should be removed once willClose() gets |
| 990 // called when a page is destroyed. page_load_histograms_.Dump() is safe | 952 // called when a page is destroyed. page_load_histograms_.Dump() is safe |
| 991 // to call multiple times for the same frame, but it will simplify things. | 953 // to call multiple times for the same frame, but it will simplify things. |
| 992 Dump(render_view()->GetWebView()->mainFrame()); | 954 Dump(render_view()->GetWebView()->mainFrame()); |
| 993 } | 955 } |
| 994 | 956 |
| 995 void PageLoadHistograms::DidUpdateLayout() { | |
| 996 DCHECK(content::RenderThread::Get()); | |
| 997 // Normally, PageLoadHistograms dumps all histograms in the FrameWillClose or | |
| 998 // ClosePage callbacks, which happen as a page is being torn down. However, | |
| 999 // renderers that are killed by fast shutdown (for example, renderers closed | |
| 1000 // due to the user closing a tab) don't get a chance to run these callbacks | |
| 1001 // (see crbug.com/382542 for details). | |
| 1002 // | |
| 1003 // Longer term, we need to migrate histogram recording to happen earlier in | |
| 1004 // the page load life cycle, so histograms aren't lost when tabs are | |
| 1005 // closed. As a first step, we use the RenderViewObserver::DidUpdateLayout | |
| 1006 // callback to log first layout histograms earlier in the page load life | |
| 1007 // cycle. | |
| 1008 | |
| 1009 if (dumped_first_layout_histograms_) | |
| 1010 return; | |
| 1011 | |
| 1012 WebFrame* frame = render_view()->GetWebView()->mainFrame(); | |
| 1013 if (!ShouldDump(frame)) | |
| 1014 return; | |
| 1015 | |
| 1016 // The canonical source for the 'first layout time' is the | |
| 1017 // blink::WebPerformance object, so we need to read the first layout timestamp | |
| 1018 // from that object, rather than taking our own timestamp in this | |
| 1019 // callback. | |
| 1020 // | |
| 1021 // This DidUpdateLayout callback gets invoked in the midst of the | |
| 1022 // layout process. The logic that records the first layout time in the | |
| 1023 // blink::WebPerformance object may run later in the layout process, after | |
| 1024 // DidUpdateLayout gets invoked. Thus, we schedule a callback to run | |
| 1025 // MaybeDumpFirstLayoutHistograms asynchronously, after the layout process is | |
| 1026 // complete. | |
| 1027 // | |
| 1028 // Note, too, that some layouts are performed with pending stylesheets, and | |
| 1029 // blink will not record firstLayout during those layouts, so firstLayout may | |
| 1030 // not be populated during the layout associated with the first | |
| 1031 // DidUpdateLayout callback. | |
| 1032 base::ThreadTaskRunnerHandle::Get()->PostTask( | |
| 1033 FROM_HERE, | |
| 1034 base::Bind(&PageLoadHistograms::MaybeDumpFirstLayoutHistograms, | |
| 1035 weak_factory_.GetWeakPtr())); | |
| 1036 } | |
| 1037 | |
| 1038 void PageLoadHistograms::LogPageLoadTime(const DocumentState* document_state, | 957 void PageLoadHistograms::LogPageLoadTime(const DocumentState* document_state, |
| 1039 const WebDataSource* ds) const { | 958 const WebDataSource* ds) const { |
| 1040 // Because this function gets called on every page load, | 959 // Because this function gets called on every page load, |
| 1041 // take extra care to optimize it away if logging is turned off. | 960 // take extra care to optimize it away if logging is turned off. |
| 1042 if (logging::LOG_INFO < logging::GetMinLogLevel()) | 961 if (logging::LOG_INFO < logging::GetMinLogLevel()) |
| 1043 return; | 962 return; |
| 1044 | 963 |
| 1045 DCHECK(document_state); | 964 DCHECK(document_state); |
| 1046 DCHECK(ds); | 965 DCHECK(ds); |
| 1047 GURL url(ds->request().url()); | 966 GURL url(ds->request().url()); |
| 1048 Time start = document_state->start_load_time(); | 967 Time start = document_state->start_load_time(); |
| 1049 Time finish = document_state->finish_load_time(); | 968 Time finish = document_state->finish_load_time(); |
| 1050 // TODO(mbelshe): should we log more stats? | 969 // TODO(mbelshe): should we log more stats? |
| 1051 VLOG(1) << "PLT: " << (finish - start).InMilliseconds() << "ms " | 970 VLOG(1) << "PLT: " << (finish - start).InMilliseconds() << "ms " |
| 1052 << url.spec(); | 971 << url.spec(); |
| 1053 } | 972 } |
| OLD | NEW |