Tutorial about logging#

Logging as supplied by the python standard library can be used.

We make use of the standard logging levels DEBUG, INFO, WARNING, ERROR, CRITICAL.

import logging
import sys
from pathlib import Path

import numpy as np
import pandas as pd

import locan as lc
/tmp/ipykernel_1549/2523231786.py:6: DeprecationWarning: 
Pyarrow will become a required dependency of pandas in the next major release of pandas (pandas 3.0),
(to allow more performant data types, such as the Arrow string type, and better interoperability with other libraries)
but was not found to be installed on your system.
If this would cause problems for you,
please provide us feedback at https://github.com/pandas-dev/pandas/issues/54466
        
  import pandas as pd
lc.show_versions(dependencies=False, verbose=False)
Locan:
   version: 0.20.0.dev41+g755b969

Python:
   version: 3.11.6

System:
python-bits: 64
    system: Linux
   release: 5.19.0-1028-aws
   version: #29~22.04.1-Ubuntu SMP Tue Jun 20 19:12:11 UTC 2023
   machine: x86_64
 processor: x86_64
 byteorder: little
    LC_ALL: None
      LANG: C.UTF-8
    LOCALE: {'language-code': 'en_US', 'encoding': 'UTF-8'}

Activate logging#

In any script or notebook logging has to be enabled e.g. for streaming to stdout.

For changing the configuration logging has to be reloaded or the kernel be restarted.

logging.basicConfig(stream=sys.stdout, level=logging.INFO, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')

A top-level logger has to be instantiated to process any log messages from the library.

logger = logging.getLogger()
logger
<RootLogger root (INFO)>

Further log messages can be added:

logger.info("test")
2024-03-14 11:09:05,926 - root - INFO - test

Handling locan.logger#

To change the filter level of locan log records, use an instance of the locan logger identified by its module name.

locan_logger = logging.getLogger('locan')
locan_logger.setLevel(logging.INFO)
locan_logger
<Logger locan (INFO)>

Logging in locan#

Many functions provide warnings if some unusual behavior occurs:

locdata = lc.LocData.from_coordinates([(0, 0), (1, 2), (2, 1), (5, 5)])
locdata.region = lc.Rectangle((0, 0), 2, 2, 0)
Jupyter environment detected. Enabling Open3D WebVisualizer.
[Open3D INFO] WebRTC GUI backend enabled.
[Open3D INFO] WebRTCWindowSystem: HTTP handshake server disabled.
2024-03-14 11:09:08,042 - locan.data.locdata - WARNING - Not all coordinates are within region.

Changing the level of the locan logger to logging.WARNING or higher, will switch off most locan log records.

locan_logger.setLevel(logging.ERROR)

locdata = lc.LocData.from_coordinates([(0, 0), (1, 2), (2, 1), (5, 5)])
locdata.region = lc.Rectangle((0, 0), 2, 2, 0)
locan_logger.setLevel(logging.INFO)

locdata = lc.LocData.from_coordinates([(0, 0), (1, 2), (2, 1), (5, 5)])
locdata.region = lc.Rectangle((0, 0), 2, 2, 0)
2024-03-14 11:09:08,061 - locan.data.locdata - WARNING - Not all coordinates are within region.

Levels can be set for selected loggers by specifying the module or function name:

logger_locan_data = logging.getLogger('locan.data')
logger_locan_data.setLevel(logging.ERROR)

locdata = lc.LocData.from_coordinates([(0, 0), (1, 2), (2, 1), (5, 5)])
locdata.region = lc.Rectangle((0, 0), 2, 2, 0)
logger_locan_data.setLevel(logging.INFO)

locdata = lc.LocData.from_coordinates([(0, 0), (1, 2), (2, 1), (5, 5)])
locdata.region = lc.Rectangle((0, 0), 2, 2, 0)
2024-03-14 11:09:08,078 - locan.data.locdata - WARNING - Not all coordinates are within region.

Logging in a pipeline#

def computation(self, file):
    logger.info(f'computation started for file: {file}')
    return self
pipes = [lc.Pipeline(computation=computation, file=file).compute() for file in range(3)]
2024-03-14 11:09:08,745 - root - INFO - computation started for file: 0
2024-03-14 11:09:08,746 - root - INFO - computation started for file: 1
2024-03-14 11:09:08,747 - root - INFO - computation started for file: 2

Another example how to use logging in analysis pipelines is given by the computation_test function.

pipes = [lc.Pipeline(computation=lc.analysis.pipeline.computation_test, locdata=file).compute() for file in range(3)]
2024-03-14 11:09:08,754 - locan.analysis.pipeline - INFO - computation finished for locdata: 0
2024-03-14 11:09:08,755 - locan.analysis.pipeline - WARNING - An exception occurred for locdata: 0
2024-03-14 11:09:08,756 - locan.analysis.pipeline - INFO - computation finished for locdata: 1
2024-03-14 11:09:08,757 - locan.analysis.pipeline - WARNING - An exception occurred for locdata: 1
2024-03-14 11:09:08,758 - locan.analysis.pipeline - INFO - computation finished for locdata: 2
2024-03-14 11:09:08,759 - locan.analysis.pipeline - WARNING - An exception occurred for locdata: 2
print(pipes[0].computation_as_string())
def computation_test(
    self: T_Pipeline,
    locdata: LocData | None = None,
    parameter: str = "test",
) -> T_Pipeline:
    """A pipeline definition for testing."""
    self.locdata = locdata  # type: ignore
    something = "changed_value"
    logger.debug(f"something has a : {something}")
    self.test = parameter  # type: ignore
    logger.info(f"computation finished for locdata: {locdata}")

    try:
        raise NotImplementedError
    except NotImplementedError:
        logger.warning(f"An exception occurred for locdata: {locdata}")

    return self

Logging in multiprocessing with ray#

To enable logging in multiprocessing using ray you need to include a default configuration in the computation function: logging.basicConfig(level=logging.INFO).

if False:
    def computation(self, file):
        logging.basicConfig(level=logging.INFO)
        logger.info(f'computation started for file: {file}')
        return self
if False:
    import ray

    ray.init()
    # ray.init(num_cpus = 4)
%%time
if False:
    @ray.remote
    def worker(file):
        pipe = lc.Pipeline(computation=computation, file=file).compute()
        return pipe

    futures = [worker.remote(file) for file in range(3)]
    pipes = ray.get(futures)
    len(pipes)
CPU times: user 3 µs, sys: 0 ns, total: 3 µs
Wall time: 5.72 µs

Logging in locan - third party libraries#

Some third-party libraries provide their own logging system. Typically the individual loggers can be imported and modified.

import trackpy as tr
tr.logger
<Logger trackpy (INFO)>

alternatively

trackpy_logger = logging.getLogger('trackpy')
trackpy_logger
<Logger trackpy (INFO)>

Depending on the library various methods can be used to change the logging level. All of the following can be used.

trackpy_logger.setLevel(logging.WARN)

tr.logger.setLevel(logging.WARN)

tr.quiet()

tr.ignore_logging() # this switches off the trackpy logging system and forwards all logs up the logger hirarchy.

dat = lc.simulate_tracks(n_walks=1, n_steps=100, ranges=((0,1000),(0,1000)),
                      diffusion_constant=1, seed=1)

dat.print_meta()
identifier: "6"
source: SIMULATION
state: RAW
history {
  name: "simulate_tracks"
  parameter: "{\'n_walks\': 1, \'n_steps\': 100, \'ranges\': ((0, 1000), (0, 1000)), \'diffusion_constant\': 1, \'time_step\': 10, \'seed\': 1}"
}
element_count: 100
frame_count: 100
creation_time {
  2024-03-14T11:09:08.812727Z
}
locdata_new, track_series = lc.track(dat, search_range=5)
Frame 99: 1 trajectories present.
2024-03-14 11:09:10,848 - locan.data.locdata_utils - WARNING - Zero uncertainties occurred resulting in nan for weighted_mean and weighted_variance.
2024-03-14 11:09:10,850 - locan.data.locdata_utils - WARNING - Zero uncertainties occurred resulting in nan for weighted_mean and weighted_variance.
trackpy_logger.setLevel(logging.WARN)
locdata_new, track_series = lc.track(dat, search_range=5)
2024-03-14 11:09:12,731 - locan.data.locdata_utils - WARNING - Zero uncertainties occurred resulting in nan for weighted_mean and weighted_variance.
2024-03-14 11:09:12,732 - locan.data.locdata_utils - WARNING - Zero uncertainties occurred resulting in nan for weighted_mean and weighted_variance.