{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": "# Setting Up Logging\n\nPyLabRobot uses standard Python [`logging`](https://docs.python.org/3/library/logging.html). All loggers live under the `\"pylabrobot\"` name, so standard Python techniques for setting levels, adding handlers, and filtering by module all apply.\n\nThis also means PLR's logging tools can serve as building blocks for **audit trails** and traceability (which are particularly important in regulated environments) - see [Logging & Validation](logging-and-validation.rst) for an overview of these concepts.\n\n## Log levels\n\nPython's five [built-in levels](https://docs.python.org/3/library/logging.html#logging-levels) apply as normal:\n\n| Level | Value | Defined by | Typical content |\n|-------|-------|------------|-----------------|\n| `CRITICAL` | 50 | Python | Unrecoverable errors |\n| `ERROR` | 40 | Python | Failures that stop an operation |\n| `WARNING` | 30 | Python | Recoverable problems (timeouts, fallbacks) |\n| `INFO` | 20 | Python | High-level actions: setup, teardown, measurement starts |\n| `DEBUG` | 10 | Python | Internal state, retry logic, per-well progress |\n| `IO` | 5 | PyLabRobot | Raw bytes sent to / received from hardware |\n\nPyLabRobot adds one extra level: **`IO`** (value 5), which sits below `DEBUG`. It exists because hardware backends can generate a large volume of raw data frames sent to and received from hardware. Mixing those into `DEBUG` would make debug logs unreadable during normal development, so they are separated into their own level that you only enable when you are actively inspecting wire traffic executed by PyLabRobot.\n\n```{note}\nThis is a device-agnostic feature of PyLabRobot: regardless of whether you are talking to a Hamilton STAR over USB, a plate reader over serial, or a temperature controller over TCP, all low-level communication is logged through the same `IO` level. This means you get a consistent way to inspect and record wire traffic across every backend, using the same `verbose()` call and the same log format. When something goes wrong at the hardware level, you don't need device-specific debugging tools - just set the log level to `IO` and every byte sent and received will appear in your log.\n```"
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Quick start\n",
    "\n",
    "```{warning}\n",
    "**Default logging behaviour:**\n",
    "- **Jupyter notebooks**: console output (StreamHandler) at `INFO` level. No file logging.\n",
    "- **Scripts**: no logging enabled. No console output, no file logging. You must opt in.\n",
    "\n",
    "In neither case does PLR write to a file by default - call `setup_logger()` to enable file logging (see details below).\n",
    "```\n"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "import pylabrobot\n",
    "\n",
    "# Enable console output at INFO level (the default)\n",
    "pylabrobot.verbose(True)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "To see `DEBUG` messages:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "import logging\n",
    "\n",
    "pylabrobot.verbose(True, level=logging.DEBUG)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "To see everything including raw IO bytes:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "from pylabrobot.io import LOG_LEVEL_IO\n",
    "\n",
    "pylabrobot.verbose(True, level=LOG_LEVEL_IO)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "To turn console output off again:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "pylabrobot.verbose(False)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": "## What the output looks like\n\nAt **INFO** level you see high-level actions:\n\n```\n2026-03-04 17:07:58,102 - pylabrobot - INFO - Setting up the plate reader.\n2026-03-04 17:07:59,003 - pylabrobot - INFO - Plate reader set up successfully.\n2026-03-04 17:07:59,210 - pylabrobot - INFO - Starting fluorescence measurement.\n```\n\nAt **DEBUG** you also see internal details:\n\n```\n2026-03-04 17:07:59,814 - pylabrobot - DEBUG - FL measurement progress: 5/96\n2026-03-04 17:07:59,920 - pylabrobot - DEBUG - Status flags: busy=True, running=True, plate_detected=True\n2026-03-04 17:08:00,015 - pylabrobot - DEBUG - Retry 1/3: waiting for device ready\n```\n\nAt **IO** you additionally see every raw frame on the wire:\n\n```\n2026-03-04 17:07:59,211 - pylabrobot - IO - sent 47 bytes: 020027...0d\n2026-03-04 17:07:59,318 - pylabrobot - IO - read 12 bytes: 02000a...0d\n```\n\nEach level includes all messages from the levels above it, so `IO` gives you everything."
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Logging to a file\n",
    "\n",
    "Use `setup_logger` to write logs to disk. This is useful for long-running protocols where you want a persistent record."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "from pylabrobot.io import LOG_LEVEL_IO\n",
    "\n",
    "# File output at IO level (captures everything)\n",
    "pylabrobot.setup_logger(log_dir=\"./logs\", level=LOG_LEVEL_IO)\n",
    "\n",
    "# Console output at INFO level\n",
    "pylabrobot.verbose(True)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": "```{warning}\n**Default log file name**\n\nWhen given a directory, `setup_logger` automatically creates a date-stamped file like `logs/pylabrobot-20260312.log`. Since the filename is based on the date only, multiple runs on the same day will append to the same file.\nTo keep logs separate per run, pass a full file path ending in `.log`, `.txt`, or `.jsonl`.\n```\n\n### How handlers work\n\nThe code above creates two independent [handlers](https://docs.python.org/3/howto/logging.html#handlers) on the `\"pylabrobot\"` [logger](https://docs.python.org/3/library/logging.html#logger-objects):\n\n```\n                         Logger: \"pylabrobot\"\n                        (level = IO, i.e. everything)\n                                  |\n                    +-------------+-------------+\n                    |                           |\n             StreamHandler                FileHandler\n            (level = INFO)              (level = IO)\n                    |                           |\n                 console                 logs/pylabrobot-\n                                        20260312.log\n```\n\nEach handler has its own level, so you can show `INFO` in the console while capturing `IO`-level detail to file. Every log message passes through the logger first. If the message meets the logger's level, it is forwarded to each handler, which then applies its own level filter. This is standard Python logging behaviour - PLR just configures it for you."
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Filtering by module\n",
    "\n",
    "Since PLR uses Python's logger hierarchy, you can adjust the level for a specific backend without changing the global level:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "import logging\n",
    "\n",
    "# Only show warnings and above from the STAR backend\n",
    "logging.getLogger(\"pylabrobot.liquid_handling.backends.hamilton.STAR\").setLevel(logging.WARNING)\n",
    "\n",
    "# Show debug output from the plate reader\n",
    "logging.getLogger(\"pylabrobot.plate_reading\").setLevel(logging.DEBUG)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Real-world example: protocol logging\n",
    "\n",
    "In practice you often want PLR's hardware logs alongside your own protocol-level messages (e.g. which protocol is running, who started it, and why). You can combine `setup_logger` for PLR with standard Python loggers for your own code, all writing to the same file:\n"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "import pylabrobot\n",
    "import logging\n",
    "from datetime import datetime\n",
    "from pylabrobot.io import LOG_LEVEL_IO\n",
    "\n",
    "# 1. Let PLR handle its own file logging with a detailed timestamp\n",
    "timestamp = datetime.now().strftime('%Y-%m-%d_%H-%M-%S')\n",
    "log_file = f\"./logs/{timestamp}_cell_viability_assay.log\"\n",
    "pylabrobot.setup_logger(log_dir=log_file, level=LOG_LEVEL_IO)\n",
    "\n",
    "# 2. Create your own loggers for protocol-level events\n",
    "logger_protocol = logging.getLogger(\"protocol\")\n",
    "logger_protocol.setLevel(logging.INFO)\n",
    "\n",
    "# 3. Reuse PLR's handlers so everything goes to the same console and file\n",
    "for handler in logging.getLogger(\"pylabrobot\").handlers:\n",
    "    logger_protocol.addHandler(handler)\n",
    "\n",
    "# 4. Log protocol metadata\n",
    "logger_protocol.info(\"START AUTOMATED PROTOCOL\")\n",
    "logger_protocol.info(\"Protocol: cell_viability_assay\")\n",
    "logger_protocol.info(\"User: alice\")"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "This gives you a single log file with both PLR hardware traces and your protocol events, without having to manually set up file handlers and formatters."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Summary\n",
    "\n",
    "| Goal | Code |\n",
    "|------|------|\n",
    "| Console output (INFO) | `pylabrobot.verbose(True)` |\n",
    "| Console output (DEBUG) | `pylabrobot.verbose(True, level=logging.DEBUG)` |\n",
    "| Console output (IO) | `pylabrobot.verbose(True, level=LOG_LEVEL_IO)` |\n",
    "| Log to file | `pylabrobot.setup_logger(log_dir=\"./logs\", level=LOG_LEVEL_IO)` |\n",
    "| Filter one module | `logging.getLogger(\"pylabrobot.module\").setLevel(...)` |\n",
    "| Disable console | `pylabrobot.verbose(False)` |"
   ]
  }
 ],
 "metadata": {
  "kernelspec": {
   "display_name": "Python 3",
   "language": "python",
   "name": "python3"
  },
  "language_info": {
   "name": "python",
   "version": "3.13.0"
  }
 },
 "nbformat": 4,
 "nbformat_minor": 4
}