[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#1035987: marked as done (unblock: ros-ros-comm/1.15.15+ds-2)



Your message dated Sun, 14 May 2023 15:42:07 +0000
with message-id <E1pyDrL-0016RP-Su@respighi.debian.org>
and subject line unblock ros-ros-comm
has caused the Debian Bug report #1035987,
regarding unblock: ros-ros-comm/1.15.15+ds-2
to be marked as done.

This means that you claim that the problem has been dealt with.
If this is not the case it is now your responsibility to reopen the
Bug report if necessary, and/or fix the problem forthwith.

(NB: If you are a system administrator and have no idea what this
message is talking about, this may indicate a serious mail system
misconfiguration somewhere. Please contact owner@bugs.debian.org
immediately.)


-- 
1035987: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1035987
Debian Bug Tracking System
Contact owner@bugs.debian.org with problems
--- Begin Message ---
Package: release.debian.org
Severity: normal
User: release.debian.org@packages.debian.org
Usertags: unblock
X-Debbugs-Cc: ros-ros-comm@packages.debian.org
Control: affects -1 + src:ros-ros-comm

Please unblock package ros-ros-comm

[ Reason ]
python3-rospy extends the Python logging system with it's own API,
overwriting the findCaller() function to get the filename and line
number where the logging function was called. This broke with Python
3.11, resulting in a dead lock and I fixed it by importing the Python
3.11 function back then. While this worked in a simple case, it showed
the wrong source code location when logging was called inside a
submodule. The new version in 1.15.15+ds-2 uses the code from
ros-ros-comm again, only fixing the deadlock.

This is done with two changes:

1. The while hasattr(f, "f_code") looping over the stack, gains a break
   once there is no more f.f_back to fix the deadlock.

2. The test to find "the right frame" does no longer work with 3.11 as
   the stack is different. Instead it is identified by the name
   "_base_logger", as it is used by the code later anyhow.

[ Impact ]
Wrong filenames and line numbers in logs.

[ Tests ]
Unit test that the function does not fail, manual tests that it returns
the correct value in different cases.

[ Risks ]
Minimal risk, the original code is part of the project for a long time and
the changes are minimal and make sure that it always terminates. The
only problem could be that it still prints the wrong value which would
be unfortunate but not a big problem as it is used for debugging only.

[ Checklist ]
  [X] all changes are documented in the d/changelog
  [X] I reviewed all changes and I approve them
  [X] attach debdiff against the package in testing

[ Other info ]
This was reported outside of Debian, thus no bug number.

unblock ros-ros-comm/1.15.15+ds-2
diff --git a/debian/changelog b/debian/changelog
index acd2cae..5193a76 100644
--- a/debian/changelog
+++ b/debian/changelog
@@ -1,3 +1,9 @@
+ros-ros-comm (1.15.15+ds-2) unstable; urgency=medium
+
+  * Properly fix rospy logging in Python 3.11
+
+ -- Jochen Sprickerhof <jspricke@debian.org>  Wed, 10 May 2023 12:27:48 +0200
+
 ros-ros-comm (1.15.15+ds-1) unstable; urgency=medium
 
   * New upstream version 1.15.15+ds
diff --git a/debian/patches/0015-rosgraph-update-code-from-Python-3.11.patch b/debian/patches/0015-rosgraph-update-code-from-Python-3.11.patch
index dc20fa5..975aca1 100644
--- a/debian/patches/0015-rosgraph-update-code-from-Python-3.11.patch
+++ b/debian/patches/0015-rosgraph-update-code-from-Python-3.11.patch
@@ -3,102 +3,27 @@ Date: Sun, 13 Nov 2022 16:39:59 +0100
 Subject: rosgraph: update code from Python 3.11
 
 ---
- tools/rosgraph/src/rosgraph/roslogging.py | 72 ++++++++++++++++++++-----------
- 1 file changed, 47 insertions(+), 25 deletions(-)
+ tools/rosgraph/src/rosgraph/roslogging.py | 7 +++----
+ 1 file changed, 3 insertions(+), 4 deletions(-)
 
 diff --git a/tools/rosgraph/src/rosgraph/roslogging.py b/tools/rosgraph/src/rosgraph/roslogging.py
-index 9ecc121..0a94b2b 100644
+index 9ecc121..2df2f22 100644
 --- a/tools/rosgraph/src/rosgraph/roslogging.py
 +++ b/tools/rosgraph/src/rosgraph/roslogging.py
-@@ -50,32 +50,58 @@ from rospkg.environment import ROS_LOG_DIR
- class LoggingException(Exception): pass
- 
- class RospyLogger(logging.getLoggerClass()):
--    def findCaller(self, *args, **kwargs):
-+    # copied from python3.11/logging/__init__.py
-+    # _srcfile is only used in conjunction with sys._getframe().
-+    # Setting _srcfile to None will prevent findCaller() from being called. This
-+    # way, you can avoid the overhead of fetching caller information.
-+
-+    # The following is based on warnings._is_internal_frame. It makes sure that
-+    # frames of the import mechanism are skipped when logging at module level and
-+    # using a stacklevel value greater than one.
-+    @staticmethod
-+    def _is_internal_frame(frame):
-+        """Signal whether the frame is a CPython or logging module internal."""
-+        filename = os.path.normcase(frame.f_code.co_filename)
-+        return filename == logging._srcfile or (
-+            "importlib" in filename and "_bootstrap" in filename
-+        )
-+
-+
-+    def findCaller(self, stack_info=False, stacklevel=1):
-         """
-         Find the stack frame of the caller so that we can note the source
-         file name, line number, and function name with class name if possible.
-         """
--        file_name, lineno, func_name = super(RospyLogger, self).findCaller(*args, **kwargs)[:3]
--        file_name = os.path.normcase(file_name)
--
--        f = inspect.currentframe()
--        if f is not None:
--            f = f.f_back
--        while hasattr(f, "f_code"):
+@@ -62,13 +62,12 @@ class RospyLogger(logging.getLoggerClass()):
+         if f is not None:
+             f = f.f_back
+         while hasattr(f, "f_code"):
 -            # Search for the right frame using the data already found by parent class.
 -            co = f.f_code
 -            filename = os.path.normcase(co.co_filename)
 -            if filename == file_name and f.f_lineno == lineno and co.co_name == func_name:
-+
-+
-+        f = logging.currentframe()
-+        #On some versions of IronPython, currentframe() returns None if
-+        #IronPython isn't run with -X:Frames.
-+        if f is None:
-+            return "(unknown file)", 0, "(unknown function)", None
-+        while stacklevel > 0:
-+            next_f = f.f_back
-+            if next_f is None:
-+                ## We've got options here.
-+                ## If we want to use the last (deepest) frame:
++            if f.f_code.co_name == '_base_logger':
                  break
--            if f.f_back:
--                f = f.f_back
--
--        # Jump up two more frames, as the logger methods have been double wrapped.
--        if f is not None and f.f_back and f.f_code and f.f_code.co_name == '_base_logger':
--            f = f.f_back
--            if f.f_back:
--                f = f.f_back
-+                ## If we want to mimic the warnings module:
-+                #return ("sys", 1, "(unknown function)", None)
-+                ## If we want to be pedantic:
-+                #raise ValueError("call stack is not deep enough")
-+            f = next_f
-+            if not RospyLogger._is_internal_frame(f):
-+                stacklevel -= 1
-         co = f.f_code
-+        sinfo = None
-+        if stack_info:
-+            with io.StringIO() as sio:
-+                sio.write("Stack (most recent call last):\n")
-+                traceback.print_stack(f, file=sio)
-+                sinfo = sio.getvalue()
-+                if sinfo[-1] == '\n':
-+                    sinfo = sinfo[:-1]
-+
-         func_name = co.co_name
- 
-         # Now extend the function name with class name, if available.
-@@ -85,11 +111,7 @@ class RospyLogger(logging.getLoggerClass()):
-         except KeyError:  # if the function is unbound, there is no self.
-             pass
- 
--        if sys.version_info > (3, 2):
--            # Dummy last argument to match Python3 return type
--            return co.co_filename, f.f_lineno, func_name, None
--        else:
--            return co.co_filename, f.f_lineno, func_name
-+        return co.co_filename, f.f_lineno, func_name, sinfo
- 
- logging.setLoggerClass(RospyLogger)
+             if f.f_back:
+                 f = f.f_back
++            else:
++                break
  
+         # Jump up two more frames, as the logger methods have been double wrapped.
+         if f is not None and f.f_back and f.f_code and f.f_code.co_name == '_base_logger':

--- End Message ---
--- Begin Message ---
Unblocked.

--- End Message ---

Reply to: