cwpk-54-statistics-logging.ipynb

{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "CWPK \\#54: Statistics and Logging\n",
    "=======================================\n",
    "\n",
    "These are Two Recommended Utilities\n",
    "--------------------------\n",
    "\n",
    "<div style=\"float: left; width: 305px; margin-right: 10px;\">\n",
    "\n",
    "<img src=\"http://kbpedia.org/cwpk-files/cooking-with-kbpedia-305.png\" title=\"Cooking with KBpedia\" width=\"305\" />\n",
    "\n",
    "</div>\n",
    "\n",
    "This installment in our [*Cooking with Python and KBpedia*](https://www.mkbergman.com/cooking-with-python-and-kbpedia/) series covers two useful (essential?) utilities for any substantial project: <code>stats</code> and <code>logging</code>. <code>stats</code> refers to internal program or knowledge graph metrics, not a generalized statistical analysis package. <code>logging</code> is a longstanding Python module that provides persistence and superior control over using simple <code>print</code> statements for program tracing and debugging.\n",
    "\n",
    "On the stats side, we will emphasize capturing metrics not already available when using [Protégé](https://en.wikipedia.org/wiki/Prot%C3%A9g%C3%A9_(software)), which provides its own set of useful baseline statistics. (See *Figure 1*.) These metrics are mostly simple counts, with some sums and averages. The results of these metrics are some of the numerical data points that we will use in the next installment on charting.\n",
    "\n",
    "On the logging front, we will edit all of our existing routines to log to file, as well as print to screen. We can embed these routines in existing functions so that we may better track our efforts."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### An Internal Stats Module\n",
    "In our earlier extract-and-build routines we have already put in place the basic file and set processing steps necessary to capture additional metrics. We will add to these here, in the process creating an internal <code>stats</code> module in our *cowpoke* package.\n",
    "\n",
    "First, there is no need to duplicate the information that already comes to us when using Protégé. Here are the standard stats provided on the main start-up screen:\n",
    "\n",
    "<div class=\"center-image\">\n",
    "\n",
    "<img src=\"files/protege-stats.png\" title=\"Protégé Internal Stats\" height=\"800\" alt=\"Protégé Internal Stats\" />\n",
    "\n",
    "</div>\n",
    "\n",
    "<div class=\"center-caption\">\n",
    "\n",
    "Figure 1: Protégé Internal Stats\n",
    "\n",
    "</div>\n",
    "\n",
    "We are loading up here **(1)** our KBpedia v 300 in-progress. We can see that Protégé gives us counts **(2)** of classes (58200), object properties (1316), data properties (802), annotation properties (2919), and a few other metrics.\n",
    "\n",
    "We will take these values as givens, and will enter them as part of the initialization for our own internal procedures (for checking totals and calculating percentages).\n",
    "\n",
    "[Pyflakes](https://github.com/PyCQA/pyflakes) is a simple Python code checker that you may want to consider. If you want to add in stylistic checks, you want [flake8](https://pypi.org/project/flake8/), which combines Pyflakes with style checks against [PEP 8](https://github.com/PyCQA/pep8-naming) or [pycodestyle](https://github.com/PyCQA/pycodestyle). [Pylint](https://github.com/PyCQA/pylint/) is another static code style checker."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 1,
   "metadata": {},
   "outputs": [],
   "source": [
    "from cowpoke.__main__ import *\n",
    "from cowpoke.config import *"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "### KEY CONFIG SETTINGS (see build_deck in config.py) ###                \n",
    "# 'kb_src'        : 'standard'\n",
    "# count           : 14                                                    # Note 1\n",
    "# out_file        : 'C:/1-PythonProjects/kbpedia/v300/targets/stats/kko_typol_stats.csv'\n",
    "\n",
    "from itertools import combinations                                       # Note 2\n",
    "\n",
    "def typol_stats(**build_deck):\n",
    "    kko_list = typol_dict.values()\n",
    "    count = build_deck.get('count')\n",
    "    out_file = build_deck.get('out_file')\n",
    "    with open(out_file, 'w', encoding='utf8') as output:\n",
    "        print('count,size_1,kko_1,size_2,kko_2,intersect RCs', file=output)\n",
    "        for i in combinations(kko_list,2):                              \n",
    "            kko_1 = i[0]                                              \n",
    "            kko_2 = i[1]                                              \n",
    "            kko_1_frag = kko_1.replace('kko.', '')\n",
    "            kko_1 = getattr(kko, kko_1_frag)\n",
    "            print(kko_1_frag)\n",
    "            kko_2_frag = kko_2.replace('kko.', '')\n",
    "            kko_2 = getattr(kko, kko_2_frag)     \n",
    "            descent_1 = kko_1.descendants(include_self = False)       \n",
    "            descent_1 = set(descent_1)\n",
    "            size_1 = len(descent_1)\n",
    "            descent_2 = kko_2.descendants(include_self = False)\n",
    "            descent_2 = set(descent_2)\n",
    "            size_2 = len(descent_2)\n",
    "            intersect = descent_1.intersection(descent_2)              \n",
    "            num = len(intersect)\n",
    "            if num <= count:                                           \n",
    "                print(num, size_1, kko_1, size_2, kko_2, intersect, sep=',', file=output)\n",
    "            else: \n",
    "                print(num, size_1, kko_1, size_2, kko_2, sep=',', file=output)\n",
    "    print('KKO typology intersection analysis is done.')"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "typol_stats(**build_deck)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "The procedure above takes a few minutes to run. You can inspect what the routine produces at <code>C:/1-PythonProjects/kbpedia/v300/targets/stats/kko_typol_stats.csv</code>.\n",
    "\n",
    "We can also get summary statistics from the knowledge graph using the <code>rdflib</code> package. Here is a modification of one of the library's routine to obtain some [VoID](https://en.wikipedia.org/wiki/VoID) statistics:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 2,
   "metadata": {},
   "outputs": [],
   "source": [
    "import collections\n",
    "\n",
    "from rdflib import URIRef, Graph, Literal\n",
    "from rdflib.namespace import VOID, RDF\n",
    "\n",
    "graph = world.as_rdflib_graph()\n",
    "g = graph\n",
    "\n",
    "def generate2VoID(g, dataset=None, res=None, distinctForPartitions=True):\n",
    "    \"\"\"\n",
    "    Returns a VoID description of the passed dataset\n",
    "\n",
    "    For more info on Vocabulary of Interlinked Datasets (VoID), see:\n",
    "    http://vocab.deri.ie/void\n",
    "\n",
    "    This only makes two passes through the triples (once to detect the types\n",
    "    of things)\n",
    "\n",
    "    The tradeoff is that lots of temporary structures are built up in memory\n",
    "    meaning lots of memory may be consumed :)\n",
    "    \n",
    "    distinctSubjects/objects are tracked for each class/propertyPartition\n",
    "    this requires more memory again\n",
    "\n",
    "    \"\"\"\n",
    "\n",
    "    typeMap = collections.defaultdict(set)\n",
    "    classes = collections.defaultdict(set)\n",
    "    for e, c in g.subject_objects(RDF.type):\n",
    "        classes[c].add(e)\n",
    "        typeMap[e].add(c)\n",
    "\n",
    "    triples = 0\n",
    "    subjects = set()\n",
    "    objects = set()\n",
    "    properties = set()\n",
    "    classCount = collections.defaultdict(int)\n",
    "    propCount = collections.defaultdict(int)\n",
    "\n",
    "    classProps = collections.defaultdict(set)\n",
    "    classObjects = collections.defaultdict(set)\n",
    "    propSubjects = collections.defaultdict(set)\n",
    "    propObjects = collections.defaultdict(set)\n",
    "    num_classObjects = 0\n",
    "    num_propSubjects = 0\n",
    "    num_propObjects = 0\n",
    "    \n",
    "    for s, p, o in g:\n",
    "\n",
    "        triples += 1\n",
    "        subjects.add(s)\n",
    "        properties.add(p)\n",
    "        objects.add(o)\n",
    "\n",
    "        # class partitions\n",
    "        if s in typeMap:\n",
    "            for c in typeMap[s]:\n",
    "                classCount[c] += 1\n",
    "                if distinctForPartitions:\n",
    "                    classObjects[c].add(o)\n",
    "                    classProps[c].add(p)\n",
    "\n",
    "        # property partitions\n",
    "        propCount[p] += 1\n",
    "        if distinctForPartitions:\n",
    "            propObjects[p].add(o)\n",
    "            propSubjects[p].add(s)\n",
    "\n",
    "    if not dataset:\n",
    "        dataset = URIRef('http://kbpedia.org/kko/rc/')\n",
    "\n",
    "    if not res:\n",
    "        res = Graph()\n",
    "\n",
    "    res.add((dataset, RDF.type, VOID.Dataset))\n",
    "\n",
    "    # basic stats\n",
    "    res.add((dataset, VOID.triples, Literal(triples)))\n",
    "    res.add((dataset, VOID.classes, Literal(len(classes))))\n",
    "\n",
    "    res.add((dataset, VOID.distinctObjects, Literal(len(objects))))\n",
    "    res.add((dataset, VOID.distinctSubjects, Literal(len(subjects))))\n",
    "    res.add((dataset, VOID.properties, Literal(len(properties))))\n",
    "\n",
    "    for i, c in enumerate(classes):\n",
    "        part = URIRef(dataset + \"_class%d\" % i)\n",
    "        res.add((dataset, VOID.classPartition, part))\n",
    "        res.add((part, RDF.type, VOID.Dataset))\n",
    "\n",
    "        res.add((part, VOID.triples, Literal(classCount[c])))\n",
    "        res.add((part, VOID.classes, Literal(1)))\n",
    "\n",
    "        res.add((part, VOID[\"class\"], c))\n",
    "\n",
    "        res.add((part, VOID.entities, Literal(len(classes[c]))))\n",
    "        res.add((part, VOID.distinctSubjects, Literal(len(classes[c]))))\n",
    "\n",
    "        if distinctForPartitions:\n",
    "            res.add(\n",
    "                (part, VOID.properties, Literal(len(classProps[c]))))\n",
    "            res.add((part, VOID.distinctObjects,\n",
    "                     Literal(len(classObjects[c]))))\n",
    "            num_classObjects = num_classObjects + len(classObjects[c])           \n",
    "            \n",
    "\n",
    "    for i, p in enumerate(properties):\n",
    "        part = URIRef(dataset + \"_property%d\" % i)\n",
    "        res.add((dataset, VOID.propertyPartition, part))\n",
    "        res.add((part, RDF.type, VOID.Dataset))\n",
    "\n",
    "        res.add((part, VOID.triples, Literal(propCount[p])))\n",
    "        res.add((part, VOID.properties, Literal(1)))\n",
    "\n",
    "        res.add((part, VOID.property, p))\n",
    "\n",
    "        if distinctForPartitions:\n",
    "\n",
    "            entities = 0\n",
    "            propClasses = set()\n",
    "            for s in propSubjects[p]:\n",
    "                if s in typeMap:\n",
    "                    entities += 1\n",
    "                for c in typeMap[s]:\n",
    "                    propClasses.add(c)\n",
    "\n",
    "            res.add((part, VOID.entities, Literal(entities)))\n",
    "            res.add((part, VOID.classes, Literal(len(propClasses))))\n",
    "\n",
    "            res.add((part, VOID.distinctSubjects,\n",
    "                     Literal(len(propSubjects[p]))))\n",
    "            res.add((part, VOID.distinctObjects,\n",
    "                     Literal(len(propObjects[p]))))\n",
    "            num_propSubjects = num_propSubjects + len(propSubjects[p])\n",
    "            num_propObjects = num_propObjects + len(propObjects[p]) \n",
    "    print('triples:', triples)\n",
    "    print('subjects:', len(subjects))\n",
    "    print('objects:', len(objects))\n",
    "    print('classObjects:', num_classObjects)\n",
    "    print('propObjects:', num_propObjects)      \n",
    "    print('propSubjects:', num_propSubjects)\n",
    "     \n",
    "\n",
    "    return res, dataset"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 3,
   "metadata": {},
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "triples: 1662129\n",
      "subjects: 213395\n",
      "objects: 698372\n",
      "classObjects: 850446\n",
      "propObjects: 858445\n",
      "propSubjects: 1268005\n"
     ]
    },
    {
     "data": {
      "text/plain": [
       "(<Graph identifier=Na47c69e2f7b84d9b911c46e2cdf0fe11 (<class 'rdflib.graph.Graph'>)>,\n",
       " rdflib.term.URIRef('http://kbpedia.org/kko/rc/'))"
      ]
     },
     "execution_count": 3,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "generate2VoID(g, dataset=None, res=None, distinctForPartitions=True)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "These metrics can go into the pot with the summary statistics we also gain from Protégé. We'll see some graphic reports on these numbers in the next installment."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### Logging\n",
    "I think an honest appraisal may straddle the fence about whether logging makes sense for the *cowpoke* package. On the one hand, we have begun to assemble a fair degree of code within the package, that perhaps would normally trigger the advisability of logging. On the other hand, we run the various scripts only sporadically, and in pieces when we do. There is not a continuous production function under what we have done, so far.\n",
    "\n",
    "If we were to introduce this code into a production setting or get multiple developers involved, I would definitely argue for the need for logging. Consider what we have in the current *cowpoke* code base as the transition condition for looking at this question. However, since logging is good practice, and we are close, let's go ahead and invoke the capability nonetheless.\n",
    "\n",
    "One chooses logging over the initial <code>print</code> statements because we gain these benefits:\n",
    "\n",
    "1. The ability to time stamp our logging messages\n",
    "2. The ability to keep our logging messages persistent\n",
    "3. We can generate messages constantly in the background for later inspection, and\n",
    "4. We can better organize our logging messages.\n",
    "\n",
    "The <code>logging</code> module that comes with Python is quite mature and has further advantages:\n",
    "\n",
    "1. We can control the warning level of the messages and what warning levels trigger logging\n",
    "2. We can format the messages as we wish, and\n",
    "3. We can send our messages to file, screen, or socket.\n",
    "\n",
    "By default, the Python <code>logging</code> module has five pre-set warning levels:\n",
    "\n",
    "- *debug* - detailed information, typically of interest only when diagnosing problems\n",
    "- *info* - confirmation that things are working as expected\n",
    "- *warning* - an indication that something unexpected happened, or indicative of some problem in the near future (e.g. ‘disk space low’). The software is still working as expected\n",
    "- *error* - due to a more serious problem, the software has not been able to perform some function, or\n",
    "- *critical* - a serious error, indicating that the program itself may be unable to continue running.\n",
    "\n",
    "We'll see in the following steps how we can configure the logger and set it up for working with our existing functions."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "#### Configuration\n",
    "Logging is organized as a tree, with the root being the system level. For a single package, it is best to set up a separate main logging branch under the root so that warnings and loggings can be treated consistently throughout the package. This design, for example, allows warning messages and logging levels to be set with a single call across the entire package (sub-branches may have their own conditions). This is what is called adding a 'custom' logger to your system. \n",
    "\n",
    "Configurations may be set in Python code (the method we will use, because it is the simplest) or via a separate <code>.ini</code> file. Configuration settings include most of the specified items below.\n",
    "\n",
    "##### Handlers\n",
    "You can set up logging messages to go to console (screen) or file. In our examples below, we will do both.\n",
    "\n",
    "##### Formatters\n",
    "You can set up how your messages are formatted. We can also format console v file messages differently, as our examples below show.\n",
    "\n",
    "##### Default Messages\n",
    "Whenever we insert a logging message, beside setting severity level, we may also assign a message unique to that part of the code. However, if we choose not to assign a new, specific message, the message invoked will be the default one defined in our configuration."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "#### Example Code\n",
    "Since our set up is straightforward, we will put our configuration settings into our existing <code>config.py</code> file and write our logging messages to the <code>log</code> subdirectory. Here is how our set up looks (with some in-line commentary):"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "WARNING:root:Warning! Something does not look right.\n",
      "ERROR:root:You have encountered an error.\n",
      "CRITICAL:root:You have experienced a critical problem.\n"
     ]
    }
   ],
   "source": [
    "import logging\n",
    "\n",
    "# Create a custom logger\n",
    "logger = logging.getLogger(__name__)                # Will invoke name of current module\n",
    "\n",
    "# Create handlers\n",
    "log_file = 'C:/1-PythonProjects/kbpedia/v300/targets/logs/kbpedia_logging.log'\n",
    "#logging.basicConfig(filename=log_file,level=logging.DEBUG)\n",
    "c_handler = logging.StreamHandler()                 # Separate c_ and f_ handlers\n",
    "f_handler = logging.FileHandler(log_file)\n",
    "c_handler.setLevel(logging.WARNING)\n",
    "f_handler.setLevel(logging.DEBUG)\n",
    "\n",
    "# Create formatters and add it to handlers          # File logs include time stamp, console does not\n",
    "c_format = logging.Formatter('%(name)s - %(levelname)s - %(message)s')\n",
    "f_format = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')\n",
    "c_handler.setFormatter(c_format)\n",
    "f_handler.setFormatter(f_format)\n",
    "\n",
    "# Add handlers to the logger\n",
    "logger.addHandler(c_handler)\n",
    "logger.addHandler(f_handler)\n",
    "\n",
    "logging.debug('This is a debug message.')\n",
    "logging.info('This is an informational message.')\n",
    "logging.warning('Warning! Something does not look right.')\n",
    "logging.error('You have encountered an error.')\n",
    "logging.critical('You have experienced a critical problem.')"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Make sure you have this statement at the top of all of your *cowpoke* files:\n",
    "\n",
    "<pre>\n",
    "  import logging\n",
    "</pre>\n",
    "\n",
    "Then, as you write or update your routines, use the <code>logging.severity()</code> statement where you previously were using <code>print</code>. This will cause you to get messages to both console and file, at the severity threshold level set. It is that easy!"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### Additional Documentation\n",
    "Here is some supporting documentation for today's installment:\n",
    "\n",
    "- [VoID documentation](https://rdflib.readthedocs.io/en/stable/_modules/rdflib/void.html) from <code>rdflib</code>\n",
    "- A nice [step-by-step logging guide](https://www.pylenin.com/blogs/python-logging-guide/)\n",
    "- ['How to' manual](https://docs.python.org/3/howto/logging.html) for the Python [<code>logging facility</code> module](https://docs.python.org/3/library/logging.html)\n",
    "- RealPython's [intro guide to the <code>logger</code>](https://realpython.com/python-logging/)\n",
    "- [Configuraton guide](https://docs.python-guide.org/writing/logging/) for the <code>logger</code> from *The Hitchhiker's Guide to Python*\n",
    "\n",
    "\n",
    " <div style=\"background-color:#ffecec; border:1px dotted #f5aca6; vertical-align:middle; margin:15px 60px; padding:8px;\"> \n",
    "  <span style=\"font-weight: bold;\">NOTE:</span> This article is part of the <a href=\"https://www.mkbergman.com/cooking-with-python-and-kbpedia/\" style=\"font-style: italic;\">Cooking with Python and KBpedia</a> series. See the <a href=\"https://www.mkbergman.com/cooking-with-python-and-kbpedia/\"><strong>CWPK</strong> listing</a> for other articles in the series. <a href=\"http://kbpedia.org/\">KBpedia</a> has its own Web site. The <em>cowpoke</em> Python <a href=\"https://github.com/Cognonto/cowpoke\">code listing covering the series</a> is also available from GitHub.\n",
    "  </div>\n",
    "\n",
    "<div style=\"background-color:#ebf8e2; border:1px dotted #71c837; vertical-align:middle; margin:15px 60px; padding:8px;\"> \n",
    "\n",
    "<span style=\"font-weight: bold;\">NOTE:</span> This <strong>CWPK \n",
    "installment</strong> is available both as an online interactive\n",
    "file <a href=\"https://mybinder.org/v2/gh/Cognonto/CWPK/master\" ><img src=\"https://mybinder.org/badge_logo.svg\" style=\"display:inline-block; vertical-align: middle;\" /></a> or as a <a href=\"https://github.com/Cognonto/CWPK\" title=\"CWPK notebook\" alt=\"CWPK notebook\">direct download</a> to use locally. Make sure and pick the correct installment number. For the online interactive option, pick the <code>*.ipynb</code> file. It may take a bit of time for the interactive option to load.</div>\n",
    "\n",
    "<div style=\"background-color:#feeedc; border:1px dotted #f7941d; vertical-align:middle; margin:15px 60px; padding:8px;\"> \n",
    "<div style=\"float: left; margin-right: 5px;\"><img src=\"http://kbpedia.org/cwpk-files/warning.png\" title=\"Caution!\" width=\"32\" /></div>I am at best an amateur with Python. There are likely more efficient methods for coding these steps than what I provide. I encourage you to experiment -- which is part of the fun of Python -- and to <a href=\"mailto:mike@mkbergman.com\">notify me</a> should you make improvements.    \n",
    "\n",
    "</div>"
   ]
  }
 ],
 "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.8"
  }
 },
 "nbformat": 4,
 "nbformat_minor": 5
}