Improved logging in recipe components.

src/Orchard.Web/Modules/Orchard.Recipes/Services/RecipeHarvester.cs

@@ -31,20 +31,19 @@ namespace Orchard.Recipes.Services {
 
         public IEnumerable<Recipe> HarvestRecipes(string extensionId) {
             var recipes = new List<Recipe>();
+
             var extension = _extensionManager.GetExtension(extensionId);
             if (extension != null) {
                 var recipeLocation = Path.Combine(extension.Location, extensionId, "Recipes");
                 var recipeFiles = _webSiteFolder.ListFiles(recipeLocation, true);
 
                 recipeFiles.Where(r => r.EndsWith(".recipe.xml", StringComparison.OrdinalIgnoreCase)).ToList().ForEach(r => {
-
                     try {
                         recipes.Add(_recipeParser.ParseRecipe(_webSiteFolder.ReadFile(r)));
                     }
                     catch (Exception ex) {
-                        Logger.Error(new Exception(string.Format("Invalid recipe file: {0}\nError: {1}", r, ex.Message)), "Invalid recipe file: {0}\nError: {1}", r, ex.Message);
+                        Logger.Error(ex, "Error while parsing recipe file '{0}'.", r);
                     }
-
                 });
             }
             else {

src/Orchard.Web/Modules/Orchard.Recipes/Services/RecipeParser.cs

@@ -19,8 +19,6 @@ namespace Orchard.Recipes.Services {
         public Recipe ParseRecipe(string recipeText) {
             var recipe = new Recipe();
 
-            try {
-
             if (string.IsNullOrEmpty(recipeText)) {
                 throw new Exception("Recipe is empty");
             }
@@ -30,7 +28,7 @@ namespace Orchard.Recipes.Services {
             var recipeSteps = new List<RecipeStep>();
 
             foreach (var element in recipeTree.Elements()) {
-                    // Recipe mETaDaTA
+                // Recipe metadata
                 if (element.Name.LocalName == "Recipe") {
                     foreach (var metadataElement in element.Elements()) {
                         switch (metadataElement.Name.LocalName) {
@@ -59,7 +57,7 @@ namespace Orchard.Recipes.Services {
                                 recipe.Tags = metadataElement.Value;
                                 break;
                             default:
-                                    Logger.Error("Unrecognized recipe metadata element {0} encountered. Skipping.", metadataElement.Name.LocalName);
+                                Logger.Warning("Unrecognized recipe metadata element '{0}' encountered; skipping.", metadataElement.Name.LocalName);
                                 break;
                         }
                     }
@@ -70,12 +68,8 @@ namespace Orchard.Recipes.Services {
                     recipeSteps.Add(recipeStep);
                 }
             }
+
             recipe.RecipeSteps = recipeSteps;
-            }
-            catch (Exception exception) {
-                Logger.Error(exception, "Parsing recipe failed. Recipe text was: {0}.", recipeText);
-                throw;
-            }
 
             return recipe;
         }

src/Orchard.Web/Modules/Orchard.Recipes/Services/RecipeScheduler.cs

@@ -3,6 +3,7 @@ using System.Collections.Generic;
 using Orchard.Environment.Configuration;
 using Orchard.Environment.Descriptor;
 using Orchard.Environment.State;
+using Orchard.Logging;
 using Orchard.Recipes.Events;
 
 namespace Orchard.Recipes.Services {
@@ -17,16 +18,21 @@ namespace Orchard.Recipes.Services {
             IProcessingEngine processingEngine,
             ShellSettings shellSettings,
             IShellDescriptorManager shellDescriptorManager,
-            Lazy<IRecipeStepExecutor> recipeStepExecutor, IShellDescriptorManagerEventHandler events) {
+            Lazy<IRecipeStepExecutor> recipeStepExecutor,
+            IShellDescriptorManagerEventHandler events) {
             _processingEngine = processingEngine;
             _shellSettings = shellSettings;
             _shellDescriptorManager = shellDescriptorManager;
             _recipeStepExecutor = recipeStepExecutor;
             _events = events;
+            Logger = NullLogger.Instance;
         }
 
+        public ILogger Logger;
+
         public void ScheduleWork(string executionId) {
             var shellDescriptor = _shellDescriptorManager.GetShellDescriptor();
+            Logger.Information("Scheduling execution of recipe {0}.", executionId);
             // TODO: this task entry may need to become appdata folder backed if it isn't already
             _processingEngine.AddTask(
                 _shellSettings,
@@ -36,6 +42,7 @@ namespace Orchard.Recipes.Services {
         }
 
         public void ExecuteWork(string executionId) {
+            Logger.Information("Executing next step of recipe {0}.", executionId);
             // todo: this callback should be guarded against concurrency by the IProcessingEngine
             var scheduleMore = _recipeStepExecutor.Value.ExecuteNextStep(executionId);
             if (scheduleMore)

src/Orchard.Web/Modules/Orchard.Recipes/Services/RecipeStepQueue.cs

@@ -23,6 +23,7 @@ namespace Orchard.Recipes.Services {
         public ILogger Logger { get; set; }
 
         public void Enqueue(string executionId, RecipeStep step) {
+            Logger.Information("Enqueuing step '{0}' for recipe {1}.", step.Name, executionId);
             var recipeStepElement = new XElement("RecipeStep");
             recipeStepElement.Add(new XElement("Name", step.Name));
             recipeStepElement.Add(step.Step);
@@ -40,6 +41,7 @@ namespace Orchard.Recipes.Services {
         }
 
         public RecipeStep Dequeue(string executionId) {
+            Logger.Information("Dequeuing steps for recipe {0}.", executionId);
             if (!_appDataFolder.DirectoryExists(Path.Combine(_recipeQueueFolder, executionId))) {
                 return null;
             }
@@ -50,6 +52,7 @@ namespace Orchard.Recipes.Services {
                 // string to xelement
                 var stepElement = XElement.Parse(_appDataFolder.ReadFile(stepPath));
                 var stepName = stepElement.Element("Name").Value;
+                Logger.Information("Dequeuing step '{0}' for recipe {1}.", stepName, executionId);
                 recipeStep = new RecipeStep {
                     Name = stepName,
                     Step = stepElement.Element(stepName)