From 34f43c3fef9078f437587a7b5af3d909ccf6ed8a Mon Sep 17 00:00:00 2001 From: Aaron Kimbrell Date: Sat, 26 Sep 2026 18:51:07 -0500 Subject: [PATCH] feat(auth): stamp each login step as it happens The login response's stamps were a fixed list: START and CLIENT_OS at the start, an ERROR or two, and IM_LOGIN_START / WORLD_COMMUNICATION_FINISH appended to every response whatever happened. Now a Stamps list (new dNet/Stamps.{h,cpp}: eStamps, Stamp and Stamps with Serialize / Deserialize in the login response's layout, so server messages can carry it too) is created when the login request arrives, and each step adds its own stamp, with the time, where it happens: the request read (value: the client's OS), the account lookup (found or not), the password check, failed checks, the closed server and play key checks, database writes, asking master for a world, master's answer, handing the session key to master, and sending the player on. The response serializes whatever was stamped; the auth server logs the list like the client does. What the client does with stamps (1.10.64): PacketHandler_MSG_CLIENT_ LOGIN_RESPONSE @ 00b32f90 reads them (LoginResponse::ReadStamps @ 005ed3c0, count = (size - 4) / 16) and only logs each with its name from StampLookup @ 017e6e88 (the 39 eStamps names) and its time relative to the first and previous stamp. Documented in Stamps.h. Behaviour change: on success, master gets the session key just before the client gets the response instead of just after, so the handoff can be stamped (and master knows the key before the client can reach a world). The client-facing layout is unchanged; tests pin the stamp bytes, check the steps of a failed login in order, and round trip the list. Co-Authored-By: Claude Opus 5.5 --- dNet/AuthPackets.cpp | 61 ++++--- dNet/AuthPackets.h | 2 +- dNet/CMakeLists.txt | 1 + dNet/ClientPackets.cpp | 26 +-- dNet/ClientPackets.h | 64 +------- dNet/Stamps.cpp | 52 ++++++ dNet/Stamps.h | 126 +++++++++++++++ dWorldServer/WorldServer.cpp | 3 +- .../dNetTests/CommonAuthPacketsTests.cpp | 153 ++++++++++++++++-- 9 files changed, 369 insertions(+), 119 deletions(-) create mode 100644 dNet/Stamps.cpp create mode 100644 dNet/Stamps.h diff --git a/dNet/AuthPackets.cpp b/dNet/AuthPackets.cpp index ee94bbd0e..147655a76 100644 --- a/dNet/AuthPackets.cpp +++ b/dNet/AuthPackets.cpp @@ -117,15 +117,16 @@ void AuthPackets::LoginRequest::Handle() { auto* const server = Game::server; const auto& packet = *this; // the old handler's sysAddr - std::vector stamps; - stamps.emplace_back(eStamps::PASSPORT_AUTH_START, 0); + // Each step of the login stamps itself here as it happens; the response carries them to the client + Stamps stamps; + stamps.Add(eStamps::PASSPORT_AUTH_START); const auto username = this->username.GetAsString(); LOG_DEBUG("Locale ID: %s", StringifiedEnum::ToString(localeID).data()); LOG_DEBUG("Operating System: %s", StringifiedEnum::ToString(clientOS).data()); - stamps.emplace_back(eStamps::PASSPORT_AUTH_CLIENT_OS, 0); + stamps.Add(eStamps::PASSPORT_AUTH_CLIENT_OS, static_cast(clientOS)); LOG_DEBUG("Memory Stats [%s]", CleanReceivedString(memoryStats.GetAsString()).c_str()); @@ -138,19 +139,24 @@ void AuthPackets::LoginRequest::Handle() { LOG_DEBUG("OS Info: [Size: %i, Major: %i, Minor %i, Buid#: %i, platformID: %i]", osVersionInfoSize, majorVersion, minorVersion, buildNumber, platformID); // Fetch account details + stamps.Add(eStamps::PASSPORT_AUTH_DB_SELECT_START); auto accountInfo = Database::Get()->GetAccountInfo(username); + stamps.Add(eStamps::PASSPORT_AUTH_DB_SELECT_FINISH, accountInfo ? 1 : 0); if (!accountInfo) { LOG("No user by name %s found!", username.c_str()); - stamps.emplace_back(eStamps::PASSPORT_AUTH_ERROR, 1); + stamps.Add(eStamps::PASSPORT_AUTH_ERROR, 1); AuthPackets::SendLoginResponse(server, sysAddr, eLoginResponse::INVALID_USER, "", "", 2001, username, stamps); return; } // The password first: someone who doesn't know it learns nothing about the account (ban details, lock, play key), // and a failed attempt changes nothing (an expired ban is only lifted for the real owner) - if (::bcrypt_checkpw(password.GetAsString().c_str(), accountInfo->bcryptPassword.c_str()) != 0) { - stamps.emplace_back(eStamps::PASSPORT_AUTH_ERROR, 1); + stamps.Add(eStamps::PASSPORT_AUTH_LEGOINT_WEBSERVICE_START); + const bool passwordMatches = ::bcrypt_checkpw(password.GetAsString().c_str(), accountInfo->bcryptPassword.c_str()) == 0; + stamps.Add(eStamps::PASSPORT_AUTH_LEGOINT_WEBSERVICE_FINISH, passwordMatches ? 1 : 0); + if (!passwordMatches) { + stamps.Add(eStamps::PASSPORT_AUTH_ERROR, 1); AuthPackets::SendLoginResponse(server, sysAddr, eLoginResponse::WRONG_PASS, "", "", 2001, username, stamps); LOG("Wrong password used"); return; @@ -158,7 +164,7 @@ void AuthPackets::LoginRequest::Handle() { //If we aren't running in live mode, then only GMs are allowed to enter: if (Game::config->GetValue("closed_to_non_devs", false) && accountInfo->maxGmLevel == eGameMasterLevel::CIVILIAN) { - stamps.emplace_back(eStamps::GM_REQUIRED, 1); + stamps.Add(eStamps::GM_REQUIRED, 1); AuthPackets::SendLoginResponse(server, sysAddr, eLoginResponse::PERMISSIONS_NOT_HIGH_ENOUGH, "The server is currently only open to developers.", "", 2001, username, stamps); return; } @@ -166,7 +172,7 @@ void AuthPackets::LoginRequest::Handle() { if (Game::config->GetValue("dont_use_keys") != "1" && accountInfo->maxGmLevel == eGameMasterLevel::CIVILIAN) { //Check to see if we have a play key: if (accountInfo->playKeyId == 0) { - stamps.emplace_back(eStamps::PASSPORT_AUTH_ERROR, 1); + stamps.Add(eStamps::PASSPORT_AUTH_ERROR, 1); AuthPackets::SendLoginResponse(server, sysAddr, eLoginResponse::PERMISSIONS_NOT_HIGH_ENOUGH, "Your account doesn't have a play key associated with it!", "", 2001, username, stamps); LOG("User %s tried to log in, but they don't have a play key.", username.c_str()); return; @@ -176,31 +182,33 @@ void AuthPackets::LoginRequest::Handle() { auto playKeyStatus = Database::Get()->IsPlaykeyActive(accountInfo->playKeyId); if (!playKeyStatus) { - stamps.emplace_back(eStamps::PASSPORT_AUTH_ERROR, 1); + stamps.Add(eStamps::PASSPORT_AUTH_ERROR, 1); AuthPackets::SendLoginResponse(server, sysAddr, eLoginResponse::PERMISSIONS_NOT_HIGH_ENOUGH, "Your account doesn't have a valid play key associated with it!", "", 2001, username, stamps); return; } if (!playKeyStatus.value()) { - stamps.emplace_back(eStamps::PASSPORT_AUTH_ERROR, 1); + stamps.Add(eStamps::PASSPORT_AUTH_ERROR, 1); AuthPackets::SendLoginResponse(server, sysAddr, eLoginResponse::PERMISSIONS_NOT_HIGH_ENOUGH, "Your play key has been disabled.", "", 2001, username, stamps); LOG("User %s tried to log in, but their play key was disabled", username.c_str()); return; } } else if (Game::config->GetValue("dont_use_keys") == "1" || accountInfo->maxGmLevel > eGameMasterLevel::CIVILIAN){ - stamps.emplace_back(eStamps::PASSPORT_AUTH_BYPASS, 1); + stamps.Add(eStamps::PASSPORT_AUTH_BYPASS, 1); } // A temporary ban that has run out is lifted as the player logs in if (accountInfo->banned && accountInfo->banExpires > 0 && accountInfo->banExpires <= static_cast(std::time(nullptr))) { + stamps.Add(eStamps::PASSPORT_AUTH_DB_INSERT_START); Database::Get()->SetAccountBan(accountInfo->id, false, 0, ""); Database::Get()->InsertAccountNote({ 0, accountInfo->id, "unban", "Temporary ban ended", "[server]", static_cast(std::time(nullptr)) }); + stamps.Add(eStamps::PASSPORT_AUTH_DB_INSERT_FINISH, 1); accountInfo->banned = false; LOG("Temporary ban of %s ended", username.c_str()); } if (accountInfo->banned) { - stamps.emplace_back(eStamps::PASSPORT_AUTH_ERROR, 1); + stamps.Add(eStamps::PASSPORT_AUTH_ERROR, 1); std::string message; if (accountInfo->banExpires > 0) { char until[32]; @@ -214,7 +222,7 @@ void AuthPackets::LoginRequest::Handle() { } if (accountInfo->locked) { - stamps.emplace_back(eStamps::PASSPORT_AUTH_ERROR, 1); + stamps.Add(eStamps::PASSPORT_AUTH_ERROR, 1); AuthPackets::SendLoginResponse(server, sysAddr, eLoginResponse::ACCOUNT_LOCKED, "", "", 2001, username, stamps); return; } @@ -224,16 +232,20 @@ void AuthPackets::LoginRequest::Handle() { // Where accounts log in from, so staff can see accounts that share a connection (log_login_addresses, on by default) if (Game::config->GetValue("log_login_addresses") != "0") { + stamps.Add(eStamps::PASSPORT_AUTH_DB_INSERT_START); Database::Get()->RecordLoginAddress(accountInfo->id, system.ToString(false), static_cast(std::time(nullptr))); + stamps.Add(eStamps::PASSPORT_AUTH_DB_INSERT_FINISH, 1); } if (!server->GetIsConnectedToMaster()) { - stamps.emplace_back(eStamps::PASSPORT_AUTH_WORLD_DISCONNECT, 1); + stamps.Add(eStamps::PASSPORT_AUTH_WORLD_DISCONNECT, 1); AuthPackets::SendLoginResponse(server, system, eLoginResponse::GENERAL_FAILED, "", "", 0, username, stamps); return; } - stamps.emplace_back(eStamps::PASSPORT_AUTH_WORLD_SESSION_CONFIRM_TO_AUTH, 1); + // Ask master for a world server to send the player to + stamps.Add(eStamps::PASSPORT_AUTH_WORLD_COMMUNICATION_START); ZoneInstanceManager::Instance()->RequestZoneTransfer(server, 0, 0, false, [system, server, username, stamps](bool mythranShift, uint32_t zoneID, uint32_t zoneInstance, uint32_t zoneClone, std::string zoneIP, uint16_t zonePort) mutable { + stamps.Add(eStamps::PASSPORT_AUTH_WORLD_PACKET_RECEIVED, zoneInstance); AuthPackets::SendLoginResponse(server, system, eLoginResponse::SUCCESS, "", zoneIP, zonePort, username, stamps); }); } @@ -243,8 +255,7 @@ void AuthPackets::LoginRequest::Handle() { } } -void AuthPackets::SendLoginResponse(dServer* server, const SystemAddress& sysAddr, eLoginResponse responseCode, const std::string& errorMsg, const std::string& wServerIP, uint16_t wServerPort, std::string username, std::vector& stamps) { - stamps.emplace_back(eStamps::PASSPORT_AUTH_IM_LOGIN_START, 1); +void AuthPackets::SendLoginResponse(dServer* server, const SystemAddress& sysAddr, eLoginResponse responseCode, const std::string& errorMsg, const std::string& wServerIP, uint16_t wServerPort, std::string username, Stamps& stamps) { ClientPackets::LoginResponse loginResponse; loginResponse.responseCode = responseCode; @@ -280,18 +291,24 @@ void AuthPackets::SendLoginResponse(dServer* server, const SystemAddress& sysAdd // Custom error message loginResponse.errorMessage = errorMsg; - stamps.emplace_back(eStamps::PASSPORT_AUTH_WORLD_COMMUNICATION_FINISH, 1); - loginResponse.stamps = stamps; - - loginResponse.Send(sysAddr); - //Inform the master server that we've created a session for this user: + //Inform the master server that we've created a session for this user, before the client can reach the world server: if (responseCode == eLoginResponse::SUCCESS) { + stamps.Add(eStamps::PASSPORT_AUTH_IM_COMMUNICATION_START); CBITSTREAM; BitStreamUtils::WriteHeader(bitStream, ServiceType::MASTER, MessageType::Master::SET_SESSION_KEY); bitStream.Write(sessionKey); bitStream.Write(LUString(username)); + stamps.Add(eStamps::PASSPORT_AUTH_IM_LOGIN_START); server->SendToMaster(bitStream); + stamps.Add(eStamps::PASSPORT_AUTH_IM_COMMUNICATION_END, 1); LOG("Set session key for user %s", username.c_str()); + + stamps.Add(eStamps::PASSPORT_AUTH_WORLD_SESSION_CONFIRM_TO_AUTH, 1); + stamps.Add(eStamps::PASSPORT_AUTH_WORLD_COMMUNICATION_FINISH, wServerPort); } + + stamps.Log("Login of " + username); + loginResponse.stamps = stamps; + loginResponse.Send(sysAddr); } diff --git a/dNet/AuthPackets.h b/dNet/AuthPackets.h index a3b86911f..13f7bba59 100644 --- a/dNet/AuthPackets.h +++ b/dNet/AuthPackets.h @@ -67,7 +67,7 @@ namespace AuthPackets { // Answers a login with a ClientPackets::LoginResponse filled from the server's settings (event gating, client // version) and a new session key; on success also registers that session key with the master server. - void SendLoginResponse(dServer* server, const SystemAddress& sysAddr, eLoginResponse responseCode, const std::string& errorMsg, const std::string& wServerIP, uint16_t wServerPort, std::string username, std::vector& stamps); + void SendLoginResponse(dServer* server, const SystemAddress& sysAddr, eLoginResponse responseCode, const std::string& errorMsg, const std::string& wServerIP, uint16_t wServerPort, std::string username, Stamps& stamps); void LoadClaimCodes(); } diff --git a/dNet/CMakeLists.txt b/dNet/CMakeLists.txt index f2df367f1..14ab3dc35 100644 --- a/dNet/CMakeLists.txt +++ b/dNet/CMakeLists.txt @@ -7,6 +7,7 @@ set(DNET_SOURCES "AuthPackets.cpp" "MailInfo.cpp" "MasterPackets.cpp" "PacketUtils.cpp" + "Stamps.cpp" "WorldPackets.cpp" "ZoneInstanceManager.cpp") diff --git a/dNet/ClientPackets.cpp b/dNet/ClientPackets.cpp index 9c269f9ee..5fff8f643 100644 --- a/dNet/ClientPackets.cpp +++ b/dNet/ClientPackets.cpp @@ -8,21 +8,6 @@ #include "PositionUpdate.h" #include "eLoginResponse.h" -static_assert(sizeof(Stamp) == 16, "the login response's stamp size field has always been 16 bytes per stamp"); - -void Stamp::Serialize(RakNet::BitStream& outBitStream) const { - outBitStream.Write(type); - outBitStream.Write(value); - outBitStream.Write(timestamp); -} - -bool Stamp::Deserialize(RakNet::BitStream& inBitStream) { - VALIDATE_READ(inBitStream.Read(type)); - VALIDATE_READ(inBitStream.Read(value)); - VALIDATE_READ(inBitStream.Read(timestamp)); - return true; -} - namespace ClientPackets { void LoginResponse::Serialize(RakNet::BitStream& bitStream) const { bitStream.Write(responseCode); @@ -44,8 +29,7 @@ namespace ClientPackets { bitStream.Write(freeToPlayTimeRemaining); bitStream.Write(errorMessage.length()); bitStream.Write(LUWString(errorMessage, static_cast(errorMessage.length()))); - bitStream.Write((sizeof(Stamp) * stamps.size()) + sizeof(uint32_t)); - for (const auto& stamp : stamps) stamp.Serialize(bitStream); + stamps.Serialize(bitStream); } bool LoginResponse::Deserialize(RakNet::BitStream& bitStream) { @@ -74,13 +58,7 @@ namespace ClientPackets { LUWString error(errorLength); if (errorLength > 0) VALIDATE_READ(bitStream.Read(error)); // RakNet fails reads of 0 bits errorMessage = error.GetAsString(); - uint32_t stampsSize{}; - VALIDATE_READ(bitStream.Read(stampsSize)); - if (stampsSize < sizeof(uint32_t) || (stampsSize - sizeof(uint32_t)) % sizeof(Stamp) != 0) return false; - const uint32_t stampCount = (stampsSize - sizeof(uint32_t)) / sizeof(Stamp); - if (stampCount > BITS_TO_BYTES(bitStream.GetNumberOfUnreadBits()) / sizeof(Stamp)) return false; - stamps.resize(stampCount); - for (auto& stamp : stamps) VALIDATE_READ(stamp.Deserialize(bitStream)); + VALIDATE_READ(stamps.Deserialize(bitStream)); return true; } } diff --git a/dNet/ClientPackets.h b/dNet/ClientPackets.h index 2b5ed0184..00d1dafdb 100644 --- a/dNet/ClientPackets.h +++ b/dNet/ClientPackets.h @@ -13,6 +13,7 @@ #include "BitStreamUtils.h" #include "MessageType/Client.h" +#include "Stamps.h" enum class eLoginResponse : uint8_t; @@ -20,65 +21,6 @@ class PositionUpdate; struct Packet; -enum class eStamps : uint32_t { - PASSPORT_AUTH_START, - PASSPORT_AUTH_BYPASS, - PASSPORT_AUTH_ERROR, - PASSPORT_AUTH_DB_SELECT_START, - PASSPORT_AUTH_DB_SELECT_FINISH, - PASSPORT_AUTH_DB_INSERT_START, - PASSPORT_AUTH_DB_INSERT_FINISH, - PASSPORT_AUTH_LEGOINT_COMMUNICATION_START, - PASSPORT_AUTH_LEGOINT_RECEIVED, - PASSPORT_AUTH_LEGOINT_THREAD_SPAWN, - PASSPORT_AUTH_LEGOINT_WEBSERVICE_START, - PASSPORT_AUTH_LEGOINT_WEBSERVICE_FINISH, - PASSPORT_AUTH_LEGOINT_LEGOCLUB_START, - PASSPORT_AUTH_LEGOINT_LEGOCLUB_FINISH, - PASSPORT_AUTH_LEGOINT_THREAD_FINISH, - PASSPORT_AUTH_LEGOINT_REPLY, - PASSPORT_AUTH_LEGOINT_ERROR, - PASSPORT_AUTH_LEGOINT_COMMUNICATION_END, - PASSPORT_AUTH_LEGOINT_DISCONNECT, - PASSPORT_AUTH_WORLD_COMMUNICATION_START, - PASSPORT_AUTH_CLIENT_OS, - PASSPORT_AUTH_WORLD_PACKET_RECEIVED, - PASSPORT_AUTH_IM_COMMUNICATION_START, - PASSPORT_AUTH_IM_LOGIN_START, - PASSPORT_AUTH_IM_LOGIN_ALREADY_LOGGED_IN, - PASSPORT_AUTH_IM_OTHER_LOGIN_REMOVED, - PASSPORT_AUTH_IM_LOGIN_QUEUED, - PASSPORT_AUTH_IM_LOGIN_RESPONSE, - PASSPORT_AUTH_IM_COMMUNICATION_END, - PASSPORT_AUTH_WORLD_SESSION_CONFIRM_TO_AUTH, - PASSPORT_AUTH_WORLD_COMMUNICATION_FINISH, - PASSPORT_AUTH_WORLD_DISCONNECT, - NO_LEGO_INTERFACE, - DB_ERROR, - GM_REQUIRED, - NO_LEGO_WEBSERVICE_XML, - LEGO_WEBSERVICE_TIMEOUT, - LEGO_WEBSERVICE_ERROR, - NO_WORLD_SERVER -}; - -struct Stamp { - eStamps type{}; - uint32_t value{}; - uint64_t timestamp{}; - - Stamp() = default; - Stamp(eStamps type, uint32_t value, uint64_t timestamp = time(nullptr)){ - this->type = type; - this->value = value; - this->timestamp = timestamp; - } - - void Serialize(RakNet::BitStream& outBitStream) const; - bool Deserialize(RakNet::BitStream& inBitStream); -}; - - enum class Language : uint32_t { en_US, pl_US, @@ -123,8 +65,8 @@ namespace ClientPackets { uint64_t freeToPlayTimeRemaining{}; // Written as a u16 character count followed by that many UTF-16 characters std::string errorMessage{}; - // Written after a u32 holding their size in bytes plus 4 - std::vector stamps{}; + // The login's stamps (see Stamps.h) + Stamps stamps{}; LoginResponse() : LUBitStream(ServiceType::CLIENT, MessageType::Client::LOGIN_RESPONSE) {} void Serialize(RakNet::BitStream& bitStream) const override; diff --git a/dNet/Stamps.cpp b/dNet/Stamps.cpp new file mode 100644 index 000000000..f0db863dd --- /dev/null +++ b/dNet/Stamps.cpp @@ -0,0 +1,52 @@ +#include "Stamps.h" + +#include "BitStreamUtils.h" +#include "Logger.h" +#include "StringifiedEnum.h" + +static_assert(sizeof(Stamp) == 16, "the login response's stamp size field has always been 16 bytes per stamp"); + +void Stamp::Serialize(RakNet::BitStream& outBitStream) const { + outBitStream.Write(type); + outBitStream.Write(value); + outBitStream.Write(timestamp); +} + +bool Stamp::Deserialize(RakNet::BitStream& inBitStream) { + VALIDATE_READ(inBitStream.Read(type)); + VALIDATE_READ(inBitStream.Read(value)); + VALIDATE_READ(inBitStream.Read(timestamp)); + return true; +} + +void Stamps::Add(const eStamps type, const uint32_t value) { + list.emplace_back(type, value, static_cast(std::time(nullptr))); +} + +void Stamps::Serialize(RakNet::BitStream& bitStream) const { + bitStream.Write((sizeof(Stamp) * list.size()) + sizeof(uint32_t)); + for (const auto& stamp : list) stamp.Serialize(bitStream); +} + +bool Stamps::Deserialize(RakNet::BitStream& bitStream) { + uint32_t stampsSize{}; + VALIDATE_READ(bitStream.Read(stampsSize)); + if (stampsSize < sizeof(uint32_t) || (stampsSize - sizeof(uint32_t)) % sizeof(Stamp) != 0) return false; + const uint32_t stampCount = (stampsSize - sizeof(uint32_t)) / sizeof(Stamp); + if (stampCount > BITS_TO_BYTES(bitStream.GetNumberOfUnreadBits()) / sizeof(Stamp)) return false; + list.resize(stampCount); + for (auto& stamp : list) VALIDATE_READ(stamp.Deserialize(bitStream)); + return true; +} + +void Stamps::Log(const std::string& context) const { + if (list.empty()) return; + const auto start = list.front().timestamp; + auto last = start; + for (const auto& stamp : list) { + // The same line the client logs for each stamp it receives + LOG_DEBUG("%s: stamp %s(%u) at %llu (start+%lld, last+%lld)", context.c_str(), StringifiedEnum::ToString(stamp.type).data(), stamp.value, + stamp.timestamp, static_cast(stamp.timestamp - start), static_cast(stamp.timestamp - last)); + last = stamp.timestamp; + } +} diff --git a/dNet/Stamps.h b/dNet/Stamps.h new file mode 100644 index 000000000..45f4cc326 --- /dev/null +++ b/dNet/Stamps.h @@ -0,0 +1,126 @@ +#ifndef STAMPS_H +#define STAMPS_H + +#include "BitStream.h" + +#include +#include +#include +#include + +/** + * Login stamps: a trace of the steps the auth server went through for one login, sent at the end of the login + * response (ClientPackets::LoginResponse::stamps). + * + * On the wire: a u32 holding 16 * count + 4, then count stamps of { u32 type, u32 value, u64 timestamp }. + * + * What the 1.10.64 client does with them (PacketHandler_MSG_CLIENT_LOGIN_RESPONSE @ 00b32f90, which reads them + * through LoginResponse::ReadVariableData @ 005ed4f0 and LoginResponse::ReadStamps @ 005ed3c0): count is + * (size - 4) / 16, and it only logs each one, "Stamp %s(%d) at %I64d (start+%d, last+%d)", with the type's name + * from StampLookup @ 017e6e88 and the timestamp relative to the first and to the previous stamp. Nothing else + * reads them, so no type is required and the order is free. The type must be one of the values below (the name + * table has exactly these 39 entries; a larger value reads past it). + * + * Live servers stamped real steps with unix timestamps in seconds: START, the LEGOINT_* steps (the LEGO account + * web service, which checked the password), DB_INSERT_*, CLIENT_OS, then the WORLD_* / IM_* steps of handing the + * session to the instance manager and picking a world server, ending with WORLD_COMMUNICATION_FINISH. The values + * were step results (1 for done) or ids (such as the server the step talked to). + * + * What DLU stamps (AuthPackets::LoginStamps; every step adds its stamp as it happens): + * START (0) the login request arrived + * CLIENT_OS (the ClientOS) the request was read + * DB_SELECT_START / _FINISH looking up the account (FINISH value: 1 found, 0 not) + * LEGOINT_WEBSERVICE_START / _FINISH checking the password (live asked the LEGO web service; DLU checks it + * itself; FINISH value: 1 matches, 0 not) + * ERROR (1) a check failed: unknown user, wrong password, play key, banned, locked + * GM_REQUIRED (1) the server is closed to non developers + * BYPASS (1) no play key needed (keys off, or a GM account) + * DB_INSERT_START / _FINISH writing to the database (lifting an expired ban, recording the address) + * WORLD_DISCONNECT (1) no master server to ask for a world + * WORLD_COMMUNICATION_START (0) asked master for a world server + * WORLD_PACKET_RECEIVED (instance) master answered + * IM_COMMUNICATION_START / IM_LOGIN_START / IM_COMMUNICATION_END (1) the session key was given to master + * WORLD_SESSION_CONFIRM_TO_AUTH (1), WORLD_COMMUNICATION_FINISH (world port) the player is sent to the world + * The auth server logs the same lines as the client (debug log) when it sends the response. + */ +enum class eStamps : uint32_t { + PASSPORT_AUTH_START, + PASSPORT_AUTH_BYPASS, + PASSPORT_AUTH_ERROR, + PASSPORT_AUTH_DB_SELECT_START, + PASSPORT_AUTH_DB_SELECT_FINISH, + PASSPORT_AUTH_DB_INSERT_START, + PASSPORT_AUTH_DB_INSERT_FINISH, + PASSPORT_AUTH_LEGOINT_COMMUNICATION_START, + PASSPORT_AUTH_LEGOINT_RECEIVED, + PASSPORT_AUTH_LEGOINT_THREAD_SPAWN, + PASSPORT_AUTH_LEGOINT_WEBSERVICE_START, + PASSPORT_AUTH_LEGOINT_WEBSERVICE_FINISH, + PASSPORT_AUTH_LEGOINT_LEGOCLUB_START, + PASSPORT_AUTH_LEGOINT_LEGOCLUB_FINISH, + PASSPORT_AUTH_LEGOINT_THREAD_FINISH, + PASSPORT_AUTH_LEGOINT_REPLY, + PASSPORT_AUTH_LEGOINT_ERROR, + PASSPORT_AUTH_LEGOINT_COMMUNICATION_END, + PASSPORT_AUTH_LEGOINT_DISCONNECT, + PASSPORT_AUTH_WORLD_COMMUNICATION_START, + PASSPORT_AUTH_CLIENT_OS, + PASSPORT_AUTH_WORLD_PACKET_RECEIVED, + PASSPORT_AUTH_IM_COMMUNICATION_START, + PASSPORT_AUTH_IM_LOGIN_START, + PASSPORT_AUTH_IM_LOGIN_ALREADY_LOGGED_IN, + PASSPORT_AUTH_IM_OTHER_LOGIN_REMOVED, + PASSPORT_AUTH_IM_LOGIN_QUEUED, + PASSPORT_AUTH_IM_LOGIN_RESPONSE, + PASSPORT_AUTH_IM_COMMUNICATION_END, + PASSPORT_AUTH_WORLD_SESSION_CONFIRM_TO_AUTH, + PASSPORT_AUTH_WORLD_COMMUNICATION_FINISH, + PASSPORT_AUTH_WORLD_DISCONNECT, + NO_LEGO_INTERFACE, + DB_ERROR, + GM_REQUIRED, + NO_LEGO_WEBSERVICE_XML, + LEGO_WEBSERVICE_TIMEOUT, + LEGO_WEBSERVICE_ERROR, + NO_WORLD_SERVER +}; + +struct Stamp { + eStamps type{}; + uint32_t value{}; + uint64_t timestamp{}; + + Stamp() = default; + Stamp(eStamps type, uint32_t value, uint64_t timestamp = time(nullptr)){ + this->type = type; + this->value = value; + this->timestamp = timestamp; + } + + void Serialize(RakNet::BitStream& outBitStream) const; + bool Deserialize(RakNet::BitStream& inBitStream); +}; + +// The stamps of one login. Each step adds its stamp when it happens, on whichever server performs it: the list +// travels with the login from auth to master and back inside the server messages (REQUEST_ZONE_TRANSFER and its +// response), and the login response finally carries it to the client. +// Written as a u32 holding 16 * count + 4, then the stamps (the login response's layout). +struct Stamps { + std::vector list{}; + + Stamps() = default; + explicit Stamps(std::vector stamps) : list(std::move(stamps)) {} + + // Stamps a step that just happened, with the current time + void Add(eStamps type, uint32_t value = 0); + bool empty() const { return list.empty(); } + size_t size() const { return list.size(); } + + void Serialize(RakNet::BitStream& bitStream) const; + bool Deserialize(RakNet::BitStream& bitStream); + + // Logs each stamp (debug log) the way the client does + void Log(const std::string& context) const; +}; + +#endif // STAMPS_H diff --git a/dWorldServer/WorldServer.cpp b/dWorldServer/WorldServer.cpp index d85d99221..8022f086f 100644 --- a/dWorldServer/WorldServer.cpp +++ b/dWorldServer/WorldServer.cpp @@ -1239,7 +1239,8 @@ void HandlePacket(Packet* packet) { if (accountInfo->maxGmLevel < eGameMasterLevel::DEVELOPER) { LOG("Client's database checksum does not match the server's, aborting connection."); - std::vector stamps; + Stamps stamps; + stamps.Add(eStamps::PASSPORT_AUTH_ERROR, 1); // Using the LoginResponse here since the UI is still in the login screen state // and we have a way to send a message about the client mismatch. diff --git a/tests/dGameTests/dNetTests/CommonAuthPacketsTests.cpp b/tests/dGameTests/dNetTests/CommonAuthPacketsTests.cpp index 8b7365d9e..a46aafb7e 100644 --- a/tests/dGameTests/dNetTests/CommonAuthPacketsTests.cpp +++ b/tests/dGameTests/dNetTests/CommonAuthPacketsTests.cpp @@ -220,7 +220,14 @@ TEST_F(CommonAuthPacketsTests, LoginResponseMatchesLegacy) { const auto sysAddr = TestAddress(); ExpectSameOutput( [&] { auto copy = legacyStamps; LegacyAuthPackets::SendLoginResponse(Game::server, sysAddr, code, text, text, 2001, "user", copy); }, - [&] { auto copy = stamps; AuthPackets::SendLoginResponse(Game::server, sysAddr, code, text, text, 2001, "user", copy); }); + [&] { + // The old function appended these two to every response; now the login steps stamp themselves + auto copy = stamps; + copy.emplace_back(eStamps::PASSPORT_AUTH_IM_LOGIN_START, 1); + copy.emplace_back(eStamps::PASSPORT_AUTH_WORLD_COMMUNICATION_FINISH, 1); + Stamps loginStamps(copy); + AuthPackets::SendLoginResponse(Game::server, sysAddr, code, text, text, 2001, "user", loginStamps); + }); } } } @@ -241,7 +248,7 @@ TEST_F(CommonAuthPacketsTests, LoginResponseRoundTrip) { response.worldServerIP = LUString("192.168.1.2"); response.worldServerPort = 2000; response.errorMessage = "Something went wrong"; - response.stamps = { Stamp(eStamps::PASSPORT_AUTH_START, 0, 5), Stamp(eStamps::NO_WORLD_SERVER, 1, 6) }; + response.stamps.list = { Stamp(eStamps::PASSPORT_AUTH_START, 0, 5), Stamp(eStamps::NO_WORLD_SERVER, 1, 6) }; const auto copy = RoundTrip(response); EXPECT_EQ(copy.responseCode, eLoginResponse::SUCCESS); EXPECT_EQ(copy.events[0].string, "Talk_Like_A_Pirate"); @@ -251,13 +258,13 @@ TEST_F(CommonAuthPacketsTests, LoginResponseRoundTrip) { EXPECT_EQ(copy.cdnTicket.string, ClientPackets::LoginResponse::DEFAULT_CDN_TICKET); EXPECT_EQ(copy.localization.string, "US"); EXPECT_EQ(copy.errorMessage, "Something went wrong"); - ASSERT_EQ(copy.stamps.size(), 2); - EXPECT_EQ(copy.stamps[1].type, eStamps::NO_WORLD_SERVER); - EXPECT_EQ(copy.stamps[1].timestamp, 6); + ASSERT_EQ(copy.stamps.list.size(), 2); + EXPECT_EQ(copy.stamps.list[1].type, eStamps::NO_WORLD_SERVER); + EXPECT_EQ(copy.stamps.list[1].timestamp, 6); ExpectTruncatedFails(response); response.errorMessage.clear(); - response.stamps.clear(); + response.stamps.list.clear(); EXPECT_TRUE(RoundTrip(response).errorMessage.empty()); } @@ -283,10 +290,52 @@ TEST_F(CommonAuthPacketsTests, LoginRequestMatchesLegacy) { request.WritePacket(bytes); const auto sysAddr = TestAddress(); - // The test database knows no accounts, so both answer INVALID_USER - ExpectSameOutput( - [&] { auto packet = MakePacket(bytes, sysAddr); LegacyAuthPackets::HandleLoginRequest(Game::server, &packet); }, - [&] { Dispatch(bytes, sysAddr, AuthPackets::Handle); }); + // The test database knows no accounts, so both answer INVALID_USER. Everything but the stamps is the same. + Game::randomEngine.seed(1234); + const auto legacy = Capture([&] { auto packet = MakePacket(bytes, sysAddr); LegacyAuthPackets::HandleLoginRequest(Game::server, &packet); }); + Game::randomEngine.seed(1234); + const auto before = static_cast(std::time(nullptr)); + const auto converted = Capture([&] { Dispatch(bytes, sysAddr, AuthPackets::Handle); }); + const auto after = static_cast(std::time(nullptr)); + ASSERT_EQ(legacy.size(), 1); + ASSERT_EQ(converted.size(), 1); + EXPECT_EQ(legacy[0].sysAddr, converted[0].sysAddr); + + const auto read = [](const CapturedPacket& captured) { + RakNet::BitStream bitStream(const_cast(captured.bytes.data()), captured.bytes.size(), true); + ClientPackets::LoginResponse response; + EXPECT_TRUE(response.ReadHeader(bitStream)); + EXPECT_TRUE(response.Deserialize(bitStream)); + return response; + }; + auto legacyResponse = read(legacy[0]); + auto convertedResponse = read(converted[0]); + const auto stamps = convertedResponse.stamps.list; + legacyResponse.stamps.list.clear(); + convertedResponse.stamps.list.clear(); + RakNet::BitStream legacyBytes; + legacyResponse.WritePacket(legacyBytes); + RakNet::BitStream convertedBytes; + convertedResponse.WritePacket(convertedBytes); + EXPECT_PACKET_EQ(FromBitStream(legacyBytes), FromBitStream(convertedBytes)); + EXPECT_EQ(convertedResponse.responseCode, eLoginResponse::INVALID_USER); + + // The steps the login went through, in order, stamped as they happened + const std::vector> expected = { + { eStamps::PASSPORT_AUTH_START, 0 }, + { eStamps::PASSPORT_AUTH_CLIENT_OS, static_cast(ClientOS::WINDOWS) }, + { eStamps::PASSPORT_AUTH_DB_SELECT_START, 0 }, + { eStamps::PASSPORT_AUTH_DB_SELECT_FINISH, 0 }, // not found + { eStamps::PASSPORT_AUTH_ERROR, 1 }, + }; + ASSERT_EQ(stamps.size(), expected.size()); + for (size_t i = 0; i < stamps.size(); i++) { + EXPECT_EQ(stamps[i].type, expected[i].first) << i; + EXPECT_EQ(stamps[i].value, expected[i].second) << i; + EXPECT_GE(stamps[i].timestamp, before); + EXPECT_LE(stamps[i].timestamp, after); + if (i > 0) EXPECT_GE(stamps[i].timestamp, stamps[i - 1].timestamp); + } const auto copy = RoundTrip(request); EXPECT_EQ(copy.username.GetAsString(), username.substr(0, 33)); @@ -297,3 +346,87 @@ TEST_F(CommonAuthPacketsTests, LoginRequestMatchesLegacy) { ExpectTruncatedFails(request); } } + +TEST_F(CommonAuthPacketsTests, LoginStampsRecordStepsAsTheyHappen) { + const auto before = static_cast(std::time(nullptr)); + Stamps stamps; + EXPECT_TRUE(stamps.empty()); + stamps.Log("nobody"); // nothing to log + stamps.Add(eStamps::PASSPORT_AUTH_START); + stamps.Add(eStamps::PASSPORT_AUTH_WORLD_PACKET_RECEIVED, 42); + stamps.Add(eStamps::NO_WORLD_SERVER, 1); + const auto after = static_cast(std::time(nullptr)); + stamps.Log("somebody"); + + const auto& list = stamps.list; + ASSERT_EQ(list.size(), 3); + EXPECT_EQ(list[0].type, eStamps::PASSPORT_AUTH_START); + EXPECT_EQ(list[0].value, 0); + EXPECT_EQ(list[1].type, eStamps::PASSPORT_AUTH_WORLD_PACKET_RECEIVED); + EXPECT_EQ(list[1].value, 42); + EXPECT_EQ(list[2].type, eStamps::NO_WORLD_SERVER); + for (const auto& stamp : list) { + EXPECT_GE(stamp.timestamp, before); + EXPECT_LE(stamp.timestamp, after); + } + + // A failed response carries exactly the stamps of the steps that ran, nothing appended + const auto sent = Capture([&] { AuthPackets::SendLoginResponse(Game::server, TestAddress(), eLoginResponse::WRONG_PASS, "", "", 2001, "somebody", stamps); }); + ASSERT_EQ(sent.size(), 1); + RakNet::BitStream bitStream(const_cast(sent[0].bytes.data()), sent[0].bytes.size(), true); + ClientPackets::LoginResponse response; + ASSERT_TRUE(response.ReadHeader(bitStream)); + ASSERT_TRUE(response.Deserialize(bitStream)); + ASSERT_EQ(response.stamps.list.size(), 3); + for (size_t i = 0; i < 3; i++) { + EXPECT_EQ(response.stamps.list[i].type, list[i].type); + EXPECT_EQ(response.stamps.list[i].value, list[i].value); + EXPECT_EQ(response.stamps.list[i].timestamp, list[i].timestamp); + } +} + +TEST_F(CommonAuthPacketsTests, StampGoldenBytes) { + ClientPackets::LoginResponse response; + response.stamps.list = { Stamp(eStamps::PASSPORT_AUTH_CLIENT_OS, 1, 0x0102030405060708) }; + RakNet::BitStream bytes; + response.WritePacket(bytes); + // ... | error length 0 | stamps size 16 * 1 + 4 | CLIENT_OS (20) | value 1 | timestamp + const auto all = FromBitStream(bytes); + const std::vector tail(all.bytes.end() - 22, all.bytes.end()); + EXPECT_PACKET_EQ(FromHex("00 00 14 00 00 00 14 00 00 00 01 00 00 00 08 07 06 05 04 03 02 01"), (PacketBytes{ tail, 22 * 8 })); +} + +TEST_F(CommonAuthPacketsTests, StampsRoundTrip) { + for (const size_t count : { size_t{ 0 }, size_t{ 1 }, size_t{ 7 } }) { + Stamps stamps; + for (size_t i = 0; i < count; i++) stamps.list.emplace_back(static_cast(i), static_cast(i + 100), 1790000000 + i); + RakNet::BitStream bytes; + stamps.Serialize(bytes); + EXPECT_EQ(bytes.GetNumberOfBytesUsed(), 4 + 16 * count); + + Stamps copy; + ASSERT_TRUE(copy.Deserialize(bytes)); + EXPECT_EQ(bytes.GetNumberOfUnreadBits(), 0); + ASSERT_EQ(copy.size(), count); + for (size_t i = 0; i < count; i++) { + EXPECT_EQ(copy.list[i].type, stamps.list[i].type); + EXPECT_EQ(copy.list[i].value, stamps.list[i].value); + EXPECT_EQ(copy.list[i].timestamp, stamps.list[i].timestamp); + } + + // Every truncation fails + for (uint32_t cut = 0; cut < bytes.GetNumberOfBytesUsed(); cut++) { + RakNet::BitStream truncated(bytes.GetData(), cut, true); + Stamps partial; + EXPECT_FALSE(partial.Deserialize(truncated)) << cut; + } + } + + // A size that is not 4 + 16 * n is rejected + RakNet::BitStream bad; + bad.Write(4 + 15); + bad.Write(0); + bad.Write(0); + Stamps rejected; + EXPECT_FALSE(rejected.Deserialize(bad)); +}