On Sat, Jan 16, 2016 at 4:35 AM, Dimitris Chloupis <kilon.alios@gmail.com> wrote:
So I decided to find out why Nuatilus delays to syntax highlight when I open ChronosManager I open my activity monitor to be amazed by the fact that pharo was consuming 30% of one of my cores.
At the time I thought it was my fault because when my GUI steps I load from a png a form that I attack to a Morph. So I optimised that part loading all the pngs before hand , creating all the forms and during steping point only to the correct form.
Nope still 30%
ok change step time to 1 sec
Nope still 30%
ok delete step and step time alltogether
Nope still 30%
so the only explanation left is that pharo does not like I use images , which are not that big anyway , my whole image library is just 1 mb.
So how I profile this ? Is there any way to find exactly where that 30% is consumed ?
See below
I tried to profile step and it retunred back with a mere 32ms , and I suspect thats the first step that loads the images , the second step would be much faster since it will just point to correct forms. So with a step of 32ms max and stepping once per second why a 30% CPU consumption ?
I loaded ChronosManager from the catalog, started it from the World menu, and I see 55% cpu. I googled for pharo profiling and found [1] which describes using World > System > Start Profiling All Processes. Profiled without & with your app running WorldMorph>>doOneCycle moved from 9% to 29% A couple of steps in I see #interCyclePause is the same at 9%, so your app seems full responsible for the 20% increase :) Drilling down (a long way) along the most expensive path until I find one of you classes (2.5%) ChrGUIMorph>>taskbarButtonFor: and a few steps further down (0.3%) ChrGUIMorph>>taskbarIcon then (0.3%) ImageReadWriter class>>formFromStream: then (0.3%) PNGReadWriter>>processNonInterlaced So its creating this icon every cycle. Modifying... ChrGUIMorph>>taskbarIcon ^ChrStopwatchSettingsPNG new logotinyIcon to... ChrGUIMorph>>taskbarIcon ^Smalltalk ui icons referencesIcon drops cpu usage to 9%, and if I close your app it drops to 6%. Profiling your app again, and again drilling down through WorldState>>doOneCycleNowFor: I see a long chain at 2.5% usage from WorldMorph>>runStepMethods all the way down to FileSystem>>entriedAt:ifAbsent:do. So filesystem access occuring every cycle is where the time is being spent. Along that chain I see ChrGUIMorph>>secondsFromTimerForm is calling ChronosManager>>workingPath outside of the nil check for the cache in secondsTimerFormCollection. Moving "wp := ChronosManager workingPath" inside the #ifNil: drops cpu usage to 7%. cheers -ben [1] http://pharobooks.gforge.inria.fr/PharoByExampleTwo-Eng/latest/Profiling.pdf