From 521c0876ef2e61b32f4e62dd895e737aa7c249fd Mon Sep 17 00:00:00 2001 From: charliebudd Date: Thu, 10 Dec 2020 11:53:54 +0000 Subject: [PATCH 1/6] adding simple profiling tools Signed-off-by: charliebudd --- monai/utils/profiling.py | 85 ++++++++++++++++++++++++++++++++++++++++ 1 file changed, 85 insertions(+) create mode 100644 monai/utils/profiling.py diff --git a/monai/utils/profiling.py b/monai/utils/profiling.py new file mode 100644 index 0000000000..19b219d03a --- /dev/null +++ b/monai/utils/profiling.py @@ -0,0 +1,85 @@ +# Copyright 2020 MONAI Consortium +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# http://www.apache.org/licenses/LICENSE-2.0 +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +import torch +import time +from functools import wraps + +def torch_profiler_full(func): + """ + A decorator which will run the torch profiler for the decorated function, + printing the results in full. + Note: Enforces a gpu sync point which could slow down pipelines. + """ + + @wraps(func) + def wrapper(*args, **kwargs): + + with torch.autograd.profiler.profile(use_cuda=True) as prof: + result = func(*args, **kwargs) + + print(prof, flush=True) + + return result + + return wrapper + +def torch_profiler_time_cpu_gpu(func): + """ + A decorator which measures the execution time of both the CPU and GPU components + of the decorated function, printing both results. + Note: Enforces a gpu sync point which could slow down pipelines. + """ + + @wraps(func) + def wrapper(*args, **kwargs): + + with torch.autograd.profiler.profile(use_cuda=True) as prof: + result = func(*args, **kwargs) + + cpu_time = prof.self_cpu_time_total + gpu_time = sum([evt.self_cuda_time_total for evt in prof.function_events]) + + cpu_time = torch.autograd.profiler.format_time(cpu_time) + gpu_time = torch.autograd.profiler.format_time(gpu_time) + + print("cpu time: {}, gpu time: {}".format(cpu_time, gpu_time), flush=True) + + return result + + return wrapper + +def torch_profiler_time_end_to_end(func): + """ + A decorator which measures the total execution time from when the decorated + function is called to when the last cuda operation finishes, printing the result. + Note: Enforces a gpu sync point which could slow down pipelines. + """ + + @wraps(func) + def wrapper(*args, **kwargs): + + torch.cuda.synchronize() + start = time.perf_counter() + + result = func(*args, **kwargs) + + torch.cuda.synchronize() + end = time.perf_counter() + + total_time = (end - start) * 1e6 + total_time_str = torch.autograd.profiler.format_time(total_time) + print("end to end time: {}".format(total_time_str), flush=True) + + return result + + return wrapper + \ No newline at end of file From 657805e75188123c90ef5112ff204b15f4ac94a6 Mon Sep 17 00:00:00 2001 From: charliebudd Date: Thu, 10 Dec 2020 11:57:54 +0000 Subject: [PATCH 2/6] removing old timing decorator Signed-off-by: charliebudd --- monai/utils/decorators.py | 20 -------------------- 1 file changed, 20 deletions(-) diff --git a/monai/utils/decorators.py b/monai/utils/decorators.py index 0d14eb0dd3..599917ae31 100644 --- a/monai/utils/decorators.py +++ b/monai/utils/decorators.py @@ -9,28 +9,8 @@ # See the License for the specific language governing permissions and # limitations under the License. -import time from functools import wraps - -def timing(func): - """ - This simple timing function decorator prints to stdout/logfile (it uses printFlush) how many seconds a call to the - original function took to execute, as well as the name before and after the call. - """ - - @wraps(func) - def timingwrap(*args, **kwargs): - print(func.__name__, flush=True) - start = time.perf_counter() - res = func(*args, **kwargs) - end = time.perf_counter() - print(func.__name__, "dT (s) =", (end - start), flush=True) - return res - - return timingwrap - - class RestartGenerator: """ Wraps a generator callable which will be called whenever this class is iterated and its result returned. This is From b92280fe2c5c3a4e39c317a35f037cbb9693e0ae Mon Sep 17 00:00:00 2001 From: charliebudd Date: Thu, 10 Dec 2020 12:19:14 +0000 Subject: [PATCH 3/6] auto-reformatting Signed-off-by: charliebudd --- monai/utils/decorators.py | 1 + monai/utils/profiling.py | 33 ++++++++++++++++++--------------- 2 files changed, 19 insertions(+), 15 deletions(-) diff --git a/monai/utils/decorators.py b/monai/utils/decorators.py index 599917ae31..35a594d077 100644 --- a/monai/utils/decorators.py +++ b/monai/utils/decorators.py @@ -11,6 +11,7 @@ from functools import wraps + class RestartGenerator: """ Wraps a generator callable which will be called whenever this class is iterated and its result returned. This is diff --git a/monai/utils/profiling.py b/monai/utils/profiling.py index 19b219d03a..b0bcd4432b 100644 --- a/monai/utils/profiling.py +++ b/monai/utils/profiling.py @@ -9,36 +9,39 @@ # See the License for the specific language governing permissions and # limitations under the License. -import torch import time from functools import wraps -def torch_profiler_full(func): +import torch + + +def torch_profiler_full(func): """ - A decorator which will run the torch profiler for the decorated function, - printing the results in full. + A decorator which will run the torch profiler for the decorated function, + printing the results in full. Note: Enforces a gpu sync point which could slow down pipelines. """ - + @wraps(func) def wrapper(*args, **kwargs): with torch.autograd.profiler.profile(use_cuda=True) as prof: result = func(*args, **kwargs) - + print(prof, flush=True) return result return wrapper -def torch_profiler_time_cpu_gpu(func): + +def torch_profiler_time_cpu_gpu(func): """ A decorator which measures the execution time of both the CPU and GPU components - of the decorated function, printing both results. + of the decorated function, printing both results. Note: Enforces a gpu sync point which could slow down pipelines. """ - + @wraps(func) def wrapper(*args, **kwargs): @@ -50,20 +53,21 @@ def wrapper(*args, **kwargs): cpu_time = torch.autograd.profiler.format_time(cpu_time) gpu_time = torch.autograd.profiler.format_time(gpu_time) - + print("cpu time: {}, gpu time: {}".format(cpu_time, gpu_time), flush=True) return result return wrapper -def torch_profiler_time_end_to_end(func): + +def torch_profiler_time_end_to_end(func): """ - A decorator which measures the total execution time from when the decorated - function is called to when the last cuda operation finishes, printing the result. + A decorator which measures the total execution time from when the decorated + function is called to when the last cuda operation finishes, printing the result. Note: Enforces a gpu sync point which could slow down pipelines. """ - + @wraps(func) def wrapper(*args, **kwargs): @@ -82,4 +86,3 @@ def wrapper(*args, **kwargs): return result return wrapper - \ No newline at end of file From 3d6613c5f6f8de263dd18aea1c7dc4b5751f44c9 Mon Sep 17 00:00:00 2001 From: charliebudd Date: Thu, 10 Dec 2020 12:44:04 +0000 Subject: [PATCH 4/6] removing unnecessary list comprehension in sum() Signed-off-by: charliebudd --- monai/utils/profiling.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/monai/utils/profiling.py b/monai/utils/profiling.py index b0bcd4432b..6fa907b640 100644 --- a/monai/utils/profiling.py +++ b/monai/utils/profiling.py @@ -49,7 +49,7 @@ def wrapper(*args, **kwargs): result = func(*args, **kwargs) cpu_time = prof.self_cpu_time_total - gpu_time = sum([evt.self_cuda_time_total for evt in prof.function_events]) + gpu_time = sum(evt.self_cuda_time_total for evt in prof.function_events) cpu_time = torch.autograd.profiler.format_time(cpu_time) gpu_time = torch.autograd.profiler.format_time(gpu_time) From 1f3eedbc958af324ee2bc4482acd45e325d64c64 Mon Sep 17 00:00:00 2001 From: charliebudd Date: Thu, 10 Dec 2020 13:38:04 +0000 Subject: [PATCH 5/6] adding imports to __init__.py Signed-off-by: charliebudd --- monai/utils/__init__.py | 1 + monai/utils/profiling.py | 7 +++++++ 2 files changed, 8 insertions(+) diff --git a/monai/utils/__init__.py b/monai/utils/__init__.py index 8f27a7faf3..d2d3e41d67 100644 --- a/monai/utils/__init__.py +++ b/monai/utils/__init__.py @@ -15,3 +15,4 @@ from .enums import * from .misc import * from .module import * +from .profiling import * diff --git a/monai/utils/profiling.py b/monai/utils/profiling.py index 6fa907b640..57a7edcd41 100644 --- a/monai/utils/profiling.py +++ b/monai/utils/profiling.py @@ -15,6 +15,13 @@ import torch +__all__ = [ + "torch_profiler_full", + "torch_profiler_time_cpu_gpu", + "torch_profiler_time_end_to_end" +] + + def torch_profiler_full(func): """ A decorator which will run the torch profiler for the decorated function, From ae3dbf4fe4d2ba4b377f1e95317041c43ec5600f Mon Sep 17 00:00:00 2001 From: monai-bot Date: Thu, 10 Dec 2020 13:48:10 +0000 Subject: [PATCH 6/6] [MONAI] python code formatting Signed-off-by: monai-bot --- monai/utils/profiling.py | 7 +------ 1 file changed, 1 insertion(+), 6 deletions(-) diff --git a/monai/utils/profiling.py b/monai/utils/profiling.py index 57a7edcd41..a8d6e2c630 100644 --- a/monai/utils/profiling.py +++ b/monai/utils/profiling.py @@ -14,12 +14,7 @@ import torch - -__all__ = [ - "torch_profiler_full", - "torch_profiler_time_cpu_gpu", - "torch_profiler_time_end_to_end" -] +__all__ = ["torch_profiler_full", "torch_profiler_time_cpu_gpu", "torch_profiler_time_end_to_end"] def torch_profiler_full(func):