SDK-2647 Serializing local game state as integer

README.md

@@ -30,4 +30,14 @@ pip install -r requirements.txt
 Run tests:
 ```bash
 pytest
-```
+```
+
+## Changelog
+
+### 0.16
+* Do not log sensitive data.
+* Return `LocalGameState` as int (possible combination of flags).
+### 0.15
+* `shutdown()` is called on socket disconnection.
+### 0.14
+* Added required version parameter to Plugin constructor.

galaxy/api/consts.py

@@ -1,4 +1,4 @@
-from enum import Enum
+from enum import Enum, Flag
 
 class Platform(Enum):
     Unknown = "unknown"
@@ -30,10 +30,10 @@ class LicenseType(Enum):
     FreeToPlay = "FreeToPlay"
     OtherUserLicense = "OtherUserLicense"
 
-class LocalGameState(Enum):
-    None_ = "None"
-    Installed = "Installed"
-    Running = "Running"
+class LocalGameState(Flag):
+    None_ = 0
+    Installed = 1
+    Running = 2
 
 class PresenceState(Enum):
     Unknown = "Unknown"

galaxy/api/jsonrpc.py

@@ -1,5 +1,6 @@
 import asyncio
 from collections import namedtuple
+from collections.abc import Iterable
 import logging
 import json
 
@@ -41,7 +42,21 @@ class ApplicationError(JsonRpcError):
         super().__init__(code, message, data)
 
 Request = namedtuple("Request", ["method", "params", "id"], defaults=[{}, None])
-Method = namedtuple("Method", ["callback", "internal"])
+Method = namedtuple("Method", ["callback", "internal", "sensitive_params"])
+
+def anonymise_sensitive_params(params, sensitive_params):
+    anomized_data = "****"
+    if not sensitive_params:
+        return params
+
+    if isinstance(sensitive_params, Iterable):
+        anomized_params = params.copy()
+        for key in anomized_params.keys():
+            if key in sensitive_params:
+                anomized_params[key] = anomized_data
+        return anomized_params
+
+    return anomized_data
 
 class Server():
     def __init__(self, reader, writer, encoder=json.JSONEncoder()):
@@ -53,11 +68,27 @@ class Server():
         self._notifications = {}
         self._eof_listeners = []
 
-    def register_method(self, name, callback, internal):
-        self._methods[name] = Method(callback, internal)
+    def register_method(self, name, callback, internal, sensitive_params=False):
+        """
+        Register method
+        :param name:
+        :param callback:
+        :param internal: if True the callback will be processed immediately (synchronously)
+        :param sensitive_params: list of parameters that will by anonymized before logging; if False - no params
+        are considered sensitive, if True - all params are considered sensitive
+        """
+        self._methods[name] = Method(callback, internal, sensitive_params)
 
-    def register_notification(self, name, callback, internal):
-        self._notifications[name] = Method(callback, internal)
+    def register_notification(self, name, callback, internal, sensitive_params=False):
+        """
+        Register notification
+        :param name:
+        :param callback:
+        :param internal: if True the callback will be processed immediately (synchronously)
+        :param sensitive_params: list of parameters that will by anonymized before logging; if False - no params
+        are considered sensitive, if True - all params are considered sensitive
+        """
+        self._notifications[name] = Method(callback, internal, sensitive_params)
 
     def register_eof(self, callback):
         self._eof_listeners.append(callback)
@@ -73,7 +104,7 @@ class Server():
                 self._eof()
                 continue
             data = data.strip()
-            logging.debug("Received data: %s", data)
+            logging.debug("Received %d bytes of data", len(data))
             self._handle_input(data)
 
     def stop(self):
@@ -92,42 +123,39 @@ class Server():
             self._send_error(None, error)
             return
 
-        logging.debug("Parsed input: %s", request)
-
         if request.id is not None:
             self._handle_request(request)
         else:
             self._handle_notification(request)
 
     def _handle_notification(self, request):
-        logging.debug("Handling notification %s", request)
         method = self._notifications.get(request.method)
         if not method:
-            logging.error("Received uknown notification: %s", request.method)
+            logging.error("Received unknown notification: %s", request.method)
+            return
+
+        callback, internal, sensitive_params = method
+        self._log_request(request, sensitive_params)
 
-        callback, internal = method
         if internal:
             # internal requests are handled immediately
             callback(**request.params)
         else:
             try:
                 asyncio.create_task(callback(**request.params))
-            except Exception as error: #pylint: disable=broad-except
-                logging.error(
-                    "Unexpected exception raised in notification handler: %s",
-                    repr(error)
-                )
+            except Exception:
+                logging.exception("Unexpected exception raised in notification handler")
 
     def _handle_request(self, request):
-        logging.debug("Handling request %s", request)
         method = self._methods.get(request.method)
-
         if not method:
-            logging.error("Received uknown request: %s", request.method)
+            logging.error("Received unknown request: %s", request.method)
             self._send_error(request.id, MethodNotFound())
             return
 
-        callback, internal = method
+        callback, internal, sensitive_params = method
+        self._log_request(request, sensitive_params)
+
         if internal:
             # internal requests are handled immediately
             response = callback(request.params)
@@ -165,7 +193,8 @@ class Server():
         try:
             line = self._encoder.encode(data)
             logging.debug("Sending data: %s", line)
-            self._writer.write((line + "\n").encode("utf-8"))
+            data = (line + "\n").encode("utf-8")
+            self._writer.write(data)
             asyncio.create_task(self._writer.drain())
         except TypeError as error:
             logging.error(str(error))
@@ -193,25 +222,47 @@ class Server():
 
         self._send(response)
 
+    @staticmethod
+    def _log_request(request, sensitive_params):
+        params = anonymise_sensitive_params(request.params, sensitive_params)
+        if request.id is not None:
+            logging.info("Handling request: id=%s, method=%s, params=%s", request.id, request.method, params)
+        else:
+            logging.info("Handling notification: method=%s, params=%s", request.method, params)
+
 class NotificationClient():
     def __init__(self, writer, encoder=json.JSONEncoder()):
         self._writer = writer
         self._encoder = encoder
         self._methods = {}
 
-    def notify(self, method, params):
+    def notify(self, method, params, sensitive_params=False):
+        """
+        Send notification
+        :param method:
+        :param params:
+        :param sensitive_params: list of parameters that will by anonymized before logging; if False - no params
+        are considered sensitive, if True - all params are considered sensitive
+        """
         notification = {
             "jsonrpc": "2.0",
             "method": method,
             "params": params
         }
+        self._log(method, params, sensitive_params)
         self._send(notification)
 
     def _send(self, data):
         try:
             line = self._encoder.encode(data)
-            logging.debug("Sending data: %s", line)
-            self._writer.write((line + "\n").encode("utf-8"))
+            data = (line + "\n").encode("utf-8")
+            logging.debug("Sending %d byte of data", len(data))
+            self._writer.write(data)
             asyncio.create_task(self._writer.drain())
         except TypeError as error:
             logging.error("Failed to parse outgoing message: %s", str(error))
+
+    @staticmethod
+    def _log(method, params, sensitive_params):
+        params = anonymise_sensitive_params(params, sensitive_params)
+        logging.info("Sending notification: method=%s, params=%s", method, params)

galaxy/api/plugin.py

@@ -6,6 +6,7 @@ import dataclasses
 from enum import Enum
 from collections import OrderedDict
 import sys
+import os
 
 from galaxy.api.jsonrpc import Server, NotificationClient
 from galaxy.api.consts import Feature
@@ -22,9 +23,10 @@ class JSONEncoder(json.JSONEncoder):
         return super().default(o)
 
 class Plugin():
-    def __init__(self, platform, reader, writer, handshake_token):
-        logging.info("Creating plugin for platform %s", platform.value)
+    def __init__(self, platform, version, reader, writer, handshake_token):
+        logging.info("Creating plugin for platform %s, version %s", platform.value, version)
         self._platform = platform
+        self._version = version
 
         self._feature_methods = OrderedDict()
         self._active = True
@@ -37,7 +39,7 @@ class Plugin():
         self._notification_client = NotificationClient(self._writer, encoder)
 
         def eof_handler():
-            self._active = False
+            self._shutdown()
         self._server.register_eof(eof_handler)
 
         # internal
@@ -46,7 +48,7 @@ class Plugin():
         self._register_method("ping", self._ping, internal=True)
 
         # implemented by developer
-        self._register_method("init_authentication", self.authenticate)
+        self._register_method("init_authentication", self.authenticate, sensitive_params=["stored_credentials"])
         self._register_method(
             "import_owned_games",
             self.get_owned_games,
@@ -136,7 +138,7 @@ class Plugin():
                 return False
         return True
 
-    def _register_method(self, name, handler, result_name=None, internal=False, feature=None):
+    def _register_method(self, name, handler, result_name=None, internal=False, sensitive_params=False, feature=None):
         if internal:
             def method(params):
                 result = handler(**params)
@@ -145,7 +147,7 @@ class Plugin():
                         result_name: result
                     }
                 return result
-            self._server.register_method(name, method, True)
+            self._server.register_method(name, method, True, sensitive_params)
         else:
             async def method(params):
                 result = await handler(**params)
@@ -154,13 +156,13 @@ class Plugin():
                         result_name: result
                     }
                 return result
-            self._server.register_method(name, method, False)
+            self._server.register_method(name, method, False, sensitive_params)
 
         if feature is not None:
             self._feature_methods.setdefault(feature, []).append(handler)
 
-    def _register_notification(self, name, handler, internal=False, feature=None):
-        self._server.register_notification(name, handler, internal)
+    def _register_notification(self, name, handler, internal=False, sensitive_params=False, feature=None):
+        self._server.register_notification(name, handler, internal, sensitive_params)
 
         if feature is not None:
             self._feature_methods.setdefault(feature, []).append(handler)
@@ -169,7 +171,6 @@ class Plugin():
         """Plugin main coorutine"""
         async def pass_control():
             while self._active:
-                logging.debug("Passing control to plugin")
                 try:
                     self.tick()
                 except Exception:
@@ -200,7 +201,7 @@ class Plugin():
         """Notify client to store plugin credentials.
         They will be pass to next authencicate calls.
         """
-        self._notification_client.notify("store_credentials", credentials)
+        self._notification_client.notify("store_credentials", credentials, sensitive_params=True)
 
     def add_game(self, game):
         params = {"owned_game" : game}
@@ -315,12 +316,28 @@ class Plugin():
     async def get_game_times(self):
         raise NotImplementedError()
 
-def create_and_run_plugin(plugin_class, argv):
+def _prepare_logging(logger_file):
     root = logging.getLogger()
     root.setLevel(logging.DEBUG)
-    if len(argv) >= 4:
-        handler = logging.handlers.RotatingFileHandler(argv[3], "a", 10000000, 10)
-        root.addHandler(handler)
+    if logger_file:
+        # ensure destination folder exists
+        os.makedirs(os.path.dirname(os.path.abspath(logger_file)), exist_ok=True)
+        handler = logging.handlers.RotatingFileHandler(
+            logger_file,
+            mode="a",
+            maxBytes=10000000,
+            backupCount=10,
+            encoding="utf-8"
+        )
+    else:
+        handler = logging.StreamHandler()
+    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
+    handler.setFormatter(formatter)
+    root.addHandler(handler)
+
+def create_and_run_plugin(plugin_class, argv):
+    logger_file = argv[3] if len(argv) >= 4 else None
+    _prepare_logging(logger_file)
 
     if len(argv) < 3:
         logging.critical("Not enough parameters, required: token, port")

galaxy/api/types.py

@@ -28,8 +28,13 @@ class Game():
 
 @dataclass
 class Achievement():
-    achievement_id: str
     unlock_time: int
+    achievement_id: Optional[str] = None
+    achievement_name: Optional[str] = None
+
+    def __post_init__(self):
+        assert self.achievement_id or self.achievement_name, \
+            "One of achievement_id or achievement_name is required"
 
 @dataclass
 class LocalGame():

setup.py

@@ -2,7 +2,7 @@ from setuptools import setup, find_packages
 
 setup(
     name="galaxy.plugin.api",
-    version="0.11",
+    version="0.16",
     description="Galaxy python plugin API",
     author='Galaxy team',
     author_email='galaxy@gog.com',

tests/conftest.py

@@ -60,7 +60,7 @@ def plugin(reader, writer):
             stack.enter_context(patch.object(Plugin, method, new_callable=AsyncMock))
         for method in methods:
             stack.enter_context(patch.object(Plugin, method))
-        yield Plugin(Platform.Generic, reader, writer, "token")
+        yield Plugin(Platform.Generic, "0.1", reader, writer, "token")
 
 @pytest.fixture(autouse=True)
 def my_caplog(caplog):

tests/test_achievements.py

@@ -1,9 +1,18 @@
 import asyncio
 import json
+from pytest import raises
 
 from galaxy.api.types import Achievement
 from galaxy.api.errors import UnknownError
 
+def test_initialization_no_unlock_time():
+    with raises(Exception):
+        Achievement(achievement_id="lvl30", achievement_name="Got level 30")
+
+def test_initialization_no_id_nor_name():
+    with raises(AssertionError):
+        Achievement(unlock_time=1234567890)
+
 def test_success(plugin, readline, write):
     request = {
         "jsonrpc": "2.0",
@@ -15,8 +24,9 @@ def test_success(plugin, readline, write):
     }
     readline.side_effect = [json.dumps(request), ""]
     plugin.get_unlocked_achievements.return_value = [
-        Achievement("lvl10", 1548421241),
-        Achievement("lvl20", 1548422395)
+        Achievement(achievement_id="lvl10", unlock_time=1548421241),
+        Achievement(achievement_name="Got level 20", unlock_time=1548422395),
+        Achievement(achievement_id="lvl30", achievement_name="Got level 30", unlock_time=1548495633)
     ]
     asyncio.run(plugin.run())
     plugin.get_unlocked_achievements.assert_called_with(game_id="14")
@@ -32,8 +42,13 @@ def test_success(plugin, readline, write):
                     "unlock_time": 1548421241
                 },
                 {
-                    "achievement_id": "lvl20",
+                    "achievement_name": "Got level 20",
                     "unlock_time": 1548422395
+                },
+                {
+                    "achievement_id": "lvl30",
+                    "achievement_name": "Got level 30",
+                    "unlock_time": 1548495633
                 }
             ]
         }
@@ -65,7 +80,7 @@ def test_failure(plugin, readline, write):
     }
 
 def test_unlock_achievement(plugin, write):
-    achievement = Achievement("lvl20", 1548422395)
+    achievement = Achievement(achievement_id="lvl20", unlock_time=1548422395)
 
     async def couritine():
         plugin.unlock_achievement("14", achievement)

tests/test_features.py

@@ -2,14 +2,14 @@ from galaxy.api.plugin import Plugin
 from galaxy.api.consts import Platform, Feature
 
 def test_base_class():
-    plugin = Plugin(Platform.Generic, None, None, None)
+    plugin = Plugin(Platform.Generic, "0.1", None, None, None)
     assert plugin.features == []
 
 def test_no_overloads():
     class PluginImpl(Plugin): #pylint: disable=abstract-method
         pass
 
-    plugin = PluginImpl(Platform.Generic, None, None, None)
+    plugin = PluginImpl(Platform.Generic, "0.1", None, None, None)
     assert plugin.features == []
 
 def test_one_method_feature():
@@ -17,7 +17,7 @@ def test_one_method_feature():
         async def get_owned_games(self):
             pass
 
-    plugin = PluginImpl(Platform.Generic, None, None, None)
+    plugin = PluginImpl(Platform.Generic, "0.1", None, None, None)
     assert plugin.features == [Feature.ImportOwnedGames]
 
 def test_multiple_methods_feature_all():
@@ -33,7 +33,7 @@ def test_multiple_methods_feature_all():
         async def get_room_history_from_timestamp(self, room_id, timestamp):
             pass
 
-    plugin = PluginImpl(Platform.Generic, None, None, None)
+    plugin = PluginImpl(Platform.Generic, "0.1", None, None, None)
     assert plugin.features == [Feature.Chat]
 
 def test_multiple_methods_feature_not_all():
@@ -41,5 +41,5 @@ def test_multiple_methods_feature_not_all():
         async def send_message(self, room_id, message):
             pass
 
-    plugin = PluginImpl(Platform.Generic, None, None, None)
+    plugin = PluginImpl(Platform.Generic, "0.1", None, None, None)
     assert plugin.features == []

tests/test_internal.py

@@ -15,7 +15,7 @@ def test_get_capabilites(reader, writer, readline, write):
         "method": "get_capabilities"
     }
     token = "token"
-    plugin = PluginImpl(Platform.Generic, reader, writer, token)
+    plugin = PluginImpl(Platform.Generic, "0.1", reader, writer, token)
     readline.side_effect = [json.dumps(request), ""]
     asyncio.run(plugin.run())
     response = json.loads(write.call_args[0][0])

tests/test_local_games.py

@@ -17,8 +17,9 @@ def test_success(plugin, readline, write):
     readline.side_effect = [json.dumps(request), ""]
 
     plugin.get_local_games.return_value = [
-        LocalGame("1", "Running"),
-        LocalGame("2", "Installed")
+        LocalGame("1", LocalGameState.Running),
+        LocalGame("2", LocalGameState.Installed),
+        LocalGame("3", LocalGameState.Installed | LocalGameState.Running)
     ]
     asyncio.run(plugin.run())
     plugin.get_local_games.assert_called_with()
@@ -31,11 +32,15 @@ def test_success(plugin, readline, write):
             "local_games" : [
                 {
                     "game_id": "1",
-                    "local_game_state": "Running"
+                    "local_game_state": LocalGameState.Running.value
                 },
                 {
                     "game_id": "2",
-                    "local_game_state": "Installed"
+                    "local_game_state": LocalGameState.Installed.value
+                },
+                {
+                    "game_id": "3",
+                    "local_game_state": (LocalGameState.Installed | LocalGameState.Running).value
                 }
             ]
         }
@@ -85,7 +90,7 @@ def test_local_game_state_update(plugin, write):
         "params": {
             "local_game": {
                 "game_id": "1",
-                "local_game_state": "Running"
+                "local_game_state": LocalGameState.Running.value
             }
         }
     }