hsahovic / poke-env

A python interface for training Reinforcement Learning bots to battle on pokemon showdown
https://poke-env.readthedocs.io/
MIT License
297 stars 103 forks source link

Remove log handler from PSClient #470

Open SirSkaro opened 11 months ago

SirSkaro commented 11 months ago

I'm creating an application where I register my own handler for root. However, I noticed that PSClient registers its own handler with a logger by the name of the logged-in user. Because the way the logging hierarchy works, the PSClient's log messages (and thus the Player's log messages) are getting logged twice. As a result, I'm having to manually remove the handler when I create the Player object.

logging.getLogger(player.username).handlers.clear()

It's my understanding that it's best practice to not have distributed packages declare their own handlers (or at least check if they are main before doing so). In my opinion, I think it would be best to either remove the handler or at least check that there aren't any other handlers registered at the root.

I'm admittedly not the most well-versed with logging in Python (most of my work in it has been academic), so please let me know if there is a better way to silence these duplicate log messages.

hsahovic commented 11 months ago

Hi @SirSkaro, Thanks for opening this issue. You are right - this doesn't follow best practices. I'll add this to the list of improvements I'd like to implement. How much of a pain point is the workaround you are currently using? Best, Haris

SirSkaro commented 11 months ago

Hi @SirSkaro, Thanks for opening this issue. You are right - this doesn't follow best practices. I'll add this to the list of improvements I'd like to implement. How much of a pain point is the workaround you are currently using? Best, Haris

Thank you!

I think the pain point of the workaround really depends on how the agent is constructed and how you want to unregister the handler. If you're just constructing a Player object directly, you'll have to

And you'd need to do this for every Player object you instantiate. It's not the worst thing in the world, but it's certainly not ideal.

My workaround is a little more painful. I'm using the Dependency Injector library to setup an IoC container for dependency injection. The first thing my __main__ does is set up the container, which sets up the root logger handler. The library lazily provides dependencies - only creating them when they are requested even if they are a singleton instance. In my case I'm registering my Player instance in the IoC container. So I either have to have precise bookkeeping and unregister the handler when the first dependency asks for my Player object(s) or I have to create a custom provider to unregister the handler when the Player when it instantiates it. I just started the project so I'm just doing the simple thing now of manually unregistering the handler after asking for the Player in __main__, but I anticipate needing the custom provider soon. If you're curious what the simple fix looks like in my scenario, you can check out the repo.

SirSkaro commented 7 months ago

One thing I did that you may be interested in is that I created a configurable filter to not log specified Showdown events. You pass in a comma-separated list of events to the filter, add the filter to the Player logger, and you're good to go. This could potentially help with debugging.

class ShowdownEventFilter(logging.Filter):
    def __init__(self, events_to_ignore: List[str] = []):
        super().__init__()
        regex = '|'.join(events_to_ignore)
        self._record_regex = re.compile(f'\\|{regex}\\|')

    def filter(self, record: logging.LogRecord) -> bool:
        if record.levelno >= logging.WARN:
            return True

        log_message = record.getMessage()
        return self._record_regex.search(log_message) is None

Then

player = Player(...)
log_ignore = get_ignore_list_from_configs()  # e.g., ['request', 'updatesearch']
player.logger.addFilter(ShowdownEventFilter(log_ignore))