Add named loggers to rospy, this change will create (named) child log…

…gers under rospy.rosout. This allows for each named logger to have seperate verbosity setting, this will allow for two different verboisty settings for logging in a single node. Two named loggers can log to rosout at two different verbosity setings, which can help noisy debug logs.

clients/rospy/src/rospy/core.py

@@ -37,11 +37,11 @@
 
 
 import atexit
-try:
-    import cPickle as pickle
-except ImportError:
-    import pickle
-import inspect
+try:
+    import cPickle as pickle
+except ImportError:
+    import pickle
+import inspect
 import logging
 import os
 import signal
@@ -72,6 +72,7 @@
 from rospy.impl.validators import ParameterInvalid
 
 from rosgraph_msgs.msg import Log
+from functools import partial
 
 _logger = logging.getLogger("rospy.core")
 
@@ -109,7 +110,7 @@ def parse_rosrpc_uri(uri):
     @raise ParameterInvalid: if uri is not a valid ROSRPC URI
     """
     if uri.startswith(ROSRPC):
-        dest_addr = uri[len(ROSRPC):]            
+        dest_addr = uri[len(ROSRPC):]
     else:
         raise ParameterInvalid("Invalid protocol for ROS service URL: %s"%uri)
     try:
@@ -122,7 +123,7 @@ def parse_rosrpc_uri(uri):
     return dest_addr, dest_port
 
 #########################################################
-        
+
 # rospy logger
 _rospy_logger = logging.getLogger("rospy.internal")
 
@@ -142,79 +143,107 @@ def rospyerr(msg, *args):
 def rospywarn(msg, *args):
     """Internal rospy client library warn logging"""
     _rospy_logger.warn(msg, *args)
-
-logdebug = logging.getLogger('rosout').debug
 
-logwarn = logging.getLogger('rosout').warning
+def _base_logger(msg, *args, **kwargs):
+
+    try:
+        name = kwargs.pop('_logger_name')
+    except KeyError:
+        name = None
+
+    try:
+        throttle = int(kwargs.pop('_logger_throttle'))
+    except KeyError:
+        throttle = None
+
+    try:
+        level = kwargs.pop('_logger_level')
+    except KeyError:
+        level = None
+
+    rospy_logger = logging.getLogger('rosout')
+    if name:
+        rospy_logger = rospy_logger.getChild(name)
+    logfunc = getattr(rospy_logger, level)
+
+    if throttle:
+        caller_id = _frame_record_to_caller_id(inspect.stack()[1])
+        _logging_throttle(caller_id, logfunc, throttle, msg)
+    else:
+        logfunc(msg, *args, **kwargs)
+
+
+loginfo = partial(_base_logger, _logger_level='info')
 
-loginfo = logging.getLogger('rosout').info
 logout = loginfo # alias deprecated name
 
-logerr = logging.getLogger('rosout').error
+logdebug = partial(_base_logger, _logger_level='debug')
+
+logwarn = partial(_base_logger, _logger_level='warn')
+
+logerr = partial(_base_logger, _logger_level='error')
+
 logerror = logerr # alias logerr
 
-logfatal = logging.getLogger('rosout').critical
-
-
-class LoggingThrottle(object):
-
-    last_logging_time_table = {}
-
-    def __call__(self, caller_id, logging_func, period, msg):
-        """Do logging specified message periodically.
-
-        - caller_id (str): Id to identify the caller
-        - logging_func (function): Function to do logging.
-        - period (float): Period to do logging in second unit.
-        - msg (object): Message to do logging.
-        """
-        now = rospy.Time.now()
-
-        last_logging_time = self.last_logging_time_table.get(caller_id)
-
-        if (last_logging_time is None or
-              (now - last_logging_time) > rospy.Duration(period)):
-            logging_func(msg)
-            self.last_logging_time_table[caller_id] = now
-
-
-_logging_throttle = LoggingThrottle()
-
-
-def _frame_record_to_caller_id(frame_record):
-    frame, _, lineno, _, code, _ = frame_record
-    caller_id = (
-        inspect.getabsfile(frame),
-        lineno,
-        frame.f_lasti,
-    )
-    return pickle.dumps(caller_id)
-
-
-def logdebug_throttle(period, msg):
-    caller_id = _frame_record_to_caller_id(inspect.stack()[1])
-    _logging_throttle(caller_id, logdebug, period, msg)
-
-
-def loginfo_throttle(period, msg):
-    caller_id = _frame_record_to_caller_id(inspect.stack()[1])
-    _logging_throttle(caller_id, loginfo, period, msg)
-
-
-def logwarn_throttle(period, msg):
-    caller_id = _frame_record_to_caller_id(inspect.stack()[1])
-    _logging_throttle(caller_id, logwarn, period, msg)
-
-
-def logerr_throttle(period, msg):
-    caller_id = _frame_record_to_caller_id(inspect.stack()[1])
-    _logging_throttle(caller_id, logerr, period, msg)
-
-
-def logfatal_throttle(period, msg):
-    caller_id = _frame_record_to_caller_id(inspect.stack()[1])
-    _logging_throttle(caller_id, logfatal, period, msg)
-
+logfatal = partial(_base_logger, _logger_level='critical')
+
+
+
+class LoggingThrottle(object):
+
+    last_logging_time_table = {}
+
+    def __call__(self, caller_id, logging_func, period, msg):
+        """Do logging specified message periodically.
+
+        - caller_id (str): Id to identify the caller
+        - logging_func (function): Function to do logging.
+        - period (float): Period to do logging in second unit.
+        - msg (object): Message to do logging.
+        """
+        now = rospy.Time.now()
+
+        last_logging_time = self.last_logging_time_table.get(caller_id)
+
+        if (last_logging_time is None or
+              (now - last_logging_time) > rospy.Duration(period)):
+            logging_func(msg)
+            self.last_logging_time_table[caller_id] = now
+
+
+_logging_throttle = LoggingThrottle()
+
+
+def _frame_record_to_caller_id(frame_record):
+    frame, _, lineno, _, code, _ = frame_record
+    caller_id = (
+        inspect.getabsfile(frame),
+        lineno,
+        frame.f_lasti,
+    )
+    return pickle.dumps(caller_id)
+
+
+def logdebug_throttle(period, msg):
+    logdebug(msg, _logger_name=None, _logger_throttle=period)
+
+
+def loginfo_throttle(period, msg):
+    loginfo(msg, _logger_name=None, _logger_throttle=period)
+
+
+def logwarn_throttle(period, msg):
+    logwarn(msg, _logger_name=None, _logger_throttle=period)
+
+
+def logerr_throttle(period, msg):
+    logerr(msg, _logger_name=None, _logger_throttle=period)
+
+
+def logfatal_throttle(period, msg):
+    logfatal(msg, _logger_name=None, _logger_throttle=period)
+
+
 
 #########################################################
 # CONSTANTS
@@ -302,10 +331,10 @@ def configure_logging(node_name, level=logging.INFO):
 class NullHandler(logging.Handler):
     def emit(self, record):
         pass
-    
+
 # keep logging happy until we have the node name to configure with
-logging.getLogger('rospy').addHandler(NullHandler())    
-    
+logging.getLogger('rospy').addHandler(NullHandler())
+
 
 #########################################################
 # Init/Shutdown/Exit API and Handlers
@@ -364,7 +393,7 @@ def is_shutdown_requested():
     received and continues until client shutdown handlers have been
     called.  After client shutdown handlers have been serviced, the
     is_shutdown state becomes true.
-    
+
     @return: True if shutdown has been requested (but possibly not yet initiated)
     @rtype: bool
     """
@@ -413,7 +442,7 @@ def add_client_shutdown_hook(h):
     Add client method to invoke when system shuts down. Unlike
     L{add_shutdown_hook} and L{add_preshutdown_hooks}, these methods
     will be called before any rospy internal shutdown code.
-    
+
     @param h: function with zero args
     @type  h: fn()
     """
@@ -424,7 +453,7 @@ def add_preshutdown_hook(h):
     Add method to invoke when system shuts down. Unlike
     L{add_shutdown_hook}, these methods will be called before any
     other shutdown hooks.
-    
+
     @param h: function that takes in a single string argument (shutdown reason)
     @type  h: fn(str)
     """
@@ -517,17 +546,17 @@ def register_signals():
     """
     _signalChain[signal.SIGTERM] = signal.signal(signal.SIGTERM, _ros_signal)
     _signalChain[signal.SIGINT]  = signal.signal(signal.SIGINT, _ros_signal)
-    
+
 # Validators ######################################
 
 def is_topic(param_name):
     """
     Validator that checks that parameter is a valid ROS topic name
-    """    
+    """
     def validator(param_value, caller_id):
         v = valid_name_validator_resolved(param_name, param_value, caller_id)
         if param_value == '/':
-            raise ParameterInvalid("ERROR: parameter [%s] cannot be the global namespace"%param_name)            
+            raise ParameterInvalid("ERROR: parameter [%s] cannot be the global namespace"%param_name)
         return v
     return validator
 
@@ -542,4 +571,3 @@ def xmlrpcapi(uri):
     if not uriValidate[0] or not uriValidate[1]:
         return None
     return xmlrpcclient.ServerProxy(uri)
-