Also, the server is returning the correct header, and the devtools show the correct header, but the JS API is getting an incorrect value.

I think it only happens for files that have a size that is exactly dividable with 1024.
Here are more files that have the same issue:

https://peer5-e2e.storage.googleapis.com/test1k.test
https://peer5-e2e.storage.googleapis.com/test5k.test
https://peer5-e2e.storage.googleapis.com/test10k.test
https://peer5-e2e.storage.googleapis.com/test50k.test
https://peer5-e2e.storage.googleapis.com/test100k.test
https://peer5-e2e.storage.googleapis.com/test500k.test
https://peer5-e2e.storage.googleapis.com/test1m.test
https://peer5-e2e.storage.googleapis.com/test5m.test
https://peer5-e2e.storage.googleapis.com/test10m.test
https://peer5-e2e.storage.googleapis.com/test50m.test
https://peer5-e2e.storage.googleapis.com/test100m.test

Those files are also filled with 0's if it makes any difference

Able to reproduce the issue on windows 7, Ubuntu 14.04 and Mac 10.12.3 using chrome version 56.0.2924.87  and canary 59.0.3036.0.
This is non regression issue from M40 old builds.
Marking it as Untriaged to get more inputs from dev team.

Thanks,

This looks to be a bug in HttpCache::Transaction.  HttpNetworkTransaction gets the headers sent by the server, but by the time they get to URLRequestHttpJob, they've been mucked up, presumably by HttpCache::Transaction's range request logic.

May dig further if I have time while on triage, but a cache expert would be better equipped to investigate and fix.

http://output.jsbin.com/copubiy/quiet - demo using fetch. See console for results. Seems to have the same bug.

[+Shivani FHI]

I'll take a look at this.  I may release it after I've dug up root cause, but in the meantime it'll aid my understanding of HttpCache::Transaction.  

(And I suspect I can narrow the problem down pretty quickly.)

Ok, so I've found the code involved, but I'm not clear as to the *reason* why the code is there (though I'm sure there is such a reason).  Before I dive into the code archaeology:

@shahar: you say you think it only happens for files where the code size is divisible by 1024.  Do you have an example where this *doesn't* happen?  It looks to me like it always should.

So what's happening is that the HttpCache::Transaction correctly finds that there's no entry and creates a new entry (state transitions GET_BACKEND -> GET_BACKEND_COMPLETE -> INIT_ENTRY -> OPEN_ENTRY -> OPEN_ENTRY_COMPLETE -> CREATE_ENTRY -> CREATE_ENTRY_COMPLETE -> ADD_TO_ENTRY -> ADD_TO_ENTRY_COMPLETE -> SEND_REQUEST). The request that's sent has "Range: bytes=0-100000" as specified by the consumer.   The response is received, and data from the response is stored in the partial_ data member of HttpCache::Transaction through PartialData::ResponseHeadersOK.  This includes the total size of the entity from the Content-Range response.  Then, in the DoOverwriteCacheResponse (state transitions to here SEND_REQUEST_COMPLETE -> SUCCESSFUL_SEND_REQUEST -> OVERWRITE_CACHED_RESPONSE) there's the following piece of code:

  // We change the value of Content-Length for partial content.
  if (handling_206_ && partial_)
    partial_->FixContentLength(new_response_->headers.get());

That overwrites the Content-Length in the response headers with the size of the entity from the Content-Range header.  Voila!  Or something.

I spent some time tracking back through the code history to see when this was entered into the code, and made it back to 2009 with larger and larger chunks of code being changed at once before giving up.  If I had to guess (and I don't particularly trust this guess) it would be that the cache is thinking that it may be creating and sending range requests to get entities piecemeal, and hence will need to provide an image to code above it that it's transparently getting the larger entity.  Which is equivalent to saying that it doesn't cleanly support Range requests from consumers.

I'm going to cc davidben@, since I know he's looked at this code in the past, specifically with regard to range requests, and he might be aware of some context that I'm missing.  But the naive answer from my investigation appears to be that we're doing the wrong thing by ancient choice.

But again, if there's a case with range requests where this *doesn't* happen, I'm very interested, as that means that the code isn't internally self-consistent and I missed something in my analysis.

@rdsmith @davidben: I just did some more testing, and figured out its only happening when the "Cache-Control: no-store" header is set.
The header can be used with a combination of any other "Cache-Control" header, but if it contains the "no-store" inside the value, its screwing up the response.

It has nothing to do with the size of the file, or the fact that its filled with 0's.

If the "Cache-Control" header value contains "no-store", the Content-Length header returned is incorrect (which means its set to the full file size and not the range). Every other case that I checked, the header is correct.

I'm not sure whats going on inside the browser when this header is set, but thats probably a good lead to follow.

Does that help?

@shahar: That's interesting.  Can you easily setup a test URL which returns the value without no-store?  If not, I'll put together a server and figure out the alternative code path, but it'd be a bit quicker with a repro.  Thanks!

@rdsmith: There you go:

A 1K file without the "no-store" header:
----------------------------
var xhr = new XMLHttpRequest();
xhr.open('GET', 'https://peer5-e2e.storage.googleapis.com/test1k-ok.test');
xhr.setRequestHeader('Range', 'bytes=0-100');
xhr.onreadystatechange = function() {
	console.log(this.getAllResponseHeaders());
};
xhr.send();
----------------------


Same 1K file with "no-store" header:
---------------------------
var xhr = new XMLHttpRequest();
xhr.open('GET', 'https://peer5-e2e.storage.googleapis.com/test1k-bad.test');
xhr.setRequestHeader('Range', 'bytes=0-100');
xhr.onreadystatechange = function() {
	console.log(this.getAllResponseHeaders());
};
xhr.send();
----------------------------

Thank you, @shahar!  Unfortunately, it leaves me in the same position of knowing what the code is doing but not why :-}.  

Everything I describe in c#10 holds true for both the no-store and !no_store case.  After the OVERWRITE_CACHE_RESPONSE/DoOverwriteCacheResponse the state transitions go to CACHE_WRITE_RESPONSE.  The divergence is in the following piece of code:

  if ((response_.headers->HasHeaderValue("cache-control", "no-store")) ||
      IsCertStatusError(response_.ssl_info.cert_status)) {
    DoneWritingToEntry(false);
    if (net_log_.IsCapturing())
      net_log_.EndEvent(NetLogEventType::HTTP_CACHE_WRITE_INFO);
    return OK;
  }

In the nostore case, the DoneWritingToEntry(false) call results in entry_ being set to nullptr and the mode of the transaction being set to NONE; that doesn't happen in the !nostore case.  Then the state transitions go CACHE_WRITE_RESPONSE_COMPLETE -> TRUNCATE_CACHED_DATA -> TRUNCATE_CACHED_DATA_COMPLETE -> TRUNCATE_CACHED_METADATA -> TRUNCATE_CACHED_METADATA_COMPLETE -> PARTIAL_HEADERS_RECEIVED.  In the entry to OnPartialHeadersReceived the response headers have the Content-Length set to 1024 (the full entity size) for both cases.  However, in that routine there's the following code:

  } else if (mode_ != NONE) {
    // We are about to return the headers for a byte-range request to the user,
    // so let's fix them.
    partial_->FixResponseHeaders(response_.headers.get(), true);
  }

This gets executed in the !nostore case, but not in the nostore case.

This gently reinforces the conclusion I had come to in c#10, which is that the cache is trying to present a non-range request based interface above it, and in the case where "the cache" isn't being used (pass through) it will not do that transformation and instead return the information gathered from the network.

Fixing this while still allowing the cache to cache range requests strikes me as likely to take years and cost thousands of lives :-} (but sorta :-|).  For one example, what should the cache return if it has cached a range request previously, and a new range request comes in for a subset of that request.  That new request can be filled from cache, but what should the content-length be?  The CL stored in the cache (the size of the previous range request)?  The size of the current RR?  It's not at all clear to me what the right interface is (which gives me some sympathy for the current implementation).

However, I'm finding myself wondering if there are use cases that really drive caching range requests at all, and if not, if we can always handle RRs as pass through.  I imagine that RRs are mostly used for video players, and I'd think that video players a) usually have a lot more bandwidth requirements than most resources (which would discourage using the disk to store them) and often have caching behavior that's very dependent on the video playing (i.e. the last three minutes is going to be much more important to cache than the whole resource).  This nicely solves the problem sketched out above, and probably drastically simplified HttpCache::Transaction.  Unfortunately, it'd require engaging with the various range request consumers to make sure that we aren't going to be causing them much grief. 

Regardless, I'm going to consider this bug triaged, and return it to the available pool.

Any update on this?

+morlovich@chromium.org FHI.

> That new request can be filled from cache, but what should the content-length 
> be?  The CL stored in the cache (the size of the previous range request)?  The 
> size of the current RR?  It's not at all clear to me what the right interface 
> is (which gives me some sympathy for the current implementation).

This currently (generally?) sets it to the # of bytes returned, via:
https://cs.chromium.org/chromium/src/net/http/http_response_headers.cc?rcl=105d8abde9a7c706df0953c08b69f39f542291c0&l=402

Called via FixResponseHeaders; but it's hard for me to reason about all the corner-cases wrt to truncated and what not.

When it comes to no-store case, I find the contrast to this site interesting:
https://cs.chromium.org/chromium/src/net/http/http_cache_transaction.cc?q=http_cache_transaction.cc&sq=package:chromium&dr&l=1885