Merge pull request #68 from JohnMarzulli/top_down_scope

Top down scope

common_utils/fast_math.py

@@ -0,0 +1,103 @@
+"""
+Shared code to help speed up various math functions.
+"""
+
+import math
+
+SIN_BY_DEGREES = {}
+COS_BY_DEGREES = {}
+TAN_BY_DEGREES = {}
+
+__RADIANS_BY_DEGREES__ = {}
+__DEGREES_BY_RADIANS___ = {}
+
+TWO_PI = 2.0 * math.pi
+
+# Fill the quick trig look up tables.
+for __degrees__ in range(0, 361):
+    __radians__ = math.radians(__degrees__)
+
+    __RADIANS_BY_DEGREES__[__degrees__] = __radians__
+
+    SIN_BY_DEGREES[__degrees__] = math.sin(__radians__)
+    COS_BY_DEGREES[__degrees__] = math.cos(__radians__)
+    TAN_BY_DEGREES[__degrees__] = math.tan(__radians__)
+
+for __indexed_radians__ in range(0, int(TWO_PI * 100)):
+    __actual_radians__ = __indexed_radians__ / 100.0
+    __DEGREES_BY_RADIANS___[
+        __indexed_radians__] = math.degrees(__actual_radians__)
+
+
+def wrap_degrees(
+    angle: float
+) -> float:
+    """
+    Wraps an angle (degrees) to be between 0.0 and 360
+    Arguments:
+        angle {float} -- The input angle
+    Returns: and value that is between 0 and 360, inclusive.
+    """
+
+    if angle < 0.0:
+        return wrap_degrees(angle + 360.0)
+
+    if angle > 360.0:
+        return wrap_degrees(angle - 360.0)
+
+    return angle
+
+
+def wrap_radians(
+    radians: float
+) -> float:
+    """
+    Wraps an angle that is in radians to be between 0.0 and 2Pi
+    Arguments:
+        angle {float} -- The input angle
+    Returns: and value that is between 0 and 2Pi, inclusive.
+    """
+    if radians < 0.0:
+        return wrap_radians(radians + TWO_PI)
+
+    if radians > TWO_PI:
+        return wrap_radians(radians - TWO_PI)
+
+    return radians
+
+
+def get_radians(
+    degrees: float
+) -> float:
+    clamped_degrees = int(wrap_degrees(degrees))
+    return __RADIANS_BY_DEGREES__[clamped_degrees]
+
+
+def get_degrees(
+    radians: float
+) -> float:
+    clamped_radians = wrap_radians(radians)
+    indexed_radians = int(clamped_radians * 100)
+
+    return __DEGREES_BY_RADIANS___[indexed_radians]
+
+
+def sin(
+    degrees: float
+) -> float:
+    clamped_degs = int(wrap_degrees(degrees))
+    return SIN_BY_DEGREES[clamped_degs]
+
+
+def cos(
+    degrees: float
+) -> float:
+    clamped_degs = int(wrap_degrees(degrees))
+    return COS_BY_DEGREES[clamped_degs]
+
+
+def tan(
+    degrees: float
+) -> float:
+    clamped_degs = int(wrap_degrees(degrees))
+    return TAN_BY_DEGREES[clamped_degs]

common_utils/local_debug.py

@@ -37,13 +37,16 @@ def validate_python_version():
         print('Python version {} is newer than the maximum allowed version of {}'.format(
             python_version, MAXIMUM_PYTHON_VERSION))
 
+        raise Exception(
+            "The HUD code is not yet compatible with Python 3.9 or newer.")
+
 
 def is_debug() -> bool:
     """
     returns True if this should be run as a local debug (Mac or Windows).
     """
 
-    return os_platform in ["win32", "darwin"]
+    return (os_platform in ["win32", "darwin"]) or (IS_LINUX and not IS_PI)
 
 
 validate_python_version()

common_utils/task_timer.py

@@ -1,6 +1,7 @@
 import datetime
+from logging import log
 import queue
-import time
+import threading
 
 
 class RollingStats(object):
@@ -103,11 +104,30 @@ def to_string(
             return '---'
 
 
+class TimerRegistry(object):
+    __TIMERS__ = {}
+
+    @staticmethod
+    def add_task_timer(
+        new_timer
+    ):
+        if new_timer is None:
+            return
+
+        TimerRegistry.__TIMERS__[new_timer.task_name] = new_timer
+
+    @staticmethod
+    def get_timers():
+        return TimerRegistry.__TIMERS__.values()
+
+
 class TaskTimer(object):
     """
     Class to track how long a task takes.
     """
 
+    __TIMER_STACK__ = {}
+
     def __init__(
         self,
         task_name: str
@@ -117,6 +137,32 @@ def __init__(
         self.is_running = False
         self.task_name = task_name
 
+        TimerRegistry.add_task_timer(self)
+
+    def __push_timer_on_stack__(
+        self
+    ):
+        """
+        This is so we can eventually keep track of the call graph,
+        and inclusive vs exclusive execution time.
+        """
+        tid = threading.get_ident()
+
+        if tid not in TaskTimer.__TIMER_STACK__:
+            TaskTimer.__TIMER_STACK__[tid] = []
+
+        TaskTimer.__TIMER_STACK__[tid].append(self.task_name)
+
+    def __pop_timer_from_stack__(
+        self
+    ):
+        tid = threading.get_ident()
+
+        if tid not in TaskTimer.__TIMER_STACK__:
+            return
+
+        TaskTimer.__TIMER_STACK__[tid].pop()
+
     def reset(
         self
     ):
@@ -131,6 +177,8 @@ def start(
         self.__start_time__ = datetime.datetime.utcnow()
         self.is_running = True
 
+        self.__push_timer_on_stack__()
+
     def stop(
         self
     ):
@@ -143,17 +191,178 @@ def stop(
                  self.__start_time__).total_seconds() * 1000.0
         self.__stats__.push(value)
 
+        self.__pop_timer_from_stack__()
+
     def to_string(
         self
     ) -> str:
         return self.__stats__.to_string()
 
 
+class TaskProfiler(object):
+    # {string:TimeDelta}
+    __TOTAL_TIMES__ = {}
+
+    # {string:float}
+    # Used to track how much time a task that was a child spent
+    # So we know what time was ONLY the given task
+    __CHILD_TIMES__ = {}
+
+    # {string: int}
+    __CALL_COUNTS__ = {}
+
+    # NOTE: Do we need to keep track of the thread here?
+    # [string]
+    __CALLING_TIMERS__ = []
+
+    @staticmethod
+    def reset():
+        for task_name in TaskProfiler.__TOTAL_TIMES__.keys():
+            TaskProfiler.__CHILD_TIMES__[task_name] = 0.0
+            TaskProfiler.__TOTAL_TIMES__[task_name] = 0.0
+            TaskProfiler.__CALL_COUNTS__[task_name] = 0
+
+        TaskProfiler.__CALLING_TIMERS__ = []
+
+    @staticmethod
+    def get_exclusive_times() -> dict:
+        exclusive_times = {}
+
+        for task_name in TaskProfiler.__TOTAL_TIMES__.keys():
+            total_time = TaskProfiler.__TOTAL_TIMES__[task_name]
+            child_time = TaskProfiler.__CHILD_TIMES__[task_name]
+            exclusive_time = total_time - child_time
+
+            exclusive_times[task_name] = exclusive_time
+
+        return exclusive_times
+
+    @staticmethod
+    def log(
+        logger
+    ):
+        if logger is None:
+            return
+
+        exclusive_times = TaskProfiler.get_exclusive_times()
+
+        expense_order = sorted(
+            exclusive_times,
+            key=lambda profile: TaskProfiler.__TOTAL_TIMES__[profile],
+            reverse=True)
+
+        logger.log_info_message('------ PERF ------')
+        logger.log_info_message(
+            'Task, Calls, IncTotal, ExTotal, IncMean, ExMean')
+        for task_name in expense_order:
+            inclusive_ms = TaskProfiler.__TOTAL_TIMES__[task_name]
+            exclusive_ms = exclusive_times[task_name]
+
+            call_count = TaskProfiler.__CALL_COUNTS__[task_name]
+
+            inclusive_mean = ''
+            exclusive_mean = ''
+
+            if call_count > 0:
+                inclusive_mean = "{:.1f}".format(inclusive_ms / call_count)
+                exclusive_mean = "{:.1f}".format(exclusive_ms / call_count)
+
+            logger.log_info_message(
+                '{0}, {1}, {2:.1f}, {3:.1f}, {4}, {5}'.format(
+                    task_name,
+                    call_count,
+                    inclusive_ms,
+                    exclusive_ms,
+                    inclusive_mean,
+                    exclusive_mean))
+
+    def __init__(
+        self,
+        task_name: str
+    ) -> None:
+        super().__init__()
+
+        if task_name not in TaskProfiler.__CHILD_TIMES__:
+            TaskProfiler.__CHILD_TIMES__[task_name] = 0.0
+
+        if task_name not in TaskProfiler.__TOTAL_TIMES__:
+            TaskProfiler.__TOTAL_TIMES__[task_name] = 0.0
+
+        if task_name not in TaskProfiler.__CALL_COUNTS__:
+            TaskProfiler.__CALL_COUNTS__[task_name] = 0
+
+        self.task_name = task_name
+        self.__timer__ = datetime.datetime.utcnow()
+        self.__is_running__ = False
+
+    def start(
+        self
+    ):
+        if self.__is_running__:
+            return
+
+        self.__timer__ = datetime.datetime.utcnow()
+        self.__is_running__ = True
+        TaskProfiler.__CALLING_TIMERS__.append(self.task_name)
+
+    def stop(
+        self
+    ):
+        if not self.__is_running__:
+            return
+
+        self.__is_running__ = False
+
+        total_delta = datetime.datetime.utcnow() - self.__timer__
+        total_ms = total_delta.total_seconds() * 1000.0
+
+        TaskProfiler.__CALL_COUNTS__[self.task_name] += 1
+
+        TaskProfiler.__TOTAL_TIMES__[self.task_name] += total_ms
+        TaskProfiler.__CALLING_TIMERS__.pop()
+
+        # Keep track of the parent's inclusive times
+        if len(TaskProfiler.__CALLING_TIMERS__) < 1:
+            return
+
+        parent_task_name = TaskProfiler.__CALLING_TIMERS__[-1]
+        TaskProfiler.__CHILD_TIMES__[parent_task_name] += total_ms
+
+    def __enter__(
+        self
+    ):
+        self.start()
+
+    def __exit__(
+        self,
+        exc_type,
+        exc_val,
+        traceback
+    ):
+        self.stop()
+
+
 if __name__ == '__main__':
-    timer = TaskTimer("test")
+    import time
+    import logging
+    from common_utils.logger import HudLogger
+
+    python_logger = logging.getLogger("task_timer_test")
+    python_logger.setLevel(logging.DEBUG)
+
+    test_logger = HudLogger(python_logger)
 
     for i in range(1, 11, 1):
-        timer.start()
-        time.sleep(i / 10.0)
-        timer.stop()
-        print(timer.to_string())
+        with TaskProfiler("Root"):
+            time.sleep(1.0)
+
+            with TaskProfiler("Middle"):
+                time.sleep(0.5)
+
+                leaf_timer = TaskProfiler("Leaf")
+                leaf_timer.start()
+                time.sleep(0.5)
+                leaf_timer.stop()
+
+        test_logger.log_info_message("-_-_-_-")
+        TaskProfiler.log(test_logger)