From fa3db1e3cafa451e42fdeb0230e4baac7a200838 Mon Sep 17 00:00:00 2001 From: Eric Froemling Date: Fri, 8 Jul 2022 12:15:37 -0700 Subject: [PATCH] made spammy timing logs require BA_DEBUG_TIMING=1 env var --- .efrocachemap | 56 ++++++++++----------- CHANGELOG.md | 3 +- assets/src/ba_data/python/._ba_sources_hash | 2 +- assets/src/ba_data/python/ba/_asyncio.py | 19 ++++--- assets/src/ba_data/python/ba/_plugin.py | 3 +- src/ballistica/app/app_globals.cc | 12 +++-- src/ballistica/app/app_globals.h | 1 + src/ballistica/ballistica.cc | 2 +- src/ballistica/game/game.cc | 3 +- src/ballistica/python/python.cc | 15 ++++-- 10 files changed, 68 insertions(+), 48 deletions(-) diff --git a/.efrocachemap b/.efrocachemap index 9a11f4aa..9cdeac4d 100644 --- a/.efrocachemap +++ b/.efrocachemap @@ -3995,26 +3995,26 @@ "assets/src/ba_data/python/ba/_generated/__init__.py": "https://files.ballistica.net/cache/ba1/ee/e8/cad05aa531c7faf7ff7b96db7f6e", "assets/src/ba_data/python/ba/_generated/enums.py": "https://files.ballistica.net/cache/ba1/b2/e5/0ee0561e16257a32830645239f34", "ballisticacore-windows/Generic/BallisticaCore.ico": "https://files.ballistica.net/cache/ba1/89/c0/e32c7d2a35dc9aef57cc73b0911a", - "build/prefab/full/linux_arm64_gui/debug/ballisticacore": "https://files.ballistica.net/cache/ba1/1a/39/acfbc22a3b5c42fc8d7041c39d69", - "build/prefab/full/linux_arm64_gui/release/ballisticacore": "https://files.ballistica.net/cache/ba1/32/13/b2fb8f259bbd899789108036bae9", - "build/prefab/full/linux_arm64_server/debug/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/c0/82/b986c8348b474e3299d4aac7bc32", - "build/prefab/full/linux_arm64_server/release/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/48/39/3978b186f6db8e0fd01c250868b7", - "build/prefab/full/linux_x86_64_gui/debug/ballisticacore": "https://files.ballistica.net/cache/ba1/4f/1e/17ffb859868e36203dc9286a4434", - "build/prefab/full/linux_x86_64_gui/release/ballisticacore": "https://files.ballistica.net/cache/ba1/77/77/6671c0637457b48041711daf27da", - "build/prefab/full/linux_x86_64_server/debug/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/18/82/776af0c81fb17839b7b8bc264012", - "build/prefab/full/linux_x86_64_server/release/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/1c/cf/75b00bce2ce670a5c95af086d9a0", - "build/prefab/full/mac_arm64_gui/debug/ballisticacore": "https://files.ballistica.net/cache/ba1/8a/35/ff23ca37f42b0bfa6ca159630fe4", - "build/prefab/full/mac_arm64_gui/release/ballisticacore": "https://files.ballistica.net/cache/ba1/9b/5f/904c100c7c5646c7331cb26b8db6", - "build/prefab/full/mac_arm64_server/debug/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/89/9d/0aacb629f5dc8fd10ce55debbe79", - "build/prefab/full/mac_arm64_server/release/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/5c/ea/0f158f114b2b3d0a534aebfeaebf", - "build/prefab/full/mac_x86_64_gui/debug/ballisticacore": "https://files.ballistica.net/cache/ba1/f3/4c/06b71f58c5b03454b61360e8591b", - "build/prefab/full/mac_x86_64_gui/release/ballisticacore": "https://files.ballistica.net/cache/ba1/72/4a/de64093c85f32f5dbba5389da90c", - "build/prefab/full/mac_x86_64_server/debug/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/14/e0/9c9088bd9db01969bf1a1e838dda", - "build/prefab/full/mac_x86_64_server/release/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/7c/39/05b1d3873ca9f1d6a7b904732630", - "build/prefab/full/windows_x86_gui/debug/BallisticaCore.exe": "https://files.ballistica.net/cache/ba1/1c/cb/2a1576774e2ac14fed571d1d3232", - "build/prefab/full/windows_x86_gui/release/BallisticaCore.exe": "https://files.ballistica.net/cache/ba1/df/0a/0284198f2802439349515c8b83f2", - "build/prefab/full/windows_x86_server/debug/dist/BallisticaCoreHeadless.exe": "https://files.ballistica.net/cache/ba1/63/66/c6fa125299b8dc26887a0e5c5f58", - "build/prefab/full/windows_x86_server/release/dist/BallisticaCoreHeadless.exe": "https://files.ballistica.net/cache/ba1/01/dd/d5d189b16974b6314ba76584b7b2", + "build/prefab/full/linux_arm64_gui/debug/ballisticacore": "https://files.ballistica.net/cache/ba1/b4/6b/d57bf44327be5c7cd5ab469b0f73", + "build/prefab/full/linux_arm64_gui/release/ballisticacore": "https://files.ballistica.net/cache/ba1/6b/8a/e15c3d97afa4e888da708a4eedb4", + "build/prefab/full/linux_arm64_server/debug/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/ae/90/efe160ebfe1a6fac7474d43848e3", + "build/prefab/full/linux_arm64_server/release/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/57/79/e1ad4d39d1e39623add63f9cf305", + "build/prefab/full/linux_x86_64_gui/debug/ballisticacore": "https://files.ballistica.net/cache/ba1/cf/14/9265e972e27bbb406b5ca90a3331", + "build/prefab/full/linux_x86_64_gui/release/ballisticacore": "https://files.ballistica.net/cache/ba1/17/8c/303ff3d19255162ca4ee44d17f14", + "build/prefab/full/linux_x86_64_server/debug/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/97/6d/b0225caf7d1bf38dfd7320a7837f", + "build/prefab/full/linux_x86_64_server/release/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/62/c4/6b53ea09f6c81fa1056c1bf6b2b3", + "build/prefab/full/mac_arm64_gui/debug/ballisticacore": "https://files.ballistica.net/cache/ba1/ff/07/0a1007b66e498a0ca6e2764dbdc4", + "build/prefab/full/mac_arm64_gui/release/ballisticacore": "https://files.ballistica.net/cache/ba1/9d/35/6a2254dc00e6d2207656ea08639b", + "build/prefab/full/mac_arm64_server/debug/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/ad/ea/4d49c0e06db1863153e63c155381", + "build/prefab/full/mac_arm64_server/release/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/e9/73/c927d2380d2e33929a55efdf8403", + "build/prefab/full/mac_x86_64_gui/debug/ballisticacore": "https://files.ballistica.net/cache/ba1/0a/e8/a69ae8672182b64e33fc1faea7a1", + "build/prefab/full/mac_x86_64_gui/release/ballisticacore": "https://files.ballistica.net/cache/ba1/80/09/f1b52871804107f77502a5a12692", + "build/prefab/full/mac_x86_64_server/debug/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/33/79/fcf389e566ae93609a0b45c6f280", + "build/prefab/full/mac_x86_64_server/release/dist/ballisticacore_headless": "https://files.ballistica.net/cache/ba1/27/2b/b3e6e2c60499942516e74c790463", + "build/prefab/full/windows_x86_gui/debug/BallisticaCore.exe": "https://files.ballistica.net/cache/ba1/e3/46/c7c92b5037e8db89c8e91d498bab", + "build/prefab/full/windows_x86_gui/release/BallisticaCore.exe": "https://files.ballistica.net/cache/ba1/df/d0/ef6344d54ec119ad332c7b50fef9", + "build/prefab/full/windows_x86_server/debug/dist/BallisticaCoreHeadless.exe": "https://files.ballistica.net/cache/ba1/ae/1a/4f9399f80f681218710a3ae47cd8", + "build/prefab/full/windows_x86_server/release/dist/BallisticaCoreHeadless.exe": "https://files.ballistica.net/cache/ba1/87/5d/ab4b1886fa00acca24ae525af0b7", "build/prefab/lib/linux_arm64_gui/debug/libballisticacore_internal.a": "https://files.ballistica.net/cache/ba1/95/cf/7c343cd320548f535b75b5993275", "build/prefab/lib/linux_arm64_gui/release/libballisticacore_internal.a": "https://files.ballistica.net/cache/ba1/a5/ee/8c89b68c2b26464768335e4c3361", "build/prefab/lib/linux_arm64_server/debug/libballisticacore_internal.a": "https://files.ballistica.net/cache/ba1/18/93/76a49888f17ea1677b9b49244416", @@ -4031,14 +4031,14 @@ "build/prefab/lib/mac_x86_64_gui/release/libballisticacore_internal.a": "https://files.ballistica.net/cache/ba1/ae/bb/4a015a49120e908a6d17f302d0d8", "build/prefab/lib/mac_x86_64_server/debug/libballisticacore_internal.a": "https://files.ballistica.net/cache/ba1/e2/ff/1b0c530cbba73a0ea895a56626b6", "build/prefab/lib/mac_x86_64_server/release/libballisticacore_internal.a": "https://files.ballistica.net/cache/ba1/9c/8e/53fdfaf4f5113970e2aefcb6a06e", - "build/prefab/lib/windows/Debug_Win32/BallisticaCoreGenericInternal.lib": "https://files.ballistica.net/cache/ba1/70/5a/bab38dcc254aeba112894ee278cd", - "build/prefab/lib/windows/Debug_Win32/BallisticaCoreGenericInternal.pdb": "https://files.ballistica.net/cache/ba1/ac/31/ce9ba1b80db55b753626d3053898", - "build/prefab/lib/windows/Debug_Win32/BallisticaCoreHeadlessInternal.lib": "https://files.ballistica.net/cache/ba1/32/5e/3c919d17f772a5bd1192a9ac3eda", - "build/prefab/lib/windows/Debug_Win32/BallisticaCoreHeadlessInternal.pdb": "https://files.ballistica.net/cache/ba1/28/2b/9b48b6805ee243f2813d5f0359e8", - "build/prefab/lib/windows/Release_Win32/BallisticaCoreGenericInternal.lib": "https://files.ballistica.net/cache/ba1/bd/2a/8627c6f6938bc46a4fca7a033ab3", - "build/prefab/lib/windows/Release_Win32/BallisticaCoreGenericInternal.pdb": "https://files.ballistica.net/cache/ba1/54/63/15a0d31548d76237c65529d3bf99", - "build/prefab/lib/windows/Release_Win32/BallisticaCoreHeadlessInternal.lib": "https://files.ballistica.net/cache/ba1/2d/d4/e7fb6077712e4267a4d64529e005", - "build/prefab/lib/windows/Release_Win32/BallisticaCoreHeadlessInternal.pdb": "https://files.ballistica.net/cache/ba1/55/44/83e93c9d77ffd2589e7a8795b212", + "build/prefab/lib/windows/Debug_Win32/BallisticaCoreGenericInternal.lib": "https://files.ballistica.net/cache/ba1/72/67/a7e5168376965df78b1b1716b76d", + "build/prefab/lib/windows/Debug_Win32/BallisticaCoreGenericInternal.pdb": "https://files.ballistica.net/cache/ba1/56/67/e7b64f45bc15fe309e0082192179", + "build/prefab/lib/windows/Debug_Win32/BallisticaCoreHeadlessInternal.lib": "https://files.ballistica.net/cache/ba1/e1/71/a7f5590a057b3b9d5e421ca3ff43", + "build/prefab/lib/windows/Debug_Win32/BallisticaCoreHeadlessInternal.pdb": "https://files.ballistica.net/cache/ba1/b1/73/06806075931d4939b10dd70a93e4", + "build/prefab/lib/windows/Release_Win32/BallisticaCoreGenericInternal.lib": "https://files.ballistica.net/cache/ba1/61/8c/06ec6a9974aedd5ac58ee55a1d98", + "build/prefab/lib/windows/Release_Win32/BallisticaCoreGenericInternal.pdb": "https://files.ballistica.net/cache/ba1/b9/9c/8b4f1842127ffda670c4b343b153", + "build/prefab/lib/windows/Release_Win32/BallisticaCoreHeadlessInternal.lib": "https://files.ballistica.net/cache/ba1/d7/4e/d3429d4b1fbf6f62ab21db7d441d", + "build/prefab/lib/windows/Release_Win32/BallisticaCoreHeadlessInternal.pdb": "https://files.ballistica.net/cache/ba1/fb/c5/d72dd63187f7e90051794bcc6bf2", "src/ballistica/generated/python_embedded/binding.inc": "https://files.ballistica.net/cache/ba1/6e/6f/004b696e9a13b083069374e4bb6a", "src/ballistica/generated/python_embedded/bootstrap.inc": "https://files.ballistica.net/cache/ba1/d3/db/e73d4dcf1280d5f677c3cf8b47c3" } \ No newline at end of file diff --git a/CHANGELOG.md b/CHANGELOG.md index c07929cc..d9198763 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,8 +1,9 @@ -### 1.7.4 (20638, 2022-07-07) +### 1.7.4 (20641, 2022-07-08) - Fixed the trophies list showing an incorrect total (Thanks itsre3!) - ba.app.meta.metascan is now ba.app.meta.scanresults - Cleaned up co-op ui code a bit - Added a utility function to add custom co-op games in the practice section: `ba.app.add_coop_practice_level`. Also added new workspace template script which uses it to define a new co-op game type. +- Removed some spammy debug timing logging I added for tracking down a recent bug (can be reenabled by setting env var `BA_DEBUG_TIMING=1`) ### 1.7.3 (20634, 2022-07-06) - Fixed an issue with King of the Hill flag regions not working when players entered them (Thanks itsre3!) diff --git a/assets/src/ba_data/python/._ba_sources_hash b/assets/src/ba_data/python/._ba_sources_hash index a6fb194e..045254ba 100644 --- a/assets/src/ba_data/python/._ba_sources_hash +++ b/assets/src/ba_data/python/._ba_sources_hash @@ -1 +1 @@ -278132313134406072250536815637474504399 \ No newline at end of file +162333092055412382592908646337833811891 \ No newline at end of file diff --git a/assets/src/ba_data/python/ba/_asyncio.py b/assets/src/ba_data/python/ba/_asyncio.py index c18dd10b..c4ebc5e0 100644 --- a/assets/src/ba_data/python/ba/_asyncio.py +++ b/assets/src/ba_data/python/ba/_asyncio.py @@ -13,6 +13,7 @@ from typing import TYPE_CHECKING import asyncio import logging import time +import os if TYPE_CHECKING: import ba @@ -21,6 +22,8 @@ if TYPE_CHECKING: _asyncio_timer: ba.Timer | None = None _asyncio_event_loop: asyncio.AbstractEventLoop | None = None +DEBUG_TIMING = os.environ.get('BA_DEBUG_TIMING') == '1' + def setup_asyncio() -> asyncio.AbstractEventLoop: """Setup asyncio functionality for the logic thread.""" @@ -55,16 +58,18 @@ def setup_asyncio() -> asyncio.AbstractEventLoop: def run_cycle() -> None: assert _asyncio_event_loop is not None _asyncio_event_loop.call_soon(_asyncio_event_loop.stop) - starttime = time.monotonic() + starttime = time.monotonic() if DEBUG_TIMING else 0 _asyncio_event_loop.run_forever() - endtime = time.monotonic() + endtime = time.monotonic() if DEBUG_TIMING else 0 # Let's aim to have nothing take longer than 1/120 of a second. - warn_time = 1.0 / 120 - duration = endtime - starttime - if duration > warn_time: - logging.warning('Asyncio loop step took %.4fs; ideal max is %.4f', - duration, warn_time) + if DEBUG_TIMING: + warn_time = 1.0 / 120 + duration = endtime - starttime + if duration > warn_time: + logging.warning( + 'Asyncio loop step took %.4fs; ideal max is %.4f', + duration, warn_time) global _asyncio_timer # pylint: disable=invalid-name _asyncio_timer = _ba.Timer(1.0 / 30.0, diff --git a/assets/src/ba_data/python/ba/_plugin.py b/assets/src/ba_data/python/ba/_plugin.py index 699cc84e..9e7200f2 100644 --- a/assets/src/ba_data/python/ba/_plugin.py +++ b/assets/src/ba_data/python/ba/_plugin.py @@ -117,9 +117,10 @@ class PluginSubsystem: subs=[('${NUM}', str(len(disappeared_plugs)))]), color=(1, 1, 0), ) + plugnames = ', '.join(disappeared_plugs) _ba.log( f'{len(disappeared_plugs)} plugin(s) no longer found:' - f' {str(disappeared_plugs)[1:-1]}.', + f' {plugnames}.', to_server=False) for goneplug in disappeared_plugs: del _ba.app.config['Plugins'][goneplug] diff --git a/src/ballistica/app/app_globals.cc b/src/ballistica/app/app_globals.cc index bb246033..96d019b7 100644 --- a/src/ballistica/app/app_globals.cc +++ b/src/ballistica/app/app_globals.cc @@ -2,11 +2,17 @@ #include "ballistica/app/app_globals.h" +#include + namespace ballistica { AppGlobals::AppGlobals(int argc_in, char** argv_in) - : argc{argc_in}, - argv{argv_in}, - main_thread_id{std::this_thread::get_id()} {} + : argc{argc_in}, argv{argv_in}, main_thread_id{std::this_thread::get_id()} { + // Enable extra timing logs via env var. + const char* debug_timing_env = getenv("BA_DEBUG_TIMING"); + if (debug_timing_env != nullptr && !strcmp(debug_timing_env, "1")) { + debug_timing = true; + } +} } // namespace ballistica diff --git a/src/ballistica/app/app_globals.h b/src/ballistica/app/app_globals.h index 89c9c2c1..dc4cddb3 100644 --- a/src/ballistica/app/app_globals.h +++ b/src/ballistica/app/app_globals.h @@ -60,6 +60,7 @@ class AppGlobals { std::string user_agent_string{"BA_USER_AGENT_UNSET (" BA_PLATFORM_STRING ")"}; int return_value{}; bool is_stdin_a_terminal{true}; + bool debug_timing{}; std::thread::id main_thread_id{}; bool is_bootstrapped{}; bool args_handled{}; diff --git a/src/ballistica/ballistica.cc b/src/ballistica/ballistica.cc index 9126f0f4..1ff44832 100644 --- a/src/ballistica/ballistica.cc +++ b/src/ballistica/ballistica.cc @@ -21,7 +21,7 @@ namespace ballistica { // These are set automatically via script; don't modify them here. -const int kAppBuildNumber = 20638; +const int kAppBuildNumber = 20641; const char* kAppVersion = "1.7.4"; // Our standalone globals. diff --git a/src/ballistica/game/game.cc b/src/ballistica/game/game.cc index 4f70532d..8cf2888f 100644 --- a/src/ballistica/game/game.cc +++ b/src/ballistica/game/game.cc @@ -650,7 +650,8 @@ void Game::Update() { in_update_ = false; // Report excessively long updates. - if (real_time >= next_long_update_report_time_) { + if (g_app_globals->debug_timing + && real_time >= next_long_update_report_time_) { auto duration{Platform::GetCurrentMilliseconds() - startms}; // Complain when our full update takes longer than 1/60th second. diff --git a/src/ballistica/python/python.cc b/src/ballistica/python/python.cc index 93b067ef..f1e68283 100644 --- a/src/ballistica/python/python.cc +++ b/src/ballistica/python/python.cc @@ -2246,15 +2246,20 @@ void Python::LogContextAuto() { } void Python::AcquireGIL() { - auto startms{Platform::GetCurrentMilliseconds()}; + auto debug_timing{g_app_globals->debug_timing}; + millisecs_t startms{debug_timing ? Platform::GetCurrentMilliseconds() : 0}; + if (thread_state_) { PyEval_RestoreThread(thread_state_); thread_state_ = nullptr; } - auto duration{Platform::GetCurrentMilliseconds() - startms}; - if (duration > (1000 / 120)) { - Log("GIL acquire took too long (" + std::to_string(duration) + " ms).", - true, false); + + if (debug_timing) { + auto duration{Platform::GetCurrentMilliseconds() - startms}; + if (duration > (1000 / 120)) { + Log("GIL acquire took too long (" + std::to_string(duration) + " ms).", + true, false); + } } } void Python::ReleaseGIL() {