Commit | Line | Data |
---|---|---|
7f918cf1 CE |
1 | <!DOCTYPE html>\r |
2 | <html lang="en">\r | |
3 | <head>\r | |
4 | <meta http-equiv="Content-Type" content="text/html; charset=UTF-8">\r | |
5 | <meta name="generator" content="AsciiDoc 8.6.9">\r | |
6 | <title>ProfilingTime</title>\r | |
7 | <link rel="stylesheet" href="./asciidoc.css" type="text/css">\r | |
8 | <link rel="stylesheet" href="./pygments.css" type="text/css">\r | |
9 | \r | |
10 | \r | |
11 | <script type="text/javascript" src="./asciidoc.js"></script>\r | |
12 | <script type="text/javascript">\r | |
13 | /*<![CDATA[*/\r | |
14 | asciidoc.install();\r | |
15 | /*]]>*/\r | |
16 | </script>\r | |
17 | <link rel="stylesheet" href="./mlton.css" type="text/css">\r | |
18 | </head>\r | |
19 | <body class="article">\r | |
20 | <div id="banner">\r | |
21 | <div id="banner-home">\r | |
22 | <a href="./Home">MLton 20180207</a>\r | |
23 | </div>\r | |
24 | </div>\r | |
25 | <div id="header">\r | |
26 | <h1>ProfilingTime</h1>\r | |
27 | </div>\r | |
28 | <div id="content">\r | |
29 | <div id="preamble">\r | |
30 | <div class="sectionbody">\r | |
31 | <div class="paragraph"><p>With MLton and <span class="monospaced">mlprof</span>, you can <a href="Profiling">profile</a> your program to\r | |
32 | find out how much time is spent in each function over an entire run of\r | |
33 | the program. To do so, compile your program with <span class="monospaced">-profile time</span>.\r | |
34 | For example, suppose that <span class="monospaced">tak.sml</span> contains the following.</p></div>\r | |
35 | <div class="listingblock">\r | |
36 | <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>\r | |
37 | <span class="w"> </span><span class="k">struct</span><span class="w"></span>\r | |
38 | <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>\r | |
39 | <span class="w"> </span><span class="k">let</span><span class="w"></span>\r | |
40 | <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>\r | |
41 | <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">>=</span><span class="w"> </span><span class="n">x</span><span class="w"></span>\r | |
42 | <span class="w"> </span><span class="k">then</span><span class="w"> </span><span class="n">z</span><span class="w"></span>\r | |
43 | <span class="w"> </span><span class="k">else</span><span class="w"></span>\r | |
44 | <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>\r | |
45 | <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>\r | |
46 | <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>\r | |
47 | <span class="w"> </span><span class="k">in</span><span class="w"></span>\r | |
48 | <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">>=</span><span class="w"> </span><span class="n">x</span><span class="w"></span>\r | |
49 | <span class="w"> </span><span class="k">then</span><span class="w"> </span><span class="n">z</span><span class="w"></span>\r | |
50 | <span class="w"> </span><span class="k">else</span><span class="w"></span>\r | |
51 | <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>\r | |
52 | <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>\r | |
53 | <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>\r | |
54 | <span class="w"> </span><span class="k">end</span><span class="w"></span>\r | |
55 | <span class="w"> </span><span class="k">end</span><span class="w"></span>\r | |
56 | \r | |
57 | <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>\r | |
58 | <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">=></span><span class="w"> </span><span class="p">()</span><span class="w"></span>\r | |
59 | <span class="w"> </span><span class="p">|</span><span class="w"> </span><span class="mi">~1</span><span class="w"> </span><span class="p">=></span><span class="w"> </span><span class="n">print</span><span class="w"> </span><span class="s">"this branch is not taken</span><span class="se">\n</span><span class="s">"</span><span class="w"></span>\r | |
60 | <span class="w"> </span><span class="p">|</span><span class="w"> </span><span class="n">n</span><span class="w"> </span><span class="p">=></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>\r | |
61 | \r | |
62 | <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>\r | |
63 | \r | |
64 | <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>\r | |
65 | </pre></div></div></div>\r | |
66 | <div class="paragraph"><p>Compile with time profiling and run the program.</p></div>\r | |
67 | <div class="listingblock">\r | |
68 | <div class="content monospaced">\r | |
69 | <pre>% mlton -profile time tak.sml\r | |
70 | % ./tak</pre>\r | |
71 | </div></div>\r | |
72 | <div class="paragraph"><p>Display the profiling data.</p></div>\r | |
73 | <div class="listingblock">\r | |
74 | <div class="content monospaced">\r | |
75 | <pre>% mlprof tak mlmon.out\r | |
76 | 6.00 seconds of CPU time (0.00 seconds GC)\r | |
77 | function cur\r | |
78 | ------------- -----\r | |
79 | Tak.tak1.tak2 75.8%\r | |
80 | Tak.tak1 24.2%</pre>\r | |
81 | </div></div>\r | |
82 | <div class="paragraph"><p>This example shows how <span class="monospaced">mlprof</span> indicates lexical nesting: as a\r | |
83 | sequence of period-separated names indicating the structures and\r | |
84 | functions in which a function definition is nested. The profiling\r | |
85 | data shows that roughly three-quarters of the time is spent in the\r | |
86 | <span class="monospaced">Tak.tak1.tak2</span> function, while the rest is spent in <span class="monospaced">Tak.tak1</span>.</p></div>\r | |
87 | <div class="paragraph"><p>Display raw counts in addition to percentages with <span class="monospaced">-raw true</span>.</p></div>\r | |
88 | <div class="listingblock">\r | |
89 | <div class="content monospaced">\r | |
90 | <pre>% mlprof -raw true tak mlmon.out\r | |
91 | 6.00 seconds of CPU time (0.00 seconds GC)\r | |
92 | function cur raw\r | |
93 | ------------- ----- -------\r | |
94 | Tak.tak1.tak2 75.8% (4.55s)\r | |
95 | Tak.tak1 24.2% (1.45s)</pre>\r | |
96 | </div></div>\r | |
97 | <div class="paragraph"><p>Display the file name and line number for each function in addition to\r | |
98 | its name with <span class="monospaced">-show-line true</span>.</p></div>\r | |
99 | <div class="listingblock">\r | |
100 | <div class="content monospaced">\r | |
101 | <pre>% mlprof -show-line true tak mlmon.out\r | |
102 | 6.00 seconds of CPU time (0.00 seconds GC)\r | |
103 | function cur\r | |
104 | ------------------------- -----\r | |
105 | Tak.tak1.tak2 tak.sml: 5 75.8%\r | |
106 | Tak.tak1 tak.sml: 3 24.2%</pre>\r | |
107 | </div></div>\r | |
108 | <div class="paragraph"><p>Time profiling is designed to have a very small performance impact.\r | |
109 | However, in some cases there will be a run-time performance cost,\r | |
110 | which may perturb the results. There is more likely to be an impact\r | |
111 | with <span class="monospaced">-codegen c</span> than <span class="monospaced">-codegen native</span>.</p></div>\r | |
112 | <div class="paragraph"><p>You can also compile with <span class="monospaced">-profile time -profile-branch true</span> to find\r | |
113 | out how much time is spent in each branch of a function; see\r | |
114 | <a href="ProfilingCounts">ProfilingCounts</a> for more details on <span class="monospaced">-profile-branch</span>.</p></div>\r | |
115 | </div>\r | |
116 | </div>\r | |
117 | <div class="sect1">\r | |
118 | <h2 id="_caveats">Caveats</h2>\r | |
119 | <div class="sectionbody">\r | |
120 | <div class="paragraph"><p>With <span class="monospaced">-profile time</span>, use of the following in your program will cause\r | |
121 | a run-time error, since they would interfere with the profiler signal\r | |
122 | handler.</p></div>\r | |
123 | <div class="ulist"><ul>\r | |
124 | <li>\r | |
125 | <p>\r | |
126 | <span class="monospaced">MLton.Itimer.set (MLton.Itimer.Prof, ...)</span>\r | |
127 | </p>\r | |
128 | </li>\r | |
129 | <li>\r | |
130 | <p>\r | |
131 | <span class="monospaced">MLton.Signal.setHandler (MLton.Signal.prof, ...)</span>\r | |
132 | </p>\r | |
133 | </li>\r | |
134 | </ul></div>\r | |
135 | <div class="paragraph"><p>Also, because of the random sampling used to implement <span class="monospaced">-profile\r | |
136 | time</span>, it is best to have a long running program (at least tens of\r | |
137 | seconds) in order to get reasonable time</p></div>\r | |
138 | </div>\r | |
139 | </div>\r | |
140 | </div>\r | |
141 | <div id="footnotes"><hr></div>\r | |
142 | <div id="footer">\r | |
143 | <div id="footer-text">\r | |
144 | </div>\r | |
145 | <div id="footer-badges">\r | |
146 | </div>\r | |
147 | </div>\r | |
148 | </body>\r | |
149 | </html>\r |