diff options
-rw-r--r-- | net/base/net_log_event_type_list.h | 28 | ||||
-rw-r--r-- | net/spdy/spdy_stream.cc | 57 |
2 files changed, 31 insertions, 54 deletions
diff --git a/net/base/net_log_event_type_list.h b/net/base/net_log_event_type_list.h index d47e575..35159d4 100644 --- a/net/base/net_log_event_type_list.h +++ b/net/base/net_log_event_type_list.h @@ -677,24 +677,20 @@ EVENT_TYPE(SPDY_SESSION_POOL_REMOVE_SESSION) // The begin and end of a SPDY STREAM. EVENT_TYPE(SPDY_STREAM) -// Logs that a stream attached to a pushed stream. -EVENT_TYPE(SPDY_STREAM_ADOPTED_PUSH_STREAM) +// Measures the time taken to send headers on a stream. +EVENT_TYPE(SPDY_STREAM_SEND_HEADERS) -// This event indicates that the send window has been updated -// { -// "id": <The stream id>, -// "delta": <The window size delta>, -// "new_window": <The new window size>, -// } -EVENT_TYPE(SPDY_STREAM_SEND_WINDOW_UPDATE) +// Measures the time taken to send the body (e.g. a POST) on a stream. +EVENT_TYPE(SPDY_STREAM_SEND_BODY) -// This event indicates that the recv window has been updated -// { -// "id": <The stream id>, -// "delta": <The window size delta>, -// "new_window": <The new window size>, -// } -EVENT_TYPE(SPDY_STREAM_RECV_WINDOW_UPDATE) +// Measures the time taken to send headers on a stream. +EVENT_TYPE(SPDY_STREAM_RECV_HEADERS) + +// Measures the time taken to read the body on a stream. +EVENT_TYPE(SPDY_STREAM_READ_BODY) + +// Logs that a stream attached to a pushed stream. +EVENT_TYPE(SPDY_STREAM_ADOPTED_PUSH_STREAM) // ------------------------------------------------------------------------ // HttpStreamParser diff --git a/net/spdy/spdy_stream.cc b/net/spdy/spdy_stream.cc index 88b009d..66ca694 100644 --- a/net/spdy/spdy_stream.cc +++ b/net/spdy/spdy_stream.cc @@ -7,35 +7,10 @@ #include "base/logging.h" #include "base/message_loop.h" #include "base/singleton.h" -#include "base/values.h" #include "net/spdy/spdy_session.h" namespace net { -namespace { - -class NetLogSpdyStreamWindowUpdateParameter : public NetLog::EventParameters { - public: - NetLogSpdyStreamWindowUpdateParameter(spdy::SpdyStreamId stream_id, - int delta, - int window_size) - : stream_id_(stream_id), delta_(delta), window_size_(window_size) {} - virtual Value* ToValue() const { - DictionaryValue* dict = new DictionaryValue(); - dict->SetInteger("id", static_cast<int>(stream_id_)); - dict->SetInteger("delta", delta_); - dict->SetInteger("window_size", window_size_); - return dict; - } - private: - const spdy::SpdyStreamId stream_id_; - const int delta_; - const int window_size_; - DISALLOW_COPY_AND_ASSIGN(NetLogSpdyStreamWindowUpdateParameter); -}; - -} - SpdyStream::SpdyStream(SpdySession* session, spdy::SpdyStreamId stream_id, bool pushed, @@ -146,11 +121,11 @@ void SpdyStream::IncreaseSendWindowSize(int delta_window_size) { return; } + LOG(INFO) << "Increasing stream " << stream_id_ + << " send_window_size_ [current:" << send_window_size_ << "]" + << " by " << delta_window_size << " bytes"; send_window_size_ = new_window_size; - net_log_.AddEvent(NetLog::TYPE_SPDY_STREAM_SEND_WINDOW_UPDATE, - new NetLogSpdyStreamWindowUpdateParameter(stream_id_, - delta_window_size, send_window_size_)); if (stalled_by_flow_control_) { stalled_by_flow_control_ = false; io_state_ = STATE_SEND_BODY; @@ -168,11 +143,10 @@ void SpdyStream::DecreaseSendWindowSize(int delta_window_size) { // this call to happen. DCHECK_GE(send_window_size_, delta_window_size); + LOG(INFO) << "Decreasing stream " << stream_id_ + << " send_window_size_ [current:" << send_window_size_ << "]" + << " by " << delta_window_size << " bytes"; send_window_size_ -= delta_window_size; - - net_log_.AddEvent(NetLog::TYPE_SPDY_STREAM_SEND_WINDOW_UPDATE, - new NetLogSpdyStreamWindowUpdateParameter(stream_id_, - -delta_window_size, send_window_size_)); } void SpdyStream::IncreaseRecvWindowSize(int delta_window_size) { @@ -184,20 +158,20 @@ void SpdyStream::IncreaseRecvWindowSize(int delta_window_size) { if (recv_window_size_ > 0) DCHECK(new_window_size > 0); + LOG(INFO) << "Increasing stream " << stream_id_ + << " recv_window_size_ [current:" << recv_window_size_ << "]" + << " by " << delta_window_size << " bytes"; recv_window_size_ = new_window_size; - net_log_.AddEvent(NetLog::TYPE_SPDY_STREAM_RECV_WINDOW_UPDATE, - new NetLogSpdyStreamWindowUpdateParameter(stream_id_, - delta_window_size, recv_window_size_)); session_->SendWindowUpdate(stream_id_, delta_window_size); } void SpdyStream::DecreaseRecvWindowSize(int delta_window_size) { DCHECK_GE(delta_window_size, 1); + LOG(INFO) << "Decreasing stream " << stream_id_ + << " recv_window_size_ [current:" << recv_window_size_ << "]" + << " by " << delta_window_size << " bytes"; recv_window_size_ -= delta_window_size; - net_log_.AddEvent(NetLog::TYPE_SPDY_STREAM_RECV_WINDOW_UPDATE, - new NetLogSpdyStreamWindowUpdateParameter(stream_id_, - -delta_window_size, recv_window_size_)); // Since we never decrease the initial window size, we should never hit // a negative |recv_window_size_|, if we do, it's a flow-control violation. @@ -216,6 +190,7 @@ void SpdyStream::SetRequestTime(base::Time t) { int SpdyStream::OnResponseReceived(const spdy::SpdyHeaderBlock& response) { int rv = OK; + LOG(INFO) << "Received response for stream " << stream_id_; metrics_.StartStream(); @@ -243,6 +218,8 @@ int SpdyStream::OnResponseReceived(const spdy::SpdyHeaderBlock& response) { void SpdyStream::OnDataReceived(const char* data, int length) { DCHECK_GE(length, 0); + LOG(INFO) << "SpdyStream: Data (" << length << " bytes) received for " + << stream_id_; if (!delegate_ || continue_buffering_data_) { // It should be valid for this to happen in the server push case. @@ -362,16 +339,20 @@ int SpdyStream::DoLoop(int result) { // State machine 1: Send headers and body. case STATE_SEND_HEADERS: CHECK_EQ(OK, result); + net_log_.BeginEvent(NetLog::TYPE_SPDY_STREAM_SEND_HEADERS, NULL); result = DoSendHeaders(); break; case STATE_SEND_HEADERS_COMPLETE: + net_log_.EndEvent(NetLog::TYPE_SPDY_STREAM_SEND_HEADERS, NULL); result = DoSendHeadersComplete(result); break; case STATE_SEND_BODY: CHECK_EQ(OK, result); + net_log_.BeginEvent(NetLog::TYPE_SPDY_STREAM_SEND_BODY, NULL); result = DoSendBody(); break; case STATE_SEND_BODY_COMPLETE: + net_log_.EndEvent(NetLog::TYPE_SPDY_STREAM_SEND_BODY, NULL); result = DoSendBodyComplete(result); break; // This is an intermediary waiting state. This state is reached when all |