Fix parsing win event log message (#627)

* Fix win event message to insert strings for placeholders

* Add test cases for insertion strings

* Add comment to insertPlaceholderValues

* Update test and test cases for insertPlaceholderValues

* Add UserData as a source of insertion strings

* Fix typo in comments. Update comments. Rename variable names

* Add test cases for EventData/UserData in windowsEventLogRecord

* Fix pointer issue in TestUnmarshalWinEvtRecord

plugins/inputs/windows_event_log/wineventlog/utils.go

@@ -11,6 +11,8 @@ import (
 	"fmt"
 	"io/ioutil"
 	"log"
+	"strconv"
+	"strings"
 	"syscall"
 	"time"
 
@@ -168,3 +170,52 @@ func WindowsEventLogLevelName(levelId int32) string {
 		return UNKNOWN
 	}
 }
+
+// insertPlaceholderValues formats the message with the correct values if we see those data
+// in evtDataValues.
+//
+// In some cases wevtapi does not insert values when formatting the message. The message
+// 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
+func insertPlaceholderValues(rawMessage string, evtDataValues []Datum) string {
+	if len(evtDataValues) == 0 || len(rawMessage) == 0 {
+		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') {
+			// 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
+			}
+		} else {
+			if c == '%' {
+				sb.WriteString(rawMessage[prevIndex:i])
+				searchingIndex = true
+				prevIndex = i
+			}
+
+		}
+	}
+	// handle the slice since the last `%` to the end of rawMessage
+	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()
+}

plugins/inputs/windows_event_log/wineventlog/utils_test.go

@@ -77,6 +77,58 @@ func TestFullBufferUsedWithHalfUsedSizeReturned(t *testing.T) {
 	assert.Equal(t, bufferUsed, len(str))
 }
 
+func TestInsertPlaceholderValues(t *testing.T) {
+	evtDataValues := []Datum{
+		{"value_1"}, {"value_2"}, {"value_3"}, {"value_4"},
+	}
+	tests := []struct {
+		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",
+		},
+		{
+			"String without a placeholder should remain the same after insertion",
+			"This is a sentence without placeholders",
+			"This is a sentence without placeholders",
+		},
+		{
+			"Empty string should remain the same",
+			"",
+			"",
+		},
+		{
+			"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%",
+		},
+		{
+			"Characters after a % other than numbers should be ignored",
+			"%foo, %foo1, %#$%^&1",
+			"%foo, %foo1, %#$%^&1",
+		},
+	}
+	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
 }

plugins/inputs/windows_event_log/wineventlog/wineventlog.go

@@ -328,18 +328,28 @@ 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
+	// Notes on the insertion strings:
+	// - The EvtFormatMessage has the valueCount and values parameters, yet it does not work when we tried passing
+	//   EventData/UserData into those parameters. We can later do more research on making EvtFormatMessage with
+	//   valueCount and values parameters works and compare if there is any benefit.
+	dataValues := newRecord.EventData.Data
+	// The UserData section is used if EventData is empty
+	if len(dataValues) == 0 {
+		dataValues = newRecord.UserData.Data
+	}
 	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)
 	}

plugins/inputs/windows_event_log/wineventlog/wineventlogrecord.go

@@ -7,6 +7,7 @@
 package wineventlog
 
 import (
+	"encoding/xml"
 	"fmt"
 	"strconv"
 	"time"
@@ -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 {
@@ -78,3 +82,46 @@ func (record *windowsEventLogRecord) Value() (valueString string, err error) {
 func (record *windowsEventLogRecord) Timestamp() string {
 	return fmt.Sprint(record.System.TimeCreated.SystemTime.UnixNano())
 }
+
+type Datum struct {
+	Value string `xml:",chardata"`
+}
+
+type EventData struct {
+	Data []Datum `xml:",any"`
+}
+
+type UserData struct {
+	Data []Datum `xml:",any"`
+}
+
+// UnmarshalXML unmarshals the UserData section in the windows event xml to UserData struct
+//
+// UserData has slightly different schema than EventData so that we need to override this
+// 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 {
+	in := EventData{}
+
+	// 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.Data = in.Data
+			d.Skip()
+			break
+		}
+	}
+
+	return nil
+}

plugins/inputs/windows_event_log/wineventlog/wineventlogrecord_test.go

@@ -0,0 +1,67 @@
+// Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved.
+// SPDX-License-Identifier: MIT
+
+//go:build windows
+// +build windows
+
+package wineventlog
+
+import (
+	"encoding/xml"
+	"github.com/stretchr/testify/assert"
+	"testing"
+)
+
+func TestUnmarshalWinEvtRecord(t *testing.T) {
+	tests := []struct {
+		xml        string
+		wEvtRecord windowsEventLogRecord
+	}{
+		{
+			xml: `
+<Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'>
+    <EventData>
+        <Data Name='param1'>2022-10-28T22:33:25Z</Data>
+        <Data Name='param2'>RulesEngine</Data>
+        <Data Name='param3'>2</Data>
+    </EventData>
+</Event>
+			`,
+			wEvtRecord: windowsEventLogRecord{
+				EventData: EventData{
+					Data: []Datum{
+						{"2022-10-28T22:33:25Z"},
+						{"RulesEngine"},
+						{"2"},
+					},
+				},
+			},
+		},
+		{
+			xml: `
+<Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'>
+    <UserData>
+        <RmSessionEvent xmlns='http://www.microsoft.com/2005/08/Windows/Reliability/RestartManager/'>
+            <RmSessionId>0</RmSessionId>
+            <UTCStartTime>2022-10-26T20:24:13.4253261Z</UTCStartTime>
+        </RmSessionEvent>
+    </UserData>
+</Event>
+			`,
+			wEvtRecord: windowsEventLogRecord{
+				UserData: UserData{
+					Data: []Datum{
+						{"0"},
+						{"2022-10-26T20:24:13.4253261Z"},
+					},
+				},
+			},
+		},
+	}
+
+	for _, test := range tests {
+		var record windowsEventLogRecord
+		xml.Unmarshal([]byte(test.xml), &record)
+		assert.Equal(t, test.wEvtRecord, record)
+	}
+}