{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Logging in Python\n",
    "Python has a very powerful [logging system](https://docs.python.org/3.7/library/logging.html). Adding logging to a Python program is as simple as:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 1,
   "metadata": {},
   "outputs": [],
   "source": [
    "import logging \n",
    "logger = logging.getLogger('__name__')\n",
    "def function_that_logs(x, y):\n",
    "    logger.info(f\"I was called with x={x}, y={y}\")"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "However, calling `function_that_logs` won't print the logged message anywhere yet:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "metadata": {},
   "outputs": [],
   "source": [
    "function_that_logs(12, 13)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "This is because unless explicitly enabled, python ignores logging calls. Otherwise calling codes would be inundated with logging messages from various libraries. \n",
    "There are a few steps to do before our logged message gets anywhere. "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 5,
   "metadata": {},
   "outputs": [],
   "source": [
    "# Set the logger level. Anything logged with level lower than DEBUG will be ignored. \n",
    "logger.setLevel(logging.DEBUG)\n",
    "# Now add a handler to our logger. StreamHandler prints to stderr\n",
    "handler = logging.StreamHandler()\n",
    "# Now the handler's level must be set too.\n",
    "handler.setLevel(logging.DEBUG)\n",
    "# Add the handler to the logger\n",
    "logger.addHandler(handler)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 7,
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "I was called with x=12, y=13\n"
     ]
    }
   ],
   "source": [
    "function_that_logs(12, 13)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Finally, our logged message appears. A `logger` can have multiple `handler`s in Python: `logging` module contains many kinds of [handlers](https://docs.python.org/3.7/library/logging.handlers.html#module-logging.handlers), e.g. `HTTPHandler` (sends logs to a web server), `SMTPHandler` (sends the log via email) etc."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Custom formatters\n",
    "We might sometimes want some additional information to be logged alongwith the message, for example the time the log was created. This can be achieved by setting the `formatter` of our log handler:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 31,
   "metadata": {},
   "outputs": [],
   "source": [
    "formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(funcName)s - %(message)s')\n",
    "handler.setFormatter(formatter)\n",
    "logger.handlers = []\n",
    "logger.addHandler(handler)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Where do the properties like `asctime` or `funcName` come from? They are all attributes of the [Logrecord](https://docs.python.org/3.7/library/logging.html#logrecord-attributes) objects. On each logging call, such a `LogRecord` object is created, and they contain a lot of information including the calling code's  module name, filepath, line number etc. "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 12,
   "metadata": {},
   "outputs": [],
   "source": [
    "class CustomFormatter(logging.Formatter):\n",
    "    def format(self, record):\n",
    "        return \"Hello\""
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 13,
   "metadata": {},
   "outputs": [],
   "source": [
    "logger.setLevel(logging.DEBUG)\n",
    "handler = logging.StreamHandler()\n",
    "handler.setLevel(logging.DEBUG)\n",
    "formatter = CustomFormatter()\n",
    "handler.setFormatter(formatter)\n",
    "logger.addHandler(handler)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 14,
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "I was called with x=12, y=13\n",
      "Hello\n"
     ]
    }
   ],
   "source": [
    "function_that_logs(12, 13)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": []
  }
 ],
 "metadata": {
  "kernelspec": {
   "display_name": "Python 3",
   "language": "python",
   "name": "python3"
  },
  "language_info": {
   "codemirror_mode": {
    "name": "ipython",
    "version": 3
   },
   "file_extension": ".py",
   "mimetype": "text/x-python",
   "name": "python",
   "nbconvert_exporter": "python",
   "pygments_lexer": "ipython3",
   "version": "3.7.3"
  },
  "latex_envs": {
   "bibliofile": "biblio.bib",
   "cite_by": "apalike",
   "current_citInitial": 1,
   "eqLabelWithNumbers": true,
   "eqNumInitial": 0
  },
  "nav_menu": {},
  "nikola": {
   "category": "",
   "date": "2019-09-30 21:05:53 UTC+02:00",
   "description": "",
   "link": "",
   "slug": "logging-in-python",
   "tags": "",
   "title": "Logging in Python",
   "type": "text"
  },
  "toc": {
   "navigate_menu": true,
   "number_sections": true,
   "sideBar": true,
   "threshold": 6,
   "toc_cell": false,
   "toc_section_display": "block",
   "toc_window_display": false
  }
 },
 "nbformat": 4,
 "nbformat_minor": 2
}