New Posts New Posts RSS Feed: Speed up initialization
  FAQ FAQ  Forum Search   Calendar   Register Register  Login Login

Speed up initialization

 Post Reply Post Reply
Author
KitKat View Drop Down
Newbie
Newbie
Avatar

Joined: 01-Nov-2012
Location: Florida
Posts: 23
Post Options Post Options   Quote KitKat Quote  Post ReplyReply Direct Link To This Post Topic: Speed up initialization
    Posted: 04-Apr-2013 at 9:14am
How can we speed up the initialization of the database, even with PreCompiled Views, the first access take about 22-25 seconds.  Below is a debug log of the initialization.  Also, where in a DevForce/Cocktail Application can I modify the Discovery Search Patters.  Anywhere I put it either has no effect or causes an exception.

Thank you,
Katerina

0 : 4/4/2013 12:10:41 PM :  : IdeaBlade.Core.IdeaBladeConfig:Initialize : Initializing configuration ...
1 : 4/4/2013 12:10:44 PM :  : IdeaBlade.Core.Composition.PartsCatalog:LoadCatalog : MEF assembly probing started: 4/4/2013 12:10:44 PM.  If this takes a long time, use IdeaBlade.Core.Composition.CompositionHost to specify/restrict which assemblies to probe.
2 : 4/4/2013 12:10:45 PM :  : IdeaBlade.Core.Composition.PartsCatalog:LoadCatalog : Assembly 'LightworkDb.Web, Version=1.0.0.147, Culture=neutral, PublicKeyToken=93fdd07a360417b6' added to PartsCatalog
3 : 4/4/2013 12:10:45 PM :  : IdeaBlade.Core.Composition.PartsCatalog:LoadCatalog : MEF assembly probing completed: 4/4/2013 12:10:45 PM
4 : 4/4/2013 12:10:45 PM :  : IdeaBlade.Core.Composition.CompositionHost:.ctor : Probe Assemblies: Caliburn.Micro, Version=1.4.0.0, Culture=neutral, PublicKeyToken=8e5891231f2ed21f :: Cocktail.Utils, Version=2.2.0.0, Culture=neutral, PublicKeyToken=7d8c7326b555a04a :: LightWork.Web, Version=1.0.0.11, Culture=neutral, PublicKeyToken=93fdd07a360417b6 :: LightworkDb.Web, Version=1.0.0.147, Culture=neutral, PublicKeyToken=93fdd07a360417b6 :: LogicNP.CryptoLicensing, Version=9.0.0.0, Culture=neutral, PublicKeyToken=4a3c0a4c668b48b4 :: LwResources, Version=1.0.0.3, Culture=neutral, PublicKeyToken=93fdd07a360417b6 :: PerrymanSoftware.INIFiles, Version=1.0.0.0, Culture=neutral, PublicKeyToken=93fdd07a360417b6  If this list is unnecessarily large, use CompositionHost.SearchPatterns to modify the search critieria for probed assemblies. If this list does not contain the assembly(ies) holding your a) domain model, b) custom interface implementations, and c) POCO/known types then your application may not work correctly. Ensure that these assemblies are available in the exe/bin folder, and if using CompositionHost.SearchPatterns that the patterns are set appropriately.
5 : 4/4/2013 12:10:45 PM :  : IdeaBlade.Core.IdeaBladeConfig:InitializationStatusCallback : IdeaBlade License: 'Silverlight', KeyDate: 11/2/2012, AllowedSessions: 10000. Found on Assembly: 'LightworkDb.Web, Version=1.0.0.147, Culture=neutral, PublicKeyToken=93fdd07a360417b6'
6 : 4/4/2013 12:10:45 PM :  : IdeaBlade.Core.Configuration.ServerSettingsElement:ConstrainSettingsBasedOnLicenseCore : The configured SupportedClientApplicationType is Silverlight
7 : 4/4/2013 12:10:45 PM :  : IdeaBlade.Core.Configuration.ServerSettingsElement:ConstrainSettingsBasedOnLicenseCore : Session-agnostic load balancing is not supported with this license.
'iisexpress.exe' (Managed (v4.0.30319)): Loaded 'C:\Windows\Microsoft.Net\assembly\GAC_MSIL\System.Net.Http\v4.0_4.0.0.0__b03f5f7f11d50a3a\System.Net.Http.dll'
8 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckMultiExport : CompositionContext: 'IbDefault' - Probed for non-default 'ITraceLoggerProvider' and found no matching exports.
9 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckSingleExport : CompositionContext: 'IbDefault' - Probed for default 'ITraceLoggerProvider' and found 'IdeaBlade.Core.DefaultLoggerProvider'.
10 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.TraceFns:CompleteTracingInitialization : IdeaBladeConfig resolution: File: C:\Projects\LightWork\LightWork.Web\web.config - found
11 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.TraceFns:CompleteTracingInitialization : IdeaBladeConfig resolution: Logging file: 
12 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.TraceFns:CompleteTracingInitialization : Bound to .NET runtime version 4.0.30319.17929
13 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.TraceFns:CompleteTracingInitialization : DevForce version 7.0.3.0
14 : 4/4/2013 12:10:46 PM :  : IdeaBlade.EntityModel.RemoteServiceFns:AddSerializationBehavior : Using DC serializer for EntityService
15 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckSingleExport : CompositionContext: 'IbDefault' - Probed for any 'ServiceHostEvents' and found 'IdeaBlade.EntityModel.Server.ServiceHostEvents'.
16 : 4/4/2013 12:10:46 PM :  : IdeaBlade.EntityModel.Server.EntityServiceHostFactory:CreateServiceHost : EntityService listening on http://localhost:42620/EntityService.svc/sl
17 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckSingleExport : CompositionContext: 'IbDefault' - Probed for any 'EntityServiceApplication' and found 'IdeaBlade.EntityModel.EntityServiceApplication'.
18 : 4/4/2013 12:10:46 PM :  : IdeaBlade.EntityModel.EntityServiceApplication:OnServiceStartup : EntityService created
19 : 4/4/2013 12:10:46 PM :  : IdeaBlade.EntityModel.Server.EntityServer:.ctor : EntityServer created for DataSourceExtension: [None], CompositionContext: IbDefault
20 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckMultiExport : CompositionContext: 'IbDefault' - Probed for any 'ICompositionContextResolver' and found no matching exports.
21 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckSingleExport : CompositionContext: 'IbDefault' - Probed for default 'IDataSourceKeyResolver' and found 'IdeaBlade.EntityModel.DefaultDataSourceKeyResolver'.
22 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckMultiExport : CompositionContext: 'IbDefault' - Probed for any 'IEntityQueryExecutor' and found 'IdeaBlade.EntityModel.Edm.EdmQueryExecutor'.
23 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckMultiExport : CompositionContext: 'IbDefault' - Probed for any 'IEntityQueryExecutor' and found 'IdeaBlade.EntityModel.Edm.PassthruEsqlQueryExecutor'.
24 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckMultiExport : CompositionContext: 'IbDefault' - Probed for any 'IEntityQueryExecutor' and found 'IdeaBlade.EntityModel.Edm.StoredProcQueryExecutor'.
25 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckMultiExport : CompositionContext: 'IbDefault' - Probed for any 'IEntityQueryExecutor' and found 'IdeaBlade.EntityModel.Edm.UdtQueryExecutor'.
26 : 4/4/2013 12:10:46 PM :  : IdeaBlade.EntityModel.Server.SessionManager:GetLoginManager : Anonymous access: enabled
27 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckSingleExport : CompositionContext: 'IbDefault' - Probed for non-default 'IEntityLoginManager' and found no matching exports.
28 : 4/4/2013 12:10:46 PM :  : IdeaBlade.EntityModel.Server.SessionManager:GetLoginManager : Looking for AspAuthenticatingLoginManager
29 : 4/4/2013 12:10:46 PM :  : IdeaBlade.EntityModel.Web.AspAuthenticatingLoginManager:.ctor : ASP.NET security service integration enabled
30 : 4/4/2013 12:10:46 PM :  : IdeaBlade.EntityModel.Web.AspAuthenticatingLoginManager:.ctor : ASP.NET authentication mode: Forms
31 : 4/4/2013 12:10:46 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckSingleExport : CompositionContext: 'IbDefault' - Probed for default 'IEntityLoginManager' and found 'IdeaBlade.EntityModel.Web.AspAuthenticatingLoginManager'.
32 : 4/4/2013 12:10:47 PM :  : IdeaBlade.Core.Composition.CompositionHost:CheckMultiExport : CompositionContext: 'IbDefault' - Probed for non-default 'IKnownTypeProvider' and found no matching exports.
33 : 4/4/2013 12:10:47 PM :  : IdeaBlade.EntityModel.RemoteServiceFns:AddSerializationBehavior : Using DC serializer for EntityServer
34 : 4/4/2013 12:10:47 PM :  : IdeaBlade.EntityModel.Server.EntityServerHostFactory:CreateServiceHost : EntityServer listening on http://localhost:42620/EntityServer.svc/sl
35 : 4/4/2013 12:10:48 PM :  : IdeaBlade.EntityModel.EntityServerProxy:GetInstance : Loaded IdeaBlade.EntityModel.LocalEntityServerProxy
'iexplore.exe' (Silverlight): Loaded 'C:\Program Files (x86)\Microsoft Silverlight\5.1.10411.0\en-US\System.Runtime.Serialization.debug.resources.dll'
The thread '<No Name>' (0x2ef8) has exited with code 0 (0x0).
The thread '<No Name>' (0x2a98) has exited with code 0 (0x0).
36 : 4/4/2013 12:10:51 PM : Guest - 1 : IdeaBlade.Core.Composition.CompositionHost:CheckSingleExport : CompositionContext: 'IbDefault' - Probed for any 'EntityServerQueryInterceptor' and found 'IdeaBlade.EntityModel.Server.EntityServerQueryInterceptor'.
The thread '<No Name>' (0x2eec) has exited with code 0 (0x0).
The thread '<No Name>' (0x1e04) has exited with code 0 (0x0).
37 : 4/4/2013 12:10:55 PM : Guest - 1 : IdeaBlade.EntityModel.EntityMetadataStore+<>c__DisplayClass13:<LoadMetadataFromEmbeddedResources>b__10 : Metadata file 'LightworkDb.Web.LightWorkDb.ibmmx' loaded from assembly 'LightworkDb.Web, Version=1.0.0.147, Culture=neutral, PublicKeyToken=93fdd07a360417b6' 
'iisexpress.exe' (Managed (v4.0.30319)): Loaded 'C:\Windows\Microsoft.Net\assembly\GAC_MSIL\Microsoft.CSharp\v4.0_4.0.0.0__b03f5f7f11d50a3a\Microsoft.CSharp.dll', Symbols loaded.
'iisexpress.exe' (Managed (v4.0.30319)): Loaded 'C:\Windows\Microsoft.Net\assembly\GAC_32\System.Data\v4.0_4.0.0.0__b77a5c561934e089\System.Data.dll', Symbols loaded.
'iisexpress.exe' (Managed (v4.0.30319)): Loaded 'C:\Windows\Microsoft.Net\assembly\GAC_MSIL\System.Numerics\v4.0_4.0.0.0__b77a5c561934e089\System.Numerics.dll'
'iisexpress.exe' (Managed (v4.0.30319)): Loaded 'C:\Windows\Microsoft.Net\assembly\GAC_32\System.Data.OracleClient\v4.0_4.0.0.0__b77a5c561934e089\System.Data.OracleClient.dll'
'iisexpress.exe' (Managed (v4.0.30319)): Loaded 'C:\Windows\Microsoft.Net\assembly\GAC_MSIL\System.Dynamic\v4.0_4.0.0.0__b03f5f7f11d50a3a\System.Dynamic.dll'
'iisexpress.exe' (Managed (v4.0.30319)): Loaded 'C:\Windows\Microsoft.Net\assembly\GAC_32\System.EnterpriseServices\v4.0_4.0.0.0__b03f5f7f11d50a3a\System.EnterpriseServices.dll'
'iisexpress.exe' (Managed (v4.0.30319)): Loaded 'C:\Windows\Microsoft.Net\assembly\GAC_32\System.EnterpriseServices\v4.0_4.0.0.0__b03f5f7f11d50a3a\System.EnterpriseServices.Wrapper.dll'
38 : 4/4/2013 12:10:55 PM : Guest - 1 : IdeaBlade.EntityModel.Server.EntityServerQueryInterceptor:ExecuteQuery : Fetch ... value(IdeaBlade.EntityModel.EntityQueryProxy`1[LightworkDb.Web.Entities.General.LwCiTheme]).Where(t => t.DefaultLightWorkTheme)
39 : 4/4/2013 12:10:55 PM : Guest - 1 : IdeaBlade.Core.Composition.CompositionHost:CheckSingleExport : CompositionContext: 'IbDefault' - Probed for non-default 'IDataSourceKeyResolver' and found no matching exports.
40 : 4/4/2013 12:10:55 PM : Guest - 1 : IdeaBlade.EntityModel.Edm.DbKey:Initialize : Initializing DbKey for LightWorkDb, connectionString = 'Server=PAI-SRV-SQL2.perryman.local;Database=LightworkDb;User Id=sa;Password=P@ssW0rd'
41 : 4/4/2013 12:10:55 PM : Guest - 1 : IdeaBlade.EntityModel.Edm.DbKey:FindSubTypedDbContext : DBKey 'LightWorkDb': Found DbContext 'LightworkDb.Web.Context.LightWorkDb'
42 : 4/4/2013 12:10:55 PM : Guest - 1 : IdeaBlade.EntityModel.Edm.DbKey:FindModelAssembly : DataSourceKey: 'LightWorkDb' found in assembly 'LightworkDb.Web, Version=1.0.0.147, Culture=neutral, PublicKeyToken=93fdd07a360417b6' at 4/4/2013 12:10:55 PM
The thread '<No Name>' (0x11b4) has exited with code 0 (0x0).
The thread '<No Name>' (0x2020) has exited with code 0 (0x0).
43 : 4/4/2013 12:11:02 PM : Guest - 1 : IdeaBlade.Core.Composition.CompositionHost:CheckMultiExport : CompositionContext: 'IbDefault' - Probed for any 'IIdGenerator' and found 'IdeaBlade.EntityModel.StoreGeneratedIdGenerator'.
'iisexpress.exe' (Managed (v4.0.30319)): Loaded 'EntityFrameworkDynamicProxies-LightworkDb.Web'
44 : 4/4/2013 12:11:02 PM : Guest - 1 : IdeaBlade.Core.Composition.CompositionHost:CheckMultiExport : CompositionContext: 'IbDefault' - Probed for non-default 'IConcurrencyStrategy' and found no matching exports.
45 : 4/4/2013 12:11:02 PM : Guest - 1 : IdeaBlade.Core.Composition.CompositionHost:CheckSingleExport : CompositionContext: 'IbDefault' - Probed for default 'IConcurrencyStrategy' and found 'IdeaBlade.EntityModel.DefaultConcurrencyValueSetter'.
46 : 4/4/2013 12:11:02 PM : Guest - 1 : IdeaBlade.EntityModel.Edm.EdmMetadataHelper:DiscoverEdmEntities : Loading EDM metadata for LightWorkDb
Back to Top
kimj View Drop Down
IdeaBlade
IdeaBlade
Avatar

Joined: 09-May-2007
Posts: 1391
Post Options Post Options   Quote kimj Quote  Post ReplyReply Direct Link To This Post Posted: 04-Apr-2013 at 11:43am
Here's what I see going on here:

- Between 12:10:41 and 12:10:44 it's not clear what's happening, presumably IIS Express startup.

- Probing starts at 12:10:44 and completes at 12:10:45. Modifying the search patterns would probably not help much, but you can set the CompositionHost.SearchPatterns and/or IgnorePatterns in the static constructor of your Cocktail bootstrapper. See Cocktail documentation for more information.

- DevForce services are started between 12:10:45 and 12:10:47.

- Login is at 12:10:48

- 12:10:51 - The first query is received, which triggers ibmmx load.

- 12:10:51 - 12:10:55 - ibmmx load

- 12:10:55 - 12:11:02 - The DbContext is created.

So I see two performance hot spots: 1) the ibmmx takes 4 seconds to load, and 2) DbContext initialization takes 7 seconds.

During ibmmx load DevForce will initialize the EntityMetadataStore and other metadata. This is generally not a fast process, but four seconds does seem slow, so we can investigate further to see if this can be reduced.

If you're already using pre-generated views, you probably won't be able to reduce the DbContext init time further without splitting your model into smaller components, although based on web searches it seems that EF has performance issues with even small DbContext-based models, so I don't know what to recommend here.

The "good" news is that all this server initialization does occur once only on a cold start. When your application is deployed to IIS you can modify application pool settings to reduce recycling or try some sort of scheduled batch job to keep the services alive and avoid performance hits visible to your users.







Back to Top
KitKat View Drop Down
Newbie
Newbie
Avatar

Joined: 01-Nov-2012
Location: Florida
Posts: 23
Post Options Post Options   Quote KitKat Quote  Post ReplyReply Direct Link To This Post Posted: 04-Apr-2013 at 1:30pm
Would a Copy of our ibmmx or Model Project help your investigation? We have the model split into its own dedicated assembly with nothing else in it.
Back to Top
kimj View Drop Down
IdeaBlade
IdeaBlade
Avatar

Joined: 09-May-2007
Posts: 1391
Post Options Post Options   Quote kimj Quote  Post ReplyReply Direct Link To This Post Posted: 04-Apr-2013 at 2:22pm
I think we still have the ibmmx and model project from your problem with the RelatedEntityList a few weeks ago. We'll try running some tests with that. Remember, though, that in the (unlikely) event we make this super fast, it still accounts for only 4 seconds out of 22.
Back to Top
KitKat View Drop Down
Newbie
Newbie
Avatar

Joined: 01-Nov-2012
Location: Florida
Posts: 23
Post Options Post Options   Quote KitKat Quote  Post ReplyReply Direct Link To This Post Posted: 05-Apr-2013 at 4:51am
I do understand that, that is still an 18% improvement.
Back to Top
kimj View Drop Down
IdeaBlade
IdeaBlade
Avatar

Joined: 09-May-2007
Posts: 1391
Post Options Post Options   Quote kimj Quote  Post ReplyReply Direct Link To This Post Posted: 30-Apr-2013 at 6:44pm
We've made some changes to ibmmx loading in the 7.1.2 release. Let us know if you see any performance improvement.
Back to Top
 Post Reply Post Reply

Forum Jump Forum Permissions View Drop Down