Skip to content

Development

Logging

RoSys uses the Python logging package with namespaced loggers. For example, the steerer actor writes its logs as rosys.steerer. This can be used for fine-granular control of what should show on the console. As a general starting point we suggest reading the Python Logging HOWTO. In the following examples we use Python's logging dictConfig for configuration, because it provides the most flexibility while having all configuration in one place.

Show Info Messages

To only print RoSys messages at the info level to the console we can use a configuration like this:

#!/usr/bin/env python3
from nicegui import ui
import logging
import logging.config
import rosys
import rosys.ui

logging.config.dictConfig({
    'version': 1,
    'disable_existing_loggers': True,  # to make sure this config is used
    'formatters': {
        'default': {
            'format': '%(asctime)s - %(levelname)s - %(message)s',
            'datefmt': '%Y-%m-%d %H:%M:%S',
        },
    },
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'formatter': 'default',
            'level': 'DEBUG',
            'stream': 'ext://sys.stdout'
        },
    },
    'loggers': {
        '': {  # this root logger is used for everything without a specific logger
            'handlers': ['console'],
            'level': 'WARN',
            'propagate': False,
        },
        'rosys': {
            'handlers': ['console'],
            'level': 'INFO',
            'propagate': False,
        },
    },
})

# setup
runtime = rosys.Runtime()
rosys.ui.configure(ui, runtime)

rosys.ui.joystick()

ui.run(title='RoSys', port=8080)

As you move the joystick rosys.steerer, messages will appear on the console:

2022-01-11 06:53:21 - INFO - start steering
2022-01-11 06:53:22 - INFO - stop steering
2022-01-11 06:53:23 - INFO - start steering
2022-01-11 06:53:23 - INFO - stop steering

Adding Loggers

You can easily add more loggers. For example, to see debug messages of the event system you can add

'rosys.event': {
    'handlers': ['console'],
    'level': 'DEBUG',
    'propagate': False,
},

Most of the time we turn off log propagation to ensure the configuration we defined ourselves is really used.

Logging to File

Sometimes it is helpful to write intensive logging into a file and only show some messages on the console. For this you can add a file handler:

            'format': '%(asctime)s - %(levelname)s - %(message)s',
            'datefmt': '%Y-%m-%d %H:%M:%S',
        },
    },
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'formatter': 'default',
            'level': 'DEBUG',
            'stream': 'ext://sys.stdout'
        },
        'file': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'formatter': 'default',
            'filename': os.path.expanduser('~/.rosys/example.log'),

Then you can decide for each logger which handlers should be used:

            'backupCount': 3
        }
    },
    'loggers': {
        '': {  # this root logger is used for everything without a specific logger
            'handlers': ['console', 'file'],
            'level': 'WARN',
            'propagate': False,
        },
        'rosys': {
            'handlers': ['console', 'file'],
            'level': 'INFO',
            'propagate': False,
        },
        'rosys.event': {
            'handlers': ['file'],
            'level': 'DEBUG',
            'propagate': False,
        },
        'rosys.runtime': {
            'handlers': ['file'],
            'level': 'DEBUG',

Note

The above file logger writes to ~/.rosys. For development it is very helpful to have auto-reloading on file change activated. Therefore logging should always be stored outside of your project's source directory.

Formatting

It is quite useful to see from which file and line number a log entry was triggered. To keep the log lines from getting too long, you can create a log filter which computes the relative path:

class PackagePathFilter(logging.Filter):
    '''Provides relative path for log formatter.
    Original code borrowed from https://stackoverflow.com/a/52582536/3419103
    '''

    def filter(self, record):
        pathname = record.pathname
        record.relativepath = None
        abs_sys_paths = map(os.path.abspath, sys.path)
        for path in sorted(abs_sys_paths, key=len, reverse=True):  # longer paths first
            if not path.endswith(os.sep):
                path += os.sep
            if pathname.startswith(path):
                record.relativepath = os.path.relpath(pathname, path)
                break
        return True

You need to register the filter and apply it in the handler. Then you can change the format for the formatter:

    'formatters': {
        'default': {
            'format': '%(asctime)s.%(msecs)03d [%(levelname)s] %(relativepath)s:%(lineno)d: %(message)s',
            'datefmt': '%Y-%m-%d %H:%M:%S',
        },
    },
    'filters': {
        'package_path_filter': {
            '()': PackagePathFilter,
        },
    },
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'filters': ['package_path_filter'],
            'formatter': 'default',
            'level': 'DEBUG',
            'stream': 'ext://sys.stdout'
        },
    },

Log output then looks like this:

2022-01-11 06:51:00.319 [DEBUG] rosys/runtime.py:78: startup completed

Profiling

You can add a profiler button to your UI:

from rosys.ui import create_profiler

...
create_profiler(ui)

When the button is pressed, the profiler yappi will start recording data. When stopped, you will see its output on the console.

Memory Leaks

To analyze memory leaks RoSys allows the integration of pyloot as a separate page:

from nicegui import ui
import rosys.ui

runtime = rosys.Runtime()
rosys.ui.configure(ui, runtime)
rosys.ui.pyloot_page()

This will add a route /pyloot to your app. The graphs will continuously update and show you which types of object counts are growing. You can then inspect them. To analyze cyclic references the objgraph library can be very helpful. You can call rosys.ui.objgraph_page(), which will add the route /objgraph to your app.

Continuous Build

We run our continuous integration with GitHub Actions. For each commit the pytests are executed.

Releases

We publish releases by creating a new version on GitHub and describe the changes. A GitHub Action then performs the following steps:

  • If the pytests are successful, a poetry build and deployment to pypi is issued.
  • A multi-arch docker image is built and pushed to Docker Hub.