Output verbose logging during tests (#1698)

* Output verbose logging during tests

* fix compile

src/Microsoft.SqlTools.ServiceLayer/LanguageServices/LanguageService.cs

@@ -887,6 +887,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices
         /// <returns>The ParseResult instance returned from SQL Parser</returns>
         public ParseResult ParseAndBind(ScriptFile scriptFile, ConnectionInfo connInfo)
         {
+            Logger.Verbose($"ParseAndBind - {scriptFile}");
             // get or create the current parse info object
             ScriptParseInfo parseInfo = GetScriptParseInfo(scriptFile.ClientUri, createIfNotExists: true);
 
@@ -1487,20 +1488,22 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices
         /// <summary>
         /// Get function signature help for the current position
         /// </summary>
-        internal SignatureHelp GetSignatureHelp(TextDocumentPosition textDocumentPosition, ScriptFile scriptFile)
+        internal SignatureHelp? GetSignatureHelp(TextDocumentPosition textDocumentPosition, ScriptFile scriptFile)
         {
+            Logger.Verbose($"GetSignatureHelp -  {scriptFile}");
             int startLine = textDocumentPosition.Position.Line;
             int endColumn = textDocumentPosition.Position.Character;
 
-            ScriptParseInfo scriptParseInfo = GetScriptParseInfo(scriptFile.ClientUri);
+            ScriptParseInfo? scriptParseInfo = GetScriptParseInfo(scriptFile.ClientUri);
 
             if (scriptParseInfo == null)
             {
+                Logger.Verbose($"GetSignatureHelp - Could not find ScriptParseInfo for {scriptFile}");
                 // Cache not set up yet - skip and wait until later
                 return null;
             }
 
-            ConnectionInfo connInfo;
+            ConnectionInfo? connInfo;
             ConnectionServiceInstance.TryFindConnection(
                 scriptFile.ClientUri,
                 out connInfo);
@@ -1509,6 +1512,9 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices
             if (RequiresReparse(scriptParseInfo, scriptFile))
             {
                 ParseAndBind(scriptFile, connInfo);
+            } else
+            {
+                Logger.Verbose($"GetSignatureHelp - No reparse needed for {scriptFile}");
             }
 
             if (scriptParseInfo.ParseResult != null)
@@ -1558,6 +1564,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices
                     }
                 }
             }
+            Logger.Verbose($"GetSignatureHelp - No ScriptParseInfo.ParseResult for {scriptFile}");
 
             // return null if there isn't a tooltip for the current location
             return null;
@@ -1836,10 +1843,12 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices
             {
                 if (this.ScriptParseInfoMap.ContainsKey(uri))
                 {
+                    Logger.Verbose($"Updating ScriptParseInfo for uri {uri}");
                     this.ScriptParseInfoMap[uri] = scriptInfo;
                 }
                 else
                 {
+                    Logger.Verbose($"Adding ScriptParseInfo for uri {uri}");
                     this.ScriptParseInfoMap.Add(uri, scriptInfo);
                 }
 
@@ -1852,16 +1861,18 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices
         /// </summary>
         /// <param name="uri"></param>
         /// <param name="createIfNotExists">Creates a new instance if one doesn't exist</param>
-        internal ScriptParseInfo GetScriptParseInfo(string uri, bool createIfNotExists = false)
+        internal ScriptParseInfo? GetScriptParseInfo(string uri, bool createIfNotExists = false)
         {
             lock (this.parseMapLock)
             {
                 if (this.ScriptParseInfoMap.ContainsKey(uri))
                 {
+                    Logger.Verbose($"Found ScriptParseInfo for uri {uri}");
                     return this.ScriptParseInfoMap[uri];
                 }
                 else if (createIfNotExists)
                 {
+                    Logger.Verbose($"ScriptParseInfo for uri {uri} did not exist, creating new one");
                     // create a new script parse info object and initialize with the current settings
                     ScriptParseInfo scriptInfo = new ScriptParseInfo();
                     this.ScriptParseInfoMap.Add(uri, scriptInfo);
@@ -1869,6 +1880,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices
                 }
                 else
                 {
+                    Logger.Verbose($"Could not find ScriptParseInfo for uri {uri}");
                     return null;
                 }
             }
@@ -1880,6 +1892,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices
             {
                 if (this.ScriptParseInfoMap.ContainsKey(uri))
                 {
+                    Logger.Verbose($"Removing ScriptParseInfo for uri {uri}");
                     return this.ScriptParseInfoMap.Remove(uri);
                 }
                 else

test/Microsoft.SqlTools.ServiceLayer.IntegrationTests/LanguageServer/LanguageServiceTests.cs

@@ -246,12 +246,12 @@ namespace Microsoft.SqlTools.ServiceLayer.IntegrationTests.LanguageServer
             Thread.Sleep(2000);
 
             // We should get back a non-null ScriptParseInfo
-            ScriptParseInfo parseInfo = service.GetScriptParseInfo(result.ScriptFile.ClientUri);
-            Assert.NotNull(parseInfo);
+            ScriptParseInfo? parseInfo = service.GetScriptParseInfo(result.ScriptFile.ClientUri);
+            Assert.That(parseInfo, Is.Not.Null, "ScriptParseInfo");
 
             // And we should get back a non-null SignatureHelp
-            SignatureHelp signatureHelp = service.GetSignatureHelp(textDocument, result.ScriptFile);
-            Assert.NotNull(signatureHelp);
+            SignatureHelp? signatureHelp = service.GetSignatureHelp(textDocument, result.ScriptFile);
+            Assert.That(signatureHelp, Is.Not.Null, "SignatureHelp");
         }
 
         /// <summary>

test/Microsoft.SqlTools.ServiceLayer.Test.Common/TestServiceProvider.cs

@@ -5,6 +5,7 @@
 
 using System;
 using System.Collections.Generic;
+using System.Diagnostics;
 using System.IO;
 using System.Linq;
 using System.Runtime.CompilerServices;
@@ -17,6 +18,7 @@ using Microsoft.SqlTools.ServiceLayer.ObjectExplorer;
 using Microsoft.SqlTools.ServiceLayer.QueryExecution;
 using Microsoft.SqlTools.ServiceLayer.SqlContext;
 using Microsoft.SqlTools.ServiceLayer.Workspace;
+using Microsoft.SqlTools.Utility;
 using NUnit.Framework;
 
 namespace Microsoft.SqlTools.ServiceLayer.Test.Common
@@ -85,7 +87,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Test.Common
         }
 
         /// <summary>
-        /// Runs a query by calling the services directly (not using the test driver) 
+        /// Runs a query by calling the services directly (not using the test driver)
         /// </summary>
         public void RunQuery(TestServerType serverType, string databaseName, string queryText, bool throwOnError = false)
         {
@@ -94,7 +96,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Test.Common
         }
 
         /// <summary>
-        /// Runs a query by calling the services directly (not using the test driver) 
+        /// Runs a query by calling the services directly (not using the test driver)
         /// </summary>
         public async Task RunQueryAsync(TestServerType serverType, string databaseName, string queryText, bool throwOnError = false)
         {
@@ -185,13 +187,18 @@ namespace Microsoft.SqlTools.ServiceLayer.Test.Common
                 const string hostProfileId = "SQLToolsTestService";
                 Version hostVersion = new Version(1, 0);
 
-                // set up the host details and profile paths 
+                // set up the host details and profile paths
                 var hostDetails = new HostDetails(hostName, hostProfileId, hostVersion);
                 SqlToolsContext sqlToolsContext = new SqlToolsContext(hostDetails);
 
                 // Initialize the ServiceHost, using a MemoryStream for the output stream so that we don't fill up the logs
                 // with a bunch of outgoing messages (which aren't used for anything during tests)
                 ServiceHost serviceHost = HostLoader.CreateAndStartServiceHost(sqlToolsContext, null, new MemoryStream());
+
+                // Set up our logger to write to Console for tests to help debug issues
+                Logger.Initialize(autoFlush: true);
+                Logger.TracingLevel = System.Diagnostics.SourceLevels.All;
+                Logger.TraceSource.Listeners.Add(new ConsoleTraceListener());
             }
         }