Skip to content

Development

Pushing Code to the Robot

To get the code onto the robot you can simply pull your repository. But this requires you to have login credentials on an external machine. And editing files must be done on slow hardware compared to development workstations and laptops. If you use VS Code Remote Development or similar to do actual development on these slow systems, everything feels like jelly. Especially if you run powerful extensions like Pylance.

That is why we at Zauberzeug created a small open source tool called LiveSync. It combines a local filesystem watcher with rsync to copy changes to a (slow) remote target whenever your local code changes. This approach has multiple advantages:

  • work with your personal choice of IDE and tooling
  • run tests (or simulate the production code) locally
  • continuously deploy the development code to the target environment (where auto-reload ensures live preview)
  • almost no overhead on the (slow) target

Logging

RoSys uses the Python logging package with namespaced loggers. For example, the steerer module 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
import logging
import logging.config

from nicegui import ui

from rosys.driving import Odometer, Steerer, joystick
from rosys.hardware import RobotSimulation, WheelsSimulation

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,
        },
    },
})

wheels = WheelsSimulation()
steerer = Steerer(wheels)
odometer = Odometer(wheels)
robot = RobotSimulation([wheels])

joystick(steerer)

ui.run(title='RoSys')

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 odometer you can add

'rosys.odometer': {
    '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:

    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'formatter': 'default',
            'level': 'DEBUG',
            'stream': 'ext://sys.stdout'
        },
        'file': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'formatter': 'default',
            'filename': PATH / 'example.log',
            'maxBytes': 1024 * 1000,
            'backupCount': 3
        }
    },

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

    },
    '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.core': {
            'handlers': ['file'],
            'level': 'DEBUG',
            'propagate': False,
        },

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: logging.LogRecord) -> bool:
        pathname = record.pathname
        record.relative_path = 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.relative_path = 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:

    'filters': {
        'package_path_filter': {
            '()': PackagePathFilter,
        },
    },
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'filters': ['package_path_filter'],
            '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,
        },
    },

Log output then looks like this:

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

Profiling

Note

The default RoSys installation via pip does not come with profiling packages. To install them, run

python3 -m pip install rosys[profiling]

Currently this does not work with Python 3.11 because yappy and line-profiler do not support 3.11 yet.

You can add a profile decorator to expensive functions and add a profiler button to your UI:

#!/usr/bin/env python3
import rosys
from nicegui import ui
from rosys.analysis import profile_button, profiling


@profiling.profile
def compute() -> None:
    s = 0
    for i in range(1_000_000):
        s += i**2
    ui.notify(s)


rosys.on_repeat(compute, 1.0)
profile_button()

ui.run()

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

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     7                                           @profiling.profile
     8                                           def compute() -> None:
     9         3         21.0      7.0      0.0      s = 0
    10   3000003     433138.0      0.1     28.2      for i in range(1_000_000):
    11   3000000    1098975.0      0.4     71.6          s += i**2
    12         3       2151.0    717.0      0.1      ui.notify(s)

Track async function calls

RoSys provides a @track decorator that you can put above asynchronous functions that are called as part of automations. The UI element track.ui() will show the stack of functions that are currently awaited.

#!/usr/bin/env python3
import asyncio

from nicegui import ui
from rosys.analysis import track


@track
async def do_A():
    await asyncio.sleep(1)


@track
async def do_B():
    await asyncio.sleep(1)


@track
async def do_something():
    await asyncio.sleep(1)
    for _ in range(3):
        await do_A()
        await do_B()

ui.button('Do something', on_click=do_something)

track.ui()

ui.run()

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.