Re: [Banshee-List] optimization research

Thanks for sharing this tool and the research !

Some comments below.

On Fri, 2009-12-11 at 22:00 -0800, Gabriel Burt wrote:
> Hey all,
> I spent some time today playing with the --trace mono option[0].  It
> prints out ENTER and LEAVE timestamps for every method call, filtered
> by namespace or type or however you want.  If you are on the latest
> git, you can use 'make run-trace' to replicate my findings below.
> I wrote a little tool[1] to dump that data to a sqlite database, and
> then I ran some queries on it.  One of the more interesting is this
> one[2], which shows which methods on the main thread took the most
> time (during starting and immediately closing Banshee), not including
> time spent in methods within assemblies in bin/ (except
> Mono.Data.Sqlite) they called:
> ms    calls   class_and_method
> ----  ------  ---------------------------------------------------------------------------------------------
> 1949  313     Hyena.Data.Sqlite.HyenaSqliteCommand:WaitForResult
> 942   20739   Hyena.Data.Sqlite.AbstractDatabaseColumn:SetValue
> 886   1       Banshee.ServiceStack.ServiceManager:InitializeAddins
> 753   1       Banshee.Gui.GtkBaseClient:Run
> 554   4       Banshee.Gui.GtkBaseClient/<RunIdle>c__AnonStorey18:<>m__85
> 553   1       Banshee.ServiceStack.Client:OnStarted
> 207   823     Hal.Device:QueryCapability
> 161   758     Hyena.Data.Sqlite.SqliteModelProvider`1:Load
> 143   8698    Hyena.Data.Sqlite.SqliteUtils:FromDbFormat
> 137   11859   Hyena.Data.Sqlite.HyenaSqliteArrayDataReader:IsDBNull
> 116   9699    Hyena.Data.Sqlite.HyenaSqliteArrayDataReader:GetValue
> So 1.9s was spent waiting for sqlite commands to return values, on the
> main thread.  .87 seconds was spent in InitializeAddins.  The
> Hal.Device querying also seems strange to be running on the main loop.

I saw approximately the same figures for
HyenaSqliteCommand:WaitForResult on a first run, but for the next runs
the time was around 300 ms. This needs further investigations.

The fact that those sqlite queries are run on the main thread is
consistent with all the "HyenaSqliteConnection command issued from the
main thread" messages I get with the --debug-sql option.

I think the time spent in InitializeAddins goes up to 800 ms only if the
addin cache is not present (in bin/addin-db-001/). On consecutive runs,
it's less than 200 ms.

> Anyway, just some interesting optimization research I'm still
> digesting.  It's possible my tool is buggy and these numbers are
> completely off, but they seem reasonable enough to me.
> Gabriel
> [0]
> [1] git clone
> [2] select sum(selfduration)/100 as ms, count(*) as calls,
> class||':'||method as class_and_method from traces where
> threadid=47328420921536 group by class, method order by ms desc limit
> 25;
> that threadid is what I determined was the main thread by looking at
> the result of
> select threadid, count(*) from traces group by threadid;
> and picking out the thread with the most method calls.
> _______________________________________________
> banshee-list mailing list
> banshee-list gnome org
Bertrand Lorentz <bertrand lorentz gmail com>

Attachment: signature.asc
Description: This is a digitally signed message part

[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]