Skip to content
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

Add throttle option for logging #14

Closed
Closed
Changes from 4 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
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
Copy link
Author

@HannesBachter HannesBachter Nov 20, 2023

Choose a reason for hiding this comment

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

Any good idea on how to make that size configurable?


_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()})

if len(Logger._last_logged) > Logger.MAX_LAST_LOGGED_SIZE:
Copy link
Member

Choose a reason for hiding this comment

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

Once we hit limit this will process every message following.

Should we consider throwing away the oldest half of messages, otherwise i fear this limit will become a limiting factor given need to sort and pop when adding a single new message.

Copy link
Author

Choose a reason for hiding this comment

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

You're right, although this would only occur under the circumstance that we have more than 1024 log_throttles and it would only happen when a changing message is logged.
But I agree, that we don't want to have that overhead. I'll change the clearing to a percentage to the 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)