Skip to content

Commit

Permalink
Add log filtering config options
Browse files Browse the repository at this point in the history
Avoids the cost of forming Python strings for logs which will be ignored.
  • Loading branch information
cjdsellers committed Jan 14, 2025
1 parent 889ade6 commit bee3511
Show file tree
Hide file tree
Showing 15 changed files with 71 additions and 30 deletions.
5 changes: 3 additions & 2 deletions RELEASES.md
Original file line number Diff line number Diff line change
Expand Up @@ -3,17 +3,18 @@
Released on TBD (UTC).

### Enhancements
None
- Added `log_commands` config option for `ActorConfig`, `StrategyConfig`, `ExecAlgorithmConfig` for more efficient log filtering

### Breaking Changes
None
- Renamed `event_logging` config option to `log_events`

### Internal Improvements
- Ported market order filling for OrderMatchingEngine in Rust (#2202), thanks @filipmacek

### Fixes
- Fixed backtest start and end time validation assertion (#2203), thanks @davidsblom
- Fixed `CustomData` import in `DataEngine` (#2207), thanks @graceyangfan and @faysou
- Fixed databento helper function (#2208), thanks @faysou

### Documentation Updates
None
Expand Down
2 changes: 2 additions & 0 deletions nautilus_trader/common/actor.pxd
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,8 @@ from nautilus_trader.portfolio.base cimport PortfolioFacade

cdef class Actor(Component):
cdef object _executor
cdef bint _log_events
cdef bint _log_commands
cdef set[type] _warning_events
cdef dict[UUID4, object] _pending_requests
cdef set[type] _pyo3_conversion_types
Expand Down
4 changes: 3 additions & 1 deletion nautilus_trader/common/actor.pyx
Original file line number Diff line number Diff line change
Expand Up @@ -130,6 +130,8 @@ cdef class Actor(Component):
self._indicators_for_bars: dict[BarType, list[Indicator]] = {}

# Configuration
self._log_events = config.log_events
self._log_commands = config.log_commands
self.config = config

self.trader_id = None # Initialized when registered
Expand Down Expand Up @@ -3290,7 +3292,7 @@ cdef class Actor(Component):
# -- EGRESS ---------------------------------------------------------------------------------------

cdef void _send_data_cmd(self, DataCommand command):
if is_logging_initialized():
if self._log_commands and is_logging_initialized():
self._log.info(f"{CMD}{SENT} {command}")
self._msgbus.send(endpoint="DataEngine.execute", msg=command)

Expand Down
7 changes: 7 additions & 0 deletions nautilus_trader/common/config.py
Original file line number Diff line number Diff line change
Expand Up @@ -415,10 +415,17 @@ class ActorConfig(NautilusConfig, kw_only=True, frozen=True):
component_id : ComponentId, optional
The component ID. If ``None`` then the identifier will be taken from
`type(self).__name__`.
log_events : bool, default True
If events should be logged by the actor.
If False, then only warning events and above are logged.
log_commands : bool, default True
If commands should be logged by the actor.
"""

component_id: ComponentId | None = None
log_events: bool = True
log_commands: bool = True


class ImportableActorConfig(NautilusConfig, frozen=True):
Expand Down
12 changes: 7 additions & 5 deletions nautilus_trader/execution/algorithm.pyx
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,6 @@ from libc.stdint cimport uint64_t
from nautilus_trader.cache.base cimport CacheFacade
from nautilus_trader.common.actor cimport Actor
from nautilus_trader.common.component cimport CMD
from nautilus_trader.common.component cimport EVT
from nautilus_trader.common.component cimport RECV
from nautilus_trader.common.component cimport SENT
from nautilus_trader.common.component cimport Clock
Expand Down Expand Up @@ -118,6 +117,8 @@ cdef class ExecAlgorithm(Actor):
self.id = config.exec_algorithm_id or ExecAlgorithmId(type(self).__name__)

# Configuration
self._log_events = config.log_events
self._log_commands = config.log_commands
self.config = config

self._exec_spawn_ids: dict[ClientOrderId, int] = {}
Expand Down Expand Up @@ -253,7 +254,8 @@ cdef class ExecAlgorithm(Actor):
"""
Condition.not_none(command, "command")

self._log.debug(f"{RECV}{CMD} {command}", LogColor.MAGENTA)
if self._log_commands:
self._log.debug(f"{RECV}{CMD} {command}", LogColor.MAGENTA)

if self._fsm.state != ComponentState.RUNNING:
return
Expand Down Expand Up @@ -1460,16 +1462,16 @@ cdef class ExecAlgorithm(Actor):
# -- EGRESS ---------------------------------------------------------------------------------------

cdef void _send_emulator_command(self, TradingCommand command):
if is_logging_initialized():
if self._log_commands and is_logging_initialized():
self.log.info(f"{CMD}{SENT} {command}.")
self._msgbus.send(endpoint="OrderEmulator.execute", msg=command)

cdef void _send_risk_command(self, TradingCommand command):
if is_logging_initialized():
if self._log_commands and is_logging_initialized():
self.log.info(f"{CMD}{SENT} {command}.")
self._msgbus.send(endpoint="RiskEngine.execute", msg=command)

cdef void _send_exec_command(self, TradingCommand command):
if is_logging_initialized():
if self._log_commands and is_logging_initialized():
self.log.info(f"{CMD}{SENT} {command}.")
self._msgbus.send(endpoint="ExecEngine.execute", msg=command)
7 changes: 7 additions & 0 deletions nautilus_trader/execution/config.py
Original file line number Diff line number Diff line change
Expand Up @@ -71,10 +71,17 @@ class ExecAlgorithmConfig(NautilusConfig, kw_only=True, frozen=True):
exec_algorithm_id : ExecAlgorithmId, optional
The unique ID for the execution algorithm.
If not ``None`` then will become the execution algorithm ID.
log_events : bool, default True
If events should be logged by the execution algorithm.
If False, then only warning events and above are logged.
log_commands : bool, default True
If commands should be logged by the execution algorithm.
"""

exec_algorithm_id: ExecAlgorithmId | None = None
log_events: bool = True
log_commands: bool = True


class ImportableExecAlgorithmConfig(NautilusConfig, frozen=True):
Expand Down
2 changes: 2 additions & 0 deletions nautilus_trader/execution/manager.pxd
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,8 @@ cdef class OrderManager:

cdef readonly bint active_local
cdef readonly bint debug
cdef readonly bint log_events
cdef readonly bint log_commands

cdef dict _submit_order_commands
cdef object _submit_order_handler
Expand Down
17 changes: 10 additions & 7 deletions nautilus_trader/execution/manager.pyx
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,6 @@ from libc.stdint cimport uint64_t
from nautilus_trader.cache.cache cimport Cache
from nautilus_trader.common.component cimport CMD
from nautilus_trader.common.component cimport EVT
from nautilus_trader.common.component cimport RECV
from nautilus_trader.common.component cimport SENT
from nautilus_trader.common.component cimport Clock
from nautilus_trader.common.component cimport LogColor
Expand Down Expand Up @@ -101,6 +100,8 @@ cdef class OrderManager:
cancel_order_handler: Callable[[Order], None] = None,
modify_order_handler: Callable[[Order, Quantity], None] = None,
bint debug = False,
bint log_events = True,
bint log_commands = True,
):
Condition.valid_string(component_name, "component_name")
Condition.callable_or_none(submit_order_handler, "submit_order_handler")
Expand All @@ -114,6 +115,8 @@ cdef class OrderManager:

self.active_local = active_local
self.debug = debug
self.log_events = log_events
self.log_commands = log_commands
self._submit_order_handler = submit_order_handler
self._cancel_order_handler = cancel_order_handler
self._modify_order_handler = modify_order_handler
Expand Down Expand Up @@ -554,42 +557,42 @@ cdef class OrderManager:
cpdef void send_emulator_command(self, TradingCommand command):
Condition.not_none(command, "command")

if is_logging_initialized():
if self.log_commands and is_logging_initialized():
self._log.info(f"{CMD}{SENT} {command}") # pragma: no cover (no logging in tests)
self._msgbus.send(endpoint="OrderEmulator.execute", msg=command)

cpdef void send_algo_command(self, TradingCommand command, ExecAlgorithmId exec_algorithm_id):
Condition.not_none(command, "command")
Condition.not_none(exec_algorithm_id, "exec_algorithm_id")

if is_logging_initialized():
if self.log_commands and is_logging_initialized():
self._log.info(f"{CMD}{SENT} {command}") # pragma: no cover (no logging in tests)
self._msgbus.send(endpoint=f"{exec_algorithm_id}.execute", msg=command)

cpdef void send_risk_command(self, TradingCommand command):
Condition.not_none(command, "command")

if is_logging_initialized():
if self.log_commands and is_logging_initialized():
self._log.info(f"{CMD}{SENT} {command}") # pragma: no cover (no logging in tests)
self._msgbus.send(endpoint="RiskEngine.execute", msg=command)

cpdef void send_exec_command(self, TradingCommand command):
Condition.not_none(command, "command")

if is_logging_initialized():
if self.log_commands and is_logging_initialized():
self._log.info(f"{CMD}{SENT} {command}") # pragma: no cover (no logging in tests)
self._msgbus.send(endpoint="ExecEngine.execute", msg=command)

cpdef void send_risk_event(self, OrderEvent event):
Condition.not_none(event, "event")

if is_logging_initialized():
if self.log_events and is_logging_initialized():
self._log.info(f"{EVT}{SENT} {event}") # pragma: no cover (no logging in tests)
self._msgbus.send(endpoint="RiskEngine.process", msg=event)

cpdef void send_exec_event(self, OrderEvent event):
Condition.not_none(event, "event")

if is_logging_initialized():
if self.log_events and is_logging_initialized():
self._log.info(f"{EVT}{SENT} {event}") # pragma: no cover (no logging in tests)
self._msgbus.send(endpoint="ExecEngine.process", msg=event)
9 changes: 6 additions & 3 deletions nautilus_trader/trading/config.py
Original file line number Diff line number Diff line change
Expand Up @@ -51,9 +51,11 @@ class StrategyConfig(NautilusConfig, kw_only=True, frozen=True):
manage_gtd_expiry : bool, default False
If all order GTD time in force expirations should be managed by the strategy.
If True, then will ensure open orders have their GTD timers re-activated on start.
event_logging : bool, default True
If event logging should be enabled for the strategy.
log_events : bool, default True
If events should be logged by the strategy.
If False, then only warning events and above are logged.
log_commands : bool, default True
If commands should be logged by the strategy.
"""

Expand All @@ -63,7 +65,8 @@ class StrategyConfig(NautilusConfig, kw_only=True, frozen=True):
external_order_claims: list[InstrumentId] | None = None
manage_contingent_orders: bool = False
manage_gtd_expiry: bool = False
event_logging: bool = True
log_events: bool = True
log_commands: bool = True


class ImportableStrategyConfig(NautilusConfig, frozen=True):
Expand Down
2 changes: 0 additions & 2 deletions nautilus_trader/trading/strategy.pxd
Original file line number Diff line number Diff line change
Expand Up @@ -81,8 +81,6 @@ cdef class Strategy(Actor):
"""If contingent orders should be managed automatically by the strategy.\n\n:returns: `bool`"""
cdef readonly bint manage_gtd_expiry
"""If all order GTD time in force expirations should be managed automatically by the strategy.\n\n:returns: `bool`"""
cdef readonly bint event_logging
"""If event logging should be enabled for the strategy.\n\n:returns: `bool`"""

# -- REGISTRATION ---------------------------------------------------------------------------------

Expand Down
9 changes: 5 additions & 4 deletions nautilus_trader/trading/strategy.pyx
Original file line number Diff line number Diff line change
Expand Up @@ -33,10 +33,8 @@ from libc.stdint cimport uint64_t
from nautilus_trader.cache.base cimport CacheFacade
from nautilus_trader.cache.cache cimport Cache
from nautilus_trader.common.actor cimport Actor
from nautilus_trader.common.component cimport CMD
from nautilus_trader.common.component cimport EVT
from nautilus_trader.common.component cimport RECV
from nautilus_trader.common.component cimport SENT
from nautilus_trader.common.component cimport Clock
from nautilus_trader.common.component cimport LogColor
from nautilus_trader.common.component cimport MessageBus
Expand Down Expand Up @@ -147,12 +145,13 @@ cdef class Strategy(Actor):
self.order_id_tag = str(config.order_id_tag)

# Configuration
self._log_events = config.log_events
self._log_commands = config.log_commands
self.config = config
self.oms_type = oms_type_from_str(str(config.oms_type).upper()) if config.oms_type else OmsType.UNSPECIFIED
self.external_order_claims = self._parse_external_order_claims(config.external_order_claims)
self.manage_contingent_orders = config.manage_contingent_orders
self.manage_gtd_expiry = config.manage_gtd_expiry
self.event_logging = config.event_logging

# Public components
self.clock = self._clock
Expand Down Expand Up @@ -294,6 +293,8 @@ cdef class Strategy(Actor):
cancel_order_handler=self.cancel_order,
modify_order_handler=self.modify_order,
debug=False, # Set True for debugging
log_events=self._log_events,
log_commands=self._log_commands,
)

# Required subscriptions
Expand Down Expand Up @@ -1530,7 +1531,7 @@ cdef class Strategy(Actor):

if type(event) in self._warning_events:
self.log.warning(f"{RECV}{EVT} {event}")
elif self.event_logging:
elif self._log_events:
self.log.info(f"{RECV}{EVT} {event}")

cdef Order order
Expand Down
6 changes: 5 additions & 1 deletion tests/unit_tests/common/test_actor.py
Original file line number Diff line number Diff line change
Expand Up @@ -135,7 +135,11 @@ def test_actor_fully_qualified_name(self) -> None:
assert isinstance(result, ImportableActorConfig)
assert result.actor_path == "nautilus_trader.common.actor:Actor"
assert result.config_path == "nautilus_trader.common.config:ActorConfig"
assert result.config == {"component_id": "ALPHA-01"}
assert result.config == {
"component_id": "ALPHA-01",
"log_events": True,
"log_commands": True,
}

def test_id(self) -> None:
# Arrange, Act
Expand Down
5 changes: 4 additions & 1 deletion tests/unit_tests/common/test_config.py
Original file line number Diff line number Diff line change
Expand Up @@ -56,4 +56,7 @@ def test_create_actor_from_importable_config() -> None:

# Assert
assert isinstance(actor, MockActor)
assert repr(actor.config) == "MockActorConfig(component_id='MyActor')"
assert (
repr(actor.config)
== "MockActorConfig(component_id='MyActor', log_events=True, log_commands=True)"
)
6 changes: 5 additions & 1 deletion tests/unit_tests/execution/test_algorithm.py
Original file line number Diff line number Diff line change
Expand Up @@ -200,7 +200,11 @@ def test_exec_algorithm_to_importable_config(self) -> None:
assert config.dict() == {
"exec_algorithm_path": "nautilus_trader.examples.algorithms.twap:TWAPExecAlgorithm",
"config_path": "nautilus_trader.examples.algorithms.twap:TWAPExecAlgorithmConfig",
"config": {"exec_algorithm_id": ExecAlgorithmId("TWAP")},
"config": {
"exec_algorithm_id": ExecAlgorithmId("TWAP"),
"log_events": True,
"log_commands": True,
},
}

def test_exec_algorithm_spawn_market_order_with_quantity_too_high(self) -> None:
Expand Down
8 changes: 5 additions & 3 deletions tests/unit_tests/trading/test_strategy.py
Original file line number Diff line number Diff line change
Expand Up @@ -194,7 +194,8 @@ def test_strategy_to_importable_config_with_no_specific_config(self) -> None:
"external_order_claims": None,
"manage_contingent_orders": False,
"manage_gtd_expiry": False,
"event_logging": True,
"log_events": True,
"log_commands": True,
}

def test_strategy_to_importable_config(self) -> None:
Expand All @@ -205,7 +206,7 @@ def test_strategy_to_importable_config(self) -> None:
external_order_claims=["ETHUSDT-PERP.DYDX"],
manage_contingent_orders=True,
manage_gtd_expiry=True,
event_logging=False,
log_events=False,
)

strategy = Strategy(config=config)
Expand All @@ -224,7 +225,8 @@ def test_strategy_to_importable_config(self) -> None:
"external_order_claims": ["ETHUSDT-PERP.DYDX"],
"manage_contingent_orders": True,
"manage_gtd_expiry": True,
"event_logging": False,
"log_events": False,
"log_commands": True,
}

def test_strategy_equality(self) -> None:
Expand Down

0 comments on commit bee3511

Please sign in to comment.