Merge #14670: http: Fix HTTP server shutdown

28479f9 qa: Test bitcond shutdown (João Barbosa)
8d3f46e http: Remove timeout to exit event loop (João Barbosa)
e98a9ee http: Remove unnecessary event_base_loopexit call (João Barbosa)
6b13580 http: Unlisten sockets after all workers quit (João Barbosa)
18e9685 http: Send "Connection: close" header if shutdown is requested (João Barbosa)
02e1e4e rpc: Add wait argument to stop (João Barbosa)

Pull request description:

  Fixes #11777. Reverts #11006. Replaces #13501.

  With this change the HTTP server will exit gracefully, meaning that all requests will finish processing and sending the response, even if this means to wait more than 2 seconds (current time allowed to exit the event loop).

  Another small change is that connections are accepted even when the server is stopping, but HTTP requests are rejected. This can be improved later, especially if chunked replies are implemented.

  Briefly, before this PR, this is the order or events when a request arrives (RPC `stop`):
   1. `bufferevent_disable(..., EV_READ)`
   2. `StartShutdown()`
   3. `evhttp_del_accept_socket(...)`
   4. `ThreadHTTP` terminates (event loop exits) because there are no active or pending events thanks to 1. and 3.
   5. client doesn't get the response thanks to 4.

  This can be verified by applying
  ```diff
       // Event loop will exit after current HTTP requests have been handled, so
       // this reply will get back to the client.
       StartShutdown();
  +    MilliSleep(2000);
       return "Bitcoin server stopping";
   }
  ```
  and checking the log output:
  ```
      Received a POST request for / from 127.0.0.1:62443
      ThreadRPCServer method=stop user=__cookie__
      Interrupting HTTP server
  **  Exited http event loop
      Interrupting HTTP RPC server
      Interrupting RPC
      tor: Thread interrupt
      Shutdown: In progress...
      torcontrol thread exit
      Stopping HTTP RPC server
      addcon thread exit
      opencon thread exit
      Unregistering HTTP handler for / (exactmatch 1)
      Unregistering HTTP handler for /wallet/ (exactmatch 0)
      Stopping RPC
      RPC stopped.
      Stopping HTTP server
      Waiting for HTTP worker threads to exit
      msghand thread exit
      net thread exit

      ... sleep 2 seconds ...

      Waiting for HTTP event thread to exit
      Stopped HTTP server
  ```

  For this reason point 3. is moved right after all HTTP workers quit. In that moment HTTP replies are queued in the event loop which keeps spinning util all connections are closed. In order to trigger the server side close with keep alive connections (implicit in HTTP/1.1) the header `Connection: close` is sent if shutdown was requested. This can be tested by
  ```
  bitcoind -regtest
  nc localhost 18443
  POST / HTTP/1.1
  Authorization: Basic ...
  Content-Type: application/json
  Content-Length: 44

  {"jsonrpc": "2.0","method":"stop","id":123}
  ```

  Summing up, this PR:
   - removes explicit event loop exit — event loop exits once there are no active or pending events
   - changes the moment the listening sockets are removed — explained above
   - sends header `Connection: close` on active requests when shutdown was requested which is relevant when it's a persistent connection (default in HTTP 1.1) — libevent is aware of this header and closes the connection gracefully
   - removes event loop explicit break after 2 seconds timeout

Tree-SHA512: 4dac1e86abe388697c1e2dedbf31fb36a394cfafe5e64eadbf6ed01d829542785a8c3b91d1ab680d3f03f912d14fc87176428041141441d25dcb6c98a1e069d8

Author: laanwj

src/httpserver.cpp

@@ -10,6 +10,7 @@
 #include <util/strencodings.h>
 #include <netbase.h>
 #include <rpc/protocol.h> // For HTTP status codes
+#include <shutdown.h>
 #include <sync.h>
 #include <ui_interface.h>
 
@@ -21,7 +22,6 @@
 #include <sys/types.h>
 #include <sys/stat.h>
 #include <signal.h>
-#include <future>
 
 #include <event2/thread.h>
 #include <event2/buffer.h>
@@ -421,17 +421,14 @@ bool UpdateHTTPServerLogging(bool enable) {
 }
 
 std::thread threadHTTP;
-std::future<bool> threadResult;
 static std::vector<std::thread> g_thread_http_workers;
 
 void StartHTTPServer()
 {
     LogPrint(BCLog::HTTP, "Starting HTTP server\n");
     int rpcThreads = std::max((long)gArgs.GetArg("-rpcthreads", DEFAULT_HTTP_THREADS), 1L);
     LogPrintf("HTTP: starting %d worker threads\n", rpcThreads);
-    std::packaged_task<bool(event_base*)> task(ThreadHTTP);
-    threadResult = task.get_future();
-    threadHTTP = std::thread(std::move(task), eventBase);
+    threadHTTP = std::thread(ThreadHTTP, eventBase);
 
     for (int i = 0; i < rpcThreads; i++) {
         g_thread_http_workers.emplace_back(HTTPWorkQueueRun, workQueue);
@@ -442,10 +439,6 @@ void InterruptHTTPServer()
 {
     LogPrint(BCLog::HTTP, "Interrupting HTTP server\n");
     if (eventHTTP) {
-        // Unlisten sockets
-        for (evhttp_bound_socket *socket : boundSockets) {
-            evhttp_del_accept_socket(eventHTTP, socket);
-        }
         // Reject requests on current connections
         evhttp_set_gencb(eventHTTP, http_reject_request_cb, nullptr);
     }
@@ -465,20 +458,14 @@ void StopHTTPServer()
         delete workQueue;
         workQueue = nullptr;
     }
+    // Unlisten sockets, these are what make the event loop running, which means
+    // that after this and all connections are closed the event loop will quit.
+    for (evhttp_bound_socket *socket : boundSockets) {
+        evhttp_del_accept_socket(eventHTTP, socket);
+    }
+    boundSockets.clear();
     if (eventBase) {
         LogPrint(BCLog::HTTP, "Waiting for HTTP event thread to exit\n");
-        // Exit the event loop as soon as there are no active events.
-        event_base_loopexit(eventBase, nullptr);
-        // Give event loop a few seconds to exit (to send back last RPC responses), then break it
-        // Before this was solved with event_base_loopexit, but that didn't work as expected in
-        // at least libevent 2.0.21 and always introduced a delay. In libevent
-        // master that appears to be solved, so in the future that solution
-        // could be used again (if desirable).
-        // (see discussion in https://github.com/bitcoin/bitcoin/pull/6990)
-        if (threadResult.valid() && threadResult.wait_for(std::chrono::milliseconds(2000)) == std::future_status::timeout) {
-            LogPrintf("HTTP event loop did not exit within allotted time, sending loopbreak\n");
-            event_base_loopbreak(eventBase);
-        }
         threadHTTP.join();
     }
     if (eventHTTP) {
@@ -583,6 +570,9 @@ void HTTPRequest::WriteHeader(const std::string& hdr, const std::string& value)
 void HTTPRequest::WriteReply(int nStatus, const std::string& strReply)
 {
     assert(!replySent && req);
+    if (ShutdownRequested()) {
+        WriteHeader("Connection", "close");
+    }
     // Send event to main http thread to send reply message
     struct evbuffer* evb = evhttp_request_get_output_buffer(req);
     assert(evb);

src/rpc/client.cpp

@@ -162,6 +162,7 @@ static const CRPCConvertParam vRPCConvertParams[] =
     { "rescanblockchain", 1, "stop_height"},
     { "createwallet", 1, "disable_private_keys"},
     { "getnodeaddresses", 0, "count"},
+    { "stop", 0, "wait" },
 };
 // clang-format on
 

src/rpc/server.cpp

@@ -221,6 +221,9 @@ UniValue help(const JSONRPCRequest& jsonRequest)
 UniValue stop(const JSONRPCRequest& jsonRequest)
 {
     // Accept the deprecated and ignored 'detach' boolean argument
+    // Also accept the hidden 'wait' integer argument (milliseconds)
+    // For instance, 'stop 1000' makes the call wait 1 second before returning
+    // to the client (intended for testing)
     if (jsonRequest.fHelp || jsonRequest.params.size() > 1)
         throw std::runtime_error(
             RPCHelpMan{"stop",
@@ -229,6 +232,9 @@ UniValue stop(const JSONRPCRequest& jsonRequest)
     // Event loop will exit after current HTTP requests have been handled, so
     // this reply will get back to the client.
     StartShutdown();
+    if (jsonRequest.params[0].isNum()) {
+        MilliSleep(jsonRequest.params[0].get_int());
+    }
     return "Bitcoin server stopping";
 }
 
@@ -255,7 +261,7 @@ static const CRPCCommand vRPCCommands[] =
   //  --------------------- ------------------------  -----------------------  ----------
     /* Overall control/query calls */
     { "control",            "help",                   &help,                   {"command"}  },
-    { "control",            "stop",                   &stop,                   {}  },
+    { "control",            "stop",                   &stop,                   {"wait"}  },
     { "control",            "uptime",                 &uptime,                 {}  },
 };
 // clang-format on

test/functional/feature_shutdown.py

@@ -0,0 +1,28 @@
+#!/usr/bin/env python3
+# Copyright (c) 2018 The Bitcoin Core developers
+# Distributed under the MIT software license, see the accompanying
+# file COPYING or http://www.opensource.org/licenses/mit-license.php.
+"""Test bitcoind shutdown."""
+
+from test_framework.test_framework import BitcoinTestFramework
+from test_framework.util import assert_equal, get_rpc_proxy
+from threading import Thread
+
+def test_long_call(node):
+    block = node.waitfornewblock()
+    assert_equal(block['height'], 0)
+
+class ShutdownTest(BitcoinTestFramework):
+
+    def set_test_params(self):
+        self.setup_clean_chain = True
+        self.num_nodes = 1
+
+    def run_test(self):
+        node = get_rpc_proxy(self.nodes[0].url, 1, timeout=600, coveragedir=self.nodes[0].coverage_dir)
+        Thread(target=test_long_call, args=(node,)).start()
+        # wait 1 second to ensure event loop waits for current connections to close
+        self.stop_node(0, wait=1000)
+
+if __name__ == '__main__':
+    ShutdownTest().main()

test/functional/test_framework/test_framework.py

@@ -327,16 +327,16 @@ def start_nodes(self, extra_args=None, *args, **kwargs):
             for node in self.nodes:
                 coverage.write_all_rpc_commands(self.options.coveragedir, node.rpc)
 
-    def stop_node(self, i, expected_stderr=''):
+    def stop_node(self, i, expected_stderr='', wait=0):
         """Stop a bitcoind test node"""
-        self.nodes[i].stop_node(expected_stderr)
+        self.nodes[i].stop_node(expected_stderr, wait=wait)
         self.nodes[i].wait_until_stopped()
 
-    def stop_nodes(self):
+    def stop_nodes(self, wait=0):
         """Stop multiple bitcoind test nodes"""
         for node in self.nodes:
             # Issue RPC to stop nodes
-            node.stop_node()
+            node.stop_node(wait=wait)
 
         for node in self.nodes:
             # Wait for nodes to stop

test/functional/test_framework/test_node.py

@@ -228,13 +228,13 @@ def get_wallet_rpc(self, wallet_name):
             wallet_path = "wallet/{}".format(urllib.parse.quote(wallet_name))
             return self.rpc / wallet_path
 
-    def stop_node(self, expected_stderr=''):
+    def stop_node(self, expected_stderr='', wait=0):
         """Stop the node."""
         if not self.running:
             return
         self.log.debug("Stopping node")
         try:
-            self.stop()
+            self.stop(wait=wait)
         except http.client.CannotSendRequest:
             self.log.exception("Unable to stop node.")
 

test/functional/test_runner.py

@@ -186,6 +186,7 @@
     'feature_config_args.py',
     'rpc_help.py',
     'feature_help.py',
+    'feature_shutdown.py',
     # Don't append tests at the end to avoid merge conflicts
     # Put them in a random line within the section that fits their approximate run-time
 ]