diff options
Diffstat (limited to 'chromium/net/http/bidirectional_stream.cc')
| -rw-r--r-- | chromium/net/http/bidirectional_stream.cc | 128 |
1 files changed, 102 insertions, 26 deletions
diff --git a/chromium/net/http/bidirectional_stream.cc b/chromium/net/http/bidirectional_stream.cc index c514da32539..8153044933f 100644 --- a/chromium/net/http/bidirectional_stream.cc +++ b/chromium/net/http/bidirectional_stream.cc @@ -11,8 +11,8 @@ #include "base/location.h" #include "base/logging.h" #include "base/memory/ptr_util.h" +#include "base/metrics/histogram_macros.h" #include "base/threading/thread_task_runner_handle.h" -#include "base/time/time.h" #include "base/timer/timer.h" #include "base/values.h" #include "net/base/load_flags.h" @@ -22,7 +22,10 @@ #include "net/http/http_network_session.h" #include "net/http/http_response_headers.h" #include "net/http/http_stream.h" +#include "net/log/net_log.h" #include "net/log/net_log_capture_mode.h" +#include "net/log/net_log_event_type.h" +#include "net/log/net_log_source_type.h" #include "net/spdy/spdy_header_block.h" #include "net/spdy/spdy_http_utils.h" #include "net/ssl/ssl_cert_request_info.h" @@ -70,7 +73,7 @@ BidirectionalStream::BidirectionalStream( session, send_request_headers_automatically, delegate, - base::WrapUnique(new base::Timer(false, false))) {} + base::MakeUnique<base::Timer>(false, false)) {} BidirectionalStream::BidirectionalStream( std::unique_ptr<BidirectionalStreamRequestInfo> request_info, @@ -79,8 +82,8 @@ BidirectionalStream::BidirectionalStream( Delegate* delegate, std::unique_ptr<base::Timer> timer) : request_info_(std::move(request_info)), - net_log_(BoundNetLog::Make(session->net_log(), - NetLog::SOURCE_BIDIRECTIONAL_STREAM)), + net_log_(NetLogWithSource::Make(session->net_log(), + NetLogSourceType::BIDIRECTIONAL_STREAM)), session_(session), send_request_headers_automatically_(send_request_headers_automatically), request_headers_sent_(false), @@ -90,9 +93,13 @@ BidirectionalStream::BidirectionalStream( DCHECK(delegate_); DCHECK(request_info_); + // Start time should be measured before connect. + load_timing_info_.request_start_time = base::Time::Now(); + load_timing_info_.request_start = base::TimeTicks::Now(); + if (net_log_.IsCapturing()) { net_log_.BeginEvent( - NetLog::TYPE_BIDIRECTIONAL_STREAM_ALIVE, + NetLogEventType::BIDIRECTIONAL_STREAM_ALIVE, base::Bind(&NetLogCallback, &request_info_->url, &request_info_->method, base::Unretained(&request_info_->extra_headers))); } @@ -100,7 +107,6 @@ BidirectionalStream::BidirectionalStream( SSLConfig server_ssl_config; session->ssl_config_service()->GetSSLConfig(&server_ssl_config); session->GetAlpnProtos(&server_ssl_config.alpn_protos); - session->GetNpnProtos(&server_ssl_config.npn_protos); if (!request_info_->url.SchemeIs(url::kHttpsScheme)) { base::ThreadTaskRunnerHandle::Get()->PostTask( @@ -126,9 +132,9 @@ BidirectionalStream::BidirectionalStream( } BidirectionalStream::~BidirectionalStream() { - Cancel(); + UpdateHistograms(); if (net_log_.IsCapturing()) { - net_log_.EndEvent(NetLog::TYPE_BIDIRECTIONAL_STREAM_ALIVE); + net_log_.EndEvent(NetLogEventType::BIDIRECTIONAL_STREAM_ALIVE); } } @@ -145,12 +151,17 @@ int BidirectionalStream::ReadData(IOBuffer* buf, int buf_len) { int rv = stream_impl_->ReadData(buf, buf_len); if (rv > 0) { + read_end_time_ = base::TimeTicks::Now(); net_log_.AddByteTransferEvent( - NetLog::TYPE_BIDIRECTIONAL_STREAM_BYTES_RECEIVED, rv, buf->data()); + NetLogEventType::BIDIRECTIONAL_STREAM_BYTES_RECEIVED, rv, buf->data()); } else if (rv == ERR_IO_PENDING) { read_buffer_ = buf; // Bytes will be logged in OnDataRead(). } + if (net_log_.IsCapturing()) { + net_log_.AddEvent(NetLogEventType::BIDIRECTIONAL_STREAM_READ_DATA, + NetLog::IntCallback("rv", rv)); + } return rv; } @@ -161,6 +172,9 @@ void BidirectionalStream::SendData(const scoped_refptr<IOBuffer>& data, DCHECK(write_buffer_list_.empty()); DCHECK(write_buffer_len_list_.empty()); + if (net_log_.IsCapturing()) { + net_log_.AddEvent(NetLogEventType::BIDIRECTIONAL_STREAM_SEND_DATA); + } stream_impl_->SendData(data, length, end_stream); write_buffer_list_.push_back(data); write_buffer_len_list_.push_back(length); @@ -175,6 +189,10 @@ void BidirectionalStream::SendvData( DCHECK(write_buffer_list_.empty()); DCHECK(write_buffer_len_list_.empty()); + if (net_log_.IsCapturing()) { + net_log_.AddEvent(NetLogEventType::BIDIRECTIONAL_STREAM_SENDV_DATA, + NetLog::IntCallback("num_buffers", buffers.size())); + } stream_impl_->SendvData(buffers, lengths, end_stream); for (size_t i = 0; i < buffers.size(); ++i) { write_buffer_list_.push_back(buffers[i]); @@ -182,14 +200,6 @@ void BidirectionalStream::SendvData( } } -void BidirectionalStream::Cancel() { - stream_request_.reset(); - if (stream_impl_) { - stream_impl_->Cancel(); - stream_impl_.reset(); - } -} - NextProto BidirectionalStream::GetProtocol() const { if (!stream_impl_) return kProtoUnknown; @@ -211,28 +221,46 @@ int64_t BidirectionalStream::GetTotalSentBytes() const { return stream_impl_->GetTotalSentBytes(); } +void BidirectionalStream::GetLoadTimingInfo( + LoadTimingInfo* load_timing_info) const { + *load_timing_info = load_timing_info_; +} + void BidirectionalStream::OnStreamReady(bool request_headers_sent) { request_headers_sent_ = request_headers_sent; if (net_log_.IsCapturing()) { net_log_.AddEvent( - NetLog::TYPE_BIDIRECTIONAL_STREAM_READY, + NetLogEventType::BIDIRECTIONAL_STREAM_READY, NetLog::BoolCallback("request_headers_sent", request_headers_sent)); } + load_timing_info_.send_start = base::TimeTicks::Now(); + load_timing_info_.send_end = load_timing_info_.send_start; delegate_->OnStreamReady(request_headers_sent); } void BidirectionalStream::OnHeadersReceived( const SpdyHeaderBlock& response_headers) { HttpResponseInfo response_info; - if (!SpdyHeadersToHttpResponse(response_headers, HTTP2, &response_info)) { + if (!SpdyHeadersToHttpResponse(response_headers, &response_info)) { DLOG(WARNING) << "Invalid headers"; NotifyFailed(ERR_FAILED); return; } if (net_log_.IsCapturing()) { - net_log_.AddEvent(NetLog::TYPE_BIDIRECTIONAL_STREAM_RECV_HEADERS, + net_log_.AddEvent(NetLogEventType::BIDIRECTIONAL_STREAM_RECV_HEADERS, base::Bind(&NetLogHeadersCallback, &response_headers)); } + // Impl should only provide |connect_timing| and |socket_reused| info, + // so use a copy to get these information only. + LoadTimingInfo impl_load_timing_info; + bool has_load_timing = + stream_impl_->GetLoadTimingInfo(&impl_load_timing_info); + if (has_load_timing) { + load_timing_info_.connect_timing = impl_load_timing_info.connect_timing; + load_timing_info_.socket_reused = impl_load_timing_info.socket_reused; + } + load_timing_info_.receive_headers_end = base::TimeTicks::Now(); + read_end_time_ = load_timing_info_.receive_headers_end; session_->http_stream_factory()->ProcessAlternativeServices( session_, response_info.headers.get(), url::SchemeHostPort(request_info_->url)); @@ -244,9 +272,10 @@ void BidirectionalStream::OnDataRead(int bytes_read) { if (net_log_.IsCapturing()) { net_log_.AddByteTransferEvent( - NetLog::TYPE_BIDIRECTIONAL_STREAM_BYTES_RECEIVED, bytes_read, + NetLogEventType::BIDIRECTIONAL_STREAM_BYTES_RECEIVED, bytes_read, read_buffer_->data()); } + read_end_time_ = base::TimeTicks::Now(); read_buffer_ = nullptr; delegate_->OnDataRead(bytes_read); } @@ -258,19 +287,21 @@ void BidirectionalStream::OnDataSent() { if (net_log_.IsCapturing()) { if (write_buffer_list_.size() > 1) { net_log_.BeginEvent( - NetLog::TYPE_BIDIRECTIONAL_STREAM_BYTES_SENT_COALESCED, + NetLogEventType::BIDIRECTIONAL_STREAM_BYTES_SENT_COALESCED, NetLog::IntCallback("num_buffers_coalesced", write_buffer_list_.size())); } for (size_t i = 0; i < write_buffer_list_.size(); ++i) { net_log_.AddByteTransferEvent( - NetLog::TYPE_BIDIRECTIONAL_STREAM_BYTES_SENT, + NetLogEventType::BIDIRECTIONAL_STREAM_BYTES_SENT, write_buffer_len_list_[i], write_buffer_list_[i]->data()); } if (write_buffer_list_.size() > 1) { - net_log_.EndEvent(NetLog::TYPE_BIDIRECTIONAL_STREAM_BYTES_SENT_COALESCED); + net_log_.EndEvent( + NetLogEventType::BIDIRECTIONAL_STREAM_BYTES_SENT_COALESCED); } } + load_timing_info_.send_end = base::TimeTicks::Now(); write_buffer_list_.clear(); write_buffer_len_list_.clear(); delegate_->OnDataSent(); @@ -278,15 +309,16 @@ void BidirectionalStream::OnDataSent() { void BidirectionalStream::OnTrailersReceived(const SpdyHeaderBlock& trailers) { if (net_log_.IsCapturing()) { - net_log_.AddEvent(NetLog::TYPE_BIDIRECTIONAL_STREAM_RECV_TRAILERS, + net_log_.AddEvent(NetLogEventType::BIDIRECTIONAL_STREAM_RECV_TRAILERS, base::Bind(&NetLogHeadersCallback, &trailers)); } + read_end_time_ = base::TimeTicks::Now(); delegate_->OnTrailersReceived(trailers); } void BidirectionalStream::OnFailed(int status) { if (net_log_.IsCapturing()) { - net_log_.AddEvent(NetLog::TYPE_BIDIRECTIONAL_STREAM_FAILED, + net_log_.AddEvent(NetLogEventType::BIDIRECTIONAL_STREAM_FAILED, NetLog::IntCallback("net_error", status)); } NotifyFailed(status); @@ -370,4 +402,48 @@ void BidirectionalStream::NotifyFailed(int error) { delegate_->OnFailed(error); } +void BidirectionalStream::UpdateHistograms() { + // If the request failed before response is started, treat the metrics as + // bogus and skip logging. + if (load_timing_info_.request_start.is_null() || + load_timing_info_.receive_headers_end.is_null() || + read_end_time_.is_null() || load_timing_info_.send_start.is_null() || + load_timing_info_.send_end.is_null()) { + return; + } + if (GetProtocol() == kProtoHTTP2) { + UMA_HISTOGRAM_TIMES("Net.BidirectionalStream.TimeToReadStart.HTTP2", + load_timing_info_.receive_headers_end - + load_timing_info_.request_start); + UMA_HISTOGRAM_TIMES("Net.BidirectionalStream.TimeToReadEnd.HTTP2", + read_end_time_ - load_timing_info_.request_start); + UMA_HISTOGRAM_TIMES( + "Net.BidirectionalStream.TimeToSendStart.HTTP2", + load_timing_info_.send_start - load_timing_info_.request_start); + UMA_HISTOGRAM_TIMES( + "Net.BidirectionalStream.TimeToSendEnd.HTTP2", + load_timing_info_.send_end - load_timing_info_.request_start); + UMA_HISTOGRAM_COUNTS("Net.BidirectionalStream.ReceivedBytes.HTTP2", + stream_impl_->GetTotalReceivedBytes()); + UMA_HISTOGRAM_COUNTS("Net.BidirectionalStream.SentBytes.HTTP2", + stream_impl_->GetTotalSentBytes()); + } else if (GetProtocol() == kProtoQUIC1SPDY3) { + UMA_HISTOGRAM_TIMES("Net.BidirectionalStream.TimeToReadStart.QUIC", + load_timing_info_.receive_headers_end - + load_timing_info_.request_start); + UMA_HISTOGRAM_TIMES("Net.BidirectionalStream.TimeToReadEnd.QUIC", + read_end_time_ - load_timing_info_.request_start); + UMA_HISTOGRAM_TIMES( + "Net.BidirectionalStream.TimeToSendStart.QUIC", + load_timing_info_.send_start - load_timing_info_.request_start); + UMA_HISTOGRAM_TIMES( + "Net.BidirectionalStream.TimeToSendEnd.QUIC", + load_timing_info_.send_end - load_timing_info_.request_start); + UMA_HISTOGRAM_COUNTS("Net.BidirectionalStream.ReceivedBytes.QUIC", + stream_impl_->GetTotalReceivedBytes()); + UMA_HISTOGRAM_COUNTS("Net.BidirectionalStream.SentBytes.QUIC", + stream_impl_->GetTotalSentBytes()); + } +} + } // namespace net |