HTTP/1.1 + 302 + Cloudflare = 404

[Shira 0]

EDIT: real issue identified here: 

 

 

Hi, I encountered a weird issue with the THttpCli component:

 

My app downloads a file from my website through a php script that redirects to the actual file. I recently set my website to use CloudFlare and the following happens:

 

- HttpCli set to use HTTP 1.0: works fine both with cloudflare and the original website

- HttpCli set to use HTTP 1.1: works fine my website, but when routing through CF it results in a 404 error (HttpCli1.StatusCode on HttpCli1RequestDone), even though the headers return 302

 

These are the headers returned by CloudFlare (some data removed):

 

Quote

HTTP/1.1 302 Found
Date: Sat, 17 Oct 2020 18:23:33 GMT
Content-Type: text/html; charset=UTF-8
Transfer-Encoding: chunked
Connection: keep-alive
Set-Cookie: __cfduid=*****; expires=Mon, 16-Nov-20 18:23:32 GMT; path=/; domain=.******; HttpOnly; SameSite=Lax
expires: Wed, 11 Jan 1984 05:00:00 GMT
cache-control: no-cache, must-revalidate, max-age=0
set-cookie: wp_dlm_downloading=****; expires=Sat, 17-Oct-2020 18:24:33 GMT; Max-Age=60; path=/; domain=*******; HttpOnly
location: ********* (real file URL after the redirection)
x-turbo-charged-by: LiteSpeed
CF-Cache-Status: DYNAMIC
cf-request-id: *******
Report-To: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report?lkg-colo=40&lkg-time=1602959013"}],"group":"cf-nel","max_age":604800}
NEL: {"report_to":"cf-nel","max_age":604800}
Server: cloudflare
CF-RAY: *******

 

Edited October 18, 2020 by Shira

[Guest]

That is interesting, i used CF for very long time and never observe the behaviour you mentioned, in fact CF is the best place to debug your HTTP client implementation.

 

But i think more info is needed, and what is missing, so if you would add the following then someone here might be able to spot the problem

1) Paste the HTTP Request header in full for both versions 1.0 and 1.1

2) Paste FULL both responses.

3) Hide whatever you deem private information like above, but please comment on them like is the hidden value of "location" in the above response you added, does it belong to CF CDN or to your site ?

4) after 302, can you open that location in a browser ?

[Angus Robertson 577]

Looks like a bug in the ICS relocation code, which is quite complex, messy and hard to maintain, but I will not look at it without being able to reproduce the problem, not interested in logs, although someone else may spot the problem from them. 

 

Angus

[Shira 0]

After further debugging it gets even stranger:

 

I found this code is causing the 404, so I thought probably the SendMessage in TProgressBar.SetParams is causing this due to the way WSocket works with messages, similar to how Application.ProcessMessages can cause these issues.

 

procedure TForm1.HttpCli1DocBegin(Sender: TObject);
begin
  ProgressBar1.Max := HttpCli1.ContentLength;
end;

but then this simple change fixes it'

 

procedure TForm1.HttpCli1DocBegin(Sender: TObject);
begin
  ProgressBar1.Max := HttpCli1.ContentLength + 1;
end;

this also works

 

  ProgressBar1.Max := 1;
  ProgressBar1.Max := ProgressBar1.Max + HttpCli1.ContentLength;

but this fails...

  ProgressBar1.Max := HttpCli1.ContentLength;
  ProgressBar1.Max := ProgressBar1.Max + 1;

but then.. directly setting a random value works:

  ProgressBar1.Max := 123;

which kinda invalidates the problem being related to the ProgressBar SendMessage.

 

The main factors still remain through all this, HTTP/1.0 works in all cases, HTTP/1.1 fails 

 

😵

 

I can provide a working demo to reproduce this if you need.

 

Edit: using a custom progressbar without SendMessage to set its Max property also works.

Edited October 18, 2020 by Shira

[Shira 0]

Further testing, encapsulating that line with Try Except ... makes it work, and does not trigger an exception

 

  Try
    ProgressBar1.Max := HttpCli1.ContentLength;
  Except
    On E:Exception do begin
      Memo1.Clear;
      Memo1.Lines.Add(E.Message);
    end;
  End;

but running the app with the debugger on (F9) does trigger here:

 

procedure TProgressBar.SetParams(AMin, AMax: Integer);
begin
  if AMax < AMin then
    raise EInvalidOperation.CreateFmt(SPropertyOutOfRange, [Self.Classname]);

with "TProgressBar property out of range"

 

In both 1.0 and 1.1 cases the ContentLength property has the same value when DocBegin triggers.

Edited October 18, 2020 by Shira

[Guest]

These symptoms might mean the ICS implementation have problem processing chunked encoding.

 

Additional information: i can't find the blog posts from CF now, where they did declared that they deliberately use strict HTTP standard to amplify and produce the most common mistakes in HTTP implementation, i saw it with the old SecureBlackBox (v15), where accessing CF API with compression and chunked encoding generate wrong result on client side, eg. insert irregular chunk sizes which does not change the outcome.

 

@Shira Does disabling chunk encoding support help ?

 

 

[Shira 0]

9 minutes ago, Kas Ob. said:

These symptoms might mean the ICS implementation have problem processing chunked encoding.

 

Additional information: i can't find the blog posts from CF now, where they did declared that they deliberately use strict HTTP standard to amplify and produce the most common mistakes in HTTP implementation, i saw it with the old SecureBlackBox (v15), where accessing CF API with compression and chunked encoding generate wrong result on client side, eg. insert irregular chunk sizes which does not change the outcome.

 

@Shira Does disabling chunk encoding support help ?

 

 

Disabling GZip (httpoEnableContentCoding) produces the same results. How do you disable chunk encoding in HttpCli?

[Angus Robertson 577]

It is unlikely to be related to chunking, this fails before the body is processed.  You can not disable chunking at the client, only the server.

 

All I need is the URL that fails, not demos. 

 

Angus

 

[Shira 0]

I found that when this triggers, AMax = -1

 

procedure TProgressBar.SetParams(AMin, AMax: Integer);
begin
  if AMax < AMin then
    raise EInvalidOperation.CreateFmt(SPropertyOutOfRange, [Self.Classname]);

 

 

39 minutes ago, Angus Robertson said:

It is unlikely to be related to chunking, this fails before the body is processed.  You can not disable chunking at the client, only the server.

 

All I need is the URL that fails, not demos. 

 

Angus

 

Sent you in a PM

 

Ok here's the actual issue: with 1.1 DocBegin triggers twice, the first time, before the 302 redict occurs, has ContentLenght set to -1 since the real file is not being sent yet.

Quote

 

-- Sending Header --
Method: GET

GET /downloads/2319 HTTP/1.1
Accept: image/gif, image/x-xbitmap, image/jpeg, image/pjpeg, */*
Referer: ***
Accept-Encoding: gzip, deflate
User-Agent: ***
Host: ***
Cache-Control: no-cache

-- Header Received --
Status: 302

HTTP/1.1 302 Found
Date: Sun, 18 Oct 2020 11:16:40 GMT
Content-Type: text/html; charset=UTF-8
Transfer-Encoding: chunked
Connection: keep-alive
Set-Cookie: ***
expires: Wed, 11 Jan 1984 05:00:00 GMT
cache-control: no-cache, must-revalidate, max-age=0
set-cookie: ***
location: *** (real file path)
x-turbo-charged-by: LiteSpeed
CF-Cache-Status: DYNAMIC
cf-request-id: ***
Report-To: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report?lkg-colo=40&lkg-time=1603019800"}],"group":"cf-nel","max_age":604800}
NEL: {"report_to":"cf-nel","max_age":604800}
Server: cloudflare
CF-RAY: ***

 

 

OnDocBegin triggers here before the 302 when it shouldn't

HttpCli1.ContentLength = -1

 

then it continues to the redirection:
 

Quote

 

-- Sending Header --
Method: GET

GET ***(real file) HTTP/1.1
Accept: image/gif, image/x-xbitmap, image/jpeg, image/pjpeg, */*
Referer: ***
Accept-Encoding: gzip, deflate
User-Agent: ***
Host: ***
Cache-Control: no-cache

-- Header Received --
Status: 200

HTTP/1.1 200 OK
Date: Sun, 18 Oct 2020 11:16:40 GMT
Content-Type: application/x-executable
Content-Length: 5286400
Connection: keep-alive
Set-Cookie: ***
etag: ***
last-modified: Fri, 09 Aug 2019 19:30:44 GMT
accept-ranges: bytes
x-turbo-charged-by: LiteSpeed
CF-Cache-Status: DYNAMIC
cf-request-id: ***
Report-To: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report?lkg-colo=40&lkg-time=1603019800"}],"group":"cf-nel","max_age":604800}
NEL: {"report_to":"cf-nel","max_age":604800}
Server: cloudflare
CF-RAY: ***

 

HttpCli1.ContentLength = 5286400

** ReqDone: Get, Status = 200

 

 

[FPiette 385]

1 hour ago, Shira said:

ProgressBar1.Max := HttpCli1.ContentLength;

You should make sure ContentLength value is suitable for the ProgressBar Max property. If the content length is unknown, then the value returned is -1. And this is definitely not an ICS bug: A server may not advertise the length of the content it will send to the client. It is your responsibility as client side developer to take this kind of perfect correct issue.

 

[Shira 0]

7 minutes ago, FPiette said:

You should make sure ContentLength value is suitable for the ProgressBar Max property. If the content length is unknown, then the value returned is -1. And this is definitely not an ICS bug: A server may not advertise the length of the content it will send to the client. It is your responsibility as client side developer to take this kind of perfect correct issue.

 

That's correct, but the underlying issue comes from DocBegin triggering inbetween the 302 before the redirection starts, which I don't think it should.

 

Please note I'm not asking for help, criticizing or demanding a fix in any way, I just found what I deemed to be a possible bug so I reported on it for discussion. I have been using your ICS suite for around 20 years and love it 🙂

Edited October 18, 2020 by Shira

[Angus Robertson 577]

I used your URL with the OverbyteIcsHttpRestTst sample, and it works perfectly with http/1.1 and Cloudfare and correctly redirects to your executable and downloads it:

 

< Content-Type: application/x-executable
< Content-Length: 5286400
 

You are assuming DocBegin is only called for a successful 200 request, when it is called otherwise.  Not sure why you want a download bar, they were useful 20 years ago with slow downloads, or for very large files, but 5MB comes down in a couple of seconds in the modern world. 

 

You may want to consider changing to use TSslHttpRest which will simplify your application and make it more robust and future proof, you don't really need any events.

 

Angus

Edited October 18, 2020 by Angus Robertson

[Shira 0]

2 minutes ago, Angus Robertson said:

You are assuming DocBegin is only called for a successful 200 request, when it is called otherwise.  Not sure why you want a download bar, they were useful 20 years ago with slow downloads, or for very large files, but 5MB comes down in a couple of seconds in the modern world. 

That url is just an example, another exe my app downloads is around 70MB, not everyone has fiber optic.

 

As you say 1.1 works fine, the problem is the double DocBegin trigger, shouldn't it happen only when the actual file starts?

[FPiette 385]

3 minutes ago, Shira said:

the problem is the double DocBegin trigger

There is only a problem if there is no corresponding DocEnd.

The real problem is you don't handle all possibles values for ContentLength, including the perfectly correct -1 value.

[Angus Robertson 577]

If you really need progress indication, make sure you don't update it more than once a second, certainly not every time the onDocData event is called.  Doing so will slow down your transfers due to the overhead of updating the screen control so often. 

 

Look at the TIcsHttpMulti.onHttpDataEvent function in OverbyteIcsHttpMulti.pas, which is another new component specifically designed for downloading files, from a list of URLs or by parsing an HTML page, it checks for existing older versions of the files which are updated if newer.  The sample is OverbyteIcsXferTst1.dpr.

 

Angus

 

[Guest]

Rereading what i wrote, suggesting to disable chunked encoding, i see it was not clear.

 

You must make sure that your server is not using dynamic pages, at least for the big files, this will disable chunked transfer from your server side, this might solve the chunked on CF side, but to make sure it is disabled then go to CF cache configuration and page rules, read the documentation and this depends on your CF plan, the idea is when CF does know the full length of a file with specific type or when it is already cached it on its own CDN, then it will not chunked encoding for speed, means CF will send Content-Length header hence your progress bar will work.