Reduce runtime for and allocations from BaseConsoleLogger.IndentString

src/Build.UnitTests/ConsoleLogger_Tests.cs

@@ -1234,15 +1234,15 @@ public void MultilineFormatUnixLineEndings()
         [Fact]
         public void MultilineFormatMixedLineEndings()
         {
-            string s = "foo" + "\r\n\r\n" + "bar" + "\n" + "baz" + "\n\r\n\n" +
+            string s = "\n" + "foo" + "\r\n\r\n" + "bar" + "\n" + "baz" + "\n\r\n\n" +
                 "jazz" + "\r\n" + "razz" + "\n\n" + "matazz" + "\n" + "end";
 
             SerialConsoleLogger cl = new SerialConsoleLogger();
 
             string ss = cl.IndentString(s, 0);
 
             // should convert lines to system format
-            ss.ShouldBe($"foo{Environment.NewLine}{Environment.NewLine}bar{Environment.NewLine}baz{Environment.NewLine}{Environment.NewLine}{Environment.NewLine}jazz{Environment.NewLine}razz{Environment.NewLine}{Environment.NewLine}matazz{Environment.NewLine}end{Environment.NewLine}");
+            ss.ShouldBe($"{Environment.NewLine}foo{Environment.NewLine}{Environment.NewLine}bar{Environment.NewLine}baz{Environment.NewLine}{Environment.NewLine}{Environment.NewLine}jazz{Environment.NewLine}razz{Environment.NewLine}{Environment.NewLine}matazz{Environment.NewLine}end{Environment.NewLine}");
         }
 
         [Fact]

src/Build.UnitTests/ConsoleOutputAlignerTests.cs

@@ -2,7 +2,9 @@
 // The .NET Foundation licenses this file to you under the MIT license.
 
 using System;
+using System.Text;
 using Microsoft.Build.BackEnd.Logging;
+using Microsoft.Build.Framework;
 using Shouldly;
 using Xunit;
 
@@ -18,7 +20,7 @@ public class ConsoleOutputAlignerTests
         public void IndentBiggerThanBuffer_IndentedAndNotAligned(string input, bool aligned)
         {
             string indent = "    ";
-            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: aligned);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: aligned, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: false, prefixWidth: indent.Length);
 
@@ -30,7 +32,7 @@ public void IndentBiggerThanBuffer_IndentedAndNotAligned(string input, bool alig
         [InlineData("12345")]
         public void NoAlignNoIndent_NotAlignedEvenIfBiggerThanBuffer(string input)
         {
-            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: false);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: false, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: false, prefixWidth: 0);
 
@@ -43,7 +45,7 @@ public void NoAlignNoIndent_NotAlignedEvenIfBiggerThanBuffer(string input)
         public void NoBufferWidthNoIndent_NotAligned(int sizeOfMessage)
         {
             string input = new string('.', sizeOfMessage);
-            var aligner = new ConsoleOutputAligner(bufferWidth: -1, alignMessages: false);
+            var aligner = new ConsoleOutputAligner(bufferWidth: -1, alignMessages: false, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: false, prefixWidth: 0);
 
@@ -55,7 +57,7 @@ public void NoBufferWidthNoIndent_NotAligned(int sizeOfMessage)
         [InlineData("12345")]
         public void WithoutBufferWidthWithoutIndentWithAlign_NotIndentedAndNotAligned(string input)
         {
-            var aligner = new ConsoleOutputAligner(bufferWidth: -1, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: -1, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: false, prefixWidth: 0);
 
@@ -67,7 +69,7 @@ public void WithoutBufferWidthWithoutIndentWithAlign_NotIndentedAndNotAligned(st
         [InlineData("12345")]
         public void NoAlignPrefixAlreadyWritten_NotChanged(string input)
         {
-            var aligner = new ConsoleOutputAligner(bufferWidth: 10, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 10, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: true, prefixWidth: 0);
 
@@ -80,7 +82,7 @@ public void NoAlignPrefixAlreadyWritten_NotChanged(string input)
         [InlineData("  ", "1")]
         public void SmallerThanBuffer_NotAligned(string indent, string input)
         {
-            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: false, prefixWidth: indent.Length);
 
@@ -93,7 +95,7 @@ public void SmallerThanBuffer_NotAligned(string indent, string input)
         [InlineData("  ", "12", "  1", "  2")]
         public void BiggerThanBuffer_AlignedWithIndent(string indent, string input, string expected1stLine, string expected2ndLine)
         {
-            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: false, prefixWidth: indent.Length);
 
@@ -114,7 +116,7 @@ public void BiggerThanBuffer_AlignedWithIndent(string indent, string input, stri
                                   "  4\n")]
         public void XTimesBiggerThanBuffer_AlignedToMultipleLines(string indent, string input, string expected)
         {
-            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: false, prefixWidth: indent.Length);
 
@@ -128,7 +130,7 @@ public void XTimesBiggerThanBuffer_AlignedToMultipleLines(string indent, string
         [InlineData("  ", "12", "1", "  2")]
         public void BiggerThanBufferWithPrefixAlreadyWritten_AlignedWithIndentFromSecondLine(string indent, string input, string expected1stLine, string expected2ndLine)
         {
-            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: true, prefixWidth: indent.Length);
 
@@ -142,7 +144,7 @@ public void BiggerThanBufferWithPrefixAlreadyWritten_AlignedWithIndentFromSecond
         public void MultiLineWithoutAlign_NotChanged(string input)
         {
             input = input.Replace("\n", Environment.NewLine);
-            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: false);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: false, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: true, prefixWidth: 0);
 
@@ -165,7 +167,7 @@ public void NonStandardNewLines_AlignAsExpected(string input, string expected)
         {
             expected = expected.Replace("\n", Environment.NewLine) + Environment.NewLine;
 
-            var aligner = new ConsoleOutputAligner(bufferWidth: 10, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 10, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: true, prefixWidth: 2);
 
@@ -179,7 +181,7 @@ public void NonStandardNewLines_AlignAsExpected(string input, string expected)
         public void ShortMultiLineWithAlign_NoChange(string input)
         {
             input = input.Replace("\n", Environment.NewLine);
-            var aligner = new ConsoleOutputAligner(bufferWidth: 10, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 10, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: true, prefixWidth: 0);
 
@@ -202,7 +204,7 @@ public void ShortMultiLineWithAlign_NoChange(string input)
         public void ShortMultiLineWithMixedNewLines_NewLinesReplacedByActualEnvironmentNewLines(string input)
         {
             string expected = input.Replace("\r", "").Replace("\n", Environment.NewLine) + Environment.NewLine;
-            var aligner = new ConsoleOutputAligner(bufferWidth: 10, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 10, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: true, prefixWidth: 0);
 
@@ -217,7 +219,7 @@ public void MultiLineWithPrefixAlreadyWritten(string prefix, string input, strin
         {
             input = input.Replace("\n", Environment.NewLine);
             expected = expected.Replace("\n", Environment.NewLine);
-            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: true, prefixWidth: prefix.Length);
 
@@ -231,7 +233,7 @@ public void MultiLineWithoutPrefixAlreadyWritten(string prefix, string input, st
         {
             input = input.Replace("\n", Environment.NewLine);
             expected = expected.Replace("\n", Environment.NewLine);
-            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 4, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: false, prefixWidth: prefix.Length);
 
@@ -244,7 +246,7 @@ public void MultiLineWithoutPrefixAlreadyWritten(string prefix, string input, st
         public void ShortTextWithTabs_NoChange(string input)
         {
             input = input.Replace("\n", Environment.NewLine);
-            var aligner = new ConsoleOutputAligner(bufferWidth: 50, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: 50, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: true, prefixWidth: 0);
 
@@ -259,7 +261,7 @@ public void ShortTextWithTabs_NoChange(string input)
         public void LastTabOverLimit_NoChange(string prefix, string input, int bufferWidthWithoutNewLine, bool prefixAlreadyWritten)
         {
             input = input.Replace("\n", Environment.NewLine);
-            var aligner = new ConsoleOutputAligner(bufferWidth: bufferWidthWithoutNewLine + 1, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: bufferWidthWithoutNewLine + 1, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: prefixAlreadyWritten, prefixWidth: prefix.Length);
 
@@ -274,7 +276,7 @@ public void LastTabOverLimit_NoChange(string prefix, string input, int bufferWid
         public void LastTabAtLimit_NoChange(string prefix, string input, int bufferWidthWithoutNewLine, bool prefixAlreadyWritten)
         {
             input = input.Replace("\n", Environment.NewLine);
-            var aligner = new ConsoleOutputAligner(bufferWidth: bufferWidthWithoutNewLine + 1, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: bufferWidthWithoutNewLine + 1, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: prefixAlreadyWritten, prefixWidth: prefix.Length);
 
@@ -289,7 +291,7 @@ public void LastTabAtLimit_NoChange(string prefix, string input, int bufferWidth
         public void TabsMakesItJustOverLimit_IndentAndAlign(string prefix, string input, int bufferWidthWithoutNewLine, bool prefixAlreadyWritten)
         {
             input = input.Replace("\n", Environment.NewLine);
-            var aligner = new ConsoleOutputAligner(bufferWidth: bufferWidthWithoutNewLine + 1, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: bufferWidthWithoutNewLine + 1, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input + "x", prefixAlreadyWritten: prefixAlreadyWritten, prefixWidth: prefix.Length);
 
@@ -366,11 +368,17 @@ public void MultiLinesOverLimit_IndentAndAlign(string prefix, string input, stri
         {
             input = input.Replace("\n", Environment.NewLine);
             expected = expected.Replace("\n", Environment.NewLine);
-            var aligner = new ConsoleOutputAligner(bufferWidth: bufferWidthWithoutNewLine + 1, alignMessages: true);
+            var aligner = new ConsoleOutputAligner(bufferWidth: bufferWidthWithoutNewLine + 1, alignMessages: true, stringBuilderProvider: new TestStringBuilderProvider());
 
             string output = aligner.AlignConsoleOutput(message: input, prefixAlreadyWritten: prefixAlreadyWritten, prefixWidth: prefix.Length);
 
             output.ShouldBe(expected);
         }
+
+        private sealed class TestStringBuilderProvider : IStringBuilderProvider
+        {
+            public StringBuilder Acquire(int capacity) => new StringBuilder(capacity);
+            public string GetStringAndRelease(StringBuilder builder) => builder.ToString();
+        }
     }
 }

src/Build/Logging/BaseConsoleLogger.cs

@@ -4,10 +4,12 @@
 using System;
 using System.Collections;
 using System.Collections.Generic;
+using System.Diagnostics;
 using System.Globalization;
 using System.IO;
 using System.Linq;
 using System.Text;
+using System.Threading;
 using Microsoft.Build.Evaluation;
 using Microsoft.Build.Framework;
 using Microsoft.Build.Internal;
@@ -24,7 +26,7 @@ namespace Microsoft.Build.BackEnd.Logging
     internal delegate void WriteLinePrettyFromResourceDelegate(int indentLevel, string resourceString, params object[] args);
     #endregion
 
-    internal abstract class BaseConsoleLogger : INodeLogger
+    internal abstract class BaseConsoleLogger : INodeLogger, IStringBuilderProvider
     {
         #region Properties
 
@@ -130,28 +132,7 @@ public int Compare(Object a, Object b)
         /// <param name="indent">Depth to indent.</param>
         internal string IndentString(string s, int indent)
         {
-            // It's possible the event has a null message
-            if (s == null)
-            {
-                return string.Empty;
-            }
-
-            // This will never return an empty array.  The returned array will always
-            // have at least one non-null element, even if "s" is totally empty.
-            String[] subStrings = SplitStringOnNewLines(s);
-
-            StringBuilder result = new StringBuilder(
-                (subStrings.Length * indent) +
-                (subStrings.Length * Environment.NewLine.Length) +
-                s.Length);
-
-            for (int i = 0; i < subStrings.Length; i++)
-            {
-                result.Append(' ', indent).Append(subStrings[i]);
-                result.AppendLine();
-            }
-
-            return result.ToString();
+            return OptimizedStringIndenter.IndentString(s, indent, (IStringBuilderProvider)this);
         }
 
         /// <summary>
@@ -1208,6 +1189,14 @@ private bool ApplyVerbosityParameter(string parameterValue)
 
         internal bool runningWithCharacterFileType = false;
 
+        /// <summary>
+        /// Since logging messages are processed serially, we can use a single StringBuilder wherever needed.
+        /// It should not be done directly, but rather through the <see cref="IStringBuilderProvider"/> interface methods.
+        /// </summary>
+        private StringBuilder _sharedStringBuilder = new StringBuilder(0x100);
+
+        #endregion
+
         #region Per-build Members
 
         /// <summary>
@@ -1252,6 +1241,72 @@ private bool ApplyVerbosityParameter(string parameterValue)
 
         #endregion
 
-        #endregion
+        /// <summary>
+        /// Since logging messages are processed serially, we can reuse a single StringBuilder wherever needed.
+        /// </summary>
+        StringBuilder IStringBuilderProvider.Acquire(int capacity)
+        {
+            StringBuilder shared = Interlocked.Exchange(ref _sharedStringBuilder, null);
+
+            Debug.Assert(shared != null, "This is not supposed to be used in multiple threads or multiple time. One method is expected to return it before next acquire. Most probably it was not returned.");
+            if (shared == null)
+            {
+                // This is not supposed to be used concurrently. One method is expected to return it before next acquire.
+                // However to avoid bugs in production, we will create new string builder
+                return StringBuilderCache.Acquire(capacity);
+            }
+
+            if (shared.Capacity < capacity)
+            {
+                const int minimumCapacity = 0x100; // 256 characters, 512 bytes
+                const int maximumBracketedCapacity = 0x80_000; // 512K characters, 1MB
+
+                if (capacity <= minimumCapacity)
+                {
+                    capacity = minimumCapacity;
+                }
+                else if (capacity < maximumBracketedCapacity)
+                {
+                    // GC likes arrays allocated with power of two bytes. Lets make it happy.
+
+                    // Find next power of two http://graphics.stanford.edu/~seander/bithacks.html#RoundUpPowerOf2
+                    int v = capacity;
+
+                    v--;
+                    v |= v >> 1;
+                    v |= v >> 2;
+                    v |= v >> 4;
+                    v |= v >> 8;
+                    v |= v >> 16;
+                    v++;
+
+                    capacity = v;
+                }
+                // If capacity is > maximumCapacity we will respect it and use it as is.
+
+                // Lets create new instance with enough capacity.
+                shared = new StringBuilder(capacity);
+            }
+
+            // Prepare for next use.
+            // Equivalent of sb.Clear() that works on .Net 3.5
+            shared.Length = 0; 
+
+            return shared;
+        }
+
+        /// <summary>
+        /// Acquired StringBuilder must be returned before next use.
+        /// Unbalanced releases are not supported.
+        /// </summary>
+        string IStringBuilderProvider.GetStringAndRelease(StringBuilder builder)
+        {
+            // This is not supposed to be used concurrently. One method is expected to return it before next acquire.
+            // But just for sure if _sharedBuilder was already returned, keep the former.
+            StringBuilder previous = Interlocked.CompareExchange(ref _sharedStringBuilder, builder, null);
+            Debug.Assert(previous == null, "This is not supposed to be used in multiple threads or multiple time. One method is expected to return it before next acquire. Most probably it was double returned.");
+
+            return builder.ToString();
+        }
     }
 }