New issue
Advanced search Search tips

Issue 783859 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Nov 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 3
Type: Bug



Sign in to add a comment

Crash in net::UploadDataStream::Reset / net::SpdyHttpStream::OnClose

Project Member Reported by mmenke@chromium.org, Nov 10 2017

Issue description

It's a top 60 crasher on Dev (64.0.3260.2) (Which is only 5 dev crashes).

All traces have SpdyHttpStream::OnClose calling into UploadDataStream::Reset, but other than that, not much in common.  There are 3 cancels, and what look like two different completion paths, which is probably more cancels than average, but as this is an upload, perhaps not.

I'm not seeing the crash in 64.0.3253.3, indicating it may be a new regression.

Current crash Link: https://crash.corp.google.com/browse?q=product.name%3D%27Chrome%27%20AND%20product.version%3D%2764.0.3260.2%27%20AND%20custom_data.ChromeCrashProto.channel%3D%27dev%27%20AND%20custom_data.ChromeCrashProto.ptype%3D%27browser%27%20AND%20custom_data.ChromeCrashProto.magic_signature_1.name%3D%27net%3A%3AUploadDataStream%3A%3AReset%27&sql_dialect=googlesql&ignore_case=false&enable_rewrite=true&omit_field_name=&omit_field_value=&omit_field_opt=%3D&stbtiq=&reportid=&index=0

Sample stack trace:

	0x58f84d79	(chrome.dll -upload_data_stream.cc:104 )	net::UploadDataStream::Reset()
0x58de6165	(chrome.dll -spdy_http_stream.cc:374 )	net::SpdyHttpStream::OnClose(int)
0x58de612d	(chrome.dll -spdy_stream.cc:654 )	net::SpdyStream::OnClose(int)
0x58dcba72	(chrome.dll -spdy_session.cc:2368 )	net::SpdySession::DeleteStream(std::unique_ptr<net::SpdyStream,std::default_delete<net::SpdyStream> >,int)
0x58dcb917	(chrome.dll -spdy_session.cc:1705 )	net::SpdySession::CloseActiveStreamIterator(std::_Tree_iterator<std::_Tree_val<std::_Tree_simple_types<std::pair<unsigned int const ,net::SpdyStream *> > > >,int)
0x598cc85a	(chrome.dll -spdy_session.cc:1082 )	net::SpdySession::ResetStream(unsigned int,net::SpdyErrorCode,std::basic_string<char,std::char_traits<char>,std::allocator<char> > const &)
0x598f3bc8	(chrome.dll -spdy_stream.cc:665 )	net::SpdyStream::Cancel()
0x58dd32aa	(chrome.dll -spdy_http_stream.cc:164 )	net::SpdyHttpStream::Close(bool)
0x58de8134	(chrome.dll -http_network_transaction.cc:107 )	net::HttpNetworkTransaction::~HttpNetworkTransaction()
0x58de80ba	(chrome.dll -http_network_transaction.cc:101 )	net::HttpNetworkTransaction::~HttpNetworkTransaction
0x5946fe5d	(chrome.dll -throttling_network_transaction.cc:36 )	content::ThrottlingNetworkTransaction::~ThrottlingNetworkTransaction()
0x5946fdb4	(chrome.dll -throttling_network_transaction.cc:34 )	content::ThrottlingNetworkTransaction::~ThrottlingNetworkTransaction
0x59897171	(chrome.dll -http_cache_writers.cc:190 )	net::HttpCache::Writers::EraseTransaction(std::_List_iterator<std::_List_val<std::_List_simple_types<std::pair<net::HttpCache::Transaction * const,net::HttpCache::Writers::TransactionInfo> > > >,int)
0x598970c7	(chrome.dll -http_cache_writers.cc:180 )	net::HttpCache::Writers::EraseTransaction(net::HttpCache::Transaction *,int)
0x5989702d	(chrome.dll -http_cache_writers.cc:158 )	net::HttpCache::Writers::RemoveTransaction(net::HttpCache::Transaction *,bool)
0x598411a0	(chrome.dll -http_cache.cc:911 )	net::HttpCache::DoneWithEntry(net::HttpCache::ActiveEntry *,net::HttpCache::Transaction *,bool,bool)
0x59898700	(chrome.dll -http_cache_transaction.cc:2940 )	net::HttpCache::Transaction::DoneWithEntry(bool)
0x58e15707	(chrome.dll -http_cache_transaction.cc:202 )	net::HttpCache::Transaction::~Transaction()
0x58e1567c	(chrome.dll -http_cache_transaction.cc:194 )	net::HttpCache::Transaction::~Transaction
0x58f97a6e	(chrome.dll -url_request_http_job.cc:398 )	net::URLRequestHttpJob::DestroyTransaction()
0x58f97a12	(chrome.dll -url_request_http_job.cc:327 )	net::URLRequestHttpJob::Kill()
0x58dd2ba3	(chrome.dll -url_request.cc:726 )	net::URLRequest::DoCancel(int,net::SSLInfo const &)
0x58fbcba4	(chrome.dll -url_request.cc:691 )	net::URLRequest::CancelWithError(int)
0x58fbca98	(chrome.dll -resource_loader.cc:628 )	content::ResourceLoader::CancelRequestInternal(int,bool)
0x5931d890	(chrome.dll -resource_loader.cc:318 )	content::ResourceLoader::OutOfBandCancel(int,bool)
0x596ad1d3	(chrome.dll -bind_internal.h:311 )	base::internal::Invoker<base::internal::BindState<void (base::trace_event::TraceLog::*)(int, bool) __attribute__((thiscall)),base::internal::UnretainedWrapper<base::trace_event::TraceLog>,int,bool>,void ()>::RunOnce
0x5932007b	(chrome.dll -stream_writer.cc:91 )	content::StreamWriter::OnClose(content::Stream *)
0x593fd6c1	(chrome.dll -stream.cc:187 )	content::Stream::CloseHandle()
 

Comment 1 by mmenke@chromium.org, Nov 10 2017

This may be related to  issue 779919  (Dev does have the fix for that issue).
This looks very similar to 779919, except the fix there fixes it for HttpNetworkTransaction and not for the streams.

The issue is that  request_info_ which is owned by the URLRequestHttpJob may have been already destroyed. The  request_info_ is set to null currently in ReadResponseBody but actually should be set to null at the end of the headers because its possible that Read never gets called.

bnc@, mmenke@: Is OnHeadersReceived() a good point to unconditionally assume that headers phase is complete or is there any case (like auth etc. ) where the headers phase can be entered again?

Comment 3 by mmenke@chromium.org, Nov 10 2017

It looks to me like response_info_ is not modified after OnHeadersReceived, and OnHeadersReceived is called only once, though I defer to bnc.
Tried the change and one of the existing tests is failing: SpdyNetworkTransactionTest.ResponseBeforePostCompletes
because the following line 
https://cs.chromium.org/chromium/src/net/spdy/chromium/spdy_network_transaction_unittest.cc?sq=package:chromium&q=ResponseBeforePostCompletes&l=1682

works on the upload data stream after the response headers are complete. It seems this is a valid scenario but wanted to confirm.

Matt, Bence, any thoughts?

Comment 5 by mmenke@chromium.org, Nov 13 2017

Yes, it's valid.  For HTTP, it's legal, we just don't start reading the response until we've finished uploading the body.  For H2 and QUIC we can't really do that, since the stream is shared.

Comment 6 by b...@chromium.org, Nov 13 2017

Sorry, I am not sure what part of the code I am supposed to be looking at.  |request_info_| is a member of URLRequestHttpJob, I see that.  But which class has the OnHeadersReceived and ReadResponseBody methods?  I did not find it either in HttpNetworkTransaction or UrlRequestHttpJob.
Its spdy_http_stream.cc
Here is a WIP CL that seems to be working:
https://chromium-review.googlesource.com/c/chromium/src/+/764652
Owner: shivanisha@chromium.org
Status: Assigned (was: Untriaged)
2 CLs uploaded for review:
Spdy stream: Move request info resetting to null at the end of headers phase. (https://chromium-review.googlesource.com/c/chromium/src/+/769492/)

Parallel writing should only be allowed for GET requests.
(https://chromium-review.googlesource.com/c/chromium/src/+/769492/)

Comment 11 by b...@chromium.org, Nov 15 2017

Re comment #3:  I agree that response_info_ is not modified after OnHeadersReceived, and that OnHeadersReceived is meant to be called only once.

However, SpdyStream::SetDelegate() posttasks SpdyStream::PushedStreamReplay(), so in theory it is possible that SpdyStream::SaveResponseHeaders() is called after |delegate_| is set by SetDelegate but before PushedStreamReplay() is called.  In this unfortunate case, SpdyHttpStream::OnHeadersReceived() could be called twice.  I don't think it could happen, because SetDelegate() is called by SpdyHttpStream upon initialization, and SaveResponseHeaders::SaveResponseHeaders() is called by SpdyStream::OnHeadersReceived(), which must happen later, but it's not immediately obvious.
Project Member

Comment 12 by bugdroid1@chromium.org, Nov 15 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/7dbf0b9563d08c4a5cdbb4beeb80a83a547026ab

commit 7dbf0b9563d08c4a5cdbb4beeb80a83a547026ab
Author: Shivani Sharma <shivanisha@chromium.org>
Date: Wed Nov 15 21:02:11 2017

Parallel writing should only be allowed for GET requests.

Requests other than GET like POST/PUT/DELETE do not need the parallel writing functionality.
Allowing 2 POSTs to do parallel writing would have also led to a race in the Spdy stream
(See https://chromium-review.googlesource.com/c/chromium/src/+/764652)

Bug:  783859 
Cq-Include-Trybots: master.tryserver.chromium.android:android_cronet_tester;master.tryserver.chromium.mac:ios-simulator-cronet
Change-Id: Ia1422fc4ce767affc28fd1121209c7394cca00da
Reviewed-on: https://chromium-review.googlesource.com/769492
Commit-Queue: Shivani Sharma <shivanisha@chromium.org>
Reviewed-by: Josh Karlin <jkarlin@chromium.org>
Cr-Commit-Position: refs/heads/master@{#516821}
[modify] https://crrev.com/7dbf0b9563d08c4a5cdbb4beeb80a83a547026ab/net/http/http_cache.cc
[modify] https://crrev.com/7dbf0b9563d08c4a5cdbb4beeb80a83a547026ab/net/http/http_cache.h
[modify] https://crrev.com/7dbf0b9563d08c4a5cdbb4beeb80a83a547026ab/net/http/http_cache_unittest.cc

Project Member

Comment 13 by bugdroid1@chromium.org, Nov 15 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/32ade74db781e7ff890d9424300398c1300c90a1

commit 32ade74db781e7ff890d9424300398c1300c90a1
Author: Shivani Sharma <shivanisha@chromium.org>
Date: Wed Nov 15 21:47:04 2017

Spdy stream: Move request info resetting to null at the end of headers phase.

There was a gap existing where request_info_ may have been destroyed because the consumer died
and it was still non-null since Read was not yet called. This CL moves the resetting of
request_info_ to either the end of headers phase or the end of upload data stream whichever is
later.

Note that if the request_info_ is destroyed after the headers completion and before upload
data stream's completion then its not an issue because the cache transaction layer will not allow
parallel writing of two POST requests with the same upload id. That change is landing via
https://chromium-review.googlesource.com/#/c/chromium/src/+/769492


Bug:  783859 
Cq-Include-Trybots: master.tryserver.chromium.android:android_cronet_tester;master.tryserver.chromium.mac:ios-simulator-cronet
Change-Id: I0b78a55f197eef35144047b0f3c594d106cec98e
Reviewed-on: https://chromium-review.googlesource.com/764652
Reviewed-by: Bence Béky <bnc@chromium.org>
Commit-Queue: Shivani Sharma <shivanisha@chromium.org>
Cr-Commit-Position: refs/heads/master@{#516839}
[modify] https://crrev.com/32ade74db781e7ff890d9424300398c1300c90a1/net/spdy/chromium/spdy_http_stream.cc
[modify] https://crrev.com/32ade74db781e7ff890d9424300398c1300c90a1/net/spdy/chromium/spdy_http_stream.h
[modify] https://crrev.com/32ade74db781e7ff890d9424300398c1300c90a1/net/spdy/chromium/spdy_http_stream_unittest.cc

Status: Fixed (was: Assigned)

Sign in to add a comment