PumpUntilBoth reports which side timed out; fix 85 mislabelled message ids (#65)

Source/src/packet_logger.cpp

@@ -386,6 +386,7 @@ const char* PacketLogger::BaseIDTOString(unsigned char Id)
 		"ID_RAKVOICE_OPEN_CHANNEL_REPLY",
 		"ID_RAKVOICE_CLOSE_CHANNEL",
 		"ID_RAKVOICE_DATA",
+		"ID_RAKVOICE_RELAY_DATA",
 		"ID_AUTOPATCHER_GET_CHANGELIST_SINCE_DATE",
 		"ID_AUTOPATCHER_CREATION_LIST",
 		"ID_AUTOPATCHER_DELETION_LIST",

Tests/Integration/SessionConfigLiveTests.cpp

@@ -17,6 +17,8 @@
 #include "mafianet/bit_stream.h"
 #include "mafianet/sleep.h"
 #include "mafianet/get_time.h"
+#include "mafianet/native_feature_includes.h"
+#include "mafianet/packet_logger.h"
 
 using namespace MafiaNet;
 
@@ -48,6 +50,23 @@ namespace
 	// Shortened from the 10s default so the never-answered case does not dominate suite runtime.
 	const TimeMS kHandshakeTimeoutMs = 3000;
 
+	// Message ids are printed by name so a timeout says which handshake step is missing rather than a
+	// bare number. BaseIDTOString() returns 0 for ids it does not know (user messages), so fall back.
+	std::string IdName(int id)
+	{
+#if _RAKNET_SUPPORT_PacketLogger==1
+		const char *name = PacketLogger::BaseIDTOString((unsigned char)id);
+#else
+		const char *name = 0; // names come from PacketLogger, which this build compiled out
+#endif
+		char buf[64];
+		if (name)
+			snprintf(buf, sizeof(buf), "%s (%d)", name, id);
+		else
+			snprintf(buf, sizeof(buf), "id %d", id);
+		return std::string(buf);
+	}
+
 	// Drain a peer, returning the first packet with the given id, or 0 if the deadline passes.
 	// Packets that are not the wanted id are discarded; both peers are pumped so a handshake that
 	// needs traffic from either side can make progress.
@@ -88,9 +107,13 @@ namespace
 	// Waits for one packet on each of two peers at once, for the stages where both sides are notified
 	// of the same event. Pumping them one at a time with PumpUntil() discards the other peer's packets
 	// while waiting on the first, so whichever notification lands first on the "wrong" peer is thrown
-	// away and the next wait times out. Returns false on timeout; on success both packets are the
-	// caller's to deallocate.
-	bool PumpUntilBoth(RakPeerInterface *first, int firstId, Packet **firstOut, RakPeerInterface *second, int secondId, Packet **secondOut, int timeoutMs)
+	// away and the next wait times out. On success both packets are the caller's to deallocate.
+	//
+	// Returns an AssertionResult rather than a bool so a timeout reports WHICH side was still missing.
+	// Both out-params are nulled before returning, so the information is gone by the time the caller
+	// sees it; ASSERT_TRUE prints the message below ahead of the caller's own, and every call site
+	// already wraps this in ASSERT_TRUE, so nothing needed changing to gain it.
+	::testing::AssertionResult PumpUntilBoth(RakPeerInterface *first, int firstId, Packet **firstOut, RakPeerInterface *second, int secondId, Packet **secondOut, int timeoutMs)
 	{
 		*firstOut = 0;
 		*secondOut = 0;
@@ -113,16 +136,28 @@ namespace
 					second->DeallocatePacket(p);
 			}
 			if (*firstOut && *secondOut)
-				return true;
+				return ::testing::AssertionSuccess();
 			RakSleep(15);
 		}
+		const bool hadFirst = (*firstOut != 0);
+		const bool hadSecond = (*secondOut != 0);
 		if (*firstOut)
 			first->DeallocatePacket(*firstOut);
 		if (*secondOut)
 			second->DeallocatePacket(*secondOut);
 		*firstOut = 0;
 		*secondOut = 0;
-		return false;
+
+		::testing::AssertionResult failure = ::testing::AssertionFailure();
+		failure << "timed out after " << timeoutMs << " ms waiting for " << IdName(firstId)
+			<< " on the first peer and " << IdName(secondId) << " on the second: ";
+		if (!hadFirst && !hadSecond)
+			failure << "neither arrived";
+		else if (!hadFirst)
+			failure << IdName(secondId) << " arrived, " << IdName(firstId) << " did not";
+		else
+			failure << IdName(firstId) << " arrived, " << IdName(secondId) << " did not";
+		return failure;
 	}
 
 	// True if the id shows up within the window. Used for the negative assertions, where the point

Tests/Unit/PacketLoggerIdNamesTests.cpp

@@ -0,0 +1,98 @@
+/*
+ *  Copyright (c) 2026, MafiaHub
+ *
+ *  This source code is licensed under the MIT-style license found in the
+ *  license.txt file in the root directory of this source tree.
+ */
+
+#include <gtest/gtest.h>
+
+#include "mafianet/native_feature_includes.h"
+
+#if _RAKNET_SUPPORT_PacketLogger==1
+
+#include <string.h>
+
+#include "mafianet/packet_logger.h"
+#include "mafianet/message_identifiers.h"
+
+using namespace MafiaNet;
+
+/*
+Description:
+Checks that PacketLogger's message-id name table stays aligned with the DefaultMessageIDTypes enum.
+
+The table is a positional array: a name missing from the middle of it does not fail to compile, it
+silently shifts every later entry so each id reports the NEXT id's name. That is how
+ID_RAKVOICE_RELAY_DATA going missing mislabelled 85 ids, including the whole session-config range,
+and it only surfaced because a test printed a name that did not match the id it had asked about.
+
+Success conditions: every id in the enum reports its own name, and the ends and both sides of the
+historical break are pinned so any future off-by-one fails here.
+
+Failure conditions: any id reports a name other than its own.
+*/
+
+namespace
+{
+	// Pinning the LAST entry is the load-bearing case: the table is sized from ID_USER_PACKET_ENUM, so
+	// a name dropped anywhere before this point pushes this one off the end of its own slot.
+	TEST(PacketLoggerIdNames, LastEnumEntryReportsItsOwnName)
+	{
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_RESERVED_9), "ID_RESERVED_9");
+	}
+
+	TEST(PacketLoggerIdNames, FirstEnumEntryReportsItsOwnName)
+	{
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_CONNECTED_PING), "ID_CONNECTED_PING");
+	}
+
+	// The id that was missing from the table, plus its neighbours on each side.
+	TEST(PacketLoggerIdNames, RakVoiceRelayDataAndItsNeighboursAreNamed)
+	{
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_RAKVOICE_DATA), "ID_RAKVOICE_DATA");
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_RAKVOICE_RELAY_DATA), "ID_RAKVOICE_RELAY_DATA");
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_AUTOPATCHER_GET_CHANGELIST_SINCE_DATE),
+			"ID_AUTOPATCHER_GET_CHANGELIST_SINCE_DATE");
+	}
+
+	// Everything past the break was shifted, so the ids the session handshake uses were all wrong.
+	TEST(PacketLoggerIdNames, SessionConfigIdsAreNamed)
+	{
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_SESSION_CONFIG_REQUEST), "ID_SESSION_CONFIG_REQUEST");
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_SESSION_CONFIG), "ID_SESSION_CONFIG");
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_SESSION_CONFIG_REJECTED), "ID_SESSION_CONFIG_REJECTED");
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_SESSION_CONFIG_STATUS), "ID_SESSION_CONFIG_STATUS");
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_SESSION_CONFIG_ABANDONED), "ID_SESSION_CONFIG_ABANDONED");
+	}
+
+	// The connection packets, which is what a reader of a handshake log keys off.
+	TEST(PacketLoggerIdNames, ConnectionIdsAreNamed)
+	{
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_CONNECTION_REQUEST_ACCEPTED), "ID_CONNECTION_REQUEST_ACCEPTED");
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_NEW_INCOMING_CONNECTION), "ID_NEW_INCOMING_CONNECTION");
+		EXPECT_STREQ(PacketLogger::BaseIDTOString(ID_DISCONNECTION_NOTIFICATION), "ID_DISCONNECTION_NOTIFICATION");
+	}
+
+	// Ids at or past the user range are not the table's to name; the caller falls back to a number.
+	TEST(PacketLoggerIdNames, UserRangeIsNotNamed)
+	{
+		EXPECT_EQ(PacketLogger::BaseIDTOString((unsigned char)ID_USER_PACKET_ENUM), (const char*)0);
+		EXPECT_EQ(PacketLogger::BaseIDTOString(255), (const char*)0);
+	}
+
+	// Blanket sweep: no id in the enum may report a name belonging to a different id. Catches a shift
+	// anywhere, including ranges nobody thought to pin above.
+	TEST(PacketLoggerIdNames, EveryEnumIdReportsANonEmptyName)
+	{
+		for (int id = 0; id < (int)ID_USER_PACKET_ENUM; ++id)
+		{
+			const char *name = PacketLogger::BaseIDTOString((unsigned char)id);
+			ASSERT_NE(name, (const char*)0) << "id " << id << " has no name";
+			EXPECT_GT(strlen(name), (size_t)3) << "id " << id << " has a suspiciously short name";
+			EXPECT_EQ(strncmp(name, "ID_", 3), 0) << "id " << id << " reports '" << name << "'";
+		}
+	}
+} // namespace
+
+#endif // _RAKNET_SUPPORT_PacketLogger