diff options
author | akalin@chromium.org <akalin@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2013-04-19 22:17:42 +0000 |
---|---|---|
committer | akalin@chromium.org <akalin@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2013-04-19 22:17:42 +0000 |
commit | b2e5209c5ab4e429292b0577e5b62aabb0422ee9 (patch) | |
tree | fcffa689c9d7b6d4c92c05dd2fb3a6e39d7680bd /net | |
parent | 3a7eba03f8d6bc0aa781c881747a0e48f5c0da07 (diff) | |
download | chromium_src-b2e5209c5ab4e429292b0577e5b62aabb0422ee9.zip chromium_src-b2e5209c5ab4e429292b0577e5b62aabb0422ee9.tar.gz chromium_src-b2e5209c5ab4e429292b0577e5b62aabb0422ee9.tar.bz2 |
[SPDY] Close SPDY sessions on session flow control errors
But just emit something to NetLog for errors in a SETTINGS
frame.
Treat the receive window going negative as a valid error for SpdyStream.
Remove net:: prefix from spdy_{session,stream}.*.
Update some enums in histograms.xml.
BUG=176592
Review URL: https://codereview.chromium.org/14348012
git-svn-id: svn://svn.chromium.org/chrome/trunk/src@195309 0039d316-1c4b-4281-b951-d872f2087c98
Diffstat (limited to 'net')
-rw-r--r-- | net/base/net_error_list.h | 2 | ||||
-rw-r--r-- | net/base/net_log_event_type_list.h | 13 | ||||
-rw-r--r-- | net/spdy/spdy_session.cc | 105 | ||||
-rw-r--r-- | net/spdy/spdy_session.h | 22 | ||||
-rw-r--r-- | net/spdy/spdy_stream.cc | 19 |
5 files changed, 88 insertions, 73 deletions
diff --git a/net/base/net_error_list.h b/net/base/net_error_list.h index f0bb1b2..ff6e347 100644 --- a/net/base/net_error_list.h +++ b/net/base/net_error_list.h @@ -465,7 +465,7 @@ NET_ERROR(INVALID_SPDY_STREAM, -335) // There are no supported proxies in the provided list. NET_ERROR(NO_SUPPORTED_PROXIES, -336) -// There is a SPDY protocol framing error. +// There is a SPDY protocol error. NET_ERROR(SPDY_PROTOCOL_ERROR, -337) // Credentials could not be established during HTTP Authentication. diff --git a/net/base/net_log_event_type_list.h b/net/base/net_log_event_type_list.h index 424be18..3bfe4fd 100644 --- a/net/base/net_log_event_type_list.h +++ b/net/base/net_log_event_type_list.h @@ -1125,10 +1125,10 @@ EVENT_TYPE(SPDY_SESSION_SEND_DATA) // } EVENT_TYPE(SPDY_SESSION_RECV_DATA) -// Logs that a stream is stalled by the session send window being closed. +// A stream is stalled by the session send window being closed. EVENT_TYPE(SPDY_SESSION_STREAM_STALLED_BY_SESSION_SEND_WINDOW) -// Logs that a stream is stalled by its send window being closed. +// A stream is stalled by its send window being closed. EVENT_TYPE(SPDY_SESSION_STREAM_STALLED_BY_STREAM_SEND_WINDOW) // Session is closing @@ -1142,11 +1142,16 @@ EVENT_TYPE(SPDY_SESSION_CLOSE) // the maximum number of concurrent streams. EVENT_TYPE(SPDY_SESSION_STALLED_MAX_STREAMS) -// Received a negative value for initial window size in SETTINGS frame. +// Received a value for initial window size in SETTINGS frame with +// flow control turned off. +EVENT_TYPE(SPDY_SESSION_INITIAL_WINDOW_SIZE_NO_FLOW_CONTROL) + +// Received an out-of-range value for initial window size in SETTINGS +// frame. // { // "initial_window_size" : <The initial window size>, // } -EVENT_TYPE(SPDY_SESSION_NEGATIVE_INITIAL_WINDOW_SIZE) +EVENT_TYPE(SPDY_SESSION_INITIAL_WINDOW_SIZE_OUT_OF_RANGE) // Updating streams send window size by the delta window size. // { diff --git a/net/spdy/spdy_session.cc b/net/spdy/spdy_session.cc index 6688b1e..eba4375 100644 --- a/net/spdy/spdy_session.cc +++ b/net/spdy/spdy_session.cc @@ -17,9 +17,9 @@ #include "base/metrics/sparse_histogram.h" #include "base/metrics/stats_counters.h" #include "base/stl_util.h" -#include "base/string_number_conversions.h" #include "base/string_util.h" #include "base/stringprintf.h" +#include "base/strings/string_number_conversions.h" #include "base/time.h" #include "base/utf_string_conversions.h" #include "base/values.h" @@ -374,7 +374,7 @@ SpdySession::~SpdySession() { state_ = STATE_CLOSED; // Cleanup all the streams. - CloseAllStreams(net::ERR_ABORTED); + CloseAllStreams(ERR_ABORTED); } if (connection_->is_initialized()) { @@ -396,7 +396,7 @@ SpdySession::~SpdySession() { net_log_.EndEvent(NetLog::TYPE_SPDY_SESSION); } -net::Error SpdySession::InitializeWithSocket( +Error SpdySession::InitializeWithSocket( ClientSocketHandle* connection, bool is_secure, int certificate_error_code) { @@ -457,7 +457,7 @@ net::Error SpdySession::InitializeWithSocket( int error = DoLoop(OK); if (error == ERR_IO_PENDING) return OK; - return static_cast<net::Error>(error); + return static_cast<Error>(error); } bool SpdySession::VerifyDomainAuthentication(const std::string& domain) { @@ -496,7 +496,7 @@ int SpdySession::GetPushStream( RecordProtocolErrorHistogram( PROTOCOL_ERROR_REQUEST_FOR_SECURE_CONTENT_OVER_INSECURE_SESSION); CloseSessionOnError( - static_cast<net::Error>(certificate_error_code_), + static_cast<Error>(certificate_error_code_), true, "Tried to get SPDY stream for secure content over an unauthenticated " "session."); @@ -537,7 +537,7 @@ int SpdySession::CreateStream(const SpdyStreamRequest& request, RecordProtocolErrorHistogram( PROTOCOL_ERROR_REQUEST_FOR_SECURE_CONTENT_OVER_INSECURE_SESSION); CloseSessionOnError( - static_cast<net::Error>(certificate_error_code_), + static_cast<Error>(certificate_error_code_), true, "Tried to create SPDY stream for secure content over an " "unauthenticated session."); @@ -740,7 +740,7 @@ scoped_ptr<SpdyFrame> SpdySession::CreateHeadersFrame( } scoped_ptr<SpdyBuffer> SpdySession::CreateDataBuffer(SpdyStreamId stream_id, - net::IOBuffer* data, + IOBuffer* data, int len, SpdyDataFlags flags) { // Find our stream. @@ -885,7 +885,7 @@ void SpdySession::ResetStream(SpdyStreamId stream_id, buffered_spdy_framer_->CreateRstStream(stream_id, status)); // Default to lowest priority unless we know otherwise. - RequestPriority priority = net::IDLE; + RequestPriority priority = IDLE; if (IsStreamActive(stream_id)) { scoped_refptr<SpdyStream> stream = active_streams_[stream_id]; priority = stream->priority(); @@ -982,7 +982,7 @@ int SpdySession::DoReadComplete(int result) { if (result <= 0) { // Session is tearing down. - net::Error error = static_cast<net::Error>(result); + Error error = static_cast<Error>(result); if (result == 0) { UMA_HISTOGRAM_CUSTOM_COUNTS("Net.SpdySession.BytesRead.EOF", total_bytes_received_, 1, 100000000, 50); @@ -1046,8 +1046,8 @@ void SpdySession::OnWriteComplete(int result) { // We only notify the stream when we've fully written the pending frame. if (in_flight_write_->GetRemainingSize() == 0) { - // It is possible that the stream was cancelled while we were - // writing to the socket. + // It is possible that the stream was cancelled while we were + // writing to the socket. if (in_flight_write_stream_ && !in_flight_write_stream_->cancelled()) { DCHECK_GT(in_flight_write_frame_size_, 0u); in_flight_write_stream_->OnFrameWriteComplete( @@ -1143,9 +1143,8 @@ void SpdySession::WriteSocket() { write_pending_ = true; // Explicitly store in a scoped_refptr<IOBuffer> to avoid problems - // with net::Socket implementations that don't store their - // IOBuffer argument in a scoped_refptr<IOBuffer> (see - // crbug.com/232345). + // with Socket implementations that don't store their IOBuffer + // argument in a scoped_refptr<IOBuffer> (see crbug.com/232345). scoped_refptr<IOBuffer> write_io_buffer = in_flight_write_->GetIOBufferForRemainingData(); // We keep |in_flight_write_| alive until OnWriteComplete(), so @@ -1158,7 +1157,7 @@ void SpdySession::WriteSocket() { // Avoid persisting |write_io_buffer| past |in_flight_write_|'s // lifetime (which will end if OnWriteComplete() is called below). write_io_buffer = NULL; - if (rv == net::ERR_IO_PENDING) + if (rv == ERR_IO_PENDING) break; // We sent the frame successfully. @@ -1172,7 +1171,7 @@ void SpdySession::WriteSocket() { } void SpdySession::CloseAllStreamsAfter(SpdyStreamId last_good_stream_id, - net::Error status) { + Error status) { for (int i = 0; i < NUM_PRIORITIES; ++i) { PendingStreamRequestQueue queue; queue.swap(pending_create_stream_queues_[i]); @@ -1203,7 +1202,7 @@ void SpdySession::CloseAllStreamsAfter(SpdyStreamId last_good_stream_id, write_queue_.RemovePendingWritesForStreamsAfter(last_good_stream_id); } -void SpdySession::CloseAllStreams(net::Error status) { +void SpdySession::CloseAllStreams(Error status) { base::StatsCounter abandoned_streams("spdy.abandoned_streams"); base::StatsCounter abandoned_push_streams( "spdy.abandoned_push_streams"); @@ -1219,7 +1218,7 @@ void SpdySession::CloseAllStreams(net::Error status) { } void SpdySession::LogAbandonedStream(const scoped_refptr<SpdyStream>& stream, - net::Error status) { + Error status) { DCHECK(stream); std::string description = base::StringPrintf( "ABANDONED (stream_id=%d): ", stream->stream_id()) + stream->path(); @@ -1234,7 +1233,7 @@ int SpdySession::GetNewStreamId() { return id; } -void SpdySession::CloseSessionOnError(net::Error err, +void SpdySession::CloseSessionOnError(Error err, bool remove_from_pool, const std::string& description) { // Closing all streams can have a side-effect of dropping the last reference @@ -1459,7 +1458,7 @@ void SpdySession::OnError(SpdyFramer::SpdyError error_code) { static_cast<SpdyProtocolErrorDetails>(error_code)); std::string description = base::StringPrintf( "SPDY_ERROR error_code: %d.", error_code); - CloseSessionOnError(net::ERR_SPDY_PROTOCOL_ERROR, true, description); + CloseSessionOnError(ERR_SPDY_PROTOCOL_ERROR, true, description); } void SpdySession::OnStreamError(SpdyStreamId stream_id, @@ -1792,7 +1791,7 @@ void SpdySession::OnGoAway(SpdyStreamId last_accepted_stream_id, unclaimed_pushed_streams_.size(), status)); RemoveFromPool(); - CloseAllStreamsAfter(last_accepted_stream_id, net::ERR_ABORTED); + CloseAllStreamsAfter(last_accepted_stream_id, ERR_ABORTED); } void SpdySession::OnPing(uint32 unique_id) { @@ -1810,7 +1809,7 @@ void SpdySession::OnPing(uint32 unique_id) { if (pings_in_flight_ < 0) { RecordProtocolErrorHistogram(PROTOCOL_ERROR_UNEXPECTED_PING); CloseSessionOnError( - net::ERR_SPDY_PROTOCOL_ERROR, true, "pings_in_flight_ is < 0."); + ERR_SPDY_PROTOCOL_ERROR, true, "pings_in_flight_ is < 0."); pings_in_flight_ = 0; return; } @@ -1852,10 +1851,12 @@ void SpdySession::OnWindowUpdate(SpdyStreamId stream_id, if (delta_window_size < 1u) { if (stream_id == kSessionFlowControlStreamId) { - LOG(WARNING) << "Received session WINDOW_UPDATE with an " - << "invalid delta_window_size " << delta_window_size; - // TODO(akalin): Figure out whether we should instead send a - // GOAWAY and close the connection here. + RecordProtocolErrorHistogram(PROTOCOL_ERROR_INVALID_WINDOW_UPDATE_SIZE); + CloseSessionOnError( + ERR_SPDY_PROTOCOL_ERROR, + true, + "Received WINDOW_UPDATE with an invalid delta_window_size " + + base::UintToString(delta_window_size)); } else { ResetStream(stream_id, RST_STREAM_FLOW_CONTROL_ERROR, base::StringPrintf( @@ -1979,23 +1980,22 @@ void SpdySession::HandleSetting(uint32 id, uint32 value) { break; case SETTINGS_INITIAL_WINDOW_SIZE: { if (flow_control_state_ < FLOW_CONTROL_STREAM) { - LOG(WARNING) << "SETTINGS_INITIAL_WINDOW_SIZE setting received " - << "when flow control is turned off"; - // TODO(akalin): Figure out whether we should instead send a - // GOAWAY and close the connection here. + net_log().AddEvent( + NetLog::TYPE_SPDY_SESSION_INITIAL_WINDOW_SIZE_NO_FLOW_CONTROL); return; } - if (static_cast<int32>(value) < 0) { + if (value > static_cast<uint32>(kint32max)) { net_log().AddEvent( - NetLog::TYPE_SPDY_SESSION_NEGATIVE_INITIAL_WINDOW_SIZE, + NetLog::TYPE_SPDY_SESSION_INITIAL_WINDOW_SIZE_OUT_OF_RANGE, NetLog::IntegerCallback("initial_window_size", value)); return; } // SETTINGS_INITIAL_WINDOW_SIZE updates initial_send_window_size_ only. - int32 delta_window_size = value - stream_initial_send_window_size_; - stream_initial_send_window_size_ = value; + int32 delta_window_size = + static_cast<int32>(value) - stream_initial_send_window_size_; + stream_initial_send_window_size_ = static_cast<int32>(value); UpdateStreamsSendWindowSize(delta_window_size); net_log().AddEvent( NetLog::TYPE_SPDY_SESSION_UPDATE_STREAMS_SEND_WINDOW_SIZE, @@ -2101,7 +2101,7 @@ void SpdySession::CheckPingStatus(base::TimeTicks last_check_time) { base::TimeDelta delay = hung_interval_ - (now - last_activity_time_); if (delay.InMilliseconds() < 0 || last_activity_time_ < last_check_time) { - CloseSessionOnError(net::ERR_SPDY_PING_FAILED, true, "Failed ping."); + CloseSessionOnError(ERR_SPDY_PING_FAILED, true, "Failed ping."); // Track all failed PING messages in a separate bucket. const base::TimeDelta kFailedPing = base::TimeDelta::FromInternalValue(INT_MAX); @@ -2123,10 +2123,10 @@ void SpdySession::RecordPingRTTHistogram(base::TimeDelta duration) { void SpdySession::RecordProtocolErrorHistogram( SpdyProtocolErrorDetails details) { - UMA_HISTOGRAM_ENUMERATION("Net.SpdySessionErrorDetails", details, + UMA_HISTOGRAM_ENUMERATION("Net.SpdySessionErrorDetails2", details, NUM_SPDY_PROTOCOL_ERROR_DETAILS); if (EndsWith(host_port_pair().host(), "google.com", false)) { - UMA_HISTOGRAM_ENUMERATION("Net.SpdySessionErrorDetails_Google", details, + UMA_HISTOGRAM_ENUMERATION("Net.SpdySessionErrorDetails_Google2", details, NUM_SPDY_PROTOCOL_ERROR_DETAILS); } } @@ -2250,12 +2250,14 @@ void SpdySession::IncreaseSendWindowSize(int32 delta_window_size) { // Check for overflow. int32 max_delta_window_size = kint32max - session_send_window_size_; if (delta_window_size > max_delta_window_size) { - LOG(WARNING) << "Received WINDOW_UPDATE [delta: " - << delta_window_size - << "] for session overflows session_send_window_size_ " - << "[current: " << session_send_window_size_ << "]"; - // TODO(akalin): Figure out whether we should instead send a - // GOAWAY and close the connection here. + RecordProtocolErrorHistogram(PROTOCOL_ERROR_INVALID_WINDOW_UPDATE_SIZE); + CloseSessionOnError( + ERR_SPDY_PROTOCOL_ERROR, + true, + "Received WINDOW_UPDATE [delta: " + + base::IntToString(delta_window_size) + + "] for session overflows session_send_window_size_ [current: " + + base::IntToString(session_send_window_size_) + "]"); return; } @@ -2326,14 +2328,17 @@ void SpdySession::DecreaseRecvWindowSize(int32 delta_window_size) { DCHECK_EQ(flow_control_state_, FLOW_CONTROL_STREAM_AND_SESSION); DCHECK_GE(delta_window_size, 1); - // |delta_window_size| should never cause - // |session_recv_window_size_| to go negative. If we do, it's a - // client-side bug. + // Since we never decrease the initial receive window size, + // |delta_window_size| should never cause |recv_window_size_| to go + // negative. If we do, the receive window isn't being respected. if (delta_window_size > session_recv_window_size_) { - NOTREACHED() << "Received session WINDOW_UPDATE with an " - << "invalid delta_window_size " << delta_window_size; - // TODO(akalin): Figure out whether we should instead send a - // GOAWAY and close the connection here. + RecordProtocolErrorHistogram(PROTOCOL_ERROR_RECEIVE_WINDOW_VIOLATION); + CloseSessionOnError( + ERR_SPDY_PROTOCOL_ERROR, + true, + "delta_window_size is " + base::IntToString(delta_window_size) + + " in DecreaseRecvWindowSize, which is larger than the receive " + + "window size of " + base::IntToString(session_recv_window_size_)); return; } diff --git a/net/spdy/spdy_session.h b/net/spdy/spdy_session.h index 42ff8c4..4368e3c 100644 --- a/net/spdy/spdy_session.h +++ b/net/spdy/spdy_session.h @@ -60,6 +60,8 @@ struct LoadTimingInfo; class SpdyStream; class SSLInfo; +// NOTE: There's an enum of the same name (also with numeric suffixes) +// in histograms.xml. enum SpdyProtocolErrorDetails { // SpdyFramer::SpdyErrors SPDY_ERROR_NO_ERROR, @@ -93,6 +95,8 @@ enum SpdyProtocolErrorDetails { PROTOCOL_ERROR_SPDY_COMPRESSION_FAILURE, PROTOCOL_ERROR_REQUEST_FOR_SECURE_CONTENT_OVER_INSECURE_SESSION, PROTOCOL_ERROR_SYN_REPLY_NOT_RECEIVED, + PROTOCOL_ERROR_INVALID_WINDOW_UPDATE_SIZE, + PROTOCOL_ERROR_RECEIVE_WINDOW_VIOLATION, NUM_SPDY_PROTOCOL_ERROR_DETAILS }; @@ -225,9 +229,9 @@ class NET_EXPORT SpdySession : public base::RefCounted<SpdySession>, // testing, setting is_secure to false allows initialization with a // pre-existing TCP socket. // Returns OK on success, or an error on failure. - net::Error InitializeWithSocket(ClientSocketHandle* connection, - bool is_secure, - int certificate_error_code); + Error InitializeWithSocket(ClientSocketHandle* connection, + bool is_secure, + int certificate_error_code); // Check to see if this SPDY session can support an additional domain. // If the session is un-authenticated, then this call always returns true. @@ -274,7 +278,7 @@ class NET_EXPORT SpdySession : public base::RefCounted<SpdySession>, // Creates and returns a SpdyBuffer holding a data frame with the // given data. May return NULL if stalled by flow control. scoped_ptr<SpdyBuffer> CreateDataBuffer(SpdyStreamId stream_id, - net::IOBuffer* data, + IOBuffer* data, int len, SpdyDataFlags flags); @@ -326,7 +330,7 @@ class NET_EXPORT SpdySession : public base::RefCounted<SpdySession>, // |remove_from_pool| indicates whether to also remove the session from the // session pool. // |description| indicates the reason for the error. - void CloseSessionOnError(net::Error err, + void CloseSessionOnError(Error err, bool remove_from_pool, const std::string& description); @@ -608,14 +612,14 @@ class NET_EXPORT SpdySession : public base::RefCounted<SpdySession>, // |last_good_stream_id|, as well as any created or pending streams. // Does not close unclaimed push streams. void CloseAllStreamsAfter(SpdyStreamId last_good_stream_id, - net::Error status); + Error status); // Closes all streams, including unclaimed push streams. Used as part of // shutdown. - void CloseAllStreams(net::Error status); + void CloseAllStreams(Error status); void LogAbandonedStream(const scoped_refptr<SpdyStream>& stream, - net::Error status); + Error status); // Invokes a user callback for stream creation. We provide this method so it // can be deferred to the MessageLoop, so we avoid re-entrancy problems. @@ -833,7 +837,7 @@ class NET_EXPORT SpdySession : public base::RefCounted<SpdySession>, // If an error has occurred on the session, the session is effectively // dead. Record this error here. When no error has occurred, |error_| will // be OK. - net::Error error_; + Error error_; State state_; // Limits diff --git a/net/spdy/spdy_stream.cc b/net/spdy/spdy_stream.cc index 482b12c..038db4c 100644 --- a/net/spdy/spdy_stream.cc +++ b/net/spdy/spdy_stream.cc @@ -11,6 +11,7 @@ #include "base/logging.h" #include "base/message_loop.h" #include "base/stringprintf.h" +#include "base/strings/string_number_conversions.h" #include "base/values.h" #include "net/spdy/spdy_buffer_producer.h" #include "net/spdy/spdy_http_utils.h" @@ -188,7 +189,7 @@ void SpdyStream::PushedStreamReplayData() { delegate_->OnDataReceived(scoped_ptr<SpdyBuffer>(buffers[i])); } else { delegate_->OnDataReceived(scoped_ptr<SpdyBuffer>()); - session_->CloseStream(stream_id_, net::OK); + session_->CloseStream(stream_id_, OK); // Note: |this| may be deleted after calling CloseStream. DCHECK_EQ(buffers.size() - 1, i); } @@ -371,15 +372,15 @@ void SpdyStream::DecreaseRecvWindowSize(int32 delta_window_size) { DCHECK_GE(session_->flow_control_state(), SpdySession::FLOW_CONTROL_STREAM); DCHECK_GE(delta_window_size, 1); - // Since we never decrease the initial window size, + // Since we never decrease the initial receive window size, // |delta_window_size| should never cause |recv_window_size_| to go - // negative. If we do, it's a client-side bug, so we use - // PROTOCOL_ERROR for lack of a better error code. + // negative. If we do, the receive window isn't being respected. if (delta_window_size > recv_window_size_) { session_->ResetStream( stream_id_, RST_STREAM_PROTOCOL_ERROR, - "Invalid delta_window_size for DecreaseRecvWindowSize"); - NOTREACHED(); + "delta_window_size is " + base::IntToString(delta_window_size) + + " in DecreaseRecvWindowSize, which is larger than the receive " + + "window size of " + base::IntToString(recv_window_size_)); return; } @@ -525,7 +526,7 @@ void SpdyStream::OnDataReceived(scoped_ptr<SpdyBuffer> buffer) { if (!buffer) { metrics_.StopStream(); - session_->CloseStream(stream_id_, net::OK); + session_->CloseStream(stream_id_, OK); // Note: |this| may be deleted after calling CloseStream. return; } @@ -544,7 +545,7 @@ void SpdyStream::OnDataReceived(scoped_ptr<SpdyBuffer> buffer) { recv_bytes_ += length; recv_last_byte_time_ = base::TimeTicks::Now(); - if (delegate_->OnDataReceived(buffer.Pass()) != net::OK) { + if (delegate_->OnDataReceived(buffer.Pass()) != OK) { // |delegate_| rejected the data. LogStreamError(ERR_SPDY_PROTOCOL_ERROR, "Delegate rejected the data"); session_->CloseStream(stream_id_, ERR_SPDY_PROTOCOL_ERROR); @@ -598,7 +599,7 @@ void SpdyStream::Cancel() { void SpdyStream::Close() { if (stream_id_ != 0) - session_->CloseStream(stream_id_, net::OK); + session_->CloseStream(stream_id_, OK); else session_->CloseCreatedStream(this, OK); } |