diff --git a/docs/source/finam-book/development/adapters.rst b/docs/source/finam-book/development/adapters.rst
index e0ad6484e992aa8a87b0343ec2fffe39af1f6c61..8953d7158ce0fa23f7b45557b02fe0dcb0429f4c 100644
--- a/docs/source/finam-book/development/adapters.rst
+++ b/docs/source/finam-book/development/adapters.rst
@@ -70,13 +70,14 @@ File ``src/scale.py``:
generator.outputs["Value"] >> adapter >> consumer.inputs["Input"]
- comp.run(end_time=datetime(2000, 1, 2))
+ comp.run(end_time=datetime(2000, 1, 2)) # doctest: +ELLIPSIS
print(consumer.data["Input"][0, ...])
.. testoutput:: scale-adapter
:hide:
+ ...
0.5 dimensionless
In :meth:`.Adapter._get_data`, we:
@@ -238,13 +239,14 @@ In :meth:`.Adapter._get_data`, we can now do the interpolation whenever data is
generator.outputs["Value"] >> adapter >> consumer.inputs["Input"]
- comp.run(end_time=datetime(2000, 1, 15))
+ comp.run(end_time=datetime(2000, 1, 15)) # doctest: +ELLIPSIS
print(consumer.data["Input"][0, ...])
.. testoutput:: time-adapter
:hide:
+ ...
15.0 dimensionless
In :meth:`.Adapter._get_data`, the following happens:
diff --git a/docs/source/finam-book/development/connect_phase.rst b/docs/source/finam-book/development/connect_phase.rst
index 0c81772fcda9fdfdcb7ae56dc2e6d5b81d8e3208..fed7eda6f18911ba02ab05edf0307ec9a99d7caa 100644
--- a/docs/source/finam-book/development/connect_phase.rst
+++ b/docs/source/finam-book/development/connect_phase.rst
@@ -197,7 +197,13 @@ In the most simple case, all metadata is known in :meth:`.Component._initialize`
generator.outputs["Output2"] >> simple_conn.inputs["B"]
simple_conn.outputs["Area"] >> consumer.inputs["Input"]
- comp.connect()
+ comp.connect() # doctest: +ELLIPSIS
+
+.. testoutput:: simple-connect
+ :hide:
+
+ ...
+
In :meth:`.Component._initialize`, we create inputs and outputs with metadata (here ``grid`` and ``units``).
Then, we create the connector with :meth:`.Component.create_connector`. No arguments required here, as there are no dependencies.
@@ -284,7 +290,13 @@ and the initial data should be generated from it.
generator.outputs["Output2"] >> complex_conn.inputs["B"]
complex_conn.outputs["Area"] >> consumer.inputs["Input"]
- comp.connect()
+ comp.connect() # doctest: +ELLIPSIS
+
+.. testoutput:: complex-connect
+ :hide:
+
+ ...
+
In :meth:`.Component._initialize`, we set the ``grid`` of input ``"A"`` to ``None``.
It will be filled from the connected output, and becomes available in
diff --git a/docs/source/finam-book/development/special_components.rst b/docs/source/finam-book/development/special_components.rst
index 9a3ffde43a6b9d28a94094a366b6540611276aa6..17b52a4b70300bdc4f56c036c29549c4c8843b92 100644
--- a/docs/source/finam-book/development/special_components.rst
+++ b/docs/source/finam-book/development/special_components.rst
@@ -82,8 +82,12 @@ Push-based components can use :class:`.CallbackInput` to get informed about inco
generator.outputs["Value"] >> push_comp.inputs["Input"]
- comp.run(end_time=datetime(2000, 1, 15))
+ comp.run(end_time=datetime(2000, 1, 15)) # doctest: +ELLIPSIS
+.. testoutput:: push-component
+ :hide:
+
+ ...
In ``_initialize()``, a :class:`.CallbackInput` is added that calls ``_data_changed()`` when notified about new data.
@@ -153,7 +157,12 @@ Push-based components can use :class:`.CallbackOutput` to intercept data pulls.
pull_comp.outputs["Output"] >> consumer.inputs["Input"]
- comp.run(end_time=datetime(2000, 1, 15))
+ comp.run(end_time=datetime(2000, 1, 15)) # doctest: +ELLIPSIS
+
+.. testoutput:: pull-component
+ :hide:
+
+ ...
In ``_initialize()``, a :class:`.CallbackOutput` is added that calls ``_get_data()`` when pulled.
``_get_data()`` must return the data that would normally be pushed to the output.
diff --git a/docs/source/finam-book/usage/coupling_scripts.rst b/docs/source/finam-book/usage/coupling_scripts.rst
index db7a54a5e9a67d53ee0a0d30cfbc6cb74504bc2d..b3b03e9736539a34cfcf4b83737e0386e305fcee 100644
--- a/docs/source/finam-book/usage/coupling_scripts.rst
+++ b/docs/source/finam-book/usage/coupling_scripts.rst
@@ -246,7 +246,7 @@ There you have several options:
- ``<pathlike>``: log file will be created under the given path
- ``log_level``: (int) this will control the level of logging (:data:`logging.INFO` by default)
- only log messages with a level equal or higher than the given logging level will be shown
- - options are (from most to least verbose): :data:`logging.DEBUG`, :data:`logging.INFO`, :data:`logging.WARNING`, :data:`logging.ERROR`, :data:`logging.CRITICAL` or any positive integer number
+ - options are (from most to least verbose): :data:`logging.TRACE`, :data:`logging.DEBUG`, :data:`logging.PROFILE`, :data:`logging.INFO`, :data:`logging.WARNING`, :data:`logging.ERROR`, :data:`logging.CRITICAL` or any positive integer number
A log file could look like this, when setting the logging level to :data:`logging.INFO`:
diff --git a/src/finam/__init__.py b/src/finam/__init__.py
index 3152946ed01e85b2ab77a02b363c5166a2d43fed..b9ba0ceffda7f13a2d1f306f00541501a8c04875 100644
--- a/src/finam/__init__.py
+++ b/src/finam/__init__.py
@@ -187,6 +187,9 @@ except ModuleNotFoundError: # pragma: no cover
# package is not installed
__version__ = "0.0.0.dev0"
+tools.log_helper.add_logging_level("TRACE", 5)
+tools.log_helper.add_logging_level("PROFILE", 15)
+
__all__ = ["__version__"]
__all__ += ["adapters", "data", "interfaces", "modules", "schedule", "sdk", "tools"]
diff --git a/src/finam/data/tools.py b/src/finam/data/tools.py
index 7989a63a159420d5dca43b82c23eb2e31da53417..b5c243aed9aba397cc7d15ddc23d078ba9f5ae33 100644
--- a/src/finam/data/tools.py
+++ b/src/finam/data/tools.py
@@ -20,7 +20,7 @@ UNITS = pint.application_registry
_UNIT_PAIRS_CACHE = {}
-def prepare(data, info, time_entries=1, force_copy=False):
+def prepare(data, info, time_entries=1, force_copy=False, report_conversion=False):
"""
Prepares data in FINAM's internal transmission format.
@@ -39,17 +39,26 @@ def prepare(data, info, time_entries=1, force_copy=False):
Forces the result to be a copy of the passed data. Default `False`.
If not used, the result is a view of the data if no units conversion needs to be done.
+ report_conversion : bool, optional
+ If true, returns a tuple with the second element indicating the unit conversion if it was required.
Returns
-------
- pint.Quantity
+ pint.Quantity or tuple(pint.Quantity, tuple(pint.Unit, pint.Unit) or None)
The prepared data as a numpy array, wrapped into a :class:`pint.Quantity`.
+ If ``report_conversion`` is ``True``, a tuple is returned with the second element
+ indicating the unit conversion if it was required.
+
+ The second element is ``None`` if no conversion was required,
+ and a tuple of two :class:`pint.Unit` objects otherwise.
+
Raises
------
FinamDataError
If the data doesn't match its info.
"""
+ units_converted = None
units = info.units
if isinstance(data, pint.Quantity):
if not compatible_units(data.units, units):
@@ -57,26 +66,25 @@ def prepare(data, info, time_entries=1, force_copy=False):
f"Given data has incompatible units. "
f"Got {data.units}, expected {units}."
)
- if not isinstance(data.magnitude, np.ndarray):
- data = np.asarray(data.magnitude) * data.units
-
if not equivalent_units(data.units, units):
+ units_converted = data.units, units
data = data.to(units)
elif force_copy:
data = data.copy()
else:
if isinstance(data, np.ndarray):
if force_copy:
- data = data * units
- else:
- data = UNITS.Quantity(data, units)
+ data = np.copy(data)
+ data = UNITS.Quantity(data, units)
else:
if force_copy:
- data = np.asarray(data) * units
- else:
- data = UNITS.Quantity(np.asarray(data), units)
+ data = copy.copy(data)
+ data = UNITS.Quantity(np.asarray(data), units)
data = _check_input_shape(data, info, time_entries)
+
+ if report_conversion:
+ return data, units_converted
return data
@@ -272,7 +280,7 @@ def get_dimensionality(xdata):
return xdata.dimensionality
-def to_units(xdata, units, check_equivalent=False):
+def to_units(xdata, units, check_equivalent=False, report_conversion=False):
"""
Convert data to given units.
@@ -284,20 +292,34 @@ def to_units(xdata, units, check_equivalent=False):
Desired units.
check_equivalent : bool, optional
Checks for equivalent units and simply re-assigns if possible.
+ report_conversion : bool, optional
+ If true, returns a tuple with the second element indicating the unit conversion if it was required.
Returns
-------
- pint.Quantity
- Converted data.
+ pint.Quantity or tuple(pint.Quantity, tuple(pint.Unit, pint.Unit) or None)
+ The converted data.
+
+ If ``report_conversion`` is ``True``, a tuple is returned with the second element
+ indicating the unit conversion if it was required.
+
+ The second element is ``None`` if no conversion was required,
+ and a tuple of two :class:`pint.Unit` objects otherwise.
"""
check_quantified(xdata, "to_units")
units = _get_pint_units(units)
units2 = xdata.units
- if units == units2:
- return xdata
- if check_equivalent and equivalent_units(units, units2):
- return UNITS.Quantity(xdata.magnitude, units)
- return xdata.to(units)
+ conversion = None
+ if units != units2:
+ if check_equivalent and equivalent_units(units, units2):
+ xdata = UNITS.Quantity(xdata.magnitude, units)
+ else:
+ xdata = xdata.to(units)
+ conversion = units2, units
+
+ if report_conversion:
+ return xdata, conversion
+ return xdata
def full_like(xdata, value):
diff --git a/src/finam/schedule.py b/src/finam/schedule.py
index 1b98b6750a9a4c05d7b6bb16016a2573e6a135af..171c5291f000a86913849c3c11de9b7d946fcec9 100644
--- a/src/finam/schedule.py
+++ b/src/finam/schedule.py
@@ -132,7 +132,7 @@ class Composition(Loggable):
After the call, module inputs and outputs are available for linking.
"""
- self.logger.debug("init composition")
+ self.logger.info("init composition")
if self.is_initialized:
raise FinamStatusError("Composition was already initialized.")
@@ -203,7 +203,7 @@ class Composition(Loggable):
self._connect_components(start_time)
- self.logger.debug("validate components")
+ self.logger.info("validate components")
for mod in self.modules:
mod.validate()
self._check_status(mod, [ComponentStatus.VALIDATED])
@@ -245,7 +245,7 @@ class Composition(Loggable):
if not self.is_connected:
self.connect(start_time)
- self.logger.debug("running composition")
+ self.logger.info("run composition")
while len(time_modules) > 0:
sort_modules = list(time_modules)
sort_modules.sort(key=lambda m: m.time)
@@ -324,7 +324,7 @@ class Composition(Loggable):
def _validate_composition(self):
"""Validates the coupling setup by checking for dangling inputs and disallowed branching connections."""
- self.logger.debug("validate composition")
+ self.logger.info("validate composition")
for mod in self.modules:
with ErrorLogger(mod.logger if is_loggable(mod) else self.logger):
for inp in mod.inputs.values():
@@ -338,7 +338,7 @@ class Composition(Loggable):
_check_missing_modules(self.modules)
def _connect_components(self, time):
- self.logger.debug("connect components")
+ self.logger.info("connect components")
counter = 0
while True:
self.logger.debug("connect iteration %d", counter)
@@ -380,7 +380,7 @@ class Composition(Loggable):
counter += 1
def _finalize_components(self):
- self.logger.debug("finalize components")
+ self.logger.info("finalize components")
for mod in self.modules:
self._check_status(
mod,
@@ -404,7 +404,7 @@ class Composition(Loggable):
ada.finalize()
def _finalize_composition(self):
- self.logger.debug("finalize composition")
+ self.logger.info("finalize composition")
handlers = self.logger.handlers[:]
for handler in handlers:
self.logger.removeHandler(handler)
diff --git a/src/finam/sdk/adapter.py b/src/finam/sdk/adapter.py
index 14bcb03d0bb03e822a6653363307214ee00b0fb7..fdf86ff71068ffc3fef59ef2e957e2dc7383ab43 100644
--- a/src/finam/sdk/adapter.py
+++ b/src/finam/sdk/adapter.py
@@ -90,7 +90,7 @@ class Adapter(IAdapter, Input, Output, ABC):
time : :class:`datetime <datetime.datetime>`
Simulation time of the notification.
"""
- self.logger.debug("source changed")
+ self.logger.debug("source updated")
if time is not None and not isinstance(time, datetime):
with ErrorLogger(self.logger):
raise ValueError("Time must be of type datetime")
@@ -107,7 +107,7 @@ class Adapter(IAdapter, Input, Output, ABC):
time : :class:`datetime <datetime.datetime>`
Simulation time of the simulation.
"""
- self.logger.debug("notify targets")
+ self.logger.trace("notify targets")
if time is not None and not isinstance(time, datetime):
with ErrorLogger(self.logger):
raise ValueError("Time must be of type datetime")
@@ -154,7 +154,12 @@ class Adapter(IAdapter, Input, Output, ABC):
data = self._get_data(time, target)
with ErrorLogger(self.logger):
- return tools.prepare(data, self._output_info)
+ xdata, conv = tools.prepare(data, self._output_info, report_conversion=True)
+ if conv is not None:
+ self.logger.profile(
+ "converted units from %s to %s (%d entries)", *conv, xdata.size
+ )
+ return xdata
def _get_data(self, time, target):
"""Get the transformed data of this adapter.
@@ -195,7 +200,7 @@ class Adapter(IAdapter, Input, Output, ABC):
FinamNoDataError
Raises the error if no info is available
"""
- self.logger.debug("get info")
+ self.logger.trace("get info")
self._output_info = self._get_info(info)
return self._output_info
@@ -234,7 +239,7 @@ class Adapter(IAdapter, Input, Output, ABC):
Info
delivered parameters
"""
- self.logger.debug("exchanging info")
+ self.logger.trace("exchanging info")
with ErrorLogger(self.logger):
if info is None:
raise FinamMetaDataError("No metadata provided")
@@ -255,7 +260,7 @@ class Adapter(IAdapter, Input, Output, ABC):
source :
source output or adapter
"""
- self.logger.debug("set source")
+ self.logger.trace("set source")
# fix to set base-logger for adapters derived from Input source logger
if self.uses_base_logger_name and not is_loggable(source):
with ErrorLogger(self.logger):
@@ -326,7 +331,12 @@ class TimeDelayAdapter(Adapter, ITimeDelayAdapter, ABC):
self._pulled(time)
with ErrorLogger(self.logger):
- return tools.prepare(data, self._output_info)
+ xdata, conv = tools.prepare(data, self._output_info, report_conversion=True)
+ if conv is not None:
+ self.logger.profile(
+ "converted units from %s to %s (%d entries)", *conv, xdata.size
+ )
+ return xdata
def _get_data(self, time, target):
"""Get the output's data-set for the given time.
@@ -377,7 +387,7 @@ class TimeDelayAdapter(Adapter, ITimeDelayAdapter, ABC):
FinamNoDataError
Raises the error if no info is available
"""
- self.logger.debug("get info")
+ self.logger.trace("get info")
self._output_info = self._get_info(info)
self.initial_time = self._output_info.time
return self._output_info
diff --git a/src/finam/sdk/component.py b/src/finam/sdk/component.py
index 24c1fd7316c02a3aca50a9dd24b141bbd70b0e4a..aa4d3a1e62590f07d30ae227548d79e621f2bf8e 100644
--- a/src/finam/sdk/component.py
+++ b/src/finam/sdk/component.py
@@ -146,9 +146,10 @@ class Component(IComponent, Loggable, ABC):
After the method call, the component should have :attr:`.status`
:attr:`.ComponentStatus.UPDATED` or :attr:`.ComponentStatus.FINISHED`.
"""
- self.logger.debug("update")
if isinstance(self, ITimeComponent):
- self.logger.debug("current time: %s", self.time)
+ self.logger.debug("update - current time: %s", self.time)
+ else:
+ self.logger.debug("update")
self._update()
@@ -335,7 +336,7 @@ class Component(IComponent, Loggable, ABC):
Rules are evaluated in the given order. Later rules can overwrite attributes set by earlier rules.
"""
- self.logger.debug("create connector")
+ self.logger.trace("create connector")
self._connector = ConnectHelper(
self.logger_name,
self.inputs,
@@ -373,7 +374,7 @@ class Component(IComponent, Loggable, ABC):
push_data : dict of [str, array-like]
currently or newly available output data by output name
"""
- self.logger.debug("try connect")
+ self.logger.trace("try connect")
if self._connector is None:
raise FinamStatusError(
@@ -386,7 +387,7 @@ class Component(IComponent, Loggable, ABC):
push_infos=push_infos,
push_data=push_data,
)
- self.logger.debug("try_connect status is %s", self.status)
+ self.logger.trace("try_connect status is %s", self.status)
def __getitem__(self, name):
"""Get an input or output by name. Implements access through square brackets.
diff --git a/src/finam/sdk/input.py b/src/finam/sdk/input.py
index 2a8a951ac184448011a600a8eee08c66c6f429fd..ec9ba53621e7ea95a231f18c7a86b25f7d872e6e 100644
--- a/src/finam/sdk/input.py
+++ b/src/finam/sdk/input.py
@@ -57,7 +57,7 @@ class Input(IInput, Loggable):
source : :class:`.IOutput`
source output or adapter
"""
- self.logger.debug("set source")
+ self.logger.trace("set source")
with ErrorLogger(self.logger):
if self.source is not None:
@@ -88,7 +88,7 @@ class Input(IInput, Loggable):
time : :class:`datetime <datetime.datetime>`
Simulation time of the notification.
"""
- self.logger.debug("source changed")
+ self.logger.trace("source changed")
def pull_data(self, time, target=None):
"""Retrieve the data from the input's source.
@@ -108,7 +108,7 @@ class Input(IInput, Loggable):
:class:`pint.Quantity`
Data set for the given simulation time.
"""
- self.logger.debug("pull data")
+ self.logger.trace("pull data")
if time is not None and not isinstance(time, datetime):
with ErrorLogger(self.logger):
@@ -116,15 +116,27 @@ class Input(IInput, Loggable):
if self.is_static:
if self._cached_data is None:
- self._cached_data = self.source.get_data(time, target or self)
+ with ErrorLogger(self.logger):
+ data = self.source.get_data(time, target or self)
+ self._cached_data = self._convert_and_check(data)
+
data = self._cached_data
else:
data = self.source.get_data(time, target or self)
+ with ErrorLogger(self.logger):
+ data = self._convert_and_check(data)
- with ErrorLogger(self.logger):
- data = tools.to_units(data, self._input_info.units, check_equivalent=True)
- tools.check(data, self._input_info)
+ return data
+ def _convert_and_check(self, data):
+ (data, conv) = tools.to_units(
+ data, self._input_info.units, check_equivalent=True, report_conversion=True
+ )
+ if conv is not None:
+ self.logger.profile(
+ "converted units from %s to %s (%d entries)", *conv, data.size
+ )
+ tools.check(data, self._input_info)
return data
def ping(self):
@@ -147,7 +159,7 @@ class Input(IInput, Loggable):
dict
delivered parameters
"""
- self.logger.debug("exchanging info")
+ self.logger.trace("exchanging info")
with ErrorLogger(self.logger):
if self._in_info_exchanged:
@@ -234,7 +246,7 @@ class CallbackInput(Input):
time : :class:`datetime <datetime.datetime>`
Simulation time of the notification.
"""
- self.logger.debug("source changed")
+ self.logger.trace("source changed")
if time is not None and not isinstance(time, datetime):
with ErrorLogger(self.logger):
raise ValueError("Time must be of type datetime")
diff --git a/src/finam/sdk/output.py b/src/finam/sdk/output.py
index bc1250e9665cdfc4a9965ed75f7c5c1df498bf4d..cb288815a0ff5f39c5b41aff1616a24401d0ef8e 100644
--- a/src/finam/sdk/output.py
+++ b/src/finam/sdk/output.py
@@ -116,7 +116,7 @@ class Output(IOutput, Loggable):
target : :class:`.IInput`
The target to add.
"""
- self.logger.debug("add target")
+ self.logger.trace("add target")
if not isinstance(target, IInput):
with ErrorLogger(self.logger):
raise ValueError("Only IInput can added as target for IOutput")
@@ -154,12 +154,12 @@ class Output(IOutput, Loggable):
time : :class:`datetime <datetime.datetime>`
Simulation time of the data set.
"""
- self.logger.debug("push data")
-
if not self.has_targets:
- self.logger.debug("skipping push to unconnected output")
+ self.logger.trace("skipping push to unconnected output")
return
+ self.logger.trace("push data")
+
with ErrorLogger(self.logger):
_check_time(time, self.is_static)
@@ -174,19 +174,23 @@ class Output(IOutput, Loggable):
time = None
with ErrorLogger(self.logger):
- xdata = tools.prepare(data, self.info)
+ xdata, conv = tools.prepare(data, self.info, report_conversion=True)
if len(self.data) > 0 and not isinstance(self.data[-1][1], str):
d = self.data[-1][1]
if np.may_share_memory(d.data, xdata.data):
raise FinamDataError(
"Received data that shares memory with previously received data."
)
+ if conv is not None:
+ self.logger.profile(
+ "converted units from %s to %s (%d entries)", *conv, xdata.size
+ )
xdata = self._pack(xdata)
self.data.append((time, xdata))
self._time = time
- self.logger.debug("data cache: %d", len(self.data))
+ self.logger.trace("data cache: %d", len(self.data))
self.notify_targets(time)
@@ -198,7 +202,7 @@ class Output(IOutput, Loggable):
info : :class:`.Info`
Delivered data info
"""
- self.logger.debug("push info")
+ self.logger.trace("push info")
if not isinstance(info, Info):
with ErrorLogger(self.logger):
raise FinamMetaDataError("Metadata must be of type Info")
@@ -212,7 +216,7 @@ class Output(IOutput, Loggable):
time : :class:`datetime <datetime.datetime>`
Simulation time of the simulation.
"""
- self.logger.debug("notify targets")
+ self.logger.trace("notify targets")
with ErrorLogger(self.logger):
_check_time(time, self.is_static)
@@ -240,7 +244,7 @@ class Output(IOutput, Loggable):
FinamNoDataError
Raises the error if no data is available
"""
- self.logger.debug("get data")
+ self.logger.trace("get data")
with ErrorLogger(self.logger):
_check_time(time, self.is_static)
@@ -264,7 +268,7 @@ class Output(IOutput, Loggable):
self._clear_data(time, target)
if len(self.data) < data_count:
- self.logger.debug(
+ self.logger.trace(
"reduced data cache: %d -> %d", data_count, len(self.data)
)
@@ -278,7 +282,7 @@ class Output(IOutput, Loggable):
fn = os.path.join(
self.memory_location or "", f"{id(self)}-{self._mem_counter}.npy"
)
- self.logger.debug(
+ self.logger.profile(
"dumping data to file %s (total RAM %0.2f MB)",
fn,
self._total_mem / 1048576,
@@ -288,14 +292,14 @@ class Output(IOutput, Loggable):
return fn
self._total_mem += data_size
- self.logger.debug(
+ self.logger.trace(
"keeping data in RAM (total RAM %0.2f MB)", self._total_mem / 1048576
)
return data
def _unpack(self, where):
if isinstance(where, str):
- self.logger.debug("reading data from file %s", where)
+ self.logger.profile("reading data from file %s", where)
data = np.load(where, allow_pickle=True)
return tools.UNITS.Quantity(data, self.info.units)
@@ -366,7 +370,7 @@ class Output(IOutput, Loggable):
FinamNoDataError
Raises the error if no info is available
"""
- self.logger.debug("get info")
+ self.logger.trace("get info")
if self._output_info is None:
raise FinamNoDataError("No data info available")
@@ -427,7 +431,7 @@ class Output(IOutput, Loggable):
:class:`.IOutput`
The last element of the chain.
"""
- self.logger.debug("chain")
+ self.logger.trace("chain")
self.add_target(other)
other.set_source(self)
return other
@@ -499,7 +503,7 @@ class CallbackOutput(Output):
FinamNoDataError
Raises the error if no data is available
"""
- self.logger.debug("source changed")
+ self.logger.trace("get data")
with ErrorLogger(self.logger):
_check_time(time, False)
@@ -515,13 +519,17 @@ class CallbackOutput(Output):
raise FinamNoDataError(f"No data available in {self.name}")
with ErrorLogger(self.logger):
- xdata = tools.prepare(data, self.info)
+ xdata, conv = tools.prepare(data, self.info, report_conversion=True)
if self.last_data is not None and np.may_share_memory(
tools.get_magnitude(self.last_data), tools.get_magnitude(xdata)
):
raise FinamDataError(
"Received data that shares memory with previously received data."
)
+ if conv is not None:
+ self.logger.profile(
+ "converted units from %s to %s (%d entries)", *conv, xdata.size
+ )
self.last_data = xdata
return xdata
diff --git a/src/finam/tools/__init__.py b/src/finam/tools/__init__.py
index bb531d130051096382ab86597e07fddfbde8111c..b5428cdeecbcfc6d5f3a4c427ac6d2790187eb45 100644
--- a/src/finam/tools/__init__.py
+++ b/src/finam/tools/__init__.py
@@ -12,6 +12,7 @@ Logging helper
LogStdOutStdErr
LogWriter
is_loggable
+ add_logging_level
Datetime helper
===============
@@ -67,6 +68,7 @@ from .log_helper import (
LogCStdOutStdErr,
LogStdOutStdErr,
LogWriter,
+ add_logging_level,
is_loggable,
)
@@ -75,6 +77,7 @@ __all__ += ["is_timedelta"]
__all__ += ["get_enum_value"]
__all__ += ["inspect"]
__all__ += [
+ "add_logging_level",
"ErrorLogger",
"is_loggable",
"LogWriter",
diff --git a/src/finam/tools/connect_helper.py b/src/finam/tools/connect_helper.py
index 743011b8f712a8aa1c34838a6edfef48ce7e9e95..2a21a39084d06e980e37a0e9fa225205be50eac0 100644
--- a/src/finam/tools/connect_helper.py
+++ b/src/finam/tools/connect_helper.py
@@ -388,9 +388,9 @@ class ConnectHelper(Loggable):
try:
self.out_infos[name] = self.outputs[name].info
any_done = True
- self.logger.debug("Successfully pulled output info for %s", name)
+ self.logger.trace("Successfully pulled output info for %s", name)
except FinamNoDataError:
- self.logger.debug("Failed to pull output info for %s", name)
+ self.logger.trace("Failed to pull output info for %s", name)
any_done += self._push(start_time)
@@ -403,9 +403,9 @@ class ConnectHelper(Loggable):
start_time or info.time
)
any_done = True
- self.logger.debug("Successfully pulled input data for %s", name)
+ self.logger.trace("Successfully pulled input data for %s", name)
except FinamNoDataError:
- self.logger.debug("Failed to pull input data for %s", name)
+ self.logger.trace("Failed to pull input data for %s", name)
if (
all(v is not None for v in self.in_infos.values())
@@ -480,9 +480,9 @@ class ConnectHelper(Loggable):
try:
self.in_infos[name] = self.inputs[name].exchange_info()
any_done = True
- self.logger.debug("Successfully exchanged input info for %s", name)
+ self.logger.trace("Successfully exchanged input info for %s", name)
except FinamNoDataError:
- self.logger.debug("Failed to exchange input info for %s", name)
+ self.logger.trace("Failed to exchange input info for %s", name)
for name, info in list(self._in_info_cache.items()):
if self.in_infos[name] is None:
@@ -493,9 +493,9 @@ class ConnectHelper(Loggable):
)
any_done = True
self._in_info_cache.pop(name)
- self.logger.debug("Successfully exchanged input info for %s", name)
+ self.logger.trace("Successfully exchanged input info for %s", name)
except FinamNoDataError:
- self.logger.debug("Failed to exchange input info for %s", name)
+ self.logger.trace("Failed to exchange input info for %s", name)
return any_done
@@ -508,7 +508,7 @@ class ConnectHelper(Loggable):
self.infos_pushed[name] = True
any_done = True
self._out_info_cache.pop(name)
- self.logger.debug("Successfully pushed output info for %s", name)
+ self.logger.trace("Successfully pushed output info for %s", name)
for name, data in list(self._out_data_cache.items()):
if not self.data_pushed[name] and self.infos_pushed[name]:
@@ -531,7 +531,7 @@ class ConnectHelper(Loggable):
self.data_pushed[name] = True
self._out_data_cache.pop(name)
- self.logger.debug("Successfully pushed output data for %s", name)
+ self.logger.trace("Successfully pushed output data for %s", name)
def _check_times(infos):
diff --git a/src/finam/tools/log_helper.py b/src/finam/tools/log_helper.py
index 0a44573ed03084b9799da87a49b6696be3c27b23..3aeaa83e7ae8326a2ccb454ef977672c8f2d1e3c 100644
--- a/src/finam/tools/log_helper.py
+++ b/src/finam/tools/log_helper.py
@@ -146,3 +146,46 @@ class ErrorLogger(AbstractContextManager):
def __exit__(self, exc_type, exc_value, traceback):
if exc_value is not None and self.do_log:
logging.getLogger(self.logger).exception(exc_value)
+
+
+def add_logging_level(name, num, method=None):
+ """
+ Adds a logging level to the `logging` module.
+
+ Examples
+ --------
+
+ .. code-block:: Python
+
+ add_logging_level("TRACE", logging.DEBUG - 5)
+
+ Parameters
+ ----------
+ name : str
+ The name of the new logging level.
+ num : int
+ The numeric severity of the new logging level.
+ method : str, optional
+ The method name for the new logging level.
+ Defaults to lowercase of ``name``.
+ """
+ if not method:
+ method = name.lower()
+
+ if hasattr(logging, name):
+ raise AttributeError(f"{name} already defined in logging module")
+ if hasattr(logging.getLoggerClass(), name):
+ raise AttributeError(f"{name} already defined in logger class")
+
+ def log_for_level(self, message, *args, **kwargs):
+ if self.isEnabledFor(num):
+ # pylint: disable=protected-access
+ self._log(num, message, args, **kwargs)
+
+ def log_to_root(message, *args, **kwargs):
+ logging.log(num, message, *args, **kwargs)
+
+ logging.addLevelName(num, name)
+ setattr(logging, name, num)
+ setattr(logging.getLoggerClass(), method, log_for_level)
+ setattr(logging, method, log_to_root)
diff --git a/tests/data/test_tools.py b/tests/data/test_tools.py
index e9bf06633cddd59cc85099ce03325af4ea932dee..7443778bcbfdc5167e83967e0e633158e5f4b88c 100644
--- a/tests/data/test_tools.py
+++ b/tests/data/test_tools.py
@@ -134,6 +134,14 @@ class TestDataTools(unittest.TestCase):
)
self.assertEqual((1, 2, 2), data.shape)
+ data = finam.data.prepare(
+ finam.UNITS.Quantity(1.0, "m"),
+ finam.Info(time, grid=finam.NoGrid(), units="m"),
+ )
+
+ self.assertEqual((1,), data.shape)
+ self.assertEqual(finam.UNITS.meter, data.units)
+
with self.assertRaises(finam.errors.FinamDataError):
finam.data.prepare(
np.asarray([1, 2]), finam.Info(time, grid=finam.NoGrid())
@@ -192,6 +200,13 @@ class TestDataTools(unittest.TestCase):
xdata[0, 0] = 0 * finam.UNITS("m")
self.assertNotEqual(finam.data.get_magnitude(xdata2[0, 0]), 0.0)
+ data = [1.0]
+ xdata2 = finam.data.prepare(data, info_1, force_copy=True)
+ self.assertEqual(1.0 * finam.UNITS.meter, xdata2[0])
+
+ xdata2[0, 0] = 0 * finam.UNITS("m")
+ self.assertNotEqual(0.0, data[0])
+
def test_assert_type(self):
finam.data.assert_type(self, "A", 1, [int, float])
diff --git a/tests/tools/test_log.py b/tests/tools/test_log.py
index 8c61b0997379df5f894fe2b01462fc28e9006876..0e5701610adbe5f614b80d98226deb86615c4f8f 100644
--- a/tests/tools/test_log.py
+++ b/tests/tools/test_log.py
@@ -29,6 +29,17 @@ class TestLog(unittest.TestCase):
# check that we only got the one dummy log
self.assertEqual(len(captured.records), 1)
+ def test_log_levels(self):
+ with self.assertLogs("foo", level="TRACE") as captured:
+ logging.getLogger("foo").trace("A")
+ logging.getLogger("foo").profile("B")
+
+ self.assertEqual(len(captured.records), 2)
+ self.assertEqual(captured.records[0].levelno, logging.TRACE)
+ self.assertEqual(captured.records[0].message, "A")
+ self.assertEqual(captured.records[1].levelno, logging.PROFILE)
+ self.assertEqual(captured.records[1].message, "B")
+
def test_redirect(self):
with self.assertLogs() as captured:
with LogStdOutStdErr():