Improve the logging implementation

[krs013]

In order to help isolate bugs experienced by new users, it would help to add more verbose logging that helps track the state of the emulator. However, we should also add a more control to the logging handling and printing for performance and clutter reasons, especially if users will be running it as an installed module and not a standalone emulator. (#87)

There are three items to address for this issue:

• Make the logging level user-configurable. It would be great to do this after making the settings window/module (Create a settings window #39), but for now we probably should just add it as another keyword argument in the PyBoy constructor.
• Use the built in logging module properly (https://docs.python.org/3.7/library/logging.html). More on this below.
• Add more logging statements everywhere, so it's much more clear what's going on. Maybe up to everything that happens less that once per frame, including inputs and the like.

So the logging module has a pretty tidy setup: Each module gets its own hierarchical Logger via logging.getLogger(__name__) instead of importing a global instance. This way the format string can be modified to include the module that created the message, and different modules can be filtered out for specific debugging. For example, we could silence all messages coming from the entire botsupport module and allow messages from the cartridge module while developing new MBC support.

Also the root Logger should be owned by... either pyboy or main.py or whatever script happens to call pyboy, I'm actually not sure. I think the best case here would be for pyboy to have a setting/kwarg that could direct its handler print to the terminal and/or save to a file. Saving to a file (or nothing) should be the default, probably, and the caller (main.py or user code) can be in charge of the actual root logger that can be configured to print at the desired level. Both of these would be active, so pyboy could automatically log to a file while main.py optionally prints messages.

[Baekalfen]

That all sounds good. I agree :)

As for who to own the root-logger. If it's supposed to be the script that calls PyBoy, I would put it in our main.py file.

But I would be against logging to a file per default. Firstly I think most people wouldn't need more than just a terminal output for the logging, and secondly, we would need to handle what happens when you run multiple instances ― which we do when testing.

[krs013]

That's a good point--multiple instances would get messy. Since Python's logging runs at the module level (not instance), we'd have to make a special handler that prepends an instance name or something if that's going to be supported.

I'm fine with not logging to a file by default. Should we still include the option to log to a file if we pass the file to pyboy, or only handle that at the root main.py level?

[Baekalfen]

I would just leave it out. Either the user can pipe stdout to a file through tee, or the user can easily add that modification to the logging handler, if needed (I assume).

[Baekalfen]

I've added the first two points in the new plugin_refactor branch. For the last one, I agree that we could have some more logging, but it's hard to add a meaningful amount of logging beforehand, without just adding random statements.

I'll close the issue for now, but I will encourage everyone to add logging if they are trying to trace out a bug in the code. If it makes sense to keep it, we'll keep it.