diff --git a/.gitattributes b/.gitattributes new file mode 100644 index 00000000..c7a51de6 --- /dev/null +++ b/.gitattributes @@ -0,0 +1,5 @@ +*.sql diff +*.cs diff +*.csproj diff +*.sln diff +*.resx diff \ No newline at end of file diff --git a/.gitignore b/.gitignore index e5302542..c7a5b1b7 100644 --- a/.gitignore +++ b/.gitignore @@ -1,6 +1,7 @@ syntax: glob ### VisualStudio ### +*.dgml # Project.json lock file project.lock.json diff --git a/sqltoolsservice.sln b/sqltoolsservice.sln index c1b33806..196977da 100644 --- a/sqltoolsservice.sln +++ b/sqltoolsservice.sln @@ -54,8 +54,6 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "Microsoft.SqlTools.Credenti EndProject Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "Microsoft.SqlTools.Hosting", "src\Microsoft.SqlTools.Hosting\Microsoft.SqlTools.Hosting.csproj", "{AAE1F8D1-F7AB-4ABE-A55B-D423393AB352}" EndProject -Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "Microsoft.SqlTools.Hosting.v2", "src\Microsoft.SqlTools.Hosting.v2\Microsoft.SqlTools.Hosting.csproj", "{BBF1F8D1-F7AB-4ABE-A55B-D423393AB352}" -EndProject Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "Microsoft.SqlTools.DataProtocol.Contracts", "src\Microsoft.SqlTools.DataProtocol.Contracts\Microsoft.SqlTools.DataProtocol.Contracts.csproj", "{220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D}" EndProject Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "Microsoft.SqlTools.CoreServices", "src\Microsoft.SqlTools.CoreServices\Microsoft.SqlTools.CoreServices.csproj", "{444E79F1-477A-481A-9BE6-6559B32CE177}" @@ -86,6 +84,10 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "Microsoft.SqlTools.Resource EndProject Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "Microsoft.SqlTools.ResourceProvider.DefaultImpl", "src\Microsoft.SqlTools.ResourceProvider.DefaultImpl\Microsoft.SqlTools.ResourceProvider.DefaultImpl.csproj", "{EFB39C03-F7D2-4E8D-BE51-09121CD71973}" EndProject +Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "ScriptGenerator", "test\ScriptGenerator\ScriptGenerator.csproj", "{8EE5B06A-2EB2-4A47-812D-1D5B98D0F49A}" +EndProject +Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "Microsoft.SqlTools.Hosting.v2", "src\Microsoft.SqlTools.Hosting.v2\Microsoft.SqlTools.Hosting.v2.csproj", "{EF02F89F-417E-4A40-B7E6-B102EE2DF24D}" +EndProject Global GlobalSection(SolutionConfigurationPlatforms) = preSolution Debug|Any CPU = Debug|Any CPU @@ -105,12 +107,36 @@ Global {AAE1F8D1-F7AB-4ABE-A55B-D423393AB352}.Integration|Any CPU.Build.0 = Debug|Any CPU {AAE1F8D1-F7AB-4ABE-A55B-D423393AB352}.Release|Any CPU.ActiveCfg = Release|Any CPU {AAE1F8D1-F7AB-4ABE-A55B-D423393AB352}.Release|Any CPU.Build.0 = Release|Any CPU + {220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D}.Debug|Any CPU.Build.0 = Debug|Any CPU + {220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D}.Integration|Any CPU.ActiveCfg = Release|Any CPU + {220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D}.Integration|Any CPU.Build.0 = Release|Any CPU + {220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D}.Release|Any CPU.ActiveCfg = Release|Any CPU + {220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D}.Release|Any CPU.Build.0 = Release|Any CPU + {444E79F1-477A-481A-9BE6-6559B32CE177}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {444E79F1-477A-481A-9BE6-6559B32CE177}.Debug|Any CPU.Build.0 = Debug|Any CPU + {444E79F1-477A-481A-9BE6-6559B32CE177}.Integration|Any CPU.ActiveCfg = Release|Any CPU + {444E79F1-477A-481A-9BE6-6559B32CE177}.Integration|Any CPU.Build.0 = Release|Any CPU + {444E79F1-477A-481A-9BE6-6559B32CE177}.Release|Any CPU.ActiveCfg = Release|Any CPU + {444E79F1-477A-481A-9BE6-6559B32CE177}.Release|Any CPU.Build.0 = Release|Any CPU + {BE04C532-C9AE-4C32-9283-F6629112228B}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {BE04C532-C9AE-4C32-9283-F6629112228B}.Debug|Any CPU.Build.0 = Debug|Any CPU + {BE04C532-C9AE-4C32-9283-F6629112228B}.Integration|Any CPU.ActiveCfg = Release|Any CPU + {BE04C532-C9AE-4C32-9283-F6629112228B}.Integration|Any CPU.Build.0 = Release|Any CPU + {BE04C532-C9AE-4C32-9283-F6629112228B}.Release|Any CPU.ActiveCfg = Release|Any CPU + {BE04C532-C9AE-4C32-9283-F6629112228B}.Release|Any CPU.Build.0 = Release|Any CPU {835EDEB4-289B-4D6D-A9A0-609E43A87D6E}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {835EDEB4-289B-4D6D-A9A0-609E43A87D6E}.Debug|Any CPU.Build.0 = Debug|Any CPU {835EDEB4-289B-4D6D-A9A0-609E43A87D6E}.Integration|Any CPU.ActiveCfg = Debug|Any CPU {835EDEB4-289B-4D6D-A9A0-609E43A87D6E}.Integration|Any CPU.Build.0 = Debug|Any CPU {835EDEB4-289B-4D6D-A9A0-609E43A87D6E}.Release|Any CPU.ActiveCfg = Release|Any CPU {835EDEB4-289B-4D6D-A9A0-609E43A87D6E}.Release|Any CPU.Build.0 = Release|Any CPU + {BA3C9622-ABFF-45A2-91AA-CC5189083256}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {BA3C9622-ABFF-45A2-91AA-CC5189083256}.Debug|Any CPU.Build.0 = Debug|Any CPU + {BA3C9622-ABFF-45A2-91AA-CC5189083256}.Integration|Any CPU.ActiveCfg = Release|Any CPU + {BA3C9622-ABFF-45A2-91AA-CC5189083256}.Integration|Any CPU.Build.0 = Release|Any CPU + {BA3C9622-ABFF-45A2-91AA-CC5189083256}.Release|Any CPU.ActiveCfg = Release|Any CPU + {BA3C9622-ABFF-45A2-91AA-CC5189083256}.Release|Any CPU.Build.0 = Release|Any CPU {F18471B5-2042-409D-BF2C-E5403C322DC9}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {F18471B5-2042-409D-BF2C-E5403C322DC9}.Debug|Any CPU.Build.0 = Debug|Any CPU {F18471B5-2042-409D-BF2C-E5403C322DC9}.Integration|Any CPU.ActiveCfg = Debug|Any CPU @@ -171,26 +197,18 @@ Global {EFB39C03-F7D2-4E8D-BE51-09121CD71973}.Integration|Any CPU.Build.0 = Debug|Any CPU {EFB39C03-F7D2-4E8D-BE51-09121CD71973}.Release|Any CPU.ActiveCfg = Release|Any CPU {EFB39C03-F7D2-4E8D-BE51-09121CD71973}.Release|Any CPU.Build.0 = Release|Any CPU - {BBF1F8D1-F7AB-4ABE-A55B-D423393AB352}.Debug|Any CPU.ActiveCfg = Debug|Any CPU - {BBF1F8D1-F7AB-4ABE-A55B-D423393AB352}.Debug|Any CPU.Build.0 = Debug|Any CPU - {BBF1F8D1-F7AB-4ABE-A55B-D423393AB352}.Release|Any CPU.ActiveCfg = Release|Any CPU - {BBF1F8D1-F7AB-4ABE-A55B-D423393AB352}.Release|Any CPU.Build.0 = Release|Any CPU - {220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D}.Debug|Any CPU.ActiveCfg = Debug|Any CPU - {220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D}.Debug|Any CPU.Build.0 = Debug|Any CPU - {220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D}.Release|Any CPU.ActiveCfg = Release|Any CPU - {220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D}.Release|Any CPU.Build.0 = Release|Any CPU - {444E79F1-477A-481A-9BE6-6559B32CE177}.Debug|Any CPU.ActiveCfg = Debug|Any CPU - {444E79F1-477A-481A-9BE6-6559B32CE177}.Debug|Any CPU.Build.0 = Debug|Any CPU - {444E79F1-477A-481A-9BE6-6559B32CE177}.Release|Any CPU.ActiveCfg = Release|Any CPU - {444E79F1-477A-481A-9BE6-6559B32CE177}.Release|Any CPU.Build.0 = Release|Any CPU - {BE04C532-C9AE-4C32-9283-F6629112228B}.Debug|Any CPU.ActiveCfg = Debug|Any CPU - {BE04C532-C9AE-4C32-9283-F6629112228B}.Debug|Any CPU.Build.0 = Debug|Any CPU - {BE04C532-C9AE-4C32-9283-F6629112228B}.Release|Any CPU.ActiveCfg = Release|Any CPU - {BE04C532-C9AE-4C32-9283-F6629112228B}.Release|Any CPU.Build.0 = Release|Any CPU - {BA3C9622-ABFF-45A2-91AA-CC5189083256}.Debug|Any CPU.ActiveCfg = Debug|Any CPU - {BA3C9622-ABFF-45A2-91AA-CC5189083256}.Debug|Any CPU.Build.0 = Debug|Any CPU - {BA3C9622-ABFF-45A2-91AA-CC5189083256}.Release|Any CPU.ActiveCfg = Release|Any CPU - {BA3C9622-ABFF-45A2-91AA-CC5189083256}.Release|Any CPU.Build.0 = Release|Any CPU + {8EE5B06A-2EB2-4A47-812D-1D5B98D0F49A}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {8EE5B06A-2EB2-4A47-812D-1D5B98D0F49A}.Debug|Any CPU.Build.0 = Debug|Any CPU + {8EE5B06A-2EB2-4A47-812D-1D5B98D0F49A}.Integration|Any CPU.ActiveCfg = Debug|Any CPU + {8EE5B06A-2EB2-4A47-812D-1D5B98D0F49A}.Integration|Any CPU.Build.0 = Debug|Any CPU + {8EE5B06A-2EB2-4A47-812D-1D5B98D0F49A}.Release|Any CPU.ActiveCfg = Release|Any CPU + {8EE5B06A-2EB2-4A47-812D-1D5B98D0F49A}.Release|Any CPU.Build.0 = Release|Any CPU + {EF02F89F-417E-4A40-B7E6-B102EE2DF24D}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {EF02F89F-417E-4A40-B7E6-B102EE2DF24D}.Debug|Any CPU.Build.0 = Debug|Any CPU + {EF02F89F-417E-4A40-B7E6-B102EE2DF24D}.Integration|Any CPU.ActiveCfg = Debug|Any CPU + {EF02F89F-417E-4A40-B7E6-B102EE2DF24D}.Integration|Any CPU.Build.0 = Debug|Any CPU + {EF02F89F-417E-4A40-B7E6-B102EE2DF24D}.Release|Any CPU.ActiveCfg = Release|Any CPU + {EF02F89F-417E-4A40-B7E6-B102EE2DF24D}.Release|Any CPU.Build.0 = Release|Any CPU EndGlobalSection GlobalSection(SolutionProperties) = preSolution HideSolutionNode = FALSE @@ -200,7 +218,11 @@ Global {87D9C7D9-18F4-4AB9-B20D-66C02B6075E2} = {AB9CA2B8-6F70-431C-8A1D-67479D8A7BE4} {0F761F76-E0F3-472E-B539-1815CE2BC696} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} {AAE1F8D1-F7AB-4ABE-A55B-D423393AB352} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} + {220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} + {444E79F1-477A-481A-9BE6-6559B32CE177} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} + {BE04C532-C9AE-4C32-9283-F6629112228B} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} {835EDEB4-289B-4D6D-A9A0-609E43A87D6E} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} + {BA3C9622-ABFF-45A2-91AA-CC5189083256} = {AB9CA2B8-6F70-431C-8A1D-67479D8A7BE4} {F18471B5-2042-409D-BF2C-E5403C322DC9} = {AB9CA2B8-6F70-431C-8A1D-67479D8A7BE4} {4F250E56-F8B4-4E69-AECC-4D31EDD891E7} = {AB9CA2B8-6F70-431C-8A1D-67479D8A7BE4} {8339991B-6D11-45A4-87D0-DF3322198990} = {AB9CA2B8-6F70-431C-8A1D-67479D8A7BE4} @@ -211,13 +233,10 @@ Global {6FEE7E14-8A1D-454E-8F7C-B63597801787} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} {70E63BC1-2C82-41C0-89D6-272FD3C7B0C9} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} {EFB39C03-F7D2-4E8D-BE51-09121CD71973} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} - {BBF1F8D1-F7AB-4ABE-A55B-D423393AB352} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} - {220E1DEC-32EC-4B3B-A1DB-159ECFDD3A8D} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} - {444E79F1-477A-481A-9BE6-6559B32CE177} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} - {BE04C532-C9AE-4C32-9283-F6629112228B} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} - {BA3C9622-ABFF-45A2-91AA-CC5189083256} = {AB9CA2B8-6F70-431C-8A1D-67479D8A7BE4} + {8EE5B06A-2EB2-4A47-812D-1D5B98D0F49A} = {AB9CA2B8-6F70-431C-8A1D-67479D8A7BE4} + {EF02F89F-417E-4A40-B7E6-B102EE2DF24D} = {2BBD7364-054F-4693-97CD-1C395E3E84A9} EndGlobalSection GlobalSection(ExtensibilityGlobals) = postSolution SolutionGuid = {B31CDF4B-2851-45E5-8C5F-BE97125D9DD8} EndGlobalSection -EndGlobal \ No newline at end of file +EndGlobal diff --git a/src/Microsoft.SqlTools.CoreServices/Connection/ConnectionServiceCore.cs b/src/Microsoft.SqlTools.CoreServices/Connection/ConnectionServiceCore.cs index 229742ed..f5a72f87 100644 --- a/src/Microsoft.SqlTools.CoreServices/Connection/ConnectionServiceCore.cs +++ b/src/Microsoft.SqlTools.CoreServices/Connection/ConnectionServiceCore.cs @@ -24,6 +24,7 @@ using Microsoft.SqlTools.CoreServices.LanguageServices.Contracts; using ConnectionType = Microsoft.SqlTools.DataProtocol.Contracts.Connection.ConnectionType; using Microsoft.SqlTools.Hosting.Extensibility; using System.Composition; +using System.Diagnostics; namespace Microsoft.SqlTools.CoreServices.Connection { @@ -317,7 +318,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection } catch (Exception ex) { - Logger.Instance.Write(LogLevel.Normal, "Failed to close temporary connections. error: " + ex.Message); + Logger.Write(TraceEventType.Information, "Failed to close temporary connections. error: " + ex.Message); } } @@ -1175,8 +1176,8 @@ namespace Microsoft.SqlTools.CoreServices.Connection } catch (Exception e) { - Logger.Instance.Write( - LogLevel.Error, + Logger.Write( + TraceEventType.Error, string.Format( "Exception caught while trying to change database context to [{0}] for OwnerUri [{1}]. Exception:{2}", newDatabaseName, @@ -1255,7 +1256,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection } catch (Exception ex) { - Logger.Instance.Write(LogLevel.Verbose, "Could not send Connection telemetry event " + ex.ToString()); + Logger.Write(TraceEventType.Verbose, "Could not send Connection telemetry event " + ex.ToString()); } }); @@ -1301,7 +1302,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection string error = string.Format(CultureInfo.InvariantCulture, "Failed opening a SqlConnection: error:{0} inner:{1} stacktrace:{2}", ex.Message, ex.InnerException != null ? ex.InnerException.Message : string.Empty, ex.StackTrace); - Logger.Instance.Write(LogLevel.Error, error); + Logger.Write(TraceEventType.Error, error); } return null; diff --git a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/AmbientSettings.cs b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/AmbientSettings.cs index 230d09c1..7a7c8841 100644 --- a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/AmbientSettings.cs +++ b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/AmbientSettings.cs @@ -5,6 +5,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Reflection; using Microsoft.SqlTools.Hosting.Utility; @@ -350,13 +351,13 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection public void TraceSettings() { // NOTE: logging as warning so we can get this data in the IEService DacFx logs - Logger.Instance.Write(LogLevel.Warning, Resources.LoggingAmbientSettings); + Logger.Write(TraceEventType.Warning, Resources.LoggingAmbientSettings); foreach (KeyValuePair setting in _configuration) { // Log Ambient Settings - Logger.Instance.Write( - LogLevel.Warning, + Logger.Write( + TraceEventType.Warning, string.Format( Resources.AmbientSettingFormat, setting.Key, @@ -406,7 +407,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection } else { - Logger.Instance.Write(LogLevel.Error, string.Format(Resources.UnableToAssignValue, value.GetType().FullName, _type.FullName)); + Logger.Write(TraceEventType.Error, string.Format(Resources.UnableToAssignValue, value.GetType().FullName, _type.FullName)); } } } diff --git a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/CachedServerInfo.cs b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/CachedServerInfo.cs index 384326fe..f6c47be8 100644 --- a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/CachedServerInfo.cs +++ b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/CachedServerInfo.cs @@ -7,6 +7,7 @@ using System; using System.Collections.Concurrent; using System.Data; using System.Data.SqlClient; +using System.Diagnostics; using System.Linq; using Microsoft.SqlTools.Hosting.Utility; @@ -270,7 +271,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection } catch { - Logger.Instance.Write(LogLevel.Error, String.Format(Resources.FailedToParseConnectionString, connection.ConnectionString)); + Logger.Write(TraceEventType.Error, String.Format(Resources.FailedToParseConnectionString, connection.ConnectionString)); return null; } } diff --git a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/ReliableConnectionHelper.cs b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/ReliableConnectionHelper.cs index 77a3b4ad..ae6863ba 100644 --- a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/ReliableConnectionHelper.cs +++ b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/ReliableConnectionHelper.cs @@ -429,7 +429,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection Validate.IsNotNull(nameof(connection), connection); if (!(connection.State == ConnectionState.Open)) { - Logger.Instance.Write(LogLevel.Warning, Resources.ConnectionPassedToIsCloudShouldBeOpen); + Logger.Write(TraceEventType.Warning, Resources.ConnectionPassedToIsCloudShouldBeOpen); } Func executeCommand = commandText => @@ -540,7 +540,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection return true; } - Logger.Instance.Write(LogLevel.Error, ex.ToString()); + Logger.Write(TraceEventType.Error, ex.ToString()); return false; } @@ -668,7 +668,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection }, (ex) => { - Logger.Instance.Write(LogLevel.Error, ex.ToString()); + Logger.Write(TraceEventType.Error, ex.ToString()); return StandardExceptionHandler(ex); // handled }, useRetry: true); @@ -739,7 +739,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection Validate.IsNotNull(nameof(connection), connection); if (!(connection.State == ConnectionState.Open)) { - Logger.Instance.Write(LogLevel.Error, "connection passed to GetServerVersion should be open."); + Logger.Write(TraceEventType.Error, "connection passed to GetServerVersion should be open."); } Func getServerInfo = commandText => @@ -788,8 +788,8 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection { //we don't want to fail the normal flow if any unexpected thing happens //during caching although it's unlikely. So we just log the exception and ignore it - Logger.Instance.Write(LogLevel.Error, Resources.FailedToCacheIsCloud); - Logger.Instance.Write(LogLevel.Error, ex.ToString()); + Logger.Write(TraceEventType.Error, Resources.FailedToCacheIsCloud); + Logger.Write(TraceEventType.Error, ex.ToString()); } }); @@ -892,7 +892,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection if (handledEx != null) { - Logger.Instance.Write(LogLevel.Error, String.Format(Resources.ErrorParsingConnectionString, handledEx)); + Logger.Write(TraceEventType.Error, String.Format(Resources.ErrorParsingConnectionString, handledEx)); return false; } diff --git a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/ReliableSqlConnection.cs b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/ReliableSqlConnection.cs index 66d7102f..3fd74ada 100644 --- a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/ReliableSqlConnection.cs +++ b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/ReliableSqlConnection.cs @@ -441,7 +441,7 @@ SET NUMERIC_ROUNDABORT OFF;"; } catch (SqlException exception) { - Logger.Instance.Write(LogLevel.Error, Resources.UnableToRetrieveAzureSessionId + exception.ToString()); + Logger.Write(TraceEventType.Error, Resources.UnableToRetrieveAzureSessionId + exception.ToString()); } } diff --git a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicy.DataTransferDetectionErrorStrategy.cs b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicy.DataTransferDetectionErrorStrategy.cs index d8919182..c9c562da 100644 --- a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicy.DataTransferDetectionErrorStrategy.cs +++ b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicy.DataTransferDetectionErrorStrategy.cs @@ -4,6 +4,7 @@ // using System.Data.SqlClient; +using System.Diagnostics; using Microsoft.SqlTools.Hosting.Utility; namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection @@ -30,7 +31,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection RetryPolicyUtils.AppendThrottlingDataIfIsThrottlingError(sqlException, err); if (RetryPolicyUtils.IsNonRetryableDataTransferError(err.Number)) { - Logger.Instance.Write(LogLevel.Error, string.Format(Resources.ExceptionCannotBeRetried, err.Number, err.Message)); + Logger.Write(TraceEventType.Error, string.Format(Resources.ExceptionCannotBeRetried, err.Number, err.Message)); return false; } } diff --git a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicy.cs b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicy.cs index 37c4fc64..fbaaf10d 100644 --- a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicy.cs +++ b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicy.cs @@ -244,7 +244,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection bool shouldRetry = canRetry && ShouldRetryImpl(retryState); - Logger.Instance.Write(LogLevel.Error, + Logger.Write(TraceEventType.Error, string.Format( CultureInfo.InvariantCulture, "Retry requested: Retry count = {0}. Delay = {1}, SQL Error Number = {2}, Can retry error = {3}, Will retry = {4}", @@ -267,7 +267,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection { bool shouldIgnoreError = ErrorDetectionStrategy.ShouldIgnoreError(retryState.LastError); - Logger.Instance.Write(LogLevel.Error, + Logger.Write(TraceEventType.Error, string.Format( CultureInfo.InvariantCulture, "Ignore Error requested: Retry count = {0}. Delay = {1}, SQL Error Number = {2}, Should Ignore Error = {3}", diff --git a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicyFactory.cs b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicyFactory.cs index ce6fda81..db2d6c8f 100644 --- a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicyFactory.cs +++ b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicyFactory.cs @@ -392,7 +392,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection internal static void DataConnectionFailureRetry(RetryState retryState) { - Logger.Instance.Write(LogLevel.Normal, string.Format(CultureInfo.InvariantCulture, + Logger.Write(TraceEventType.Information, string.Format(CultureInfo.InvariantCulture, "Connection retry number {0}. Delaying {1} ms before retry. Exception: {2}", retryState.RetryCount, retryState.Delay.TotalMilliseconds.ToString(CultureInfo.InvariantCulture), @@ -403,7 +403,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection internal static void CommandFailureRetry(RetryState retryState, string commandKeyword) { - Logger.Instance.Write(LogLevel.Normal, string.Format( + Logger.Write(TraceEventType.Information, string.Format( CultureInfo.InvariantCulture, "{0} retry number {1}. Delaying {2} ms before retry. Exception: {3}", commandKeyword, @@ -416,7 +416,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection internal static void CommandFailureIgnore(RetryState retryState, string commandKeyword) { - Logger.Instance.Write(LogLevel.Normal, string.Format( + Logger.Write(TraceEventType.Information, string.Format( CultureInfo.InvariantCulture, "{0} retry number {1}. Ignoring failure. Exception: {2}", commandKeyword, diff --git a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicyUtils.cs b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicyUtils.cs index c301b48b..4195ad1d 100644 --- a/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicyUtils.cs +++ b/src/Microsoft.SqlTools.CoreServices/Connection/ReliableConnection/RetryPolicyUtils.cs @@ -6,6 +6,7 @@ using System; using System.Collections.Generic; using System.Data.SqlClient; +using System.Diagnostics; using System.Runtime.InteropServices; using Microsoft.SqlTools.Hosting.Utility; @@ -344,7 +345,7 @@ namespace Microsoft.SqlTools.CoreServices.Connection.ReliableConnection { if (azureSessionId != Guid.Empty) { - Logger.Instance.Write(LogLevel.Warning, string.Format( + Logger.Write(TraceEventType.Warning, string.Format( "Retry occurred: session: {0}; attempt - {1}; delay - {2}; exception - \"{3}\"", azureSessionId, retryState.RetryCount, diff --git a/src/Microsoft.SqlTools.CoreServices/LanguageServices/BindingQueue.cs b/src/Microsoft.SqlTools.CoreServices/LanguageServices/BindingQueue.cs index df3708ec..9c75a9aa 100644 --- a/src/Microsoft.SqlTools.CoreServices/LanguageServices/BindingQueue.cs +++ b/src/Microsoft.SqlTools.CoreServices/LanguageServices/BindingQueue.cs @@ -9,6 +9,7 @@ using System.Threading; using System.Threading.Tasks; using System.Linq; using Microsoft.SqlTools.Hosting.Utility; +using System.Diagnostics; namespace Microsoft.SqlTools.CoreServices.LanguageServices { @@ -319,7 +320,7 @@ namespace Microsoft.SqlTools.CoreServices.LanguageServices } catch (Exception ex) { - Logger.Instance.Write(LogLevel.Error, "Unexpected exception on the binding queue: " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unexpected exception on the binding queue: " + ex.ToString()); if (queueItem.ErrorHandler != null) { result = queueItem.ErrorHandler(ex); @@ -346,14 +347,14 @@ namespace Microsoft.SqlTools.CoreServices.LanguageServices bindTask .ContinueWith((a) => bindingContext.BindingLock.Set()) - .ContinueWithOnFaulted(t => Logger.Instance.Write(LogLevel.Error, "Binding queue threw exception " + t.Exception.ToString())); + .ContinueWithOnFaulted(t => Logger.Write(TraceEventType.Error, "Binding queue threw exception " + t.Exception.ToString())); } } catch (Exception ex) { // catch and log any exceptions raised in the binding calls // set item processed to avoid deadlocks - Logger.Instance.Write(LogLevel.Error, "Binding queue threw exception " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Binding queue threw exception " + ex.ToString()); } finally { diff --git a/src/Microsoft.SqlTools.CoreServices/Microsoft.SqlTools.CoreServices.csproj b/src/Microsoft.SqlTools.CoreServices/Microsoft.SqlTools.CoreServices.csproj index dd71a076..1d471c4b 100644 --- a/src/Microsoft.SqlTools.CoreServices/Microsoft.SqlTools.CoreServices.csproj +++ b/src/Microsoft.SqlTools.CoreServices/Microsoft.SqlTools.CoreServices.csproj @@ -1,4 +1,4 @@ - + Library @@ -29,8 +29,8 @@ - - + + diff --git a/src/Microsoft.SqlTools.CoreServices/Workspace/SettingsService.cs b/src/Microsoft.SqlTools.CoreServices/Workspace/SettingsService.cs index 94d73f52..e981b0a2 100644 --- a/src/Microsoft.SqlTools.CoreServices/Workspace/SettingsService.cs +++ b/src/Microsoft.SqlTools.CoreServices/Workspace/SettingsService.cs @@ -5,6 +5,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using System.Text; using System.Threading.Tasks; @@ -100,7 +101,7 @@ namespace Microsoft.SqlTools.CoreServices.Workspace { try { - Logger.Instance.Write(LogLevel.Verbose, "HandleDidChangeConfigurationNotification"); + Logger.Write(TraceEventType.Verbose, "HandleDidChangeConfigurationNotification"); // Propagate the changes to the event handlers var configUpdateTasks = ConfigChangeCallbacks.Select( @@ -109,7 +110,7 @@ namespace Microsoft.SqlTools.CoreServices.Workspace } catch (Exception ex) { - Logger.Instance.Write(LogLevel.Error, "Unknown error " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown error " + ex.ToString()); // Swallow exceptions here to prevent us from crashing // TODO: this probably means the ScriptFile model is in a bad state or out of sync with the actual file; we should recover here return; diff --git a/src/Microsoft.SqlTools.Credentials/Credentials/CredentialService.cs b/src/Microsoft.SqlTools.Credentials/Credentials/CredentialService.cs index 8e55d431..90c3155d 100644 --- a/src/Microsoft.SqlTools.Credentials/Credentials/CredentialService.cs +++ b/src/Microsoft.SqlTools.Credentials/Credentials/CredentialService.cs @@ -4,6 +4,7 @@ // using System; +using System.Diagnostics; using System.Runtime.InteropServices; using System.Threading.Tasks; using Microsoft.SqlTools.Credentials.Contracts; @@ -165,7 +166,7 @@ namespace Microsoft.SqlTools.Credentials private async Task HandleRequest(Func> handler, RequestContext requestContext, string requestType) { - Logger.Write(LogLevel.Verbose, requestType); + Logger.Write(TraceEventType.Verbose, requestType); try { diff --git a/src/Microsoft.SqlTools.Credentials/Credentials/Win32/CredentialSet.cs b/src/Microsoft.SqlTools.Credentials/Credentials/Win32/CredentialSet.cs index 15f6e77c..e51b2d83 100644 --- a/src/Microsoft.SqlTools.Credentials/Credentials/Win32/CredentialSet.cs +++ b/src/Microsoft.SqlTools.Credentials/Credentials/Win32/CredentialSet.cs @@ -6,6 +6,7 @@ using System; using System.Collections.Generic; using System.ComponentModel; +using System.Diagnostics; using System.Linq; using System.Runtime.InteropServices; using Microsoft.SqlTools.Utility; @@ -69,13 +70,11 @@ namespace Microsoft.SqlTools.Credentials.Win32 private void LoadInternal() { - uint count; - IntPtr pCredentials = IntPtr.Zero; - bool result = NativeMethods.CredEnumerateW(Target, 0, out count, out pCredentials); + bool result = NativeMethods.CredEnumerateW(Target, 0, out uint count, out pCredentials); if (!result) { - Logger.Write(LogLevel.Error, string.Format("Win32Exception: {0}", new Win32Exception(Marshal.GetLastWin32Error()).ToString())); + Logger.Write(TraceEventType.Error, string.Format("Win32Exception: {0}", new Win32Exception(Marshal.GetLastWin32Error()).ToString())); return; } diff --git a/src/Microsoft.SqlTools.Credentials/Program.cs b/src/Microsoft.SqlTools.Credentials/Program.cs index a7ee1a02..0301a8cf 100644 --- a/src/Microsoft.SqlTools.Credentials/Program.cs +++ b/src/Microsoft.SqlTools.Credentials/Program.cs @@ -3,6 +3,7 @@ // Licensed under the MIT license. See LICENSE file in the project root for full license information. using System; +using System.Diagnostics; using System.IO; using Microsoft.SqlTools.Credentials.Utility; using Microsoft.SqlTools.Hosting.Utility; @@ -32,16 +33,18 @@ namespace Microsoft.SqlTools.Credentials return; } - string logFilePath = "credentials"; + string logFilePath = commandOptions.LogFilePath; + if (string.IsNullOrWhiteSpace(logFilePath)) + { + logFilePath = "credentials"; + } if (!string.IsNullOrWhiteSpace(commandOptions.LoggingDirectory)) { - logFilePath = Path.Combine(commandOptions.LoggingDirectory, logFilePath); + logFilePath = Logger.GenerateLogFilePath(Path.Combine(commandOptions.LoggingDirectory, logFilePath)); } - // turn on Verbose logging during early development - // we need to switch to Normal when preparing for public preview - Logger.Initialize(logFilePath: logFilePath, minimumLogLevel: LogLevel.Verbose, isEnabled: commandOptions.EnableLogging); - Logger.Write(LogLevel.Normal, "Starting SqlTools Credentials Provider"); + Logger.Initialize(tracingLevel: commandOptions.TracingLevel, logFilePath: logFilePath, traceSource: "credentials"); + Logger.Write(TraceEventType.Information, "Starting SqlTools Credentials Provider"); // set up the host details and profile paths var hostDetails = new HostDetails( @@ -56,8 +59,8 @@ namespace Microsoft.SqlTools.Credentials } catch (Exception e) { - Logger.Write(LogLevel.Error, string.Format("An unhandled exception occurred: {0}", e)); - Environment.Exit(1); + Logger.WriteWithCallstack(TraceEventType.Critical, $"An unhandled exception occurred: {e}"); + Environment.Exit(1); } } } diff --git a/src/Microsoft.SqlTools.DataProtocol.Contracts/GeneralRequestDetails.cs b/src/Microsoft.SqlTools.DataProtocol.Contracts/GeneralRequestDetails.cs index 17dd01db..88b3307e 100644 --- a/src/Microsoft.SqlTools.DataProtocol.Contracts/GeneralRequestDetails.cs +++ b/src/Microsoft.SqlTools.DataProtocol.Contracts/GeneralRequestDetails.cs @@ -30,7 +30,7 @@ namespace Microsoft.SqlTools.DataProtocol.Contracts { result = default(T); // TODO move logger to a utilities project - // Logger.Instance.Write(LogLevel.Warning, string.Format(CultureInfo.InvariantCulture, + // Logger.Write(TraceEventType.Warning, string.Format(CultureInfo.InvariantCulture, // "Cannot convert option value {0}:{1} to {2}", name, value ?? "", typeof(T))); } } diff --git a/src/Microsoft.SqlTools.Hosting.v2/Extensibility/IHostedService.cs b/src/Microsoft.SqlTools.Hosting.v2/Extensibility/IHostedService.cs index 0d02b754..c67e3537 100644 --- a/src/Microsoft.SqlTools.Hosting.v2/Extensibility/IHostedService.cs +++ b/src/Microsoft.SqlTools.Hosting.v2/Extensibility/IHostedService.cs @@ -4,6 +4,7 @@ // using System; +using System.Diagnostics; using System.Threading.Tasks; using Microsoft.SqlTools.Hosting.Protocol; using Microsoft.SqlTools.Hosting.Utility; @@ -64,7 +65,7 @@ namespace Microsoft.SqlTools.Hosting.Extensibility RequestContext requestContext, string requestType) { - Logger.Instance.Write(LogLevel.Verbose, requestType); + Logger.Write(TraceEventType.Verbose, requestType); try { @@ -83,7 +84,7 @@ namespace Microsoft.SqlTools.Hosting.Extensibility RequestContext requestContext, string requestType) { - Logger.Instance.Write(LogLevel.Verbose, requestType); + Logger.Write(TraceEventType.Verbose, requestType); return await Task.Factory.StartNew(() => { try { diff --git a/src/Microsoft.SqlTools.Hosting.v2/Microsoft.SqlTools.Hosting.csproj b/src/Microsoft.SqlTools.Hosting.v2/Microsoft.SqlTools.Hosting.v2.csproj similarity index 100% rename from src/Microsoft.SqlTools.Hosting.v2/Microsoft.SqlTools.Hosting.csproj rename to src/Microsoft.SqlTools.Hosting.v2/Microsoft.SqlTools.Hosting.v2.csproj diff --git a/src/Microsoft.SqlTools.Hosting.v2/Protocol/JsonRpcHost.cs b/src/Microsoft.SqlTools.Hosting.v2/Protocol/JsonRpcHost.cs index 725b38f2..ed9e18a0 100644 --- a/src/Microsoft.SqlTools.Hosting.v2/Protocol/JsonRpcHost.cs +++ b/src/Microsoft.SqlTools.Hosting.v2/Protocol/JsonRpcHost.cs @@ -6,6 +6,7 @@ using System; using System.Collections.Concurrent; using System.Collections.Generic; +using System.Diagnostics; using System.IO; using System.Threading; using System.Threading.Tasks; @@ -286,7 +287,7 @@ namespace Microsoft.SqlTools.Hosting.Protocol { // Log the error and send an error event to the client string message = string.Format("Exception occurred while receiving input message: {0}", e.Message); - Logger.Instance.Write(LogLevel.Error, message); + Logger.Write(TraceEventType.Error, message); // TODO: Add event to output queue, and unit test it @@ -297,7 +298,7 @@ namespace Microsoft.SqlTools.Hosting.Protocol // Verbose logging string logMessage = string.Format("Received message of type[{0}] and method[{1}]", incomingMessage.MessageType, incomingMessage.Method); - Logger.Instance.Write(LogLevel.Verbose, logMessage); + Logger.Write(TraceEventType.Verbose, logMessage); // Process the message try @@ -310,7 +311,7 @@ namespace Microsoft.SqlTools.Hosting.Protocol // TODO: Localize string mnfLogMessage = string.Format("Failed to find method handler for type[{0}] and method[{1}]", incomingMessage.MessageType, incomingMessage.Method); - Logger.Instance.Write(LogLevel.Warning, mnfLogMessage); + Logger.Write(TraceEventType.Warning, mnfLogMessage); if (incomingMessage.MessageType == MessageType.Request) { @@ -325,12 +326,12 @@ namespace Microsoft.SqlTools.Hosting.Protocol // General errors should be logged but not halt the processing loop string geLogMessage = string.Format("Exception thrown when handling message of type[{0}] and method[{1}]: {2}", incomingMessage.MessageType, incomingMessage.Method, e); - Logger.Instance.Write(LogLevel.Error, geLogMessage); + Logger.Write(TraceEventType.Error, geLogMessage); // TODO: Should we be returning a response for failing requests? } } - Logger.Instance.Write(LogLevel.Warning, "Exiting consume input loop!"); + Logger.Write(TraceEventType.Warning, "Exiting consume input loop!"); }, consumeOutputCancellationToken, TaskCreationOptions.LongRunning, TaskScheduler.Default).Unwrap(); } @@ -355,7 +356,7 @@ namespace Microsoft.SqlTools.Hosting.Protocol { // If we hit an exception here, it is unrecoverable string message = string.Format("Unexpected occurred while receiving output message: {0}", e.Message); - Logger.Instance.Write(LogLevel.Error, message); + Logger.Write(TraceEventType.Error, message); break; } @@ -363,11 +364,11 @@ namespace Microsoft.SqlTools.Hosting.Protocol // Send the message string logMessage = string.Format("Sending message of type[{0}] and method[{1}]", outgoingMessage.MessageType, outgoingMessage.Method); - Logger.Instance.Write(LogLevel.Verbose, logMessage); + Logger.Write(TraceEventType.Verbose, logMessage); await protocolChannel.MessageWriter.WriteMessage(outgoingMessage); } - Logger.Instance.Write(LogLevel.Warning, "Exiting consume output loop!"); + Logger.Write(TraceEventType.Warning, "Exiting consume output loop!"); }, consumeOutputCancellationToken, TaskCreationOptions.LongRunning, TaskScheduler.Default).Unwrap(); } diff --git a/src/Microsoft.SqlTools.Hosting.v2/Protocol/MessageWriter.cs b/src/Microsoft.SqlTools.Hosting.v2/Protocol/MessageWriter.cs index 27535561..5e048c5f 100644 --- a/src/Microsoft.SqlTools.Hosting.v2/Protocol/MessageWriter.cs +++ b/src/Microsoft.SqlTools.Hosting.v2/Protocol/MessageWriter.cs @@ -3,6 +3,7 @@ // Licensed under the MIT license. See LICENSE file in the project root for full license information. // +using System.Diagnostics; using System.IO; using System.Text; using System.Threading.Tasks; @@ -34,7 +35,7 @@ namespace Microsoft.SqlTools.Hosting.Protocol // Log the JSON representation of the message string logMessage = string.Format("Sending message of type[{0}] and method[{1}]", messageToWrite.MessageType, messageToWrite.Method); - Logger.Instance.Write(LogLevel.Verbose, logMessage); + Logger.Write(TraceEventType.Verbose, logMessage); string serializedMessage = messageToWrite.Serialize(); // TODO: Allow encoding to be passed in diff --git a/src/Microsoft.SqlTools.Hosting.v2/ServiceHost.cs b/src/Microsoft.SqlTools.Hosting.v2/ServiceHost.cs index a7d11357..e343e515 100644 --- a/src/Microsoft.SqlTools.Hosting.v2/ServiceHost.cs +++ b/src/Microsoft.SqlTools.Hosting.v2/ServiceHost.cs @@ -5,6 +5,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using System.Threading.Tasks; using Microsoft.SqlTools.DataProtocol.Contracts; @@ -168,7 +169,7 @@ namespace Microsoft.SqlTools.Hosting internal async Task HandleInitializeRequest(InitializeParameters initParams, RequestContext requestContext) { - Logger.Instance.Write(LogLevel.Normal, "Service host received intialize request"); + Logger.Write(TraceEventType.Information, "Service host received intialize request"); // Call all initialize methods provided by the service components IEnumerable initializeTasks = initCallbacks.Select(t => t(initParams, requestContext)); @@ -194,7 +195,7 @@ namespace Microsoft.SqlTools.Hosting internal async Task HandleShutdownRequest(object shutdownParams, RequestContext requestContext) { - Logger.Instance.Write(LogLevel.Normal, "Service host received shutdown request"); + Logger.Write(TraceEventType.Information, "Service host received shutdown request"); // Call all the shutdown methods provided by the service components IEnumerable shutdownTasks = shutdownCallbacks.Select(t => t(shutdownParams, requestContext)); diff --git a/src/Microsoft.SqlTools.Hosting.v2/Utility/CommandOptions.cs b/src/Microsoft.SqlTools.Hosting.v2/Utility/CommandOptions.cs index bc56d254..364f0c6a 100644 --- a/src/Microsoft.SqlTools.Hosting.v2/Utility/CommandOptions.cs +++ b/src/Microsoft.SqlTools.Hosting.v2/Utility/CommandOptions.cs @@ -14,6 +14,11 @@ namespace Microsoft.SqlTools.Hosting.Utility /// public class CommandOptions { + // set default log directory + // refer to https://jimrich.sk/environment-specialfolder-on-windows-linux-and-os-x/ && https://stackoverflow.com/questions/895723/environment-getfolderpath-commonapplicationdata-is-still-returning-c-docum + // for cross platform locations + internal readonly string DefaultLogRoot = Environment.GetFolderPath(Environment.SpecialFolder.ApplicationData); + /// /// Construct and parse command line options from the arguments array /// @@ -23,6 +28,13 @@ namespace Microsoft.SqlTools.Hosting.Utility ErrorMessage = string.Empty; Locale = string.Empty; + //set default log directory + LoggingDirectory = DefaultLogRoot; + if (!string.IsNullOrWhiteSpace(ServiceName)) + { + LoggingDirectory = Path.Combine(LoggingDirectory, ServiceName); + } + try { for (int i = 0; i < args.Length; ++i) @@ -37,7 +49,12 @@ namespace Microsoft.SqlTools.Hosting.Utility switch (argName) { case "-enable-logging": - EnableLogging = true; + break; //ignore this old option for now for backward compat with older opsstudio code - to be removed in a future checkin + case "-tracing-level": + TracingLevel = args[++i]; + break; + case "-log-file": + LogFilePath = args[++i]; break; case "-log-dir": SetLoggingDirectory(args[++i]); @@ -76,12 +93,6 @@ namespace Microsoft.SqlTools.Hosting.Utility /// public string ErrorMessage { get; private set; } - - /// - /// Whether diagnostic logging is enabled - /// - public bool EnableLogging { get; private set; } - /// /// Gets the directory where log files are output. /// @@ -112,15 +123,21 @@ namespace Microsoft.SqlTools.Hosting.Utility var str = string.Format("{0}" + Environment.NewLine + ServiceName + " " + Environment.NewLine + " Options:" + Environment.NewLine + - " [--enable-logging]" + Environment.NewLine + - " [--log-dir **] (default: current directory)" + Environment.NewLine + - " [--help]" + Environment.NewLine + + " [--enable-logging ] (obsolete - present for backward compat. Logging is always on, except -tracing-level Off has the effect of disabling logging)" + Environment.NewLine + + " [--tracing-level **] (** can be any of: All, Off, Critical, Error, Warning, Information, Verbose. Default is Critical)" + Environment.NewLine + + " [--log-file **]" + Environment.NewLine + + " [--log-dir **] (default: %APPDATA%\\)" + Environment.NewLine + " [--locale **] (default: 'en')" + Environment.NewLine, + " [--help]" + Environment.NewLine + ErrorMessage); return str; } } + public string TracingLevel { get; private set; } + + public string LogFilePath { get; private set; } + private void SetLoggingDirectory(string loggingDirectory) { if (string.IsNullOrWhiteSpace(loggingDirectory)) diff --git a/src/Microsoft.SqlTools.Hosting.v2/Utility/Logger.cs b/src/Microsoft.SqlTools.Hosting.v2/Utility/Logger.cs index d8c62c43..47ba6877 100644 --- a/src/Microsoft.SqlTools.Hosting.v2/Utility/Logger.cs +++ b/src/Microsoft.SqlTools.Hosting.v2/Utility/Logger.cs @@ -5,86 +5,157 @@ using System; using System.Diagnostics; +using System.Globalization; using System.IO; -using System.Runtime.CompilerServices; -using System.Text; +using System.Threading; namespace Microsoft.SqlTools.Hosting.Utility { /// - /// Defines the level indicators for log messages. + /// Ordinal value of each LogEvent value corresponds to a unique event id to be used in trace. + /// By convention explicitly specify the integer value so that when this list grows large it is easy to figure out + /// enumeration corresponding to a numeric value. We could be reserving ranges of values for specific areas or logEvents. + /// Maximum value assignable to LogEvent enum value is 65,535. /// - public enum LogLevel + public enum LogEvent : ushort { - /// - /// Indicates a verbose log message. - /// - Verbose, - - /// - /// Indicates a normal, non-verbose log message. - /// - Normal, - - /// - /// Indicates a warning message. - /// - Warning, - - /// - /// Indicates an error message. - /// - Error + Default = 0, + IoFileSystem = 1, + OsSubSystem = 2, } /// - /// Provides a simple logging interface. May be replaced with a - /// more robust solution at a later date. + /// Provides a simple logging interface built on top of .Net tracing frameworks /// - public class Logger + public static class Logger { - private static LogWriter logWriter; + internal const SourceLevels defaultTracingLevel = SourceLevels.Critical; + internal const string defaultTraceSource = "sqltools"; + private static SourceLevels tracingLevel = defaultTracingLevel; + private static string logFileFullPath; - private static bool isEnabled; - - private static bool isInitialized = false; - - private static Lazy lazyInstance = new Lazy(() => new Logger()); - - public static Logger Instance + internal static TraceSource TraceSource { get; set; } + internal static string LogFileFullPath { - get + get => logFileFullPath; + private set { - return lazyInstance.Value; + //If the log file path has a directory component then ensure that the directory exists. + if (!string.IsNullOrEmpty(Path.GetDirectoryName(value)) && !Directory.Exists(Path.GetDirectoryName(value))) + { + Directory.CreateDirectory(Path.GetDirectoryName(value)); + } + + logFileFullPath = value; + ConfigureListener(); } } - + + private static SqlToolsTraceListener Listener { get; set; } + + private static void ConfigureLogFile(string logFilePrefix) => LogFileFullPath = GenerateLogFilePath(logFilePrefix); + /// - /// Initializes the Logger for the current session. + /// Calling this method will turn on inclusion CallStack in the log for all future traces /// - /// - /// Optional. Specifies the path at which log messages will be written. - /// - /// + public static void StartCallStack() => Listener.TraceOutputOptions |= TraceOptions.Callstack; + + /// + /// Calling this method will turn off inclusion of CallStack in the log for all future traces + /// + public static void StopCallStack() => Listener.TraceOutputOptions &= ~TraceOptions.Callstack; + + /// + /// Calls flush on defaultTracingLevel configured listeners. + /// + public static void Flush() + { + TraceSource.Flush(); + Trace.Flush(); + } + + public static void Close() + { + Flush(); + TraceSource.Close(); + Trace.Close(); + Listener = null; // Since we have closed the listener, set listener to null. + } + public static SourceLevels TracingLevel + { + get => tracingLevel; + set + { + // configures the source level filter. This alone is not enough for tracing that is done via "Trace" object instead of "TraceSource" object + TraceSource.Switch = new SourceSwitch(TraceSource.Name, value.ToString()); + // configure the listener level filter + tracingLevel = value; + Listener.Filter = new EventTypeFilter(tracingLevel); + } + } + + /// + /// Initializes the Logger for the current process. + /// + /// /// Optional. Specifies the minimum log message level to write to the log file. /// - public void Initialize( - string logFilePath = "sqltools", - LogLevel minimumLogLevel = LogLevel.Normal, - bool isEnabled = true) + /// + /// Optional. Specifies the log name prefix for the log file name at which log messages will be written. + /// + /// Optional. Specifies the tracesource name. + /// + public static void Initialize( + SourceLevels tracingLevel = defaultTracingLevel, + string logFilePath = null, + string traceSource = defaultTraceSource) { - Logger.isEnabled = isEnabled; - - // return if the logger is not enabled or already initialized - if (!Logger.isEnabled || Logger.isInitialized) + Logger.tracingLevel = tracingLevel; + TraceSource = new TraceSource(traceSource, Logger.tracingLevel); + if (string.IsNullOrWhiteSpace(logFilePath)) { - return; + logFilePath = GenerateLogFilePath(traceSource); } - Logger.isInitialized = true; + LogFileFullPath = logFilePath; + Write(TraceEventType.Information, $"Initialized the {traceSource} logger"); + } + /// + /// Initializes the Logger for the current process. + /// + /// + /// + /// Optional. Specifies the minimum log message level to write to the log file. + /// + /// + /// Optional. Specifies the log name prefix for the log file name at which log messages will be written. + /// + /// Optional. Specifies the tracesource name. + /// + public static void Initialize(string tracingLevel, string logFilePath = null, string traceSource = defaultTraceSource) + { + Initialize(Enum.TryParse(tracingLevel, out SourceLevels sourceTracingLevel) + ? sourceTracingLevel + : defaultTracingLevel + , logFilePath + , traceSource); + } + + /// + /// Configures the LogfilePath for the tracelistener in use for this process. + /// + /// + /// Returns the log file path corresponding to logfilePrefix + /// + public static string GenerateLogFilePath(string logFilePrefix = defaultTraceSource) + { + if (string.IsNullOrWhiteSpace(logFilePrefix)) + { + throw new ArgumentOutOfRangeException(nameof(logFilePrefix), $"LogfilePath cannot be configured if argument {nameof(logFilePrefix)} has not been set"); + } // Create the log directory - string logDir = Path.GetDirectoryName(logFilePath); + string logDir = Path.GetDirectoryName(logFilePrefix); if (!string.IsNullOrWhiteSpace(logDir)) { if (!Directory.Exists(logDir)) @@ -93,207 +164,280 @@ namespace Microsoft.SqlTools.Hosting.Utility { Directory.CreateDirectory(logDir); } - catch (Exception) + catch (Exception ex) { - // Creating the log directory is a best effort operation, so ignore any failures. + Write(TraceEventType.Error, LogEvent.IoFileSystem, $"Unable to create directory:{logDir}\nException encountered:{ex}"); } } } - // get a unique number to prevent conflicts of two process launching at the same time int uniqueId; try { uniqueId = Process.GetCurrentProcess().Id; } - catch (Exception) + catch (Exception ex) { + Write(TraceEventType.Information, LogEvent.OsSubSystem, $"Unable to get process id of current running process\nException encountered:{ex}"); // if the pid look up fails for any reason, just use a random number - uniqueId = new Random().Next(1000, 9999); + uniqueId = new Random().Next(1000, 9999); } // make the log path unique - string fullFileName = string.Format( - "{0}_{1,4:D4}{2,2:D2}{3,2:D2}{4,2:D2}{5,2:D2}{6,2:D2}{7}.log", - logFilePath, - DateTime.Now.Year, DateTime.Now.Month, DateTime.Now.Day, - DateTime.Now.Hour, DateTime.Now.Minute, DateTime.Now.Second, - uniqueId); - - if (logWriter != null) - { - logWriter.Dispose(); - } - - // TODO: Parameterize this - logWriter = - new LogWriter( - minimumLogLevel, - fullFileName, - true); - - Write(LogLevel.Normal, "Initializing SQL Tools Service Host logger"); + return $"{logFilePrefix}_{DateTime.Now.Year,4:D4}{DateTime.Now.Month,2:D2}{DateTime.Now.Day,2:D2}{DateTime.Now.Hour,2:D2}{DateTime.Now.Minute,2:D2}{DateTime.Now.Second,2:D2}{uniqueId}.log"; } - /// - /// Closes the Logger. - /// - public void Close() + private static void ConfigureListener() { - if (logWriter != null) + if (string.IsNullOrWhiteSpace(LogFileFullPath)) { - logWriter.Dispose(); + throw new InvalidOperationException("Listeners cannot be configured if LogFileFullPath has not been set"); } + Listener = new SqlToolsTraceListener(LogFileFullPath) + { + TraceOutputOptions = TraceOptions.DateTime | TraceOptions.ProcessId | TraceOptions.ThreadId, + Filter = new EventTypeFilter(TracingLevel), + }; + TraceSource.Listeners.Clear(); + TraceSource.Listeners.Add(Listener); + Trace.Listeners.Clear(); + Trace.Listeners.Add(Listener); } /// /// Writes a message to the log file. /// - /// The level at which the message will be written. + /// The level at which the message will be written. /// The message text to be written. - /// The name of the calling method. - /// The source file path where the calling method exists. - /// The line number of the calling method. - public void Write( - LogLevel logLevel, - string logMessage, - [CallerMemberName] string callerName = null, - [CallerFilePath] string callerSourceFile = null, - [CallerLineNumber] int callerLineNumber = 0) - { - // return if the logger is not enabled or not initialized - if (!Logger.isEnabled || !Logger.isInitialized) + public static void Write(TraceEventType eventType, string logMessage) => Write(eventType, LogEvent.Default, logMessage); + + /// + /// Writes a message to the log file with accompanying callstack. + /// + /// The level at which the message will be written. + /// The message text to be written. + /// + /// The callstack logging gets turned on globally and any other log writes that happens in the time window + /// while this log write is happening will also get callstack information logged. This is not considered + /// and trying to isolate the callstack logging to be turned of for just one call is unnecessarily complex. + /// + public static void WriteWithCallstack(TraceEventType eventType, string logMessage) => WriteWithCallstack(eventType, LogEvent.Default, logMessage); + + /// + /// Writes a message to the log file with accompanying callstack. + /// + /// The level at which the message will be written. + /// The event id enumeration for the log event. + /// The message text to be written. + /// + /// The callstack logging gets turned on globally and any other log writes that happens in the time window + /// while this log write is happening will also get callstack information logged. This is not considered + /// and trying to isolate the callstack logging to be turned of for just one call is unnecessarily complex. + /// + public static void WriteWithCallstack(TraceEventType eventType, LogEvent logEvent, string logMessage) + { + Logger.StartCallStack(); + Write(eventType, logEvent, logMessage); + Logger.StopCallStack(); + } + + /// + /// Writes a message to the log file. + /// + /// The level at which the message will be written. + /// The event id enumeration for the log event. + /// The message text to be written. + public static void Write( + TraceEventType eventType, + LogEvent logEvent, + string logMessage) + { + // If logger is initialized then use TraceSource else use Trace + if (TraceSource != null) + { + TraceSource.TraceEvent(eventType, (ushort)logEvent, logMessage); + } + else + { + switch (eventType) + { + case TraceEventType.Critical: + case TraceEventType.Error: + if (eventType == TraceEventType.Critical) + { + logMessage = $@"event={eventType}: {logMessage}"; + } + + Trace.TraceError(logMessage); + break; + case TraceEventType.Warning: + Trace.TraceWarning(logMessage); + break; + case TraceEventType.Information: + case TraceEventType.Resume: + case TraceEventType.Start: + case TraceEventType.Stop: + case TraceEventType.Suspend: + case TraceEventType.Transfer: + case TraceEventType.Verbose: + if (eventType != TraceEventType.Information) + { + logMessage = $@"event={eventType}: {logMessage}"; + } + + Trace.TraceInformation(logMessage); + break; + } + } + } + } + + /// + /// This listener has the same behavior as TextWriterTraceListener except it controls how the + /// options: TraceOptions.DateTime, TraceOptions.ProcessId and TraceOptions.ThreadId is written to the output stream. + /// This listener writes the above options, if turned on, inline with the message + /// instead of writing them to indented fields as is the case with TextWriterTraceListener. + /// This implementation also lazily initializes the underlying tracelistener + /// + /// + /// Implementation of this is a lazily initialize trace listener that is partly inspired + /// by: https://stackoverflow.com/questions/30664527/how-to-stop-streamwriter-to-not-to-create-file-if-nothing-to-write + /// + internal sealed class SqlToolsTraceListener : TraceListener + { + Lazy _lazyListener; + private TextWriterTraceListener Listener => _lazyListener.Value; + private bool IsListenerCreated => _lazyListener.IsValueCreated; + public SqlToolsTraceListener(string file, string listenerName = "") : base(listenerName) + { + // Wrapping around lazy to make sure that we do not create file if the log.Write events are getting filtered out. i.e. the log file actually gets created the first time an actual write to log file happens. + _lazyListener = new Lazy( + valueFactory: () => new TextWriterTraceListener(new StreamWriter(file, append: true), listenerName), + // LazyThreadSafetyMode.PublicationOnly mode ensures that we keep trying to create the listener (especially the file that write) on all future log.write events even if previous attempt(s) have failed + mode: LazyThreadSafetyMode.PublicationOnly + ); + } + #region forward actual write/close/flush/dispose calls to the underlying listener. + public override void Write(string message) => Listener.Write(message); + + public override void WriteLine(string message) => Listener.WriteLine(message); + + /// + /// Closes the so that it no longer + /// receives tracing or debugging output. + /// Make sure that we do not Close if the lazy listener never got created. + /// + public override void Close() + { + if (IsListenerCreated) + { + Listener.Close(); + } + } + + /// + /// Releases all resources used by the + /// No unmanaged resources in this class, and it is sealed. + /// No finalizer needed. See http://stackoverflow.com/a/3882819/613130 + /// We skip disposing if the lazy listener never got created. + /// + public new void Dispose() + { + if (IsListenerCreated) + { + Listener.Dispose(); + } + } + + /// + /// Flushes the output buffer for the . + /// Make sure that we do not Flush if the lazy listener never got created. + /// + public override void Flush() + { + if (IsListenerCreated) + { + Listener.Flush(); + } + } + #endregion + + public override void TraceEvent(TraceEventCache eventCache, String source, TraceEventType eventType, int id) + { + TraceEvent(eventCache, source, eventType, id, String.Empty); + } + + // All other TraceEvent methods come through this one. + public override void TraceEvent(TraceEventCache eventCache, String source, TraceEventType eventType, int id, string message) + { + if (Filter != null && !Filter.ShouldTrace(eventCache, source, eventType, id, message, null, null, null)) { return; } - if (logWriter != null) - { - logWriter.Write( - logLevel, - logMessage, - callerName, - callerSourceFile, - callerLineNumber); - } + WriteHeader(eventCache, source, eventType, id); + WriteLine(message); + WriteFooter(eventCache); } - } - internal class LogWriter : IDisposable - { - private object logLock = new object(); - private TextWriter textWriter; - private LogLevel minimumLogLevel = LogLevel.Verbose; - - public LogWriter(LogLevel minimumLogLevel, string logFilePath, bool deleteExisting) + public override void TraceEvent(TraceEventCache eventCache, String source, TraceEventType eventType, int id, string format, params object[] args) { - this.minimumLogLevel = minimumLogLevel; + if (Filter != null && !Filter.ShouldTrace(eventCache, source, eventType, id, format, args, null, null)) + { + return; + } - // Ensure that we have a usable log file path - if (!Path.IsPathRooted(logFilePath)) - { - logFilePath = - Path.Combine( - AppContext.BaseDirectory, - logFilePath); - } - - - if (!this.TryOpenLogFile(logFilePath, deleteExisting)) - { - // If the log file couldn't be opened at this location, - // try opening it in a more reliable path - this.TryOpenLogFile( - Path.Combine( - Environment.GetEnvironmentVariable("TEMP"), - Path.GetFileName(logFilePath)), - deleteExisting); - } + WriteHeader(eventCache, source, eventType, id); + if (args != null) + { + WriteLine(String.Format(CultureInfo.InvariantCulture, format, args)); + } + else + { + WriteLine(format); + } + WriteFooter(eventCache); } - public void Write( - LogLevel logLevel, - string logMessage, - string callerName = null, - string callerSourceFile = null, - int callerLineNumber = 0) + private void WriteHeader(TraceEventCache eventCache, String source, TraceEventType eventType, int id) + => Write(FormatHeader(eventCache, String.Format(CultureInfo.InvariantCulture, "{0} {1}: {2} : ", source, eventType.ToString(), id.ToString(CultureInfo.InvariantCulture)))); + + private void WriteFooter(TraceEventCache eventCache) { - if (this.textWriter != null && - logLevel >= this.minimumLogLevel) + if (eventCache == null) { - // System.IO is not thread safe - lock (this.logLock) - { - // Print the timestamp and log level - this.textWriter.WriteLine( - "{0} [{1}] - Method \"{2}\" at line {3} of {4}\r\n", - DateTime.Now, - logLevel.ToString().ToUpper(), - callerName, - callerLineNumber, - callerSourceFile); - - // Print out indented message lines - foreach (var messageLine in logMessage.Split('\n')) - { - this.textWriter.WriteLine(" " + messageLine.TrimEnd()); - } - - // Finish with a newline and flush the writer - this.textWriter.WriteLine(); - this.textWriter.Flush(); - } + return; } + + IndentLevel++; + if (TraceOutputOptions.HasFlag(TraceOptions.LogicalOperationStack)) + { + WriteLine("LogicalOperationStack=" + eventCache.LogicalOperationStack); + } + + if (TraceOutputOptions.HasFlag(TraceOptions.Callstack)) + { + WriteLine("Callstack=" + eventCache.Callstack); + } + + IndentLevel--; } - public void Dispose() + private string FormatHeader(TraceEventCache eventCache, string message) { - if (this.textWriter != null) + if (eventCache == null) { - this.textWriter.Flush(); - this.textWriter.Dispose(); - this.textWriter = null; + return message; } + + return $"{(IsEnabled(TraceOptions.DateTime) ? string.Format(CultureInfo.InvariantCulture, "{0} ", eventCache.DateTime.ToLocalTime().ToString("u", CultureInfo.InvariantCulture)) : string.Empty)}" + + $"{(IsEnabled(TraceOptions.ProcessId) ? string.Format(CultureInfo.InvariantCulture, "pid:{0} ", eventCache.ProcessId.ToString(CultureInfo.InvariantCulture)) : string.Empty)}" + + $"{(IsEnabled(TraceOptions.ThreadId) ? string.Format(CultureInfo.InvariantCulture, "tid:{0} ", eventCache.ThreadId.ToString(CultureInfo.InvariantCulture)) : string.Empty)}" + + message; } - private bool TryOpenLogFile( - string logFilePath, - bool deleteExisting) - { - try - { - // Make sure the log directory exists - Directory.CreateDirectory( - Path.GetDirectoryName( - logFilePath)); + private bool IsEnabled(TraceOptions opt) => TraceOutputOptions.HasFlag(opt); - // Open the log file for writing with UTF8 encoding - this.textWriter = - new StreamWriter( - new FileStream( - logFilePath, - deleteExisting ? - FileMode.Create : - FileMode.Append), - Encoding.UTF8); - - return true; - } - catch (Exception e) - { - if (e is UnauthorizedAccessException || - e is IOException) - { - // This exception is thrown when we can't open the file - // at the path in logFilePath. Return false to indicate - // that the log file couldn't be created. - return false; - } - - // Unexpected exception, rethrow it - throw; - } - } } } diff --git a/src/Microsoft.SqlTools.Hosting.v2/Utility/TaskExtensions.cs b/src/Microsoft.SqlTools.Hosting.v2/Utility/TaskExtensions.cs index 110d06d7..75ad0823 100644 --- a/src/Microsoft.SqlTools.Hosting.v2/Utility/TaskExtensions.cs +++ b/src/Microsoft.SqlTools.Hosting.v2/Utility/TaskExtensions.cs @@ -4,6 +4,7 @@ // using System; +using System.Diagnostics; using System.Text; using System.Threading.Tasks; @@ -41,8 +42,8 @@ namespace Microsoft.SqlTools.Hosting.Utility } catch (Exception e) { - Logger.Instance.Write(LogLevel.Error, $"Exception in exception handling continuation: {e}"); - Logger.Instance.Write(LogLevel.Error, e.StackTrace); + Logger.Write(TraceEventType.Error, $"Exception in exception handling continuation: {e}"); + Logger.Write(TraceEventType.Error, e.StackTrace); } }); } @@ -78,8 +79,8 @@ namespace Microsoft.SqlTools.Hosting.Utility } catch (Exception e) { - Logger.Instance.Write(LogLevel.Error, $"Exception in exception handling continuation: {e}"); - Logger.Instance.Write(LogLevel.Error, e.StackTrace); + Logger.Write(TraceEventType.Error, $"Exception in exception handling continuation: {e}"); + Logger.Write(TraceEventType.Error, e.StackTrace); } }); } @@ -93,7 +94,7 @@ namespace Microsoft.SqlTools.Hosting.Utility sb.AppendLine($"{e.GetType().Name}: {e.Message}"); sb.AppendLine(e.StackTrace); } - Logger.Instance.Write(LogLevel.Error, sb.ToString()); + Logger.Write(TraceEventType.Error, sb.ToString()); } } } \ No newline at end of file diff --git a/src/Microsoft.SqlTools.Hosting/Hosting/IHostedService.cs b/src/Microsoft.SqlTools.Hosting/Hosting/IHostedService.cs index 44e5030a..f905a073 100644 --- a/src/Microsoft.SqlTools.Hosting/Hosting/IHostedService.cs +++ b/src/Microsoft.SqlTools.Hosting/Hosting/IHostedService.cs @@ -4,6 +4,7 @@ // using System; +using System.Diagnostics; using System.Threading.Tasks; using Microsoft.SqlTools.Extensibility; using Microsoft.SqlTools.Hosting.Protocol; @@ -69,7 +70,7 @@ namespace Microsoft.SqlTools.Hosting protected async Task HandleRequestAsync(Func> handler, RequestContext requestContext, string requestType) { - Logger.Write(LogLevel.Verbose, requestType); + Logger.Write(TraceEventType.Verbose, requestType); try { diff --git a/src/Microsoft.SqlTools.Hosting/Hosting/Protocol/MessageDispatcher.cs b/src/Microsoft.SqlTools.Hosting/Hosting/Protocol/MessageDispatcher.cs index b5963b1b..7937e7ca 100644 --- a/src/Microsoft.SqlTools.Hosting/Hosting/Protocol/MessageDispatcher.cs +++ b/src/Microsoft.SqlTools.Hosting/Hosting/Protocol/MessageDispatcher.cs @@ -5,6 +5,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.IO; using System.Threading; using System.Threading.Tasks; @@ -169,7 +170,7 @@ namespace Microsoft.SqlTools.Hosting.Protocol } catch (Exception ex) { - Logger.Write(LogLevel.Verbose, ex.ToString()); + Logger.Write(TraceEventType.Verbose, ex.ToString()); } } @@ -217,7 +218,7 @@ namespace Microsoft.SqlTools.Hosting.Protocol catch (MessageParseException e) { string message = string.Format("Exception occurred while parsing message: {0}", e.Message); - Logger.Write(LogLevel.Error, message); + Logger.Write(TraceEventType.Error, message); await MessageWriter.WriteEvent(HostingErrorEvent.Type, new HostingErrorParams { Message = message }); // Continue the loop @@ -232,7 +233,7 @@ namespace Microsoft.SqlTools.Hosting.Protocol { // Log the error and send an error event to the client string message = string.Format("Exception occurred while receiving message: {0}", e.Message); - Logger.Write(LogLevel.Error, message); + Logger.Write(TraceEventType.Error, message); await MessageWriter.WriteEvent(HostingErrorEvent.Type, new HostingErrorParams { Message = message }); // Continue the loop @@ -246,7 +247,7 @@ namespace Microsoft.SqlTools.Hosting.Protocol // Verbose logging string logMessage = string.Format("Received message of type[{0}] and method[{1}]", newMessage.MessageType, newMessage.Method); - Logger.Write(LogLevel.Verbose, logMessage); + Logger.Write(TraceEventType.Verbose, logMessage); // Process the message await this.DispatchMessage(newMessage, this.MessageWriter); @@ -312,7 +313,7 @@ namespace Microsoft.SqlTools.Hosting.Protocol if (!(e is AggregateException && ((AggregateException)e).InnerExceptions[0] is TaskCanceledException)) { // Log the error but don't rethrow it to prevent any errors in the handler from crashing the service - Logger.Write(LogLevel.Error, string.Format("An unexpected error occured in the request handler: {0}", e.ToString())); + Logger.Write(TraceEventType.Error, string.Format("An unexpected error occured in the request handler: {0}", e.ToString())); } } } diff --git a/src/Microsoft.SqlTools.Hosting/Hosting/Protocol/MessageWriter.cs b/src/Microsoft.SqlTools.Hosting/Hosting/Protocol/MessageWriter.cs index e77942b4..d8ba4bb8 100644 --- a/src/Microsoft.SqlTools.Hosting/Hosting/Protocol/MessageWriter.cs +++ b/src/Microsoft.SqlTools.Hosting/Hosting/Protocol/MessageWriter.cs @@ -3,6 +3,7 @@ // Licensed under the MIT license. See LICENSE file in the project root for full license information. // +using System.Diagnostics; using System.IO; using System.Text; using System.Threading.Tasks; @@ -60,7 +61,7 @@ namespace Microsoft.SqlTools.Hosting.Protocol // Log the JSON representation of the message string logMessage = string.Format("Sending message of type[{0}] and method[{1}]", messageToWrite.MessageType, messageToWrite.Method); - Logger.Write(LogLevel.Verbose, logMessage); + Logger.Write(TraceEventType.Verbose, logMessage); string serializedMessage = JsonConvert.SerializeObject( diff --git a/src/Microsoft.SqlTools.Hosting/Hosting/Protocol/ProtocolEndpoint.cs b/src/Microsoft.SqlTools.Hosting/Hosting/Protocol/ProtocolEndpoint.cs index 56678b44..1dc64521 100644 --- a/src/Microsoft.SqlTools.Hosting/Hosting/Protocol/ProtocolEndpoint.cs +++ b/src/Microsoft.SqlTools.Hosting/Hosting/Protocol/ProtocolEndpoint.cs @@ -5,6 +5,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Threading; using System.Threading.Tasks; using Microsoft.SqlTools.Hosting.Protocol.Channel; @@ -254,7 +255,7 @@ namespace Microsoft.SqlTools.Hosting.Protocol { if (SendEventIgnoreExceptions) { - Logger.Write(LogLevel.Verbose, "Exception in SendEvent " + ex.ToString()); + Logger.Write(TraceEventType.Verbose, "Exception in SendEvent " + ex.ToString()); } else { diff --git a/src/Microsoft.SqlTools.Hosting/Microsoft.SqlTools.Hosting.csproj b/src/Microsoft.SqlTools.Hosting/Microsoft.SqlTools.Hosting.csproj index 8a4f3589..b159d5a6 100644 --- a/src/Microsoft.SqlTools.Hosting/Microsoft.SqlTools.Hosting.csproj +++ b/src/Microsoft.SqlTools.Hosting/Microsoft.SqlTools.Hosting.csproj @@ -6,7 +6,7 @@ false false false - $(DefineConstants);NETCOREAPP1_0 + $(DefineConstants);NETCOREAPP1_0;TRACE true true portable diff --git a/src/Microsoft.SqlTools.Hosting/Utility/CommandOptions.cs b/src/Microsoft.SqlTools.Hosting/Utility/CommandOptions.cs index bc56d254..364f0c6a 100644 --- a/src/Microsoft.SqlTools.Hosting/Utility/CommandOptions.cs +++ b/src/Microsoft.SqlTools.Hosting/Utility/CommandOptions.cs @@ -14,6 +14,11 @@ namespace Microsoft.SqlTools.Hosting.Utility /// public class CommandOptions { + // set default log directory + // refer to https://jimrich.sk/environment-specialfolder-on-windows-linux-and-os-x/ && https://stackoverflow.com/questions/895723/environment-getfolderpath-commonapplicationdata-is-still-returning-c-docum + // for cross platform locations + internal readonly string DefaultLogRoot = Environment.GetFolderPath(Environment.SpecialFolder.ApplicationData); + /// /// Construct and parse command line options from the arguments array /// @@ -23,6 +28,13 @@ namespace Microsoft.SqlTools.Hosting.Utility ErrorMessage = string.Empty; Locale = string.Empty; + //set default log directory + LoggingDirectory = DefaultLogRoot; + if (!string.IsNullOrWhiteSpace(ServiceName)) + { + LoggingDirectory = Path.Combine(LoggingDirectory, ServiceName); + } + try { for (int i = 0; i < args.Length; ++i) @@ -37,7 +49,12 @@ namespace Microsoft.SqlTools.Hosting.Utility switch (argName) { case "-enable-logging": - EnableLogging = true; + break; //ignore this old option for now for backward compat with older opsstudio code - to be removed in a future checkin + case "-tracing-level": + TracingLevel = args[++i]; + break; + case "-log-file": + LogFilePath = args[++i]; break; case "-log-dir": SetLoggingDirectory(args[++i]); @@ -76,12 +93,6 @@ namespace Microsoft.SqlTools.Hosting.Utility /// public string ErrorMessage { get; private set; } - - /// - /// Whether diagnostic logging is enabled - /// - public bool EnableLogging { get; private set; } - /// /// Gets the directory where log files are output. /// @@ -112,15 +123,21 @@ namespace Microsoft.SqlTools.Hosting.Utility var str = string.Format("{0}" + Environment.NewLine + ServiceName + " " + Environment.NewLine + " Options:" + Environment.NewLine + - " [--enable-logging]" + Environment.NewLine + - " [--log-dir **] (default: current directory)" + Environment.NewLine + - " [--help]" + Environment.NewLine + + " [--enable-logging ] (obsolete - present for backward compat. Logging is always on, except -tracing-level Off has the effect of disabling logging)" + Environment.NewLine + + " [--tracing-level **] (** can be any of: All, Off, Critical, Error, Warning, Information, Verbose. Default is Critical)" + Environment.NewLine + + " [--log-file **]" + Environment.NewLine + + " [--log-dir **] (default: %APPDATA%\\)" + Environment.NewLine + " [--locale **] (default: 'en')" + Environment.NewLine, + " [--help]" + Environment.NewLine + ErrorMessage); return str; } } + public string TracingLevel { get; private set; } + + public string LogFilePath { get; private set; } + private void SetLoggingDirectory(string loggingDirectory) { if (string.IsNullOrWhiteSpace(loggingDirectory)) diff --git a/src/Microsoft.SqlTools.Hosting/Utility/GeneralRequestDetails.cs b/src/Microsoft.SqlTools.Hosting/Utility/GeneralRequestDetails.cs index a407dc6e..b88cf3d0 100644 --- a/src/Microsoft.SqlTools.Hosting/Utility/GeneralRequestDetails.cs +++ b/src/Microsoft.SqlTools.Hosting/Utility/GeneralRequestDetails.cs @@ -5,6 +5,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Globalization; namespace Microsoft.SqlTools.Utility @@ -29,7 +30,7 @@ namespace Microsoft.SqlTools.Utility catch { result = default(T); - Logger.Write(LogLevel.Warning, string.Format(CultureInfo.InvariantCulture, + Logger.Write(TraceEventType.Warning, string.Format(CultureInfo.InvariantCulture, "Cannot convert option value {0}:{1} to {2}", name, value ?? "", typeof(T))); } } diff --git a/src/Microsoft.SqlTools.Hosting/Utility/Logger.cs b/src/Microsoft.SqlTools.Hosting/Utility/Logger.cs index 6b515a17..843e8436 100644 --- a/src/Microsoft.SqlTools.Hosting/Utility/Logger.cs +++ b/src/Microsoft.SqlTools.Hosting/Utility/Logger.cs @@ -5,76 +5,157 @@ using System; using System.Diagnostics; +using System.Globalization; using System.IO; -using System.Runtime.CompilerServices; -using System.Text; +using System.Threading; namespace Microsoft.SqlTools.Utility { /// - /// Defines the level indicators for log messages. + /// Ordinal value of each LogEvent value corresponds to a unique event id to be used in trace. + /// By convention explicitly specify the integer value so that when this list grows large it is easy to figure out + /// enumeration corresponding to a numeric value. We could be reserving ranges of values for specific areas or logEvents. + /// Maximum value assignable to LogEvent enum value is 65,535. /// - public enum LogLevel + public enum LogEvent : ushort { - /// - /// Indicates a verbose log message. - /// - Verbose, - - /// - /// Indicates a normal, non-verbose log message. - /// - Normal, - - /// - /// Indicates a warning message. - /// - Warning, - - /// - /// Indicates an error message. - /// - Error + Default = 0, + IoFileSystem = 1, + OsSubSystem = 2, } /// - /// Provides a simple logging interface. May be replaced with a - /// more robust solution at a later date. + /// Provides a simple logging interface built on top of .Net tracing frameworks /// public static class Logger { - private static LogWriter logWriter; + internal const SourceLevels defaultTracingLevel = SourceLevels.Critical; + internal const string defaultTraceSource = "sqltools"; + private static SourceLevels tracingLevel = defaultTracingLevel; + private static string logFileFullPath; - private static bool isEnabled; + internal static TraceSource TraceSource { get; set; } + internal static string LogFileFullPath + { + get => logFileFullPath; + private set + { + //If the log file path has a directory component then ensure that the directory exists. + if (!string.IsNullOrEmpty(Path.GetDirectoryName(value)) && !Directory.Exists(Path.GetDirectoryName(value))) + { + Directory.CreateDirectory(Path.GetDirectoryName(value)); + } - private static bool isInitialized = false; + logFileFullPath = value; + ConfigureListener(); + } + } + + private static SqlToolsTraceListener Listener { get; set; } + + private static void ConfigureLogFile(string logFilePrefix) => LogFileFullPath = GenerateLogFilePath(logFilePrefix); /// - /// Initializes the Logger for the current session. + /// Calling this method will turn on inclusion CallStack in the log for all future traces /// - /// - /// Optional. Specifies the path at which log messages will be written. - /// - /// + public static void StartCallStack() => Listener.TraceOutputOptions |= TraceOptions.Callstack; + + /// + /// Calling this method will turn off inclusion of CallStack in the log for all future traces + /// + public static void StopCallStack() => Listener.TraceOutputOptions &= ~TraceOptions.Callstack; + + /// + /// Calls flush on defaultTracingLevel configured listeners. + /// + public static void Flush() + { + TraceSource.Flush(); + Trace.Flush(); + } + + public static void Close() + { + Flush(); + TraceSource.Close(); + Trace.Close(); + Listener = null; // Since we have closed the listener, set listener to null. + } + public static SourceLevels TracingLevel + { + get => tracingLevel; + set + { + // configures the source level filter. This alone is not enough for tracing that is done via "Trace" object instead of "TraceSource" object + TraceSource.Switch = new SourceSwitch(TraceSource.Name, value.ToString()); + // configure the listener level filter + tracingLevel = value; + Listener.Filter = new EventTypeFilter(tracingLevel); + } + } + + /// + /// Initializes the Logger for the current process. + /// + /// /// Optional. Specifies the minimum log message level to write to the log file. /// + /// + /// Optional. Specifies the log name prefix for the log file name at which log messages will be written. + /// + /// Optional. Specifies the tracesource name. + /// public static void Initialize( - string logFilePath = "sqltools", - LogLevel minimumLogLevel = LogLevel.Normal, - bool isEnabled = true) + SourceLevels tracingLevel = defaultTracingLevel, + string logFilePath = null, + string traceSource = defaultTraceSource) { - Logger.isEnabled = isEnabled; - - // return if the logger is not enabled or already initialized - if (!Logger.isEnabled || Logger.isInitialized) + Logger.tracingLevel = tracingLevel; + TraceSource = new TraceSource(traceSource, Logger.tracingLevel); + if (string.IsNullOrWhiteSpace(logFilePath)) { - return; + logFilePath = GenerateLogFilePath(traceSource); } - Logger.isInitialized = true; + LogFileFullPath = logFilePath; + Write(TraceEventType.Information, $"Initialized the {traceSource} logger"); + } + /// + /// Initializes the Logger for the current process. + /// + /// + /// + /// Optional. Specifies the minimum log message level to write to the log file. + /// + /// + /// Optional. Specifies the log name prefix for the log file name at which log messages will be written. + /// + /// Optional. Specifies the tracesource name. + /// + public static void Initialize(string tracingLevel, string logFilePath = null, string traceSource = defaultTraceSource) + { + Initialize(Enum.TryParse(tracingLevel, out SourceLevels sourceTracingLevel) + ? sourceTracingLevel + : defaultTracingLevel + , logFilePath + , traceSource); + } + + /// + /// Configures the LogfilePath for the tracelistener in use for this process. + /// + /// + /// Returns the log file path corresponding to logfilePrefix + /// + public static string GenerateLogFilePath(string logFilePrefix = defaultTraceSource) + { + if (string.IsNullOrWhiteSpace(logFilePrefix)) + { + throw new ArgumentOutOfRangeException(nameof(logFilePrefix), $"LogfilePath cannot be configured if argument {nameof(logFilePrefix)} has not been set"); + } // Create the log directory - string logDir = Path.GetDirectoryName(logFilePath); + string logDir = Path.GetDirectoryName(logFilePrefix); if (!string.IsNullOrWhiteSpace(logDir)) { if (!Directory.Exists(logDir)) @@ -83,207 +164,280 @@ namespace Microsoft.SqlTools.Utility { Directory.CreateDirectory(logDir); } - catch (Exception) + catch (Exception ex) { - // Creating the log directory is a best effort operation, so ignore any failures. + Write(TraceEventType.Error, LogEvent.IoFileSystem, $"Unable to create directory:{logDir}\nException encountered:{ex}"); } } } - // get a unique number to prevent conflicts of two process launching at the same time int uniqueId; try { uniqueId = Process.GetCurrentProcess().Id; } - catch (Exception) + catch (Exception ex) { + Write(TraceEventType.Information, LogEvent.OsSubSystem, $"Unable to get process id of current running process\nException encountered:{ex}"); // if the pid look up fails for any reason, just use a random number - uniqueId = new Random().Next(1000, 9999); + uniqueId = new Random().Next(1000, 9999); } // make the log path unique - string fullFileName = string.Format( - "{0}_{1,4:D4}{2,2:D2}{3,2:D2}{4,2:D2}{5,2:D2}{6,2:D2}{7}.log", - logFilePath, - DateTime.Now.Year, DateTime.Now.Month, DateTime.Now.Day, - DateTime.Now.Hour, DateTime.Now.Minute, DateTime.Now.Second, - uniqueId); - - if (logWriter != null) - { - logWriter.Dispose(); - } - - // TODO: Parameterize this - logWriter = - new LogWriter( - minimumLogLevel, - fullFileName, - true); - - Logger.Write(LogLevel.Normal, "Initializing SQL Tools Service Host logger"); + return $"{logFilePrefix}_{DateTime.Now.Year,4:D4}{DateTime.Now.Month,2:D2}{DateTime.Now.Day,2:D2}{DateTime.Now.Hour,2:D2}{DateTime.Now.Minute,2:D2}{DateTime.Now.Second,2:D2}{uniqueId}.log"; } - /// - /// Closes the Logger. - /// - public static void Close() + private static void ConfigureListener() { - if (logWriter != null) + if (string.IsNullOrWhiteSpace(LogFileFullPath)) { - logWriter.Dispose(); + throw new InvalidOperationException("Listeners cannot be configured if LogFileFullPath has not been set"); } + Listener = new SqlToolsTraceListener(LogFileFullPath) + { + TraceOutputOptions = TraceOptions.DateTime | TraceOptions.ProcessId | TraceOptions.ThreadId, + Filter = new EventTypeFilter(TracingLevel), + }; + TraceSource.Listeners.Clear(); + TraceSource.Listeners.Add(Listener); + Trace.Listeners.Clear(); + Trace.Listeners.Add(Listener); } /// /// Writes a message to the log file. /// - /// The level at which the message will be written. + /// The level at which the message will be written. + /// The message text to be written. + public static void Write(TraceEventType eventType, string logMessage) => Write(eventType, LogEvent.Default, logMessage); + + /// + /// Writes a message to the log file with accompanying callstack. + /// + /// The level at which the message will be written. + /// The message text to be written. + /// + /// The callstack logging gets turned on globally and any other log writes that happens in the time window + /// while this log write is happening will also get callstack information logged. This is not considered + /// and trying to isolate the callstack logging to be turned of for just one call is unnecessarily complex. + /// + public static void WriteWithCallstack(TraceEventType eventType, string logMessage) => WriteWithCallstack(eventType, LogEvent.Default, logMessage); + + /// + /// Writes a message to the log file with accompanying callstack. + /// + /// The level at which the message will be written. + /// The event id enumeration for the log event. + /// The message text to be written. + /// + /// The callstack logging gets turned on globally and any other log writes that happens in the time window + /// while this log write is happening will also get callstack information logged. This is not considered + /// and trying to isolate the callstack logging to be turned of for just one call is unnecessarily complex. + /// + public static void WriteWithCallstack(TraceEventType eventType, LogEvent logEvent, string logMessage) + { + Logger.StartCallStack(); + Write(eventType, logEvent, logMessage); + Logger.StopCallStack(); + } + + /// + /// Writes a message to the log file. + /// + /// The level at which the message will be written. + /// The event id enumeration for the log event. /// The message text to be written. - /// The name of the calling method. - /// The source file path where the calling method exists. - /// The line number of the calling method. public static void Write( - LogLevel logLevel, - string logMessage, - [CallerMemberName] string callerName = null, - [CallerFilePath] string callerSourceFile = null, - [CallerLineNumber] int callerLineNumber = 0) - { - // return if the logger is not enabled or not initialized - if (!Logger.isEnabled || !Logger.isInitialized) + TraceEventType eventType, + LogEvent logEvent, + string logMessage) + { + // If logger is initialized then use TraceSource else use Trace + if (TraceSource != null) + { + TraceSource.TraceEvent(eventType, (ushort)logEvent, logMessage); + } + else + { + switch (eventType) + { + case TraceEventType.Critical: + case TraceEventType.Error: + if (eventType == TraceEventType.Critical) + { + logMessage = $@"event={eventType}: {logMessage}"; + } + + Trace.TraceError(logMessage); + break; + case TraceEventType.Warning: + Trace.TraceWarning(logMessage); + break; + case TraceEventType.Information: + case TraceEventType.Resume: + case TraceEventType.Start: + case TraceEventType.Stop: + case TraceEventType.Suspend: + case TraceEventType.Transfer: + case TraceEventType.Verbose: + if (eventType != TraceEventType.Information) + { + logMessage = $@"event={eventType}: {logMessage}"; + } + + Trace.TraceInformation(logMessage); + break; + } + } + } + } + + /// + /// This listener has the same behavior as TextWriterTraceListener except it controls how the + /// options: TraceOptions.DateTime, TraceOptions.ProcessId and TraceOptions.ThreadId is written to the output stream. + /// This listener writes the above options, if turned on, inline with the message + /// instead of writing them to indented fields as is the case with TextWriterTraceListener. + /// This implementation also lazily initializes the underlying tracelistener + /// + /// + /// Implementation of this is a lazily initialize trace listener that is partly inspired + /// by: https://stackoverflow.com/questions/30664527/how-to-stop-streamwriter-to-not-to-create-file-if-nothing-to-write + /// + internal sealed class SqlToolsTraceListener : TraceListener + { + Lazy _lazyListener; + private TextWriterTraceListener Listener => _lazyListener.Value; + private bool IsListenerCreated => _lazyListener.IsValueCreated; + public SqlToolsTraceListener(string file, string listenerName = "") : base(listenerName) + { + // Wrapping around lazy to make sure that we do not create file if the log.Write events are getting filtered out. i.e. the log file actually gets created the first time an actual write to log file happens. + _lazyListener = new Lazy( + valueFactory: () => new TextWriterTraceListener(new StreamWriter(file, append: true), listenerName), + // LazyThreadSafetyMode.PublicationOnly mode ensures that we keep trying to create the listener (especially the file that write) on all future log.write events even if previous attempt(s) have failed + mode: LazyThreadSafetyMode.PublicationOnly + ); + } + #region forward actual write/close/flush/dispose calls to the underlying listener. + public override void Write(string message) => Listener.Write(message); + + public override void WriteLine(string message) => Listener.WriteLine(message); + + /// + /// Closes the so that it no longer + /// receives tracing or debugging output. + /// Make sure that we do not Close if the lazy listener never got created. + /// + public override void Close() + { + if (IsListenerCreated) + { + Listener.Close(); + } + } + + /// + /// Releases all resources used by the + /// No unmanaged resources in this class, and it is sealed. + /// No finalizer needed. See http://stackoverflow.com/a/3882819/613130 + /// We skip disposing if the lazy listener never got created. + /// + public new void Dispose() + { + if (IsListenerCreated) + { + Listener.Dispose(); + } + } + + /// + /// Flushes the output buffer for the . + /// Make sure that we do not Flush if the lazy listener never got created. + /// + public override void Flush() + { + if (IsListenerCreated) + { + Listener.Flush(); + } + } + #endregion + + public override void TraceEvent(TraceEventCache eventCache, String source, TraceEventType eventType, int id) + { + TraceEvent(eventCache, source, eventType, id, String.Empty); + } + + // All other TraceEvent methods come through this one. + public override void TraceEvent(TraceEventCache eventCache, String source, TraceEventType eventType, int id, string message) + { + if (Filter != null && !Filter.ShouldTrace(eventCache, source, eventType, id, message, null, null, null)) { return; } - if (logWriter != null) - { - logWriter.Write( - logLevel, - logMessage, - callerName, - callerSourceFile, - callerLineNumber); - } + WriteHeader(eventCache, source, eventType, id); + WriteLine(message); + WriteFooter(eventCache); } - } - internal class LogWriter : IDisposable - { - private object logLock = new object(); - private TextWriter textWriter; - private LogLevel minimumLogLevel = LogLevel.Verbose; - - public LogWriter(LogLevel minimumLogLevel, string logFilePath, bool deleteExisting) + public override void TraceEvent(TraceEventCache eventCache, String source, TraceEventType eventType, int id, string format, params object[] args) { - this.minimumLogLevel = minimumLogLevel; + if (Filter != null && !Filter.ShouldTrace(eventCache, source, eventType, id, format, args, null, null)) + { + return; + } - // Ensure that we have a usable log file path - if (!Path.IsPathRooted(logFilePath)) - { - logFilePath = - Path.Combine( - AppContext.BaseDirectory, - logFilePath); - } - - - if (!this.TryOpenLogFile(logFilePath, deleteExisting)) - { - // If the log file couldn't be opened at this location, - // try opening it in a more reliable path - this.TryOpenLogFile( - Path.Combine( - Environment.GetEnvironmentVariable("TEMP"), - Path.GetFileName(logFilePath)), - deleteExisting); - } + WriteHeader(eventCache, source, eventType, id); + if (args != null) + { + WriteLine(String.Format(CultureInfo.InvariantCulture, format, args)); + } + else + { + WriteLine(format); + } + WriteFooter(eventCache); } - public void Write( - LogLevel logLevel, - string logMessage, - string callerName = null, - string callerSourceFile = null, - int callerLineNumber = 0) + private void WriteHeader(TraceEventCache eventCache, String source, TraceEventType eventType, int id) + => Write(FormatHeader(eventCache, String.Format(CultureInfo.InvariantCulture, "{0} {1}: {2} : ", source, eventType.ToString(), id.ToString(CultureInfo.InvariantCulture)))); + + private void WriteFooter(TraceEventCache eventCache) { - if (this.textWriter != null && - logLevel >= this.minimumLogLevel) + if (eventCache == null) { - // System.IO is not thread safe - lock (this.logLock) - { - // Print the timestamp and log level - this.textWriter.WriteLine( - "{0} [{1}] - Method \"{2}\" at line {3} of {4}\r\n", - DateTime.Now, - logLevel.ToString().ToUpper(), - callerName, - callerLineNumber, - callerSourceFile); - - // Print out indented message lines - foreach (var messageLine in logMessage.Split('\n')) - { - this.textWriter.WriteLine(" " + messageLine.TrimEnd()); - } - - // Finish with a newline and flush the writer - this.textWriter.WriteLine(); - this.textWriter.Flush(); - } + return; } + + IndentLevel++; + if (TraceOutputOptions.HasFlag(TraceOptions.LogicalOperationStack)) + { + WriteLine("LogicalOperationStack=" + eventCache.LogicalOperationStack); + } + + if (TraceOutputOptions.HasFlag(TraceOptions.Callstack)) + { + WriteLine("Callstack=" + eventCache.Callstack); + } + + IndentLevel--; } - public void Dispose() + private string FormatHeader(TraceEventCache eventCache, string message) { - if (this.textWriter != null) + if (eventCache == null) { - this.textWriter.Flush(); - this.textWriter.Dispose(); - this.textWriter = null; + return message; } + + return $"{(IsEnabled(TraceOptions.DateTime) ? string.Format(CultureInfo.InvariantCulture, "{0} ", eventCache.DateTime.ToLocalTime().ToString("u", CultureInfo.InvariantCulture)) : string.Empty)}" + + $"{(IsEnabled(TraceOptions.ProcessId) ? string.Format(CultureInfo.InvariantCulture, "pid:{0} ", eventCache.ProcessId.ToString(CultureInfo.InvariantCulture)) : string.Empty)}" + + $"{(IsEnabled(TraceOptions.ThreadId) ? string.Format(CultureInfo.InvariantCulture, "tid:{0} ", eventCache.ThreadId.ToString(CultureInfo.InvariantCulture)) : string.Empty)}" + + message; } - private bool TryOpenLogFile( - string logFilePath, - bool deleteExisting) - { - try - { - // Make sure the log directory exists - Directory.CreateDirectory( - Path.GetDirectoryName( - logFilePath)); + private bool IsEnabled(TraceOptions opt) => TraceOutputOptions.HasFlag(opt); - // Open the log file for writing with UTF8 encoding - this.textWriter = - new StreamWriter( - new FileStream( - logFilePath, - deleteExisting ? - FileMode.Create : - FileMode.Append), - Encoding.UTF8); - - return true; - } - catch (Exception e) - { - if (e is UnauthorizedAccessException || - e is IOException) - { - // This exception is thrown when we can't open the file - // at the path in logFilePath. Return false to indicate - // that the log file couldn't be created. - return false; - } - - // Unexpected exception, rethrow it - throw; - } - } } } diff --git a/src/Microsoft.SqlTools.Hosting/Utility/UtilityServiceHost.cs b/src/Microsoft.SqlTools.Hosting/Utility/UtilityServiceHost.cs index e9e3a482..176d1c2d 100644 --- a/src/Microsoft.SqlTools.Hosting/Utility/UtilityServiceHost.cs +++ b/src/Microsoft.SqlTools.Hosting/Utility/UtilityServiceHost.cs @@ -5,6 +5,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using System.Reflection; using System.Threading.Tasks; @@ -120,7 +121,7 @@ namespace Microsoft.SqlTools.Utility /// private async Task HandleShutdownRequest(object shutdownParams, RequestContext requestContext) { - Logger.Write(LogLevel.Normal, "Service host is shutting down..."); + Logger.Write(TraceEventType.Information, "Service host is shutting down..."); // Call all the shutdown methods provided by the service components Task[] shutdownTasks = shutdownCallbacks.Select(t => t(shutdownParams, requestContext)).ToArray(); diff --git a/src/Microsoft.SqlTools.ResourceProvider.Core/AuthenticationService.cs b/src/Microsoft.SqlTools.ResourceProvider.Core/AuthenticationService.cs index 9ed88d42..5d6e1c31 100644 --- a/src/Microsoft.SqlTools.ResourceProvider.Core/AuthenticationService.cs +++ b/src/Microsoft.SqlTools.ResourceProvider.Core/AuthenticationService.cs @@ -6,6 +6,7 @@ using System; using System.Collections.Generic; using System.Composition; +using System.Diagnostics; using System.Threading.Tasks; using Microsoft.SqlTools.Extensibility; using Microsoft.SqlTools.Hosting; @@ -32,7 +33,7 @@ namespace Microsoft.SqlTools.ResourceProvider.Core public override void InitializeService(IProtocolEndpoint serviceHost) { - Logger.Write(LogLevel.Verbose, "AuthenticationService initialized"); + Logger.Write(TraceEventType.Verbose, "AuthenticationService initialized"); } public async Task SetCurrentAccountAsync(Account account, Dictionary securityTokenMappings) diff --git a/src/Microsoft.SqlTools.ResourceProvider.Core/ResourceProviderService.cs b/src/Microsoft.SqlTools.ResourceProvider.Core/ResourceProviderService.cs index f013faad..f4d0cb5a 100644 --- a/src/Microsoft.SqlTools.ResourceProvider.Core/ResourceProviderService.cs +++ b/src/Microsoft.SqlTools.ResourceProvider.Core/ResourceProviderService.cs @@ -5,6 +5,7 @@ using System; using System.Composition; +using System.Diagnostics; using System.Threading.Tasks; using Microsoft.SqlTools.Extensibility; using Microsoft.SqlTools.Hosting; @@ -32,7 +33,7 @@ namespace Microsoft.SqlTools.ResourceProvider.Core public override void InitializeService(IProtocolEndpoint serviceHost) { - Logger.Write(LogLevel.Verbose, "ResourceProvider initialized"); + Logger.Write(TraceEventType.Verbose, "ResourceProvider initialized"); serviceHost.SetRequestHandler(CreateFirewallRuleRequest.Type, HandleCreateFirewallRuleRequest); serviceHost.SetRequestHandler(CanHandleFirewallRuleRequest.Type, ProcessHandleFirewallRuleRequest); @@ -112,7 +113,7 @@ namespace Microsoft.SqlTools.ResourceProvider.Core private async Task HandleRequest(Func> handler, Func expiredTokenHandler, RequestContext requestContext, string requestType) { - Logger.Write(LogLevel.Verbose, requestType); + Logger.Write(TraceEventType.Verbose, requestType); try { diff --git a/src/Microsoft.SqlTools.ResourceProvider.DefaultImpl/AzureResourceManager.cs b/src/Microsoft.SqlTools.ResourceProvider.DefaultImpl/AzureResourceManager.cs index 2948381d..824de076 100644 --- a/src/Microsoft.SqlTools.ResourceProvider.DefaultImpl/AzureResourceManager.cs +++ b/src/Microsoft.SqlTools.ResourceProvider.DefaultImpl/AzureResourceManager.cs @@ -68,7 +68,7 @@ namespace Microsoft.SqlTools.ResourceProvider.DefaultImpl } catch (Exception ex) { - Logger.Write(LogLevel.Error, string.Format(CultureInfo.CurrentCulture, "Failed to get databases {0}", ex)); + Logger.Write(TraceEventType.Error, string.Format(CultureInfo.CurrentCulture, "Failed to get databases {0}", ex)); throw; } } @@ -100,7 +100,7 @@ namespace Microsoft.SqlTools.ResourceProvider.DefaultImpl } catch (Exception ex) { - Logger.Write(LogLevel.Error, string.Format(CultureInfo.CurrentCulture, "Failed to get databases {0}", ex.Message)); + Logger.Write(TraceEventType.Error, string.Format(CultureInfo.CurrentCulture, "Failed to get databases {0}", ex.Message)); throw; } diff --git a/src/Microsoft.SqlTools.ResourceProvider/Program.cs b/src/Microsoft.SqlTools.ResourceProvider/Program.cs index bc0c212d..cde1d33f 100644 --- a/src/Microsoft.SqlTools.ResourceProvider/Program.cs +++ b/src/Microsoft.SqlTools.ResourceProvider/Program.cs @@ -3,6 +3,7 @@ // Licensed under the MIT license. See LICENSE file in the project root for full license information. using System; +using System.Diagnostics; using System.IO; using Microsoft.SqlTools.Hosting.Utility; using Microsoft.SqlTools.ServiceLayer.SqlContext; @@ -31,16 +32,20 @@ namespace Microsoft.SqlTools.ResourceProvider return; } - string logFilePath = "SqlToolsResourceProviderService"; + string logFilePath = commandOptions.LogFilePath; + if (string.IsNullOrWhiteSpace(logFilePath)) + { + logFilePath = "SqlToolsResourceProviderService"; + } if (!string.IsNullOrWhiteSpace(commandOptions.LoggingDirectory)) { logFilePath = Path.Combine(commandOptions.LoggingDirectory, logFilePath); } // turn on Verbose logging during early development - // we need to switch to Normal when preparing for public preview - Logger.Initialize(logFilePath: logFilePath, minimumLogLevel: LogLevel.Verbose, isEnabled: commandOptions.EnableLogging); - Logger.Write(LogLevel.Normal, "Starting SqlTools Resource Provider"); + // we need to switch to Information when preparing for public preview + Logger.Initialize(tracingLevel: commandOptions.TracingLevel, logFilePath: logFilePath, traceSource: "resourceprovider"); + Logger.Write(TraceEventType.Information, "Starting SqlTools Resource Provider"); // set up the host details and profile paths var hostDetails = new HostDetails( @@ -55,7 +60,7 @@ namespace Microsoft.SqlTools.ResourceProvider } catch (Exception e) { - Logger.Write(LogLevel.Error, string.Format("An unhandled exception occurred: {0}", e)); + Logger.WriteWithCallstack(TraceEventType.Critical, $"An unhandled exception occurred: {e}"); Environment.Exit(1); } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Admin/Database/DatabaseTaskHelper.cs b/src/Microsoft.SqlTools.ServiceLayer/Admin/Database/DatabaseTaskHelper.cs index 709249a8..6f14ec98 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Admin/Database/DatabaseTaskHelper.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Admin/Database/DatabaseTaskHelper.cs @@ -11,6 +11,7 @@ using Microsoft.SqlTools.Utility; using System; using System.Collections; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using System.Threading.Tasks; using System.Xml; @@ -221,7 +222,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Admin } catch(Exception ex) { - Logger.Write(LogLevel.Warning, $"Failed to disconnect Database task Helper connection. Error: {ex.Message}"); + Logger.Write(TraceEventType.Warning, $"Failed to disconnect Database task Helper connection. Error: {ex.Message}"); } } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/BatchParser/BatchParserWrapper.cs b/src/Microsoft.SqlTools.ServiceLayer/BatchParser/BatchParserWrapper.cs index 3564930b..48fd228d 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/BatchParser/BatchParserWrapper.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/BatchParser/BatchParserWrapper.cs @@ -9,6 +9,7 @@ using System.Collections.Generic; using System.IO; using Microsoft.SqlTools.ServiceLayer.BatchParser.ExecutionEngineCode; using System.Globalization; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.BatchParser { @@ -347,7 +348,7 @@ namespace Microsoft.SqlTools.ServiceLayer.BatchParser if (args != null) { - Logger.Write(LogLevel.Verbose, SR.BatchParserWrapperExecutionError); + Logger.Write(TraceEventType.Verbose, SR.BatchParserWrapperExecutionError); throw new Exception(string.Format(CultureInfo.CurrentCulture, SR.BatchParserWrapperExecutionEngineError, args.Message + Environment.NewLine + '\t' + args.Description)); @@ -389,7 +390,7 @@ namespace Microsoft.SqlTools.ServiceLayer.BatchParser catch (Exception e) { // adding this for debugging - Logger.Write(LogLevel.Warning, "Exception Caught in BatchParserWrapper.OnBatchParserExecutionFinished(...)" + e.ToString()); + Logger.Write(TraceEventType.Warning, "Exception Caught in BatchParserWrapper.OnBatchParserExecutionFinished(...)" + e.ToString()); throw; } } @@ -408,7 +409,7 @@ namespace Microsoft.SqlTools.ServiceLayer.BatchParser if (args != null) { - Logger.Write(LogLevel.Normal, SR.BatchParserWrapperExecutionEngineError); + Logger.Write(TraceEventType.Information, SR.BatchParserWrapperExecutionEngineError); throw new Exception(SR.BatchParserWrapperExecutionEngineError); } @@ -419,7 +420,7 @@ namespace Microsoft.SqlTools.ServiceLayer.BatchParser #if DEBUG if (args != null) { - Logger.Write(LogLevel.Normal, SR.BatchParserWrapperExecutionEngineBatchMessage); + Logger.Write(TraceEventType.Information, SR.BatchParserWrapperExecutionEngineBatchMessage); } #endif } @@ -429,7 +430,7 @@ namespace Microsoft.SqlTools.ServiceLayer.BatchParser #if DEBUG if (args != null && args.DataReader != null) { - Logger.Write(LogLevel.Normal, SR.BatchParserWrapperExecutionEngineBatchResultSetProcessing); + Logger.Write(TraceEventType.Information, SR.BatchParserWrapperExecutionEngineBatchResultSetProcessing); } #endif } @@ -437,13 +438,13 @@ namespace Microsoft.SqlTools.ServiceLayer.BatchParser public void OnBatchResultSetFinished(object sender, EventArgs args) { #if DEBUG - Logger.Write(LogLevel.Normal, SR.BatchParserWrapperExecutionEngineBatchResultSetFinished); + Logger.Write(TraceEventType.Information, SR.BatchParserWrapperExecutionEngineBatchResultSetFinished); #endif } public void OnBatchCancelling(object sender, EventArgs args) { - Logger.Write(LogLevel.Normal, SR.BatchParserWrapperExecutionEngineBatchCancelling); + Logger.Write(TraceEventType.Information, SR.BatchParserWrapperExecutionEngineBatchCancelling); } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/BatchParser/ExecutionEngineCode/Batch.cs b/src/Microsoft.SqlTools.ServiceLayer/BatchParser/ExecutionEngineCode/Batch.cs index 87eda717..9e4e5532 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/BatchParser/ExecutionEngineCode/Batch.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/BatchParser/ExecutionEngineCode/Batch.cs @@ -723,7 +723,7 @@ namespace Microsoft.SqlTools.ServiceLayer.BatchParser.ExecutionEngineCode if (messageHandler == null) { - Logger.Write(LogLevel.Error, "Expected handler to be declared"); + Logger.Write(TraceEventType.Error, "Expected handler to be declared"); } if (null != connectionWrapper) @@ -736,7 +736,7 @@ namespace Microsoft.SqlTools.ServiceLayer.BatchParser.ExecutionEngineCode if (statementCompletedHandler == null) { - Logger.Write(LogLevel.Error, "Expect handler to be declared if we have a command wrapper"); + Logger.Write(TraceEventType.Error, "Expect handler to be declared if we have a command wrapper"); } commandWrapper.StatementCompleted -= statementCompletedHandler; } diff --git a/src/Microsoft.SqlTools.ServiceLayer/BatchParser/ExecutionEngineCode/ExecutionEngine.cs b/src/Microsoft.SqlTools.ServiceLayer/BatchParser/ExecutionEngineCode/ExecutionEngine.cs index 933a23a2..8aaefdfb 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/BatchParser/ExecutionEngineCode/ExecutionEngine.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/BatchParser/ExecutionEngineCode/ExecutionEngine.cs @@ -132,7 +132,7 @@ namespace Microsoft.SqlTools.ServiceLayer.BatchParser.ExecutionEngineCode catch (Exception ex) { // if anything goes wrong it will shutdown VS - Logger.Write(LogLevel.Error, "Exception Caught in ExecutionEngine.DoBatchExecution(Batch) :" + ex.ToString()); + Logger.Write(TraceEventType.Error, "Exception Caught in ExecutionEngine.DoBatchExecution(Batch) :" + ex.ToString()); result = ScriptExecutionResult.Failure; } } @@ -494,7 +494,7 @@ namespace Microsoft.SqlTools.ServiceLayer.BatchParser.ExecutionEngineCode } catch (Exception ex) { - Logger.Write(LogLevel.Warning, "Exception Caught in ExecutionEngine.DoScriptExecution(bool): " + ex.ToString()); + Logger.Write(TraceEventType.Warning, "Exception Caught in ExecutionEngine.DoScriptExecution(bool): " + ex.ToString()); throw; } } @@ -924,7 +924,7 @@ namespace Microsoft.SqlTools.ServiceLayer.BatchParser.ExecutionEngineCode } catch (SqlException ex) { - Logger.Write(LogLevel.Warning, "Exception Caught in ExecutionEngine.ConnectSqlCmdInternal(SqlConnectionStringBuilder): " + ex.ToString()); + Logger.Write(TraceEventType.Warning, "Exception Caught in ExecutionEngine.ConnectSqlCmdInternal(SqlConnectionStringBuilder): " + ex.ToString()); throw; } @@ -960,7 +960,7 @@ namespace Microsoft.SqlTools.ServiceLayer.BatchParser.ExecutionEngineCode } catch (SqlException ex) { - Logger.Write(LogLevel.Warning, "Exception Caught in ExecutionEngine.CloseConnection(SqlConnection): " + ex.ToString()); + Logger.Write(TraceEventType.Warning, "Exception Caught in ExecutionEngine.CloseConnection(SqlConnection): " + ex.ToString()); } } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Connection/ConnectionService.cs b/src/Microsoft.SqlTools.ServiceLayer/Connection/ConnectionService.cs index 735eed29..215b83b4 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Connection/ConnectionService.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Connection/ConnectionService.cs @@ -21,6 +21,7 @@ using Microsoft.SqlTools.ServiceLayer.LanguageServices; using Microsoft.SqlTools.ServiceLayer.LanguageServices.Contracts; using Microsoft.SqlTools.ServiceLayer.Utility; using Microsoft.SqlTools.Utility; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.Connection { @@ -333,7 +334,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection } catch (Exception ex) { - Logger.Write(LogLevel.Normal, "Failed to close temporary connections. error: " + ex.Message); + Logger.Write(TraceEventType.Information, "Failed to close temporary connections. error: " + ex.Message); } } @@ -982,7 +983,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection ConnectParams connectParams, RequestContext requestContext) { - Logger.Write(LogLevel.Verbose, "HandleConnectRequest"); + Logger.Write(TraceEventType.Verbose, "HandleConnectRequest"); try { @@ -1032,7 +1033,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection CancelConnectParams cancelParams, RequestContext requestContext) { - Logger.Write(LogLevel.Verbose, "HandleCancelConnectRequest"); + Logger.Write(TraceEventType.Verbose, "HandleCancelConnectRequest"); try { @@ -1052,7 +1053,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection DisconnectParams disconnectParams, RequestContext requestContext) { - Logger.Write(LogLevel.Verbose, "HandleDisconnectRequest"); + Logger.Write(TraceEventType.Verbose, "HandleDisconnectRequest"); try { @@ -1073,7 +1074,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection ListDatabasesParams listDatabasesParams, RequestContext requestContext) { - Logger.Write(LogLevel.Verbose, "ListDatabasesRequest"); + Logger.Write(TraceEventType.Verbose, "ListDatabasesRequest"); try { @@ -1409,7 +1410,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection catch (Exception e) { Logger.Write( - LogLevel.Error, + TraceEventType.Error, string.Format( "Exception caught while trying to change database context to [{0}] for OwnerUri [{1}]. Exception:{2}", newDatabaseName, @@ -1477,7 +1478,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection } catch (Exception ex) { - Logger.Write(LogLevel.Verbose, "Could not send Connection telemetry event " + ex.ToString()); + Logger.Write(TraceEventType.Verbose, "Could not send Connection telemetry event " + ex.ToString()); } } } @@ -1522,7 +1523,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection string error = string.Format(CultureInfo.InvariantCulture, "Failed opening a SqlConnection: error:{0} inner:{1} stacktrace:{2}", ex.Message, ex.InnerException != null ? ex.InnerException.Message : string.Empty, ex.StackTrace); - Logger.Write(LogLevel.Error, error); + Logger.Write(TraceEventType.Error, error); } return null; diff --git a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/AmbientSettings.cs b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/AmbientSettings.cs index 3de3b634..46f621c2 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/AmbientSettings.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/AmbientSettings.cs @@ -5,6 +5,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Reflection; using Microsoft.SqlTools.Utility; @@ -350,13 +351,13 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection public void TraceSettings() { // NOTE: logging as warning so we can get this data in the IEService DacFx logs - Logger.Write(LogLevel.Warning, Resources.LoggingAmbientSettings); + Logger.Write(TraceEventType.Warning, Resources.LoggingAmbientSettings); foreach (KeyValuePair setting in _configuration) { // Log Ambient Settings Logger.Write( - LogLevel.Warning, + TraceEventType.Warning, string.Format( Resources.AmbientSettingFormat, setting.Key, @@ -406,7 +407,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection } else { - Logger.Write(LogLevel.Error, string.Format(Resources.UnableToAssignValue, value.GetType().FullName, _type.FullName)); + Logger.Write(TraceEventType.Error, string.Format(Resources.UnableToAssignValue, value.GetType().FullName, _type.FullName)); } } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/CachedServerInfo.cs b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/CachedServerInfo.cs index 7ab2bd2b..a1548b6a 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/CachedServerInfo.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/CachedServerInfo.cs @@ -7,6 +7,7 @@ using System; using System.Collections.Concurrent; using System.Data; using System.Data.SqlClient; +using System.Diagnostics; using System.Linq; using Microsoft.SqlTools.Utility; @@ -270,7 +271,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection } catch { - Logger.Write(LogLevel.Error, String.Format(Resources.FailedToParseConnectionString, connection.ConnectionString)); + Logger.Write(TraceEventType.Error, String.Format(Resources.FailedToParseConnectionString, connection.ConnectionString)); return null; } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/ReliableConnectionHelper.cs b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/ReliableConnectionHelper.cs index b7d4620d..297cf28c 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/ReliableConnectionHelper.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/ReliableConnectionHelper.cs @@ -429,7 +429,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection Validate.IsNotNull(nameof(connection), connection); if (!(connection.State == ConnectionState.Open)) { - Logger.Write(LogLevel.Warning, Resources.ConnectionPassedToIsCloudShouldBeOpen); + Logger.Write(TraceEventType.Warning, Resources.ConnectionPassedToIsCloudShouldBeOpen); } Func executeCommand = commandText => @@ -540,7 +540,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection return true; } - Logger.Write(LogLevel.Error, ex.ToString()); + Logger.Write(TraceEventType.Error, ex.ToString()); return false; } @@ -612,14 +612,13 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection if (!string.IsNullOrWhiteSpace(filePath)) { // Remove filename from the filePath - Uri pathUri; if (!Uri.IsWellFormedUriString(filePath, UriKind.Absolute)) { // In linux "file://" is required otehrwise the Uri cannot parse the path //this should be fixed in dotenet core 2.0 filePath = $"file://{filePath}"; } - if (!Uri.TryCreate(filePath, UriKind.Absolute, out pathUri)) + if (!Uri.TryCreate(filePath, UriKind.Absolute, out Uri pathUri)) { // Invalid Uri return null; @@ -668,7 +667,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection }, (ex) => { - Logger.Write(LogLevel.Error, ex.ToString()); + Logger.Write(TraceEventType.Error, ex.ToString()); return StandardExceptionHandler(ex); // handled }, useRetry: true); @@ -701,8 +700,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection public static bool TryGetServerVersion(string connectionString, out ServerInfo serverInfo) { serverInfo = null; - SqlConnectionStringBuilder builder; - if (!TryGetConnectionStringBuilder(connectionString, out builder)) + if (!TryGetConnectionStringBuilder(connectionString, out SqlConnectionStringBuilder builder)) { return false; } @@ -739,7 +737,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection Validate.IsNotNull(nameof(connection), connection); if (!(connection.State == ConnectionState.Open)) { - Logger.Write(LogLevel.Error, "connection passed to GetServerVersion should be open."); + Logger.Write(TraceEventType.Error, "connection passed to GetServerVersion should be open."); } Func getServerInfo = commandText => @@ -788,8 +786,8 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection { //we don't want to fail the normal flow if any unexpected thing happens //during caching although it's unlikely. So we just log the exception and ignore it - Logger.Write(LogLevel.Error, Resources.FailedToCacheIsCloud); - Logger.Write(LogLevel.Error, ex.ToString()); + Logger.Write(TraceEventType.Error, Resources.FailedToCacheIsCloud); + Logger.Write(TraceEventType.Error, ex.ToString()); } }); @@ -892,7 +890,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection if (handledEx != null) { - Logger.Write(LogLevel.Error, String.Format(Resources.ErrorParsingConnectionString, handledEx)); + Logger.Write(TraceEventType.Error, String.Format(Resources.ErrorParsingConnectionString, handledEx)); return false; } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/ReliableSqlConnection.cs b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/ReliableSqlConnection.cs index 058c0c92..f498338e 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/ReliableSqlConnection.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/ReliableSqlConnection.cs @@ -360,18 +360,18 @@ SET NUMERIC_ROUNDABORT OFF;"; } /// - /// Adds an info message event listener. + /// Adds an info message event Listener. /// - /// An info message event listener. + /// An info message event Listener. public void AddInfoMessageHandler(SqlInfoMessageEventHandler handler) { _underlyingConnection.InfoMessage += handler; } /// - /// Removes an info message event listener. + /// Removes an info message event Listener. /// - /// An info message event listener. + /// An info message event Listener. public void RemoveInfoMessageHandler(SqlInfoMessageEventHandler handler) { _underlyingConnection.InfoMessage -= handler; @@ -436,7 +436,7 @@ SET NUMERIC_ROUNDABORT OFF;"; string sessionId = (string)command.ExecuteScalar(); if (!Guid.TryParse(sessionId, out _azureSessionId)) { - Logger.Write(LogLevel.Error, Resources.UnableToRetrieveAzureSessionId); + Logger.Write(TraceEventType.Error, Resources.UnableToRetrieveAzureSessionId); } } } @@ -444,7 +444,7 @@ SET NUMERIC_ROUNDABORT OFF;"; } catch (Exception exception) { - Logger.Write(LogLevel.Error, Resources.UnableToRetrieveAzureSessionId + exception.ToString()); + Logger.Write(TraceEventType.Error, Resources.UnableToRetrieveAzureSessionId + exception.ToString()); } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicy.DataTransferDetectionErrorStrategy.cs b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicy.DataTransferDetectionErrorStrategy.cs index 0efd9a04..b271ab9b 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicy.DataTransferDetectionErrorStrategy.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicy.DataTransferDetectionErrorStrategy.cs @@ -4,6 +4,7 @@ // using System.Data.SqlClient; +using System.Diagnostics; using Microsoft.SqlTools.Utility; namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection @@ -30,7 +31,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection RetryPolicyUtils.AppendThrottlingDataIfIsThrottlingError(sqlException, err); if (RetryPolicyUtils.IsNonRetryableDataTransferError(err.Number)) { - Logger.Write(LogLevel.Error, string.Format(Resources.ExceptionCannotBeRetried, err.Number, err.Message)); + Logger.Write(TraceEventType.Error, string.Format(Resources.ExceptionCannotBeRetried, err.Number, err.Message)); return false; } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicy.cs b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicy.cs index f8f4ed44..3f158602 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicy.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicy.cs @@ -244,7 +244,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection bool shouldRetry = canRetry && ShouldRetryImpl(retryState); - Logger.Write(LogLevel.Error, + Logger.Write(TraceEventType.Error, string.Format( CultureInfo.InvariantCulture, "Retry requested: Retry count = {0}. Delay = {1}, SQL Error Number = {2}, Can retry error = {3}, Will retry = {4}", @@ -267,7 +267,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection { bool shouldIgnoreError = ErrorDetectionStrategy.ShouldIgnoreError(retryState.LastError); - Logger.Write(LogLevel.Error, + Logger.Write(TraceEventType.Error, string.Format( CultureInfo.InvariantCulture, "Ignore Error requested: Retry count = {0}. Delay = {1}, SQL Error Number = {2}, Should Ignore Error = {3}", diff --git a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicyFactory.cs b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicyFactory.cs index bb75fbf5..99f505a9 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicyFactory.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicyFactory.cs @@ -392,7 +392,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection internal static void DataConnectionFailureRetry(RetryState retryState) { - Logger.Write(LogLevel.Normal, string.Format(CultureInfo.InvariantCulture, + Logger.Write(TraceEventType.Information, string.Format(CultureInfo.InvariantCulture, "Connection retry number {0}. Delaying {1} ms before retry. Exception: {2}", retryState.RetryCount, retryState.Delay.TotalMilliseconds.ToString(CultureInfo.InvariantCulture), @@ -403,7 +403,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection internal static void CommandFailureRetry(RetryState retryState, string commandKeyword) { - Logger.Write(LogLevel.Normal, string.Format( + Logger.Write(TraceEventType.Information, string.Format( CultureInfo.InvariantCulture, "{0} retry number {1}. Delaying {2} ms before retry. Exception: {3}", commandKeyword, @@ -416,7 +416,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection internal static void CommandFailureIgnore(RetryState retryState, string commandKeyword) { - Logger.Write(LogLevel.Normal, string.Format( + Logger.Write(TraceEventType.Information, string.Format( CultureInfo.InvariantCulture, "{0} retry number {1}. Ignoring failure. Exception: {2}", commandKeyword, diff --git a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicyUtils.cs b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicyUtils.cs index a22549a7..c522a706 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicyUtils.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Connection/ReliableConnection/RetryPolicyUtils.cs @@ -6,6 +6,7 @@ using System; using System.Collections.Generic; using System.Data.SqlClient; +using System.Diagnostics; using System.Runtime.InteropServices; using Microsoft.SqlTools.Utility; @@ -344,7 +345,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Connection.ReliableConnection { if (azureSessionId != Guid.Empty) { - Logger.Write(LogLevel.Warning, string.Format( + Logger.Write(TraceEventType.Warning, string.Format( "Retry occurred: session: {0}; attempt - {1}; delay - {2}; exception - \"{3}\"", azureSessionId, retryState.RetryCount, diff --git a/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/DisasterRecoveryService.cs b/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/DisasterRecoveryService.cs index 792b53df..6d01e4be 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/DisasterRecoveryService.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/DisasterRecoveryService.cs @@ -4,6 +4,7 @@ // using System; using System.Data.SqlClient; +using System.Diagnostics; using System.Threading.Tasks; using Microsoft.SqlTools.Hosting.Protocol; using Microsoft.SqlTools.ServiceLayer.Admin; @@ -183,7 +184,7 @@ namespace Microsoft.SqlTools.ServiceLayer.DisasterRecovery } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Failed to cancel restore session. error: " + ex.Message); + Logger.Write(TraceEventType.Error, "Failed to cancel restore session. error: " + ex.Message); await requestContext.SendResult(result); } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/RestoreOperation/RestoreDatabaseHelper.cs b/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/RestoreOperation/RestoreDatabaseHelper.cs index d2f2d0d7..c99ac928 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/RestoreOperation/RestoreDatabaseHelper.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/RestoreOperation/RestoreDatabaseHelper.cs @@ -15,6 +15,7 @@ using Microsoft.SqlTools.ServiceLayer.DisasterRecovery.Contracts; using Microsoft.SqlTools.Utility; using System.Collections.Concurrent; using Microsoft.SqlTools.ServiceLayer.Utility; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.DisasterRecovery.RestoreOperation { @@ -51,7 +52,7 @@ namespace Microsoft.SqlTools.ServiceLayer.DisasterRecovery.RestoreOperation } catch(Exception ex) { - Logger.Write(LogLevel.Warning, $"Failed to create restore config info. error: { ex.Message}"); + Logger.Write(TraceEventType.Warning, $"Failed to create restore config info. error: { ex.Message}"); response.ErrorMessage = ex.Message; } finally @@ -164,7 +165,7 @@ namespace Microsoft.SqlTools.ServiceLayer.DisasterRecovery.RestoreOperation response.ErrorMessage += Environment.NewLine; response.ErrorMessage += ex.InnerException.Message; } - Logger.Write(LogLevel.Normal, $"Failed to create restore plan. error: { response.ErrorMessage}"); + Logger.Write(TraceEventType.Information, $"Failed to create restore plan. error: { response.ErrorMessage}"); } return response; diff --git a/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/RestoreOperation/RestoreDatabaseTaskDataObject.cs b/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/RestoreOperation/RestoreDatabaseTaskDataObject.cs index fea485b7..0816e05e 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/RestoreOperation/RestoreDatabaseTaskDataObject.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/RestoreOperation/RestoreDatabaseTaskDataObject.cs @@ -15,6 +15,7 @@ using Microsoft.SqlTools.ServiceLayer.TaskServices; using Microsoft.SqlTools.ServiceLayer.Utility; using Microsoft.SqlTools.Utility; using Microsoft.SqlTools.ServiceLayer.Connection; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.DisasterRecovery.RestoreOperation { @@ -316,7 +317,7 @@ namespace Microsoft.SqlTools.ServiceLayer.DisasterRecovery.RestoreOperation } catch(Exception ex) { - Logger.Write(LogLevel.Normal, $"Failed to execute restore task. error: {ex.Message}"); + Logger.Write(TraceEventType.Information, $"Failed to execute restore task. error: {ex.Message}"); throw ex; } finally @@ -903,7 +904,7 @@ namespace Microsoft.SqlTools.ServiceLayer.DisasterRecovery.RestoreOperation } catch(Exception ex ) { - Logger.Write(LogLevel.Normal, $"Failed to get restore db files. error: {ex.Message}"); + Logger.Write(TraceEventType.Information, $"Failed to get restore db files. error: {ex.Message}"); } return ret; } diff --git a/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/RestoreOperation/RestoreOptionFactory.cs b/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/RestoreOperation/RestoreOptionFactory.cs index 76c5ae61..508af7c3 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/RestoreOperation/RestoreOptionFactory.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/DisasterRecovery/RestoreOperation/RestoreOptionFactory.cs @@ -5,6 +5,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using Microsoft.SqlServer.Management.Smo; using Microsoft.SqlTools.ServiceLayer.DisasterRecovery.Contracts; @@ -54,7 +55,7 @@ namespace Microsoft.SqlTools.ServiceLayer.DisasterRecovery.RestoreOperation } else { - Logger.Write(LogLevel.Warning, $"cannot find restore option builder for {optionKey}"); + Logger.Write(TraceEventType.Warning, $"cannot find restore option builder for {optionKey}"); return null; } } @@ -77,7 +78,7 @@ namespace Microsoft.SqlTools.ServiceLayer.DisasterRecovery.RestoreOperation } else { - Logger.Write(LogLevel.Warning, $"cannot find restore option builder for {optionKey}"); + Logger.Write(TraceEventType.Warning, $"cannot find restore option builder for {optionKey}"); } } @@ -115,7 +116,7 @@ namespace Microsoft.SqlTools.ServiceLayer.DisasterRecovery.RestoreOperation { var defaultValue = builder.DefaultValueFunction(restoreDataObject); builder.SetValueFunction(restoreDataObject, defaultValue); - Logger.Write(LogLevel.Warning, $"Failed tp set restore option {optionKey} error:{ex.Message}"); + Logger.Write(TraceEventType.Warning, $"Failed tp set restore option {optionKey} error:{ex.Message}"); } } @@ -128,13 +129,13 @@ namespace Microsoft.SqlTools.ServiceLayer.DisasterRecovery.RestoreOperation } catch (Exception) { - Logger.Write(LogLevel.Warning, $"Failed to set restore option {optionKey} to default value"); + Logger.Write(TraceEventType.Warning, $"Failed to set restore option {optionKey} to default value"); } } } else { - Logger.Write(LogLevel.Warning, $"cannot find restore option builder for {optionKey}"); + Logger.Write(TraceEventType.Warning, $"cannot find restore option builder for {optionKey}"); } } } @@ -171,7 +172,7 @@ namespace Microsoft.SqlTools.ServiceLayer.DisasterRecovery.RestoreOperation else { errorMessage = $"cannot find restore option builder for {optionKey}"; - Logger.Write(LogLevel.Warning, errorMessage); + Logger.Write(TraceEventType.Warning, errorMessage); } return errorMessage; diff --git a/src/Microsoft.SqlTools.ServiceLayer/FileBrowser/FileBrowserService.cs b/src/Microsoft.SqlTools.ServiceLayer/FileBrowser/FileBrowserService.cs index 34f06d46..ceea6709 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/FileBrowser/FileBrowserService.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/FileBrowser/FileBrowserService.cs @@ -6,6 +6,7 @@ using System; using System.Collections.Concurrent; using System.Data.SqlClient; +using System.Diagnostics; using System.Threading.Tasks; using Microsoft.SqlTools.Hosting.Protocol; using Microsoft.SqlTools.ServiceLayer.Connection; @@ -97,7 +98,7 @@ namespace Microsoft.SqlTools.ServiceLayer.FileBrowser } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unexpected exception while handling file browser open request: " + ex.Message); + Logger.Write(TraceEventType.Error, "Unexpected exception while handling file browser open request: " + ex.Message); await requestContext.SendResult(false); } } @@ -112,7 +113,7 @@ namespace Microsoft.SqlTools.ServiceLayer.FileBrowser } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unexpected exception while handling file browser expand request: " + ex.Message); + Logger.Write(TraceEventType.Error, "Unexpected exception while handling file browser expand request: " + ex.Message); await requestContext.SendResult(false); } } @@ -127,7 +128,7 @@ namespace Microsoft.SqlTools.ServiceLayer.FileBrowser } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unexpected exception while handling file browser validate request: " + ex.Message); + Logger.Write(TraceEventType.Error, "Unexpected exception while handling file browser validate request: " + ex.Message); await requestContext.SendResult(false); } } @@ -144,7 +145,7 @@ namespace Microsoft.SqlTools.ServiceLayer.FileBrowser } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unexpected exception while handling file browser close request: " + ex.Message); + Logger.Write(TraceEventType.Error, "Unexpected exception while handling file browser close request: " + ex.Message); await requestContext.SendResult(new FileBrowserCloseResponse() { Message = ex.Message }); } } @@ -204,7 +205,7 @@ namespace Microsoft.SqlTools.ServiceLayer.FileBrowser } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unexpected exception while closing file browser: " + ex.Message); + Logger.Write(TraceEventType.Error, "Unexpected exception while closing file browser: " + ex.Message); result.Message = ex.Message; } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Formatter/TSqlFormatterService.cs b/src/Microsoft.SqlTools.ServiceLayer/Formatter/TSqlFormatterService.cs index 61bea2dd..7f781aed 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Formatter/TSqlFormatterService.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Formatter/TSqlFormatterService.cs @@ -6,6 +6,7 @@ using System; using System.Collections.Generic; using System.Composition; +using System.Diagnostics; using System.IO; using System.Threading.Tasks; using Microsoft.SqlServer.Management.SqlParser.Parser; @@ -39,7 +40,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Formatter public override void InitializeService(IProtocolEndpoint serviceHost) { - Logger.Write(LogLevel.Verbose, "TSqlFormatter initialized"); + Logger.Write(TraceEventType.Verbose, "TSqlFormatter initialized"); serviceHost.SetRequestHandler(DocumentFormattingRequest.Type, HandleDocFormatRequest); serviceHost.SetRequestHandler(DocumentRangeFormattingRequest.Type, HandleDocRangeFormatRequest); WorkspaceService?.RegisterConfigChangeCallback(HandleDidChangeConfigurationNotification); @@ -230,7 +231,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Formatter private async Task HandleRequest(Func> handler, RequestContext requestContext, string requestType) { - Logger.Write(LogLevel.Verbose, requestType); + Logger.Write(TraceEventType.Verbose, requestType); try { diff --git a/src/Microsoft.SqlTools.ServiceLayer/LanguageServices/BindingQueue.cs b/src/Microsoft.SqlTools.ServiceLayer/LanguageServices/BindingQueue.cs index 71dfa99a..93b1a9f6 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/LanguageServices/BindingQueue.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/LanguageServices/BindingQueue.cs @@ -10,6 +10,7 @@ using System.Threading.Tasks; using Microsoft.SqlTools.Utility; using System.Linq; using Microsoft.SqlTools.ServiceLayer.Utility; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.LanguageServices { @@ -320,7 +321,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unexpected exception on the binding queue: " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unexpected exception on the binding queue: " + ex.ToString()); if (queueItem.ErrorHandler != null) { result = queueItem.ErrorHandler(ex); @@ -347,14 +348,14 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices bindTask .ContinueWith((a) => bindingContext.BindingLock.Set()) - .ContinueWithOnFaulted(t => Logger.Write(LogLevel.Error, "Binding queue threw exception " + t.Exception.ToString())); + .ContinueWithOnFaulted(t => Logger.Write(TraceEventType.Error, "Binding queue threw exception " + t.Exception.ToString())); } } catch (Exception ex) { // catch and log any exceptions raised in the binding calls // set item processed to avoid deadlocks - Logger.Write(LogLevel.Error, "Binding queue threw exception " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Binding queue threw exception " + ex.ToString()); } finally { diff --git a/src/Microsoft.SqlTools.ServiceLayer/LanguageServices/LanguageService.cs b/src/Microsoft.SqlTools.ServiceLayer/LanguageServices/LanguageService.cs index 23b547e9..78cc0311 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/LanguageServices/LanguageService.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/LanguageServices/LanguageService.cs @@ -6,6 +6,7 @@ using System; using System.Collections.Concurrent; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using System.Threading; using System.Threading.Tasks; @@ -250,7 +251,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices // Register a no-op shutdown task for validation of the shutdown logic serviceHost.RegisterShutdownTask(async (shutdownParams, shutdownRequestContext) => { - Logger.Write(LogLevel.Verbose, "Shutting down language service"); + Logger.Write(TraceEventType.Verbose, "Shutting down language service"); DeletePeekDefinitionScripts(); this.Dispose(); await Task.FromResult(0); @@ -573,7 +574,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unknown error " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown error " + ex.ToString()); // TODO: need mechanism return errors from event handlers } } @@ -599,7 +600,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unknown error " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown error " + ex.ToString()); // TODO: need mechanism return errors from event handlers } } @@ -613,7 +614,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices { try { - Logger.Write(LogLevel.Verbose, "HandleRebuildIntelliSenseNotification"); + Logger.Write(TraceEventType.Verbose, "HandleRebuildIntelliSenseNotification"); // Skip closing this file if the file doesn't exist var scriptFile = this.CurrentWorkspace.GetFile(rebuildParams.OwnerUri); @@ -642,7 +643,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unknown error " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown error " + ex.ToString()); } finally { @@ -672,7 +673,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unknown error " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown error " + ex.ToString()); await ServiceHostInstance.SendEvent(IntelliSenseReadyNotification.Type, new IntelliSenseReadyParams() {OwnerUri = rebuildParams.OwnerUri}); } } @@ -719,7 +720,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unknown error " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown error " + ex.ToString()); // TODO: need mechanism return errors from event handlers } } @@ -757,7 +758,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unknown error " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown error " + ex.ToString()); // TODO: need mechanism return errors from event handlers } } @@ -814,7 +815,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices catch (Exception e) { // Log the exception but don't rethrow it to prevent parsing errors from crashing SQL Tools Service - Logger.Write(LogLevel.Error, string.Format("An unexpected error occured while parsing: {0}", e.ToString())); + Logger.Write(TraceEventType.Error, string.Format("An unexpected error occured while parsing: {0}", e.ToString())); } }, ConnectedBindingQueue.QueueThreadStackSize); parseThread.Start(); @@ -848,15 +849,15 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices } catch (ConnectionException) { - Logger.Write(LogLevel.Error, "Hit connection exception while binding - disposing binder object..."); + Logger.Write(TraceEventType.Error, "Hit connection exception while binding - disposing binder object..."); } catch (SqlParserInternalBinderError) { - Logger.Write(LogLevel.Error, "Hit connection exception while binding - disposing binder object..."); + Logger.Write(TraceEventType.Error, "Hit connection exception while binding - disposing binder object..."); } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unknown exception during parsing " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown exception during parsing " + ex.ToString()); } return null; @@ -869,7 +870,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices { // reset the parse result to do a full parse next time parseInfo.ParseResult = null; - Logger.Write(LogLevel.Error, "Unknown exception during parsing " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown exception during parsing " + ex.ToString()); } finally { @@ -878,7 +879,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices } else { - Logger.Write(LogLevel.Warning, "Binding metadata lock timeout in ParseAndBind"); + Logger.Write(TraceEventType.Warning, "Binding metadata lock timeout in ParseAndBind"); } return parseInfo.ParseResult; @@ -907,7 +908,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unknown error in OnConnection " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown error in OnConnection " + ex.ToString()); scriptInfo.IsConnected = false; } finally @@ -1100,7 +1101,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices { // if any exceptions are raised looking up extended completion metadata // then just return the original completion item - Logger.Write(LogLevel.Error, "Exception in ResolveCompletionItem " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Exception in ResolveCompletionItem " + ex.ToString()); } finally { @@ -1196,7 +1197,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices catch (Exception ex) { // if any exceptions are raised return error result with message - Logger.Write(LogLevel.Error, "Exception in GetDefinition " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Exception in GetDefinition " + ex.ToString()); return new DefinitionResult { IsErrorResult = true, @@ -1211,7 +1212,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices } else { - Logger.Write(LogLevel.Error, "Timeout waiting to query metadata from server"); + Logger.Write(TraceEventType.Error, "Timeout waiting to query metadata from server"); } } return (lastResult != null) ? lastResult : null; @@ -1586,7 +1587,7 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices } catch (Exception e) { - Logger.Write(LogLevel.Error, string.Format("Exception while cancelling analysis task:\n\n{0}", e.ToString())); + Logger.Write(TraceEventType.Error, string.Format("Exception while cancelling analysis task:\n\n{0}", e.ToString())); TaskCompletionSource cancelTask = new TaskCompletionSource(); cancelTask.SetCanceled(); @@ -1657,9 +1658,9 @@ namespace Microsoft.SqlTools.ServiceLayer.LanguageServices continue; } - Logger.Write(LogLevel.Verbose, "Analyzing script file: " + scriptFile.FilePath); + Logger.Write(TraceEventType.Verbose, "Analyzing script file: " + scriptFile.FilePath); ScriptFileMarker[] semanticMarkers = GetSemanticMarkers(scriptFile); - Logger.Write(LogLevel.Verbose, "Analysis complete."); + Logger.Write(TraceEventType.Verbose, "Analysis complete."); await DiagnosticsHelper.PublishScriptDiagnostics(scriptFile, semanticMarkers, eventContext); } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Microsoft.SqlTools.ServiceLayer.csproj b/src/Microsoft.SqlTools.ServiceLayer/Microsoft.SqlTools.ServiceLayer.csproj index af1f16f1..66dcaf76 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Microsoft.SqlTools.ServiceLayer.csproj +++ b/src/Microsoft.SqlTools.ServiceLayer/Microsoft.SqlTools.ServiceLayer.csproj @@ -1,4 +1,4 @@ - + netcoreapp2.1 @@ -9,7 +9,7 @@ false false false - $(DefineConstants);NETCOREAPP1_0 + $(DefineConstants);NETCOREAPP1_0;TRACE true true portable diff --git a/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/Nodes/TreeNode.cs b/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/Nodes/TreeNode.cs index 9a6bb58c..823791f4 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/Nodes/TreeNode.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/Nodes/TreeNode.cs @@ -317,7 +317,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer.Nodes protected virtual void PopulateChildren(bool refresh, string name = null) { - Logger.Write(LogLevel.Verbose, string.Format(CultureInfo.InvariantCulture, "Populating oe node :{0}", this.GetNodePath())); + Logger.Write(TraceEventType.Verbose, string.Format(CultureInfo.InvariantCulture, "Populating oe node :{0}", this.GetNodePath())); Debug.Assert(IsAlwaysLeaf == false); SmoQueryContext context = this.GetContextAs(); @@ -353,7 +353,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer.Nodes { string error = string.Format(CultureInfo.InvariantCulture, "Failed populating oe children. error:{0} inner:{1} stacktrace:{2}", ex.Message, ex.InnerException != null ? ex.InnerException.Message : "", ex.StackTrace); - Logger.Write(LogLevel.Error, error); + Logger.Write(TraceEventType.Error, error); ErrorMessage = ex.Message; } } @@ -363,7 +363,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer.Nodes { string error = string.Format(CultureInfo.InvariantCulture, "Failed populating oe children. error:{0} inner:{1} stacktrace:{2}", ex.Message, ex.InnerException != null ? ex.InnerException.Message : "", ex.StackTrace); - Logger.Write(LogLevel.Error, error); + Logger.Write(TraceEventType.Error, error); ErrorMessage = ex.Message; } finally diff --git a/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/ObjectExplorerService.cs b/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/ObjectExplorerService.cs index 7bd85898..4f59976b 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/ObjectExplorerService.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/ObjectExplorerService.cs @@ -26,6 +26,7 @@ using Microsoft.SqlTools.ServiceLayer.Utility; using Microsoft.SqlTools.ServiceLayer.Workspace; using Microsoft.SqlTools.Utility; using Microsoft.SqlServer.Management.Common; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer { @@ -119,7 +120,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer } catch(Exception ex) { - Logger.Write(LogLevel.Error, ex.Message); + Logger.Write(TraceEventType.Error, ex.Message); } } @@ -129,7 +130,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer /// The service host instance to register with public override void InitializeService(IProtocolEndpoint serviceHost) { - Logger.Write(LogLevel.Verbose, "ObjectExplorer service initialized"); + Logger.Write(TraceEventType.Verbose, "ObjectExplorer service initialized"); this.serviceHost = serviceHost; // Register handlers for requests serviceHost.SetRequestHandler(CreateSessionRequest.Type, HandleCreateSessionRequest); @@ -172,7 +173,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer { try { - Logger.Write(LogLevel.Verbose, "HandleCreateSessionRequest"); + Logger.Write(TraceEventType.Verbose, "HandleCreateSessionRequest"); Func> doCreateSession = async () => { Validate.IsNotNull(nameof(connectionDetails), connectionDetails); @@ -200,7 +201,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer internal async Task HandleExpandRequest(ExpandParams expandParams, RequestContext context) { - Logger.Write(LogLevel.Verbose, "HandleExpandRequest"); + Logger.Write(TraceEventType.Verbose, "HandleExpandRequest"); Func> expandNode = async () => { @@ -211,7 +212,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer ObjectExplorerSession session = null; if (!sessionMap.TryGetValue(uri, out session)) { - Logger.Write(LogLevel.Verbose, $"Cannot expand object explorer node. Couldn't find session for uri. {uri} "); + Logger.Write(TraceEventType.Verbose, $"Cannot expand object explorer node. Couldn't find session for uri. {uri} "); await serviceHost.SendEvent(ExpandCompleteNotification.Type, new ExpandResponse { SessionId = expandParams.SessionId, @@ -233,7 +234,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer { try { - Logger.Write(LogLevel.Verbose, "HandleRefreshRequest"); + Logger.Write(TraceEventType.Verbose, "HandleRefreshRequest"); Validate.IsNotNull(nameof(refreshParams), refreshParams); Validate.IsNotNull(nameof(context), context); @@ -241,7 +242,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer ObjectExplorerSession session = null; if (!sessionMap.TryGetValue(uri, out session)) { - Logger.Write(LogLevel.Verbose, $"Cannot expand object explorer node. Couldn't find session for uri. {uri} "); + Logger.Write(TraceEventType.Verbose, $"Cannot expand object explorer node. Couldn't find session for uri. {uri} "); await serviceHost.SendEvent(ExpandCompleteNotification.Type, new ExpandResponse { SessionId = refreshParams.SessionId, @@ -264,7 +265,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer internal async Task HandleCloseSessionRequest(CloseSessionParams closeSessionParams, RequestContext context) { - Logger.Write(LogLevel.Verbose, "HandleCloseSessionRequest"); + Logger.Write(TraceEventType.Verbose, "HandleCloseSessionRequest"); Func> closeSession = () => { Validate.IsNotNull(nameof(closeSessionParams), closeSessionParams); @@ -276,7 +277,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer bool success = false; if (!sessionMap.TryGetValue(uri, out session)) { - Logger.Write(LogLevel.Verbose, $"Cannot close object explorer session. Couldn't find session for uri. {uri} "); + Logger.Write(TraceEventType.Verbose, $"Cannot close object explorer session. Couldn't find session for uri. {uri} "); } if (session != null) @@ -326,7 +327,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer private void RunCreateSessionTask(ConnectionDetails connectionDetails, string uri) { - Logger.Write(LogLevel.Normal, "Creating OE session"); + Logger.Write(TraceEventType.Information, "Creating OE session"); CancellationTokenSource cancellationTokenSource = new CancellationTokenSource(); if (connectionDetails != null && !string.IsNullOrEmpty(uri)) { @@ -435,7 +436,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer } catch(Exception ex) { - Logger.Write(LogLevel.Warning, $"Failed to change the database in OE connection. error: {ex.Message}"); + Logger.Write(TraceEventType.Warning, $"Failed to change the database in OE connection. error: {ex.Message}"); // We should just try to change the connection. If it fails, there's not much we can do } return response; @@ -541,7 +542,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer private async Task SendSessionFailedNotification(string uri, string errorMessage) { - Logger.Write(LogLevel.Warning, $"Failed To create OE session: {errorMessage}"); + Logger.Write(TraceEventType.Warning, $"Failed To create OE session: {errorMessage}"); SessionCreatedParameters result = new SessionCreatedParameters() { Success = false, @@ -604,7 +605,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer response = await ExpandNode(session, expandParams.NodePath, forceRefresh); if (cancellationToken.IsCancellationRequested) { - Logger.Write(LogLevel.Verbose, "OE expand canceled"); + Logger.Write(TraceEventType.Verbose, "OE expand canceled"); } else { diff --git a/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/DatabaseTreeNode.cs b/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/DatabaseTreeNode.cs index 1333204f..ff5a782d 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/DatabaseTreeNode.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/DatabaseTreeNode.cs @@ -5,6 +5,7 @@ using System; +using System.Diagnostics; using System.Globalization; using Microsoft.SqlServer.Management.Smo; using Microsoft.SqlTools.Utility; @@ -70,7 +71,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer.SmoModel { string error = string.Format(CultureInfo.InvariantCulture, "Failed to get IsAccessible. error:{0} inner:{1} stacktrace:{2}", ex.Message, ex.InnerException != null ? ex.InnerException.Message : "", ex.StackTrace); - Logger.Write(LogLevel.Error, error); + Logger.Write(TraceEventType.Error, error); ErrorMessage = ex.Message; return false; } diff --git a/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/ServerNode.cs b/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/ServerNode.cs index 45bc5d32..2e135aad 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/ServerNode.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/ServerNode.cs @@ -6,6 +6,7 @@ using System; using System.Data.Common; using System.Data.SqlClient; +using System.Diagnostics; using System.Globalization; using System.Linq; using Microsoft.SqlServer.Management.Common; @@ -153,7 +154,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer.SmoModel exceptionMessage = ex.Message; } - Logger.Write(LogLevel.Error, "Exception at ServerNode.CreateContext() : " + exceptionMessage); + Logger.Write(TraceEventType.Error, "Exception at ServerNode.CreateContext() : " + exceptionMessage); this.ErrorStateMessage = string.Format(SR.TreeNodeError, exceptionMessage); return null; } diff --git a/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/SmoChildFactoryBase.cs b/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/SmoChildFactoryBase.cs index 00d65495..78f33922 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/SmoChildFactoryBase.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/SmoChildFactoryBase.cs @@ -38,7 +38,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer.SmoModel { string error = string.Format(CultureInfo.InvariantCulture, "Failed expanding oe children. parent:{0} error:{1} inner:{2} stacktrace:{3}", parent != null ? parent.GetNodePath() : "", ex.Message, ex.InnerException != null ? ex.InnerException.Message : "", ex.StackTrace); - Logger.Write(LogLevel.Error, error); + Logger.Write(TraceEventType.Error, error); throw ex; } finally @@ -85,7 +85,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer.SmoModel /// Parent the nodes are being added to protected virtual void OnExpandPopulateNonFolders(IList allChildren, TreeNode parent, bool refresh, string name) { - Logger.Write(LogLevel.Verbose, string.Format(CultureInfo.InvariantCulture, "child factory parent :{0}", parent.GetNodePath())); + Logger.Write(TraceEventType.Verbose, string.Format(CultureInfo.InvariantCulture, "child factory parent :{0}", parent.GetNodePath())); if (ChildQuerierTypes == null) { @@ -127,7 +127,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer.SmoModel { if (smoObject == null) { - Logger.Write(LogLevel.Error, "smoObject should not be null"); + Logger.Write(TraceEventType.Error, "smoObject should not be null"); } TreeNode childNode = CreateChild(parent, smoObject); if (childNode != null && PassesFinalFilters(childNode, smoObject) && !ShouldFilterNode(childNode, serverValidFor)) @@ -141,7 +141,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer.SmoModel { string error = string.Format(CultureInfo.InvariantCulture, "Failed getting smo objects. parent:{0} querier: {1} error:{2} inner:{3} stacktrace:{4}", parent != null ? parent.GetNodePath() : "", querier.GetType(), ex.Message, ex.InnerException != null ? ex.InnerException.Message : "", ex.StackTrace); - Logger.Write(LogLevel.Error, error); + Logger.Write(TraceEventType.Error, error); throw ex; } } @@ -313,7 +313,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer.SmoModel else { // Return true if cannot find the proeprty, SMO still tries to get that property but adding the property to supported list can make loading the nodes faster - Logger.Write(LogLevel.Verbose, $"Smo property name {propertyName} for Smo type {smoObj.GetType()} is not added as supported properties. This can cause the performance of loading the OE nodes"); + Logger.Write(TraceEventType.Verbose, $"Smo property name {propertyName} for Smo type {smoObj.GetType()} is not added as supported properties. This can cause the performance of loading the OE nodes"); return true; } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/SmoColumnCustomNode.cs b/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/SmoColumnCustomNode.cs index 9933acbc..9d02fe2b 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/SmoColumnCustomNode.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/ObjectExplorer/SmoModel/SmoColumnCustomNode.cs @@ -4,6 +4,7 @@ // using System; +using System.Diagnostics; using System.Globalization; using Microsoft.SqlServer.Management.Smo; using Microsoft.SqlTools.Utility; @@ -73,7 +74,7 @@ namespace Microsoft.SqlTools.ServiceLayer.ObjectExplorer.SmoModel } catch(Exception ex) { - Logger.Write(LogLevel.Error, $"Failed to get customized column name. error:{ex.Message}"); + Logger.Write(TraceEventType.Error, $"Failed to get customized column name. error:{ex.Message}"); } return string.Empty; } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerSessionMonitor.cs b/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerSessionMonitor.cs index 42e6311d..15e11de5 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerSessionMonitor.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Profiler/ProfilerSessionMonitor.cs @@ -7,6 +7,7 @@ using System; using System.Collections.Concurrent; using System.Collections.Generic; using System.Data.SqlClient; +using System.Diagnostics; using System.Linq; using System.Threading; using System.Threading.Tasks; @@ -61,7 +62,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler private List listeners = new List(); /// - /// Registers a session event listener to receive a callback when events arrive + /// Registers a session event Listener to receive a callback when events arrive /// public void AddSessionListener(IProfilerSessionListener listener) { @@ -283,7 +284,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Profiler } catch (Exception ex) { - Logger.Write(LogLevel.Warning, "Failed to poll session. error: " + ex.Message); + Logger.Write(TraceEventType.Warning, "Failed to poll session. error: " + ex.Message); } finally { diff --git a/src/Microsoft.SqlTools.ServiceLayer/Program.cs b/src/Microsoft.SqlTools.ServiceLayer/Program.cs index 6d89dc95..7a2e6070 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Program.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Program.cs @@ -7,6 +7,7 @@ using Microsoft.SqlTools.ServiceLayer.SqlContext; using Microsoft.SqlTools.ServiceLayer.Utility; using Microsoft.SqlTools.Utility; using System.IO; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer { @@ -16,7 +17,7 @@ namespace Microsoft.SqlTools.ServiceLayer internal class Program { /// - /// Main entry point into the SQL Tools API Service Host + /// Main entry point into the SQL Tools API Service Layer /// internal static void Main(string[] args) { @@ -29,16 +30,20 @@ namespace Microsoft.SqlTools.ServiceLayer return; } - string logFilePath = "sqltools"; + string logFilePath = commandOptions.LogFilePath; + if (string.IsNullOrWhiteSpace(logFilePath)) + { + logFilePath = "sqltools"; + } if (!string.IsNullOrWhiteSpace(commandOptions.LoggingDirectory)) { logFilePath = Path.Combine(commandOptions.LoggingDirectory, logFilePath); } // turn on Verbose logging during early development - // we need to switch to Normal when preparing for public preview - Logger.Initialize(logFilePath: logFilePath, minimumLogLevel: LogLevel.Verbose, isEnabled: commandOptions.EnableLogging); - Logger.Write(LogLevel.Normal, "Starting SQL Tools Service Host"); + // we need to switch to Information when preparing for public preview + Logger.Initialize(tracingLevel: commandOptions.TracingLevel, logFilePath: logFilePath, traceSource: "sqltools"); + Logger.Write(TraceEventType.Information, "Starting SQL Tools Service Layer"); // set up the host details and profile paths var hostDetails = new HostDetails(version: new Version(1, 0)); @@ -50,7 +55,7 @@ namespace Microsoft.SqlTools.ServiceLayer } catch (Exception e) { - Logger.Write(LogLevel.Error, string.Format("An unhandled exception occurred: {0}", e)); + Logger.WriteWithCallstack(TraceEventType.Critical, $"An unhandled exception occurred: {e}"); Environment.Exit(1); } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/QueryExecution/Batch.cs b/src/Microsoft.SqlTools.ServiceLayer/QueryExecution/Batch.cs index 8b40d7ec..fe2e1f36 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/QueryExecution/Batch.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/QueryExecution/Batch.cs @@ -251,7 +251,7 @@ namespace Microsoft.SqlTools.ServiceLayer.QueryExecution await BatchStart(this); } - // Register the message listener to *this instance* of the batch + // Register the message Listener to *this instance* of the batch // Note: This is being done to associate messages with batches ReliableSqlConnection sqlConn = conn as ReliableSqlConnection; if (sqlConn != null) @@ -460,7 +460,7 @@ namespace Microsoft.SqlTools.ServiceLayer.QueryExecution private DbCommand CreateCommand(DbConnection conn) { - // Register the message listener to *this instance* of the batch + // Register the message Listener to *this instance* of the batch // Note: This is being done to associate messages with batches ReliableSqlConnection sqlConn = conn as ReliableSqlConnection; DbCommand dbCommand; diff --git a/src/Microsoft.SqlTools.ServiceLayer/QueryExecution/QueryExecutionService.cs b/src/Microsoft.SqlTools.ServiceLayer/QueryExecution/QueryExecutionService.cs index e64df616..b5f39fe1 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/QueryExecution/QueryExecutionService.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/QueryExecution/QueryExecutionService.cs @@ -18,7 +18,7 @@ using Microsoft.SqlTools.ServiceLayer.Workspace; using Microsoft.SqlTools.ServiceLayer.Workspace.Contracts; using Microsoft.SqlTools.ServiceLayer.Hosting; using Microsoft.SqlTools.Utility; - +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.QueryExecution { @@ -875,7 +875,7 @@ namespace Microsoft.SqlTools.ServiceLayer.QueryExecution { // We don't particularly care if we fail to cancel during shutdown string message = string.Format("Failed to cancel query {0} during query service disposal: {1}", query.Key, e); - Logger.Write(LogLevel.Warning, message); + Logger.Write(TraceEventType.Warning, message); } } query.Value.Dispose(); diff --git a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptAsScriptingOperation.cs b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptAsScriptingOperation.cs index a3b7ff16..d2b5318a 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptAsScriptingOperation.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptAsScriptingOperation.cs @@ -16,6 +16,7 @@ using System.Globalization; using Microsoft.SqlServer.Management.SqlScriptPublish; using Microsoft.SqlTools.ServiceLayer.Utility; using Microsoft.SqlServer.Management.Sdk.Sfc; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.Scripting { @@ -103,7 +104,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting this.CancellationToken.ThrowIfCancellationRequested(); Logger.Write( - LogLevel.Verbose, + TraceEventType.Verbose, string.Format( "Sending script complete notification event for operation {0}", this.OperationId @@ -126,7 +127,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting { if (e.IsOperationCanceledException()) { - Logger.Write(LogLevel.Normal, string.Format("Scripting operation {0} was canceled", this.OperationId)); + Logger.Write(TraceEventType.Information, string.Format("Scripting operation {0} was canceled", this.OperationId)); this.SendCompletionNotificationEvent(new ScriptingCompleteParams { Canceled = true, @@ -134,7 +135,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting } else { - Logger.Write(LogLevel.Error, string.Format("Scripting operation {0} failed with exception {1}", this.OperationId, e)); + Logger.Write(TraceEventType.Error, string.Format("Scripting operation {0} failed with exception {1}", this.OperationId, e)); this.SendCompletionNotificationEvent(new ScriptingCompleteParams { OperationId = OperationId, @@ -568,7 +569,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting { //If you are getting this assertion fail it means you are working for higher //version of SQL Server. You need to update this part of code. - Logger.Write(LogLevel.Warning, "This part of the code is not updated corresponding to latest version change"); + Logger.Write(TraceEventType.Warning, "This part of the code is not updated corresponding to latest version change"); } // for cloud scripting to work we also have to have Script Compat set to 105. @@ -664,7 +665,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting this.CancellationToken.ThrowIfCancellationRequested(); Logger.Write( - LogLevel.Verbose, + TraceEventType.Verbose, string.Format( "Sending scripting error progress event, Urn={0}, OperationId={1}, Completed={2}, Error={3}", e.Current, diff --git a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScripterCore.cs b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScripterCore.cs index bbe47f6b..b29320e7 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScripterCore.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScripterCore.cs @@ -25,6 +25,7 @@ using Location = Microsoft.SqlTools.ServiceLayer.Workspace.Contracts.Location; using Microsoft.SqlServer.Management.Sdk.Sfc; using System.Text; using System.Data; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.Scripting { @@ -94,14 +95,14 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting } catch (ConnectionFailureException cfe) { - Logger.Write(LogLevel.Error, "Exception at PeekDefinition Database.get() : " + cfe.Message); + Logger.Write(TraceEventType.Error, "Exception at PeekDefinition Database.get() : " + cfe.Message); this.error = true; this.errorMessage = (connectionInfo != null && connectionInfo.IsCloud) ? SR.PeekDefinitionAzureError(cfe.Message) : SR.PeekDefinitionError(cfe.Message); return null; } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Exception at PeekDefinition Database.get() : " + ex.Message); + Logger.Write(TraceEventType.Error, "Exception at PeekDefinition Database.get() : " + ex.Message); this.error = true; this.errorMessage = SR.PeekDefinitionError(ex.Message); return null; @@ -822,7 +823,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting catch (Exception ex) { // log any exceptions determining if InMemory, but don't treat as fatal exception - Logger.Write(LogLevel.Error, "Could not determine if is InMemory table " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Could not determine if is InMemory table " + ex.ToString()); } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingExtensionMethods.cs b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingExtensionMethods.cs index cc17761e..f872d74b 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingExtensionMethods.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingExtensionMethods.cs @@ -5,6 +5,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using System.Threading.Tasks; using Microsoft.SqlServer.Management.Sdk.Sfc; @@ -59,7 +60,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting IEnumerable objectTypes = publishModel.GetDatabaseObjectTypes(); Logger.Write( - LogLevel.Verbose, + TraceEventType.Verbose, string.Format( "Loaded SMO object type count {0}, types: {1}", objectTypes.Count(), @@ -70,7 +71,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting IEnumerable> databaseObjectsOfType = publishModel.EnumChildrenForDatabaseObjectType(objectType); Logger.Write( - LogLevel.Verbose, + TraceEventType.Verbose, string.Format( "Loaded SMO urn object count {0} for type {1}, urns: {2}", objectType, diff --git a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingListObjectsOperation.cs b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingListObjectsOperation.cs index 01d43fd8..f2f58938 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingListObjectsOperation.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingListObjectsOperation.cs @@ -17,6 +17,7 @@ using Microsoft.SqlTools.Hosting.Protocol; using Microsoft.SqlTools.ServiceLayer.Scripting.Contracts; using Microsoft.SqlTools.Utility; using Microsoft.SqlTools.Hosting.Protocol.Contracts; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.Scripting { @@ -61,7 +62,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting List databaseObjects = publishModel.GetDatabaseObjects(); Logger.Write( - LogLevel.Verbose, + TraceEventType.Verbose, string.Format( "Sending list object completion notification count {0}, objects: {1}", databaseObjects, @@ -78,7 +79,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting } catch (Exception e) { - Logger.Write(LogLevel.Normal, string.Format("Scripting operation {0} was canceled", this.OperationId)); + Logger.Write(TraceEventType.Information, string.Format("Scripting operation {0} was canceled", this.OperationId)); if (e.IsOperationCanceledException()) { this.SendCompletionNotificationEvent(new ScriptingListObjectsCompleteParams @@ -89,7 +90,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting } else { - Logger.Write(LogLevel.Error, string.Format("Scripting operation {0} failed with exception {1}", this.OperationId, e)); + Logger.Write(TraceEventType.Error, string.Format("Scripting operation {0} failed with exception {1}", this.OperationId, e)); this.SendCompletionNotificationEvent(new ScriptingListObjectsCompleteParams { OperationId = this.OperationId, diff --git a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingOperation.cs b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingOperation.cs index 32adbe63..b852f5e3 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingOperation.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingOperation.cs @@ -4,6 +4,7 @@ // using System; +using System.Diagnostics; using System.Threading; using System.Threading.Tasks; using Microsoft.SqlTools.Utility; @@ -43,7 +44,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting { if (!this.cancellation.IsCancellationRequested) { - Logger.Write(LogLevel.Verbose, string.Format("Cancel invoked for OperationId {0}", this.OperationId)); + Logger.Write(TraceEventType.Verbose, string.Format("Cancel invoked for OperationId {0}", this.OperationId)); this.cancellation.Cancel(); } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingScriptOperation.cs b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingScriptOperation.cs index 71f323bd..87b8dca6 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingScriptOperation.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingScriptOperation.cs @@ -6,6 +6,7 @@ using System; using System.Collections.Generic; using System.Data.SqlClient; +using System.Diagnostics; using System.Linq; using Microsoft.SqlServer.Management.SqlScriptPublish; using Microsoft.SqlTools.ServiceLayer.Scripting.Contracts; @@ -64,7 +65,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting this.CancellationToken.ThrowIfCancellationRequested(); Logger.Write( - LogLevel.Verbose, + TraceEventType.Verbose, string.Format( "Sending script complete notification event for operation {0}, sequence number {1} with total count {2} and scripted count {3}", this.OperationId, @@ -83,7 +84,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting { if (e.IsOperationCanceledException()) { - Logger.Write(LogLevel.Normal, string.Format("Scripting operation {0} was canceled", this.OperationId)); + Logger.Write(TraceEventType.Information, string.Format("Scripting operation {0} was canceled", this.OperationId)); this.SendCompletionNotificationEvent(new ScriptingCompleteParams { Canceled = true, @@ -91,7 +92,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting } else { - Logger.Write(LogLevel.Error, string.Format("Scripting operation {0} failed with exception {1}", this.OperationId, e)); + Logger.Write(TraceEventType.Error, string.Format("Scripting operation {0} failed with exception {1}", this.OperationId, e)); this.SendCompletionNotificationEvent(new ScriptingCompleteParams { HasError = true, @@ -193,7 +194,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting PopulateAdvancedScriptOptions(this.Parameters.ScriptOptions, publishModel.AdvancedOptions); Logger.Write( - LogLevel.Normal, + TraceEventType.Information, string.Format( "Scripting object count {0}, objects: {1}", selectedObjects.Count(), @@ -214,7 +215,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting this.CancellationToken.ThrowIfCancellationRequested(); Logger.Write( - LogLevel.Verbose, + TraceEventType.Verbose, string.Format( "Sending scripting error progress event, Urn={0}, OperationId={1}, Sequence={2}, Completed={3}, Error={4}", e.Urn, @@ -245,7 +246,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting this.totalScriptedObjectCount = scriptingObjects.Count; Logger.Write( - LogLevel.Verbose, + TraceEventType.Verbose, string.Format( "Sending scripting plan notification event OperationId={0}, Sequence={1}, Count={2}, Objects: {3}", this.OperationId, @@ -270,7 +271,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting } Logger.Write( - LogLevel.Verbose, + TraceEventType.Verbose, string.Format( "Sending progress event, Urn={0}, OperationId={1}, Sequence={2}, Status={3}, Error={4}", e.Urn, diff --git a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingService.cs b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingService.cs index 820a330c..2d8b51da 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingService.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Scripting/ScriptingService.cs @@ -4,26 +4,16 @@ // using System; -using System.IO; using System.Collections.Concurrent; -using System.Collections.Specialized; -using System.Data.SqlClient; using System.Diagnostics; -using System.Text; -using System.Threading; using System.Threading.Tasks; using Microsoft.SqlTools.Hosting.Protocol; using Microsoft.SqlTools.Hosting.Protocol.Contracts; using Microsoft.SqlTools.ServiceLayer.Connection; using Microsoft.SqlTools.ServiceLayer.Hosting; -using Microsoft.SqlTools.ServiceLayer.Metadata.Contracts; using Microsoft.SqlTools.ServiceLayer.Scripting.Contracts; using Microsoft.SqlTools.Utility; -using Microsoft.SqlServer.Management.Smo; -using Microsoft.SqlServer.Management.Common; -using Microsoft.SqlServer.Management.Sdk.Sfc; using Microsoft.SqlTools.ServiceLayer.Utility; -using Microsoft.SqlTools.ServiceLayer.LanguageServices; namespace Microsoft.SqlTools.ServiceLayer.Scripting { @@ -188,7 +178,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting } else { - Logger.Write(LogLevel.Normal, string.Format("Operation {0} was not found", operation.OperationId)); + Logger.Write(TraceEventType.Information, string.Format("Operation {0} was not found", operation.OperationId)); } await requestContext.SendResult(new ScriptingCancelResult()); diff --git a/src/Microsoft.SqlTools.ServiceLayer/Scripting/SmoScriptingOperation.cs b/src/Microsoft.SqlTools.ServiceLayer/Scripting/SmoScriptingOperation.cs index 9ce935ea..f06f2e26 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Scripting/SmoScriptingOperation.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Scripting/SmoScriptingOperation.cs @@ -8,6 +8,7 @@ using Microsoft.SqlTools.ServiceLayer.Scripting.Contracts; using Microsoft.SqlTools.Utility; using System; using System.Data.SqlClient; +using System.Diagnostics; using System.IO; using System.Reflection; using static Microsoft.SqlServer.Management.SqlScriptPublish.SqlScriptOptions; @@ -86,12 +87,12 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting catch (SqlException e) { Logger.Write( - LogLevel.Verbose, + TraceEventType.Verbose, string.Format("Exception getting server name", e)); } } - Logger.Write(LogLevel.Verbose, string.Format("Resolved server name '{0}'", serverName)); + Logger.Write(TraceEventType.Verbose, string.Format("Resolved server name '{0}'", serverName)); return serverName; } @@ -122,7 +123,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting { if (scriptOptionsParameters == null) { - Logger.Write(LogLevel.Verbose, "No advanced options set, the ScriptOptions object is null."); + Logger.Write(TraceEventType.Verbose, "No advanced options set, the ScriptOptions object is null."); return; } @@ -131,14 +132,14 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting PropertyInfo advancedOptionPropInfo = advancedOptions.GetType().GetProperty(optionPropInfo.Name); if (advancedOptionPropInfo == null) { - Logger.Write(LogLevel.Warning, string.Format("Invalid property info name {0} could not be mapped to a property on SqlScriptOptions.", optionPropInfo.Name)); + Logger.Write(TraceEventType.Warning, string.Format("Invalid property info name {0} could not be mapped to a property on SqlScriptOptions.", optionPropInfo.Name)); continue; } object optionValue = optionPropInfo.GetValue(scriptOptionsParameters, index: null); if (optionValue == null) { - Logger.Write(LogLevel.Verbose, string.Format("Skipping ScriptOptions.{0} since value is null", optionPropInfo.Name)); + Logger.Write(TraceEventType.Verbose, string.Format("Skipping ScriptOptions.{0} since value is null", optionPropInfo.Name)); continue; } @@ -168,13 +169,13 @@ namespace Microsoft.SqlTools.ServiceLayer.Scripting smoValue = Enum.Parse(advancedOptionPropInfo.PropertyType, (string)optionValue, ignoreCase: true); } - Logger.Write(LogLevel.Verbose, string.Format("Setting ScriptOptions.{0} to value {1}", optionPropInfo.Name, smoValue)); + Logger.Write(TraceEventType.Verbose, string.Format("Setting ScriptOptions.{0} to value {1}", optionPropInfo.Name, smoValue)); advancedOptionPropInfo.SetValue(advancedOptions, smoValue); } catch (Exception e) { Logger.Write( - LogLevel.Warning, + TraceEventType.Warning, string.Format("An exception occurred setting option {0} to value {1}: {2}", optionPropInfo.Name, optionValue, e)); } } diff --git a/src/Microsoft.SqlTools.ServiceLayer/ServiceHost.cs b/src/Microsoft.SqlTools.ServiceLayer/ServiceHost.cs index 3ab6adae..c0d1f6d4 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/ServiceHost.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/ServiceHost.cs @@ -17,6 +17,7 @@ using Microsoft.SqlTools.Utility; using Microsoft.SqlTools.ServiceLayer.Connection; using Microsoft.SqlTools.ServiceLayer.Admin; using Microsoft.SqlTools.ServiceLayer.Utility; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.Hosting { @@ -144,7 +145,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Hosting /// private async Task HandleShutdownRequest(object shutdownParams, RequestContext requestContext) { - Logger.Write(LogLevel.Normal, "Service host is shutting down..."); + Logger.Write(TraceEventType.Information, "Service host is shutting down..."); // Call all the shutdown methods provided by the service components Task[] shutdownTasks = shutdownCallbacks.Select(t => t(shutdownParams, requestContext)).ToArray(); diff --git a/src/Microsoft.SqlTools.ServiceLayer/TaskServices/SmoScriptableOperationWithFullDbAccess.cs b/src/Microsoft.SqlTools.ServiceLayer/TaskServices/SmoScriptableOperationWithFullDbAccess.cs index a3c57c82..2f584d6c 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/TaskServices/SmoScriptableOperationWithFullDbAccess.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/TaskServices/SmoScriptableOperationWithFullDbAccess.cs @@ -7,6 +7,7 @@ using Microsoft.SqlServer.Management.Smo; using Microsoft.SqlTools.ServiceLayer.Connection; using Microsoft.SqlTools.Utility; using System; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.TaskServices { @@ -66,7 +67,7 @@ namespace Microsoft.SqlTools.ServiceLayer.TaskServices } catch (DatabaseFullAccessException databaseFullAccessException) { - Logger.Write(LogLevel.Warning, $"Failed to gain access to database. server|database:{ServerName}|{DatabaseName}"); + Logger.Write(TraceEventType.Warning, $"Failed to gain access to database. server|database:{ServerName}|{DatabaseName}"); throw databaseFullAccessException; } catch diff --git a/src/Microsoft.SqlTools.ServiceLayer/TaskServices/TaskService.cs b/src/Microsoft.SqlTools.ServiceLayer/TaskServices/TaskService.cs index b0614444..a777afd1 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/TaskServices/TaskService.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/TaskServices/TaskService.cs @@ -11,6 +11,7 @@ using Microsoft.SqlTools.Hosting; using Microsoft.SqlTools.Extensibility; using Microsoft.SqlTools.Utility; using System.Linq; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.TaskServices { @@ -53,7 +54,7 @@ namespace Microsoft.SqlTools.ServiceLayer.TaskServices public override void InitializeService(IProtocolEndpoint serviceHost) { this.serviceHost = serviceHost; - Logger.Write(LogLevel.Verbose, "TaskService initialized"); + Logger.Write(TraceEventType.Verbose, "TaskService initialized"); serviceHost.SetRequestHandler(ListTasksRequest.Type, HandleListTasksRequest); serviceHost.SetRequestHandler(CancelTaskRequest.Type, HandleCancelTaskRequest); TaskManager.TaskAdded += OnTaskAdded; @@ -66,7 +67,7 @@ namespace Microsoft.SqlTools.ServiceLayer.TaskServices ListTasksParams listTasksParams, RequestContext context) { - Logger.Write(LogLevel.Verbose, "HandleListTasksRequest"); + Logger.Write(TraceEventType.Verbose, "HandleListTasksRequest"); Func> getAllTasks = () => { @@ -86,7 +87,7 @@ namespace Microsoft.SqlTools.ServiceLayer.TaskServices internal async Task HandleCancelTaskRequest(CancelTaskParams cancelTaskParams, RequestContext context) { - Logger.Write(LogLevel.Verbose, "HandleCancelTaskRequest"); + Logger.Write(TraceEventType.Verbose, "HandleCancelTaskRequest"); Func> cancelTask = () => { Validate.IsNotNull(nameof(cancelTaskParams), cancelTaskParams); diff --git a/src/Microsoft.SqlTools.ServiceLayer/Utility/ServiceLayerCommandOptions.cs b/src/Microsoft.SqlTools.ServiceLayer/Utility/ServiceLayerCommandOptions.cs index 43c5f6b3..5298b4cb 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Utility/ServiceLayerCommandOptions.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Utility/ServiceLayerCommandOptions.cs @@ -9,7 +9,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Utility { class ServiceLayerCommandOptions : CommandOptions { - private const string ServiceLayerServiceName = "MicrosoftSqlToolsServiceLayer.exe"; + internal const string ServiceLayerServiceName = "MicrosoftSqlToolsServiceLayer.exe"; public ServiceLayerCommandOptions(string[] args) : base(args, ServiceLayerServiceName) { diff --git a/src/Microsoft.SqlTools.ServiceLayer/Utility/TaskExtensions.cs b/src/Microsoft.SqlTools.ServiceLayer/Utility/TaskExtensions.cs index a60b438b..0d611f58 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Utility/TaskExtensions.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Utility/TaskExtensions.cs @@ -4,6 +4,7 @@ // using System; +using System.Diagnostics; using System.Text; using System.Threading.Tasks; using Microsoft.SqlTools.Utility; @@ -42,8 +43,8 @@ namespace Microsoft.SqlTools.ServiceLayer.Utility } catch (Exception e) { - Logger.Write(LogLevel.Error, $"Exception in exception handling continuation: {e}"); - Logger.Write(LogLevel.Error, e.StackTrace); + Logger.Write(TraceEventType.Error, $"Exception in exception handling continuation: {e}"); + Logger.Write(TraceEventType.Error, e.StackTrace); } }); } @@ -79,8 +80,8 @@ namespace Microsoft.SqlTools.ServiceLayer.Utility } catch (Exception e) { - Logger.Write(LogLevel.Error, $"Exception in exception handling continuation: {e}"); - Logger.Write(LogLevel.Error, e.StackTrace); + Logger.Write(TraceEventType.Error, $"Exception in exception handling continuation: {e}"); + Logger.Write(TraceEventType.Error, e.StackTrace); } }); } @@ -94,7 +95,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Utility sb.AppendLine($"{e.GetType().Name}: {e.Message}"); sb.AppendLine(e.StackTrace); } - Logger.Write(LogLevel.Error, sb.ToString()); + Logger.Write(TraceEventType.Error, sb.ToString()); } } } \ No newline at end of file diff --git a/src/Microsoft.SqlTools.ServiceLayer/Workspace/Workspace.cs b/src/Microsoft.SqlTools.ServiceLayer/Workspace/Workspace.cs index a4813d7b..29de3f91 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Workspace/Workspace.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Workspace/Workspace.cs @@ -13,6 +13,7 @@ using Microsoft.SqlTools.Utility; using Microsoft.SqlTools.ServiceLayer.Workspace.Contracts; using System.Runtime.InteropServices; using Microsoft.SqlTools.ServiceLayer.Utility; +using System.Diagnostics; namespace Microsoft.SqlTools.ServiceLayer.Workspace { @@ -121,7 +122,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Workspace this.workspaceFiles.Add(keyName, scriptFile); } - Logger.Write(LogLevel.Verbose, "Opened file on disk: " + resolvedFile.FilePath); + Logger.Write(TraceEventType.Verbose, "Opened file on disk: " + resolvedFile.FilePath); } return scriptFile; @@ -165,7 +166,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Workspace canReadFromDisk = resolvedFile.CanReadFromDisk; } - Logger.Write(LogLevel.Verbose, "Resolved path: " + filePath); + Logger.Write(TraceEventType.Verbose, "Resolved path: " + filePath); return new ResolvedFile(filePath, canReadFromDisk); } @@ -213,7 +214,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Workspace this.workspaceFiles.Add(keyName, scriptFile); - Logger.Write(LogLevel.Verbose, "Opened file as in-memory buffer: " + resolvedFile.FilePath); + Logger.Write(TraceEventType.Verbose, "Opened file as in-memory buffer: " + resolvedFile.FilePath); } return scriptFile; diff --git a/src/Microsoft.SqlTools.ServiceLayer/Workspace/WorkspaceService.cs b/src/Microsoft.SqlTools.ServiceLayer/Workspace/WorkspaceService.cs index 4df336d6..a2970043 100644 --- a/src/Microsoft.SqlTools.ServiceLayer/Workspace/WorkspaceService.cs +++ b/src/Microsoft.SqlTools.ServiceLayer/Workspace/WorkspaceService.cs @@ -5,6 +5,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using System.Text; using System.Threading.Tasks; @@ -132,7 +133,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Workspace // Register an initialization handler that sets the workspace path serviceHost.RegisterInitializeTask(async (parameters, contect) => { - Logger.Write(LogLevel.Verbose, "Initializing workspace service"); + Logger.Write(TraceEventType.Verbose, "Initializing workspace service"); if (Workspace != null) { @@ -144,7 +145,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Workspace // Register a shutdown request that disposes the workspace serviceHost.RegisterShutdownTask(async (parameters, context) => { - Logger.Write(LogLevel.Verbose, "Shutting down workspace service"); + Logger.Write(TraceEventType.Verbose, "Shutting down workspace service"); if (Workspace != null) { @@ -227,14 +228,14 @@ namespace Microsoft.SqlTools.ServiceLayer.Workspace } } - Logger.Write(LogLevel.Verbose, msg.ToString()); + Logger.Write(TraceEventType.Verbose, msg.ToString()); var handlers = TextDocChangeCallbacks.Select(t => t(changedFiles.ToArray(), eventContext)); return Task.WhenAll(handlers); } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unknown error " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown error " + ex.ToString()); // Swallow exceptions here to prevent us from crashing // TODO: this probably means the ScriptFile model is in a bad state or out of sync with the actual file; we should recover here return Task.FromResult(true); @@ -247,7 +248,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Workspace { try { - Logger.Write(LogLevel.Verbose, "HandleDidOpenTextDocumentNotification"); + Logger.Write(TraceEventType.Verbose, "HandleDidOpenTextDocumentNotification"); if (IsScmEvent(openParams.TextDocument.Uri)) { @@ -268,7 +269,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Workspace } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unknown error " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown error " + ex.ToString()); // Swallow exceptions here to prevent us from crashing // TODO: this probably means the ScriptFile model is in a bad state or out of sync with the actual file; we should recover here return; @@ -281,7 +282,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Workspace { try { - Logger.Write(LogLevel.Verbose, "HandleDidCloseTextDocumentNotification"); + Logger.Write(TraceEventType.Verbose, "HandleDidCloseTextDocumentNotification"); if (IsScmEvent(closeParams.TextDocument.Uri)) { @@ -304,7 +305,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Workspace } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unknown error " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown error " + ex.ToString()); // Swallow exceptions here to prevent us from crashing // TODO: this probably means the ScriptFile model is in a bad state or out of sync with the actual file; we should recover here return; @@ -320,7 +321,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Workspace { try { - Logger.Write(LogLevel.Verbose, "HandleDidChangeConfigurationNotification"); + Logger.Write(TraceEventType.Verbose, "HandleDidChangeConfigurationNotification"); // Propagate the changes to the event handlers var configUpdateTasks = ConfigChangeCallbacks.Select( @@ -329,7 +330,7 @@ namespace Microsoft.SqlTools.ServiceLayer.Workspace } catch (Exception ex) { - Logger.Write(LogLevel.Error, "Unknown error " + ex.ToString()); + Logger.Write(TraceEventType.Error, "Unknown error " + ex.ToString()); // Swallow exceptions here to prevent us from crashing // TODO: this probably means the ScriptFile model is in a bad state or out of sync with the actual file; we should recover here return; diff --git a/test/Microsoft.SqlTools.Hosting.UnitTests/Microsoft.SqlTools.Hosting.UnitTests.csproj b/test/Microsoft.SqlTools.Hosting.UnitTests/Microsoft.SqlTools.Hosting.UnitTests.csproj index 63dcfea2..f28f4d44 100644 --- a/test/Microsoft.SqlTools.Hosting.UnitTests/Microsoft.SqlTools.Hosting.UnitTests.csproj +++ b/test/Microsoft.SqlTools.Hosting.UnitTests/Microsoft.SqlTools.Hosting.UnitTests.csproj @@ -12,6 +12,6 @@ - + \ No newline at end of file diff --git a/test/Microsoft.SqlTools.Hosting.UnitTests/UtilityTests/LoggerTests.cs b/test/Microsoft.SqlTools.Hosting.UnitTests/UtilityTests/LoggerTests.cs index ca85117c..126d6ac3 100644 --- a/test/Microsoft.SqlTools.Hosting.UnitTests/UtilityTests/LoggerTests.cs +++ b/test/Microsoft.SqlTools.Hosting.UnitTests/UtilityTests/LoggerTests.cs @@ -3,6 +3,7 @@ // Licensed under the MIT license. See LICENSE file in the project root for full license information. using System; +using System.Diagnostics; using System.IO; using System.Linq; using Microsoft.SqlTools.Hosting.Utility; @@ -30,28 +31,28 @@ namespace Microsoft.SqlTools.Hosting.UnitTests.UtilityTests .ToList() .ForEach(File.Delete); - Logger logger = new Logger(); - // initialize the logger - logger.Initialize( + Logger.Initialize( logFilePath: Path.Combine(Directory.GetCurrentDirectory(), "sqltools"), - minimumLogLevel: LogLevel.Verbose); + tracingLevel: SourceLevels.Verbose); + + // Write a test message. + string logMessage = $"Message from {nameof(LoggerDefaultFile)} test"; + Logger.Write(TraceEventType.Information, logMessage); // close the logger - logger.Close(); + Logger.Close(); // find the name of the new log file - string logFileName = Directory.GetFiles(Directory.GetCurrentDirectory()) - .SingleOrDefault(fileName => - fileName.Contains("sqltools_") - && fileName.EndsWith(".log", StringComparison.OrdinalIgnoreCase)); + string logFileName = Logger.LogFileFullPath; // validate the log file was created with desired name Assert.True(!string.IsNullOrWhiteSpace(logFileName)); if (!string.IsNullOrWhiteSpace(logFileName)) { Assert.True(logFileName.Length > "sqltools_.log".Length); - Assert.True(File.Exists(logFileName)); - + Assert.True(File.Exists(logFileName), $"the log file: {logFileName} must exist"); + //Ensure that our log message exists in the log file + Assert.True(File.ReadAllText(logFileName).Contains(logMessage, StringComparison.InvariantCultureIgnoreCase), $"the log message:'{logMessage}' must be present in the log file"); // delete the test log file if (File.Exists(logFileName)) { diff --git a/test/Microsoft.SqlTools.ServiceLayer.IntegrationTests/LanguageServer/PeekDefinitionTests.cs b/test/Microsoft.SqlTools.ServiceLayer.IntegrationTests/LanguageServer/PeekDefinitionTests.cs index e42a4242..8312e68a 100644 --- a/test/Microsoft.SqlTools.ServiceLayer.IntegrationTests/LanguageServer/PeekDefinitionTests.cs +++ b/test/Microsoft.SqlTools.ServiceLayer.IntegrationTests/LanguageServer/PeekDefinitionTests.cs @@ -105,6 +105,24 @@ GO"; Cleanup(locations); } + [Fact] + public void LoggerGetValidTableDefinitionTest() + { + TestLogger test = new TestLogger() + { + TraceSource = System.Reflection.MethodInfo.GetCurrentMethod().Name, + EventType = System.Diagnostics.TraceEventType.Information, + TracingLevel = System.Diagnostics.SourceLevels.All, + }; + + test.Initialize(); + GetValidTableDefinitionTest(); // This should emit log.from SMO code base + test.LogMessage = "OnScriptingProgress ScriptingCompleted"; //Log message to verify. This message comes from SMO code. + test.Verify(); // The log message should be absent since the tracing level is set to Off. + test.Cleanup(); + + } + /// /// Test get definition for a invalid table object with active connection /// diff --git a/test/Microsoft.SqlTools.ServiceLayer.IntegrationTests/Microsoft.SqlTools.ServiceLayer.IntegrationTests.csproj b/test/Microsoft.SqlTools.ServiceLayer.IntegrationTests/Microsoft.SqlTools.ServiceLayer.IntegrationTests.csproj index 023f87e1..88330b73 100644 --- a/test/Microsoft.SqlTools.ServiceLayer.IntegrationTests/Microsoft.SqlTools.ServiceLayer.IntegrationTests.csproj +++ b/test/Microsoft.SqlTools.ServiceLayer.IntegrationTests/Microsoft.SqlTools.ServiceLayer.IntegrationTests.csproj @@ -1,26 +1,27 @@ - + netcoreapp2.1 - false + false portable Microsoft.SqlTools.ServiceLayer.IntegrationTests Microsoft.SqlTools.ServiceLayer.IntegrationTests true + $(DefineConstants);TRACE - - ../../bin/ref/Newtonsoft.Json.dll - - - ../../bin/ref/Moq.dll - - - ../../bin/ref/Castle.Core.dll - + + ../../bin/ref/Newtonsoft.Json.dll + + + ../../bin/ref/Moq.dll + + + ../../bin/ref/Castle.Core.dll + diff --git a/test/Microsoft.SqlTools.ServiceLayer.PerfTests/Program.cs b/test/Microsoft.SqlTools.ServiceLayer.PerfTests/Program.cs index 1462df66..bc471b04 100644 --- a/test/Microsoft.SqlTools.ServiceLayer.PerfTests/Program.cs +++ b/test/Microsoft.SqlTools.ServiceLayer.PerfTests/Program.cs @@ -4,6 +4,7 @@ // using System; +using System.Diagnostics; using Microsoft.SqlTools.ServiceLayer.TestDriver.Driver; using Microsoft.SqlTools.ServiceLayer.TestDriver.Utility; using Microsoft.SqlTools.Utility; @@ -24,7 +25,7 @@ namespace Microsoft.SqlTools.ServiceLayer.PerfTests return 0; } - Logger.Initialize("testdriver", LogLevel.Verbose); + Logger.Initialize(logFilePath: Logger.GenerateLogFilePath("testdriver"), traceSource: "perftests", tracingLevel: SourceLevels.Verbose); return TestRunner.Instance.RunTests(args, "Microsoft.SqlTools.ServiceLayer.PerfTests.").Result; } } diff --git a/test/Microsoft.SqlTools.ServiceLayer.Test.Common/Microsoft.SqlTools.ServiceLayer.Test.Common.csproj b/test/Microsoft.SqlTools.ServiceLayer.Test.Common/Microsoft.SqlTools.ServiceLayer.Test.Common.csproj index d12c40d4..29891e27 100644 --- a/test/Microsoft.SqlTools.ServiceLayer.Test.Common/Microsoft.SqlTools.ServiceLayer.Test.Common.csproj +++ b/test/Microsoft.SqlTools.ServiceLayer.Test.Common/Microsoft.SqlTools.ServiceLayer.Test.Common.csproj @@ -5,7 +5,7 @@ false false false - $(DefineConstants);NETCOREAPP1_0 + $(DefineConstants);NETCOREAPP1_0;TRACE false diff --git a/test/Microsoft.SqlTools.ServiceLayer.Test.Common/TestLogger.cs b/test/Microsoft.SqlTools.ServiceLayer.Test.Common/TestLogger.cs new file mode 100644 index 00000000..7d1fee7a --- /dev/null +++ b/test/Microsoft.SqlTools.ServiceLayer.Test.Common/TestLogger.cs @@ -0,0 +1,168 @@ +// +// Copyright (c) Microsoft. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. +// + +using Microsoft.SqlTools.Utility; +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.IO; +using System.Text.RegularExpressions; +using Xunit; + +namespace Microsoft.SqlTools.ServiceLayer.Test.Common +{ + public class TestLogger + { + private string logFilePath; + private string logMessage; + private string logContents; + private string logFileName; + private string topFrame; + + public bool ShouldVerifyCallstack { get; set; } = false; + public string TestName { get => testName ?? TraceSource; set => testName = value; } + public string TraceSource { get; set; } = "sqltoolsTest"; + public string LogMessage { get => logMessage ?? $"{TestName} test message"; set => logMessage = value; } + public string LogFilePath { get => logFilePath ?? Logger.GenerateLogFilePath(Path.Combine(Directory.GetCurrentDirectory(), TraceSource)); set => logFilePath = value; } + public TraceEventType EventType { get; set; } = TraceEventType.Information; + public SourceLevels TracingLevel { get; set; } = SourceLevels.Critical; + public bool DoNotUseTraceSource { get; set; } = false; + + private List pendingVerifications; + private string testName; + + public string CallstackMessage { get => $"Callstack=\\s*{TopFrame}"; } + + public string LogFileName { get => logFileName ?? Logger.LogFileFullPath; set => logFileName = value; } + public void Initialize() => + Logger.Initialize(TracingLevel, LogFilePath, TraceSource); // initialize the logger + public string LogContents + { + get + { + if (logContents == null) + { + Logger.Close(); + Assert.True(!string.IsNullOrWhiteSpace(LogFileName)); + Assert.True(LogFileName.Length > "{TraceSource}_.log".Length); + Assert.True(File.Exists(LogFileName)); + logContents = File.ReadAllText(LogFileName); + } + return logContents; + } + set => logContents = value; + } + + public string TopFrame { get => topFrame ?? "at System.Environment.get_StackTrace()"; set => topFrame = value; } + + public List PendingVerifications + { + get + { + if (pendingVerifications == null) + { + pendingVerifications = new List(); + } + return pendingVerifications; + } + set => pendingVerifications = value; + } + + public void Write() + { + // write test log + if (DoNotUseTraceSource) + { + TraceSource savedTraceSource = Logger.TraceSource; + Logger.TraceSource = null; + Logger.Write(EventType, LogMessage); + Logger.TraceSource = savedTraceSource; + } + else + Logger.Write(EventType, LogMessage); + } + + public void WriteWithCallstack() + { + // write test log with callstack + Logger.WriteWithCallstack(EventType, LogMessage); + ShouldVerifyCallstack = true; + } + + public void Verify(bool expectLogMessage = true) => Verify(ShouldVerifyCallstack, expectLogMessage); + + public void Verify(bool shouldVerifyCallstack, bool expectLogMessage = true) => Verify(EventType, LogMessage, CallstackMessage, shouldVerifyCallstack, expectLogMessage); + + public void Verify(TraceEventType eventType, string message, string callstackMessage, bool shouldVerifyCallstack = false, bool expectLogMessage = true) + { + if (expectLogMessage) + { + Assert.True(File.Exists(Logger.LogFileFullPath) && Regex.IsMatch(LogContents, $@"\b{eventType}:\s+\d+\s+:\s+{message}", RegexOptions.Compiled)); + } + else + { + Assert.False(File.Exists(Logger.LogFileFullPath) && Regex.IsMatch(LogContents, $@"\b{eventType}:\s+\d+\s+:\s+{message}", RegexOptions.Compiled)); + } + if (shouldVerifyCallstack) + { + VerifyCallstack(callstackMessage, expectLogMessage); + } + } + + /// + /// Perform all the pending verifications + /// + public void VerifyPending() + { + foreach (var pv in PendingVerifications) + { + pv.Invoke(); + } + } + + public void VerifyCallstack(bool expectLogMessage = true) => VerifyCallstack(CallstackMessage, expectLogMessage); + + public void VerifyCallstack(string message, bool expectLogMessage = true) + { + if (expectLogMessage) + { + Assert.True(File.Exists(Logger.LogFileFullPath) && Regex.IsMatch(LogContents, $"{message}", RegexOptions.Compiled)); + } + else + { + Assert.False(File.Exists(Logger.LogFileFullPath) && Regex.IsMatch(LogContents, $"{message}", RegexOptions.Compiled)); + } + } + + + public static void VerifyInitialization(SourceLevels expectedTracingLevel, string expectedTraceSource, string logFilePath, bool isLogFileExpectedToExist, int? testNo = null) + { + string FailureMessagePrefix = testNo.HasValue ? $"For Test No:{testNo.Value.ToString()}," : string.Empty; + Assert.False(string.IsNullOrWhiteSpace(logFilePath), $"{FailureMessagePrefix} LogFilePath should not be null or whitespaces"); + Assert.True(expectedTracingLevel == Logger.TracingLevel, $"{FailureMessagePrefix} expected Tracing Level did not match the configured value"); + if (isLogFileExpectedToExist) + { + Assert.True(File.Exists(logFilePath), $"{FailureMessagePrefix} logFilePath:{logFilePath} must exist"); + } + else + { + Assert.False(File.Exists(logFilePath), $"{FailureMessagePrefix} {logFilePath} must not exist"); + } + Assert.True(string.Compare(expectedTraceSource, Logger.TraceSource.Name, ignoreCase: true) == 0, $"{FailureMessagePrefix} expected Trace Source Name did not match the configured value"); + } + + public void Cleanup() => Cleanup(Logger.LogFileFullPath); + + public static void Cleanup(string logFileName) + { + if (File.Exists(logFileName)) + { + Logger.Close(); + File.Delete(logFileName); + } + } + + } +} diff --git a/test/Microsoft.SqlTools.ServiceLayer.TestDriver.Tests/Program.cs b/test/Microsoft.SqlTools.ServiceLayer.TestDriver.Tests/Program.cs index 7a68ea28..3ea3a2f5 100644 --- a/test/Microsoft.SqlTools.ServiceLayer.TestDriver.Tests/Program.cs +++ b/test/Microsoft.SqlTools.ServiceLayer.TestDriver.Tests/Program.cs @@ -31,7 +31,7 @@ namespace Microsoft.SqlTools.ServiceLayer.TestDriver.Tests return 0; } - Logger.Initialize("testdriver", LogLevel.Verbose); + Logger.Initialize("testdriver", TraceEventType.Verbose); int returnCode = 0; Task.Run(async () => diff --git a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Connection/DatabaseLocksManagerTests.cs b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Connection/DatabaseLocksManagerTests.cs index 8ef90b97..75ef5cdc 100644 --- a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Connection/DatabaseLocksManagerTests.cs +++ b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Connection/DatabaseLocksManagerTests.cs @@ -12,8 +12,8 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Connection { public class DatabaseLocksManagerTests { - private string server1 = "server1"; - private string database1 = "database1"; + private const string server1 = "server1"; + private const string database1 = "database1"; [Fact] public void GainFullAccessShouldDisconnectTheConnections() diff --git a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerServiceTests.cs b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerServiceTests.cs index d359d611..7eb6ed9e 100644 --- a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerServiceTests.cs +++ b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Profiler/ProfilerServiceTests.cs @@ -43,7 +43,7 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler return Task.FromResult(0); }); - // capture listener event notifications + // capture Listener event notifications var mockListener = new Mock(); mockListener.Setup(p => p.EventsAvailable(It.IsAny(), It.IsAny>(), It.IsAny())).Callback(() => { @@ -163,7 +163,7 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler return Task.FromResult(0); }); - // capture listener event notifications + // capture Listener event notifications var mockListener = new Mock(); mockListener.Setup(p => p.EventsAvailable(It.IsAny(), It.IsAny>(), It.IsAny())).Callback(() => { @@ -212,7 +212,7 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler profilerService.SessionMonitor.PollSession(1); - // confirm that no events were sent to paused listener + // confirm that no events were sent to paused Listener Assert.False(recievedEvents); // unpause viewer @@ -229,7 +229,7 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler Thread.Sleep(250); } - // check that events got sent to listener + // check that events got sent to Listener Assert.True(recievedEvents); requestContext.VerifyAll(); @@ -244,7 +244,7 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Profiler bool sessionStopped = false; string testUri = "profiler_uri"; - // capture listener event notifications + // capture Listener event notifications var mockSession = new Mock(); mockSession.Setup(p => p.GetTargetXml()).Callback(() => { diff --git a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/ServiceHost/LoggerTests.cs b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/ServiceHost/LoggerTests.cs index 0ed5e85a..d11ce268 100644 --- a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/ServiceHost/LoggerTests.cs +++ b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/ServiceHost/LoggerTests.cs @@ -2,9 +2,10 @@ // Copyright (c) Microsoft. All rights reserved. // Licensed under the MIT license. See LICENSE file in the project root for full license information. -using System; +using System.Diagnostics; using System.IO; -using System.Linq; +using System.Reflection; +using Microsoft.SqlTools.ServiceLayer.Test.Common; using Microsoft.SqlTools.Utility; using Xunit; @@ -15,48 +16,447 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.ServiceHost /// public class LoggerTests { - /// /// Test to verify that the logger initialization is generating a valid file + /// Verifies that a test log entries is succesfully written to a default log file. /// [Fact] public void LoggerDefaultFile() { - // delete any existing log files from the current directory - Directory.GetFiles(Directory.GetCurrentDirectory()) - .Where(fileName - => fileName.Contains("sqltools_") - && fileName.EndsWith(".log", StringComparison.OrdinalIgnoreCase)) - .ToList() - .ForEach(File.Delete); - - // initialize the logger - Logger.Initialize( - logFilePath: Path.Combine(Directory.GetCurrentDirectory(), "sqltools"), - minimumLogLevel: LogLevel.Verbose); - - // close the logger - Logger.Close(); - - // find the name of the new log file - string logFileName = Directory.GetFiles(Directory.GetCurrentDirectory()) - .SingleOrDefault(fileName => - fileName.Contains("sqltools_") - && fileName.EndsWith(".log", StringComparison.OrdinalIgnoreCase)); - - // validate the log file was created with desired name - Assert.True(!string.IsNullOrWhiteSpace(logFileName)); - if (!string.IsNullOrWhiteSpace(logFileName)) + TestLogger test = new TestLogger() { - Assert.True(logFileName.Length > "sqltools_.log".Length); - Assert.True(File.Exists(logFileName)); + TraceSource = MethodInfo.GetCurrentMethod().Name, + EventType = TraceEventType.Information, + TracingLevel = SourceLevels.Verbose, + }; - // delete the test log file - if (File.Exists(logFileName)) - { - File.Delete(logFileName); - } + test.Initialize(); + test.Write(); + test.Verify(); + test.Cleanup(); + } + + /// + /// Test to verify that the logger initialization works using various possibilities. + /// + [Fact] + public void LoggerTestInitialization() + { + int? testNo = 1; + //Test 1: Initialization with all defaults. Logfile names get autogenerated with the well known prefix. + { + SourceLevels expectedTracingLevel = Logger.defaultTracingLevel; + string expectedTraceSource = Logger.defaultTraceSource; + Logger.Initialize(); + bool isLogFileExpectedToExist = ((uint)expectedTracingLevel >= (uint)SourceLevels.Information); + TestLogger.VerifyInitialization(expectedTracingLevel, expectedTraceSource, Logger.LogFileFullPath, isLogFileExpectedToExist, testNo++); + TestLogger.Cleanup(Logger.LogFileFullPath); } + + //Test 2: Initialization with TracingLevel set to Critical. Logfile names get autogenerated with the well known prefix. Before we do a write at Critical level the logfile must not get even created. + { + SourceLevels expectedTracingLevel = SourceLevels.Critical; + string expectedTraceSource = Logger.defaultTraceSource; + Logger.Initialize(expectedTracingLevel); + bool isLogFileExpectedToExist = ((uint)expectedTracingLevel >= (uint)SourceLevels.Information); + TestLogger.VerifyInitialization(expectedTracingLevel, expectedTraceSource, Logger.LogFileFullPath, isLogFileExpectedToExist, testNo++); + TestLogger.Cleanup(Logger.LogFileFullPath); + } + + //Test 3: Initialization with TraceSourceName set to specified name. Logfile names get autogenerated with the well known prefix. + { + SourceLevels expectedTracingLevel = Logger.defaultTracingLevel; + string expectedTraceSource = nameof(LoggerTestInitialization); + Logger.Initialize(traceSource:expectedTraceSource); + bool isLogFileExpectedToExist = ((uint)expectedTracingLevel >= (uint)SourceLevels.Information); + TestLogger.VerifyInitialization(expectedTracingLevel, expectedTraceSource, Logger.LogFileFullPath, isLogFileExpectedToExist, testNo++); + TestLogger.Cleanup(Logger.LogFileFullPath); + } + + + //Test 4: Initialization with logfile set to specified random filepath. + { + SourceLevels expectedTracingLevel = Logger.defaultTracingLevel; + string expectedTraceSource = Logger.defaultTraceSource; + string logFilePath = Path.Combine(Path.GetRandomFileName(), nameof(LoggerTestInitialization)); + Logger.Initialize(traceSource: expectedTraceSource, logFilePath: logFilePath); + Assert.True(string.Compare(logFilePath, Logger.LogFileFullPath, ignoreCase: true) == 0, "The logfile path of the Logger should be the one specified"); + bool isLogFileExpectedToExist = ((uint)expectedTracingLevel >= (uint)SourceLevels.Information); + TestLogger.VerifyInitialization(expectedTracingLevel, expectedTraceSource, logFilePath, isLogFileExpectedToExist, testNo++); + TestLogger.Cleanup(Logger.LogFileFullPath); + } + + //Test 5: Initialization with logfile generated from log directory and LogFilePrefix using Logger.GenerateLogFielPath method. + { + SourceLevels expectedTracingLevel = Logger.defaultTracingLevel; + string expectedTraceSource = Logger.defaultTraceSource; + string logFilePath = Logger.GenerateLogFilePath(Path.Combine(Directory.GetCurrentDirectory(), nameof(LoggerTestInitialization))); + Assert.True(string.Compare(Path.GetDirectoryName(logFilePath), Directory.GetCurrentDirectory(), ignoreCase: true) == 0, "The directory path of the logfile should match the directory path specified"); + Logger.Initialize(traceSource: expectedTraceSource, logFilePath: logFilePath); + Assert.True(string.Compare(logFilePath, Logger.LogFileFullPath, ignoreCase: true) == 0, "The logfile path of the Logger should be the one specified"); + bool isLogFileExpectedToExist = ((uint)expectedTracingLevel >= (uint)SourceLevels.Information); + TestLogger.VerifyInitialization(expectedTracingLevel, expectedTraceSource, Logger.LogFileFullPath, isLogFileExpectedToExist, testNo++); + TestLogger.Cleanup(Logger.LogFileFullPath); + } + + #region TracingLevel Settings + //Test 6: Initialization tracingLevel specified as a null string. + { + string tracingLevel = null; + SourceLevels expectedTracingLevel = Logger.defaultTracingLevel; + string expectedTraceSource = Logger.defaultTraceSource; + Logger.Initialize(tracingLevel); + bool isLogFileExpectedToExist = false; + TestLogger.VerifyInitialization(expectedTracingLevel, expectedTraceSource, Logger.LogFileFullPath, isLogFileExpectedToExist, testNo++); + TestLogger.Cleanup(Logger.LogFileFullPath); + } + + //Test 7: Initialization tracingLevel specified as an empty string. + { + string tracingLevel = null; + SourceLevels expectedTracingLevel = Logger.defaultTracingLevel; + string expectedTraceSource = Logger.defaultTraceSource; + Logger.Initialize(tracingLevel); + bool isLogFileExpectedToExist = false; + TestLogger.VerifyInitialization(expectedTracingLevel, expectedTraceSource, Logger.LogFileFullPath, isLogFileExpectedToExist, testNo++); + TestLogger.Cleanup(Logger.LogFileFullPath); + } + + //Test 8: Initialization tracingLevel specified as an invalid string. + { + string tracingLevel = "invalid"; + SourceLevels expectedTracingLevel = Logger.defaultTracingLevel; + string expectedTraceSource = Logger.defaultTraceSource; + Logger.Initialize(tracingLevel); + bool isLogFileExpectedToExist = false; + TestLogger.VerifyInitialization(expectedTracingLevel, expectedTraceSource, Logger.LogFileFullPath, isLogFileExpectedToExist, testNo++); + TestLogger.Cleanup(Logger.LogFileFullPath); + } + + //Test 9: Initialization with logfile set to empty string. + { + SourceLevels expectedTracingLevel = SourceLevels.All; + string expectedTraceSource = Logger.defaultTraceSource; + string logFilePath = string.Empty; + Logger.Initialize(traceSource: expectedTraceSource, logFilePath: logFilePath, tracingLevel:expectedTracingLevel); + bool isLogFileExpectedToExist = ((uint)expectedTracingLevel >= (uint)SourceLevels.Information); + TestLogger.VerifyInitialization(expectedTracingLevel, expectedTraceSource, Logger.LogFileFullPath, isLogFileExpectedToExist, testNo++); + TestLogger.Cleanup(Logger.LogFileFullPath); + } + //Test 10: Initialization with logfile set to null. + { + SourceLevels expectedTracingLevel = SourceLevels.All; + string expectedTraceSource = Logger.defaultTraceSource; + string logFilePath = null; + Logger.Initialize(traceSource: expectedTraceSource, logFilePath: logFilePath, tracingLevel: expectedTracingLevel); + bool isLogFileExpectedToExist = ((uint)expectedTracingLevel >= (uint)SourceLevels.Information); + TestLogger.VerifyInitialization(expectedTracingLevel, expectedTraceSource, Logger.LogFileFullPath, isLogFileExpectedToExist, testNo++); + TestLogger.Cleanup(Logger.LogFileFullPath); + } + //Test 11: Initialization with LogDirectory in Logger.GenerateLogFilePath set to empty string. + { + SourceLevels expectedTracingLevel = SourceLevels.All; + string expectedTraceSource = Logger.defaultTraceSource; + string logFilePath = Logger.GenerateLogFilePath(Path.Combine(string.Empty, nameof(LoggerTestInitialization))); + Logger.Initialize(traceSource: expectedTraceSource, logFilePath: logFilePath, tracingLevel: expectedTracingLevel); + Assert.True(string.Compare(logFilePath, Logger.LogFileFullPath, ignoreCase: true) == 0, "The logfile should match the path specified"); + bool isLogFileExpectedToExist = ((uint)expectedTracingLevel >= (uint)SourceLevels.Information); + TestLogger.VerifyInitialization(expectedTracingLevel, expectedTraceSource, Logger.LogFileFullPath, isLogFileExpectedToExist, testNo++); + TestLogger.Cleanup(Logger.LogFileFullPath); + } + #endregion + + } + + /// + /// Test to verify that there is no log file created if TracingLevel is set to off. + /// + [Fact] + public void LoggerTracingLevelOff() + { + TestLogger test = new TestLogger() + { + TraceSource = MethodInfo.GetCurrentMethod().Name, + EventType = TraceEventType.Information, + TracingLevel = SourceLevels.Off, + }; + + test.Initialize(); + test.Write(); + Assert.False(File.Exists(Logger.LogFileFullPath), $"Log file must not exist when tracing level is: {test.TracingLevel}"); + test.Verify(expectLogMessage: false); // The log message should be absent since the tracing level is set to Off. + test.Cleanup(); + } + + /// + /// Test to verify that the tracinglevel setting filters message logged at lower levels. + /// Verifies that a test log entries logged at Information level are not present in log when tracingLevel + /// is set to 'Critical' + /// + [Fact] + public void LoggerInformationalNotLoggedWithCriticalTracingLevel() + { + TestLogger test = new TestLogger() + { + TraceSource = MethodInfo.GetCurrentMethod().Name, + EventType = TraceEventType.Information, + TracingLevel = SourceLevels.Critical, + }; + + test.Initialize(); + test.Write(); + test.Verify(expectLogMessage:false); // The log message should be absent since the tracing level is set to collect messages only at 'Critical' logging level + test.Cleanup(); + } + + /// + /// Test to verify that WriteWithCallstack() method turns on the callstack logging + /// + [Fact] + public void LoggerWithCallstack() + { + TestLogger test = new TestLogger() + { + TraceSource = MethodInfo.GetCurrentMethod().Name, + EventType = TraceEventType.Warning, + TracingLevel = SourceLevels.Information, + }; + + test.Initialize(); + test.WriteWithCallstack(); + test.Verify(); // This should verify the logging of callstack fields as well. + test.Cleanup(); + } + + /// + /// Test to verify that callstack logging is turned on, it does not get logged because tracing level filters them out. + /// + [Fact] + public void LoggerWithCallstackFilteredOut() + { + TestLogger test = new TestLogger() + { + TraceSource = MethodInfo.GetCurrentMethod().Name, + EventType = TraceEventType.Information, + TracingLevel = SourceLevels.Error, + }; + + test.Initialize(); + test.WriteWithCallstack(); + test.Verify(expectLogMessage:false); // The log message and corresponding callstack details should be absent since the tracing level is set to collect messages only at 'Error' logging level + test.Cleanup(); + } + + /// + /// No TraceSource test to verify that WriteWithCallstack() method turns on the callstack logging + /// + [Fact] + public void LoggerNoTraceSourceWithCallstack() + { + TestLogger test = new TestLogger() + { + TraceSource = MethodInfo.GetCurrentMethod().Name, + EventType = TraceEventType.Warning, + TracingLevel = SourceLevels.Information, + DoNotUseTraceSource = true, + }; + + test.Initialize(); + test.WriteWithCallstack(); + test.Verify(); // This should verify the logging of callstack fields as well. + test.Cleanup(); + } + + /// + /// No TraceSrouce test to verify that callstack logging is turned on, it does not get logged because tracing level filters them out. + /// + [Fact] + public void LoggerNoTraceSourceWithCallstackFilteredOut() + { + TestLogger test = new TestLogger() + { + TraceSource = MethodInfo.GetCurrentMethod().Name, + EventType = TraceEventType.Information, + TracingLevel = SourceLevels.Error, + DoNotUseTraceSource = true, + }; + + test.Initialize(); + test.WriteWithCallstack(); + test.Verify(expectLogMessage: false); // The log message and corresponding callstack details should be absent since the tracing level is set to collect messages only at 'Error' logging level + test.Cleanup(); + } + + /// + /// Tests to verify that upon changing TracingLevel from Warning To Error, + /// after the change, messages of Error type are present in the log and those logged with warning type are not present. + /// + [Fact] + public void LoggerTracingLevelFromWarningToError() + { + // setup the test object + TestLogger test = new TestLogger() + { + TraceSource = MethodInfo.GetCurrentMethod().Name, + }; + TestTracingLevelChangeFromWarningToError(test); + } + + /// + /// Tests to verify that upon changing TracingLevel from Error To Warning, + /// after the change, messages of Warning as well as of Error type are present in the log. + /// + [Fact] + public void LoggerTracingLevelFromErrorToWarning() + { + // setup the test object + TestLogger test = new TestLogger() + { + TraceSource = MethodInfo.GetCurrentMethod().Name, + }; + TestTracingLevelChangeFromErrorToWarning(test); + } + + /// + /// When not use TraceSource, test to verify that upon changing TracingLevel from Warning To Error, + /// after the change, messages of Error type are present in the log and those logged with warning type are not present. + /// + [Fact] + public void LoggerNoTraceSourceTracingLevelFromWarningToError() + { + // setup the test object + TestLogger test = new TestLogger() + { + TraceSource = MethodInfo.GetCurrentMethod().Name, + DoNotUseTraceSource = true, + }; + TestTracingLevelChangeFromWarningToError(test); + } + + /// + /// When not use TraceSource, test to verify that upon changing TracingLevel from Error To Warning, + /// after the change, messages of Warning as well as of Error type are present in the log. + /// + [Fact] + public void LoggerNoTraceSourceTracingLevelFromErrorToWarning() + { + // setup the test object + TestLogger test = new TestLogger() + { + TraceSource = MethodInfo.GetCurrentMethod().Name, + DoNotUseTraceSource = true, + }; + TestTracingLevelChangeFromErrorToWarning(test); + } + + private static void TestTracingLevelChangeFromWarningToError(TestLogger test) + { + test.Initialize(); + Logger.TracingLevel = SourceLevels.Warning; + string oldMessage = @"Old Message with Tracing Level set to Warning"; + test.LogMessage = oldMessage; + // Initially with TracingLevel at Warning, logging of Warning type does not get filtered out. + Assert.Equal(SourceLevels.Warning, Logger.TracingLevel); + { + test.EventType = TraceEventType.Warning; + test.Write(); + test.PendingVerifications.Add(() => + { + test.Verify(eventType: TraceEventType.Warning, message: oldMessage, callstackMessage: null, shouldVerifyCallstack: false, expectLogMessage: true); + }); + } + // and logging of Error type also succeeeds + { + test.EventType = TraceEventType.Error; + test.Write(); + test.PendingVerifications.Add(() => + { + test.Verify(eventType: TraceEventType.Error, message: oldMessage, callstackMessage: null, shouldVerifyCallstack: false, expectLogMessage: true); + }); + } + + //Now Update the tracing level to Error. Now logging both of Warning type gets filtered and only Error type should succeed. + Logger.TracingLevel = SourceLevels.Error; + Assert.Equal(SourceLevels.Error, Logger.TracingLevel); + string newMessage = @"New Message After Tracing Level set to Error"; + test.LogMessage = newMessage; + + // Now with TracingLevel at Error, logging of Warning type gets filtered out. + { + test.EventType = TraceEventType.Warning; + test.Write(); + test.PendingVerifications.Add(() => + { + test.Verify(eventType: TraceEventType.Warning, message: newMessage, callstackMessage: null, shouldVerifyCallstack: false, expectLogMessage: false); + }); + } + // but logging of Error type succeeds + { + test.EventType = TraceEventType.Error; + test.Write(); + test.PendingVerifications.Add(() => + { + test.Verify(eventType: TraceEventType.Error, message: newMessage, callstackMessage: null, shouldVerifyCallstack: false, expectLogMessage: true); + }); + } + + test.VerifyPending(); + test.Cleanup(); + } + + private static void TestTracingLevelChangeFromErrorToWarning(TestLogger test) + { + test.Initialize(); + Logger.TracingLevel = SourceLevels.Error; + string oldMessage = @"Old Message with Tracing Level set to Error"; + test.LogMessage = oldMessage; + // Initially with TracingLevel at Error, logging of Warning type gets filtered out. + Assert.Equal(SourceLevels.Error, Logger.TracingLevel); + { + test.EventType = TraceEventType.Warning; + test.Write(); + test.PendingVerifications.Add(() => + { + test.Verify(eventType: TraceEventType.Warning, message: oldMessage, callstackMessage: null, shouldVerifyCallstack: false, expectLogMessage: false); + }); + } + // But logging of Error type succeeeds + { + test.EventType = TraceEventType.Error; + test.Write(); + test.PendingVerifications.Add(() => + { + test.Verify(eventType: TraceEventType.Error, message: oldMessage, callstackMessage: null, shouldVerifyCallstack: false, expectLogMessage: true); + }); + } + + //Now Update the tracing level to Warning. Now logging both of Error type and Warning type should succeed. + Logger.TracingLevel = SourceLevels.Warning; + Assert.Equal(SourceLevels.Warning, Logger.TracingLevel); + string newMessage = @"New Message After Tracing Level set to Warning"; + test.LogMessage = newMessage; + + // Now with TracingLevel at Warning, logging of Warning type does not get filtered out. + { + test.EventType = TraceEventType.Warning; + test.Write(); + test.PendingVerifications.Add(() => + { + test.Verify(eventType: TraceEventType.Warning, message: newMessage, callstackMessage: null, shouldVerifyCallstack: false, expectLogMessage: true); + }); + } + // and logging of Error type also succeeds + { + test.EventType = TraceEventType.Error; + test.Write(); + test.PendingVerifications.Add(() => + { + test.Verify(eventType: TraceEventType.Error, message: newMessage, callstackMessage: null, shouldVerifyCallstack: false, expectLogMessage: true); + }); + } + + test.VerifyPending(); + test.Cleanup(); } } } diff --git a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Utility/CommandOptionsTests.cs b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Utility/CommandOptionsTests.cs index c0a2a3f0..29c45eef 100644 --- a/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Utility/CommandOptionsTests.cs +++ b/test/Microsoft.SqlTools.ServiceLayer.UnitTests/Utility/CommandOptionsTests.cs @@ -14,29 +14,6 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Utility /// public class CommandOptionsTests { - [Fact] - public void LoggingEnabledWhenFlagProvided() - { - var args = new string[] {"--enable-logging"}; - ServiceLayerCommandOptions options = new ServiceLayerCommandOptions(args); - Assert.NotNull(options); - - Assert.True(options.EnableLogging); - Assert.False(options.ShouldExit); - Assert.Equal(options.Locale, string.Empty); - } - - [Fact] - public void LoggingDisabledWhenFlagNotProvided() - { - var args = new string[] {}; - ServiceLayerCommandOptions options = new ServiceLayerCommandOptions(args); - Assert.NotNull(options); - - Assert.False(options.EnableLogging); - Assert.False(options.ShouldExit); - Assert.Equal(options.Locale, string.Empty); - } [Fact] public void UsageIsShownWhenHelpFlagProvided() @@ -63,16 +40,56 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Utility [Fact] public void DefaultValuesAreUsedWhenNoArgumentsAreProvided() { - var args = new string[] {}; - ServiceLayerCommandOptions options = new ServiceLayerCommandOptions(args); - Assert.NotNull(options); - - Assert.False(options.EnableLogging); - Assert.False(options.ShouldExit); - Assert.True(string.IsNullOrWhiteSpace(options.LoggingDirectory)); - Assert.Equal(options.Locale, string.Empty); + int? testNo = 1; + // Test 1: All defaults, no options specified + { + var args = new string[] { }; + ServiceLayerCommandOptions options = new ServiceLayerCommandOptions(args); + VerifyCommandOptions(options, testNo++); + } + // Test 2: All defaults, -logDir as null + { + var args = new string[] { "--log-dir", null }; + ServiceLayerCommandOptions options = new ServiceLayerCommandOptions(args); + VerifyCommandOptions(options, testNo++); + } + // Test 3: All defaults, -logDir as empty string + { + var args = new string[] { "--log-dir", string.Empty }; + ServiceLayerCommandOptions options = new ServiceLayerCommandOptions(args); + VerifyCommandOptions(options, testNo++); + } + // Test 4: All defaults, -log-file as null + { + var args = new string[] { "--log-file", null }; + ServiceLayerCommandOptions options = new ServiceLayerCommandOptions(args); + VerifyCommandOptions(options, testNo++, logFilePath: null); + } + // Test 5: All defaults, -log-file as empty string + { + var args = new string[] { "--log-file", string.Empty }; + ServiceLayerCommandOptions options = new ServiceLayerCommandOptions(args); + VerifyCommandOptions(options, testNo++, logFilePath: string.Empty); + } } - + + private static void VerifyCommandOptions(ServiceLayerCommandOptions options, int? testNo = null, string errorMessage = "", string tracingLevel = null, string logFilePath = null, bool shouldExit = false, string locale = "", string logDirectory = null) + { + Assert.NotNull(options); + string MsgPrefix = testNo != null ? $"TestNo:{testNo} ::" : string.Empty; + Assert.True(errorMessage == options.ErrorMessage, $"{MsgPrefix} options:{nameof(errorMessage)} should be '{errorMessage}'"); + Assert.True(tracingLevel == options.TracingLevel, $"{MsgPrefix} options:{nameof(tracingLevel)} should be '{tracingLevel}'"); + Assert.True(logFilePath == options.LogFilePath, $"{MsgPrefix} options:{nameof(logFilePath)} should be '{logFilePath}'"); + Assert.True(shouldExit == options.ShouldExit, $"{MsgPrefix} options:{nameof(shouldExit)} should be '{shouldExit}'"); + Assert.False(string.IsNullOrWhiteSpace(options.LoggingDirectory)); + if (string.IsNullOrWhiteSpace(logDirectory)) + { + logDirectory = Path.Combine(options.DefaultLogRoot, options.ServiceName); + } + Assert.True(logDirectory == options.LoggingDirectory, $"{MsgPrefix} options:{nameof(logDirectory)} should be '{logDirectory}'"); + Assert.True(options.Locale == locale, $"{MsgPrefix} options:{nameof(locale)} should be '{locale}'"); + } + [Theory] [InlineData("en")] [InlineData("es")] @@ -107,7 +124,6 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Utility // Asserting all options were properly set Assert.NotNull(options); - Assert.False(options.EnableLogging); Assert.False(options.ShouldExit); Assert.Equal(options.Locale, string.Empty); } @@ -124,5 +140,33 @@ namespace Microsoft.SqlTools.ServiceLayer.UnitTests.Utility Assert.False(options.ShouldExit); Assert.Equal(options.LoggingDirectory, logDir); } + + + [Fact] + public void TracingLevelSet() + { + string expectedLevel = "Critical"; + var args = new string[] { "--tracing-level", expectedLevel }; + ServiceLayerCommandOptions options = new ServiceLayerCommandOptions(args); + + // Asserting all options were properly set + Assert.NotNull(options); + Assert.False(options.ShouldExit); + Assert.Equal(options.TracingLevel, expectedLevel); + } + + + [Fact] + public void LogFilePathSet() + { + string expectedFilePath = Path.GetRandomFileName(); + var args = new string[] { "--log-file", expectedFilePath }; + ServiceLayerCommandOptions options = new ServiceLayerCommandOptions(args); + + // Asserting all options were properly set + Assert.NotNull(options); + Assert.False(options.ShouldExit); + Assert.Equal(options.LogFilePath, expectedFilePath); + } } } diff --git a/test/ScriptGenerator/AdventureWorks.sql b/test/ScriptGenerator/AdventureWorks.sql new file mode 100644 index 00000000..2b11b96c Binary files /dev/null and b/test/ScriptGenerator/AdventureWorks.sql differ diff --git a/test/ScriptGenerator/AdventureWorksDbCreate.sql b/test/ScriptGenerator/AdventureWorksDbCreate.sql new file mode 100644 index 00000000..c7baf563 Binary files /dev/null and b/test/ScriptGenerator/AdventureWorksDbCreate.sql differ diff --git a/test/ScriptGenerator/AdventureWorksDbReadWrite.sql b/test/ScriptGenerator/AdventureWorksDbReadWrite.sql new file mode 100644 index 00000000..0bc02d72 Binary files /dev/null and b/test/ScriptGenerator/AdventureWorksDbReadWrite.sql differ diff --git a/test/ScriptGenerator/AdventureWorksStoredProceduresCreate.sql b/test/ScriptGenerator/AdventureWorksStoredProceduresCreate.sql new file mode 100644 index 00000000..689f061a Binary files /dev/null and b/test/ScriptGenerator/AdventureWorksStoredProceduresCreate.sql differ diff --git a/test/ScriptGenerator/AdventureWorksTablesCreate.sql b/test/ScriptGenerator/AdventureWorksTablesCreate.sql new file mode 100644 index 00000000..8d974042 Binary files /dev/null and b/test/ScriptGenerator/AdventureWorksTablesCreate.sql differ diff --git a/test/ScriptGenerator/AdventureWorksViewsCreate.sql b/test/ScriptGenerator/AdventureWorksViewsCreate.sql new file mode 100644 index 00000000..92342052 Binary files /dev/null and b/test/ScriptGenerator/AdventureWorksViewsCreate.sql differ diff --git a/test/ScriptGenerator/CommandOptions.cs b/test/ScriptGenerator/CommandOptions.cs new file mode 100644 index 00000000..03a2fbea --- /dev/null +++ b/test/ScriptGenerator/CommandOptions.cs @@ -0,0 +1,160 @@ +// +// Copyright (c) Microsoft. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. +// + +using System; +using System.Globalization; +using System.IO; + +namespace ScriptGenerator +{ + /// + /// The command-line options helper class. + /// + public class CommandOptions + { + private const string DefaultFilePrefix = "AdventureWorks"; + /// + /// Construct and parse command line options from the arguments array + /// + public CommandOptions(string[] args) + { + ErrorMessage = string.Empty; + try + { + for (int i = 0; i < args.Length; ++i) + { + string arg = args[i]; + if (arg.StartsWith("--") || arg.StartsWith("-")) + { + // Extracting arguments and properties + arg = arg.Substring(1).ToLowerInvariant(); + string argName = arg; + switch (argName) + { + case "-filepathprefix": + case "fp": + FilePathPrefix = args[++i]; + break; + case "-numberofdatabases": + case "-numberofdbs": + case "ndb": + { + if (int.TryParse(args[++i], out int n)) + { + Databases = n; + } + else + { + ErrorMessage += $@"Argument for NumberOfDatabases:'{args[i]}' is not a valid integer"; + } + break; + } + case "-tablesmultiplier": + case "tm": + { + if (int.TryParse(args[++i], out int n)) + { + TablesMultiplier = n; + } + else + { + ErrorMessage += $@"Argument for NumberOfTables:'{args[i]}' is not a valid integer"; + } + break; + } + case "-storedproceduresmultiplier": + case "spm": + { + if (int.TryParse(args[++i], out int n)) + { + StoredProceduresMultiplier = n; + } + else + { + ErrorMessage += $@"Argument for NumberOfStoredProcedures:'{args[i]}' is not a valid integer"; + } + break; + } + case "-viewsmultiplier": + case "vm": + { + if (int.TryParse(args[++i], out int n)) + { + ViewsMultiplier = n; + } + else + { + ErrorMessage += $@"Argument for NumberOfTables:'{args[i]}' is not a valid integer"; + } + + break; + } + case "h": + case "-help": + ShouldExit = true; + return; + default: + ErrorMessage += string.Format("Unknown argument \"{0}\"" + Environment.NewLine, argName); + break; + } + } + } + } + catch (Exception ex) + { + ErrorMessage += ex.ToString(); + return; + } + finally + { + if (!string.IsNullOrEmpty(ErrorMessage) || ShouldExit) + { + Console.WriteLine(Usage); + ShouldExit = true; + } + } + } + + /// + /// Contains any error messages during execution + /// + public string ErrorMessage { get; private set; } + + /// + /// Whether the program should exit immediately. Set to true when the usage is printed. + /// + public bool ShouldExit { get; private set; } + + /// + /// Get the usage string describing command-line arguments for the program + /// + public string Usage + { + get + { + var str = $@"{ErrorMessage}" + Environment.NewLine + + " Options:" + Environment.NewLine + + $@" [--filepathprefix **] (default {DefaultFilePrefix})" + Environment.NewLine + + $@" [-fp **] (default {DefaultFilePrefix})" + Environment.NewLine + + " [--NumberOfDatabases **] (default 1)" + Environment.NewLine + + " [-ndb **] (default 1)" + Environment.NewLine + + " [--TablesMultiplier **] (default 1)" + Environment.NewLine + + " [-tm **] (default 1)" + Environment.NewLine + + " [--ViewsMultiplier **] (default 1)" + Environment.NewLine + + " [-vm **] (default 1)" + Environment.NewLine + + " [--StoreProceduresMultiplier **] (default 1)" + Environment.NewLine + + " [-spm **] (default 1)" + Environment.NewLine + + " [--help]" + Environment.NewLine; + return str; + } + } + + public int Databases { get; private set; } = 1; + public int TablesMultiplier { get; private set; } = 1; + public int StoredProceduresMultiplier { get; private set; } = 1; + public int ViewsMultiplier { get; private set; } = 1; + public string FilePathPrefix { get; private set; } = DefaultFilePrefix; + } +} diff --git a/test/ScriptGenerator/Program.cs b/test/ScriptGenerator/Program.cs new file mode 100644 index 00000000..8e2f0481 --- /dev/null +++ b/test/ScriptGenerator/Program.cs @@ -0,0 +1,57 @@ +using ScriptGenerator.Properties; +using System; +using System.IO; +using System.Text.RegularExpressions; + +namespace ScriptGenerator +{ + + class Program + { + internal const string DefaultFileExtension = "Sql"; + static readonly Regex ExtractDbName = new Regex(@"CREATE\s+DATABASE\s+\[(?\w+)\]", RegexOptions.Compiled | RegexOptions.IgnoreCase); + static readonly Regex CreateTableRegex = new Regex(@"(?CREATE\s+TABLE\s+.*)(?\](?![\.])[\s\S]*?CONSTRAINT\s+\[\w+?)(?\](?![\.]))", RegexOptions.Compiled | RegexOptions.IgnoreCase); + static readonly Regex AlterTableConstraintRegex = new Regex(@"(?ALTER\s+TABLE\s+.*?)(?\](?![\.])\s*\b(?:ADD|WITH|CHECK)\b[\s\S]*?CONSTRAINT\s+\[\w+?)(?\](?![\.]))", RegexOptions.Compiled | RegexOptions.IgnoreCase); + static readonly Regex CreateViewRegex = new Regex(@"(?CREATE\s+VIEW\s+.*?)(?\](?![\.])[\s\S]*?\bAS\b)", RegexOptions.Compiled | RegexOptions.IgnoreCase ); + static readonly Regex CreateProcedureRegex = new Regex(@"(?CREATE\s+PROCEDURE\s+.*?)(?\](?![\.])[\s\S]*?(?:@|WITH|AS))", RegexOptions.Compiled | RegexOptions.IgnoreCase); + static void Main(string[] args) + { + CommandOptions options = new CommandOptions(args); + for (int d = 1; d <= options.Databases; d++) + { + using (StreamWriter writer = new StreamWriter(Path.ChangeExtension($@"{options.FilePathPrefix}{d}", DefaultFileExtension))) + { + string oldDbName = ExtractDbName.Match(Resources.AdventureWorks).Groups["dbName"].Value; + string newDbName = $@"{oldDbName}{d}"; + //Turn Off Strict Clr Mode + writer.WriteLine(Resources.TurnOffClrStrictSecurityMode); + + //Put all original objects in the 'newDbName' database + writer.WriteLine(Resources.AdventureWorks.Replace(oldDbName, newDbName)); + + // Multiple copies of Create Table statements + for (int t = 1; t <= options.TablesMultiplier; t++) + { + string tablesScript = Resources.AdventureWorksTablesCreate.Replace(oldDbName, newDbName); + tablesScript = CreateTableRegex.Replace(tablesScript, "${begin}" + t + "${middle}" + t + "${end}"); + writer.WriteLine(AlterTableConstraintRegex.Replace(tablesScript, "${begin}"+ t + "${middle}" + t + "${end}")); + } + // Multiple copies of Create View statements + for (int v = 1; v <= options.ViewsMultiplier; v++) + { + string viewScript = Resources.AdventureWorksViewsCreate.Replace(oldDbName, newDbName); + writer.WriteLine(CreateViewRegex.Replace(viewScript, "${begin}" + v + "${end}")); + } + // Multiple copies of Create Procedure statements + for (int s = 1; s <= options.StoredProceduresMultiplier; s++) + { + string spScript = Resources.AdventureWorksStoredProceduresCreate.Replace(oldDbName, newDbName); + writer.WriteLine(CreateProcedureRegex.Replace(spScript, "${begin}" + s + "${end}")); + } + //Turn On Strict Clr Mode + writer.WriteLine(Resources.TurnOnClrStrictSecurityMode); + } + } + } + } +} diff --git a/test/ScriptGenerator/Properties/Resources.resx b/test/ScriptGenerator/Properties/Resources.resx new file mode 100644 index 00000000..352b55a8 --- /dev/null +++ b/test/ScriptGenerator/Properties/Resources.resx @@ -0,0 +1,139 @@ + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + text/microsoft-resx + + + 2.0 + + + System.Resources.ResXResourceReader, System.Windows.Forms, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089 + + + System.Resources.ResXResourceWriter, System.Windows.Forms, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089 + + + + ..\AdventureWorks.sql;System.String, mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089;utf-16 + + + ..\AdventureWorksStoredProceduresCreate.sql;System.String, mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089;utf-16 + + + ..\AdventureWorksTablesCreate.sql;System.String, mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089;utf-16 + + + ..\AdventureWorksViewsCreate.sql;System.String, mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089;utf-16 + + + ..\TurnOffClrStrictSecurityMode.sql;System.String, mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089;utf-16 + + + ..\TurnOnClrStrictSecurityMode.sql;System.String, mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089;utf-16 + + \ No newline at end of file diff --git a/test/ScriptGenerator/Properties/launchSettings.json b/test/ScriptGenerator/Properties/launchSettings.json new file mode 100644 index 00000000..2276a4c4 --- /dev/null +++ b/test/ScriptGenerator/Properties/launchSettings.json @@ -0,0 +1,8 @@ +{ + "profiles": { + "ScriptGenerator": { + "commandName": "Project", + "commandLineArgs": "-vm 59 -spm 8 -tm 15 -ndb 200" + } + } +} \ No newline at end of file diff --git a/test/ScriptGenerator/ScriptGenerator.csproj b/test/ScriptGenerator/ScriptGenerator.csproj new file mode 100644 index 00000000..b3f80b52 --- /dev/null +++ b/test/ScriptGenerator/ScriptGenerator.csproj @@ -0,0 +1,23 @@ + + + + Exe + netcoreapp2.1 + + + + + True + True + Resources.resx + + + + + + ResXFileCodeGenerator + Resources.Designer.cs + + + + diff --git a/test/ScriptGenerator/TurnOffClrStrictSecurityMode.sql b/test/ScriptGenerator/TurnOffClrStrictSecurityMode.sql new file mode 100644 index 00000000..7d18b5a0 Binary files /dev/null and b/test/ScriptGenerator/TurnOffClrStrictSecurityMode.sql differ diff --git a/test/ScriptGenerator/TurnOnClrStrictSecurityMode.sql b/test/ScriptGenerator/TurnOnClrStrictSecurityMode.sql new file mode 100644 index 00000000..df67662b Binary files /dev/null and b/test/ScriptGenerator/TurnOnClrStrictSecurityMode.sql differ