[bitbake-devel] [PATCH 1/1] lib/bb/codeparser: ensure BufferedLogger respects target filtering

[Christopher Larson]

On Tue, Mar 28, 2017 at 1:04 PM, Christopher Larson <chris_larson at mentor.com
> wrote:

> On Tue, Mar 28, 2017 at 12:50 PM, Paul Eggleton <
> paul.eggleton at linux.intel.com> wrote:
>
>> On Wednesday, 29 March 2017 5:01:31 AM NZDT Christopher Larson wrote:
>> > On Mon, Mar 27, 2017 at 5:51 PM, Paul Eggleton <
>> > paul.eggleton at linux.intel.com> wrote:
>> > > BufferedLogger was sending log records to the target logger using
>> > > handle() - this meant that the filtering (e.g. log level set)
>> > > on the target logger was bypassed, leading for example to debug
>> records
>> > > getting printed when the log level was set to logging.WARNING.
>> > >
>> > > Signed-off-by: Paul Eggleton <paul.eggleton at linux.intel.com>
>> >
>> > The ‘filter’ method of a Logger instance doesn’t log anything, it’s a
>> > subclass of Filterer, which just checks whether it should be logged. The
>> > ‘handle’ method of a Logger already consults self.filter(), if you check
>> > the code:
>> >
>> >    def handle(self, record):
>> >           """
>> >           Call the handlers for the specified record.
>> >
>> >           This method is used for unpickled records received from a
>> socket,
>> > as
>> >           well as those created locally. Logger-level filtering is
>> applied.
>> >           """
>> >           if (not self.disabled) and self.filter(record):
>> >               self.callHandlers(record)
>>
>> Oops, you're right. I'm still confused about why I'm seeing debugging
>> messages
>> when the target logger is set to INFO then. Do you have any suggestions
>> on how
>> we fix this?
>>
>> (I've attached a simplified test script demonstrating the issue.)
>
>
> handle() obeys filter(), but it seems filter() only checks to see if this
> logger is or isn’t responsible for a given message, it doesn’t actually
> check to see whether the logger is enabled for a given record given its
> level. The level based checking for a logger (as opposed to a handler)
> seems to be done in the actual message function, i.e.:
>
>     def debug(self, msg, *args, **kwargs):
>           if self.isEnabledFor(DEBUG):
>               self._log(DEBUG, msg, args, **kwargs)
>
> The setLevel() for the BufferLogger itself ensures that anything of that
> level (logging.DEBUG) or higher severity gets buffered, but then we bypass
> the isEnabledFor() on the main logger by calling handle directly rather
> than the individual level-based methods. I expect we should use
> isEnabledFor rather than filter, and keep the conditional ourselves:
>
>      def flush(self):
>          for record in self.buffer:
> -            self.target.handle(record)
> +            if self.target.isEnabledFor(record.level):
> +                self.target.handle(record)
>          self.buffer = []
>

s/\.level/.levelno/


-- 
Christopher Larson
kergoth at gmail dot com
Founder - BitBake, OpenEmbedded, OpenZaurus
Senior Software Engineer, Mentor Graphics
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openembedded.org/pipermail/bitbake-devel/attachments/20170328/fdcc23a0/attachment-0002.html>