File: ProfilingTime

package info (click to toggle)
mlton 20130715-3
  • links: PTS
  • area: main
  • in suites: stretch
  • size: 60,900 kB
  • ctags: 69,386
  • sloc: xml: 34,418; ansic: 17,399; lisp: 2,879; makefile: 1,605; sh: 1,254; pascal: 256; python: 143; asm: 97
file content (149 lines) | stat: -rw-r--r-- 11,913 bytes parent folder | download 
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
 
<!DOCTYPE html>
<html lang="en">
<head>
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
<meta name="generator" content="AsciiDoc 8.6.8">
<title>ProfilingTime</title>
<link rel="stylesheet" href="./asciidoc.css" type="text/css">
<link rel="stylesheet" href="./pygments.css" type="text/css">


<script type="text/javascript" src="./asciidoc.js"></script>
<script type="text/javascript">
/*<![CDATA[*/
asciidoc.install();
/*]]>*/
</script>
<link rel="stylesheet" href="./mlton.css" type="text/css"/>
</head>
<body class="article">
<div id="banner">
<div id="banner-home">
<a href="./Home">MLton 20130715</a>
</div>
</div>
<div id="header">
<h1>ProfilingTime</h1>
</div>
<div id="content">
<div id="preamble">
<div class="sectionbody">
<div class="paragraph"><p>With MLton and <span class="monospaced">mlprof</span>, you can <a href="Profiling">profile</a> your program to
find out how much time is spent in each function over an entire run of
the program.  To do so, compile your program with <span class="monospaced">-profile time</span>.
For example, suppose that <span class="monospaced">tak.sml</span> contains the following.</p></div>
<div class="listingblock">
<div class="content"><div class="highlight"><pre><span class="k">structure</span><span class="w"> </span><span class="n">Tak</span><span class="w"> </span><span class="p">=</span><span class="w"></span>
<span class="w">   </span><span class="k">struct</span><span class="w"></span>
<span class="w">      </span><span class="k">fun</span><span class="w"> </span><span class="n">tak1</span><span class="w"> </span><span class="p">(</span><span class="n">x</span><span class="p">,</span><span class="w"> </span><span class="n">y</span><span class="p">,</span><span class="w"> </span><span class="n">z</span><span class="p">)</span><span class="w"> </span><span class="p">=</span><span class="w"></span>
<span class="w">         </span><span class="k">let</span><span class="w"></span>
<span class="w">            </span><span class="k">fun</span><span class="w"> </span><span class="n">tak2</span><span class="w"> </span><span class="p">(</span><span class="n">x</span><span class="p">,</span><span class="w"> </span><span class="n">y</span><span class="p">,</span><span class="w"> </span><span class="n">z</span><span class="p">)</span><span class="w"> </span><span class="p">=</span><span class="w"></span>
<span class="w">               </span><span class="k">if</span><span class="w"> </span><span class="n">y</span><span class="w"> </span><span class="n">&gt;=</span><span class="w"> </span><span class="n">x</span><span class="w"></span>
<span class="w">                  </span><span class="k">then</span><span class="w"> </span><span class="n">z</span><span class="w"></span>
<span class="w">               </span><span class="k">else</span><span class="w"></span>
<span class="w">                  </span><span class="n">tak1</span><span class="w"> </span><span class="p">(</span><span class="n">tak2</span><span class="w"> </span><span class="p">(</span><span class="n">x</span><span class="w"> </span><span class="n">-</span><span class="w"> </span><span class="mi">1</span><span class="p">,</span><span class="w"> </span><span class="n">y</span><span class="p">,</span><span class="w"> </span><span class="n">z</span><span class="p">),</span><span class="w"></span>
<span class="w">                        </span><span class="n">tak2</span><span class="w"> </span><span class="p">(</span><span class="n">y</span><span class="w"> </span><span class="n">-</span><span class="w"> </span><span class="mi">1</span><span class="p">,</span><span class="w"> </span><span class="n">z</span><span class="p">,</span><span class="w"> </span><span class="n">x</span><span class="p">),</span><span class="w"></span>
<span class="w">                        </span><span class="n">tak2</span><span class="w"> </span><span class="p">(</span><span class="n">z</span><span class="w"> </span><span class="n">-</span><span class="w"> </span><span class="mi">1</span><span class="p">,</span><span class="w"> </span><span class="n">x</span><span class="p">,</span><span class="w"> </span><span class="n">y</span><span class="p">))</span><span class="w"></span>
<span class="w">         </span><span class="k">in</span><span class="w"></span>
<span class="w">            </span><span class="k">if</span><span class="w"> </span><span class="n">y</span><span class="w"> </span><span class="n">&gt;=</span><span class="w"> </span><span class="n">x</span><span class="w"></span>
<span class="w">               </span><span class="k">then</span><span class="w"> </span><span class="n">z</span><span class="w"></span>
<span class="w">            </span><span class="k">else</span><span class="w"></span>
<span class="w">               </span><span class="n">tak1</span><span class="w"> </span><span class="p">(</span><span class="n">tak2</span><span class="w"> </span><span class="p">(</span><span class="n">x</span><span class="w"> </span><span class="n">-</span><span class="w"> </span><span class="mi">1</span><span class="p">,</span><span class="w"> </span><span class="n">y</span><span class="p">,</span><span class="w"> </span><span class="n">z</span><span class="p">),</span><span class="w"></span>
<span class="w">                     </span><span class="n">tak2</span><span class="w"> </span><span class="p">(</span><span class="n">y</span><span class="w"> </span><span class="n">-</span><span class="w"> </span><span class="mi">1</span><span class="p">,</span><span class="w"> </span><span class="n">z</span><span class="p">,</span><span class="w"> </span><span class="n">x</span><span class="p">),</span><span class="w"></span>
<span class="w">                     </span><span class="n">tak2</span><span class="w"> </span><span class="p">(</span><span class="n">z</span><span class="w"> </span><span class="n">-</span><span class="w"> </span><span class="mi">1</span><span class="p">,</span><span class="w"> </span><span class="n">x</span><span class="p">,</span><span class="w"> </span><span class="n">y</span><span class="p">))</span><span class="w"></span>
<span class="w">         </span><span class="k">end</span><span class="w"></span>
<span class="w">   </span><span class="k">end</span><span class="w"></span>

<span class="k">val</span><span class="w"> </span><span class="k">rec</span><span class="w"> </span><span class="n">f</span><span class="w"> </span><span class="p">=</span><span class="w"></span>
<span class="w">   </span><span class="k">fn</span><span class="w"> </span><span class="mi">0</span><span class="w"> </span><span class="p">=&gt;</span><span class="w"> </span><span class="p">()</span><span class="w"></span>
<span class="w">    </span><span class="p">|</span><span class="w"> </span><span class="mi">~1</span><span class="w"> </span><span class="p">=&gt;</span><span class="w"> </span><span class="n">print</span><span class="w"> </span><span class="s">&quot;this branch is not taken</span><span class="se">\n</span><span class="s">&quot;</span><span class="w"></span>
<span class="w">    </span><span class="p">|</span><span class="w"> </span><span class="n">n</span><span class="w"> </span><span class="p">=&gt;</span><span class="w"> </span><span class="p">(</span><span class="n">Tak</span><span class="p">.</span><span class="n">tak1</span><span class="w"> </span><span class="p">(</span><span class="mi">18</span><span class="p">,</span><span class="w"> </span><span class="mi">12</span><span class="p">,</span><span class="w"> </span><span class="mi">6</span><span class="p">)</span><span class="w"> </span><span class="p">;</span><span class="w"> </span><span class="n">f</span><span class="w"> </span><span class="p">(</span><span class="n">n-</span><span class="mi">1</span><span class="p">))</span><span class="w"></span>

<span class="k">val</span><span class="w"> </span><span class="p">_</span><span class="w"> </span><span class="p">=</span><span class="w"> </span><span class="n">f</span><span class="w"> </span><span class="mi">5000</span><span class="w"></span>

<span class="k">fun</span><span class="w"> </span><span class="n">uncalled</span><span class="w"> </span><span class="p">()</span><span class="w"> </span><span class="p">=</span><span class="w"> </span><span class="p">()</span><span class="w"></span>
</pre></div></div></div>
<div class="paragraph"><p>Compile with time profiling and run the program.</p></div>
<div class="listingblock">
<div class="content monospaced">
<pre>% mlton -profile time tak.sml
% ./tak</pre>
</div></div>
<div class="paragraph"><p>Display the profiling data.</p></div>
<div class="listingblock">
<div class="content monospaced">
<pre>% mlprof tak mlmon.out
6.00 seconds of CPU time (0.00 seconds GC)
function     cur
------------- -----
Tak.tak1.tak2 75.8%
Tak.tak1      24.2%</pre>
</div></div>
<div class="paragraph"><p>This example shows how <span class="monospaced">mlprof</span> indicates lexical nesting: as a
sequence of period-separated names indicating the structures and
functions in which a function definition is nested.  The profiling
data shows that roughly three-quarters of the time is spent in the
<span class="monospaced">Tak.tak1.tak2</span> function, while the rest is spent in <span class="monospaced">Tak.tak1</span>.</p></div>
<div class="paragraph"><p>Display raw counts in addition to percentages with <span class="monospaced">-raw true</span>.</p></div>
<div class="listingblock">
<div class="content monospaced">
<pre>% mlprof -raw true tak mlmon.out
6.00 seconds of CPU time (0.00 seconds GC)
  function     cur    raw
------------- ----- -------
Tak.tak1.tak2 75.8% (4.55s)
Tak.tak1      24.2% (1.45s)</pre>
</div></div>
<div class="paragraph"><p>Display the file name and line number for each function in addition to
its name with <span class="monospaced">-show-line true</span>.</p></div>
<div class="listingblock">
<div class="content monospaced">
<pre>% mlprof -show-line true tak mlmon.out
6.00 seconds of CPU time (0.00 seconds GC)
        function           cur
------------------------- -----
Tak.tak1.tak2  tak.sml: 5 75.8%
Tak.tak1  tak.sml: 3      24.2%</pre>
</div></div>
<div class="paragraph"><p>Time profiling is designed to have a very small performance impact.
However, in some cases there will be a run-time performance cost,
which may perturb the results.  There is more likely to be an impact
with <span class="monospaced">-codegen c</span> than <span class="monospaced">-codegen native</span>.</p></div>
<div class="paragraph"><p>You can also compile with <span class="monospaced">-profile time -profile-branch true</span> to find
out how much time is spent in each branch of a function; see
<a href="ProfilingCounts">ProfilingCounts</a> for more details on <span class="monospaced">-profile-branch</span>.</p></div>
</div>
</div>
<div class="sect1">
<h2 id="_caveats">Caveats</h2>
<div class="sectionbody">
<div class="paragraph"><p>With <span class="monospaced">-profile time</span>, use of the following in your program will cause
a run-time error, since they would interfere with the profiler signal
handler.</p></div>
<div class="ulist"><ul>
<li>
<p>
<span class="monospaced">MLton.Itimer.set (MLton.Itimer.Prof, ...)</span>
</p>
</li>
<li>
<p>
<span class="monospaced">MLton.Signal.setHandler (MLton.Signal.prof, ...)</span>
</p>
</li>
</ul></div>
<div class="paragraph"><p>Also, because of the random sampling used to implement <span class="monospaced">-profile
time</span>, it is best to have a long running program (at least tens of
seconds) in order to get reasonable time</p></div>
</div>
</div>
</div>
<div id="footnotes"><hr></div>
<div id="footer">
<div id="footer-text">
</div>
<div id="footer-badges">
</div>
</div>
</body>
</html>