examples/notebooks/HandlersTimeProfiler_MNIST.ipynb

{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Profiling MNIST example with 3-conv. layer network\n",
    "\n",
    "This example demonstrates the usage of `HandlersTimeProfiler`. The example uses MNIST dataset."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Install requirements"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {
    "scrolled": true
   },
   "outputs": [],
   "source": [
    "!pip install --upgrade --pre pytorch-ignite"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Imports"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 1,
   "metadata": {
    "pycharm": {
     "is_executing": false
    }
   },
   "outputs": [
    {
     "data": {
      "text/html": [
       "<style>pre { white-space: pre !important; }</style>"
      ],
      "text/plain": [
       "<IPython.core.display.HTML object>"
      ]
     },
     "metadata": {},
     "output_type": "display_data"
    }
   ],
   "source": [
    "%matplotlib inline\n",
    "\n",
    "import torch\n",
    "import torch.nn as nn\n",
    "import torch.nn.functional as F\n",
    "import torch.optim as optim\n",
    "import torchvision.transforms as transforms\n",
    "from torch.utils.data import DataLoader\n",
    "from torchvision.datasets import MNIST\n",
    "\n",
    "# A hack to fix the horizontal spill in large output\n",
    "# ref: https://stackoverflow.com/a/59058418/6574605\n",
    "from IPython.core.display import HTML\n",
    "display(HTML(\"<style>pre { white-space: pre !important; }</style>\"))"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Loading MNIST"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 2,
   "metadata": {},
   "outputs": [],
   "source": [
    "mnist_pwd = \"data\"\n",
    "batch_size= 256"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 3,
   "metadata": {},
   "outputs": [],
   "source": [
    "transform = transforms.Compose([transforms.ToTensor(), transforms.Normalize((0.1307,), (0.3081,))])\n",
    "\n",
    "trainset = MNIST(mnist_pwd, train=True, download=True, transform=transform)\n",
    "trainloader = DataLoader(trainset, batch_size=batch_size, shuffle=True, num_workers=4)\n",
    "\n",
    "testset = MNIST(mnist_pwd, train=False, download=True, transform=transform)\n",
    "testloader = DataLoader(testset, batch_size=batch_size * 2, shuffle=False, num_workers=0)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Model"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "metadata": {
    "scrolled": true
   },
   "outputs": [],
   "source": [
    "class Net(nn.Module):\n",
    "    def __init__(self):\n",
    "        super(Net, self).__init__()\n",
    "        self.conv1 = nn.Conv2d(1, 10, kernel_size=5)\n",
    "        self.conv2 = nn.Conv2d(10, 20, kernel_size=5)\n",
    "        self.conv2_drop = nn.Dropout2d()\n",
    "        self.fc1 = nn.Linear(320, 50)\n",
    "        self.fc2 = nn.Linear(50, 10)\n",
    "\n",
    "    def forward(self, x):\n",
    "        x = F.relu(F.max_pool2d(self.conv1(x), 2))\n",
    "        x = F.relu(F.max_pool2d(self.conv2_drop(self.conv2(x)), 2))\n",
    "        x = x.view(-1, 320)\n",
    "        x = F.relu(self.fc1(x))\n",
    "        x = F.dropout(x, training=self.training)\n",
    "        x = self.fc2(x)\n",
    "        return F.log_softmax(x, dim=1)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 5,
   "metadata": {},
   "outputs": [],
   "source": [
    "from ignite.engine import Events, create_supervised_trainer, create_supervised_evaluator\n",
    "from ignite.metrics import Loss, Accuracy\n",
    "from ignite.contrib.handlers import ProgressBar, HandlersTimeProfiler"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Training Loss"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 6,
   "metadata": {},
   "outputs": [],
   "source": [
    "device = \"cuda\" if torch.cuda.is_available() else \"cpu\"\n",
    "criterion = nn.NLLLoss()\n",
    "model = Net()\n",
    "model.to(device)  # Move model before creating optimizer\n",
    "optimizer = optim.SGD(model.parameters(), lr=3e-4, momentum=0.9)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 7,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "application/vnd.jupyter.widget-view+json": {
       "model_id": "a65e4cdac5114ccfba39eee1a1a4d1e2",
       "version_major": 2,
       "version_minor": 0
      },
      "text/plain": [
       "HBox(children=(FloatProgress(value=0.0, max=235.0), HTML(value='')))"
      ]
     },
     "metadata": {},
     "output_type": "display_data"
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "\n",
      "Validation Results - Epoch: 1  Avg accuracy: 0.17 Avg loss: 2.27\n"
     ]
    },
    {
     "data": {
      "application/vnd.jupyter.widget-view+json": {
       "model_id": "dad2c328fb534056b11574d4657c6e3d",
       "version_major": 2,
       "version_minor": 0
      },
      "text/plain": [
       "HBox(children=(FloatProgress(value=0.0, max=235.0), HTML(value='')))"
      ]
     },
     "metadata": {},
     "output_type": "display_data"
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "\n",
      "Validation Results - Epoch: 2  Avg accuracy: 0.36 Avg loss: 2.19\n"
     ]
    },
    {
     "data": {
      "application/vnd.jupyter.widget-view+json": {
       "model_id": "813ed0d687734b7f9b9b8f3de4618b5f",
       "version_major": 2,
       "version_minor": 0
      },
      "text/plain": [
       "HBox(children=(FloatProgress(value=0.0, max=235.0), HTML(value='')))"
      ]
     },
     "metadata": {},
     "output_type": "display_data"
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "\n",
      "Validation Results - Epoch: 3  Avg accuracy: 0.65 Avg loss: 1.97\n"
     ]
    },
    {
     "data": {
      "application/vnd.jupyter.widget-view+json": {
       "model_id": "95c7683596904c3fa33f0f75fe193b18",
       "version_major": 2,
       "version_minor": 0
      },
      "text/plain": [
       "HBox(children=(FloatProgress(value=0.0, max=235.0), HTML(value='')))"
      ]
     },
     "metadata": {},
     "output_type": "display_data"
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "\n",
      "Validation Results - Epoch: 4  Avg accuracy: 0.75 Avg loss: 1.44\n"
     ]
    },
    {
     "data": {
      "application/vnd.jupyter.widget-view+json": {
       "model_id": "dc6311d29fad445981e30c933a8be5c2",
       "version_major": 2,
       "version_minor": 0
      },
      "text/plain": [
       "HBox(children=(FloatProgress(value=0.0, max=235.0), HTML(value='')))"
      ]
     },
     "metadata": {},
     "output_type": "display_data"
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "\n",
      "Validation Results - Epoch: 5  Avg accuracy: 0.83 Avg loss: 0.91\n"
     ]
    },
    {
     "data": {
      "application/vnd.jupyter.widget-view+json": {
       "model_id": "62ea40c9dda14e11b85b438713c2d568",
       "version_major": 2,
       "version_minor": 0
      },
      "text/plain": [
       "HBox(children=(FloatProgress(value=0.0, max=235.0), HTML(value='')))"
      ]
     },
     "metadata": {},
     "output_type": "display_data"
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "\n",
      "Validation Results - Epoch: 6  Avg accuracy: 0.86 Avg loss: 0.65\n"
     ]
    },
    {
     "data": {
      "application/vnd.jupyter.widget-view+json": {
       "model_id": "144aa5921dea4b0cb6b95366aeefa3d5",
       "version_major": 2,
       "version_minor": 0
      },
      "text/plain": [
       "HBox(children=(FloatProgress(value=0.0, max=235.0), HTML(value='')))"
      ]
     },
     "metadata": {},
     "output_type": "display_data"
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "\n",
      "Validation Results - Epoch: 7  Avg accuracy: 0.88 Avg loss: 0.52\n"
     ]
    },
    {
     "data": {
      "application/vnd.jupyter.widget-view+json": {
       "model_id": "f6461a00ecd648e9a34366d1be5cd945",
       "version_major": 2,
       "version_minor": 0
      },
      "text/plain": [
       "HBox(children=(FloatProgress(value=0.0, max=235.0), HTML(value='')))"
      ]
     },
     "metadata": {},
     "output_type": "display_data"
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "\n",
      "Validation Results - Epoch: 8  Avg accuracy: 0.89 Avg loss: 0.44\n"
     ]
    },
    {
     "data": {
      "application/vnd.jupyter.widget-view+json": {
       "model_id": "a9192d65250340349a98b303333de9f9",
       "version_major": 2,
       "version_minor": 0
      },
      "text/plain": [
       "HBox(children=(FloatProgress(value=0.0, max=235.0), HTML(value='')))"
      ]
     },
     "metadata": {},
     "output_type": "display_data"
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "\n",
      "Validation Results - Epoch: 9  Avg accuracy: 0.90 Avg loss: 0.39\n"
     ]
    },
    {
     "data": {
      "application/vnd.jupyter.widget-view+json": {
       "model_id": "95a18e2e9fc54929af9ca4e09584bcdd",
       "version_major": 2,
       "version_minor": 0
      },
      "text/plain": [
       "HBox(children=(FloatProgress(value=0.0, max=235.0), HTML(value='')))"
      ]
     },
     "metadata": {},
     "output_type": "display_data"
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "\n",
      "Validation Results - Epoch: 10  Avg accuracy: 0.91 Avg loss: 0.36\n"
     ]
    },
    {
     "data": {
      "text/plain": [
       "State:\n",
       "\titeration: 2350\n",
       "\tepoch: 10\n",
       "\tepoch_length: 235\n",
       "\tmax_epochs: 10\n",
       "\tmax_iters: <class 'NoneType'>\n",
       "\toutput: 0.5932911038398743\n",
       "\tbatch: <class 'list'>\n",
       "\tmetrics: <class 'dict'>\n",
       "\tdataloader: <class 'torch.utils.data.dataloader.DataLoader'>\n",
       "\tseed: <class 'NoneType'>\n",
       "\ttimes: <class 'dict'>"
      ]
     },
     "execution_count": 7,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "trainer = create_supervised_trainer(model, optimizer, criterion, device=device)\n",
    "evaluator = create_supervised_evaluator(model, metrics={\"acc\": Accuracy(), \"loss\": Loss(nn.NLLLoss())}, device=device)\n",
    "\n",
    "# Attach handlers profiler\n",
    "profiler = HandlersTimeProfiler()\n",
    "profiler.attach(trainer)\n",
    "\n",
    "# Init and attach progressbar\n",
    "pbar = ProgressBar(persist=True)\n",
    "pbar.attach(trainer, metric_names=\"all\")\n",
    "\n",
    "# Evaluate on each epoch using event handler\n",
    "@trainer.on(Events.EPOCH_COMPLETED)\n",
    "def log_validation_results(engine):\n",
    "    evaluator.run(testloader)\n",
    "    metrics = evaluator.state.metrics\n",
    "    avg_accuracy = metrics[\"acc\"]\n",
    "    avg_nll = metrics[\"loss\"]\n",
    "    pbar.log_message(\n",
    "        \"Validation Results - Epoch: {}  Avg accuracy: {:.2f} Avg loss: {:.2f}\".format(\n",
    "            engine.state.epoch, avg_accuracy, avg_nll\n",
    "        )\n",
    "    )\n",
    "\n",
    "    pbar.n = pbar.last_print_n = 0\n",
    "\n",
    "trainer.run(trainloader, max_epochs=10)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "We can see the summary of the profiling results from our run using the `get_results()` method of the profiler as shown below. The output shows total, average and other details of execution time for each handler attached."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 8,
   "metadata": {},
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "\n",
      "--------------------------  -----------------------  --------------  --------------  --------------  --------------  --------------  \n",
      "Handler                     Event Name                     Total(s)      Min(s)/IDX      Max(s)/IDX         Mean(s)          Std(s)  \n",
      "--------------------------  -----------------------  --------------  --------------  --------------  --------------  --------------  \n",
      "ProgressBar._close          EPOCH_COMPLETED                 0.01793       0.00094/5       0.00238/9         0.00179         0.00041  \n",
      "log_validation_results      EPOCH_COMPLETED                10.74416       1.03968/4       1.14411/0         1.07442         0.03126  \n",
      "_OutputHandler              ITERATION_COMPLETED             2.91436     0.00011/646    0.02959/1645         0.00124         0.00156  \n",
      "--------------------------  -----------------------  --------------  --------------  --------------  --------------  --------------  \n",
      "Total                                                      13.67645                                                                  \n",
      "--------------------------  -----------------------  --------------  --------------  --------------  --------------  --------------  \n",
      "Processing took total 10.52226s [min/index: 0.00308s/939, max/index: 0.06015s/0, mean: 0.00448s, std: 0.00138s]\n",
      "Dataflow took total 9.97417s [min/index: 9e-05s/232, max/index: 0.13135s/235, mean: 0.00424s, std: 0.008s]\n",
      "\n"
     ]
    }
   ],
   "source": [
    "profiler.print_results(profiler.get_results())"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Profiling results can be exported to a CSV file by using the `write_results()` method of profiler."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 9,
   "metadata": {},
   "outputs": [],
   "source": [
    "profiler.write_results(\"./results.csv\")"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Following code shows the preview of few rows of the CSV. Each handler has its separate column and the numbers of rows for each column will be equal to the number of times the handler invoked."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 10,
   "metadata": {},
   "outputs": [],
   "source": [
    "import pandas as pd"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 11,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<div>\n",
       "<style scoped>\n",
       "    .dataframe tbody tr th:only-of-type {\n",
       "        vertical-align: middle;\n",
       "    }\n",
       "\n",
       "    .dataframe tbody tr th {\n",
       "        vertical-align: top;\n",
       "    }\n",
       "\n",
       "    .dataframe thead th {\n",
       "        text-align: right;\n",
       "    }\n",
       "</style>\n",
       "<table border=\"1\" class=\"dataframe\">\n",
       "  <thead>\n",
       "    <tr style=\"text-align: right;\">\n",
       "      <th></th>\n",
       "      <th>#</th>\n",
       "      <th>processing_stats</th>\n",
       "      <th>dataflow_stats</th>\n",
       "      <th>ProgressBar._close (EPOCH_COMPLETED)</th>\n",
       "      <th>log_validation_results (EPOCH_COMPLETED)</th>\n",
       "      <th>_OutputHandler (ITERATION_COMPLETED)</th>\n",
       "    </tr>\n",
       "  </thead>\n",
       "  <tbody>\n",
       "    <tr>\n",
       "      <th>0</th>\n",
       "      <td>1.0</td>\n",
       "      <td>0.060145</td>\n",
       "      <td>0.036991</td>\n",
       "      <td>0.001666</td>\n",
       "      <td>1.144115</td>\n",
       "      <td>0.021295</td>\n",
       "    </tr>\n",
       "    <tr>\n",
       "      <th>1</th>\n",
       "      <td>2.0</td>\n",
       "      <td>0.004226</td>\n",
       "      <td>0.002801</td>\n",
       "      <td>0.001738</td>\n",
       "      <td>1.057090</td>\n",
       "      <td>0.000642</td>\n",
       "    </tr>\n",
       "    <tr>\n",
       "      <th>2</th>\n",
       "      <td>3.0</td>\n",
       "      <td>0.003816</td>\n",
       "      <td>0.003010</td>\n",
       "      <td>0.001735</td>\n",
       "      <td>1.062781</td>\n",
       "      <td>0.001289</td>\n",
       "    </tr>\n",
       "    <tr>\n",
       "      <th>3</th>\n",
       "      <td>4.0</td>\n",
       "      <td>0.004890</td>\n",
       "      <td>0.000185</td>\n",
       "      <td>0.001849</td>\n",
       "      <td>1.101738</td>\n",
       "      <td>0.001339</td>\n",
       "    </tr>\n",
       "    <tr>\n",
       "      <th>4</th>\n",
       "      <td>5.0</td>\n",
       "      <td>0.003556</td>\n",
       "      <td>0.006651</td>\n",
       "      <td>0.001942</td>\n",
       "      <td>1.039676</td>\n",
       "      <td>0.000968</td>\n",
       "    </tr>\n",
       "  </tbody>\n",
       "</table>\n",
       "</div>"
      ],
      "text/plain": [
       "     #  processing_stats  dataflow_stats  \\\n",
       "0  1.0          0.060145        0.036991   \n",
       "1  2.0          0.004226        0.002801   \n",
       "2  3.0          0.003816        0.003010   \n",
       "3  4.0          0.004890        0.000185   \n",
       "4  5.0          0.003556        0.006651   \n",
       "\n",
       "   ProgressBar._close (EPOCH_COMPLETED)  \\\n",
       "0                              0.001666   \n",
       "1                              0.001738   \n",
       "2                              0.001735   \n",
       "3                              0.001849   \n",
       "4                              0.001942   \n",
       "\n",
       "   log_validation_results (EPOCH_COMPLETED)  \\\n",
       "0                                  1.144115   \n",
       "1                                  1.057090   \n",
       "2                                  1.062781   \n",
       "3                                  1.101738   \n",
       "4                                  1.039676   \n",
       "\n",
       "   _OutputHandler (ITERATION_COMPLETED)  \n",
       "0                              0.021295  \n",
       "1                              0.000642  \n",
       "2                              0.001289  \n",
       "3                              0.001339  \n",
       "4                              0.000968  "
      ]
     },
     "execution_count": 11,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "results = pd.read_csv(\"./results.csv\")\n",
    "results.head()"
   ]
  }
 ],
 "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.9"
  }
 },
 "nbformat": 4,
 "nbformat_minor": 4
}