https://github.com/python/cpython/commit/5ca6d7469be53960843df39bb900e9c3359... commit: 5ca6d7469be53960843df39bb900e9c3359f127f branch: main author: Jouke Witteveen <j.witteveen@gmail.com> committer: vsajip <vinay_sajip@yahoo.co.uk> date: 2022-03-27T14:49:28+01:00 summary: bpo-45171: Fix stacklevel handling in logging. (GH-28287) files: A Misc/NEWS.d/next/Library/2021-09-11-16-06-54.bpo-45171.ec597j.rst M Lib/logging/__init__.py M Lib/test/test_logging.py diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 160b1afcee0f9..e8054fb1f72ac 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -159,8 +159,8 @@ def addLevelName(level, levelName): finally: _releaseLock() -if hasattr(sys, '_getframe'): - currentframe = lambda: sys._getframe(3) +if hasattr(sys, "_getframe"): + currentframe = lambda: sys._getframe(1) else: #pragma: no cover def currentframe(): """Return the frame object for the caller's stack frame.""" @@ -184,13 +184,18 @@ def currentframe(): _srcfile = os.path.normcase(addLevelName.__code__.co_filename) # _srcfile is only used in conjunction with sys._getframe(). -# To provide compatibility with older versions of Python, set _srcfile -# to None if _getframe() is not available; this value will prevent -# findCaller() from being called. You can also do this if you want to avoid -# the overhead of fetching caller information, even when _getframe() is -# available. -#if not hasattr(sys, '_getframe'): -# _srcfile = None +# 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. +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 == _srcfile or ( + "importlib" in filename and "_bootstrap" in filename + ) def _checkLevel(level): @@ -1558,33 +1563,31 @@ def findCaller(self, stack_info=False, stacklevel=1): f = currentframe() #On some versions of IronPython, currentframe() returns None if #IronPython isn't run with -X:Frames. - if f is not None: - f = f.f_back - orig_f = f - while f and stacklevel > 1: - f = f.f_back - stacklevel -= 1 - if not f: - f = orig_f - rv = "(unknown file)", 0, "(unknown function)", None - while hasattr(f, "f_code"): - co = f.f_code - filename = os.path.normcase(co.co_filename) - if filename == _srcfile: - f = f.f_back - continue - sinfo = None - if stack_info: - sio = io.StringIO() - sio.write('Stack (most recent call last):\n') + if f is None: + return "(unknown file)", 0, "(unknown function)", None + while stacklevel > 0: + next_f = f.f_back + if next_f is None: + ##TODO: We've got options here + ## If we want to use the last (deepest) frame: + break + ## 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 _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] - sio.close() - rv = (co.co_filename, f.f_lineno, co.co_name, sinfo) - break - return rv + return co.co_filename, f.f_lineno, co.co_name, sinfo def makeRecord(self, name, level, fn, lno, msg, args, exc_info, func=None, extra=None, sinfo=None): diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index 5f72a6dd5871a..00e354147a27c 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -5050,9 +5050,10 @@ def test_find_caller_with_stack_info(self): def test_find_caller_with_stacklevel(self): the_level = 1 + trigger = self.logger.warning def innermost(): - self.logger.warning('test', stacklevel=the_level) + trigger('test', stacklevel=the_level) def inner(): innermost() @@ -5074,6 +5075,16 @@ def outer(): self.assertEqual(records[-1].funcName, 'outer') self.assertGreater(records[-1].lineno, lineno) lineno = records[-1].lineno + trigger = self.logger.warn + outer() + self.assertEqual(records[-1].funcName, 'outer') + root_logger = logging.getLogger() + root_logger.addHandler(self.recording) + trigger = logging.warning + outer() + self.assertEqual(records[-1].funcName, 'outer') + root_logger.removeHandler(self.recording) + trigger = self.logger.warning the_level += 1 outer() self.assertEqual(records[-1].funcName, 'test_find_caller_with_stacklevel') diff --git a/Misc/NEWS.d/next/Library/2021-09-11-16-06-54.bpo-45171.ec597j.rst b/Misc/NEWS.d/next/Library/2021-09-11-16-06-54.bpo-45171.ec597j.rst new file mode 100644 index 0000000000000..eaa3fb2915e52 --- /dev/null +++ b/Misc/NEWS.d/next/Library/2021-09-11-16-06-54.bpo-45171.ec597j.rst @@ -0,0 +1,4 @@ +Fix handling of the ``stacklevel`` argument to logging functions in the +:mod:`logging` module so that it is consistent accross all logging functions +and, as advertised, similar to the ``stacklevel`` argument used in +:meth:`~warnings.warn`.