yes, with 0 it works.
But, in some cases, we would like to have all branches.
So, I will do the method spyOn:cutoff:, and keep the 1% threshold for
spyOn:.
Cheers,
Jannik
On Oct 25, 2009, at 20:54 , Adrian Lienhard wrote:
> Have you tried with 0? I guess you get way too much in the tree
> (especially when you trace a larger part of your application and not
> only adding elements to a dictionary). It seems that 1% is a sensible
> default as usually it does not make sense to look into these branches
> more closely as you cannot optimize them much.
>
> Adrian
>
> On Oct 25, 2009, at 19:42 , Laval Jannik wrote:
>
>> Hi Adrian,
>>
>> Now I understand the "problem".
>> So we can use "report:cutoff:" which allows us to give a specific
>> value for the threshold.
>>
>> I will create a new method, spyOn:cutoff:.
>>
>> I think the method "spyOn:" must have the threshold equals to 0.
>> No ?
>>
>> Cheers,
>> Jannik
>>
>>
>> On Oct 24, 2009, at 12:08 , Adrian Lienhard wrote:
>>
>>> Hi Jannik,
>>>
>>> Interesting question!
>>>
>>> You left out an important part oft the tally: the part about GC
>>> activity.
>>>
>>> For the large dictionary I get:
>>>
>>> **GCs**
>>> full 9 totalling 1,696ms (1.0% uptime), avg 188.0ms
>>> incr 3776 totalling 186,310ms (94.0% uptime), avg 49.0ms
>>>
>>> That is, 95% of time is spent in GC! A lot of incremental GC cycles
>>> are triggered because for each at:put: a new association instance is
>>> created. The larger the dictionary, the larger is the new memory
>>> space
>>> and hence the incremental GC takes longer to complete. In the above
>>> tally the average was 49ms compared to
>>>
>>> incr 275 totalling 1,113ms (58.0% uptime), avg 4.0ms
>>>
>>> for the smaller dictionary. Therefore, the ratio between actual
>>> method
>>> execution time and GC time differs significantly between the two
>>> runs.
>>> As a result, a lot of branches of the tally are below a total of 1%
>>> runtime in the second case. Message tally has a threshold that cuts
>>> off branches with less than 1% runtime. Therefore you see less
>>> details.
>>>
>>> Cheers,
>>> Adrian
>>>
>>>
>>> On Oct 24, 2009, at 07:21 , Laval Jannik wrote:
>>>
>>>> Hi,
>>>>
>>>> when I use MassageTally>>spyOn: on the creation of a Dictionary,
>>>> results have not the same details according to the size of
>>>> Dictionary.
>>>>
>>>> For example:
>>>> ===
>>>> |n|
>>>> MessageTally spyOn:[
>>>> n := Dictionary new.
>>>> 1 to: 400000 do:[:each | n at: each put:each].
>>>> ]
>>>> ===
>>>>
>>>> returns this results:
>>>>
>>>> ====
>>>> - 1745 tallies, 1751 msec.
>>>>
>>>> **Tree**
>>>> --------------------------------
>>>> Process: (40s) 1964: nil
>>>> --------------------------------
>>>> 45.8% {802ms} Dictionary(Set)>>atNewIndex:put:
>>>> |43.6% {763ms} Dictionary(Set)>>fullCheck
>>>> | |39.4% {690ms} Dictionary(Set)>>grow
>>>> | | |27.2% {476ms} Dictionary>>noCheckAdd:
>>>> | | | |25.2% {441ms} Dictionary(Set)>>findElementOrNil:
>>>> | | | | |23.6% {413ms} Dictionary>>scanFor:
>>>> | | | | |1.6% {28ms} primitives
>>>> | | | |2.0% {35ms} primitives
>>>> | | |9.2% {161ms} primitives
>>>> | | |3.0% {53ms} Array(SequenceableCollection)>>do:
>>>> | |2.4% {42ms} primitives
>>>> | |1.8% {32ms} SmallInteger(Magnitude)>>max:
>>>> |2.2% {39ms} primitives
>>>> 22.4% {392ms} Association class>>key:value:
>>>> |18.9% {331ms} Association class(LookupKey class)>>key:
>>>> | |16.3% {285ms} Association(LookupKey)>>key:
>>>> | |2.6% {46ms} primitives
>>>> |1.9% {33ms} Association>>value:
>>>> |1.6% {28ms} primitives
>>>> 4.4% {77ms} Dictionary(Set)>>findElementOrNil:
>>>> |2.3% {40ms} primitives
>>>> |2.1% {37ms} Dictionary>>scanFor:
>>>> 1.9% {33ms} primitives
>>>> ====
>>>>
>>>> But, if I do:
>>>> ===
>>>> |n|
>>>> MessageTally spyOn:[
>>>> n := Dictionary new.
>>>> 1 to: 4000000 do:[:each | n at: each put:each].
>>>> ]
>>>> ===
>>>>
>>>> results are:
>>>> ====
>>>> - 179772 tallies, 180312 msec.
>>>>
>>>> **Tree**
>>>> --------------------------------
>>>> Process: (40s) 1964: nil
>>>> --------------------------------
>>>> 3.1% {5590ms} Dictionary(Set)>>atNewIndex:put:
>>>> |2.8% {5049ms} Dictionary(Set)>>fullCheck
>>>> | 2.3% {4147ms} Dictionary(Set)>>grow
>>>> | 1.3% {2344ms} Dictionary>>noCheckAdd:
>>>> 1.0% {1803ms} Association class>>key:value:
>>>> ====
>>>>
>>>> Where are the rest of the process ?
>>>> Does anybody understand this behavior ? can you explain ?
>>>>
>>>>
>>>> Cheers,
>>>> Jannik
>>>>
>>>>
>>>> _______________________________________________
>>>> Pharo-project mailing list
>>>> [email protected]
>>>> http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
>>>
>>>
>>> _______________________________________________
>>> Pharo-project mailing list
>>> [email protected]
>>> http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
>>
>> ---
>> Jannik Laval
>> PhD Student - Rmod Team - INRIA
>> Certified Project Management Associate (IPMA)
>> http://www.jannik-laval.eu
>> http://rmod.lille.inria.fr
>> ---
>>
>>
>> _______________________________________________
>> Pharo-project mailing list
>> [email protected]
>> http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
>
>
> _______________________________________________
> Pharo-project mailing list
> [email protected]
> http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
---
Jannik Laval
PhD Student - Rmod Team - INRIA
Certified Project Management Associate (IPMA)
http://www.jannik-laval.eu
http://rmod.lille.inria.fr
---
_______________________________________________
Pharo-project mailing list
[email protected]
http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
