From 515b5cbe6b4dff9cad3de6c2d4f0a88aed716b11 Mon Sep 17 00:00:00 2001 From: "power-grid-model-ci-bot[bot]" <249743335+power-grid-model-ci-bot[bot]@users.noreply.github.com> Date: Wed, 7 Oct 2026 02:33:59 +0000 Subject: [PATCH] Update the examples Signed-off-by: github-actions[bot] <41898282+github-actions[bot]@users.noreply.github.com> --- examples/Logging Example.ipynb | 593 +++++++++++++++++++++++++ examples/Logging Example.ipynb.license | 3 + 2 files changed, 596 insertions(+) create mode 100644 examples/Logging Example.ipynb create mode 100644 examples/Logging Example.ipynb.license diff --git a/examples/Logging Example.ipynb b/examples/Logging Example.ipynb new file mode 100644 index 0000000..6e604fd --- /dev/null +++ b/examples/Logging Example.ipynb @@ -0,0 +1,593 @@ +{ + "cells": [ + { + "cell_type": "markdown", + "id": "487cb63e", + "metadata": {}, + "source": [ + "# Logging Example\n", + "\n", + "This notebook shows how to use the logging feature of `power-grid-model`.\n", + "So far, there are two types of loggers available:\n", + "\n", + "| Type | What it captures |\n", + "|------|------------------|\n", + "| `LoggerType.info` | Timestamped debug messages. Useful for diagnosing various issues |\n", + "| `LoggerType.benchmark` | Per calculation phase timing totals. Useful for performance analysis |\n", + "\n", + "\n", + "> **Important**: loggers provide *hints*, not conclusions. Output is intended for advanced\n", + "> users and may change between releases.\n", + ">\n", + "> Logging has a performance cost, which is why it is **opt-in**: loggers are not active\n", + "> by default.\n", + "\n", + "## Example Network\n", + "\n", + "We reuse the 3-node network from the Power Flow Example:\n", + "\n", + "```\n", + " -----------------------line_8---------------\n", + " | |\n", + "node_1 ---line_3--- node_2 ----line_5---- node_6\n", + " | | |\n", + "source_10 sym_load_4 sym_load_7\n", + "```" + ] + }, + { + "cell_type": "markdown", + "id": "1202b29f", + "metadata": {}, + "source": [ + "## Imports" + ] + }, + { + "cell_type": "code", + "execution_count": 1, + "id": "e5b07c05", + "metadata": {}, + "outputs": [], + "source": [ + "from power_grid_model import (\n", + " AttributeType,\n", + " CalculationMethod,\n", + " ComponentType,\n", + " DatasetType,\n", + " LoadGenType,\n", + " Logger,\n", + " LoggerType,\n", + " PowerGridModel,\n", + " initialize_array,\n", + ")" + ] + }, + { + "cell_type": "markdown", + "id": "1368862a", + "metadata": {}, + "source": [ + "## Build the Input Dataset" + ] + }, + { + "cell_type": "code", + "execution_count": 2, + "id": "3fed3eaa", + "metadata": {}, + "outputs": [], + "source": [ + "node = initialize_array(DatasetType.input, ComponentType.node, 3)\n", + "node[AttributeType.id] = [1, 2, 6]\n", + "node[AttributeType.u_rated] = [10.5e3, 10.5e3, 10.5e3]\n", + "\n", + "line = initialize_array(DatasetType.input, ComponentType.line, 3)\n", + "line[AttributeType.id] = [3, 5, 8]\n", + "line[AttributeType.from_node] = [1, 2, 1]\n", + "line[AttributeType.to_node] = [2, 6, 6]\n", + "line[AttributeType.from_status] = [1, 1, 1]\n", + "line[AttributeType.to_status] = [1, 1, 1]\n", + "line[AttributeType.r1] = [0.25, 0.25, 0.25]\n", + "line[AttributeType.x1] = [0.2, 0.2, 0.2]\n", + "line[AttributeType.c1] = [10e-6, 10e-6, 10e-6]\n", + "line[AttributeType.tan1] = [0.0, 0.0, 0.0]\n", + "line[AttributeType.i_n] = [1000, 1000, 1000]\n", + "\n", + "sym_load = initialize_array(DatasetType.input, ComponentType.sym_load, 2)\n", + "sym_load[AttributeType.id] = [4, 7]\n", + "sym_load[AttributeType.node] = [2, 6]\n", + "sym_load[AttributeType.status] = [1, 1]\n", + "sym_load[AttributeType.type] = [LoadGenType.const_power, LoadGenType.const_power]\n", + "sym_load[AttributeType.p_specified] = [20e6, 10e6]\n", + "sym_load[AttributeType.q_specified] = [5e6, 2e6]\n", + "\n", + "source = initialize_array(DatasetType.input, ComponentType.source, 1)\n", + "source[AttributeType.id] = [10]\n", + "source[AttributeType.node] = [1]\n", + "source[AttributeType.status] = [1]\n", + "source[AttributeType.u_ref] = [1.0]\n", + "\n", + "input_data = {\n", + " ComponentType.node: node,\n", + " ComponentType.line: line,\n", + " ComponentType.sym_load: sym_load,\n", + " ComponentType.source: source,\n", + "}\n", + "\n", + "model = PowerGridModel(input_data)" + ] + }, + { + "cell_type": "markdown", + "id": "454914fc", + "metadata": {}, + "source": [ + "## Text Logger\n", + "\n", + "A `LoggerType.info` logger captures diagnostic messages emitted\n", + "during any stage of calculation. Each line is timestamped and tagged with the event code.\n", + "\n", + "**Usage:** use `Logger` as a context manager. On entry the logger is registered and active while on exit it is unregistered as renderend inactive. \n", + "The output buffer is preserved after the `with` block and is accessible via `logger.output`." + ] + }, + { + "cell_type": "code", + "execution_count": 3, + "id": "709151c2", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "[2026-10-06 13:50:26.923Z] Tag:2000: 0.000658\n", + "[2026-10-06 13:50:26.923Z] Tag:3100: 0.000001\n", + "[2026-10-06 13:50:26.924Z] Tag:3211: 0.000872\n", + "[2026-10-06 13:50:26.924Z] Tag:3233: 0.000007\n", + "[2026-10-06 13:50:26.924Z] Tag:3241: 0.000001\n", + "[2026-10-06 13:50:26.924Z] Tag:3251: 0.000083\n", + "[2026-10-06 13:50:26.924Z] Tag:3233: 0.000000\n", + "[2026-10-06 13:50:26.924Z] Tag:3241: 0.000001\n", + "[2026-10-06 13:50:26.924Z] Tag:3251: 0.000000\n", + "[2026-10-06 13:50:26.924Z] Tag:3233: 0.000000\n", + "[2026-10-06 13:50:26.924Z] Tag:3241: 0.000000\n", + "[2026-10-06 13:50:26.924Z] Tag:3251: 0.000000\n", + "[2026-10-06 13:50:26.924Z] Tag:3290: 0.000003\n", + "[2026-10-06 13:50:26.924Z] Tag:3200: 0.000990\n", + "[2026-10-06 13:50:26.924Z] Tag:3253: 3\n", + "[2026-10-06 13:50:26.924Z] Tag:3000: 0.001001\n", + "[2026-10-06 13:50:26.924Z] Tag:4000: 0.000008\n", + "[2026-10-06 13:50:26.924Z] Tag:100: 0.002803\n", + "\n" + ] + } + ], + "source": [ + "with Logger(LoggerType.info) as info_logger:\n", + " output_data = model.calculate_power_flow(\n", + " symmetric=True,\n", + " calculation_method=CalculationMethod.newton_raphson,\n", + " )\n", + "\n", + "print(info_logger.output)" + ] + }, + { + "cell_type": "markdown", + "id": "5646db62", + "metadata": {}, + "source": [ + "## Benchmark Logger\n", + "\n", + "A `LoggerType.benchmark` logger records cumulative time spent in each\n", + "calculation phase. The output is tab-separated with two columns: `EVENT_CODE` and\n", + "`VALUE` (seconds).\n", + "\n", + "Unlike the info logger, the benchmark logger ignores string messages entirely. It\n", + "only accumulates numeric (double) values of duration from internal timer events." + ] + }, + { + "cell_type": "code", + "execution_count": 4, + "id": "426c48ac", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "100\t4.3974e-05\n", + "2000\t5.725e-06\n", + "3000\t1.9704e-05\n", + "3200\t1.7246e-05\n", + "3211\t6.527e-06\n", + "3233\t1.052e-06\n", + "3241\t1.535e-06\n", + "3251\t1.492e-06\n", + "3253\t3\n", + "3290\t4.35e-06\n", + "4000\t1.1787e-05\n", + "\n" + ] + } + ], + "source": [ + "with Logger(LoggerType.benchmark) as bench_logger:\n", + " output_data = model.calculate_power_flow(\n", + " symmetric=True,\n", + " calculation_method=CalculationMethod.newton_raphson,\n", + " )\n", + "\n", + "print(bench_logger.output)" + ] + }, + { + "cell_type": "markdown", + "id": "17ba056c", + "metadata": {}, + "source": [ + "## Multiple Simultaneous Loggers\n", + "\n", + "Multiple logger types can be combined in a single `with` statement. Each logger\n", + "independently captures its own output." + ] + }, + { + "cell_type": "code", + "execution_count": 5, + "id": "754b572d", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "=== Info logger ===\n", + "[2026-10-06 13:50:26.950Z] Tag:2000: 0.000008\n", + "[2026-10-06 13:50:26.950Z] Tag:3211: 0.000006\n", + "[2026-10-06 13:50:26.950Z] Tag:3233: 0.000001\n", + "[2026-10-06 13:50:26.950Z] Tag:3241: 0.000001\n", + "[2026-10-06 13:50:26.950Z] Tag:3251: 0.000001\n", + "[2026-10-06 13:50:26.950Z] Tag:3233: 0.000000\n", + "[2026-10-06 13:50:26.950Z] Tag:3241: 0.000000\n", + "[2026-10-06 13:50:26.950Z] Tag:3251: 0.000000\n", + "[2026-10-06 13:50:26.950Z] Tag:3233: 0.000000\n", + "[2026-10-06 13:50:26.950Z] Tag:3241: 0.000000\n", + "[2026-10-06 13:50:26.950Z] Tag:3251: 0.000000\n", + "[2026-10-06 13:50:26.950Z] Tag:3290: 0.000008\n", + "[2026-10-06 13:50:26.950Z] Tag:3200: 0.000035\n", + "[2026-10-06 13:50:26.950Z] Tag:3253: 3\n", + "[2026-10-06 13:50:26.950Z] Tag:3000: 0.000040\n", + "[2026-10-06 13:50:26.950Z] Tag:4000: 0.000032\n", + "[2026-10-06 13:50:26.950Z] Tag:100: 0.000140\n", + "\n", + "=== Benchmark logger ===\n", + "100\t0.000139593\n", + "2000\t7.813e-06\n", + "3000\t3.9733e-05\n", + "3200\t3.4965e-05\n", + "3211\t5.763e-06\n", + "3233\t1.175e-06\n", + "3241\t1.548e-06\n", + "3251\t1.45e-06\n", + "3253\t3\n", + "3290\t7.65e-06\n", + "4000\t3.191e-05\n", + "\n" + ] + } + ], + "source": [ + "with (\n", + " Logger(LoggerType.info) as info_logger2,\n", + " Logger(LoggerType.benchmark) as bench_logger2,\n", + "):\n", + " output_data = model.calculate_power_flow(\n", + " symmetric=True,\n", + " calculation_method=CalculationMethod.newton_raphson,\n", + " )\n", + "\n", + "print(\"=== Info logger ===\")\n", + "print(info_logger2.output)\n", + "print(\"=== Benchmark logger ===\")\n", + "print(bench_logger2.output)" + ] + }, + { + "cell_type": "markdown", + "id": "5f8f356d", + "metadata": {}, + "source": [ + "## Accumulation and Clearing Content\n", + "\n", + "Output accumulates across all calculations inside a single `with` block. Call\n", + "`logger.clear_content()` inside the block to reset between calculations without\n", + "unregistering." + ] + }, + { + "cell_type": "code", + "execution_count": 6, + "id": "2d5130a7", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "Combined output (11 lines):\n", + "100\t0.000104808\n", + "2000\t1.3031e-05\n", + "3000\t4.802e-05\n", + "3200\t4.2484e-05\n", + "3211\t1.3951e-05\n", + "3233\t3.622e-06\n", + "3241\t5.827e-06\n", + "3251\t3.873e-06\n", + "3253\t3\n", + "3290\t1e-05\n", + "4000\t2.6465e-05\n", + "\n" + ] + } + ], + "source": [ + "with Logger(LoggerType.benchmark) as acc_logger:\n", + " # Run four calculations while output accumulates inside the with block\n", + " for _ in range(4):\n", + " model.calculate_power_flow(symmetric=True)\n", + "\n", + "print(f\"Combined output ({acc_logger.output.count('\\n')} lines):\")\n", + "print(acc_logger.output)" + ] + }, + { + "cell_type": "code", + "execution_count": 7, + "id": "d8a09276", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "After first calc (11 lines)\n", + "After clear_content: ''\n", + "After second calc (11 lines):\n", + "100\t4.4643e-05\n", + "2000\t5.386e-06\n", + "3000\t2.0341e-05\n", + "3200\t1.8172e-05\n", + "3211\t6.252e-06\n", + "3233\t1.266e-06\n", + "3241\t1.805e-06\n", + "3251\t3.294e-06\n", + "3253\t3\n", + "3290\t3.861e-06\n", + "4000\t1.0799e-05\n", + "\n" + ] + } + ], + "source": [ + "# clear_content() resets the buffer without unregistering. This can be useful between runs\n", + "with Logger(LoggerType.benchmark) as acc_logger:\n", + " model.calculate_power_flow(symmetric=True)\n", + " print(f\"After first calc ({acc_logger.output.count('\\n')} lines)\")\n", + "\n", + " acc_logger.clear_content()\n", + " print(f\"After clear_content: {acc_logger.output!r}\")\n", + "\n", + " model.calculate_power_flow(symmetric=True)\n", + "\n", + "print(f\"After second calc ({acc_logger.output.count('\\n')} lines):\")\n", + "print(acc_logger.output)" + ] + }, + { + "cell_type": "markdown", + "id": "7a081163", + "metadata": {}, + "source": [ + "## Reuse Across Runs\n", + "\n", + "A `Logger` object can be re-entered across multiple `with` blocks. Each entry\n", + "re-registers on the handle; each exit unregisters. Call `logger.clear_content()` between\n", + "runs to start with a fresh buffer." + ] + }, + { + "cell_type": "code", + "execution_count": 8, + "id": "73f98385", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "Run 1: 11 lines, Run 2: 11 lines\n" + ] + } + ], + "source": [ + "reuse_logger = Logger(LoggerType.benchmark)\n", + "\n", + "with reuse_logger:\n", + " model.calculate_power_flow(symmetric=True)\n", + "lines_run1 = reuse_logger.output.count(\"\\n\")\n", + "\n", + "reuse_logger.clear_content()\n", + "\n", + "with reuse_logger:\n", + " model.calculate_power_flow(symmetric=True)\n", + "lines_run2 = reuse_logger.output.count(\"\\n\")\n", + "\n", + "print(f\"Run 1: {lines_run1} lines, Run 2: {lines_run2} lines\")" + ] + }, + { + "cell_type": "markdown", + "id": "2e9ddc69", + "metadata": {}, + "source": [ + "## Python Logging Integration\n", + "\n", + "Pass `python_logger=` to route output through the standard `logging` module.\n", + "On `__exit__`, accumulated lines are flushed to `python_logger`. One log is recorded\n", + "per line at the configured level and the internal buffer is cleared. No manual flush needed." + ] + }, + { + "cell_type": "code", + "execution_count": 9, + "id": "0b63d096", + "metadata": {}, + "outputs": [ + { + "name": "stderr", + "output_type": "stream", + "text": [ + "INFO power_grid_model: Starting power flow calculation\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:2000: 0.000006\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3211: 0.000005\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3233: 0.000001\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3241: 0.000001\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3251: 0.000001\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3233: 0.000000\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3241: 0.000000\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3251: 0.000000\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3233: 0.000000\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3241: 0.000000\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3251: 0.000000\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3290: 0.000003\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3200: 0.000022\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3253: 3\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:3000: 0.000025\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:4000: 0.000010\n", + "INFO power_grid_model: [2026-10-06 13:50:27.028Z] Tag:100: 0.000068\n" + ] + }, + { + "name": "stdout", + "output_type": "stream", + "text": [ + "Buffer after exit: ''\n" + ] + } + ], + "source": [ + "import logging\n", + "\n", + "logging.basicConfig(level=logging.INFO, format=\"%(levelname)s %(name)s: %(message)s\")\n", + "py_logger = logging.getLogger(\"power_grid_model\")\n", + "\n", + "with Logger(LoggerType.info, python_logger=py_logger) as py_log_logger:\n", + " py_logger.info(\"Starting power flow calculation\")\n", + " model.calculate_power_flow(\n", + " symmetric=True,\n", + " calculation_method=CalculationMethod.newton_raphson,\n", + " )\n", + "\n", + "# __exit__ flushed each line to py_logger automatically; buffer is now empty\n", + "print(f\"Buffer after exit: {py_log_logger.output!r}\")" + ] + }, + { + "cell_type": "markdown", + "id": "a80668b1", + "metadata": {}, + "source": [ + "## Batch Calculations\n", + "\n", + "Loggers work seamlessly with batch calculations as well.\n", + "It internally handles logging of multi-threaded calculations.\n", + "In case of exceptions, correct output from loggers is not guaranteed." + ] + }, + { + "cell_type": "code", + "execution_count": 10, + "id": "aa8d5dfb", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "100\t0.00243333\n", + "1100\t0.000238997\n", + "1200\t0.000301152\n", + "1220\t5.8282e-05\n", + "1230\t8.8664e-05\n", + "1231\t3.2429e-05\n", + "2000\t2.1209e-05\n", + "3000\t8.1919e-05\n", + "3200\t7.464e-05\n", + "3211\t2.2738e-05\n", + "3233\t5.423e-06\n", + "3241\t6.964e-06\n", + "3251\t5.219e-06\n", + "3253\t3\n", + "3290\t2.7732e-05\n", + "4000\t3.5953e-05\n", + "\n" + ] + } + ], + "source": [ + "# Create a small batch update: vary the load in node_2 across 3 scenarios\n", + "load_update = initialize_array(DatasetType.update, ComponentType.sym_load, (3, 3))\n", + "load_update[AttributeType.id] = [4, 4, 4]\n", + "load_update[AttributeType.p_specified] = [10e6, 20e6, 30e6]\n", + "update_data = {ComponentType.sym_load: load_update}\n", + "\n", + "with Logger(LoggerType.benchmark) as batch_bench:\n", + " batch_output = model.calculate_power_flow(\n", + " update_data=update_data,\n", + " symmetric=True,\n", + " threading=0, # parallel\n", + " )\n", + "\n", + "print(batch_bench.output)" + ] + }, + { + "cell_type": "markdown", + "id": "24a62b68", + "metadata": {}, + "source": [ + "## Usage notes\n", + "\n", + "- **Do not** destroy (or let Python GC collect) a `Logger` inside an active `with` block. It \n", + " triggers a `ResourceWarning` and it is inefficient as the logger is not broadcasting but active internally. \n", + "- **Do not** use the same logger from multiple user threads simultaneously. (The internal C-level\n", + " batch calculation threads are safe.)" + ] + } + ], + "metadata": { + "kernelspec": { + "display_name": "power-grid-model (3.14.7)", + "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.14.7" + } + }, + "nbformat": 4, + "nbformat_minor": 5 +} diff --git a/examples/Logging Example.ipynb.license b/examples/Logging Example.ipynb.license new file mode 100644 index 0000000..7601059 --- /dev/null +++ b/examples/Logging Example.ipynb.license @@ -0,0 +1,3 @@ +SPDX-FileCopyrightText: Contributors to the Power Grid Model project + +SPDX-License-Identifier: MPL-2.0