From d4e843983db8f21ad3d66c4b57b5d570085ea585 Mon Sep 17 00:00:00 2001 From: Dan Albert Date: Fri, 28 May 2021 15:27:53 -0700 Subject: [PATCH] Add more tracing for turn processing. Most of the time (1-2 seconds) is going to flight plan layout. There don't seem to be any easy opportunities for improvement. --- game/game.py | 24 ++++++++++++++-------- game/profiling.py | 22 ++++++++++++++++++++ gen/flights/ai_flight_planner.py | 35 +++++++++++++++++++++++--------- 3 files changed, 63 insertions(+), 18 deletions(-) diff --git a/game/game.py b/game/game.py index a3d6b5ac..7ddf3733 100644 --- a/game/game.py +++ b/game/game.py @@ -352,8 +352,10 @@ class Game: def pass_turn(self, no_action: bool = False) -> None: logging.info("Pass turn") - self.finish_turn(no_action) - self.initialize_turn() + with logged_duration("Turn finalization"): + self.finish_turn(no_action) + with logged_duration("Turn initialization"): + self.initialize_turn() # Autosave progress persistency.autosave(self) @@ -399,22 +401,28 @@ class Game: return self.process_win_loss(turn_state) # Plan flights & combat for next turn - self.compute_conflicts_position() - self.compute_threat_zones() - self.compute_transit_networks() + with logged_duration("Computing conflict positions"): + self.compute_conflicts_position() + with logged_duration("Threat zone computation"): + self.compute_threat_zones() + with logged_duration("Transit network identification"): + self.compute_transit_networks() self.ground_planners = {} self.blue_procurement_requests.clear() self.red_procurement_requests.clear() - self.transfers.order_airlift_assets() - self.transfers.plan_transports() + with logged_duration("Procurement of airlift assets"): + self.transfers.order_airlift_assets() + with logged_duration("Transport planning"): + self.transfers.plan_transports() - with logged_duration("Mission planning"): + with logged_duration("Blue mission planning"): if self.settings.auto_ato_behavior is not AutoAtoBehavior.Disabled: blue_planner = CoalitionMissionPlanner(self, is_player=True) blue_planner.plan_missions() + with logged_duration("Red mission planning"): red_planner = CoalitionMissionPlanner(self, is_player=False) red_planner.plan_missions() diff --git a/game/profiling.py b/game/profiling.py index 364cdfd3..82c2c326 100644 --- a/game/profiling.py +++ b/game/profiling.py @@ -1,5 +1,8 @@ +from __future__ import annotations + import logging import timeit +from collections import defaultdict from contextlib import contextmanager from datetime import timedelta from typing import Iterator @@ -11,3 +14,22 @@ def logged_duration(event: str) -> Iterator[None]: yield end = timeit.default_timer() logging.debug("%s took %s", event, timedelta(seconds=end - start)) + + +class MultiEventTracer: + def __init__(self) -> None: + self.events: dict[str, timedelta] = defaultdict(timedelta) + + def __enter__(self) -> MultiEventTracer: + return self + + def __exit__(self, exc_type, exc_val, exc_tb) -> None: + for event, duration in self.events.items(): + logging.debug("%s took %s", event, duration) + + @contextmanager + def trace(self, event: str) -> Iterator[None]: + start = timeit.default_timer() + yield + end = timeit.default_timer() + self.events[event] += timedelta(seconds=end - start) diff --git a/gen/flights/ai_flight_planner.py b/gen/flights/ai_flight_planner.py index 12dd8a68..c5d084bf 100644 --- a/gen/flights/ai_flight_planner.py +++ b/gen/flights/ai_flight_planner.py @@ -25,6 +25,7 @@ from dcs.unittype import FlyingType from game.factions.faction import Faction from game.infos.information import Information from game.procurement import AircraftProcurementRequest +from game.profiling import logged_duration, MultiEventTracer from game.squadrons import AirWing, Squadron from game.theater import ( Airfield, @@ -807,13 +808,19 @@ class CoalitionMissionPlanner: def plan_missions(self) -> None: """Identifies and plans mission for the turn.""" - for proposed_mission in self.propose_missions(): - self.plan_mission(proposed_mission) + player = "Blue" if self.is_player else "Red" + with logged_duration(f"{player} mission identification and fulfillment"): + with MultiEventTracer() as tracer: + for proposed_mission in self.propose_missions(): + self.plan_mission(proposed_mission, tracer) - for critical_mission in self.critical_missions(): - self.plan_mission(critical_mission, reserves=True) + with logged_duration(f"{player} reserve mission planning"): + with MultiEventTracer() as tracer: + for critical_mission in self.critical_missions(): + self.plan_mission(critical_mission, tracer, reserves=True) - self.stagger_missions() + with logged_duration(f"{player} mission scheduling"): + self.stagger_missions() for cp in self.objective_finder.friendly_control_points(): inventory = self.game.aircraft_inventory.for_control_point(cp) @@ -878,7 +885,9 @@ class CoalitionMissionPlanner: threats[EscortType.Sead] = True return threats - def plan_mission(self, mission: ProposedMission, reserves: bool = False) -> None: + def plan_mission( + self, mission: ProposedMission, tracer: MultiEventTracer, reserves: bool = False + ) -> None: """Allocates aircraft for a proposed mission and adds it to the ATO.""" builder = PackageBuilder( mission.location, @@ -907,7 +916,10 @@ class CoalitionMissionPlanner: # If the package does not need escorts they may be pruned. escorts.append(proposed_flight) continue - self.plan_flight(mission, proposed_flight, builder, missing_types, reserves) + with tracer.trace("Flight planning"): + self.plan_flight( + mission, proposed_flight, builder, missing_types, reserves + ) if missing_types: self.scrub_mission_missing_aircraft( @@ -931,7 +943,8 @@ class CoalitionMissionPlanner: self.game, builder.package, self.is_player ) for flight in builder.package.flights: - flight_plan_builder.populate_flight_plan(flight) + with tracer.trace("Flight plan population"): + flight_plan_builder.populate_flight_plan(flight) needed_escorts = self.check_needed_escorts(builder) for escort in escorts: @@ -939,7 +952,8 @@ class CoalitionMissionPlanner: # impossible. assert escort.escort_type is not None if needed_escorts[escort.escort_type]: - self.plan_flight(mission, escort, builder, missing_types, reserves) + with tracer.trace("Flight planning"): + self.plan_flight(mission, escort, builder, missing_types, reserves) # Check again for unavailable aircraft. If the escort was required and # none were found, scrub the mission. @@ -959,7 +973,8 @@ class CoalitionMissionPlanner: # Add flight plans for escorts. for flight in package.flights: if not flight.flight_plan.waypoints: - flight_plan_builder.populate_flight_plan(flight) + with tracer.trace("Flight plan population"): + flight_plan_builder.populate_flight_plan(flight) if package.has_players and self.game.settings.auto_ato_player_missions_asap: package.auto_asap = True