Logging improvements

GitVersionCore.Tests/ModuleInitializer.cs

@@ -11,8 +11,6 @@ public static class ModuleInitializer
     /// </summary>
     public static void Initialize()
     {
-        Logger.WriteInfo = s => Trace.WriteLine(s);
-        Logger.WriteError = s => Trace.WriteLine(s);
-        Logger.WriteWarning = s => Trace.WriteLine(s);
+        Logger.SetLoggers(s => Trace.WriteLine(s), s => Trace.WriteLine(s), s => Trace.WriteLine(s));
     }
 }

GitVersionCore/BranchConfigurationCalculator.cs

@@ -40,103 +40,105 @@ static KeyValuePair<string, BranchConfig>[] LookupBranchConfiguration(Config con
 
         static KeyValuePair<string, BranchConfig> InheritBranchConfiguration(bool onlyEvaluateTrackedBranches, IRepository repository, Commit currentCommit, Branch currentBranch, KeyValuePair<string, BranchConfig> keyValuePair, BranchConfig branchConfiguration, Config config, IList<Branch> excludedInheritBranches)
         {
-            Logger.WriteInfo("Attempting to inherit branch configuration from parent branch");
-            var excludedBranches = new [] { currentBranch };
-            // Check if we are a merge commit. If so likely we are a pull request
-            var parentCount = currentCommit.Parents.Count();
-            if (parentCount == 2)
+            using (Logger.IndentLog("Attempting to inherit branch configuration from parent branch"))
             {
-                var parents = currentCommit.Parents.ToArray();
-                var branch = repository.Branches.SingleOrDefault(b => !b.IsRemote && b.Tip == parents[1]);
-                if (branch != null)
+                var excludedBranches = new[] { currentBranch };
+                // Check if we are a merge commit. If so likely we are a pull request
+                var parentCount = currentCommit.Parents.Count();
+                if (parentCount == 2)
                 {
-                    excludedBranches = new[]
+                    var parents = currentCommit.Parents.ToArray();
+                    var branch = repository.Branches.SingleOrDefault(b => !b.IsRemote && b.Tip == parents[1]);
+                    if (branch != null)
                     {
+                        excludedBranches = new[]
+                        {
                         currentBranch,
                         branch
                     };
-                    currentBranch = branch;
+                        currentBranch = branch;
+                    }
+                    else
+                    {
+                        var possibleTargetBranches = repository.Branches.Where(b => !b.IsRemote && b.Tip == parents[0]).ToList();
+                        if (possibleTargetBranches.Count() > 1)
+                        {
+                            currentBranch = possibleTargetBranches.FirstOrDefault(b => b.Name == "master") ?? possibleTargetBranches.First();
+                        }
+                        else
+                        {
+                            currentBranch = possibleTargetBranches.FirstOrDefault() ?? currentBranch;
+                        }
+                    }
+
+                    Logger.WriteInfo("HEAD is merge commit, this is likely a pull request using " + currentBranch.Name + " as base");
+                }
+                if (excludedInheritBranches == null)
+                {
+                    excludedInheritBranches = repository.Branches.Where(b =>
+                    {
+                        var branchConfig = LookupBranchConfiguration(config, b);
+                        return branchConfig.Length == 1 && branchConfig[0].Value.Increment == IncrementStrategy.Inherit;
+                    }).ToList();
+                }
+                excludedBranches.ToList().ForEach(excludedInheritBranches.Add);
+
+                var branchPoint = currentBranch.FindCommitBranchWasBranchedFrom(repository, excludedInheritBranches.ToArray());
+
+                List<Branch> possibleParents;
+                if (branchPoint == null)
+                {
+                    possibleParents = currentCommit.GetBranchesContainingCommit(repository, true).Except(excludedInheritBranches).ToList();
                 }
                 else
                 {
-                    var possibleTargetBranches = repository.Branches.Where(b => !b.IsRemote && b.Tip == parents[0]).ToList();
-                    if (possibleTargetBranches.Count() > 1)
+                    var branches = branchPoint.GetBranchesContainingCommit(repository, true).Except(excludedInheritBranches).ToList();
+                    if (branches.Count > 1)
                     {
-                        currentBranch = possibleTargetBranches.FirstOrDefault(b => b.Name == "master") ?? possibleTargetBranches.First();
+                        var currentTipBranches = currentCommit.GetBranchesContainingCommit(repository, true).Except(excludedInheritBranches).ToList();
+                        possibleParents = branches.Except(currentTipBranches).ToList();
                     }
                     else
                     {
-                        currentBranch = possibleTargetBranches.FirstOrDefault() ?? currentBranch;
+                        possibleParents = branches;
                     }
                 }
 
-                Logger.WriteInfo("HEAD is merge commit, this is likely a pull request using " + currentBranch.Name + " as base");
-            }
-            if (excludedInheritBranches == null)
-            {
-                excludedInheritBranches = repository.Branches.Where(b =>
-                {
-                    var branchConfig = LookupBranchConfiguration(config, b);
-                    return branchConfig.Length == 1 && branchConfig[0].Value.Increment == IncrementStrategy.Inherit;
-                }).ToList();
-            }
-            excludedBranches.ToList().ForEach(excludedInheritBranches.Add);
-
-            var branchPoint = currentBranch.FindCommitBranchWasBranchedFrom(repository, excludedInheritBranches.ToArray());
+                Logger.WriteInfo("Found possible parent branches: " + string.Join(", ", possibleParents.Select(p => p.Name)));
 
-            List<Branch> possibleParents;
-            if (branchPoint == null)
-            {
-                possibleParents = currentCommit.GetBranchesContainingCommit(repository, true).Except(excludedInheritBranches).ToList();
-            }
-            else
-            {
-                var branches = branchPoint.GetBranchesContainingCommit(repository, true).Except(excludedInheritBranches).ToList();
-                if (branches.Count > 1)
+                if (possibleParents.Count == 1)
                 {
-                    var currentTipBranches = currentCommit.GetBranchesContainingCommit(repository, true).Except(excludedInheritBranches).ToList();
-                    possibleParents = branches.Except(currentTipBranches).ToList();
+                    var branchConfig = GetBranchConfiguration(currentCommit, repository, onlyEvaluateTrackedBranches, config, possibleParents[0], excludedInheritBranches).Value;
+                    return new KeyValuePair<string, BranchConfig>(
+                        keyValuePair.Key,
+                        new BranchConfig(branchConfiguration)
+                        {
+                            Increment = branchConfig.Increment,
+                            PreventIncrementOfMergedBranchVersion = branchConfig.PreventIncrementOfMergedBranchVersion
+                        });
                 }
+
+                // If we fail to inherit it is probably because the branch has been merged and we can't do much. So we will fall back to develop's config
+                // if develop exists and master if not
+                string errorMessage;
+                if (possibleParents.Count == 0)
+                    errorMessage = "Failed to inherit Increment branch configuration, no branches found.";
                 else
-                {
-                    possibleParents = branches;
-                }
-            }
+                    errorMessage = "Failed to inherit Increment branch configuration, ended up with: " + string.Join(", ", possibleParents.Select(p => p.Name));
 
-            Logger.WriteInfo("Found possible parent branches: " + string.Join(", ", possibleParents.Select(p => p.Name)));
+                var developBranch = repository.Branches.FirstOrDefault(b => Regex.IsMatch(b.Name, "^develop", RegexOptions.IgnoreCase));
+                var branchName = developBranch != null ? developBranch.Name : "master";
 
-            if (possibleParents.Count == 1)
-            {
-                var branchConfig = GetBranchConfiguration(currentCommit, repository, onlyEvaluateTrackedBranches, config, possibleParents[0], excludedInheritBranches).Value;
+                Logger.WriteWarning(errorMessage + Environment.NewLine + Environment.NewLine + "Falling back to " + branchName + " branch config");
+                var value = GetBranchConfiguration(currentCommit, repository, onlyEvaluateTrackedBranches, config, repository.Branches[branchName]).Value;
                 return new KeyValuePair<string, BranchConfig>(
                     keyValuePair.Key,
                     new BranchConfig(branchConfiguration)
                     {
-                        Increment = branchConfig.Increment,
-                        PreventIncrementOfMergedBranchVersion = branchConfig.PreventIncrementOfMergedBranchVersion
+                        Increment = value.Increment,
+                        PreventIncrementOfMergedBranchVersion = value.PreventIncrementOfMergedBranchVersion
                     });
             }
-
-            // If we fail to inherit it is probably because the branch has been merged and we can't do much. So we will fall back to develop's config
-            // if develop exists and master if not
-            string errorMessage;
-            if (possibleParents.Count == 0)
-                errorMessage = "Failed to inherit Increment branch configuration, no branches found.";
-            else
-                errorMessage = "Failed to inherit Increment branch configuration, ended up with: " + string.Join(", ", possibleParents.Select(p => p.Name));
-
-            var developBranch = repository.Branches.FirstOrDefault(b => Regex.IsMatch(b.Name, "^develop", RegexOptions.IgnoreCase));
-            var branchName = developBranch != null ? developBranch.Name : "master";
-
-            Logger.WriteWarning(errorMessage + Environment.NewLine + Environment.NewLine + "Falling back to " + branchName + " branch config");
-            var value = GetBranchConfiguration(currentCommit, repository, onlyEvaluateTrackedBranches, config, repository.Branches[branchName]).Value;
-            return new KeyValuePair<string, BranchConfig>(
-                keyValuePair.Key,
-                new BranchConfig(branchConfiguration)
-                {
-                    Increment = value.Increment,
-                    PreventIncrementOfMergedBranchVersion = value.PreventIncrementOfMergedBranchVersion
-                });
         }
     }
 }

GitVersionCore/Logger.cs

@@ -1,23 +1,65 @@
 namespace GitVersion
 {
     using System;
+    using System.Globalization;
 
     public static class Logger
     {
-        public static Action<string> WriteInfo;
-        public static Action<string> WriteWarning;
-        public static Action<string> WriteError;
+        static string indent = string.Empty;
+
+        public static Action<string> WriteInfo { get; private set; }
+        public static Action<string> WriteWarning { get; private set; }
+        public static Action<string> WriteError { get; private set; }
 
         static Logger()
         {
             Reset();
         }
 
+        public static IDisposable IndentLog(string operationDescription)
+        {
+            var start = DateTime.Now;
+            indent = indent + "  ";
+            WriteInfo("Begin: " + operationDescription);
+            return new ActionDisposable(() =>
+            {
+                indent = indent.Substring(0, indent.Length - 2);
+                WriteInfo(string.Format(CultureInfo.InvariantCulture, "End: {0} (Took: {1:N}ms)", operationDescription, DateTime.Now.Subtract(start).TotalMilliseconds));
+            });
+        }
+
+        public static void SetLoggers(Action<string> info, Action<string> warn, Action<string> error)
+        {
+            WriteInfo = LogMessage(info, "INFO");
+            WriteWarning = LogMessage(warn, "WARN");
+            WriteError = LogMessage(error, "ERROR");
+        }
+
+        static Action<string> LogMessage(Action<string> logAction, string level)
+        {
+            return s => logAction(string.Format(CultureInfo.InvariantCulture, "{0}{1} [{2:MM/dd/yy H:mm:ss:ff}] {3}", indent, level, DateTime.Now, s));
+        }
+
         public static void Reset()
         {
             WriteInfo = s => { throw new Exception("Logger not defined."); };
             WriteWarning = s => { throw new Exception("Logger not defined."); };
             WriteError = s => { throw new Exception("Logger not defined."); };
         }
+
+        class ActionDisposable : IDisposable
+        {
+            readonly Action action;
+
+            public ActionDisposable(Action action)
+            {
+                this.action = action;
+            }
+
+            public void Dispose()
+            {
+                action();
+            }
+        }
     }
 }

GitVersionCore/VersionCalculation/BaseVersionCalculator.cs

@@ -14,33 +14,34 @@ public BaseVersionCalculator(params BaseVersionStrategy[] strategies)
 
         public BaseVersion GetBaseVersion(GitVersionContext context)
         {
-            Logger.WriteInfo("Base Versions:");
-
-            var baseVersion = strategies
-                .Select(s => s.GetVersion(context))
-                .Where(v =>
-                {
-                    if (v != null)
+            using (Logger.IndentLog("Calculating base versions"))
+            {
+                var baseVersion = strategies
+                    .Select(s => s.GetVersion(context))
+                    .Where(v =>
                     {
-                        Logger.WriteInfo(v.ToString());
-                        return true;
-                    }
-
-                    return false;
-                })
-                .Aggregate((v1, v2) =>
-                {
-                    if (v1.SemanticVersion > v2.SemanticVersion)
+                        if (v != null)
+                        {
+                            Logger.WriteInfo(v.ToString());
+                            return true;
+                        }
+
+                        return false;
+                    })
+                    .Aggregate((v1, v2) =>
                     {
-                        return new BaseVersion(v1.Source, v1.ShouldIncrement, v1.SemanticVersion, v1.BaseVersionSource ?? v2.BaseVersionSource, v1.BranchNameOverride);
-                    }
+                        if (v1.SemanticVersion > v2.SemanticVersion)
+                        {
+                            return new BaseVersion(v1.Source, v1.ShouldIncrement, v1.SemanticVersion, v1.BaseVersionSource ?? v2.BaseVersionSource, v1.BranchNameOverride);
+                        }
 
-                    return new BaseVersion(v2.Source, v2.ShouldIncrement, v2.SemanticVersion, v2.BaseVersionSource ?? v1.BaseVersionSource, v2.BranchNameOverride);
-                });
+                        return new BaseVersion(v2.Source, v2.ShouldIncrement, v2.SemanticVersion, v2.BaseVersionSource ?? v1.BaseVersionSource, v2.BranchNameOverride);
+                    });
 
-            Logger.WriteInfo(string.Format("Base version used: {0}", baseVersion));
+                Logger.WriteInfo(string.Format("Base version used: {0}", baseVersion));
 
-            return baseVersion;
+                return baseVersion;
+            }
         }
     }
 }

GitVersionExe.Tests/GitPreparerTests.cs

@@ -11,9 +11,7 @@ public class GitPreparerTests
 {
     public GitPreparerTests()
     {
-        Logger.WriteInfo = s => { };
-        Logger.WriteWarning = s => { };
-        Logger.WriteError = s => { };
+        Logger.SetLoggers(s => { }, s => { }, s => { });
     }
 
     const string DefaultBranchName = "master";

GitVersionExe/Program.cs

@@ -126,9 +126,10 @@ static void ConfigureLogging(Arguments arguments)
                 }
             }
 
-            Logger.WriteInfo = s => writeActions.ForEach(a => a(s));
-            Logger.WriteWarning = s => writeActions.ForEach(a => a(s));
-            Logger.WriteError = s => writeActions.ForEach(a => a(s));
+            Logger.SetLoggers(
+                s => writeActions.ForEach(a => a(s)),
+                s => writeActions.ForEach(a => a(s)),
+                s => writeActions.ForEach(a => a(s)));
         }
 
         static void WriteLogEntry(Arguments arguments, string s)

GitVersionTask.Tests/ModuleInitializer.cs

@@ -11,9 +11,7 @@ public static class ModuleInitializer
     /// </summary>
     public static void Initialize()
     {
-        Logger.WriteInfo = s => Trace.WriteLine(s);
-        Logger.WriteError = s => Trace.WriteLine(s);
-        Logger.WriteWarning = s => Trace.WriteLine(s);
+        Logger.SetLoggers(s => Trace.WriteLine(s), s => Trace.WriteLine(s), s => Trace.WriteLine(s));
     }
 
 }

GitVersionTask/AssemblyInfoBuilder/UpdateAssemblyInfo.cs

@@ -35,8 +35,10 @@ public UpdateAssemblyInfo()
             CompileFiles = new ITaskItem[] { };
             logger = new TaskLogger(this);
             fileSystem = new FileSystem();
-            Logger.WriteInfo = this.LogInfo;
-            Logger.WriteWarning = this.LogWarning;
+            Logger.SetLoggers(
+                this.LogInfo,
+                this.LogWarning,
+                s => this.LogError(s));
         }
 
         public override bool Execute()

GitVersionTask/GetVersion.cs

@@ -78,8 +78,10 @@ public GetVersion()
         {
             logger = new TaskLogger(this);
             fileSystem = new FileSystem();
-            Logger.WriteInfo = this.LogInfo;
-            Logger.WriteWarning = this.LogWarning;
+            Logger.SetLoggers(
+                this.LogInfo,
+                this.LogWarning,
+                s => this.LogError(s));
         }
 
         public override bool Execute()

GitVersionTask/WriteVersionInfoToBuildLog.cs

@@ -22,8 +22,10 @@ public WriteVersionInfoToBuildLog()
         {
             logger = new TaskLogger(this);
             fileSystem = new FileSystem();
-            Logger.WriteInfo = this.LogInfo;
-            Logger.WriteWarning = this.LogWarning;
+            Logger.SetLoggers(
+                this.LogInfo,
+                this.LogWarning,
+                s => this.LogError(s));
         }
 
         public override bool Execute()