New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 813061 link

Starred by 4 users

Issue metadata

Status: Available
Owner: ----
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Mac
Pri: 3
Type: Bug



Sign in to add a comment

Chrome doesn't respond after get request with suffix byte range to empty file from cache.

Reported by maximamb...@gmail.com, Feb 16 2018

Issue description

Chrome Version       : 64.0.3282.167 (Official Build) (64-bit)
OS version               : Mac OS 10.13.3
Other browsers tested:
  Chrome on MacOs 64.0.3282.167 (Official Build) (64-bit) - CRASH.
  Chrome on Windows 64.0.3282.167 (Official Build), (64-bitт) - CRASH.
have tested this issue:
     Safari: Version 11.0.3 (13604.5.6) - OK
    Firefox (MAC and WIN): 58.0.2 (64-bit) - OK 

What steps will reproduce the problem?
(0) Get a working Nginx server.
(1) Create empty file on server. (After the server crash all our files were empty).
(2) Send get request to this file (with axios (https://github.com/axios/axios) if it's matters) with the 'Range' header like this "Range: 'bytes=-800'".

What is the expected result?
process an empty query.

What happens instead?
Browser does not respond to any actions. I was able to close it only with the help of force quit.

Additional info.
Network request frozen at "pending" state.
Console is empty.
I made this request with curl 

I. with range 1-8

curl -v -X GET -H "range: bytes=1-8" https://*confidential*
Note: Unnecessary use of -X or --request, GET is already inferred.
*   Trying *confidential*...
* TCP_NODELAY set
* Connected to host *confidential* port *confidential* (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
*   CAfile: *confidential*
  CApath: none
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Server hello (2):
* NPN, negotiated HTTP1.1
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Unknown (67):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using *confidential*
* ALPN, server did not agree to a protocol
* Server certificate:
*  subject: OU=Domain Control Validated; OU=PositiveSSL Wildcard; CN=*confidential*
*  start date: Oct 13 00:00:00 2017 GMT
*  expire date: Oct 13 23:59:59 2019 GMT
*  subjectAltName: host *confidential* matched cert's *confidential*
*  issuer: *confidential*
*  SSL certificate verify ok.
> GET /trades/etc_eur HTTP/1.1
> Host: *confidential*
> User-Agent: curl/7.54.0
> Accept: */*
> range: bytes=1-8
> 
< HTTP/1.1 416 Requested Range Not Satisfiable
< Server: nginx
< Date: Fri, 16 Feb 2018 11:24:28 GMT
< Content-Type: text/html
< Content-Length: 206
< Connection: keep-alive
< Access-Control-Allow-Origin: *
< Access-Control-Allow-Methods: GET, POST, OPTIONS, HEAD
< Access-Control-Allow-Headers: Authorization, Origin, X-Requested-With, Accept, Cache-Control, Last-Modified, Pragma, Expires, Content-Type, Content-Language, Range, Content-Range
< Access-Control-Expose-Headers: Authorization, Origin, X-Requested-With, Accept, Cache-Control, Last-Modified, Pragma, Expires, Content-Type, Content-Language, Range, Content-Range
< Content-Range: bytes */0
< 
<html>
<head><title>416 Requested Range Not Satisfiable</title></head>
<body bgcolor="white">
<center><h1>416 Requested Range Not Satisfiable</h1></center>
<hr><center>nginx</center>
</body>
</html>

II. with range -800

curl -v -X GET -H "range: bytes=-800" https://*confidential*/trades/etc_eur
Note: Unnecessary use of -X or --request, GET is already inferred.
*   Trying *confidential*...
* TCP_NODELAY set
* Connected to *confidential* (*confidential*) port *confidential* (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
*   CAfile: *confidential*
  CApath: none
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Server hello (2):
* NPN, negotiated HTTP1.1
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Unknown (67):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / *confidential*
* ALPN, server did not agree to a protocol
* Server certificate:
*  subject: OU=Domain Control Validated; OU=PositiveSSL Wildcard; CN=**confidential*
*  start date: Oct 13 00:00:00 2017 GMT
*  expire date: Oct 13 23:59:59 2019 GMT
*  subjectAltName: host "*confidential*" matched cert's "*confidential*"
*  issuer: *confidential*
*  SSL certificate verify ok.
> GET /trades/etc_eur HTTP/1.1
> Host: *confidential*
> User-Agent: curl/7.54.0
> Accept: */*
> range: bytes=-800
> 
< HTTP/1.1 200 OK
< Server: nginx
< Date: Fri, 16 Feb 2018 11:25:02 GMT
< Content-Type: application/x-bin
< Content-Length: 0
< Last-Modified: Fri, 16 Feb 2018 08:45:07 GMT
< Connection: keep-alive
< ETag: "5a869a13-0"
< Access-Control-Allow-Origin: *
< Access-Control-Allow-Methods: GET, POST, OPTIONS, HEAD
< Access-Control-Allow-Headers: Authorization, Origin, X-Requested-With, Accept, Cache-Control, Last-Modified, Pragma, Expires, Content-Type, Content-Language, Range, Content-Range
< Access-Control-Expose-Headers: Authorization, Origin, X-Requested-With, Accept, Cache-Control, Last-Modified, Pragma, Expires, Content-Type, Content-Language, Range, Content-Range
< Accept-Ranges: bytes

I hope it may help you to make chrome better!
 
Labels: Needs-Triage-M64
Cc: vamshi.kommuri@chromium.org
Components: Internals>Network
Labels: Triaged-ET TE-NeedsTriageHelp OS-Mac
Thanks for filing the issue!

This issue seems to be out of scope for triaging from ET end as this requires a working Nginx server and needs to be tested by creating empty files on server.
Hence adding label TE-NeedsTriageHelp for further investigation.
Cool, I will wait
Cc: morlovich@chromium.org
Couldn't reproduce with this as an attempted testcase:
<script>
var xhr = new XMLHttpRequest();
xhr.open("GET", "http://127.0.0.1/empty");
xhr.setRequestHeader("Range", "bytes=-800");
xhr.send();
</script>
(with empty being, well, an empty file, and nginx 1.13.3; though w/o any of the CORS stuff configured that you had)

Reporter, any reason you mention the 1-8 range in your curl examples? Also any chance you only saw the issue with incognito profiles?

Comment 5 by mmenke@chromium.org, Feb 20 2018

Labels: Needs-Feedback
Hello!

1. I use the range 1-8 to show that everything works with start-end notation, but for some reason the -offset_from_end does not work.

2. No, i saw this in regular profile (if I understand your question correctly)
Project Member

Comment 7 by sheriffbot@chromium.org, Feb 26 2018

Cc: mmenke@chromium.org
Labels: -Needs-Feedback
Thank you for providing more feedback. Adding the requester to the cc list.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot

Comment 8 by mmenke@chromium.org, Feb 26 2018

Cc: -mmenke@chromium.org
1. Any idea on what my testcase is missing then?
2. Thanks, you did.

Hi!

Looks like you did everything right. When I have some free time I will try again to repeat this error and to provide more information
Hmm, tried my own testcase again on a debug build (wanted to see if a different cache backend might make a difference), and stumbled on a check-failure 
when reloading with F5:

[83982:83993:0227/095218.009094:FATAL:http_response_headers.cc(392)] Check failed: byte_range.HasLastBytePosition(). 
#0 0x5584f76677bd base::debug::StackTrace::StackTrace()
#1 0x5584f7665e0c base::debug::StackTrace::StackTrace()
#2 0x5584f76cb93a logging::LogMessage::~LogMessage()
#3 0x5584f876ac78 net::HttpResponseHeaders::UpdateWithNewRange()
#4 0x5584f8b50a8f net::PartialData::FixResponseHeaders()
#5 0x5584f8ac37f2 net::HttpCache::Transaction::DoPartialHeadersReceived()
#6 0x5584f8ab1d17 net::HttpCache::Transaction::DoLoop()
#7 0x5584f8aae7db net::HttpCache::Transaction::OnIOComplete()
#8 0x5584f218cf41 _ZN4base8internal13FunctorTraitsIMN5media26AudioDebugRecordingManagerEFviEvE6InvokeINS_7WeakPtrIS3_EEJiEEEvS5_OT_DpOT0_
#9 0x5584f218cea5 _ZN4base8internal12InvokeHelperILb1EvE8MakeItSoIMN5media26AudioDebugRecordingManagerEFviENS_7WeakPtrIS5_EEJiEEEvOT_OT0_DpOT1_
#10 0x5584f22ccd60 _ZN4base8internal7InvokerINS0_9BindStateIMN5media12PipelineImpl15RendererWrapperEFvNS3_14PipelineStatusEEJNS_7WeakPtrIS5_EEEEEFvS6_EE7RunImplIRKS8_RKNSt3__15tupleIJSA_EEEJLm0EEEEvOT_OT0_NSH_16integer_sequenceImJXspT1_EEEEOS6_
#11 0x5584f22ccceb _ZN4base8internal7InvokerINS0_9BindStateIMN5media12PipelineImpl15RendererWrapperEFvNS3_14PipelineStatusEEJNS_7WeakPtrIS5_EEEEEFvS6_EE3RunEPNS0_13BindStateBaseES6_
#12 0x5584f21f93be _ZNKR4base17RepeatingCallbackIFvN5media18OutputDeviceStatusEEE3RunES2_
#13 0x5584f8a9d720 net::HttpCache::ProcessAddToEntryQueue()
#14 0x5584f8a9d4b7 net::HttpCache::OnProcessQueuedTransactions()
#15 0x5584f22ce2b2 _ZN4base8internal13FunctorTraitsIMN5media12PipelineImpl15RendererWrapperEFvPNS2_13DemuxerStreamEEvE6InvokeIRKNS_7WeakPtrIS4_EEJRKS6_EEEvS8_OT_DpOT0_
#16 0x5584f22ce215 _ZN4base8internal12InvokeHelperILb1EvE8MakeItSoIRKMN5media12PipelineImpl15RendererWrapperEFvPNS4_13DemuxerStreamEERKNS_7WeakPtrIS6_EEJRKS8_EEEvOT_OT0_DpOT1_
#17 0x5584f22ce18d _ZN4base8internal7InvokerINS0_9BindStateIMN5media12PipelineImpl15RendererWrapperEFvPNS3_13DemuxerStreamEEJNS_7WeakPtrIS5_EES7_EEEFvvEE7RunImplIRKS9_RKNSt3__15tupleIJSB_S7_EEEJLm0ELm1EEEEvOT_OT0_NSI_16integer_sequenceImJXspT1_EEEE
#18 0x5584f22ce0fc _ZN4base8internal7InvokerINS0_9BindStateIMN5media12PipelineImpl15RendererWrapperEFvPNS3_13DemuxerStreamEEJNS_7WeakPtrIS5_EES7_EEEFvvEE3RunEPNS0_13BindStateBaseE
#19 0x5584f19d8cf1 _ZNO4base12OnceCallbackIFvvEE3RunEv
#20 0x5584f766d35a base::debug::TaskAnnotator::RunTask()
#21 0x5584f76dd609 base::internal::IncomingTaskQueue::RunTask()
#22 0x5584f76db96b base::MessageLoop::RunTask()
#23 0x5584f76dbc08 base::MessageLoop::DeferOrRunPendingTask()
#24 0x5584f76dbf18 base::MessageLoop::DoWork()
#25 0x5584f76e5b51 base::MessagePumpLibevent::Run()
#26 0x5584f76db12c base::MessageLoop::Run()
#27 0x5584f7772a0d base::RunLoop::Run()
#28 0x5584f7817898 base::Thread::Run()
#29 0x5584f378d7c6 content::BrowserThreadImpl::IOThreadRun()
#30 0x5584f378da5f content::BrowserThreadImpl::Run()
#31 0x5584f7818505 base::Thread::ThreadMain()
#32 0x5584f780eeed base::(anonymous namespace)::ThreadFunc()
#33 0x7fbe31428494 start_thread
#34 0x7fbe2b59ca8f clone

Hmm, it's strange that chrome produced an FATAL on it. Request like -800 is in the range specification.
So HttpResponseHeaders::UpdateWithNewRange() assumes that the |byte_range| can't be a suffix byte range or a right unbounded range?
Maks, should we fix this function? 
Don't know at the moment --- I need to read a bunch of code to answer that.

Owner: xunji...@chromium.org
Status: Assigned (was: Unconfirmed)
Summary: Chrome doesn't respond after get request with suffix byte range to empty file from cache. (was: Chrome doesn't respond after get request with range to empty file.)
I am working on a fix.
Cc: xunji...@chromium.org
Owner: ----
Status: Available (was: Assigned)
I didn't get time during triage to come up with a working solution. Unassigning myself. 

I am not sure why UI/IO thread is locked up, but the DCHECK is really easy to repro using a regression test (pasted below). I tried stepping through the debugger, but I am not exactly sure about the state transitions in HttpCache::Transaction and PartialData. I tried also fixing HttpByteRange::ComputeBounds to take into account the resource size when computing indices. All tests pass with this approach, but it made the concept of start and end indices inconsistent.

const MockTransaction kEmptyBody_Transaction = {"http://www.example.com/",
                                                "GET",
                                                base::Time(),
                                                "",
                                                LOAD_NORMAL,
                                                "HTTP/1.1 200 OK",
                                                "Cache-Control: max-age=10000\n"
                                                "Content-Length: 0\n",
                                                base::Time(),
                                                "",
                                                TEST_MODE_NORMAL,
                                                nullptr,
                                                nullptr,
                                                nullptr,
                                                0,
                                                0,
                                                OK,
                                                OK};


// Similiar to UnknownRangeGET_3, except that the resource size is empty.
// Regression test for crbug.com/813061.
TEST(HttpCache, UnknownRangeGET_3) {
  MockHttpCache cache;
  std::string headers;

  MockTransaction transaction(kEmptyBody_Transaction);
  transaction.test_mode = TEST_MODE_SYNC_CACHE_START |
                          TEST_MODE_SYNC_CACHE_READ |
                          TEST_MODE_SYNC_CACHE_WRITE;
  AddMockTransaction(&transaction);

  // Write the empty resource to the cache.
  RunTransactionTestWithResponse(cache.http_cache(), transaction, &headers);

  EXPECT_EQ(
      "HTTP/1.1 200 OK\nCache-Control: max-age=10000\nContent-Length: 0\n",
      headers);
  EXPECT_EQ(1, cache.network_layer()->transaction_count());
  EXPECT_EQ(0, cache.disk_cache()->open_count());
  EXPECT_EQ(1, cache.disk_cache()->create_count());

  // Make sure we are done with the previous transaction.
  base::RunLoop().RunUntilIdle();

  // Write and read from the cache. This will trigger the DCHECK.
  transaction.request_headers = "Range: bytes = -20\r\n" EXTRA_HEADER;
  RunTransactionTestWithResponse(cache.http_cache(), transaction, &headers);

  EXPECT_EQ(
      "HTTP/1.1 200 OK\nCache-Control: max-age=10000\nContent-Length: 0\n",
      headers);
  EXPECT_EQ(2, cache.network_layer()->transaction_count());
  EXPECT_EQ(1, cache.disk_cache()->open_count());
  EXPECT_EQ(1, cache.disk_cache()->create_count());

  RemoveMockTransaction(&transaction);
}
Components: -Internals>Network Internals>Network>Cache

Sign in to add a comment