Logging Recording

logging_recording.ipynb

{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# About\n",
    "\n",
    "logging で `info` とかで出したものを文字列として取得したい!"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 1,
   "metadata": {},
   "outputs": [],
   "source": [
    "from logging import getLogger, StreamHandler, Formatter"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### 下準備\n",
    "\n",
    "* 単純な logger と stream handler (コンソールへの出力のハンドラ) を用意します。\n",
    "* 詳しくは https://docs.python.org/ja/3/howto/logging.html#logging-advanced-tutorial など参考に"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 2,
   "metadata": {},
   "outputs": [],
   "source": [
    "handler = StreamHandler()\n",
    "handler.setLevel('INFO')\n",
    "\n",
    "logger = getLogger('nyk.510')\n",
    "logger.setLevel('INFO')\n",
    "logger.addHandler(handler)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "`INFO` level が設定されているので `INFO` よりも重要度が高いものが logging として output される.\n",
    "\n",
    "> https://docs.python.org/ja/3/howto/logging.html#loggers  \n",
    "> 組み込みの深刻度の中では DEBUG が一番低く、 CRITICAL が一番高くなります。たとえば、深刻度が INFO と設定されたロガーは INFO, WARNING, ERROR, CRITICAL のメッセージしか扱わず、 DEBUG メッセージは無視します。"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 3,
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "warn\n",
      "foo\n"
     ]
    }
   ],
   "source": [
    "logger.warning('warn')\n",
    "logger.info('foo')\n",
    "\n",
    "logger.debug('debug') # debug はでないよ"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### logging をテキストとしてとる\n",
    "\n",
    "StringIO を stream にもつような handler を作成して設定する"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "metadata": {},
   "outputs": [],
   "source": [
    "import io"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 5,
   "metadata": {},
   "outputs": [],
   "source": [
    "log_capture_io = io.StringIO()\n",
    "stream_handler = StreamHandler(stream=log_capture_io)\n",
    "\n",
    "# オシャに formatting\n",
    "formatter = Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')\n",
    "stream_handler.setFormatter(formatter)\n",
    "\n",
    "stream_handler.setLevel('INFO')\n",
    "logger.addHandler(stream_handler)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 6,
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "hoge\n",
      "bar\n"
     ]
    }
   ],
   "source": [
    "logger.info('hoge')\n",
    "logger.info('bar')"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### log の取得\n",
    "\n",
    "作成した IO から `getvalue` すればOK\n",
    "\n",
    "* 通常のコンソールアウトプットは単に文字列だったが, `formatter` をリッチにしているので取得される文字列には何時 log が記録されたかなどの情報も入っている\n",
    "* コンソールの方も普通の `StreamHandler` に formatter を設定すれば時間も表示できる."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 7,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/plain": [
       "['2020-08-01 07:42:26,918 - nyk.510 - INFO - hoge',\n",
       " '2020-08-01 07:42:26,920 - nyk.510 - INFO - bar']"
      ]
     },
     "execution_count": 7,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "s = log_capture_io.getvalue()\n",
    "s.splitlines()"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### 後片付け\n",
    "\n",
    "ずっと handler が付いていると記録され続けるので、いらなくなったら消しましょう\n",
    "\n",
    "* io の close\n",
    "* handler のひも付けを logger から削除 `removeHandler`"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 8,
   "metadata": {},
   "outputs": [],
   "source": [
    "# 終わったら消しましょう\n",
    "log_capture_io.close()\n",
    "logger.removeHandler(stream_handler)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 9,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/plain": [
       "True"
      ]
     },
     "execution_count": 9,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "log_capture_io.closed"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 10,
   "metadata": {},
   "outputs": [
    {
     "ename": "ValueError",
     "evalue": "I/O operation on closed file",
     "output_type": "error",
     "traceback": [
      "\u001b[0;31m---------------------------------------------------------------------------\u001b[0m",
      "\u001b[0;31mValueError\u001b[0m                                Traceback (most recent call last)",
      "\u001b[0;32m<ipython-input-10-b5f4bf9c6e8d>\u001b[0m in \u001b[0;36m<module>\u001b[0;34m\u001b[0m\n\u001b[0;32m----> 1\u001b[0;31m \u001b[0mlog_capture_io\u001b[0m\u001b[0;34m.\u001b[0m\u001b[0mgetvalue\u001b[0m\u001b[0;34m(\u001b[0m\u001b[0;34m)\u001b[0m\u001b[0;34m\u001b[0m\u001b[0;34m\u001b[0m\u001b[0m\n\u001b[0m",
      "\u001b[0;31mValueError\u001b[0m: I/O operation on closed file"
     ]
    }
   ],
   "source": [
    "log_capture_io.getvalue()"
   ]
  }
 ],
 "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.7"
  }
 },
 "nbformat": 4,
 "nbformat_minor": 4
}