ENH: Print failure logs from logfiles for ERT log - #138
Conversation
3a42e0f to
eba6567
Compare
|
|
||
| # 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): |
There was a problem hiding this comment.
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
| # 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): | ||
| if line.strip().startswith("<pre>"): |
There was a problem hiding this comment.
Each new job starts with this <pre> tag
| if last_job_line_no == 0: | ||
| return "" | ||
|
|
||
| # Collect the logs for the last job and look for failures |
There was a problem hiding this comment.
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.
| if cleaned_text != "": | ||
| job_failed_msg += cleaned_text | ||
|
|
||
| return job_failed_msg if "failed" in job_failed_msg else "" |
There was a problem hiding this comment.
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
| * 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 |
There was a problem hiding this comment.
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.
| ) | ||
| fail_msg += "\n".join([f"* {f}" for f in log_files]) | ||
|
|
||
| for log_file in log_files: |
There was a problem hiding this comment.
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 |
There was a problem hiding this comment.
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.
| try: | ||
| job_failed_msg = self._find_job_failures(Path(log_file)) | ||
| except Exception: | ||
| job_failed_msg = "" |
There was a problem hiding this comment.
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.
eba6567 to
2baf347
Compare
|
@perolavsvendsen feel free to add your feedback here as well |
tnatt
left a comment
There was a problem hiding this comment.
This looks like a nice first iteration, and it will be very useful and welcomed by users 🥳
We should remove all the rms/model/YYYYMMDD-HHMMSS-XXXXXX-RMS.log from the list of logs in the stderr though. They are making noise in the print and makes the failure message less prominent. I've never found anything useful in there that I could not use the workflow log for. This could be a separate issue.
Maybe in another iteration we will make a more general parser of the workflow log 🙂 For the user it would be very useful to have a structured log of what was run in RMS, the order of the jobs/workflows and the duration of them.
There was a problem hiding this comment.
Very nice!
I agree with Therese, that long list of log files is probably not needed and create some noise.
I also agree with the comment about making the workflow.log more available to the users, as it has a good overview of what is run and where it has failed.
I've tested it both with failing python script and with failing RMS standard job. Same result.
Good point regarding the |

Resolves #124
Add failure logs found in RMS logfiles as part of the output that is printed to ERT GUI after running RMS.
In this way we hope to improve the current error logging situation for users where they are left a bit in the dark if RMS fails during an ERT run. With this change, the users should in some situations (f.ex if a python script is failing) get a better understanding of what is actually failing and needs to be fixed.
Today,
runrmsprints the path to the logfiles so that the users can go and look for errors in the files themselves. This points them in the right direction, but actually finding the errors in these files can be challenging as the files can be large and it is difficult to know what to look for.With this change, runrms will now:
🔍 An example of how the job failures will be displayed in ERT gui can be seen in the comment below.
💬 Some comments are added below explaining assumptions that are made when looking for failures.
Checklist
--cov=runrms --cov-report term-missing)