From c020e8c453f4648cbe1b2e14fea9fa4e6e97fb0f Mon Sep 17 00:00:00 2001 From: Andreas Eknes Lie Date: Wed, 4 Sep 2024 13:18:49 +0200 Subject: [PATCH] Add debug info to clipboard capability --- src/ert/__main__.py | 14 +--- src/ert/gui/simulation/experiment_panel.py | 83 ++++++++++++++++++- src/ert/gui/simulation/run_dialog.py | 11 +++ src/ert/run_models/base_run_model.py | 38 +++++++-- src/ert/shared/status/utils.py | 13 +++ .../gui/simulation/test_run_dialog.py | 38 ++++++++- 6 files changed, 175 insertions(+), 22 deletions(-) diff --git a/src/ert/__main__.py b/src/ert/__main__.py index 1ad82a4f076..29a712478ac 100755 --- a/src/ert/__main__.py +++ b/src/ert/__main__.py @@ -626,17 +626,7 @@ def ert_parser(parser: Optional[ArgumentParser], args: Sequence[str]) -> Namespa def log_process_usage() -> None: try: usage = resource.getrusage(resource.RUSAGE_SELF) - - if sys.platform == "darwin": - # macOS apparently outputs the maxrss value as bytes rather than - # kilobytes as on Linux. - # - # https://stackoverflow.com/questions/59913657/strange-values-of-get-rusage-maxrss-on-macos-and-linux - rss_scale = 1000 - else: - rss_scale = 1 - - maxrss = usage.ru_maxrss // rss_scale + max_rss = ert.shared.status.utils.get_ert_memory_usage() usage_dict: Dict[str, Union[int, float]] = { "User time": usage.ru_utime, @@ -647,7 +637,7 @@ def log_process_usage() -> None: "Socket messages Received": usage.ru_msgrcv, "Signals received": usage.ru_nsignals, "Swaps": usage.ru_nswap, - "Peak memory use (KB)": maxrss, + "Peak memory use (KB)": max_rss, } logger.info(f"Ert process usage: {usage_dict}") except Exception as exc: diff --git a/src/ert/gui/simulation/experiment_panel.py b/src/ert/gui/simulation/experiment_panel.py index 90a02a18c2e..32f1bd94963 100644 --- a/src/ert/gui/simulation/experiment_panel.py +++ b/src/ert/gui/simulation/experiment_panel.py @@ -1,8 +1,13 @@ from __future__ import annotations +import os +import platform from collections import OrderedDict +from dataclasses import fields +from datetime import datetime +from pathlib import Path from queue import SimpleQueue -from typing import TYPE_CHECKING, Any, List, Type +from typing import TYPE_CHECKING, Any, Dict, List, Type from qtpy.QtCore import QSize, Qt, Signal from qtpy.QtGui import QIcon, QStandardItemModel @@ -21,8 +26,14 @@ QWidget, ) +import ert.shared from ert.gui.ertnotifier import ErtNotifier -from ert.run_models import BaseRunModel, StatusEvents, create_model +from ert.run_models import BaseRunModel, SingleTestRun, StatusEvents, create_model +from ert.shared.status.utils import ( + byte_with_unit, + format_running_time, + get_ert_memory_usage, +) from .combobox_with_description import QComboBoxWithDescription from .ensemble_experiment_panel import EnsembleExperimentPanel @@ -42,6 +53,14 @@ EXPERIMENT_IS_RUNNING_BUTTON_MESSAGE = "Experiment running..." +def create_md_table(kv: Dict[str, str], output: str) -> str: + for k, v in kv.items(): + v = v.replace("_", r"\_") + output += f"| {k} | {v} |\n" + output += "\n" + return output + + class ExperimentPanel(QWidget): experiment_type_changed = Signal(ExperimentConfigPanel) @@ -206,6 +225,8 @@ def run_experiment(self) -> None: ) return + self._model = model + QApplication.restoreOverrideCursor() if model.check_if_runpath_exists(): msg_box = QMessageBox(self) @@ -270,6 +291,8 @@ def run_experiment(self) -> None: self.parent(), # type: ignore output_path=self.config.analysis_config.log_path, ) + dialog.produce_clipboard_debug_info.connect(self.populate_clipboard_debug_info) + self.run_button.setEnabled(False) self.run_button.setText(EXPERIMENT_IS_RUNNING_BUTTON_MESSAGE) dialog.run_experiment() @@ -297,3 +320,59 @@ def validationStatusChanged(self) -> None: self.run_button.text() == EXPERIMENT_READY_TO_RUN_BUTTON_MESSAGE and widget.isConfigurationValid() ) + + def populate_clipboard_debug_info(self) -> None: + kv = {"**Platform**": "", ":-----": ":-----"} + kv["Date"] = datetime.now().isoformat(" ", "seconds") + kv["OS"] = ( + platform.system() + " " + platform.release() + " " + platform.machine() + ) + kv["Hostname"] = ert.shared.get_machine_name() + kv["Komodo release"] = os.environ.get("KOMODO_RELEASE", "") + kv["Python version"] = platform.python_version() + + kv["**Ensemble**"] = "" + queue_system = self.config.queue_config.queue_system + kv["Queue"] = queue_system.name.capitalize() + kv["Simulation mode"] = self.get_current_experiment_type().name() + kv["Config file"] = str(Path(self._config_file).absolute()) + kv["Storage path"] = self.config.ens_path + kv["Run path"] = str(self.config.model_config.runpath_format_string) + kv["Ensemble size"] = str(self.config.model_config.num_realizations) + + if self.config.queue_config.realization_memory > 0: + kv["Realization memory"] = byte_with_unit( + self.config.queue_config.realization_memory + ) + + if self.config.queue_config.max_submit > 1: + kv["Max submit"] = str(self.config.queue_config.max_submit) + if self.config.queue_config.stop_long_running: + kv["Stop long running"] = str(self.config.queue_config.stop_long_running) + + queue_opts = self.config.queue_config.queue_options + + if isinstance(self.get_current_experiment_type(), SingleTestRun): + queue_opts = self.config.queue_config.queue_options_test_run + + for field in fields(queue_opts): + field_value = getattr(queue_opts, field.name) + if field_value is not None: + kv[field.name.replace("_", " ").capitalize()] = str(field_value) + + kv["**Status**"] = "" + kv["Running time"] = ( + format_running_time(self._model.get_runtime()).split(":")[1].strip() + ) + kv["Ert max memory"] = byte_with_unit(get_ert_memory_usage()) + kv["Forward model max memory"] = byte_with_unit( + self._model.get_memory_consumption() + ) + + for status, count in self._model.get_current_status().items(): + kv[status] = str(count) + + output = create_md_table(kv, "") + clipboard = QApplication.clipboard() + if clipboard: + clipboard.setText(output) diff --git a/src/ert/gui/simulation/run_dialog.py b/src/ert/gui/simulation/run_dialog.py index ab53bbf28f7..92437e01c53 100644 --- a/src/ert/gui/simulation/run_dialog.py +++ b/src/ert/gui/simulation/run_dialog.py @@ -169,6 +169,7 @@ def mouseMoveEvent(self, event: QMouseEvent | None) -> None: class RunDialog(QDialog): simulation_done = Signal(bool, str) + produce_clipboard_debug_info = Signal() on_run_model_event = Signal(object) _RUN_TIME_POLL_RATE = 1000 @@ -234,6 +235,10 @@ def __init__( self.done_button.setHidden(True) self.restart_button = QPushButton("Restart") self.restart_button.setHidden(True) + self.copy_debug_info_button = QPushButton("Debug Info") + self.copy_debug_info_button.setToolTip("Copies useful information to clipboard") + self.copy_debug_info_button.clicked.connect(self.produce_clipboard_debug_info) + self.copy_debug_info_button.setObjectName("copy_debug_info_button") size = 20 spin_movie = QMovie("img:loading.gif") @@ -252,6 +257,7 @@ def __init__( button_layout.addStretch() button_layout.addWidget(self.memory_usage) button_layout.addStretch() + button_layout.addWidget(self.copy_debug_info_button) button_layout.addWidget(self.plot_button) button_layout.addWidget(self.kill_button) button_layout.addWidget(self.done_button) @@ -517,6 +523,9 @@ def restart_failed_realizations(self) -> None: self.done_button.setVisible(False) self.run_experiment(restart=True) + def get_runtime(self) -> int: + return self._run_model.get_runtime() + def _on_finished(self) -> None: for file_dialog in self.findChildren(FileDialog): file_dialog.close() @@ -526,6 +535,8 @@ def keyPressEvent(self, a0: Optional[QKeyEvent]) -> None: # so call self.close() instead if a0 is not None and a0.key() == Qt.Key.Key_Escape: self.close() + elif a0 is not None and a0.key() == Qt.Key.Key_F1: + self.produce_clipboard_debug_info.emit() else: QDialog.keyPressEvent(self, a0) diff --git a/src/ert/run_models/base_run_model.py b/src/ert/run_models/base_run_model.py index a9944365efd..e66215c8b5c 100644 --- a/src/ert/run_models/base_run_model.py +++ b/src/ert/run_models/base_run_model.py @@ -365,18 +365,40 @@ def get_runtime(self) -> int: return round(time.time() - self.start_time) return self.stop_time - self.start_time - def _current_status(self) -> tuple[dict[str, int], float, int]: + def get_current_status(self) -> dict[str, int]: + status: dict[str, int] = defaultdict(int) + if self._iter_snapshot.keys(): + current_iter = max(list(self._iter_snapshot.keys())) + all_realizations = self._iter_snapshot[current_iter].reals + + if all_realizations: + for real in all_realizations.values(): + status[str(real["status"])] += 1 + + return status + + def get_memory_consumption(self) -> int: + max_memory_consumption: int = 0 + if self._iter_snapshot.keys(): + current_iter = max(list(self._iter_snapshot.keys())) + for fm in ( + self._iter_snapshot[current_iter].get_all_forward_models().values() + ): + max_usage = fm.get("max_memory_usage", "0") + if max_usage: + max_memory_consumption = max(int(max_usage), max_memory_consumption) + + return max_memory_consumption + + def _current_progress(self) -> tuple[float, int]: current_iter = max(list(self._iter_snapshot.keys())) done_realizations = 0 all_realizations = self._iter_snapshot[current_iter].reals current_progress = 0.0 - status: dict[str, int] = defaultdict(int) realization_count = len(all_realizations) if all_realizations: for real in all_realizations.values(): - status[str(real["status"])] += 1 - if real["status"] in [ REALIZATION_STATE_FINISHED, REALIZATION_STATE_FAILED, @@ -390,13 +412,14 @@ def _current_status(self) -> tuple[dict[str, int], float, int]: else realization_progress ) - return status, current_progress, realization_count + return current_progress, realization_count def send_snapshot_event(self, event: Event, iteration: int) -> None: if type(event) is EESnapshot: snapshot = Snapshot.from_nested_dict(event.snapshot) self._iter_snapshot[iteration] = snapshot - status, current_progress, realization_count = self._current_status() + current_progress, realization_count = self._current_progress() + status = self.get_current_status() self.send_event( FullSnapshotEvent( iteration_label=f"Running forecast for iteration: {iteration}", @@ -420,7 +443,8 @@ def send_snapshot_event(self, event: Event, iteration: int) -> None: event, source_snapshot=self._iter_snapshot[iteration] ) self._iter_snapshot[iteration].merge_snapshot(snapshot) - status, current_progress, realization_count = self._current_status() + current_progress, realization_count = self._current_progress() + status = self.get_current_status() self.send_event( SnapshotUpdateEvent( iteration_label=f"Running forecast for iteration: {iteration}", diff --git a/src/ert/shared/status/utils.py b/src/ert/shared/status/utils.py index 0836e695390..99c905f542e 100644 --- a/src/ert/shared/status/utils.py +++ b/src/ert/shared/status/utils.py @@ -1,5 +1,7 @@ import math import os +import resource +import sys def byte_with_unit(byte_count: float) -> str: @@ -69,3 +71,14 @@ def file_has_content(file_path: str) -> bool: if file_path_exists: return os.path.getsize(file_path) > 0 return False + + +def get_ert_memory_usage() -> int: + usage = resource.getrusage(resource.RUSAGE_SELF) + rss_scale = 1 + if sys.platform == "darwin": + # macOS apparently outputs the maxrss value as bytes rather than kilobytes as on Linux. + # https://stackoverflow.com/questions/59913657/strange-values-of-get-rusage-maxrss-on-macos-and-linux + rss_scale = 1000 + + return usage.ru_maxrss // rss_scale diff --git a/tests/unit_tests/gui/simulation/test_run_dialog.py b/tests/unit_tests/gui/simulation/test_run_dialog.py index 8a73927a58b..8078b352e41 100644 --- a/tests/unit_tests/gui/simulation/test_run_dialog.py +++ b/tests/unit_tests/gui/simulation/test_run_dialog.py @@ -6,7 +6,7 @@ from pytestqt.qtbot import QtBot from qtpy import QtWidgets from qtpy.QtCore import Qt, QTimer -from qtpy.QtWidgets import QComboBox, QToolButton, QWidget +from qtpy.QtWidgets import QApplication, QComboBox, QPushButton, QToolButton, QWidget import ert from ert.config import ErtConfig @@ -553,6 +553,42 @@ def handle_error_dialog(run_dialog): qtbot.waitUntil(run_dialog.done_button.isVisible, timeout=200000) +@pytest.mark.usefixtures("use_tmpdir") +def test_that_debug_info_button_provides_data_in_clipboard(qtbot: QtBot, storage): + config_file = "minimal_config.ert" + with open(config_file, "w", encoding="utf-8") as f: + f.write("NUM_REALIZATIONS 1") + args_mock = Mock() + args_mock.config = config_file + + ert_config = ErtConfig.from_file(config_file) + with StorageService.init_service( + project=os.path.abspath(ert_config.ens_path), + ): + gui = _setup_main_window(ert_config, args_mock, GUILogHandler(), storage) + experiment_panel = gui.findChild(ExperimentPanel) + assert isinstance(experiment_panel, ExperimentPanel) + + run_experiment = experiment_panel.findChild(QWidget, name="run_experiment") + assert run_experiment + assert isinstance(run_experiment, QToolButton) + + qtbot.mouseClick(run_experiment, Qt.LeftButton) + qtbot.waitUntil(lambda: gui.findChild(RunDialog) is not None, timeout=5000) + run_dialog = gui.findChild(RunDialog) + qtbot.waitUntil(run_dialog.done_button.isVisible, timeout=100000) + + copy_debug_info_button = gui.findChild(QPushButton, "copy_debug_info_button") + assert copy_debug_info_button + assert isinstance(copy_debug_info_button, QPushButton) + qtbot.mouseClick(copy_debug_info_button, Qt.LeftButton) + + clipboard_text = QApplication.clipboard().text() + + for keyword in ["Single realization test-run", "Local", r"minimal\_config.ert"]: + assert keyword in clipboard_text + + def test_that_stdout_and_stderr_buttons_react_to_file_content( snake_oil_case_storage: ErtConfig, qtbot: QtBot ):