fix truncated event log message (#41327) (#41367)

* fix truncated event log

* changelog

* fix warning

* fix golint

* playing hide an catch with CI

* size in bytes

* review

* code review

* add comment, unify code path

* refactor code

(cherry picked from commit 99d11eb)

Co-authored-by: Leszek Kubik <[email protected]>

CHANGELOG.next.asciidoc

@@ -83,6 +83,7 @@ https://github.com/elastic/beats/compare/v8.8.1\...main[Check the HEAD diff]
 *Winlogbeat*
 
 - Add "event.category" and "event.type" to Sysmon module for EventIDs 8, 9, 19, 20, 27, 28, 255 {pull}35193[35193]
+- Fix truncated windows event log message {pull}41327[41327]
 
 *Functionbeat*
 

winlogbeat/eventlog/wineventlog.go

@@ -62,8 +62,7 @@ var (
 
 const (
 	// renderBufferSize is the size in bytes of the buffer used to render events.
-	renderBufferSize = 1 << 14
-
+	renderBufferSize = 1 << 19 // 512KB, 256K wide characters
 	// winEventLogApiName is the name used to identify the Windows Event Log API
 	// as both an event type and an API.
 	winEventLogAPIName = "wineventlog"
@@ -448,14 +447,6 @@ func (l *winEventLog) Read() ([]Record, error) {
 	for _, h := range handles {
 		l.outputBuf.Reset()
 		err := l.render(h, l.outputBuf)
-		var bufErr sys.InsufficientBufferError
-		if errors.As(err, &bufErr) {
-			detailf("%s Increasing render buffer size to %d", l.logPrefix,
-				bufErr.RequiredSize)
-			l.renderBuf = make([]byte, bufErr.RequiredSize)
-			l.outputBuf.Reset()
-			err = l.render(h, l.outputBuf)
-		}
 		l.metrics.logError(err)
 		if err != nil && l.outputBuf.Len() == 0 {
 			logp.Err("%s Dropping event with rendering error. %v", l.logPrefix, err)

winlogbeat/sys/wineventlog/format_message.go

@@ -75,39 +75,43 @@ func evtFormatMessage(metadataHandle EvtHandle, eventHandle EvtHandle, messageID
 		valuesPtr = &values[0]
 	}
 
-	// best guess render buffer size, 16KB, to avoid rendering message twice in most cases
-	const bestGuessRenderBufferSize = 1 << 14
+	// best guess render buffer size, to avoid rendering message twice in most cases
+	const bestGuessRenderBufferSize = 1 << 19 // 512KB, 256K wide characters
 
 	// EvtFormatMessage operates with WCHAR buffer, assuming the size of the buffer in characters.
 	// https://docs.microsoft.com/en-us/windows/win32/api/winevt/nf-winevt-evtformatmessage
-	var bufferNeeded uint32
-	bufferSize := uint32(bestGuessRenderBufferSize / 2)
+	var wcharBufferUsed uint32
+	wcharBufferSize := uint32(bestGuessRenderBufferSize / 2)
 
 	// Get a buffer from the pool and adjust its length.
 	bb := sys.NewPooledByteBuffer()
 	defer bb.Free()
-	bb.Reserve(int(bufferSize * 2))
+	bb.Reserve(int(wcharBufferSize * 2))
 
-	err := _EvtFormatMessage(metadataHandle, eventHandle, messageID, valuesCount, valuesPtr, messageFlag, bufferSize, bb.PtrAt(0), &bufferNeeded)
+	err := _EvtFormatMessage(metadataHandle, eventHandle, messageID, valuesCount, valuesPtr, messageFlag, wcharBufferSize, bb.PtrAt(0), &wcharBufferUsed)
 	switch err { //nolint:errorlint // This is an errno or nil.
-	case nil: // OK
-		return sys.UTF16BytesToString(bb.Bytes())
-
 	// Ignore some errors so it can tolerate missing or mismatched parameter values.
-	case windows.ERROR_EVT_UNRESOLVED_VALUE_INSERT,
+	case nil, // OK
+		windows.ERROR_EVT_UNRESOLVED_VALUE_INSERT,
 		windows.ERROR_EVT_UNRESOLVED_PARAMETER_INSERT,
 		windows.ERROR_EVT_MAX_INSERTS_REACHED:
-		return sys.UTF16BytesToString(bb.Bytes())
+		// wcharBufferUsed indicates the size used internally to render the message. When called with nil buffer
+		// EvtFormatMessage returns ERROR_INSUFFICIENT_BUFFER, but otherwise succeeds copying only up to
+		// wcharBufferSize to our buffer, truncating the message if our buffer was too small.
+		if wcharBufferUsed <= wcharBufferSize {
+			return sys.UTF16BytesToString(bb.Bytes())
+		}
+		fallthrough
 
 	case windows.ERROR_INSUFFICIENT_BUFFER:
-		bb.Reserve(int(bufferNeeded * 2))
-		bufferSize = bufferNeeded
+		bb.Reserve(int(wcharBufferUsed * 2))
+		wcharBufferSize = wcharBufferUsed
 
 	default:
 		return "", fmt.Errorf("failed in EvtFormatMessage: %w", err)
 	}
 
-	err = _EvtFormatMessage(metadataHandle, eventHandle, messageID, valuesCount, valuesPtr, messageFlag, bufferSize, bb.PtrAt(0), &bufferNeeded)
+	err = _EvtFormatMessage(metadataHandle, eventHandle, messageID, valuesCount, valuesPtr, messageFlag, wcharBufferSize, bb.PtrAt(0), &wcharBufferUsed)
 	switch err { //nolint:errorlint // This is an errno or nil.
 	case nil: // OK
 

winlogbeat/sys/wineventlog/wineventlog_windows.go

@@ -403,35 +403,35 @@ func FormatEventString(
 	}
 
 	var bufferPtr *byte
-	if renderBuf != nil {
+	if len(renderBuf) > 0 {
 		bufferPtr = &renderBuf[0]
 	}
 
 	// EvtFormatMessage operates with WCHAR buffer, assuming the size of the buffer in characters.
 	// https://docs.microsoft.com/en-us/windows/win32/api/winevt/nf-winevt-evtformatmessage
-	var bufferNeeded uint32
-	bufferSize := uint32(len(renderBuf) / 2)
+	var wcharBufferUsed uint32
+	wcharBufferSize := uint32(len(renderBuf) / 2)
 
-	err := _EvtFormatMessage(ph, eventHandle, 0, 0, nil, messageFlag, bufferSize, bufferPtr, &bufferNeeded)
-	if err != nil && err != windows.ERROR_INSUFFICIENT_BUFFER { //nolint:errorlint // This is an errno.
+	err := _EvtFormatMessage(ph, eventHandle, 0, 0, nil, messageFlag, wcharBufferSize, bufferPtr, &wcharBufferUsed)
+	if err != nil && !errors.Is(err, windows.ERROR_INSUFFICIENT_BUFFER) {
 		return fmt.Errorf("failed in EvtFormatMessage: %w", err)
 	} else if err == nil {
-		// Windows API returns a null terminated WCHAR C-style string in the buffer. bufferNeeded applies
-		// only when ERROR_INSUFFICIENT_BUFFER is returned. Luckily the UTF16ToUTF8Bytes/UTF16ToString
-		// functions stop at null termination. Note, as signaled in a comment at the end of this function,
-		// this behavior is bad for EvtFormatMessageKeyword as then the API returns a list of null terminated
-		// strings in the buffer (it's fine for now as we don't use this parameter value).
-		return common.UTF16ToUTF8Bytes(renderBuf, out)
+		// wcharBufferUsed indicates the size used internally to render the message. When called with nil buffer
+		// EvtFormatMessage returns ERROR_INSUFFICIENT_BUFFER, but otherwise succeeds copying only up to
+		// wcharBufferSize to our buffer, truncating the message if our buffer was too small.
+		if wcharBufferUsed <= wcharBufferSize {
+			return common.UTF16ToUTF8Bytes(renderBuf[:wcharBufferUsed*2], out)
+		}
 	}
 
 	// Get a buffer from the pool and adjust its length.
 	bb := sys.NewPooledByteBuffer()
 	defer bb.Free()
 
-	bb.Reserve(int(bufferNeeded * 2))
-	bufferSize = bufferNeeded
+	bb.Reserve(int(wcharBufferUsed * 2))
+	wcharBufferSize = wcharBufferUsed
 
-	err = _EvtFormatMessage(ph, eventHandle, 0, 0, nil, messageFlag, bufferSize, bb.PtrAt(0), &bufferNeeded)
+	err = _EvtFormatMessage(ph, eventHandle, 0, 0, nil, messageFlag, wcharBufferSize, bb.PtrAt(0), &wcharBufferUsed)
 	if err != nil {
 		return fmt.Errorf("failed in EvtFormatMessage: %w", err)
 	}
@@ -550,20 +550,36 @@ func evtRenderProviderName(renderBuf []byte, eventHandle EvtHandle) (string, err
 }
 
 func renderXML(eventHandle EvtHandle, flag EvtRenderFlag, renderBuf []byte, out io.Writer) error {
-	var bufferUsed, propertyCount uint32
-	err := _EvtRender(0, eventHandle, flag, uint32(len(renderBuf)),
-		&renderBuf[0], &bufferUsed, &propertyCount)
-	if err == ERROR_INSUFFICIENT_BUFFER { //nolint:errorlint // This is an errno or nil.
-		return sys.InsufficientBufferError{Cause: err, RequiredSize: int(bufferUsed)}
+	var bufferUsed, bufferSize, propertyCount uint32
+	var bufferPtr *byte
+
+	bufferSize = uint32(len(renderBuf))
+	if bufferSize > 0 {
+		bufferPtr = &renderBuf[0]
 	}
-	if err != nil {
+	err := _EvtRender(0, eventHandle, flag, bufferSize, bufferPtr, &bufferUsed, &propertyCount)
+	if err != nil && !errors.Is(err, windows.ERROR_INSUFFICIENT_BUFFER) {
 		return err
+	} else if err == nil {
+		// bufferUsed indicates the size used internally to render the message. When called with nil buffer
+		// EvtRender returns ERROR_INSUFFICIENT_BUFFER, but otherwise succeeds copying only up to
+		// bufferSize to our buffer, truncating the message if our buffer was too small.
+		if bufferUsed <= bufferSize {
+			return common.UTF16ToUTF8Bytes(renderBuf[:bufferUsed], out)
+		}
 	}
 
-	if int(bufferUsed) > len(renderBuf) {
-		return fmt.Errorf("Windows EvtRender reported that wrote %d bytes "+
-			"to the buffer, but the buffer can only hold %d bytes",
-			bufferUsed, len(renderBuf))
+	// Get a buffer from the pool and adjust its length.
+	bb := sys.NewPooledByteBuffer()
+	defer bb.Free()
+
+	bb.Reserve(int(bufferUsed))
+	bufferSize = bufferUsed
+
+	err = _EvtRender(0, eventHandle, flag, bufferSize, bb.PtrAt(0), &bufferUsed, &propertyCount)
+	if err != nil {
+		return fmt.Errorf("failed in EvtRender: %w", err)
 	}
-	return common.UTF16ToUTF8Bytes(renderBuf[:bufferUsed], out)
+
+	return common.UTF16ToUTF8Bytes(bb.Bytes(), out)
 }