[rospy] Write log for class method with class name for rospy #877

wkentaro · 2016-08-25T20:12:27Z

$ export ROSCONSOLE_FORMAT='[${severity}] [${time}]: [${node}] [${function}] ${message}'

$ python spam.py
[INFO] [1472155704.567361]: [/a] [<module>] a
[WARN] [1472155704.568193]: [/a] [<module>] a
[FATAL] [1472155704.568894]: [/a] [<module>] a
[ERROR] [1472155704.569581]: [/a] [<module>] a
[INFO] [1472155704.570351]: [/a] [main] a
[WARN] [1472155704.571100]: [/a] [main] a
[FATAL] [1472155704.571878]: [/a] [main] a
[ERROR] [1472155704.572626]: [/a] [main] a
[INFO] [1472155704.573439]: [/a] [Test::__init__] a
[WARN] [1472155704.574176]: [/a] [Test::__init__] a
[FATAL] [1472155704.574937]: [/a] [Test::__init__] a
[ERROR] [1472155704.575672]: [/a] [Test::__init__] a

$ cat spam.py

import rospy

rospy.init_node('a')

rospy.loginfo('a')
rospy.logwarn('a')
rospy.logfatal('a')
rospy.logerr('a')

def main():
    rospy.loginfo('a')
    rospy.logwarn('a')
    rospy.logfatal('a')
    rospy.logerr('a')
main()

class Test(object):
    def __init__(self):
        rospy.loginfo('a')
        rospy.logwarn('a')
        rospy.logfatal('a')
        rospy.logerr('a')
Test()

``` $ export ROSCONSOLE_FORMAT='[${severity}] [${time}]: [${node}] [${function}] ${message}' ``` ``` $ python spam.py [INFO] [1472155704.567361]: [/a] [<module>] a [WARN] [1472155704.568193]: [/a] [<module>] a [FATAL] [1472155704.568894]: [/a] [<module>] a [ERROR] [1472155704.569581]: [/a] [<module>] a [INFO] [1472155704.570351]: [/a] [main] a [WARN] [1472155704.571100]: [/a] [main] a [FATAL] [1472155704.571878]: [/a] [main] a [ERROR] [1472155704.572626]: [/a] [main] a [INFO] [1472155704.573439]: [/a] [Test::__init__] a [WARN] [1472155704.574176]: [/a] [Test::__init__] a [FATAL] [1472155704.574937]: [/a] [Test::__init__] a [ERROR] [1472155704.575672]: [/a] [Test::__init__] a ``` ``` $ cat spam.py import rospy rospy.init_node('a') rospy.loginfo('a') rospy.logwarn('a') rospy.logfatal('a') rospy.logerr('a') def main(): rospy.loginfo('a') rospy.logwarn('a') rospy.logfatal('a') rospy.logerr('a') main() class Test(object): def __init__(self): rospy.loginfo('a') rospy.logwarn('a') rospy.logfatal('a') rospy.logerr('a') Test() ```

dirk-thomas · 2016-08-30T16:46:34Z

This patch seems to not resolve the line number. Doesn't this breaks existing behavior when ${line} is being used.

Please also add a test for the new behavior.

dirk-thomas · 2016-08-30T16:47:12Z

tools/rosgraph/src/rosgraph/roslogging.py

+        func_name = frame.f_code.co_name
+        try:
+            class_name = frame.f_locals['self'].__class__.__name__
+            func_name = '%s::%s' % (class_name, func_name)


%s::%s is not the Python way to reference a method of a class. Please use %s.%s instead.

wkentaro · 2016-08-30T21:41:07Z

Fixed.

dirk-thomas · 2016-08-31T16:00:00Z

tools/rosgraph/src/rosgraph/roslogging.py

+            pass
+        return file_name, lineno, func_name
+
+logging.setLoggerClass(RospyLogger)


This should ensure not to overwrite custom logger classes already being set by user code. See https://docs.python.org/2/library/logging.html#logging.getLoggerClass on how to achieve this.

Could you please also cover that case in the test.

wkentaro · 2016-09-01T04:48:34Z

Fixed.

dirk-thomas · 2016-09-01T18:50:39Z

Please use the approach described in the link from #877 (comment) since it also allows to customize the logger if a user defined class has been set before.

wkentaro · 2016-09-01T19:18:24Z

This should ensure not to overwrite custom logger classes already being set by user code. See https://docs.python.org/2/library/logging.html#logging.getLoggerClass on how to achieve this.

But below code overwrites the custom logger class. Is that ok?

class MyLogger(logging.getLoggerClass()):
    # ... override behaviour here

dirk-thomas · 2016-09-01T19:20:42Z

Yes, but it creates the subclass not of the original logger but of the currently set logger class which could be set by a user before. So it will maintain all other changes from the custom class (except the overridden functionality).

wkentaro · 2016-09-01T19:59:20Z

Ok, fixed.

dirk-thomas · 2016-09-02T20:38:57Z

The patch currently fails one of the new tests.

wkentaro · 2016-09-03T08:00:35Z

Fixed.

dirk-thomas · 2016-09-06T17:44:02Z

tools/rosgraph/test/isolated/test_roslogging_user_logger.py

@@ -0,0 +1,133 @@
+# Software License Agreement (BSD License)


Why is this file in a subfolder?

This file shouldn't repeat all the tests from the other file but only check the UserCustomLogger.

This file shouldn't repeat all the tests from the other file but only check the UserCustomLogger.

Ok I will fix it.

This reverts commit 6ac0137.

wkentaro · 2016-10-28T19:26:45Z

Well, .. it still fails

% nosetests test/    
........ERROR: Invalid remapping argument ':=:='
ERROR: Invalid remapping argument 'foo:=bar:=baz'
..........invalid ROS_IP (must be a valid IPv4 or IPv6 address)
invalid ROS_IP (must be a valid IPv4 or IPv6 address)
.invalid ROS_IP (must be a valid IPv4 or IPv6 address)
.invalid ROS_IP (must be a valid IPv4 or IPv6 address)
..............................F..
======================================================================
FAIL: test.test_roslogging_user_logger.test_roslogging_user_logger
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/nose/case.py", line 197, in runTest
    self.test(*self.arg)
  File "/home/wkentaro/ros/ros_comm_ws/src/ros_comm/tools/rosgraph/test/test_roslogging_user_logger.py", line 112, in test_roslogging_user_logger
    assert_regexp_matches(log_actual, log_expected)
AssertionError: Regexp didn't match: 'INFO 127.0.0.1 Hello world. [0-9]*\\.[0-9]* [0-9]* rosout <filename> <lineno> <func_name> /unnamed [0-9]*\\.[0-9]*' not found in 'INFO Hello world. 1477682768.908821 140199866681152 rosout /home/wkentaro/ros/ros_comm_ws/src/ros_comm/tools/rosgraph/test/test_roslogging_user_logger.py 93 test_roslogging_user_logger /unnamed 1477682768.908852'

----------------------------------------------------------------------
Ran 53 tests in 0.531s

FAILED (failures=1)

% nosetests test/test_roslogging_user_logger.py
.
----------------------------------------------------------------------
Ran 1 test in 0.079s

OK

dirk-thomas · 2017-07-07T22:24:50Z

Addressed by #1043.

wkentaro mentioned this pull request Aug 30, 2016

[rospy] Logging function for rospy with node/func named msg #875

Closed

dirk-thomas reviewed Aug 30, 2016
View reviewed changes

dirk-thomas added enhancement requires-changes labels Aug 30, 2016

wkentaro added 2 commits August 31, 2016 06:35

Fix func name {class_name}.{method_name}

1642602

Get line number for rospy logger

00ab383

Add test for roslogging ROSCONSOLE_FORMAT

9f86e24

dirk-thomas reviewed Aug 31, 2016
View reviewed changes

wkentaro added 2 commits September 1, 2016 13:47

Add license header

bb4e980

Don't overwrite logger defined by user

4a1cdde

wkentaro force-pushed the rosconsole-format-func-with-class branch from 484af79 to 901290a Compare September 1, 2016 19:50

Inherit user defined custom logger class in RospyLogger

76835b0

wkentaro force-pushed the rosconsole-format-func-with-class branch from 901290a to 76835b0 Compare September 1, 2016 19:57

wkentaro added 2 commits September 3, 2016 16:49

Fix test name of test_roslogging_user_logger.py

0abb0db

Make logging test as isolated one

6ac0137

wkentaro closed this Sep 4, 2016

wkentaro reopened this Sep 4, 2016

dirk-thomas reviewed Sep 6, 2016
View reviewed changes

Revert "Make logging test as isolated one"

603cdea

This reverts commit 6ac0137.

Fix test for rosgraph with user custom logger

5b7e3e8

asmodehn mentioned this pull request May 2, 2017

[rospy] Write log for class method with class name for rospy #1043

Merged

wkentaro mentioned this pull request May 31, 2017

[jsk_topic_tools] Show deprecation warning for jsk_logxxx logging functions jsk-ros-pkg/jsk_common#1524

Closed

dirk-thomas closed this Jul 7, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[rospy] Write log for class method with class name for rospy #877

[rospy] Write log for class method with class name for rospy #877

wkentaro commented Aug 25, 2016 •

edited

Loading

dirk-thomas commented Aug 30, 2016 •

edited

Loading

dirk-thomas Aug 30, 2016

wkentaro commented Aug 30, 2016

dirk-thomas Aug 31, 2016 •

edited

Loading

wkentaro commented Sep 1, 2016

dirk-thomas commented Sep 1, 2016

wkentaro commented Sep 1, 2016

dirk-thomas commented Sep 1, 2016

wkentaro commented Sep 1, 2016

dirk-thomas commented Sep 2, 2016

wkentaro commented Sep 3, 2016

dirk-thomas Sep 6, 2016

dirk-thomas Sep 6, 2016

wkentaro Sep 7, 2016

wkentaro commented Oct 28, 2016 •

edited

Loading

dirk-thomas commented Jul 7, 2017

[rospy] Write log for class method with class name for rospy #877

[rospy] Write log for class method with class name for rospy #877

Conversation

wkentaro commented Aug 25, 2016 • edited Loading

dirk-thomas commented Aug 30, 2016 • edited Loading

dirk-thomas Aug 30, 2016

Choose a reason for hiding this comment

wkentaro commented Aug 30, 2016

dirk-thomas Aug 31, 2016 • edited Loading

Choose a reason for hiding this comment

wkentaro commented Sep 1, 2016

dirk-thomas commented Sep 1, 2016

wkentaro commented Sep 1, 2016

dirk-thomas commented Sep 1, 2016

wkentaro commented Sep 1, 2016

dirk-thomas commented Sep 2, 2016

wkentaro commented Sep 3, 2016

dirk-thomas Sep 6, 2016

Choose a reason for hiding this comment

dirk-thomas Sep 6, 2016

Choose a reason for hiding this comment

wkentaro Sep 7, 2016

Choose a reason for hiding this comment

wkentaro commented Oct 28, 2016 • edited Loading

dirk-thomas commented Jul 7, 2017

wkentaro commented Aug 25, 2016 •

edited

Loading

dirk-thomas commented Aug 30, 2016 •

edited

Loading

dirk-thomas Aug 31, 2016 •

edited

Loading

wkentaro commented Oct 28, 2016 •

edited

Loading