[libmicrohttpd] Busy waiting up to one second using connection timeout

[Irion, Alexander]

Hello!

I discovered a problem with closing connections, when 
MHD_OPTION_CONNECTION_TIMEOUT is used. When I set the timeout option to 3 
seconds and connect with a browser, I get a timeout value from 
MHD_get_timeout() of 3000 ms returned. I then sleep the desired time and call 
MHD_run again(). Then, MHD_get_timeout() returns repetitive a timeout of 0 
which causes thousands of calls to MHD_run(), taking up several hundred 
milliseconds and burning CPU time.

I use an external event loop with MHD_DAEMON_INFO_EPOLL_FD.

As reason I found that the condition  timeout < (MHD_monotonic_sec_counter () - 
connection->last_activity) will not be true, after waiting the timeout time. 
The right side will be equal to timeout, so the connection is not closed, 
MHD_get_timeout() continues to return a timeout value of 0, and this runs 
repetitively in a loop for some thousand iterations, until the time jumps to 
the next second.

In the attachment please find a small patch for fixing this issue. It's just 
turning the < into a <=.

Regards,
Alexander Irion

-
Siemens Electronic Design Automation GmbH; Anschrift: Arnulfstraße 201, 80634 
München; Gesellschaft mit beschränkter Haftung; Geschäftsführer: Thomas 
Heurung, Frank Thürauf; Sitz der Gesellschaft: München; Registergericht 
München, HRB 106955
From eb6e3c9c7b6c50ac71c2922d95c35f5faeed9b85 Mon Sep 17 00:00:00 2001
From: Alexander Irion 
Date: Wed, 11 Aug 2021 17:13:12 +0200
Subject: [PATCH] Fix busy waiting up to one second using connection timeout

MHD_daemon_get_timeout computes the time to wait as:
timeout = (last_activity + connection_timeout - MHD_monotonic_sec_counter ()) * 1000

After sleeping timeout milliseconds, MHD_monotonic_sec_counter () will be:

MHD_monotonic_sec_counter () = last_activity + connection_timeout

With that (timeout < (MHD_monotonic_sec_counter () - connection->last_activity)) evaluates to false and the MHD_connection_close_ is not done.
For the next cycle, MHD_daemon_get_timeout() will return 0 and this goes on, until MHD_monotonic_sec_counter jumps to the next second.

This bug causes thousands of unnecessary calls to MHD_run, when a connection timed out.
---
 src/lib/connection_call_handlers.c | 4 ++--
 src/microhttpd/connection.c| 4 ++--
 2 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/src/lib/connection_call_handlers.c b/src/lib/connection_call_handlers.c
index aa082ebb..5f2b9d24 100644
--- a/src/lib/connection_call_handlers.c
+++ b/src/lib/connection_call_handlers.c
@@ -3582,8 +3582,8 @@ MHD_request_handle_idle_ (struct MHD_Request *request)
 time_t timeout;
 timeout = connection->connection_timeout;
 if ( (0 != timeout) &&
- (timeout < (MHD_monotonic_sec_counter ()
- - connection->last_activity)) )
+ (timeout <= (MHD_monotonic_sec_counter ()
+  - connection->last_activity)) )
 {
   MHD_connection_close_ (connection,
  MHD_REQUEST_TERMINATED_TIMEOUT_REACHED);
diff --git a/src/microhttpd/connection.c b/src/microhttpd/connection.c
index b2d285e3..f4cd774b 100644
--- a/src/microhttpd/connection.c
+++ b/src/microhttpd/connection.c
@@ -4304,8 +4304,8 @@ MHD_connection_handle_idle (struct MHD_Connection *connection)
 time_t timeout;
 timeout = connection->connection_timeout;
 if ( (0 != timeout) &&
- (timeout < (MHD_monotonic_sec_counter ()
- - connection->last_activity)) )
+ (timeout <= (MHD_monotonic_sec_counter ()
+  - connection->last_activity)) )
 {
   MHD_connection_close_ (connection,
  MHD_REQUEST_TERMINATED_TIMEOUT_REACHED);
-- 
2.30.2

Re: [libmicrohttpd] Busy waiting up to one second using connection timeout

[Irion, Alexander]

I would say that the timer granularity and the fix are two different things, 
even if granularity would be finer, the checking condition like before was 
wrong and would lead to unnecessary busy cycles. Is a timeout of only one 
second a real use case? In any way, your example below would result in a 
returned timeout value of 1000ms, so you would sleep 1s into the external poll, 
before calling MHD_run() again. So, in fact it would be closed at 51.999. 
However, yes - when a new event would come in shortly after 50.999 this would 
trigger the connection close earlier.
--Alex


The report itself is correct, thanks for this!

However while the patch fixed one problem, it creates another one.
The problem connected to low granularity (rounded to one second) of the
MHD's internal timer. If connection timeout is set to one second (for
example) then connection may expire at any moment up to one second with
the patch applied.
A full example: if activity is recorded at 50.999 seconds, which is
rounded to 50 internally, then connection with 1 second timeout can be
closed at 51.0, which is not what is expected by user.

The proper solution would be increase of the resolution of the internal
MHD timer.
I'll handle it.

--
Evgeny

On 11.08.2021 23:39, Christian Grothoff wrote:
> Thanks for the detailed report, the patch looks good as-is, applied to
> master as
>
> f5d387df7e7fb8de1a5dd0739ddb83a8b19fe64b
>
> Happy hacking!
>
> Christian
>
> On 8/11/21 6:02 PM, Irion, Alexander wrote:
>> Hello!
>>
>> I discovered a problem with closing connections, when
>> MHD_OPTION_CONNECTION_TIMEOUT is used. When I set the timeout option to
>> 3 seconds and connect with a browser, I get a timeout value from
>> MHD_get_timeout() of 3000 ms returned. I then sleep the desired time and
>> call MHD_run again(). Then, MHD_get_timeout() returns repetitive a
>> timeout of 0 which causes thousands of calls to MHD_run(), taking up
>> several hundred milliseconds and burning CPU time.
>>
>> I use an external event loop with MHD_DAEMON_INFO_EPOLL_FD.
>>
>> As reason I found that the condition  timeout <
>> (MHD_monotonic_sec_counter () - connection->last_activity) will not be
>> true, after waiting the timeout time. The right side will be equal to
>> timeout, so the connection is not closed, MHD_get_timeout() continues to
>> return a timeout value of 0, and this runs repetitively in a loop for
>> some thousand iterations, until the time jumps to the next second.
>>
>> In the attachment please find a small patch for fixing this issue. It's
>> just turning the < into a <=.
>>

-
Siemens Electronic Design Automation GmbH; Anschrift: Arnulfstraße 201, 80634 
München; Gesellschaft mit beschränkter Haftung; Geschäftsführer: Thomas 
Heurung, Frank Thürauf; Sitz der Gesellschaft: München; Registergericht 
München, HRB 106955

[libmicrohttpd] Fix: Remove double adding of MHD_HTTP_HEADER_CONNECTION response header

[Irion, Alexander]

Please, see the attached small fix:

Remove double adding of MHD_HTTP_HEADER_CONNECTION response header

MHD_create_response_for_upgrade() already adds the MHD_HTTP_HEADER_CONNECTION 
response header, so
the additional MHD_add_response_header is wrong.

In our application it caused, that on a Apple iPad, the websocket was 
immediately closed by the
browser(Safari, Chrome, Opera) after the protocol upgrade. Browsers on Linux, 
Android did not had this issue.

Signed-off-by: Alexander Irion 
alexander_ir...@mentor.com

-
Siemens Electronic Design Automation GmbH; Anschrift: Arnulfstra?e 201, 80634 
M?nchen; Gesellschaft mit beschr?nkter Haftung; Gesch?ftsf?hrer: Thomas 
Heurung, Frank Th?rauf; Sitz der Gesellschaft: M?nchen; Registergericht 
M?nchen, HRB 106955


0001-Remove-double-adding-of-MHD_HTTP_HEADER_CONNECTION-r.patch
Description: 0001-Remove-double-adding-of-MHD_HTTP_HEADER_CONNECTION-r.patch