From 1c8f4bfaef44109a77dddd66d2db86c4bb0524d3 Mon Sep 17 00:00:00 2001 From: Rubidium Date: Fri, 23 Jul 2021 21:36:17 +0100 Subject: [PATCH] Fix #9388: thread unsafe use of NetworkAdminConsole/IConsolePrint (cherry picked from commit d7a0e80fc18b689455eaca09883fccbcc722d7e3) # Conflicts: # src/debug.cpp # src/debug.h # src/table/settings/gui_settings.ini See: https://github.com/OpenTTD/OpenTTD/pull/9456 --- src/console.cpp | 14 ------- src/console_func.h | 1 - src/debug.cpp | 76 ++++++++++++++++++++++++++++++++++- src/debug.h | 3 ++ src/network/network_admin.cpp | 7 ++++ src/openttd.cpp | 2 + src/settings.cpp | 7 ++++ src/table/settings.ini | 2 + 8 files changed, 95 insertions(+), 17 deletions(-) diff --git a/src/console.cpp b/src/console.cpp index 8c12b066a8..de297a68c1 100644 --- a/src/console.cpp +++ b/src/console.cpp @@ -145,20 +145,6 @@ void CDECL IConsolePrintF(TextColour colour_code, const char *format, ...) IConsolePrint(colour_code, buf); } -/** - * It is possible to print debugging information to the console, - * which is achieved by using this function. Can only be used by - * debug() in debug.cpp. You need at least a level 2 (developer) for debugging - * messages to show up - * @param dbg debugging category - * @param string debugging message - */ -void IConsoleDebug(const char *dbg, const char *string) -{ - if (_settings_client.gui.developer <= 1) return; - IConsolePrintF(CC_DEBUG, "dbg: [%s] %s", dbg, string); -} - /** * It is possible to print warnings to the console. These are mostly * errors or mishaps, but non-fatal. You need at least a level 1 (developer) for diff --git a/src/console_func.h b/src/console_func.h index 023c8fa2f8..94cd714d30 100644 --- a/src/console_func.h +++ b/src/console_func.h @@ -23,7 +23,6 @@ void IConsoleClose(); /* console output */ void IConsolePrint(TextColour colour_code, const char *string); void CDECL IConsolePrintF(TextColour colour_code, const char *format, ...) WARN_FORMAT(2, 3); -void IConsoleDebug(const char *dbg, const char *string); void IConsoleWarning(const char *string); void IConsoleError(const char *string); diff --git a/src/debug.cpp b/src/debug.cpp index e9a433061c..24d4598b98 100644 --- a/src/debug.cpp +++ b/src/debug.cpp @@ -15,7 +15,9 @@ #include "fileio_func.h" #include "settings_type.h" #include "date_func.h" +#include "thread.h" #include +#include #if defined(_WIN32) #include "os/windows/win32.h" @@ -32,6 +34,16 @@ SOCKET _debug_socket = INVALID_SOCKET; #include "safeguards.h" +/** Element in the queue of debug messages that have to be passed to either NetworkAdminConsole or IConsolePrint.*/ +struct QueuedDebugItem { + std::string level; ///< The used debug level. + std::string message; ///< The actual formatted message. +}; +std::atomic _debug_remote_console; ///< Whether we need to send data to either NetworkAdminConsole or IConsolePrint. +std::mutex _debug_remote_console_mutex; ///< Mutex to guard the queue of debug messages for either NetworkAdminConsole or IConsolePrint. +std::vector _debug_remote_console_queue; ///< Queue for debug messages to be passed to NetworkAdminConsole or IConsolePrint. +std::vector _debug_remote_console_queue_spare; ///< Spare queue to swap with _debug_remote_console_queue. + int _debug_driver_level; int _debug_grf_level; int _debug_map_level; @@ -130,6 +142,11 @@ static void debug_print(const char *dbg, const char *buf) char buf2[1024 + 32]; seprintf(buf2, lastof(buf2), "%sdbg: [%s] %s\n", GetLogPrefix(), dbg, buf); + + /* Prevent sending a message concurrently, as that might cause interleaved messages. */ + static std::mutex _debug_socket_mutex; + std::lock_guard lock(_debug_socket_mutex); + /* Sending out an error when this fails would be nice, however... the error * would have to be send over this failing socket which won't work. */ send(_debug_socket, buf2, (int)strlen(buf2), 0); @@ -192,8 +209,16 @@ static void debug_print(const char *dbg, const char *buf) fputs(buffer, stderr); #endif - NetworkAdminConsole(dbg, buf); - IConsoleDebug(dbg, buf); + if (_debug_remote_console.load()) { + /* Only add to the queue when there is at least one consumer of the data. */ + if (IsNonGameThread()) { + std::lock_guard lock(_debug_remote_console_mutex); + _debug_remote_console_queue.push_back({ dbg, buf }); + } else { + NetworkAdminConsole(dbg, buf); + if (_settings_client.gui.developer >= 2) IConsolePrintF(CC_DEBUG, "dbg: [%s] %s", dbg, buf); + } + } } /** @@ -403,3 +428,50 @@ void LogRemoteDesyncMsg(Date date, DateFract date_fract, uint8 tick_skip_counter entry.src_id = src_id; _remote_desync_msg_log.LogMsg(std::move(entry)); } + +/** + * Send the queued Debug messages to either NetworkAdminConsole or IConsolePrint from the + * GameLoop thread to prevent concurrent accesses to both the NetworkAdmin's packet queue + * as well as IConsolePrint's buffers. + * + * This is to be called from the GameLoop thread. + */ +void DebugSendRemoteMessages() +{ + if (!_debug_remote_console.load()) return; + + { + std::lock_guard lock(_debug_remote_console_mutex); + std::swap(_debug_remote_console_queue, _debug_remote_console_queue_spare); + } + + for (auto &item : _debug_remote_console_queue_spare) { + NetworkAdminConsole(item.level.c_str(), item.message.c_str()); + if (_settings_client.gui.developer >= 2) IConsolePrintF(CC_DEBUG, "dbg: [%s] %s", item.level.c_str(), item.message.c_str()); + } + + _debug_remote_console_queue_spare.clear(); +} + +/** + * Reconsider whether we need to send debug messages to either NetworkAdminConsole + * or IConsolePrint. The former is when they have enabled console handling whereas + * the latter depends on the gui.developer setting's value. + * + * This is to be called from the GameLoop thread. + */ +void DebugReconsiderSendRemoteMessages() +{ + bool enable = _settings_client.gui.developer >= 2; + + if (!enable) { + for (ServerNetworkAdminSocketHandler *as : ServerNetworkAdminSocketHandler::IterateActive()) { + if (as->update_frequency[ADMIN_UPDATE_CONSOLE] & ADMIN_FREQUENCY_AUTOMATIC) { + enable = true; + break; + } + } + } + + _debug_remote_console.store(enable); +} diff --git a/src/debug.h b/src/debug.h index f13a5ebca3..f422e3c78b 100644 --- a/src/debug.h +++ b/src/debug.h @@ -135,4 +135,7 @@ void ClearDesyncMsgLog(); void LogDesyncMsg(std::string msg); char *DumpDesyncMsgLog(char *buffer, const char *last); +void DebugSendRemoteMessages(); +void DebugReconsiderSendRemoteMessages(); + #endif /* DEBUG_H */ diff --git a/src/network/network_admin.cpp b/src/network/network_admin.cpp index 3d015b81c2..8eb91f69d8 100644 --- a/src/network/network_admin.cpp +++ b/src/network/network_admin.cpp @@ -75,6 +75,11 @@ ServerNetworkAdminSocketHandler::~ServerNetworkAdminSocketHandler() _network_admins_connected--; DEBUG(net, 1, "[admin] '%s' (%s) has disconnected", this->admin_name, this->admin_version); if (_redirect_console_to_admin == this->index) _redirect_console_to_admin = INVALID_ADMIN_ID; + + if (this->update_frequency[ADMIN_UPDATE_CONSOLE] & ADMIN_FREQUENCY_AUTOMATIC) { + this->update_frequency[ADMIN_UPDATE_CONSOLE] = (AdminUpdateFrequency)0; + DebugReconsiderSendRemoteMessages(); + } } /** @@ -708,6 +713,8 @@ NetworkRecvStatus ServerNetworkAdminSocketHandler::Receive_ADMIN_UPDATE_FREQUENC this->update_frequency[type] = freq; + if (type == ADMIN_UPDATE_CONSOLE) DebugReconsiderSendRemoteMessages(); + return NETWORK_RECV_STATUS_OKAY; } diff --git a/src/openttd.cpp b/src/openttd.cpp index 1d474ccfb4..87f1434f99 100644 --- a/src/openttd.cpp +++ b/src/openttd.cpp @@ -1960,6 +1960,8 @@ void GameLoop() /* Check for UDP stuff */ if (_network_available) NetworkBackgroundLoop(); + DebugSendRemoteMessages(); + if (_networking && !HasModalProgress()) { /* Multiplayer */ NetworkGameLoop(); diff --git a/src/settings.cpp b/src/settings.cpp index 34af02fbd0..6609d7679a 100644 --- a/src/settings.cpp +++ b/src/settings.cpp @@ -1360,6 +1360,12 @@ static bool InvalidateSettingsWindow(int32 p1) return true; } +static bool DeveloperModeChanged(int32 p1) +{ + DebugReconsiderSendRemoteMessages(); + return true; +} + /** * Update any possible saveload window and delete any newgrf dialogue as * its widget parts might change. Reinit all windows as it allows access to the @@ -2241,6 +2247,7 @@ void LoadFromConfig(bool startup) HandleOldDiffCustom(false); ValidateSettings(); + DebugReconsiderSendRemoteMessages(); PostZoningModeChange(); diff --git a/src/table/settings.ini b/src/table/settings.ini index 63cca6a9ab..f684dd64e4 100644 --- a/src/table/settings.ini +++ b/src/table/settings.ini @@ -40,6 +40,7 @@ static bool ChangeTimetableInTicksMode(int32 p1); static bool UpdateTimeSettings(int32 p1); static bool ChangeTimeOverrideMode(int32 p1); static bool InvalidateCompanyLiveryWindow(int32 p1); +static bool DeveloperModeChanged(int32 p1); static bool InvalidateNewGRFChangeWindows(int32 p1); static bool InvalidateIndustryViewWindow(int32 p1); static bool InvalidateAISettingsWindow(int32 p1); @@ -5585,6 +5586,7 @@ flags = SLF_NOT_IN_SAVE | SLF_NO_NETWORK_SYNC def = 1 min = 0 max = 2 +proc = DeveloperModeChanged cat = SC_EXPERT [SDTC_BOOL]