I need help debugging FPHTTPClient

[Gustavo 'Gus' Carreno]

Hey Y'all,

Ok, here's my situation, and it's quite particular to my setup, since it only occurs when I'm tethering to my phone:
ANY HTTPS download using FPHHTPClient will prematurely end at around 74%

Using Ikel's cli-fp I've done this to try and find out what's happening:

Code: Pascal  [Select][+][-]

1. unit CMD.FPHTTPCli;
2.  
3. {$mode ObjFPC}{$H+}{$J-}
4.  
5. interface
6.  
7. uses
8.   Classes
9. , SysUtils
10. , Common.Utils    // Utilities for formatting
11. , CLI.Interfaces  // Core interfaces
12. , CLI.Progress    // Optional: Progress indicators
13. , CLI.Command     // Base command implementation
14. , CLI.Console     // Optional: Colored console output
15. ;
16.  
17. type
18.  
19. { TCmdFHTTPCli }
20.   TCmdFHTTPCli = class(TBaseCommand)
21.   private
22.     FSpinner: IProgressIndicator;
23.     FStream: TMemoryStream;
24.  
25.     FSize: Int64;
26.  
27.     procedure OnDataReceived(Sender: TObject; Const ContentLength, CurrentPos: Int64);
28.   protected
29.   public
30.     { Main execution method that orchestrates the greeting display
31.       @return 0 for success, 1 for errors }
32.     function Execute: Integer; override;
33.   published
34.   end;
35.  
36. var
37.   CmdFHTTPCli: TCmdFHTTPCli;
38.  
39. implementation
40.  
41. uses
42.   fphttpclient   // Free Pascal HTTP Client
43. , opensslsockets
44. ;
45.  
46. const
47.   codes: array of Integer = (
48.     200,
49.     400,
50.     401,
51.     403,
52.     404,
53.     405,
54.     500,
55.     501,
56.     502,
57.     503,
58.     504
59.   );
60.  
61. { TCmdFHTTPCli }
62.  
63. procedure TCmdFHTTPCli.OnDataReceived(Sender: TObject; const ContentLength,
64.   CurrentPos: Int64);
65. begin
66.   FSpinner.Update(0);
67.   TConsole.Write(Format(' Data Received: %9s of %9s (%6.2f%%); Stream: %9s',[
68.     FormatBytes(CurrentPos),
69.     FormatBytes(FSize),
70.     Percent(FSize, CurrentPos),
71.     FormatBytes(FStream.Position)
72.   ]));
73. end;
74.  
75. function TCmdFHTTPCli.Execute: Integer;
76. var
77.   http: TFPHTTPClient;
78.   url: String;
79.   index: Integer;
80. begin
81.   Result:= 0;
82.  
83.   if GetParameterValue('--url', url) then
84.   begin
85.     http:= TFPHTTPClient.Create(nil);
86.     try
87.       FStream:= TMemoryStream.Create;
88.       try
89.         try
90.           FSpinner := CreateSpinner(ssDots);
91.           FSpinner.Start;
92.  
93.           http.AllowRedirect:= True;
94.           http.KeepConnection:= False;
95.  
96.           FSpinner.Update(0);
97.           TConsole.Write(' Calling HEAD');
98.  
99.           http.HTTPMethod('HEAD', url, nil, []);
100.           FSize := 0;
101.           for index := 0 to Pred(http.ResponseHeaders.Count) do
102.           begin
103.             if LowerCase(http.ResponseHeaders.Names[index]) = 'content-length' then
104.             begin
105.               FSize:= StrToInt64(http.ResponseHeaders.ValueFromIndex[index]);
106.               FSpinner.Update(0);
107.               TConsole.Write(Format(' Got Size: %d; Status(%d): %s', [
108.                 FSize,
109.                 http.ResponseStatusCode,
110.                 http.ResponseStatusText
111.               ]));
112.               break;
113.             end;
114.           end;
115.           Sleep(2000);
116.  
117.           FSpinner.Update(0);
118.           TConsole.Write(' Calling GET                                    ');
119.           http.OnDataReceived:=@OnDataReceived;
120.           http.HTTPMethod(
121.             'GET',
122.             url,
123.             FStream,
124.             codes
125.           );
126.           FSpinner.Stop;
127.           TConsole.WriteLn(Format('Status(%d): %s', [http.ResponseStatusCode, http.ResponseStatusText]));
128.         except
129.           on E:Exception do
130.           begin
131.             Result:= 1;
132.             TConsole.WriteLn('ERROR: ' + E.Message, ccRed);
133.           end;
134.         end;
135.       finally
136.         FStream.Free;
137.       end;
138.     finally
139.       http.free;
140.     end;
141.   end
142.   else
143.   begin
144.     Result:= 1;
145.     TConsole.WriteLn('ERROR: No URL to download', ccRed);
146.   end;
147. end;
148.  
149. end.

As you can see I have:

• Created a codes variable with a ton of HTTP Status codes.
• Put a call to HEAD because the first 4 or 5 calls to OnDataReceived come with the total at zero
• A try..except around the entire transfer code

While testing it, no matter the speed that my provider's allowing me, I get consistent download drop at around 74%, I know this is a clue, just not figured what it means yet.
This only happens in HTTPS not HTTP. I've tested both and the HTTP completes every time, no issue.
The call to HTTPMethod never triggers any exception and always returns 200 OK.
It only happens on files above 10MB. I've tested with files of ~1MB and it downloads it fine, but with files of 11MB, 16MB and 17MB it drops.
I've tested with aria2c, wget and cURL. They download the file without any issue.

One of the things that bothers me is the fact that FPHHTPClient swallows any/all exception. I don't think that we get anything going bad if it happens at the SSL level. Which is where my suspicions are at the moment. I don't think it's chunking, but I'm not sure.

My suspicions, at the moment are: It's either an SSL issue, or a chunking issue.

Since I don't want to post an issue on GitLab to something that can only be reproduced with my own phone's tethering, I need some help to debug. I'm quite unfamiliar with the code and the hierarchy of the Classes that it's just a black box at the moment.

Why all this? Welp, I did a GUI downloader that is now used on fpcupdeluxe, and it fails miserably  . I need to get to the bottom of this in order to not disappoint it's author!!

Can someone give me some pointers to where I should dig in?
Many thanks in advance!!

Cheers,
Gus

[dbannon]

Gee Gus, I just do this, first few line important. Most of the code is excepton handling and reporting. As you can see, fpHTPclient generates lots of exceptions for me. I have, during testing, seen then all.

The downloaded file, in my case, text (md) or xml, ends up in Somestring and is never truncated.

Code: Pascal  [Select][+][-]

1. function TMistySync.Downloader(URL : string; out SomeString : String; const ConType : TContentType; const Header : string = '') : boolean;
2. var
3.     Client: TFPHTTPClient;
4. begin
5.     if DebugMode then debugln('TMistySync.Downloader URL is ' + URL);
6.     Client := TFPHttpClient.Create(nil);
7.     Client.UserName := UserName;
8.     Client.Password := Password; // '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';     eg a github token
9.     Client.AddHeader('User-Agent','Mozilla/5.0 (compatible; fpweb)');
10.     case ConType of
11.         ctXML : Client.AddHeader('Content-Type','application/xml; charset=UTF-8');
12.         ctText : Client.AddHeader('Content-Type','application/text; charset=UTF-8');
13.         ctJSON : Client.AddHeader('Content-Type','application/json; charset=UTF-8');
14.         ctHTML : Client.AddHeader('Content-Type','application/HTML; charset=UTF-8');
15.     end;
16.     Client.AllowRedirect := true;
17.     Client.ConnectTimeout := 8000;      // mS ?  was 3000, I find initial response from github very slow ....
18.     Client.IOTimeout := 4000;           // mS ? was 0
19.     SomeString := '';
20.     try
21.         try
22.             SomeString := Client.Get(URL);
23.         except
24.             on E: EHTTPClient do begin                                          // eg, File Not Found, we have asked for an unavailable file
25.                 ErrorString := 'TMistySync.Downloader - EHTTPClient Error ' + E.Message
26.                     + ' ResultCode ' + inttostr(Client.ResponseStatusCode);
27.                 exit(SayDebugSafe(ErrorString));
28.             end;
29.             on E: ESocketError do begin
30.                 ErrorString := 'TMistySync.Downloader - SocketError ' + E.Message     // eg failed dns, timeout etc
31.                     + ' ResultCode ' + inttostr(Client.ResponseStatusCode);
32.                 SomeString := 'Fatal, is server availale ?';
33.                 exit(SayDebugSafe(ErrorString));
34.                 end;
35.             on E: EInOutError do begin
36.                 ErrorString := 'TMistySync Downloader - InOutError ' + E.Message;
37.                 // might generate "TGithubSync Downloader - InOutError Could not initialize OpenSSL library"
38.                 SomeString := 'Failed to initialise OpenSSL';           // is error message translated ?
39.                 exit(SayDebugSafe(ErrorString));
40.                 end;
41.             on E: ESSL do begin
42.                 ErrorString := 'TMistySync.Downloader - SSLError ' + E.Message;         // eg openssl problem, maybe FPC cannot work with libopenssl
43.                 SomeString := 'Failed to work with OpenSSL';
44.                 exit(SayDebugSafe(ErrorString));
45.                 end;
46.             on E: Exception do begin
47.                 ErrorString := 'TMistySync.Downloader Unexpected Exception ' + E.Message + ' downloading ' + URL;
48.                 ErrorString := ErrorString + ' HTTPS error no ' + inttostr(Client.ResponseStatusCode);
49.                 exit(SayDebugSafe(ErrorString));
50.                 end;
51.         end;
52.         Result := Client.ResponseStatusCode = 200;
53.         // My version of this in GitHubSync then did some processing of Client.ResponseHeaders,  not necessary here.
54.     finally
55.         Client.Free;
56.     end;
57. end;

             

Davo

[440bx]

@Davo,

I've been looking for some documentation for TFPHttpClient but, it looks like I may have looked in all the wrong places.

Based on the code you posted above, it seems like you may know of where it is documented and, if so, I'd really appreciate it if you shared where that documentation is found.

Thank you in advance.

[Gustavo 'Gus' Carreno]

Hey Davo,

Wow, that's a freekin' humongous list of Exceptions, that is LOL!!!

Thank you so very much for sharing that code!! That does inform me of a lot of stuff and I'll look at it better and compare with my code!!

Nonetheless, the thing that frustrates me the most is the fact that I get NO exceptions at all, and to add injury to insult, it returns 200 OK.

What I'm guessing is that the SSL layer, somehow drops the stream, but for some reason the issue does not bubble up to Pascal land. Somehow, Pascal land interpretes the stream drop as a completion and then happily spits out a 200 OK 

My connection, during peek times is abysmal. That has given me the opportunity to memorize a lot of errors that other apps dish out when they can't download.
A lot of errors telling me that the SSL handshake timed out, or that the SSL layer had an unexpected EOF and much more.
With that knowledge, I think a premature EOF is happening at the SSL layer, but for some mysterious reason, it doesn't bubble up to Pascal land...
Cuz, you have to remember that it always drops at ~74%. And that's consistent !! So, the connection goes through, it pull about 74% of data and then all of a sudden BOOM, drops...

Welp, I've ranted enough about this...

Cheers,
Gus

[dbannon]

Well Gus, all the exceptions listed there do happen and do pop up as an exception. I got the basic thing happening and deliberately provoked errors, caught them. That included using, at the time, a very flaky network connection, while totally out of control, useful for testing. I cannot imagine why yours fail silently. The fpc httpserver does handle some mystery exceptions internally, you see it when running under the debugger. Maybe same thing ?

440bx, no, no secrets I am afraid. What you see there is from the examples in the compiler (use fpc324-branch, not fpc322) and the wiki. And a lot of experimenting, especially, as noted, the error handling.

That code was first used in a Github API sync, https://github.com/tomboy-notes/tomboy-ng/blob/master/source/transgithub.pas and it now reused in another unit that will talk directly to the fpc httpserver. That is a work in progress.

Davo

[440bx]

440bx, no, no secrets I am afraid. What you see there is from the examples in the compiler (use fpc324-branch, not fpc322) and the wiki. And a lot of experimenting, especially, as noted, the error handling.

That code was first used in a Github API sync, https://github.com/tomboy-notes/tomboy-ng/blob/master/source/transgithub.pas and it now reused in another unit that will talk directly to the fpc httpserver. That is a work in progress.

Davo

I now see your knowledge was the product of genuine sweat (just like most of the little bit of knowledge I have about it.)  Thank you for clarifying the source of your knowledge in that area.

[Thaddy]

The real TFPHTTPClient does not swallow exceptions. Why do you think so? That is the first thing that draws my attention. That statement is plainly not true. It is written by the core team and they do not swallow exceptions because that is bad coding.

The cause can be a problem with the frame size (I encountered that in the past) but that would be a problem in ssockets or sockets, not FPHttpClient. Although the bug I referred to above was actually that the remote connection used a non-standard frame size (1500 instead of 1512)

[MarkMLl]

Although the bug I referred to above was actually that the remote connection used a non-standard frame size (1500 instead of 1512)

And OP (Gus) specifically says that he gets the problem with a tethered 'phone: I've previously seen non-standard MTU/frame size in this context because the carrier is using a tunneling protocol.

MarkMLl

[Thaddy]

Googling a bit deeper, it seems the most likely case. In my example 1500 is the payload, excluding overhead so the frame becomes too small. Usually PMTUD should solve this and is usually implemented.
If not, you get frame drift and that brings MTU down eventually.
That will also explain the ~75% mark depending on size.
(Because of (1500/1512)/ div 2)
So we need to focus on that, but then I need some more code.
If Path MTU isn't working, packages get dropped mid-stream.
I think that is what is happening here.

This is a noughty one.... Although it is known in theory and practice.

Do you have an exact URL to which I can test? And what are the exact versions of THttpClient and opensslsockets you are using?

[Gustavo 'Gus' Carreno]

Hey Thaddy,

The real TFPHTTPClient does not swallow exceptions. Why do you think so? That is the first thing that draws my attention. That statement is plainly not true. It is written by the core team and they do not swallow exceptions because that is bad coding.

You're absolutely right!! This was made evident when Davo dropped his code.

My only excuse, and it's a really bad one, is that I never got an exception in the past. So, yeah, mea culpa all the way !!!

The cause can be a problem with the frame size (I encountered that in the past) but that would be a problem in ssockets or sockets, not FPHttpClient. Although the bug I referred to above was actually that the remote connection used a non-standard frame size (1500 instead of 1512)

Hummm.... This is above my pay grade, and I'll need a bit more info so I can look at the appropriate code lines to test that...

Cheers,
Gus

[Thaddy]

It is likely solvable by using a smaller MTU frame size. That would be slightly slower, but then the whole protocol chain will be such that it can easier recover. Try specifying e.g. 512.
As I wrote: I encountered this issue only once but it is not uncommon. And many lost a lot of hair, pulled out, and now need a whig.

[Gustavo 'Gus' Carreno]

Hey Thaddy,

Googling a bit deeper, it seems the most likely case. In my example 1500 is the payload, excluding overhead so the frame becomes too small. Usually PMTUD should solve this and is usually implemented.
If not, you get frame drift and that brings MTU down eventually.
That will also explain the ~75% mark depending on size.
(Because of (1500/1512)/ div 2)
So we need to focus on that, but then I need some more code.
If Path MTU isn't working, packages get dropped mid-stream.
I think that is what is happening here.

I'll take your word for it

This is a noughty one.... Although it is known in theory and practice.

Indeed it is !!

Do you have an exact URL to which I can test? And what are the exact versions of THttpClient and opensslsockets you are using?

This has been happening for some years now, so I'm gonna say any version.
I've been doing my testing with Lazarus [3.6, 4.0, 4.99] and FPC [3.2.2, 3.3.1].
I'm using this URL: https://github.com/LongDirtyAnimAlf/fpcupdeluxe/releases/download/darwin_arm64_crossbins_all/Embedded_riscv32_unknown_V240.zip in particular, but I suspect any SSL one will do.

What baffles me the most is that I've now tested: cURL, wget, aria2c, a program in Go, a program in Zig and they all work with no issues.
I was unable to test Indy because it errors out with the LCL on a CLI only program. I did try on a GUI app, and ran into OpenSSL versioning shenanigans
I was unable to test with synapse 40.1 because of OpenSSL versioning shenanigans.
Both Indy and synapse 40.1 are from the current OPM versions.
It's only FPHTClient that drops the ball at ~%74, consistently, in the case of the above file size ~16MiB.
Also of note: If I DON'T use my phone as the tether, I have no issue what so ever !!

Hope that helps!!

EDIT: I'm adding the code that I'm using for the tests.

Cheers,
Gus

[Gustavo 'Gus' Carreno]

Hey Thaddy,

It is likely solvable by using a smaller MTU frame size. That would be slightly slower, but then the whole protocol chain will be such that it can easier recover. Try specifying e.g. 512.
As I wrote: I encountered this issue only once but it is not uncommon. And many lost a lot of hair, pulled out, and now need a whig.

Please provide me the line of code where I can change the MTU. I'm not quite sure where that is. I'm guessing in the Socket somewhere, but I', too ignorant to be sure!!

Cheers,
Gus

[Thaddy]

Hm. Seems to need a patch or two...
We have to adapt TInetSocket a bit, or I can prepare a hack for it. Come back later. It is not a big fix.

[Gustavo 'Gus' Carreno]

Hey Thaddy,

I remember that Ubuntu has a way to set the MTU on the wired connection settings.

I'll do some testing with the 512 value you proposed. I'll relay the results once my connection is not capped at ~20KiB/s 

Cheers,
Gus