<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN" "http://www.w3.org/TR/html4/strict.dtd">
<html>
<head>
<meta name="robots" content="index,nofollow">



<title>ProfilingTime - MLton Standard ML Compiler (SML Compiler)</title>
<link rel="stylesheet" type="text/css" charset="iso-8859-1" media="all" href="common.css">
<link rel="stylesheet" type="text/css" charset="iso-8859-1" media="screen" href="screen.css">
<link rel="stylesheet" type="text/css" charset="iso-8859-1" media="print" href="print.css">


<link rel="Start" href="Home">


</head>

<body lang="en" dir="ltr">

<table bgcolor = lightblue cellspacing = 0 style = "border: 0px;" width = 100%>
  <tr>
    <td style = "
		border: 0px;
		color: darkblue; 
		font-size: 150%;
		text-align: left;">
      <a class = mltona href="Home">MLton 20051202</a>
    <td style = "
		border: 0px;
		font-size: 150%;
		text-align: center;
		width: 50%;">
      ProfilingTime
    <td style = "
		border: 0px;
		text-align: right;">
      <table cellspacing = 0 style = "border: 0px">
        <tr style = "vertical-align: middle;">
      </table>
  <tr style = "background-color: white;">
    <td colspan = 3
	style = "
		border: 0px;
		font-size:70%;
		text-align: right;">
      <a href = "Home">Home</a>
      &nbsp;<a href = "Index">Index</a>
      &nbsp;
</table>
<div id="content" lang="en" dir="ltr">
With MLton and <tt>mlprof</tt>, 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  <tt>-profile&nbsp;time</tt>.  For example, suppose that <tt>tak.sml</tt> contains the following. <p>
<pre class=code><B><FONT COLOR="#0000FF">structure</FONT></B> Tak =
   <B><FONT COLOR="#0000FF">struct</FONT></B>
      <B><FONT COLOR="#A020F0">fun</FONT></B> tak1 (x, y, z) =
         <B><FONT COLOR="#A020F0">let</FONT></B>
            <B><FONT COLOR="#A020F0">fun</FONT></B> tak2 (x, y, z) =
               <B><FONT COLOR="#A020F0">if</FONT></B> y &gt;= x
                  <B><FONT COLOR="#A020F0">then</FONT></B> z
               <B><FONT COLOR="#A020F0">else</FONT></B>
                  tak1 (tak2 (x - <B><FONT COLOR="#5F9EA0">1</FONT></B>, y, z),
                        tak2 (y - <B><FONT COLOR="#5F9EA0">1</FONT></B>, z, x),
                        tak2 (z - <B><FONT COLOR="#5F9EA0">1</FONT></B>, x, y))
         <B><FONT COLOR="#A020F0">in</FONT></B>
            <B><FONT COLOR="#A020F0">if</FONT></B> y &gt;= x
               <B><FONT COLOR="#A020F0">then</FONT></B> z
            <B><FONT COLOR="#A020F0">else</FONT></B>
               tak1 (tak2 (x - <B><FONT COLOR="#5F9EA0">1</FONT></B>, y, z),
                     tak2 (y - <B><FONT COLOR="#5F9EA0">1</FONT></B>, z, x),
                     tak2 (z - <B><FONT COLOR="#5F9EA0">1</FONT></B>, x, y))
         <B><FONT COLOR="#A020F0">end</FONT></B>
   <B><FONT COLOR="#0000FF">end</FONT></B>

<B><FONT COLOR="#A020F0">val</FONT></B> <B><FONT COLOR="#A020F0">rec</FONT></B> f =
   <B><FONT COLOR="#A020F0">fn</FONT></B> <B><FONT COLOR="#5F9EA0">0</FONT></B> =&gt; ()
    | ~<B><FONT COLOR="#5F9EA0">1</FONT></B> =&gt; print <FONT COLOR="#BC8F8F"><B>&quot;this branch is not taken\n&quot;</FONT></B>
    | n =&gt; (Tak.tak1 (<B><FONT COLOR="#5F9EA0">18</FONT></B>, <B><FONT COLOR="#5F9EA0">12</FONT></B>, <B><FONT COLOR="#5F9EA0">6</FONT></B>) ; f (n-<B><FONT COLOR="#5F9EA0">1</FONT></B>))

<B><FONT COLOR="#A020F0">val</FONT></B> _ = f <B><FONT COLOR="#5F9EA0">5000</FONT></B>

<B><FONT COLOR="#A020F0">fun</FONT></B> uncalled () = ()
</PRE>
 
</p>
<p>
Compile with time profiling and run the program. 
<pre>% mlton -profile time tak.sml
% ./tak
</pre>
</p>
<p>
Display the profiling data. 
</p>

<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><p>
This example shows how <tt>mlprof</tt> 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 <tt>Tak.tak1.tak2</tt> function, while the rest is spent in <tt>Tak.tak1</tt>. 
</p>
<p>
Display raw counts in addition to percentages with <tt>-raw&nbsp;true</tt>. 
<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>
</p>
<p>
Display the file name and line number for each function in addition to its name with <tt>-show-line&nbsp;true</tt>. 
<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>
</p>
<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 <tt>-codegen&nbsp;c</tt> than <tt>-codegen&nbsp;native</tt>. 
</p>
<p>
You can also compile with <tt>-profile&nbsp;time&nbsp;-profile-branch&nbsp;true</tt> to find out how much time is spent in each branch of a function; see <a href="ProfilingCounts">ProfilingCounts</a> for more details on <tt>-profile-branch</tt>. 
</p>
<h2 id="head-bcaa33a7ae44bd5042c37a9cdbea7f843b1cf7c8">Caveats</h2>
<p>
With <tt>-profile&nbsp;time</tt>, use of the following in your program will cause a run-time error, since they would interfere with the profiler signal handler. 
</p>

    <ul>

    <li>
<p>
 <tt>MLton.Itimer.set&nbsp;(MLton.Itimer.Prof,&nbsp;...)</tt> 
</p>
</li>
    <li>
<p>
 <tt>MLton.Signal.setHandler&nbsp;(MLton.Signal.prof,&nbsp;...)</tt> 
</p>
</li>

    </ul>


<p>
Also, because of the random sampling used to implement  <tt>-profile&nbsp;time</tt>, it is best to have a long running program (at least tens of seconds) in order to get reasonable time  
</p>
</div>



<p>
<hr>
Last edited on 2005-12-02 00:51:55 by <span title="ppp-71-139-183-221.dsl.snfc21.pacbell.net"><a href="StephenWeeks">StephenWeeks</a></span>.
</body></html>
