Fix for erroneous MG_EV_HTTP_CHUNK

[david-collett]

Do not send MG_EV_HTTP_CHUNK if chunk len would be zero and
response is not yet fully received.

This can occur in circumstances where the first socket read
contains only the header (no data). In this case, the calculated
chunk length is zero.

[david-collett]

This issue can be observed using the http-streaming-client example with a local URL to a file served with pythons http server.

e.g. (client):

dave@dave-internet:~/code/mongoose/examples/http-streaming-client$ ./example http://localhost:8000/words
d3f2b9ad 3 net.c:184:mg_connect         1 -1 http://localhost:8000/words
d3f2b9ad 3 sock.c:375:mg_connect_resolv 1 0x3 -> 7f000001:8000 pend
d3f2b9ad 3 sock.c:307:write_conn        1 0x3 snd 88/2048 rcv 0/0 n=88 err=115
d3f2b9b4 3 sock.c:296:read_conn         1 0x3 snd 0/2048 rcv 0/2048 n=203 err=115
d3f2b9b4 3 net.c:161:mg_close_conn      1 closed
d3f2b9b4 3 net.c:243:mg_mgr_free        All connections closed

server:

dave@dave-internet:~$ cd /usr/share/dict
dave@dave-internet:/usr/share/dict$ python3 -m http.server
Serving HTTP on 0.0.0.0 port 8000 (http://0.0.0.0:8000/) ...
127.0.0.1 - - [03/Aug/2022 16:56:51] "GET /words HTTP/1.1" 200 -
----------------------------------------
Exception occurred during processing of request from ('127.0.0.1', 59374)
Traceback (most recent call last):
  File "/usr/lib/python3.9/socketserver.py", line 683, in process_request_thread
    self.finish_request(request, client_address)
  File "/usr/lib/python3.9/socketserver.py", line 360, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "/usr/lib/python3.9/http/server.py", line 653, in __init__
    super().__init__(*args, **kwargs)
  File "/usr/lib/python3.9/socketserver.py", line 747, in __init__
    self.handle()
  File "/usr/lib/python3.9/http/server.py", line 427, in handle
    self.handle_one_request()
  File "/usr/lib/python3.9/http/server.py", line 415, in handle_one_request
    method()
  File "/usr/lib/python3.9/http/server.py", line 660, in do_GET
    self.copyfile(f, self.wfile)
  File "/usr/lib/python3.9/http/server.py", line 860, in copyfile
    shutil.copyfileobj(source, outputfile)
  File "/usr/lib/python3.9/shutil.py", line 208, in copyfileobj
    fdst_write(buf)
  File "/usr/lib/python3.9/socketserver.py", line 826, in write
    self._sock.sendall(b)
ConnectionResetError: [Errno 104] Connection reset by peer
----------------------------------------

With the fix in place, it will instead print the file (word list).

I think http.server (and probably others) send only the header in the first packet. Depending on timing, this results in hitting this bug and the client will not print the resource. This happens to me more often than not, but not always. Client logic is (correctly) to consider the response complete on receiving a chunk of zero length.

[scaprile]

I think http.server (and probably others) send only the header in the first packet

Can you please run Wireshark and check what is actually going on ? Please post the capture file (preferably with no other traffic)

[cpq]

I think @david-collett observes a situation when a server sends headers, then pauses, then sends a body. Mongoose client receives headers, then tries to send a HTTP chunk - and since no content is sent by a server YET, it report a zero chunk which is a marker for the end of data.

That situation should definitely be covered by the unit test.
The one who feels brave, please go ahead and add a failing unit test that covers a "zero chunk" situation. Otherwise, I'll add that myself .

[david-collett]

@cpq is correct.
Here's a pcap for what its worth. A unit test should be easy enough to create.

test.zip

[scaprile]

Yeap, that can be clearly seen in the capture. The server pauses after sending the whole headers and starts sending the body ~100us later, but the client has already disconnected.

[scaprile]

Check PR #1658
(uncommenting the MG_INFO line shows CHUNK[] detecting the zero length chunk at start)

[david-collett]

Yeah, that test reproduces the issue in the eh5 handler. The patch in this PR passes the test.

[cpq]

I've refactored MG_EV_HTTP_CHUNK functionality, to make it predictable and stable.
Before the change, HTTP chunks delivery depended on how server received data.
Now, the flow of chunks must be sequential and predictable.
chunks get sent in order until whole body is buffered - which is marked by the zero-length chunk.
If chunks were deleted, then MG_EV_HTTP_MSG is not fired. Otherwise, it is fired.

[cpq]

@david-collett could you pull the change and test on your code please?

[david-collett]

I believe your changes may introduce a problem, but I don't have time to fully debug it now, instead I will describe what I am seeing.

I have test code that does a HTTP get, followed by another HTTP get on the same connection (pipelining). The resource requested is very small (8 bytes).

In the old code I got a MSG callback for each request with the 8 bytes of the resource.

With the new code, I get a CHUNK callback of 8 bytes, followed by a CHUNK callback if 0 bytes for the first request (no MSG callbacks as I am deleting chunks), and the data is good. So far so good.

But for the second response, I seem to get the two CHUNK callbacks(8, 0), followed by a MSG callback with 16 bytes containing data of HTTP. The CHUNK callback has 200 OK as the bytes and the MSG callback has HTTP 1.1 etc. mongoose subsequently logs http parsing errors. So I think the buffers / state are not properly reset between the two responses?

[david-collett]

I have replied in the original PR about a possible issue with your changes.

…

On Fri, 5 Aug 2022 at 02:11, Sergey Lyubka ***@***.***> wrote: @david-collett <https://github.com/david-collett> could you pull the change and test on your code please? — Reply to this email directly, view it on GitHub <#1656 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ABJPAEO36AUUJA6ZQLBAB3TVXPTS5ANCNFSM55NUZIGA> . You are receiving this because you were mentioned.Message ID: ***@***.***>

[cpq]

@david-collett I confirm the issue with the pipelined requests. Going to add a unit test and a fix for it.

[cpq]

@david-collett please pull the latest, and test again.
This commit 779c825 fixed the pipelining behavior

[david-collett]

Unfortunately I get exactly the same result with this patch.
I can see that your test cases in test_http_chunked is testing this. The only difference I can see with my code is that I am not sending the second request until after receiving the first response (which would be typical of a normal use-case), I will try to refactor the test to do this and see if it passes.

[david-collett]

Ok, I found the problem.
The receive buffer is not correctly reset in deliver_normal_chunks if the whole response is received in a single read. The problem is that deleted is initially false and is not re-evaluated after delivering the data chunk and before sending the zero chunk and performing the mg_iobuf_del.

The following fixes it:

--- a/mongoose.c
+++ b/mongoose.c
@@ -2332,6 +2332,7 @@ static void deliver_normal_chunks(struct mg_connection *c, size_t hlen,
   if (hm->chunk.len > 0) mg_call(c, MG_EV_HTTP_CHUNK, hm);
   processed += hm->chunk.len;
   if (processed >= hm->body.len) {     // Last, 0-len chunk
+    deleted = ((size_t) c->pfn_data) & MG_DMARK;
     hm->chunk.len = 0;                 // Reset length
     mg_call(c, MG_EV_HTTP_CHUNK, hm);  // Call user handler
     c->pfn_data = NULL;                // Reset processed counter

[david-collett]

This case can be tested as follows:

diff --git a/test/unit_test.c b/test/unit_test.c
index 6e536e78..dce65ab1 100644
--- a/test/unit_test.c
+++ b/test/unit_test.c
@@ -1909,6 +1909,14 @@ static void eY(struct mg_connection *c, int ev, void *ev_data, void *fn_data) {
   (void) ev_data, (void) fn_data;
 }
 
+static void eYb(struct mg_connection *c, int ev, void *ev_data, void *fn_data) {
+  if (ev == MG_EV_HTTP_MSG) {
+    mg_printf(c, "HTTP/1.1 200 OK\r\nContent-Length: 4\r\n\r\nabcd");
+    c->is_resp = 0;
+  }
+  (void) ev_data, (void) fn_data;
+}
+
 // Do not delete chunks as they arrive
 static void eh4(struct mg_connection *c, int ev, void *ev_data, void *fn_data) {
   uint32_t *crc = (uint32_t *) fn_data;
@@ -1965,6 +1973,8 @@ static void test_http_chunked(void) {
   test_http_chunked_case(eY, eh5, 1, "axbcxdxx");      // Chunks deleted
   test_http_chunked_case(eY, eh4, 2, "axbcxdxxabcdaxbcxdxxabcd");
   test_http_chunked_case(eY, eh5, 2, "axbcxdxxaxbcxdxx");
+  test_http_chunked_case(eYb, eh5, 1, "abcdxx");
+  test_http_chunked_case(eYb, eh5, 2, "abcdxxabcdxx");
 
   // Chunked encoding
   test_http_chunked_case(eX, eh4, 1, "axbxcxdxxabcd");  // Chunks not deleted

[cpq]

@david-collett thank you for taking your time to test, dig and fix!
Pushed 740b609

[david-collett]

no worries!

…

On Sat, 6 Aug 2022 at 18:02, Sergey Lyubka ***@***.***> wrote: @david-collett <https://github.com/david-collett> thank you for taking your time to test, dig and fix! Pushed 740b609 <740b609> — Reply to this email directly, view it on GitHub <#1656 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ABJPAENNXMSG5RWBYFHUYLTVXYLZPANCNFSM55NUZIGA> . You are receiving this because you were mentioned.Message ID: ***@***.***>

[cpq]

@david-collett does the the latest HEAD work as expected?

[david-collett]

Yep, its working for me, thanks.