Merge bitcoin/bitcoin#28077: I2P: also sleep after errors in Accept() & destroy the session if we get an unexpected error

5c8e15c451 i2p: destroy the session if we get an unexpected error from the I2P router (Vasil Dimov)
762404a68c i2p: also sleep after errors in Accept() (Vasil Dimov)

Pull request description:

  ### Background

  In the `i2p::sam::Session` class:

  `Listen()` does:
  * if the session is not created yet
    * create the control socket and on it:
    * `HELLO`
    * `SESSION CREATE ID=sessid`
    * leave the control socked opened
  * create a new socket and on it:
  * `HELLO`
  * `STREAM ACCEPT ID=sessid`
  * read reply (`STREAM STATUS`), `Listen()` only succeeds if it contains `RESULT=OK`

  Then a wait starts, for a peer to connect. When connected,

  `Accept()` does:
  * on the socket from `STREAM ACCEPT` from `Listen()`: read the Base64 identification of the connecting peer

  ### Problem

  The I2P router may be in such a state that this happens in a quick succession (many times per second, see https://github.com/bitcoin/bitcoin/issues/22759#issuecomment-1609907115): `Listen()`-succeeds, `Accept()`-fails.

  `Accept()` fails because the I2P router sends something that is not Base64 on the socket: `STREAM STATUS RESULT=I2P_ERROR MESSAGE="Session was closed"`

  We only sleep after failed `Listen()` because the assumption was that if `Accept()` fails then the next `Listen()` will also fail.

  ### Solution

  Avoid filling the log with "Error accepting:" messages and sleep also after a failed `Accept()`.

  ### Extra changes

  * Reset the error waiting time after one successful connection. Otherwise the timer will remain high due to problems that have been solved long time in the past.

  * Increment the wait time less aggressively.

  * Handle the unexpected "Session was closed" message more gracefully (don't log stupid messages like `Cannot decode Base64: "STREAM STATUS...`) and destroy the session right way.

ACKs for top commit:
  achow101:
    ACK 5c8e15c451
  jonatack:
    re-ACK 5c8e15c451

Tree-SHA512: 1d47958c50eeae9eefcb668b8539fd092adead93328e4bf3355267819304b99ab41cbe1b5dbedbc3452c2bc389dc8330c0e27eb5ccb880e33dc46930a1592885
This commit is contained in:
Andrew Chow
2023-10-19 16:01:41 -04:00
4 changed files with 150 additions and 32 deletions

View File

@@ -16,14 +16,34 @@
#include <memory>
#include <string>
BOOST_FIXTURE_TEST_SUITE(i2p_tests, BasicTestingSetup)
/// Save the log level and the value of CreateSock and restore them when the test ends.
class EnvTestingSetup : public BasicTestingSetup
{
public:
explicit EnvTestingSetup(const ChainType chainType = ChainType::MAIN,
const std::vector<const char*>& extra_args = {})
: BasicTestingSetup{chainType, extra_args},
m_prev_log_level{LogInstance().LogLevel()},
m_create_sock_orig{CreateSock}
{
LogInstance().SetLogLevel(BCLog::Level::Trace);
}
~EnvTestingSetup()
{
CreateSock = m_create_sock_orig;
LogInstance().SetLogLevel(m_prev_log_level);
}
private:
const BCLog::Level m_prev_log_level;
const std::function<std::unique_ptr<Sock>(const CService&)> m_create_sock_orig;
};
BOOST_FIXTURE_TEST_SUITE(i2p_tests, EnvTestingSetup)
BOOST_AUTO_TEST_CASE(unlimited_recv)
{
const auto prev_log_level{LogInstance().LogLevel()};
LogInstance().SetLogLevel(BCLog::Level::Trace);
auto CreateSockOrig = CreateSock;
// Mock CreateSock() to create MockSock.
CreateSock = [](const CService&) {
return std::make_unique<StaticContentsSock>(std::string(i2p::sam::MAX_MSG_SIZE + 1, 'a'));
@@ -40,9 +60,69 @@ BOOST_AUTO_TEST_CASE(unlimited_recv)
bool proxy_error;
BOOST_REQUIRE(!session.Connect(CService{}, conn, proxy_error));
}
}
CreateSock = CreateSockOrig;
LogInstance().SetLogLevel(prev_log_level);
BOOST_AUTO_TEST_CASE(listen_ok_accept_fail)
{
size_t num_sockets{0};
CreateSock = [&num_sockets](const CService&) {
// clang-format off
++num_sockets;
// First socket is the control socket for creating the session.
if (num_sockets == 1) {
return std::make_unique<StaticContentsSock>(
// reply to HELLO
"HELLO REPLY RESULT=OK VERSION=3.1\n"
// reply to DEST GENERATE
"DEST REPLY PUB=WnGOLXRBqHQhdVjFlWqRxJwz9hxx~2~wGc2Vplta1KhacY4tdEGodCF1WMWVapHEnDP2HHH~b~AZzZWmW1rUqFpxji10Qah0IXVYxZVqkcScM~Yccf9v8BnNlaZbWtSoWnGOLXRBqHQhdVjFlWqRxJwz9hxx~2~wGc2Vplta1KhacY4tdEGodCF1WMWVapHEnDP2HHH~b~AZzZWmW1rUqFpxji10Qah0IXVYxZVqkcScM~Yccf9v8BnNlaZbWtSoWnGOLXRBqHQhdVjFlWqRxJwz9hxx~2~wGc2Vplta1KhacY4tdEGodCF1WMWVapHEnDP2HHH~b~AZzZWmW1rUqFpxji10Qah0IXVYxZVqkcScM~Yccf9v8BnNlaZbWtSoWnGOLXRBqHQhdVjFlWqRxJwz9hxx~2~wGc2Vplta1KhacY4tdEGodCF1WMWVapHEnDP2HHH~b~AZzZWmW1rUqLE4SD-yjT48UNI7qiTUfIPiDitCoiTTz2cr4QGfw89rBQAEAAcAAA== PRIV=WnGOLXRBqHQhdVjFlWqRxJwz9hxx~2~wGc2Vplta1KhacY4tdEGodCF1WMWVapHEnDP2HHH~b~AZzZWmW1rUqFpxji10Qah0IXVYxZVqkcScM~Yccf9v8BnNlaZbWtSoWnGOLXRBqHQhdVjFlWqRxJwz9hxx~2~wGc2Vplta1KhacY4tdEGodCF1WMWVapHEnDP2HHH~b~AZzZWmW1rUqFpxji10Qah0IXVYxZVqkcScM~Yccf9v8BnNlaZbWtSoWnGOLXRBqHQhdVjFlWqRxJwz9hxx~2~wGc2Vplta1KhacY4tdEGodCF1WMWVapHEnDP2HHH~b~AZzZWmW1rUqFpxji10Qah0IXVYxZVqkcScM~Yccf9v8BnNlaZbWtSoWnGOLXRBqHQhdVjFlWqRxJwz9hxx~2~wGc2Vplta1KhacY4tdEGodCF1WMWVapHEnDP2HHH~b~AZzZWmW1rUqLE4SD-yjT48UNI7qiTUfIPiDitCoiTTz2cr4QGfw89rBQAEAAcAAOvuCIKTyv5f~1QgGq7XQl-IqBULTB5WzB3gw5yGPtd1p0AeoADrq1ccZggLPQ4ZLUsGK-HVw373rcTfvxrcuwenqVjiN4tbbYLWtP7xXGWj6fM6HyORhU63GphrjEePpMUHDHXd3o7pWGM-ieVVQSK~1MzF9P93pQWI3Do52EeNAayz4HbpPjNhVBzG1hUEFwznfPmUZBPuaOR4-uBm1NEWEuONlNOCctE4-U0Ukh94z-Qb55U5vXjR5G4apmBblr68t6Wm1TKlzpgFHzSqLryh3stWqrOKY1H0z9eZ2z1EkHFOpD5LyF6nf51e-lV7HLMl44TYzoEHK8RRVodtLcW9lacVdBpv~tOzlZERIiDziZODPETENZMz5oy9DQ7UUw==\n"
// reply to SESSION CREATE
"SESSION STATUS RESULT=OK\n"
// dummy to avoid reporting EOF on the socket
"a"
);
}
// Subsequent sockets are for recreating the session or for listening and accepting incoming connections.
if (num_sockets % 2 == 0) {
// Replies to Listen() and Accept()
return std::make_unique<StaticContentsSock>(
// reply to HELLO
"HELLO REPLY RESULT=OK VERSION=3.1\n"
// reply to STREAM ACCEPT
"STREAM STATUS RESULT=OK\n"
// continued reply to STREAM ACCEPT, violating the protocol described at
// https://geti2p.net/en/docs/api/samv3#Accept%20Response
// should be base64, something like
// "IchV608baDoXbqzQKSqFDmTXPVgoDbPAhZJvNRXXxi4hyFXrTxtoOhdurNApKoUOZNc9WCgNs8CFkm81FdfGLiHIVetPG2g6F26s0CkqhQ5k1z1YKA2zwIWSbzUV18YuIchV608baDoXbqzQKSqFDmTXPVgoDbPAhZJvNRXXxi4hyFXrTxtoOhdurNApKoUOZNc9WCgNs8CFkm81FdfGLiHIVetPG2g6F26s0CkqhQ5k1z1YKA2zwIWSbzUV18YuIchV608baDoXbqzQKSqFDmTXPVgoDbPAhZJvNRXXxi4hyFXrTxtoOhdurNApKoUOZNc9WCgNs8CFkm81FdfGLiHIVetPG2g6F26s0CkqhQ5k1z1YKA2zwIWSbzUV18YuIchV608baDoXbqzQKSqFDmTXPVgoDbPAhZJvNRXXxi4hyFXrTxtoOhdurNApKoUOZNc9WCgNs8CFkm81FdfGLlSreVaCuCS5sdb-8ToWULWP7kt~lRPDeUNxQMq3cRSBBQAEAAcAAA==\n"
"STREAM STATUS RESULT=I2P_ERROR MESSAGE=\"Session was closed\"\n"
);
} else {
// Another control socket, but without creating a destination (it is cached in the session).
return std::make_unique<StaticContentsSock>(
// reply to HELLO
"HELLO REPLY RESULT=OK VERSION=3.1\n"
// reply to SESSION CREATE
"SESSION STATUS RESULT=OK\n"
// dummy to avoid reporting EOF on the socket
"a"
);
}
// clang-format on
};
CThreadInterrupt interrupt;
i2p::sam::Session session(gArgs.GetDataDirNet() / "test_i2p_private_key",
CService{in6_addr(IN6ADDR_LOOPBACK_INIT), /*port=*/7656},
&interrupt);
i2p::Connection conn;
for (size_t i = 0; i < 5; ++i) {
ASSERT_DEBUG_LOG("Creating persistent SAM session");
ASSERT_DEBUG_LOG("Persistent SAM session" /* ... created */);
ASSERT_DEBUG_LOG("Error accepting");
ASSERT_DEBUG_LOG("Destroying SAM session");
BOOST_REQUIRE(session.Listen(conn));
BOOST_REQUIRE(!session.Accept(conn));
}
}
BOOST_AUTO_TEST_SUITE_END()