Bug#1035987: unblock: ros-ros-comm/1.15.15+ds-2

[Jochen Sprickerhof]

Package: release.debian.org
Severity: normal
User: release.debian.org at packages.debian.org
Usertags: unblock
X-Debbugs-Cc: ros-ros-comm at 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
-------------- next part --------------
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 at 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':