Skip to content

ENH: Print failure logs from logfiles for ERT log #138

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
slangeveld merged 1 commit into from
Aug 10, 2026
Merged

ENH: Print failure logs from logfiles for ERT log #138

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
53 changes: 52 additions & 1 deletion src/runrms/executor/fm_executor.py
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
import glob
import os
import re
import subprocess
import sys
import time
Expand Down Expand Up @@ -63,6 +64,37 @@ def _exec_rms(self) -> int:
comp_process = subprocess.run(args=args, check=False)
return comp_process.returncode

def _find_job_failures(self, logfile_path: Path) -> str:
"""Reads through a .log file and returns logs regarding failing jobs.

Any failure logs must be at the end of the log file as a failing job
breaks the workflow and will be the last thing that is logged.

The method first finds the logs for the last job that was started and returns
the findings as a formatted string if any job failures are found.
"""
current_job_line_no = 0

# Find the line number where the logging of the last job starts
with open(logfile_path) as logfile:
for line_no, line in enumerate(logfile, start=1):

@slangeveld slangeveld Jul 17, 2026 •
edited
Loading

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The assumption is that the logs from the failing job we are interested in, will be at the end of the file as that will break the workflow (and stop logging)

Therefore we look for the log section for the last job that was ran before the workflow breaks

if line.strip().startswith("<pre>"):

@slangeveld slangeveld Jul 17, 2026

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Each new job starts with this <pre> tag

current_job_line_no = line_no
last_job_line_no = current_job_line_no
if last_job_line_no == 0:
return ""

# Collect the logs for the last job and look for failures

@slangeveld slangeveld Jul 17, 2026

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Once we know which line the log section for the last job starts, we can iterate through this section line for line, parse the logs and look for failures.

with open(logfile_path) as logfile:
job_failed_msg = ""
for line_no, line in enumerate(logfile, start=1):
if line_no >= last_job_line_no:
cleaned_text = re.sub(r"<[^>]*>", "", line)
if cleaned_text != "":
job_failed_msg += cleaned_text

return job_failed_msg if "failed" in job_failed_msg else ""

@slangeveld slangeveld Jul 17, 2026

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

When a job fails it is logged "Job: failed", "Failed job " or "Workflow failed" so the assumption is that as long as the log section for the last job contains the word "failed", the job has failed and we want to return those log messages.

Can probably improve a bit on how we evaluate if a job has failures, but maybe it is good enough as a first iteration


def print_failure(self, exit_status: int) -> None:
run_path = self.config.run_path.resolve()
# Reverse sort so workflow.log is (probably) first and
Expand Down Expand Up @@ -111,14 +143,33 @@ def print_failure(self, exit_status: int) -> None:
* RMS.stderr.NN and RMS.stdout.NN
* rms/model/workflow.log
* Other named log files in rms/model, e.g. workflow_sim2seis.log
* rms/model/YYYYMMDD-HHMMSS-XXXXX-RMS.log corresponding to your run
* rms/model/YYYYMMDD-HHMMSS-XXXXXX-RMS.log corresponding to your run

@slangeveld slangeveld Jul 17, 2026

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

From checking the logs on scratch after an ERT run, the given format appeared to be wrong. The XXXXXX part of the file name has 6 characters, not 5.


The following log files were found in this realization's run path:

"""
)
fail_msg += "\n".join([f"* {f}" for f in log_files])

for log_file in log_files:

@slangeveld slangeveld Jul 17, 2026 •
edited
Loading

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Loop through the logfiles and look for failures. If any failures are found we break and return as we only want to print the most relevant log files to not pollute the logs of the users.

Due to the sorting of the logfiles, we assume the most relevant logfile (workflog.log) will appear first in the list so that will be checked first. If no failures are found in workflow.log, we examine the next file.

if re.match(
r"^\d{8}-\d{6}-[A-Za-z0-9]{6}-RMS", os.path.basename(log_file)
):
# These logfiles are unstructured and will not give any results

@slangeveld slangeveld Jul 17, 2026

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Logfiles on the format "YYYYMMDD-HHMMSS-XXXXXX-RMS.log" are skipped as they are on a different format and does not contain job specific logs: As the workflow.log files are easier to parse and gives a more detailed overview of the failure, we have chosen to focus on these workflow.log files in this first iteration.

continue
try:
job_failed_msg = self._find_job_failures(Path(log_file))
except Exception:
job_failed_msg = ""

@slangeveld slangeveld Jul 17, 2026 •
edited
Loading

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

To make sure an exception in the search after job failures does not affect the rest of the error logging, we simply catch all exception that might occur during this search and return an emtpy string instead.

In this way the error message is kept as before if no failures are found or any exceptions occur while searching, with the addition that any discovered failures will be appended at the end of the fail_msg and displayed to the user.

if job_failed_msg:
fail_msg += dedent(
f"""
\nThe following logs regarding failed jobs were found in the log file {log_file}:"
"""
)
fail_msg += job_failed_msg
break

print(fail_msg, file=sys.stderr)

@property
Expand Down
57 changes: 57 additions & 0 deletions tests/conftest.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -221,3 +221,60 @@ def master_version() -> str:
End GEOMATIC file header
"""
)


@pytest.fixture
def workflow_log() -> Callable[[Path], Path]:
"""Returns a helper function to write a workflow log to file."""

def _workflow_log(run_path: Path) -> Path:
"""Writes a workflow log to the workflow.log file at the provided run path."""
path = run_path / "workflow.log"
with open(path, "w", encoding="utf-8") as f:
f.write(
dedent(
"""
Log format
<head><meta http-equiv="Content-Type" content="text/html; charset=UTF-8" /></head>
<b>Project realization 1</b>

<pre>
Job 1 - Some job that runs OK - for project realization 0
</pre>
<font color="green"><b>Completed job 1</b></font>
<table border="1"><tr><td><b>Elapsed time</b></td><td>0:00:02.2</td></tr><tr><td><b>Total elapsed time</b></td><td>0:00:02.9</td></tr></table>

<pre>
Job 2 - structural_model_initial - for project realization 0
<head><meta http-equiv="Content-Type" content="text/html; charset=UTF-8" /></head>
<b>Project realization 0</b>
<pre>

Job 1 - Note - for project realization 0 - skipped
</pre>
<font color="green"><b>Completed job 1</b></font>

<pre>
Job 2 - failing_python_job.py - for project realization 0
Traceback (most recent call last):
Python script, line 36
Python script, line 24, in main
ModuleNotFoundError: No module named 'non_existing_package'
Job: failing_python_job.py failed.
</pre>
<font color='red'><b>Failed job 2</b></font>
<font color="red"><b>Workflow structural_model_initial failed</b></font>
<table border="1"><tr><td><b>Finish time</b></td><td>15:37:07</td></tr><tr><td><b>Elapsed time for workflow</b></td><td>0:00:20.0</td></tr></table>
<hr /><div />
Job: structural_model_initial failed.
</pre>
<font color='red'><b>Failed job 2</b></font>
<font color="red"><b>Workflow MAIN failed</b></font>
<table border="1"><tr><td><b>Finish time</b></td><td>15:37:07</td></tr><tr><td><b>Elapsed time for workflow</b></td><td>0:00:20.5</td></tr></table>
<hr /><div />
""" # noqa: E501
)
)
return path

return _workflow_log
Loading