Skip to content

Commit

Permalink
Merge pull request #2 from mantidproject/signals
Browse files Browse the repository at this point in the history
Add information about disk read/write speeds
  • Loading branch information
peterfpeterson authored Dec 29, 2023
2 parents 5c4112f + ee6e199 commit df605f9
Show file tree
Hide file tree
Showing 8 changed files with 364 additions and 165 deletions.
4 changes: 4 additions & 0 deletions .pre-commit-config.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -13,3 +13,7 @@ repos:
- id: ruff
args: [--fix, --exit-non-zero-on-fix]
- id: ruff-format
- repo: https://github.com/pre-commit/mirrors-mypy
rev: v1.1.1
hooks:
- id: mypy
20 changes: 15 additions & 5 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,8 @@ Use [psrecord](https://github.com/astrofrog/psrecord) and [Plotly.js](https://pl

It monitors CPU and RAM usage, and reports the time span of each algorithm (currently, only algorithms are recorded).

![screenshot of AlignAndFocusPowderFromFiles](screenshot.png)

## Usage

To profile the `SNSPowderReduction.py` workflow:
Expand Down Expand Up @@ -36,11 +38,16 @@ You can interact with a demo profile [here](http://www.nbi.dk/~nvaytet/SNSPowder

## More options for mantid-profiler.py

- `--outfile`: (type=`str`) Specify the name of the output profile. Default is `profile.html`.
- `--infile`: (type=`str`) Specify the name of input file containing algorithm timings. Default is `algotimeregister.out`.
- `--logfile`: (type=`str`) Choose a name for output file containing process monitor data generated by `psrecord`. Default is `mantidprofile.txt`.
- `--interval`: (type=`float`) How long to wait between each sample (in seconds) for CPU and RAM monitoring. By default the process is sampled as often as possible.
- `--mintime`: (type=`float`) Minimum duration of an algorithm for it to appear in the profiling graph (in seconds). Default is 0.1s.
- `-h`, `--help` show this help message and exit
- `--outfile OUTFILE` name of output html file (default: `profile.html`)
- `--infile INFILE` name of input file containing algorithm timings (default: `algotimeregister.out`)
- `--logfile LOGFILE` name of output file containing process monitor data (default: `mantidprofile.txt`)
- `--diskfile DISKFILE` name of output file containing process disk usage data (default: `mantiddisk.txt`)
- `--interval INTERVAL` how long to wait between each sample (in seconds). By default the process is sampled as often as possible. (default: None)
- `--noclean` remove files upon successful completion (default: False)
- `--height HEIGHT` height for html plot (default: 800)
- `--bytes` Report disk speed in GBps rather than Gbps (default: False)
- `--mintime MINTIME` minimum duration for an algorithm to appear inthe profiling graph (in seconds). (default: 0.1)

## Similar projects

Expand All @@ -49,3 +56,6 @@ You can interact with a demo profile [here](http://www.nbi.dk/~nvaytet/SNSPowder
## Contact

Neil Vaytet, European Spallation Source

[![License: GPL v3](https://img.shields.io/badge/License-GPLv3-blue.svg)](https://www.gnu.org/licenses/gpl-3.0)
[![pre-commit.ci status](https://results.pre-commit.ci/badge/github/mantidproject/mantid-profiler/main.svg)](https://results.pre-commit.ci/latest/github/mantidproject/mantid-profiler/main)
7 changes: 6 additions & 1 deletion algorithm_tree.py
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@

import copy
import re
from pathlib import Path


class Node:
Expand Down Expand Up @@ -137,7 +138,7 @@ def parseLine(line):
return {"thread_id": res.group(1), "name": res.group(2), "start": int(res.group(3)), "finish": int(res.group(4))}


def fromFile(fileName):
def fromFile(fileName: Path, cleanup: bool = True):
res = []
header = ""
with open(fileName) as inp:
Expand All @@ -146,6 +147,10 @@ def fromFile(fileName):
header = line.strip("\n")
continue
res.append(parseLine(line))

if cleanup and fileName.exists():
fileName.unlink()

return header, res


Expand Down
120 changes: 120 additions & 0 deletions diskrecord.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,120 @@
from pathlib import Path
from time import sleep
from typing import Optional

import numpy as np
import psutil

from time_util import get_current_time, get_start_time


def monitor(pid: int, logfile: Path, interval: Optional[float], show_bytes: bool = False) -> None:
"""Monitor the disk usage of the supplied process id
The interval defaults to 0.05 if not supplied"""
# change interval to reasonable default
# being too small doesn't aid in understanding performance
DEFAULT_INTERVAL = 0.05
if interval is None:
interval = DEFAULT_INTERVAL
else:
interval = max(DEFAULT_INTERVAL, interval)

process = psutil.Process(pid)

# Record start time
starting_point = get_start_time()
start_time = get_current_time()
last_time = start_time

disk_before = process.io_counters()

with open(logfile, "w") as handle:
# add header
handle.write(
"# {0:12s} {1:12s} {2:12s} {3:12s} {4}\n".format(
"Elapsed time".center(12),
"ReadChars (Mbit per sec)".center(12),
"WriteChars (Gbit per sec)".center(12),
"ReadBytes (Gbit per sec)".center(12),
"WriteBytes (Gbit per sec)".center(12),
)
)
handle.write("START_TIME: {}\n".format(starting_point))

# conversion factor of bytes per sec to Giga-bits per second - 8 bits in a byte
conversion_to_size = 1e-9
if not show_bytes:
conversion_to_size = 8.0 * conversion_to_size

# main event loop
try:
while True:
try:
# update information
current_time = get_current_time()
disk_after = process.io_counters()

delta_time = current_time - last_time
if delta_time <= 0.0:
continue

# calculate bytes amount per second
read_char_per_sec = (
conversion_to_size * (disk_after.read_chars - disk_before.read_chars) / delta_time
)
write_char_per_sec = (
conversion_to_size * (disk_after.write_chars - disk_before.write_chars) / delta_time
)

read_byte_per_sec = (
conversion_to_size * (disk_after.read_bytes - disk_before.read_bytes) / delta_time
)
write_byte_per_sec = (
conversion_to_size * (disk_after.write_bytes - disk_before.write_bytes) / delta_time
)

# write information to the log file
handle.write(
"{0:12.6f} {1:12.3f} {2:12.3f} {3:12.3f} {4}\n".format(
current_time - start_time + starting_point,
read_char_per_sec,
write_char_per_sec,
read_byte_per_sec,
write_byte_per_sec,
)
)

# copy over information to new previous
disk_before = disk_after
last_time = current_time
except (psutil.NoSuchProcess, psutil.AccessDenied):
break # all done

if interval > 0.0:
sleep(interval)
except KeyboardInterrupt: # pragma: no cover
print(f"killing process being monitored [PID={process.pid}]:", " ".join(process.cmdline()))
process.kill()


def parse_log(filename: Path, cleanup: bool = True):
rows = []
start_time = 0.0
with open(filename, "r") as handle:
for line in handle:
line = line.strip()
if line.startswith("#") or not line: # skip comment and empty lines
continue
elif line.startswith("START_TIME:"):
start_time = float(line.split()[-1])
continue

# parse the line
rows.append([float(value) for value in line.split()])

# remove the file
if cleanup and filename.exists():
filename.unlink()

# return results
return start_time, np.array(rows)
Loading

0 comments on commit df605f9

Please sign in to comment.