[cfe-dev] Accuracy of -ftime-report

[Daniel Dunbar]

On Thu, Aug 5, 2010 at 7:36 AM, Argyrios Kyrtzidis <kyrtzidis at apple.com> wrote:
> On 5 Aug 2010, at 15:19, Daniel Dunbar wrote:
>
>> On Thu, Aug 5, 2010 at 6:43 AM, Argyrios Kyrtzidis <kyrtzidis at apple.com> wrote:
>>> On 5 Aug 2010, at 14:37, Amaury Pouly wrote:
>>>
>>> That can be due to lots of things. Just consider this difference:
>>> - Wall time: preception of time form the user. That is, if you run your
>>> program at time T and it ends at time T+D, then the wall time is D normally
>>> - Processor time: time allocated on the processor, which can even be greater
>>> than the wall time if the program uses several processors (if you have two
>>> processors, you can in theory use 2*D processor time for a wall time of D).
>>>
>>> I don't know how the times are computed but it could be related to these
>>> points. And perhaps the time needed to do all the initialisation and loading
>>> of the executable is counted somewhere.
>>>
>>> Yes but the difference between the 'time' utility and the internal timers is
>>> not constant, with '-fsyntax-only' the internal timers report lower numbers
>>> but with '-emit-llvm-bc' they report higher ones.
>>> In general is 'time' utility the more reliable one ?
>>
>> The individual timers are just as reliable as 'time', for tracking
>> user time, but you have to know what they mean (i.e., exactly what
>> they are counting).
>>
>> What is happening here is that some of the timers overlap, I suspect.
>> The Clang frontend timer probably is ending up including the LLVM IR
>> generation timer.
>
> How do you suggest timing the phases ? If the timers overlap, the percentages are not reliable, right ?

Does that matter? The absolute values are still comparable. Presumably
you are wanting to check before-and-after numbers?

That said, I personally almost always use something like 'time' for my
measurements, once I have a test case that demonstrates the
performance of the component I am change.

 - Daniel

> Use 'time' on separate executions (time -fsyntax-only, time -emit-llvm, etc) ?
>
> -Argiris
>
>>
>> - Daniel
>>
>>> -Argiris
>>>
>>> Amaury Pouly
>>>
>>>
>>> 2010/8/5 Argyrios Kyrtzidis <kyrtzidis at apple.com>
>>>>
>>>> Hi,
>>>> When I try '-ftime-report' the numbers differ from 'time', either higher
>>>> or lower, e.g:
>>>>> time clang -cc1 lib/VMCore/Dominators.cpp -Iinclude -Ilib/VMCore
>>>>> -D_DEBUG -D_GNU_SOURCE -D__STDC_LIMIT_MACROS -D__STDC_CONSTANT_MACROS
>>>>> -ftime-report -emit-llvm-bc -o t.o
>>>> [LLVM pass timers]
>>>>
>>>> ===-------------------------------------------------------------------------===
>>>>                          Miscellaneous Ungrouped Timers
>>>>
>>>> ===-------------------------------------------------------------------------===
>>>>    ---User Time---   --System Time--   --User+System--   ---Wall Time---
>>>>  --- Name ---
>>>>    0.8070 ( 87.2%)   0.0550 ( 73.7%)   0.8620 ( 86.2%)   0.8620 ( 86.2%)
>>>>  Clang front-end timer
>>>>    0.0747 (  8.1%)   0.0090 ( 12.0%)   0.0837 (  8.4%)   0.0840 (  8.4%)
>>>>  LLVM IR Generation Time
>>>>    0.0435 (  4.7%)   0.0106 ( 14.3%)   0.0541 (  5.4%)   0.0541 (  5.4%)
>>>>  Code Generation Time
>>>>    0.9251 (100.0%)   0.0746 (100.0%)   0.9998 (100.0%)   1.0001 (100.0%)
>>>>  Total
>>>>
>>>> real 0m0.903s
>>>> user 0m0.827s
>>>> sys 0m0.074s
>>>>
>>>>
>>>>> time clang -cc1 lib/VMCore/Dominators.cpp -Iinclude -Ilib/VMCore
>>>>> -D_DEBUG -D_GNU_SOURCE -D__STDC_LIMIT_MACROS -D__STDC_CONSTANT_MACROS
>>>>> -ftime-report -fsyntax-only
>>>>
>>>> ===-------------------------------------------------------------------------===
>>>>                          Miscellaneous Ungrouped Timers
>>>>
>>>> ===-------------------------------------------------------------------------===
>>>>    ---User Time---   --System Time--   --User+System--   ---Wall Time---
>>>>  --- Name ---
>>>>    0.6823 (100.0%)   0.0317 (100.0%)   0.7139 (100.0%)   0.7139 (100.0%)
>>>>  Clang front-end timer
>>>>    0.6823 (100.0%)   0.0317 (100.0%)   0.7139 (100.0%)   0.7139 (100.0%)
>>>>  Total
>>>>
>>>> real 0m0.736s
>>>> user 0m0.690s
>>>> sys 0m0.043s
>>>>
>>>>
>>>> Why the difference, am I doing something wrong ?
>>>> -Argiris
>>>> _______________________________________________
>>>> cfe-dev mailing list
>>>> cfe-dev at cs.uiuc.edu
>>>> http://lists.cs.uiuc.edu/mailman/listinfo/cfe-dev
>>>>
>>>
>>>
>>>
>>> _______________________________________________
>>> cfe-dev mailing list
>>> cfe-dev at cs.uiuc.edu
>>> http://lists.cs.uiuc.edu/mailman/listinfo/cfe-dev
>>>
>>>
>
>