{ "cells": [ { "metadata": {}, "cell_type": "markdown", "source": [ "# Logging 📄\n", "\n", "This notebook introduces the concept of logging using Python's built-in logging module. Logging is essential for tracking events that happen when some software runs. The module provides a way to configure different log handlers and severity levels.\n", "\n", "This notebook can be downloaded from the source code [here](https://github.com/andersretznerSGU/gwrefpy/blob/main/docs/user_guide/6_logging.ipynb).\n", "\n", "The logging levels available in `gwrefpy` are:\n", "- `DEBUG`: Detailed information, typically of interest only when diagnosing problems.\n", "- `INFO`: Confirmation that things are working as expected. This is the default logging level.\n", "- `WARNING`: An indication that something unexpected happened, or indicative of some problem in the near future\n", "- `ERROR`: Due to a more serious problem, the software has not been able to perform some function. Typically, these are issues will also raise exceptions." ], "id": "7089c522dababc77" }, { "metadata": {}, "cell_type": "markdown", "source": "Let's start by importing the necessary libraries and setting the logging level to `DEBUG` using the `set_logging_level` function.", "id": "e90d19164555a7c1" }, { "metadata": { "ExecuteTime": { "end_time": "2025-09-25T18:54:08.122694Z", "start_time": "2025-09-25T18:54:07.395160Z" } }, "cell_type": "code", "source": [ "import gwrefpy as gr\n", "import numpy as np\n", "import pandas as pd\n", "\n", "gr.set_log_level(\"DEBUG\") # Set logging level to DEBUG" ], "id": "8055b90446a20e26", "outputs": [ { "name": "stdout", "output_type": "stream", "text": [ "Log level set to DEBUG\n" ] } ], "execution_count": 1 }, { "metadata": {}, "cell_type": "markdown", "source": "We can now create some well objects and a model to see the logging in action.", "id": "820ba12d41db682c" }, { "metadata": { "tags": [ "hide-input" ], "ExecuteTime": { "end_time": "2025-09-25T18:54:08.147597Z", "start_time": "2025-09-25T18:54:08.142975Z" } }, "cell_type": "code", "source": [ "# Create some example data\n", "n_days = 100\n", "dates = pd.date_range(\"2020-01-01\", periods=n_days, freq=\"D\")\n", "\n", "# Observed and reference values with some noise\n", "values_obs1 = (\n", " 25.75\n", " + 0.7 * np.sin(np.linspace(0, 4 * np.pi, n_days))\n", " + np.random.normal(0, 0.1, n_days)\n", ")\n", "values_obs1 = pd.Series(values_obs1, index=dates)\n", "values_ref1 = (\n", " 18.75\n", " + 0.3 * np.sin(np.linspace(0, 4 * np.pi, n_days))\n", " + np.random.normal(0, 0.05, n_days)\n", ")\n", "values_ref1 = pd.Series(values_ref1, index=dates)" ], "id": "1aa3bef7234032fc", "outputs": [], "execution_count": 2 }, { "metadata": { "ExecuteTime": { "end_time": "2025-09-25T18:54:08.164174Z", "start_time": "2025-09-25T18:54:08.158764Z" } }, "cell_type": "code", "source": [ "# Creat the observed and reference wells\n", "obs1 = gr.Well(name=\"Obs. well\", is_reference=False)\n", "obs1.add_timeseries(values_obs1) # <-- Here we will see logging messages\n", "ref1 = gr.Well(name=\"Ref. well\", is_reference=True)\n", "ref1.add_timeseries(values_ref1) # <-- Here we will see logging messages\n", "\n", "# Create the model and add the wells\n", "model1 = gr.Model(name=\"Logging Example Model\")\n", "model1.add_well(obs1) # <-- Here we will see logging messages\n", "model1.add_well(ref1) # <-- Here we will see logging messages" ], "id": "d4cf851212fa7c3b", "outputs": [ { "name": "stdout", "output_type": "stream", "text": [ "Added timeseries to well Obs. well\n", "Added timeseries to well Ref. well\n", "Well 'Obs. well' added to model 'Logging Example Model'.\n", "Well 'Ref. well' added to model 'Logging Example Model'.\n" ] } ], "execution_count": 3 }, { "metadata": {}, "cell_type": "markdown", "source": "As you can see, we got logging messages in the console when adding the wells to the model. Now let's fit the model to see more logging messages.", "id": "96d264e429d5e067" }, { "metadata": { "ExecuteTime": { "end_time": "2025-09-25T18:54:09.468831Z", "start_time": "2025-09-25T18:54:08.925472Z" } }, "cell_type": "code", "source": [ "# Fit the model\n", "model1.fit(\n", " obs1,\n", " ref1,\n", " offset=\"0D\",\n", " tmin=dates[0],\n", " tmax=dates[-21],\n", ")" ], "id": "c97e4e0ebc9559fc", "outputs": [ { "name": "stdout", "output_type": "stream", "text": [ "Using linear regression method for fitting.\n", "Fit completed for model 'Logging Example Model' with RMSE 0.15953090249600974.\n", "Fitting model 'Logging Example Model' using reference well 'Ref. well' and observation well 'Obs. well'.\n", "Fit Results: Obs. well ~ Ref. well\n", "==================================\n", "Statistic Value Description\n", "--------------------------------------------------\n", "RMSE 0.1595 Root Mean Square Error\n", "R² 0.8928 Coefficient of Determination\n", "R-value 0.9449 Correlation Coefficient\n", "Slope 2.2887 Linear Regression Slope\n", "Intercept -17.1899 Linear Regression Intercept\n", "P-value 0.0000 Statistical Significance\n", "N 80 Number of Data Points\n", "Std Error 0.1616 Standard Error\n", "Confidence 95.0 % Confidence Level\n", "\n", "Calibration Period: 2020-01-01 00:00:00 to 2020-03-20 00:00:00\n", "Time Offset: 0D\n", "Aggregation Method: mean\n" ] }, { "data": { "text/plain": [ "FitResultData(ref_well='Ref. well', obs_well='Obs. well', rmse=0.1595, r²=0.8928, n=80)" ], "text/html": [ "\n", "
\n", " Fit Results: Obs. well ~ Ref. well\n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", "
StatisticValueDescription
RMSE0.1595Root Mean Square Error
R²0.8928Coefficient of Determination
R-value0.9449Correlation Coefficient
Slope2.2887Linear Regression Slope
Intercept-17.1899Linear Regression Intercept
P-value0.0000Statistical Significance
N80Number of Data Points
Std Error0.1616Standard Error
Confidence95.0%Confidence Level
\n", "

\n", " Calibration Period: 2020-01-01 00:00:00 to 2020-03-20 00:00:00
\n", " Time Offset: 0D
\n", " Aggregation Method: mean\n", "

\n", "
\n", " " ] }, "execution_count": 4, "metadata": {}, "output_type": "execute_result" } ], "execution_count": 4 }, { "metadata": {}, "cell_type": "markdown", "source": [ "As you can see both the progress and the results of the fitting are logged to the console.\n", "\n", "Usually, we do not want that much information printed to the console. For many practivale applications, the `INFO` logging level is sufficient. Let's change the logging level and see how it affects the output. We will also enable logging to a file with the `enable_file_logging` function, here we can set the logging level to `DEBUG` to capture all messages in the file.\n", "\n", "```{tip}\n", "If you want to log your own messages in your code, you can use the `get_logger` function to get a logger object and then use its methods to log messages at different levels (e.g., `logger.debug()`, `logger.info()`, etc.).\n", "\n", "In the example below, we will use the `logging` module directly to demonstrate this. The `info` and `debug` messages will be logged according to the logging level we set.\n", "```" ], "id": "8f894af570ada6da" }, { "metadata": { "ExecuteTime": { "end_time": "2025-09-25T18:54:09.478568Z", "start_time": "2025-09-25T18:54:09.475196Z" } }, "cell_type": "code", "source": [ "import logging\n", "logger = logging.getLogger(__name__)\n", "\n", "# Set logging level to INFO (default)\n", "gr.set_log_level(\"INFO\")\n", "# Enable logging to a file with DEBUG level\n", "gr.enable_file_logging(\"gwrefpy_debug.log\", loglevel=\"DEBUG\")" ], "id": "4687560a5c344524", "outputs": [ { "name": "stdout", "output_type": "stream", "text": [ "Log level set to INFO\n" ] } ], "execution_count": 5 }, { "metadata": {}, "cell_type": "markdown", "source": "Let's create a new model and fit it again to see the detailed logging in the file.", "id": "bd26b74cbb637617" }, { "metadata": { "tags": [ "hide-input" ], "ExecuteTime": { "end_time": "2025-09-25T18:54:09.491752Z", "start_time": "2025-09-25T18:54:09.488564Z" } }, "cell_type": "code", "source": [ "# Observed and reference values with some noise\n", "values_obs2 = (\n", " 25.75\n", " + 0.7 * np.sin(np.linspace(0, 4 * np.pi, n_days))\n", " + np.random.normal(0, 0.1, n_days)\n", ")\n", "values_obs2 = pd.Series(values_obs2, index=dates)\n", "values_ref2 = (\n", " 18.75\n", " + 0.3 * np.sin(np.linspace(0, 4 * np.pi, n_days))\n", " + np.random.normal(0, 0.05, n_days)\n", ")\n", "values_ref2 = pd.Series(values_ref2, index=dates)" ], "id": "fc03f000f89f8ef2", "outputs": [], "execution_count": 6 }, { "metadata": { "ExecuteTime": { "end_time": "2025-09-25T18:54:09.510373Z", "start_time": "2025-09-25T18:54:09.506308Z" } }, "cell_type": "code", "source": [ "# Creat the observed and reference wells\n", "logger.info(\"Creating wells with timeseries data\")\n", "obs2 = gr.Well(name=\"Obs. well 1\", is_reference=False)\n", "obs2.add_timeseries(values_obs2)\n", "ref2 = gr.Well(name=\"Ref. well 1\", is_reference=True)\n", "ref2.add_timeseries(values_ref2)\n", "logger.debug(\"Timeseries data added to wells\") # <-- This will be logged to the file only \n", "\n", "# Create the model and add the wells\n", "logger.info(\"Creating a new model\")\n", "model2 = gr.Model(name=\"Logging Example Model DEBUG\")\n", "model2.add_well(obs2)\n", "model2.add_well(ref2)\n", "logger.debug(\"The wells have been added to the model\") # <-- This will be logged to the file only " ], "id": "3f5ab2bae8fdd23c", "outputs": [ { "name": "stdout", "output_type": "stream", "text": [ "Creating wells with timeseries data\n", "Creating a new model\n" ] } ], "execution_count": 7 }, { "metadata": {}, "cell_type": "markdown", "source": [ "Now, when we add the wells to the model, we will not see any logging messages in the console, but they will be logged to the file.\n", "\n", "We can now fit the model again." ], "id": "5715ce34f5f3be4c" }, { "metadata": { "ExecuteTime": { "end_time": "2025-09-25T18:54:09.531907Z", "start_time": "2025-09-25T18:54:09.523971Z" } }, "cell_type": "code", "source": [ "# Fit the model\n", "logger.info(\"Running the fit method on the model\")\n", "model2.fit(\n", " obs2,\n", " ref2,\n", " offset=\"0D\",\n", " tmin=dates[0],\n", " tmax=dates[-21],\n", ")" ], "id": "ce5257d5c221bf27", "outputs": [ { "name": "stdout", "output_type": "stream", "text": [ "Running the fit method on the model\n", "Fitting model 'Logging Example Model DEBUG' using reference well 'Ref. well 1' and observation well 'Obs. well 1'.\n" ] }, { "data": { "text/plain": [ "FitResultData(ref_well='Ref. well 1', obs_well='Obs. well 1', rmse=0.1712, r²=0.8609, n=80)" ], "text/html": [ "\n", "
\n", " Fit Results: Obs. well 1 ~ Ref. well 1\n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", " \n", "
StatisticValueDescription
RMSE0.1712Root Mean Square Error
R²0.8609Coefficient of Determination
R-value0.9278Correlation Coefficient
Slope2.1421Linear Regression Slope
Intercept-14.3748Linear Regression Intercept
P-value0.0000Statistical Significance
N80Number of Data Points
Std Error0.1734Standard Error
Confidence95.0%Confidence Level
\n", "

\n", " Calibration Period: 2020-01-01 00:00:00 to 2020-03-20 00:00:00
\n", " Time Offset: 0D
\n", " Aggregation Method: mean\n", "

\n", "
\n", " " ] }, "execution_count": 8, "metadata": {}, "output_type": "execute_result" } ], "execution_count": 8 }, { "metadata": {}, "cell_type": "markdown", "source": "As you can see, not as much will be printed to the console. But if we instead open `gwrefpy_debug.log` file we can see all the detailed logging information.", "id": "3e9080108ada3cd7" }, { "metadata": { "ExecuteTime": { "end_time": "2025-09-25T18:54:09.551819Z", "start_time": "2025-09-25T18:54:09.548235Z" } }, "cell_type": "code", "source": [ "# Print the log file content\n", "with open(\"gwrefpy_debug.log\", \"r\") as log_file:\n", " log_content = log_file.read()\n", "print(log_content)" ], "id": "46198cbe6fc96fc", "outputs": [ { "name": "stdout", "output_type": "stream", "text": [ "2025-09-25 20:54:09,507 [INFO] __main__: Creating wells with timeseries data\n", "2025-09-25 20:54:09,508 [DEBUG] gwrefpy.well: Added timeseries to well Obs. well 1\n", "2025-09-25 20:54:09,508 [DEBUG] gwrefpy.well: Added timeseries to well Ref. well 1\n", "2025-09-25 20:54:09,508 [DEBUG] __main__: Timeseries data added to wells\n", "2025-09-25 20:54:09,508 [INFO] __main__: Creating a new model\n", "2025-09-25 20:54:09,508 [DEBUG] gwrefpy.model: Well 'Obs. well 1' added to model 'Logging Example Model DEBUG'.\n", "2025-09-25 20:54:09,509 [DEBUG] gwrefpy.model: Well 'Ref. well 1' added to model 'Logging Example Model DEBUG'.\n", "2025-09-25 20:54:09,509 [DEBUG] __main__: The wells have been added to the model\n", "2025-09-25 20:54:09,524 [INFO] __main__: Running the fit method on the model\n", "2025-09-25 20:54:09,524 [DEBUG] gwrefpy.fitbase: Using linear regression method for fitting.\n", "2025-09-25 20:54:09,529 [DEBUG] gwrefpy.fitbase: Fit completed for model 'Logging Example Model DEBUG' with RMSE 0.17123610587395097.\n", "2025-09-25 20:54:09,529 [INFO] gwrefpy.fitbase: Fitting model 'Logging Example Model DEBUG' using reference well 'Ref. well 1' and observation well 'Obs. well 1'.\n", "2025-09-25 20:54:09,529 [DEBUG] gwrefpy.model: Fit Results: Obs. well 1 ~ Ref. well 1\n", "======================================\n", "Statistic Value Description\n", "--------------------------------------------------\n", "RMSE 0.1712 Root Mean Square Error\n", "R² 0.8609 Coefficient of Determination\n", "R-value 0.9278 Correlation Coefficient\n", "Slope 2.1421 Linear Regression Slope\n", "Intercept -14.3748 Linear Regression Intercept\n", "P-value 0.0000 Statistical Significance\n", "N 80 Number of Data Points\n", "Std Error 0.1734 Standard Error\n", "Confidence 95.0 % Confidence Level\n", "\n", "Calibration Period: 2020-01-01 00:00:00 to 2020-03-20 00:00:00\n", "Time Offset: 0D\n", "Aggregation Method: mean\n", "\n" ] } ], "execution_count": 9 }, { "metadata": {}, "cell_type": "markdown", "source": [ "As you can see, the log file contains detailed information about the program's execution, module, time, and log level, including messages that are not necessarily printed to the console.\n", "\n", "This concludes this notebook on logging in `gwrefpy`. For more information on logging, please refer to the [logging documentation](https://docs.python.org/3/library/logging.html) and the API for `gwrefpy`'s logging functions [here](https://andersretznersgu.github.io/gwrefpy/constants.html)." ], "id": "22742cc6441d7cc2" } ], "metadata": { "kernelspec": { "display_name": "Python 3", "language": "python", "name": "python3" }, "language_info": { "codemirror_mode": { "name": "ipython", "version": 2 }, "file_extension": ".py", "mimetype": "text/x-python", "name": "python", "nbconvert_exporter": "python", "pygments_lexer": "ipython2", "version": "2.7.6" } }, "nbformat": 4, "nbformat_minor": 5 }