Skip to content

Add throttle option for logging #166

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 14 commits into
base: develop
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 3 additions & 5 deletions .github/workflows/flexbe_ci.yml
Original file line number Diff line number Diff line change
@@ -1,17 +1,15 @@
# This is a basic workflow to help you get started with Actions
name: FlexBE CI
# Controls when the action will run.
# Controls when the action will run.
on: [push, pull_request, workflow_dispatch]

# A workflow run is made up of one or more jobs that can run sequentially or in parallel
jobs:
test:
strategy:
matrix:
ros: [melodic, noetic]
ros: [noetic]
include:
- os: ubuntu-18.04
ros: melodic
- os: ubuntu-20.04
ros: noetic
python: python3
Expand All @@ -24,7 +22,7 @@ jobs:
# Steps represent a sequence of tasks that will be executed as part of the job
steps:
# Checks-out your repository under $GITHUB_WORKSPACE, so your job can access it
- uses: actions/checkout@v2
- uses: actions/checkout@v3
- name: Prepare CI
run: |
git clone https://github.com/FlexBE/flexbe_ci.git ~/flexbe_ci
Expand Down
3 changes: 1 addition & 2 deletions LICENSE
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
Copyright (c) 2015, DARPA Robotics Challenge Team ViGIR
Copyright (c) 2015-2023, DARPA Robotics Challenge Team ViGIR
All rights reserved.

Redistribution and use in source and binary forms, with or without
Expand All @@ -25,4 +25,3 @@ SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER
CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.

13 changes: 7 additions & 6 deletions README.md
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
# FlexBE Behavior Engine

FlexBE is a high-level behavior engine coordinating the capabilities of a robot in order to solve complex tasks.
Behaviors are modeled as hierarchical state machines where states correspond to active actions and transitions describe the reaction to outcomes.
Main advantage over similar approaches is the good operator integration and extensive user interface.
Expand All @@ -8,27 +9,27 @@ The user interface features a runtime control interface as well as a graphical e

Please refer to the FlexBE Homepage ([flexbe.github.io](http://flexbe.github.io)) for further information, tutorials, application examples, and much more.

![FlexBE CI](https://github.com/team-vigir/flexbe_behavior_engine/workflows/FlexBE%20CI/badge.svg)
![FlexBE CI](https://github.com/FlexBE/flexbe_behavior_engine/workflows/FlexBE%20CI/badge.svg)

## Installation

Execute the following commands to install FlexBE:

roscd && cd ../src
git clone https://github.com/team-vigir/flexbe_behavior_engine.git
git clone https://github.com/FlexBE/flexbe_behavior_engine.git

Furthermore, create your own repository for behavior development (contains examples):

rosrun flexbe_widget create_repo [your_project_name]

Finally, it is recommended to install the FlexBE App user interface by following [these steps](http://philserver.bplaced.net/fbe/download.php).

## Usage

Use the following launch file for running the onboard engine:

roslaunch flexbe_onboard behavior_onboard.launch

Use the following launch file for running the operator control station (requires the FlexBE App):

roslaunch flexbe_app flexbe_ocs.launch
Expand Down
13 changes: 13 additions & 0 deletions flexbe_behavior_engine/CHANGELOG.rst
Original file line number Diff line number Diff line change
@@ -1,6 +1,19 @@
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Changelog for package flexbe_behavior_engine
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
1.4.1 (2023-07-19)
------------------
* make cmake_minimum_version consistent 3.10.2 for Noetic
* update maintainer tags in Noetic

1.4.0 (2023-05-18)
------------------
* Updates for Melodic and Noetic releases on github.com/FlexBE
* [flexbe_core] Merge pull request #153 from omercans/fix/set-current-state-of-cc-to-none-on-forced-exit
* [flexbe_core] Merge pull request #154 from duwke/patch-1 - Check topic availability before returning last_msg
* [flexbe_states] Merge pull request #160 from cpswarm/fix_namespace - namespace fix for topic lookup with rostopic in subscriber state
* [flexbe_core] Merge pull request #163 from LoyVanBeek/fix/nested_sm_userdata - Fix nested state machine userdata
* [flexbe_onboard] Merge pull request #165 from HannesBachter/feature/get_userdata - get userdata by service

1.3.1 (2020-12-11)
------------------
Expand Down
2 changes: 1 addition & 1 deletion flexbe_behavior_engine/CMakeLists.txt
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
cmake_minimum_required(VERSION 3.0.2)
cmake_minimum_required(VERSION 3.10.2)
project(flexbe_behavior_engine)
find_package(catkin REQUIRED)
catkin_metapackage()
7 changes: 4 additions & 3 deletions flexbe_behavior_engine/package.xml
Original file line number Diff line number Diff line change
@@ -1,13 +1,14 @@
<?xml version="1.0"?>
<package format="2">
<name>flexbe_behavior_engine</name>
<version>1.3.1</version>
<version>1.4.1</version>
<description>
A meta-package to aggregate all the FlexBE packages
</description>

<maintainer email="[email protected]">Philipp Schillinger</maintainer>
<maintainer email="[email protected]">Alireza Hosseini</maintainer>
<author>Philipp Schillinger</author>
<maintainer email="[email protected]">Philipp Schillinger</maintainer>
+ <maintainer email="[email protected]">David Conner</maintainer>
<license>BSD</license>

<url>http://ros.org/wiki/flexbe</url>
Expand Down
12 changes: 12 additions & 0 deletions flexbe_core/CHANGELOG.rst
Original file line number Diff line number Diff line change
@@ -1,6 +1,18 @@
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Changelog for package flexbe_core
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
1.4.1 (2023-07-19)
------------------
* make cmake_minimum_version consistent 3.10.2 for Noetic
* ignore time dependent tests on build farm due to OS switching; just warn

1.4.0 (2023-05-18)
------------------
* Updates for Melodic and Noetic releases on github.com/FlexBE
* [flexbe_core] Fix handling of boolean behavior args
* [flexbe_core] Merge pull request #153 from omercans/fix/set-current-state-of-cc-to-none-on-forced-exit
* [flexbe_core] Merge pull request #154 from duwke/patch-1 - Check topic availability before returning last_msg
* [flexbe_core] Merge pull request #163 from LoyVanBeek/fix/nested_sm_userdata - Fix nested state machine userdata

1.3.1 (2020-12-11)
------------------
Expand Down
2 changes: 1 addition & 1 deletion flexbe_core/CMakeLists.txt
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
cmake_minimum_required(VERSION 3.0.2)
cmake_minimum_required(VERSION 3.10.2)
project(flexbe_core)

find_package(catkin REQUIRED)
Expand Down
2 changes: 1 addition & 1 deletion flexbe_core/package.xml
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@
schematypens="http://www.w3.org/2001/XMLSchema"?>
<package format="3">
<name>flexbe_core</name>
<version>1.3.1</version>
<version>1.4.1</version>
<description>
flexbe_core provides the core components for the FlexBE behavior engine.
</description>
Expand Down
70 changes: 63 additions & 7 deletions flexbe_core/src/flexbe_core/logger.py
Original file line number Diff line number Diff line change
Expand Up @@ -16,11 +16,15 @@ class Logger(object):

LOGGING_TOPIC = 'flexbe/log'

# max number of items in last logged dict (used for log_throttle)
MAX_LAST_LOGGED_SIZE = 1024

_pub = None

@staticmethod
def initialize():
Logger._pub = rospy.Publisher(Logger.LOGGING_TOPIC, BehaviorLog, queue_size=100)
Logger._last_logged = {}

@staticmethod
def log(text, severity):
Expand All @@ -34,6 +38,23 @@ def log(text, severity):
# also log locally
Logger.local(text, severity)

@staticmethod
def log_throttle(period, text, severity):
# creat unique identifier for each logging message
log_id = str(severity) + "_" + text
# only log when it's the first time or period time has passed for the logging message
if not log_id in Logger._last_logged.keys() or \
rospy.Time.now().to_sec() - Logger._last_logged[log_id].to_sec() > period:
Logger.log(text, severity)
Logger._last_logged.update({log_id: rospy.Time.now()})
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for adding! Would you see a way that entries can also be removed again eventually so that this dict can't grow infinitely?

Copy link
Author

@HannesBachter HannesBachter Mar 28, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The update function would only update the entry within the dict (whose key is a combination of the logger level and the text) - so the dictionary would only have the max length of the number of Logger.log*_throttles
This idea works only until the text within the log is not static, and in the worst case changing for every log (e.g. a timestamp).
As a safety-net I could add the clearing of the dict from all entries that are older than e.g. one hour (as the entries are {log_id: timestamp})?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think it would be sufficient as a safety-net to just check whether the number of dict entries exceeds a certain limit and then remove entries. As long as the limit is not exceeded, it's probably fine to keep old entries.
As a further idea, I would suggest to log a warning message if the size limit is reached because, as you pointed out, this would likely be caused by improper usage of the throttle such as a non-static messages.


if len(Logger._last_logged) > Logger.MAX_LAST_LOGGED_SIZE:
# iterate through last logged items, sorted by the timestamp (oldest last)
for i, log in enumerate(sorted(Logger._last_logged.items(), key=lambda item: item[1], reverse=True)):
# remove oldest items that exceed the max logged size
if i > Logger.MAX_LAST_LOGGED_SIZE:
Logger._last_logged.pop(log[0])

@staticmethod
def local(text, severity):
if severity == Logger.REPORT_INFO:
Expand All @@ -50,29 +71,64 @@ def local(text, severity):
rospy.logdebug(text + ' (unknown log level %s)' % str(severity))

@staticmethod
def logdebug(text, *args):
def logdebug(text: str, *args):
Logger.log(text % args, Logger.REPORT_DEBUG)

@staticmethod
def loginfo(text, *args):
def loginfo(text: str, *args):
Logger.log(text % args, Logger.REPORT_INFO)

@staticmethod
def logwarn(text, *args):
def logwarn(text: str, *args):
Logger.log(text % args, Logger.REPORT_WARN)

@staticmethod
def loghint(text, *args):
def loghint(text: str, *args):
Logger.log(text % args, Logger.REPORT_HINT)

@staticmethod
def logerr(text, *args):
def logerr(text: str, *args):
Logger.log(text % args, Logger.REPORT_ERROR)

@staticmethod
def localdebug(text, *args):
def logdebug_throttle(period: float, text: str, *args):
Logger.log_throttle(period, text % args, Logger.REPORT_DEBUG)

@staticmethod
def loginfo_throttle(period: float, text: str, *args):
Logger.log_throttle(period, text % args, Logger.REPORT_INFO)


@staticmethod
def logwarn_throttle(period: float, text: str, *args):
Logger.log_throttle(period, text % args, Logger.REPORT_WARN)

@staticmethod
def loghint_throttle(period: float, text: str, *args):
Logger.log_throttle(period, text % args, Logger.REPORT_HINT)


@staticmethod
def logerr_throttle(period: float, text: str, *args):
Logger.log_throttle(period, text % args, Logger.REPORT_ERROR)


@staticmethod
def localdebug(text: str, *args):
Logger.local(text % args, Logger.REPORT_DEBUG)

@staticmethod
def localinfo(text, *args):
def localinfo(text: str, *args):
Logger.local(text % args, Logger.REPORT_INFO)

@staticmethod
def localwarn(text: str, *args):
Logger.local(text % args, Logger.REPORT_WARN)

@staticmethod
def localhint(text: str, *args):
Logger.local(text % args, Logger.REPORT_HINT)

@staticmethod
def localerr(text: str, *args):
Logger.local(text % args, Logger.REPORT_ERROR)
26 changes: 21 additions & 5 deletions flexbe_core/test/test_core.py
Original file line number Diff line number Diff line change
Expand Up @@ -267,16 +267,28 @@ def test_ros_state(self):
for i in range(10):
state.sleep()
duration = rospy.get_time() - start
self.assertAlmostEqual(duration, 1., places=2)
self.assertAlmostEqual(state.sleep_duration, .1, places=2)
try:
self.assertAlmostEqual(duration, 1., places=2)
except AssertionError:
rospy.logwarn(f"elapsed time duration {duration} is not 1. - likely due to OS sleep")
try:
self.assertAlmostEqual(state.sleep_duration, .1, places=2)
except AssertionError:
rospy.logwarn(f"Sleep duration {state.sleep_duration} is not .1 - likely due to OS sleep")

# change of rate works as expected
state.set_rate(1)
start = rospy.get_time()
state.sleep()
duration = rospy.get_time() - start
self.assertAlmostEqual(duration, 1., places=2)
self.assertAlmostEqual(state.sleep_duration, 1., places=2)
try:
self.assertAlmostEqual(duration, 1., places=2)
except AssertionError:
rospy.logwarn(f"elapsed time duration {duration} is not 1. - likely due to OS sleep")
try:
self.assertAlmostEqual(state.sleep_duration, 1., places=2)
except AssertionError:
rospy.logwarn(f"Sleep duration {state.sleep_duration} is not 1. - likely due to OS sleep")

def test_cross_combinations(self):
state = self._create()
Expand Down Expand Up @@ -358,7 +370,11 @@ def sleep(self):
cc.execute(None)
cc.sleep()
cc.execute(None)
self.assertAlmostEqual(cc.sleep_duration, .1, places=2)
try:
self.assertAlmostEqual(cc.sleep_duration, .1, places=2)
except AssertionError:
rospy.logwarn(f"Sleep duration {cc.sleep_duration} is not .1 - likely due to OS sleep")

cc.sleep()
cc['main'].set_rate(15)
cc['side'].set_rate(10)
Expand Down
8 changes: 8 additions & 0 deletions flexbe_input/CHANGELOG.rst
Original file line number Diff line number Diff line change
@@ -1,6 +1,14 @@
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Changelog for package flexbe_input
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
1.4.1 (2023-07-19)
------------------
* make cmake_minimum_version consistent 3.10.2 for Noetic
* update maintainer tags in Noetic

1.4.0 (2023-05-18)
------------------
* Updates for Melodic and Noetic releases on github.com/FlexBE

1.3.1 (2020-12-11)
------------------
Expand Down
2 changes: 1 addition & 1 deletion flexbe_input/CMakeLists.txt
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
cmake_minimum_required(VERSION 3.0.2)
cmake_minimum_required(VERSION 3.10.2)
project(flexbe_input)

find_package(catkin REQUIRED)
Expand Down
6 changes: 4 additions & 2 deletions flexbe_input/package.xml
Original file line number Diff line number Diff line change
Expand Up @@ -4,11 +4,13 @@
schematypens="http://www.w3.org/2001/XMLSchema"?>
<package format="3">
<name>flexbe_input</name>
<version>1.3.1</version>
<version>1.4.1</version>
<description>
flexbe_input enables to send data to onboard behavior when required.
</description>
<maintainer email="[email protected]">Philipp Schillinger</maintainer>
<author>Philipp Schillinger</author>
<maintainer email="[email protected]">Philipp Schillinger</maintainer>
+ <maintainer email="[email protected]">David Conner</maintainer>
<license>BSD</license>

<url>http://ros.org/wiki/flexbe_input</url>
Expand Down
8 changes: 8 additions & 0 deletions flexbe_mirror/CHANGELOG.rst
Original file line number Diff line number Diff line change
@@ -1,6 +1,14 @@
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Changelog for package flexbe_mirror
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
1.4.1 (2023-07-19)
------------------
* make cmake_minimum_version consistent 3.10.2 for Noetic
* update maintainer tags in Noetic

1.4.0 (2023-05-18)
------------------
* Updates for Melodic and Noetic releases on github.com/FlexBE

1.3.1 (2020-12-11)
------------------
Expand Down
2 changes: 1 addition & 1 deletion flexbe_mirror/CMakeLists.txt
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
cmake_minimum_required(VERSION 3.0.2)
cmake_minimum_required(VERSION 3.10.2)
project(flexbe_mirror)

find_package(catkin REQUIRED)
Expand Down
7 changes: 4 additions & 3 deletions flexbe_mirror/package.xml
Original file line number Diff line number Diff line change
Expand Up @@ -4,15 +4,16 @@
schematypens="http://www.w3.org/2001/XMLSchema"?>
<package format="3">
<name>flexbe_mirror</name>
<version>1.3.1</version>
<version>1.4.1</version>
<description>
flexbe_mirror implements functionality to remotely mirror an executed behavior.
</description>
<maintainer email="[email protected]">Philipp Schillinger</maintainer>
<author>Philipp Schillinger</author>
<maintainer email="[email protected]">Philipp Schillinger</maintainer>
+ <maintainer email="[email protected]">David Conner</maintainer>
<license>BSD</license>

<url>http://ros.org/wiki/flexbe_mirror</url>
<author>Philipp Schillinger</author>

<buildtool_depend>catkin</buildtool_depend>
<buildtool_depend condition="$ROS_PYTHON_VERSION == 2">python-setuptools</buildtool_depend>
Expand Down
Loading