Fix msbuild log truncation issue

The msbuild output was sometimes truncated since it was sent from the builder
process to MD using a one-way WriteLine method, which means the call may return
before the remote method is executed. In some cases the remote logger was
disposed before the WriteLine method was completed, and that log was lost.

This patch removes the one-way method and adds code to periodically flush
the log to MD. Before returning the build result it ensures that all log has
been sent.

Fixes bug #35322 - Xamarin Studio diagnostic build output sometimes omits
some of the Task and Target "performance summary" lines

4 files changed, 73 insertions, 17 deletions

diff --git a/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ILogWriter.cs b/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ILogWriter.cs
index 10f7982178..744b177d75 100644
--- a/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ILogWriter.cs
+++ b/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ILogWriter.cs
@@ -32,7 +32,7 @@ namespace MonoDevelop.Projects.MSBuild
 {
 	public interface ILogWriter
 	{
-		void WriteLine (string text);
+		void Write (string text);
 	}
 	
 	public class LogWriter: MarshalByRefObject, ILogWriter
@@ -44,10 +44,9 @@ namespace MonoDevelop.Projects.MSBuild
 			this.writer = writer;
 		}
 
-		[OneWayAttribute]
-		public void WriteLine (string text)
+		public void Write (string text)
 		{
-			writer.WriteLine (text);
+			writer.Write (text);
 		}
 		
 		public override object InitializeLifetimeService ()
diff --git a/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ProjectBuilder.Shared.cs b/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ProjectBuilder.Shared.cs
index ec79d80dc5..48c6e228c3 100644
--- a/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ProjectBuilder.Shared.cs
+++ b/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ProjectBuilder.Shared.cs
@@ -29,11 +29,21 @@
 using Microsoft.Build.Framework;

 using System.Xml;

 using System.IO;

+using System;

+using System.Text;

+using System.Threading;

 

 namespace MonoDevelop.Projects.MSBuild

 {

 	partial class ProjectBuilder

 	{

+		ILogWriter currentLogWriter;

+		StringBuilder log = new StringBuilder ();

+		bool flushingLog;

+		Timer flushTimer;

+		object flushLogLock = new object ();

+		const int LogFlushTimeout = 100;

+

 		public void Dispose ()

 		{

 			buildEngine.UnloadProject (file);

@@ -50,10 +60,61 @@ namespace MonoDevelop.Projects.MSBuild
 			buildEngine.SetUnsavedProjectContent (file, projectContent);

 		}

 

+		/// <summary>

+		/// Prepares the logging infrastructure

+		/// </summary>

+		void InitLogger (ILogWriter logWriter)

+		{

+			currentLogWriter = logWriter;

+			log.Clear ();

+			flushingLog = false;

+			flushTimer = new Timer (o => FlushLog ());

+		}

+

+		/// <summary>

+		/// Flushes the log that has not yet been sent and disposes the logging infrastructure

+		/// </summary>

+		void DisposeLogger ()

+		{

+			flushTimer.Dispose ();

+			flushTimer = null;

+			FlushLog ();

+			currentLogWriter = null;

+		}

+

 		void LogWriteLine (string txt)

 		{

-			if (currentLogWriter != null)

-				currentLogWriter.WriteLine (txt);

+			if (currentLogWriter != null) {

+				lock (log) {

+					// Append the line to the log, and schedule the flush of the log, unless it has already been done

+					log.AppendLine (txt);

+					if (!flushingLog) {

+						// Flush the log after 100ms

+						flushingLog = true;

+						flushTimer.Change (LogFlushTimeout, Timeout.Infinite);

+					}

+				}

+			}

+		}

+

+		void FlushLog ()

+		{

+			// We need a lock for the whole method here because it is called from the timer

+			// and from DisposeLogger, and we want to make sure a flush is complete before

+			// trying another one

+

+			lock (flushLogLock) {
+				string txt;
+				lock (log) {

+					// Don't flush the log inside the lock since that would prevent LogWriteLine from writing

+					// more log while the current log is being flushed (that would slow down the whole build)
+					txt = log.ToString ();
+					log.Clear ();
+					flushingLog = false;
+				}
+				if (txt.Length > 0 && currentLogWriter != null)
+					currentLogWriter.Write (txt);

+			}

 		}

 

 		LoggerVerbosity GetVerbosity (MSBuildVerbosity verbosity)

diff --git a/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ProjectBuilder.cs b/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ProjectBuilder.cs
index 73a986555b..2139d21456 100644
--- a/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ProjectBuilder.cs
+++ b/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ProjectBuilder.cs
@@ -45,7 +45,6 @@ namespace MonoDevelop.Projects.MSBuild
 	public partial class ProjectBuilder: MarshalByRefObject, IProjectBuilder
 	{
 		readonly string file;
-		ILogWriter currentLogWriter;
 		readonly MDConsoleLogger consoleLogger;
 		readonly BuildEngine buildEngine;
 

@@ -66,8 +65,8 @@ namespace MonoDevelop.Projects.MSBuild
 			MSBuildResult result = null;
 			BuildEngine.RunSTA (taskId, delegate {
 				try {
-					var project = SetupProject (configurations);

-					currentLogWriter = logWriter;

+					var project = SetupProject (configurations);
+					InitLogger (logWriter);

 

 					buildEngine.Engine.UnregisterAllLoggers ();
 
@@ -122,11 +121,10 @@ namespace MonoDevelop.Projects.MSBuild
 						file, false, ex.ErrorSubcategory, ex.ErrorCode, ex.ProjectFile,
 						ex.LineNumber, ex.ColumnNumber, ex.EndLineNumber, ex.EndColumnNumber,
 						ex.BaseMessage, ex.HelpKeyword);
-					if (logWriter != null)
-						logWriter.WriteLine (r.ToString ());
+					LogWriteLine (r.ToString ());
 					result = new MSBuildResult (new [] { r });
 				} finally {

-					currentLogWriter = null;

+					DisposeLogger ();

 				}

 			});

 			return result;
diff --git a/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ProjectBuilder.v4.0.cs b/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ProjectBuilder.v4.0.cs
index 5f0b8a06f1..14b5b382f8 100644
--- a/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ProjectBuilder.v4.0.cs
+++ b/main/src/core/MonoDevelop.Projects.Formats.MSBuild/MonoDevelop.Projects.Formats.MSBuild/ProjectBuilder.v4.0.cs
@@ -42,7 +42,6 @@ namespace MonoDevelop.Projects.MSBuild
 	{

 		readonly ProjectCollection engine;

 		readonly string file;

-		ILogWriter currentLogWriter;

 		readonly BuildEngine buildEngine;

 

 		public ProjectBuilder (BuildEngine buildEngine, ProjectCollection engine, string file)

@@ -64,7 +63,7 @@ namespace MonoDevelop.Projects.MSBuild
 			BuildEngine.RunSTA (taskId, delegate {

 				try {

 					var project = SetupProject (configurations);

-					currentLogWriter = logWriter;

+					InitLogger (logWriter);

 

 					ILogger[] loggers;

 					var logger = new LocalLogger (file);

@@ -112,11 +111,10 @@ namespace MonoDevelop.Projects.MSBuild
 						file, false, ex.ErrorSubcategory, ex.ErrorCode, ex.ProjectFile,

 						ex.LineNumber, ex.ColumnNumber, ex.EndLineNumber, ex.EndColumnNumber,

 						ex.BaseMessage, ex.HelpKeyword);

-					if (logWriter != null)

-						logWriter.WriteLine (r.ToString ());

+					LogWriteLine (r.ToString ());

 					result = new MSBuildResult (new [] { r });

 				} finally {

-					currentLogWriter = null;

+					DisposeLogger ();

 				}

 			});

 			return result;