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.

Author fviard
Recipients fviard, r.david.murray, vinay.sajip
Date 2016-01-13.14:59:52
SpamBayes Score -1.0
Marked as misclassified Yes
Message-id <1452697194.86.0.972646075269.issue25668@psf.upfronthosting.co.za>
In-reply-to
Content
Sorry to reply after a so long time.

Please don't close this issue too fast, there is really a big issue that is not related to my specific case.
(Note that the attached test case is not the real case, but a small piece of code that is able to reproduce the issue consistently)

Also, I don't pretend that my fix proposal is the solution, but the issue definitively exists.

To reply to your comment:
<<<
handle() and emit() are high level methods of a handler, and format() is at a lower level. Not all emit() methods will call format(). For example, socket-based and queue-based handlers don't. So it is not in general possible to separate format() out - you will need to have a customised handler to deal with your somewhat unusual use case, and do whatever you need in there.
>>>
That is not true even if it is a little hidden in the code:
- SocketHandler: emit first calls makePickle that almost starts with "record.getMessages()" that does the interesting thing.
(self.format mainly does getMessages(), that is the function that gets the messages arguments, eventually from properties)
- QueueHandler: emit first calls "prepare(record)", that starts by calling self.format(record).

But after having looked deeper at the code, maybe my fix proposal could be modified to be something like:
new function in "LogRecord" class:
 def stringifyMessage(self):
     # CODE THAT WAS IN getMessages()
     self.processed_msg = str(self.msg)
     if self.args:
         self.processed_msg = self.processed_msg % self.args

modify the getMessages function to:
 def getMessages(self):
     if not self.processed_msg:
         self.stringifyMessage()
     return self.processed_msg

Then, in the "__init__.py" handle function, add the following before "self.acquire()":
record.stringifyMessage()

Thus, no need to change anything, any handler, but the "message" arguments will be processed before getting the lock of "logging".

Regarding the second part of your comment, just saying that "generally" threading locks are a complex topic, doesn't remove the fact that in this specific logging case, there is a real bug regarding how python works. Here, you assume that an user of "logging" is supposed to know how the inside thread locking of "logging" works because the section under locking of logging leaks into "user space code". I'm pretty sure that almost everyone using logging today would not think that such an issue could arise.

I could agree with your point if the problem that was solvable, but i'm pretty sure that there is at least a solution that is working with backward compatibility and at worst minor disturbance to some very specific users of some specific handlers.
History
Date User Action Args
2016-01-13 14:59:54fviardsetrecipients: + fviard, vinay.sajip, r.david.murray
2016-01-13 14:59:54fviardsetmessageid: <1452697194.86.0.972646075269.issue25668@psf.upfronthosting.co.za>
2016-01-13 14:59:54fviardlinkissue25668 messages
2016-01-13 14:59:52fviardcreate