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 "net/http/http_network_transaction.h" | 5 #include "net/http/http_network_transaction.h" |
6 | 6 |
7 #include <set> | 7 #include <set> |
8 #include <vector> | 8 #include <vector> |
9 | 9 |
10 #include "base/bind.h" | 10 #include "base/bind.h" |
(...skipping 46 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
57 #include "net/socket/transport_client_socket_pool.h" | 57 #include "net/socket/transport_client_socket_pool.h" |
58 #include "net/spdy/hpack_huffman_aggregator.h" | 58 #include "net/spdy/hpack_huffman_aggregator.h" |
59 #include "net/spdy/spdy_http_stream.h" | 59 #include "net/spdy/spdy_http_stream.h" |
60 #include "net/spdy/spdy_session.h" | 60 #include "net/spdy/spdy_session.h" |
61 #include "net/spdy/spdy_session_pool.h" | 61 #include "net/spdy/spdy_session_pool.h" |
62 #include "net/ssl/ssl_cert_request_info.h" | 62 #include "net/ssl/ssl_cert_request_info.h" |
63 #include "net/ssl/ssl_connection_status_flags.h" | 63 #include "net/ssl/ssl_connection_status_flags.h" |
64 #include "url/gurl.h" | 64 #include "url/gurl.h" |
65 #include "url/url_canon.h" | 65 #include "url/url_canon.h" |
66 | 66 |
67 using base::Time; | |
68 using base::TimeDelta; | |
69 | |
70 namespace net { | 67 namespace net { |
71 | 68 |
72 namespace { | 69 namespace { |
73 | 70 |
74 void ProcessAlternateProtocol( | 71 void ProcessAlternateProtocol( |
75 HttpNetworkSession* session, | 72 HttpNetworkSession* session, |
76 const HttpResponseHeaders& headers, | 73 const HttpResponseHeaders& headers, |
77 const HostPortPair& http_host_port_pair) { | 74 const HostPortPair& http_host_port_pair) { |
78 if (!headers.HasHeader(kAlternateProtocolHeader)) | 75 if (!headers.HasHeader(kAlternateProtocolHeader)) |
79 return; | 76 return; |
(...skipping 46 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
126 | 123 |
127 HttpNetworkTransaction::HttpNetworkTransaction(RequestPriority priority, | 124 HttpNetworkTransaction::HttpNetworkTransaction(RequestPriority priority, |
128 HttpNetworkSession* session) | 125 HttpNetworkSession* session) |
129 : pending_auth_target_(HttpAuth::AUTH_NONE), | 126 : pending_auth_target_(HttpAuth::AUTH_NONE), |
130 io_callback_(base::Bind(&HttpNetworkTransaction::OnIOComplete, | 127 io_callback_(base::Bind(&HttpNetworkTransaction::OnIOComplete, |
131 base::Unretained(this))), | 128 base::Unretained(this))), |
132 session_(session), | 129 session_(session), |
133 request_(NULL), | 130 request_(NULL), |
134 priority_(priority), | 131 priority_(priority), |
135 headers_valid_(false), | 132 headers_valid_(false), |
136 logged_response_time_(false), | |
137 fallback_error_code_(ERR_SSL_INAPPROPRIATE_FALLBACK), | 133 fallback_error_code_(ERR_SSL_INAPPROPRIATE_FALLBACK), |
138 request_headers_(), | 134 request_headers_(), |
139 read_buf_len_(0), | 135 read_buf_len_(0), |
140 total_received_bytes_(0), | 136 total_received_bytes_(0), |
141 next_state_(STATE_NONE), | 137 next_state_(STATE_NONE), |
142 establishing_tunnel_(false), | 138 establishing_tunnel_(false), |
143 websocket_handshake_stream_base_create_helper_(NULL) { | 139 websocket_handshake_stream_base_create_helper_(NULL) { |
144 session->ssl_config_service()->GetSSLConfig(&server_ssl_config_); | 140 session->ssl_config_service()->GetSSLConfig(&server_ssl_config_); |
145 session->GetNextProtos(&server_ssl_config_.next_protos); | 141 session->GetNextProtos(&server_ssl_config_.next_protos); |
146 proxy_ssl_config_ = server_ssl_config_; | 142 proxy_ssl_config_ = server_ssl_config_; |
(...skipping 30 matching lines...) Expand all Loading... |
177 request_->upload_data_stream->Reset(); // Invalidate pending callbacks. | 173 request_->upload_data_stream->Reset(); // Invalidate pending callbacks. |
178 } | 174 } |
179 | 175 |
180 int HttpNetworkTransaction::Start(const HttpRequestInfo* request_info, | 176 int HttpNetworkTransaction::Start(const HttpRequestInfo* request_info, |
181 const CompletionCallback& callback, | 177 const CompletionCallback& callback, |
182 const BoundNetLog& net_log) { | 178 const BoundNetLog& net_log) { |
183 SIMPLE_STATS_COUNTER("HttpNetworkTransaction.Count"); | 179 SIMPLE_STATS_COUNTER("HttpNetworkTransaction.Count"); |
184 | 180 |
185 net_log_ = net_log; | 181 net_log_ = net_log; |
186 request_ = request_info; | 182 request_ = request_info; |
187 start_time_ = base::Time::Now(); | |
188 | 183 |
189 if (request_->load_flags & LOAD_DISABLE_CERT_REVOCATION_CHECKING) { | 184 if (request_->load_flags & LOAD_DISABLE_CERT_REVOCATION_CHECKING) { |
190 server_ssl_config_.rev_checking_enabled = false; | 185 server_ssl_config_.rev_checking_enabled = false; |
191 proxy_ssl_config_.rev_checking_enabled = false; | 186 proxy_ssl_config_.rev_checking_enabled = false; |
192 } | 187 } |
193 | 188 |
194 // Channel ID is disabled if privacy mode is enabled for this request. | 189 // Channel ID is disabled if privacy mode is enabled for this request. |
195 if (request_->privacy_mode == PRIVACY_MODE_ENABLED) | 190 if (request_->privacy_mode == PRIVACY_MODE_ENABLED) |
196 server_ssl_config_.channel_id_enabled = false; | 191 server_ssl_config_.channel_id_enabled = false; |
197 | 192 |
(...skipping 781 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
979 result = HandleCertificateRequest(result); | 974 result = HandleCertificateRequest(result); |
980 if (result == OK) | 975 if (result == OK) |
981 return result; | 976 return result; |
982 } | 977 } |
983 | 978 |
984 if (result == ERR_QUIC_HANDSHAKE_FAILED) { | 979 if (result == ERR_QUIC_HANDSHAKE_FAILED) { |
985 ResetConnectionAndRequestForResend(); | 980 ResetConnectionAndRequestForResend(); |
986 return OK; | 981 return OK; |
987 } | 982 } |
988 | 983 |
989 // After we call RestartWithAuth a new response_time will be recorded, and | |
990 // we need to be cautious about incorrectly logging the duration across the | |
991 // authentication activity. | |
992 if (result == OK) | |
993 LogTransactionConnectedMetrics(); | |
994 | |
995 // ERR_CONNECTION_CLOSED is treated differently at this point; if partial | 984 // ERR_CONNECTION_CLOSED is treated differently at this point; if partial |
996 // response headers were received, we do the best we can to make sense of it | 985 // response headers were received, we do the best we can to make sense of it |
997 // and send it back up the stack. | 986 // and send it back up the stack. |
998 // | 987 // |
999 // TODO(davidben): Consider moving this to HttpBasicStream, It's a little | 988 // TODO(davidben): Consider moving this to HttpBasicStream, It's a little |
1000 // bizarre for SPDY. Assuming this logic is useful at all. | 989 // bizarre for SPDY. Assuming this logic is useful at all. |
1001 // TODO(davidben): Bubble the error code up so we do not cache? | 990 // TODO(davidben): Bubble the error code up so we do not cache? |
1002 if (result == ERR_CONNECTION_CLOSED && response_.headers.get()) | 991 if (result == ERR_CONNECTION_CLOSED && response_.headers.get()) |
1003 result = OK; | 992 result = OK; |
1004 | 993 |
(...skipping 104 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1109 // ResponseHeaders. | 1098 // ResponseHeaders. |
1110 if (stream_->CanFindEndOfResponse()) { | 1099 if (stream_->CanFindEndOfResponse()) { |
1111 HttpResponseHeaders* headers = GetResponseHeaders(); | 1100 HttpResponseHeaders* headers = GetResponseHeaders(); |
1112 if (headers) | 1101 if (headers) |
1113 keep_alive = headers->IsKeepAlive(); | 1102 keep_alive = headers->IsKeepAlive(); |
1114 } | 1103 } |
1115 } | 1104 } |
1116 | 1105 |
1117 // Clean up connection if we are done. | 1106 // Clean up connection if we are done. |
1118 if (done) { | 1107 if (done) { |
1119 LogTransactionMetrics(); | |
1120 stream_->Close(!keep_alive); | 1108 stream_->Close(!keep_alive); |
1121 // Note: we don't reset the stream here. We've closed it, but we still | 1109 // Note: we don't reset the stream here. We've closed it, but we still |
1122 // need it around so that callers can call methods such as | 1110 // need it around so that callers can call methods such as |
1123 // GetUploadProgress() and have them be meaningful. | 1111 // GetUploadProgress() and have them be meaningful. |
1124 // TODO(mbelshe): This means we closed the stream here, and we close it | 1112 // TODO(mbelshe): This means we closed the stream here, and we close it |
1125 // again in ~HttpNetworkTransaction. Clean that up. | 1113 // again in ~HttpNetworkTransaction. Clean that up. |
1126 | 1114 |
1127 // The next Read call will return 0 (EOF). | 1115 // The next Read call will return 0 (EOF). |
1128 } | 1116 } |
1129 | 1117 |
(...skipping 31 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1161 if (done) { | 1149 if (done) { |
1162 DidDrainBodyForAuthRestart(keep_alive); | 1150 DidDrainBodyForAuthRestart(keep_alive); |
1163 } else { | 1151 } else { |
1164 // Keep draining. | 1152 // Keep draining. |
1165 next_state_ = STATE_DRAIN_BODY_FOR_AUTH_RESTART; | 1153 next_state_ = STATE_DRAIN_BODY_FOR_AUTH_RESTART; |
1166 } | 1154 } |
1167 | 1155 |
1168 return OK; | 1156 return OK; |
1169 } | 1157 } |
1170 | 1158 |
1171 void HttpNetworkTransaction::LogTransactionConnectedMetrics() { | |
1172 if (logged_response_time_) | |
1173 return; | |
1174 | |
1175 logged_response_time_ = true; | |
1176 | |
1177 base::TimeDelta total_duration = response_.response_time - start_time_; | |
1178 | |
1179 UMA_HISTOGRAM_CUSTOM_TIMES( | |
1180 "Net.Transaction_Connected", | |
1181 total_duration, | |
1182 base::TimeDelta::FromMilliseconds(1), base::TimeDelta::FromMinutes(10), | |
1183 100); | |
1184 | |
1185 bool reused_socket = stream_->IsConnectionReused(); | |
1186 if (!reused_socket) { | |
1187 UMA_HISTOGRAM_CUSTOM_TIMES( | |
1188 "Net.Transaction_Connected_New_b", | |
1189 total_duration, | |
1190 base::TimeDelta::FromMilliseconds(1), base::TimeDelta::FromMinutes(10), | |
1191 100); | |
1192 } | |
1193 | |
1194 // Currently, non-HIGHEST priority requests are frame or sub-frame resource | |
1195 // types. This will change when we also prioritize certain subresources like | |
1196 // css, js, etc. | |
1197 if (priority_ != HIGHEST) { | |
1198 UMA_HISTOGRAM_CUSTOM_TIMES( | |
1199 "Net.Priority_High_Latency_b", | |
1200 total_duration, | |
1201 base::TimeDelta::FromMilliseconds(1), base::TimeDelta::FromMinutes(10), | |
1202 100); | |
1203 } else { | |
1204 UMA_HISTOGRAM_CUSTOM_TIMES( | |
1205 "Net.Priority_Low_Latency_b", | |
1206 total_duration, | |
1207 base::TimeDelta::FromMilliseconds(1), base::TimeDelta::FromMinutes(10), | |
1208 100); | |
1209 } | |
1210 } | |
1211 | |
1212 void HttpNetworkTransaction::LogTransactionMetrics() const { | |
1213 base::TimeDelta duration = base::Time::Now() - | |
1214 response_.request_time; | |
1215 if (60 < duration.InMinutes()) | |
1216 return; | |
1217 | |
1218 base::TimeDelta total_duration = base::Time::Now() - start_time_; | |
1219 | |
1220 UMA_HISTOGRAM_CUSTOM_TIMES("Net.Transaction_Latency_b", duration, | |
1221 base::TimeDelta::FromMilliseconds(1), | |
1222 base::TimeDelta::FromMinutes(10), | |
1223 100); | |
1224 UMA_HISTOGRAM_CUSTOM_TIMES("Net.Transaction_Latency_Total", | |
1225 total_duration, | |
1226 base::TimeDelta::FromMilliseconds(1), | |
1227 base::TimeDelta::FromMinutes(10), 100); | |
1228 | |
1229 if (!stream_->IsConnectionReused()) { | |
1230 UMA_HISTOGRAM_CUSTOM_TIMES( | |
1231 "Net.Transaction_Latency_Total_New_Connection", | |
1232 total_duration, base::TimeDelta::FromMilliseconds(1), | |
1233 base::TimeDelta::FromMinutes(10), 100); | |
1234 } | |
1235 } | |
1236 | |
1237 int HttpNetworkTransaction::HandleCertificateRequest(int error) { | 1159 int HttpNetworkTransaction::HandleCertificateRequest(int error) { |
1238 // There are two paths through which the server can request a certificate | 1160 // There are two paths through which the server can request a certificate |
1239 // from us. The first is during the initial handshake, the second is | 1161 // from us. The first is during the initial handshake, the second is |
1240 // during SSL renegotiation. | 1162 // during SSL renegotiation. |
1241 // | 1163 // |
1242 // In both cases, we want to close the connection before proceeding. | 1164 // In both cases, we want to close the connection before proceeding. |
1243 // We do this for two reasons: | 1165 // We do this for two reasons: |
1244 // First, we don't want to keep the connection to the server hung for a | 1166 // First, we don't want to keep the connection to the server hung for a |
1245 // long time while the user selects a certificate. | 1167 // long time while the user selects a certificate. |
1246 // Second, even if we did keep the connection open, NSS has a bug where | 1168 // Second, even if we did keep the connection open, NSS has a bug where |
(...skipping 355 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1602 description = base::StringPrintf("Unknown state 0x%08X (%u)", state, | 1524 description = base::StringPrintf("Unknown state 0x%08X (%u)", state, |
1603 state); | 1525 state); |
1604 break; | 1526 break; |
1605 } | 1527 } |
1606 return description; | 1528 return description; |
1607 } | 1529 } |
1608 | 1530 |
1609 #undef STATE_CASE | 1531 #undef STATE_CASE |
1610 | 1532 |
1611 } // namespace net | 1533 } // namespace net |
OLD | NEW |