Q185295: INFO: Results of Function Timing from Microsoft Source Profiler
Article: Q185295
Product(s): Microsoft Programming Utilities
Version(s): winnt:2.0,2.1,2.2,4.0,4.1,4.2,5.0,6.0
Operating System(s):
Keyword(s): kbVC200 kbVC210 kbVC220 kbVC400 kbVC410 kbVC420 kbVC500 kbVC600
Last Modified: 29-AUG-2001
-------------------------------------------------------------------------------
The information in this article applies to:
- The Source Profiler, included with:
- Microsoft Visual C++, 32-bit Editions, versions 2.0, 2.1, 2.2, 4.0, 4.1
- Microsoft Visual C++, 32-bit Enterprise Edition, version 4.2
- Microsoft Visual C++, 32-bit Professional Edition, version 4.2
- Microsoft Visual C++, 32-bit Enterprise Edition, version 5.0
- Microsoft Visual C++, 32-bit Professional Edition, version 5.0
- Microsoft Visual C++, 32-bit Enterprise Edition, version 6.0
- Microsoft Visual C++, 32-bit Professional Edition, version 6.0
- Microsoft Visual C++, 32-bit Learning Edition, version 6.0
-------------------------------------------------------------------------------
SUMMARY
=======
This article describes the output generated from the Microsoft Source Profiler
and specifically focuses on the use of function timing. The sample output comes
from a default MFC AppWizard-based application called ProfTest. Although it is
not a complete listing of the output from this profile, it is sufficient to
demonstrate the output results. A description of each entry presented in the
"Sample Output" section follows in the "Output Description" section of this
article.
MORE INFORMATION
================
Sample Output
-------------
Profile: Function timing, sorted by time
Date: Wed Nov 05 23:37:00 1997
Program Statistics
------------------
Command line at 1997 Nov 05 23:35: "C:\code\ProfTest\Debug\ProfTest"
Total time: 88816.409 millisecond
Time outside of functions: 86.090 millisecond
Call depth: 21
Total functions: 317
Total hits: 23933
Function coverage: 58.0%
Overhead calculated 8
Overhead average 8
Module Statistics for proftest.exe
----------------------------------
Time in module: 88730.319 millisecond
Percent of time in module: 100.0%
Functions in module: 317
Hits in module: 23933
Module function coverage: 58.0%
Func Func+Child Hit
Time % Time % Count Function
---------------------------------------------------------
86571.608 97.6 87316.863 98.4 70 CWinThread::PumpMessage(void)
(mfc42d.dll)
246.177 0.3 367.692 0.4 184 CMDIFrameWnd::DefWindowProcA
(unsigned int,unsigned
int,long) (mfc42d.dll)
188.947 0.2 188.947 0.2 751 CView::AssertValid(void)
(mfc42d.dll)
171.866 0.2 172.011 0.2 1 CToolBar::Create(class CWnd
*,unsigned long,unsigned int)
(mfc42d.dll)
144.324 0.2 940.322 1.1 517 CWnd::OnWndMsg(unsigned
int,unsigned int,long,long *)
(mfc42d.dll)
94.550 0.1 314.706 0.4 69 CWinThread::
PreTranslateMessage(struct
tagMSG *) (mfc42d.dll)
50.008 0.1 88727.904 100.0 1 AfxWinMain(struct HINSTANCE__
*,struct HINSTANCE__ *,char
*,int) (mfc42d.dll)
Output Description
------------------
Program Statistics:
Command line -
Time and date the application ran, and the complete command line issued by
the profiler.
Total time -
Total application execution time. The time listed in milliseconds might not
be completely accurate. Use the times as a relative measure.
Time outside of functions -
Time spent outside of any profiled functions. If a top level profiled
function is called, no time is added to this value until that function
returns.
Call depth -
The deepest level of functions called. For example, if function A calls
function B which calls function C, the call depth is 3.
Total functions -
The number of functions listed in the output.
Total hits -
How many times the functions listed were executed.
Function coverage -
The percentage of time spent in the listed functions.
Overhead calculated -
A relative value that represents profiler overhead. This is not a measure of
time, but a larger value indicates more time spent in overhead.
Overhead average -
The average overhead required for all profiles. This should be the same as
the overhead calculated, unless you are merging multiple profiles.
Module Statistics:
These statistics are similar to the Program Statistics. They are useful when
profiling multiple modules, such as an executable and dynamic link library.
Function Time:
In the Function Timing section of the Visual C++ online documentation, there is
one error. The function time is in milliseconds, not seconds as it is stated in
the documentation. The following excerpt is reprinted from the documentation
with the correct measure for function time (milliseconds):
The Func Time column reports how much time it took for the function to run in
milliseconds. The next column shows what percent of the total profile time is
represented by the function time. Func+Child Time refers to the total time
profiled for the function as well as any functions called by that function.
The next column shows what percent of the total profile time is represented
by the Func+Child time. The Hit Count column reports the number of times that
the function was called. The Function column displays the decorated name of
the function.
If a called function contains profiler information, then the Func+Child Time is
greater than the Func Time.
REFERENCES
==========
Visual C++ online documentation: search on "Function Timing"
Additional query words: Prep Profile Plist Ftime
======================================================================
Keywords : kbVC200 kbVC210 kbVC220 kbVC400 kbVC410 kbVC420 kbVC500 kbVC600
Technology : kbVCsearch kbAudDeveloper kbSProfilerSearch kbVC32bitSearch kbSProfiler100
Version : winnt:2.0,2.1,2.2,4.0,4.1,4.2,5.0,6.0
Issue type : kbinfo
=============================================================================
THE INFORMATION PROVIDED IN THE MICROSOFT KNOWLEDGE BASE IS PROVIDED "AS IS" WITHOUT WARRANTY OF ANY KIND. MICROSOFT DISCLAIMS ALL WARRANTIES, EITHER EXPRESS OR IMPLIED, INCLUDING THE WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE. IN NO EVENT SHALL MICROSOFT CORPORATION OR ITS SUPPLIERS BE LIABLE FOR ANY DAMAGES WHATSOEVER INCLUDING DIRECT, INDIRECT, INCIDENTAL, CONSEQUENTIAL, LOSS OF BUSINESS PROFITS OR SPECIAL DAMAGES, EVEN IF MICROSOFT CORPORATION OR ITS SUPPLIERS HAVE BEEN ADVISED OF THE POSSIBILITY OF SUCH DAMAGES. SOME STATES DO NOT ALLOW THE EXCLUSION OR LIMITATION OF LIABILITY FOR CONSEQUENTIAL OR INCIDENTAL DAMAGES SO THE FOREGOING LIMITATION MAY NOT APPLY.
Copyright Microsoft Corporation 1986-2002.