From 23ed9773bc9b941369e28cb2f92b981a940b3898 Mon Sep 17 00:00:00 2001 From: Warren Date: Tue, 14 Aug 2018 22:36:47 +0100 Subject: [PATCH] FIRST PASS - Updates Umbraco.Web project to not use the func overload & to use new message template instead --- .../Editors/AuthenticationController.cs | 9 +-- .../Editors/ContentTypeController.cs | 2 +- .../Editors/DashboardController.cs | 4 +- .../Editors/PackageInstallController.cs | 2 +- src/Umbraco.Web/Editors/PasswordChanger.cs | 4 +- .../HealthCheck/HealthCheckResults.cs | 6 +- src/Umbraco.Web/Macros/MacroRenderer.cs | 6 +- .../Macros/UserControlMacroEngine.cs | 10 +-- ...taTypeConfigurationFieldDisplayResolver.cs | 2 +- .../Models/Mapping/MacroMapperProfile.cs | 2 +- src/Umbraco.Web/Mvc/RenderRouteHandler.cs | 7 +- .../RelatedLinksValueConverter.cs | 4 +- .../PublishedCache/NuCache/ContentStore.cs | 13 ++-- .../NuCache/DataSource/DatabaseDataSource.cs | 4 +- .../NuCache/PublishedSnapshotService.cs | 29 ++++--- .../PublishedContentTypeCache.cs | 6 +- .../DictionaryPublishedContent.cs | 2 +- .../XmlPublishedCache/PublishedMediaCache.cs | 7 +- .../XmlPublishedCache/XmlStore.cs | 18 +++-- .../XmlStoreFilePersister.cs | 6 +- .../Routing/ContentFinderByIdPath.cs | 4 +- .../Routing/ContentFinderByLegacy404.cs | 2 +- .../Routing/ContentFinderByRedirectUrl.cs | 6 +- src/Umbraco.Web/Routing/ContentFinderByUrl.cs | 4 +- .../Routing/ContentFinderByUrlAlias.cs | 2 +- .../Routing/ContentFinderByUrlAndTemplate.cs | 6 +- src/Umbraco.Web/Routing/DefaultUrlProvider.cs | 3 +- src/Umbraco.Web/Routing/PublishedRouter.cs | 75 +++++++++---------- .../Scheduling/BackgroundTaskRunner.cs | 25 ++++--- .../Scheduling/SchedulerComponent.cs | 2 +- src/Umbraco.Web/Search/ExamineComponent.cs | 4 +- src/Umbraco.Web/Security/MembershipHelper.cs | 2 +- .../Providers/UmbracoMembershipProvider.cs | 22 ++---- .../Services/ApplicationTreeService.cs | 2 +- src/Umbraco.Web/UmbracoModule.cs | 9 ++- 35 files changed, 159 insertions(+), 152 deletions(-) diff --git a/src/Umbraco.Web/Editors/AuthenticationController.cs b/src/Umbraco.Web/Editors/AuthenticationController.cs index 89f80091c8..3def722738 100644 --- a/src/Umbraco.Web/Editors/AuthenticationController.cs +++ b/src/Umbraco.Web/Editors/AuthenticationController.cs @@ -406,20 +406,19 @@ namespace Umbraco.Web.Editors var lockedOut = await UserManager.IsLockedOutAsync(model.UserId); if (lockedOut) { - Logger.Info(() => - $"User {model.UserId} is currently locked out, unlocking and resetting AccessFailedCount"); + Logger.Info("User {UserId} is currently locked out, unlocking and resetting AccessFailedCount", model.UserId); //var user = await UserManager.FindByIdAsync(model.UserId); var unlockResult = await UserManager.SetLockoutEndDateAsync(model.UserId, DateTimeOffset.Now); if (unlockResult.Succeeded == false) { - Logger.Warn(() => $"Could not unlock for user {model.UserId} - error {unlockResult.Errors.First()}"); + Logger.Warn("Could not unlock for user {UserId} - error {UnlockError}", model.UserId, unlockResult.Errors.First()); } var resetAccessFailedCountResult = await UserManager.ResetAccessFailedCountAsync(model.UserId); if (resetAccessFailedCountResult.Succeeded == false) { - Logger.Warn(() => $"Could not reset access failed count {model.UserId} - error {unlockResult.Errors.First()}"); + Logger.Warn("Could not reset access failed count {UserId} - error {UnlockError}", model.UserId, unlockResult.Errors.First()); } } @@ -445,7 +444,7 @@ namespace Umbraco.Web.Editors Core.Constants.Security.BackOfficeAuthenticationType, Core.Constants.Security.BackOfficeExternalAuthenticationType); - Logger.Info(() => $"User {(User.Identity == null ? "UNKNOWN" : User.Identity.Name)} from IP address {owinContext.Request.RemoteIpAddress} has logged out"); + Logger.Info("User {UserName} from IP address {RemoteIpAddress} has logged out", User.Identity == null ? "UNKNOWN" : User.Identity.Name, owinContext.Request.RemoteIpAddress); if (UserManager != null) { diff --git a/src/Umbraco.Web/Editors/ContentTypeController.cs b/src/Umbraco.Web/Editors/ContentTypeController.cs index 79079265af..ac58177625 100644 --- a/src/Umbraco.Web/Editors/ContentTypeController.cs +++ b/src/Umbraco.Web/Editors/ContentTypeController.cs @@ -278,7 +278,7 @@ namespace Umbraco.Web.Editors var tryCreateTemplate = Services.FileService.CreateTemplateForContentType(ctSave.Alias, ctSave.Name); if (tryCreateTemplate == false) { - Logger.Warn(() => $"Could not create a template for the Content Type: {ctSave.Alias}, status: {tryCreateTemplate.Result.Result}"); + Logger.Warn("Could not create a template for the Content Type: {ContentTypeAlias}, status: {CreateTemplateResult}", ctSave.Alias, tryCreateTemplate.Result.Result); } template = tryCreateTemplate.Result.Entity; } diff --git a/src/Umbraco.Web/Editors/DashboardController.cs b/src/Umbraco.Web/Editors/DashboardController.cs index 6b71eb0ead..3faa30d084 100644 --- a/src/Umbraco.Web/Editors/DashboardController.cs +++ b/src/Umbraco.Web/Editors/DashboardController.cs @@ -66,7 +66,7 @@ namespace Umbraco.Web.Editors } catch (HttpRequestException ex) { - Logger.Debug(() => $"Error getting dashboard content from '{url}': {ex.Message}\n{ex.InnerException}"); + Logger.Error("Error getting dashboard content from '{Url}'", ex.InnerException ?? ex, url); //it's still new JObject() - we return it like this to avoid error codes which triggers UI warnings ApplicationCache.RuntimeCache.InsertCacheItem(key, () => result, new TimeSpan(0, 5, 0)); @@ -107,7 +107,7 @@ namespace Umbraco.Web.Editors } catch (HttpRequestException ex) { - Logger.Debug(() => string.Format("Error getting dashboard CSS from '{0}': {1}\n{2}", url, ex.Message, ex.InnerException)); + Logger.Error("Error getting dashboard CSS from '{Url}'", ex.InnerException ?? ex, url); //it's still string.Empty - we return it like this to avoid error codes which triggers UI warnings ApplicationCache.RuntimeCache.InsertCacheItem(key, () => result, new TimeSpan(0, 5, 0)); diff --git a/src/Umbraco.Web/Editors/PackageInstallController.cs b/src/Umbraco.Web/Editors/PackageInstallController.cs index fec358f113..3c6cd9f46d 100644 --- a/src/Umbraco.Web/Editors/PackageInstallController.cs +++ b/src/Umbraco.Web/Editors/PackageInstallController.cs @@ -188,7 +188,7 @@ namespace Umbraco.Web.Editors var actionsXml = new XmlDocument(); actionsXml.LoadXml("" + pack.Data.Actions + ""); - Logger.Debug(() => $"executing undo actions: {actionsXml.OuterXml}"); + Logger.Debug("Executing undo actions: {UndoActionsXml}", actionsXml.OuterXml); foreach (XmlNode n in actionsXml.DocumentElement.SelectNodes("//Action")) { diff --git a/src/Umbraco.Web/Editors/PasswordChanger.cs b/src/Umbraco.Web/Editors/PasswordChanger.cs index 44042352bb..5034ce1950 100644 --- a/src/Umbraco.Web/Editors/PasswordChanger.cs +++ b/src/Umbraco.Web/Editors/PasswordChanger.cs @@ -93,7 +93,7 @@ namespace Umbraco.Web.Editors if (resetResult.Succeeded == false) { var errors = string.Join(". ", resetResult.Errors); - _logger.Warn(() => $"Could not reset user password {errors}"); + _logger.Warn("Could not reset user password {PasswordErrors}", errors); return Attempt.Fail(new PasswordChangedModel { ChangeError = new ValidationResult("Could not reset password, errors: " + errors, new[] { "resetPassword" }) }); } @@ -122,7 +122,7 @@ namespace Umbraco.Web.Editors if (changeResult.Succeeded == false) { var errors = string.Join(". ", changeResult.Errors); - _logger.Warn(() => $"Could not change user password {errors}"); + _logger.Warn("Could not change user password {PasswordErrors}", errors); return Attempt.Fail(new PasswordChangedModel { ChangeError = new ValidationResult("Could not change password, errors: " + errors, new[] { "oldPassword" }) }); } return Attempt.Succeed(new PasswordChangedModel()); diff --git a/src/Umbraco.Web/HealthCheck/HealthCheckResults.cs b/src/Umbraco.Web/HealthCheck/HealthCheckResults.cs index 74b44ea7b8..6baccf5808 100644 --- a/src/Umbraco.Web/HealthCheck/HealthCheckResults.cs +++ b/src/Umbraco.Web/HealthCheck/HealthCheckResults.cs @@ -62,16 +62,16 @@ namespace Umbraco.Web.HealthCheck var checkIsSuccess = result.Value.All(x => x.ResultType == StatusResultType.Success); if (checkIsSuccess) { - Logger.Info(() => $" Checks for '{checkName}' all completed succesfully."); + Logger.Info("Checks for '{HealthCheckName}' all completed succesfully.", checkName); } else { - Logger.Warn(() => $" Checks for '{checkName}' completed with errors."); + Logger.Warn("Checks for '{HealthCheckName}' completed with errors.", checkName); } foreach (var checkResult in checkResults) { - Logger.Info(() => $" Result: {checkResult.ResultType}, Message: '{checkResult.Message}'"); + Logger.Info("Result for {HealthCheckName}: {HealthCheckResult}, Message: '{HealthCheckMessage}'", checkName, checkResult.ResultType, checkResult.Message); } } } diff --git a/src/Umbraco.Web/Macros/MacroRenderer.cs b/src/Umbraco.Web/Macros/MacroRenderer.cs index cf8dcb76d5..c6972a0067 100644 --- a/src/Umbraco.Web/Macros/MacroRenderer.cs +++ b/src/Umbraco.Web/Macros/MacroRenderer.cs @@ -99,7 +99,7 @@ namespace Umbraco.Web.Macros if (macroContent == null) return null; - Current.Logger.Debug(() => $"Macro content loaded from cache \"{model.CacheIdentifier}\"."); + Current.Logger.Debug("Macro content loaded from cache '{MacroCacheId}'", model.CacheIdentifier); // ensure that the source has not changed // note: does not handle dependencies, and never has @@ -159,7 +159,7 @@ namespace Umbraco.Web.Macros priority: CacheItemPriority.NotRemovable ); - Current.Logger.Debug(() => $"Macro content saved to cache \"{model.CacheIdentifier}\"."); + Current.Logger.Debug("Macro content saved to cache '{MacroCacheId}'", model.CacheIdentifier); } // gets the macro source file name @@ -304,7 +304,7 @@ namespace Umbraco.Web.Macros { Exceptions.Add(e); - _plogger.Logger.Warn(e, () => $"Failed {msgIn}"); + _plogger.Logger.Warn(e, "Failed {MsgIn}", msgIn); var macroErrorEventArgs = new MacroErrorEventArgs { diff --git a/src/Umbraco.Web/Macros/UserControlMacroEngine.cs b/src/Umbraco.Web/Macros/UserControlMacroEngine.cs index e6cf497b3d..12730c1d1d 100644 --- a/src/Umbraco.Web/Macros/UserControlMacroEngine.cs +++ b/src/Umbraco.Web/Macros/UserControlMacroEngine.cs @@ -31,7 +31,7 @@ namespace Umbraco.Web.Macros // note: we are not setting the 'CurrentNode' property on the control anymore, // as that was an INode which is gone in v8. Use UmbracoContext to access the // current content. - Current.Logger.Info(() => $"Loaded control \"{filename}\" with ID \"{control.ID}\"."); + Current.Logger.Info("Loaded control '{UserControlFile}' with ID '{UserControlId}'", filename, control.ID); UpdateControlProperties(control, model); return new MacroContent { Control = control }; @@ -64,7 +64,7 @@ namespace Umbraco.Web.Macros var controlProperty = type.GetProperty(modelProperty.Key); if (controlProperty == null) { - Current.Logger.Warn(() => $"Control property \"{modelProperty.Key}\" doesn't exist or isn't accessible, skip."); + Current.Logger.Warn("Control property '{UserControlProperty}' doesn't exist or isn't accessible, skip.", modelProperty.Key); continue; } @@ -74,16 +74,16 @@ namespace Umbraco.Web.Macros try { controlProperty.SetValue(control, tryConvert.Result, null); - Current.Logger.Debug(() => $"Set property \"{modelProperty.Key}\" value \"{modelProperty.Value}\"."); + Current.Logger.Debug("Set property '{UserControlProperty}' value '{UserControlPropertyValue}'", modelProperty.Key, modelProperty.Value); } catch (Exception e) { - Current.Logger.Warn(e, () => $"Failed to set property \"{modelProperty.Key}\" value \"{modelProperty.Value}\"."); + Current.Logger.Warn(e, "Failed to set property '{UserControlProperty}' value '{UserControlPropertyValue}'", modelProperty.Key, modelProperty.Value); } } else { - Current.Logger.Warn(() => $"Failed to set property \"{modelProperty.Key}\" value \"{modelProperty.Value}\"."); + Current.Logger.Warn("Failed to set property '{UserControlProperty}' value '{UserControlPropertyValue}'", modelProperty.Key, modelProperty.Value); } } } diff --git a/src/Umbraco.Web/Models/Mapping/DataTypeConfigurationFieldDisplayResolver.cs b/src/Umbraco.Web/Models/Mapping/DataTypeConfigurationFieldDisplayResolver.cs index d1838fc0f8..e262753b83 100644 --- a/src/Umbraco.Web/Models/Mapping/DataTypeConfigurationFieldDisplayResolver.cs +++ b/src/Umbraco.Web/Models/Mapping/DataTypeConfigurationFieldDisplayResolver.cs @@ -25,7 +25,7 @@ namespace Umbraco.Web.Models.Mapping if (configuration.TryGetValue(field.Key, out var value)) field.Value = value; else // weird - just leave the field without a value - but warn - Current.Logger.Warn(() => $"Could not find a value for configuration field \"{field.Key}\"."); + Current.Logger.Warn("Could not find a value for configuration field '{ConfigField}'", field.Key); } } diff --git a/src/Umbraco.Web/Models/Mapping/MacroMapperProfile.cs b/src/Umbraco.Web/Models/Mapping/MacroMapperProfile.cs index e888d78c07..9977b1cfb1 100644 --- a/src/Umbraco.Web/Models/Mapping/MacroMapperProfile.cs +++ b/src/Umbraco.Web/Models/Mapping/MacroMapperProfile.cs @@ -41,7 +41,7 @@ namespace Umbraco.Web.Models.Mapping { //we'll just map this to a text box paramEditor = Current.ParameterEditors[Constants.PropertyEditors.Aliases.TextBox]; - Current.Logger.Warn(() => $"Could not resolve a parameter editor with alias {property.EditorAlias}, a textbox will be rendered in it's place"); + Current.Logger.Warn("Could not resolve a parameter editor with alias {PropertyEditorAlias}, a textbox will be rendered in it's place", property.EditorAlias); } parameter.View = paramEditor.GetValueEditor().View; diff --git a/src/Umbraco.Web/Mvc/RenderRouteHandler.cs b/src/Umbraco.Web/Mvc/RenderRouteHandler.cs index 13aef3a01e..8480c9fb89 100644 --- a/src/Umbraco.Web/Mvc/RenderRouteHandler.cs +++ b/src/Umbraco.Web/Mvc/RenderRouteHandler.cs @@ -319,8 +319,11 @@ namespace Umbraco.Web.Mvc } else { - Current.Logger.Warn(() => - $"The current Document Type {request.PublishedContent.ContentType.Alias} matches a locally declared controller of type {controllerType.FullName}. Custom Controllers for Umbraco routing must implement '{typeof(IRenderController).FullName}' and inherit from '{typeof(ControllerBase).FullName}'."); + Current.Logger.Warn("The current Document Type {ContentTypeAlias} matches a locally declared controller of type {ControllerName}. Custom Controllers for Umbraco routing must implement '{UmbracoRenderController}' and inherit from '{UmbracoControllerBase}'.", + request.PublishedContent.ContentType.Alias, + controllerType.FullName, + typeof(IRenderController).FullName, + typeof(ControllerBase).FullName); //we cannot route to this custom controller since it is not of the correct type so we'll continue with the defaults // that have already been set above. diff --git a/src/Umbraco.Web/PropertyEditors/ValueConverters/RelatedLinksValueConverter.cs b/src/Umbraco.Web/PropertyEditors/ValueConverters/RelatedLinksValueConverter.cs index 632052d3e7..23670e1601 100644 --- a/src/Umbraco.Web/PropertyEditors/ValueConverters/RelatedLinksValueConverter.cs +++ b/src/Umbraco.Web/PropertyEditors/ValueConverters/RelatedLinksValueConverter.cs @@ -95,7 +95,7 @@ namespace Umbraco.Web.PropertyEditors.ValueConverters } else { - _logger.Warn(() => $"Related Links value converter skipped a link as the node has been unpublished/deleted (Internal Link NodeId: {relatedLink.Link}, Link Caption: \"{relatedLink.Caption}\")"); + _logger.Warn("Related Links value converter skipped a link as the node has been unpublished/deleted (Internal Link NodeId: {RelatedLinkNodeId}, Link Caption: '{RelatedLinkCaption}')", relatedLink.Link, relatedLink.Caption); } } @@ -158,7 +158,7 @@ namespace Umbraco.Web.PropertyEditors.ValueConverters } catch (Exception ex) { - _logger.Error("Could not parse the string " + sourceString + " to a json object", ex); + _logger.Error("Could not parse the string {SourceString} to a json object", ex, sourceString); } } diff --git a/src/Umbraco.Web/PublishedCache/NuCache/ContentStore.cs b/src/Umbraco.Web/PublishedCache/NuCache/ContentStore.cs index 834594af9e..c6b45aed0d 100644 --- a/src/Umbraco.Web/PublishedCache/NuCache/ContentStore.cs +++ b/src/Umbraco.Web/PublishedCache/NuCache/ContentStore.cs @@ -446,7 +446,7 @@ namespace Umbraco.Web.PublishedCache.NuCache throw new ArgumentException("Kit content cannot have children.", nameof(kit)); // ReSharper restore LocalizableElement - _logger.Debug(() => "Set content ID:" + kit.Node.Id); + _logger.Debug("Set content ID: {KitNodeId}", kit.Node.Id); var lockInfo = new WriteLockInfo(); try @@ -571,7 +571,7 @@ namespace Umbraco.Web.PublishedCache.NuCache if (link?.Value == null) return false; var content = link.Value; - _logger.Debug(() => "Clear content ID:" + content.Id); + _logger.Debug("Clear content ID: {ContentId}", content.Id); // clear the entire branch ClearBranchLocked(content); @@ -921,7 +921,7 @@ namespace Umbraco.Web.PublishedCache.NuCache { // see notes in CreateSnapshot #if DEBUG - _logger.Debug(() => "Collect."); + _logger.Debug("Collect."); #endif while (_genRefRefs.TryPeek(out GenRefRef genRefRef) && (genRefRef.Count == 0 || genRefRef.WGenRef.IsAlive == false)) { @@ -1098,7 +1098,7 @@ namespace Umbraco.Web.PublishedCache.NuCache #if DEBUG _logger = logger; - _logger.Debug(() => "Creating snapshot."); + _logger.Debug("Creating snapshot."); #endif } @@ -1113,7 +1113,7 @@ namespace Umbraco.Web.PublishedCache.NuCache #if DEBUG _logger = logger; - _logger.Debug(() => "Creating live."); + _logger.Debug("Creating live."); #endif } @@ -1194,7 +1194,8 @@ namespace Umbraco.Web.PublishedCache.NuCache { if (_gen < 0) return; #if DEBUG - _logger.Debug(() => "Dispose snapshot (" + (_genRef?.GenRefRef.Count.ToString() ?? "live") + ")."); + //WB: TODO Need to inspect what Snapshot prop is returning here + _logger.Debug("Dispose snapshot ({Snapshot})", _genRef?.GenRefRef.Count.ToString() ?? "live"); #endif _gen = -1; if (_genRef != null) diff --git a/src/Umbraco.Web/PublishedCache/NuCache/DataSource/DatabaseDataSource.cs b/src/Umbraco.Web/PublishedCache/NuCache/DataSource/DatabaseDataSource.cs index 0a0c398cd6..a143997fab 100644 --- a/src/Umbraco.Web/PublishedCache/NuCache/DataSource/DatabaseDataSource.cs +++ b/src/Umbraco.Web/PublishedCache/NuCache/DataSource/DatabaseDataSource.cs @@ -186,7 +186,7 @@ namespace Umbraco.Web.PublishedCache.NuCache.DataSource { if (Debugger.IsAttached) throw new Exception("Missing cmsContentNu edited content for node " + dto.Id + ", consider rebuilding."); - Current.Logger.Warn(() => $"Missing cmsContentNu edited content for node {dto.Id}, consider rebuilding."); + Current.Logger.Warn("Missing cmsContentNu edited content for node {NodeId}, consider rebuilding.", dto.Id); } else { @@ -211,7 +211,7 @@ namespace Umbraco.Web.PublishedCache.NuCache.DataSource { if (Debugger.IsAttached) throw new Exception("Missing cmsContentNu published content for node " + dto.Id + ", consider rebuilding."); - Current.Logger.Warn(() => $"Missing cmsContentNu published content for node {dto.Id}, consider rebuilding."); + Current.Logger.Warn("Missing cmsContentNu published content for node {NodeId}, consider rebuilding.", dto.Id); } else { diff --git a/src/Umbraco.Web/PublishedCache/NuCache/PublishedSnapshotService.cs b/src/Umbraco.Web/PublishedCache/NuCache/PublishedSnapshotService.cs index 34efa7136a..d42860480a 100644 --- a/src/Umbraco.Web/PublishedCache/NuCache/PublishedSnapshotService.cs +++ b/src/Umbraco.Web/PublishedCache/NuCache/PublishedSnapshotService.cs @@ -298,12 +298,12 @@ namespace Umbraco.Web.PublishedCache.NuCache _localContentDb?.Clear(); - _logger.Debug(() => "Loading content from database..."); + _logger.Debug("Loading content from database..."); var sw = Stopwatch.StartNew(); var kits = _dataSource.GetAllContentSources(scope); _contentStore.SetAll(kits); sw.Stop(); - _logger.Debug(() => "Loaded content from database (" + sw.ElapsedMilliseconds + "ms)."); + _logger.Debug("Loaded content from database ({ElapsedMilliseconds}ms)", sw.ElapsedMilliseconds); } private void LoadContentFromLocalDbLocked(IScope scope) @@ -312,12 +312,12 @@ namespace Umbraco.Web.PublishedCache.NuCache .Select(x => _publishedContentTypeFactory.CreateContentType(x)); _contentStore.UpdateContentTypes(null, contentTypes, null); - _logger.Debug(() => "Loading content from local db..."); + _logger.Debug("Loading content from local db..."); var sw = Stopwatch.StartNew(); var kits = _localContentDb.Select(x => x.Value).OrderBy(x => x.Node.Level); _contentStore.SetAll(kits); sw.Stop(); - _logger.Debug(() => "Loaded content from local db (" + sw.ElapsedMilliseconds + "ms)."); + _logger.Debug("Loaded content from local db ({ElapsedMilliseconds}ms)", sw.ElapsedMilliseconds); } // keep these around - might be useful @@ -365,12 +365,12 @@ namespace Umbraco.Web.PublishedCache.NuCache _localMediaDb?.Clear(); - _logger.Debug(() => "Loading media from database..."); + _logger.Debug("Loading media from database..."); var sw = Stopwatch.StartNew(); var kits = _dataSource.GetAllMediaSources(scope); _mediaStore.SetAll(kits); sw.Stop(); - _logger.Debug(() => "Loaded media from database (" + sw.ElapsedMilliseconds + "ms)."); + _logger.Debug("Loaded media from database ({ElapsedMilliseconds}ms)", sw.ElapsedMilliseconds); } private void LoadMediaFromLocalDbLocked(IScope scope) @@ -379,12 +379,12 @@ namespace Umbraco.Web.PublishedCache.NuCache .Select(x => _publishedContentTypeFactory.CreateContentType(x)); _mediaStore.UpdateContentTypes(null, mediaTypes, null); - _logger.Debug(() => "Loading media from local db..."); + _logger.Debug("Loading media from local db..."); var sw = Stopwatch.StartNew(); var kits = _localMediaDb.Select(x => x.Value); _mediaStore.SetAll(kits); sw.Stop(); - _logger.Debug(() => "Loaded media from local db (" + sw.ElapsedMilliseconds + "ms)."); + _logger.Debug("Loaded media from local db ({ElapsedMilliseconds}ms)", sw.ElapsedMilliseconds); } // keep these around - might be useful @@ -551,7 +551,8 @@ namespace Umbraco.Web.PublishedCache.NuCache foreach (var payload in payloads) { - _logger.Debug(() => $"Notified {payload.ChangeTypes} for content {payload.Id}"); + //WB: TODO Check ChangeTypes as its an enum (be nice to get the text & not 0, 1, 2) + _logger.Debug("Notified {ChangeTypes} for content {ContentId}", payload.ChangeTypes, payload.Id); if (payload.ChangeTypes.HasType(TreeChangeTypes.RefreshAll)) { @@ -641,7 +642,8 @@ namespace Umbraco.Web.PublishedCache.NuCache foreach (var payload in payloads) { - _logger.Debug(() => $"Notified {payload.ChangeTypes} for media {payload.Id}"); + //WB: TODO Check ChangeTypes as its an enum (be nice to get the text & not 0, 1, 2) + _logger.Debug("Notified {ChangeTypes} for media {MediaId}", payload.ChangeTypes, payload.Id); if (payload.ChangeTypes.HasType(TreeChangeTypes.RefreshAll)) { @@ -710,7 +712,8 @@ namespace Umbraco.Web.PublishedCache.NuCache return; foreach (var payload in payloads) - _logger.Debug(() => $"Notified {payload.ChangeTypes} for {payload.ItemType} {payload.Id}"); + //WB: TODO Check ChangeTypes as its an enum (be nice to get the text & not 0, 1, 2) + _logger.Debug("Notified {ChangeTypes} for {ItemType} {ItemId}", payload.ChangeTypes, payload.ItemType, payload.Id); Notify(_contentStore, payloads, RefreshContentTypesLocked); Notify(_mediaStore, payloads, RefreshMediaTypesLocked); @@ -760,7 +763,9 @@ namespace Umbraco.Web.PublishedCache.NuCache var idsA = payloads.Select(x => x.Id).ToArray(); foreach (var payload in payloads) - _logger.Debug(() => $"Notified {(payload.Removed ? "Removed" : "Refreshed")} for data type {payload.Id}"); + _logger.Debug("Notified {RemovedStatus} for data type {DataTypeId}", + payload.Removed ? "Removed" : "Refreshed", + payload.Id); using (_contentStore.GetWriter(_scopeProvider)) using (_mediaStore.GetWriter(_scopeProvider)) diff --git a/src/Umbraco.Web/PublishedCache/PublishedContentTypeCache.cs b/src/Umbraco.Web/PublishedCache/PublishedContentTypeCache.cs index a41a270c52..ca30370598 100644 --- a/src/Umbraco.Web/PublishedCache/PublishedContentTypeCache.cs +++ b/src/Umbraco.Web/PublishedCache/PublishedContentTypeCache.cs @@ -48,7 +48,7 @@ namespace Umbraco.Web.PublishedCache /// public void ClearAll() { - _logger.Debug(() => "Clear all."); + _logger.Debug("Clear all."); try { @@ -70,7 +70,7 @@ namespace Umbraco.Web.PublishedCache /// An identifier. public void ClearContentType(int id) { - _logger.Debug(() => $"Clear content type w/id {id}."); + _logger.Debug("Clear content type w/id {ContentTypeId}", id); try { @@ -105,7 +105,7 @@ namespace Umbraco.Web.PublishedCache /// A data type identifier. public void ClearDataType(int id) { - _logger.Debug(() => $"Clear data type w/id {id}."); + _logger.Debug("Clear data type w/id {DataTypeId}.", id); // there is no recursion to handle here because a PublishedContentType contains *all* its // properties ie both its own properties and those that were inherited (it's based upon an diff --git a/src/Umbraco.Web/PublishedCache/XmlPublishedCache/DictionaryPublishedContent.cs b/src/Umbraco.Web/PublishedCache/XmlPublishedCache/DictionaryPublishedContent.cs index 9d4dfda461..49e0d1e9d2 100644 --- a/src/Umbraco.Web/PublishedCache/XmlPublishedCache/DictionaryPublishedContent.cs +++ b/src/Umbraco.Web/PublishedCache/XmlPublishedCache/DictionaryPublishedContent.cs @@ -108,7 +108,7 @@ namespace Umbraco.Web.PublishedCache.XmlPublishedCache else { // this is a property that does not correspond to anything, ignore and log - Current.Logger.Warn(() => "Dropping property \"" + i.Key + "\" because it does not belong to the content type."); + Current.Logger.Warn("Dropping property '{PropertyKey}' because it does not belong to the content type.", i.Key); } } } diff --git a/src/Umbraco.Web/PublishedCache/XmlPublishedCache/PublishedMediaCache.cs b/src/Umbraco.Web/PublishedCache/XmlPublishedCache/PublishedMediaCache.cs index 6cf8b85ed1..26542e376a 100644 --- a/src/Umbraco.Web/PublishedCache/XmlPublishedCache/PublishedMediaCache.cs +++ b/src/Umbraco.Web/PublishedCache/XmlPublishedCache/PublishedMediaCache.cs @@ -330,8 +330,8 @@ namespace Umbraco.Web.PublishedCache.XmlPublishedCache var miss = Interlocked.CompareExchange(ref _examineIndexMiss, 0, 0); // volatile read if (miss < ExamineIndexMissMax && Interlocked.Increment(ref _examineIndexMiss) == ExamineIndexMissMax) - Current.Logger.Warn(() => $"Failed ({ExamineIndexMissMax} times) to retrieve medias from Examine index and had to load" - + " them from DB. This may indicate that the Examine index is corrupted."); + Current.Logger.Warn("Failed ({ExamineIndexMissMax} times) to retrieve medias from Examine index and had to load" + + " them from DB. This may indicate that the Examine index is corrupted.", ExamineIndexMissMax); return ConvertFromIMedia(media); } @@ -348,8 +348,7 @@ namespace Umbraco.Web.PublishedCache.XmlPublishedCache : ConvertFromXPathNavigator(media.Current); } - Current.Logger.Warn(() => - $"Could not retrieve media {id} from Examine index or from legacy library.GetMedia method"); + Current.Logger.Warn("Could not retrieve media {MediaId} from Examine index or from legacy library.GetMedia method", id); return null; } diff --git a/src/Umbraco.Web/PublishedCache/XmlPublishedCache/XmlStore.cs b/src/Umbraco.Web/PublishedCache/XmlPublishedCache/XmlStore.cs index caf937315e..340a40bb97 100644 --- a/src/Umbraco.Web/PublishedCache/XmlPublishedCache/XmlStore.cs +++ b/src/Umbraco.Web/PublishedCache/XmlPublishedCache/XmlStore.cs @@ -1038,7 +1038,8 @@ ORDER BY umbracoNode.level, umbracoNode.sortOrder"; { foreach (var payload in payloads) { - Current.Logger.Debug(() => $"Notified {payload.ChangeTypes} for content {payload.Id}."); + //WB: TODO Check ChangeTypes as its an enum (be nice to get the text & not 0, 1, 2) + Current.Logger.Debug("Notified {ChangeTypes} for content {ContentId}", payload.ChangeTypes, payload.Id); if (payload.ChangeTypes.HasType(TreeChangeTypes.RefreshAll)) { @@ -1071,7 +1072,8 @@ ORDER BY umbracoNode.level, umbracoNode.sortOrder"; if (content == null || content.Published == false || content.Trashed) { // no published version - Current.Logger.Debug(() => $"Notified, content {payload.Id} has no published version."); + Current.Logger.Debug("Notified, content {ContentId} has no published version.", payload.Id); + if (current != null) { // remove from xml if exists @@ -1109,7 +1111,8 @@ ORDER BY umbracoNode.level, umbracoNode.sortOrder"; if (dtos.MoveNext() == false) { // gone fishing, remove (possible race condition) - Current.Logger.Debug(() => $"Notifified, content {payload.Id} gone fishing."); + Current.Logger.Debug("Notified, content {ContentId} gone fishing.", payload.Id); + if (current != null) { // remove from xml if exists @@ -1222,7 +1225,8 @@ ORDER BY umbracoNode.level, umbracoNode.sortOrder"; .ToArray(); foreach (var payload in payloads) - Current.Logger.Debug(() => $"Notified {payload.ChangeTypes} for content type {payload.Id}."); + //WB: TODO Check ChangeTypes as its an enum (be nice to get the text & not 0, 1, 2) + Current.Logger.Debug("Notified {ChangeTypes} for content type {ContentTypeId}", payload.ChangeTypes, payload.Id); if (ids.Length > 0) // must have refreshes, not only removes RefreshContentTypes(ids); @@ -1239,9 +1243,11 @@ ORDER BY umbracoNode.level, umbracoNode.sortOrder"; // the types will be reloaded if/when needed foreach (var payload in payloads) _contentTypeCache.ClearDataType(payload.Id); - + foreach (var payload in payloads) - Current.Logger.Debug(() => $"Notified {(payload.Removed ? "Removed" : "Refreshed")} for data type {payload.Id}."); + Current.Logger.Debug("Notified {RemovedStatus} for data type {payload.Id}", + payload.Removed ? "Removed" : "Refreshed", + payload.Id); // that's all we need to do as the changes have NO impact whatsoever on the Xml content diff --git a/src/Umbraco.Web/PublishedCache/XmlPublishedCache/XmlStoreFilePersister.cs b/src/Umbraco.Web/PublishedCache/XmlPublishedCache/XmlStoreFilePersister.cs index 6b247bdf0d..c656562236 100644 --- a/src/Umbraco.Web/PublishedCache/XmlPublishedCache/XmlStoreFilePersister.cs +++ b/src/Umbraco.Web/PublishedCache/XmlPublishedCache/XmlStoreFilePersister.cs @@ -62,7 +62,7 @@ namespace Umbraco.Web.PublishedCache.XmlPublishedCache if (touched == false) return; - _logger.Debug(() => $"Created, save in {WaitMilliseconds}ms."); + _logger.Debug("Created, save in {WaitMilliseconds}ms.", WaitMilliseconds); _initialTouch = DateTime.Now; _timer = new Timer(_ => TimerRelease()); _timer.Change(WaitMilliseconds, 0); @@ -107,7 +107,7 @@ namespace Umbraco.Web.PublishedCache.XmlPublishedCache else if (_timer == null) // we don't have a timer yet { - _logger.Debug(() => $"Touched, was idle, start and save in {WaitMilliseconds}ms."); + _logger.Debug("Touched, was idle, start and save in {WaitMilliseconds}ms.", WaitMilliseconds); _initialTouch = DateTime.Now; _timer = new Timer(_ => TimerRelease()); _timer.Change(WaitMilliseconds, 0); @@ -120,7 +120,7 @@ namespace Umbraco.Web.PublishedCache.XmlPublishedCache if (DateTime.Now - _initialTouch < TimeSpan.FromMilliseconds(MaxWaitMilliseconds)) { - _logger.Debug(() => $"Touched, was waiting, can delay, save in {WaitMilliseconds}ms."); + _logger.Debug("Touched, was waiting, can delay, save in {WaitMilliseconds}ms.", WaitMilliseconds); _timer.Change(WaitMilliseconds, 0); } else diff --git a/src/Umbraco.Web/Routing/ContentFinderByIdPath.cs b/src/Umbraco.Web/Routing/ContentFinderByIdPath.cs index fa2ca519d9..447d4e34af 100644 --- a/src/Umbraco.Web/Routing/ContentFinderByIdPath.cs +++ b/src/Umbraco.Web/Routing/ContentFinderByIdPath.cs @@ -48,13 +48,13 @@ namespace Umbraco.Web.Routing if (nodeId > 0) { - _logger.Debug(() => $"Id={nodeId}"); + _logger.Debug("Id={NodeId}", nodeId); node = frequest.UmbracoContext.ContentCache.GetById(nodeId); if (node != null) { frequest.PublishedContent = node; - _logger.Debug(() => $"Found node with id={frequest.PublishedContent.Id}"); + _logger.Debug("Found node with id={PublishedContentId}", frequest.PublishedContent.Id); } else { diff --git a/src/Umbraco.Web/Routing/ContentFinderByLegacy404.cs b/src/Umbraco.Web/Routing/ContentFinderByLegacy404.cs index cac9244dbf..99b4e22b5a 100644 --- a/src/Umbraco.Web/Routing/ContentFinderByLegacy404.cs +++ b/src/Umbraco.Web/Routing/ContentFinderByLegacy404.cs @@ -70,7 +70,7 @@ namespace Umbraco.Web.Routing if (error404.HasValue) { - _logger.Debug(() => $"Got id={error404.Value}."); + _logger.Debug("Got id={ErrorNodeId}.", error404.Value); content = frequest.UmbracoContext.ContentCache.GetById(error404.Value); diff --git a/src/Umbraco.Web/Routing/ContentFinderByRedirectUrl.cs b/src/Umbraco.Web/Routing/ContentFinderByRedirectUrl.cs index b8bc5f19fb..d50951161c 100644 --- a/src/Umbraco.Web/Routing/ContentFinderByRedirectUrl.cs +++ b/src/Umbraco.Web/Routing/ContentFinderByRedirectUrl.cs @@ -48,7 +48,7 @@ namespace Umbraco.Web.Routing if (redirectUrl == null) { - _logger.Debug(() => $"No match for route: \"{route}\"."); + _logger.Debug("No match for route: '{Route}'", route); return false; } @@ -56,11 +56,11 @@ namespace Umbraco.Web.Routing var url = content == null ? "#" : content.Url; if (url.StartsWith("#")) { - _logger.Debug(() => $"Route \"{route}\" matches content {redirectUrl.ContentId} which has no url."); + _logger.Debug("Route '{Route}' matches content {ContentId} which has no url.", route, redirectUrl.ContentId); return false; } - _logger.Debug(() => $"Route \"{route}\" matches content {content.Id} with url \"{url}\", redirecting."); + _logger.Debug("Route '{Route}' matches content {ContentId} with url '{Url}', redirecting.", route, content.Id, url); frequest.SetRedirectPermanent(url); return true; } diff --git a/src/Umbraco.Web/Routing/ContentFinderByUrl.cs b/src/Umbraco.Web/Routing/ContentFinderByUrl.cs index 042ca5882f..a3c54406a8 100644 --- a/src/Umbraco.Web/Routing/ContentFinderByUrl.cs +++ b/src/Umbraco.Web/Routing/ContentFinderByUrl.cs @@ -46,13 +46,13 @@ namespace Umbraco.Web.Routing { if (docreq == null) throw new System.ArgumentNullException(nameof(docreq)); - Logger.Debug(() => $"Test route \"{route}\""); + Logger.Debug("Test route '{Route}'", route); var node = docreq.UmbracoContext.ContentCache.GetByRoute(route, culture: docreq.Culture?.Name); if (node != null) { docreq.PublishedContent = node; - Logger.Debug(() => $"Got content, id={node.Id}"); + Logger.Debug("Got content, id={NodeId}", node.Id); } else { diff --git a/src/Umbraco.Web/Routing/ContentFinderByUrlAlias.cs b/src/Umbraco.Web/Routing/ContentFinderByUrlAlias.cs index 59e30cc8b0..bbf3ee1283 100644 --- a/src/Umbraco.Web/Routing/ContentFinderByUrlAlias.cs +++ b/src/Umbraco.Web/Routing/ContentFinderByUrlAlias.cs @@ -44,7 +44,7 @@ namespace Umbraco.Web.Routing if (node != null) { frequest.PublishedContent = node; - Logger.Debug(() => $"Path \"{frequest.Uri.AbsolutePath}\" is an alias for id={frequest.PublishedContent.Id}"); + Logger.Debug("Path '{UriAbsolutePath}' is an alias for id={PublishedContentId}", frequest.Uri.AbsolutePath, frequest.PublishedContent.Id); } } diff --git a/src/Umbraco.Web/Routing/ContentFinderByUrlAndTemplate.cs b/src/Umbraco.Web/Routing/ContentFinderByUrlAndTemplate.cs index 0b4c02aa8e..1d1661966f 100644 --- a/src/Umbraco.Web/Routing/ContentFinderByUrlAndTemplate.cs +++ b/src/Umbraco.Web/Routing/ContentFinderByUrlAndTemplate.cs @@ -49,7 +49,7 @@ namespace Umbraco.Web.Routing var template = _fileService.GetTemplate(templateAlias); if (template != null) { - Logger.Debug(() => $"Valid template: \"{templateAlias}\""); + Logger.Debug("Valid template: '{TemplateAlias}'", templateAlias); var route = frequest.HasDomain ? (frequest.Domain.ContentId.ToString() + path) : path; node = FindContent(frequest, route); @@ -59,12 +59,12 @@ namespace Umbraco.Web.Routing } else { - Logger.Debug(() => $"Not a valid template: \"{templateAlias}\""); + Logger.Debug("Not a valid template: '{TemplateAlias}'", templateAlias); } } else { - Logger.Debug("No template in path \"/\""); + Logger.Debug("No template in path '/'"); } return node != null; diff --git a/src/Umbraco.Web/Routing/DefaultUrlProvider.cs b/src/Umbraco.Web/Routing/DefaultUrlProvider.cs index fb9cdfa9bd..61437b6640 100644 --- a/src/Umbraco.Web/Routing/DefaultUrlProvider.cs +++ b/src/Umbraco.Web/Routing/DefaultUrlProvider.cs @@ -43,8 +43,7 @@ namespace Umbraco.Web.Routing { if (string.IsNullOrWhiteSpace(route)) { - _logger.Debug(() => - $"Couldn't find any page with nodeId={id}. This is most likely caused by the page not being published."); + _logger.Debug("Couldn't find any page with nodeId={NodeId}. This is most likely caused by the page not being published.", id); return null; } diff --git a/src/Umbraco.Web/Routing/PublishedRouter.cs b/src/Umbraco.Web/Routing/PublishedRouter.cs index 4c137b2d81..a728798253 100644 --- a/src/Umbraco.Web/Routing/PublishedRouter.cs +++ b/src/Umbraco.Web/Routing/PublishedRouter.cs @@ -276,7 +276,7 @@ namespace Umbraco.Web.Routing // note - we are not handling schemes nor ports here. - _logger.Debug(() => $"{tracePrefix}Uri=\"{request.Uri}\""); + _logger.Debug("{TracePrefix}Uri='{RequestUri}'", tracePrefix, request.Uri); var domainsCache = request.UmbracoContext.PublishedSnapshot.Domains; var domains = domainsCache.GetAll(includeWildcards: false).ToList(); @@ -313,7 +313,7 @@ namespace Umbraco.Web.Routing if (domainAndUri != null) { // matching an existing domain - _logger.Debug(() => $"{tracePrefix}Matches domain=\"{domainAndUri.Name}\", rootId={domainAndUri.ContentId}, culture=\"{domainAndUri.Culture}\""); + _logger.Debug("{TracePrefix}Matches domain='{Domain}', rootId={RootContentId}, culture='{Culture}'", tracePrefix, domainAndUri.Name, domainAndUri.ContentId, domainAndUri.Culture); request.Domain = domainAndUri; request.Culture = domainAndUri.Culture; @@ -328,12 +328,12 @@ namespace Umbraco.Web.Routing else { // not matching any existing domain - _logger.Debug(() => $"{tracePrefix}Matches no domain"); + _logger.Debug("{TracePrefix}Matches no domain", tracePrefix); request.Culture = defaultCulture == null ? CultureInfo.CurrentUICulture : new CultureInfo(defaultCulture); } - _logger.Debug(() => $"{tracePrefix}Culture=\"{request.Culture.Name}\""); + _logger.Debug("{TracePrefix}Culture='{CultureName}'", tracePrefix, request.Culture.Name); return request.Domain != null; } @@ -349,7 +349,7 @@ namespace Umbraco.Web.Routing return; var nodePath = request.PublishedContent.Path; - _logger.Debug(() => $"{tracePrefix}Path=\"{nodePath}\""); + _logger.Debug("{TracePrefix}Path='{NodePath}'", tracePrefix, nodePath); var rootNodeId = request.HasDomain ? request.Domain.ContentId : (int?)null; var domain = DomainHelper.FindWildcardDomainInPath(request.UmbracoContext.PublishedSnapshot.Domains.GetAll(true), nodePath, rootNodeId); @@ -357,11 +357,11 @@ namespace Umbraco.Web.Routing if (domain != null) { request.Culture = domain.Culture; - _logger.Debug(() => $"{tracePrefix}Got domain on node {domain.ContentId}, set culture to \"{request.Culture.Name}\"."); + _logger.Debug("{TracePrefix}Got domain on node {DomainContentId}, set culture to '{CultureName}'", tracePrefix, domain.ContentId, request.Culture.Name); } else { - _logger.Debug(() => $"{tracePrefix}No match."); + _logger.Debug("{TracePrefix}No match.", tracePrefix); } } @@ -434,8 +434,7 @@ namespace Umbraco.Web.Routing /// A value indicating whether a document and template were found. private void FindPublishedContentAndTemplate(PublishedRequest request) { - const string tracePrefix = "FindPublishedContentAndTemplate: "; - _logger.Debug(() => $"{tracePrefix}Path=\"{request.Uri.AbsolutePath}\""); + _logger.Debug("FindPublishedContentAndTemplate: Path='{UriAbsolutePath}'", request.Uri.AbsolutePath); // run the document finders FindPublishedContent(request); @@ -478,7 +477,7 @@ namespace Umbraco.Web.Routing //iterate but return on first one that finds it var found = _contentFinders.Any(finder => { - _logger.Debug(() => "Finder " + finder.GetType().FullName); + _logger.Debug("Finder {ContentFinderType}", finder.GetType().FullName); return finder.TryFindContent(request); }); } @@ -504,22 +503,22 @@ namespace Umbraco.Web.Routing const int maxLoop = 8; do { - _logger.Debug(() => $"{tracePrefix}{(i == 0 ? "Begin" : "Loop")}"); + _logger.Debug("HandlePublishedContent: Loop {LoopCounter}", i); // handle not found if (request.HasPublishedContent == false) { request.Is404 = true; - _logger.Debug(() => $"{tracePrefix}No document, try last chance lookup"); + _logger.Debug("HandlePublishedContent: No document, try last chance lookup"); // if it fails then give up, there isn't much more that we can do if (_contentLastChanceFinder.TryFindContent(request) == false) { - _logger.Debug(() => $"{tracePrefix}Failed to find a document, give up"); + _logger.Debug("HandlePublishedContent: Failed to find a document, give up"); break; } - _logger.Debug(() => $"{tracePrefix}Found a document"); + _logger.Debug("HandlePublishedContent: Found a document"); } // follow internal redirects as long as it's not running out of control ie infinite loop of some sort @@ -541,11 +540,11 @@ namespace Umbraco.Web.Routing if (i == maxLoop || j == maxLoop) { - _logger.Debug(() => $"{tracePrefix}Looks like we're running into an infinite loop, abort"); + _logger.Debug("HandlePublishedContent: Looks like we're running into an infinite loop, abort"); request.PublishedContent = null; } - _logger.Debug(() => $"{tracePrefix}End"); + _logger.Debug("HandlePublishedContent: End"); } /// @@ -558,8 +557,6 @@ namespace Umbraco.Web.Routing /// private bool FollowInternalRedirects(PublishedRequest request) { - const string tracePrefix = "FollowInternalRedirects: "; - if (request.PublishedContent == null) throw new InvalidOperationException("There is no PublishedContent."); @@ -592,23 +589,25 @@ namespace Umbraco.Web.Routing if (valid == false) { // bad redirect - log and display the current page (legacy behavior) - _logger.Debug(() => $"{tracePrefix}Failed to redirect to id={request.PublishedContent.GetProperty(Constants.Conventions.Content.InternalRedirectId).GetSourceValue()}: value is not an int nor a GuidUdi."); + _logger.Debug("FollowInternalRedirects: Failed to redirect to id={InternalRedirectId}: value is not an int nor a GuidUdi.", + request.PublishedContent.GetProperty(Constants.Conventions.Content.InternalRedirectId).GetSourceValue()); } if (internalRedirectNode == null) { - _logger.Debug(() => $"{tracePrefix}Failed to redirect to id={request.PublishedContent.GetProperty(Constants.Conventions.Content.InternalRedirectId).GetSourceValue()}: no such published document."); + _logger.Debug("FollowInternalRedirects: Failed to redirect to id={InternalRedirectId}: no such published document.", + request.PublishedContent.GetProperty(Constants.Conventions.Content.InternalRedirectId).GetSourceValue()); } else if (internalRedirectId == request.PublishedContent.Id) { // redirect to self - _logger.Debug(() => $"{tracePrefix}Redirecting to self, ignore"); + _logger.Debug("FollowInternalRedirects: Redirecting to self, ignore"); } else { request.SetInternalRedirectPublishedContent(internalRedirectNode); // don't use .PublishedContent here redirect = true; - _logger.Debug(() => $"{tracePrefix}Redirecting to id={internalRedirectId}"); + _logger.Debug("FollowInternalRedirects: Redirecting to id={InternalRedirectId}", internalRedirectId); } return redirect; @@ -620,8 +619,6 @@ namespace Umbraco.Web.Routing /// Redirecting to a different site root and/or culture will not pick the new site root nor the new culture. private void EnsurePublishedContentAccess(PublishedRequest request) { - const string tracePrefix = "EnsurePublishedContentAccess: "; - if (request.PublishedContent == null) throw new InvalidOperationException("There is no PublishedContent."); @@ -631,13 +628,13 @@ namespace Umbraco.Web.Routing if (publicAccessAttempt) { - _logger.Debug(() => $"{tracePrefix}Page is protected, check for access"); + _logger.Debug("EnsurePublishedContentAccess: Page is protected, check for access"); var membershipHelper = new MembershipHelper(request.UmbracoContext); if (membershipHelper.IsLoggedIn() == false) { - _logger.Debug(() => $"{tracePrefix}Not logged in, redirect to login page"); + _logger.Debug("EnsurePublishedContentAccess: Not logged in, redirect to login page"); var loginPageId = publicAccessAttempt.Result.LoginNodeId; @@ -646,19 +643,19 @@ namespace Umbraco.Web.Routing } else if (_services.PublicAccessService.HasAccess(request.PublishedContent.Id, _services.ContentService, GetRolesForLogin(membershipHelper.CurrentUserName)) == false) { - _logger.Debug(() => $"{tracePrefix}Current member has not access, redirect to error page"); + _logger.Debug("EnsurePublishedContentAccess: Current member has not access, redirect to error page"); var errorPageId = publicAccessAttempt.Result.NoAccessNodeId; if (errorPageId != request.PublishedContent.Id) request.PublishedContent = request.UmbracoContext.PublishedSnapshot.Content.GetById(errorPageId); } else { - _logger.Debug(() => $"{tracePrefix}Current member has access"); + _logger.Debug("EnsurePublishedContentAccess: Current member has access"); } } else { - _logger.Debug(() => $"{tracePrefix}Page is not protected"); + _logger.Debug("EnsurePublishedContentAccess: Page is not protected"); } } @@ -671,8 +668,6 @@ namespace Umbraco.Web.Routing // use the Prepared event to change the template if they wish. Should we also // implement an ITemplateFinder logic? - const string tracePrefix = "FindTemplate: "; - if (request.PublishedContent == null) { request.TemplateModel = null; @@ -709,16 +704,16 @@ namespace Umbraco.Web.Routing if (templateId > 0) { - _logger.Debug(() => $"{tracePrefix}Look for template id={templateId}"); + _logger.Debug("FindTemplate: Look for template id={TemplateId}", templateId); var template = _services.FileService.GetTemplate(templateId); if (template == null) throw new InvalidOperationException("The template with Id " + templateId + " does not exist, the page cannot render"); request.TemplateModel = template; - _logger.Debug(() => $"{tracePrefix}Got template id={template.Id} alias=\"{template.Alias}\""); + _logger.Debug("FindTemplate: Got template id={TemplateId} alias='{TemplateAlias}'", template.Id, template.Alias); } else { - _logger.Debug(() => $"{tracePrefix}No specified template."); + _logger.Debug("FindTemplate: No specified template."); } } else @@ -730,24 +725,24 @@ namespace Umbraco.Web.Routing // ignore if the alias does not match - just trace if (request.HasTemplate) - _logger.Debug(() => $"{tracePrefix}Has a template already, but also an alternate template."); - _logger.Debug(() => $"{tracePrefix}Look for alternate template alias=\"{altTemplate}\""); + _logger.Debug("FindTemplate: Has a template already, but also an alternate template."); + _logger.Debug("FindTemplate: Look for alternate template alias='{AltTemplate}'", altTemplate); var template = _services.FileService.GetTemplate(altTemplate); if (template != null) { request.TemplateModel = template; - _logger.Debug(() => $"{tracePrefix}Got template id={template.Id} alias=\"{template.Alias}\""); + _logger.Debug("FindTemplate: Got template id={TemplateId} alias='{TemplateAlias}'", template.Id, template.Alias); } else { - _logger.Debug(() => $"{tracePrefix}The template with alias=\"{altTemplate}\" does not exist, ignoring."); + _logger.Debug("FindTemplate: The template with alias='{AltTemplate}' does not exist, ignoring.", altTemplate); } } if (request.HasTemplate == false) { - _logger.Debug(() => $"{tracePrefix}No template was found."); + _logger.Debug("FindTemplate: No template was found."); // initial idea was: if we're not already 404 and UmbracoSettings.HandleMissingTemplateAs404 is true // then reset _pcr.Document to null to force a 404. @@ -760,7 +755,7 @@ namespace Umbraco.Web.Routing } else { - _logger.Debug(() => $"{tracePrefix}Running with template id={request.TemplateModel.Id} alias=\"{request.TemplateModel.Alias}\""); + _logger.Debug("FindTemplate: Running with template id={TemplateId} alias='{TemplateAlias}'", request.TemplateModel.Id, request.TemplateModel.Alias); } } diff --git a/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs b/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs index 630d00c95c..421b97d7d2 100644 --- a/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs +++ b/src/Umbraco.Web/Scheduling/BackgroundTaskRunner.cs @@ -233,7 +233,7 @@ namespace Umbraco.Web.Scheduling throw new InvalidOperationException("The task runner has completed."); // add task - _logger.Debug(() => _logPrefix + "Task added " + task.GetType().FullName); + _logger.Debug("{LogPrefix} Task Added {TaskType}", _logPrefix , task.GetType().FullName); _tasks.Post(task); // start @@ -253,12 +253,12 @@ namespace Umbraco.Web.Scheduling { if (_completed) { - _logger.Debug(() => _logPrefix + $"Task cannot be added {task.GetType().FullName}, the task runner has already shutdown"); + _logger.Debug("{LogPrefix} Task cannot be added {TaskType}, the task runner has already shutdown", _logPrefix, task.GetType().FullName); return false; } // add task - _logger.Debug(() => _logPrefix + "Task added " + task.GetType().FullName); + _logger.Debug("{LogPrefix} Task added {TaskType}", _logPrefix, task.GetType().FullName); _tasks.Post(task); // start @@ -315,7 +315,7 @@ namespace Umbraco.Web.Scheduling _shutdownToken = _shutdownTokenSource.Token; _runningTask = Task.Run(async () => await Pump().ConfigureAwait(false), _shutdownToken); - _logger.Debug(() => _logPrefix + "Starting"); + _logger.Debug("{LogPrefix} Starting", _logPrefix); } /// @@ -389,7 +389,7 @@ namespace Umbraco.Web.Scheduling } catch (Exception e) { - _logger.Error(_logPrefix + "Task runner exception.", e); + _logger.Error("{LogPrefix} Task runner exception", e, _logPrefix); } // done @@ -414,7 +414,7 @@ namespace Umbraco.Web.Scheduling if (_shutdownToken.IsCancellationRequested == false && _tasks.Count > 0) continue; // if we really have nothing to do, stop - _logger.Debug(() => _logPrefix + "Stopping"); + _logger.Debug("{LogPrefix} Stopping", _logPrefix); if (_options.PreserveRunningTask == false) _runningTask = null; @@ -536,7 +536,8 @@ namespace Umbraco.Web.Scheduling } catch (Exception ex) { - _logger.Error(_logPrefix + "Task has failed", ex); + + _logger.Error("{LogPrefix} Task has failed", ex, _logPrefix); } } @@ -667,7 +668,7 @@ namespace Umbraco.Web.Scheduling if (_terminating == false) { _terminating = true; - _logger.Info(() => $"{_logPrefix}Terminating{(immediate ? immediate.ToString() : "")}"); + _logger.Info("{LogPrefix} Terminating {Immediate}", _logPrefix, immediate ? immediate.ToString() : string.Empty); onTerminating = true; } } @@ -681,7 +682,7 @@ namespace Umbraco.Web.Scheduling // processing, call the UnregisterObject method, and then return or it can return immediately and complete // processing asynchronously before calling the UnregisterObject method. - _logger.Info(() => _logPrefix + "Waiting for tasks to complete"); + _logger.Info("{LogPrefix} Waiting for tasks to complete", _logPrefix); Shutdown(false, false); // do not accept any more tasks, flush the queue, do not wait // raise the completed event only after the running threading task has completed @@ -700,7 +701,7 @@ namespace Umbraco.Web.Scheduling // immediate parameter is true, the registered object must call the UnregisterObject method before returning; // otherwise, its registration will be removed by the application manager. - _logger.Info(() => _logPrefix + "Cancelling tasks"); + _logger.Info("{LogPrefix} Cancelling tasks", _logPrefix); Shutdown(true, true); // cancel all tasks, wait for the current one to end Terminate(true); } @@ -723,7 +724,9 @@ namespace Umbraco.Web.Scheduling terminatedSource = _terminatedSource; } - _logger.Info(() => _logPrefix + "Tasks " + (immediate ? "cancelled" : "completed") + ", terminated"); + _logger.Info("{LogPrefix} Tasks {TaskStatus}, terminated", + _logPrefix, + immediate ? "cancelled" : "completed"); OnEvent(Terminated, "Terminated"); diff --git a/src/Umbraco.Web/Scheduling/SchedulerComponent.cs b/src/Umbraco.Web/Scheduling/SchedulerComponent.cs index 68f6d008e2..12f85c49ba 100644 --- a/src/Umbraco.Web/Scheduling/SchedulerComponent.cs +++ b/src/Umbraco.Web/Scheduling/SchedulerComponent.cs @@ -87,7 +87,7 @@ namespace Umbraco.Web.Scheduling { LazyInitializer.EnsureInitialized(ref _tasks, ref _started, ref _locker, () => { - _logger.Debug(() => "Initializing the scheduler"); + _logger.Debug("Initializing the scheduler"); var settings = UmbracoConfig.For.UmbracoSettings(); var tasks = new List(); diff --git a/src/Umbraco.Web/Search/ExamineComponent.cs b/src/Umbraco.Web/Search/ExamineComponent.cs index 44cc6d60f1..627166bbb9 100644 --- a/src/Umbraco.Web/Search/ExamineComponent.cs +++ b/src/Umbraco.Web/Search/ExamineComponent.cs @@ -91,7 +91,7 @@ namespace Umbraco.Web.Search var registeredIndexers = examineManager.IndexProviders.Values.OfType().Count(x => x.EnableDefaultEventHandler); - profilingLogger.Logger.Info(() => $"Adding examine event handlers for {registeredIndexers} index providers."); + profilingLogger.Logger.Info("Adding examine event handlers for {RegisteredIndexers} index providers.", registeredIndexers); // don't bind event handlers if we're not suppose to listen if (registeredIndexers == 0) @@ -200,7 +200,7 @@ namespace Umbraco.Web.Search var dir = luceneIndexer.GetLuceneDirectory(); if (IndexWriter.IsLocked(dir)) { - logger.Info(() => $"Forcing index {luceneIndexer.Name} to be unlocked since it was left in a locked state"); + logger.Info("Forcing index {IndexerName} to be unlocked since it was left in a locked state", luceneIndexer.Name); IndexWriter.Unlock(dir); } } diff --git a/src/Umbraco.Web/Security/MembershipHelper.cs b/src/Umbraco.Web/Security/MembershipHelper.cs index 9816a0caa1..309190b241 100644 --- a/src/Umbraco.Web/Security/MembershipHelper.cs +++ b/src/Umbraco.Web/Security/MembershipHelper.cs @@ -301,7 +301,7 @@ namespace Umbraco.Web.Security if (member == null) { //this should not happen - Current.Logger.Warn(() => $"The member validated but then no member was returned with the username {username}"); + Current.Logger.Warn("The member validated but then no member was returned with the username {Username}", username); return false; } //Log them in diff --git a/src/Umbraco.Web/Security/Providers/UmbracoMembershipProvider.cs b/src/Umbraco.Web/Security/Providers/UmbracoMembershipProvider.cs index 51feed6746..1b528c2ba9 100644 --- a/src/Umbraco.Web/Security/Providers/UmbracoMembershipProvider.cs +++ b/src/Umbraco.Web/Security/Providers/UmbracoMembershipProvider.cs @@ -149,7 +149,7 @@ namespace Umbraco.Web.Security.Providers if (MemberService.Exists(username)) { status = MembershipCreateStatus.DuplicateUserName; - Current.Logger.Warn>(() => $"Cannot create member as username already exists: {username}"); + Current.Logger.Warn>("Cannot create member as username already exists: {Username}", username); return null; } @@ -157,7 +157,7 @@ namespace Umbraco.Web.Security.Providers if (MemberService.GetByEmail(email) != null && RequiresUniqueEmail) { status = MembershipCreateStatus.DuplicateEmail; - Current.Logger.Warn>(() => $"Cannot create member as a member with the same email address exists: {email}"); + Current.Logger.Warn>("Cannot create member as a member with the same email address exists: {Email}", email); return null; } @@ -524,8 +524,7 @@ namespace Umbraco.Web.Security.Providers if (member == null) { - Current.Logger.Info(() => - $"Login attempt failed for username {username} from IP address {GetCurrentRequestIpAddress()}, the user does not exist" ); + Current.Logger.Info("Login attempt failed for username {Username} from IP address {IpAddress}, the user does not exist", username, GetCurrentRequestIpAddress()); return new ValidateUserResult { @@ -535,8 +534,7 @@ namespace Umbraco.Web.Security.Providers if (member.IsApproved == false) { - Current.Logger.Info(() => - $"Login attempt failed for username {username} from IP address {GetCurrentRequestIpAddress()}, the user is not approved"); + Current.Logger.Info("Login attempt failed for username {Username} from IP address {IpAddress}, the user is not approved", username, GetCurrentRequestIpAddress()); return new ValidateUserResult { @@ -546,8 +544,7 @@ namespace Umbraco.Web.Security.Providers } if (member.IsLockedOut) { - Current.Logger.Info(() => - $"Login attempt failed for username {username} from IP address {GetCurrentRequestIpAddress()}, the user is locked"); + Current.Logger.Info("Login attempt failed for username {Username} from IP address {IpAddress}, the user is locked", username, GetCurrentRequestIpAddress()); return new ValidateUserResult { @@ -571,13 +568,11 @@ namespace Umbraco.Web.Security.Providers member.IsLockedOut = true; member.LastLockoutDate = DateTime.Now; - Current.Logger.Info(() => - $"Login attempt failed for username {username} from IP address {GetCurrentRequestIpAddress()}, the user is now locked out, max invalid password attempts exceeded"); + Current.Logger.Info("Login attempt failed for username {Username} from IP address {IpAddress}, the user is now locked out, max invalid password attempts exceeded", username, GetCurrentRequestIpAddress()); } else { - Current.Logger.Info(() => - $"Login attempt failed for username {username} from IP address {GetCurrentRequestIpAddress()}"); + Current.Logger.Info("Login attempt failed for username {Username} from IP address {IpAddress}", username, GetCurrentRequestIpAddress()); } } else @@ -590,8 +585,7 @@ namespace Umbraco.Web.Security.Providers member.LastLoginDate = DateTime.Now; - Current.Logger.Info(() => - $"Login attempt succeeded for username {username} from IP address {GetCurrentRequestIpAddress()}"); + Current.Logger.Info("Login attempt succeeded for username {Username} from IP address {IpAddress}", username, GetCurrentRequestIpAddress()); } //don't raise events for this! It just sets the member dates, if we do raise events this will diff --git a/src/Umbraco.Web/Services/ApplicationTreeService.cs b/src/Umbraco.Web/Services/ApplicationTreeService.cs index 006c0fb07d..abd9f08a53 100644 --- a/src/Umbraco.Web/Services/ApplicationTreeService.cs +++ b/src/Umbraco.Web/Services/ApplicationTreeService.cs @@ -339,7 +339,7 @@ namespace Umbraco.Web.Services var clrType = Type.GetType(type); if (clrType == null) { - _logger.Warn(() => $"The tree definition: {addElement} could not be resolved to a .Net object type"); + _logger.Warn("The tree definition: {AddElement} could not be resolved to a .Net object type", addElement); continue; } diff --git a/src/Umbraco.Web/UmbracoModule.cs b/src/Umbraco.Web/UmbracoModule.cs index bc252dda70..61c3d80b81 100644 --- a/src/Umbraco.Web/UmbracoModule.cs +++ b/src/Umbraco.Web/UmbracoModule.cs @@ -354,7 +354,10 @@ namespace Umbraco.Web var end = false; var response = context.Response; - logger.Debug(() => $"Response status: Redirect={(pcr.IsRedirect ? (pcr.IsRedirectPermanent ? "permanent" : "redirect") : "none")}, Is404={(pcr.Is404 ? "true" : "false")}, StatusCode={pcr.ResponseStatusCode}"); + logger.Debug("Response status: Redirect={Redirect}, Is404={Is404}, StatusCode={ResponseStatusCode}", + pcr.IsRedirect ? (pcr.IsRedirectPermanent ? "permanent" : "redirect") : "none", + pcr.Is404 ? "true" : "false", + pcr.ResponseStatusCode); if(pcr.Cacheability != default) response.Cache.SetCacheability(pcr.Cacheability); @@ -551,7 +554,7 @@ namespace Umbraco.Web app.BeginRequest += (sender, e) => { var httpContext = ((HttpApplication) sender).Context; - Logger.Debug(() => $"Begin request: {httpContext.Request.Url}."); + Logger.Debug("Begin request: {RequestUrl}", httpContext.Request.Url); BeginRequest(new HttpContextWrapper(httpContext)); }; @@ -594,7 +597,7 @@ namespace Umbraco.Web if (UmbracoContext.Current != null && UmbracoContext.Current.IsFrontEndUmbracoRequest) { - Logger.Debug(() => $"End Request. ({DateTime.Now.Subtract(UmbracoContext.Current.ObjectCreated).TotalMilliseconds}ms)"); + Logger.Debug("End Request: {RequestUrl} ({RequestTotalMilliseconds}ms)", httpContext.Request.Url, DateTime.Now.Subtract(UmbracoContext.Current.ObjectCreated).TotalMilliseconds); } OnEndRequest(new UmbracoRequestEventArgs(UmbracoContext.Current, new HttpContextWrapper(httpContext)));