Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix parsing win event log message #627

Merged
merged 10 commits into from
Nov 2, 2022
51 changes: 51 additions & 0 deletions plugins/inputs/windows_event_log/wineventlog/utils.go
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,8 @@ import (
"fmt"
"io/ioutil"
"log"
"strconv"
"strings"
"syscall"
"time"

Expand Down Expand Up @@ -168,3 +170,52 @@ func WindowsEventLogLevelName(levelId int32) string {
return UNKNOWN
}
}

// In some cases wevtapi does not insert values when formatting the message. The message
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
// will contain insertion string placeholders, of the form %n, where %1 indicates the first
// insertion string, and so on. Noted that wevtapi start the index with 1.
// https://learn.microsoft.com/en-us/windows/win32/eventlog/event-identifiers#insertion-strings
//
// If we see those data in the `EventData` section, `insertPlaceholderValues` format the message
// with the correct values
func insertPlaceholderValues(rawMessage string, evtDataValues []Data) string {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

IMO, would it be better to use regexp with FindAllString and replaces as we go? It shares the same time complexity in the code and avoid special condition. (e.g regexp with %d)

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should not be measuring purely on time complexity. We should proof it out with benchmark tests to verify CPU and mem usage.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Agree. Benchmark would be a better data for weighing the decisions.

if len(evtDataValues) == 0 {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nit: Consider checking the rawMessage for % as well to see if we can skip this entire section.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That's true. I was thinking checking % would iterate through the strings first and iterate again when inserting values. This would make it a O(2n) time. But I guess although it would be O(n) without checking %, re-constructing the string for rawMessage without % also takes time/resouce

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

2nd thought on this. I'm keeping the current implementation for rawMessage without % since :

  • it will jump only do
    sb.WriteString(rawMessage[0:])
    
    after iterating through rawMessage only once and return sb.String()
  • So in the case there are not any %, it's doing almost the same as !strings.Contains(rawMessage, "%"). But in case there are any %, it is going to iterate each character of rawMessage twice.

return rawMessage
}
var sb strings.Builder
prevIndex := 0
searchingIndex := false
for i, c := range rawMessage {
// found `%` previously. Determine the index number from the following character(s)
if searchingIndex && (c > '9' || c < '0') {
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
// Convert the Slice since the last `%` and see if it's a valid number.
ind, err := strconv.Atoi(rawMessage[prevIndex+1 : i])
// If the index is in [1 - len(evtDataValues)], get it from evtDataValues.
if err == nil && ind <= len(evtDataValues) && ind > 0 {
sb.WriteString(evtDataValues[ind-1].Value)
} else {
sb.WriteString(rawMessage[prevIndex:i])
}
prevIndex = i
// In case of consecutive `%`, continue searching for the next index
if c != '%' {
searchingIndex = false
}
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
} else {
if c == '%' {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nit: This could be else if.

sb.WriteString(rawMessage[prevIndex:i])
searchingIndex = true
prevIndex = i
}

}
}
// handle the slice sine the last `%` to the end of rawMessage
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
ind, err := strconv.Atoi(rawMessage[prevIndex+1:])
if searchingIndex && err == nil && ind <= len(evtDataValues) && ind > 0 {
sb.WriteString(evtDataValues[ind-1].Value)
} else {
sb.WriteString(rawMessage[prevIndex:])
}
return sb.String()
}
37 changes: 37 additions & 0 deletions plugins/inputs/windows_event_log/wineventlog/utils_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -77,6 +77,43 @@ func TestFullBufferUsedWithHalfUsedSizeReturned(t *testing.T) {
assert.Equal(t, bufferUsed, len(str))
}

func TestInsertPlaceholderValues(t *testing.T) {
evtDataValues := []Data{
{"value_1"}, {"value_2"}, {"value_3"}, {"value_4"},
}
tests := []struct {
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
name string
message string
expected string
}{
{
"Placeholders %{number} should be replaced by insertion strings",
"Service %1 in region %3 stop at %2",
"Service value_1 in region value_3 stop at value_2",
},
{
"Index should start from 1 and less than or equal to the amount of values in event data",
"%0 %3 %5",
"%0 value_3 %5",
},
{
"Handle consecutive % characters",
"%1 %%3% %2",
"value_1 %value_3% value_2",
},
{
"Handle % character at the end of message",
"%3 %2%",
"value_3 value_2%",
},
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
}
for _, tc := range tests {
t.Run(tc.name, func(t *testing.T) {
assert.Equal(t, tc.expected, insertPlaceholderValues(tc.message, evtDataValues))
})
}
}

func resetState() {
NumberOfBytesPerCharacter = 0
}
10 changes: 8 additions & 2 deletions plugins/inputs/windows_event_log/wineventlog/wineventlog.go
Original file line number Diff line number Diff line change
Expand Up @@ -328,18 +328,24 @@ func (w *windowsEventLog) getRecord(evtHandle EvtHandle) (*windowsEventLogRecord
return nil, fmt.Errorf("utf16ToUTF8Bytes() err %v", err)
}

// The insertion strings could be in either EventData or UserData
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
dataValues := newRecord.EventData.Values
// The UserData section is used if EventData is empty
if len(dataValues) == 0 {
dataValues = newRecord.UserData.Values
}
switch w.renderFormat {
case FormatXml, FormatDefault:
//XML format
newRecord.XmlFormatContent = string(descriptionBytes)
newRecord.XmlFormatContent = insertPlaceholderValues(string(descriptionBytes), dataValues)
case FormatPlainText:
//old SSM agent Windows format
var recordMessage eventMessage
err = xml.Unmarshal(descriptionBytes, &recordMessage)
if err != nil {
return nil, fmt.Errorf("Unmarshal() err %v", err)
}
newRecord.System.Description = recordMessage.Message
newRecord.System.Description = insertPlaceholderValues(recordMessage.Message, dataValues)
default:
return nil, fmt.Errorf("renderFormat is not recognized, %s", w.renderFormat)
}
Expand Down
48 changes: 48 additions & 0 deletions plugins/inputs/windows_event_log/wineventlog/wineventlogrecord.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
package wineventlog

import (
"encoding/xml"
"fmt"
"strconv"
"time"
Expand Down Expand Up @@ -45,6 +46,9 @@ type windowsEventLogRecord struct {
Name string `xml:"Name,attr"`
} `xml:"Provider"`
} `xml:"System"`

EventData EventData `xml:"EventData"`
UserData UserData `xml:"UserData"`
}

func newEventLogRecord(l *windowsEventLog) *windowsEventLogRecord {
Expand Down Expand Up @@ -78,3 +82,47 @@ func (record *windowsEventLogRecord) Value() (valueString string, err error) {
func (record *windowsEventLogRecord) Timestamp() string {
return fmt.Sprint(record.System.TimeCreated.SystemTime.UnixNano())
}

type EventData struct {
Values []Data `xml:",any"`
}

type UserData struct {
Values []Data `xml:",any"`
}

// UserData has slightly different schema than EventData so that we need to overrid this
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
// unmarshal function to get similar structure
//
// https://learn.microsoft.com/en-us/windows/win32/wes/eventschema-userdatatype-complextype
// https://learn.microsoft.com/en-us/windows/win32/wes/eventschema-eventdatatype-complextype
func (u *UserData) UnmarshalXML(d *xml.Decoder, start xml.StartElement) error {
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
in := struct {
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
Values []Data `xml:",any"`
}{}

// Read tokens until we find the first StartElement then unmarshal it.
for {
t, err := d.Token()
if err != nil {
return err
}

if se, ok := t.(xml.StartElement); ok {
err = d.DecodeElement(&in, &se)
if err != nil {
return err
}

u.Values = in.Values
d.Skip()
break
}
}

return nil
}

type Data struct {
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
taohungyang marked this conversation as resolved.
Show resolved Hide resolved
Value string `xml:",chardata"`
}