Skip to content

Commit

Permalink
Merge pull request #28 from Alphagon/master
Browse files Browse the repository at this point in the history 
Function time profiler - decorator
  • Loading branch information
@sizhky
sizhky authored Oct 2, 2024
2 parents a6a8495 + 974a5a2 commit 161b6fe
Show file tree
Hide file tree
Showing 3 changed files with 212 additions and 0 deletions.
180 changes: 180 additions & 0 deletions nbs/profiler.ipynb
View file
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 profiler"
]
},
{
"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
View file
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
31 changes: 31 additions & 0 deletions torch_snippets/profiler.py
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,31 @@
# AUTOGENERATED! DO NOT EDIT! File to edit: ../nbs/profiler.ipynb.

# %% auto 0
__all__ = ['time_profiler']

# %% ../nbs/profiler.ipynb 2
import cProfile
import pstats
from io import StringIO

# %% ../nbs/profiler.ipynb 3
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

0 comments on commit 161b6fe

Please sign in to comment.