Skip to content

Commit 818219d

Browse files
slangeveldslangeveld
authored
ENH: Print failure logs in logfiles to display in ERT (#138)
1 parent 8f3b3f9 commit 818219d

3 files changed

Lines changed: 438 additions & 3 deletions

File tree

‎src/runrms/executor/fm_executor.py‎

Lines changed: 52 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
import glob
22
import os
3+
import re
34
import subprocess
45
import sys
56
import time
@@ -63,6 +64,37 @@ def _exec_rms(self) -> int:
6364
comp_process = subprocess.run(args=args, check=False)
6465
return comp_process.returncode
6566

67+
def _find_job_failures(self, logfile_path: Path) -> str:
68+
"""Reads through a .log file and returns logs regarding failing jobs.
69+
70+
Any failure logs must be at the end of the log file as a failing job
71+
breaks the workflow and will be the last thing that is logged.
72+
73+
The method first finds the logs for the last job that was started and returns
74+
the findings as a formatted string if any job failures are found.
75+
"""
76+
current_job_line_no = 0
77+
78+
# Find the line number where the logging of the last job starts
79+
with open(logfile_path) as logfile:
80+
for line_no, line in enumerate(logfile, start=1):
81+
if line.strip().startswith("<pre>"):
82+
current_job_line_no = line_no
83+
last_job_line_no = current_job_line_no
84+
if last_job_line_no == 0:
85+
return ""
86+
87+
# Collect the logs for the last job and look for failures
88+
with open(logfile_path) as logfile:
89+
job_failed_msg = ""
90+
for line_no, line in enumerate(logfile, start=1):
91+
if line_no >= last_job_line_no:
92+
cleaned_text = re.sub(r"<[^>]*>", "", line)
93+
if cleaned_text != "":
94+
job_failed_msg += cleaned_text
95+
96+
return job_failed_msg if "failed" in job_failed_msg else ""
97+
6698
def print_failure(self, exit_status: int) -> None:
6799
run_path = self.config.run_path.resolve()
68100
# Reverse sort so workflow.log is (probably) first and
@@ -111,14 +143,33 @@ def print_failure(self, exit_status: int) -> None:
111143
* RMS.stderr.NN and RMS.stdout.NN
112144
* rms/model/workflow.log
113145
* Other named log files in rms/model, e.g. workflow_sim2seis.log
114-
* rms/model/YYYYMMDD-HHMMSS-XXXXX-RMS.log corresponding to your run
146+
* rms/model/YYYYMMDD-HHMMSS-XXXXXX-RMS.log corresponding to your run
115147
116148
The following log files were found in this realization's run path:
117149
118150
"""
119151
)
120152
fail_msg += "\n".join([f"* {f}" for f in log_files])
121153

154+
for log_file in log_files:
155+
if re.match(
156+
r"^\d{8}-\d{6}-[A-Za-z0-9]{6}-RMS", os.path.basename(log_file)
157+
):
158+
# These logfiles are unstructured and will not give any results
159+
continue
160+
try:
161+
job_failed_msg = self._find_job_failures(Path(log_file))
162+
except Exception:
163+
job_failed_msg = ""
164+
if job_failed_msg:
165+
fail_msg += dedent(
166+
f"""
167+
\nThe following logs regarding failed jobs were found in the log file {log_file}:"
168+
"""
169+
)
170+
fail_msg += job_failed_msg
171+
break
172+
122173
print(fail_msg, file=sys.stderr)
123174

124175
@property

‎tests/conftest.py‎

Lines changed: 57 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -221,3 +221,60 @@ def master_version() -> str:
221221
End GEOMATIC file header
222222
"""
223223
)
224+
225+
226+
@pytest.fixture
227+
def workflow_log() -> Callable[[Path], Path]:
228+
"""Returns a helper function to write a workflow log to file."""
229+
230+
def _workflow_log(run_path: Path) -> Path:
231+
"""Writes a workflow log to the workflow.log file at the provided run path."""
232+
path = run_path / "workflow.log"
233+
with open(path, "w", encoding="utf-8") as f:
234+
f.write(
235+
dedent(
236+
"""
237+
Log format
238+
<head><meta http-equiv="Content-Type" content="text/html; charset=UTF-8" /></head>
239+
<b>Project realization 1</b>
240+
241+
<pre>
242+
Job 1 - Some job that runs OK - for project realization 0
243+
</pre>
244+
<font color="green"><b>Completed job 1</b></font>
245+
<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>
246+
247+
<pre>
248+
Job 2 - structural_model_initial - for project realization 0
249+
<head><meta http-equiv="Content-Type" content="text/html; charset=UTF-8" /></head>
250+
<b>Project realization 0</b>
251+
<pre>
252+
253+
Job 1 - Note - for project realization 0 - skipped
254+
</pre>
255+
<font color="green"><b>Completed job 1</b></font>
256+
257+
<pre>
258+
Job 2 - failing_python_job.py - for project realization 0
259+
Traceback (most recent call last):
260+
Python script, line 36
261+
Python script, line 24, in main
262+
ModuleNotFoundError: No module named 'non_existing_package'
263+
Job: failing_python_job.py failed.
264+
</pre>
265+
<font color='red'><b>Failed job 2</b></font>
266+
<font color="red"><b>Workflow structural_model_initial failed</b></font>
267+
<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>
268+
<hr /><div />
269+
Job: structural_model_initial failed.
270+
</pre>
271+
<font color='red'><b>Failed job 2</b></font>
272+
<font color="red"><b>Workflow MAIN failed</b></font>
273+
<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>
274+
<hr /><div />
275+
""" # noqa: E501
276+
)
277+
)
278+
return path
279+
280+
return _workflow_log

0 commit comments

Comments
 (0)