/// <summary> /// Configure event replaying when a timed scope ends /// </summary> /// <param name="scope"></param> public void ConfigureReplayEventsOnScopeEnd(TimedScope scope) { CorrelationData currentCorrelation = Correlation.CurrentCorrelation; if (scope.IsSuccessful ?? false) { // assumption is that if any lower level scopes fail that should bubble up to the parent scope; if replay is enabled a previous scope has failed so // log some telemetry to help us understand these mixed scenarios better / identify error handling bugs if (currentCorrelation != null && currentCorrelation.ShouldReplayUls) { // ASSERTTAG_IGNORE_START ULSLogging.LogTraceTag(0, Categories.TimingGeneral, Levels.Warning, "Scope '{0}' succeeded even though a previous scope on this correlation failed.", scope.Name); // ASSERTTAG_IGNORE_FINISH } } else { // flip the replay switch on Scope failure for scenarios where its useful to get a verbose ULS trace in production if (currentCorrelation != null && scope.Result.ShouldReplayEvents() && !scope.IsTransaction && !scope.ScopeDefinition.OnDemand && !scope.DisableVerboseUlsCapture && !DisabledTimedScopes.IsDisabled(scope.ScopeDefinition)) { currentCorrelation.ShouldReplayUls = true; currentCorrelation.ReplayPreviouslyCachedUlsEvents(); } } }
public void FailedScope_ResultAndFailureDescription_ShouldOutputValueInLogEvent() { FailOnErrors = false; UnitTestTimedScopeLogger unitTestTimedScopeLogger = new UnitTestTimedScopeLogger(); Mock <IReplayEventConfigurator> replyEventConfiguratorMock = new Mock <IReplayEventConfigurator>(); Mock <ICallContextManager> callContextManagerMock = new Mock <ICallContextManager>(); IMachineInformation machineInformation = new UnitTestMachineInformation(); ITimedScopeStackManager timedScopeStackManager = new TimedScopeStackManager(callContextManagerMock.Object, machineInformation); using (TimedScope scope = TestHooks.CreateTestCountersUnitTestTimedScope(machineInformation: machineInformation, scopeLogger: unitTestTimedScopeLogger, replayEventConfigurator: replyEventConfiguratorMock.Object, timedScopeStackManager: timedScopeStackManager)) { scope.Result = TimedScopeResult.ExpectedError; scope.FailureDescription = UnitTestFailureDescription.ExampleDescription; } TimedScopeLogEvent scopeEvent = unitTestTimedScopeLogger.Events.SingleOrDefault(); if (VerifyNotNullAndReturn(scopeEvent, "Scope end event should be logged")) { Assert.Equal(scopeEvent.Result, TimedScopeResult.ExpectedError); Assert.Equal(scopeEvent.FailureDescription, UnitTestFailureDescription.ExampleDescription.ToString()); } }
public void DefaultTimedScopeResult_LogsAsSystemError() { LoggedEvents.Clear(); CorrelationData data = new CorrelationData(); UnitTestTimedScopeLogger unitTestTimedScopeLogger = new UnitTestTimedScopeLogger(); Mock <IReplayEventConfigurator> replyEventConfiguratorMock = new Mock <IReplayEventConfigurator>(); Mock <ICallContextManager> callContextManagerMock = new Mock <ICallContextManager>(); IMachineInformation machineInformation = new UnitTestMachineInformation(); ITimedScopeStackManager timedScopeStackManager = new TimedScopeStackManager(callContextManagerMock.Object, machineInformation); using (TimedScope.Create(data, machineInformation, TestHooks.DefaultTimedScopeName, "description", unitTestTimedScopeLogger, replyEventConfiguratorMock.Object, timedScopeStackManager, default(TimedScopeResult))) { } TimedScopeLogEvent evt = unitTestTimedScopeLogger.SingleTimedScopeEvent(TestHooks.DefaultTimedScopeName); if (VerifyNotNullAndReturn(evt, "A scope event has been logged")) { Assert.Equal(TimedScopeResult.SystemError, evt.Result); } }
public void End_WithDisposedTimedScope_ShouldLogError() { FailOnErrors = false; Mock <ITimedScopeLogger> timedScopeLoggerMock = new Mock <ITimedScopeLogger>(); Mock <IReplayEventConfigurator> replyEventConfiguratorMock = new Mock <IReplayEventConfigurator>(); Mock <ICallContextManager> callContextManagerMock = new Mock <ICallContextManager>(); IMachineInformation machineInformation = new UnitTestMachineInformation(); ITimedScopeStackManager timedScopeStackManager = new TimedScopeStackManager(callContextManagerMock.Object, machineInformation); using (TimedScope scope = TestHooks.CreateDefaultTimedScope(timedScopeLoggerMock.Object, replyEventConfiguratorMock.Object, machineInformation, timedScopeStackManager)) { Assert.True(scope.IsScopeActive, "Timer should be active."); scope.Dispose(); Assert.False(scope.IsScopeActive, "Dispose should turn off timer."); scope.End(); Assert.Equal(TraceErrors.Count(), 1); LoggedEvents.Clear(); } }
/// <summary> /// Logs the scope end /// </summary> /// <param name="scope">Scope to log</param> /// <param name="data">Correlation data</param> public void LogScopeEnd(TimedScope scope, CorrelationData data) { if (!Code.ValidateArgument(scope, nameof(scope), TaggingUtilities.ReserveTag(0x2375d3d8 /* tag_933py */)) || !Code.ValidateArgument(data, nameof(data), TaggingUtilities.ReserveTag(0x2375d3d9 /* tag_933pz */))) { return; } if (scope.IsTransaction) { m_eventSource.LogEvent(Categories.TimingGeneral, name: scope.Name, subtype: scope.SubType ?? NullPlaceholder, metadata: scope.MetaData ?? NullPlaceholder, serviceName: ServiceName ?? NullPlaceholder, result: scope.Result, correlationId: data.VisibleId.ToString("D", CultureInfo.InvariantCulture), durationMs: scope.DurationInMilliseconds); } else { m_eventSource.LogEvent(Categories.TimingGeneral, name: scope.Name, subtype: scope.SubType ?? NullPlaceholder, metadata: scope.MetaData ?? NullPlaceholder, serviceName: ServiceName ?? NullPlaceholder, userHash: data.Data(TimedScopeDataKeys.InternalOnly.UserHash) ?? data.UserHash ?? NullPlaceholder, result: scope.Result, correlationId: data.VisibleId.ToString("D", CultureInfo.InvariantCulture), durationMs: scope.DurationInMilliseconds); } }
public void SuccessTimedScope_DoesntReplayLogs() { Mock <ITimedScopeLogger> timedScopeLoggerMock = new Mock <ITimedScopeLogger>(); Mock <IReplayEventConfigurator> replyEventConfiguratorMock = new Mock <IReplayEventConfigurator>(); Correlation = new Correlation(new MemoryCorrelationHandler(), CallContextManagerInstance, MachineInformation); Correlation.CorrelationStart(new CorrelationData()); IMachineInformation machineInformation = new UnitTestMachineInformation(); ITimedScopeStackManager timedScopeStackManager = new TimedScopeStackManager(CallContextManagerInstance, machineInformation); CorrelationData currentCorrelation = Correlation.CurrentCorrelation; Assert.False(currentCorrelation.ShouldReplayUls); using (TimedScope scope = TimedScope.Start(currentCorrelation, MachineInformation, "TestScope", customLogger: timedScopeLoggerMock.Object, replayEventConfigurator: replyEventConfiguratorMock.Object, timedScopeStackManager: timedScopeStackManager)) { scope.Result = TimedScopeResult.Success; Mock <IReplayEventDisabledTimedScopes> disabledScopes = new Mock <IReplayEventDisabledTimedScopes>(); disabledScopes.Setup(x => x.IsDisabled(scope.ScopeDefinition)).Returns(false); ReplayEventConfigurator configurator = new ReplayEventConfigurator(disabledScopes.Object, Correlation); configurator.ConfigureReplayEventsOnScopeEnd(scope); } Assert.False(currentCorrelation.ShouldReplayUls); }
private void TestExecution( string scopeName, Action <Task <bool>, ITimedScopeProvider, TimedScopeDefinition> createTask, Action <TaskCompletionSource <bool> > finishTask, TimedScopeResult expectedResult) { Mock <ITimedScopeProvider> providerMock = new Mock <ITimedScopeProvider>(); TimedScopeDefinition timedScopeDefinition = new TimedScopeDefinition(scopeName); Activity activity = new Activity(scopeName); TimedScope scope = new TimedScope(activity, TimedScopeResult.SystemError); providerMock.Setup(p => p.CreateAndStart(timedScopeDefinition, TimedScopeResult.SystemError)).Returns(scope); TaskCompletionSource <bool> taskCompletionSource = new TaskCompletionSource <bool>(); createTask(taskCompletionSource.Task, providerMock.Object, timedScopeDefinition); providerMock.Verify(p => p.CreateAndStart(timedScopeDefinition, TimedScopeResult.SystemError), Times.Once); scope.Activity.AssertResult(TimedScopeResult.SystemError); finishTask(taskCompletionSource); scope.Activity.AssertResult(expectedResult); }
public void AddLoggingValue_ShouldOutputValueInLogEvent() { Mock <ITimedScopeLogger> timedScopeLoggerMock = new Mock <ITimedScopeLogger>(); Mock <IReplayEventConfigurator> replyEventConfiguratorMock = new Mock <IReplayEventConfigurator>(); Mock <ICallContextManager> callContextManagerMock = new Mock <ICallContextManager>(); IMachineInformation machineInformation = new UnitTestMachineInformation(); ITimedScopeStackManager timedScopeStackManager = new TimedScopeStackManager(callContextManagerMock.Object, machineInformation); using (TimedScope scope = TestHooks.CreateTestCountersUnitTestTimedScope(machineInformation: machineInformation, scopeLogger: timedScopeLoggerMock.Object, replayEventConfigurator: replyEventConfiguratorMock.Object, timedScopeStackManager: timedScopeStackManager)) { scope.AddLoggingValue(TimedScopeDataKeys.Category, "MyCategory"); scope.End(); // There should be one 'Ending' transaction log call with formatted output foreach (LogEventArgs args in LoggedEvents) { if (args.CategoryId == Categories.TimingGeneral) { if (args.FullMessage.Contains("Ending timed scope")) { Assert.Contains("Category:'MyCategory';", args.FullMessage, StringComparison.Ordinal); } } } } }
public void FailedTimedScope_ShouldReplayLogs() { Mock<ITimedScopeLogger> timedScopeLoggerMock = new Mock<ITimedScopeLogger>(); Mock<IReplayEventConfigurator> replyEventConfiguratorMock = new Mock<IReplayEventConfigurator>(); Mock<ILogEventCache> mockCache = new Mock<ILogEventCache>(); Correlation = new Correlation(new MemoryCorrelationHandler(), CallContextManagerInstance, MachineInformation); Correlation.CorrelationStart(new CorrelationData(mockCache.Object)); IMachineInformation machineInformation = new UnitTestMachineInformation(); ITimedScopeStackManager timedScopeStackManager = new TimedScopeStackManager(CallContextManagerInstance, machineInformation); CorrelationData currentCorrelation = Correlation.CurrentCorrelation; Assert.False(currentCorrelation.ShouldReplayUls, "Logs shouldn't be replayed"); using (TimedScope scope = TestHooks.CreateDefaultTimedScope( timedScopeLoggerMock.Object, replyEventConfiguratorMock.Object, machineInformation, timedScopeStackManager, startScope: true)) { scope.Result = TimedScopeResult.SystemError; Mock<IReplayEventDisabledTimedScopes> disabledScopes = new Mock<IReplayEventDisabledTimedScopes>(); disabledScopes.Setup(x => x.IsDisabled(scope.ScopeDefinition)).Returns(false); ReplayEventConfigurator configurator = new ReplayEventConfigurator(disabledScopes.Object, Correlation); configurator.ConfigureReplayEventsOnScopeEnd(scope); } Assert.True(currentCorrelation.ShouldReplayUls, "Logs should be replayed"); }
public void Stop_WhenCalledMultipleTimes_IgnoresSuperfluousCalls() { TimedScope scope = CreateTimedScope(); scope.Start(); scope.Stop(); scope.Stop(); }
public void MarkAsHealthCheck_SetsValue() { TimedScope scope1 = CreateScope("MarkAsHealthCheckTest1").MarkAsHealthCheck(); TimedScope scope2 = CreateScope("MarkAsHealthCheckTest2"); Assert.IsTrue(scope1.Activity.IsHealthCheck()); Assert.IsFalse(scope2.Activity.IsHealthCheck()); }
public void CreateAndStart_TimedScopeCreated() { TimedScopeResult result = TimedScopeResult.ExpectedError; TimedScopeDefinition definition = new TimedScopeDefinition(nameof(CreateAndStart_TimedScopeCreated)); SimpleScopeProvider provider = new SimpleScopeProvider(); TimedScope scope = provider.CreateAndStart(definition, result); Assert.IsNotNull(scope); }
public async Task <LoggerResult> SaveProject() { if (PackageSession == null) { throw new InvalidOperationException("Cannot save the project before it was loaded."); } // TODO: check asset consistency // TODO: read more about Stride.Core.Assets.Editor.PackageViewModel //// Prepare packages to be saved by setting their dirty flag correctly //foreach (var package in LocalPackages) //{ // package.PreparePackageForSaving(); //} var viewUpdater = Services.GetService <IViewUpdater>(); PackageSessionResult sessionResult = await SetupResultProgress(viewUpdater, SaveProjectScope); // TODO: display a dialog with save progress // Force PackageSession.Save to be executed on the thread pool // otherwise it would block execution and we want this process to be async using (var scope = new TimedScope(SaveProjectScope, TimedScope.Status.Success)) { await Task.Run(() => { try { var saveParameters = PackageSaveParameters.Default(); // TODO: read more about Stride.Core.Assets.Editor.AssetViewModel // AllAssets.ForEach(x => x.PrepareSave(sessionResult)); PackageSession.Save(sessionResult, saveParameters); } catch (Exception e) { sessionResult.Error(string.Format("There was a problem saving the solution. {0}", e.Message), e); scope.Result = TimedScope.Status.Failure; } }); if (sessionResult.HasErrors) { scope.Result = TimedScope.Status.Failure; } } EditorViewModel.LoadingStatus = null; await viewUpdater.UpdateView(); ProjectSaved?.Invoke(sessionResult); return(sessionResult); }
public MainWindow() { this.InitializeComponent(); #if DEBUG this.AttachDevTools(); #endif using var initScope = new TimedScope(LoggingScope.Global($"{nameof(MainWindow)}.InitializeServices")); Session = new Session(); var menuProvider = new MenuProvider(); Services.AddService <IMenuProvider>(menuProvider); Session.EditorViewModel = new EditorViewModel(menuProvider); Session.Services = Services; Services.AddService <Window>(this); Services.AddService <Session>(Session); Services.AddService <IRootViewModelContainer>(Session); Services.AddService <ViewRegistry>(new ViewRegistry()); Services.AddService <IDialogService>(new DialogService(Services)); var viewDataTemplate = new ViewDataTemplate(Services); Services.AddService <IViewUpdater>(viewDataTemplate); DataTemplates.Add(viewDataTemplate); Services.AddService <IUndoService>(new UndoService()); Services.AddService <IMemberViewProvider <IViewBuilder> >(new MemberViewProvider(Services)); var commandDispatcher = new CommandDispatcher(Services); Services.AddService <ICommandDispatcher>(commandDispatcher); // after all synchronous code caused by user input has been executed // we begin the commands processing. InputManager.Instance.PostProcess.Subscribe(async(e) => await commandDispatcher.ProcessDispatchedCommands()); var tabManager = new SimpleTabManager(Services); Services.AddService <ITabManager>(tabManager); Services.AddService <SimpleTabManager>(tabManager); var assetManager = new AssetManager(Services); Services.AddService <IAssetManager>(assetManager); Services.AddService <IAssetEditorRegistry>(assetManager); var pluginRegistry = new PluginRegistry(Services); pluginRegistry.RefreshAvailablePlugins(); Services.AddService <PluginRegistry>(pluginRegistry); foreach (var initialPlugin in pluginRegistry.AvailablePlugins) { pluginRegistry.Register(initialPlugin); } // It will be rendered by the DataTemplate DataContext = Session.EditorViewModel; }
public void SetResult_SetsValue(TimedScopeResult result) { TimedScope scope1 = CreateScope("SetResultTest1"); TimedScope scope2 = CreateScope("SetResultTest2"); scope1.SetResult(result); scope1.Activity.AssertResult(result); scope2.Activity.AssertResult(TimedScopeResult.SystemError); }
public void Start_StartsActivity() { TimedScope scope = CreateTimedScope(); Assert.IsNull(scope.Activity.Id); scope.Start(); Assert.IsNotNull(scope.Activity.Id); }
public static string ToString(TimedScope timedScope) { return (string .Format( "{0} took {1}\n{2}", timedScope.Description, ToString(timedScope.TimeElapsed), timedScope.StackTrace.ToString() )); }
public void SetMetadata_SetsValue() { TimedScope scope1 = CreateScope("SetMetadataTest1"); TimedScope scope2 = CreateScope("SetMetadataTest2"); string value = "Some metadata"; scope1.SetMetadata(value); Assert.AreEqual(value, scope1.Activity.GetTag(ActivityTagKeys.Metadata)); Assert.IsNull(scope2.Activity.GetTag(ActivityTagKeys.Metadata)); }
public void Dispose_WhenCalledMultipleTimes_IgnoresSuperfluousCalls() { TimedScope scope = CreateTimedScope(); scope.Start(); IDisposable disposable = scope; disposable.Dispose(); disposable.Dispose(); }
/// <summary> /// Creates a default timed scope. /// </summary> /// <param name="scopeLogger">Custom logger</param> /// <param name="replayEventConfigurator">Reply event configurator</param> /// <param name="machineInformation">Machine information</param> /// <param name="timedScopeStackManager">Timed scope stack manager</param> /// <param name="initialResult">Initial scope result.</param> /// <param name="startScope">Start scope implicitly.</param> /// <returns>The created scope.</returns> public static TimedScope CreateDefaultTimedScope( ITimedScopeLogger scopeLogger = null, IReplayEventConfigurator replayEventConfigurator = null, IMachineInformation machineInformation = null, ITimedScopeStackManager timedScopeStackManager = null, bool?initialResult = null, bool startScope = true) { return(CreateTimedScopeProvider(machineInformation, scopeLogger, replayEventConfigurator, timedScopeStackManager) .Create(UnitTestTimedScopes.DefaultScope, TimedScope.ConvertBoolResultToTimedScopeResult(initialResult), startScope)); }
public void SetSubType_SetsValue() { TimedScope scope1 = CreateScope("SetSubTypeTest1"); TimedScope scope2 = CreateScope("SetSubTypeTest2"); string value = "Some sub type"; scope1.SetSubType(value); Assert.AreEqual(value, scope1.Activity.GetTag(ActivityTagKeys.SubType)); Assert.IsNull(scope2.Activity.GetTag(ActivityTagKeys.SubType)); }
private TimedScope CreateTimedScope() { Activity activity = new Activity("TestName"); TimedScopeResult result = TimedScopeResult.Success; TimedScope scope = new TimedScope(activity, result); Assert.AreEqual(activity, scope.Activity); scope.Activity.AssertResult(result); return(scope); }
/// <summary> /// Logs the scope end /// </summary> /// <param name="scope">Scope to log</param> /// <param name="data">Correlation data</param> public void LogScopeEnd(TimedScope scope, CorrelationData data) { if (scope == null) { return; } TimedScopeLogEvent evt = new TimedScopeLogEvent(scope.Name, scope.SubType, scope.MetaData, scope.Result, scope.FailureDescription, data.Data(TimedScopeDataKeys.InternalOnly.UserHash), scope.Duration ?? TimeSpan.Zero); m_events.Enqueue(evt); }
public static TimedScope Create(this TimedScopeDefinition timedScopeDefinition, TimedScopeResult initialResult, bool startScope = true) { if (s_timedScopeProvider == null) { throw new OmexCompatibilityInitializationException(); } TimedScope scope = s_timedScopeProvider.Create(timedScopeDefinition, initialResult); if (startScope) { scope.Start(); } return(scope); }
private void CreateAndValidateActivity(string activityName) { TimedScopeResult result = TimedScopeResult.ExpectedError; Mock <IActivityProvider> activityProviderMock = new Mock <IActivityProvider>(); Mock <Activity> activityMock = new Mock <Activity>(activityName); TimedScopeDefinition definition = new TimedScopeDefinition(activityName); activityProviderMock.Setup(p => p.Create(definition)).Returns(activityMock.Object); TimedScopeProvider provider = new TimedScopeProvider(activityProviderMock.Object); TimedScope scope = provider.CreateAndStart(definition, result); Assert.IsNotNull(scope); }
public void SimpleTimeCheckFromRef() { Stopwatch stopwatch = new Stopwatch(); stopwatch.Start(); double timedScopeTime = 0; using (TimedScope.FromRef(ref timedScopeTime)) { Thread.Sleep(k_MillisecondsTimeout); } stopwatch.Stop(); double stopWatchTime = stopwatch.Elapsed.TotalMilliseconds; Assert.AreEqual(stopWatchTime, timedScopeTime, k_TimeComparisonDelta); }
/// <inheritdoc /> public async Task <HealthCheckResult> CheckHealthAsync(HealthCheckContext context, CancellationToken token = default) { using TimedScope scope = m_scopeProvider.CreateAndStart(s_scopeDefinition).MarkAsHealthCheck(); try { HealthCheckResult result = await CheckHealthInternalAsync(context, token).ConfigureAwait(false); scope.SetResult(TimedScopeResult.Success); return(result); } catch (Exception exception) { Logger.LogError(Tag.Create(), exception, "'{0}' check failed with exception", context.Registration.Name); return(HealthCheckResult.Unhealthy("HealthCheck failed", exception)); } }
public void AbortTimer_ShouldDisableTimerActive() { Mock <ITimedScopeLogger> timedScopeLoggerMock = new Mock <ITimedScopeLogger>(); Mock <IReplayEventConfigurator> replyEventConfiguratorMock = new Mock <IReplayEventConfigurator>(); Mock <ICallContextManager> callContextManagerMock = new Mock <ICallContextManager>(); IMachineInformation machineInformation = new UnitTestMachineInformation(); ITimedScopeStackManager timedScopeStackManager = new TimedScopeStackManager(callContextManagerMock.Object, machineInformation); using (TimedScope scope = TestHooks.CreateDefaultTimedScope(timedScopeLoggerMock.Object, replyEventConfiguratorMock.Object, machineInformation: machineInformation, timedScopeStackManager: timedScopeStackManager)) { Assert.True(scope.IsScopeActive, "Default scope should have timer active."); scope.AbortTimer(); Assert.False(scope.IsScopeActive, "Aborting timer should stop timer."); } }
public void Create_ShouldConstructTimedScope_WithTimerInactive() { Mock <ITimedScopeLogger> timedScopeLoggerMock = new Mock <ITimedScopeLogger>(); Mock <IReplayEventConfigurator> replyEventConfiguratorMock = new Mock <IReplayEventConfigurator>(); Mock <ICallContextManager> callContextManagerMock = new Mock <ICallContextManager>(); IMachineInformation machineInformation = new UnitTestMachineInformation(); ITimedScopeStackManager timedScopeStackManager = new TimedScopeStackManager(callContextManagerMock.Object, machineInformation); using (TimedScope scope = TestHooks.CreateTestCountersUnitTestTimedScope(true, false, machineInformation, timedScopeLoggerMock.Object, replyEventConfiguratorMock.Object, timedScopeStackManager)) { Assert.False(scope.IsScopeActive, "Creating a scope should not start the timer."); Assert.True(scope.IsSuccessful.HasValue, "IsSuccessful should be set."); Assert.True(scope.IsSuccessful.Value, "IsSuccessful should be set to true."); } }
public void AddLoggingValue_WithNullKey_ShouldLogError() { FailOnErrors = false; Mock <ITimedScopeLogger> timedScopeLoggerMock = new Mock <ITimedScopeLogger>(); Mock <IReplayEventConfigurator> replyEventConfiguratorMock = new Mock <IReplayEventConfigurator>(); Mock <ICallContextManager> callContextManagerMock = new Mock <ICallContextManager>(); IMachineInformation machineInformation = new UnitTestMachineInformation(); ITimedScopeStackManager timedScopeStackManager = new TimedScopeStackManager(callContextManagerMock.Object, machineInformation); using (TimedScope scope = TestHooks.CreateDefaultTimedScope(timedScopeLoggerMock.Object, replyEventConfiguratorMock.Object, machineInformation, timedScopeStackManager)) { scope.AddLoggingValue(null, "My Application."); Assert.Equal(TraceErrors.Count(), 1); LoggedEvents.Clear(); } }