Add data updater (#212)

* Added core.updater module

* Added data updater to setup routine

Added setting to disable auto data updates.
Added debug option to find out which data files are being accessed
before the data has been updated.

* Log file is now getting cleared

* Changed setup routines to load data files later

* Use our standard

* Renamed updater to update

* Fixed an error when fire_output is not found

* Added logging to the update functions

* Added reloading languages.ini

* Removed unused import

Author: Ayuto

addons/source-python/packages/source-python/__init__.py

@@ -26,6 +26,45 @@
 # all respects for all other code used.  Additionally, the Source.Python
 # Development Team grants this exception to all derivative works.
 
+
+# =============================================================================
+# >> FILE ACCESS LOGGER
+# =============================================================================
+# If True, all calls to open() with a path to a Source.Python data file will be
+# logged in ../logs/file_access.log. The log entry will contain the file that
+# is being accessed and a full stack trace. The logger will be removed as soon
+# as setup_data_update() is called.
+# This is a debug option to ensure that no data files are being accessed before
+# the data has been updated. Release builds should have this option set to
+# False.
+LOG_FILE_OPERATIONS = False
+
+if LOG_FILE_OPERATIONS:
+    import builtins
+    import traceback
+    from paths import SP_DATA_PATH
+    from paths import LOG_PATH
+
+    LOG_FILE = LOG_PATH / 'file_access.log'
+
+    # Clear log file
+    LOG_FILE.open('w').close()
+
+    old_open = builtins.open
+
+    def new_open(f, *args, **kwargs):
+        if isinstance(f, str) and f.startswith(SP_DATA_PATH):
+            print(f)
+            with LOG_FILE.open('a') as log_f:
+                log_f.write('File access: {}\n'.format(f))
+                traceback.print_stack(file=log_f)
+                log_f.write('\n\n')
+
+        return old_open(f, *args, **kwargs)
+
+    builtins.open = new_open
+
+
 # =============================================================================
 # >> IMPORTS
 # =============================================================================
@@ -46,8 +85,10 @@ def load():
     setup_stdout_redirect()
     setup_core_settings()
     setup_logging()
-    setup_hooks()
+    setup_exception_hooks()
+    setup_data_update()
     setup_translations()
+    setup_data()
     setup_global_pointers()
     setup_sp_command()
     setup_auth()
@@ -65,6 +106,71 @@ def unload():
     unload_auth()
 
 
+# =============================================================================
+# >> DATA UPDATE
+# =============================================================================
+def setup_data_update():
+    """Setup data update."""
+    _sp_logger.log_debug('Setting up data update...')
+
+    if LOG_FILE_OPERATIONS:
+        builtins.open = old_open
+
+    from core.settings import _core_settings
+
+    if not _core_settings.auto_data_update:
+        _sp_logger.log_debug('Automatic data updates are disable.')
+        return
+
+    _sp_logger.log_info('Checking for data updates...')
+
+    from core.update import is_new_data_available, update_data
+    from translations.manager import language_manager
+
+    try:
+        if is_new_data_available():
+            _sp_logger.log_info('New data is available. Downloading...')
+            update_data()
+
+            # languages.ini is loaded before the data has been updated. Thus,
+            # we need to reload the file.
+            language_manager.reload()
+        else:
+            _sp_logger.log_info('No new data is available.')
+    except:
+        _sp_logger.log_exception(
+            'An error occured during the data update.', exc_info=True)
+
+def setup_data():
+    """Setup data."""
+    _sp_logger.log_debug('Setting up data...')
+
+    from core import GameConfigObj
+    from memory.manager import manager
+    from paths import SP_DATA_PATH
+
+    import players
+    players.BaseClient = manager.create_type_from_dict(
+        'BaseClient',
+        GameConfigObj(SP_DATA_PATH / 'client' / 'CBaseClient.ini'))
+
+    import listeners
+    listeners.BaseEntityOutput = manager.create_type_from_dict(
+        'BaseEntityOutput',
+        GameConfigObj(SP_DATA_PATH / 'entity_output' / 'CBaseEntityOutput.ini'))
+
+    try:
+        _fire_output = listeners.BaseEntityOutput.fire_output
+    except AttributeError:
+        from warnings import warn
+        warn(
+            'BaseEntityOutput.fire_output not found. '
+            'OnEntityOutput listener will not fire.'
+        )
+    else:
+        _fire_output.add_pre_hook(listeners._pre_fire_output)
+
+
 # =============================================================================
 # >> CORE SETTINGS
 # =============================================================================
@@ -121,24 +227,13 @@ def setup_logging():
 # =============================================================================
 # >> HOOKS
 # =============================================================================
-def setup_hooks():
+def setup_exception_hooks():
     """Set up hooks."""
-    _sp_logger.log_debug('Setting up hooks...')
+    _sp_logger.log_debug('Setting up exception hooks...')
 
     from hooks.exceptions import except_hooks
     from hooks.warnings import warning_hooks
 
-    # This is added to warn about BaseEntityOutput.fire_output.
-    # Sending the warning on its initial import will happen prior
-    #   to these hooks being setup.
-    from listeners._entity_output import _fire_output
-    if _fire_output is None:
-        from warnings import warn
-        warn(
-            'BaseEntityOutput.fire_output not found.  '
-            'OnEntityOutput listener will not fire.'
-        )
-
 
 # =============================================================================
 # >> TRANSLATIONS

addons/source-python/packages/source-python/auth/manager.py

@@ -10,9 +10,6 @@
 import re
 #   Importlib
 from importlib.machinery import SourceFileLoader
-# Site-Package Imports
-#   Configobj
-from configobj import ConfigObj
 # Source.Python Imports
 #   Auth
 from auth.base import Backend

addons/source-python/packages/source-python/core/settings.py

@@ -40,6 +40,7 @@ def __init__(self, infile, *args, **kwargs):
         # Import the file
         super().__init__(infile, *args, **kwargs)
         self._language = None
+        self.auto_data_update = True
 
     def load(self):
         """Load and update the core settings."""
@@ -87,6 +88,15 @@ def _check_base_settings(self):
         self['BASE_SETTINGS'].comments['language'] = _core_strings[
             'language'].get_string(self._language).splitlines()
 
+        # Auto data update
+        if 'auto_data_update' not in self['BASE_SETTINGS']:
+            self['BASE_SETTINGS']['auto_data_update'] = '1'
+
+        self.auto_data_update = self['BASE_SETTINGS']['auto_data_update'] == '1'
+
+        self['BASE_SETTINGS'].comments['auto_data_update'] = _core_strings[
+            'auto_data_update'].get_string(self._language).splitlines()
+
     def _check_version_settings(self):
         """Add version settings if they are missing."""
         if 'VERSION_SETTINGS' not in self:

addons/source-python/packages/source-python/core/update.py

@@ -0,0 +1,101 @@
+# ../core/update.py
+
+"""Provides functions to update Source.Python's data files."""
+
+# =============================================================================
+# >> IMPORTS
+# =============================================================================
+# Python Imports
+from zipfile import ZipFile
+from urllib.request import urlopen
+
+# Source.Python Imports
+#   Core
+from core import core_logger
+#   Paths
+from paths import DATA_PATH
+from paths import SP_DATA_PATH
+
+
+# =============================================================================
+# >> ALL DECLARATION
+# =============================================================================
+__all__ = (
+    'CHECKSUM_URL',
+    'DATA_URL',
+    'DATA_ZIP_FILE',
+    'download_latest_data',
+    'get_latest_data_checksum',
+    'is_new_data_available',
+    'unpack_data',
+    'update_data'
+)
+
+
+# =============================================================================
+# >> GLOBAL VARIABLES
+# =============================================================================
+# Don't use __getattr__ here. 'update' is a method of the _LogInstance class.
+update_logger = core_logger['update']
+
+DATA_ZIP_FILE = DATA_PATH / 'source-python-data.zip'
+CHECKSUM_URL = 'http://data.sourcepython.com/checksum.txt'
+DATA_URL = 'http://data.sourcepython.com/source-python-data.zip'
+
+
+# =============================================================================
+# >> FUNCTIONS
+# =============================================================================
+def get_latest_data_checksum(timeout=3):
+    """Return the MD5 checksum of the latest data from the build server.
+
+    :param float timeout:
+        Number of seconds that need to pass until a timeout occurs.
+    :rtype: str
+    """
+    with urlopen(CHECKSUM_URL, timeout=timeout) as url:
+        return url.read().decode()
+
+def download_latest_data(timeout=3):
+    """Download the latest data from the build server.
+
+    :param float timeout:
+        Number of seconds that need to pass until a timeout occurs.
+    """
+    update_logger.log_debug('Downloading data to {} ...'.format(DATA_ZIP_FILE))
+    with urlopen(DATA_URL, timeout=timeout) as url:
+        data = url.read()
+
+    with DATA_ZIP_FILE.open('wb') as f:
+        f.write(data)
+
+def unpack_data():
+    """Unpack ``source-python-data.zip``."""
+    update_logger.log_debug('Extracting data in {} ...'.format(DATA_PATH))
+    with ZipFile(DATA_ZIP_FILE) as zip:
+        zip.extractall(DATA_PATH)
+
+def update_data(timeout=3):
+    """Download and unpack the latest data from the build server.
+
+    :param float timeout:
+        Number of seconds that need to pass until a timeout occurs.
+    """
+    download_latest_data(timeout)
+    if SP_DATA_PATH.isdir():
+        update_logger.log_debug('Removing {} ...'.format(SP_DATA_PATH))
+        SP_DATA_PATH.rmtree()
+
+    unpack_data()
+
+def is_new_data_available(timeout=3):
+    """Return ``True`` if new data is available.
+
+    :param float timeout:
+        Number of seconds that need to pass until a timeout occurs.
+    :rtype: bool
+    """
+    if not DATA_ZIP_FILE.isfile():
+        return True
+
+    return DATA_ZIP_FILE.read_hexhash('md5') != get_latest_data_checksum(timeout)

addons/source-python/packages/source-python/listeners/__init__.py

@@ -14,6 +14,7 @@
 #   Core
 from core import AutoUnload
 from core import SOURCE_ENGINE
+from core import PLATFORM
 from core.settings import _core_settings
 from core.version import get_last_successful_build_number
 from core.version import is_unversioned
@@ -23,6 +24,8 @@
 from cvars import cvar
 #   Engines
 from engines.server import server_game_dll
+from entities.datamaps import Variant
+from entities.helpers import find_output_name
 #   Memory
 from memory import get_virtual_function
 #   Players
@@ -63,8 +66,6 @@
 from _listeners import on_server_activate_listener_manager
 from _listeners import on_tick_listener_manager
 from _listeners import on_server_output_listener_manager
-#   Entity output
-from listeners._entity_output import on_entity_output_listener_manager
 
 
 # =============================================================================
@@ -154,6 +155,7 @@
 on_level_end_listener_manager = ListenerManager()
 on_player_run_command_listener_manager = ListenerManager()
 on_button_state_changed_listener_manager = ListenerManager()
+on_entity_output_listener_manager = ListenerManager()
 
 _check_for_update = ConVar(
     'sp_check_for_update',
@@ -536,6 +538,47 @@ def _pre_call_global_change_callbacks(args):
     on_convar_changed_listener_manager.notify(convar, old_value)
 
 
+def _pre_fire_output(args):
+    """Called when an output is about to be fired."""
+    if not on_entity_output_listener_manager:
+        return
+
+    # Windows is a bit weird: the function takes 4 additional arguments...
+    if PLATFORM == 'windows':
+        args = (args[0],) + tuple(args)[5:]
+
+    caller_ptr = args[3]
+    if not caller_ptr:
+        # If we don't know the caller, we won't be able to retrieve the
+        # output name
+        return
+
+    # Done here to fix cyclic import...
+    from entities.entity import BaseEntity
+    caller = make_object(BaseEntity, caller_ptr)
+    output_name = find_output_name(caller, args[0])
+    if output_name is None:
+        return None
+
+    # Done here to fix cyclic import...
+    from entities.entity import Entity
+    if caller.is_networked():
+        caller = make_object(Entity, caller_ptr)
+
+    value_ptr = args[1]
+    value = (value_ptr or None) and make_object(Variant, value_ptr)
+
+    activator_ptr = args[2]
+    activator = ((activator_ptr or None) and make_object(
+        BaseEntity, activator_ptr))
+    if activator is not None and activator.is_networked():
+        activator = make_object(Entity, activator_ptr)
+
+    delay = args[4]
+    on_entity_output_listener_manager.notify(
+        output_name, activator, caller, value, delay)
+
+
 # ============================================================================
 # >> Fix for issue #181.
 # ============================================================================