From e5053cb42f4b7db67e7c71d16e0eaf50b296830c Mon Sep 17 00:00:00 2001 From: Keith Hill Date: Sun, 4 Nov 2018 17:21:26 -0700 Subject: [PATCH 1/2] Add managed thread id to log output to add debugging threading issues Also update format to display method before filename, makes it easy to visually scan the log to see what is going on. --- .../Utility/PsesLogger.cs | 21 ++++++++++--------- 1 file changed, 11 insertions(+), 10 deletions(-) diff --git a/src/PowerShellEditorServices/Utility/PsesLogger.cs b/src/PowerShellEditorServices/Utility/PsesLogger.cs index 2d00e57b2..32f4012f2 100644 --- a/src/PowerShellEditorServices/Utility/PsesLogger.cs +++ b/src/PowerShellEditorServices/Utility/PsesLogger.cs @@ -1,6 +1,7 @@ using System; using System.Runtime.CompilerServices; using System.Text; +using System.Threading; using Serilog.Core; namespace Microsoft.PowerShell.EditorServices.Utility @@ -54,27 +55,27 @@ public void Write( string indentedLogMsg = IndentMsg(logMessage); string logLevelName = logLevel.ToString().ToUpper(); + int threadId = Thread.CurrentThread.ManagedThreadId; + + string messageTemplate = + "[{LogLevelName:l}] [tid:{threadId}] In method '{CallerName:l}' {CallerSourceFile:l}:{CallerLineNumber}:{IndentedLogMsg:l}"; + switch (logLevel) { case LogLevel.Diagnostic: - _logger.Verbose("[{LogLevelName:l}] {CallerSourceFile:l}: In method '{CallerName:l}', line {CallerLineNumber}:{IndentedLogMsg:l}", - logLevelName, callerSourceFile, callerName, callerLineNumber, indentedLogMsg); + _logger.Verbose(messageTemplate, logLevelName, threadId, callerName, callerSourceFile, callerLineNumber, indentedLogMsg); return; case LogLevel.Verbose: - _logger.Debug("[{LogLevelName:l}] {CallerSourceFile:l}: In method '{CallerName:l}', line {CallerLineNumber}:{IndentedLogMsg:l}", - logLevelName, callerSourceFile, callerName, callerLineNumber, indentedLogMsg); + _logger.Debug(messageTemplate, logLevelName, threadId, callerName, callerSourceFile, callerLineNumber, indentedLogMsg); return; case LogLevel.Normal: - _logger.Information("[{LogLevelName:l}] {CallerSourceFile:l}: In method '{CallerName:l}', line {CallerLineNumber}:{IndentedLogMsg:l}", - logLevelName, callerSourceFile, callerName, callerLineNumber, indentedLogMsg); + _logger.Information(messageTemplate, logLevelName, threadId, callerName, callerSourceFile, callerLineNumber, indentedLogMsg); return; case LogLevel.Warning: - _logger.Warning("[{LogLevelName:l}] {CallerSourceFile:l}: In method '{CallerName:l}', line {CallerLineNumber}:{IndentedLogMsg:l}", - logLevelName, callerSourceFile, callerName, callerLineNumber, indentedLogMsg); + _logger.Warning(messageTemplate, logLevelName, threadId, callerName, callerSourceFile, callerLineNumber, indentedLogMsg); return; case LogLevel.Error: - _logger.Error("[{LogLevelName:l}] {CallerSourceFile:l}: In method '{CallerName:l}', line {CallerLineNumber}:{IndentedLogMsg:l}", - logLevelName, callerSourceFile, callerName, callerLineNumber, indentedLogMsg); + _logger.Error(messageTemplate, logLevelName, threadId, callerName, callerSourceFile, callerLineNumber, indentedLogMsg); return; } } From 35cd7f3df486f7cd2205cc0c81f6b840c9f85c17 Mon Sep 17 00:00:00 2001 From: Keith Hill Date: Sat, 10 Nov 2018 13:03:53 -0700 Subject: [PATCH 2/2] Lessen log output a bit - remove 'method' and [] around the thread id --- src/PowerShellEditorServices/Utility/PsesLogger.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/PowerShellEditorServices/Utility/PsesLogger.cs b/src/PowerShellEditorServices/Utility/PsesLogger.cs index 32f4012f2..b7ad8f6b2 100644 --- a/src/PowerShellEditorServices/Utility/PsesLogger.cs +++ b/src/PowerShellEditorServices/Utility/PsesLogger.cs @@ -58,7 +58,7 @@ public void Write( int threadId = Thread.CurrentThread.ManagedThreadId; string messageTemplate = - "[{LogLevelName:l}] [tid:{threadId}] In method '{CallerName:l}' {CallerSourceFile:l}:{CallerLineNumber}:{IndentedLogMsg:l}"; + "[{LogLevelName:l}] tid:{threadId} in '{CallerName:l}' {CallerSourceFile:l}:{CallerLineNumber}:{IndentedLogMsg:l}"; switch (logLevel) {