Sweet Ayende!!! On Fri, Sep 18, 2009 at 1:48 AM, Ayende Rahien <[email protected]> wrote:
> I did another batch of optimizations. > 1/ That dropped the perf for registering 5,000 invalid services from 2.5 > seconds to 2.0 seconds. > 2/ That dropped the perf for registering 5,000 invalid services from 2.0 > seconds to 1.4 seconds. > > We still aren't linear here, unfortunately, registering 10,000 services > takes 5.3 seconds, 15,000 takes 11.1 seconds and 20,000 takes 27 seconds. > But I think that we can defer *those* optimizations for a later date :-) > > > > On Fri, Sep 18, 2009 at 2:43 AM, Ayende Rahien <[email protected]> wrote: > >> No, it doesn't. >> It is easier with code. >> Test code is interesting, it shows a pathological case of adding only >> invalid components. >> And the problem only show up when we have a large number of invalid >> components. >> >> var kernel = new DefaultKernel(); >> for (int i = 0; i < 500; i++) >> { >> kernel.AddComponent("key" + i, typeof(string), typeof(string)); >> } >> >> Before optimization, this runs in 9.2 seconds >> >> After optimization, this runs in 0.5 seconds. >> >> Raising the number of components to 5,000 leads to about: 44.5 seconds (no >> idea how much before optimization, don't have the patience. >> >> Using this approach, however: >> >> var kernel = new DefaultKernel(); >> using(kernel.OptimizeDependencyResolution()) >> { >> for (int i = 0; i < 300; i++) >> { >> kernel.AddComponent("key" + i, typeof(string), typeof(string)); >> } >> } >> >> Resolve everything in 1.9 seconds. >> The OptimizeDependencyResolution defer dependency resolution to the >> Dispose part, and allow us to both gain significant optimization in >> registering component while at the same time work nicely with all the usual >> tools and facilities. >> >> I also optimized GetHandlers(Type) and GetAssignableHandlers(Type) >> >> I think that this is good enough for now :-) >> >> >> On Fri, Sep 18, 2009 at 1:44 AM, Tyler Burd <[email protected]> wrote: >> >>> I fully accept that. Does this mean that the startable facility will >>> not be usable with this feature? >>> >>> >>> >>> *From:* [email protected] [mailto: >>> [email protected]] *On Behalf Of *Ayende Rahien >>> *Sent:* Thursday, September 17, 2009 3:53 PM >>> >>> *To:* [email protected] >>> *Subject:* Re: long startup time >>> >>> >>> >>> Hm, that is a bit complex, though. >>> In particular, it effect the way the startable facility behaves. >>> I think that I will make this an opt in feature. >>> >>> On Thu, Sep 17, 2009 at 10:55 PM, Ayende Rahien <[email protected]> >>> wrote: >>> >>> Tyler, >>> No, it isn't. >>> Basically, I think we need to restructure the way we do this so we will >>> defer that as late as possible (to the first resolve call, I think.). >>> >>> >>> >>> On Thu, Sep 17, 2009 at 8:09 PM, Tyler Burd <[email protected]> wrote: >>> >>> Attached is the profiling screenshot for a VERY simple console app (code >>> below). It took so long to profile that I didn't have the patience to wait >>> until all 1000 services were registered, but this clearly shows where the >>> problem lies. >>> >>> Total calls to AddComponent: 409 >>> Total calls to AbstractHandler.DependencySatisfied: 83,773 >>> >>> >>> If I try to profile my original app, it times out and causes a profiler >>> error even when left overnight to finish starting up. When I stopped the >>> profiler after 30 minutes of running I saw over 600,000 calls to >>> DependencySatisfied. >>> >>> Am I wrong in thinking that 1000 services is not THAT many in a well >>> designed app? I have a large financial app that has many complicated >>> processes, so I split out every process into isolated services. I also use >>> a service to encapsulate ever query with a dedicated service interface. The >>> number of services registered adds up fast, but it sure seems like the >>> right, maintainable, and testable way to do things. >>> >>> >>> Profiled code: >>> >>> var container = new WindsorContainer(); >>> var kernel = container.Kernel; >>> >>> for (int i = 0; i < 1000; i++) >>> { >>> kernel.AddComponent("key" + i, typeof(string), typeof(string)); >>> } >>> >>> Console.ReadLine(); >>> >>> >>> >>> >>> -----Original Message----- >>> From: [email protected] [mailto: >>> [email protected]] On Behalf Of Mauricio Scheffer >>> Sent: Wednesday, September 16, 2009 8:28 PM >>> To: Castle Project Users >>> Subject: Re: long startup time >>> >>> >>> It's definitely the HandlerRegistered event, or more likely >>> AbstractEventHandler.DependencySatisfied()... here's a little test: >>> >>> import System >>> import System.Diagnostics >>> import Castle.Windsor from Castle.Windsor >>> import Castle.MicroKernel from Castle.MicroKernel >>> import Castle.MicroKernel.Handlers from Castle.MicroKernel >>> import Castle.MicroKernel.SubSystems.Naming from Castle.MicroKernel >>> import Castle.MicroKernel.ModelBuilder from Castle.MicroKernel >>> >>> def KernelAddComponent(k as IKernel): >>> for i in range(1000): >>> w = Stopwatch() >>> w.Start() >>> k.AddComponent("key${i}", typeof(string), typeof(string)) >>> w.Stop() >>> print "${i} took ${w.ElapsedMilliseconds}" >>> >>> class CustomKernel(DefaultKernel): >>> override def RaiseHandlerRegistered(h as IHandler): >>> pass >>> >>> KernelAddComponent(DefaultKernel()) >>> >>> Change the DefaultKernel() to CustomKernel() and the perf hit goes >>> away. >>> >>> >>> On Sep 16, 2:00 pm, Tuna Toksoz <[email protected]> wrote: >>> > N! times? How? >>> > >>> > Tuna Toksöz >>> > Eternal sunshine of the open source mind. >>> > >>> > >>> http://devlicio.us/blogs/tuna_toksozhttp://tunatoksoz.comhttp://twitter.com/tehlike<http://devlicio.us/blogs/tuna_toksozhttp:/tunatoksoz.comhttp:/twitter.com/tehlike> >>> > >>> > >>> > >>> > On Wed, Sep 16, 2009 at 12:59 PM, Ayende Rahien <[email protected]> >>> wrote: >>> > > IIRC, the culprit is the ComponentRegistered event, that is being >>> raised N! >>> > > times >>> > > We had to do that when we use the AddComponent model, but with >>> Register, we >>> > > can probably optimize this. >>> > >>> > > On Wed, Sep 16, 2009 at 7:54 PM, Tyler Burd <[email protected]> wrote: >>> > >>> > >> I'm not sure how feasible that idea could be. SO much of an >>> application >>> > >> depends on having everything registered and ready to go before any >>> actual >>> > >> services are invoked. For instance, my project uses Rhino Service >>> Bus, >>> > >> which depends heavily on the GetAssignableHandlers and similar >>> methods on >>> > >> the kernel. If a critical message came in and we weren't finished >>> > >> registering services (AKA Message Consumers), that message could be >>> lost >>> > >> forever since GetAssignableHandlers would not return all of the >>> expected >>> > >> handlers. >>> > >>> > >> I'd much rather have some form of lazy initialization of handlers >>> and >>> > >> dependencies to amortize whatever this startup cost is, but I'm not >>> sure >>> > >> right now how that might look. >>> > >>> > >> -----Original Message----- >>> > >> From: [email protected] [mailto: >>> > >> [email protected]] On Behalf Of James Curran >>> > >> Sent: Wednesday, September 16, 2009 10:31 AM >>> > >> To: [email protected] >>> > >> Subject: Re: long startup time >>> > >>> > >> This leads to interesting question. Since, one presumes you won't >>> > >> need all 1000 service immediately, could building the container be >>> > >> spun off as a background task? This of course would lead to some >>> > >> interesting race conditions, but if most of those services are for >>> > >> corner cases (ie, say 90% of your functionality could be handled by >>> > >> 10% of the services), then it just become a case of filling it in th >>> > >> eproper order, and releasing semaphores as you go. >>> > >>> > >> On Wed, Sep 16, 2009 at 12:05 PM, Tyler Burd <[email protected]> >>> wrote: >>> > >> > I have another similar project that has around 300 services, and >>> the >>> > >> average >>> > >> > AddComponent time there is 20ms, so that would make sense. I'll >>> try to >>> > >> get >>> > >> > profile results today (have to buy dotTrace first). >>> > >>> > >> > From: [email protected] >>> > >> > [mailto:[email protected]] On Behalf Of >>> Ayende >>> > >> Rahien >>> > >> > Sent: Wednesday, September 16, 2009 3:00 AM >>> > >> > To: [email protected] >>> > >> > Subject: Re: long startup time >>> > >>> > >> > IIRC, >>> > >>> > >> > We saw something like that previously, I think that there is an >>> O(N) >>> > >> > operation in Windsor somewhere. >>> > >>> > >> > On Wed, Sep 16, 2009 at 7:19 AM, Tyler Burd <[email protected]> >>> wrote: >>> > >>> > >> > Hi all, >>> > >>> > >> > I've got a large application that takes about 1 minute to start >>> up. I >>> > >> > investigated today what could be the cause of this very long >>> delay, and >>> > >> > narrowed it down to the WindsorContainer.AddComponent method. I >>> have >>> > >> about >>> > >> > 1000 service classes, each with an interface (the service type). >>> The >>> > >> > average time to call WindsorContainer.AddComponent is 52ms on my >>> system. >>> > >> > 52ms * 1000 is 52 seconds, which is the vast majority of the app's >>> > >> startup >>> > >> > time. >>> > >>> > >> > My system is a Quad Core, 2.66GHz Core2 running Windows XP. The >>> same >>> > >> > approximate startup time can be verified on multiple machines, >>> servers, >>> > >> and >>> > >> > OS's. >>> > >>> > >> > Is this normal? Do I have to just bite the bullet on a long >>> startup >>> > >> time, >>> > >> > or is there something I can do to help this? >>> > >>> > >> > Here is the block of code in a small executable I used to >>> calculate the >>> > >> > times. I can provide a profile report if necessary. I normally >>> use >>> > >> > AllTypes along with the fluent registration, but I wanted to get >>> as >>> > >> > low-level as possible. This code outputs: >>> > >>> > >> "Called AddComponent 957 times. Average AddComponent time: >>> 52.0267175572519ms" >>> > >>> > >> > var container = new WindsorContainer(); >>> > >>> > >> > //calculates the time for each AddComponent call >>> > >>> > >> > var watch = new Stopwatch(); >>> > >>> > >> > var totalAddComponentCalls = 0; >>> > >>> > >> > //keeps track of the average ms to call AddComponent >>> > >>> > >> > var allAddComponentTimes = new List<long>(1000); >>> > >>> > >> > foreach (var classType in >>> > >> > >>> typeof(TheBigApplicationThingyWithAllTheServices).Assembly.GetTypes()) >>> > >>> > >> > { >>> > >>> > >> > if (classType.IsInterface) >>> > >>> > >> > continue; >>> > >>> > >> > if (classType.Namespace == null) >>> > >>> > >> > continue; >>> > >>> > >> > if (!classType.Namespace.Contains("Services")) >>> > >>> > >> > continue; >>> > >>> > >> > var interfaces = classType.GetInterfaces(); >>> > >>> > >> > if (interfaces.Length == 0) >>> > >>> > >> > continue; >>> > >>> > >> > var firstInterface = interfaces[0]; >>> > >>> > >> > var serviceName = >>> totalAddComponentCalls.ToString(); >>> > >> > //simple way to get unique name >>> > >>> > >> > watch.Start(); >>> > >>> > >> > container.AddComponent(serviceName, >>> firstInterface, >>> > >> > classType); >>> > >>> > >> > watch.Stop(); >>> > >>> > >> > >>> allAddComponentTimes.Add(watch.ElapsedMilliseconds); >>> > >>> > >> > watch.Reset(); >>> > >>> > >> > ++totalAddComponentCalls; >>> > >>> > >> > } >>> > >>> > >> > var avgAddCompTime = (from ms in allAddComponentTimes select >>> > >> ms).Average(); >>> > >>> > >> > Console.Out.WriteLine(string.Format("Called AddComponent {0} >>> times. >>> > >> Average >>> > >> > AddComponent time: {1}ms", totalAddComponentCalls, >>> avgAddCompTime)); >>> > >>> > >> -- >>> > >> Truth, >>> > >> James >>> >>> >>> >>> >>> >>> >>> >>> >>> >>> >> > > > > --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Castle Project Users" group. To post to this group, send email to [email protected] To unsubscribe from this group, send email to [email protected] For more options, visit this group at http://groups.google.com/group/castle-project-users?hl=en -~----------~----~----~----~------~----~------~--~---
