Thanks Henry. I push in pharoInbox a new method. MessageTally>>spyOn:cutoff: which allows us to specify an appropriate filter. I will see the TimeProfileBrowser. Cheers, Jannik On Oct 26, 2009, at 00:26 , Henrik Sperre Johansen wrote:
Personally, I always change to 0.1 in spyOn: (my experience in VW was that doing 0.0 makes the tree building take a long time). You'd probably also want to try out TimeProfileBrowser onBlock: instead of MessageTally spyOn:, while not a huge improvement, it's nice to have the method source accessible directly. I had a dream of making a new one, with a proper treeview of the tally (and a button for auto-expand to certain %, no need to worry if you'd set the cutoff correctly before starting the tally), color- coding of the hotspots in the method view, and store/compare of tallies, but never seem to get around to it. Well, I did start once, but my head started hurting too soon from the total lack of separation between result production/storage/ presentation responsibilities in MT.
Cheers, Henry
On 25.10.2009 21:00, Laval Jannik wrote:
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 Pharo-project@lists.gforge.inria.fr http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
_______________________________________________ Pharo-project mailing list Pharo-project@lists.gforge.inria.fr 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 Pharo-project@lists.gforge.inria.fr http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
_______________________________________________ Pharo-project mailing list Pharo-project@lists.gforge.inria.fr 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 Pharo-project@lists.gforge.inria.fr http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
_______________________________________________ Pharo-project mailing list Pharo-project@lists.gforge.inria.fr 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 ---