From b54fd3c1dd906be0bf01f874fe91d2772b7336ef Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Tue, 10 Oct 2023 14:41:59 +0100 Subject: [PATCH 01/19] refactor some simple log.setup() usages - pass temporary log attributes instead of copying the logger instance. Adds TODO comments for the remaining ones --- sysbrokers/IB/client/ib_contracts_client.py | 74 +++++++++++-------- sysbrokers/IB/client/ib_fx_client.py | 1 + sysbrokers/IB/client/ib_price_client.py | 32 ++++---- sysbrokers/IB/config/ib_instrument_config.py | 12 +-- sysbrokers/IB/ib_Fx_prices_data.py | 29 +++++--- .../IB/ib_futures_contract_price_data.py | 29 +++++--- sysbrokers/IB/ib_futures_contracts_data.py | 36 +++++---- sysbrokers/IB/ib_orders.py | 16 ++-- sysbrokers/broker_futures_contract_data.py | 8 +- syscontrol/run_process.py | 1 + syscontrol/timer_functions.py | 1 + .../arctic_futures_per_contract_prices.py | 15 ++-- sysdata/arctic/arctic_spotfx_prices.py | 15 ++-- sysdata/config/configdata.py | 1 + sysdata/csv/csv_futures_contract_prices.py | 7 +- sysdata/data_blob.py | 1 + sysdata/futures/contracts.py | 32 +++++--- .../futures/futures_per_contract_prices.py | 48 +++++++----- sysdata/futures/multiple_prices.py | 27 ++++--- sysdata/fx/spotfx.py | 56 +++++++++----- sysdata/sim/sim_data.py | 1 + sysexecution/algos/algo.py | 34 +++++---- sysexecution/algos/algo_market.py | 13 +++- sysexecution/algos/algo_original_best.py | 6 +- sysexecution/algos/allocate_algo_to_order.py | 32 +++++--- sysexecution/algos/common_functions.py | 22 ++++-- .../order_stacks/contract_order_stack.py | 14 +++- .../order_stacks/instrument_order_stack.py | 11 ++- sysexecution/order_stacks/order_stack.py | 47 ++++++------ sysexecution/orders/base_orders.py | 8 ++ sysexecution/orders/broker_orders.py | 18 +++++ sysexecution/orders/contract_orders.py | 17 +++++ sysexecution/orders/instrument_orders.py | 14 ++++ sysexecution/stack_handler/balance_trades.py | 61 +++++++++------ .../stack_handler/cancel_and_modify.py | 23 ++++-- ...eate_broker_orders_from_contract_orders.py | 24 +++--- sysexecution/stack_handler/fills.py | 29 ++++---- sysexecution/stack_handler/roll_orders.py | 8 +- .../spawn_children_from_instrument_orders.py | 54 ++++++++------ .../stack_handler/stackHandlerCore.py | 7 +- .../strategies/classic_buffered_positions.py | 7 +- .../strategies/dynamic_optimised_positions.py | 7 +- .../strategies/strategy_order_handling.py | 35 +++++---- sysinit/futures/seed_price_data_from_IB.py | 23 ++++-- sysobjects/contracts.py | 18 +++-- sysproduction/data/positions.py | 29 ++++---- .../interactive_update_roll_status.py | 1 - sysproduction/update_historical_prices.py | 1 + sysproduction/update_sampled_contracts.py | 38 ++++++---- systems/stage.py | 1 + 50 files changed, 668 insertions(+), 376 deletions(-) diff --git a/sysbrokers/IB/client/ib_contracts_client.py b/sysbrokers/IB/client/ib_contracts_client.py index a9082047da..c26251e408 100644 --- a/sysbrokers/IB/client/ib_contracts_client.py +++ b/sysbrokers/IB/client/ib_contracts_client.py @@ -44,10 +44,6 @@ def broker_get_futures_contract_list( ) -> list: ## Returns list of contract date strings YYYYMMDD - specific_log = self.log.setup( - instrument_code=futures_instrument_with_ib_data.instrument_code - ) - ibcontract_pattern = ib_futures_instrument(futures_instrument_with_ib_data) contract_list = self.ib_get_contract_chain( ibcontract_pattern, allow_expired=allow_expired @@ -72,9 +68,11 @@ def broker_get_single_contract_expiry_date( :param futures_contract_with_ib_data: contract where instrument has ib metadata :return: YYYYMMDD str """ - specific_log = futures_contract_with_ib_data.specific_log(self.log) + log_attrs = {**futures_contract_with_ib_data.log_attributes(), "method": "temp"} if futures_contract_with_ib_data.is_spread_contract(): - specific_log.warning("Can only find expiry for single leg contract!") + self.log.warning( + "Can only find expiry for single leg contract!", **log_attrs + ) raise missingContract try: @@ -84,7 +82,7 @@ def broker_get_single_contract_expiry_date( always_return_single_leg=True, ) except missingContract: - specific_log.warning("Contract is missing can't get expiry") + self.log.warning("Contract is missing can't get expiry", **log_attrs) raise missingContract expiry_date = ibcontract.lastTradeDateOrContractMonth @@ -103,16 +101,16 @@ def _ib_get_uncached_trading_hours( self, contract_object_with_ib_data: futuresContract ) -> listOfTradingHours: - specific_log = contract_object_with_ib_data.specific_log(self.log) - try: trading_hours_from_ib = self.ib_get_trading_hours_from_IB( contract_object_with_ib_data ) except Exception as e: - specific_log.warning( + self.log.warning( "%s when getting trading hours from %s!" - % (str(e), str(contract_object_with_ib_data)) + % (str(e), str(contract_object_with_ib_data)), + **contract_object_with_ib_data.log_attributes(), + method="temp", ) raise missingData @@ -136,7 +134,6 @@ def _ib_get_uncached_trading_hours( def ib_get_trading_hours_from_IB( self, contract_object_with_ib_data: futuresContract ) -> listOfTradingHours: - specific_log = contract_object_with_ib_data.specific_log(self.log) try: ib_contract_details = self.ib_get_contract_details( @@ -146,9 +143,11 @@ def ib_get_trading_hours_from_IB( ib_contract_details ) except Exception as e: - specific_log.warning( + self.log.warning( "%s when getting trading hours from %s!" - % (str(e), str(contract_object_with_ib_data)) + % (str(e), str(contract_object_with_ib_data)), + **contract_object_with_ib_data.log_attributes(), + method="temp", ) raise missingData @@ -214,15 +213,16 @@ def ib_get_saved_weekly_trading_hours_custom_for_contract( def ib_get_saved_weekly_trading_hours_for_timezone_of_contract( self, contract_object_with_ib_data: futuresContract ) -> weekdayDictOfListOfTradingHoursAnyDay: - specific_log = contract_object_with_ib_data.log(self.log) + log_attrs = {**contract_object_with_ib_data.log_attributes(), "method": "temp"} try: time_zone_id = self.ib_get_timezoneid(contract_object_with_ib_data) except missingData: # problem getting timezoneid - specific_log.warning( + self.log.warning( "No time zone ID, can't get trading hours for timezone for %s" - % str(contract_object_with_ib_data) + % str(contract_object_with_ib_data), + **log_attrs, ) raise missingData @@ -235,22 +235,24 @@ def ib_get_saved_weekly_trading_hours_for_timezone_of_contract( "Check ib_config_trading_hours in sysbrokers/IB or private directory, hours for timezone %s not found!" % time_zone_id ) - specific_log.log.critical(error_msg) + # TODO check this double log + self.log.log.critical(error_msg, **log_attrs) raise missingData return weekly_hours_for_timezone def ib_get_timezoneid(self, contract_object_with_ib_data: futuresContract) -> str: - specific_log = contract_object_with_ib_data.specific_log(self.log) try: ib_contract_details = self.ib_get_contract_details( contract_object_with_ib_data ) time_zone_id = ib_contract_details.timeZoneId except Exception as e: - specific_log.warning( + self.log.warning( "%s when getting time zone from %s!" - % (str(e), str(contract_object_with_ib_data)) + % (str(e), str(contract_object_with_ib_data)), + **contract_object_with_ib_data.log_attributes(), + method="temp", ) raise missingData @@ -273,13 +275,16 @@ def _get_all_saved_weekly_trading_hours_from_file(self): def ib_get_min_tick_size( self, contract_object_with_ib_data: futuresContract ) -> float: - specific_log = contract_object_with_ib_data.specific_log(self.log) + log_attrs = {**contract_object_with_ib_data.log_attributes(), "method": "temp"} try: ib_contract = self.ib_futures_contract( contract_object_with_ib_data, always_return_single_leg=True ) except missingContract: - specific_log.warning("Can't get tick size as contract missing") + self.log.warning( + "Can't get tick size as contract missing", + **log_attrs, + ) raise ib_contract_details = self.ib.reqContractDetails(ib_contract)[0] @@ -287,9 +292,10 @@ def ib_get_min_tick_size( try: min_tick = ib_contract_details.minTick except Exception as e: - specific_log.warning( + self.log.warning( "%s when getting min tick size from %s!" - % (str(e), str(ib_contract_details)) + % (str(e), str(ib_contract_details)), + log_attrs, ) raise missingContract @@ -298,13 +304,15 @@ def ib_get_min_tick_size( def ib_get_price_magnifier( self, contract_object_with_ib_data: futuresContract ) -> float: - specific_log = contract_object_with_ib_data.specific_log(self.log) + log_attrs = {**contract_object_with_ib_data.log_attributes(), "method": "temp"} try: ib_contract = self.ib_futures_contract( contract_object_with_ib_data, always_return_single_leg=True ) except missingContract: - specific_log.warning("Can't get price magnifier as contract missing") + self.log.warning( + "Can't get price magnifier as contract missing", **log_attrs + ) raise ib_contract_details = self.ib.reqContractDetails(ib_contract)[0] @@ -312,22 +320,26 @@ def ib_get_price_magnifier( try: price_magnifier = ib_contract_details.priceMagnifier except Exception as e: - specific_log.warning( + self.log.warning( "%s when getting price magnifier from %s!" - % (str(e), str(ib_contract_details)) + % (str(e), str(ib_contract_details)), + **log_attrs, ) raise missingContract return price_magnifier def ib_get_contract_details(self, contract_object_with_ib_data: futuresContract): - specific_log = contract_object_with_ib_data.specific_log(self.log) try: ib_contract = self.ib_futures_contract( contract_object_with_ib_data, always_return_single_leg=True ) except missingContract: - specific_log.warning("Can't get trading hours as contract is missing") + self.log.warning( + "Can't get trading hours as contract is missing", + contract_object_with_ib_data.log_attributes(), + method="temp", + ) raise # returns a list but should only have one element diff --git a/sysbrokers/IB/client/ib_fx_client.py b/sysbrokers/IB/client/ib_fx_client.py index 4faf02da55..105439fda8 100644 --- a/sysbrokers/IB/client/ib_fx_client.py +++ b/sysbrokers/IB/client/ib_fx_client.py @@ -77,6 +77,7 @@ def broker_get_daily_fx_data( """ ccy_code = ccy1 + ccy2 + # TODO log.setup log = self.log.setup(currency_code=ccy_code) try: diff --git a/sysbrokers/IB/client/ib_price_client.py b/sysbrokers/IB/client/ib_price_client.py index 8de70e23b1..45a4cb5580 100644 --- a/sysbrokers/IB/client/ib_price_client.py +++ b/sysbrokers/IB/client/ib_price_client.py @@ -49,7 +49,7 @@ def broker_get_historical_futures_data_for_contract( :param freq: str; one of D, H, 5M, M, 10S, S :return: futuresContractPriceData """ - + # TODO specific_log specific_log = contract_object_with_ib_broker_config.specific_log(self.log) try: @@ -93,17 +93,17 @@ def get_ib_ticker_object( trade_list_for_multiple_legs: tradeQuantity = None, ) -> "ib.ticker": - specific_log = contract_object_with_ib_data.specific_log(self.log) - try: ibcontract = self.ib_futures_contract( contract_object_with_ib_data, trade_list_for_multiple_legs=trade_list_for_multiple_legs, ) except missingContract: - specific_log.warning( + self.log.warning( "Can't find matching IB contract for %s" - % str(contract_object_with_ib_data) + % str(contract_object_with_ib_data), + **contract_object_with_ib_data.log_attributes(), + method="temp", ) raise @@ -124,17 +124,17 @@ def cancel_market_data_for_contract_and_trade_qty( trade_list_for_multiple_legs: tradeQuantity = None, ): - specific_log = contract_object_with_ib_data.specific_log(self.log) - try: ibcontract = self.ib_futures_contract( contract_object_with_ib_data, trade_list_for_multiple_legs=trade_list_for_multiple_legs, ) except missingContract: - specific_log.warning( + self.log.warning( "Can't find matching IB contract for %s" - % str(contract_object_with_ib_data) + % str(contract_object_with_ib_data), + **contract_object_with_ib_data.log_attributes(), + method="temp", ) raise @@ -151,21 +151,19 @@ def _ib_get_recent_bid_ask_tick_data_using_reqHistoricalTicks( :param contract_object_with_ib_data: :return: """ - specific_log = self.log.setup( - instrument_code=contract_object_with_ib_data.instrument_code, - contract_date=contract_object_with_ib_data.date_str, - ) + log_attrs = {**contract_object_with_ib_data.log_attributes(), "method": "temp"} if contract_object_with_ib_data.is_spread_contract(): error_msg = "Can't get historical data for combo" - specific_log.critical(error_msg) + self.log.critical(error_msg, **log_attrs) raise Exception(error_msg) try: ibcontract = self.ib_futures_contract(contract_object_with_ib_data) except missingContract: - specific_log.warning( + self.log.warning( "Can't find matching IB contract for %s" - % str(contract_object_with_ib_data) + % str(contract_object_with_ib_data), + **log_attrs, ) raise @@ -178,7 +176,7 @@ def _ib_get_recent_bid_ask_tick_data_using_reqHistoricalTicks( return tick_data - def _get_generic_data_for_contract( + def _get_generic_data_for_contract( # TODO passed logger instance self, ibcontract: ibContract, log: pst_logger = None, diff --git a/sysbrokers/IB/config/ib_instrument_config.py b/sysbrokers/IB/config/ib_instrument_config.py index d196450628..ee35650f27 100644 --- a/sysbrokers/IB/config/ib_instrument_config.py +++ b/sysbrokers/IB/config/ib_instrument_config.py @@ -36,15 +36,16 @@ def get_instrument_object_from_config( instrument_code: str, config: IBconfig = None, log: pst_logger = get_logger("") ) -> futuresInstrumentWithIBConfigData: - new_log = log.setup(instrument_code=instrument_code) + log_attrs = {INSTRUMENT_CODE_LOG_LABEL: instrument_code, "method": "temp"} if config is None: try: config = read_ib_config_from_file() except missingFile as e: - new_log.warning( + log.warning( "Can't get config for instrument %s as IB configuration file missing" - % instrument_code + % instrument_code, + **log_attrs, ) raise missingInstrument from e @@ -52,8 +53,9 @@ def get_instrument_object_from_config( try: assert instrument_code in list_of_instruments except: - new_log.warning( - "Instrument %s is not in IB configuration file" % instrument_code + log.warning( + "Instrument %s is not in IB configuration file" % instrument_code, + **log_attrs, ) raise missingInstrument diff --git a/sysbrokers/IB/ib_Fx_prices_data.py b/sysbrokers/IB/ib_Fx_prices_data.py index 7da66b699c..f252faf1c4 100644 --- a/sysbrokers/IB/ib_Fx_prices_data.py +++ b/sysbrokers/IB/ib_Fx_prices_data.py @@ -52,8 +52,11 @@ def _get_fx_prices_without_checking(self, currency_code: str) -> fxPrices: try: ib_config_for_code = self._get_config_info_for_code(currency_code) except missingInstrument: - log = self.log.setup(**{CURRENCY_CODE_LOG_LABEL: currency_code}) - log.warning("Can't get prices as missing IB config for %s" % currency_code) + self.log.warning( + "Can't get prices as missing IB config for %s" % currency_code, + CURRENCY_CODE_LOG_LABEL=currency_code, + method="temp", + ) return fxPrices.create_empty() data = self._get_fx_prices_with_ib_config(currency_code, ib_config_for_code) @@ -65,12 +68,16 @@ def _get_fx_prices_with_ib_config( ) -> fxPrices: raw_fx_prices_as_series = self._get_raw_fx_prices(ib_config_for_code) - log = self.log.setup(**{CURRENCY_CODE_LOG_LABEL: currency_code}) + log_attrs = { + CURRENCY_CODE_LOG_LABEL: currency_code, + "method": "temp", + } if len(raw_fx_prices_as_series) == 0: - log.warning( + self.log.warning( "No available IB prices for %s %s" - % (currency_code, str(ib_config_for_code)) + % (currency_code, str(ib_config_for_code)), + **log_attrs, ) return fxPrices.create_empty() @@ -82,7 +89,10 @@ def _get_fx_prices_with_ib_config( # turn into a fxPrices fx_prices = fxPrices(raw_fx_prices) - log.debug("Downloaded %d prices" % len(fx_prices)) + self.log.debug( + "Downloaded %d prices" % len(fx_prices), + **log_attrs, + ) return fx_prices @@ -103,9 +113,10 @@ def _get_config_info_for_code(self, currency_code: str) -> ibFXConfig: try: config_data = self._get_ib_fx_config() except missingFile as e: - new_log = self.log.setup(**{CURRENCY_CODE_LOG_LABEL: currency_code}) - new_log.warning( - "Can't get IB FX config for %s as config file missing" % currency_code + self.log.warning( + "Can't get IB FX config for %s as config file missing" % currency_code, + CURRENCY_CODE_LOG_LABEL=currency_code, + method="temp", ) raise missingInstrument from e diff --git a/sysbrokers/IB/ib_futures_contract_price_data.py b/sysbrokers/IB/ib_futures_contract_price_data.py index ff9ba6de61..dabefa80bd 100644 --- a/sysbrokers/IB/ib_futures_contract_price_data.py +++ b/sysbrokers/IB/ib_futures_contract_price_data.py @@ -201,7 +201,6 @@ def _get_prices_at_frequency_for_contract_object_no_checking_with_expiry_flag( :param frequency: str; one of D, H, 15M, 5M, M, 10S, S :return: data """ - new_log = futures_contract_object.log(self.log) try: contract_object_with_ib_broker_config = ( @@ -210,7 +209,11 @@ def _get_prices_at_frequency_for_contract_object_no_checking_with_expiry_flag( ) ) except missingContract: - new_log.warning("Can't get data for %s" % str(futures_contract_object)) + self.log.warning( + "Can't get data for %s" % str(futures_contract_object), + **futures_contract_object.log_attributes(), + method="temp", + ) raise missingData price_data = self._get_prices_at_frequency_for_ibcontract_object_no_checking( @@ -275,7 +278,6 @@ def get_ticker_object_for_contract_and_trade_qty( futures_contract: futuresContract, trade_list_for_multiple_legs: tradeQuantity = None, ) -> tickerObject: - new_log = futures_contract.specific_log(self.log) try: contract_object_with_ib_data = ( @@ -284,7 +286,11 @@ def get_ticker_object_for_contract_and_trade_qty( ) ) except missingContract as e: - new_log.warning("Can't get data for %s" % str(futures_contract)) + self.log.warning( + "Can't get data for %s" % str(futures_contract), + **futures_contract.log_attributes(), + method="temp", + ) raise e ticker_with_bs = self.ib_client.get_ticker_object_with_BS( @@ -297,13 +303,16 @@ def get_ticker_object_for_contract_and_trade_qty( return ticker_object def cancel_market_data_for_contract(self, contract: futuresContract): - new_log = contract.specific_log(self.log) try: contract_object_with_ib_data = ( self.futures_contract_data.get_contract_object_with_IB_data(contract) ) except missingContract: - new_log.warning("Can't get data for %s" % str(contract)) + self.log.warning( + "Can't get data for %s" % str(contract), + **contract.log_attributes(), + method="temp", + ) return futuresContractPrices.create_empty() self.ib_client.cancel_market_data_for_contract(contract_object_with_ib_data) @@ -312,8 +321,6 @@ def cancel_market_data_for_order(self, order: ibBrokerOrder): contract_object = order.futures_contract trade_list_for_multiple_legs = order.trade - new_log = order.log_with_attributes(self.log) - try: contract_object_with_ib_data = ( self.futures_contract_data.get_contract_object_with_IB_data( @@ -321,7 +328,11 @@ def cancel_market_data_for_order(self, order: ibBrokerOrder): ) ) except missingContract: - new_log.warning("Can't get data for %s" % str(contract_object)) + self.log.warning( + "Can't get data for %s" % str(contract_object), + **order.log_attributes(), + method="temp", + ) return futuresContractPrices.create_empty() self.ib_client.cancel_market_data_for_contract_and_trade_qty( diff --git a/sysbrokers/IB/ib_futures_contracts_data.py b/sysbrokers/IB/ib_futures_contracts_data.py index a1a5a09a51..57cbc72b23 100644 --- a/sysbrokers/IB/ib_futures_contracts_data.py +++ b/sysbrokers/IB/ib_futures_contracts_data.py @@ -98,9 +98,12 @@ def get_actual_expiry_date_for_single_contract( :param futures_contract: type futuresContract :return: YYYYMMDD or None """ - log = futures_contract.specific_log(self.log) if futures_contract.is_spread_contract(): - log.warning("Can't find expiry for multiple leg contract here") + self.log.warning( + "Can't find expiry for multiple leg contract here", + **futures_contract.log_attributes(), + method="temp", + ) raise missingContract contract_object_with_ib_data = self.get_contract_object_with_IB_data( @@ -114,9 +117,12 @@ def get_actual_expiry_date_for_single_contract( def _get_actual_expiry_date_given_single_contract_with_ib_metadata( self, futures_contract_with_ib_data: futuresContract, allow_expired=False ) -> expiryDate: - log = futures_contract_with_ib_data.specific_log(self.log) if futures_contract_with_ib_data.is_spread_contract(): - log.warning("Can't find expiry for multiple leg contract here") + self.log.warning( + "Can't find expiry for multiple leg contract here", + **futures_contract_with_ib_data.log_attributes(), + method="temp", + ) raise missingContract expiry_date = self.ib_client.broker_get_single_contract_expiry_date( @@ -158,13 +164,15 @@ def _get_futures_instrument_object_with_IB_data( ) def get_min_tick_size_for_contract(self, contract_object: futuresContract) -> float: - new_log = contract_object.log(self.log) + log_attrs = {**contract_object.log_attributes(), "method": "temp"} try: contract_object_with_ib_data = self.get_contract_object_with_IB_data( contract_object ) except missingContract: - new_log.debug("Can't resolve contract so can't find tick size") + self.log.debug( + "Can't resolve contract so can't find tick size", **log_attrs + ) raise try: @@ -172,7 +180,7 @@ def get_min_tick_size_for_contract(self, contract_object: futuresContract) -> fl contract_object_with_ib_data ) except missingContract: - new_log.debug("No tick size found") + self.log.debug("No tick size found", **log_attrs) raise return min_tick_size @@ -180,13 +188,15 @@ def get_min_tick_size_for_contract(self, contract_object: futuresContract) -> fl def get_price_magnifier_for_contract( self, contract_object: futuresContract ) -> float: - new_log = contract_object.log(self.log) + log_attrs = {**contract_object.log_attributes(), "method": "temp"} try: contract_object_with_ib_data = self.get_contract_object_with_IB_data( contract_object ) except missingContract: - new_log.debug("Can't resolve contract so can't find tick size") + self.log.debug( + "Can't resolve contract so can't find tick size", **log_attrs + ) raise try: @@ -194,7 +204,7 @@ def get_price_magnifier_for_contract( contract_object_with_ib_data ) except missingContract: - new_log.debug("No contract found") + self.log.debug("No contract found", **log_attrs) raise return price_magnifier @@ -207,14 +217,14 @@ def get_trading_hours_for_contract( :param futures_contract: :return: list of paired date times """ - new_log = futures_contract.log(self.log) + log_attrs = {**futures_contract.log_attributes(), "method": "temp"} try: contract_object_with_ib_data = self.get_contract_object_with_IB_data( futures_contract ) except missingContract: - new_log.debug("Can't resolve contract") + self.log.debug("Can't resolve contract", **log_attrs) raise missingContract try: @@ -222,7 +232,7 @@ def get_trading_hours_for_contract( contract_object_with_ib_data ) except missingData: - new_log.debug("No trading hours found") + self.log.debug("No trading hours found", **log_attrs) trading_hours = listOfTradingHours([]) return trading_hours diff --git a/sysbrokers/IB/ib_orders.py b/sysbrokers/IB/ib_orders.py index c97586e977..1435ecb7b1 100644 --- a/sysbrokers/IB/ib_orders.py +++ b/sysbrokers/IB/ib_orders.py @@ -297,8 +297,10 @@ def _send_broker_order_to_IB(self, broker_order: brokerOrder) -> tradeWithContra """ - log = broker_order.log_with_attributes(self.log) - log.debug("Going to submit order %s to IB" % str(broker_order)) + log_attrs = {**broker_order.log_attributes(), "method": "temp"} + self.log.debug( + "Going to submit order %s to IB" % str(broker_order), **log_attrs + ) trade_list = broker_order.trade order_type = broker_order.order_type @@ -318,10 +320,10 @@ def _send_broker_order_to_IB(self, broker_order: brokerOrder) -> tradeWithContra limit_price=limit_price, ) if placed_broker_trade_object is missing_order: - log.warning("Couldn't submit order") + self.log.warning("Couldn't submit order", **log_attrs) return missing_order - log.debug("Order submitted to IB") + self.log.debug("Order submitted to IB", **log_attrs) return placed_broker_trade_object @@ -377,16 +379,16 @@ def match_db_broker_order_to_control_order_from_brokers( def cancel_order_on_stack(self, broker_order: brokerOrder): - log = broker_order.log_with_attributes(self.log) + log_attrs = {**broker_order.log_attributes(), "method": "temp"} matched_control_order = ( self.match_db_broker_order_to_control_order_from_brokers(broker_order) ) if matched_control_order is missing_order: - log.warning("Couldn't cancel non existent order") + self.log.warning("Couldn't cancel non existent order", **log_attrs) return None self.cancel_order_given_control_object(matched_control_order) - log.debug("Sent cancellation for %s" % str(broker_order)) + self.log.debug("Sent cancellation for %s" % str(broker_order), **log_attrs) def cancel_order_given_control_object( self, broker_orders_with_controls: ibOrderWithControls diff --git a/sysbrokers/broker_futures_contract_data.py b/sysbrokers/broker_futures_contract_data.py index 9e46726ba7..a927d40ada 100644 --- a/sysbrokers/broker_futures_contract_data.py +++ b/sysbrokers/broker_futures_contract_data.py @@ -22,13 +22,15 @@ def get_min_tick_size_for_contract(self, contract_object: futuresContract) -> fl raise NotImplementedError def is_contract_okay_to_trade(self, futures_contract: futuresContract) -> bool: - new_log = futures_contract.log(self.log) try: trading_hours = self.get_trading_hours_for_contract(futures_contract) except missingContract: - new_log.critical( - "Error! Cannot find active contract! Expired? interactive_update_roll_status.py not executed?" + self.log.critical( + "Error! Cannot find active contract! Expired? " + "interactive_update_roll_status.py not executed?", + **futures_contract.log_attributes(), + method="temp", ) return False diff --git a/syscontrol/run_process.py b/syscontrol/run_process.py index 409ae1085f..b8008d0236 100644 --- a/syscontrol/run_process.py +++ b/syscontrol/run_process.py @@ -70,6 +70,7 @@ def list_of_timer_functions(self) -> listOfTimerFunctions: return self._list_of_timer_functions def _setup(self): + # TODO log.setup self.data.log.setup(type=self.process_name) self._log = self.data.log data_control = dataControlProcess(self.data) diff --git a/syscontrol/timer_functions.py b/syscontrol/timer_functions.py index dc289cefd4..41a889207b 100644 --- a/syscontrol/timer_functions.py +++ b/syscontrol/timer_functions.py @@ -27,6 +27,7 @@ def __init__( self._data = data self._parameters = parameters + # TODO log.setup log.setup(type=self.process_name) self._log = log self._report_status = reportStatus(log) diff --git a/sysdata/arctic/arctic_futures_per_contract_prices.py b/sysdata/arctic/arctic_futures_per_contract_prices.py index ccdf538323..f11d9d75b7 100644 --- a/sysdata/arctic/arctic_futures_per_contract_prices.py +++ b/sysdata/arctic/arctic_futures_per_contract_prices.py @@ -94,7 +94,6 @@ def _write_prices_at_frequency_for_contract_object_no_checking( frequency: Frequency, ): - log = futures_contract_object.log(self.log) ident = from_contract_and_freq_to_key( futures_contract_object, frequency=frequency ) @@ -102,14 +101,16 @@ def _write_prices_at_frequency_for_contract_object_no_checking( self.arctic_connection.write(ident, futures_price_data_as_pd) - log.debug( + self.log.debug( "Wrote %s lines of prices for %s at %s to %s" % ( len(futures_price_data), str(futures_contract_object.key), str(frequency), str(self), - ) + ), + **futures_contract_object.log_attributes(), + method="temp", ) def get_contracts_with_merged_price_data(self) -> listOfFuturesContracts: @@ -190,15 +191,15 @@ def _delete_merged_prices_for_contract_object_with_no_checks_be_careful( def _delete_prices_at_frequency_for_contract_object_with_no_checks_be_careful( self, futures_contract_object: futuresContract, frequency: Frequency ): - log = futures_contract_object.log(self.log) - ident = from_contract_and_freq_to_key( contract=futures_contract_object, frequency=frequency ) self.arctic_connection.delete(ident) - log.debug( + self.log.debug( "Deleted all prices for %s from %s" - % (futures_contract_object.key, str(self)) + % (futures_contract_object.key, str(self)), + **futures_contract_object.log_attributes(), + method="temp", ) diff --git a/sysdata/arctic/arctic_spotfx_prices.py b/sysdata/arctic/arctic_spotfx_prices.py index 5badf78342..4eb56b730d 100644 --- a/sysdata/arctic/arctic_spotfx_prices.py +++ b/sysdata/arctic/arctic_spotfx_prices.py @@ -36,21 +36,24 @@ def _get_fx_prices_without_checking(self, currency_code: str) -> fxPrices: return fx_prices def _delete_fx_prices_without_any_warning_be_careful(self, currency_code: str): - log = self.log.setup(**{CURRENCY_CODE_LOG_LABEL: currency_code}) self.arctic.delete(currency_code) - log.debug("Deleted fX prices for %s from %s" % (currency_code, str(self))) + self.log.debug( + "Deleted fX prices for %s from %s" % (currency_code, str(self)), + CURRENCY_CODE_LOG_LABEL=currency_code, + method="temp", + ) def _add_fx_prices_without_checking_for_existing_entry( self, currency_code: str, fx_price_data: fxPrices ): - log = self.log.setup(**{CURRENCY_CODE_LOG_LABEL: currency_code}) - fx_price_data_aspd = pd.DataFrame(fx_price_data) fx_price_data_aspd.columns = ["price"] fx_price_data_aspd = fx_price_data_aspd.astype(float) self.arctic.write(currency_code, fx_price_data_aspd) - log.debug( + self.log.debug( "Wrote %s lines of prices for %s to %s" - % (len(fx_price_data), currency_code, str(self)) + % (len(fx_price_data), currency_code, str(self)), + CURRENCY_CODE_LOG_LABEL=currency_code, + method="temp", ) diff --git a/sysdata/config/configdata.py b/sysdata/config/configdata.py index 8a6849dcf2..934d0720ca 100644 --- a/sysdata/config/configdata.py +++ b/sysdata/config/configdata.py @@ -190,6 +190,7 @@ def system_init(self, base_system): """ # inherit the log + # TODO log.setup setattr(self, "log", base_system.log.setup(stage="config")) # fill with defaults diff --git a/sysdata/csv/csv_futures_contract_prices.py b/sysdata/csv/csv_futures_contract_prices.py index 2d48a056e1..7c951abb07 100644 --- a/sysdata/csv/csv_futures_contract_prices.py +++ b/sysdata/csv/csv_futures_contract_prices.py @@ -91,8 +91,11 @@ def _get_prices_at_frequency_for_contract_object_no_checking( skipfooter=skipfooter, ) except OSError: - log = futures_contract_object.log(self.log) - log.warning("Can't find adjusted price file %s" % filename) + self.log.warning( + "Can't find adjusted price file %s" % filename, + **futures_contract_object.log_attributes(), + method="temp", + ) return futuresContractPrices.create_empty() instrpricedata = instrpricedata.groupby(level=0).last() diff --git a/sysdata/data_blob.py b/sysdata/data_blob.py index 7c11be2943..efdc0db9df 100644 --- a/sysdata/data_blob.py +++ b/sysdata/data_blob.py @@ -208,6 +208,7 @@ def csv_data_paths(self) -> dict: def _get_specific_logger(self, class_object): class_name = get_class_name(class_object) + # TODO log.setup log = self.log.setup(**{COMPONENT_LOG_LABEL: class_name}) return log diff --git a/sysdata/futures/contracts.py b/sysdata/futures/contracts.py index 8cebc8ccd7..77cec6ca5f 100644 --- a/sysdata/futures/contracts.py +++ b/sysdata/futures/contracts.py @@ -45,21 +45,28 @@ def get_contract_object( def delete_contract_data( self, instrument_code: str, contract_date: str, are_you_sure=False ): - - log = self.log.setup( - instrument_code=instrument_code, contract_date=contract_date - ) + log_attrs = { + INSTRUMENT_CODE_LOG_LABEL: instrument_code, + CONTRACT_DATE_LOG_LABEL: contract_date, + "method": "temp", + } if are_you_sure: if self.is_contract_in_data(instrument_code, contract_date): self._delete_contract_data_without_any_warning_be_careful( instrument_code, contract_date ) - log.info("Deleted contract %s/%s" % (instrument_code, contract_date)) + self.log.info( + "Deleted contract %s/%s" % (instrument_code, contract_date), + **log_attrs, + ) else: # doesn't exist anyway - log.warning("Tried to delete non existent contract") + self.log.warning("Tried to delete non existent contract", **log_attrs) else: - log.error("You need to call delete_contract_data with a flag to be sure") + self.log.error( + "You need to call delete_contract_data with a flag to be sure", + **log_attrs, + ) def delete_all_contracts_for_instrument( self, instrument_code: str, areyoureallysure=False @@ -82,20 +89,23 @@ def add_contract_data( instrument_code = contract_object.instrument_code contract_date = contract_object.date_str - log = contract_object.log(self.log) + log_attrs = {**contract_object.log_attributes(), "method": "temp"} if self.is_contract_in_data(instrument_code, contract_date): if ignore_duplication: pass else: - log.warning( + self.log.warning( "There is already %s in the data, you have to delete it first" - % (contract_object.key) + % (contract_object.key), + **log_attrs, ) return None self._add_contract_object_without_checking_for_existing_entry(contract_object) - log.info("Added contract %s %s" % (instrument_code, contract_date)) + self.log.info( + "Added contract %s %s" % (instrument_code, contract_date), **log_attrs + ) def get_list_of_contract_dates_for_instrument_code( self, instrument_code: str, allow_expired: bool = False diff --git a/sysdata/futures/futures_per_contract_prices.py b/sysdata/futures/futures_per_contract_prices.py index 828d94c5ad..fa8df20bc4 100644 --- a/sysdata/futures/futures_per_contract_prices.py +++ b/sysdata/futures/futures_per_contract_prices.py @@ -299,10 +299,11 @@ def write_merged_prices_for_contract_object( not_ignoring_duplication = not ignore_duplication if not_ignoring_duplication: if self.has_merged_price_data_for_contract(futures_contract_object): - log = futures_contract_object.log(self.log) - log.warning( + self.log.warning( "There is already existing data for %s" - % futures_contract_object.key + % futures_contract_object.key, + **futures_contract_object.log_attributes(), + method="temp", ) return None @@ -330,10 +331,11 @@ def write_prices_at_frequency_for_contract_object( if self.has_price_data_for_contract_at_frequency( contract_object=futures_contract_object, frequency=frequency ): - log = futures_contract_object.log(self.log) - log.warning( + self.log.warning( "There is already existing data for %s" - % futures_contract_object.key + % futures_contract_object.key, + **futures_contract_object.log_attributes(), + method="temp", ) return None @@ -352,10 +354,10 @@ def update_prices_at_frequency_for_contract( max_price_spike: float = VERY_BIG_NUMBER, ) -> int: - new_log = contract_object.log(self.log) + log_attrs = {**contract_object.log_attributes(), "method": "temp"} if len(new_futures_per_contract_prices) == 0: - new_log.debug("No new data") + self.log.debug("No new data", **log_attrs) return 0 if frequency is MIXED_FREQ: @@ -372,8 +374,9 @@ def update_prices_at_frequency_for_contract( ) if merged_prices is SPIKE_IN_DATA: - new_log.debug( - "Price has moved too much - will need to manually check - no price update done" + self.log.debug( + "Price has moved too much - will need to manually check - no price update done", + **log_attrs, ) return SPIKE_IN_DATA @@ -381,16 +384,17 @@ def update_prices_at_frequency_for_contract( rows_added = len(merged_prices) - len(old_prices) if rows_added < 0: - new_log.critical("Can't remove prices something gone wrong!") + self.log.critical("Can't remove prices something gone wrong!", **log_attrs) raise mergeError("Merged prices have fewer rows than old prices!") elif rows_added == 0: if len(old_prices) == 0: - new_log.debug("No existing or additional data") + self.log.debug("No existing or additional data", **log_attrs) return 0 else: - new_log.debug( - "No additional data since %s " % str(old_prices.index[-1]) + self.log.debug( + "No additional data since %s " % str(old_prices.index[-1]), + **log_attrs, ) return 0 @@ -407,7 +411,7 @@ def update_prices_at_frequency_for_contract( ignore_duplication=True, ) - new_log.debug("Added %d additional rows of data" % rows_added) + self.log.debug("Added %d additional rows of data" % rows_added) return rows_added @@ -428,8 +432,11 @@ def delete_merged_prices_for_contract_object( futures_contract_object ) else: - log = futures_contract_object.log(self.log) - log.warning("Tried to delete non existent contract") + self.log.warning( + "Tried to delete non existent contract", + **futures_contract_object.log_attributes(), + method="temp", + ) def delete_prices_at_frequency_for_contract_object( self, @@ -453,9 +460,10 @@ def delete_prices_at_frequency_for_contract_object( futures_contract_object=futures_contract_object, frequency=frequency ) else: - log = futures_contract_object.log(self.log) - log.warning( - "Tried to delete non existent contract at frequency %s" % frequency + self.log.warning( + "Tried to delete non existent contract at frequency %s" % frequency, + **futures_contract_object.log_attributes(), + method="temp", ) def delete_merged_prices_for_instrument_code( diff --git a/sysdata/futures/multiple_prices.py b/sysdata/futures/multiple_prices.py index edd3c00dec..95c6a9dca7 100644 --- a/sysdata/futures/multiple_prices.py +++ b/sysdata/futures/multiple_prices.py @@ -11,6 +11,7 @@ """ from syscore.exceptions import existingData from sysdata.base_data import baseData +from syslogging.logger import * # These are used when inferring prices in an incomplete series from sysobjects.multiple_prices import futuresMultiplePrices @@ -46,23 +47,30 @@ def get_multiple_prices(self, instrument_code: str) -> futuresMultiplePrices: return multiple_prices def delete_multiple_prices(self, instrument_code: str, are_you_sure=False): - log = self.log.setup(instrument_code=instrument_code) + log_attrs = {INSTRUMENT_CODE_LOG_LABEL: instrument_code, "method": "temp"} if are_you_sure: if self.is_code_in_data(instrument_code): self._delete_multiple_prices_without_any_warning_be_careful( instrument_code ) - log.info("Deleted multiple price data for %s" % instrument_code) + self.log.info( + "Deleted multiple price data for %s" % instrument_code, + **log_attrs, + ) else: # doesn't exist anyway - log.warning( + self.log.warning( "Tried to delete non existent multiple prices for %s" - % instrument_code + % instrument_code, + **log_attrs, ) else: - log.error("You need to call delete_multiple_prices with a flag to be sure") + self.log.error( + "You need to call delete_multiple_prices with a flag to be sure", + **log_attrs, + ) raise Exception("You need to be sure!") def is_code_in_data(self, instrument_code: str) -> bool: @@ -77,14 +85,15 @@ def add_multiple_prices( multiple_price_data: futuresMultiplePrices, ignore_duplication=False, ): - log = self.log.setup(instrument_code=instrument_code) + log_attrs = {INSTRUMENT_CODE_LOG_LABEL: instrument_code, "method": "temp"} if self.is_code_in_data(instrument_code): if ignore_duplication: pass else: - log.error( + self.log.error( "There is already %s in the data, you have to delete it first" - % instrument_code + % instrument_code, + **log_attrs, ) raise existingData @@ -92,7 +101,7 @@ def add_multiple_prices( instrument_code, multiple_price_data ) - log.info("Added data for instrument %s" % instrument_code) + self.log.info("Added data for instrument %s" % instrument_code, **log_attrs) def _add_multiple_prices_without_checking_for_existing_entry( self, instrument_code: str, multiple_price_data: futuresMultiplePrices diff --git a/sysdata/fx/spotfx.py b/sysdata/fx/spotfx.py index e8ad0f7ed0..d949dddc79 100644 --- a/sysdata/fx/spotfx.py +++ b/sysdata/fx/spotfx.py @@ -83,10 +83,11 @@ def _get_fx_prices_for_inversion(self, fx_code: str) -> fxPrices: raw_fx_data = self._get_fx_prices_vs_default(currency2) if raw_fx_data.empty: - log = self.log.setup(**{CURRENCY_CODE_LOG_LABEL: fx_code}) - log.warning( + self.log.warning( "Data for %s is missing, needed to calculate %s" - % (currency2 + DEFAULT_CURRENCY, DEFAULT_CURRENCY + currency2) + % (currency2 + DEFAULT_CURRENCY, DEFAULT_CURRENCY + currency2), + CURRENCY_CODE_LOG_LABEL=fx_code, + method="temp", ) return raw_fx_data @@ -129,8 +130,11 @@ def _get_fx_prices_vs_default(self, currency1: str) -> fxPrices: def _get_fx_prices(self, code: str) -> fxPrices: if not self.is_code_in_data(code): - log = self.log.setup(**{CURRENCY_CODE_LOG_LABEL: code}) - log.warning("Currency %s is missing from list of FX data" % code) + self.log.warning( + "Currency %s is missing from list of FX data" % code, + CURRENCY_CODE_LOG_LABEL=code, + method="temp", + ) return fxPrices.create_empty() @@ -139,18 +143,27 @@ def _get_fx_prices(self, code: str) -> fxPrices: return data def delete_fx_prices(self, code: str, are_you_sure=False): - log = self.log.setup(**{CURRENCY_CODE_LOG_LABEL: code}) + log_attrs = {CURRENCY_CODE_LOG_LABEL: code, "method": "temp"} if are_you_sure: if self.is_code_in_data(code): self._delete_fx_prices_without_any_warning_be_careful(code) - log.info("Deleted fx price data for %s" % code) + self.log.info( + "Deleted fx price data for %s" % code, + **log_attrs, + ) else: # doesn't exist anyway - log.warning("Tried to delete non existent fx prices for %s" % code) + self.log.warning( + "Tried to delete non existent fx prices for %s" % code, + **log_attrs, + ) else: - log.warning("You need to call delete_fx_prices with a flag to be sure") + self.log.warning( + "You need to call delete_fx_prices with a flag to be sure", + **log_attrs, + ) def is_code_in_data(self, code: str) -> bool: if code in self.get_list_of_fxcodes(): @@ -161,19 +174,20 @@ def is_code_in_data(self, code: str) -> bool: def add_fx_prices( self, code: str, fx_price_data: fxPrices, ignore_duplication: bool = False ): - log = self.log.setup(**{CURRENCY_CODE_LOG_LABEL: code}) + log_attrs = {CURRENCY_CODE_LOG_LABEL: code, "method": "temp"} if self.is_code_in_data(code): if ignore_duplication: pass else: - log.warning( - "There is already %s in the data, you have to delete it first, or set ignore_duplication=True, or use update_fx_prices" - % code + self.log.warning( + "There is already %s in the data, you have to delete it first, or " + "set ignore_duplication=True, or use update_fx_prices" % code, + **log_attrs, ) return None self._add_fx_prices_without_checking_for_existing_entry(code, fx_price_data) - log.info("Added fx data for code %s" % code) + self.log.info("Added fx data for code %s" % code, **log_attrs) def update_fx_prices( self, code: str, new_fx_prices: fxPrices, check_for_spike=True @@ -185,7 +199,7 @@ def update_fx_prices( :param new_fx_prices: fxPrices object :return: int, number of rows added """ - log = self.log.setup(**{CURRENCY_CODE_LOG_LABEL: code}) + log_attrs = {CURRENCY_CODE_LOG_LABEL: code, "method": "temp"} old_fx_prices = self.get_fx_prices(code) merged_fx_prices = old_fx_prices.add_rows_to_existing_data( @@ -199,18 +213,22 @@ def update_fx_prices( if rows_added == 0: if len(old_fx_prices) == 0: - log.debug("No new or old prices for %s" % code) + self.log.debug("No new or old prices for %s" % code, **log_attrs) else: - log.debug( + self.log.debug( "No additional data since %s for %s" - % (str(old_fx_prices.index[-1]), code) + % (str(old_fx_prices.index[-1]), code), + **log_attrs, ) return 0 self.add_fx_prices(code, merged_fx_prices, ignore_duplication=True) - log.debug("Added %d additional rows for %s" % (rows_added, code)) + self.log.debug( + "Added %d additional rows for %s" % (rows_added, code), + **log_attrs, + ) return rows_added diff --git a/sysdata/sim/sim_data.py b/sysdata/sim/sim_data.py index 0855134eff..dc9d7ae4ea 100644 --- a/sysdata/sim/sim_data.py +++ b/sysdata/sim/sim_data.py @@ -71,6 +71,7 @@ def system_init(self, base_system: "System"): """ # inherit the log + # TODO log.setup self._log = base_system.log.setup(stage="data") self._parent = base_system diff --git a/sysexecution/algos/algo.py b/sysexecution/algos/algo.py index 86125e5a01..4bf7624ca9 100644 --- a/sysexecution/algos/algo.py +++ b/sysexecution/algos/algo.py @@ -85,7 +85,6 @@ def get_and_submit_broker_order_for_contract_order( broker_account: str = arg_not_supplied, ): - log = contract_order.log_with_attributes(self.data.log) broker = self.data_broker.get_broker_name() if broker_account is arg_not_supplied: @@ -129,9 +128,11 @@ def get_and_submit_broker_order_for_contract_order( limit_price=limit_price, ) - log.debug( + self.data.log.debug( "Created a broker order %s (not yet submitted or written to local DB)" - % str(broker_order) + % str(broker_order), + **contract_order.log_attributes(), + method="temp", ) placed_broker_order_with_controls = self.data_broker.submit_broker_order( @@ -139,12 +140,17 @@ def get_and_submit_broker_order_for_contract_order( ) if placed_broker_order_with_controls is missing_order: - log.warning("Order could not be submitted") + self.data.log.warning( + "Order could not be submitted", + **contract_order.log_attributes(), + method="temp", + ) return missing_order - log = placed_broker_order_with_controls.order.log_with_attributes(log) - log.debug( - "Submitted order to IB %s" % str(placed_broker_order_with_controls.order) + self.data.log.debug( + "Submitted order to IB %s" % str(placed_broker_order_with_controls.order), + **placed_broker_order_with_controls.order.log_attributes(), + method="temp", ) placed_broker_order_with_controls.add_or_replace_ticker(ticker_object) @@ -158,7 +164,6 @@ def get_market_data_for_order_modifies_ticker_object( # to provide a benchmark for execution purposes # (optionally) to set limit prices ## - log = contract_order.log_with_attributes(self.data.log) # Get the first 'reference' tick try: @@ -168,9 +173,11 @@ def get_market_data_for_order_modifies_ticker_object( ) ) except missingData: - log.warning( + self.data.log.warning( "Can't get market data for %s so not trading with limit order %s" - % (contract_order.instrument_code, str(contract_order)) + % (contract_order.instrument_code, str(contract_order)), + **contract_order.log_attributes(), + method="temp", ) raise @@ -225,10 +232,11 @@ def round_limit_price_to_tick_size( try: min_tick = self.data_broker.get_min_tick_size_for_contract(contract) except missingContract: - log = contract_order.log_with_attributes(self.data.log) - log.warning( + self.data.log.warning( "Couldn't find min tick size for %s, not rounding limit price %f" - % (str(contract), limit_price) + % (str(contract), limit_price), + **contract_order.log_attributes(), + method="temp", ) return limit_price diff --git a/sysexecution/algos/algo_market.py b/sysexecution/algos/algo_market.py index 6197b6ac5c..904a7cb328 100644 --- a/sysexecution/algos/algo_market.py +++ b/sysexecution/algos/algo_market.py @@ -45,10 +45,13 @@ def manage_trade( def prepare_and_submit_trade(self): contract_order = self.contract_order - log = contract_order.log_with_attributes(self.data.log) + log_attrs = {**contract_order.log_attributes(), "method": "temp"} if contract_order.panic_order: - log.debug("PANIC ORDER! DON'T RESIZE AND DO ENTIRE TRADE") + self.data.log.debug( + "PANIC ORDER! DON'T RESIZE AND DO ENTIRE TRADE", + **log_attrs, + ) cut_down_contract_order = copy(contract_order) else: cut_down_contract_order = contract_order.reduce_trade_size_proportionally_so_smallest_leg_is_max_size( @@ -56,9 +59,10 @@ def prepare_and_submit_trade(self): ) if cut_down_contract_order.trade != contract_order.trade: - log.debug( + self.data.log.debug( "Cut down order to size %s from %s because of algo size limit" - % (str(contract_order.trade), str(cut_down_contract_order.trade)) + % (str(contract_order.trade), str(cut_down_contract_order.trade)), + **log_attrs, ) order_type = self.order_type_to_use @@ -77,6 +81,7 @@ def order_type_to_use(self) -> brokerOrderType: def manage_live_trade( self, broker_order_with_controls: orderWithControls ) -> orderWithControls: + # TODO log_with_attributes log = broker_order_with_controls.order.log_with_attributes(self.data.log) data_broker = self.data_broker diff --git a/sysexecution/algos/algo_original_best.py b/sysexecution/algos/algo_original_best.py index 1b8a02646c..99c4e17a78 100644 --- a/sysexecution/algos/algo_original_best.py +++ b/sysexecution/algos/algo_original_best.py @@ -84,6 +84,7 @@ def prepare_and_submit_trade(self) -> orderWithControls: data = self.data contract_order = self.contract_order + # TODO log_with_attributes log = contract_order.log_with_attributes(data.log) ## check order type is 'best' not 'limit' or 'market' @@ -148,6 +149,7 @@ def manage_live_trade( ) -> orderWithControls: data = self.data + # TODO log_with_attributes log = broker_order_with_controls_and_order_id.order.log_with_attributes( data.log ) @@ -220,7 +222,7 @@ def manage_live_trade( return broker_order_with_controls_and_order_id -def limit_trade_viable( +def limit_trade_viable( # TODO passed logger instance data: dataBlob, order: contractOrder, ticker_object: tickerObject, log: pst_logger ) -> bool: @@ -248,7 +250,7 @@ def limit_trade_viable( no_need_to_switch = "_NO_NEED_TO_SWITCH" -def file_log_report( +def file_log_report( # TODO passed logger instance log, is_aggressive: bool, broker_order_with_controls: orderWithControls ): limit_trade = broker_order_with_controls.order.order_type == limit_order_type diff --git a/sysexecution/algos/allocate_algo_to_order.py b/sysexecution/algos/allocate_algo_to_order.py index 17ed31fbae..cd628fa88f 100644 --- a/sysexecution/algos/allocate_algo_to_order.py +++ b/sysexecution/algos/allocate_algo_to_order.py @@ -82,7 +82,7 @@ def check_and_if_required_allocate_algo_to_single_contract_order( ) -> contractOrder: config = get_algo_allocation_config(data) - log = contract_order.log_with_attributes(data.log) + log_attrs = {**contract_order.log_attributes(), "method": "temp"} if already_has_algo_allocated(contract_order): # Already done @@ -100,7 +100,10 @@ def check_and_if_required_allocate_algo_to_single_contract_order( contract_order=contract_order, config=config ) elif instrument_order_type == market_order_type: - log.debug("Market order type, so allocating to algo_market") + data.log.debug( + "Market order type, so allocating to algo_market", + **log_attrs, + ) contract_order = allocate_market_algo( contract_order=contract_order, config=config ) @@ -119,12 +122,16 @@ def check_and_if_required_allocate_algo_to_single_contract_order( ) elif instrument_order_type == balance_order_type: - log.critical("Balance orders aren't executed, shouldn't even be here!") + data.log.critical( + "Balance orders aren't executed, shouldn't even be here!", + **log_attrs, + ) return missing_order else: - log.warning( + data.log.warning( "Don't recognise order type %s so allocating to default %s" - % (instrument_order_type, config.default_algo) + % (instrument_order_type, config.default_algo), + **log_attrs, ) contract_order = allocate_default_algo( contract_order=contract_order, config=config @@ -170,9 +177,11 @@ def allocate_for_best_execution_no_limit( data: dataBlob, config: AlgoConfig, contract_order: contractOrder ) -> contractOrder: # in the future could be randomized... - log = contract_order.log_with_attributes(data.log) - - log.debug("'Best' order so allocating to original_best") + data.log.debug( + "'Best' order so allocating to original_best", + **contract_order.log_attributes(), + method="temp", + ) contract_order.algo_to_use = config.best_algo return contract_order @@ -182,8 +191,11 @@ def allocate_for_limit_order( data: dataBlob, config: AlgoConfig, contract_order: contractOrder ) -> contractOrder: # in the future could be randomized... - log = contract_order.log_with_attributes(data.log) - log.debug("Allocating to limit order") + data.log.debug( + "Allocating to limit order", + **contract_order.log_attributes(), + method="temp", + ) contract_order.algo_to_use = config.limit_order_algo return contract_order diff --git a/sysexecution/algos/common_functions.py b/sysexecution/algos/common_functions.py index 513a1987af..5f785516a8 100644 --- a/sysexecution/algos/common_functions.py +++ b/sysexecution/algos/common_functions.py @@ -34,7 +34,7 @@ def cancel_order( data: dataBlob, broker_order_with_controls: orderWithControls ) -> orderWithControls: - log = broker_order_with_controls.order.log_with_attributes(data.log) + log_attrs = {**broker_order_with_controls.order.log_attributes(), "method": "temp"} data_broker = dataBroker(data) data_broker.cancel_order_given_control_object(broker_order_with_controls) @@ -47,10 +47,13 @@ def cancel_order( broker_order_with_controls ) if is_cancelled: - log.debug("Cancelled order") + data.log.debug("Cancelled order", **log_attrs) break if timer.finished: - log.warning("Ran out of time to cancel order - may cause weird behaviour!") + data.log.warning( + "Ran out of time to cancel order - may cause weird behaviour!", + **log_attrs, + ) break return broker_order_with_controls @@ -62,7 +65,7 @@ def set_limit_price( new_limit_price: float, ): - log = broker_order_with_controls.order.log_with_attributes(data.log) + log_attrs = {**broker_order_with_controls.order.log_attributes(), "method": "temp"} data_broker = dataBroker(data) try: @@ -71,9 +74,15 @@ def set_limit_price( broker_order_with_controls, new_limit_price ) ) - log.debug("Tried to change limit price to %f" % new_limit_price) + data.log.debug( + "Tried to change limit price to %f" % new_limit_price, + **log_attrs, + ) except orderCannotBeModified as error: - log.debug("Can't modify limit price for order, error %s" % str(error)) + data.log.debug( + "Can't modify limit price for order, error %s" % str(error), + **log_attrs, + ) return broker_order_with_controls @@ -105,6 +114,7 @@ def check_current_limit_price_at_inside_spread( return new_limit_price +# TODO passed logger instance def file_log_report_market_order(log, broker_order_with_controls: orderWithControls): ticker_object = broker_order_with_controls.ticker diff --git a/sysexecution/order_stacks/contract_order_stack.py b/sysexecution/order_stacks/contract_order_stack.py index 8573c6505d..c83dbdfb0f 100644 --- a/sysexecution/order_stacks/contract_order_stack.py +++ b/sysexecution/order_stacks/contract_order_stack.py @@ -33,13 +33,16 @@ def add_controlling_algo_ref(self, order_id: int, control_algo_ref: str): modified_order.add_controlling_algo_ref(control_algo_ref) self._change_order_on_stack(order_id, modified_order) except Exception as e: - log = existing_order.log_with_attributes(self.log) error_msg = "%s couldn't add controlling algo %s to order %d" % ( str(e), control_algo_ref, order_id, ) - log.warning(error_msg) + self.log.warning( + error_msg, + **existing_order.log_attributes(), + method="temp", + ) raise Exception(error_msg) def release_order_from_algo_control(self, order_id: int): @@ -60,12 +63,15 @@ def release_order_from_algo_control(self, order_id: int): modified_order.release_order_from_algo_control() self._change_order_on_stack(order_id, modified_order) except Exception as e: - log = existing_order.log_with_attributes(self.log) error_msg = "%s couldn't remove controlling algo from order %d" % ( str(e), order_id, ) - log.warning(error_msg) + self.log.warning( + error_msg, + **existing_order.log_attributes(), + method="temp", + ) raise Exception(error_msg) def get_order_with_id_from_stack(self, order_id: int) -> contractOrder: diff --git a/sysexecution/order_stacks/instrument_order_stack.py b/sysexecution/order_stacks/instrument_order_stack.py index 7cb007c54d..3242f6eca8 100644 --- a/sysexecution/order_stacks/instrument_order_stack.py +++ b/sysexecution/order_stacks/instrument_order_stack.py @@ -94,14 +94,16 @@ def _put_new_order_on_stack_when_no_existing_order( ) -> int: # no current order for this instrument/strategy - log = new_order.log_with_attributes(self.log) + log_attrs = {**new_order.log_attributes(), "method": "temp"} if new_order.is_zero_trade() and not allow_zero_orders: log_msg = "Zero orders not allowed" - log.debug(log_msg) + self.log.debug(log_msg, **log_attrs) raise zeroOrderException(log_msg) - log.debug("New order %s putting on %s" % (str(new_order), str(self))) + self.log.debug( + "New order %s putting on %s" % (str(new_order), str(self)), **log_attrs + ) order_id = self._put_order_on_stack_and_get_order_id(new_order) @@ -119,6 +121,7 @@ def _put_adjusting_order_on_stack( :param new_order: :return: """ + # TODO log_with_attributes log = new_order.log_with_attributes(self.log) existing_orders = listOfOrders( @@ -145,7 +148,7 @@ def _put_adjusting_order_on_stack( return order_id -def calculate_adjusted_order_given_existing_orders( +def calculate_adjusted_order_given_existing_orders( # TODO passed logger instance new_order: instrumentOrder, existing_orders: listOfOrders, log ): diff --git a/sysexecution/order_stacks/order_stack.py b/sysexecution/order_stacks/order_stack.py index b53345dab7..b8231dd24e 100644 --- a/sysexecution/order_stacks/order_stack.py +++ b/sysexecution/order_stacks/order_stack.py @@ -88,14 +88,15 @@ def put_list_of_orders_on_stack( list_of_order_ids = [] for order in list_of_orders: - log = order.log_with_attributes(self.log) order.lock_order() try: order_id = self.put_order_on_stack(order) except Exception as e: - log.warning( + self.log.warning( "Failed to put order %s on stack error %s, rolling back entire transaction" - % (str(order), str(e)) + % (str(order), str(e)), + **order.log_attributes(), + method="temp", ) # rollback any orders we did manage to add @@ -255,15 +256,17 @@ def add_children_to_order_without_existing_children( self.log.warning(error_msg) raise missingOrder(error_msg) - log = existing_order.log_with_attributes(self.log) - already_have_children = not existing_order.no_children() if already_have_children: error_msg = ( "Can't add children to order that already has children %s" % str(existing_order.children) ) - log.warning(error_msg) + self.log.warning( + error_msg, + **existing_order.log_attributes(), + method="temp", + ) raise Exception(error_msg) new_order = copy(existing_order) @@ -319,7 +322,7 @@ def change_fill_quantity_for_order( # nout to do here, fills are cumulative return None - log = existing_order.log_with_attributes(self.log) + log_attrs = {**existing_order.log_attributes(), "method": "temp"} new_order = copy(existing_order) try: @@ -327,14 +330,15 @@ def change_fill_quantity_for_order( fill_qty, filled_price=filled_price, fill_datetime=fill_datetime ) except overFilledOrder as e: - log.warning(str(e)) + self.log.warning(str(e), **log_attrs) raise overFilledOrder(e) self._change_order_on_stack(order_id, new_order) - log.debug( + self.log.debug( "Changed fill qty from %s to %s for order %s" - % (str(existing_order.fill), str(fill_qty), str(existing_order)) + % (str(existing_order.fill), str(fill_qty), str(existing_order)), + **log_attrs, ) def zero_out(self, order_id: int): @@ -346,11 +350,13 @@ def zero_out(self, order_id: int): self.log.warning(error_msg) raise missingOrder(error_msg) - log = existing_order.log_with_attributes(existing_order) - if not existing_order.active: # already inactive - log.warning("Can't zero out order which is already inactive") + self.log.warning( + "Can't zero out order which is already inactive", + **existing_order.log_attributes(), + method="temp", + ) return None new_order = copy(existing_order) @@ -368,8 +374,6 @@ def deactivate_order(self, order_id: int): self.log.warning(error_msg) raise missingOrder(error_msg) - log = existing_order.log_with_attributes(self.log) - if not existing_order.active: # already inactive return None @@ -424,20 +428,20 @@ def _change_order_on_stack( self.log.warning(error_msg) raise missingOrder(error_msg) - log = existing_order.log_with_attributes(self.log) + log_attrs = {**existing_order.log_attributes(), "method": "temp"} lock_status = existing_order.is_order_locked() if lock_status is True: # already locked can't change error_msg = "Can't change locked order %s" % str(existing_order) - log.warning(error_msg) + self.log.warning(error_msg, **log_attrs) raise Exception(error_msg) if check_if_inactive: existing_order_is_inactive = not existing_order.active if existing_order_is_inactive: error_msg = "Can't change order %s as inactive" % str(existing_order) - log.warning(error_msg) + self.log.warning(error_msg, **log_attrs) self._change_order_on_stack_no_checking(order_id, new_order) @@ -466,10 +470,11 @@ def lock_order_on_stack(self, order_id: int): def _put_order_on_stack_and_get_order_id(self, order: Order) -> int: order_has_existing_id = not order.order_id is no_order_id if order_has_existing_id: - log = order.log_with_attributes(self.log) - log.warning( + self.log.warning( "Order %s already has order ID will be ignored and allocated a new ID!" - % str(order) + % str(order), + **order.log_attributes(), + method="temp", ) order_to_add = copy(order) diff --git a/sysexecution/orders/base_orders.py b/sysexecution/orders/base_orders.py index 415cbd2d46..a4cfed5d0d 100644 --- a/sysexecution/orders/base_orders.py +++ b/sysexecution/orders/base_orders.py @@ -453,6 +453,14 @@ def log_with_attributes(self, log): return log + def log_attributes(self): + """ + Returns a dict of order log attributes + :return: dict + """ + + return {} + def resolve_inputs_to_order(trade, fill) -> (tradeQuantity, tradeQuantity): resolved_trade = tradeQuantity(trade) diff --git a/sysexecution/orders/broker_orders.py b/sysexecution/orders/broker_orders.py index de0667e484..23cf282639 100644 --- a/sysexecution/orders/broker_orders.py +++ b/sysexecution/orders/broker_orders.py @@ -360,6 +360,24 @@ def log_with_attributes(self, log): return new_log + def log_attributes(self): + """ + Returns a dict of broker_order log attributes + + :return: dict + """ + broker_order = self + return { + STRATEGY_NAME_LOG_LABEL: broker_order.strategy_name, + INSTRUMENT_CODE_LOG_LABEL: broker_order.instrument_code, + CONTRACT_ORDER_ID_LOG_LABEL: if_object_matches_return_empty_string( + broker_order.parent, no_parent + ), + BROKER_ORDER_ID_LOG_LABEL: if_object_matches_return_empty_string( + broker_order.order_id, no_order_id + ), + } + def add_execution_details_from_matched_broker_order(self, matched_broker_order): fill_qty_okay = self.trade.fill_less_than_or_equal_to_desired_trade( matched_broker_order.fill diff --git a/sysexecution/orders/contract_orders.py b/sysexecution/orders/contract_orders.py index 83b37dd05c..b7ded12780 100644 --- a/sysexecution/orders/contract_orders.py +++ b/sysexecution/orders/contract_orders.py @@ -302,6 +302,23 @@ def log_with_attributes(self, log): return new_log + def log_attributes(self): + """ + Returns a dict of contract_order log attributes + + :return: dict + """ + return { + STRATEGY_NAME_LOG_LABEL: self.strategy_name, + INSTRUMENT_CODE_LOG_LABEL: self.instrument_code, + CONTRACT_ORDER_ID_LOG_LABEL: if_object_matches_return_empty_string( + self.order_id, no_order_id + ), + INSTRUMENT_ORDER_ID_LABEL: if_object_matches_return_empty_string( + self.parent, no_parent + ), + } + @dataclass class contractOrderKeyArguments: diff --git a/sysexecution/orders/instrument_orders.py b/sysexecution/orders/instrument_orders.py index 39e4fb16d1..11f35481f8 100644 --- a/sysexecution/orders/instrument_orders.py +++ b/sysexecution/orders/instrument_orders.py @@ -254,3 +254,17 @@ def log_with_attributes(self, log): ) return new_log + + def log_attributes(self): + """ + Returns a dict of instrument_order log attributes + + :return: dict + """ + return { + STRATEGY_NAME_LOG_LABEL: self.strategy_name, + INSTRUMENT_CODE_LOG_LABEL: self.instrument_code, + INSTRUMENT_ORDER_ID_LABEL: if_object_matches_return_empty_string( + self.order_id, no_order_id + ), + } diff --git a/sysexecution/stack_handler/balance_trades.py b/sysexecution/stack_handler/balance_trades.py index 3022898dbd..6aa60f5a6c 100644 --- a/sysexecution/stack_handler/balance_trades.py +++ b/sysexecution/stack_handler/balance_trades.py @@ -14,14 +14,14 @@ class stackHandlerCreateBalanceTrades(stackHandlerForFills): def create_balance_trade(self, broker_order: brokerOrder): - log = broker_order.log_with_attributes(self.log) + log_attrs = {**broker_order.log_attributes(), "method": "temp"} contract_order = create_balance_contract_order_from_broker_order(broker_order) instrument_order = create_balance_instrument_order_from_contract_order( contract_order ) - log.debug("Putting balancing trades on stacks") + self.log.debug("Putting balancing trades on stacks", **log_attrs) try: self.put_balance_trades_on_stack( @@ -30,7 +30,7 @@ def create_balance_trade(self, broker_order: brokerOrder): except failureWithRollback: return None - log.debug("Updating positions") + self.log.debug("Updating positions", **log_attrs) self.apply_position_change_to_stored_contract_positions( contract_order, contract_order.fill, apply_entire_trade=True ) @@ -38,7 +38,10 @@ def create_balance_trade(self, broker_order: brokerOrder): instrument_order, instrument_order.fill, apply_entire_trade=True ) - log.debug("Marking balancing trades as completed and historic order data") + self.log.debug( + "Marking balancing trades as completed and historic order data", + **log_attrs, + ) self.handle_completed_instrument_order( instrument_order.order_id, treat_inactive_as_complete=True ) @@ -49,8 +52,8 @@ def put_balance_trades_on_stack( contract_order: contractOrder, broker_order: brokerOrder, ): - log = instrument_order.log_with_attributes(self.log) - log.debug("Putting balancing trades on stacks") + log_attrs = {**instrument_order.log_attributes(), "method": "temp"} + self.log.debug("Putting balancing trades on stacks", **log_attrs) try: instrument_order_id = ( @@ -59,20 +62,22 @@ def put_balance_trades_on_stack( ) ) except Exception as e: - log.error( - "Couldn't add balancing instrument trade error condition %s" % str(e) + self.log.error( + "Couldn't add balancing instrument trade error condition %s" % str(e), + **log_attrs, ) - log.error("Nothing to roll back") + self.log.error("Nothing to roll back", **log_attrs) raise failureWithRollback from e try: contract_order.parent = instrument_order_id contract_order_id = self.contract_stack.put_order_on_stack(contract_order) except Exception as e: - log.error( - "Couldn't add balancing contract trade error condition %s " % str(e) + self.log.error( + "Couldn't add balancing contract trade error condition %s " % str(e), + **log_attrs, ) - log.error("Rolling back") + self.log.error("Rolling back", **log_attrs) self.rollback_balance_trades( instrument_order_id, missing_order, missing_order ) @@ -84,8 +89,11 @@ def put_balance_trades_on_stack( ) except Exception as e: - log.error("Couldn't add children to instrument order error %s" % str(e)) - log.error("Rolling back") + self.log.error( + "Couldn't add children to instrument order error %s" % str(e), + **log_attrs, + ) + self.log.error("Rolling back", **log_attrs) self.rollback_balance_trades( instrument_order_id, contract_order_id, missing_order ) @@ -95,8 +103,11 @@ def put_balance_trades_on_stack( try: broker_order_id = self.broker_stack.put_order_on_stack(broker_order) except Exception as e: - log.error("Couldn't add balancing broker trade error condition %s" % str(e)) - log.error("Rolling back") + self.log.error( + "Couldn't add balancing broker trade error condition %s" % str(e), + **log_attrs, + ) + self.log.error("Rolling back", **log_attrs) self.rollback_balance_trades( instrument_order_id, contract_order_id, missing_order ) @@ -107,8 +118,11 @@ def put_balance_trades_on_stack( contract_order_id, [broker_order_id] ) except Exception as e: - log.error("Couldn't add children to contract order exception %s" % str(e)) - log.error("Rolling back") + self.log.error( + "Couldn't add children to contract order exception %s" % str(e), + **log_attrs, + ) + self.log.error("Rolling back", **log_attrs) self.rollback_balance_trades( instrument_order_id, contract_order_id, broker_order_id ) @@ -117,7 +131,7 @@ def put_balance_trades_on_stack( contract_order.order_id = contract_order_id instrument_order.order_id = instrument_order_id - log.debug("All balancing trades added to stacks") + self.log.debug("All balancing trades added to stacks", **log_attrs) def rollback_balance_trades( self, instrument_order_id: int, contract_order_id: int, broker_order_id: int @@ -131,8 +145,8 @@ def rollback_balance_trades( self.broker_stack.remove_order_with_id_from_stack(broker_order_id) def create_balance_instrument_trade(self, instrument_order: instrumentOrder): - log = instrument_order.log_with_attributes(self.log) - log.debug("Putting balancing order on instrument stack") + log_attrs = {**instrument_order.log_attributes(), "method": "temp"} + self.log.debug("Putting balancing order on instrument stack", **log_attrs) instrument_order_id = ( self.instrument_stack.put_manual_order_on_stack_and_return_order_id( instrument_order @@ -141,8 +155,9 @@ def create_balance_instrument_trade(self, instrument_order: instrumentOrder): instrument_order.order_id = instrument_order_id - log.debug( - "Marking balancing trades as completed and updating positions and historic order data" + self.log.debug( + "Marking balancing trades as completed and updating positions and historic order data", + **log_attrs, ) self.apply_position_change_to_instrument( instrument_order, instrument_order.fill, apply_entire_trade=True diff --git a/sysexecution/stack_handler/cancel_and_modify.py b/sysexecution/stack_handler/cancel_and_modify.py index 1615544620..6d622897d6 100644 --- a/sysexecution/stack_handler/cancel_and_modify.py +++ b/sysexecution/stack_handler/cancel_and_modify.py @@ -65,8 +65,11 @@ def cancel_broker_order_with_id_and_return_order( # no need to cancel return missing_order - log = broker_order.log_with_attributes(self.log) - log.debug("Cancelling order on stack with broker %s" % str(broker_order)) + self.log.debug( + "Cancelling order on stack with broker %s" % str(broker_order), + **broker_order.log_attributes(), + method="temp", + ) data_broker = self.data_broker data_broker.cancel_order_on_stack(broker_order) @@ -101,9 +104,12 @@ def list_of_orders_not_yet_cancelled( order_is_cancelled = True if order_is_cancelled: - log = broker_order.log_with_attributes(self.log) new_list_of_orders.remove(broker_order) - log.debug("Order %s succesfully cancelled" % broker_order) + self.log.debug( + "Order %s succesfully cancelled" % broker_order, + **broker_order.log_attributes(), + method="temp", + ) new_list_of_orders = listOfOrders(new_list_of_orders) @@ -118,8 +124,9 @@ def check_order_cancelled(self, broker_order: brokerOrder) -> bool: def critical_cancel_log(self, list_of_broker_orders: listOfOrders): for broker_order in list_of_broker_orders: - log = broker_order.log_with_attributes(self.log) - log.critical( - "Broker order %s could not be cancelled within time limit; might be a position break" - % broker_order + self.log.critical( + "Broker order %s could not be cancelled within time limit; might be a " + "position break" % broker_order, + **broker_order.log_attributes(), + method="temp", ) diff --git a/sysexecution/stack_handler/create_broker_orders_from_contract_orders.py b/sysexecution/stack_handler/create_broker_orders_from_contract_orders.py index 02b3fa39ef..731c681daa 100644 --- a/sysexecution/stack_handler/create_broker_orders_from_contract_orders.py +++ b/sysexecution/stack_handler/create_broker_orders_from_contract_orders.py @@ -159,7 +159,6 @@ def size_contract_order( def apply_trade_limits_to_contract_order( self, proposed_order: contractOrder ) -> contractOrder: - log = proposed_order.log_with_attributes(self.log) data_trade_limits = dataTradeLimits(self.data) instrument_strategy = proposed_order.instrument_strategy @@ -178,13 +177,15 @@ def apply_trade_limits_to_contract_order( ) if contract_order_after_trade_limits.trade != proposed_order.trade: - log.debug( + self.log.debug( "%s trade change from %s to %s because of trade limits" % ( proposed_order.key, str(proposed_order.trade), str(contract_order_after_trade_limits.trade), - ) + ), + **proposed_order.log_attributes(), + method="temp", ) return contract_order_after_trade_limits @@ -194,7 +195,6 @@ def liquidity_size_contract_order( ) -> contractOrder: data_broker = self.data_broker - log = contract_order_after_trade_limits.log_with_attributes(self.log) # check liquidity, and if necessary carve up order # Note for spread orders we check liquidity in the component markets @@ -205,9 +205,11 @@ def liquidity_size_contract_order( ) if liquid_qty != contract_order_after_trade_limits.trade: - log.debug( + self.log.debug( "Cut down order to size %s from %s because of liquidity" - % (str(liquid_qty), str(contract_order_after_trade_limits.trade)) + % (str(liquid_qty), str(contract_order_after_trade_limits.trade)), + **contract_order_after_trade_limits.log_attributes(), + method="temp", ) if liquid_qty.equals_zero(): @@ -223,7 +225,6 @@ def send_to_algo( self, contract_order_to_trade: contractOrder ) -> (Algo, orderWithControls): - log = contract_order_to_trade.log_with_attributes(self.log) instrument_order = self.get_parent_of_contract_order(contract_order_to_trade) contract_order_to_trade_with_algo_set = ( @@ -234,12 +235,14 @@ def send_to_algo( ) ) - log.debug( + self.log.debug( "Sending order %s to algo %s" % ( str(contract_order_to_trade_with_algo_set), contract_order_to_trade_with_algo_set.algo_to_use, - ) + ), + **contract_order_to_trade.log_attributes(), + method="temp", ) algo_class_to_call = self.add_controlling_algo_to_order( @@ -298,7 +301,6 @@ def add_trade_to_database( broker_order = broker_order_with_controls_and_order_id.order - log = broker_order.log_with_attributes(self.log) try: broker_order_id = self.broker_stack.put_order_on_stack(broker_order) except Exception as e: @@ -309,7 +311,7 @@ def add_trade_to_database( "Created a broker order %s but can't add it to the order stack!! (condition %s) STACK CORRUPTED" % (str(broker_order), str(e)) ) - log.critical(error_msg) + self.log.critical(error_msg, **broker_order.log_attributes(), method="temp") raise Exception(error_msg) # set order_id (wouldn't have had one before, might be done inside db adding but make explicit) diff --git a/sysexecution/stack_handler/fills.py b/sysexecution/stack_handler/fills.py index dccc0ff643..0d23245936 100644 --- a/sysexecution/stack_handler/fills.py +++ b/sysexecution/stack_handler/fills.py @@ -58,10 +58,11 @@ def apply_broker_fill_from_broker_to_broker_database(self, broker_order_id: int) ) if matched_broker_order is missing_order: - log = db_broker_order.log_with_attributes(self.log) - log.warning( + self.log.warning( "Order in database %s does not match any broker orders: can't fill" - % db_broker_order + % db_broker_order, + **db_broker_order.log_attributes(), + method="temp", ) return None @@ -214,10 +215,11 @@ def apply_contract_fill_to_instrument_order(self, contract_order_id: int): instrument_order_id = contract_order.parent if instrument_order_id is no_parent: - log = contract_order.log_with_attributes(self.log) - log.error( + self.log.error( "No parent for contract order %s %d" - % (str(contract_order), contract_order_id) + % (str(contract_order), contract_order_id), + **contract_order.log_attributes(), + method="temp", ) return None @@ -254,7 +256,6 @@ def apply_contract_fill_to_parent_order_single_child( contract_order = self.contract_stack.get_order_with_id_from_stack( contract_order_id ) - log = contract_order.log_with_attributes(self.log) fill_for_contract = contract_order.fill filled_price = contract_order.filled_price @@ -274,9 +275,11 @@ def apply_contract_fill_to_parent_order_single_child( pass else: # A spread order that isn't flat - log.critical( + self.log.critical( "Can't handle non-flat intra-market spread orders! Instrument order %s %s" - % (str(instrument_order), str(instrument_order.order_id)) + % (str(instrument_order), str(instrument_order.order_id)), + **contract_order.log_attributes(), + method="temp", ) def apply_contract_fill_to_parent_order_multiple_children( @@ -287,8 +290,6 @@ def apply_contract_fill_to_parent_order_multiple_children( # - Leg by leg flat spread eg forced roll order: do nothing since doesn't change instrument positions # Distributed roll order eg if we are short -2 front, want to buy 3, will do +2 front +1 next - log = instrument_order.log_with_attributes(self.log) - distributed_order = self.check_to_see_if_distributed_instrument_order( list_of_contract_order_ids, instrument_order ) @@ -309,9 +310,11 @@ def apply_contract_fill_to_parent_order_multiple_children( else: # A proper spread trade across markets can't do this - log.critical( + self.log.critical( "Can't handle inter-market spread orders! Instrument order %s %s" - % (str(instrument_order), str(instrument_order.order_id)) + % (str(instrument_order), str(instrument_order.order_id)), + **instrument_order.log_attributes(), + method="temp", ) def check_to_see_if_distributed_instrument_order( diff --git a/sysexecution/stack_handler/roll_orders.py b/sysexecution/stack_handler/roll_orders.py index 2289445c54..ad0825803d 100644 --- a/sysexecution/stack_handler/roll_orders.py +++ b/sysexecution/stack_handler/roll_orders.py @@ -205,6 +205,7 @@ def add_instrument_and_list_of_contract_orders_to_stack( instrument_stack = self.instrument_stack contract_stack = self.contract_stack + # TODO log_with_attributes parent_log = instrument_order.log_with_attributes(self.log) # Do as a transaction: if everything doesn't go to plan can roll back @@ -502,9 +503,12 @@ def create_contract_roll_orders( contract_orders = create_contract_orders_outright(roll_spread_info) else: - log = instrument_order.log_with_attributes(data.log) roll_state = diag_positions.get_roll_state(instrument_code) - log.warning("Roll state %s is unexpected, might have changed" % str(roll_state)) + data.log.warning( + "Roll state %s is unexpected, might have changed" % str(roll_state), + **instrument_order.log_attributes(), + method="temp", + ) return missing_order contract_orders = allocate_algo_to_list_of_contract_orders( diff --git a/sysexecution/stack_handler/spawn_children_from_instrument_orders.py b/sysexecution/stack_handler/spawn_children_from_instrument_orders.py index 54db138d70..346c5c8e44 100644 --- a/sysexecution/stack_handler/spawn_children_from_instrument_orders.py +++ b/sysexecution/stack_handler/spawn_children_from_instrument_orders.py @@ -64,8 +64,11 @@ def spawn_children_from_instrument_order_id(self, instrument_order_id: int): self.data, instrument_order ) - log = instrument_order.log_with_attributes(self.log) - log.debug("List of contract orders spawned %s" % str(list_of_contract_orders)) + self.log.debug( + "List of contract orders spawned %s" % str(list_of_contract_orders), + **instrument_order.log_attributes(), + method="temp", + ) self.add_children_to_stack_and_child_id_to_parent( self.instrument_stack, @@ -82,6 +85,7 @@ def add_children_to_stack_and_child_id_to_parent( list_of_child_orders: listOfOrders, ): + # TODO log_with_attributes parent_log = parent_order.log_with_attributes(self.log) list_of_child_ids = put_children_on_stack( @@ -232,6 +236,7 @@ def get_required_contract_trade_for_instrument( :return: tuple: list of child orders: each is a tuple: contract str or missing_contract, trade int """ instrument_code = instrument_order.instrument_code + # TODO log_with_attributes log = instrument_order.log_with_attributes(data.log) trade = instrument_order.as_single_trade_qty_or_error() @@ -294,7 +299,7 @@ def get_required_contract_trade_for_instrument( return [] -def child_order_in_priced_contract_only( +def child_order_in_priced_contract_only( # TODO passed logger instance data: dataBlob, instrument_order: instrumentOrder, log ): diag_contracts = dataContracts(data) @@ -313,7 +318,7 @@ def passive_roll_child_order( instrument_order: instrumentOrder, ) -> list: - log = instrument_order.log_with_attributes(data.log) + log_attrs = {**instrument_order.log_attributes(), "method": "temp"} diag_positions = diagPositions(data) instrument_code = instrument_order.instrument_code trade = instrument_order.trade @@ -330,9 +335,10 @@ def passive_roll_child_order( if position_current_contract == 0: # Passive roll and no position in the current contract, start trading # the next contract - log.debug( + data.log.debug( "Passive roll handling order %s, no position in current contract, entire trade in next contract %s" - % (str(instrument_order), next_contract) + % (str(instrument_order), next_contract), + **log_attrs, ) return [contractIdAndTrade(next_contract, trade)] @@ -343,9 +349,10 @@ def passive_roll_child_order( if increasing_trade: # Passive roll and increasing trade # Do it all in next contract - log.debug( + data.log.debug( "Passive roll handling order %s, increasing trade, entire trade in next contract %s" - % (str(instrument_order), next_contract) + % (str(instrument_order), next_contract), + **log_attrs, ) return [contractIdAndTrade(next_contract, trade)] @@ -356,18 +363,20 @@ def passive_roll_child_order( ) if new_position == 0 or sign_of_position_is_unchanged: # A reducing trade that we can do entirely in the current contract - log.debug( + data.log.debug( "Passive roll handling order %s, reducing trade, entire trade in next contract %s" - % (str(instrument_order), next_contract) + % (str(instrument_order), next_contract), + **log_attrs, ) return [contractIdAndTrade(current_contract, trade)] # OKAY to recap: it's a passive roll, but the trade will be split between # current and next - log.debug( + data.log.debug( "Passive roll handling order %s, reducing trade, split trade between contract %s and %s" - % (str(instrument_order), current_contract, next_contract) + % (str(instrument_order), current_contract, next_contract), + **log_attrs, ) return passive_trade_split_over_two_contracts( @@ -550,15 +559,16 @@ def add_reference_price_to_a_direct_child_order( data, child_order, contract_to_match, price_to_adjust ) except missingData: - log = instrument_order.log_with_attributes(data.log) - log.warning( + data.log.warning( "Couldn't adjust reference price for order %s child %s going from %s to %s, can't do TCA" % ( str(instrument_order), str(child_order), contract_to_match, child_order.contract_date, - ) + ), + **instrument_order.log_attributes(), + method="temp", ) return child_order @@ -624,10 +634,11 @@ def calculate_limit_prices_for_direct_child_orders( child_order is missing_order for child_order in list_of_contract_orders ] if any(flag_missing_orders): - log = instrument_order.log_with_attributes(data.log) - log.critical( + data.log.critical( "Couldn't adjust limit price for at least one child order %s: can't execute any child orders" - % str(instrument_order) + % str(instrument_order), + **instrument_order.log_attributes(), + method="temp", ) return listOfOrders([]) @@ -661,15 +672,16 @@ def add_limit_price_to_a_direct_child_order( except missingData: # This is a serious problem # We can't possibly execute any part of the parent order - log = instrument_order.log_with_attributes(data.log) - log.critical( + data.log.critical( "Couldn't adjust limit price for order %s child %s going from %s to %s" % ( str(instrument_order), str(child_order), contract_to_match, child_order.contract_date, - ) + ), + **instrument_order.log_attributes(), + method="temp", ) return missing_order diff --git a/sysexecution/stack_handler/stackHandlerCore.py b/sysexecution/stack_handler/stackHandlerCore.py index 7f7c6b83ec..f145c988b2 100644 --- a/sysexecution/stack_handler/stackHandlerCore.py +++ b/sysexecution/stack_handler/stackHandlerCore.py @@ -95,7 +95,7 @@ def update_prices(self) -> updatePrices: return update_prices -def put_children_on_stack( +def put_children_on_stack( # TODO passed logger instance child_stack: orderStackData, parent_order: Order, list_of_child_orders: listOfOrders, @@ -123,7 +123,7 @@ def put_children_on_stack( return list_of_child_ids -def add_children_to_parent_or_rollback_children( +def add_children_to_parent_or_rollback_children( # TODO passed logger instance parent_order: Order, list_of_child_ids: list, parent_stack: orderStackData, @@ -152,7 +152,7 @@ def add_children_to_parent_or_rollback_children( return success -def log_successful_adding( +def log_successful_adding( # TODO passed logger instance list_of_child_orders: listOfOrders, list_of_child_ids: list, parent_order: Order, @@ -160,6 +160,7 @@ def log_successful_adding( ): for child_order, child_id in zip(list_of_child_orders, list_of_child_ids): + # TODO log_with_attributes child_log = child_order.log_with_attributes(parent_log) child_log.debug( "Put child order %s on stack with ID %d from parent order %s" diff --git a/sysexecution/strategies/classic_buffered_positions.py b/sysexecution/strategies/classic_buffered_positions.py index 9bd0ff6613..e563b464c1 100644 --- a/sysexecution/strategies/classic_buffered_positions.py +++ b/sysexecution/strategies/classic_buffered_positions.py @@ -179,8 +179,7 @@ def trade_given_optimal_and_actual_positions( reference_datetime=ref_date, ) - log = order_required.log_with_attributes(data.log) - log.debug( + data.log.debug( "Upper %.2f Lower %.2f Current %d Required position %d Required trade %d Reference price %f for contract %s" % ( upper_for_instrument, @@ -190,7 +189,9 @@ def trade_given_optimal_and_actual_positions( trade_required, reference_price, reference_contract, - ) + ), + **order_required.log_attributes(), + method="temp", ) return order_required diff --git a/sysexecution/strategies/dynamic_optimised_positions.py b/sysexecution/strategies/dynamic_optimised_positions.py index d70bae364e..b81b333ec4 100644 --- a/sysexecution/strategies/dynamic_optimised_positions.py +++ b/sysexecution/strategies/dynamic_optimised_positions.py @@ -741,8 +741,7 @@ def trade_given_optimal_and_actual_positions( reference_datetime=reference_date, ) - log = order_required.log_with_attributes(data.log) - log.debug( + data.log.debug( "Current %d Required position %d Required trade %d Reference price %f for contract %s" % ( current_position, @@ -750,7 +749,9 @@ def trade_given_optimal_and_actual_positions( trade_required, reference_price, reference_contract, - ) + ), + **order_required.log_attributes(), + method="temp", ) return order_required diff --git a/sysexecution/strategies/strategy_order_handling.py b/sysexecution/strategies/strategy_order_handling.py index 36ea397274..b3746cc98c 100644 --- a/sysexecution/strategies/strategy_order_handling.py +++ b/sysexecution/strategies/strategy_order_handling.py @@ -132,15 +132,16 @@ def apply_overrides_for_instrument_and_strategy( revised_order = override.apply_override(original_position, proposed_order) if revised_order.trade != proposed_order.trade: - log = proposed_order.log_with_attributes(self.log) - log.debug( + self.log.debug( "%s trade change from %s to %s because of override %s" % ( instrument_strategy.key, str(revised_order.trade), str(proposed_order.trade), str(override), - ) + ), + **proposed_order.log_attributes(), + method="temp", ) return revised_order @@ -149,7 +150,7 @@ def adjust_order_for_position_limits( self, order: instrumentOrder ) -> instrumentOrder: - log = order.log_with_attributes(self.log) + log_attrs = {**order.log_attributes(), "method": "temp"} data_position_limits = dataPositionLimits(self.data) new_order = data_position_limits.apply_position_limit_to_order(order) @@ -157,13 +158,15 @@ def adjust_order_for_position_limits( if new_order.trade != order.trade: if new_order.is_zero_trade(): ## at position limit, can't do anything - log.warning( - "Can't trade at all because of position limits %s" % str(order) + self.log.warning( + "Can't trade at all because of position limits %s" % str(order), + **log_attrs, ) else: - log.warning( + self.log.warning( "Can't do trade of %s because of position limits,instead will do %s" - % (str(order), str(new_order.trade)) + % (str(order), str(new_order.trade)), + **log_attrs, ) return new_order @@ -173,30 +176,32 @@ def submit_order_list(self, order_list: listOfOrders): for order in order_list: # try: # we allow existing orders to be modified - log = order.log_with_attributes(self.log) - log.debug("Required order %s" % str(order)) + log_attrs = {**order.log_attributes(), "method": "temp"} + self.log.debug("Required order %s" % str(order), **log_attrs) instrument_locked = data_lock.is_instrument_locked(order.instrument_code) if instrument_locked: - log.debug("Instrument locked, not submitting") + self.log.debug("Instrument locked, not submitting", **log_attrs) continue self.submit_order(order) def submit_order(self, order: instrumentOrder): - log = order.log_with_attributes(self.log) + log_attrs = {**order.log_attributes(), "method": "temp"} try: order_id = self.order_stack.put_order_on_stack(order) except zeroOrderException: # we checked for zero already, which means that there is an existing order on the stack # An existing order of the same size - log.warning( - "Ignoring new order as either zero size or it replicates an existing order on the stack" + self.log.warning( + "Ignoring new order as either zero size or it replicates an existing order on the stack", + **log_attrs, ) else: - log.debug( + self.log.debug( "Added order %s to instrument order stack with order id %d" % (str(order), order_id), instrument_order_id=order_id, + **log_attrs, ) diff --git a/sysinit/futures/seed_price_data_from_IB.py b/sysinit/futures/seed_price_data_from_IB.py index 40716e2bb8..f15eaa6737 100644 --- a/sysinit/futures/seed_price_data_from_IB.py +++ b/sysinit/futures/seed_price_data_from_IB.py @@ -32,16 +32,16 @@ def seed_price_data_from_IB(instrument_code): def seed_price_data_for_contract(data: dataBlob, contract_object: futuresContract): - log = contract_object.specific_log(data.log) + log_attrs = {**contract_object.log_attributes(), "method": "temp"} list_of_frequencies = [HOURLY_FREQ, DAILY_PRICE_FREQ] for frequency in list_of_frequencies: - log.debug("Getting data at frequency %s" % str(frequency)) + data.log.debug("Getting data at frequency %s" % str(frequency), **log_attrs) seed_price_data_for_contract_at_frequency( data=data, contract_object=contract_object, frequency=frequency ) - log.debug("Writing merged data for %s" % str(contract_object)) + data.log.debug("Writing merged data for %s" % str(contract_object), **log_attrs) write_merged_prices_for_contract( data, contract_object=contract_object, list_of_frequencies=list_of_frequencies ) @@ -53,7 +53,7 @@ def seed_price_data_for_contract_at_frequency( data_broker = dataBroker(data) update_prices = updatePrices(data) - log = contract_object.specific_log(data.log) + log_attrs = {**contract_object.log_attributes(), "method": "temp"} try: prices = ( @@ -62,13 +62,22 @@ def seed_price_data_for_contract_at_frequency( ) ) except missingData: - log.warning("Error getting data for %s" % str(contract_object)) + data.log.warning( + "Error getting data for %s" % str(contract_object), + **log_attrs, + ) return None - log.debug("Got %d lines of prices for %s" % (len(prices), str(contract_object))) + data.log.debug( + "Got %d lines of prices for %s" % (len(prices), str(contract_object)), + **log_attrs, + ) if len(prices) == 0: - log.warning("No price data for %s" % str(contract_object)) + data.log.warning( + "No price data for %s" % str(contract_object), + **log_attrs, + ) else: update_prices.overwrite_prices_at_frequency_for_contract( contract_object=contract_object, frequency=frequency, new_prices=prices diff --git a/sysobjects/contracts.py b/sysobjects/contracts.py index 3c18bd5873..25b99dd6f9 100644 --- a/sysobjects/contracts.py +++ b/sysobjects/contracts.py @@ -90,7 +90,7 @@ def __init__( self._contract_date = contract_date_object self._params = parameter_object - def specific_log(self, log): + def specific_log(self, log): # TODO remove new_log = log.setup( **{ INSTRUMENT_CODE_LOG_LABEL: self.instrument_code, @@ -100,6 +100,17 @@ def specific_log(self, log): return new_log + def log_attributes(self): + """ + Returns a dict of futuresContract log attributes + + :return: dict + """ + return { + INSTRUMENT_CODE_LOG_LABEL: self.instrument_code, + CONTRACT_DATE_LOG_LABEL: self.date_str, + } + @property def instrument(self): return self._instrument @@ -146,11 +157,6 @@ def sampling_on(self): def sampling_off(self): self.params.sampling = False - def log(self, log: pst_logger): - return log.setup( - instrument_code=self.instrument_code, contract_date=self.date_str - ) - def as_dict(self): """ Turn into a dict. We only include instrument_code from the instrument_object, the rest would be found elsewhere diff --git a/sysproduction/data/positions.py b/sysproduction/data/positions.py index 8e7e47a4eb..671eae55f2 100644 --- a/sysproduction/data/positions.py +++ b/sysproduction/data/positions.py @@ -306,10 +306,11 @@ def update_expiry_for_single_contract( original_contract.instrument_code, original_contract.contract_date ) except ContractNotFound: - log = original_contract.specific_log(self.data.log) - log.warning( + self.data.log.warning( "Contract %s is missing from database - expiry not found and will mismatch" - % str(original_contract) + % str(original_contract), + **original_contract.log_attributes(), + method="temp", ) new_contract = copy(original_contract) else: @@ -465,8 +466,7 @@ def update_strategy_position_table_with_instrument_order( instrument_strategy, new_position_as_int ) - log = original_instrument_order.log_with_attributes(self.log) - log.debug( + self.log.debug( "Updated position of %s from %d to %d because of trade %s %d fill %s" % ( str(instrument_strategy), @@ -475,7 +475,9 @@ def update_strategy_position_table_with_instrument_order( str(original_instrument_order), original_instrument_order.order_id, str(new_fill), - ) + ), + **original_instrument_order.log_attributes(), + method="temp", ) return success @@ -496,20 +498,20 @@ def update_contract_position_table_with_contract_order( time_date = datetime.datetime.now() - log = contract_order_before_fills.log_with_attributes(self.log) - for contract, trade_done in zip(list_of_individual_contracts, fill_list): self._update_positions_for_individual_contract_leg( contract=contract, trade_done=trade_done, time_date=time_date ) - log.debug( + self.log.debug( "Updated position of %s because of trade %s ID:%d with fills %d" % ( str(contract), str(contract_order_before_fills), contract_order_before_fills.order_id, trade_done, - ) + ), + **contract_order_before_fills.log_attributes(), + method="temp", ) def _update_positions_for_individual_contract_leg( @@ -526,15 +528,16 @@ def _update_positions_for_individual_contract_leg( # check new_position_db = self.diag_positions.get_position_for_contract(contract) - log = contract.specific_log(self.log) - log.debug( + self.log.debug( "Updated position of %s from %d to %d; new position in db is %d" % ( str(contract), current_position, new_position, new_position_db, - ) + ), + **contract.log_attributes(), + method="temp", ) diff --git a/sysproduction/interactive_update_roll_status.py b/sysproduction/interactive_update_roll_status.py index cbe881160b..56280c8c7a 100644 --- a/sysproduction/interactive_update_roll_status.py +++ b/sysproduction/interactive_update_roll_status.py @@ -572,7 +572,6 @@ def manually_update_roll_state_for_code( # First get the roll info # This will also update to console - data.log.setup(instrument_code=instrument_code) roll_state_suggested = suggest_roll_state_for_instrument( roll_data=roll_data, auto_parameters=auto_parameters ) diff --git a/sysproduction/update_historical_prices.py b/sysproduction/update_historical_prices.py index ef74b5a62d..2347cbc832 100644 --- a/sysproduction/update_historical_prices.py +++ b/sysproduction/update_historical_prices.py @@ -320,6 +320,7 @@ def update_historical_prices_for_instrument( return failure for contract_object in contract_list: + # TODO specific_log data.update_log(contract_object.specific_log(data.log)) update_historical_prices_for_instrument_and_contract( contract_object, diff --git a/sysproduction/update_sampled_contracts.py b/sysproduction/update_sampled_contracts.py index 2aeec70cf7..e60631eb40 100644 --- a/sysproduction/update_sampled_contracts.py +++ b/sysproduction/update_sampled_contracts.py @@ -275,9 +275,12 @@ def mark_existing_contract_as_sampling( ): data_contracts = dataContracts(data) data_contracts.mark_contract_as_sampling(contract_to_add) - log = contract_to_add.specific_log(data.log) - log.debug("Contract %s now sampling" % str(contract_to_add)) + data.log.debug( + "Contract %s now sampling" % str(contract_to_add), + **contract_to_add.log_attributes(), + method="temp", + ) def add_new_contract_with_sampling_on(contract_to_add: futuresContract, data: dataBlob): @@ -290,9 +293,11 @@ def add_new_contract_with_sampling_on(contract_to_add: futuresContract, data: da # Should not be any duplication to ignore data_contracts.add_contract_data(contract_to_add, ignore_duplication=False) - log = contract_to_add.specific_log(data.log) - - log.debug("Contract %s now added to database and sampling" % str(contract_to_add)) + data.log.debug( + "Contract %s now added to database and sampling" % str(contract_to_add), + **contract_to_add.log_attributes(), + method="temp", + ) def update_expiries_and_sampling_status_for_contracts( @@ -334,7 +339,7 @@ def update_expiry_and_sampling_status_for_contract( OK_TO_SAMPLE = "okay to sample" unsample_reason = OK_TO_SAMPLE - log = contract_object.specific_log(data.log) + log_attrs = {**contract_object.log_attributes(), "method": "temp"} data_contracts = dataContracts(data) db_contract = data_contracts.get_contract_from_db(contract_object) @@ -343,18 +348,20 @@ def update_expiry_and_sampling_status_for_contract( try: broker_expiry_date = get_contract_expiry_from_broker(contract_object, data=data) except missingContract: - log.debug( + data.log.debug( "Can't find expiry for %s, could be a connection problem but could be because contract has already expired" - % (str(contract_object)) + % (str(contract_object)), + **log_attrs, ) ## As probably expired we'll remove it from the sampling list unsample_reason = "Contract not available from IB" else: if broker_expiry_date == db_expiry_date: - log.debug( + data.log.debug( "No change to contract expiry %s to %s" - % (str(contract_object), str(broker_expiry_date)) + % (str(contract_object), str(broker_expiry_date)), + **log_attrs, ) else: # Different! @@ -376,10 +383,11 @@ def update_expiry_and_sampling_status_for_contract( if turn_off_sampling: # Mark it as stop sampling in the database data_contracts.mark_contract_as_not_sampling(contract_object) - log.debug( + data.log.debug( "Contract %s %s so now stopped sampling" % (str(contract_object), unsample_reason), contract_date=contract_object.date_str, + **log_attrs, ) @@ -402,11 +410,11 @@ def update_contract_object_with_new_expiry_date( contract_object, new_expiry_date=broker_expiry_date ) - log = contract_object.specific_log(data.log) - - log.debug( + data.log.debug( "Updated expiry of contract %s to %s" - % (str(contract_object), str(broker_expiry_date)) + % (str(contract_object), str(broker_expiry_date)), + **contract_object.log_attributes(), + method="temp", ) diff --git a/systems/stage.py b/systems/stage.py index 59e56ff75f..2161624a99 100644 --- a/systems/stage.py +++ b/systems/stage.py @@ -38,6 +38,7 @@ def system_init(self, system: System): self._parent = system # and a log + # TODO log.setup log = system.log.setup(stage=self.name) self._log = log From 2e5b6ceaafe066e485feb6b65109bab51cf25090 Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Tue, 10 Oct 2023 16:40:27 +0100 Subject: [PATCH 02/19] removing usages of log.setup() which have no effect --- syscontrol/run_process.py | 2 -- syscontrol/timer_functions.py | 2 -- 2 files changed, 4 deletions(-) diff --git a/syscontrol/run_process.py b/syscontrol/run_process.py index b8008d0236..d06abbbee7 100644 --- a/syscontrol/run_process.py +++ b/syscontrol/run_process.py @@ -70,8 +70,6 @@ def list_of_timer_functions(self) -> listOfTimerFunctions: return self._list_of_timer_functions def _setup(self): - # TODO log.setup - self.data.log.setup(type=self.process_name) self._log = self.data.log data_control = dataControlProcess(self.data) self._data_control = data_control diff --git a/syscontrol/timer_functions.py b/syscontrol/timer_functions.py index 41a889207b..551ce3e8b4 100644 --- a/syscontrol/timer_functions.py +++ b/syscontrol/timer_functions.py @@ -27,8 +27,6 @@ def __init__( self._data = data self._parameters = parameters - # TODO log.setup - log.setup(type=self.process_name) self._log = log self._report_status = reportStatus(log) From 7708841bc2ae8a3d1af3bc8f929119179dd4dada Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Tue, 10 Oct 2023 22:40:27 +0100 Subject: [PATCH 03/19] removing unnecessary use of log.setup(), logger is set up in __init__() --- sysdata/config/configdata.py | 4 ---- 1 file changed, 4 deletions(-) diff --git a/sysdata/config/configdata.py b/sysdata/config/configdata.py index 934d0720ca..48cefb0a59 100644 --- a/sysdata/config/configdata.py +++ b/sysdata/config/configdata.py @@ -189,10 +189,6 @@ def system_init(self, base_system): :return: nothing """ - # inherit the log - # TODO log.setup - setattr(self, "log", base_system.log.setup(stage="config")) - # fill with defaults self.fill_with_defaults() From f851a7ad37bfd67af3a4ac14407a1235a0e74625 Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Tue, 10 Oct 2023 22:49:55 +0100 Subject: [PATCH 04/19] removing unnecessary use of log.setup(), system_init() adds 'stage' attribute to 'base_system' logger --- systems/stage.py | 9 +++------ 1 file changed, 3 insertions(+), 6 deletions(-) diff --git a/systems/stage.py b/systems/stage.py index 2161624a99..1cbd219186 100644 --- a/systems/stage.py +++ b/systems/stage.py @@ -38,14 +38,11 @@ def system_init(self, system: System): self._parent = system # and a log - # TODO log.setup - log = system.log.setup(stage=self.name) - self._log = log + self._log = get_logger("base_system", {STAGE_LOG_LABEL: self.name}) @property - def log(self) -> pst_logger: - log = getattr(self, "_log", get_logger("")) - return log + def log(self): + return self._log @property def parent(self) -> System: From 17d0d53a5a242212f0868629bb9914e5aec2914c Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Tue, 10 Oct 2023 22:52:32 +0100 Subject: [PATCH 05/19] removing unnecessary use of log.setup(), system_init() adds 'stage' attribute to 'base_system' logger --- sysdata/sim/sim_data.py | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/sysdata/sim/sim_data.py b/sysdata/sim/sim_data.py index dc9d7ae4ea..c5b6eb0a1a 100644 --- a/sysdata/sim/sim_data.py +++ b/sysdata/sim/sim_data.py @@ -9,7 +9,7 @@ resample_prices_to_business_day_index, ) from sysdata.base_data import baseData - +from syslogging.logger import * from sysobjects.spot_fx_prices import fxPrices from sysobjects.instruments import instrumentCosts @@ -71,8 +71,7 @@ def system_init(self, base_system: "System"): """ # inherit the log - # TODO log.setup - self._log = base_system.log.setup(stage="data") + self._log = get_logger("base_system", {STAGE_LOG_LABEL: "data"}) self._parent = base_system @property From 2ca048effeafee683e676db79a36c16c4132d042 Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Fri, 13 Oct 2023 12:59:12 +0100 Subject: [PATCH 06/19] refactoring away log.setup() in dataBlob --- sysdata/data_blob.py | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/sysdata/data_blob.py b/sysdata/data_blob.py index efdc0db9df..c743bb4a0c 100644 --- a/sysdata/data_blob.py +++ b/sysdata/data_blob.py @@ -208,8 +208,7 @@ def csv_data_paths(self) -> dict: def _get_specific_logger(self, class_object): class_name = get_class_name(class_object) - # TODO log.setup - log = self.log.setup(**{COMPONENT_LOG_LABEL: class_name}) + log = get_logger(self.log.name, {COMPONENT_LOG_LABEL: class_name}) return log @@ -244,7 +243,7 @@ def _already_existing_class_name(self, attr_name: str): def _add_attr_to_list(self, new_attr: str): self._attr_list.append(new_attr) - def update_log(self, new_log: pst_logger): + def update_log(self, new_log): self._log = new_log """ From 7e5e566ed9b2d13d3ad4f68b65af32024155ea17 Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Fri, 13 Oct 2023 13:00:28 +0100 Subject: [PATCH 07/19] refactoring away contract.specific_log(), which uses log.setup() --- sysproduction/update_historical_prices.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/sysproduction/update_historical_prices.py b/sysproduction/update_historical_prices.py index 2347cbc832..4421353528 100644 --- a/sysproduction/update_historical_prices.py +++ b/sysproduction/update_historical_prices.py @@ -19,6 +19,7 @@ from sysdata.tools.cleaner import priceFilterConfig, get_config_for_price_filtering from syslogdiag.email_via_db_interface import send_production_mail_msg +from syslogging.logger import * from sysobjects.contracts import futuresContract from sysobjects.futures_per_contract_prices import futuresContractPrices @@ -320,8 +321,7 @@ def update_historical_prices_for_instrument( return failure for contract_object in contract_list: - # TODO specific_log - data.update_log(contract_object.specific_log(data.log)) + data.update_log(get_logger(data.log.name, **contract_object.log_attributes())) update_historical_prices_for_instrument_and_contract( contract_object, data, From 35add5533da4e0aa62a386fc2b000642371c3513 Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Fri, 13 Oct 2023 13:00:49 +0100 Subject: [PATCH 08/19] updating logging TODOs --- syslogging/adapter.py | 3 --- 1 file changed, 3 deletions(-) diff --git a/syslogging/adapter.py b/syslogging/adapter.py index ece8771f0e..8bff87ddaa 100644 --- a/syslogging/adapter.py +++ b/syslogging/adapter.py @@ -9,9 +9,6 @@ class DynamicAttributeLogger(logging.LoggerAdapter): """ # TODO futures_contract.specific_log - # TODO data_blob.update_log - # TODO data.update_log(contract_object.specific_log(data.log)) - # TODO data_blob._get_specific_logger # TODO log_with_attributes """ From bfc5114eb9de1ece04d949bb0b8af09adfbdf3d4 Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Tue, 17 Oct 2023 14:31:14 +0100 Subject: [PATCH 09/19] safe logger setup --- systems/stage.py | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/systems/stage.py b/systems/stage.py index 1cbd219186..5ee02c9a9e 100644 --- a/systems/stage.py +++ b/systems/stage.py @@ -42,7 +42,10 @@ def system_init(self, system: System): @property def log(self): - return self._log + log = getattr( + self, "_log", get_logger("base_system", {STAGE_LOG_LABEL: self.name}) + ) + return log @property def parent(self) -> System: From 0f373795cbb2f18443f8f28f3b1f24a3b7ab6f84 Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Tue, 17 Oct 2023 16:07:57 +0100 Subject: [PATCH 10/19] fix logger attributes --- sysproduction/update_historical_prices.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sysproduction/update_historical_prices.py b/sysproduction/update_historical_prices.py index 4421353528..833b71abc7 100644 --- a/sysproduction/update_historical_prices.py +++ b/sysproduction/update_historical_prices.py @@ -321,7 +321,7 @@ def update_historical_prices_for_instrument( return failure for contract_object in contract_list: - data.update_log(get_logger(data.log.name, **contract_object.log_attributes())) + data.update_log(get_logger(data.log.name, contract_object.log_attributes())) update_historical_prices_for_instrument_and_contract( contract_object, data, From cf146e32ecc790420ac469615826b422cb73424b Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Tue, 17 Oct 2023 16:18:14 +0100 Subject: [PATCH 11/19] remove pst_logger type hints --- docs/data.md | 2 +- sysbrokers/IB/client/ib_client.py | 4 +--- sysbrokers/IB/client/ib_contracts_client.py | 2 +- sysbrokers/IB/client/ib_price_client.py | 12 ++++-------- sysbrokers/IB/config/ib_instrument_config.py | 6 +++--- sysbrokers/IB/ib_capital_data.py | 2 +- sysbrokers/broker_capital_data.py | 4 +--- syscontrol/report_process_status.py | 2 +- sysdata/data_blob.py | 4 ++-- sysexecution/algos/algo_original_best.py | 14 ++++++-------- sysexecution/orders/base_orders.py | 2 +- sysexecution/orders/broker_orders.py | 2 +- sysexecution/orders/contract_orders.py | 2 +- sysexecution/orders/instrument_orders.py | 2 +- syslogging/adapter.py | 4 ---- sysquant/optimisation/generic_optimiser.py | 2 +- systems/basesystem.py | 2 +- .../dynamic_small_system_optimise/optimisation.py | 2 +- 18 files changed, 28 insertions(+), 42 deletions(-) diff --git a/docs/data.md b/docs/data.md index e513450157..8f5c46ce1a 100644 --- a/docs/data.md +++ b/docs/data.md @@ -980,7 +980,7 @@ Here's a quick whistle-stop tour of dataBlob's other features: - you can create it with a starting class list by passing the `parameter class_list=...` -- it includes a `log` attribute that is passed to create data storage instances (you can override this by passing in a pst_logger via the `log=` parameter when dataBlob is created), the log will have top level type attribute as defined by the log_name parameter +- it includes a `log` attribute that is passed to create data storage instances (you can override this by passing in a logger via the `log=` parameter when dataBlob is created), the log will have top level type attribute as defined by the log_name parameter - when required it creates a `mongoDb` instance that is passed to create data storage instances (you can override this by passing in a `mongoDb` instance via the `mongo_db=` parameter when dataBlob is created) - when required it creates a `connectionIB` instance that is passed to create data storage instances (you can override this by passing in a connection instance via the `ib_conn=` parameter when dataBlob is created) - The parameter `csv_data_paths` will allow you to use different .csv data paths, not the defaults. The dict should have the keys of the class names, and values will be the paths to use. diff --git a/sysbrokers/IB/client/ib_client.py b/sysbrokers/IB/client/ib_client.py index 7180604c8c..b53d0ec2d2 100644 --- a/sysbrokers/IB/client/ib_client.py +++ b/sysbrokers/IB/client/ib_client.py @@ -64,9 +64,7 @@ class ibClient(object): """ - def __init__( - self, ibconnection: connectionIB, log: pst_logger = get_logger("ibClient") - ): + def __init__(self, ibconnection: connectionIB, log=get_logger("ibClient")): # means our first call won't be throttled for pacing self.last_historic_price_calltime = ( diff --git a/sysbrokers/IB/client/ib_contracts_client.py b/sysbrokers/IB/client/ib_contracts_client.py index c26251e408..c3793985e5 100644 --- a/sysbrokers/IB/client/ib_contracts_client.py +++ b/sysbrokers/IB/client/ib_contracts_client.py @@ -543,7 +543,7 @@ def _get_vanilla_ib_futures_contract( return resolved_contract - def ib_resolve_unique_contract(self, ibcontract_pattern, log: pst_logger = None): + def ib_resolve_unique_contract(self, ibcontract_pattern, log=None): """ Returns the 'resolved' IB contract based on a pattern. We expect a unique contract. diff --git a/sysbrokers/IB/client/ib_price_client.py b/sysbrokers/IB/client/ib_price_client.py index 45a4cb5580..327d2d846a 100644 --- a/sysbrokers/IB/client/ib_price_client.py +++ b/sysbrokers/IB/client/ib_price_client.py @@ -179,7 +179,7 @@ def _ib_get_recent_bid_ask_tick_data_using_reqHistoricalTicks( def _get_generic_data_for_contract( # TODO passed logger instance self, ibcontract: ibContract, - log: pst_logger = None, + log=None, bar_freq: Frequency = DAILY_PRICE_FREQ, whatToShow: str = "TRADES", ) -> pd.DataFrame: @@ -215,9 +215,7 @@ def _get_generic_data_for_contract( # TODO passed logger instance return price_data_as_df - def _raw_ib_data_to_df( - self, price_data_raw: pd.DataFrame, log: pst_logger - ) -> pd.DataFrame: + def _raw_ib_data_to_df(self, price_data_raw: pd.DataFrame, log) -> pd.DataFrame: if price_data_raw is None: log.warning("No price data from IB") @@ -272,7 +270,7 @@ def _ib_get_historical_data_of_duration_and_barSize( durationStr: str = "1 Y", barSizeSetting: str = "1 day", whatToShow="TRADES", - log: pst_logger = None, + log=None, ) -> pd.DataFrame: """ Returns historical prices for a contract, up to today @@ -345,9 +343,7 @@ def _get_barsize_and_duration_from_frequency(bar_freq: Frequency) -> (str, str): return ib_barsize, ib_duration -def _avoid_pacing_violation( - last_call_datetime: datetime.datetime, log: pst_logger = get_logger("") -): +def _avoid_pacing_violation(last_call_datetime: datetime.datetime, log=get_logger("")): printed_warning_already = False while _pause_for_pacing(last_call_datetime): if not printed_warning_already: diff --git a/sysbrokers/IB/config/ib_instrument_config.py b/sysbrokers/IB/config/ib_instrument_config.py index ee35650f27..83d3bc0bb7 100644 --- a/sysbrokers/IB/config/ib_instrument_config.py +++ b/sysbrokers/IB/config/ib_instrument_config.py @@ -22,7 +22,7 @@ class IBconfig(pd.DataFrame): ) -def read_ib_config_from_file(log: pst_logger = get_logger("")) -> IBconfig: +def read_ib_config_from_file(log=get_logger("")) -> IBconfig: try: df = pd.read_csv(IB_FUTURES_CONFIG_FILE) except Exception as e: @@ -33,7 +33,7 @@ def read_ib_config_from_file(log: pst_logger = get_logger("")) -> IBconfig: def get_instrument_object_from_config( - instrument_code: str, config: IBconfig = None, log: pst_logger = get_logger("") + instrument_code: str, config: IBconfig = None, log=get_logger("") ) -> futuresInstrumentWithIBConfigData: log_attrs = {INSTRUMENT_CODE_LOG_LABEL: instrument_code, "method": "temp"} @@ -113,7 +113,7 @@ class IBInstrumentIdentity: def get_instrument_code_from_broker_instrument_identity( config: IBconfig, ib_instrument_identity: IBInstrumentIdentity, - log: pst_logger = get_logger(""), + log=get_logger(""), ) -> str: ib_code = ib_instrument_identity.ib_code diff --git a/sysbrokers/IB/ib_capital_data.py b/sysbrokers/IB/ib_capital_data.py index 69cb9bb533..c89c819664 100644 --- a/sysbrokers/IB/ib_capital_data.py +++ b/sysbrokers/IB/ib_capital_data.py @@ -14,7 +14,7 @@ def __init__( self, ibconnection: connectionIB, data: dataBlob, - log: pst_logger = get_logger("ibCapitalData"), + log=get_logger("ibCapitalData"), ): super().__init__(log=log, data=data) self._ibconnection = ibconnection diff --git a/sysbrokers/broker_capital_data.py b/sysbrokers/broker_capital_data.py index a6c5470981..17dabeeea1 100644 --- a/sysbrokers/broker_capital_data.py +++ b/sysbrokers/broker_capital_data.py @@ -8,9 +8,7 @@ class brokerCapitalData(capitalData): - def __init__( - self, data: dataBlob, log: pst_logger = get_logger("brokerCapitalData") - ): + def __init__(self, data: dataBlob, log=get_logger("brokerCapitalData")): super().__init__(log=log) self._data = data diff --git a/syscontrol/report_process_status.py b/syscontrol/report_process_status.py index 5d7e54429d..5778b1130d 100644 --- a/syscontrol/report_process_status.py +++ b/syscontrol/report_process_status.py @@ -10,7 +10,7 @@ class reportStatus(object): ## Report on status when waiting and paused, ensures we don't spam the log - def __init__(self, log: pst_logger = arg_not_supplied): + def __init__(self, log=arg_not_supplied): if log is arg_not_supplied: log = get_logger("") self._log = log diff --git a/sysdata/data_blob.py b/sysdata/data_blob.py index c743bb4a0c..48362a4188 100644 --- a/sysdata/data_blob.py +++ b/sysdata/data_blob.py @@ -18,7 +18,7 @@ def __init__( csv_data_paths: dict = arg_not_supplied, ib_conn: connectionIB = arg_not_supplied, mongo_db: mongoDb = arg_not_supplied, - log: pst_logger = arg_not_supplied, + log=arg_not_supplied, keep_original_prefix: bool = False, ): """ @@ -40,7 +40,7 @@ def __init__( This abstracts the precise data source :param arg_string: str like a named tuple in the form 'classNameOfData1 classNameOfData2' and so on - :param log_name: pst_logger type to set + :param log_name: logger name :param keep_original_prefix: bool. If True then: data = dataBlob([arcticFuturesContractPriceData, arcticFuturesContractPriceData, mongoFuturesContractData]) diff --git a/sysexecution/algos/algo_original_best.py b/sysexecution/algos/algo_original_best.py index 99c4e17a78..a6a07de6b4 100644 --- a/sysexecution/algos/algo_original_best.py +++ b/sysexecution/algos/algo_original_best.py @@ -223,7 +223,7 @@ def manage_live_trade( def limit_trade_viable( # TODO passed logger instance - data: dataBlob, order: contractOrder, ticker_object: tickerObject, log: pst_logger + data: dataBlob, order: contractOrder, ticker_object: tickerObject, log ) -> bool: # no point doing limit order if we've got imbalanced size issues, as we'd @@ -286,7 +286,7 @@ def file_log_report_limit_order( def reason_to_switch_to_aggressive( - data: dataBlob, broker_order_with_controls: orderWithControls, log: pst_logger + data: dataBlob, broker_order_with_controls: orderWithControls, log ) -> str: ticker_object = broker_order_with_controls.ticker @@ -329,7 +329,7 @@ def reason_to_switch_to_aggressive( def is_market_about_to_close( data: dataBlob, order: Union[brokerOrder, contractOrder, orderWithControls], - log: pst_logger, + log, ) -> bool: data_broker = dataBroker(data) @@ -353,7 +353,7 @@ def required_to_switch_to_aggressive(reason: str) -> bool: def adverse_size_issue( - ticker_object: tickerObject, log: pst_logger, wait_for_valid_tick=False + ticker_object: tickerObject, log, wait_for_valid_tick=False ) -> bool: if wait_for_valid_tick: current_tick_analysis = ( @@ -377,9 +377,7 @@ def adverse_size_issue( return False -def _is_imbalance_ratio_exceeded( - current_tick_analysis: analysisTick, log: pst_logger -) -> bool: +def _is_imbalance_ratio_exceeded(current_tick_analysis: analysisTick, log) -> bool: latest_imbalance_ratio = current_tick_analysis.imbalance_ratio latest_imbalance_ratio_exceeded = latest_imbalance_ratio > IMBALANCE_THRESHOLD @@ -393,7 +391,7 @@ def _is_imbalance_ratio_exceeded( def _is_insufficient_size_on_our_preferred_side( - ticker_object: tickerObject, current_tick_analysis: analysisTick, log: pst_logger + ticker_object: tickerObject, current_tick_analysis: analysisTick, log ) -> bool: abs_size_we_wish_to_trade = abs(ticker_object.qty) size_we_require_to_trade_limit = IMBALANCE_ADJ_FACTOR * abs_size_we_wish_to_trade diff --git a/sysexecution/orders/base_orders.py b/sysexecution/orders/base_orders.py index a4cfed5d0d..d897979082 100644 --- a/sysexecution/orders/base_orders.py +++ b/sysexecution/orders/base_orders.py @@ -447,7 +447,7 @@ def log_with_attributes(self, log): """ Returns a new log object with order attributes added - :param log: pst_logger + :param log: logger :return: log """ diff --git a/sysexecution/orders/broker_orders.py b/sysexecution/orders/broker_orders.py index 23cf282639..324c2a8f05 100644 --- a/sysexecution/orders/broker_orders.py +++ b/sysexecution/orders/broker_orders.py @@ -341,7 +341,7 @@ def log_with_attributes(self, log): """ Returns a new log object with broker_order attributes added - :param log: pst_logger + :param log: logger :return: log """ broker_order = self diff --git a/sysexecution/orders/contract_orders.py b/sysexecution/orders/contract_orders.py index b7ded12780..675095486a 100644 --- a/sysexecution/orders/contract_orders.py +++ b/sysexecution/orders/contract_orders.py @@ -284,7 +284,7 @@ def log_with_attributes(self, log): """ Returns a new log object with contract_order attributes added - :param log: pst_logger + :param log: logger :return: log """ new_log = log.setup( diff --git a/sysexecution/orders/instrument_orders.py b/sysexecution/orders/instrument_orders.py index 11f35481f8..6f3539424e 100644 --- a/sysexecution/orders/instrument_orders.py +++ b/sysexecution/orders/instrument_orders.py @@ -232,7 +232,7 @@ def log_with_attributes(self, log): """ Returns a new log object with instrument_order attributes added - :param log: pst_logger + :param log: logger :return: log """ new_log = log.setup( diff --git a/syslogging/adapter.py b/syslogging/adapter.py index 8bff87ddaa..0bc60ddd9f 100644 --- a/syslogging/adapter.py +++ b/syslogging/adapter.py @@ -82,7 +82,3 @@ def _check_attributes(self, attributes: dict): raise Exception( "Attributes %s not allowed in log" % str(bad_attributes) ) - - -class pst_logger(DynamicAttributeLogger): - pass diff --git a/sysquant/optimisation/generic_optimiser.py b/sysquant/optimisation/generic_optimiser.py index acaf06cfe5..9393ec123f 100644 --- a/sysquant/optimisation/generic_optimiser.py +++ b/sysquant/optimisation/generic_optimiser.py @@ -28,7 +28,7 @@ def net_returns(self) -> returnsForOptimisation: return self._net_returns @property - def log(self) -> pst_logger: + def log(self): return self._log @property diff --git a/systems/basesystem.py b/systems/basesystem.py index 302b9815e1..61489c6e90 100644 --- a/systems/basesystem.py +++ b/systems/basesystem.py @@ -44,7 +44,7 @@ def __init__( stage_list: list, data: simData, config: Config = arg_not_supplied, - log: pst_logger = get_logger("base_system"), + log=get_logger("base_system"), ): """ Create a system object for doing simulations or live trading diff --git a/systems/provided/dynamic_small_system_optimise/optimisation.py b/systems/provided/dynamic_small_system_optimise/optimisation.py index 6ea008e32a..c9e00cfec4 100644 --- a/systems/provided/dynamic_small_system_optimise/optimisation.py +++ b/systems/provided/dynamic_small_system_optimise/optimisation.py @@ -39,7 +39,7 @@ def __init__( previous_positions: portfolioWeights = arg_not_supplied, constraints: constraintsForDynamicOpt = arg_not_supplied, maximum_positions: portfolioWeights = arg_not_supplied, - log: pst_logger = get_logger("objectiveFunctionForGreedy"), + log=get_logger("objectiveFunctionForGreedy"), ): self.covariance_matrix = covariance_matrix From 99ed02a2269d85567f92afb225898ec32bd906d9 Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Tue, 17 Oct 2023 22:11:32 +0100 Subject: [PATCH 12/19] better logging for submit_order() --- sysexecution/strategies/strategy_order_handling.py | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/sysexecution/strategies/strategy_order_handling.py b/sysexecution/strategies/strategy_order_handling.py index b3746cc98c..c667ea532e 100644 --- a/sysexecution/strategies/strategy_order_handling.py +++ b/sysexecution/strategies/strategy_order_handling.py @@ -11,7 +11,7 @@ from sysexecution.orders.list_of_orders import listOfOrders from sysexecution.orders.instrument_orders import instrumentOrder from sysexecution.order_stacks.instrument_order_stack import zeroOrderException - +from syslogging.logger import * from sysproduction.data.positions import diagPositions from sysproduction.data.orders import dataOrders from sysproduction.data.controls import diagOverrides, dataLocks, dataPositionLimits @@ -190,11 +190,14 @@ def submit_order(self, order: instrumentOrder): try: order_id = self.order_stack.put_order_on_stack(order) + log_attrs[INSTRUMENT_ORDER_ID_LABEL] = order_id except zeroOrderException: - # we checked for zero already, which means that there is an existing order on the stack + # we checked for zero already, which means that there is an existing order + # on the stack # An existing order of the same size self.log.warning( - "Ignoring new order as either zero size or it replicates an existing order on the stack", + "Ignoring new order as either zero size or it replicates an existing " + "order on the stack", **log_attrs, ) @@ -202,6 +205,5 @@ def submit_order(self, order: instrumentOrder): self.log.debug( "Added order %s to instrument order stack with order id %d" % (str(order), order_id), - instrument_order_id=order_id, **log_attrs, ) From 24a9c0fdbf3b707c4159d5849c097f3bbd05384a Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Wed, 18 Oct 2023 12:05:18 +0100 Subject: [PATCH 13/19] add missing dict expanders ** --- sysbrokers/IB/client/ib_contracts_client.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sysbrokers/IB/client/ib_contracts_client.py b/sysbrokers/IB/client/ib_contracts_client.py index c3793985e5..d78e6139e0 100644 --- a/sysbrokers/IB/client/ib_contracts_client.py +++ b/sysbrokers/IB/client/ib_contracts_client.py @@ -337,7 +337,7 @@ def ib_get_contract_details(self, contract_object_with_ib_data: futuresContract) except missingContract: self.log.warning( "Can't get trading hours as contract is missing", - contract_object_with_ib_data.log_attributes(), + **contract_object_with_ib_data.log_attributes(), method="temp", ) raise From de693e5020b33cf2a595ccd56b28bad7cf48fe9c Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Wed, 18 Oct 2023 12:05:59 +0100 Subject: [PATCH 14/19] fix temp fx log attributes --- sysbrokers/IB/ib_Fx_prices_data.py | 6 ++---- sysdata/arctic/arctic_spotfx_prices.py | 6 ++---- sysdata/fx/spotfx.py | 6 ++---- 3 files changed, 6 insertions(+), 12 deletions(-) diff --git a/sysbrokers/IB/ib_Fx_prices_data.py b/sysbrokers/IB/ib_Fx_prices_data.py index f252faf1c4..b8339dac49 100644 --- a/sysbrokers/IB/ib_Fx_prices_data.py +++ b/sysbrokers/IB/ib_Fx_prices_data.py @@ -54,8 +54,7 @@ def _get_fx_prices_without_checking(self, currency_code: str) -> fxPrices: except missingInstrument: self.log.warning( "Can't get prices as missing IB config for %s" % currency_code, - CURRENCY_CODE_LOG_LABEL=currency_code, - method="temp", + **{CURRENCY_CODE_LOG_LABEL: currency_code, "method": "temp"}, ) return fxPrices.create_empty() @@ -115,8 +114,7 @@ def _get_config_info_for_code(self, currency_code: str) -> ibFXConfig: except missingFile as e: self.log.warning( "Can't get IB FX config for %s as config file missing" % currency_code, - CURRENCY_CODE_LOG_LABEL=currency_code, - method="temp", + **{CURRENCY_CODE_LOG_LABEL: currency_code, "method": "temp"}, ) raise missingInstrument from e diff --git a/sysdata/arctic/arctic_spotfx_prices.py b/sysdata/arctic/arctic_spotfx_prices.py index 4eb56b730d..57b92a518c 100644 --- a/sysdata/arctic/arctic_spotfx_prices.py +++ b/sysdata/arctic/arctic_spotfx_prices.py @@ -39,8 +39,7 @@ def _delete_fx_prices_without_any_warning_be_careful(self, currency_code: str): self.arctic.delete(currency_code) self.log.debug( "Deleted fX prices for %s from %s" % (currency_code, str(self)), - CURRENCY_CODE_LOG_LABEL=currency_code, - method="temp", + **{CURRENCY_CODE_LOG_LABEL: currency_code, "method": "temp"}, ) def _add_fx_prices_without_checking_for_existing_entry( @@ -54,6 +53,5 @@ def _add_fx_prices_without_checking_for_existing_entry( self.log.debug( "Wrote %s lines of prices for %s to %s" % (len(fx_price_data), currency_code, str(self)), - CURRENCY_CODE_LOG_LABEL=currency_code, - method="temp", + **{CURRENCY_CODE_LOG_LABEL: currency_code, "method": "temp"}, ) diff --git a/sysdata/fx/spotfx.py b/sysdata/fx/spotfx.py index d949dddc79..e52ea2b5af 100644 --- a/sysdata/fx/spotfx.py +++ b/sysdata/fx/spotfx.py @@ -86,8 +86,7 @@ def _get_fx_prices_for_inversion(self, fx_code: str) -> fxPrices: self.log.warning( "Data for %s is missing, needed to calculate %s" % (currency2 + DEFAULT_CURRENCY, DEFAULT_CURRENCY + currency2), - CURRENCY_CODE_LOG_LABEL=fx_code, - method="temp", + **{CURRENCY_CODE_LOG_LABEL: fx_code, "method": "temp"}, ) return raw_fx_data @@ -132,8 +131,7 @@ def _get_fx_prices(self, code: str) -> fxPrices: if not self.is_code_in_data(code): self.log.warning( "Currency %s is missing from list of FX data" % code, - CURRENCY_CODE_LOG_LABEL=code, - method="temp", + **{CURRENCY_CODE_LOG_LABEL: code, "method": "temp"}, ) return fxPrices.create_empty() From 04027f0c882f7d03cc64a07860861c259aa0365e Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Wed, 18 Oct 2023 13:39:37 +0100 Subject: [PATCH 15/19] adding more tests for temp method --- syslogging/tests/logging_tests.py | 64 +++++++++++++++++++++++++++++++ 1 file changed, 64 insertions(+) diff --git a/syslogging/tests/logging_tests.py b/syslogging/tests/logging_tests.py index eebf7116b7..6023b6e8a4 100644 --- a/syslogging/tests/logging_tests.py +++ b/syslogging/tests/logging_tests.py @@ -1,5 +1,6 @@ import pytest from syslogging.logger import * +from sysobjects.contracts import futuresContract class TestLogging: @@ -78,6 +79,69 @@ def test_attributes_temp(self, caplog): "{'stage': 'first'} no type attribute", ) + def test_contract_log_attributes(self, caplog): + contract_logger = get_logger("contract") + contract = futuresContract( + instrument_object="AUD", contract_date_object="20231200" + ) + log_attrs = contract.log_attributes() + contract_logger.info( + "setting temp contract attributes", **log_attrs, method="temp" + ) + assert caplog.record_tuples[0] == ( + "contract", + logging.INFO, + "{'instrument_code': 'AUD', 'contract_date': '20231200'} setting temp " + "contract attributes", + ) + contract_logger.info("no contract attributes") + assert caplog.record_tuples[1] == ( + "contract", + logging.INFO, + "no contract attributes", + ) + + def test_contract_log_attributes_inline(self, caplog): + contract_inline = get_logger("contract_inline") + contract = futuresContract( + instrument_object="AUD", contract_date_object="20231200" + ) + contract_inline.info( + "setting temp contract attributes inline", + **contract.log_attributes(), + method="temp", + ) + assert caplog.record_tuples[0] == ( + "contract_inline", + logging.INFO, + "{'instrument_code': 'AUD', 'contract_date': '20231200'} setting temp " + "contract attributes inline", + ) + contract_inline.info("no contract attributes") + assert caplog.record_tuples[1] == ( + "contract_inline", + logging.INFO, + "no contract attributes", + ) + + def test_fx_log_attributes(self, caplog): + fx = get_logger("fx") + fx.info( + "setting temp fx attributes inline", + **{CURRENCY_CODE_LOG_LABEL: "USDAUD", "method": "temp"}, + ) + assert caplog.record_tuples[0] == ( + "fx", + logging.INFO, + "{'currency_code': 'USDAUD'} setting temp fx attributes inline", + ) + fx.info("no contract attributes") + assert caplog.record_tuples[1] == ( + "fx", + logging.INFO, + "no contract attributes", + ) + def test_setup(self): logger = get_logger("my_type", {"stage": "bar"}) logger = logger.setup(stage="left") From 346bdd54a1da6589bb3e212750b21f5228b3c139 Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Wed, 18 Oct 2023 13:39:52 +0100 Subject: [PATCH 16/19] expanding log attributes --- sysbrokers/IB/client/ib_contracts_client.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sysbrokers/IB/client/ib_contracts_client.py b/sysbrokers/IB/client/ib_contracts_client.py index d78e6139e0..096b36a98c 100644 --- a/sysbrokers/IB/client/ib_contracts_client.py +++ b/sysbrokers/IB/client/ib_contracts_client.py @@ -295,7 +295,7 @@ def ib_get_min_tick_size( self.log.warning( "%s when getting min tick size from %s!" % (str(e), str(ib_contract_details)), - log_attrs, + **log_attrs, ) raise missingContract From 737643dbd17e14ca0d5ec4bc31c80e2707143215 Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Wed, 18 Oct 2023 13:40:16 +0100 Subject: [PATCH 17/19] fixing duplicated log attribute --- sysproduction/update_sampled_contracts.py | 1 - 1 file changed, 1 deletion(-) diff --git a/sysproduction/update_sampled_contracts.py b/sysproduction/update_sampled_contracts.py index e60631eb40..2f50d90bd2 100644 --- a/sysproduction/update_sampled_contracts.py +++ b/sysproduction/update_sampled_contracts.py @@ -386,7 +386,6 @@ def update_expiry_and_sampling_status_for_contract( data.log.debug( "Contract %s %s so now stopped sampling" % (str(contract_object), unsample_reason), - contract_date=contract_object.date_str, **log_attrs, ) From ec1c616cf77247d29eb22271c8db2709f6e92439 Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Fri, 20 Oct 2023 08:47:15 +0100 Subject: [PATCH 18/19] refactoring away contract.log(), which uses log.setup() --- sysbrokers/IB/ib_futures_contract_price_data.py | 15 ++++++++++----- 1 file changed, 10 insertions(+), 5 deletions(-) diff --git a/sysbrokers/IB/ib_futures_contract_price_data.py b/sysbrokers/IB/ib_futures_contract_price_data.py index dabefa80bd..dbfc2e3e04 100644 --- a/sysbrokers/IB/ib_futures_contract_price_data.py +++ b/sysbrokers/IB/ib_futures_contract_price_data.py @@ -231,7 +231,10 @@ def _get_prices_at_frequency_for_ibcontract_object_no_checking( allow_expired: bool = False, ) -> futuresContractPrices: - new_log = contract_object_with_ib_broker_config.log(self.log) + log_attrs = { + **contract_object_with_ib_broker_config.log_attributes(), + "method": "temp", + } try: price_data = self.ib_client.broker_get_historical_futures_data_for_contract( @@ -240,16 +243,18 @@ def _get_prices_at_frequency_for_ibcontract_object_no_checking( allow_expired=allow_expired, ) except missingData: - new_log.warning( + self.log.warning( "Something went wrong getting IB price data for %s" - % str(contract_object_with_ib_broker_config) + % str(contract_object_with_ib_broker_config), + **log_attrs, ) raise if len(price_data) == 0: - new_log.warning( + self.log.warning( "No IB price data found for %s" - % str(contract_object_with_ib_broker_config) + % str(contract_object_with_ib_broker_config), + **log_attrs, ) return futuresContractPrices.create_empty() From cffecf45962bbb235589ca2f48f26e89f4f2434e Mon Sep 17 00:00:00 2001 From: Andy Geach Date: Tue, 24 Oct 2023 16:06:39 +0100 Subject: [PATCH 19/19] log twice twice --- sysbrokers/IB/client/ib_contracts_client.py | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/sysbrokers/IB/client/ib_contracts_client.py b/sysbrokers/IB/client/ib_contracts_client.py index 096b36a98c..017b3ab118 100644 --- a/sysbrokers/IB/client/ib_contracts_client.py +++ b/sysbrokers/IB/client/ib_contracts_client.py @@ -235,8 +235,7 @@ def ib_get_saved_weekly_trading_hours_for_timezone_of_contract( "Check ib_config_trading_hours in sysbrokers/IB or private directory, hours for timezone %s not found!" % time_zone_id ) - # TODO check this double log - self.log.log.critical(error_msg, **log_attrs) + self.log.critical(error_msg, **log_attrs) raise missingData return weekly_hours_for_timezone