Logging activation time for domain object grains.

src/Squidex.Domain.Apps.Entities/Apps/AppGrain.cs

@@ -18,6 +18,7 @@ using Squidex.Domain.Apps.Events.Apps;
 using Squidex.Infrastructure;
 using Squidex.Infrastructure.Commands;
 using Squidex.Infrastructure.EventSourcing;
+using Squidex.Infrastructure.Log;
 using Squidex.Infrastructure.Orleans;
 using Squidex.Infrastructure.Reflection;
 using Squidex.Infrastructure.States;
@@ -36,11 +37,12 @@ namespace Squidex.Domain.Apps.Entities.Apps
         public AppGrain(
             InitialPatterns initialPatterns,
             IStore<Guid> store,
+            ISemanticLog log,
             IAppProvider appProvider,
             IAppPlansProvider appPlansProvider,
             IAppPlanBillingManager appPlansBillingManager,
             IUserResolver userResolver)
-            : base(store)
+            : base(store, log)
         {
             Guard.NotNull(initialPatterns, nameof(initialPatterns));
             Guard.NotNull(appProvider, nameof(appProvider));

src/Squidex.Domain.Apps.Entities/Assets/AssetGrain.cs

@@ -15,6 +15,7 @@ using Squidex.Domain.Apps.Events.Assets;
 using Squidex.Infrastructure;
 using Squidex.Infrastructure.Commands;
 using Squidex.Infrastructure.EventSourcing;
+using Squidex.Infrastructure.Log;
 using Squidex.Infrastructure.Orleans;
 using Squidex.Infrastructure.Reflection;
 using Squidex.Infrastructure.States;
@@ -23,8 +24,8 @@ namespace Squidex.Domain.Apps.Entities.Assets
 {
     public class AssetGrain : SquidexDomainObjectGrain<AssetState>, IAssetGrain
     {
-        public AssetGrain(IStore<Guid> store)
-            : base(store)
+        public AssetGrain(IStore<Guid> store, ISemanticLog log)
+            : base(store, log)
         {
         }
 

src/Squidex.Domain.Apps.Entities/Contents/ContentGrain.cs

@@ -19,6 +19,7 @@ using Squidex.Domain.Apps.Events.Contents;
 using Squidex.Infrastructure;
 using Squidex.Infrastructure.Commands;
 using Squidex.Infrastructure.EventSourcing;
+using Squidex.Infrastructure.Log;
 using Squidex.Infrastructure.Reflection;
 using Squidex.Infrastructure.States;
 
@@ -33,11 +34,12 @@ namespace Squidex.Domain.Apps.Entities.Contents
 
         public ContentGrain(
             IStore<Guid> store,
+            ISemanticLog log,
             IAppProvider appProvider,
             IAssetRepository assetRepository,
             IScriptEngine scriptEngine,
             IContentRepository contentRepository)
-            : base(store)
+            : base(store, log)
         {
             Guard.NotNull(appProvider, nameof(appProvider));
             Guard.NotNull(scriptEngine, nameof(scriptEngine));

src/Squidex.Domain.Apps.Entities/Rules/RuleGrain.cs

@@ -15,6 +15,7 @@ using Squidex.Domain.Apps.Events.Rules;
 using Squidex.Infrastructure;
 using Squidex.Infrastructure.Commands;
 using Squidex.Infrastructure.EventSourcing;
+using Squidex.Infrastructure.Log;
 using Squidex.Infrastructure.Orleans;
 using Squidex.Infrastructure.Reflection;
 using Squidex.Infrastructure.States;
@@ -25,8 +26,8 @@ namespace Squidex.Domain.Apps.Entities.Rules
     {
         private readonly IAppProvider appProvider;
 
-        public RuleGrain(IStore<Guid> store, IAppProvider appProvider)
-            : base(store)
+        public RuleGrain(IStore<Guid> store, ISemanticLog log, IAppProvider appProvider)
+            : base(store, log)
         {
             Guard.NotNull(appProvider, nameof(appProvider));
 

src/Squidex.Domain.Apps.Entities/Schemas/SchemaGrain.cs

@@ -18,6 +18,7 @@ using Squidex.Domain.Apps.Events.Schemas;
 using Squidex.Infrastructure;
 using Squidex.Infrastructure.Commands;
 using Squidex.Infrastructure.EventSourcing;
+using Squidex.Infrastructure.Log;
 using Squidex.Infrastructure.Orleans;
 using Squidex.Infrastructure.Reflection;
 using Squidex.Infrastructure.States;
@@ -29,8 +30,8 @@ namespace Squidex.Domain.Apps.Entities.Schemas
         private readonly IAppProvider appProvider;
         private readonly FieldRegistry registry;
 
-        public SchemaGrain(IStore<Guid> store, IAppProvider appProvider, FieldRegistry registry)
-            : base(store)
+        public SchemaGrain(IStore<Guid> store, ISemanticLog log, IAppProvider appProvider, FieldRegistry registry)
+            : base(store, log)
         {
             Guard.NotNull(appProvider, nameof(appProvider));
             Guard.NotNull(registry, nameof(registry));

src/Squidex.Domain.Apps.Entities/SquidexDomainObjectGrain.cs

@@ -9,14 +9,15 @@ using System;
 using Squidex.Domain.Apps.Events;
 using Squidex.Infrastructure.Commands;
 using Squidex.Infrastructure.EventSourcing;
+using Squidex.Infrastructure.Log;
 using Squidex.Infrastructure.States;
 
 namespace Squidex.Domain.Apps.Entities
 {
     public abstract class SquidexDomainObjectGrain<T> : DomainObjectGrain<T> where T : IDomainState, new()
     {
-        protected SquidexDomainObjectGrain(IStore<Guid> store)
-            : base(store)
+        protected SquidexDomainObjectGrain(IStore<Guid> store, ISemanticLog log)
+            : base(store, log)
         {
         }
 

src/Squidex.Infrastructure/Commands/DomainObjectGrain.cs

@@ -9,6 +9,7 @@ using System;
 using System.Collections.Generic;
 using System.Threading.Tasks;
 using Squidex.Infrastructure.EventSourcing;
+using Squidex.Infrastructure.Log;
 using Squidex.Infrastructure.Orleans;
 using Squidex.Infrastructure.States;
 using Squidex.Infrastructure.Tasks;
@@ -19,6 +20,7 @@ namespace Squidex.Infrastructure.Commands
     {
         private readonly List<Envelope<IEvent>> uncomittedEvents = new List<Envelope<IEvent>>();
         private readonly IStore<Guid> store;
+        private readonly ISemanticLog log;
         private Guid id;
         private T snapshot = new T { Version = EtagVersion.Empty };
         private IPersistence<T> persistence;
@@ -43,20 +45,29 @@ namespace Squidex.Infrastructure.Commands
             get { return snapshot; }
         }
 
-        protected DomainObjectGrain(IStore<Guid> store)
+        protected DomainObjectGrain(IStore<Guid> store, ISemanticLog log)
         {
             Guard.NotNull(store, nameof(store));
+            Guard.NotNull(log, nameof(log));
 
             this.store = store;
+
+            this.log = log;
         }
 
-        public override Task OnActivateAsync(Guid key)
+        public override async Task OnActivateAsync(Guid key)
         {
-            id = key;
+            using (log.MeasureInformation(w => w
+                .WriteProperty("action", "ActivateDomainObject")
+                .WriteProperty("doType", GetType().Name)
+                .WriteProperty("doKey", key.ToString())))
+            {
+                id = key;
 
-            persistence = store.WithSnapshotsAndEventSourcing<T, Guid>(GetType(), id, ApplySnapshot, ApplyEvent);
+                persistence = store.WithSnapshotsAndEventSourcing<T, Guid>(GetType(), id, ApplySnapshot, ApplyEvent);
 
-            return persistence.ReadAsync();
+                await persistence.ReadAsync();
+            }
         }
 
         public void RaiseEvent(IEvent @event)

src/Squidex.Infrastructure/FileExtensions.cs

@@ -6,6 +6,7 @@
 // ==========================================================================
 
 using System;
+using System.Globalization;
 using System.IO;
 
 namespace Squidex.Infrastructure
@@ -62,7 +63,7 @@ namespace Squidex.Infrastructure
                 u = Extensions.Length - 1;
             }
 
-            return $"{Math.Round(d, 1)} {Extensions[u]}";
+            return $"{Math.Round(d, 1).ToString(CultureInfo.InvariantCulture)} {Extensions[u]}";
         }
     }
 }

tests/Squidex.Domain.Apps.Entities.Tests/Apps/AppGrainTests.cs

@@ -17,6 +17,7 @@ using Squidex.Domain.Apps.Entities.TestHelpers;
 using Squidex.Domain.Apps.Events.Apps;
 using Squidex.Infrastructure;
 using Squidex.Infrastructure.Commands;
+using Squidex.Infrastructure.Log;
 using Squidex.Shared.Users;
 using Xunit;
 
@@ -61,7 +62,7 @@ namespace Squidex.Domain.Apps.Entities.Apps
                 { patternId2, new AppPattern("Numbers", "[0-9]*") }
             };
 
-            sut = new AppGrain(initialPatterns, Store, appProvider, appPlansProvider, appPlansBillingManager, userResolver);
+            sut = new AppGrain(initialPatterns, Store, A.Dummy<ISemanticLog>(), appProvider, appPlansProvider, appPlansBillingManager, userResolver);
             sut.OnActivateAsync(Id).Wait();
         }
 

tests/Squidex.Domain.Apps.Entities.Tests/Assets/AssetCommandMiddlewareTests.cs

@@ -16,6 +16,7 @@ using Squidex.Domain.Apps.Entities.Assets.State;
 using Squidex.Domain.Apps.Entities.TestHelpers;
 using Squidex.Infrastructure.Assets;
 using Squidex.Infrastructure.Commands;
+using Squidex.Infrastructure.Log;
 using Squidex.Infrastructure.Tasks;
 using Xunit;
 
@@ -42,7 +43,7 @@ namespace Squidex.Domain.Apps.Entities.Assets
         {
             file = new AssetFile("my-image.png", "image/png", 1024, () => stream);
 
-            asset = new AssetGrain(Store);
+            asset = new AssetGrain(Store, A.Dummy<ISemanticLog>());
             asset.OnActivateAsync(Id).Wait();
 
             A.CallTo(() => grainFactory.GetGrain<IAssetGrain>(Id, null))

tests/Squidex.Domain.Apps.Entities.Tests/Assets/AssetGrainTests.cs

@@ -8,6 +8,7 @@
 using System;
 using System.IO;
 using System.Threading.Tasks;
+using FakeItEasy;
 using Squidex.Domain.Apps.Entities.Assets.Commands;
 using Squidex.Domain.Apps.Entities.Assets.State;
 using Squidex.Domain.Apps.Entities.TestHelpers;
@@ -15,6 +16,7 @@ using Squidex.Domain.Apps.Events.Assets;
 using Squidex.Infrastructure;
 using Squidex.Infrastructure.Assets;
 using Squidex.Infrastructure.Commands;
+using Squidex.Infrastructure.Log;
 using Xunit;
 
 namespace Squidex.Domain.Apps.Entities.Assets
@@ -33,7 +35,7 @@ namespace Squidex.Domain.Apps.Entities.Assets
 
         public AssetGrainTests()
         {
-            sut = new AssetGrain(Store);
+            sut = new AssetGrain(Store, A.Dummy<ISemanticLog>());
             sut.OnActivateAsync(Id).Wait();
         }
 

tests/Squidex.Domain.Apps.Entities.Tests/Contents/ContentGrainTests.cs

@@ -25,6 +25,7 @@ using Squidex.Domain.Apps.Entities.TestHelpers;
 using Squidex.Domain.Apps.Events.Contents;
 using Squidex.Infrastructure;
 using Squidex.Infrastructure.Commands;
+using Squidex.Infrastructure.Log;
 using Xunit;
 
 namespace Squidex.Domain.Apps.Entities.Contents
@@ -107,7 +108,7 @@ namespace Squidex.Domain.Apps.Entities.Contents
 
             patched = patch.MergeInto(data);
 
-            sut = new ContentGrain(Store, appProvider, A.Dummy<IAssetRepository>(), scriptEngine, A.Dummy<IContentRepository>());
+            sut = new ContentGrain(Store, A.Dummy<ISemanticLog>(), appProvider, A.Dummy<IAssetRepository>(), scriptEngine, A.Dummy<IContentRepository>());
             sut.OnActivateAsync(Id).Wait();
         }
 

tests/Squidex.Domain.Apps.Entities.Tests/Rules/RuleDequeuerTests.cs

@@ -22,7 +22,7 @@ namespace Squidex.Domain.Apps.Entities.Rules
     public class RuleDequeuerTests
     {
         private readonly IClock clock = A.Fake<IClock>();
-        private readonly ISemanticLog log = A.Fake<ISemanticLog>();
+        private readonly ISemanticLog log = A.Dummy<ISemanticLog>();
         private readonly IAppProvider appProvider = A.Fake<IAppProvider>();
         private readonly IRuleEventRepository ruleEventRepository = A.Fake<IRuleEventRepository>();
         private readonly Instant now = SystemClock.Instance.GetCurrentInstant();

tests/Squidex.Domain.Apps.Entities.Tests/Rules/RuleGrainTests.cs

@@ -17,6 +17,7 @@ using Squidex.Domain.Apps.Entities.TestHelpers;
 using Squidex.Domain.Apps.Events.Rules;
 using Squidex.Infrastructure;
 using Squidex.Infrastructure.Commands;
+using Squidex.Infrastructure.Log;
 using Xunit;
 
 namespace Squidex.Domain.Apps.Entities.Rules
@@ -34,7 +35,7 @@ namespace Squidex.Domain.Apps.Entities.Rules
 
         public RuleGrainTests()
         {
-            sut = new RuleGrain(Store, appProvider);
+            sut = new RuleGrain(Store, A.Dummy<ISemanticLog>(), appProvider);
             sut.OnActivateAsync(Id).Wait();
         }
 

tests/Squidex.Domain.Apps.Entities.Tests/Schemas/SchemaGrainTests.cs

@@ -17,6 +17,7 @@ using Squidex.Domain.Apps.Entities.TestHelpers;
 using Squidex.Domain.Apps.Events.Schemas;
 using Squidex.Infrastructure;
 using Squidex.Infrastructure.Commands;
+using Squidex.Infrastructure.Log;
 using Xunit;
 
 namespace Squidex.Domain.Apps.Entities.Schemas
@@ -41,7 +42,7 @@ namespace Squidex.Domain.Apps.Entities.Schemas
 
             fieldId = new NamedId<long>(1, fieldName);
 
-            sut = new SchemaGrain(Store, appProvider, registry);
+            sut = new SchemaGrain(Store, A.Dummy<ISemanticLog>(), appProvider, registry);
             sut.OnActivateAsync(Id).Wait();
         }
 

tests/Squidex.Infrastructure.Tests/Commands/DomainObjectGrainTests.cs

@@ -11,6 +11,7 @@ using System.Linq;
 using System.Threading.Tasks;
 using FakeItEasy;
 using Squidex.Infrastructure.EventSourcing;
+using Squidex.Infrastructure.Log;
 using Squidex.Infrastructure.Orleans;
 using Squidex.Infrastructure.States;
 using Squidex.Infrastructure.TestHelpers;
@@ -60,7 +61,7 @@ namespace Squidex.Infrastructure.Commands
         public sealed class MyDomainObject : DomainObjectGrain<MyDomainState>
         {
             public MyDomainObject(IStore<Guid> store)
-               : base(store)
+               : base(store, A.Dummy<ISemanticLog>())
             {
             }
 

tests/Squidex.Infrastructure.Tests/TestHelpers/MyGrain.cs

@@ -7,7 +7,9 @@
 
 using System;
 using System.Threading.Tasks;
+using FakeItEasy;
 using Squidex.Infrastructure.Commands;
+using Squidex.Infrastructure.Log;
 using Squidex.Infrastructure.States;
 
 namespace Squidex.Infrastructure.TestHelpers
@@ -15,7 +17,7 @@ namespace Squidex.Infrastructure.TestHelpers
     public class MyGrain : DomainObjectGrain<MyDomainState>
     {
         public MyGrain(IStore<Guid> store)
-            : base(store)
+            : base(store, A.Dummy<ISemanticLog>())
         {
         }