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.

Sign up for GitHub

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

adding tests for new unique loggers #4

Merged
merged 1 commit into from
Apr 17, 2018
Merged

adding tests for new unique loggers #4

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
1 change: 1 addition & 0 deletions clients/rospy/src/rospy/__init__.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -58,6 +58,7 @@
get_node_uri, get_ros_root, \
logdebug, logwarn, loginfo, logout, logerr, logfatal, \
logdebug_throttle, logwarn_throttle, loginfo_throttle, logerr_throttle, logfatal_throttle, \
logdebug_throttle_identical, logwarn_throttle_identical, loginfo_throttle_identical, logerr_throttle_identical, logfatal_throttle_identical, \
logdebug_once, logwarn_once, loginfo_once, logerr_once, logfatal_once, \
parse_rosrpc_uri
from .exceptions import *
Expand Down
60 changes: 41 additions & 19 deletions clients/rospy/src/rospy/core.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -144,7 +144,16 @@ def rospyerr(msg, *args):
def rospywarn(msg, *args):
"""Internal rospy client library warn logging"""
_rospy_logger.warn(msg, *args)



def _frame_to_caller_id(frame):
caller_id = (
inspect.getabsfile(frame),
frame.f_lineno,
frame.f_lasti,
)
return pickle.dumps(caller_id)


def _base_logger(msg, *args, **kwargs):

Expand Down Expand Up @@ -224,6 +233,22 @@ def __call__(self, caller_id, period):
_logging_throttle = LoggingThrottle()


def logdebug_throttle(period, msg):
_base_logger(msg, logger_throttle=period, logger_level='debug')

def loginfo_throttle(period, msg):
_base_logger(msg, logger_throttle=period, logger_level='info')

def logwarn_throttle(period, msg):
_base_logger(msg, logger_throttle=period, logger_level='warn')

def logerr_throttle(period, msg):
_base_logger(msg, logger_throttle=period, logger_level='error')

def logfatal_throttle(period, msg):
_base_logger(msg, logger_throttle=period, logger_level='critical')


class LoggingIdentical(object):

last_logging_msg_table = {}
Expand All @@ -245,29 +270,26 @@ def __call__(self, caller_id, msg):
_logging_identical = LoggingIdentical()


def _frame_to_caller_id(frame):
caller_id = (
inspect.getabsfile(frame),
frame.f_lineno,
frame.f_lasti,
)
return pickle.dumps(caller_id)
def logdebug_throttle_identical(period, msg):
_base_logger(msg, logger_throttle=period, logger_throttle_identical=True,
logger_level='debug')

def loginfo_throttle_identical(period, msg):
_base_logger(msg, logger_throttle=period, logger_throttle_identical=True,
logger_level='info')

def logdebug_throttle(period, msg):
_base_logger(msg, logger_throttle=period, logger_level='debug')
def logwarn_throttle_identical(period, msg):
_base_logger(msg, logger_throttle=period, logger_throttle_identical=True,
logger_level='warn')

def loginfo_throttle(period, msg):
_base_logger(msg, logger_throttle=period, logger_level='info')
def logerr_throttle_identical(period, msg):
_base_logger(msg, logger_throttle=period, logger_throttle_identical=True,
logger_level='error')

def logwarn_throttle(period, msg):
_base_logger(msg, logger_throttle=period, logger_level='warn')
def logfatal_throttle_identical(period, msg):
_base_logger(msg, logger_throttle=period, logger_throttle_identical=True,
logger_level='critical')

def logerr_throttle(period, msg):
_base_logger(msg, logger_throttle=period, logger_level='error')

def logfatal_throttle(period, msg):
_base_logger(msg, logger_throttle=period, logger_level='critical')

class LoggingOnce(object):

Expand Down
93 changes: 91 additions & 2 deletions test/test_rospy/test/rostest/test_rospy_client_online.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -164,7 +164,7 @@ def test_log(self):
self.assert_("test 1" in lout_last)
lout_len = len(lout.getvalue())
rospy.sleep(rospy.Duration(1))
elif i == 1: # making sure the length of lerr doesnt change
elif i == 1: # making sure the length of lout doesnt change
self.assert_(lout_len == len(lout.getvalue()))
rospy.sleep(rospy.Duration(2))
else:
Expand Down Expand Up @@ -211,7 +211,96 @@ def test_log(self):
rospy.sleep(rospy.Duration(2))
else:
self.assert_("test 4" in lerr_last)


# logXXX_throttle_identical
lout_len = -1
for i in range(5):
if i < 2:
test_text = "test 1"
else:
test_text = "test 1a"
rospy.loginfo_throttle_identical(2, test_text)
lout_last = lout.getvalue().splitlines()[-1]
if i == 0: # Confirm test text was logged
self.assert_(test_text in lout_last)
lout_len = len(lout.getvalue())
elif i == 1: # Confirm the length of lout hasn't changed
self.assert_(lout_len == len(lout.getvalue()))
elif i == 2: # Confirm the new message was logged correctly
self.assert_(test_text in lout_last)
lout_len = len(lout.getvalue())
rospy.sleep(rospy.Duration(2))
elif i == 3: # Confirm the length of lout has changed
self.assert_(lout_len != len(lout.getvalue()))
else: # Confirm new test text is in last log
self.assert_(test_text in lout_last)

lerr_len = -1
for i in range(5):
if i < 2:
test_text = "test 2"
else:
test_text = "test 2a"
rospy.logwarn_throttle_identical(2, test_text)
lerr_last = lerr.getvalue().splitlines()[-1]
if i == 0: # Confirm test text was logged
self.assert_(test_text in lerr_last)
lerr_len = len(lerr.getvalue())
elif i == 1: # Confirm the length of lerr hasn't changed
self.assert_(lerr_len == len(lerr.getvalue()))
elif i == 2: # Confirm the new message was logged correctly
self.assert_(test_text in lerr_last)
lerr_len = len(lerr.getvalue())
rospy.sleep(rospy.Duration(2))
elif i == 3: # Confirm the length of lerr has incremented
self.assert_(lerr_len != len(lerr.getvalue()))
else: # Confirm new test text is in last log
self.assert_(test_text in lerr_last)

lerr_len = -1
for i in range(5):
if i < 2:
test_text = "test 3"
else:
test_text = "test 3a"
rospy.logerr_throttle_identical(2, test_text)
lerr_last = lerr.getvalue().splitlines()[-1]
if i == 0: # Confirm test text was logged
self.assert_(test_text in lerr_last)
lerr_len = len(lerr.getvalue())
elif i == 1: # Confirm the length of lerr hasn't changed
self.assert_(lerr_len == len(lerr.getvalue()))
elif i == 2: # Confirm the new message was logged correctly
self.assert_(test_text in lerr_last)
lerr_len = len(lerr.getvalue())
rospy.sleep(rospy.Duration(2))
elif i == 3: # Confirm the length of lerr has incremented
self.assert_(lerr_len != len(lerr.getvalue()))
else: # Confirm new test text is in last log
self.assert_(test_text in lerr_last)

lerr_len = -1
for i in range(5):
if i < 2:
test_text = "test 4"
else:
test_text = "test 4a"
rospy.logfatal_throttle_identical(2, test_text)
lerr_last = lerr.getvalue().splitlines()[-1]
if i == 0: # Confirm test text was logged
self.assert_(test_text in lerr_last)
lerr_len = len(lerr.getvalue())
elif i == 1: # Confirm the length of lerr hasn't changed
self.assert_(lerr_len == len(lerr.getvalue()))
elif i == 2: # Confirm the new message was logged correctly
self.assert_(test_text in lerr_last)
lerr_len = len(lerr.getvalue())
rospy.sleep(rospy.Duration(2))
elif i == 3: # Confirm the length of lerr has incremented
self.assert_(lerr_len != len(lerr.getvalue()))
else: # Confirm new test text is in last log
self.assert_(test_text in lerr_last)

rospy.loginfo("test child logger 1", logger_name="log1")
lout_last = lout.getvalue().splitlines()[-1]
self.assert_("test child logger 1" in lout_last)
Expand Down