http: Track active requests and wait for last to finish #19420

promag · 2020-06-30T10:38:41Z

This PR calls evhttp_free before releasing event base. But according to evhttp_free docs:

Works only if no requests are currently being served.

So this PR also tracks active requests with libevent and waits for last request to finish. This requires libevent 2.1 due to evhttp_request_set_on_complete_cb (https://github.com/libevent/libevent/blob/master/whatsnew-2.1.txt).

Finally, the call to evhttp_free is done in the event base loop to avoid concurrency issues.

Now test/functional/feature_abortnode.py quits normally, not due to socket timeouts.

promag · 2020-06-30T10:51:44Z

~~Minimal fix in #15363.~~

DrahtBot · 2020-06-30T12:59:16Z

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Conflicts

No conflicts as of last run.

promag · 2020-07-01T13:54:54Z

@laanwj ping, again 😅

promag · 2020-07-03T01:34:17Z

There is an issue which is fixed in #19434 - complete callback isn't called if client closes the connection.

jonatack · 2020-07-05T10:24:45Z

Interesting! -- this PR brings the run time of test/functional/feature_abortnode.py for me, with a debug build, from 32 seconds down to only 2.

jonatack

Concept ACK, the code looks fine, tests pass and feature_abortnode.py for instance runs much faster.

Also, you may want to see libevent/libevent#643 and libevent/libevent#591.

fjahr · 2021-05-18T22:36:03Z

Concept ACK

promag · 2022-03-21T19:25:17Z

@laanwj don't you miss reviewing this code? 😅

jonatack · 2022-03-23T11:25:10Z

So this PR also tracks active requests with libevent and waits for last request to finish. This requires libevent 2.1 due to evhttp_request_set_on_complete_cb (libevent/libevent@master/whatsnew-2.1.txt).

Does this change require bumping the minimum enforced libevent version from 2.0.21 to 2.1?

promag · 2022-03-23T11:27:21Z

@jonatack yes, I think it should be fine, cc @hebasto

jonatack

Light approach ACK ea724b9 based on code review, looked at the libevent repo, doc/dependencies and configure.ac, rebased, debug build, ran unit tests, re-verified that test/functional/feature_abortnode.py runs far faster (under 2 seconds with debug build on a slow CPU), ran mainnet/signet/testnet nodes with http logging on and made a few CLI calls, checked nodes shutdown. Modulo we would need to bump the minimum required version of libevent from 2.0.21 to 2.1.

debug log on signet shutdown

2022-03-23T11:57:59Z [http] Received a POST request for / from 127.0.0.1:33432
2022-03-23T11:57:59Z [init] Interrupting HTTP server
2022-03-23T11:57:59Z [init] tor: Thread interrupt
2022-03-23T11:57:59Z [init] Shutdown: In progress...
2022-03-23T11:57:59Z [shutoff] Unregistering HTTP handler for / (exactmatch 1)
2022-03-23T11:57:59Z [shutoff] Unregistering HTTP handler for /wallet/ (exactmatch 0)
2022-03-23T11:57:59Z [shutoff] Stopping HTTP server
2022-03-23T11:57:59Z [shutoff] Waiting for HTTP worker threads to exit
2022-03-23T11:57:59Z [addcon] addcon thread exit
2022-03-23T11:57:59Z [torcontrol] RemoveLocal(xxx.onion:38333)
2022-03-23T11:57:59Z [torcontrol] torcontrol thread exit
2022-03-23T11:57:59Z [opencon] opencon thread exit
2022-03-23T11:57:59Z [http] Exited http event loop
2022-03-23T11:57:59Z [shutoff] Waiting for HTTP event thread to exit
2022-03-23T11:57:59Z [shutoff] Stopped HTTP server
2022-03-23T11:57:59Z [net] net thread exit
2022-03-23T11:57:59Z [msghand] msghand thread exit
2022-03-23T11:58:00Z [i2paccept] i2paccept thread exit
2022-03-23T11:58:00Z [shutoff] DumpAnchors: Flush 2 outbound block-relay-only peer addresses to anchors.dat started
2022-03-23T11:58:00Z [shutoff] DumpAnchors: Flush 2 outbound block-relay-only peer addresses to anchors.dat completed (0.01s)
2022-03-23T11:58:00Z [scheduler] scheduler thread exit
2022-03-23T11:58:00Z [shutoff] I2P: Destroying session 99c6a79e84
2022-03-23T11:58:00Z [shutoff] Writing 0 unbroadcast transactions to disk.
2022-03-23T11:58:00Z [shutoff] Dumped mempool: 7.4e-05s to copy, 0.008535s to dump
2022-03-23T11:58:00Z [shutoff] [default wallet] Releasing wallet
2022-03-23T11:58:00Z [shutoff] [blank] Releasing wallet
2022-03-23T11:58:00Z [shutoff] [encrypted blank descriptor] Releasing wallet
2022-03-23T11:58:00Z [shutoff] [disable private keys] Releasing wallet
2022-03-23T11:58:00Z [shutoff] [disable private keys and blank] Releasing wallet
2022-03-23T11:58:00Z [shutoff] [default settings] Releasing wallet
2022-03-23T11:58:00Z [shutoff] Shutdown: done

Commit message: "http: Relese server before waiting for event base loop exit" -> s/Relese/Release/

jonatack · 2022-03-23T11:39:25Z

src/httpserver.cpp

@@ -146,6 +146,10 @@ static std::unique_ptr<WorkQueue<HTTPClosure>> g_work_queue{nullptr};
 static std::vector<HTTPPathHandler> pathHandlers;
 //! Bound listening sockets
 static std::vector<evhttp_bound_socket *> boundSockets;
+//! Track active requests
+static Mutex g_requests_mutex;
+static std::condition_variable g_requests_cv;


662cba4 maybe add these headers

--- a/src/httpserver.cpp +++ b/src/httpserver.cpp @@ -21,8 +21,10 @@ #include <util/threadnames.h> #include <util/translation.h> +#include <condition_variable> #include <deque> #include <memory> +#include <mutex> #include <stdio.h>

jonatack · 2022-03-23T11:50:26Z

src/httpserver.cpp

+        }
+    }
+    if (eventHTTP) {
+        event_base_once(eventBase, -1, EV_TIMEOUT, [](evutil_socket_t, short, void*) {


ea724b9 curious why you added this line (maybe describe the change in the commit message)

The other place in this codebase that calls event_base_once() to schedule a one-time event is torcontrol.cpp in InterruptTorControl.

This is a way to call evhttp_free in the event base thread, meaning it's not called concurrently with the handling of unfinished request connections.

hebasto · 2022-03-26T08:03:07Z

Does this change require bumping the minimum enforced libevent version from 2.0.21 to 2.1?

Done in #24681.

…to 2.1.8 e40779a refactor: Remove outdated libevent logging code (Fabian Jahr) 0598f36 refactor: account for requiring libevent 2.1.8+ (fanquake) aaf72d6 build: Bump libevent minimum version up to 2.1.8 (Hennadii Stepanov) Pull request description: Required to support new functionality in bitcoin/bitcoin#19420. `libevent` availability: https://repology.org/project/libevent/versions ACKs for top commit: laanwj: Code review ACK e40779a fanquake: ACK e40779a Tree-SHA512: ccb14ea2f591484a3df5bc4a19f4f5400ef6b1cfb7dc45dd99f96cb948748215ed3b5debc34869763c91b8c7a26993fdb9b870950c0743c4d01038ab27c5e4e2

achow101 · 2022-10-12T18:10:47Z

Are you still working on this?

achow101 · 2022-11-10T17:12:29Z

Closing this as it has not had any activity in a while. If you are interested in continuing work on this, please leave a comment so that it can be reopened.

fjahr · 2022-12-22T18:50:13Z

I have reopened this PR in #26742. Comments by @jonatack have been addressed.

… - 2nd attempt 60978c8 test: Reduce extended timeout on abortnode test (Fabian Jahr) 660bdbf http: Release server before waiting for event base loop exit (João Barbosa) 8c6d007 http: Track active requests and wait for last to finish (João Barbosa) Pull request description: This revives #19420. Since promag is not so active at the moment, I can support this to finally get it merged. The PR is rebased and comments by jonatack have been addressed. Once this is merged, I will also reopen #19434. ACKs for top commit: achow101: ACK 60978c8 stickies-v: re-ACK [60978c8](60978c8) hebasto: ACK 60978c8 Tree-SHA512: eef0fe1081e9331b95cfafc71d82f2398abd1d3439dac5b2fa5c6d9c0a3f63ef19adde1c38c88d3b4e7fb41ce7c097943f1815c10e33d165918ccbdec512fe1c

… finish - 2nd attempt 60978c8 test: Reduce extended timeout on abortnode test (Fabian Jahr) 660bdbf http: Release server before waiting for event base loop exit (João Barbosa) 8c6d007 http: Track active requests and wait for last to finish (João Barbosa) Pull request description: This revives bitcoin#19420. Since promag is not so active at the moment, I can support this to finally get it merged. The PR is rebased and comments by jonatack have been addressed. Once this is merged, I will also reopen bitcoin#19434. ACKs for top commit: achow101: ACK 60978c8 stickies-v: re-ACK [60978c8](bitcoin@60978c8) hebasto: ACK 60978c8 Tree-SHA512: eef0fe1081e9331b95cfafc71d82f2398abd1d3439dac5b2fa5c6d9c0a3f63ef19adde1c38c88d3b4e7fb41ce7c097943f1815c10e33d165918ccbdec512fe1c

…ase of remote client disconnection 68f23f5 http: bugfix: track closed connection (stickies-v) 084d037 http: log connection instead of request count (stickies-v) 41f9027 http: refactor: use encapsulated HTTPRequestTracker (stickies-v) Pull request description: #26742 significantly increased the http server shutdown speed, but also introduced a bug (#27722 - see bitcoin/bitcoin#27722 (comment) for steps to reproduce on master) that causes http server shutdown to halt in case of a remote client disconnection. This happens because `evhttp_request_set_on_complete_cb` is never called and thus the request is never removed from `g_requests`. This PR fixes that bug, and improves robustness of the code by encapsulating the request tracking logic. Earlier approaches (#27909, #27245, #19434) attempted to resolve this but [imo are fundamentally unsafe](bitcoin/bitcoin#27909 (comment)) because of differences in lifetime between an `evhttp_request` and `evhttp_connection`. We don't need to keep track of open requests or connections, we just [need to ensure](bitcoin/bitcoin#19420 (comment)) that there are no active requests on server shutdown. Because a connection can have multiple requests, and a request can be completed in various ways (the request actually being handled, or the client performing a remote disconnect), keeping a counter per connection seems like the approach with the least overhead to me. Fixes #27722 ACKs for top commit: vasild: ACK 68f23f5 theStack: ACK 68f23f5 Tree-SHA512: dfa711ff55ec75ba44d73e9e6fac16b0be25cf3c20868c2145a844a7878ad9fc6998d9ff62d72f3a210bfa411ef03d3757b73d68a7c22926e874c421e51444d6

…emote client disconnection 68f23f5 http: bugfix: track closed connection (stickies-v) 084d037 http: log connection instead of request count (stickies-v) 41f9027 http: refactor: use encapsulated HTTPRequestTracker (stickies-v) Pull request description: bitcoin#26742 significantly increased the http server shutdown speed, but also introduced a bug (bitcoin#27722 - see bitcoin#27722 (comment) for steps to reproduce on master) that causes http server shutdown to halt in case of a remote client disconnection. This happens because `evhttp_request_set_on_complete_cb` is never called and thus the request is never removed from `g_requests`. This PR fixes that bug, and improves robustness of the code by encapsulating the request tracking logic. Earlier approaches (bitcoin#27909, bitcoin#27245, bitcoin#19434) attempted to resolve this but [imo are fundamentally unsafe](bitcoin#27909 (comment)) because of differences in lifetime between an `evhttp_request` and `evhttp_connection`. We don't need to keep track of open requests or connections, we just [need to ensure](bitcoin#19420 (comment)) that there are no active requests on server shutdown. Because a connection can have multiple requests, and a request can be completed in various ways (the request actually being handled, or the client performing a remote disconnect), keeping a counter per connection seems like the approach with the least overhead to me. Fixes bitcoin#27722 ACKs for top commit: vasild: ACK 68f23f5 theStack: ACK 68f23f5 Tree-SHA512: dfa711ff55ec75ba44d73e9e6fac16b0be25cf3c20868c2145a844a7878ad9fc6998d9ff62d72f3a210bfa411ef03d3757b73d68a7c22926e874c421e51444d6

fanquake added the RPC/REST/ZMQ label Jun 30, 2020

DrahtBot mentioned this pull request Jun 30, 2020

http: Release server before waiting for event base loop exit #15363

Closed

promag force-pushed the 2020-06-track-requests branch from 62f6c7c to bc744d9 Compare July 1, 2020 09:12

promag marked this pull request as ready for review July 1, 2020 11:10

promag mentioned this pull request Jul 3, 2020

http: Detect remote disconnect #19434

Closed

promag marked this pull request as draft July 3, 2020 01:27

jonatack reviewed Jul 5, 2020

View reviewed changes

promag added 2 commits February 23, 2022 10:11

http: Track active requests and wait for last to finish

662cba4

http: Relese server before waiting for event base loop exit

ea724b9

promag force-pushed the 2020-06-track-requests branch from bc744d9 to ea724b9 Compare February 23, 2022 10:19

promag marked this pull request as ready for review February 23, 2022 12:03

promag requested a review from jonatack March 21, 2022 19:22

jonatack reviewed Mar 23, 2022

View reviewed changes

hebasto mentioned this pull request Mar 26, 2022

build: Bump libevent minimum version up to 2.1.8 #24681

Merged

promag mentioned this pull request Apr 1, 2022

Change code #24731

Closed

achow101 closed this Nov 10, 2022

fjahr mentioned this pull request Dec 22, 2022

http: Track active requests and wait for last to finish - 2nd attempt #26742

Merged

promag deleted the 2020-06-track-requests branch December 22, 2022 22:24

stickies-v mentioned this pull request Sep 29, 2023

http: bugfix: allow server shutdown in case of remote client disconnection #28551

Merged

bitcoin locked and limited conversation to collaborators Dec 22, 2023

http: Track active requests and wait for last to finish #19420

http: Track active requests and wait for last to finish #19420

Uh oh!

Conversation

promag commented Jun 30, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

promag commented Jun 30, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

DrahtBot commented Jun 30, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Conflicts

Uh oh!

promag commented Jul 1, 2020

Uh oh!

promag commented Jul 3, 2020

Uh oh!

jonatack commented Jul 5, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jonatack left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

fjahr commented May 18, 2021

Uh oh!

promag commented Mar 21, 2022

Uh oh!

jonatack commented Mar 23, 2022

Uh oh!

promag commented Mar 23, 2022

Uh oh!

jonatack left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jonatack Mar 23, 2022

Choose a reason for hiding this comment

Uh oh!

jonatack Mar 23, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

promag Mar 23, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

hebasto commented Mar 26, 2022

Uh oh!

achow101 commented Oct 12, 2022

Uh oh!

achow101 commented Nov 10, 2022

Uh oh!

fjahr commented Dec 22, 2022

Uh oh!

Uh oh!

promag commented Jun 30, 2020 •

edited

Loading

promag commented Jun 30, 2020 •

edited

Loading

DrahtBot commented Jun 30, 2020 •

edited

Loading

jonatack commented Jul 5, 2020 •

edited

Loading

jonatack left a comment •

edited

Loading

jonatack left a comment •

edited

Loading

jonatack Mar 23, 2022 •

edited

Loading

promag Mar 23, 2022 •

edited

Loading