Repository: liampauling/flumine
Pull request #330 (2020-11-16 22:58:07)

Adding logging of order validation
https://betfairlightweight.slack.com/archives/C4HL6EZTQ/p1605481702489900


Patch:
diff --git a/HISTORY.rst b/HISTORY.rst
index e061c42..12c5b6a 100644
--- a/HISTORY.rst
+++ b/HISTORY.rst
@@ -3,35 +3,6 @@
 Release History
 ---------------
 
-1.14.8 (2020-11-16)
-+++++++++++++++++++
-
-**Improvements**
-
-- Config event added and processed on start
-
-**Bug Fixes**
-
-- #320 prevent market on close limit order when below min bsp liability
-
-1.14.7 (2020-11-14)
-+++++++++++++++++++
-
-**Improvements**
-
-- Minor bug on initial init with calculate_traded func
-
-1.14.6 (2020-11-13)
-+++++++++++++++++++
-
-**Improvements**
-
-- Refactor on calculate_traded func (15% speed increase)
-
-**Bug Fixes**
-
-- Refactoring create_order_from_current, so that it is not dependent on the '-' separator (@jsphon)
-
 1.14.5 (2020-11-11)
 +++++++++++++++++++
 
diff --git a/flumine/__version__.py b/flumine/__version__.py
index e9581ca..92b98ae 100644
--- a/flumine/__version__.py
+++ b/flumine/__version__.py
@@ -1,6 +1,6 @@
 __title__ = "flumine"
 __description__ = "Betfair trading framework"
 __url__ = "https://github.com/liampauling/flumine"
-__version__ = "1.14.8"
+__version__ = "1.14.5"
 __author__ = "Liam Pauling"
 __license__ = "MIT"
diff --git a/flumine/baseflumine.py b/flumine/baseflumine.py
index 073e5bf..ba6d359 100644
--- a/flumine/baseflumine.py
+++ b/flumine/baseflumine.py
@@ -359,8 +359,6 @@ class BaseFlumine:
         # start logging controls
         for c in self._logging_controls:
             c.start()
-        # process config (logging)
-        self.log_control(events.ConfigEvent(config))
         # start strategies
         self.strategies.start()
         # start streams
diff --git a/flumine/controls/loggingcontrols.py b/flumine/controls/loggingcontrols.py
index 978532e..e49521e 100644
--- a/flumine/controls/loggingcontrols.py
+++ b/flumine/controls/loggingcontrols.py
@@ -2,6 +2,7 @@ import logging
 import queue
 from threading import Thread
 
+from .. import config
 from ..events import events
 from ..events.events import EventType
 
@@ -41,11 +42,11 @@ class LoggingControl(Thread):
                         extra={"event": event},
                     )
 
-    def process_event(self, event: events.BaseEvent):
-        if event.EVENT_TYPE == EventType.CONFIG:
-            self._process_config(event)
+    def process_config(self, config: config):
+        logger.debug("process_config: %s" % config)
 
-        elif event.EVENT_TYPE == EventType.STRATEGY:
+    def process_event(self, event: events.BaseEvent):
+        if event.EVENT_TYPE == EventType.STRATEGY:
             self._process_strategy(event)
 
         elif event.EVENT_TYPE == EventType.MARKET:
@@ -85,9 +86,6 @@ class LoggingControl(Thread):
         else:
             logger.error("Unwanted item in logging control: {0}".format(event))
 
-    def _process_config(self, event):
-        logger.debug("process_config: %s" % event)
-
     def _process_strategy(self, event):
         logger.debug("process_strategy: %s" % event)
 
diff --git a/flumine/events/events.py b/flumine/events/events.py
index 0ce21a5..f728c00 100644
--- a/flumine/events/events.py
+++ b/flumine/events/events.py
@@ -3,7 +3,6 @@ from enum import Enum
 
 
 class EventType(Enum):
-    CONFIG = "Config"
     TERMINATOR = "Terminator"
     # betfair objects
     MARKET_CATALOGUE = "MarketCatalogue"
@@ -101,11 +100,6 @@ class NewDayEvent(BaseEvent):
 # LOGGING
 
 
-class ConfigEvent(BaseEvent):
-    EVENT_TYPE = EventType.CONFIG
-    QUEUE_TYPE = QueueType.LOGGING
-
-
 class ClearedOrdersMetaEvent(BaseEvent):
     EVENT_TYPE = EventType.CLEARED_ORDERS_META
     QUEUE_TYPE = QueueType.LOGGING
diff --git a/flumine/markets/middleware.py b/flumine/markets/middleware.py
index 73c86ed..3e121ab 100644
--- a/flumine/markets/middleware.py
+++ b/flumine/markets/middleware.py
@@ -138,16 +138,13 @@ class SimulatedMiddleware(Middleware):
 class RunnerAnalytics:
     def __init__(self, runner: RunnerBook):
         self._runner = runner
-        self.traded = {}  # price: size traded since last update
-        self.middle = None  # middle of odds at last update
-        self.matched = 0  # amount matched since last update
+        self.traded = {}  # price: size traded since last event
+        self.middle = None  # middle of odds at last event
+        self.matched = 0  # amount matched since last event
         self._traded_volume = runner.ex.traded_volume
-        self._p_v = {
-            i["price"]: i["size"] for i in runner.ex.traded_volume
-        }  # cached current volume
 
     def __call__(self, runner: RunnerBook):
-        self.middle = self._calculate_middle(self._runner)  # use last update
+        self.middle = self._calculate_middle(self._runner)  # use last event
         self.matched = self._calculate_matched(runner)
         self.traded = self._calculate_traded(runner)
         self._traded_volume = runner.ex.traded_volume
@@ -157,9 +154,12 @@ class RunnerAnalytics:
         if self._traded_volume == runner.ex.traded_volume:
             return {}
         else:
-            c_v, p_v, traded = {}, self._p_v, {}
-            # create dictionary
-            c_v = {i["price"]: i["size"] for i in runner.ex.traded_volume}
+            c_v, p_v, traded = {}, {}, {}
+            # create dictionaries
+            for i in runner.ex.traded_volume:
+                c_v[i["price"]] = i["size"]
+            for i in self._traded_volume:
+                p_v[i["price"]] = i["size"]  # todo cache from previous run?
             # calculate difference
             for key in c_v.keys():
                 if key in p_v:
@@ -167,9 +167,8 @@ class RunnerAnalytics:
                 else:
                     new_value = float(c_v[key])
                 if new_value > 0:
-                    traded[key] = round(new_value, 2)
-            # cache for next update
-            self._p_v = c_v
+                    new_value = round(new_value, 2)
+                    traded[key] = new_value
             return traded
 
     @staticmethod
diff --git a/flumine/order/order.py b/flumine/order/order.py
index 27ca471..9195cd2 100644
--- a/flumine/order/order.py
+++ b/flumine/order/order.py
@@ -1,8 +1,8 @@
 import uuid
 import logging
 import datetime
-import string
 from enum import Enum
+import string
 from typing import Union, Optional
 from betfairlightweight import filters
 from betfairlightweight.resources.bettingresources import CurrentOrder
@@ -233,6 +233,7 @@ class BaseOrder:
                 self.date_time_execution_complete - self.responses.date_time_placed
             ).total_seconds()
 
+    # todo cached properties?
     @property
     def market_id(self) -> str:
         return self.trade.market_id
@@ -241,7 +242,7 @@ class BaseOrder:
     def selection_id(self) -> int:
         return self.trade.selection_id
 
-    @property  # todo cache (slow when lots of orders)
+    @property
     def lookup(self) -> tuple:
         return self.market_id, self.selection_id, self.handicap
 
diff --git a/flumine/strategy/strategy.py b/flumine/strategy/strategy.py
index 9232836..5433461 100644
--- a/flumine/strategy/strategy.py
+++ b/flumine/strategy/strategy.py
@@ -1,5 +1,7 @@
 from typing import Type, Iterator
 
+import logging
+
 from betfairlightweight import filters
 from betfairlightweight.resources import MarketBook
 from .runnercontext import RunnerContext
@@ -8,6 +10,8 @@ from ..markets.market import Market
 from ..streams.marketstream import BaseStream, MarketStream
 from ..utils import create_cheap_hash
 
+logger = logging.getLogger(__name__)
+
 STRATEGY_NAME_HASH_LENGTH = 13
 
 DEFAULT_MARKET_DATA_FILTER = filters.streaming_market_data_filter(
@@ -38,6 +42,7 @@ class BaseStrategy:
         client: BaseClient = None,
         max_trade_count: int = 1e6,  # max total number of trades per runner
         max_live_trade_count: int = 1,  # max live (with executable orders) trades per runner
+        log_validation_failures: bool = False,
     ):
         """
         Processes data from streams.
@@ -51,6 +56,7 @@ class BaseStrategy:
         :param context: Dictionary holding additional vars
         :param max_selection_exposure: Max exposure per selection
         :param max_order_exposure: Max exposure per order
+        :param log_validation_failures: determines whether or not to log validation failures
         """
         self.market_filter = market_filter
         self.market_data_filter = market_data_filter or DEFAULT_MARKET_DATA_FILTER
@@ -67,6 +73,7 @@ class BaseStrategy:
 
         self._invested = {}  # {(marketId, selectionId, handicap): RunnerContext}
         self.streams = []  # list of streams strategy is subscribed
+        self.log_validation_failures = log_validation_failures
 
     def check_market(self, market: Market, market_book: MarketBook) -> bool:
         if market_book.streaming_unique_id not in self.stream_ids:
@@ -141,18 +148,41 @@ class BaseStrategy:
     def validate_order(self, runner_context: RunnerContext, order) -> bool:
         # validate context
         if runner_context.trade_count >= self.max_trade_count:
+            if self.log_validation_failures:
+                logger.warning(
+                    "validate_order failed: trade_count (%s) >= max_trade_count (%s)",
+                    runner_context.trade_count,
+                    self.max_live_trade_count,
+                )
             return False
         elif runner_context.live_trade_count >= self.max_live_trade_count:
+            if self.log_validation_failures:
+                logger.warning(
+                    "validate_order failed: live_trade_count (%s) >= max_live_trade_count (%s)"
+                    % (runner_context.live_trade_count, self.max_live_trade_count)
+                )
             return False
         elif (
             runner_context.placed_elapsed_seconds
             and runner_context.placed_elapsed_seconds < order.trade.place_reset_seconds
         ):
+            if self.log_validation_failures:
+                logger.warning(
+                    "validate_order failed: placed_elapsed_seconds (%s) < place_reset_seconds (%s)",
+                    runner_context.placed_elapsed_seconds,
+                    order.trade.place_reset_seconds,
+                )
             return False
         elif (
             runner_context.reset_elapsed_seconds
             and runner_context.reset_elapsed_seconds < order.trade.reset_seconds
         ):
+            if self.log_validation_failures:
+                logger.warning(
+                    "validate_order failed: reset_elapsed_seconds (%s) < reset_seconds (%s)",
+                    runner_context.reset_elapsed_seconds,
+                    order.trade.reset_seconds,
+                )
             return False
         else:
             return True


Test patch:
diff --git a/flumine/backtest/simulated.py b/flumine/backtest/simulated.py
index 4ce1e2b..41927c0 100644
--- a/flumine/backtest/simulated.py
+++ b/flumine/backtest/simulated.py
@@ -206,15 +206,9 @@ class Simulated:
                     size = self.size_remaining
                 else:
                     remaining_risk = (_order_type.price - 1.0) * self.size_remaining
-                    client = self.order.trade.client
-                    if remaining_risk >= client.min_bsp_liability:
-                        size = round(remaining_risk / (actual_sp - 1.0), 2)
-                        # Cancel remaining size
-                        self.size_cancelled += round(self.size_remaining - size, 2)
-                    else:  # lapse
-                        self.size_lapsed += self.size_remaining
-                        self.order.lapsed()
-                        return
+                    size = round(remaining_risk / (actual_sp - 1.0), 2)
+                    # Cancel remaining size
+                    self.size_cancelled += round(self.size_remaining - size, 2)
             elif _order_type.ORDER_TYPE == OrderTypes.LIMIT_ON_CLOSE:
                 if self.side == "BACK":
                     if actual_sp < _order_type.price:
diff --git a/tests/test_baseflumine.py b/tests/test_baseflumine.py
index f95a891..05d98a6 100644
--- a/tests/test_baseflumine.py
+++ b/tests/test_baseflumine.py
@@ -395,7 +395,6 @@ class BaseFlumineTest(unittest.TestCase):
         with self.base_flumine:
             self.assertTrue(self.base_flumine._running)
             self.mock_client.login.assert_called_with()
-            mock_log_control.assert_called_with(mock_events.ConfigEvent(None))
 
         self.assertFalse(self.base_flumine._running)
         self.mock_client.logout.assert_called_with()
diff --git a/tests/test_loggingcontrols.py b/tests/test_loggingcontrols.py
index 57ee850..b09683c 100644
--- a/tests/test_loggingcontrols.py
+++ b/tests/test_loggingcontrols.py
@@ -23,13 +23,6 @@ class TestLoggingControl(unittest.TestCase):
         self.logging_control.logging_queue.put(None)
         self.logging_control.run()
 
-    @mock.patch("flumine.controls.loggingcontrols.LoggingControl._process_config")
-    def test_process_event_config(self, mock_process_config):
-        mock_event = mock.Mock()
-        mock_event.EVENT_TYPE = EventType.CONFIG
-        self.logging_control.process_event(mock_event)
-        mock_process_config.assert_called_with(mock_event)
-
     @mock.patch("flumine.controls.loggingcontrols.LoggingControl._process_strategy")
     def test_process_event_strategy(self, mock_process_strategy):
         mock_event = mock.Mock()
@@ -124,7 +117,7 @@ class TestLoggingControl(unittest.TestCase):
         self.assertIsNone(self.logging_control.logging_queue.get())
 
     def test_process_config(self):
-        self.logging_control._process_config(None)
+        self.logging_control.process_config(None)
 
     def test_process_strategy(self):
         self.logging_control._process_strategy(None)
diff --git a/tests/test_middleware.py b/tests/test_middleware.py
index bec8d60..b60b904 100644
--- a/tests/test_middleware.py
+++ b/tests/test_middleware.py
@@ -170,7 +170,6 @@ class SimulatedMiddlewareTest(unittest.TestCase):
 class RunnerAnalyticsTest(unittest.TestCase):
     def setUp(self) -> None:
         self.mock_runner = mock.Mock()
-        self.mock_runner.ex.traded_volume = [{"price": 1.01, "size": 2}]
         self.runner_analytics = RunnerAnalytics(self.mock_runner)
 
     def test_init(self):
@@ -181,7 +180,6 @@ class RunnerAnalyticsTest(unittest.TestCase):
         self.assertEqual(self.runner_analytics.traded, {})
         self.assertEqual(self.runner_analytics.matched, 0)
         self.assertIsNone(self.runner_analytics.middle)
-        self.assertEqual(self.runner_analytics._p_v, {1.01: 2})
 
     @mock.patch("flumine.markets.middleware.RunnerAnalytics._calculate_matched")
     @mock.patch("flumine.markets.middleware.RunnerAnalytics._calculate_middle")
@@ -212,18 +210,15 @@ class RunnerAnalyticsTest(unittest.TestCase):
         mock_runner = mock.Mock()
         mock_runner.ex.traded_volume = [{"price": 1.01, "size": 69}]
         self.runner_analytics._traded_volume = [{"price": 1.01, "size": 69}]
-        self.runner_analytics._p_v = {1.01: 69}
         self.assertEqual(self.runner_analytics._calculate_traded(mock_runner), {})
-        self.assertEqual(self.runner_analytics._p_v, {1.01: 69})
 
     def test__calculate_traded_dict_new(self):
         mock_runner = mock.Mock()
         mock_runner.ex.traded_volume = [{"price": 1.01, "size": 69}]
         self.runner_analytics._traded_volume = []
         self.assertEqual(
-            self.runner_analytics._calculate_traded(mock_runner), {1.01: 67.0}
+            self.runner_analytics._calculate_traded(mock_runner), {1.01: 69.0}
         )
-        self.assertEqual(self.runner_analytics._p_v, {1.01: 69})
 
     def test__calculate_traded_dict_new_multi(self):
         mock_runner = mock.Mock()
@@ -232,12 +227,10 @@ class RunnerAnalyticsTest(unittest.TestCase):
             {"price": 10, "size": 32},
         ]
         self.runner_analytics._traded_volume = [{"price": 1.01, "size": 30}]
-        self.runner_analytics._p_v = {1.01: 30}
         self.assertEqual(
             self.runner_analytics._calculate_traded(mock_runner),
             {1.01: 39.0, 10: 32},
         )
-        self.assertEqual(self.runner_analytics._p_v, {1.01: 69, 10: 32})
 
     def test__calculate_middle(self):
         mock_runner = mock.Mock()
diff --git a/tests/test_simulated.py b/tests/test_simulated.py
index d9f32a1..f1efccd 100644
--- a/tests/test_simulated.py
+++ b/tests/test_simulated.py
@@ -10,7 +10,7 @@ class SimulatedTest(unittest.TestCase):
         self.mock_order_type = mock.Mock(
             price=12, size=2.00, ORDER_TYPE=OrderTypes.LIMIT
         )
-        mock_client = mock.Mock(paper_trade=False, min_bsp_liability=10)
+        mock_client = mock.Mock(paper_trade=False)
         mock_trade = mock.Mock(client=mock_client)
         self.mock_order = mock.Mock(
             selection_id=1234,
@@ -342,17 +342,6 @@ class SimulatedTest(unittest.TestCase):
         self.assertTrue(self.simulated._bsp_reconciled)
         self.simulated.order.execution_complete.assert_called()
 
-    def test__process_sp_lay_liability(self):
-        self.simulated.size_matched = 1.90
-        mock_runner = mock.Mock()
-        mock_runner.sp.actual_sp = 12.20
-        self.simulated.order.side = "LAY"
-        self.simulated._process_sp(1234571, mock_runner)
-        self.assertEqual(self.simulated.matched, [])
-        self.assertEqual(self.simulated.size_lapsed, 0.10)
-        self.assertTrue(self.simulated._bsp_reconciled)
-        self.simulated.order.lapsed.assert_called()
-
     def test__process_sp_none(self):
         mock_runner = mock.Mock()
         mock_runner.sp.actual_sp = None
diff --git a/tests/test_strategy.py b/tests/test_strategy.py
index 5496f62..fe0bf10 100644
--- a/tests/test_strategy.py
+++ b/tests/test_strategy.py
@@ -191,6 +191,7 @@ class BaseStrategyTest(unittest.TestCase):
             placed_elapsed_seconds=None,
             reset_elapsed_seconds=None,
         )
+        self.strategy.log_validation = True
         self.assertTrue(self.strategy.validate_order(runner_context, mock_order))
         # trade count
         runner_context.trade_count = 3