Profile in Notebook#
Profiling with Python CProfiler#
Before getting started, this example requires the config flag PFlow.init_tds
to be 0
, which is the default value.
import andes
from andes.utils.paths import get_case
case_path = get_case("kundur/kundur_full.xlsx")
Passing profile=True, no_output = True
to run
will enable the profiler and have the results printed.
ss = andes.run(
case_path, profile=True, routine="tds", no_output=True, default_config=True
)
Working directory: "/home/hacui/repos/andes/examples"
> Loaded generated Python code in "/home/hacui/.andes/pycode".
Parsing input file "/home/hacui/repos/andes/andes/cases/kundur/kundur_full.xlsx"...
Input file parsed in 0.3536 seconds.
System internal structure set up in 0.0412 seconds.
-> System connectivity check results:
No islanded bus detected.
System is interconnected.
Each island has a slack bus correctly defined and enabled.
-> Power flow calculation
Numba: Off
Sparse solver: KLU
Solution method: NR method
Power flow initialized in 0.0051 seconds.
0: |F(x)| = 14.9282832
1: |F(x)| = 3.608627841
2: |F(x)| = 0.1701107882
3: |F(x)| = 0.002038626956
4: |F(x)| = 3.745103977e-07
Converged in 5 iterations in 0.0045 seconds.
Initialization for dynamics completed in 0.0368 seconds.
Initialization was successful.
<Toggle 1>: Line.Line_8 status changed to 0 at t=2.0 sec.
Simulation to t=20.00 sec completed in 0.9577 seconds.
2126948 function calls (2100484 primitive calls) in 1.634 seconds
Ordered by: cumulative time
List reduced from 5556 to 40 due to restriction <40>
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.006 0.006 1.065 1.065 /home/hacui/repos/andes/andes/routines/tds.py:326(run)
603 0.001 0.000 0.891 0.001 /home/hacui/repos/andes/andes/routines/tds.py:521(itm_step)
603 0.051 0.000 0.890 0.001 /home/hacui/repos/andes/andes/routines/daeint.py:27(step)
2025 0.006 0.000 0.703 0.000 /home/hacui/repos/andes/andes/routines/tds.py:820(fg_update)
10176 0.060 0.000 0.646 0.000 /home/hacui/repos/andes/andes/system.py:1672(call_models)
1 0.000 0.000 0.558 0.558 /home/hacui/repos/andes/andes/main.py:275(load)
1040/207 0.003 0.000 0.423 0.002 <frozen importlib._bootstrap>:1022(_find_and_load)
960/129 0.002 0.000 0.420 0.003 <frozen importlib._bootstrap>:987(_find_and_load_unlocked)
847/34 0.001 0.000 0.419 0.012 <frozen importlib._bootstrap_external>:877(exec_module)
905/66 0.002 0.000 0.419 0.006 {built-in method builtins.exec}
1246/34 0.001 0.000 0.418 0.012 <frozen importlib._bootstrap>:233(_call_with_frames_removed)
925/130 0.002 0.000 0.415 0.003 <frozen importlib._bootstrap>:664(_load_unlocked)
2030 0.001 0.000 0.367 0.000 /home/hacui/repos/andes/andes/system.py:1047(g_update)
1 0.000 0.000 0.355 0.355 /home/hacui/repos/andes/andes/io/__init__.py:115(parse)
1 0.000 0.000 0.353 0.353 /home/hacui/repos/andes/andes/io/xlsx.py:88(read)
20279 0.082 0.000 0.349 0.000 /home/hacui/repos/andes/andes/core/model/model.py:963(g_update)
35 0.000 0.000 0.270 0.008 /home/hacui/repos/andes/andes/utils/lazyimport.py:61(__maybe_import__)
34 0.000 0.000 0.214 0.006 /home/hacui/repos/andes/andes/utils/lazyimport.py:73(__getattr__)
1 0.000 0.000 0.213 0.213 /home/hacui/mambaforge/envs/a/lib/python3.10/site-packages/pandas/__init__.py:1(<module>)
1 0.000 0.000 0.169 0.169 /home/hacui/mambaforge/envs/a/lib/python3.10/site-packages/pandas/core/api.py:1(<module>)
1 0.000 0.000 0.161 0.161 /home/hacui/repos/andes/andes/system.py:93(__init__)
109/107 0.000 0.000 0.138 0.001 /home/hacui/mambaforge/envs/a/lib/python3.10/importlib/__init__.py:108(import_module)
109/107 0.000 0.000 0.138 0.001 <frozen importlib._bootstrap>:1038(_gcd_import)
1 0.000 0.000 0.122 0.122 /home/hacui/mambaforge/envs/a/lib/python3.10/site-packages/pandas/io/excel/_base.py:460(read_excel)
254/196 0.000 0.000 0.108 0.001 {built-in method builtins.__import__}
2030 0.001 0.000 0.101 0.000 /home/hacui/repos/andes/andes/system.py:1033(f_update)
1 0.000 0.000 0.100 0.100 /home/hacui/repos/andes/andes/system.py:1800(import_models)
79/52 0.000 0.000 0.097 0.002 <frozen importlib._bootstrap_external>:1182(exec_module)
79/52 0.082 0.001 0.097 0.002 {built-in method _imp.exec_dynamic}
1636/1630 0.009 0.000 0.097 0.000 {built-in method builtins.__build_class__}
1 0.000 0.000 0.097 0.097 /home/hacui/mambaforge/envs/a/lib/python3.10/site-packages/pandas/io/excel/_base.py:1520(__init__)
1 0.000 0.000 0.094 0.094 /home/hacui/mambaforge/envs/a/lib/python3.10/site-packages/pandas/io/excel/_openpyxl.py:534(__init__)
20279 0.039 0.000 0.086 0.000 /home/hacui/repos/andes/andes/core/model/model.py:935(f_update)
2030 0.002 0.000 0.084 0.000 /home/hacui/repos/andes/andes/system.py:989(l_update_eq)
4 0.000 0.000 0.083 0.021 /home/hacui/mambaforge/envs/a/lib/python3.10/site-packages/pandas/compat/_optional.py:81(import_optional_dependency)
1864/802 0.002 0.000 0.082 0.000 <frozen importlib._bootstrap>:1053(_handle_fromlist)
1 0.000 0.000 0.080 0.080 /home/hacui/mambaforge/envs/a/lib/python3.10/site-packages/openpyxl/__init__.py:1(<module>)
2025 0.076 0.000 0.076 0.000 /home/hacui/.andes/pycode/GENROU.py:20(g_update)
1 0.000 0.000 0.069 0.069 /home/hacui/mambaforge/envs/a/lib/python3.10/site-packages/pandas/core/arrays/__init__.py:1(<module>)
20279 0.011 0.000 0.068 0.000 /home/hacui/repos/andes/andes/core/model/model.py:712(l_check_eq)
-> Single process finished in 1.7222 seconds.
Profiling with line_profiler
.#
line_profiler
provides line-based profiling results for functions.
Install with pip install line_profiler
and restart the notebook.
import andes
from andes.utils.paths import get_case
case_path = get_case("kundur/kundur_full.xlsx")
Profile power flow#
Pass the function name to profile to the magic %lprun
, followed by a call to the function itself or an upper-level function.
Results will be shown in a popup window.
%load_ext line_profiler
%lprun -f andes.routines.pflow.PFlow.run andes.run(case_path, no_output=True, default_config=True)
Working directory: "/home/hacui/repos/andes/examples"
> Reloaded generated Python code of module "pycode".
Parsing input file "/home/hacui/repos/andes/andes/cases/kundur/kundur_full.xlsx"...
Input file parsed in 0.0498 seconds.
System internal structure set up in 0.0402 seconds.
-> System connectivity check results:
No islanded bus detected.
System is interconnected.
Each island has a slack bus correctly defined and enabled.
-> Power flow calculation
Numba: Off
Sparse solver: KLU
Solution method: NR method
Power flow initialized in 0.0050 seconds.
0: |F(x)| = 14.9282832
1: |F(x)| = 3.608627841
2: |F(x)| = 0.1701107882
3: |F(x)| = 0.002038626956
4: |F(x)| = 3.745103977e-07
Converged in 5 iterations in 0.0041 seconds.
-> Single process finished in 0.2605 seconds.
Timer unit: 1e-09 s
Total time: 0.0114298 s
File: /home/hacui/repos/andes/andes/routines/pflow.py
Function: run at line 211
Line # Hits Time Per Hit % Time Line Contents
==============================================================
211 def run(self, **kwargs):
212 """
213 Solve the power flow using the selected method.
214
215 Returns
216 -------
217 bool
218 convergence status
219 """
220
221 1 1363.0 1363.0 0.0 system = self.system
222 1 581.0 581.0 0.0 if self.config.check_conn == 1:
223 1 1378597.0 1e+06 12.1 self.system.connectivity()
224
225 1 250450.0 250450.0 2.2 self.summary()
226 1 5393416.0 5e+06 47.2 self.init()
227
228 1 401.0 401.0 0.0 if system.dae.m == 0:
229 logger.error("Loaded case contains no power flow element.")
230 system.exit_code = 1
231 return False
232
233 1 762.0 762.0 0.0 method = self.config.method.lower()
234
235 1 4629.0 4629.0 0.0 t0, _ = elapsed()
236
237 # ---------- Call solution methods ----------
238 1 251.0 251.0 0.0 if method == 'nr':
239 1 4163484.0 4e+06 36.4 self.nr_solve()
240 elif method == 'nk':
241 self.newton_krylov()
242
243 1 5711.0 5711.0 0.0 t1, s1 = elapsed(t0)
244 1 311.0 311.0 0.0 self.exec_time = t1 - t0
245
246 1 260.0 260.0 0.0 if not self.converged:
247 if abs(self.mis[-1] - self.mis[-2]) < self.config.tol:
248 max_idx = np.argmax(np.abs(system.dae.xy))
249 name = system.dae.xy_name[max_idx]
250 logger.error('Mismatch is not correctable possibly due to large load-generation imbalance.')
251 logger.error('Largest mismatch on equation associated with <%s>', name)
252 else:
253 logger.error('Power flow failed after %d iterations for "%s".', self.niter + 1, system.files.case)
254
255 else:
256 1 222407.0 222407.0 1.9 logger.info('Converged in %d iterations in %s.', self.niter + 1, s1)
257
258 # make a copy of power flow solutions
259 1 3146.0 3146.0 0.0 self.x_sol = system.dae.x.copy()
260 1 862.0 862.0 0.0 self.y_sol = system.dae.y.copy()
261
262 1 441.0 441.0 0.0 if self.config.init_tds:
263 system.TDS.init()
264 1 330.0 330.0 0.0 if self.config.report:
265 1 1803.0 1803.0 0.0 system.PFlow.report()
266
267 1 491.0 491.0 0.0 system.exit_code = 0 if self.converged else 1
268 1 110.0 110.0 0.0 return self.converged
Alternatively, do
ss = andes.load(case_path, no_output=True, default_config=True)
%lprun -f ss.PFlow.run ss.PFlow.run()
Working directory: "/home/hacui/repos/andes/examples"
> Reloaded generated Python code of module "pycode".
Parsing input file "/home/hacui/repos/andes/andes/cases/kundur/kundur_full.xlsx"...
Input file parsed in 0.0293 seconds.
System internal structure set up in 0.0231 seconds.
-> System connectivity check results:
No islanded bus detected.
System is interconnected.
Each island has a slack bus correctly defined and enabled.
-> Power flow calculation
Numba: Off
Sparse solver: KLU
Solution method: NR method
Power flow initialized in 0.0043 seconds.
0: |F(x)| = 14.9282832
1: |F(x)| = 3.608627841
2: |F(x)| = 0.1701107882
3: |F(x)| = 0.002038626956
4: |F(x)| = 3.745103977e-07
Converged in 5 iterations in 0.0040 seconds.
Timer unit: 1e-09 s
Total time: 0.0109119 s
File: /home/hacui/repos/andes/andes/routines/pflow.py
Function: run at line 211
Line # Hits Time Per Hit % Time Line Contents
==============================================================
211 def run(self, **kwargs):
212 """
213 Solve the power flow using the selected method.
214
215 Returns
216 -------
217 bool
218 convergence status
219 """
220
221 1 972.0 972.0 0.0 system = self.system
222 1 511.0 511.0 0.0 if self.config.check_conn == 1:
223 1 1557962.0 2e+06 14.3 self.system.connectivity()
224
225 1 253977.0 253977.0 2.3 self.summary()
226 1 4784035.0 5e+06 43.8 self.init()
227
228 1 451.0 451.0 0.0 if system.dae.m == 0:
229 logger.error("Loaded case contains no power flow element.")
230 system.exit_code = 1
231 return False
232
233 1 842.0 842.0 0.0 method = self.config.method.lower()
234
235 1 4840.0 4840.0 0.0 t0, _ = elapsed()
236
237 # ---------- Call solution methods ----------
238 1 211.0 211.0 0.0 if method == 'nr':
239 1 4053092.0 4e+06 37.1 self.nr_solve()
240 elif method == 'nk':
241 self.newton_krylov()
242
243 1 5711.0 5711.0 0.1 t1, s1 = elapsed(t0)
244 1 200.0 200.0 0.0 self.exec_time = t1 - t0
245
246 1 241.0 241.0 0.0 if not self.converged:
247 if abs(self.mis[-1] - self.mis[-2]) < self.config.tol:
248 max_idx = np.argmax(np.abs(system.dae.xy))
249 name = system.dae.xy_name[max_idx]
250 logger.error('Mismatch is not correctable possibly due to large load-generation imbalance.')
251 logger.error('Largest mismatch on equation associated with <%s>', name)
252 else:
253 logger.error('Power flow failed after %d iterations for "%s".', self.niter + 1, system.files.case)
254
255 else:
256 1 241955.0 241955.0 2.2 logger.info('Converged in %d iterations in %s.', self.niter + 1, s1)
257
258 # make a copy of power flow solutions
259 1 3116.0 3116.0 0.0 self.x_sol = system.dae.x.copy()
260 1 701.0 701.0 0.0 self.y_sol = system.dae.y.copy()
261
262 1 562.0 562.0 0.0 if self.config.init_tds:
263 system.TDS.init()
264 1 241.0 241.0 0.0 if self.config.report:
265 1 1753.0 1753.0 0.0 system.PFlow.report()
266
267 1 441.0 441.0 0.0 system.exit_code = 0 if self.converged else 1
268 1 110.0 110.0 0.0 return self.converged
To dig into the Newton Raphson iteration steps, profile each step instead with:
ss = andes.load(case_path, no_output=True, default_config=True)
%lprun -f ss.PFlow.nr_step ss.PFlow.run()
Working directory: "/home/hacui/repos/andes/examples"
> Reloaded generated Python code of module "pycode".
Parsing input file "/home/hacui/repos/andes/andes/cases/kundur/kundur_full.xlsx"...
Input file parsed in 0.0299 seconds.
System internal structure set up in 0.0242 seconds.
-> System connectivity check results:
No islanded bus detected.
System is interconnected.
Each island has a slack bus correctly defined and enabled.
-> Power flow calculation
Numba: Off
Sparse solver: KLU
Solution method: NR method
Power flow initialized in 0.0045 seconds.
0: |F(x)| = 14.9282832
1: |F(x)| = 3.608627841
2: |F(x)| = 0.1701107882
3: |F(x)| = 0.002038626956
4: |F(x)| = 3.745103977e-07
Converged in 5 iterations in 0.0040 seconds.
Timer unit: 1e-09 s
Total time: 0.00289216 s
File: /home/hacui/repos/andes/andes/routines/pflow.py
Function: nr_step at line 104
Line # Hits Time Per Hit % Time Line Contents
==============================================================
104 def nr_step(self):
105 """
106 Solve a single iteration step using the Newton-Raphson method.
107
108 Returns
109 -------
110 float
111 maximum absolute mismatch
112 """
113
114 5 2064.0 412.8 0.1 system = self.system
115
116 # ---------- Build numerical DAE----------
117 5 1288374.0 257674.8 44.5 self.fg_update()
118
119 # ---------- update the Jacobian on conditions ----------
120 5 2365.0 473.0 0.1 if self.config.method != 'dishonest' or (self.niter < self.config.n_factorize):
121 5 1263947.0 252789.4 43.7 system.j_update(self.models)
122 5 4048.0 809.6 0.1 self.solver.worker.new_A = True
123
124 # ---------- prepare and solve linear equations ----------
125 5 12294.0 2458.8 0.4 self.res[:system.dae.n] = -system.dae.f[:]
126 5 9229.0 1845.8 0.3 self.res[system.dae.n:] = -system.dae.g[:]
127
128 10 15200.0 1520.0 0.5 self.A = sparse([[system.dae.fx, system.dae.gx],
129 5 1994.0 398.8 0.1 [system.dae.fy, system.dae.gy]])
130
131 5 1422.0 284.4 0.0 if not self.config.linsolve:
132 5 95764.0 19152.8 3.3 self.inc = self.solver.solve(self.A, self.res)
133 else:
134 self.inc = self.solver.linsolve(self.A, self.res)
135
136 5 15670.0 3134.0 0.5 system.dae.x += np.ravel(self.inc[:system.dae.n])
137 5 11501.0 2300.2 0.4 system.dae.y += np.ravel(self.inc[system.dae.n:])
138
139 # find out variables associated with maximum mismatches
140 5 591.0 118.2 0.0 fmax = 0
141 5 1232.0 246.4 0.0 if system.dae.n > 0:
142 fmax_idx = np.argmax(np.abs(system.dae.f))
143 fmax = system.dae.f[fmax_idx]
144 logger.debug("Max. diff mismatch %.10g on %s", fmax, system.dae.x_name[fmax_idx])
145
146 5 28063.0 5612.6 1.0 gmax_idx = np.argmax(np.abs(system.dae.g))
147 5 2987.0 597.4 0.1 gmax = system.dae.g[gmax_idx]
148 5 87689.0 17537.8 3.0 logger.debug("Max. algeb mismatch %.10g on %s", gmax, system.dae.y_name[gmax_idx])
149
150 5 6012.0 1202.4 0.2 mis = max(abs(fmax), abs(gmax))
151 5 41141.0 8228.2 1.4 system.vars_to_models()
152
153 5 570.0 114.0 0.0 return mis
Profile time-domain simulation#
xy = ss.TDS.init()
Initialization for dynamics completed in 0.0209 seconds.
Initialization was successful.
%lprun -f ss.TDS.itm_step ss.TDS.run()
-> Time Domain Simulation Summary:
Sparse Solver: KLU
Simulation time: 0.0-20.0 s.
Fixed step size: h=33.33 ms. Shrink if not converged.
<Toggle 1>: Line.Line_8 status changed to 0 at t=2.0 sec.
Simulation to t=20.00 sec completed in 0.9426 seconds.
Timer unit: 1e-09 s
Total time: 0.882568 s
File: /home/hacui/repos/andes/andes/routines/tds.py
Function: itm_step at line 521
Line # Hits Time Per Hit % Time Line Contents
==============================================================
521 def itm_step(self):
522 """
523 Integrate for the step size of ``self.h`` using implicit trapezoid method.
524
525 Returns
526 -------
527 bool
528 Convergence status in ``self.converged``.
529
530 """
531 602 882567523.0 1e+06 100.0 return self.method.step(self)
Cleanup#
!andes misc -C
No output file found in the working directory.