Skip to content

Try to get a more reasonable stacklevel#4656

Merged
happz merged 3 commits intoteemtee:mainfrom
LecrisUT:fix/stacklevel
Mar 9, 2026
Merged

Try to get a more reasonable stacklevel#4656
happz merged 3 commits intoteemtee:mainfrom
LecrisUT:fix/stacklevel

Conversation

@LecrisUT
Copy link
Contributor

@LecrisUT LecrisUT commented Mar 6, 2026

Try to provide a more reasonable stacklevel to the inner logging.Logger._log, skipping any functions that are wrappers around the loggers. The references in the logger's record should point to the most relevant function that requested the log command, or any such indirect commands like the guest.run.


Found that this would be useful in #4642 for getting a more accurate source of the caller and I split it out from there to simplify the review.

The stack can be further improved as it goes, as shown in the second commit of this PR, but that can be gradually addressed.

Pull Request Checklist

  • implement the feature

@LecrisUT LecrisUT added this to planning Mar 6, 2026
@LecrisUT LecrisUT added code | logging Changes related to debug logging status | blocking other work An important pull request, blocking other pull requests or issues ci | full test Pull request is ready for the full test execution labels Mar 6, 2026
@github-project-automation github-project-automation bot moved this to backlog in planning Mar 6, 2026
@LecrisUT LecrisUT moved this from backlog to review in planning Mar 6, 2026
@LecrisUT LecrisUT added this to the 1.69 milestone Mar 6, 2026
Copy link
Contributor

@gemini-code-assist gemini-code-assist bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review

This pull request introduces stacklevel handling to logging functions to provide more accurate caller information in logs. The core logic in tmt/log.py correctly adjusts the stack level. The comment suggesting to refactor repeated stacklevel logic into a decorator has been kept as it aligns with general code quality improvements and is not contradicted by existing rules.

Note: Security Review did not run due to the size of the PR.

@happz
Copy link
Contributor

happz commented Mar 6, 2026

What is a “stacklevel”, and what is it good for? If there’s a vhange to output, would it be possible to inckude an example or two to demonstrate the change, e.g. before/after?

@LecrisUT
Copy link
Contributor Author

LecrisUT commented Mar 6, 2026

What is a “stacklevel”, and what is it good for? If there’s a vhange to output, would it be possible to inckude an example or two to demonstrate the change, e.g. before/after?

It's related to the stack trace and so far I don't think we use it anywhere yet (will do in #4642). It basically controls how many levels up the stack trace do you navigate (from inside logging.Logger._log call) to save the origin of the caller in the record. Best place to see this imo is in #4642.

@skycastlelily
Copy link
Collaborator

What is a “stacklevel”, and what is it good for? If there’s a vhange to output, would it be possible to inckude an example or two to demonstrate the change, e.g. before/after?

It's related to the stack trace and so far I don't think we use it anywhere yet (will do in #4642). It basically controls >how many levels up the stack trace do you navigate (from inside logging.Logger._log call) to save the origin of the >caller in the record. Best place to see this imo is in #4642.

Hmm, imo it's better to put  _log  in this mr , #4642 is mainly about warning file , and Warnings classes,plus the mr will be merged before #4642.Not strong opinion though:)

Copy link
Collaborator

@skycastlelily skycastlelily left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM in general:)

@thrix thrix self-requested a review March 9, 2026 14:54
Copy link
Contributor

@thrix thrix left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The PR fixes source location reporting in log records.                                                                                                                                       
                                                                                                                                                                                               
  Python's logging module records the filename, line number, and function name of the code that emitted each log message. Without stacklevel, every log record in tmt would show tmt/log.py    
  (the internal Logger._log method) as the source, because that's where self._logger._log() is actually called.                                                                                
                                                                                                                                                                                               
  With this patch, log records correctly point to the actual caller - e.g., the plugin or step code that called logger.verbose() or self.info(). This matters when:

  - Using log formatters that include %(filename)s:%(lineno)d (standard Python logging pattern)
  - Debugging with file-based log handlers that show source locations
  - Any tooling that inspects LogRecord.pathname / LogRecord.lineno to trace where a message originated

  Before this PR, all log records would point to the same internal location regardless of which code emitted them. After it, each record correctly identifies its origin in the business logic.

  The PR description notes this was split out from #4642, which specifically needs accurate caller information.

@LecrisUT I would make the MR description a bit more descriptive, for example this AI summary is a lot better for me then the current description.

@LecrisUT
Copy link
Contributor Author

LecrisUT commented Mar 9, 2026

The PR fixes source location reporting in log records.                                                                                                                                       
                                                                                                                                                                                               
  Python's logging module records the filename, line number, and function name of the code that emitted each log message. Without stacklevel, every log record in tmt would show tmt/log.py    
  (the internal Logger._log method) as the source, because that's where self._logger._log() is actually called.                                                                                
                                                                                                                                                                                               
  With this patch, log records correctly point to the actual caller - e.g., the plugin or step code that called logger.verbose() or self.info(). This matters when:

  - Using log formatters that include %(filename)s:%(lineno)d (standard Python logging pattern)
  - Debugging with file-based log handlers that show source locations
  - Any tooling that inspects LogRecord.pathname / LogRecord.lineno to trace where a message originated

  Before this PR, all log records would point to the same internal location regardless of which code emitted them. After it, each record correctly identifies its origin in the business logic.

  The PR description notes this was split out from #4642, which specifically needs accurate caller information.

@LecrisUT I would make the MR description a bit more descriptive, for example this AI summary is a lot better for me then the current description.

I do not like the verbosity there at all. If there is a concise version I could consider, but I do not want the commit message to be so full of tangents

Edit: tried to manually improve the message.

@thrix thrix moved this from review to merge in planning Mar 9, 2026
LecrisUT added 3 commits March 9, 2026 19:02
Signed-off-by: Cristian Le <git@lecris.dev>
Signed-off-by: Cristian Le <git@lecris.dev>
Signed-off-by: Cristian Le <git@lecris.dev>
@happz happz merged commit ff4f7e4 into teemtee:main Mar 9, 2026
30 checks passed
@github-project-automation github-project-automation bot moved this from merge to done in planning Mar 9, 2026
@LecrisUT LecrisUT deleted the fix/stacklevel branch March 10, 2026 11:53
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

ci | full test Pull request is ready for the full test execution code | logging Changes related to debug logging status | blocking other work An important pull request, blocking other pull requests or issues

Projects

Status: done

Development

Successfully merging this pull request may close these issues.

4 participants