From a7e3d4853abb7520248c2ae8ddb7bb1aba5edafe Mon Sep 17 00:00:00 2001 From: Martin Michelsen Date: Fri, 1 Jul 2022 00:26:48 -0700 Subject: [PATCH] add session replay functions --- CMakeLists.txt | 1 + src/Channel.cc | 16 +- src/Channel.hh | 4 +- src/Client.cc | 8 +- src/Client.hh | 1 + src/CommandFormats.hh | 4 +- src/IPStackSimulator.cc | 3 +- src/Loggers.cc | 4 +- src/Loggers.hh | 1 + src/Main.cc | 146 +++++++++------ src/PSOProtocol.cc | 55 ++++++ src/PSOProtocol.hh | 7 + src/ProxyCommands.cc | 8 +- src/ReceiveCommands.cc | 4 +- src/ReplaySession.cc | 358 +++++++++++++++++++++++++++++++++++++ src/ReplaySession.hh | 90 ++++++++++ src/SendCommands.cc | 8 +- src/SendCommands.hh | 4 +- src/Server.cc | 63 ++++--- src/Server.hh | 13 +- src/ServerShell.cc | 2 +- src/ServerShell.hh | 2 + src/Shell.cc | 4 + src/Shell.hh | 2 + system/config.example.json | 3 + 25 files changed, 686 insertions(+), 125 deletions(-) create mode 100644 src/ReplaySession.cc create mode 100644 src/ReplaySession.hh diff --git a/CMakeLists.txt b/CMakeLists.txt index d8a30b09..e7231cc3 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -73,6 +73,7 @@ add_executable(newserv src/RareItemSet.cc src/ReceiveCommands.cc src/ReceiveSubcommands.cc + src/ReplaySession.cc src/SendCommands.cc src/Server.cc src/ServerShell.cc diff --git a/src/Channel.cc b/src/Channel.cc index 25c98bef..95fa241a 100644 --- a/src/Channel.cc +++ b/src/Channel.cc @@ -213,12 +213,8 @@ Channel::Message Channel::recv(bool print_contents) { print_color_escape(stderr, this->terminal_recv_color, TerminalFormat::BOLD, TerminalFormat::END); } - string name_token; - if (!this->name.empty()) { - name_token = " from " + this->name; - } - command_data_log.info("Received%s (version=%s command=%04hX flag=%08X)", - name_token.c_str(), + command_data_log.info("Received from %s (version=%s command=%04hX flag=%08X)", + this->name.c_str(), name_for_version(this->version), header.command(this->version), header.flag(this->version)); @@ -320,15 +316,11 @@ void Channel::send(uint16_t cmd, uint32_t flag, const void* data, size_t size, } if (print_contents && (this->terminal_send_color != TerminalFormat::END)) { - string name_token; - if (!this->name.empty()) { - name_token = " to " + this->name; - } if (use_terminal_colors && this->terminal_send_color != TerminalFormat::NORMAL) { print_color_escape(stderr, TerminalFormat::FG_YELLOW, TerminalFormat::BOLD, TerminalFormat::END); } - command_data_log.info("Sending%s (version=%s command=%04hX flag=%08X)", - name_token.c_str(), name_for_version(version), cmd, flag); + command_data_log.info("Sending to %s (version=%s command=%04hX flag=%08X)", + this->name.c_str(), name_for_version(version), cmd, flag); print_data(stderr, send_data.data(), logical_size, 0, nullptr, PrintDataFlags::PRINT_ASCII | PrintDataFlags::DISABLE_COLOR); if (use_terminal_colors && this->terminal_send_color != TerminalFormat::NORMAL) { print_color_escape(stderr, TerminalFormat::NORMAL, TerminalFormat::END); diff --git a/src/Channel.hh b/src/Channel.hh index ad4fd002..9b3a2e24 100644 --- a/src/Channel.hh +++ b/src/Channel.hh @@ -38,14 +38,16 @@ struct Channel { on_error_t on_error; void* context_obj; + // Creates an unconnected channel Channel( GameVersion version, on_command_received_t on_command_received, on_error_t on_error, void* context_obj, - const std::string& name = "", + const std::string& name, TerminalFormat terminal_send_color = TerminalFormat::END, TerminalFormat terminal_recv_color = TerminalFormat::END); + // Creates a connected channel Channel( struct bufferevent* bev, GameVersion version, diff --git a/src/Client.cc b/src/Client.cc index 8cd9fcc0..2294cebd 100644 --- a/src/Client.cc +++ b/src/Client.cc @@ -6,6 +6,7 @@ #include #include +#include #include #include @@ -18,17 +19,20 @@ using namespace std; const uint64_t CLIENT_CONFIG_MAGIC = 0x492A890E82AC9839; +static atomic next_id(1); + Client::Client( struct bufferevent* bev, GameVersion version, ServerBehavior server_behavior) - : log("", client_log.min_level), + : id(next_id++), + log("", client_log.min_level), version(version), bb_game_state(0), flags(flags_for_version(this->version, 0)), - channel(bev, this->version, nullptr, nullptr, this, "", TerminalFormat::FG_YELLOW, TerminalFormat::FG_GREEN), + channel(bev, this->version, nullptr, nullptr, this, string_printf("C-%" PRIX64, this->id), TerminalFormat::FG_YELLOW, TerminalFormat::FG_GREEN), server_behavior(server_behavior), should_disconnect(false), should_send_to_lobby_server(false), diff --git a/src/Client.hh b/src/Client.hh index 4c70642b..1763ae4c 100644 --- a/src/Client.hh +++ b/src/Client.hh @@ -57,6 +57,7 @@ struct Client { DEFAULT_V4_BB = NO_MESSAGE_BOX_CLOSE_CONFIRMATION_AFTER_LOBBY_JOIN | NO_MESSAGE_BOX_CLOSE_CONFIRMATION | SAVE_ENABLED, }; + uint64_t id; PrefixedLogger log; // License & account diff --git a/src/CommandFormats.hh b/src/CommandFormats.hh index a4678339..7a9fbf7b 100644 --- a/src/CommandFormats.hh +++ b/src/CommandFormats.hh @@ -269,7 +269,7 @@ struct SC_TextHeader_01_06_11_B0_EE { // The copyright field in the below structure must contain the following text: // "DreamCast Lobby Server. Copyright SEGA Enterprises. 1999" -struct S_ServerInit_DC_PC_GC_02_17_92_9B { +struct S_ServerInit_DC_PC_GC_02_17_91_9B { ptext copyright; le_uint32_t server_key; // Key for data sent by server le_uint32_t client_key; // Key for data sent by client @@ -305,7 +305,7 @@ struct C_LegacyLogin_PC_GC_03 { // The copyright field in the below structure must contain the following text: // "Phantasy Star Online Blue Burst Game Server. Copyright 1999-2004 SONICTEAM." -struct S_ServerInit_BB_03 { +struct S_ServerInit_BB_03_9B { ptext copyright; parray server_key; parray client_key; diff --git a/src/IPStackSimulator.cc b/src/IPStackSimulator.cc index f2f73434..ed233ed3 100644 --- a/src/IPStackSimulator.cc +++ b/src/IPStackSimulator.cc @@ -776,7 +776,8 @@ void IPStackSimulator::open_server_connection( } } else if (this->state->game_server.get()) { this->state->game_server->connect_client(bevs[1], c->ipv4_addr, - conn.client_port, port_config->version, port_config->behavior); + conn.client_port, conn.server_port, port_config->version, + port_config->behavior); ip_stack_simulator_log.info("Connected TCP connection %s to game server", conn_str.c_str()); } else { diff --git a/src/Loggers.cc b/src/Loggers.cc index 42aa65e9..f7c433e9 100644 --- a/src/Loggers.cc +++ b/src/Loggers.cc @@ -9,7 +9,7 @@ using namespace std; PrefixedLogger ax_messages_log ("[$ax message] " , LogLevel::USE_DEFAULT); PrefixedLogger channel_exceptions_log("[Channel] " , LogLevel::USE_DEFAULT); PrefixedLogger client_log ("" , LogLevel::USE_DEFAULT); -PrefixedLogger command_data_log ("" , LogLevel::USE_DEFAULT); +PrefixedLogger command_data_log ("[Commands] " , LogLevel::USE_DEFAULT); PrefixedLogger config_log ("[Config] " , LogLevel::USE_DEFAULT); PrefixedLogger dns_server_log ("[DNSServer] " , LogLevel::USE_DEFAULT); PrefixedLogger function_compiler_log ("[FunctionCompiler] ", LogLevel::USE_DEFAULT); @@ -18,6 +18,7 @@ PrefixedLogger license_log ("[LicenseManager] " , LogLevel::USE_DEFAU PrefixedLogger lobby_log ("" , LogLevel::USE_DEFAULT); PrefixedLogger player_data_log ("" , LogLevel::USE_DEFAULT); PrefixedLogger proxy_server_log ("[ProxyServer] " , LogLevel::USE_DEFAULT); +PrefixedLogger replay_log ("[ReplaySession] " , LogLevel::USE_DEFAULT); PrefixedLogger server_log ("[Server] " , LogLevel::USE_DEFAULT); PrefixedLogger static_game_data_log ("[StaticGameData] " , LogLevel::USE_DEFAULT); @@ -52,6 +53,7 @@ void set_log_levels_from_json(shared_ptr json) { set_log_level_from_json(lobby_log , json, "Lobbies"); set_log_level_from_json(player_data_log , json, "PlayerData"); set_log_level_from_json(proxy_server_log , json, "ProxyServer"); + set_log_level_from_json(replay_log , json, "Replay"); set_log_level_from_json(server_log , json, "GameServer"); set_log_level_from_json(static_game_data_log , json, "StaticGameData"); } diff --git a/src/Loggers.hh b/src/Loggers.hh index dacb3570..63633a3b 100644 --- a/src/Loggers.hh +++ b/src/Loggers.hh @@ -17,6 +17,7 @@ extern PrefixedLogger license_log; extern PrefixedLogger lobby_log; extern PrefixedLogger player_data_log; extern PrefixedLogger proxy_server_log; +extern PrefixedLogger replay_log; extern PrefixedLogger server_log; extern PrefixedLogger static_game_data_log; diff --git a/src/Main.cc b/src/Main.cc index 32eefe07..71b82b7c 100644 --- a/src/Main.cc +++ b/src/Main.cc @@ -1,26 +1,27 @@ -#include -#include #include +#include +#include #include -#include +#include #include #include #include -#include #include +#include +#include "DNSServer.hh" +#include "FileContentsCache.hh" +#include "IPStackSimulator.hh" #include "Loggers.hh" #include "NetworkAddresses.hh" -#include "SendCommands.hh" -#include "DNSServer.hh" #include "ProxyServer.hh" -#include "ServerState.hh" +#include "ReplaySession.hh" +#include "SendCommands.hh" #include "Server.hh" -#include "FileContentsCache.hh" -#include "Text.hh" #include "ServerShell.hh" -#include "IPStackSimulator.hh" +#include "ServerState.hh" +#include "Text.hh" using namespace std; @@ -198,6 +199,7 @@ enum class Behavior { ENCRYPT_DATA, DECODE_QUEST_FILE, DECODE_SJIS, + REPLAY_LOG, }; enum class EncryptionType { @@ -220,6 +222,7 @@ int main(int argc, char** argv) { string seed; string key_file_name; bool parse_data = false; + const char* replay_log_filename = nullptr; for (int x = 1; x < argc; x++) { if (!strcmp(argv[x], "--decrypt-data")) { behavior = Behavior::DECRYPT_DATA; @@ -251,6 +254,9 @@ int main(int argc, char** argv) { key_file_name = &argv[x][6]; } else if (!strcmp(argv[x], "--parse-data")) { parse_data = true; + } else if (!strncmp(argv[x], "--replay-log=", 13)) { + behavior = Behavior::REPLAY_LOG; + replay_log_filename = &argv[x][13]; } else { throw invalid_argument(string_printf("unknown option: %s", argv[x])); } @@ -373,54 +379,71 @@ int main(int argc, char** argv) { config_log.info("DNS server is disabled"); } - config_log.info("Opening sockets"); - for (const auto& it : state->name_to_port_config) { - const auto& pc = it.second; - if (pc->behavior == ServerBehavior::PROXY_SERVER) { - if (!state->proxy_server.get()) { - config_log.info("Starting proxy server"); - state->proxy_server.reset(new ProxyServer(base, state)); - } - if (state->proxy_server.get()) { - // For PC and GC, proxy sessions are dynamically created when a client - // picks a destination from the menu. For patch and BB clients, there's - // no way to ask the client which destination they want, so only one - // destination is supported, and we have to manually specify the - // destination netloc here. - if (pc->version == GameVersion::PATCH) { - struct sockaddr_storage ss = make_sockaddr_storage( - state->proxy_destination_patch.first, - state->proxy_destination_patch.second).first; - state->proxy_server->listen(pc->port, pc->version, &ss); - } else if (pc->version == GameVersion::BB) { - struct sockaddr_storage ss = make_sockaddr_storage( - state->proxy_destination_bb.first, - state->proxy_destination_bb.second).first; - state->proxy_server->listen(pc->port, pc->version, &ss); - } else { - state->proxy_server->listen(pc->port, pc->version); - } - } - } else { - if (!state->game_server.get()) { - config_log.info("Starting game server"); - state->game_server.reset(new Server(base, state)); - } - string name = string_printf("%s (%s, %s) on port %hu", - pc->name.c_str(), name_for_version(pc->version), - name_for_server_behavior(pc->behavior), pc->port); - state->game_server->listen(name, "", pc->port, pc->version, pc->behavior); - } - } - + shared_ptr shell; + shared_ptr replay_session; shared_ptr ip_stack_simulator; - if (!state->ip_stack_addresses.empty()) { - config_log.info("Starting IP stack simulator"); - ip_stack_simulator.reset(new IPStackSimulator(base, state)); - for (const auto& it : state->ip_stack_addresses) { - auto netloc = parse_netloc(it); - ip_stack_simulator->listen(netloc.first, netloc.second); + if (behavior == Behavior::REPLAY_LOG) { + config_log.info("Starting proxy server"); + state->proxy_server.reset(new ProxyServer(base, state)); + config_log.info("Starting game server"); + state->game_server.reset(new Server(base, state)); + + auto f = fopen_unique(replay_log_filename, "rt"); + replay_session.reset(new ReplaySession(base, f.get(), state)); + replay_session->start(); + + } else if (behavior == Behavior::RUN_SERVER) { + config_log.info("Opening sockets"); + for (const auto& it : state->name_to_port_config) { + const auto& pc = it.second; + if (pc->behavior == ServerBehavior::PROXY_SERVER) { + if (!state->proxy_server.get()) { + config_log.info("Starting proxy server"); + state->proxy_server.reset(new ProxyServer(base, state)); + } + if (state->proxy_server.get()) { + // For PC and GC, proxy sessions are dynamically created when a client + // picks a destination from the menu. For patch and BB clients, there's + // no way to ask the client which destination they want, so only one + // destination is supported, and we have to manually specify the + // destination netloc here. + if (pc->version == GameVersion::PATCH) { + struct sockaddr_storage ss = make_sockaddr_storage( + state->proxy_destination_patch.first, + state->proxy_destination_patch.second).first; + state->proxy_server->listen(pc->port, pc->version, &ss); + } else if (pc->version == GameVersion::BB) { + struct sockaddr_storage ss = make_sockaddr_storage( + state->proxy_destination_bb.first, + state->proxy_destination_bb.second).first; + state->proxy_server->listen(pc->port, pc->version, &ss); + } else { + state->proxy_server->listen(pc->port, pc->version); + } + } + } else { + if (!state->game_server.get()) { + config_log.info("Starting game server"); + state->game_server.reset(new Server(base, state)); + } + string spec = string_printf("T-%hu-%s-%s-%s", + pc->port, name_for_version(pc->version), pc->name.c_str(), + name_for_server_behavior(pc->behavior)); + state->game_server->listen(spec, "", pc->port, pc->version, pc->behavior); + } } + + if (!state->ip_stack_addresses.empty()) { + config_log.info("Starting IP stack simulator"); + ip_stack_simulator.reset(new IPStackSimulator(base, state)); + for (const auto& it : state->ip_stack_addresses) { + auto netloc = parse_netloc(it); + ip_stack_simulator->listen(netloc.first, netloc.second); + } + } + + } else { + throw logic_error("invalid behavior"); } if (!state->username.empty()) { @@ -428,12 +451,17 @@ int main(int argc, char** argv) { drop_privileges(state->username); } - bool should_run_shell = (state->run_shell_behavior == ServerState::RunShellBehavior::ALWAYS); + bool should_run_shell; if (state->run_shell_behavior == ServerState::RunShellBehavior::DEFAULT) { should_run_shell = isatty(fileno(stdin)); + } else if (state->run_shell_behavior == ServerState::RunShellBehavior::ALWAYS) { + should_run_shell = true; + } else { + should_run_shell = false; + } + if (should_run_shell) { + should_run_shell = !replay_session.get(); } - - shared_ptr shell; if (should_run_shell) { shell.reset(new ServerShell(base, state)); } diff --git a/src/PSOProtocol.cc b/src/PSOProtocol.cc index faa87a1e..0833df8a 100644 --- a/src/PSOProtocol.cc +++ b/src/PSOProtocol.cc @@ -146,3 +146,58 @@ void check_size_v(size_t size, size_t min_size, size_t max_size) { max_size, size)); } } + + + +std::string prepend_command_header( + GameVersion version, + bool encryption_enabled, + uint16_t cmd, + uint32_t flag, + const std::string& data) { + StringWriter ret; + switch (version) { + case GameVersion::GC: + case GameVersion::DC: { + PSOCommandHeaderDCGC header; + if (encryption_enabled) { + header.size = (sizeof(header) + data.size() + 3) & ~3; + } else { + header.size = (sizeof(header) + data.size()); + } + header.command = cmd; + header.flag = flag; + ret.put(header); + break; + } + case GameVersion::PC: + case GameVersion::PATCH: { + PSOCommandHeaderPC header; + if (encryption_enabled) { + header.size = (sizeof(header) + data.size() + 3) & ~3; + } else { + header.size = (sizeof(header) + data.size()); + } + header.command = cmd; + header.flag = flag; + ret.put(header); + break; + } + case GameVersion::BB: { + PSOCommandHeaderBB header; + if (encryption_enabled) { + header.size = (sizeof(header) + data.size() + 7) & ~7; + } else { + header.size = (sizeof(header) + data.size()); + } + header.command = cmd; + header.flag = flag; + ret.put(header); + break; + } + default: + throw logic_error("unimplemented game version in prepend_command_header"); + } + ret.write(data); + return move(ret.str()); +} diff --git a/src/PSOProtocol.hh b/src/PSOProtocol.hh index eeda81dc..ff639bc0 100644 --- a/src/PSOProtocol.hh +++ b/src/PSOProtocol.hh @@ -90,3 +90,10 @@ T& check_size_t( } void check_size_v(size_t size, size_t min_size, size_t max_size = 0); + +std::string prepend_command_header( + GameVersion version, + bool encryption_enabled, + uint16_t cmd, + uint32_t flag, + const std::string& data); diff --git a/src/ProxyCommands.cc b/src/ProxyCommands.cc index 6dd5b48f..b0142848 100644 --- a/src/ProxyCommands.cc +++ b/src/ProxyCommands.cc @@ -155,8 +155,8 @@ static HandlerResult process_server_pc_gc_patch_02_17(shared_ptr s, // Most servers don't include after_message or have a shorter // after_message than newserv does, so don't require it - const auto& cmd = check_size_t(data, - offsetof(S_ServerInit_DC_PC_GC_02_17_92_9B, after_message), 0xFFFF); + const auto& cmd = check_size_t(data, + offsetof(S_ServerInit_DC_PC_GC_02_17_91_9B, after_message), 0xFFFF); if (!session.license) { session.log.info("No license in linked session"); @@ -250,8 +250,8 @@ static HandlerResult process_server_bb_03(shared_ptr s, ProxyServer::LinkedSession& session, uint16_t, uint32_t, string& data) { // Most servers don't include after_message or have a shorter after_message // than newserv does, so don't require it - const auto& cmd = check_size_t(data, - offsetof(S_ServerInit_BB_03, after_message), 0xFFFF); + const auto& cmd = check_size_t(data, + offsetof(S_ServerInit_BB_03_9B, after_message), 0xFFFF); // If the session has a detector crypt, then it was resumed from an unlinked // session, during which we already sent an 03 command. diff --git a/src/ReceiveCommands.cc b/src/ReceiveCommands.cc index 507231d4..1c10a7c6 100644 --- a/src/ReceiveCommands.cc +++ b/src/ReceiveCommands.cc @@ -1388,7 +1388,9 @@ void process_player_data(shared_ptr s, shared_ptr c, auto player = c->game_data.player(false); if (player) { - c->channel.name = remove_language_marker(encode_sjis(player->disp.name)); + string name_str = remove_language_marker(encode_sjis(player->disp.name)); + c->channel.name = string_printf("C-%" PRIX64 " (%s)", + c->id, name_str.c_str()); } // 98 should only be sent when leaving a game, and we should leave the client diff --git a/src/ReplaySession.cc b/src/ReplaySession.cc new file mode 100644 index 00000000..945858ba --- /dev/null +++ b/src/ReplaySession.cc @@ -0,0 +1,358 @@ +#include "ReplaySession.hh" + +#include +#include +#include + +#include "Loggers.hh" +#include "Shell.hh" +#include "Server.hh" + +using namespace std; + + + +ReplaySession::Event::Event(Type type, uint64_t client_id) + : type(type), client_id(client_id), complete(false) { } + +ReplaySession::Client::Client( + ReplaySession* session, uint64_t id, uint16_t port, GameVersion version) + : id(id), + port(port), + version(version), + channel( + this->version, + &ReplaySession::dispatch_on_command_received, + &ReplaySession::dispatch_on_error, + session, + string_printf("R-%" PRIX64, this->id)) { } + + + +shared_ptr ReplaySession::create_event( + Event::Type type, shared_ptr c) { + shared_ptr event(new Event(type, c->id)); + if (!this->last_event.get()) { + this->first_event = event; + } else { + this->last_event->next_event = event; + } + this->last_event = event; + if (type == Event::Type::RECEIVE) { + c->receive_events.emplace_back(event); + } + return event; +} + +ReplaySession::ReplaySession( + shared_ptr base, + FILE* input_log, + shared_ptr state) + : state(state), + base(base), + commands_sent(0), + bytes_sent(0), + commands_received(0), + bytes_received(0) { + shared_ptr parsing_command = nullptr; + + while (!feof(input_log)) { + string line = fgets(input_log); + if (starts_with(line, Shell::PROMPT)) { + line = line.substr(Shell::PROMPT.size()); + } + if (ends_with(line, "\n")) { + line.resize(line.size() - 1); + } + if (line.empty()) { + continue; + } + + if (parsing_command.get()) { + string expected_start = string_printf("%016zX |", parsing_command->data.size()); + if (starts_with(line, expected_start)) { + // Parse out the hex part of the hex/ASCII dump + string mask_bytes; + string data_bytes = parse_data_string( + line.substr(expected_start.size(), 16 * 3 + 1), &mask_bytes); + parsing_command->data += data_bytes; + parsing_command->mask += mask_bytes; + continue; + } else { + parsing_command = nullptr; + } + } + + if (starts_with(line, "I ")) { + // I - [Server] Client connected: C-%X on fd %d via %d (T-%hu-%s-%s-%s) + // I - [Server] Client connected: C-%X on virtual connection %p via T-%hu-VI + size_t offset = line.find(" - [Server] Client connected: C-"); + if (offset != string::npos) { + auto tokens = split(line, ' '); + if (tokens.size() != 15) { + throw runtime_error("client connection message has incorrect token count"); + } + if (!starts_with(tokens[8], "C-")) { + throw runtime_error("client connection message missing client ID token"); + } + auto listen_tokens = split(tokens[14], '-'); + if (listen_tokens.size() < 4) { + throw runtime_error("client connection message listening socket token format is incorrect"); + } + + shared_ptr c(new Client( + this, + stoull(tokens[8].substr(2), nullptr, 16), + stoul(listen_tokens[1], nullptr, 10), + version_for_name(listen_tokens[2].c_str()))); + if (!this->clients.emplace(c->id, c).second) { + throw runtime_error("duplicate client ID in input log"); + } + this->create_event(Event::Type::CONNECT, c); + continue; + } + + // I - [Server] Disconnecting C-%X on fd %d + offset = line.find(" - [Server] Client disconnected: C-"); + if (offset != string::npos) { + auto tokens = split(line, ' '); + if (tokens.size() < 9) { + throw runtime_error("client disconnection message has incorrect token count"); + } + if (!starts_with(tokens[8], "C-")) { + throw runtime_error("client disconnection message missing client ID token"); + } + uint64_t client_id = stoul(tokens[8].substr(2), nullptr, 16); + try { + auto& c = this->clients.at(client_id); + if (c->disconnect_event.get()) { + throw runtime_error("client has multiple disconnect events"); + } + c->disconnect_event = this->create_event(Event::Type::DISCONNECT, c); + } catch (const out_of_range&) { + throw runtime_error("unknown disconnecting client ID in input log"); + } + continue; + } + + // I - [Commands] Sending to C-%X (...) + // I - [Commands] Received from C-%X (...) + offset = line.find(" - [Commands] Sending to C-"); + if (offset == string::npos) { + offset = line.find(" - [Commands] Received from C-"); + } + if (offset != string::npos) { + auto tokens = split(line, ' '); + if (tokens.size() < 10) { + throw runtime_error("command header line too short"); + } + bool from_client = (tokens[6] == "Received"); + uint64_t client_id = stoull(tokens[8].substr(2), nullptr, 16); + try { + parsing_command = this->create_event( + from_client ? Event::Type::SEND : Event::Type::RECEIVE, + this->clients.at(client_id)); + } catch (const out_of_range&) { + throw runtime_error("input log contains command for missing client"); + } + continue; + } + } + } +} + +void ReplaySession::start() { + this->update_timeout_event(); + this->execute_pending_events(); +} + +void ReplaySession::update_timeout_event() { + if (!this->timeout_ev.get()) { + this->timeout_ev.reset( + event_new(this->base.get(), -1, EV_TIMEOUT, this->dispatch_on_timeout, this), + event_free); + } + struct timeval tv = usecs_to_timeval(3000000); + event_add(this->timeout_ev.get(), &tv); +} + +void ReplaySession::dispatch_on_timeout(evutil_socket_t, short, void*) { + throw runtime_error("timeout waiting for next event"); +} + +void ReplaySession::execute_pending_events() { + while (this->first_event) { + if (!this->first_event->complete) { + auto& c = this->clients.at(this->first_event->client_id); + switch (this->first_event->type) { + case Event::Type::CONNECT: { + if (c->channel.connected()) { + throw runtime_error("connect event on already-connected client"); + } + + struct bufferevent* bevs[2]; + bufferevent_pair_new(this->base.get(), 0, bevs); + + c->channel.set_bufferevent(bevs[0]); + this->channel_to_client.emplace(&c->channel, c); + + shared_ptr port_config; + try { + port_config = this->state->number_to_port_config.at(c->port); + } catch (const out_of_range&) { + bufferevent_free(bevs[1]); + throw runtime_error("client connected to port missing from configuration"); + } + + if (port_config->behavior == ServerBehavior::PROXY_SERVER) { + // TODO: We should support this at some point in the future + throw runtime_error("client connected to proxy server"); + } else if (this->state->game_server.get()) { + this->state->game_server->connect_client(bevs[1], 0x20202020, + 1025, c->port, port_config->version, port_config->behavior); + } else { + throw runtime_error("no server available for connection"); + bufferevent_free(bevs[1]); + } + break; + } + case Event::Type::DISCONNECT: + this->channel_to_client.erase(&c->channel); + c->channel.disconnect(); + break; + case Event::Type::SEND: + if (!c->channel.connected()) { + throw runtime_error("send event attempted on unconnected client"); + } + c->channel.send(this->first_event->data); + this->commands_sent++; + this->bytes_sent += this->first_event->data.size(); + break; + case Event::Type::RECEIVE: + // Receive events cannot be executed here, since we have to wait for + // an incoming command. The existing handlers will take care of it: + // on_command_received will be called sometime (hopefully) soon. + return; + default: + throw logic_error("unhandled event type"); + } + this->first_event->complete = true; + } + + this->first_event = this->first_event->next_event; + if (!this->first_event.get()) { + this->last_event = nullptr; + } + } + + // If we get here, then there are no more events to run: we're done. + // TODO: We should flush any pending sends on the remaining client here, even + // though there are no pending receives (to make sure the last sent commands + // don't crash newserv) + replay_log.info("Replay complete: %zu commands sent (%zu bytes), %zu commands received (%zu bytes)", + this->commands_sent, this->bytes_sent, this->commands_received, this->bytes_received); + event_base_loopexit(this->base.get(), nullptr); +} + +void ReplaySession::dispatch_on_command_received( + Channel& ch, uint16_t command, uint32_t flag, string& data) { + ReplaySession* session = reinterpret_cast(ch.context_obj); + session->on_command_received( + session->channel_to_client.at(&ch), command, flag, data); +} + +void ReplaySession::dispatch_on_error(Channel& ch, short events) { + ReplaySession* session = reinterpret_cast(ch.context_obj); + session->on_error(session->channel_to_client.at(&ch), events); +} + +void ReplaySession::on_command_received( + shared_ptr c, uint16_t command, uint32_t flag, string& data) { + + string full_command = prepend_command_header( + c->version, c->channel.crypt_in.get(), command, flag, data); + this->commands_received++; + this->bytes_received += full_command.size(); + + if (c->receive_events.empty()) { + print_data(stderr, full_command); + throw runtime_error("received unexpected command for client"); + } + + auto& ev = c->receive_events.front(); + if (full_command.size() != ev->data.size()) { + replay_log.error("Expected command:"); + print_data(stderr, ev->data); + replay_log.error("Received command:"); + print_data(stderr, full_command); + throw runtime_error("received command sizes do not match"); + } + for (size_t x = 0; x < full_command.size(); x++) { + if ((full_command[x] & ev->mask[x]) != (ev->data[x] & ev->mask[x])) { + replay_log.error("Expected command:"); + print_data(stderr, ev->data); + replay_log.error("Received command:"); + print_data(stderr, full_command, 0, ev->data.data()); + throw runtime_error("received command data does not match expected data"); + } + } + + ev->complete = true; + c->receive_events.pop_front(); + + // If the command is an encryption init, set up encryption on the channel + switch (c->version) { + case GameVersion::DC: + throw runtime_error("DC encryption is not supported during replays"); + case GameVersion::PC: + case GameVersion::GC: + if (command == 0x02 || command == 0x17 || command == 0x91 || command == 0x9B) { + auto& cmd = check_size_t(data, + offsetof(S_ServerInit_DC_PC_GC_02_17_91_9B, after_message), 0xFFFF); + if (c->version == GameVersion::GC) { + c->channel.crypt_in.reset(new PSOGCEncryption(cmd.server_key)); + c->channel.crypt_out.reset(new PSOGCEncryption(cmd.client_key)); + } else { + c->channel.crypt_in.reset(new PSOPCEncryption(cmd.server_key)); + c->channel.crypt_out.reset(new PSOPCEncryption(cmd.client_key)); + } + } + break; + case GameVersion::BB: + if (command == 0x03 || command == 0x9B) { + auto& cmd = check_size_t(data, + sizeof(S_ServerInit_BB_03_9B), 0xFFFF); + // TODO: At some point it may matter which BB private key file we use. + // Don't just blindly use the first one here. + c->channel.crypt_in.reset(new PSOBBEncryption( + *this->state->bb_private_keys[0], cmd.server_key.data(), cmd.server_key.size())); + c->channel.crypt_out.reset(new PSOBBEncryption( + *this->state->bb_private_keys[0], cmd.client_key.data(), cmd.client_key.size())); + } + break; + default: + throw logic_error("unsupported encryption version"); + } + + this->update_timeout_event(); + this->execute_pending_events(); +} + +void ReplaySession::on_error(shared_ptr c, short events) { + if (events & BEV_EVENT_ERROR) { + throw runtime_error(string_printf("C-%" PRIX64 " caused stream error", c->id)); + } + if (events & BEV_EVENT_EOF) { + if (!c->disconnect_event.get()) { + throw runtime_error(string_printf( + "C-%" PRIX64 " disconnected, but has no disconnect event", c->id)); + } + if (!c->receive_events.empty()) { + throw runtime_error(string_printf( + "C-%" PRIX64 " disconnected, but has pending receive events", c->id)); + } + c->disconnect_event->complete = true; + this->channel_to_client.erase(&c->channel); + c->channel.disconnect(); + } +} diff --git a/src/ReplaySession.hh b/src/ReplaySession.hh new file mode 100644 index 00000000..845f2665 --- /dev/null +++ b/src/ReplaySession.hh @@ -0,0 +1,90 @@ +#pragma once + +#include +#include +#include + +#include +#include +#include + +#include "Channel.hh" +#include "Version.hh" +#include "ServerState.hh" + + + +class ReplaySession { +public: + ReplaySession( + std::shared_ptr base, + FILE* input_log, + std::shared_ptr state); + ReplaySession(const ReplaySession&) = delete; + ReplaySession(ReplaySession&&) = delete; + ReplaySession& operator=(const ReplaySession&) = delete; + ReplaySession& operator=(ReplaySession&&) = delete; + ~ReplaySession() = default; + + void start(); + +private: + struct Event { + enum class Type { + CONNECT = 0, + DISCONNECT, + SEND, + RECEIVE, + }; + Type type; + uint64_t client_id; + std::string data; // Only used for SEND and RECEIVE + std::string mask; // Only used for RECEIVE + bool complete; + + std::shared_ptr next_event; + + Event(Type type, uint64_t client_id); + }; + + struct Client { + uint64_t id; + uint16_t port; + GameVersion version; + Channel channel; + std::deque> receive_events; + std::shared_ptr disconnect_event; + + Client(ReplaySession* session, uint64_t id, uint16_t port, GameVersion version); + }; + + std::shared_ptr state; + + std::unordered_map> clients; + std::unordered_map> channel_to_client; + + std::shared_ptr first_event; + std::shared_ptr last_event; + + std::shared_ptr base; + std::shared_ptr timeout_ev; + + size_t commands_sent; + size_t bytes_sent; + size_t commands_received; + size_t bytes_received; + + std::shared_ptr create_event( + Event::Type type, std::shared_ptr c); + void update_timeout_event(); + + static void dispatch_on_timeout(evutil_socket_t fd, short events, void* ctx); + static void dispatch_on_command_received( + Channel& ch, uint16_t command, uint32_t flag, std::string& data); + static void dispatch_on_error(Channel& ch, short events); + void on_command_received( + std::shared_ptr c, uint16_t command, uint32_t flag, std::string& data); + void on_error(std::shared_ptr c, short events); + + void execute_pending_events(); +}; diff --git a/src/SendCommands.cc b/src/SendCommands.cc index 35f43fc6..a184a2da 100644 --- a/src/SendCommands.cc +++ b/src/SendCommands.cc @@ -100,11 +100,11 @@ static const char* bb_game_server_copyright = "Phantasy Star Online Blue Burst G static const char* bb_pm_server_copyright = "PSO NEW PM Server. Copyright 1999-2002 SONICTEAM."; static const char* patch_server_copyright = "Patch Server. Copyright SonicTeam, LTD. 2001"; -S_ServerInit_DC_PC_GC_02_17_92_9B prepare_server_init_contents_dc_pc_gc( +S_ServerInit_DC_PC_GC_02_17_91_9B prepare_server_init_contents_dc_pc_gc( bool initial_connection, uint32_t server_key, uint32_t client_key) { - S_ServerInit_DC_PC_GC_02_17_92_9B cmd; + S_ServerInit_DC_PC_GC_02_17_91_9B cmd; cmd.copyright = initial_connection ? dc_port_map_copyright : dc_lobby_server_copyright; cmd.server_key = server_key; @@ -138,11 +138,11 @@ void send_server_init_dc_pc_gc(shared_ptr c, } } -S_ServerInit_BB_03 prepare_server_init_contents_bb( +S_ServerInit_BB_03_9B prepare_server_init_contents_bb( const parray& server_key, const parray& client_key, bool use_secondary_message) { - S_ServerInit_BB_03 cmd; + S_ServerInit_BB_03_9B cmd; cmd.copyright = use_secondary_message ? bb_pm_server_copyright : bb_game_server_copyright; cmd.server_key = server_key; cmd.client_key = client_key; diff --git a/src/SendCommands.hh b/src/SendCommands.hh index 02ecea4e..1498ab49 100644 --- a/src/SendCommands.hh +++ b/src/SendCommands.hh @@ -96,11 +96,11 @@ void send_command_with_header(std::shared_ptr c, const void* data, -S_ServerInit_DC_PC_GC_02_17_92_9B prepare_server_init_contents_dc_pc_gc( +S_ServerInit_DC_PC_GC_02_17_91_9B prepare_server_init_contents_dc_pc_gc( bool initial_connection, uint32_t server_key, uint32_t client_key); -S_ServerInit_BB_03 prepare_server_init_contents_bb( +S_ServerInit_BB_03_9B prepare_server_init_contents_bb( const parray& server_key, const parray& client_key, bool use_secondary_message); diff --git a/src/Server.cc b/src/Server.cc index 1d39cb57..5a62826d 100644 --- a/src/Server.cc +++ b/src/Server.cc @@ -31,11 +31,11 @@ using namespace std::placeholders; void Server::disconnect_client(shared_ptr c) { if (c->channel.is_virtual_connection) { - server_log.info("Disconnecting client on virtual connection %p", - c->channel.bev.get()); + server_log.info("Client disconnected: C-%" PRIX64 " on virtual connection %p", + c->id, c->channel.bev.get()); } else { - server_log.info("Disconnecting client on fd %d", - bufferevent_getfd(c->channel.bev.get())); + server_log.info("Client disconnected: C-%" PRIX64 " on fd %d", + c->id, bufferevent_getfd(c->channel.bev.get())); } this->channel_to_client.erase(&c->channel); @@ -76,9 +76,6 @@ void Server::on_listen_accept(struct evconnlistener* listener, return; } - server_log.info("Client fd %d connected via fd %d (%s)", - fd, listen_fd, listening_socket->name.c_str()); - struct bufferevent *bev = bufferevent_socket_new(this->base.get(), fd, BEV_OPT_CLOSE_ON_FREE | BEV_OPT_DEFER_CALLBACKS); shared_ptr c(new Client( @@ -88,6 +85,9 @@ void Server::on_listen_accept(struct evconnlistener* listener, c->channel.context_obj = this; this->channel_to_client.emplace(&c->channel, c); + server_log.info("Client connected: C-%" PRIX64 " on fd %d via %d (%s)", + c->id, fd, listen_fd, listening_socket->addr_str.c_str()); + try { process_connect(this->state, c); } catch (const exception& e) { @@ -97,23 +97,28 @@ void Server::on_listen_accept(struct evconnlistener* listener, } void Server::connect_client( - struct bufferevent* bev, uint32_t address, uint16_t port, - GameVersion version, ServerBehavior initial_state) { - server_log.info("Client connected on virtual connection %p", bev); - + struct bufferevent* bev, uint32_t address, uint16_t client_port, + uint16_t server_port, GameVersion version, ServerBehavior initial_state) { shared_ptr c(new Client(bev, version, initial_state)); c->channel.on_command_received = Server::on_client_input; c->channel.on_error = Server::on_client_error; c->channel.context_obj = this; + server_log.info("Client connected: C-%" PRIX64 " on virtual connection %p via T-%hu-%s-%s-VI", + c->id, + bev, + server_port, + name_for_version(version), + name_for_server_behavior(initial_state)); + this->channel_to_client.emplace(&c->channel, c); // Manually set the remote address, since the bufferevent has no fd and the // Channel constructor can't figure out the virtual remote address - auto* sin = reinterpret_cast(&c->channel.remote_addr); - sin->sin_family = AF_INET; - sin->sin_addr.s_addr = htonl(address); - sin->sin_port = htons(port); + auto* remote_sin = reinterpret_cast(&c->channel.remote_addr); + remote_sin->sin_family = AF_INET; + remote_sin->sin_addr.s_addr = htonl(address); + remote_sin->sin_port = htons(client_port); try { process_connect(this->state, c); @@ -169,36 +174,36 @@ Server::Server( : base(base), state(state) { } void Server::listen( - const std::string& name, + const std::string& addr_str, const string& socket_path, GameVersion version, ServerBehavior behavior) { int fd = ::listen(socket_path, 0, SOMAXCONN); - server_log.info("Listening on Unix socket %s (%s) on fd %d (name: %s)", - socket_path.c_str(), name_for_version(version), fd, name.c_str()); - this->add_socket(name, fd, version, behavior); + server_log.info("Listening on Unix socket %s on fd %d as %s", + socket_path.c_str(), fd, addr_str.c_str()); + this->add_socket(addr_str, fd, version, behavior); } void Server::listen( - const std::string& name, + const std::string& addr_str, const string& addr, int port, GameVersion version, ServerBehavior behavior) { int fd = ::listen(addr, port, SOMAXCONN); string netloc_str = render_netloc(addr, port); - server_log.info("Listening on TCP interface %s (%s) on fd %d (name: %s)", - netloc_str.c_str(), name_for_version(version), fd, name.c_str()); - this->add_socket(name, fd, version, behavior); + server_log.info("Listening on TCP interface %s on fd %d as %s", + netloc_str.c_str(), fd, addr_str.c_str()); + this->add_socket(addr_str, fd, version, behavior); } -void Server::listen(const std::string& name, int port, GameVersion version, ServerBehavior behavior) { - this->listen(name, "", port, version, behavior); +void Server::listen(const std::string& addr_str, int port, GameVersion version, ServerBehavior behavior) { + this->listen(addr_str, "", port, version, behavior); } -Server::ListeningSocket::ListeningSocket(Server* s, const std::string& name, +Server::ListeningSocket::ListeningSocket(Server* s, const std::string& addr_str, int fd, GameVersion version, ServerBehavior behavior) : - name(name), fd(fd), version(version), behavior(behavior), listener( + addr_str(addr_str), fd(fd), version(version), behavior(behavior), listener( evconnlistener_new(s->base.get(), Server::dispatch_on_listen_accept, s, LEV_OPT_REUSEABLE, 0, this->fd), evconnlistener_free) { evconnlistener_set_error_cb(this->listener.get(), @@ -206,12 +211,12 @@ Server::ListeningSocket::ListeningSocket(Server* s, const std::string& name, } void Server::add_socket( - const std::string& name, + const std::string& addr_str, int fd, GameVersion version, ServerBehavior behavior) { this->listening_sockets.emplace(piecewise_construct, forward_as_tuple(fd), - forward_as_tuple(this, name, fd, version, behavior)); + forward_as_tuple(this, addr_str, fd, version, behavior)); } shared_ptr Server::get_client() const { diff --git a/src/Server.hh b/src/Server.hh index 881c950c..e6a7467d 100644 --- a/src/Server.hh +++ b/src/Server.hh @@ -21,12 +21,13 @@ public: std::shared_ptr state); virtual ~Server() = default; - void listen(const std::string& name, const std::string& socket_path, GameVersion version, ServerBehavior initial_state); - void listen(const std::string& name, const std::string& addr, int port, GameVersion version, ServerBehavior initial_state); - void listen(const std::string& name, int port, GameVersion version, ServerBehavior initial_state); - void add_socket(const std::string& name, int fd, GameVersion version, ServerBehavior initial_state); + void listen(const std::string& addr_str, const std::string& socket_path, GameVersion version, ServerBehavior initial_state); + void listen(const std::string& addr_str, const std::string& addr, int port, GameVersion version, ServerBehavior initial_state); + void listen(const std::string& addr_str, int port, GameVersion version, ServerBehavior initial_state); + void add_socket(const std::string& addr_str, int fd, GameVersion version, ServerBehavior initial_state); - void connect_client(struct bufferevent* bev, uint32_t address, uint16_t port, + void connect_client(struct bufferevent* bev, uint32_t address, + uint16_t client_port, uint16_t server_port, GameVersion version, ServerBehavior initial_state); std::shared_ptr get_client() const; @@ -35,7 +36,7 @@ private: std::shared_ptr base; struct ListeningSocket { - std::string name; + std::string addr_str; int fd; GameVersion version; ServerBehavior behavior; diff --git a/src/ServerShell.cc b/src/ServerShell.cc index 48cdbea8..c43e6dc0 100644 --- a/src/ServerShell.cc +++ b/src/ServerShell.cc @@ -20,7 +20,7 @@ ServerShell::ServerShell( : Shell(base, state) { } void ServerShell::print_prompt() { - fwrite("newserv> ", 9, 1, stdout); + fwritex(stdout, Shell::PROMPT); fflush(stdout); } diff --git a/src/ServerShell.hh b/src/ServerShell.hh index 1b4f66d5..e179d4c3 100644 --- a/src/ServerShell.hh +++ b/src/ServerShell.hh @@ -8,6 +8,8 @@ #include "Shell.hh" #include "ProxyServer.hh" +#define SHELL_PROMPT "newserv> " + class ServerShell : public Shell { diff --git a/src/Shell.cc b/src/Shell.cc index a276844a..3b51efa1 100644 --- a/src/Shell.cc +++ b/src/Shell.cc @@ -10,6 +10,10 @@ using namespace std; +const std::string Shell::PROMPT("newserv> "); + + + Shell::exit_shell::exit_shell() : runtime_error("shell exited") { } diff --git a/src/Shell.hh b/src/Shell.hh index 30150fe6..177f68ce 100644 --- a/src/Shell.hh +++ b/src/Shell.hh @@ -21,6 +21,8 @@ public: Shell& operator=(const Shell&) = delete; Shell& operator=(Shell&&) = delete; + static const std::string PROMPT; + protected: std::shared_ptr base; std::shared_ptr state; diff --git a/system/config.example.json b/system/config.example.json index 0731b4c7..bbc3b74a 100644 --- a/system/config.example.json +++ b/system/config.example.json @@ -130,6 +130,9 @@ // Proxy server messages describe clients connecting and disconnecting from // the proxy server, as well as events that occur in each session. "ProxyServer": "info", + // Replay messages are generated when replaying a session log (usually + // during functional testing). + "Replay": "info", // Game server messages describe clients connecting and disconnecting from // the game server. "GameServer": "info",