Skip to content

Commit 7f2ebd2

Browse files
committed
Start of a PSES log file analyzer
1 parent 487ad1d commit 7f2ebd2

File tree

5 files changed

+464
-23
lines changed

5 files changed

+464
-23
lines changed

src/PowerShellEditorServices.Protocol/MessageProtocol/MessageReader.cs

+25-12
Original file line numberDiff line numberDiff line change
@@ -110,20 +110,33 @@ public async Task<Message> ReadMessage()
110110
// Get the JObject for the JSON content
111111
JObject messageObject = JObject.Parse(messageContent);
112112

113-
// Load the message
114-
this.logger.Write(
115-
LogLevel.Diagnostic,
116-
string.Format(
117-
"READ MESSAGE:\r\n\r\n{0}",
118-
messageObject.ToString(Formatting.Indented)));
119-
120-
// Return the parsed message
113+
// Deserialize the message from the parsed JSON message
121114
Message parsedMessage = this.messageSerializer.DeserializeMessage(messageObject);
122115

123-
this.logger.Write(
124-
LogLevel.Verbose,
125-
$"Received {parsedMessage.MessageType} '{parsedMessage.Method}'" +
126-
(!string.IsNullOrEmpty(parsedMessage.Id) ? $" with id {parsedMessage.Id}" : string.Empty));
116+
// Log message info
117+
var logStrBld =
118+
new StringBuilder(512)
119+
.Append("Received ")
120+
.Append(parsedMessage.MessageType)
121+
.Append(" '").Append(parsedMessage.Method).Append("'");
122+
123+
if (!string.IsNullOrEmpty(parsedMessage.Id))
124+
{
125+
logStrBld.Append(" with id ").Append(parsedMessage.Id);
126+
}
127+
128+
if (this.logger.MinimumConfiguredLogLevel == LogLevel.Diagnostic)
129+
{
130+
string jsonPayload = messageObject.ToString(Formatting.Indented);
131+
logStrBld.Append("\r\n\r\n").Append(jsonPayload);
132+
133+
// Log the JSON representation of the message
134+
this.logger.Write(LogLevel.Diagnostic, logStrBld.ToString());
135+
}
136+
else
137+
{
138+
this.logger.Write(LogLevel.Verbose, logStrBld.ToString());
139+
}
127140

128141
return parsedMessage;
129142
}

src/PowerShellEditorServices.Protocol/MessageProtocol/MessageWriter.cs

+26-11
Original file line numberDiff line numberDiff line change
@@ -58,20 +58,35 @@ public async Task WriteMessage(Message messageToWrite)
5858
this.messageSerializer.SerializeMessage(
5959
messageToWrite);
6060

61-
this.logger.Write(
62-
LogLevel.Verbose,
63-
$"Writing {messageToWrite.MessageType} '{messageToWrite.Method}'" +
64-
(!string.IsNullOrEmpty(messageToWrite.Id) ? $" with id {messageToWrite.Id}" : string.Empty));
65-
66-
// Log the JSON representation of the message
67-
this.logger.Write(
68-
LogLevel.Diagnostic,
69-
string.Format(
70-
"WRITE MESSAGE:\r\n\r\n{0}",
61+
// Log message info
62+
var logStrBld =
63+
new StringBuilder(512)
64+
.Append("Writing ")
65+
.Append(messageToWrite.MessageType)
66+
.Append(" '").Append(messageToWrite.Method).Append("'");
67+
68+
if (!string.IsNullOrEmpty(messageToWrite.Id))
69+
{
70+
logStrBld.Append(" with id ").Append(messageToWrite.Id);
71+
}
72+
73+
if (this.logger.MinimumConfiguredLogLevel == LogLevel.Diagnostic)
74+
{
75+
string jsonPayload =
7176
JsonConvert.SerializeObject(
7277
messageObject,
7378
Formatting.Indented,
74-
Constants.JsonSerializerSettings)));
79+
Constants.JsonSerializerSettings);
80+
81+
logStrBld.Append("\r\n\r\n").Append(jsonPayload);
82+
83+
// Log the JSON representation of the message
84+
this.logger.Write(LogLevel.Diagnostic, logStrBld.ToString());
85+
}
86+
else
87+
{
88+
this.logger.Write(LogLevel.Verbose, logStrBld.ToString());
89+
}
7590

7691
string serializedMessage =
7792
JsonConvert.SerializeObject(
+178
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,178 @@
1+
2+
$peekBuf = $null
3+
$currentLineNum = 1
4+
5+
function Parse-PsesLog {
6+
param(
7+
# Specifies a path to one or more PSES EditorServices log files.
8+
[Parameter(Mandatory=$true, Position=0)]
9+
[Alias("PSPath")]
10+
[ValidateNotNullOrEmpty()]
11+
[string]
12+
$Path
13+
)
14+
15+
begin {
16+
17+
# Example log entry start:
18+
# 2018-11-24 12:26:58.302 [DIAGNOSTIC] tid:28 in 'ReadMessage' C:\Users\Keith\GitHub\rkeithhill\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs:114:
19+
$logEntryRegex =
20+
[regex]::new(
21+
'(?<ts>[^\[]+)\[(?<lev>([^\]]+))\]\s+tid:(?<tid>\d+)\s+in\s+''(?<meth>\w+)''\s+(?<file>..[^:]+):(?<line>\d+)',
22+
[System.Text.RegularExpressions.RegexOptions]::Compiled -bor [System.Text.RegularExpressions.RegexOptions]::IgnoreCase)
23+
24+
$filestream =
25+
[System.IO.FileStream]::new(
26+
$Path,
27+
[System.IO.FileMode]:: Open,
28+
[System.IO.FileAccess]::Read,
29+
[System.IO.FileShare]::ReadWrite,
30+
4096,
31+
[System.IO.FileOptions]::SequentialScan)
32+
33+
$streamReader = [System.IO.StreamReader]::new($filestream, [System.Text.Encoding]::UTF8)
34+
35+
function nextLine() {
36+
if ($null -ne $peekBuf) {
37+
$line = $peekBuf
38+
$script:peekBuf = $null
39+
}
40+
else {
41+
$line = $streamReader.ReadLine()
42+
}
43+
44+
$script:currentLineNum += 1
45+
$line
46+
}
47+
48+
function peekLine() {
49+
if ($null -ne $peekBuf) {
50+
$line = $peekBuf;
51+
}
52+
else {
53+
$line = $script:peekBuf = $streamReader.ReadLine()
54+
}
55+
56+
$line
57+
}
58+
59+
function parseLogEntryStart([string]$line) {
60+
while ($line -notmatch $logEntryRegex) {
61+
Write-Warning "Ignoring line: '$line'"
62+
$line = nextLine
63+
}
64+
65+
[string]$timestampStr = $matches["ts"]
66+
[DateTime]$timestamp = $timestampStr
67+
[PsesLogLevel]$logLevel = $matches["lev"]
68+
[int]$threadId = $matches["tid"]
69+
[string]$method = $matches["meth"]
70+
[string]$file = $matches["file"]
71+
[int]$lineNumber = $matches["line"]
72+
73+
$message = parseMessage $method
74+
75+
[PsesLogEntry]::new($timestamp, $timestampStr, $logLevel, $threadId, $method, $file, $lineNumber,
76+
$message.MessageType, $message.Message)
77+
}
78+
79+
function parseMessage([string]$Method) {
80+
$result = [PSCustomObject]@{
81+
MessageType = [PsesMessageType]::Log
82+
Message = $null
83+
}
84+
85+
$line = nextLine
86+
if ($null -eq $line) {
87+
Write-Warning "$($MyInvocation.MyCommand.Name) encountered end of file early."
88+
return $result
89+
}
90+
91+
if (($Method -eq 'ReadMessage') -and
92+
($line -match '\s+Received Request ''(?<msg>[^'']+)'' with id (?<id>\d+)')) {
93+
$result.MessageType = [PsesMessageType]::Request
94+
$msg = $matches["msg"]
95+
$id = $matches["id"]
96+
$json = parseJsonMessageBody
97+
$result.Message = [PsesJsonRpcMessage]::new($msg, $id, $json)
98+
}
99+
elseif (($Method -eq 'ReadMessage') -and
100+
($line -match '\s+Received event ''(?<msg>[^'']+)''')) {
101+
$result.MessageType = [PsesMessageType]::Notification
102+
$msg = $matches["msg"]
103+
$json = parseJsonMessageBody
104+
$result.Message = [PsesNotificationMessage]::new($msg, [PsesNotificationSource]::Client, $json)
105+
}
106+
elseif (($Method -eq 'WriteMessage') -and
107+
($line -match '\s+Writing Response ''(?<msg>[^'']+)'' with id (?<id>\d+)')) {
108+
$result.MessageType = [PsesMessageType]::Response
109+
$msg = $matches["msg"]
110+
$id = $matches["id"]
111+
$json = parseJsonMessageBody
112+
$result.Message = [PsesJsonRpcMessage]::new($msg, $id, $json)
113+
}
114+
elseif (($Method -eq 'WriteMessage') -and
115+
($line -match '\s+Writing event ''(?<msg>[^'']+)''')) {
116+
$result.MessageType = [PsesMessageType]::Notification
117+
$msg = $matches["msg"]
118+
$json = parseJsonMessageBody
119+
$result.Message = [PsesNotificationMessage]::new($msg, [PsesNotificationSource]::Server, $json)
120+
}
121+
else {
122+
$result.MessageType = [PsesMessageType]::Log
123+
$body = parseMessageBody $line
124+
$result.Message = [PsesLogMessage]::new($body)
125+
}
126+
127+
$result
128+
}
129+
130+
function parseMessageBody([string]$startLine = '') {
131+
$result = $startLine
132+
try {
133+
while ($true) {
134+
$peekLine = peekLine
135+
if ($null -eq $peekLine) {
136+
break
137+
}
138+
139+
if ($peekLine -match $logEntryRegex) {
140+
break
141+
}
142+
143+
$result += (nextLine) + "`r`n"
144+
}
145+
146+
}
147+
catch {
148+
Write-Error "Failed parsing message body with error: $_"
149+
}
150+
151+
$result.Trim()
152+
}
153+
154+
function parseJsonMessageBody() {
155+
$obj = $null
156+
157+
try {
158+
$result = parseMessageBody
159+
$obj = $result.Trim() | ConvertFrom-Json
160+
}
161+
catch {
162+
Write-Error "Failed parsing JSON message body with error: $_"
163+
}
164+
165+
$obj
166+
}
167+
}
168+
169+
process {
170+
while ($null -ne ($line = nextLine)) {
171+
parseLogEntryStart $line
172+
}
173+
}
174+
175+
end {
176+
if ($streamReader) { $streamReader.Dispose() }
177+
}
178+
}
+123
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,123 @@
1+
#
2+
# Module manifest for module 'Pses-LogAnalyzer'
3+
#
4+
# Generated by: Keith
5+
#
6+
# Generated on: 11/23/2018
7+
#
8+
9+
@{
10+
11+
# Script module or binary module file associated with this manifest.
12+
RootModule = 'PsesLogAnalyzer.psm1'
13+
14+
# Version number of this module.
15+
ModuleVersion = '1.0.0'
16+
17+
# Supported PSEditions
18+
# CompatiblePSEditions = @()
19+
20+
# ID used to uniquely identify this module
21+
GUID = '99116548-ad0f-4087-a425-7edab3aa9e57'
22+
23+
# Author of this module
24+
Author = 'Microsoft'
25+
26+
# Company or vendor of this module
27+
CompanyName = 'Microsoft'
28+
29+
# Copyright statement for this module
30+
Copyright = '(c) 2017 Microsoft. All rights reserved.'
31+
32+
# Description of the functionality provided by this module
33+
# Description = ''
34+
35+
# Minimum version of the PowerShell engine required by this module
36+
# PowerShellVersion = ''
37+
38+
# Name of the PowerShell host required by this module
39+
# PowerShellHostName = ''
40+
41+
# Minimum version of the PowerShell host required by this module
42+
# PowerShellHostVersion = ''
43+
44+
# Minimum version of Microsoft .NET Framework required by this module. This prerequisite is valid for the PowerShell Desktop edition only.
45+
# DotNetFrameworkVersion = ''
46+
47+
# Minimum version of the common language runtime (CLR) required by this module. This prerequisite is valid for the PowerShell Desktop edition only.
48+
# CLRVersion = ''
49+
50+
# Processor architecture (None, X86, Amd64) required by this module
51+
# ProcessorArchitecture = ''
52+
53+
# Modules that must be imported into the global environment prior to importing this module
54+
# RequiredModules = @()
55+
56+
# Assemblies that must be loaded prior to importing this module
57+
# RequiredAssemblies = @()
58+
59+
# Script files (.ps1) that are run in the caller's environment prior to importing this module.
60+
# ScriptsToProcess = @()
61+
62+
# Type files (.ps1xml) to be loaded when importing this module
63+
# TypesToProcess = @()
64+
65+
# Format files (.ps1xml) to be loaded when importing this module
66+
# FormatsToProcess = @()
67+
68+
# Modules to import as nested modules of the module specified in RootModule/ModuleToProcess
69+
# NestedModules = @()
70+
71+
# Functions to export from this module, for best performance, do not use wildcards and do not delete the entry, use an empty array if there are no functions to export.
72+
FunctionsToExport = @('Parse-PsesLog')
73+
74+
# Cmdlets to export from this module, for best performance, do not use wildcards and do not delete the entry, use an empty array if there are no cmdlets to export.
75+
CmdletsToExport = @()
76+
77+
# Variables to export from this module
78+
VariablesToExport = ''
79+
80+
# Aliases to export from this module, for best performance, do not use wildcards and do not delete the entry, use an empty array if there are no aliases to export.
81+
AliasesToExport = @()
82+
83+
# DSC resources to export from this module
84+
# DscResourcesToExport = @()
85+
86+
# List of all modules packaged with this module
87+
# ModuleList = @()
88+
89+
# List of all files packaged with this module
90+
# FileList = @()
91+
92+
# Private data to pass to the module specified in RootModule/ModuleToProcess. This may also contain a PSData hashtable with additional module metadata used by PowerShell.
93+
PrivateData = @{
94+
95+
PSData = @{
96+
97+
# Tags applied to this module. These help with module discovery in online galleries.
98+
# Tags = @()
99+
100+
# A URL to the license for this module.
101+
# LicenseUri = ''
102+
103+
# A URL to the main website for this project.
104+
# ProjectUri = ''
105+
106+
# A URL to an icon representing this module.
107+
# IconUri = ''
108+
109+
# ReleaseNotes of this module
110+
# ReleaseNotes = ''
111+
112+
} # End of PSData hashtable
113+
114+
} # End of PrivateData hashtable
115+
116+
# HelpInfo URI of this module
117+
# HelpInfoURI = ''
118+
119+
# Default prefix for commands exported from this module. Override the default prefix using Import-Module -Prefix.
120+
# DefaultCommandPrefix = ''
121+
122+
}
123+

0 commit comments

Comments
 (0)