Recommendation_System.ipynb

{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Importing all necessary Packages"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 27,
   "metadata": {
    "id": "-DiCPiWd1v_q",
    "tags": []
   },
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Looking in indexes: https://pypi.org/simple, https://pip.repos.neuron.amazonaws.com\n",
      "Collecting mxnet-cu92\n",
      "  Downloading mxnet_cu92-1.7.0-py2.py3-none-manylinux2014_x86_64.whl (789.8 MB)\n",
      "\u001b[2K     \u001b[90m━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━\u001b[0m \u001b[32m789.8/789.8 MB\u001b[0m \u001b[31m834.3 kB/s\u001b[0m eta \u001b[36m0:00:00\u001b[0m00:01\u001b[0m00:01\u001b[0m\n",
      "\u001b[?25hRequirement already satisfied: numpy<2.0.0,>1.16.0 in /home/ec2-user/anaconda3/envs/amazonei_pytorch_latest_p37/lib/python3.7/site-packages (from mxnet-cu92) (1.21.6)\n",
      "Requirement already satisfied: graphviz<0.9.0,>=0.8.1 in /home/ec2-user/anaconda3/envs/amazonei_pytorch_latest_p37/lib/python3.7/site-packages (from mxnet-cu92) (0.8.4)\n",
      "Requirement already satisfied: requests<3,>=2.20.0 in /home/ec2-user/anaconda3/envs/amazonei_pytorch_latest_p37/lib/python3.7/site-packages (from mxnet-cu92) (2.28.1)\n",
      "Requirement already satisfied: urllib3<1.27,>=1.21.1 in /home/ec2-user/anaconda3/envs/amazonei_pytorch_latest_p37/lib/python3.7/site-packages (from requests<3,>=2.20.0->mxnet-cu92) (1.26.8)\n",
      "Requirement already satisfied: certifi>=2017.4.17 in /home/ec2-user/anaconda3/envs/amazonei_pytorch_latest_p37/lib/python3.7/site-packages (from requests<3,>=2.20.0->mxnet-cu92) (2022.12.7)\n",
      "Requirement already satisfied: idna<4,>=2.5 in /home/ec2-user/anaconda3/envs/amazonei_pytorch_latest_p37/lib/python3.7/site-packages (from requests<3,>=2.20.0->mxnet-cu92) (3.4)\n",
      "Requirement already satisfied: charset-normalizer<3,>=2 in /home/ec2-user/anaconda3/envs/amazonei_pytorch_latest_p37/lib/python3.7/site-packages (from requests<3,>=2.20.0->mxnet-cu92) (2.1.1)\n",
      "Installing collected packages: mxnet-cu92\n",
      "Successfully installed mxnet-cu92-1.7.0\n"
     ]
    }
   ],
   "source": [
    "import os\n",
    "!pip install mxnet-cu92\n",
    "import mxnet as mx\n",
    "from mxnet import gluon, nd, ndarray\n",
    "\n",
    "import pandas as pd\n",
    "import numpy as np"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Hyper Parameters"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 13,
   "metadata": {
    "id": "ppi8iI2y2Ri-",
    "tags": []
   },
   "outputs": [],
   "source": [
    "data_path = 'ml-100k'\n",
    "num_emb = 128 # Numerical Embedding value\n",
    "opt = 'Adam' # Optimizer - Adam // can be SGD(Stochastic Gradient Descent)\n",
    "lr = 0.02 # Learning Rate\n",
    "mnmtm = 0. # Momentum\n",
    "wd = 0.4 \n",
    "batch_size = 50\n",
    "ctx = mx.gpu(4) "
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Downloading Data from Movielens"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 14,
   "metadata": {
    "id": "1aOhQnsW2sut",
    "tags": []
   },
   "outputs": [],
   "source": [
    "def download_ml_data(prefix):\n",
    "  if not os.path.exists(\"%s.zip\" % prefix):\n",
    "    print(\"Downloading Movielens Data %s\" % prefix)\n",
    "    os.system(\"wget http://files.grouplens.org/datasets/movielens/%s.zip\" % prefix)\n",
    "    os.system(\"unzip %s.zip\" % prefix)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 15,
   "metadata": {
    "id": "yZLbUmxs3QCu",
    "tags": []
   },
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Downloading Movielens Data ml-100k\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "--2023-04-21 11:37:44--  http://files.grouplens.org/datasets/movielens/ml-100k.zip\n",
      "Resolving files.grouplens.org (files.grouplens.org)... 128.101.65.152\n",
      "Connecting to files.grouplens.org (files.grouplens.org)|128.101.65.152|:80... connected.\n",
      "HTTP request sent, awaiting response... 200 OK\n",
      "Length: 4924029 (4.7M) [application/zip]\n",
      "Saving to: ‘ml-100k.zip’\n",
      "\n",
      "     0K .......... .......... .......... .......... ..........  1%  114K 42s\n",
      "    50K .......... .......... .......... .......... ..........  2%  228K 31s\n",
      "   100K .......... .......... .......... .......... ..........  3%  228K 27s\n",
      "   150K .......... .......... .......... .......... ..........  4%  228K 25s\n",
      "   200K .......... .......... .......... .......... ..........  5%  228K 24s\n",
      "   250K .......... .......... .......... .......... ..........  6% 59.9M 20s\n",
      "   300K .......... .......... .......... .......... ..........  7% 72.7M 17s\n",
      "   350K .......... .......... .......... .......... ..........  8%  229K 17s\n",
      "   400K .......... .......... .......... .......... ..........  9%  261M 15s\n",
      "   450K .......... .......... .......... .......... .......... 10%  109M 13s\n",
      "   500K .......... .......... .......... .......... .......... 11% 45.0M 12s\n",
      "   550K .......... .......... .......... .......... .......... 12%  254M 11s\n",
      "   600K .......... .......... .......... .......... .......... 13%  230K 11s\n",
      "   650K .......... .......... .......... .......... .......... 14% 96.3M 10s\n",
      "   700K .......... .......... .......... .......... .......... 15%  108M 9s\n",
      "   750K .......... .......... .......... .......... .......... 16%  128M 9s\n",
      "   800K .......... .......... .......... .......... .......... 17%  101M 8s\n",
      "   850K .......... .......... .......... .......... .......... 18% 97.5M 8s\n",
      "   900K .......... .......... .......... .......... .......... 19% 90.7M 7s\n",
      "   950K .......... .......... .......... .......... .......... 20% 65.3M 7s\n",
      "  1000K .......... .......... .......... .......... .......... 21%  177M 6s\n",
      "  1050K .......... .......... .......... .......... .......... 22%  232K 7s\n",
      "  1100K .......... .......... .......... .......... .......... 23% 71.3M 6s\n",
      "  1150K .......... .......... .......... .......... .......... 24%  133M 6s\n",
      "  1200K .......... .......... .......... .......... .......... 25%  147M 6s\n",
      "  1250K .......... .......... .......... .......... .......... 27%  136M 5s\n",
      "  1300K .......... .......... .......... .......... .......... 28% 92.6M 5s\n",
      "  1350K .......... .......... .......... .......... .......... 29%  135M 5s\n",
      "  1400K .......... .......... .......... .......... .......... 30%  158M 5s\n",
      "  1450K .......... .......... .......... .......... .......... 31%  116M 4s\n",
      "  1500K .......... .......... .......... .......... .......... 32%  109M 4s\n",
      "  1550K .......... .......... .......... .......... .......... 33%  116M 4s\n",
      "  1600K .......... .......... .......... .......... .......... 34%  144M 4s\n",
      "  1650K .......... .......... .......... .......... .......... 35%  129M 4s\n",
      "  1700K .......... .......... .......... .......... .......... 36%  143M 3s\n",
      "  1750K .......... .......... .......... .......... .......... 37%  150M 3s\n",
      "  1800K .......... .......... .......... .......... .......... 38%  128M 3s\n",
      "  1850K .......... .......... .......... .......... .......... 39%  137M 3s\n",
      "  1900K .......... .......... .......... .......... .......... 40%  130M 3s\n",
      "  1950K .......... .......... .......... .......... .......... 41%  235K 3s\n",
      "  2000K .......... .......... .......... .......... .......... 42% 51.7M 3s\n",
      "  2050K .......... .......... .......... .......... .......... 43%  183M 3s\n",
      "  2100K .......... .......... .......... .......... .......... 44%  206M 3s\n",
      "  2150K .......... .......... .......... .......... .......... 45%  266M 3s\n",
      "  2200K .......... .......... .......... .......... .......... 46%  177M 2s\n",
      "  2250K .......... .......... .......... .......... .......... 47%  222M 2s\n",
      "  2300K .......... .......... .......... .......... .......... 48%  165M 2s\n",
      "  2350K .......... .......... .......... .......... .......... 49%  117M 2s\n",
      "  2400K .......... .......... .......... .......... .......... 50%  103M 2s\n",
      "  2450K .......... .......... .......... .......... .......... 51% 87.3M 2s\n",
      "  2500K .......... .......... .......... .......... .......... 53% 81.6M 2s\n",
      "  2550K .......... .......... .......... .......... .......... 54% 82.7M 2s\n",
      "  2600K .......... .......... .......... .......... .......... 55%  102M 2s\n",
      "  2650K .......... .......... .......... .......... .......... 56%  111M 2s\n",
      "  2700K .......... .......... .......... .......... .......... 57% 84.3M 2s\n",
      "  2750K .......... .......... .......... .......... .......... 58% 61.8M 2s\n",
      "  2800K .......... .......... .......... .......... .......... 59%  105M 2s\n",
      "  2850K .......... .......... .......... .......... .......... 60% 66.2M 1s\n",
      "  2900K .......... .......... .......... .......... .......... 61% 73.4M 1s\n",
      "  2950K .......... .......... .......... .......... .......... 62% 90.1M 1s\n",
      "  3000K .......... .......... .......... .......... .......... 63% 64.1M 1s\n",
      "  3050K .......... .......... .......... .......... .......... 64% 50.2M 1s\n",
      "  3100K .......... .......... .......... .......... .......... 65% 25.5M 1s\n",
      "  3150K .......... .......... .......... .......... .......... 66%  163M 1s\n",
      "  3200K .......... .......... .......... .......... .......... 67%  136M 1s\n",
      "  3250K .......... .......... .......... .......... .......... 68%  168M 1s\n",
      "  3300K .......... .......... .......... .......... .......... 69%  132M 1s\n",
      "  3350K .......... .......... .......... .......... .......... 70%  112M 1s\n",
      "  3400K .......... .......... .......... .......... .......... 71%  152M 1s\n",
      "  3450K .......... .......... .......... .......... .......... 72%  147M 1s\n",
      "  3500K .......... .......... .......... .......... .......... 73%  115M 1s\n",
      "  3550K .......... .......... .......... .......... .......... 74%  157M 1s\n",
      "  3600K .......... .......... .......... .......... .......... 75%  152M 1s\n",
      "  3650K .......... .......... .......... .......... .......... 76%  166M 1s\n",
      "  3700K .......... .......... .......... .......... .......... 77%  105M 1s\n",
      "  3750K .......... .......... .......... .......... .......... 79%  155M 1s\n",
      "  3800K .......... .......... .......... .......... .......... 80%  248K 1s\n",
      "  3850K .......... .......... .......... .......... .......... 81%  199M 1s\n",
      "  3900K .......... .......... .......... .......... .......... 82%  120M 1s\n",
      "  3950K .......... .......... .......... .......... .......... 83%  143M 0s\n",
      "  4000K .......... .......... .......... .......... .......... 84%  102M 0s\n",
      "  4050K .......... .......... .......... .......... .......... 85%  151M 0s\n",
      "  4100K .......... .......... .......... .......... .......... 86% 91.9M 0s\n",
      "  4150K .......... .......... .......... .......... .......... 87%  186M 0s\n",
      "  4200K .......... .......... .......... .......... .......... 88%  100M 0s\n",
      "  4250K .......... .......... .......... .......... .......... 89%  190M 0s\n",
      "  4300K .......... .......... .......... .......... .......... 90%  176M 0s\n",
      "  4350K .......... .......... .......... .......... .......... 91% 90.7M 0s\n",
      "  4400K .......... .......... .......... .......... .......... 92% 66.3M 0s\n",
      "  4450K .......... .......... .......... .......... .......... 93% 51.1M 0s\n",
      "  4500K .......... .......... .......... .......... .......... 94% 78.6M 0s\n",
      "  4550K .......... .......... .......... .......... .......... 95% 86.3M 0s\n",
      "  4600K .......... .......... .......... .......... .......... 96%  298M 0s\n",
      "  4650K .......... .......... .......... .......... .......... 97%  306M 0s\n",
      "  4700K .......... .......... .......... .......... .......... 98%  256M 0s\n",
      "  4750K .......... .......... .......... .......... .......... 99%  269M 0s\n",
      "  4800K ........                                              100%  299M=2.4s\n",
      "\n",
      "2023-04-21 11:37:47 (1.94 MB/s) - ‘ml-100k.zip’ saved [4924029/4924029]\n",
      "\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Archive:  ml-100k.zip\n",
      "   creating: ml-100k/\n",
      "  inflating: ml-100k/allbut.pl       \n",
      "  inflating: ml-100k/mku.sh          \n",
      "  inflating: ml-100k/README          \n",
      "  inflating: ml-100k/u.data          \n",
      "  inflating: ml-100k/u.genre         \n",
      "  inflating: ml-100k/u.info          \n",
      "  inflating: ml-100k/u.item          \n",
      "  inflating: ml-100k/u.occupation    \n",
      "  inflating: ml-100k/u.user          \n",
      "  inflating: ml-100k/u1.base         \n",
      "  inflating: ml-100k/u1.test         \n",
      "  inflating: ml-100k/u2.base         \n",
      "  inflating: ml-100k/u2.test         \n",
      "  inflating: ml-100k/u3.base         \n",
      "  inflating: ml-100k/u3.test         \n",
      "  inflating: ml-100k/u4.base         \n",
      "  inflating: ml-100k/u4.test         \n",
      "  inflating: ml-100k/u5.base         \n",
      "  inflating: ml-100k/u5.test         \n",
      "  inflating: ml-100k/ua.base         \n",
      "  inflating: ml-100k/ua.test         \n",
      "  inflating: ml-100k/ub.base         \n",
      "  inflating: ml-100k/ub.test         \n"
     ]
    }
   ],
   "source": [
    "download_ml_data(data_path)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 17,
   "metadata": {
    "id": "ZGI4wodH3QFb",
    "tags": []
   },
   "outputs": [],
   "source": [
    "## Finding the No of users and no of items \n",
    "from re import M\n",
    "def max_id(fname):\n",
    "  mu = 0\n",
    "  mi = 0\n",
    "  with open(fname) as f:\n",
    "    for line in f:\n",
    "      tks = line.strip().split('\\t')\n",
    "      if len(tks) != 4:\n",
    "        continue\n",
    "      mu = max(mu, int(tks[0]))\n",
    "      mi = max(mi, int(tks[1]))\n",
    "  return mu+1,mi+1\n",
    "max_users, max_items = max_id(data_path + '/u.data')"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Splitting train data, test data, labels"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 47,
   "metadata": {
    "id": "1hCVb_xV3QIO",
    "tags": []
   },
   "outputs": [],
   "source": [
    "train_df = pd.read_csv(data_path+'/u1.base', header = None, sep = '\\t')\n",
    "test_df = pd.read_csv(data_path+'/u1.test',header = None, sep = '\\t')\n",
    "\n",
    "train_data = nd.array(train_df[[0,1]].values, dtype = np.float32)\n",
    "train_label = nd.array(train_df[2].values, dtype = np.float32)\n",
    "\n",
    "test_data = nd.array(test_df[[0,1]].values, dtype = np.float32)\n",
    "test_label = nd.array(test_df[2].values, dtype = np.float32)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Creating a SparseMatrixDataset\n",
    "This class inherits the gluon dataset class. "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 22,
   "metadata": {
    "id": "5MpGJv9g3QLG",
    "tags": []
   },
   "outputs": [],
   "source": [
    "class SparseMatrixDataset(gluon.data.Dataset):\n",
    "  def __init__(self, data, label):\n",
    "    assert data.shape[0] == len(label) ## Checks whether the first dimension in the shape of data is equal to len of label, else raise Assertion Error\n",
    "    self.data = data\n",
    "    self.label = label\n",
    "    ## Checking whether the label is of the type ndarray using isinstance()\n",
    "    if isinstance(label, ndarray.NDArray) and len(label.shape) == 1:\n",
    "      # using self._ will be available in the entire instance of the class\n",
    "      # using only label will be scoped only within the method itself\n",
    "      self._label = label.asnumpy()\n",
    "    else:\n",
    "      self._label = label\n",
    "    \n",
    "  def __getitem__(self,idx):\n",
    "    return self.data[idx,0], self.data[idx,1], self.label[idx]\n",
    "  \n",
    "  def __len__(self):\n",
    "    return self.data.shape[0]\n"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 54,
   "metadata": {
    "id": "ksIhneLT3QNu",
    "tags": []
   },
   "outputs": [],
   "source": [
    "class MFBlock(gluon.Block):\n",
    "  def __init__(self, max_users, max_items, num_emb, dropout_p = 0.5):\n",
    "    super(MFBlock,self).__init__()\n",
    "\n",
    "    self.max_users = max_users\n",
    "    self.max_items = max_items\n",
    "    self.dropout_p = dropout_p\n",
    "    self.num_emb = num_emb\n",
    "\n",
    "    with self.name_scope(): \n",
    "      #To manage the names of nested Blocks, each Block has a name_scope attached to it. All Blocks created within a name scope will have its parent Block’s prefix prepended to its name.\n",
    "      self.user_embeddings = gluon.nn.Embedding(max_users, num_emb)\n",
    "      self.item_embeddings = gluon.nn.Embedding(max_items, num_emb)\n",
    "      self.dropout = gluon.nn.Dropout(dropout_p)\n",
    "    \n",
    "  def forward(self, users, items):\n",
    "    a = self.user_embeddings(users)\n",
    "    b = self.item_embeddings(items)\n",
    "    predictions = self.dropout(a) * self.dropout(b)\n",
    "    predictions = nd.sum(predictions, axis = 1) ## Calculate the sum of each elements in the array    \n",
    "    return predictions\n"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 55,
   "metadata": {
    "id": "1czQV9Ty3QQL",
    "tags": []
   },
   "outputs": [
    {
     "data": {
      "text/plain": [
       "mfblock2_ (\n",
       "  Parameter mfblock2_embedding0_weight (shape=(944, 128), dtype=float32)\n",
       "  Parameter mfblock2_embedding1_weight (shape=(1683, 128), dtype=float32)\n",
       ")"
      ]
     },
     "execution_count": 55,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "net = MFBlock(max_users = max_users, max_items = max_items, num_emb = num_emb, dropout_p = 0.)\n",
    "net.collect_params()  "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 57,
   "metadata": {
    "id": "f1-L7JTU3QS7",
    "tags": []
   },
   "outputs": [],
   "source": [
    "loss_function = gluon.loss.L2Loss()"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 58,
   "metadata": {
    "tags": []
   },
   "outputs": [],
   "source": [
    "ctx = mx.cpu()"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 59,
   "metadata": {
    "id": "5AMGSlzw3QV0",
    "tags": []
   },
   "outputs": [],
   "source": [
    "net.collect_params().initialize(mx.init.Xavier(magnitude = 2.24), ctx = mx.cpu(), force_reinit = True)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 60,
   "metadata": {
    "id": "0811KEln3QYc",
    "tags": []
   },
   "outputs": [],
   "source": [
    "trainer = gluon.Trainer(net.collect_params(), 'sgd', {\n",
    "    'learning_rate' : lr, 'wd':wd, 'momentum': 0.9\n",
    "})"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 61,
   "metadata": {
    "id": "kJrgo3kI3Qa-",
    "tags": []
   },
   "outputs": [],
   "source": [
    "train_data_iter = gluon.data.DataLoader(SparseMatrixDataset(train_data, train_label),\n",
    "                                        shuffle = True, batch_size = batch_size)\n",
    "test_data_iter =  gluon.data.DataLoader(SparseMatrixDataset(test_data, test_label),\n",
    "                                       shuffle = True, batch_size = batch_size)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 64,
   "metadata": {
    "id": "DWB2FgQj3Qd3",
    "tags": []
   },
   "outputs": [],
   "source": [
    "def eval_net(data, net):\n",
    "  acc = mx.metric.RMSE()\n",
    "  for i, (user,item,label) in enumerate(data):\n",
    "    user = user.as_in_context(ctx).reshape((batch_size,))\n",
    "    item = item.as_in_context(ctx).reshape((batch_size,))\n",
    "    label = label.as_in_context(ctx).reshape((batch_size,))\n",
    "    predictions = net(user, item)\n",
    "    loss = loss_function(predictions, label)\n",
    "    acc.update(preds = predictions, labels = label)\n",
    "  return acc.get()[1]  "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 65,
   "metadata": {
    "id": "L0MRtXLL3QgT",
    "tags": []
   },
   "outputs": [
    {
     "data": {
      "text/plain": [
       "3.7163775902986527"
      ]
     },
     "execution_count": 65,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "eval_net(test_data_iter, net)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 68,
   "metadata": {
    "id": "qaPCNvS1B8f3",
    "tags": []
   },
   "outputs": [],
   "source": [
    "epochs = 10\n",
    "def train(data_iter, net):\n",
    "  a = []\n",
    "  b = []\n",
    "  for e in range(epochs):\n",
    "    print(f'Epoch: {format(e)} ')\n",
    "    for i, (user,item,label) in enumerate(data_iter):\n",
    "      user = user.as_in_context(ctx).reshape((batch_size,))\n",
    "      item = item.as_in_context(ctx).reshape((batch_size,))\n",
    "      label = label.as_in_context(ctx).reshape((batch_size,))\n",
    "      with mx.autograd.record():\n",
    "        output = net(user,item)\n",
    "        loss = loss_function(output,label)\n",
    "        loss.backward()\n",
    "      net.collect_params().values()\n",
    "      trainer.step(batch_size)\n",
    "    a = eval_net(train_data_iter, net)\n",
    "    b = eval_net(test_data_iter, net)\n",
    "    print(\"EPOCH {}: RMSE ON TRAINING DATA AND TEST DATA: {}. {}\".format(e,a,b))\n",
    "  return a, b\n",
    "\n",
    "\n"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 69,
   "metadata": {
    "id": "TYvsXUMAB8jg",
    "tags": []
   },
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Epoch: 0 \n",
      "EPOCH 0: RMSE ON TRAINING DATA AND TEST DATA: 3.698545118868351. 3.7165595012903214\n",
      "Epoch: 1 \n",
      "EPOCH 1: RMSE ON TRAINING DATA AND TEST DATA: 3.6985192470252515. 3.716602285504341\n",
      "Epoch: 2 \n",
      "EPOCH 2: RMSE ON TRAINING DATA AND TEST DATA: 3.6985854786634444. 3.716644257903099\n",
      "Epoch: 3 \n",
      "EPOCH 3: RMSE ON TRAINING DATA AND TEST DATA: 3.698873323947191. 3.7165798515081407\n",
      "Epoch: 4 \n",
      "EPOCH 4: RMSE ON TRAINING DATA AND TEST DATA: 3.6987005624175073. 3.7166377264261246\n",
      "Epoch: 5 \n",
      "EPOCH 5: RMSE ON TRAINING DATA AND TEST DATA: 3.6988156653940676. 3.7167279362678527\n",
      "Epoch: 6 \n",
      "EPOCH 6: RMSE ON TRAINING DATA AND TEST DATA: 3.6987258034944532. 3.716428287625313\n",
      "Epoch: 7 \n",
      "EPOCH 7: RMSE ON TRAINING DATA AND TEST DATA: 3.6988907086849214. 3.7164703798294068\n",
      "Epoch: 8 \n",
      "EPOCH 8: RMSE ON TRAINING DATA AND TEST DATA: 3.6986256209015846. 3.716779120564461\n",
      "Epoch: 9 \n",
      "EPOCH 9: RMSE ON TRAINING DATA AND TEST DATA: 3.6987649576365946. 3.716369916200638\n",
      "The final RMSE of training data and testing data are (3.6987649576365946, 3.716369916200638)\n"
     ]
    }
   ],
   "source": [
    "(a,b) = train(train_data_iter, net)\n",
    "print(\"The final RMSE of training data and testing data are\",(a,b))"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Let' change the Model \n",
    "## Let's add some Dense Layer and Make it as Fully Connected layer, and check the performance"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 126,
   "metadata": {
    "id": "3q3InKD3B8mv",
    "tags": []
   },
   "outputs": [],
   "source": [
    "class MFBlock1(gluon.Block):\n",
    "  def __init__(self, max_users, max_items, num_emb, dropout_p = 0.):\n",
    "    super(MFBlock1,self).__init__()\n",
    "\n",
    "    self.max_users = max_users\n",
    "    self.max_items = max_items\n",
    "    self.dropout_p = dropout_p\n",
    "    self.num_emb = num_emb\n",
    "\n",
    "    with self.name_scope(): \n",
    "      #To manage the names of nested Blocks, each Block has a name_scope attached to it. All Blocks created within a name scope will have its parent Block’s prefix prepended to its name.\n",
    "      self.user_embeddings = gluon.nn.Embedding(max_users, num_emb)\n",
    "      self.item_embeddings = gluon.nn.Embedding(max_items, num_emb)\n",
    "      self.dropout = gluon.nn.Dropout(dropout_p)\n",
    "      self.dense = gluon.nn.Dense(num_emb)\n",
    "    \n",
    "  def forward(self, users, items):\n",
    "    a = self.user_embeddings(users)\n",
    "    a = self.dense(a)\n",
    "\n",
    "\n",
    "    b = self.item_embeddings(items)\n",
    "    b = self.dense(b)\n",
    "\n",
    "\n",
    "    predictions = self.dropout(a) * self.dropout(b)\n",
    "    predictions = nd.sum(predictions, axis = 1) ## Calculate the sum of each elements in the array    \n",
    "    return predictions"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 127,
   "metadata": {
    "tags": []
   },
   "outputs": [
    {
     "data": {
      "text/plain": [
       "mfblock12_ (\n",
       "  Parameter mfblock12_embedding0_weight (shape=(944, 128), dtype=float32)\n",
       "  Parameter mfblock12_embedding1_weight (shape=(1683, 128), dtype=float32)\n",
       "  Parameter mfblock12_dense0_weight (shape=(128, 0), dtype=float32)\n",
       "  Parameter mfblock12_dense0_bias (shape=(128,), dtype=float32)\n",
       ")"
      ]
     },
     "execution_count": 127,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "net1 = MFBlock1(max_users = max_users, max_items = max_items, num_emb = num_emb, dropout_p = 0.)\n",
    "net1.collect_params()  "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 128,
   "metadata": {
    "tags": []
   },
   "outputs": [],
   "source": [
    "loss_function = gluon.loss.L2Loss()"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 129,
   "metadata": {
    "tags": []
   },
   "outputs": [],
   "source": [
    "net1.collect_params().initialize(mx.init.Xavier(magnitude = 2.24), ctx = mx.cpu(), force_reinit = True)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 130,
   "metadata": {
    "tags": []
   },
   "outputs": [],
   "source": [
    "trainer = gluon.Trainer(net1.collect_params(), 'sgd', {\n",
    "    'learning_rate' : lr, 'wd':wd, 'momentum': 0.9\n",
    "})"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 131,
   "metadata": {
    "tags": []
   },
   "outputs": [
    {
     "data": {
      "text/plain": [
       "3.7166581296920778"
      ]
     },
     "execution_count": 131,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "eval_net(test_data_iter, net1)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 133,
   "metadata": {
    "tags": []
   },
   "outputs": [],
   "source": [
    "epochs = 10\n",
    "def train1(data_iter, net):\n",
    "  a = []\n",
    "  b = []\n",
    "  for e in range(epochs):\n",
    "    print(f'Epoch: {format(e)} ')\n",
    "    for i, (user,item,label) in enumerate(data_iter):\n",
    "      user = user.as_in_context(ctx).reshape((batch_size,))\n",
    "      item = item.as_in_context(ctx).reshape((batch_size,))\n",
    "      label = label.as_in_context(ctx).reshape((batch_size,))\n",
    "      with mx.autograd.record():\n",
    "        output = net(user,item)\n",
    "        loss = loss_function(output,label)\n",
    "        loss.backward()\n",
    "      net.collect_params().values()\n",
    "      trainer.step(batch_size,ignore_stale_grad = True)\n",
    "    a = eval_net(train_data_iter, net)\n",
    "    b = eval_net(test_data_iter, net)\n",
    "    print(\"EPOCH {}: RMSE ON TRAINING DATA AND TEST DATA: {}. {}\".format(e,a,b))\n",
    "  return a, b\n",
    "\n",
    "\n"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 134,
   "metadata": {},
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Epoch: 0 \n",
      "EPOCH 0: RMSE ON TRAINING DATA AND TEST DATA: 3.6986864763498306. 3.7164743614196776\n",
      "Epoch: 1 \n",
      "EPOCH 1: RMSE ON TRAINING DATA AND TEST DATA: 3.698616882264614. 3.716383241415024\n",
      "Epoch: 2 \n",
      "EPOCH 2: RMSE ON TRAINING DATA AND TEST DATA: 3.698664338588715. 3.7170433419942857\n",
      "Epoch: 3 \n",
      "EPOCH 3: RMSE ON TRAINING DATA AND TEST DATA: 3.6985878494381903. 3.7162007969617843\n",
      "Epoch: 4 \n",
      "EPOCH 4: RMSE ON TRAINING DATA AND TEST DATA: 3.6986929927766323. 3.7165655320882798\n",
      "Epoch: 5 \n",
      "EPOCH 5: RMSE ON TRAINING DATA AND TEST DATA: 3.698709747046232. 3.7163346296548845\n",
      "Epoch: 6 \n",
      "EPOCH 6: RMSE ON TRAINING DATA AND TEST DATA: 3.6987730634212492. 3.7163832676410675\n",
      "Epoch: 7 \n",
      "EPOCH 7: RMSE ON TRAINING DATA AND TEST DATA: 3.6987247894704343. 3.7162336218357086\n",
      "Epoch: 8 \n",
      "EPOCH 8: RMSE ON TRAINING DATA AND TEST DATA: 3.6987047734856606. 3.7167682909965514\n",
      "Epoch: 9 \n",
      "EPOCH 9: RMSE ON TRAINING DATA AND TEST DATA: 3.698653819859028. 3.7161995333433153\n",
      "The final RMSE of training data and testing data are (3.698653819859028, 3.7161995333433153)\n"
     ]
    }
   ],
   "source": [
    "(a,b) = train1(train_data_iter, net)\n",
    "print(\"The final RMSE of training data and testing data are\",(a,b))"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 163,
   "metadata": {
    "id": "0EoV7g6kB8pe",
    "tags": []
   },
   "outputs": [],
   "source": [
    "class MFBlock2(gluon.Block):\n",
    "  def __init__(self, max_users, max_items, num_emb, dropout_p = 0.5):\n",
    "    super(MFBlock2,self).__init__()\n",
    "\n",
    "    self.max_users = max_users\n",
    "    self.max_items = max_items\n",
    "    self.dropout_p = dropout_p\n",
    "    self.num_emb = num_emb\n",
    "\n",
    "    with self.name_scope(): \n",
    "      #To manage the names of nested Blocks, each Block has a name_scope attached to it. All Blocks created within a name scope will have its parent Block’s prefix prepended to its name.\n",
    "      self.user_embeddings = gluon.nn.Embedding(max_users, num_emb)\n",
    "      self.item_embeddings = gluon.nn.Embedding(max_items, num_emb)\n",
    "      self.dropout = gluon.nn.Dropout(dropout_p)\n",
    "      # self.conv = gluon.nn.Conv1D(num_emb, kernel_size = (1),activation = \"relu\")\n",
    "      self.dense = gluon.nn.Dense(num_emb, activation = 'sigmoid')\n",
    "    \n",
    "  def forward(self, users, items):\n",
    "    a = self.user_embeddings(users)\n",
    "    # a = self.conv(a)\n",
    "    a = self.dense(a)\n",
    "    a = self.dense(a)\n",
    "\n",
    "    b = self.item_embeddings(items)\n",
    "    # b = self.conv(b)\n",
    "    b = self.dense(b)\n",
    "    b = self.dense(b)\n",
    "\n",
    "    predictions = self.dropout(a) * self.dropout(b)\n",
    "    predictions = nd.sum(predictions, axis = 1) ## Calculate the sum of each elements in the array    \n",
    "    return predictions"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 164,
   "metadata": {
    "tags": []
   },
   "outputs": [
    {
     "data": {
      "text/plain": [
       "mfblock210_ (\n",
       "  Parameter mfblock210_embedding0_weight (shape=(944, 128), dtype=float32)\n",
       "  Parameter mfblock210_embedding1_weight (shape=(1683, 128), dtype=float32)\n",
       "  Parameter mfblock210_dense0_weight (shape=(128, 0), dtype=float32)\n",
       "  Parameter mfblock210_dense0_bias (shape=(128,), dtype=float32)\n",
       ")"
      ]
     },
     "execution_count": 164,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "net2 = MFBlock2(max_users = max_users, max_items = max_items, num_emb = num_emb, dropout_p = 0.)\n",
    "net2.collect_params() "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 165,
   "metadata": {
    "tags": []
   },
   "outputs": [],
   "source": [
    "loss_function = gluon.loss.L2Loss()"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 166,
   "metadata": {
    "tags": []
   },
   "outputs": [],
   "source": [
    "net2.collect_params().initialize(mx.init.Xavier(magnitude = 2.24), ctx = mx.cpu(), force_reinit = True)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 167,
   "metadata": {
    "tags": []
   },
   "outputs": [],
   "source": [
    "trainer = gluon.Trainer(net2.collect_params(), 'sgd', {\n",
    "    'learning_rate' : lr, 'wd':wd, 'momentum': 0.9\n",
    "})"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 168,
   "metadata": {
    "tags": []
   },
   "outputs": [
    {
     "data": {
      "text/plain": [
       "31.97821319580078"
      ]
     },
     "execution_count": 168,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "eval_net(test_data_iter, net2)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 169,
   "metadata": {
    "tags": []
   },
   "outputs": [],
   "source": [
    "epochs = 10\n",
    "def train2(data_iter, net):\n",
    "  a = []\n",
    "  b = []\n",
    "  for e in range(epochs):\n",
    "    print(f'Epoch: {format(e)} ')\n",
    "    for i, (user,item,label) in enumerate(data_iter):\n",
    "      user = user.as_in_context(ctx).reshape((batch_size,))\n",
    "      item = item.as_in_context(ctx).reshape((batch_size,))\n",
    "      label = label.as_in_context(ctx).reshape((batch_size,))\n",
    "      with mx.autograd.record():\n",
    "        output = net(user,item)\n",
    "        loss = loss_function(output,label)\n",
    "        loss.backward()\n",
    "      net.collect_params().values()\n",
    "      trainer.step(batch_size,ignore_stale_grad = True)\n",
    "    a = eval_net(train_data_iter, net)\n",
    "    b = eval_net(test_data_iter, net)\n",
    "    print(\"EPOCH {}: RMSE ON TRAINING DATA AND TEST DATA: {}. {}\".format(e,a,b))\n",
    "  return a, b"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 170,
   "metadata": {
    "tags": []
   },
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Epoch: 0 \n",
      "EPOCH 0: RMSE ON TRAINING DATA AND TEST DATA: 1.1483189037442207. 1.1797329393029212\n",
      "Epoch: 1 \n",
      "EPOCH 1: RMSE ON TRAINING DATA AND TEST DATA: 1.1710994287580252. 1.2020826146006585\n",
      "Epoch: 2 \n",
      "EPOCH 2: RMSE ON TRAINING DATA AND TEST DATA: 1.1955617877840996. 1.2255912278592587\n",
      "Epoch: 3 \n",
      "EPOCH 3: RMSE ON TRAINING DATA AND TEST DATA: 1.1465987780690192. 1.1786295545101166\n",
      "Epoch: 4 \n",
      "EPOCH 4: RMSE ON TRAINING DATA AND TEST DATA: 1.214436404928565. 1.2448888936638831\n",
      "Epoch: 5 \n",
      "EPOCH 5: RMSE ON TRAINING DATA AND TEST DATA: 1.1238364177942275. 1.1573218400776386\n",
      "Epoch: 6 \n",
      "EPOCH 6: RMSE ON TRAINING DATA AND TEST DATA: 1.1341331158950925. 1.1675885209441186\n",
      "Epoch: 7 \n",
      "EPOCH 7: RMSE ON TRAINING DATA AND TEST DATA: 1.2676864267140626. 1.2953204399347304\n",
      "Epoch: 8 \n",
      "EPOCH 8: RMSE ON TRAINING DATA AND TEST DATA: 1.1401097257435322. 1.1723342721164227\n",
      "Epoch: 9 \n",
      "EPOCH 9: RMSE ON TRAINING DATA AND TEST DATA: 1.13102034997195. 1.1643961435556411\n",
      "The final RMSE of training data and testing data are (1.13102034997195, 1.1643961435556411)\n"
     ]
    }
   ],
   "source": [
    "(a,b) = train2(train_data_iter, net2)\n",
    "print(\"The final RMSE of training data and testing data are\",(a,b))"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Amazon SageMaker Built in Algorithm \n",
    "## Factorization Machines for Recommendation System"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 175,
   "metadata": {
    "tags": []
   },
   "outputs": [],
   "source": [
    "import os\n",
    "import csv\n",
    "from urllib.parse import urlparse\n",
    "import boto3\n",
    "import numpy as np\n",
    "from scipy.sparse import lil_matrix\n",
    "\n",
    "BUCKET  = 'recommendationbuck'\n",
    "s3 = boto3.client('s3')"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 177,
   "metadata": {
    "tags": []
   },
   "outputs": [],
   "source": [
    "def download_file(s3_source, dest):\n",
    "    if not os.path.exists(dest):\n",
    "        os.makedirs(dest)\n",
    "    \n",
    "    url = urlparse(s3_source)\n",
    "    bucket,key = url.netloc, url.path.lstrip('/')\n",
    "    filename = key.split('/')[-1]\n",
    "    with open ('%s/%s' %(dest,filename), 'wb') as data:\n",
    "        s3.download_fileobj(bucket, key,data)\n",
    "    \n",
    "\n",
    "def loadDataset(filename, lines, columns):\n",
    "    X = lil_matrix((lines,columns)).astype('float32')\n",
    "    Y = []\n",
    "    line=0\n",
    "    with open(filename,'r') as f:\n",
    "        samples = csv.reader(f,delimiter='\\t')\n",
    "        for userId,movieId,rating,timestamp in samples:\n",
    "            X[line, int(userId)-1] = 1\n",
    "            X[line, int(nbUsers)+int(movieId)-1] = 1\n",
    "            Y.append(int(rating))\n",
    "            line = line+1\n",
    "    Y = np.array(Y).astype('float32')\n",
    "    return X,Y\n",
    "\n",
    "nbUsers = 943\n",
    "nbMovies = 1682\n",
    "nbFeatures = nbUsers+nbMovies\n",
    "nbRatingsTrain = 80000\n",
    "nbRatingsTest = 20000\n",
    "\n",
    "input_dir = 'ml-100k'\n",
    "X_train, Y_train = loadDataset('%s/u1.base' % input_dir, nbRatingsTrain, nbFeatures)\n",
    "X_test, Y_test = loadDataset('%s/u1.test' % input_dir, nbRatingsTest, nbFeatures)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 178,
   "metadata": {
    "tags": []
   },
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "<_io.BytesIO object at 0x7f447e8d9710>\n",
      "Wrote dataset: recommendationbuck/exercies4/fm-movielens100k/train/train.protobuf\n",
      "<_io.BytesIO object at 0x7f447e8d9110>\n",
      "Wrote dataset: recommendationbuck/exercies4/fm-movielens100k/test/test.protobuf\n",
      "Output: s3://recommendationbuck/exercies4/fm-movielens100k/output\n"
     ]
    }
   ],
   "source": [
    "prefix = 'exercies4/fm-movielens100k'\n",
    "train_key = 'train.protobuf'\n",
    "train_prefix = '{}/{}'.format(prefix,'train')\n",
    "test_key = 'test.protobuf'\n",
    "test_prefix = '{}/{}'.format(prefix,'test')\n",
    "output_prefix = 's3://{}/{}/output'.format(BUCKET, prefix)\n",
    "\n",
    "def writeDatasetToProtobuf(X,Y,bucket,prefix,key):\n",
    "    import io,boto3\n",
    "    import sagemaker.amazon.common as smac\n",
    "    buf = io.BytesIO()\n",
    "    smac.write_spmatrix_to_sparse_tensor(buf,X,Y)\n",
    "    buf.seek(0)\n",
    "    print(buf)\n",
    "    obj = '{}/{}' .format(prefix,key)\n",
    "    boto3.resource('s3').Bucket(bucket).Object(obj).upload_fileobj(buf)\n",
    "    print('Wrote dataset: {}/{}'.format(bucket,obj))\n",
    "\n",
    "writeDatasetToProtobuf(X_train,Y_train,BUCKET,train_prefix,train_key)\n",
    "writeDatasetToProtobuf(X_test,Y_test,BUCKET,test_prefix,test_key)\n",
    "print('Output: {}'.format(output_prefix))"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 182,
   "metadata": {
    "tags": []
   },
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "ap-south-1\n"
     ]
    }
   ],
   "source": [
    "import sagemaker\n",
    "from sagemaker import get_execution_role\n",
    "\n",
    "train_data = 's3://%s/exercies4/fm-movielens100k/train/train.protobuf' %BUCKET\n",
    "test_data = 's3://%s/exercies4/fm-movielens100k/test/test.protobuf' %BUCKET\n",
    "\n",
    "print(boto3.Session().region_name)\n",
    "region = boto3.Session.region_name"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 184,
   "metadata": {
    "tags": []
   },
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "WARNING:sagemaker.deprecations:train_instance_count has been renamed in sagemaker>=2.\n",
      "See: https://sagemaker.readthedocs.io/en/stable/v2.html for details.\n",
      "WARNING:sagemaker.deprecations:train_instance_type has been renamed in sagemaker>=2.\n",
      "See: https://sagemaker.readthedocs.io/en/stable/v2.html for details.\n",
      "INFO:sagemaker:Creating training-job with name: factorization-machines-2023-04-21-14-23-41-245\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "2023-04-21 14:23:41 Starting - Starting the training job...\n",
      "2023-04-21 14:23:58 Starting - Preparing the instances for training......\n",
      "2023-04-21 14:25:08 Downloading - Downloading input data\n",
      "2023-04-21 14:25:08 Training - Downloading the training image.........\n",
      "2023-04-21 14:26:34 Training - Training image download completed. Training in progress...\u001b[34mDocker entrypoint called with argument(s): train\u001b[0m\n",
      "\u001b[34mRunning default environment configuration script\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] Reading default configuration from /opt/amazon/lib/python3.7/site-packages/algorithm/resources/default-conf.json: {'epochs': 1, 'mini_batch_size': '1000', 'use_bias': 'true', 'use_linear': 'true', 'bias_lr': '0.1', 'linear_lr': '0.001', 'factors_lr': '0.0001', 'bias_wd': '0.01', 'linear_wd': '0.001', 'factors_wd': '0.00001', 'bias_init_method': 'normal', 'bias_init_sigma': '0.01', 'linear_init_method': 'normal', 'linear_init_sigma': '0.01', 'factors_init_method': 'normal', 'factors_init_sigma': '0.001', 'batch_metrics_publish_interval': '500', '_data_format': 'record', '_kvstore': 'auto', '_learning_rate': '1.0', '_log_level': 'info', '_num_gpus': 'auto', '_num_kv_servers': 'auto', '_optimizer': 'adam', '_tuning_objective_metric': '', '_use_full_symbolic': 'true', '_wd': '1.0'}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] Merging with provided configuration from /opt/ml/input/config/hyperparameters.json: {'epochs': '50', 'feature_dim': '2625', 'mini_batch_size': '1000', 'num_factors': '64', 'predictor_type': 'regressor'}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] Final configuration: {'epochs': '50', 'mini_batch_size': '1000', 'use_bias': 'true', 'use_linear': 'true', 'bias_lr': '0.1', 'linear_lr': '0.001', 'factors_lr': '0.0001', 'bias_wd': '0.01', 'linear_wd': '0.001', 'factors_wd': '0.00001', 'bias_init_method': 'normal', 'bias_init_sigma': '0.01', 'linear_init_method': 'normal', 'linear_init_sigma': '0.01', 'factors_init_method': 'normal', 'factors_init_sigma': '0.001', 'batch_metrics_publish_interval': '500', '_data_format': 'record', '_kvstore': 'auto', '_learning_rate': '1.0', '_log_level': 'info', '_num_gpus': 'auto', '_num_kv_servers': 'auto', '_optimizer': 'adam', '_tuning_objective_metric': '', '_use_full_symbolic': 'true', '_wd': '1.0', 'feature_dim': '2625', 'num_factors': '64', 'predictor_type': 'regressor'}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 WARNING 139893122135872] Loggers have already been setup.\u001b[0m\n",
      "\u001b[34mProcess 7 is a worker.\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] Using default worker.\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] Checkpoint loading and saving are disabled.\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:45.091] [tensorio] [warning] TensorIO is already initialized; ignoring the initialization routine.\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:45.096] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 0, \"duration\": 8, \"num_examples\": 1, \"num_bytes\": 64000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] nvidia-smi: took 0.034 seconds to run.\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] nvidia-smi identified 0 GPUs.\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] Number of GPUs being used: 0\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] [Sparse network] Building a sparse network.\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] Create Store: local\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087205.0878313, \"EndTime\": 1682087205.1340022, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"initialize.time\": {\"sum\": 39.68691825866699, \"count\": 1, \"min\": 39.68691825866699, \"max\": 39.68691825866699}}}\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087205.1341317, \"EndTime\": 1682087205.1341803, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"Meta\": \"init_train_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1000.0, \"count\": 1, \"min\": 1000, \"max\": 1000}, \"Total Batches Seen\": {\"sum\": 1.0, \"count\": 1, \"min\": 1, \"max\": 1}, \"Max Records Seen Between Resets\": {\"sum\": 1000.0, \"count\": 1, \"min\": 1000, \"max\": 1000}, \"Max Batches Seen Between Resets\": {\"sum\": 1.0, \"count\": 1, \"min\": 1, \"max\": 1}, \"Reset Count\": {\"sum\": 1.0, \"count\": 1, \"min\": 1, \"max\": 1}, \"Number of Records Since Last Reset\": {\"sum\": 0.0, \"count\": 1, \"min\": 0, \"max\": 0}, \"Number of Batches Since Last Reset\": {\"sum\": 0.0, \"count\": 1, \"min\": 0, \"max\": 0}}}\u001b[0m\n",
      "\u001b[34m[14:26:45] /opt/brazil-pkg-cache/packages/AIAlgorithmsMXNet/AIAlgorithmsMXNet-1.3.x_Cuda_11.1.x.190.0/AL2_x86_64/generic-flavor/src/src/kvstore/./kvstore_local.h:306: Warning: non-default weights detected during kvstore pull. This call has been ignored. Please make sure to use kv.row_sparse_pull() or module.prepare() with row_ids.\u001b[0m\n",
      "\u001b[34m[14:26:45] /opt/brazil-pkg-cache/packages/AIAlgorithmsMXNet/AIAlgorithmsMXNet-1.3.x_Cuda_11.1.x.190.0/AL2_x86_64/generic-flavor/src/src/kvstore/./kvstore_local.h:306: Warning: non-default weights detected during kvstore pull. This call has been ignored. Please make sure to use kv.row_sparse_pull() or module.prepare() with row_ids.\u001b[0m\n",
      "\u001b[34m[14:26:45] /opt/brazil-pkg-cache/packages/AIAlgorithmsMXNet/AIAlgorithmsMXNet-1.3.x_Cuda_11.1.x.190.0/AL2_x86_64/generic-flavor/src/src/operator/././../common/utils.h:450: Optimizer with lazy_update = True detected. Be aware that lazy update with row_sparse gradient is different from standard update, and may lead to different empirical results. See https://mxnet.incubator.apache.org/api/python/optimization/optimization.html for more details.\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=0, batch=0 train rmse <loss>=3.846082752497988\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=0, batch=0 train mse <loss>=14.7923525390625\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=0, batch=0 train absolute_loss <loss>=3.66441796875\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:45.482] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 2, \"duration\": 329, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=0, train rmse <loss>=1.8169458122088216\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=0, train mse <loss>=3.301292084503174\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=0, train absolute_loss <loss>=1.4409705154418946\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087205.1340775, \"EndTime\": 1682087205.4827774, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"epochs\": {\"sum\": 50.0, \"count\": 1, \"min\": 50, \"max\": 50}, \"update.time\": {\"sum\": 348.3448028564453, \"count\": 1, \"min\": 348.3448028564453, \"max\": 348.3448028564453}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #progress_metric: host=algo-1, completed 2.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087205.1344013, \"EndTime\": 1682087205.4830143, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 0, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 81000.0, \"count\": 1, \"min\": 81000, \"max\": 81000}, \"Total Batches Seen\": {\"sum\": 81.0, \"count\": 1, \"min\": 81, \"max\": 81}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 2.0, \"count\": 1, \"min\": 2, \"max\": 2}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=229405.34775444906 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=1, batch=0 train rmse <loss>=1.1701337584632419\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=1, batch=0 train mse <loss>=1.3692130126953126\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=1, batch=0 train absolute_loss <loss>=0.9895603637695313\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:45.821] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 4, \"duration\": 335, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=1, train rmse <loss>=1.1112681212519286\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=1, train mse <loss>=1.234916837310791\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=1, train absolute_loss <loss>=0.9350776443481446\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087205.482863, \"EndTime\": 1682087205.8216903, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 338.411808013916, \"count\": 1, \"min\": 338.411808013916, \"max\": 338.411808013916}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #progress_metric: host=algo-1, completed 4.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087205.4832506, \"EndTime\": 1682087205.8219507, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 1, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 161000.0, \"count\": 1, \"min\": 161000, \"max\": 161000}, \"Total Batches Seen\": {\"sum\": 161.0, \"count\": 1, \"min\": 161, \"max\": 161}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 3.0, \"count\": 1, \"min\": 3, \"max\": 3}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=236099.79475048147 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=2, batch=0 train rmse <loss>=1.1695984136526305\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=2, batch=0 train mse <loss>=1.36796044921875\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:45 INFO 139893122135872] #quality_metric: host=algo-1, epoch=2, batch=0 train absolute_loss <loss>=0.9952677001953125\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:46.172] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 6, \"duration\": 348, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=2, train rmse <loss>=1.1039864427038169\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=2, train mse <loss>=1.218786065673828\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=2, train absolute_loss <loss>=0.928227963256836\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087205.8217735, \"EndTime\": 1682087206.1738424, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 351.48024559020996, \"count\": 1, \"min\": 351.48024559020996, \"max\": 351.48024559020996}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #progress_metric: host=algo-1, completed 6.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087205.8222375, \"EndTime\": 1682087206.1744087, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 2, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 241000.0, \"count\": 1, \"min\": 241000, \"max\": 241000}, \"Total Batches Seen\": {\"sum\": 241.0, \"count\": 1, \"min\": 241, \"max\": 241}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 4.0, \"count\": 1, \"min\": 4, \"max\": 4}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=227063.41236306942 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=3, batch=0 train rmse <loss>=1.1591912021595328\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=3, batch=0 train mse <loss>=1.3437242431640626\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=3, batch=0 train absolute_loss <loss>=0.9844362182617188\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:46.543] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 8, \"duration\": 365, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=3, train rmse <loss>=1.0961224350170047\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=3, train mse <loss>=1.2014843925476075\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=3, train absolute_loss <loss>=0.9204639587402343\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087206.1740735, \"EndTime\": 1682087206.544173, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 369.3554401397705, \"count\": 1, \"min\": 369.3554401397705, \"max\": 369.3554401397705}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #progress_metric: host=algo-1, completed 8.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087206.1747875, \"EndTime\": 1682087206.5444584, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 3, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 321000.0, \"count\": 1, \"min\": 321000, \"max\": 321000}, \"Total Batches Seen\": {\"sum\": 321.0, \"count\": 1, \"min\": 321, \"max\": 321}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 5.0, \"count\": 1, \"min\": 5, \"max\": 5}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=216344.5374900385 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=4, batch=0 train rmse <loss>=1.1489240572195416\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=4, batch=0 train mse <loss>=1.3200264892578124\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=4, batch=0 train absolute_loss <loss>=0.9734102783203125\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:46.895] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 10, \"duration\": 348, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=4, train rmse <loss>=1.0883975717962588\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=4, train mse <loss>=1.1846092742919923\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=4, train absolute_loss <loss>=0.9126331817626954\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087206.5442417, \"EndTime\": 1682087206.8964784, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 351.7160415649414, \"count\": 1, \"min\": 351.7160415649414, \"max\": 351.7160415649414}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #progress_metric: host=algo-1, completed 10.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087206.5447285, \"EndTime\": 1682087206.8967516, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 4, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 401000.0, \"count\": 1, \"min\": 401000, \"max\": 401000}, \"Total Batches Seen\": {\"sum\": 401.0, \"count\": 1, \"min\": 401, \"max\": 401}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 6.0, \"count\": 1, \"min\": 6, \"max\": 6}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=227165.3308220945 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=5, batch=0 train rmse <loss>=1.1392222753168606\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=5, batch=0 train mse <loss>=1.297827392578125\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:46 INFO 139893122135872] #quality_metric: host=algo-1, epoch=5, batch=0 train absolute_loss <loss>=0.9627130126953125\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:47.265] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 12, \"duration\": 365, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #quality_metric: host=algo-1, epoch=5, train rmse <loss>=1.0809860302413277\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #quality_metric: host=algo-1, epoch=5, train mse <loss>=1.1685307975769044\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #quality_metric: host=algo-1, epoch=5, train absolute_loss <loss>=0.9048709083557129\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087206.8965647, \"EndTime\": 1682087207.266437, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 369.34971809387207, \"count\": 1, \"min\": 369.34971809387207, \"max\": 369.34971809387207}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #progress_metric: host=algo-1, completed 12.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087206.8970542, \"EndTime\": 1682087207.266725, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 5, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 481000.0, \"count\": 1, \"min\": 481000, \"max\": 481000}, \"Total Batches Seen\": {\"sum\": 481.0, \"count\": 1, \"min\": 481, \"max\": 481}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 7.0, \"count\": 1, \"min\": 7, \"max\": 7}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=216322.91875520186 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #quality_metric: host=algo-1, epoch=6, batch=0 train rmse <loss>=1.1300982569283522\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #quality_metric: host=algo-1, epoch=6, batch=0 train mse <loss>=1.2771220703125\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #quality_metric: host=algo-1, epoch=6, batch=0 train absolute_loss <loss>=0.9523208618164063\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:47.677] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 14, \"duration\": 405, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #quality_metric: host=algo-1, epoch=6, train rmse <loss>=1.0739550382981071\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #quality_metric: host=algo-1, epoch=6, train mse <loss>=1.1533794242858886\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #quality_metric: host=algo-1, epoch=6, train absolute_loss <loss>=0.8972570831298828\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087207.2665308, \"EndTime\": 1682087207.6787267, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 411.6518497467041, \"count\": 1, \"min\": 411.6518497467041, \"max\": 411.6518497467041}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #progress_metric: host=algo-1, completed 14.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087207.2670424, \"EndTime\": 1682087207.6790855, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 6, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 561000.0, \"count\": 1, \"min\": 561000, \"max\": 561000}, \"Total Batches Seen\": {\"sum\": 561.0, \"count\": 1, \"min\": 561, \"max\": 561}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 8.0, \"count\": 1, \"min\": 8, \"max\": 8}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=194087.7403651491 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #quality_metric: host=algo-1, epoch=7, batch=0 train rmse <loss>=1.1215530962269464\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #quality_metric: host=algo-1, epoch=7, batch=0 train mse <loss>=1.25788134765625\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:47 INFO 139893122135872] #quality_metric: host=algo-1, epoch=7, batch=0 train absolute_loss <loss>=0.9422288208007813\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:48.099] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 16, \"duration\": 417, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=7, train rmse <loss>=1.0673229243977984\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=7, train mse <loss>=1.1391782249450684\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=7, train absolute_loss <loss>=0.8898450866699219\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087207.678861, \"EndTime\": 1682087208.1009014, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 421.24414443969727, \"count\": 1, \"min\": 421.24414443969727, \"max\": 421.24414443969727}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #progress_metric: host=algo-1, completed 16.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087207.6796253, \"EndTime\": 1682087208.1013048, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 7, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 641000.0, \"count\": 1, \"min\": 641000, \"max\": 641000}, \"Total Batches Seen\": {\"sum\": 641.0, \"count\": 1, \"min\": 641, \"max\": 641}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 9.0, \"count\": 1, \"min\": 9, \"max\": 9}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=189628.77229468545 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=8, batch=0 train rmse <loss>=1.1135911301182877\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=8, batch=0 train mse <loss>=1.240085205078125\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=8, batch=0 train absolute_loss <loss>=0.9324667358398437\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:48.494] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 18, \"duration\": 390, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=8, train rmse <loss>=1.0610827371910236\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=8, train mse <loss>=1.125896575164795\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=8, train absolute_loss <loss>=0.8826699928283691\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087208.1010332, \"EndTime\": 1682087208.4956818, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 393.79191398620605, \"count\": 1, \"min\": 393.79191398620605, \"max\": 393.79191398620605}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #progress_metric: host=algo-1, completed 18.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087208.1018617, \"EndTime\": 1682087208.495923, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 8, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 721000.0, \"count\": 1, \"min\": 721000, \"max\": 721000}, \"Total Batches Seen\": {\"sum\": 721.0, \"count\": 1, \"min\": 721, \"max\": 721}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 10.0, \"count\": 1, \"min\": 10, \"max\": 10}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=202943.2378325743 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=9, batch=0 train rmse <loss>=1.1062138610799055\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=9, batch=0 train mse <loss>=1.2237091064453125\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=9, batch=0 train absolute_loss <loss>=0.923087158203125\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:48.800] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 20, \"duration\": 301, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=9, train rmse <loss>=1.0552151826646896\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=9, train mse <loss>=1.1134790817260742\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=9, train absolute_loss <loss>=0.875757551574707\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087208.4957514, \"EndTime\": 1682087208.801389, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 304.9759864807129, \"count\": 1, \"min\": 304.9759864807129, \"max\": 304.9759864807129}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #progress_metric: host=algo-1, completed 20.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087208.4963863, \"EndTime\": 1682087208.8016603, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 9, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 801000.0, \"count\": 1, \"min\": 801000, \"max\": 801000}, \"Total Batches Seen\": {\"sum\": 801.0, \"count\": 1, \"min\": 801, \"max\": 801}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 11.0, \"count\": 1, \"min\": 11, \"max\": 11}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=261962.2636795723 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=10, batch=0 train rmse <loss>=1.0994129625871651\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=10, batch=0 train mse <loss>=1.2087088623046875\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:48 INFO 139893122135872] #quality_metric: host=algo-1, epoch=10, batch=0 train absolute_loss <loss>=0.9141504516601563\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:49.117] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 22, \"duration\": 313, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=10, train rmse <loss>=1.0496956095221825\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=10, train mse <loss>=1.1018608726501464\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=10, train absolute_loss <loss>=0.8691340446472168\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087208.8014846, \"EndTime\": 1682087209.1184394, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 316.2662982940674, \"count\": 1, \"min\": 316.2662982940674, \"max\": 316.2662982940674}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #progress_metric: host=algo-1, completed 22.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087208.8021467, \"EndTime\": 1682087209.1186478, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 10, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 881000.0, \"count\": 1, \"min\": 881000, \"max\": 881000}, \"Total Batches Seen\": {\"sum\": 881.0, \"count\": 1, \"min\": 881, \"max\": 881}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 12.0, \"count\": 1, \"min\": 12, \"max\": 12}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=252680.33194270826 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=11, batch=0 train rmse <loss>=1.093166250472395\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=11, batch=0 train mse <loss>=1.195012451171875\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=11, batch=0 train absolute_loss <loss>=0.905710205078125\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:49.427] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 24, \"duration\": 306, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=11, train rmse <loss>=1.0444976566593367\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=11, train mse <loss>=1.0909753547668457\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=11, train absolute_loss <loss>=0.8628247802734375\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087209.1185088, \"EndTime\": 1682087209.4279594, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 308.8042736053467, \"count\": 1, \"min\": 308.8042736053467, \"max\": 308.8042736053467}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #progress_metric: host=algo-1, completed 24.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087209.1191268, \"EndTime\": 1682087209.4281704, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 11, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 961000.0, \"count\": 1, \"min\": 961000, \"max\": 961000}, \"Total Batches Seen\": {\"sum\": 961.0, \"count\": 1, \"min\": 961, \"max\": 961}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 13.0, \"count\": 1, \"min\": 13, \"max\": 13}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=258768.28683317165 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=12, batch=0 train rmse <loss>=1.0874373634978935\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=12, batch=0 train mse <loss>=1.18252001953125\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=12, batch=0 train absolute_loss <loss>=0.8978036499023437\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:49.748] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 26, \"duration\": 318, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=12, train rmse <loss>=1.039594987354178\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=12, train mse <loss>=1.0807577377319335\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=12, train absolute_loss <loss>=0.8568561576843262\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087209.4280286, \"EndTime\": 1682087209.7495809, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 320.925235748291, \"count\": 1, \"min\": 320.925235748291, \"max\": 320.925235748291}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #progress_metric: host=algo-1, completed 26.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087209.428628, \"EndTime\": 1682087209.7497954, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 12, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1041000.0, \"count\": 1, \"min\": 1041000, \"max\": 1041000}, \"Total Batches Seen\": {\"sum\": 1041.0, \"count\": 1, \"min\": 1041, \"max\": 1041}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 14.0, \"count\": 1, \"min\": 14, \"max\": 14}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=249001.76467357992 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=13, batch=0 train rmse <loss>=1.0821794235188082\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=13, batch=0 train mse <loss>=1.1711123046875\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:49 INFO 139893122135872] #quality_metric: host=algo-1, epoch=13, batch=0 train absolute_loss <loss>=0.8905328369140625\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:50.099] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 28, \"duration\": 347, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=13, train rmse <loss>=1.0349620222412461\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=13, train mse <loss>=1.0711463874816896\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=13, train absolute_loss <loss>=0.8512454933166503\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087209.7496498, \"EndTime\": 1682087210.100822, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 350.5139350891113, \"count\": 1, \"min\": 350.5139350891113, \"max\": 350.5139350891113}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #progress_metric: host=algo-1, completed 28.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087209.750276, \"EndTime\": 1682087210.1010857, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 13, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1121000.0, \"count\": 1, \"min\": 1121000, \"max\": 1121000}, \"Total Batches Seen\": {\"sum\": 1121.0, \"count\": 1, \"min\": 1121, \"max\": 1121}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 15.0, \"count\": 1, \"min\": 15, \"max\": 15}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=227956.10505384285 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=14, batch=0 train rmse <loss>=1.0773404074458663\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=14, batch=0 train mse <loss>=1.160662353515625\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=14, batch=0 train absolute_loss <loss>=0.8840455932617187\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:50.420] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 30, \"duration\": 315, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=14, train rmse <loss>=1.0305742314906525\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=14, train mse <loss>=1.062083246612549\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=14, train absolute_loss <loss>=0.8459917427062988\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087210.100906, \"EndTime\": 1682087210.4208412, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 319.17500495910645, \"count\": 1, \"min\": 319.17500495910645, \"max\": 319.17500495910645}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #progress_metric: host=algo-1, completed 30.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087210.1016352, \"EndTime\": 1682087210.421129, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 14, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1201000.0, \"count\": 1, \"min\": 1201000, \"max\": 1201000}, \"Total Batches Seen\": {\"sum\": 1201.0, \"count\": 1, \"min\": 1201, \"max\": 1201}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 16.0, \"count\": 1, \"min\": 16, \"max\": 16}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=250286.1089790496 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=15, batch=0 train rmse <loss>=1.0728680713104943\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=15, batch=0 train mse <loss>=1.1510458984375\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=15, batch=0 train absolute_loss <loss>=0.8782387084960938\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:50.751] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 32, \"duration\": 327, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=15, train rmse <loss>=1.0264083610021677\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=15, train mse <loss>=1.0535141235351562\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=15, train absolute_loss <loss>=0.8410938674926758\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087210.4209323, \"EndTime\": 1682087210.7520478, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 330.3942680358887, \"count\": 1, \"min\": 330.3942680358887, \"max\": 330.3942680358887}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #progress_metric: host=algo-1, completed 32.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087210.4216251, \"EndTime\": 1682087210.7523057, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 15, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1281000.0, \"count\": 1, \"min\": 1281000, \"max\": 1281000}, \"Total Batches Seen\": {\"sum\": 1281.0, \"count\": 1, \"min\": 1281, \"max\": 1281}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 17.0, \"count\": 1, \"min\": 17, \"max\": 17}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=241822.0669704598 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=16, batch=0 train rmse <loss>=1.0687135638891392\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=16, batch=0 train mse <loss>=1.142148681640625\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:50 INFO 139893122135872] #quality_metric: host=algo-1, epoch=16, batch=0 train absolute_loss <loss>=0.87298974609375\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:51.062] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 34, \"duration\": 307, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=16, train rmse <loss>=1.0224426167621992\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=16, train mse <loss>=1.0453889045715332\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=16, train absolute_loss <loss>=0.836504931640625\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087210.7521265, \"EndTime\": 1682087211.0631049, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 310.29200553894043, \"count\": 1, \"min\": 310.29200553894043, \"max\": 310.29200553894043}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #progress_metric: host=algo-1, completed 34.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087210.752783, \"EndTime\": 1682087211.0633664, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 16, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1361000.0, \"count\": 1, \"min\": 1361000, \"max\": 1361000}, \"Total Batches Seen\": {\"sum\": 1361.0, \"count\": 1, \"min\": 1361, \"max\": 1361}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 18.0, \"count\": 1, \"min\": 18, \"max\": 18}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=257472.87875741816 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=17, batch=0 train rmse <loss>=1.0648333179973228\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=17, batch=0 train mse <loss>=1.1338699951171876\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=17, batch=0 train absolute_loss <loss>=0.868235107421875\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:51.380] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 36, \"duration\": 314, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=17, train rmse <loss>=1.0186568594638548\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=17, train mse <loss>=1.0376617973327638\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=17, train absolute_loss <loss>=0.8322137336730957\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087211.0631871, \"EndTime\": 1682087211.3815544, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 317.67821311950684, \"count\": 1, \"min\": 317.67821311950684, \"max\": 317.67821311950684}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #progress_metric: host=algo-1, completed 36.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087211.0638502, \"EndTime\": 1682087211.3817654, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 17, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1441000.0, \"count\": 1, \"min\": 1441000, \"max\": 1441000}, \"Total Batches Seen\": {\"sum\": 1441.0, \"count\": 1, \"min\": 1441, \"max\": 1441}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 19.0, \"count\": 1, \"min\": 19, \"max\": 19}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=251554.53664226923 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=18, batch=0 train rmse <loss>=1.0611896216444718\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=18, batch=0 train mse <loss>=1.1261234130859374\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=18, batch=0 train absolute_loss <loss>=0.8638764038085938\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:51.694] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 38, \"duration\": 310, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=18, train rmse <loss>=1.015032757385531\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=18, train mse <loss>=1.030291498565674\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=18, train absolute_loss <loss>=0.8281947677612305\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087211.3816218, \"EndTime\": 1682087211.69537, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 313.11798095703125, \"count\": 1, \"min\": 313.11798095703125, \"max\": 313.11798095703125}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #progress_metric: host=algo-1, completed 38.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087211.3822205, \"EndTime\": 1682087211.6956341, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 18, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1521000.0, \"count\": 1, \"min\": 1521000, \"max\": 1521000}, \"Total Batches Seen\": {\"sum\": 1521.0, \"count\": 1, \"min\": 1521, \"max\": 1521}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 20.0, \"count\": 1, \"min\": 20, \"max\": 20}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=255151.06674037568 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=19, batch=0 train rmse <loss>=1.057750125099703\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=19, batch=0 train mse <loss>=1.1188353271484375\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:51 INFO 139893122135872] #quality_metric: host=algo-1, epoch=19, batch=0 train absolute_loss <loss>=0.859832763671875\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:52.020] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 40, \"duration\": 321, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=19, train rmse <loss>=1.0115538856533162\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=19, train mse <loss>=1.0232412635803223\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=19, train absolute_loss <loss>=0.8244191719055176\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087211.695474, \"EndTime\": 1682087212.0211687, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 325.01983642578125, \"count\": 1, \"min\": 325.01983642578125, \"max\": 325.01983642578125}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #progress_metric: host=algo-1, completed 40.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087211.696122, \"EndTime\": 1682087212.021445, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 19, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1601000.0, \"count\": 1, \"min\": 1601000, \"max\": 1601000}, \"Total Batches Seen\": {\"sum\": 1601.0, \"count\": 1, \"min\": 1601, \"max\": 1601}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 21.0, \"count\": 1, \"min\": 21, \"max\": 21}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=245812.2711152689 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=20, batch=0 train rmse <loss>=1.0544874810334401\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=20, batch=0 train mse <loss>=1.11194384765625\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=20, batch=0 train absolute_loss <loss>=0.8560760498046875\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:52.337] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 42, \"duration\": 313, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=20, train rmse <loss>=1.0082056891827378\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=20, train mse <loss>=1.0164787117004395\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=20, train absolute_loss <loss>=0.8208538505554199\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087212.0212462, \"EndTime\": 1682087212.3382452, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 316.48945808410645, \"count\": 1, \"min\": 316.48945808410645, \"max\": 316.48945808410645}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #progress_metric: host=algo-1, completed 42.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087212.0217226, \"EndTime\": 1682087212.3385363, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 20, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1681000.0, \"count\": 1, \"min\": 1681000, \"max\": 1681000}, \"Total Batches Seen\": {\"sum\": 1681.0, \"count\": 1, \"min\": 1681, \"max\": 1681}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 22.0, \"count\": 1, \"min\": 22, \"max\": 22}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=252397.1326057032 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=21, batch=0 train rmse <loss>=1.0513787218680408\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=21, batch=0 train mse <loss>=1.105397216796875\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=21, batch=0 train absolute_loss <loss>=0.8526008911132813\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:52.652] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 44, \"duration\": 311, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=21, train rmse <loss>=1.0049754899865133\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=21, train mse <loss>=1.0099757354736327\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=21, train absolute_loss <loss>=0.8174701736450195\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087212.33834, \"EndTime\": 1682087212.6535478, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 314.65840339660645, \"count\": 1, \"min\": 314.65840339660645, \"max\": 314.65840339660645}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #progress_metric: host=algo-1, completed 44.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087212.3388596, \"EndTime\": 1682087212.6537483, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 21, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1761000.0, \"count\": 1, \"min\": 1761000, \"max\": 1761000}, \"Total Batches Seen\": {\"sum\": 1761.0, \"count\": 1, \"min\": 1761, \"max\": 1761}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 23.0, \"count\": 1, \"min\": 23, \"max\": 23}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=253964.17118330157 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=22, batch=0 train rmse <loss>=1.0484043167252437\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=22, batch=0 train mse <loss>=1.099151611328125\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=22, batch=0 train absolute_loss <loss>=0.8493021850585938\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:52.969] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 46, \"duration\": 313, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=22, train rmse <loss>=1.0018523013660454\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=22, train mse <loss>=1.0037080337524413\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=22, train absolute_loss <loss>=0.8142483840942383\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087212.6536155, \"EndTime\": 1682087212.970437, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 316.43152236938477, \"count\": 1, \"min\": 316.43152236938477, \"max\": 316.43152236938477}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #progress_metric: host=algo-1, completed 46.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087212.653973, \"EndTime\": 1682087212.970657, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 22, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1841000.0, \"count\": 1, \"min\": 1841000, \"max\": 1841000}, \"Total Batches Seen\": {\"sum\": 1841.0, \"count\": 1, \"min\": 1841, \"max\": 1841}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 24.0, \"count\": 1, \"min\": 24, \"max\": 24}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=252514.5167262186 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=23, batch=0 train rmse <loss>=1.045547724374795\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=23, batch=0 train mse <loss>=1.0931700439453125\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:52 INFO 139893122135872] #quality_metric: host=algo-1, epoch=23, batch=0 train absolute_loss <loss>=0.8462221069335938\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:53.294] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 48, \"duration\": 320, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=23, train rmse <loss>=0.9988267332924406\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=23, train mse <loss>=0.9976548431396485\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=23, train absolute_loss <loss>=0.8111617004394531\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087212.9705076, \"EndTime\": 1682087213.2952726, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 324.2940902709961, \"count\": 1, \"min\": 324.2940902709961, \"max\": 324.2940902709961}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #progress_metric: host=algo-1, completed 48.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087212.9709456, \"EndTime\": 1682087213.2955291, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 23, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 1921000.0, \"count\": 1, \"min\": 1921000, \"max\": 1921000}, \"Total Batches Seen\": {\"sum\": 1921.0, \"count\": 1, \"min\": 1921, \"max\": 1921}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 25.0, \"count\": 1, \"min\": 25, \"max\": 25}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=246364.90523729773 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=24, batch=0 train rmse <loss>=1.0427950463964923\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=24, batch=0 train mse <loss>=1.0874215087890624\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=24, batch=0 train absolute_loss <loss>=0.8433500366210938\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:53.602] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 50, \"duration\": 304, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=24, train rmse <loss>=0.9958908080642748\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=24, train mse <loss>=0.9917985015869141\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=24, train absolute_loss <loss>=0.808202611541748\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087213.2953448, \"EndTime\": 1682087213.6030362, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 307.2013854980469, \"count\": 1, \"min\": 307.2013854980469, \"max\": 307.2013854980469}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #progress_metric: host=algo-1, completed 50.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087213.295805, \"EndTime\": 1682087213.6033325, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 24, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2001000.0, \"count\": 1, \"min\": 2001000, \"max\": 2001000}, \"Total Batches Seen\": {\"sum\": 2001.0, \"count\": 1, \"min\": 2001, \"max\": 2001}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 26.0, \"count\": 1, \"min\": 26, \"max\": 26}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=260003.84336430754 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=25, batch=0 train rmse <loss>=1.0401344916606639\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=25, batch=0 train mse <loss>=1.0818797607421875\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=25, batch=0 train absolute_loss <loss>=0.8405986938476563\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:53.921] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 52, \"duration\": 315, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=25, train rmse <loss>=0.9930377758174356\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=25, train mse <loss>=0.9861240242004394\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=25, train absolute_loss <loss>=0.8053568191528321\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087213.6031535, \"EndTime\": 1682087213.9222445, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 318.5923099517822, \"count\": 1, \"min\": 318.5923099517822, \"max\": 318.5923099517822}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #progress_metric: host=algo-1, completed 52.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087213.603621, \"EndTime\": 1682087213.9225025, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 25, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2081000.0, \"count\": 1, \"min\": 2081000, \"max\": 2081000}, \"Total Batches Seen\": {\"sum\": 2081.0, \"count\": 1, \"min\": 2081, \"max\": 2081}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 27.0, \"count\": 1, \"min\": 27, \"max\": 27}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=250762.70369443126 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=26, batch=0 train rmse <loss>=1.0375560625854452\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=26, batch=0 train mse <loss>=1.0765225830078125\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:53 INFO 139893122135872] #quality_metric: host=algo-1, epoch=26, batch=0 train absolute_loss <loss>=0.8379243774414062\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:54.234] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 54, \"duration\": 308, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=26, train rmse <loss>=0.9902619730036097\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=26, train mse <loss>=0.9806187751770019\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=26, train absolute_loss <loss>=0.8026090309143067\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087213.922329, \"EndTime\": 1682087214.2352371, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 312.41583824157715, \"count\": 1, \"min\": 312.41583824157715, \"max\": 312.41583824157715}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #progress_metric: host=algo-1, completed 54.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087213.9227953, \"EndTime\": 1682087214.235739, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 26, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2161000.0, \"count\": 1, \"min\": 2161000, \"max\": 2161000}, \"Total Batches Seen\": {\"sum\": 2161.0, \"count\": 1, \"min\": 2161, \"max\": 2161}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 28.0, \"count\": 1, \"min\": 28, \"max\": 28}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=255532.10673815035 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=27, batch=0 train rmse <loss>=1.0350514687534866\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=27, batch=0 train mse <loss>=1.07133154296875\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=27, batch=0 train absolute_loss <loss>=0.8353858032226562\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:54.565] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 56, \"duration\": 326, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=27, train rmse <loss>=0.9875586777649258\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=27, train mse <loss>=0.9752721420288086\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=27, train absolute_loss <loss>=0.7999495071411132\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087214.2353163, \"EndTime\": 1682087214.5659454, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 329.82826232910156, \"count\": 1, \"min\": 329.82826232910156, \"max\": 329.82826232910156}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #progress_metric: host=algo-1, completed 56.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087214.2360876, \"EndTime\": 1682087214.5661502, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 27, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2241000.0, \"count\": 1, \"min\": 2241000, \"max\": 2241000}, \"Total Batches Seen\": {\"sum\": 2241.0, \"count\": 1, \"min\": 2241, \"max\": 2241}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 29.0, \"count\": 1, \"min\": 29, \"max\": 29}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=242294.75903701456 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=28, batch=0 train rmse <loss>=1.0326136225881817\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=28, batch=0 train mse <loss>=1.0662908935546875\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=28, batch=0 train absolute_loss <loss>=0.8329559936523437\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:54.890] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 58, \"duration\": 321, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=28, train rmse <loss>=0.984923928900824\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=28, train mse <loss>=0.9700751457214355\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=28, train absolute_loss <loss>=0.7973751663208007\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087214.5660138, \"EndTime\": 1682087214.8907576, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 324.35059547424316, \"count\": 1, \"min\": 324.35059547424316, \"max\": 324.35059547424316}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #progress_metric: host=algo-1, completed 58.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087214.5663798, \"EndTime\": 1682087214.8909655, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 28, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2321000.0, \"count\": 1, \"min\": 2321000, \"max\": 2321000}, \"Total Batches Seen\": {\"sum\": 2321.0, \"count\": 1, \"min\": 2321, \"max\": 2321}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 30.0, \"count\": 1, \"min\": 30, \"max\": 30}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=246379.19615361458 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=29, batch=0 train rmse <loss>=1.030236718095652\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=29, batch=0 train mse <loss>=1.0613876953125\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:54 INFO 139893122135872] #quality_metric: host=algo-1, epoch=29, batch=0 train absolute_loss <loss>=0.8306128540039063\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:55.195] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 60, \"duration\": 301, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=29, train rmse <loss>=0.9823544040573639\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=29, train mse <loss>=0.9650201751708984\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=29, train absolute_loss <loss>=0.7948818748474121\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087214.8908262, \"EndTime\": 1682087215.1958718, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 304.62074279785156, \"count\": 1, \"min\": 304.62074279785156, \"max\": 304.62074279785156}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #progress_metric: host=algo-1, completed 60.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087214.8912237, \"EndTime\": 1682087215.196069, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 29, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2401000.0, \"count\": 1, \"min\": 2401000, \"max\": 2401000}, \"Total Batches Seen\": {\"sum\": 2401.0, \"count\": 1, \"min\": 2401, \"max\": 2401}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 31.0, \"count\": 1, \"min\": 31, \"max\": 31}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=262333.5769990032 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=30, batch=0 train rmse <loss>=1.0279158340613606\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=30, batch=0 train mse <loss>=1.0566109619140625\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=30, batch=0 train absolute_loss <loss>=0.8283232421875\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:55.513] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 62, \"duration\": 315, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=30, train rmse <loss>=0.9798472795406152\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=30, train mse <loss>=0.9601006912231446\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=30, train absolute_loss <loss>=0.792461498260498\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087215.1959367, \"EndTime\": 1682087215.5141726, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 317.8389072418213, \"count\": 1, \"min\": 317.8389072418213, \"max\": 317.8389072418213}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #progress_metric: host=algo-1, completed 62.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087215.1963022, \"EndTime\": 1682087215.514452, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 30, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2481000.0, \"count\": 1, \"min\": 2481000, \"max\": 2481000}, \"Total Batches Seen\": {\"sum\": 2481.0, \"count\": 1, \"min\": 2481, \"max\": 2481}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 32.0, \"count\": 1, \"min\": 32, \"max\": 32}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=251344.05992509364 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=31, batch=0 train rmse <loss>=1.025647006638523\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=31, batch=0 train mse <loss>=1.0519517822265625\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=31, batch=0 train absolute_loss <loss>=0.826072265625\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:55.843] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 64, \"duration\": 327, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=31, train rmse <loss>=0.977400139588404\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=31, train mse <loss>=0.9553110328674317\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=31, train absolute_loss <loss>=0.7901077491760254\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087215.5142622, \"EndTime\": 1682087215.8446279, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 329.8470973968506, \"count\": 1, \"min\": 329.8470973968506, \"max\": 329.8470973968506}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #progress_metric: host=algo-1, completed 64.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087215.514751, \"EndTime\": 1682087215.844901, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 31, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2561000.0, \"count\": 1, \"min\": 2561000, \"max\": 2561000}, \"Total Batches Seen\": {\"sum\": 2561.0, \"count\": 1, \"min\": 2561, \"max\": 2561}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 33.0, \"count\": 1, \"min\": 33, \"max\": 33}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=242208.01007105754 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=32, batch=0 train rmse <loss>=1.023426944124952\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=32, batch=0 train mse <loss>=1.0474027099609375\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:55 INFO 139893122135872] #quality_metric: host=algo-1, epoch=32, batch=0 train absolute_loss <loss>=0.8238901977539063\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:56.162] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 66, \"duration\": 314, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=32, train rmse <loss>=0.9750108512861446\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=32, train mse <loss>=0.9506461601257324\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=32, train absolute_loss <loss>=0.7878163444519043\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087215.8447146, \"EndTime\": 1682087216.163013, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 317.7685737609863, \"count\": 1, \"min\": 317.7685737609863, \"max\": 317.7685737609863}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #progress_metric: host=algo-1, completed 66.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087215.8452117, \"EndTime\": 1682087216.163276, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 32, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2641000.0, \"count\": 1, \"min\": 2641000, \"max\": 2641000}, \"Total Batches Seen\": {\"sum\": 2641.0, \"count\": 1, \"min\": 2641, \"max\": 2641}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 34.0, \"count\": 1, \"min\": 34, \"max\": 34}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=251404.88672540247 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=33, batch=0 train rmse <loss>=1.0212530360649485\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=33, batch=0 train mse <loss>=1.042957763671875\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=33, batch=0 train absolute_loss <loss>=0.8217366333007813\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:56.479] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 68, \"duration\": 313, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=33, train rmse <loss>=0.9726775184358922\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=33, train mse <loss>=0.9461015548706054\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=33, train absolute_loss <loss>=0.7855838562011719\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087216.163099, \"EndTime\": 1682087216.480178, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 316.47419929504395, \"count\": 1, \"min\": 316.47419929504395, \"max\": 316.47419929504395}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #progress_metric: host=algo-1, completed 68.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087216.1636753, \"EndTime\": 1682087216.4803848, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 33, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2721000.0, \"count\": 1, \"min\": 2721000, \"max\": 2721000}, \"Total Batches Seen\": {\"sum\": 2721.0, \"count\": 1, \"min\": 2721, \"max\": 2721}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 35.0, \"count\": 1, \"min\": 35, \"max\": 35}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=252509.57603560403 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=34, batch=0 train rmse <loss>=1.0191231223343735\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=34, batch=0 train mse <loss>=1.0386119384765624\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=34, batch=0 train absolute_loss <loss>=0.8196526489257813\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:56.786] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 70, \"duration\": 303, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=34, train rmse <loss>=0.9703983794460618\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=34, train mse <loss>=0.941673014831543\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=34, train absolute_loss <loss>=0.7834087715148926\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087216.4802463, \"EndTime\": 1682087216.787056, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 306.42199516296387, \"count\": 1, \"min\": 306.42199516296387, \"max\": 306.42199516296387}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #progress_metric: host=algo-1, completed 70.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087216.4806068, \"EndTime\": 1682087216.7872581, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 34, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2801000.0, \"count\": 1, \"min\": 2801000, \"max\": 2801000}, \"Total Batches Seen\": {\"sum\": 2801.0, \"count\": 1, \"min\": 2801, \"max\": 2801}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 36.0, \"count\": 1, \"min\": 36, \"max\": 36}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=260789.72709686495 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=35, batch=0 train rmse <loss>=1.0170353188772503\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=35, batch=0 train mse <loss>=1.03436083984375\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:56 INFO 139893122135872] #quality_metric: host=algo-1, epoch=35, batch=0 train absolute_loss <loss>=0.817614013671875\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:57.098] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 72, \"duration\": 309, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=35, train rmse <loss>=0.9681717831640664\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=35, train mse <loss>=0.937356601715088\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=35, train absolute_loss <loss>=0.7812871536254883\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087216.7871234, \"EndTime\": 1682087217.099538, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 312.02244758605957, \"count\": 1, \"min\": 312.02244758605957, \"max\": 312.02244758605957}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #progress_metric: host=algo-1, completed 72.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087216.7874863, \"EndTime\": 1682087217.0997863, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 35, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2881000.0, \"count\": 1, \"min\": 2881000, \"max\": 2881000}, \"Total Batches Seen\": {\"sum\": 2881.0, \"count\": 1, \"min\": 2881, \"max\": 2881}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 37.0, \"count\": 1, \"min\": 37, \"max\": 37}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=256049.6189904965 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=36, batch=0 train rmse <loss>=1.0149882018056602\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=36, batch=0 train mse <loss>=1.0302010498046874\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=36, batch=0 train absolute_loss <loss>=0.8156118774414063\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:57.429] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 74, \"duration\": 327, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=36, train rmse <loss>=0.9659960868392886\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=36, train mse <loss>=0.9331484397888183\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=36, train absolute_loss <loss>=0.779221548461914\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087217.0996208, \"EndTime\": 1682087217.4312773, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 331.1350345611572, \"count\": 1, \"min\": 331.1350345611572, \"max\": 331.1350345611572}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #progress_metric: host=algo-1, completed 74.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087217.100089, \"EndTime\": 1682087217.4317806, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 36, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 2961000.0, \"count\": 1, \"min\": 2961000, \"max\": 2961000}, \"Total Batches Seen\": {\"sum\": 2961.0, \"count\": 1, \"min\": 2961, \"max\": 2961}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 38.0, \"count\": 1, \"min\": 38, \"max\": 38}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=241048.49068260513 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=37, batch=0 train rmse <loss>=1.0129805717149145\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=37, batch=0 train mse <loss>=1.026129638671875\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=37, batch=0 train absolute_loss <loss>=0.8136621704101562\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:57.743] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 76, \"duration\": 307, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=37, train rmse <loss>=0.9638697540650986\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=37, train mse <loss>=0.9290449028015136\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=37, train absolute_loss <loss>=0.7772083511352539\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087217.4313996, \"EndTime\": 1682087217.7439232, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 311.659574508667, \"count\": 1, \"min\": 311.659574508667, \"max\": 311.659574508667}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #progress_metric: host=algo-1, completed 76.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087217.4321783, \"EndTime\": 1682087217.7442482, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 37, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 3041000.0, \"count\": 1, \"min\": 3041000, \"max\": 3041000}, \"Total Batches Seen\": {\"sum\": 3041.0, \"count\": 1, \"min\": 3041, \"max\": 3041}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 39.0, \"count\": 1, \"min\": 39, \"max\": 39}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=256246.91761546963 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=38, batch=0 train rmse <loss>=1.0110112753219545\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=38, batch=0 train mse <loss>=1.022143798828125\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:57 INFO 139893122135872] #quality_metric: host=algo-1, epoch=38, batch=0 train absolute_loss <loss>=0.8117344360351563\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:58.074] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 78, \"duration\": 327, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=38, train rmse <loss>=0.9617912429521965\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=38, train mse <loss>=0.9250423950195312\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=38, train absolute_loss <loss>=0.7752405647277832\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087217.744033, \"EndTime\": 1682087218.0750935, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 330.5225372314453, \"count\": 1, \"min\": 330.5225372314453, \"max\": 330.5225372314453}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #progress_metric: host=algo-1, completed 78.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087217.744536, \"EndTime\": 1682087218.0753567, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 38, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 3121000.0, \"count\": 1, \"min\": 3121000, \"max\": 3121000}, \"Total Batches Seen\": {\"sum\": 3121.0, \"count\": 1, \"min\": 3121, \"max\": 3121}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 40.0, \"count\": 1, \"min\": 40, \"max\": 40}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=241723.29184358282 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=39, batch=0 train rmse <loss>=1.009079357584102\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=39, batch=0 train mse <loss>=1.0182411499023438\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=39, batch=0 train absolute_loss <loss>=0.8098663330078125\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:58.393] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 80, \"duration\": 315, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=39, train rmse <loss>=0.9597590028738527\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=39, train mse <loss>=0.9211373435974121\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=39, train absolute_loss <loss>=0.7733189521789551\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087218.07518, \"EndTime\": 1682087218.3945043, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 318.5265064239502, \"count\": 1, \"min\": 318.5265064239502, \"max\": 318.5265064239502}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #progress_metric: host=algo-1, completed 80.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087218.0759442, \"EndTime\": 1682087218.3947778, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 39, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 3201000.0, \"count\": 1, \"min\": 3201000, \"max\": 3201000}, \"Total Batches Seen\": {\"sum\": 3201.0, \"count\": 1, \"min\": 3201, \"max\": 3201}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 41.0, \"count\": 1, \"min\": 41, \"max\": 41}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=250806.7510800831 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=40, batch=0 train rmse <loss>=1.0071839730972998\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=40, batch=0 train mse <loss>=1.0144195556640625\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=40, batch=0 train absolute_loss <loss>=0.8080326538085938\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:58.775] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 82, \"duration\": 377, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=40, train rmse <loss>=0.9577715285034148\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=40, train mse <loss>=0.9173263008117676\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=40, train absolute_loss <loss>=0.7714394775390625\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087218.3945901, \"EndTime\": 1682087218.7758799, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 380.542516708374, \"count\": 1, \"min\": 380.542516708374, \"max\": 380.542516708374}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #progress_metric: host=algo-1, completed 82.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087218.3953063, \"EndTime\": 1682087218.7761598, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 40, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 3281000.0, \"count\": 1, \"min\": 3281000, \"max\": 3281000}, \"Total Batches Seen\": {\"sum\": 3281.0, \"count\": 1, \"min\": 3281, \"max\": 3281}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 42.0, \"count\": 1, \"min\": 42, \"max\": 42}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=209977.54068989944 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=41, batch=0 train rmse <loss>=1.0053242660369899\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=41, batch=0 train mse <loss>=1.0106768798828125\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:58 INFO 139893122135872] #quality_metric: host=algo-1, epoch=41, batch=0 train absolute_loss <loss>=0.8062289428710937\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:59.094] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 84, \"duration\": 315, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=41, train rmse <loss>=0.9558273007491583\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=41, train mse <loss>=0.9136058288574219\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=41, train absolute_loss <loss>=0.7696015670776367\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087218.7759702, \"EndTime\": 1682087219.0951428, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 318.3908462524414, \"count\": 1, \"min\": 318.3908462524414, \"max\": 318.3908462524414}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #progress_metric: host=algo-1, completed 84.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087218.7767253, \"EndTime\": 1682087219.095428, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 41, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 3361000.0, \"count\": 1, \"min\": 3361000, \"max\": 3361000}, \"Total Batches Seen\": {\"sum\": 3361.0, \"count\": 1, \"min\": 3361, \"max\": 3361}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 43.0, \"count\": 1, \"min\": 43, \"max\": 43}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=250903.1469791662 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=42, batch=0 train rmse <loss>=1.0034994007787355\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=42, batch=0 train mse <loss>=1.0070110473632812\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=42, batch=0 train absolute_loss <loss>=0.80449658203125\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:59.400] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 86, \"duration\": 302, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=42, train rmse <loss>=0.9539248336993794\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=42, train mse <loss>=0.9099725883483887\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=42, train absolute_loss <loss>=0.7678054878234863\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087219.0952473, \"EndTime\": 1682087219.4015396, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 305.55105209350586, \"count\": 1, \"min\": 305.55105209350586, \"max\": 305.55105209350586}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #progress_metric: host=algo-1, completed 86.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087219.0959618, \"EndTime\": 1682087219.4017613, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 42, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 3441000.0, \"count\": 1, \"min\": 3441000, \"max\": 3441000}, \"Total Batches Seen\": {\"sum\": 3441.0, \"count\": 1, \"min\": 3441, \"max\": 3441}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 44.0, \"count\": 1, \"min\": 44, \"max\": 44}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=261517.99130830573 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=43, batch=0 train rmse <loss>=1.001708562379953\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=43, batch=0 train mse <loss>=1.0034200439453125\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=43, batch=0 train absolute_loss <loss>=0.8028063354492188\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:26:59.715] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 88, \"duration\": 310, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=43, train rmse <loss>=0.95206266721059\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=43, train mse <loss>=0.9064233222961425\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=43, train absolute_loss <loss>=0.7660515777587891\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087219.4016166, \"EndTime\": 1682087219.7160156, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 313.617467880249, \"count\": 1, \"min\": 313.617467880249, \"max\": 313.617467880249}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #progress_metric: host=algo-1, completed 88.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087219.4023669, \"EndTime\": 1682087219.7162747, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 43, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 3521000.0, \"count\": 1, \"min\": 3521000, \"max\": 3521000}, \"Total Batches Seen\": {\"sum\": 3521.0, \"count\": 1, \"min\": 3521, \"max\": 3521}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 45.0, \"count\": 1, \"min\": 45, \"max\": 45}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=254746.01646557928 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=44, batch=0 train rmse <loss>=0.999950987568422\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=44, batch=0 train mse <loss>=0.9999019775390625\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:26:59 INFO 139893122135872] #quality_metric: host=algo-1, epoch=44, batch=0 train absolute_loss <loss>=0.8011531372070313\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:27:00.035] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 90, \"duration\": 316, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=44, train rmse <loss>=0.9502393726134971\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=44, train mse <loss>=0.9029548652648925\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=44, train absolute_loss <loss>=0.7643394882202148\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087219.7161062, \"EndTime\": 1682087220.0358372, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 319.2448616027832, \"count\": 1, \"min\": 319.2448616027832, \"max\": 319.2448616027832}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #progress_metric: host=algo-1, completed 90.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087219.7165601, \"EndTime\": 1682087220.036163, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 44, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 3601000.0, \"count\": 1, \"min\": 3601000, \"max\": 3601000}, \"Total Batches Seen\": {\"sum\": 3601.0, \"count\": 1, \"min\": 3601, \"max\": 3601}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 46.0, \"count\": 1, \"min\": 46, \"max\": 46}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=250175.6366334013 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=45, batch=0 train rmse <loss>=0.9982258126041517\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=45, batch=0 train mse <loss>=0.9964547729492188\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=45, batch=0 train absolute_loss <loss>=0.7995296630859375\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:27:00.351] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 92, \"duration\": 312, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=45, train rmse <loss>=0.9484535310952101\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=45, train mse <loss>=0.8995641006469727\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=45, train absolute_loss <loss>=0.762669083404541\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087220.0359468, \"EndTime\": 1682087220.352583, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 316.0443305969238, \"count\": 1, \"min\": 316.0443305969238, \"max\": 316.0443305969238}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #progress_metric: host=algo-1, completed 92.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087220.0365067, \"EndTime\": 1682087220.352822, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 45, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 3681000.0, \"count\": 1, \"min\": 3681000, \"max\": 3681000}, \"Total Batches Seen\": {\"sum\": 3681.0, \"count\": 1, \"min\": 3681, \"max\": 3681}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 47.0, \"count\": 1, \"min\": 47, \"max\": 47}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=252814.7410328548 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=46, batch=0 train rmse <loss>=0.9965321951726522\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=46, batch=0 train mse <loss>=0.993076416015625\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=46, batch=0 train absolute_loss <loss>=0.7979529418945313\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:27:00.678] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 94, \"duration\": 322, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=46, train rmse <loss>=0.9467037819136973\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=46, train mse <loss>=0.8962480506896973\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=46, train absolute_loss <loss>=0.7610377487182617\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087220.3526616, \"EndTime\": 1682087220.679436, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 326.3261318206787, \"count\": 1, \"min\": 326.3261318206787, \"max\": 326.3261318206787}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #progress_metric: host=algo-1, completed 94.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087220.3530777, \"EndTime\": 1682087220.6796875, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 46, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 3761000.0, \"count\": 1, \"min\": 3761000, \"max\": 3761000}, \"Total Batches Seen\": {\"sum\": 3761.0, \"count\": 1, \"min\": 3761, \"max\": 3761}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 48.0, \"count\": 1, \"min\": 48, \"max\": 48}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=244841.72398343906 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=47, batch=0 train rmse <loss>=0.9948693761914645\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=47, batch=0 train mse <loss>=0.9897650756835937\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:00 INFO 139893122135872] #quality_metric: host=algo-1, epoch=47, batch=0 train absolute_loss <loss>=0.796429931640625\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:27:01.002] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 96, \"duration\": 320, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=47, train rmse <loss>=0.9449887802830464\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=47, train mse <loss>=0.8930037948608398\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=47, train absolute_loss <loss>=0.7594432289123535\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087220.679521, \"EndTime\": 1682087221.0033937, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 323.3833312988281, \"count\": 1, \"min\": 323.3833312988281, \"max\": 323.3833312988281}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #progress_metric: host=algo-1, completed 96.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087220.679981, \"EndTime\": 1682087221.0036762, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 47, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 3841000.0, \"count\": 1, \"min\": 3841000, \"max\": 3841000}, \"Total Batches Seen\": {\"sum\": 3841.0, \"count\": 1, \"min\": 3841, \"max\": 3841}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 49.0, \"count\": 1, \"min\": 49, \"max\": 49}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=247050.016050608 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=48, batch=0 train rmse <loss>=0.9932364349552709\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=48, batch=0 train mse <loss>=0.9865186157226562\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=48, batch=0 train absolute_loss <loss>=0.7949535522460938\u001b[0m\n",
      "\n",
      "2023-04-21 14:27:04 Uploading - Uploading generated training model\u001b[34m[2023-04-21 14:27:01.311] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 98, \"duration\": 305, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=48, train rmse <loss>=0.9433072279518229\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=48, train mse <loss>=0.8898285263061524\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=48, train absolute_loss <loss>=0.7578834030151367\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087221.0035245, \"EndTime\": 1682087221.3124702, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 308.52746963500977, \"count\": 1, \"min\": 308.52746963500977, \"max\": 308.52746963500977}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #progress_metric: host=algo-1, completed 98.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087221.0039148, \"EndTime\": 1682087221.3126836, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 48, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 3921000.0, \"count\": 1, \"min\": 3921000, \"max\": 3921000}, \"Total Batches Seen\": {\"sum\": 3921.0, \"count\": 1, \"min\": 3921, \"max\": 3921}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 50.0, \"count\": 1, \"min\": 50, \"max\": 50}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=258999.9830186378 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=49, batch=0 train rmse <loss>=0.991632565037559\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=49, batch=0 train mse <loss>=0.9833351440429687\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=49, batch=0 train absolute_loss <loss>=0.7935211181640625\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:27:01.683] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/train\", \"epoch\": 100, \"duration\": 367, \"num_examples\": 80, \"num_bytes\": 5120000}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=49, train rmse <loss>=0.9416578732870481\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=49, train mse <loss>=0.8867195503234864\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, epoch=49, train absolute_loss <loss>=0.7563570640563965\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, train rmse <loss>=0.9416578732870481\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, train mse <loss>=0.8867195503234864\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, train absolute_loss <loss>=0.7563570640563965\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087221.312542, \"EndTime\": 1682087221.6841397, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"update.time\": {\"sum\": 371.2010383605957, \"count\": 1, \"min\": 371.2010383605957, \"max\": 371.2010383605957}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #progress_metric: host=algo-1, completed 100.0 % of epochs\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087221.3129077, \"EndTime\": 1682087221.6844027, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"epoch\": 49, \"Meta\": \"training_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 4001000.0, \"count\": 1, \"min\": 4001000, \"max\": 4001000}, \"Total Batches Seen\": {\"sum\": 4001.0, \"count\": 1, \"min\": 4001, \"max\": 4001}, \"Max Records Seen Between Resets\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Max Batches Seen Between Resets\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}, \"Reset Count\": {\"sum\": 51.0, \"count\": 1, \"min\": 51, \"max\": 51}, \"Number of Records Since Last Reset\": {\"sum\": 80000.0, \"count\": 1, \"min\": 80000, \"max\": 80000}, \"Number of Batches Since Last Reset\": {\"sum\": 80.0, \"count\": 1, \"min\": 80, \"max\": 80}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #throughput_metric: host=algo-1, train throughput=215269.97255429797 records/second\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 WARNING 139893122135872] wait_for_all_workers will not sync workers since the kv store is not running distributed\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] Pulling entire model from kvstore to finalize\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087221.6842248, \"EndTime\": 1682087221.690055, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"finalize.time\": {\"sum\": 5.262136459350586, \"count\": 1, \"min\": 5.262136459350586, \"max\": 5.262136459350586}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] Saved checkpoint to \"/tmp/tmpzjv_09zv/state-0001.params\"\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:27:01.702] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/test\", \"epoch\": 0, \"duration\": 16610, \"num_examples\": 1, \"num_bytes\": 64000}\u001b[0m\n",
      "\u001b[34m[2023-04-21 14:27:01.759] [tensorio] [info] epoch_stats={\"data_pipeline\": \"/opt/ml/input/data/test\", \"epoch\": 1, \"duration\": 56, \"num_examples\": 20, \"num_bytes\": 1280000}\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087221.7024763, \"EndTime\": 1682087221.7596557, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\", \"Meta\": \"test_data_iter\"}, \"Metrics\": {\"Total Records Seen\": {\"sum\": 20000.0, \"count\": 1, \"min\": 20000, \"max\": 20000}, \"Total Batches Seen\": {\"sum\": 20.0, \"count\": 1, \"min\": 20, \"max\": 20}, \"Max Records Seen Between Resets\": {\"sum\": 20000.0, \"count\": 1, \"min\": 20000, \"max\": 20000}, \"Max Batches Seen Between Resets\": {\"sum\": 20.0, \"count\": 1, \"min\": 20, \"max\": 20}, \"Reset Count\": {\"sum\": 1.0, \"count\": 1, \"min\": 1, \"max\": 1}, \"Number of Records Since Last Reset\": {\"sum\": 20000.0, \"count\": 1, \"min\": 20000, \"max\": 20000}, \"Number of Batches Since Last Reset\": {\"sum\": 20.0, \"count\": 1, \"min\": 20, \"max\": 20}}}\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #test_score (algo-1) : ('rmse', 1.0002629948968227)\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #test_score (algo-1) : ('mse', 1.000526058959961)\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #test_score (algo-1) : ('absolute_loss', 0.7952481262207032)\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, test rmse <loss>=1.0002629948968227\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, test mse <loss>=1.000526058959961\u001b[0m\n",
      "\u001b[34m[04/21/2023 14:27:01 INFO 139893122135872] #quality_metric: host=algo-1, test absolute_loss <loss>=0.7952481262207032\u001b[0m\n",
      "\u001b[34m#metrics {\"StartTime\": 1682087221.6901116, \"EndTime\": 1682087221.7607105, \"Dimensions\": {\"Algorithm\": \"factorization-machines\", \"Host\": \"algo-1\", \"Operation\": \"training\"}, \"Metrics\": {\"setuptime\": {\"sum\": 19.84381675720215, \"count\": 1, \"min\": 19.84381675720215, \"max\": 19.84381675720215}, \"totaltime\": {\"sum\": 16695.873737335205, \"count\": 1, \"min\": 16695.873737335205, \"max\": 16695.873737335205}}}\u001b[0m\n",
      "\n",
      "2023-04-21 14:27:15 Completed - Training job completed\n",
      "Training seconds: 148\n",
      "Billable seconds: 148\n"
     ]
    }
   ],
   "source": [
    "containers = {\n",
    "    region:'991648021394.dkr.ecr.ap-south-1.amazonaws.com/factorization-machines:latest'\n",
    "}\n",
    "fm = sagemaker.estimator.Estimator(containers[region],\n",
    "                                   get_execution_role(),\n",
    "                                   train_instance_count = 1,\n",
    "                                   train_instance_type = 'ml.c4.xlarge',\n",
    "                                   output_path = output_prefix,\n",
    "                                   sagemaker_session = sagemaker.Session())\n",
    "\n",
    "fm.set_hyperparameters(feature_dim = nbFeatures,\n",
    "                       predictor_type = 'regressor',\n",
    "                       mini_batch_size = 1000,\n",
    "                       num_factors = 64,\n",
    "                       epochs = 50)\n",
    "\n",
    "fm.fit({'train':train_data,'test':test_data})"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 207,
   "metadata": {
    "tags": []
   },
   "outputs": [],
   "source": [
    "import json\n",
    "import numpy as np\n",
    "# from sagemaker.predictor import json_deserializer\n",
    "from sagemaker.deserializers import JSONDeserializer\n",
    "from sagemaker.serializers import JSONSerializer\n",
    "\n",
    "nbUsers = 943\n",
    "nbMovies = 1682\n",
    "nbFeatures = nbUsers+nbMovies\n",
    "\n",
    "class FMSerializer(JSONSerializer):\n",
    "    def serializer(self,data):\n",
    "        js = {'instances':[]}\n",
    "        # fm_predictor.content_type('application/json')\n",
    "        for row in data:\n",
    "            keys = np.argwhere(row == np.amax(row)).flatten().tolist()\n",
    "            js['instances'].append({\n",
    "                'data':{\n",
    "                'features':{\n",
    "                'keys':keys,\n",
    "                'shape':[nbFeatures],\n",
    "                'values':[1]*len(keys)\n",
    "                }\n",
    "                }\n",
    "            })\n",
    "        print(js)\n",
    "        return json.dumps(js)\n",
    "\n",
    "# fm_predictor.content_type ='application/json'\n",
    "# fm_predictor.serializer = fm_serializer\n",
    "# fm_predictor.deserializer = json_deserializer"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 208,
   "metadata": {
    "tags": []
   },
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "INFO:sagemaker:Creating model with name: factorization-machines-2023-04-21-15-11-57-455\n",
      "INFO:sagemaker:Creating endpoint-config with name factorization-machines-2023-04-21-15-11-57-455\n",
      "INFO:sagemaker:Creating endpoint with name factorization-machines-2023-04-21-15-11-57-455\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "--------!"
     ]
    }
   ],
   "source": [
    "fm_predictor = fm.deploy(instance_type = 'ml.m4.xlarge', initial_instance_count = 1,serializer = FMSerializer(), deserializer = JSONDeserializer)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "result = fm_predictor.predict(X_test[1000:1010].toarray())\n",
    "print(result)\n",
    "print(Y_test[1000:1010])"
   ]
  }
 ],
 "metadata": {
  "colab": {
   "provenance": []
  },
  "kernelspec": {
   "display_name": "conda_amazonei_pytorch_latest_p37",
   "language": "python",
   "name": "conda_amazonei_pytorch_latest_p37"
  },
  "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.10"
  }
 },
 "nbformat": 4,
 "nbformat_minor": 4
}