| 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 void PageLoadHistograms::Dump(WebFrame* frame) { |
| 862 } | |
| 863 | |
| 864 bool PageLoadHistograms::ShouldDump(WebFrame* frame) { | |
| 865 // We only dump histograms for main frames. | 859 // We only dump histograms for main frames. |
| 866 // In the future, it may be interesting to tag subframes and dump them too. | 860 // In the future, it may be interesting to tag subframes and dump them too. |
| 867 if (!frame || frame->parent()) | 861 if (!frame || frame->parent()) |
| 868 return false; | 862 return; |
| 869 | 863 |
| 870 // If the main frame lives in a different process, don't do anything. | 864 // If the main frame lives in a different process, don't do anything. |
| 871 // Histogram data will be recorded by the real main frame. | 865 // Histogram data will be recorded by the real main frame. |
| 872 if (frame->isWebRemoteFrame()) | 866 if (frame->isWebRemoteFrame()) |
| 873 return false; | 867 return; |
| 874 | 868 |
| 875 // Only dump for supported schemes. | 869 // Only dump for supported schemes. |
| 876 URLPattern::SchemeMasks scheme_type = | 870 URLPattern::SchemeMasks scheme_type = |
| 877 GetSupportedSchemeType(frame->document().url()); | 871 GetSupportedSchemeType(frame->document().url()); |
| 878 if (scheme_type == 0) | 872 if (scheme_type == 0) |
| 879 return false; | 873 return; |
| 880 | 874 |
| 881 // Don't dump stats for the NTP, as PageLoadHistograms should only be recorded | 875 // Don't dump stats for the NTP, as PageLoadHistograms should only be recorded |
| 882 // for pages visited due to an explicit user navigation. | 876 // for pages visited due to an explicit user navigation. |
| 883 if (SearchBouncer::GetInstance()->IsNewTabPage(frame->document().url())) { | 877 if (SearchBouncer::GetInstance()->IsNewTabPage(frame->document().url())) { |
| 884 return false; | 878 return; |
| 885 } | 879 } |
| 886 | 880 |
| 887 // Ignore multipart requests. | 881 // Ignore multipart requests. |
| 888 if (frame->dataSource()->response().isMultipartPayload()) | 882 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; | 883 return; |
| 897 | 884 |
| 898 URLPattern::SchemeMasks scheme_type = | |
| 899 GetSupportedSchemeType(frame->document().url()); | |
| 900 | |
| 901 DocumentState* document_state = | 885 DocumentState* document_state = |
| 902 DocumentState::FromDataSource(frame->dataSource()); | 886 DocumentState::FromDataSource(frame->dataSource()); |
| 903 | 887 |
| 904 bool data_reduction_proxy_was_used = false; | 888 bool data_reduction_proxy_was_used = false; |
| 905 if (!document_state->proxy_server().IsEmpty()) { | 889 if (!document_state->proxy_server().IsEmpty()) { |
| 906 bool handled = | 890 bool handled = |
| 907 Send(new DataReductionProxyViewHostMsg_IsDataReductionProxy( | 891 Send(new DataReductionProxyViewHostMsg_IsDataReductionProxy( |
| 908 document_state->proxy_server(), &data_reduction_proxy_was_used)); | 892 document_state->proxy_server(), &data_reduction_proxy_was_used)); |
| 909 // If the IPC call is not handled, then |data_reduction_proxy_was_used| | 893 // If the IPC call is not handled, then |data_reduction_proxy_was_used| |
| 910 // should remain |false|. | 894 // should remain |false|. |
| 911 DCHECK(handled || !data_reduction_proxy_was_used); | 895 DCHECK(handled || !data_reduction_proxy_was_used); |
| 912 } | 896 } |
| 913 | 897 |
| 914 bool came_from_websearch = IsFromGoogleSearchResult( | 898 bool came_from_websearch = IsFromGoogleSearchResult( |
| 915 frame->document().url(), | 899 frame->document().url(), |
| 916 blink::WebStringToGURL(frame->document().referrer())); | 900 blink::WebStringToGURL(frame->document().referrer())); |
| 917 int websearch_chrome_joint_experiment_id = kNoExperiment; | 901 int websearch_chrome_joint_experiment_id = kNoExperiment; |
| 918 bool is_preview = false; | 902 bool is_preview = false; |
| 919 if (came_from_websearch) { | 903 if (came_from_websearch) { |
| 920 websearch_chrome_joint_experiment_id = GetQueryStringBasedExperiment( | 904 websearch_chrome_joint_experiment_id = GetQueryStringBasedExperiment( |
| 921 blink::WebStringToGURL(frame->document().referrer())); | 905 blink::WebStringToGURL(frame->document().referrer())); |
| 922 is_preview = ViaHeaderContains(frame, "1.1 Google Instant Proxy Preview"); | 906 is_preview = ViaHeaderContains(frame, "1.1 Google Instant Proxy Preview"); |
| 923 } | 907 } |
| 924 | 908 |
| 925 MaybeDumpFirstLayoutHistograms(); | |
| 926 | |
| 927 content::RenderFrame* render_frame = | 909 content::RenderFrame* render_frame = |
| 928 content::RenderFrame::FromWebFrame(frame); | 910 content::RenderFrame::FromWebFrame(frame); |
| 929 | 911 |
| 930 // Metrics based on the timing information recorded for the Navigation Timing | 912 // Metrics based on the timing information recorded for the Navigation Timing |
| 931 // API - http://www.w3.org/TR/navigation-timing/. | 913 // API - http://www.w3.org/TR/navigation-timing/. |
| 932 DumpHistograms( | 914 DumpHistograms( |
| 933 frame->performance(), document_state, data_reduction_proxy_was_used, | 915 frame->performance(), document_state, data_reduction_proxy_was_used, |
| 934 render_frame && render_frame->IsUsingLoFi(), came_from_websearch, | 916 render_frame && render_frame->IsUsingLoFi(), came_from_websearch, |
| 935 websearch_chrome_joint_experiment_id, is_preview, scheme_type); | 917 websearch_chrome_joint_experiment_id, is_preview, scheme_type); |
| 936 | 918 |
| (...skipping 14 matching lines...) Expand all Loading... |
| 951 // the histograms we generated. Without this call, pages that don't have an | 933 // 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 | 934 // on-close-handler might generate data that is lost when the renderer is |
| 953 // shutdown abruptly (perchance because the user closed the tab). | 935 // shutdown abruptly (perchance because the user closed the tab). |
| 954 // TODO(jar) BUG=33233: This needs to be moved to a PostDelayedTask, and it | 936 // 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 | 937 // should post when the onload is complete, so that it doesn't interfere with |
| 956 // the next load. | 938 // the next load. |
| 957 content::RenderThread::Get()->UpdateHistograms( | 939 content::RenderThread::Get()->UpdateHistograms( |
| 958 content::kHistogramSynchronizerReservedSequenceNumber); | 940 content::kHistogramSynchronizerReservedSequenceNumber); |
| 959 } | 941 } |
| 960 | 942 |
| 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) { | 943 void PageLoadHistograms::FrameWillClose(WebFrame* frame) { |
| 985 Dump(frame); | 944 Dump(frame); |
| 986 } | 945 } |
| 987 | 946 |
| 988 void PageLoadHistograms::ClosePage() { | 947 void PageLoadHistograms::ClosePage() { |
| 989 // TODO(davemoore) This code should be removed once willClose() gets | 948 // TODO(davemoore) This code should be removed once willClose() gets |
| 990 // called when a page is destroyed. page_load_histograms_.Dump() is safe | 949 // 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. | 950 // to call multiple times for the same frame, but it will simplify things. |
| 992 Dump(render_view()->GetWebView()->mainFrame()); | 951 Dump(render_view()->GetWebView()->mainFrame()); |
| 993 } | 952 } |
| 994 | 953 |
| 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, | 954 void PageLoadHistograms::LogPageLoadTime(const DocumentState* document_state, |
| 1039 const WebDataSource* ds) const { | 955 const WebDataSource* ds) const { |
| 1040 // Because this function gets called on every page load, | 956 // Because this function gets called on every page load, |
| 1041 // take extra care to optimize it away if logging is turned off. | 957 // take extra care to optimize it away if logging is turned off. |
| 1042 if (logging::LOG_INFO < logging::GetMinLogLevel()) | 958 if (logging::LOG_INFO < logging::GetMinLogLevel()) |
| 1043 return; | 959 return; |
| 1044 | 960 |
| 1045 DCHECK(document_state); | 961 DCHECK(document_state); |
| 1046 DCHECK(ds); | 962 DCHECK(ds); |
| 1047 GURL url(ds->request().url()); | 963 GURL url(ds->request().url()); |
| 1048 Time start = document_state->start_load_time(); | 964 Time start = document_state->start_load_time(); |
| 1049 Time finish = document_state->finish_load_time(); | 965 Time finish = document_state->finish_load_time(); |
| 1050 // TODO(mbelshe): should we log more stats? | 966 // TODO(mbelshe): should we log more stats? |
| 1051 VLOG(1) << "PLT: " << (finish - start).InMilliseconds() << "ms " | 967 VLOG(1) << "PLT: " << (finish - start).InMilliseconds() << "ms " |
| 1052 << url.spec(); | 968 << url.spec(); |
| 1053 } | 969 } |
| OLD | NEW |