From b7619630cfcbdd3f8770b831798e589b9d98c629 Mon Sep 17 00:00:00 2001 From: Dan Albert Date: Sat, 8 May 2021 17:55:18 -0700 Subject: [PATCH] Add logged_duration context manager for profiling. --- game/profiling.py | 13 +++++++++ game/theater/conflicttheater.py | 8 ++++-- game/theater/start_generator.py | 28 ++++++++++--------- qt_ui/main.py | 25 +++++++++-------- qt_ui/widgets/QTopPanel.py | 16 ++++------- .../windows/QWaitingForMissionResultWindow.py | 15 ++++------ 6 files changed, 59 insertions(+), 46 deletions(-) create mode 100644 game/profiling.py diff --git a/game/profiling.py b/game/profiling.py new file mode 100644 index 00000000..364cdfd3 --- /dev/null +++ b/game/profiling.py @@ -0,0 +1,13 @@ +import logging +import timeit +from contextlib import contextmanager +from datetime import timedelta +from typing import Iterator + + +@contextmanager +def logged_duration(event: str) -> Iterator[None]: + start = timeit.default_timer() + yield + end = timeit.default_timer() + logging.debug("%s took %s", event, timedelta(seconds=end - start)) diff --git a/game/theater/conflicttheater.py b/game/theater/conflicttheater.py index 533cac27..9933404e 100644 --- a/game/theater/conflicttheater.py +++ b/game/theater/conflicttheater.py @@ -56,6 +56,7 @@ from .frontline import FrontLine from .landmap import Landmap, load_landmap, poly_contains from .projections import TransverseMercator from ..point_with_heading import PointWithHeading +from ..profiling import logged_duration from ..utils import Distance, meters, nautical_miles SIZE_TINY = 150 @@ -114,7 +115,8 @@ class MizCampaignLoader: def __init__(self, miz: Path, theater: ConflictTheater) -> None: self.theater = theater self.mission = Mission() - self.mission.load_file(str(miz)) + with logged_duration("Loading miz"): + self.mission.load_file(str(miz)) self.control_point_id = itertools.count(1000) # If there are no red carriers there usually aren't red units. Make sure @@ -682,7 +684,9 @@ class ConflictTheater: raise RuntimeError( "Old format (non-miz) campaigns are no longer supported." ) - MizCampaignLoader(directory / miz, t).populate_theater() + + with logged_duration("Importing miz data"): + MizCampaignLoader(directory / miz, t).populate_theater() return t @property diff --git a/game/theater/start_generator.py b/game/theater/start_generator.py index 34bc8dad..d560b9d9 100644 --- a/game/theater/start_generator.py +++ b/game/theater/start_generator.py @@ -46,6 +46,7 @@ from . import ( Fob, OffMapSpawn, ) +from ..profiling import logged_duration from ..settings import Settings GroundObjectTemplates = Dict[str, Dict[str, Any]] @@ -91,20 +92,21 @@ class GameGenerator: self.generator_settings = generator_settings def generate(self) -> Game: - # Reset name generator - namegen.reset() - self.prepare_theater() - game = Game( - player_name=self.player, - enemy_name=self.enemy, - theater=self.theater, - start_date=self.generator_settings.start_date, - settings=self.settings, - player_budget=self.generator_settings.player_budget, - enemy_budget=self.generator_settings.enemy_budget, - ) + with logged_duration("TGO population"): + # Reset name generator + namegen.reset() + self.prepare_theater() + game = Game( + player_name=self.player, + enemy_name=self.enemy, + theater=self.theater, + start_date=self.generator_settings.start_date, + settings=self.settings, + player_budget=self.generator_settings.player_budget, + enemy_budget=self.generator_settings.enemy_budget, + ) - GroundObjectGenerator(game, self.generator_settings).generate() + GroundObjectGenerator(game, self.generator_settings).generate() game.settings.version = VERSION game.begin_turn_0() return game diff --git a/qt_ui/main.py b/qt_ui/main.py index 28582593..08755e15 100644 --- a/qt_ui/main.py +++ b/qt_ui/main.py @@ -7,18 +7,18 @@ from pathlib import Path from typing import Optional import dcs -from dcs.weapons_data import weapon_ids - from PySide2 import QtWidgets from PySide2.QtGui import QPixmap from PySide2.QtWidgets import QApplication, QSplashScreen +from dcs.weapons_data import weapon_ids -from game import Game, db, persistency, VERSION +from game import Game, VERSION, persistency from game.data.weapons import ( WEAPON_FALLBACK_MAP, WEAPON_INTRODUCTION_YEARS, Weapon, ) +from game.profiling import logged_duration from game.settings import Settings from game.theater.start_generator import GameGenerator, GeneratorSettings from qt_ui import ( @@ -228,15 +228,16 @@ def main(): lint_weapon_data() if args.subcommand == "new-game": - game = create_game( - args.campaign, - args.blue, - args.red, - args.supercarrier, - args.auto_procurement, - args.inverted, - args.cheats, - ) + with logged_duration("New game creation"): + game = create_game( + args.campaign, + args.blue, + args.red, + args.supercarrier, + args.auto_procurement, + args.inverted, + args.cheats, + ) run_ui(game) diff --git a/qt_ui/widgets/QTopPanel.py b/qt_ui/widgets/QTopPanel.py index f43657f7..a49d68c1 100644 --- a/qt_ui/widgets/QTopPanel.py +++ b/qt_ui/widgets/QTopPanel.py @@ -1,6 +1,3 @@ -import logging -import timeit -from datetime import timedelta from typing import List, Optional from PySide2.QtWidgets import ( @@ -15,10 +12,12 @@ from PySide2.QtWidgets import ( import qt_ui.uiconstants as CONST from game import Game from game.event.airwar import AirWarEvent +from game.profiling import logged_duration from gen.ato import Package from gen.flights.traveltime import TotEstimator from qt_ui.models import GameModel from qt_ui.widgets.QBudgetBox import QBudgetBox +from qt_ui.widgets.QConditionsWidget import QConditionsWidget from qt_ui.widgets.QFactionsInfos import QFactionsInfos from qt_ui.widgets.QIntelBox import QIntelBox from qt_ui.widgets.clientslots import MaxPlayerCount @@ -27,7 +26,6 @@ from qt_ui.windows.PendingTransfersDialog import PendingTransfersDialog from qt_ui.windows.QWaitingForMissionResultWindow import QWaitingForMissionResultWindow from qt_ui.windows.settings.QSettingsWindow import QSettingsWindow from qt_ui.windows.stats.QStatsWindow import QStatsWindow -from qt_ui.widgets.QConditionsWidget import QConditionsWidget class QTopPanel(QFrame): @@ -145,12 +143,10 @@ class QTopPanel(QFrame): self.dialog.show() def passTurn(self): - start = timeit.default_timer() - self.game.pass_turn(no_action=True) - GameUpdateSignal.get_instance().updateGame(self.game) - self.proceedButton.setEnabled(True) - end = timeit.default_timer() - logging.info("Skipping turn took %s", timedelta(seconds=end - start)) + with logged_duration("Skipping turn"): + self.game.pass_turn(no_action=True) + GameUpdateSignal.get_instance().updateGame(self.game) + self.proceedButton.setEnabled(True) def negative_start_packages(self) -> List[Package]: packages = [] diff --git a/qt_ui/windows/QWaitingForMissionResultWindow.py b/qt_ui/windows/QWaitingForMissionResultWindow.py index 7f02f755..b4addd4d 100644 --- a/qt_ui/windows/QWaitingForMissionResultWindow.py +++ b/qt_ui/windows/QWaitingForMissionResultWindow.py @@ -2,8 +2,6 @@ from __future__ import annotations import json import os -import timeit -from datetime import timedelta from typing import Sized from PySide2 import QtCore @@ -25,6 +23,7 @@ from jinja2 import Environment, FileSystemLoader, select_autoescape from game.debriefing import Debriefing, wait_for_debriefing from game.game import Event, Game, logging from game.persistency import base_path +from game.profiling import logged_duration from game.unitmap import UnitMap from qt_ui.windows.GameUpdateSignal import GameUpdateSignal @@ -205,14 +204,12 @@ class QWaitingForMissionResultWindow(QDialog): ) def process_debriefing(self): - start = timeit.default_timer() - self.game.finish_event(event=self.gameEvent, debriefing=self.debriefing) - self.game.pass_turn() + with logged_duration("Turn processing"): + self.game.finish_event(event=self.gameEvent, debriefing=self.debriefing) + self.game.pass_turn() - GameUpdateSignal.get_instance().sendDebriefing(self.debriefing) - GameUpdateSignal.get_instance().updateGame(self.game) - end = timeit.default_timer() - logging.info("Turn processing took %s", timedelta(seconds=end - start)) + GameUpdateSignal.get_instance().sendDebriefing(self.debriefing) + GameUpdateSignal.get_instance().updateGame(self.game) self.close() def debriefing_directory_location(self) -> str: