{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Logging in PLAMS"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "PLAMS has built-in logging which aims to simplify tracking the progress and status of jobs. This consists of progress logging to stdout and a logfile, and writing job summaries to CSV files. Each of these is explained below."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### Progress Logger"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "PLAMS writes job progress to stdout and a plain text logfile. The location of this logfile is determined by the working directory of the default job manager, and is called `logfile`.\n",
    "\n",
    "Users can also write logs to the same locations using the `log` function. This takes a `level` argument. By convention in PLAMS, the level should be between 0-7, with 0 being the most and 7 the least important logging.\n",
    "\n",
    "The level of logging that is written to stdout and the logfile can be changed through the `config.LogSettings`."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 1,
   "metadata": {},
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "PLAMS working folder: /path/plams/examples/Logging/plams_workdir.004\n"
     ]
    }
   ],
   "source": [
    "from scm.plams import Settings, AMSJob, from_smiles, log, config, init\n",
    "\n",
    "# this line is not required in AMS2025+\n",
    "init()\n",
    "\n",
    "counter = 0\n",
    "\n",
    "\n",
    "def get_test_job():\n",
    "    global counter\n",
    "    s = Settings()\n",
    "    s.input.ams.Task = \"SinglePoint\"\n",
    "    s.input.dftb\n",
    "    counter += 1\n",
    "    return AMSJob(name=f\"test{counter}\", molecule=from_smiles(\"C\"), settings=s)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 2,
   "metadata": {},
   "outputs": [],
   "source": [
    "config.log.stdout = 3\n",
    "config.log.file = 5\n",
    "config.jobmanager.hashing = None  # Force PLAMS to re-run identical test jobs"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 3,
   "metadata": {},
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[10.02|15:33:22] JOB test1 STARTED\n",
      "[10.02|15:33:22] JOB test1 RUNNING\n",
      "[10.02|15:33:23] JOB test1 FINISHED\n",
      "[10.02|15:33:23] JOB test1 SUCCESSFUL\n"
     ]
    }
   ],
   "source": [
    "job = get_test_job()\n",
    "job.run()\n",
    "log(\"Test job finished\", 5)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "metadata": {},
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[10.02|15:33:22] JOB test1 STARTED\n",
      "[10.02|15:33:22] Starting test1.prerun()\n",
      "[10.02|15:33:22] test1.prerun() finished\n",
      "[10.02|15:33:22] JOB test1 RUNNING\n",
      "[10.02|15:33:22] Executing test1.run\n",
      "[10.02|15:33:23] Execution of test1.run finished with returncode 0\n",
      "[10.02|15:33:23] JOB test1 FINISHED\n",
      "[10.02|15:33:23] Starting test1.postrun()\n",
      "[10.02|15:33:23] test1.postrun() finished\n",
      "[10.02|15:33:23] JOB test1 SUCCESSFUL\n",
      "[10.02|15:33:23] Test job finished\n",
      "\n"
     ]
    }
   ],
   "source": [
    "with open(config.default_jobmanager.logfile, \"r\") as f:\n",
    "    print(f.read())"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Note that the logs from an AMS calculation can also be forwarded to the progress logs using the `watch = True` flag."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 5,
   "metadata": {
    "scrolled": true
   },
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[10.02|15:33:23] JOB test2 STARTED\n",
      "[10.02|15:33:23] JOB test2 RUNNING\n",
      "[10.02|15:33:23] test2: AMS 2024.207  RunTime: Feb10-2025 15:33:23  ShM Nodes: 1  Procs: 6\n",
      "[10.02|15:33:24] test2: DFTB: SCC cycle\n",
      "[10.02|15:33:24] test2: cyc=  1 err=1.1E+00 method=1 nvec= 1 mix=0.075 e=    0.0000\n",
      "[10.02|15:33:24] test2: cyc=  2 err=1.1E+00 method=1 nvec= 1 mix=0.154 e=    0.0000\n",
      "[10.02|15:33:24] test2: cyc=  3 err=8.9E-01 method=1 nvec= 2 mix=0.201 e=    0.0000\n",
      "[10.02|15:33:24] test2: cyc=  4 err=1.7E-02 method=1 nvec= 3 mix=0.207 e=    0.0000\n",
      "[10.02|15:33:24] test2: cyc=  5 err=6.8E-03 method=1 nvec= 4 mix=0.213 e=    0.0000\n",
      "[10.02|15:33:24] test2: cyc=  6 err=2.6E-03 method=1 nvec= 5 mix=0.219 e=    0.0000\n",
      "[10.02|15:33:24] test2: cyc=  7 err=7.2E-05 method=1 nvec= 6 mix=0.226 e=    0.0000\n",
      "[10.02|15:33:24] test2: cyc=  8 err=6.8E-05 method=1 nvec= 1 mix=0.233 e=    0.0000\n",
      "[10.02|15:33:24] test2: cyc=  9 err=4.2E-05 method=1 nvec= 2 mix=0.240 e=    0.0000\n",
      "[10.02|15:33:24] test2: cyc= 10 err=6.2E-07 method=1 nvec= 3 mix=0.247 e=    0.0000\n",
      "[10.02|15:33:24] test2: cyc= 11 err=5.8E-08 method=1 nvec= 3 mix=0.254 e=    0.0000\n",
      "[10.02|15:33:24] test2: cyc= 12 err=3.6E-08 method=1 nvec= 4 mix=0.262 e=    0.0000\n",
      "[10.02|15:33:24] test2: cyc= 13 err=9.0E-11 method=1 nvec= 4 mix=0.270 e=    0.0000\n",
      "[10.02|15:33:24] test2: SCC cycle converged!\n",
      "[10.02|15:33:24] test2: NORMAL TERMINATION\n",
      "[10.02|15:33:24] JOB test2 FINISHED\n",
      "[10.02|15:33:24] JOB test2 SUCCESSFUL\n"
     ]
    }
   ],
   "source": [
    "job = get_test_job()\n",
    "job.run(watch=True);"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### Job Summary Logger"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "For AMS2025+, PLAMS also writes summaries of jobs to a CSV file, the location of which by default is also determined by the job manager. It is called `job_logfile.csv`."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 6,
   "metadata": {
    "scrolled": true
   },
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "[10.02|15:33:24] JOB test3 STARTED\n",
      "[10.02|15:33:24] JOB test3 RUNNING\n",
      "[10.02|15:33:25] JOB test3 FINISHED\n",
      "[10.02|15:33:25] JOB test3 SUCCESSFUL\n",
      "[10.02|15:33:25] JOB test4 STARTED\n",
      "[10.02|15:33:25] JOB test4 RUNNING\n",
      "[10.02|15:33:26] JOB test4 FINISHED\n",
      "[10.02|15:33:26] JOB test4 SUCCESSFUL\n",
      "[10.02|15:33:26] JOB test5 STARTED\n",
      "[10.02|15:33:26] JOB test5 RUNNING\n",
      "[10.02|15:33:34] WARNING: Job test5 finished with nonzero return code\n",
      "[10.02|15:33:34] WARNING: Main KF file ams.rkf not present in /path/plams/examples/Logging/plams_workdir.004/test5\n",
      "[10.02|15:33:34] JOB test5 CRASHED\n",
      "[10.02|15:33:34] File ams.rkf not present in /path/plams/examples/Logging/plams_workdir.004/test5\n",
      "[10.02|15:33:34] Error message for job test5 was:\n",
      "\tInput error: value \"Not a task!\" found in line 1 for multiple choice key \"Task\" is not an allowed choice\n",
      "[10.02|15:33:34] File ams.rkf not present in /path/plams/examples/Logging/plams_workdir.004/test5\n",
      "[10.02|15:33:34] File ams.rkf not present in /path/plams/examples/Logging/plams_workdir.004/test5\n"
     ]
    }
   ],
   "source": [
    "from scm.plams import MultiJob\n",
    "\n",
    "\n",
    "jobs = [get_test_job() for _ in range(3)]\n",
    "jobs[2].settings.input.ams.Task = \"Not a task!\"\n",
    "\n",
    "for job in jobs:\n",
    "    job.run()"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "These CSVs give overall information on the status of all jobs run by a given job manager."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 9,
   "metadata": {},
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "test1 successful: \n",
      "test2 successful: \n",
      "test3 successful: \n",
      "test4 successful: \n",
      "test5 crashed: Input error: value \"Not a task!\" found in line 1 for multiple choice key \"Task\" is not an allowed choice\n"
     ]
    }
   ],
   "source": [
    "import csv\n",
    "\n",
    "try:\n",
    "    with open(config.default_jobmanager.job_logger.logfile, newline=\"\") as csvfile:\n",
    "        reader = csv.DictReader(csvfile)\n",
    "        for row in reader:\n",
    "            print(f\"{row['job_name']} {row['job_status']}: {row['job_get_errormsg']}\")\n",
    "except AttributeError:\n",
    "    pass"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": []
  }
 ],
 "metadata": {
  "kernelspec": {
   "display_name": "Python 3 (ipykernel)",
   "language": "python",
   "name": "python3"
  },
  "language_info": {
   "codemirror_mode": {
    "name": "ipython",
    "version": 3
   },
   "file_extension": ".py",
   "mimetype": "text/x-python",
   "name": "python",
   "nbconvert_exporter": "python",
   "pygments_lexer": "ipython3",
   "version": "3.8.16"
  }
 },
 "nbformat": 4,
 "nbformat_minor": 4
}