About profiling code

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
11 messages Options
Reply | Threaded
Open this post in threaded view
|

About profiling code

kilon.alios
Why

[CheckboxMorph new] timeProfile

returns nothing ?

I also tried it in the profile tool without the block and still displays nothing . Is there any special requirement for profiling code ?
Reply | Threaded
Open this post in threaded view
|

Re: About profiling code

Nicolai Hess-3-2


2015-11-22 20:01 GMT+01:00 Dimitris Chloupis <[hidden email]>:
Why

[CheckboxMorph new] timeProfile

returns nothing ?

too fast?
[ 3+3 ] timeProfile
return nothing too.

try
[CheckboxMorph new openInWorld] timeProfile.
 

I also tried it in the profile tool without the block and still displays nothing . Is there any special requirement for profiling code ?

Reply | Threaded
Open this post in threaded view
|

Re: About profiling code

kilon.alios
yeah probably , your code returns nothing too. So what we suppose to use to profile fast code ?

On Sun, Nov 22, 2015 at 9:12 PM Nicolai Hess <[hidden email]> wrote:
2015-11-22 20:01 GMT+01:00 Dimitris Chloupis <[hidden email]>:
Why

[CheckboxMorph new] timeProfile

returns nothing ?

too fast?
[ 3+3 ] timeProfile
return nothing too.

try
[CheckboxMorph new openInWorld] timeProfile.
 

I also tried it in the profile tool without the block and still displays nothing . Is there any special requirement for profiling code ?
Reply | Threaded
Open this post in threaded view
|

Re: About profiling code

Guillermo Polito

Out of the top of my head, doing it like that only profiles widget creation/install if I'm not mistaken. But not render time.

Because the doit is executed inside the event processing of the morphic render loop. But a cool ui profiling should also measure the drawOn: methods.

I don't know if there is a tool to do that right know but it would be possible...

Le 22 nov. 2015 20:23, "Dimitris Chloupis" <[hidden email]> a écrit :
yeah probably , your code returns nothing too. So what we suppose to use to profile fast code ?

On Sun, Nov 22, 2015 at 9:12 PM Nicolai Hess <[hidden email]> wrote:
2015-11-22 20:01 GMT+01:00 Dimitris Chloupis <[hidden email]>:
Why

[CheckboxMorph new] timeProfile

returns nothing ?

too fast?
[ 3+3 ] timeProfile
return nothing too.

try
[CheckboxMorph new openInWorld] timeProfile.
 

I also tried it in the profile tool without the block and still displays nothing . Is there any special requirement for profiling code ?
Reply | Threaded
Open this post in threaded view
|

Re: About profiling code

Thierry Goubier
Le 22/11/2015 20:42, Guillermo Polito a écrit :
> Out of the top of my head, doing it like that only profiles widget
> creation/install if I'm not mistaken. But not render time.
>
> Because the doit is executed inside the event processing of the morphic
> render loop. But a cool ui profiling should also measure the drawOn:
> methods.

> I don't know if there is a tool to do that right know but it would be
> possible...

Inspect the morph and do: [ self fullDrawOn: Display getCanvas ] timeProfile

If it is a FT-based morph, you may have to do a self refresh or self
changed, so that you can measure the recreation of the submorphs.

Normal GUI code has very short rendering time (a few tens of
milliseconds), except when you use large fonts and sub-pixel rendering
(LCD setting on FreeType rendering).

Thierry

> Le 22 nov. 2015 20:23, "Dimitris Chloupis" <[hidden email]
> <mailto:[hidden email]>> a écrit :
>
>     yeah probably , your code returns nothing too. So what we suppose to
>     use to profile fast code ?
>
>     On Sun, Nov 22, 2015 at 9:12 PM Nicolai Hess <[hidden email]
>     <mailto:[hidden email]>> wrote:
>
>         2015-11-22 20:01 GMT+01:00 Dimitris Chloupis
>         <[hidden email] <mailto:[hidden email]>>:
>
>             Why
>
>             [CheckboxMorph new] timeProfile
>
>             returns nothing ?
>
>
>         too fast?
>         [ 3+3 ] timeProfile
>         return nothing too.
>
>         try
>         [CheckboxMorph new openInWorld] timeProfile.
>
>
>             I also tried it in the profile tool without the block and
>             still displays nothing . Is there any special requirement
>             for profiling code ?
>


Reply | Threaded
Open this post in threaded view
|

Re: About profiling code

Stephan Eggermont-3
In reply to this post by Guillermo Polito
On 22-11-15 20:42, Guillermo Polito wrote:
> Out of the top of my head, doing it like that only profiles widget
> creation/install if I'm not mistaken. But not render time.
>
> Because the doit is executed inside the event processing of the morphic
> render loop. But a cool ui profiling should also measure the drawOn:
> methods.
>
> I don't know if there is a tool to do that right know but it would be
> possible...

Thierry explained:
Show halos on a Morph, inspect morph, DoIt
[self fullDrawOn: Display getCanvas] timeProfile
in the inspector.

I've noticed very large differences in where time is
spend (and not just the first time when all default values still need to
be calculated).

Stephan


Reply | Threaded
Open this post in threaded view
|

Re: About profiling code

Henrik Nergaard
To profile the creation and drawing, create a canvas and do a #fullDrawOn: onto it.

Example:
[
        | morph canvas |
       
        morph := FTTableMorph new
                extent: 300@300;
                dataSource: (FTExampleDataSource elements: (Smalltalk allClassesAndTraits
                        sorted: [ :a :b | a name < b name]));
                yourself.
       
        canvas := FormCanvas
                extent: morph fullBounds extent
                depth: Display depth.
       
        morph fullDrawOn: canvas

] timeProfile.

Best regards,
Henrik

-----Original Message-----
From: Pharo-users [mailto:[hidden email]] On Behalf Of Stephan Eggermont
Sent: Sunday, November 22, 2015 9:16 PM
To: [hidden email]
Subject: Re: [Pharo-users] About profiling code

On 22-11-15 20:42, Guillermo Polito wrote:
> Out of the top of my head, doing it like that only profiles widget
> creation/install if I'm not mistaken. But not render time.
>
> Because the doit is executed inside the event processing of the
> morphic render loop. But a cool ui profiling should also measure the drawOn:
> methods.
>
> I don't know if there is a tool to do that right know but it would be
> possible...

Thierry explained:
Show halos on a Morph, inspect morph, DoIt [self fullDrawOn: Display getCanvas] timeProfile in the inspector.

I've noticed very large differences in where time is spend (and not just the first time when all default values still need to be calculated).

Stephan


Reply | Threaded
Open this post in threaded view
|

Re: About profiling code

abergel
In reply to this post by kilon.alios
Hi!

Why do you need to profile fast code? You can always put your code in a loop.

Alexandre


> On Nov 22, 2015, at 4:22 PM, Dimitris Chloupis <[hidden email]> wrote:
>
> yeah probably , your code returns nothing too. So what we suppose to use to profile fast code ?
>
> On Sun, Nov 22, 2015 at 9:12 PM Nicolai Hess <[hidden email]> wrote:
> 2015-11-22 20:01 GMT+01:00 Dimitris Chloupis <[hidden email]>:
> Why
>
> [CheckboxMorph new] timeProfile
>
> returns nothing ?
>
> too fast?
> [ 3+3 ] timeProfile
> return nothing too.
>
> try
> [CheckboxMorph new openInWorld] timeProfile.
>  
>
> I also tried it in the profile tool without the block and still displays nothing . Is there any special requirement for profiling code ?

--
_,.;:~^~:;._,.;:~^~:;._,.;:~^~:;._,.;:~^~:;._,.;:
Alexandre Bergel  http://www.bergel.eu
^~:;._,.;:~^~:;._,.;:~^~:;._,.;:~^~:;._,.;:~^~:;.




Reply | Threaded
Open this post in threaded view
|

Re: About profiling code

EuanM
Because profiling longer loops takes longer.

Why profile a 32768-cycle loop if a 2048-cycle loop would work?

On 22 November 2015 at 20:21, Alexandre Bergel <[hidden email]> wrote:

> Hi!
>
> Why do you need to profile fast code? You can always put your code in a loop.
>
> Alexandre
>
>
>> On Nov 22, 2015, at 4:22 PM, Dimitris Chloupis <[hidden email]> wrote:
>>
>> yeah probably , your code returns nothing too. So what we suppose to use to profile fast code ?
>>
>> On Sun, Nov 22, 2015 at 9:12 PM Nicolai Hess <[hidden email]> wrote:
>> 2015-11-22 20:01 GMT+01:00 Dimitris Chloupis <[hidden email]>:
>> Why
>>
>> [CheckboxMorph new] timeProfile
>>
>> returns nothing ?
>>
>> too fast?
>> [ 3+3 ] timeProfile
>> return nothing too.
>>
>> try
>> [CheckboxMorph new openInWorld] timeProfile.
>>
>>
>> I also tried it in the profile tool without the block and still displays nothing . Is there any special requirement for profiling code ?
>
> --
> _,.;:~^~:;._,.;:~^~:;._,.;:~^~:;._,.;:~^~:;._,.;:
> Alexandre Bergel  http://www.bergel.eu
> ^~:;._,.;:~^~:;._,.;:~^~:;._,.;:~^~:;._,.;:~^~:;.
>
>
>
>

Reply | Threaded
Open this post in threaded view
|

Re: About profiling code

EuanM
I was profiling yesterday, and discovered these issues:

Issue:
=====
Time and DateAndTime both show human-readable time information to
micro-second precision.  Time also holds information to nano-second
precision.

Both objects are only providing information to the nearest millisecond.

The digits beyond milliseconds are always (on my PC) filled in as '902'.

In the nanoseconds instvar of the Time objects, the nanoseconds are
always filled in as '000'.


Root cause:
=========
When Times (and DateAndTimes) are created, they use the
Time>>primUTCMicrosecondsClock method to generate the time

primUTCMicrosecondsClock
"Answer the number of micro-seconds ellapsed since Squeak epoch.
That is since 00:00 on the morning of January 1, 1901 UTC.
At least a 60-bit unsigned integer is used internally which is enough
for dates up to year 38435.
Essential. See Object documentation whatIsAPrimitive. "

<primitive: 240>
self primitiveFailed

Potential for solution:
================
[The following is taken from Stack Overflow,
http://stackoverflow.com/questions/2607263/how-precise-is-the-internal-clock-of-a-modern-pc]
Modern PCs have a hardware  High Precision Event Timer (HPET) which
specifies a clock speed of 10MHz
http://www.intel.com/hardwaredesign/hpetspec_1.pdf
Even newer PC architectures take this and put it on the Northbridge
controller and the HPET can tun at 100MHz or even greater. At 10Mhz we
should be able to get a resolution of 100 nano-seconds and at 100MHZ
we should be able to get 10 nano-second resolution.

The following operating systems are known not to be able to use HPET:
Windows XP, Windows Server 2003, and earlier Windows versions, older
Linux versions
The following operating systems are known to be able to use HPET:
Windows Vista, Windows 2008, Windows 7, x86 based versions of Mac OS
X, Linux operating systems using the 2.6 kernel and FreeBSD.

Final Question:
===========
Is this something we should pass on to the VM teams?

On 22 November 2015 at 20:23, EuanM <[hidden email]> wrote:

> Because profiling longer loops takes longer.
>
> Why profile a 32768-cycle loop if a 2048-cycle loop would work?
>
> On 22 November 2015 at 20:21, Alexandre Bergel <[hidden email]> wrote:
>> Hi!
>>
>> Why do you need to profile fast code? You can always put your code in a loop.
>>
>> Alexandre
>>
>>
>>> On Nov 22, 2015, at 4:22 PM, Dimitris Chloupis <[hidden email]> wrote:
>>>
>>> yeah probably , your code returns nothing too. So what we suppose to use to profile fast code ?
>>>
>>> On Sun, Nov 22, 2015 at 9:12 PM Nicolai Hess <[hidden email]> wrote:
>>> 2015-11-22 20:01 GMT+01:00 Dimitris Chloupis <[hidden email]>:
>>> Why
>>>
>>> [CheckboxMorph new] timeProfile
>>>
>>> returns nothing ?
>>>
>>> too fast?
>>> [ 3+3 ] timeProfile
>>> return nothing too.
>>>
>>> try
>>> [CheckboxMorph new openInWorld] timeProfile.
>>>
>>>
>>> I also tried it in the profile tool without the block and still displays nothing . Is there any special requirement for profiling code ?
>>
>> --
>> _,.;:~^~:;._,.;:~^~:;._,.;:~^~:;._,.;:~^~:;._,.;:
>> Alexandre Bergel  http://www.bergel.eu
>> ^~:;._,.;:~^~:;._,.;:~^~:;._,.;:~^~:;._,.;:~^~:;.
>>
>>
>>
>>

Reply | Threaded
Open this post in threaded view
|

Re: About profiling code

kilon.alios
thanks stephan , thierry and henrik I will use your code.

Alexander I would prefer to profile slow code, but sometimes profiling even fast code gives more info about the internals of the system and what is fast and what is slow and why.

On Sun, Nov 22, 2015 at 10:39 PM EuanM <[hidden email]> wrote:
I was profiling yesterday, and discovered these issues:

Issue:
=====
Time and DateAndTime both show human-readable time information to
micro-second precision.  Time also holds information to nano-second
precision.

Both objects are only providing information to the nearest millisecond.

The digits beyond milliseconds are always (on my PC) filled in as '902'.

In the nanoseconds instvar of the Time objects, the nanoseconds are
always filled in as '000'.


Root cause:
=========
When Times (and DateAndTimes) are created, they use the
Time>>primUTCMicrosecondsClock method to generate the time

primUTCMicrosecondsClock
"Answer the number of micro-seconds ellapsed since Squeak epoch.
That is since 00:00 on the morning of January 1, 1901 UTC.
At least a 60-bit unsigned integer is used internally which is enough
for dates up to year 38435.
Essential. See Object documentation whatIsAPrimitive. "

<primitive: 240>
self primitiveFailed

Potential for solution:
================
[The following is taken from Stack Overflow,
http://stackoverflow.com/questions/2607263/how-precise-is-the-internal-clock-of-a-modern-pc]
Modern PCs have a hardware  High Precision Event Timer (HPET) which
specifies a clock speed of 10MHz
http://www.intel.com/hardwaredesign/hpetspec_1.pdf
Even newer PC architectures take this and put it on the Northbridge
controller and the HPET can tun at 100MHz or even greater. At 10Mhz we
should be able to get a resolution of 100 nano-seconds and at 100MHZ
we should be able to get 10 nano-second resolution.

The following operating systems are known not to be able to use HPET:
Windows XP, Windows Server 2003, and earlier Windows versions, older
Linux versions
The following operating systems are known to be able to use HPET:
Windows Vista, Windows 2008, Windows 7, x86 based versions of Mac OS
X, Linux operating systems using the 2.6 kernel and FreeBSD.

Final Question:
===========
Is this something we should pass on to the VM teams?

On 22 November 2015 at 20:23, EuanM <[hidden email]> wrote:
> Because profiling longer loops takes longer.
>
> Why profile a 32768-cycle loop if a 2048-cycle loop would work?
>
> On 22 November 2015 at 20:21, Alexandre Bergel <[hidden email]> wrote:
>> Hi!
>>
>> Why do you need to profile fast code? You can always put your code in a loop.
>>
>> Alexandre
>>
>>
>>> On Nov 22, 2015, at 4:22 PM, Dimitris Chloupis <[hidden email]> wrote:
>>>
>>> yeah probably , your code returns nothing too. So what we suppose to use to profile fast code ?
>>>
>>> On Sun, Nov 22, 2015 at 9:12 PM Nicolai Hess <[hidden email]> wrote:
>>> 2015-11-22 20:01 GMT+01:00 Dimitris Chloupis <[hidden email]>:
>>> Why
>>>
>>> [CheckboxMorph new] timeProfile
>>>
>>> returns nothing ?
>>>
>>> too fast?
>>> [ 3+3 ] timeProfile
>>> return nothing too.
>>>
>>> try
>>> [CheckboxMorph new openInWorld] timeProfile.
>>>
>>>
>>> I also tried it in the profile tool without the block and still displays nothing . Is there any special requirement for profiling code ?
>>
>> --
>> _,.;:~^~:;._,.;:~^~:;._,.;:~^~:;._,.;:~^~:;._,.;:
>> Alexandre Bergel  http://www.bergel.eu
>> ^~:;._,.;:~^~:;._,.;:~^~:;._,.;:~^~:;._,.;:~^~:;.
>>
>>
>>
>>