1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
508
509
510
511
512
513
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
535
536
537
538
539
540
541
542
543
544
545
546
547
548
549
550
551
552
553
554
555
556
557
558
559
560
561
562
563
564
565
566
567
568
569
570
571
572
573
574
575
576
577
578
579
580
581
582
583
584
585
586
587
588
589
590
591
592
593
594
595
596
597
598
599
600
601
602
603
604
605
606
607
608
609
610
611
612
613
614
615
616
617
618
619
620
621
622
623
624
625
626
627
628
629
630
631
632
633
634
635
636
637
638
639
640
641
642
643
644
645
646
647
648
649
650
651
652
653
654
655
656
657
658
659
660
661
662
663
664
665
666
667
668
669
670
671
672
673
674
675
676
677
678
679
680
681
682
683
684
685
686
687
688
689
690
691
692
693
694
695
696
697
698
|
<!DOCTYPE html>
<html xmlns="http://www.w3.org/1999/xhtml">
<head> <link rel="canonical" href="http://www.mcs.anl.gov/petsc/petsc-current/docs/sphinx_docs/html/manual/profiling.html" />
<meta charset="utf-8" />
<title>Profiling — PETSc 3.14.5 documentation</title>
<link rel="stylesheet" href="../_static/sphinxdoc.css" type="text/css" />
<link rel="stylesheet" href="../_static/pygments.css" type="text/css" />
<link rel="stylesheet" type="text/css" href="../_static/graphviz.css" />
<link rel="stylesheet" type="text/css" href="https://cdn.jsdelivr.net/npm/katex@0.12.0/dist/katex.min.css" />
<link rel="stylesheet" type="text/css" href="../_static/katex-math.css" />
<script id="documentation_options" data-url_root="../" src="../_static/documentation_options.js"></script>
<script src="../_static/jquery.js"></script>
<script src="../_static/underscore.js"></script>
<script src="../_static/doctools.js"></script>
<script src="../_static/language_data.js"></script>
<script src="https://cdn.jsdelivr.net/npm/katex@0.12.0/dist/katex.min.js"></script>
<script src="https://cdn.jsdelivr.net/npm/katex@0.12.0/dist/contrib/auto-render.min.js"></script>
<script src="../_static/katex_autorenderer.js"></script>
<link rel="shortcut icon" href="../_static/PETSc_RGB-logo.png"/>
<link rel="index" title="Index" href="../genindex.html" />
<link rel="search" title="Search" href="../search.html" />
<link rel="next" title="Hints for Performance Tuning" href="performance.html" />
<link rel="prev" title="Using MATLAB with PETSc" href="matlab.html" />
</head><body>
<div id="version" align=right><b>petsc-3.14.5 2021-03-03</b></div>
<div id="bugreport" align=right><a href="mailto:petsc-maint@mcs.anl.gov?subject=Typo or Error in Documentation &body=Please describe the typo or error in the documentation: petsc-3.14.5 v3.14.5 docs/sphinx_docs/html/manual/profiling.html "><small>Report Typos and Errors</small></a></div>
<div class="related" role="navigation" aria-label="related navigation">
<h3>Navigation</h3>
<ul>
<li class="right" style="margin-right: 10px">
<a href="../genindex.html" title="General Index"
accesskey="I">index</a></li>
<li class="right" >
<a href="performance.html" title="Hints for Performance Tuning"
accesskey="N">next</a> |</li>
<li class="right" >
<a href="matlab.html" title="Using MATLAB with PETSc"
accesskey="P">previous</a> |</li>
<li class="nav-item nav-item-0"><a href="../index.html">PETSc 3.14.5 documentation</a> »</li>
<li class="nav-item nav-item-1"><a href="index.html" >PETSc Users Manual</a> »</li>
<li class="nav-item nav-item-2"><a href="additional.html" accesskey="U">Additional Information</a> »</li>
</ul>
</div>
<div class="sphinxsidebar" role="navigation" aria-label="main navigation">
<div class="sphinxsidebarwrapper">
<p class="logo"><a href="../index.html">
<img class="logo" src="../_static/PETSc-TAO_RGB.svg" alt="Logo"/>
</a></p>
<h3><a href="../index.html">Table of Contents</a></h3>
<ul>
<li><a class="reference internal" href="#">Profiling</a><ul>
<li><a class="reference internal" href="#basic-profiling-information">Basic Profiling Information</a><ul>
<li><a class="reference internal" href="#interpreting-log-view-output-the-basics">Interpreting <code class="docutils literal notranslate"><span class="pre">-log_view</span></code> Output: The Basics</a></li>
<li><a class="reference internal" href="#interpreting-log-view-output-parallel-performance">Interpreting <code class="docutils literal notranslate"><span class="pre">-log_view</span></code> Output: Parallel Performance</a></li>
<li><a class="reference internal" href="#using-log-mpe-with-jumpshot">Using <code class="docutils literal notranslate"><span class="pre">-log_mpe</span></code> with Jumpshot</a></li>
</ul>
</li>
<li><a class="reference internal" href="#profiling-application-codes">Profiling Application Codes</a></li>
<li><a class="reference internal" href="#profiling-multiple-sections-of-code">Profiling Multiple Sections of Code</a></li>
<li><a class="reference internal" href="#restricting-event-logging">Restricting Event Logging</a></li>
<li><a class="reference internal" href="#interpreting-log-info-output-informative-messages">Interpreting <code class="docutils literal notranslate"><span class="pre">-log_info</span></code> Output: Informative Messages</a></li>
<li><a class="reference internal" href="#time">Time</a></li>
<li><a class="reference internal" href="#saving-output-to-a-file">Saving Output to a File</a></li>
<li><a class="reference internal" href="#accurate-profiling-and-paging-overheads">Accurate Profiling and Paging Overheads</a></li>
</ul>
</li>
</ul>
<h4>Previous topic</h4>
<p class="topless"><a href="matlab.html"
title="previous chapter">Using MATLAB with PETSc</a></p>
<h4>Next topic</h4>
<p class="topless"><a href="performance.html"
title="next chapter">Hints for Performance Tuning</a></p>
<div role="note" aria-label="source link">
<h3>This Page</h3>
<ul class="this-page-menu">
<li><a href="../_sources/manual/profiling.rst.txt"
rel="nofollow">Show Source</a></li>
</ul>
</div>
<div id="searchbox" style="display: none" role="search">
<h3 id="searchlabel">Quick search</h3>
<div class="searchformwrapper">
<form class="search" action="../search.html" method="get">
<input type="text" name="q" aria-labelledby="searchlabel" />
<input type="submit" value="Go" />
</form>
</div>
</div>
<script>$('#searchbox').show(0);</script>
</div>
</div>
<div class="document">
<div class="documentwrapper">
<div class="bodywrapper">
<div class="body" role="main">
<div class="section" id="profiling">
<span id="ch-profiling"></span><h1>Profiling<a class="headerlink" href="#profiling" title="Permalink to this headline">¶</a></h1>
<p>PETSc includes a consistent, lightweight scheme to allow the profiling
of application programs. The PETSc routines automatically log
performance data if certain options are specified at runtime. The user
can also log information about application codes for a complete picture
of performance. In addition, as described in
<a class="reference internal" href="#sec-ploginfo"><span class="std std-ref">Interpreting -log_view Output: The Basics</span></a>, PETSc provides a mechanism for
printing informative messages about computations.
<a class="reference internal" href="#sec-profbasic"><span class="std std-ref">Basic Profiling Information</span></a> introduces the various profiling
options in PETSc, while the remainder of the chapter focuses on details
such as monitoring application codes and tips for accurate profiling.</p>
<div class="section" id="basic-profiling-information">
<span id="sec-profbasic"></span><h2>Basic Profiling Information<a class="headerlink" href="#basic-profiling-information" title="Permalink to this headline">¶</a></h2>
<p>If an application code and the PETSc libraries have been configured with
<code class="docutils literal notranslate"><span class="pre">--with-log=1</span></code>, the default, then various kinds of profiling of code
between calls to <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscInitialize.html#PetscInitialize">PetscInitialize</a>()</span></code> and <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscFinalize.html#PetscFinalize">PetscFinalize</a>()</span></code> can be
activated at runtime. The profiling options include the following:</p>
<ul class="simple">
<li><p><code class="docutils literal notranslate"><span class="pre">-log_view</span></code> - Prints an ASCII version of performance data at
program’s conclusion. These statistics are comprehensive and concise
and require little overhead; thus, <code class="docutils literal notranslate"><span class="pre">-log_view</span></code> is intended as the
primary means of monitoring the performance of PETSc codes.</p></li>
<li><p><code class="docutils literal notranslate"><span class="pre">-info</span> <span class="pre">[infofile]</span></code> - Prints verbose information about code to
stdout or an optional file. This option provides details about
algorithms, data structures, etc. Since the overhead of printing such
output slows a code, this option should not be used when evaluating a
program’s performance.</p></li>
<li><p><code class="docutils literal notranslate"><span class="pre">-log_trace</span> <span class="pre">[logfile]</span></code> - Traces the beginning and ending of all
PETSc events. This option, which can be used in conjunction with
<code class="docutils literal notranslate"><span class="pre">-info</span></code>, is useful to see where a program is hanging without
running in the debugger.</p></li>
</ul>
<p>As discussed in <a class="reference internal" href="#sec-mpelogs"><span class="std std-ref">Using -log_mpe with Jumpshot</span></a>, additional profiling
can be done with MPE.</p>
<div class="section" id="interpreting-log-view-output-the-basics">
<span id="sec-ploginfo"></span><h3>Interpreting <code class="docutils literal notranslate"><span class="pre">-log_view</span></code> Output: The Basics<a class="headerlink" href="#interpreting-log-view-output-the-basics" title="Permalink to this headline">¶</a></h3>
<p>As shown in <a class="reference external" href="listing_exprof">the listing</a> in <a class="reference internal" href="getting_started.html#sec-profiling-programs"><span class="std std-ref">Profiling Programs</span></a>, the
option <code class="docutils literal notranslate"><span class="pre">-log_view</span></code> activates printing of profile data to standard
output at the conclusion of a program. Profiling data can also be
printed at any time within a program by calling <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogView.html#PetscLogView">PetscLogView</a>()</span></code>.</p>
<p>We print performance data for each routine, organized by PETSc
libraries, followed by any user-defined events (discussed in
<a class="reference internal" href="#sec-profileuser"><span class="std std-ref">Profiling Application Codes</span></a>). For each routine, the output data
include the maximum time and floating point operation (flop) rate over
all processes. Information about parallel performance is also included,
as discussed in the following section.</p>
<p>For the purpose of PETSc floating point operation counting, we define
one <em>flop</em> as one operation of any of the following types:
multiplication, division, addition, or subtraction. For example, one
<code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecAXPY.html#VecAXPY">VecAXPY</a>()</span></code> operation, which computes <span class="math">\(y = \alpha x + y\)</span> for
vectors of length <span class="math">\(N\)</span>, requires <span class="math">\(2N\)</span> flop (consisting of
<span class="math">\(N\)</span> additions and <span class="math">\(N\)</span> multiplications). Bear in mind that
flop rates present only a limited view of performance, since memory
loads and stores are the real performance barrier.</p>
<p>For simplicity, the remainder of this discussion focuses on interpreting
profile data for the <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSP.html#KSP">KSP</a></span></code> library, which provides the linear solvers
at the heart of the PETSc package. Recall the hierarchical organization
of the PETSc library, as shown in
<a class="reference internal" href="getting_started.html#fig-library"><span class="std std-ref">Numerical Libraries in PETSc</span></a>. Each <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSP.html#KSP">KSP</a></span></code> solver is composed
of a <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/PC/PC.html#PC">PC</a></span></code> (preconditioner) and a <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSP.html#KSP">KSP</a></span></code> (Krylov subspace) part, which
are in turn built on top of the <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/Mat.html#Mat">Mat</a></span></code> (matrix) and <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/Vec.html#Vec">Vec</a></span></code> (vector)
modules. Thus, operations in the <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSP.html#KSP">KSP</a></span></code> module are composed of
lower-level operations in these packages. Note also that the nonlinear
solvers library, <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/SNES/SNES.html#SNES">SNES</a></span></code>, is built on top of the <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSP.html#KSP">KSP</a></span></code> module, and
the timestepping library, <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/TS/TS.html#TS">TS</a></span></code>, is in turn built on top of <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/SNES/SNES.html#SNES">SNES</a></span></code>.</p>
<p>We briefly discuss interpretation of the sample output in
<a class="reference external" href="listing_exprof">the listing</a>, which was generated by solving a
linear system on one process using restarted GMRES and ILU
preconditioning. The linear solvers in <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSP.html#KSP">KSP</a></span></code> consist of two basic
phases, <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSetUp.html#KSPSetUp">KSPSetUp</a>()</span></code> and <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSolve.html#KSPSolve">KSPSolve</a>()</span></code>, each of which consists of a
variety of actions, depending on the particular solution technique. For
the case of using the <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/PC/PCILU.html#PCILU">PCILU</a></span></code> preconditioner and <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPGMRES.html#KSPGMRES">KSPGMRES</a></span></code> Krylov
subspace method, the breakdown of PETSc routines is listed below. As
indicated by the levels of indentation, the operations in <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSetUp.html#KSPSetUp">KSPSetUp</a>()</span></code>
include all of the operations within <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/PC/PCSetUp.html#PCSetUp">PCSetUp</a>()</span></code>, which in turn
include <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/MatILUFactor.html#MatILUFactor">MatILUFactor</a>()</span></code>, and so on.</p>
<ul class="simple">
<li><p><code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSetUp.html#KSPSetUp">KSPSetUp</a></span></code> - Set up linear solver</p>
<ul>
<li><p><code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/PC/PCSetUp.html#PCSetUp">PCSetUp</a></span></code> - Set up preconditioner</p>
<ul>
<li><p><code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/MatILUFactor.html#MatILUFactor">MatILUFactor</a></span></code> - Factor preconditioning matrix</p>
<ul>
<li><p><code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/MatILUFactorSymbolic.html#MatILUFactorSymbolic">MatILUFactorSymbolic</a></span></code> - Symbolic factorization phase</p></li>
<li><p><code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/MatLUFactorNumeric.html#MatLUFactorNumeric">MatLUFactorNumeric</a></span></code> - Numeric factorization phase</p></li>
</ul>
</li>
</ul>
</li>
</ul>
</li>
<li><p><code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSolve.html#KSPSolve">KSPSolve</a></span></code> - Solve linear system</p>
<ul>
<li><p><code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/PC/PCApply.html#PCApply">PCApply</a></span></code> - Apply preconditioner</p>
<ul>
<li><p><code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/MatSolve.html#MatSolve">MatSolve</a></span></code> - Forward/backward triangular solves</p></li>
</ul>
</li>
<li><p><code class="docutils literal notranslate"><span class="pre">KSPGMRESOrthog</span></code> - Orthogonalization in GMRES</p>
<ul>
<li><p><code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecDot.html#VecDot">VecDot</a></span></code> or <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecMDot.html#VecMDot">VecMDot</a></span></code> - Inner products</p></li>
</ul>
</li>
<li><p><code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/MatMult.html#MatMult">MatMult</a></span></code> - Matrix-vector product</p></li>
<li><p><code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/MatMultAdd.html#MatMultAdd">MatMultAdd</a></span></code> - Matrix-vector product + vector addition</p>
<ul>
<li><p><code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecScale.html#VecScale">VecScale</a></span></code>, <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecNorm.html#VecNorm">VecNorm</a></span></code>, <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecAXPY.html#VecAXPY">VecAXPY</a></span></code>, <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecCopy.html#VecCopy">VecCopy</a></span></code>, …</p></li>
</ul>
</li>
</ul>
</li>
</ul>
<p>The summaries printed via <code class="docutils literal notranslate"><span class="pre">-log_view</span></code> reflect this routine hierarchy.
For example, the performance summaries for a particular high-level
routine such as <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSolve.html#KSPSolve">KSPSolve</a>()</span></code> include all of the operations accumulated
in the lower-level components that make up the routine.</p>
<p>Admittedly, we do not currently present the output with <code class="docutils literal notranslate"><span class="pre">-log_view</span></code> so
that the hierarchy of PETSc operations is completely clear, primarily
because we have not determined a clean and uniform way to do so
throughout the library. Improvements may follow. However, for a
particular problem, the user should generally have an idea of the basic
operations that are required for its implementation (e.g., which
operations are performed when using GMRES and ILU, as described above),
so that interpreting the <code class="docutils literal notranslate"><span class="pre">-log_view</span></code> data should be relatively
straightforward.</p>
</div>
<div class="section" id="interpreting-log-view-output-parallel-performance">
<span id="sec-parperformance"></span><h3>Interpreting <code class="docutils literal notranslate"><span class="pre">-log_view</span></code> Output: Parallel Performance<a class="headerlink" href="#interpreting-log-view-output-parallel-performance" title="Permalink to this headline">¶</a></h3>
<p>We next discuss performance summaries for parallel programs, as shown
within the <a class="reference external" href="listing_exparprof">listings</a> <a class="reference external" href="listing_exparprof2">below</a> ,
which present the combined
output generated by the <code class="docutils literal notranslate"><span class="pre">-log_view</span></code> option. The program that generated
this data is
<a class="reference external" href="https://www.mcs.anl.gov/petsc/petsc-current/src/ksp/ksp/tutorials/ex10.c.html">KSP Tutorial ex10</a>.
The code loads a matrix and right-hand-side vector from a binary file
and then solves the resulting linear system; the program then repeats
this process for a second linear system. This particular case was run on
four processors of an Intel x86_64 Linux cluster, using restarted GMRES
and the block Jacobi preconditioner, where each block was solved with
ILU. The two input files <code class="docutils literal notranslate"><span class="pre">medium</span></code> and <code class="docutils literal notranslate"><span class="pre">arco6</span></code> can be downloaded from
<a class="reference external" href="http://ftp.mcs.anl.gov/pub/petsc/Datafiles/matrices/">this FTP link</a>.</p>
<p><a class="reference external" href="listing_exparprof">The first listing</a> presents an overall
performance summary, including times, floating-point operations,
computational rates, and message-passing activity (such as the number
and size of messages sent and collective operations). Summaries for
various user-defined stages of monitoring (as discussed in
<a class="reference internal" href="#sec-profstages"><span class="std std-ref">Profiling Multiple Sections of Code</span></a>) are also given. Information about the
various phases of computation then follow (as shown separately here in
<a class="reference external" href="listing_exparprof2">the second listing</a>). Finally, a summary of
memory usage and object creation and destruction is presented.</p>
<div class="highlight-none notranslate" id="listing-exparprof"><div class="highlight"><pre><span></span>mpiexec -n 4 ./ex10 -f0 medium -f1 arco6 -ksp_gmres_classicalgramschmidt -log_view -mat_type baij \
-matload_block_size 3 -pc_type bjacobi -options_left
Number of iterations = 19
Residual norm 1.088292e-05
Number of iterations = 59
Residual norm 3.871022e-02
---------------------------------------------- PETSc Performance Summary: ----------------------------------------------
./ex10 on a intel-bdw-opt named beboplogin4 with 4 processors, by jczhang Mon Apr 23 13:36:54 2018
Using Petsc Development GIT revision: v3.9-163-gbe3efd42 GIT Date: 2018-04-16 10:45:40 -0500
Max Max/Min Avg Total
Time (sec): 1.849e-01 1.00002 1.849e-01
Objects: 1.060e+02 1.00000 1.060e+02
Flop: 2.361e+08 1.00684 2.353e+08 9.413e+08
Flop/sec: 1.277e+09 1.00685 1.273e+09 5.091e+09
MPI Messages: 2.360e+02 1.34857 2.061e+02 8.245e+02
MPI Message Lengths: 1.256e+07 2.24620 4.071e+04 3.357e+07
MPI Reductions: 2.160e+02 1.00000
Summary of Stages: ----- Time ------ ----- Flop ----- --- Messages --- -- Message Lengths -- -- Reductions --
Avg %Total Avg %Total counts %Total Avg %Total counts %Total
0: Main Stage: 5.9897e-04 0.3% 0.0000e+00 0.0% 0.000e+00 0.0% 0.000e+00 0.0% 2.000e+00 0.9%
1: Load System 0: 2.9113e-03 1.6% 0.0000e+00 0.0% 3.550e+01 4.3% 5.984e+02 0.1% 2.200e+01 10.2%
2: <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSetUp.html#KSPSetUp">KSPSetUp</a> 0: 7.7349e-04 0.4% 9.9360e+03 0.0% 0.000e+00 0.0% 0.000e+00 0.0% 2.000e+00 0.9%
3: <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSolve.html#KSPSolve">KSPSolve</a> 0: 1.7690e-03 1.0% 2.9673e+05 0.0% 1.520e+02 18.4% 1.800e+02 0.1% 3.900e+01 18.1%
4: Load System 1: 1.0056e-01 54.4% 0.0000e+00 0.0% 3.700e+01 4.5% 5.657e+05 62.4% 2.200e+01 10.2%
5: <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSetUp.html#KSPSetUp">KSPSetUp</a> 1: 5.6883e-03 3.1% 2.1205e+07 2.3% 0.000e+00 0.0% 0.000e+00 0.0% 2.000e+00 0.9%
6: <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSolve.html#KSPSolve">KSPSolve</a> 1: 7.2578e-02 39.3% 9.1979e+08 97.7% 6.000e+02 72.8% 2.098e+04 37.5% 1.200e+02 55.6%
------------------------------------------------------------------------------------------------------------------------
.... [Summary of various phases, see part II below] ...
------------------------------------------------------------------------------------------------------------------------
Memory usage is given in bytes:
Object Type Creations Destructions Memory Descendants' Mem.
Reports information only for process 0.
...
--- Event Stage 3: <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSolve.html#KSPSolve">KSPSolve</a> 0
Matrix 0 4 23024 0.
Vector 20 30 60048 0.
Index Set 0 3 2568 0.
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/Vec.html#Vec">Vec</a> Scatter 0 1 1264 0.
Krylov Solver 0 2 19592 0.
Preconditioner 0 2 1912 0.
</pre></div>
</div>
<p>We next focus on the summaries for the various phases of the
computation, as given in the table within
<a class="reference external" href="listing_exparprof2">the following listing</a>. The summary for each
phase presents the maximum times and flop rates over all processes, as
well as the ratio of maximum to minimum times and flop rates for all
processes. A ratio of approximately 1 indicates that computations within
a given phase are well balanced among the processes; as the ratio
increases, the balance becomes increasingly poor. Also, the total
computational rate (in units of MFlop/sec) is given for each phase in
the final column of the phase summary table.</p>
<div class="math">
\[{\rm Total\: Mflop/sec} \:=\: 10^{-6} * ({\rm sum\; of\; flop\; over\; all\; processors})/({\rm max\; time\; over\; all\; processors})
\]</div>
<p><em>Note</em>: Total computational rates <span class="math">\(<\)</span> 1 MFlop are listed as 0 in
this column of the phase summary table. Additional statistics for each
phase include the total number of messages sent, the average message
length, and the number of global reductions.</p>
<div class="highlight-none notranslate" id="listing-exparprof2"><div class="highlight"><pre><span></span>mpiexec -n 4 ./ex10 -f0 medium -f1 arco6 -ksp_gmres_classicalgramschmidt -log_view -mat_type baij \
-matload_block_size 3 -pc_type bjacobi -options_left
---------------------------------------------- PETSc Performance Summary: ----------------------------------------------
.... [Overall summary, see part I] ...
Phase summary info:
Count: number of times phase was executed
Time and Flop/sec: Max - maximum over all processors
Ratio - ratio of maximum to minimum over all processors
Mess: number of messages sent
AvgLen: average message length
Reduct: number of global reductions
Global: entire computation
Stage: optional user-defined stages of a computation. Set stages with <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStagePush.html#PetscLogStagePush">PetscLogStagePush</a>() and <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStagePop.html#PetscLogStagePop">PetscLogStagePop</a>().
%T - percent time in this phase %F - percent flop in this phase
%M - percent messages in this phase %L - percent message lengths in this phase
%R - percent reductions in this phase
Total Mflop/s: 10^6 * (sum of flop over all processors)/(max time over all processors)
------------------------------------------------------------------------------------------------------------------------
Phase Count Time (sec) Flop/sec --- Global --- --- Stage ---- Total
Max Ratio Max Ratio Mess AvgLen Reduct %T %F %M %L %R %T %F %M %L %R Mflop/s
------------------------------------------------------------------------------------------------------------------------
...
--- Event Stage 5: <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSetUp.html#KSPSetUp">KSPSetUp</a> 1
MatLUFactorNum 1 1.0 3.6440e-03 1.1 5.30e+06 1.0 0.0e+00 0.0e+00 0.0e+00 2 2 0 0 0 62100 0 0 0 5819
MatILUFactorSym 1 1.0 1.7111e-03 1.4 0.00e+00 0.0 0.0e+00 0.0e+00 0.0e+00 1 0 0 0 0 26 0 0 0 0 0
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/MatGetRowIJ.html#MatGetRowIJ">MatGetRowIJ</a> 1 1.0 1.1921e-06 1.2 0.00e+00 0.0 0.0e+00 0.0e+00 0.0e+00 0 0 0 0 0 0 0 0 0 0 0
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/MatOrderings/MatGetOrdering.html#MatGetOrdering">MatGetOrdering</a> 1 1.0 3.0041e-05 1.1 0.00e+00 0.0 0.0e+00 0.0e+00 0.0e+00 0 0 0 0 0 1 0 0 0 0 0
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSetUp.html#KSPSetUp">KSPSetUp</a> 2 1.0 6.6495e-04 1.5 0.00e+00 0.0 0.0e+00 0.0e+00 2.0e+00 0 0 0 0 1 9 0 0 0100 0
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/PC/PCSetUp.html#PCSetUp">PCSetUp</a> 2 1.0 5.4271e-03 1.2 5.30e+06 1.0 0.0e+00 0.0e+00 0.0e+00 3 2 0 0 0 90100 0 0 0 3907
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/PC/PCSetUpOnBlocks.html#PCSetUpOnBlocks">PCSetUpOnBlocks</a> 1 1.0 5.3999e-03 1.2 5.30e+06 1.0 0.0e+00 0.0e+00 0.0e+00 3 2 0 0 0 90100 0 0 0 3927
--- Event Stage 6: <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSolve.html#KSPSolve">KSPSolve</a> 1
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/MatMult.html#MatMult">MatMult</a> 60 1.0 2.4068e-02 1.1 6.54e+07 1.0 6.0e+02 2.1e+04 0.0e+00 12 27 73 37 0 32 28100100 0 10731
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/MatSolve.html#MatSolve">MatSolve</a> 61 1.0 1.9177e-02 1.0 5.99e+07 1.0 0.0e+00 0.0e+00 0.0e+00 10 25 0 0 0 26 26 0 0 0 12491
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecMDot.html#VecMDot">VecMDot</a> 59 1.0 1.4741e-02 1.3 4.86e+07 1.0 0.0e+00 0.0e+00 5.9e+01 7 21 0 0 27 18 21 0 0 49 13189
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecNorm.html#VecNorm">VecNorm</a> 61 1.0 3.0417e-03 1.4 3.29e+06 1.0 0.0e+00 0.0e+00 6.1e+01 1 1 0 0 28 4 1 0 0 51 4332
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecScale.html#VecScale">VecScale</a> 61 1.0 9.9802e-04 1.0 1.65e+06 1.0 0.0e+00 0.0e+00 0.0e+00 1 1 0 0 0 1 1 0 0 0 6602
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecCopy.html#VecCopy">VecCopy</a> 2 1.0 5.9128e-05 1.4 0.00e+00 0.0 0.0e+00 0.0e+00 0.0e+00 0 0 0 0 0 0 0 0 0 0 0
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecSet.html#VecSet">VecSet</a> 64 1.0 8.0323e-04 1.0 0.00e+00 0.0 0.0e+00 0.0e+00 0.0e+00 0 0 0 0 0 1 0 0 0 0 0
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecAXPY.html#VecAXPY">VecAXPY</a> 3 1.0 7.4387e-05 1.1 1.62e+05 1.0 0.0e+00 0.0e+00 0.0e+00 0 0 0 0 0 0 0 0 0 0 8712
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecMAXPY.html#VecMAXPY">VecMAXPY</a> 61 1.0 8.8558e-03 1.1 5.18e+07 1.0 0.0e+00 0.0e+00 0.0e+00 5 22 0 0 0 12 23 0 0 0 23393
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecScatterBegin.html#VecScatterBegin">VecScatterBegin</a> 60 1.0 9.6416e-04 1.8 0.00e+00 0.0 6.0e+02 2.1e+04 0.0e+00 0 0 73 37 0 1 0100100 0 0
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecScatterEnd.html#VecScatterEnd">VecScatterEnd</a> 60 1.0 6.1543e-03 1.2 0.00e+00 0.0 0.0e+00 0.0e+00 0.0e+00 3 0 0 0 0 8 0 0 0 0 0
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecNormalize.html#VecNormalize">VecNormalize</a> 61 1.0 4.2675e-03 1.3 4.94e+06 1.0 0.0e+00 0.0e+00 6.1e+01 2 2 0 0 28 5 2 0 0 51 4632
KSPGMRESOrthog 59 1.0 2.2627e-02 1.1 9.72e+07 1.0 0.0e+00 0.0e+00 5.9e+01 11 41 0 0 27 29 42 0 0 49 17185
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSPSolve.html#KSPSolve">KSPSolve</a> 1 1.0 7.2577e-02 1.0 2.31e+08 1.0 6.0e+02 2.1e+04 1.2e+02 39 98 73 37 56 99100100100100 12673
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/PC/PCSetUpOnBlocks.html#PCSetUpOnBlocks">PCSetUpOnBlocks</a> 1 1.0 9.5367e-07 0.0 0.00e+00 0.0 0.0e+00 0.0e+00 0.0e+00 0 0 0 0 0 0 0 0 0 0 0
<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/PC/PCApply.html#PCApply">PCApply</a> 61 1.0 2.0427e-02 1.0 5.99e+07 1.0 0.0e+00 0.0e+00 0.0e+00 11 25 0 0 0 28 26 0 0 0 11726
------------------------------------------------------------------------------------------------------------------------
.... [Conclusion of overall summary, see part I] ...
</pre></div>
</div>
<p>As discussed in the preceding section, the performance summaries for
higher-level PETSc routines include the statistics for the lower levels
of which they are made up. For example, the communication within
matrix-vector products <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/MatMult.html#MatMult">MatMult</a>()</span></code> consists of vector scatter
operations, as given by the routines <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecScatterBegin.html#VecScatterBegin">VecScatterBegin</a>()</span></code> and
<code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecScatterEnd.html#VecScatterEnd">VecScatterEnd</a>()</span></code>.</p>
<p>The final data presented are the percentages of the various statistics
(time (<code class="docutils literal notranslate"><span class="pre">%T</span></code>), flop/sec (<code class="docutils literal notranslate"><span class="pre">%F</span></code>), messages(<code class="docutils literal notranslate"><span class="pre">%M</span></code>), average message
length (<code class="docutils literal notranslate"><span class="pre">%L</span></code>), and reductions (<code class="docutils literal notranslate"><span class="pre">%R</span></code>)) for each event relative to the
total computation and to any user-defined stages (discussed in
<a class="reference internal" href="#sec-profstages"><span class="std std-ref">Profiling Multiple Sections of Code</span></a>). These statistics can aid in
optimizing performance, since they indicate the sections of code that
could benefit from various kinds of tuning.
<a class="reference internal" href="performance.html#ch-performance"><span class="std std-ref">Hints for Performance Tuning</span></a> gives suggestions about achieving good
performance with PETSc codes.</p>
</div>
<div class="section" id="using-log-mpe-with-jumpshot">
<span id="sec-mpelogs"></span><h3>Using <code class="docutils literal notranslate"><span class="pre">-log_mpe</span></code> with Jumpshot<a class="headerlink" href="#using-log-mpe-with-jumpshot" title="Permalink to this headline">¶</a></h3>
<p>It is also possible to use the <em>Jumpshot</em> package
<span id="id1">[<a class="reference internal" href="#id209"><span>HL91</span></a>]</span> to visualize PETSc events. This package comes
with the MPE software, which is part of the MPICH
<span id="id2">[<a class="reference internal" href="#id200"><span>Getal</span></a>]</span> implementation of MPI. The option</p>
<div class="highlight-none notranslate"><div class="highlight"><pre><span></span>-log_mpe [logfile]
</pre></div>
</div>
<p>creates a logfile of events appropriate for viewing with <em>Jumpshot</em>. The
user can either use the default logging file or specify a name via
<code class="docutils literal notranslate"><span class="pre">logfile</span></code>. Events can be deactivated as described in
<a class="reference internal" href="#sec-deactivate"><span class="std std-ref">Restricting Event Logging</span></a>.</p>
<p>The user can also log MPI events. To do this, simply consider the PETSc
application as any MPI application, and follow the MPI implementation’s
instructions for logging MPI calls. For example, when using MPICH, this
merely required adding <code class="docutils literal notranslate"><span class="pre">-llmpich</span></code> to the library list <em>before</em>
<code class="docutils literal notranslate"><span class="pre">-lmpich</span></code>.</p>
</div>
</div>
<div class="section" id="profiling-application-codes">
<span id="sec-profileuser"></span><h2>Profiling Application Codes<a class="headerlink" href="#profiling-application-codes" title="Permalink to this headline">¶</a></h2>
<p>PETSc automatically logs object creation, times, and floating-point
counts for the library routines. Users can easily supplement this
information by monitoring their application codes as well. The basic
steps involved in logging a user-defined portion of code, called an
<em>event</em>, are shown in the code fragment below:</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEvent.html#PetscLogEvent">PetscLogEvent</a></span> <span class="n">USER_EVENT</span><span class="p">;</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscClassId.html#PetscClassId">PetscClassId</a></span> <span class="n">classid</span><span class="p">;</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscLogDouble.html#PetscLogDouble">PetscLogDouble</a></span> <span class="n">user_event_flops</span><span class="p">;</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscClassIdRegister.html#PetscClassIdRegister">PetscClassIdRegister</a></span><span class="p">(</span><span class="s">"class name"</span><span class="p">,</span><span class="o">&</span><span class="n">classid</span><span class="p">);</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventRegister.html#PetscLogEventRegister">PetscLogEventRegister</a></span><span class="p">(</span><span class="s">"User event name"</span><span class="p">,</span><span class="n">classid</span><span class="p">,</span><span class="o">&</span><span class="n">USER_EVENT</span><span class="p">);</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventBegin.html#PetscLogEventBegin">PetscLogEventBegin</a></span><span class="p">(</span><span class="n">USER_EVENT</span><span class="p">,</span><span class="mi">0</span><span class="p">,</span><span class="mi">0</span><span class="p">,</span><span class="mi">0</span><span class="p">,</span><span class="mi">0</span><span class="p">);</span>
<span class="cm">/* code segment to monitor */</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogFlops.html#PetscLogFlops">PetscLogFlops</a></span><span class="p">(</span><span class="n">user_event_flops</span><span class="p">);</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventEnd.html#PetscLogEventEnd">PetscLogEventEnd</a></span><span class="p">(</span><span class="n">USER_EVENT</span><span class="p">,</span><span class="mi">0</span><span class="p">,</span><span class="mi">0</span><span class="p">,</span><span class="mi">0</span><span class="p">,</span><span class="mi">0</span><span class="p">);</span>
</pre></div>
</div>
<p>One must register the event by calling <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventRegister.html#PetscLogEventRegister">PetscLogEventRegister</a>()</span></code>,
which assigns a unique integer to identify the event for profiling
purposes:</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventRegister.html#PetscLogEventRegister">PetscLogEventRegister</a></span><span class="p">(</span><span class="k">const</span> <span class="kt">char</span> <span class="n">string</span><span class="p">[],</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscClassId.html#PetscClassId">PetscClassId</a></span> <span class="n">classid</span><span class="p">,</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEvent.html#PetscLogEvent">PetscLogEvent</a></span> <span class="o">*</span><span class="n">e</span><span class="p">);</span>
</pre></div>
</div>
<p>Here <code class="docutils literal notranslate"><span class="pre">string</span></code> is a user-defined event name, and <code class="docutils literal notranslate"><span class="pre">color</span></code> is an
optional user-defined event color (for use with <em>Jumpshot</em> logging; see
<a class="reference internal" href="#sec-mpelogs"><span class="std std-ref">Using -log_mpe with Jumpshot</span></a>); one should see the manual page for
details. The argument returned in <code class="docutils literal notranslate"><span class="pre">e</span></code> should then be passed to the
<code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventBegin.html#PetscLogEventBegin">PetscLogEventBegin</a>()</span></code> and <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventEnd.html#PetscLogEventEnd">PetscLogEventEnd</a>()</span></code> routines.</p>
<p>Events are logged by using the pair</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventBegin.html#PetscLogEventBegin">PetscLogEventBegin</a></span><span class="p">(</span><span class="kt">int</span> <span class="n">event</span><span class="p">,</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscObject.html#PetscObject">PetscObject</a></span> <span class="n">o1</span><span class="p">,</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscObject.html#PetscObject">PetscObject</a></span> <span class="n">o2</span><span class="p">,</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscObject.html#PetscObject">PetscObject</a></span> <span class="n">o3</span><span class="p">,</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscObject.html#PetscObject">PetscObject</a></span> <span class="n">o4</span><span class="p">);</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventEnd.html#PetscLogEventEnd">PetscLogEventEnd</a></span><span class="p">(</span><span class="kt">int</span> <span class="n">event</span><span class="p">,</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscObject.html#PetscObject">PetscObject</a></span> <span class="n">o1</span><span class="p">,</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscObject.html#PetscObject">PetscObject</a></span> <span class="n">o2</span><span class="p">,</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscObject.html#PetscObject">PetscObject</a></span> <span class="n">o3</span><span class="p">,</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscObject.html#PetscObject">PetscObject</a></span> <span class="n">o4</span><span class="p">);</span>
</pre></div>
</div>
<p>The four objects are the PETSc objects that are most closely associated
with the event. For instance, in a matrix-vector product they would be
the matrix and the two vectors. These objects can be omitted by
specifying 0 for <code class="docutils literal notranslate"><span class="pre">o1</span></code> - <code class="docutils literal notranslate"><span class="pre">o4</span></code>. The code between these two routine
calls will be automatically timed and logged as part of the specified
event.</p>
<p>The user can log the number of floating-point operations for this
segment of code by calling</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogFlops.html#PetscLogFlops">PetscLogFlops</a></span><span class="p">(</span><span class="n">number</span> <span class="n">of</span> <span class="n">flop</span> <span class="k">for</span> <span class="n">this</span> <span class="n">code</span> <span class="n">segment</span><span class="p">);</span>
</pre></div>
</div>
<p>between the calls to <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventBegin.html#PetscLogEventBegin">PetscLogEventBegin</a>()</span></code> and
<code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventEnd.html#PetscLogEventEnd">PetscLogEventEnd</a>()</span></code>. This value will automatically be added to the
global flop counter for the entire program.</p>
</div>
<div class="section" id="profiling-multiple-sections-of-code">
<span id="sec-profstages"></span><h2>Profiling Multiple Sections of Code<a class="headerlink" href="#profiling-multiple-sections-of-code" title="Permalink to this headline">¶</a></h2>
<p>By default, the profiling produces a single set of statistics for all
code between the <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscInitialize.html#PetscInitialize">PetscInitialize</a>()</span></code> and <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscFinalize.html#PetscFinalize">PetscFinalize</a>()</span></code> calls
within a program. One can independently monitor up to ten stages of code
by switching among the various stages with the commands</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStagePush.html#PetscLogStagePush">PetscLogStagePush</a></span><span class="p">(</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStage.html#PetscLogStage">PetscLogStage</a></span> <span class="n">stage</span><span class="p">);</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStagePop.html#PetscLogStagePop">PetscLogStagePop</a></span><span class="p">();</span>
</pre></div>
</div>
<p>where <code class="docutils literal notranslate"><span class="pre">stage</span></code> is an integer (0-9); see the manual pages for details.
The command</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStageRegister.html#PetscLogStageRegister">PetscLogStageRegister</a></span><span class="p">(</span><span class="k">const</span> <span class="kt">char</span> <span class="o">*</span><span class="n">name</span><span class="p">,</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStage.html#PetscLogStage">PetscLogStage</a></span> <span class="o">*</span><span class="n">stage</span><span class="p">)</span>
</pre></div>
</div>
<p>allows one to associate a name with a stage; these names are printed
whenever summaries are generated with <code class="docutils literal notranslate"><span class="pre">-log_view</span></code> or
<code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogView.html#PetscLogView">PetscLogView</a>()</span></code>. The following code fragment uses three profiling
stages within an program.</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscInitialize.html#PetscInitialize">PetscInitialize</a></span><span class="p">(</span><span class="kt">int</span> <span class="o">*</span><span class="n">argc</span><span class="p">,</span><span class="kt">char</span> <span class="o">***</span><span class="n">args</span><span class="p">,</span><span class="mi">0</span><span class="p">,</span><span class="mi">0</span><span class="p">);</span>
<span class="cm">/* stage 0 of code here */</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStageRegister.html#PetscLogStageRegister">PetscLogStageRegister</a></span><span class="p">(</span><span class="s">"Stage 0 of Code"</span><span class="p">,</span> <span class="o">&</span><span class="n">stagenum0</span><span class="p">);</span>
<span class="k">for</span> <span class="p">(</span><span class="n">i</span><span class="o">=</span><span class="mi">0</span><span class="p">;</span> <span class="n">i</span><span class="o"><</span><span class="n">ntimes</span><span class="p">;</span> <span class="n">i</span><span class="o">++</span><span class="p">)</span> <span class="p">{</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStageRegister.html#PetscLogStageRegister">PetscLogStageRegister</a></span><span class="p">(</span><span class="s">"Stage 1 of Code"</span><span class="p">,</span> <span class="o">&</span><span class="n">stagenum1</span><span class="p">);</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStagePush.html#PetscLogStagePush">PetscLogStagePush</a></span><span class="p">(</span><span class="n">stagenum1</span><span class="p">);</span>
<span class="cm">/* stage 1 of code here */</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStagePop.html#PetscLogStagePop">PetscLogStagePop</a></span><span class="p">();</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStageRegister.html#PetscLogStageRegister">PetscLogStageRegister</a></span><span class="p">(</span><span class="s">"Stage 2 of Code"</span><span class="p">,</span> <span class="o">&</span><span class="n">stagenum2</span><span class="p">);</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStagePush.html#PetscLogStagePush">PetscLogStagePush</a></span><span class="p">(</span><span class="n">stagenum2</span><span class="p">);</span>
<span class="cm">/* stage 2 of code here */</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogStagePop.html#PetscLogStagePop">PetscLogStagePop</a></span><span class="p">();</span>
<span class="p">}</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscFinalize.html#PetscFinalize">PetscFinalize</a></span><span class="p">();</span>
</pre></div>
</div>
<p>The <a class="reference external" href="listing_exparprof">listings</a> <a class="reference external" href="listing_exparprof2">above</a>
Figures <a class="reference external" href="#fig_exparprof">[fig_exparprof]</a> and
show output generated by
<code class="docutils literal notranslate"><span class="pre">-log_view</span></code> for a program that employs several profiling stages. In
particular, this program is subdivided into six stages except the Main
stage: loading a matrix and right-hand-side vector from a binary file,
setting up the preconditioner, and solving the linear system; this
sequence is then repeated for a second linear system. For simplicity,
<a class="reference external" href="listing_exparprof2">the second listing</a> contains output only for
stages 5 and 6 (linear solve of the second system), which comprise the
part of this computation of most interest to us in terms of performance
monitoring. This code organization (solving a small linear system
followed by a larger system) enables generation of more accurate
profiling statistics for the second system by overcoming the often
considerable overhead of paging, as discussed in
<a class="reference internal" href="#sec-profaccuracy"><span class="std std-ref">Accurate Profiling and Paging Overheads</span></a>.</p>
</div>
<div class="section" id="restricting-event-logging">
<span id="sec-deactivate"></span><h2>Restricting Event Logging<a class="headerlink" href="#restricting-event-logging" title="Permalink to this headline">¶</a></h2>
<p>By default, all PETSc operations are logged. To enable or disable the
PETSc logging of individual events, one uses the commands</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventActivate.html#PetscLogEventActivate">PetscLogEventActivate</a></span><span class="p">(</span><span class="kt">int</span> <span class="n">event</span><span class="p">);</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventDeactivate.html#PetscLogEventDeactivate">PetscLogEventDeactivate</a></span><span class="p">(</span><span class="kt">int</span> <span class="n">event</span><span class="p">);</span>
</pre></div>
</div>
<p>The <code class="docutils literal notranslate"><span class="pre">event</span></code> may be either a predefined PETSc event (as listed in the
file <code class="docutils literal notranslate"><span class="pre">${PETSC_DIR}/include/petsclog.h</span></code>) or one obtained with
<code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventRegister.html#PetscLogEventRegister">PetscLogEventRegister</a>()</span></code> (as described in
<a class="reference internal" href="#sec-profileuser"><span class="std std-ref">Profiling Application Codes</span></a>).</p>
<p>PETSc also provides routines that deactivate (or activate) logging for
entire components of the library. Currently, the components that support
such logging (de)activation are <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/Mat.html#Mat">Mat</a></span></code> (matrices), <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/Vec.html#Vec">Vec</a></span></code> (vectors),
<code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSP.html#KSP">KSP</a></span></code> (linear solvers, including <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSP.html#KSP">KSP</a></span></code> and <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/PC/PC.html#PC">PC</a></span></code>), and <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/SNES/SNES.html#SNES">SNES</a></span></code>
(nonlinear solvers):</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventDeactivateClass.html#PetscLogEventDeactivateClass">PetscLogEventDeactivateClass</a></span><span class="p">(</span><span class="n">MAT_CLASSID</span><span class="p">);</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventDeactivateClass.html#PetscLogEventDeactivateClass">PetscLogEventDeactivateClass</a></span><span class="p">(</span><span class="n">KSP_CLASSID</span><span class="p">);</span> <span class="cm">/* includes <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/PC/PC.html#PC">PC</a> and <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSP.html#KSP">KSP</a> */</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventDeactivateClass.html#PetscLogEventDeactivateClass">PetscLogEventDeactivateClass</a></span><span class="p">(</span><span class="n">VEC_CLASSID</span><span class="p">);</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventDeactivateClass.html#PetscLogEventDeactivateClass">PetscLogEventDeactivateClass</a></span><span class="p">(</span><span class="n">SNES_CLASSID</span><span class="p">);</span>
</pre></div>
</div>
<p>and</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventActivateClass.html#PetscLogEventActivateClass">PetscLogEventActivateClass</a></span><span class="p">(</span><span class="n">MAT_CLASSID</span><span class="p">);</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventActivateClass.html#PetscLogEventActivateClass">PetscLogEventActivateClass</a></span><span class="p">(</span><span class="n">KSP_CLASSID</span><span class="p">);</span> <span class="cm">/* includes <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/PC/PC.html#PC">PC</a> and <a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/KSP/KSP.html#KSP">KSP</a> */</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventActivateClass.html#PetscLogEventActivateClass">PetscLogEventActivateClass</a></span><span class="p">(</span><span class="n">VEC_CLASSID</span><span class="p">);</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscLogEventActivateClass.html#PetscLogEventActivateClass">PetscLogEventActivateClass</a></span><span class="p">(</span><span class="n">SNES_CLASSID</span><span class="p">);</span>
</pre></div>
</div>
<p>Recall that the option <code class="docutils literal notranslate"><span class="pre">-log_all</span></code> produces extensive profile data,
which can be a challenge for PETScView to handle due to the memory
limitations of Tcl/Tk. Thus, one should generally use <code class="docutils literal notranslate"><span class="pre">-log_all</span></code> when
running programs with a relatively small number of events or when
disabling some of the events that occur many times in a code (e.g.,
<code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Vec/VecSetValues.html#VecSetValues">VecSetValues</a>()</span></code>, <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/MatSetValues.html#MatSetValues">MatSetValues</a>()</span></code>).</p>
</div>
<div class="section" id="interpreting-log-info-output-informative-messages">
<span id="sec-petscloginfo"></span><h2>Interpreting <code class="docutils literal notranslate"><span class="pre">-log_info</span></code> Output: Informative Messages<a class="headerlink" href="#interpreting-log-info-output-informative-messages" title="Permalink to this headline">¶</a></h2>
<p>Users can activate the printing of verbose information about algorithms,
data structures, etc. to the screen by using the option <code class="docutils literal notranslate"><span class="pre">-info</span></code> or by
calling <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscInfoAllow.html#PetscInfoAllow">PetscInfoAllow</a>(<a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PETSC_TRUE.html#PETSC_TRUE">PETSC_TRUE</a>)</span></code>. Such logging, which is used
throughout the PETSc libraries, can aid the user in understanding
algorithms and tuning program performance. For example, as discussed in
<a class="reference internal" href="mat.html#sec-matsparse"><span class="std std-ref">Sparse Matrices</span></a>, <code class="docutils literal notranslate"><span class="pre">-info</span></code> activates the printing of
information about memory allocation during matrix assembly.</p>
<p>Application programmers can employ this logging as well, by using the
routine</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscInfo.html#PetscInfo">PetscInfo</a></span><span class="p">(</span><span class="kt">void</span><span class="o">*</span> <span class="n">obj</span><span class="p">,</span><span class="kt">char</span> <span class="o">*</span><span class="n">message</span><span class="p">,...)</span>
</pre></div>
</div>
<p>where <code class="docutils literal notranslate"><span class="pre">obj</span></code> is the PETSc object associated most closely with the
logging statement, <code class="docutils literal notranslate"><span class="pre">message</span></code>. For example, in the line search Newton
methods, we use a statement such as</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscInfo.html#PetscInfo">PetscInfo</a></span><span class="p">(</span><span class="n">snes</span><span class="p">,</span><span class="s">"Cubically determined step, lambda %g</span><span class="se">\n</span><span class="s">"</span><span class="p">,</span><span class="n">lambda</span><span class="p">);</span>
</pre></div>
</div>
<p>One can selectively turn off informative messages about any of the basic
PETSc objects (e.g., <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/Mat.html#Mat">Mat</a></span></code>, <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/SNES/SNES.html#SNES">SNES</a></span></code>) with the command</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscInfoDeactivateClass.html#PetscInfoDeactivateClass">PetscInfoDeactivateClass</a></span><span class="p">(</span><span class="kt">int</span> <span class="n">object_classid</span><span class="p">)</span>
</pre></div>
</div>
<p>where <code class="docutils literal notranslate"><span class="pre">object_classid</span></code> is one of <code class="docutils literal notranslate"><span class="pre">MAT_CLASSID</span></code>, <code class="docutils literal notranslate"><span class="pre">SNES_CLASSID</span></code>,
etc. Messages can be reactivated with the command</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscInfoActivateClass.html#PetscInfoActivateClass">PetscInfoActivateClass</a></span><span class="p">(</span><span class="kt">int</span> <span class="n">object_classid</span><span class="p">)</span>
</pre></div>
</div>
<p>Such deactivation can be useful when one wishes to view information
about higher-level PETSc libraries (e.g., <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/TS/TS.html#TS">TS</a></span></code> and <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/SNES/SNES.html#SNES">SNES</a></span></code>) without
seeing all lower level data as well (e.g., <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Mat/Mat.html#Mat">Mat</a></span></code>). One can deactivate
events at runtime for matrix and linear solver libraries via
<code class="docutils literal notranslate"><span class="pre">-info</span> <span class="pre">[no_mat,</span> <span class="pre">no_ksp]</span></code>.</p>
</div>
<div class="section" id="time">
<h2>Time<a class="headerlink" href="#time" title="Permalink to this headline">¶</a></h2>
<p>PETSc application programmers can access the wall clock time directly
with the command</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscLogDouble.html#PetscLogDouble">PetscLogDouble</a></span> <span class="n">time</span><span class="p">;</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscTime.html#PetscTime">PetscTime</a></span><span class="p">(</span><span class="o">&</span><span class="n">time</span><span class="p">);</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/CHKERRQ.html#CHKERRQ">CHKERRQ</a></span><span class="p">(</span><span class="n">ierr</span><span class="p">);</span>
</pre></div>
</div>
<p>which returns the current time in seconds since the epoch, and is
commonly implemented with <code class="docutils literal notranslate"><span class="pre"><a href="http://www.mpich.org/static/docs/latest/www3/MPI_Wtime.html#MPI_Wtime">MPI_Wtime</a></span></code>. A floating point number is
returned in order to express fractions of a second. In addition, as
discussed in <a class="reference internal" href="#sec-profileuser"><span class="std std-ref">Profiling Application Codes</span></a>, PETSc can automatically
profile user-defined segments of code.</p>
</div>
<div class="section" id="saving-output-to-a-file">
<h2>Saving Output to a File<a class="headerlink" href="#saving-output-to-a-file" title="Permalink to this headline">¶</a></h2>
<p>All output from PETSc programs (including informative messages,
profiling information, and convergence data) can be saved to a file by
using the command line option <code class="docutils literal notranslate"><span class="pre">-history</span> <span class="pre">[filename]</span></code>. If no file name
is specified, the output is stored in the file
<code class="docutils literal notranslate"><span class="pre">${HOME}/.petschistory</span></code>. Note that this option only saves output
printed with the <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscPrintf.html#PetscPrintf">PetscPrintf</a>()</span></code> and <code class="docutils literal notranslate"><span class="pre"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscFPrintf.html#PetscFPrintf">PetscFPrintf</a>()</span></code> commands, not
the standard <code class="docutils literal notranslate"><span class="pre">printf()</span></code> and <code class="docutils literal notranslate"><span class="pre">fprintf()</span></code> statements.</p>
</div>
<div class="section" id="accurate-profiling-and-paging-overheads">
<span id="sec-profaccuracy"></span><h2>Accurate Profiling and Paging Overheads<a class="headerlink" href="#accurate-profiling-and-paging-overheads" title="Permalink to this headline">¶</a></h2>
<p>One factor that often plays a significant role in profiling a code is
paging by the operating system. Generally, when running a program, only
a few pages required to start it are loaded into memory rather than the
entire executable. When the execution proceeds to code segments that are
not in memory, a pagefault occurs, prompting the required pages to be
loaded from the disk (a very slow process). This activity distorts the
results significantly. (The paging effects are noticeable in the log
files generated by <code class="docutils literal notranslate"><span class="pre">-log_mpe</span></code>, which is described in
<a class="reference internal" href="#sec-mpelogs"><span class="std std-ref">Using -log_mpe with Jumpshot</span></a>.)</p>
<p>To eliminate the effects of paging when profiling the performance of a
program, we have found an effective procedure is to run the <em>exact same
code</em> on a small dummy problem before running it on the actual problem
of interest. We thus ensure that all code required by a solver is loaded
into memory during solution of the small problem. When the code proceeds
to the actual (larger) problem of interest, all required pages have
already been loaded into main memory, so that the performance numbers
are not distorted.</p>
<p>When this procedure is used in conjunction with the user-defined stages
of profiling described in <a class="reference internal" href="#sec-profstages"><span class="std std-ref">Profiling Multiple Sections of Code</span></a>, we can
focus easily on the problem of interest. For example, we used this
technique in the program
<a class="reference external" href="https://www.mcs.anl.gov/petsc/petsc-current/src/ksp/ksp/tutorials/ex10.c.html">KSP Tutorial ex10</a>
to generate the timings within the
<a class="reference external" href="listing_exparprof">listings</a> <a class="reference external" href="listing_exparprof2">above</a>
In this case, the profiled code
of interest (solving the linear system for the larger problem) occurs
within event stages 5 and 6. <a class="reference internal" href="#sec-parperformance"><span class="std std-ref">Interpreting -log_view Output: Parallel Performance</span></a>
provides details about interpreting such profiling data.</p>
<p>In particular, the macros</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscPreLoadBegin.html#PetscPreLoadBegin">PetscPreLoadBegin</a></span><span class="p">(</span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Sys/PetscBool.html#PetscBool">PetscBool</a></span> <span class="n">flag</span><span class="p">,</span><span class="kt">char</span><span class="o">*</span> <span class="n">stagename</span><span class="p">)</span>
<span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscPreLoadStage.html#PetscPreLoadStage">PetscPreLoadStage</a></span><span class="p">(</span><span class="kt">char</span> <span class="o">*</span><span class="n">stagename</span><span class="p">)</span>
</pre></div>
</div>
<p>and</p>
<div class="highlight-c notranslate"><div class="highlight"><pre><span></span><span class="n"><a href="https://www.mcs.anl.gov/petsc/petsc-current/docs/manualpages/Profiling/PetscPreLoadEnd.html#PetscPreLoadEnd">PetscPreLoadEnd</a></span><span class="p">()</span>
</pre></div>
</div>
<p>can be used to easily convert a regular PETSc program to one that uses
preloading. The command line options <code class="docutils literal notranslate"><span class="pre">-preload</span></code> <code class="docutils literal notranslate"><span class="pre">true</span></code> and
<code class="docutils literal notranslate"><span class="pre">-preload</span></code> <code class="docutils literal notranslate"><span class="pre">false</span></code> may be used to turn on and off preloading at run
time for PETSc programs that use these macros.</p>
<hr><p id="id3"><dl class="citation">
<dt class="label" id="id200"><span class="brackets"><a class="fn-backref" href="#id2">Getal</a></span></dt>
<dd><p>William Gropp and et. al. MPICH Web page. <span><a class="reference external" href="#"></a></span>http://www.mpich.org. URL: <a class="reference external" href="http://www.mpich.org">http://www.mpich.org</a>.</p>
</dd>
<dt class="label" id="id209"><span class="brackets"><a class="fn-backref" href="#id1">HL91</a></span></dt>
<dd><p>Virginia Herrarte and Ewing Lusk. Studying parallel program behavior with Upshot. Technical Report ANL-91/15, Argonne National Laboratory, August 1991.</p>
</dd>
</dl>
</p>
<span class="target" id="id1253"></span></div>
</div>
</div>
</div>
</div>
<div class="clearer"></div>
</div>
<div class="related" role="navigation" aria-label="related navigation">
<h3>Navigation</h3>
<ul>
<li class="right" style="margin-right: 10px">
<a href="../genindex.html" title="General Index"
>index</a></li>
<li class="right" >
<a href="performance.html" title="Hints for Performance Tuning"
>next</a> |</li>
<li class="right" >
<a href="matlab.html" title="Using MATLAB with PETSc"
>previous</a> |</li>
<li class="nav-item nav-item-0"><a href="../index.html">PETSc 3.14.5 documentation</a> »</li>
<li class="nav-item nav-item-1"><a href="index.html" >PETSc Users Manual</a> »</li>
<li class="nav-item nav-item-2"><a href="additional.html" >Additional Information</a> »</li>
</ul>
</div>
<div class="footer" role="contentinfo">
© Copyright 1991-2021, UChicago Argonne, LLC and the PETSc Development Team.
Created using <a href="http://sphinx-doc.org/">Sphinx</a> 2.4.4.
</div>
</body>
</html>
|
