This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

classification
Title: Logging doesn't report the correct filename or line numbers
Type: Stage:
Components: Library (Lib) Versions: Python 2.4
process
Status: closed Resolution: postponed
Dependencies: Superseder:
Assigned To: vinay.sajip Nosy List: michaeltsai, vinay.sajip
Priority: normal Keywords:

Created on 2006-04-14 15:48 by michaeltsai, last changed 2022-04-11 14:56 by admin. This issue is now closed.

Messages (4)
msg28235 - (view) Author: Michael Tsai (michaeltsai) Date: 2006-04-14 15:48
I have a logger that prints out %(filename)s:%(lineno)d along with the 
message. Instead of printing the file and line in my code where I call the 
logger, it prints out a location in logging/__init__.py.

I was able to fix this, at least for my purposes, by changing 
logging.currentframe from sys._getframe to lambda:sys._getframe(3).
msg28236 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2006-04-21 18:20
Logged In: YES 
user_id=308438

Please can you provide a small script which demonstrates the
problem? Which platform are you running on? Is there
anything unusual about your setup (e.g. running from a
frozen system)?

I'm not sure your patch is the correct solution. The system
looks up the call stack until a file is found which is not
the source file of the logging module itself - that is
presumed to be the caller. However, determining the source
file of the logging module can come unstuck in scenarios
such as py2exe-ified programs.
msg28237 - (view) Author: Michael Tsai (michaeltsai) Date: 2006-04-21 19:04
Logged In: YES 
user_id=817528

I'm running on Mac OS X 10.4.6.

Here's a simple script:
"""#!/usr/local/bin/python2.4

import logging
logging.basicConfig(format=u"%(filename)s:%(lineno)d %(message)s")
log = logging.getLogger("test")
log.error(u"this is an error")
"""

Unfortunately, it doesn't reliably fail; most of the time it works. I haven't 
figured out how to trigger it.

It does reliably fail when I use a frozen system created with "py2app -A" in 
which the Python libraries are symlinked in (rather than in a Zip). Then, 
logging._srcfile is "logging/__init__.py", but __file__ is something like "/
System/Library/Frameworks/Python.framework/Versions/2.3/lib/python2.3/
logging/__init__.py" Maybe py2app shouldn't set sys.frozen in this case? 

Anyway, I don't think that's the real problem, because I've seen this happen 
when not using py2app (but, sorry, I'm not able to reliably duplicate it at this 
time).

My patch isn't really the right fix, but I do think it works because, at least with 
the current logging module, currentframe() is always called with the same 
sequence of frames on the top of the stack.
msg28238 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2006-06-22 16:39
Logged In: YES 
user_id=308438

Michael,

I'll close this now, please feel free to re-open and
reassign to me when you can reproduce the problem more
predictably.
History
Date User Action Args
2022-04-11 14:56:16adminsetgithub: 43203
2006-04-14 15:48:47michaeltsaicreate