[BUG] AutoGluon ignores logging configuration about autogluon HOT 3 OPEN

My assumption is that you

• add the log handler to the autogluon logger to ensure that users receive output even IF they have not configured logging
• set propagate = False to avoid duplicate logs IF they have configured logging.

To gracefully handle both cases, I would suggest to add a handler to the autogluon logger which will produce output only if the root logger is not associated with any handlers, i.e. to use a handler like this one I've added to sensAI:

class FallbackHandler(logging.Handler):
    """
    A log handler which applies the given handler only if the root logger has no defined handlers 
    (or has no handlers other than this fallback handler itself)
    """
    def __init__(self, handler: logging.Handler, level=logging.NOTSET):
        """
        :param handler: the handler to which messages shall be passed on
        :param level: the minimum level to output; if NOTSET, pass on everything
        """
        super().__init__(level=level)
        self._handler = handler

    def emit(self, record):
        root_handlers = logging.getLogger().handlers
        if len(root_handlers) == 0 or (len(root_handlers) == 1 and root_handlers[0] == self):
            self._handler.emit(record)

With this type of handler, you can do this:

    ag_logger = logging.getLogger("autogluon")
    ag_logger.setLevel(logging.INFO)

    ag_logger.addHandler(FallbackHandler(logging.StreamHandler(sys.stderr)))
    ag_logger.info("Foo")

    logging.basicConfig(level=logging.INFO, stream=sys.stdout)

    logging.getLogger("foo").info("I am some other logger")
    ag_logger.info("Bar")

and you will get

i.e. as long as no root log handler is configured, the autogluon logger will print to stderr (as indicated by the red output colour), and after logging has been configured by the user, the logs will end up wherever it was configured instead (stdout with a different format in this case).

I don't really think a test is needed, as once this is handled properly, it's unlikely to break, but a simple test you could add is this:

def test_root_logger_receives_autogluon_logs():
    import autogluon
    root_logger = logging.getLogger()
    stream = io.StringIO()
    stream_handler = logging.StreamHandler(stream=stream)
    root_logger.addHandler(stream_handler)
    try:
        ag_logger = logging.getLogger("autogluon")
        ag_logger.setLevel(logging.INFO)
        ag_logger.info("Foobar")
        assert "Foobar" in stream.getvalue()
    finally:
        root_logger.removeHandler(stream_handler)

It will currently fail, but it will pass if you apply the function _fix_autogluon_logging I had pasted above.

I can issue a PR if you like, but I really don't know what you were trying to achieve wrt the kaggle case.

from autogluon.

Thanks for this issue @opcode81!

Indeed logging is a bit odd in AutoGluon (and previously it was even odder). I remember that we chose the current method because of the ways in which other packages sometimes altered logging functionality, which would then also alter AutoGluon's logging in unexpected ways and thus we got GitHub issues from users that were the inverse of yours. Therefore, we isolated the logging logic to be harder to accidentally override in other packages as they are imported. (One of the big ones is Kaggle, which previously hid all AutoGluon logs due to how it altered the logger).

This definitely has side effects, such as what you encountered, and we are interested in making things work with less friction.

I'd be interested in a small code snippet that includes your user-defined logging configuration followed by an import of AutoGluon and calling logger or fitting TabularPredictor so we can use that for testing.

from autogluon.

Awesome write-up, this is very helpful @opcode81! We will look into addressing this for the next minor release (v1.2).

from autogluon.