An item that is often overlooked by developers is making use of proper logging in their applications. In this post I'm going to provide you with a simple logging setup you can easily incorporate into any of your existing Python applications.
2014-09-03 06:27:41,983 - root - DEBUG - Input data in descending order for file ../data/ACN.csv, reversing 2014-09-03 06:27:41,986 - root - DEBUG - Annualised Sharpe Ratio: 0.107247516502 2014-09-03 06:27:41,987 - root - DEBUG - Annualised Sharpe Ratio: -1.66352350713 2014-09-03 06:27:42,274 - root - DEBUG - Annualised Sharpe Ratio: 2.70814542564 2014-09-03 06:27:42,275 - root - DEBUG - Annualised Sharpe Ratio: -0.472650592402 2014-09-03 06:27:42,275 - root - DEBUG - Annualised Sharpe Ratio: 0.545042748417 2014-09-03 06:27:45,610 - root - INFO - Optimial result - Sharpe Ratio=2.70814542564 [lookback=12.7406798265, entry_z_score=0.79527475333, exit_z_score=-0.76807706034]
It's so simple to get up and running once you know how, and the flexibility offered by any decent logging framework far outweighs the limited learning required to use it. Print statements do have their place (occasionally), but you should be using logging in any applications that matter to you.
Just a few of the many benefits of using a proper logging framework include:
- The ability to log to the console and/or multiple files, the syslog, or even a web server, e-mail address, or remote computer!
- Fine grained control over what severity messages to send where based on the log level
- Custom formatters allowing you to include a date/timestamp, the function/module the statement is being called from
But that's enough about the benefits - to get up and running, there are then three items we need to address:
- Create a configuration file for our logger
- Write a utility function to read and load the configuration file
- Incorporate the logger into our application
We will use Python's logging library which comes as part of the standard library.
Other then Python itself, the only additional dependency we require is PyYAML, as we will use YAML to configure our logger. PyYAML can be installed via Pip:
pip install pyyaml
I have chosen to use YAML, as it keeps the config clean, but you can use JSON, XML, or any other format you can convert into a Python dictionary.
The logging library contains 5 different logging levels for our application, ranging from debug to assist with debugging behaviour as the name suggests, all the way to critical when something goes very wrong.
In our configuration file we define the locations(s) where we wish to log, the severity of messages, and the format in which to log the messages.
The following example provides logging of all messages to standard out:
version: 1 formatters: simple: format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s' handlers: console: class: logging.StreamHandler level: DEBUG formatter: simple stream: ext://sys.stdout root: level: DEBUG handlers: [console]
To log all messages to standard out and any error or critical messages to an error file (errors.log), use the following:
version: 1 formatters: simple: format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s' handlers: console: class: logging.StreamHandler level: DEBUG formatter: simple stream: ext://sys.stdout error_file: class: logging.handlers.RotatingFileHandler level: ERROR formatter: simple filename: errors.log maxBytes: 104857600 backupCount: 100 root: level: DEBUG handlers: [console, error_file]
We use the RotatingFileHandler to roll our error log file when it reaches a specific size. It's a good idea to roll your log file periodically to prevent it getting too large. Typically this means each time your application is restarted, or once per day using the TimedRotatingFileHandler.
Note that the minumum level of the root logger defines the minimum log level message that will be handled. I.e. if you specify a root level of WARN, the console will only display log messages of WARN or above.
We then write a helper module for initialising the logger. This helper module looks for an environment variable LOG_CFG to specify a configuration file location. In the absence of this, it tries to use the file location config/logging.yaml. Should this fail it creates a default logger which works much like the print statement.
INFO:root:This is using the default basicConfig...
import logging.config import os import yaml def setup(default_path='config/logging.yaml', default_level=logging.INFO, env_key='LOG_CFG'): path = default_path value = os.getenv(env_key, None) if value: path = value if os.path.exists(path): with open(path, 'rt') as f: config = yaml.load(f.read()) logging.config.dictConfig(config) else: logging.basicConfig(level=default_level)
To incorporate the logger into your application, simply import init_logger and call setup() in the first line of your main method.
import logging import init_logger if __name__ == '__main__': init_logger.setup() logging.info("Wow, that was simple...")
When you run the above, you should see the following:
2014-09-02 21:01:06,647 - root - INFO - Wow, that was simple...
From here on in, anywhere you wish to log a message, you have two choices:
1. Call the root logger
logging.debug("Log this message if debug is enabled")
2014-09-02 21:01:06,647 - root - DEBUG - Log this message if debug is enabled
2. Or, if you want the current module the message is being called from, use
log = logging.getLogger(__name__) log.error("Uh oh, somethings not right...")
2014-09-02 21:03:14,654 - __main__ - ERROR - Uh oh, something's not right
That's all there is to it. As a rule of thumb it's better to go with option 2, as you'll see details of the module. But it's up to you how you proceed.
Even if you don't wish to make use of log files, I suggest you make use of the console logger in all of the scripts/modules you write, however simple. Besides, it looks way cooler when all of your messages have timestamps and details of where they're being generated...
For a more general overview of logging in Python, I suggest you read this great post written by Victor Lin.
All code for this example is available here.