Skip to content
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.

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

Time profiler - new decorator #27

Closed
wants to merge 1 commit into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
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
180 changes: 180 additions & 0 deletions nbs/profiler.ipynb
Original file line number Diff line number Diff line change
@@ -0,0 +1,180 @@
{
"cells": [
{
"cell_type": "markdown",
"id": "597ba8be-dee7-433e-8794-caf0a3d53646",
"metadata": {},
"source": [
"# Profiler"
]
},
{
"cell_type": "code",
"execution_count": 1,
"id": "fb94504f-89e9-468c-bcef-abc64b72f02c",
"metadata": {},
"outputs": [],
"source": [
"# | default_exp misc"
]
},
{
"cell_type": "code",
"execution_count": 2,
"id": "72f6d5d9-7e41-45b9-8838-500ac791ee15",
"metadata": {},
"outputs": [],
"source": [
"# | export\n",
"import cProfile\n",
"import pstats\n",
"from io import StringIO"
]
},
{
"cell_type": "code",
"execution_count": 3,
"id": "87ba2ff6-cf80-4fb2-b02d-03944de4fc2a",
"metadata": {},
"outputs": [],
"source": [
"# | export\n",
"# | hide\n",
"\n",
"def time_profiler(filename='profiling_results.txt'):\n",
" # The outer function that allows customization of the filename\n",
" def decorator(func):\n",
" # The middle function which receives the function to be wrapped\n",
" def wrapper(*args, **kwargs):\n",
" # The inner function that actually runs the profiling\n",
" profiler = cProfile.Profile()\n",
" profiler.enable() # Start profiling\n",
" result = func(*args, **kwargs)\n",
" profiler.disable() # End profiling\n",
" # Create a StringIO stream to capture profiling results\n",
" s = StringIO()\n",
" ps = pstats.Stats(profiler, stream=s).sort_stats('cumulative')\n",
" ps.print_stats()\n",
" # Write the profiling results to the specified file\n",
" with open(filename, 'w') as f:\n",
" f.write(s.getvalue())\n",
" return result\n",
" return wrapper\n",
" return decorator"
]
},
{
"cell_type": "markdown",
"id": "e745f58a-f685-4a73-ac2c-f329ba599494",
"metadata": {},
"source": [
"## Time Profiler\n",
"The time profiler decorator measures the execution time of a function, including any sub-functions that the main function calls. It allows users to specify a file name or complete file path to store the profiling results. The output includes the total time taken by the function, which can be useful for understanding performance bottlenecks in the code. By applying this decorator to any function, developers can easily track its runtime and optimize accordingly."
]
},
{
"cell_type": "code",
"execution_count": 4,
"id": "5c9b2770-b018-4ee5-a6bb-2126ccccb591",
"metadata": {},
"outputs": [
{
"name": "stdout",
"output_type": "stream",
"text": [
"Result from inner_function_1: 124999750000\n",
"Result from inner_function_2: 333333283333335000000\n"
]
}
],
"source": [
"def inner_function_1():\n",
" # Simulating some work by counting\n",
" total = 0\n",
" for i in range(500000):\n",
" total += i\n",
" return total\n",
"\n",
"def inner_function_2():\n",
" # Simulating some different work, like squaring numbers\n",
" total = 0\n",
" for i in range(10000000):\n",
" total += i * i\n",
" return total\n",
"\n",
"@time_profiler('outer_function_profile.txt')\n",
"def outer_function():\n",
" result_1 = inner_function_1()\n",
" print(f\"Result from inner_function_1: {result_1}\")\n",
"\n",
" result_2 = inner_function_2()\n",
" print(f\"Result from inner_function_2: {result_2}\")\n",
"\n",
"# Call the outer function\n",
"outer_function()"
]
},
{
"cell_type": "markdown",
"id": "8102b353-dba5-4a66-a223-15911f515119",
"metadata": {},
"source": [
"#### outer_function_profile.txt\n",
"\n",
"```\n",
" 67 function calls in 1.362 seconds\n",
"\n",
" Ordered by: cumulative time\n",
"\n",
" ncalls tottime percall cumtime percall filename:lineno(function)\n",
" 1 0.000 0.000 1.362 1.362 /tmp/ipykernel_156766/1515566242.py:15(outer_function)\n",
" 1 1.303 1.303 1.303 1.303 /tmp/ipykernel_156766/1515566242.py:8(inner_function_2)\n",
" 1 0.058 0.058 0.058 0.058 /tmp/ipykernel_156766/1515566242.py:1(inner_function_1)\n",
" 2 0.000 0.000 0.001 0.000 {built-in method builtins.print}\n",
" 4 0.000 0.000 0.001 0.000 /home/user/miniconda3/lib/python3.11/site-packages/ipykernel/iostream.py:655(write)\n",
" 4 0.000 0.000 0.000 0.000 /home/user/miniconda3/lib/python3.11/site-packages/ipykernel/iostream.py:577(_schedule_flush)\n",
" 2 0.000 0.000 0.000 0.000 /home/user/miniconda3/lib/python3.11/site-packages/ipykernel/iostream.py:259(schedule)\n",
" 2 0.000 0.000 0.000 0.000 /home/user/miniconda3/lib/python3.11/site-packages/zmq/sugar/socket.py:621(send)\n",
" 2 0.000 0.000 0.000 0.000 /home/user/miniconda3/lib/python3.11/threading.py:1185(is_alive)\n",
" 4 0.000 0.000 0.000 0.000 /home/user/miniconda3/lib/python3.11/site-packages/ipykernel/iostream.py:505(parent_header)\n",
" 4 0.000 0.000 0.000 0.000 /home/user/miniconda3/lib/python3.11/site-packages/ipykernel/iostream.py:550(_is_master_process)\n",
" 2 0.000 0.000 0.000 0.000 /home/user/miniconda3/lib/python3.11/threading.py:1118(_wait_for_tstate_lock)\n",
" 2 0.000 0.000 0.000 0.000 /home/user/miniconda3/lib/python3.11/site-packages/ipykernel/iostream.py:138(_event_pipe)\n",
" 2 0.000 0.000 0.000 0.000 {method 'acquire' of '_thread.lock' objects}\n",
" 4 0.000 0.000 0.000 0.000 {built-in method posix.getpid}\n",
" 4 0.000 0.000 0.000 0.000 {built-in method builtins.isinstance}\n",
" 4 0.000 0.000 0.000 0.000 {method 'get' of '_contextvars.ContextVar' objects}\n",
" 4 0.000 0.000 0.000 0.000 {method '__exit__' of '_thread.RLock' objects}\n",
" 4 0.000 0.000 0.000 0.000 {method 'write' of '_io.StringIO' objects}\n",
" 2 0.000 0.000 0.000 0.000 /home/user/miniconda3/lib/python3.11/threading.py:568(is_set)\n",
" 4 0.000 0.000 0.000 0.000 {built-in method builtins.len}\n",
" 4 0.000 0.000 0.000 0.000 {method 'items' of 'dict' objects}\n",
" 1 0.000 0.000 0.000 0.000 /home/user/miniconda3/lib/python3.11/site-packages/dateutil/tz/tz.py:74(utcoffset)\n",
" 1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}\n",
" 2 0.000 0.000 0.000 0.000 {method 'append' of 'collections.deque' objects}\n",
"```"
]
}
],
"metadata": {
"kernelspec": {
"display_name": "Python 3 (ipykernel)",
"language": "python",
"name": "python3"
},
"language_info": {
"codemirror_mode": {
"name": "ipython",
"version": 3
},
"file_extension": ".py",
"mimetype": "text/x-python",
"name": "python",
"nbconvert_exporter": "python",
"pygments_lexer": "ipython3",
"version": "3.11.5"
}
},
"nbformat": 4,
"nbformat_minor": 5
}
1 change: 1 addition & 0 deletions requirements.txt
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@ numpy
pandas
setuptools
tqdm
CProfileV

# opencv_python_headless
# pytorch_lightning
Expand Down
25 changes: 25 additions & 0 deletions torch_snippets/profiler.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,25 @@
import cProfile
import pstats
from io import StringIO


def time_profiler(filename='profiling_results.txt'):
# The outer function that allows customization of the filename
def decorator(func):
# The middle function which receives the function to be wrapped
def wrapper(*args, **kwargs):
# The inner function that actually runs the profiling
profiler = cProfile.Profile()
profiler.enable() # Start profiling
result = func(*args, **kwargs)
profiler.disable() # End profiling
# Create a StringIO stream to capture profiling results
s = StringIO()
ps = pstats.Stats(profiler, stream=s).sort_stats('cumulative')
ps.print_stats()
# Write the profiling results to the specified file
with open(filename, 'w') as f:
f.write(s.getvalue())
return result
return wrapper
return decorator
Loading