wineventlog performance improvment; avoid rendering message twice

winlogbeat/sys/wineventlog/format_message.go

@@ -75,23 +75,32 @@ func evtFormatMessage(metadataHandle EvtHandle, eventHandle EvtHandle, messageID
 		valuesPtr = &values[0]
 	}
 
-	// Determine the buffer size needed (given in WCHARs).
+	// best guess render buffer size, 16KB, to avoid rendering message twice in most cases
+	const bestGuessRenderBufferSize = 1 << 14
+
+	// 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 bufferUsed uint32
-	err := _EvtFormatMessage(metadataHandle, eventHandle, messageID, valuesCount, valuesPtr, messageFlag, 0, nil, &bufferUsed)
-	if err != windows.ERROR_INSUFFICIENT_BUFFER { //nolint:errorlint // This is an errno.
-		return "", fmt.Errorf("failed in EvtFormatMessage: %w", err)
-	}
+	bufferSize := uint32(bestGuessRenderBufferSize / 2)
 
 	// Get a buffer from the pool and adjust its length.
 	bb := sys.NewPooledByteBuffer()
 	defer bb.Free()
-	// The documentation for EventFormatMessage specifies that the buffer is
-	// requested "in characters", and the buffer itself is LPWSTR, meaning the
-	// characters are WCHAR so double the value.
-	// https://docs.microsoft.com/en-us/windows/win32/api/winevt/nf-winevt-evtformatmessage
-	bb.Reserve(int(bufferUsed * 2))
+	bb.Reserve(int(bufferSize * 2))
+
+	err := _EvtFormatMessage(metadataHandle, eventHandle, messageID, valuesCount, valuesPtr, messageFlag, bufferSize, bb.PtrAt(0), &bufferUsed)
+	if err != nil && err != windows.ERROR_INSUFFICIENT_BUFFER { //nolint:errorlint // This is an errno.
+		return "", fmt.Errorf("failed in EvtFormatMessage: %w", err)
+	}
+
+	if bufferUsed <= bufferSize {
+		return sys.UTF16BytesToString(bb.Bytes())
+	}
+
+	bufferSize = bufferUsed
+	bb.Reserve(int(bufferSize * 2))
 
-	err = _EvtFormatMessage(metadataHandle, eventHandle, messageID, valuesCount, valuesPtr, messageFlag, bufferUsed, bb.PtrAt(0), &bufferUsed)
+	err = _EvtFormatMessage(metadataHandle, eventHandle, messageID, valuesCount, valuesPtr, messageFlag, bufferSize, bb.PtrAt(0), &bufferUsed)
 	switch err { //nolint:errorlint // This is an errno or nil.
 	case nil: // OK
 

winlogbeat/sys/wineventlog/wineventlog_windows.go

@@ -239,15 +239,9 @@ func RenderEvent(
 
 	// Only a single string is returned when rendering XML.
 	err = FormatEventString(EvtFormatMessageXml,
-		eventHandle, providerName, EvtHandle(publisherHandle), lang, out)
+		eventHandle, providerName, EvtHandle(publisherHandle), lang, renderBuf, out)
 	// Recover by rendering the XML without the RenderingInfo (message string).
 	if err != nil {
-		// Do not try to recover from InsufficientBufferErrors because these
-		// can be retried with a larger buffer.
-		if errors.Is(err, sys.InsufficientBufferError{}) {
-			return err
-		}
-
 		err = RenderEventXML(eventHandle, renderBuf, out)
 	}
 
@@ -256,8 +250,8 @@ func RenderEvent(
 
 // Message reads the event data associated with the EvtHandle and renders
 // and returns the message only.
-func Message(h EvtHandle, buf []byte, pubHandleProvider func(string) sys.MessageFiles) (message string, err error) {
-	providerName, err := evtRenderProviderName(buf, h)
+func Message(h EvtHandle, renderBuf []byte, pubHandleProvider func(string) sys.MessageFiles) (message string, err error) {
+	providerName, err := evtRenderProviderName(renderBuf, h)
 	if err != nil {
 		return "", err
 	}
@@ -386,12 +380,15 @@ func Close(h EvtHandle) error {
 // publisherHandle is a handle to the publisher's metadata as provided by
 // EvtOpenPublisherMetadata.
 // lang is the language ID.
+// renderBuf is a scratch buffer to render the message, if not provided or of
+// insufficient size then a buffer from a system pool will be used
 func FormatEventString(
 	messageFlag EvtFormatMessageFlag,
 	eventHandle EvtHandle,
 	publisher string,
 	publisherHandle EvtHandle,
 	lang uint32,
+	renderBuf []byte,
 	out io.Writer,
 ) error {
 	// Open a publisher handle if one was not provided.
@@ -405,29 +402,48 @@ func FormatEventString(
 		defer _EvtClose(ph) //nolint:errcheck // This is just a resource release.
 	}
 
-	// Determine the buffer size needed (given in WCHARs).
+	var bufferPtr *byte
+	if renderBuf != nil {
+		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 bufferUsed uint32
-	err := _EvtFormatMessage(ph, eventHandle, 0, 0, nil, messageFlag, 0, nil, &bufferUsed)
-	if err != windows.ERROR_INSUFFICIENT_BUFFER { //nolint:errorlint // This is an errno.
+	bufferSize := uint32(len(renderBuf) / 2)
+
+	err := _EvtFormatMessage(ph, eventHandle, 0, 0, nil, messageFlag, bufferSize, bufferPtr, &bufferUsed)
+	if err != nil && err != windows.ERROR_INSUFFICIENT_BUFFER { //nolint:errorlint // This is an errno.
 		return fmt.Errorf("failed in EvtFormatMessage: %w", err)
 	}
 
+	// Sanity check against quirk reported earlier https://github.com/elastic/beats/pull/34005
+	// Indeed, Windows API EvtFormatMessage return indicates if the function succeeded or failed,
+	// but the go wrapper implementation hides it
+	//		r1, _, e1 := syscall.Syscall9()
+	//		if r1 == 0 {
+	//			err = errnoErr(e1)
+	//		}
+	// Windows guarantees per thread last error code, how go runtime handles it per go routine?
+	if bufferUsed <= bufferSize && renderBuf != nil {
+		return common.UTF16ToUTF8Bytes(renderBuf[:(bufferUsed*2)], out)
+	}
+
+	bufferSize = bufferUsed
+
 	// Get a buffer from the pool and adjust its length.
 	bb := sys.NewPooledByteBuffer()
 	defer bb.Free()
-	// The documentation for EvtFormatMessage specifies that the buffer is
-	// requested "in characters", and the buffer itself is LPWSTR, meaning the
-	// characters are WCHAR so double the value.
-	// https://docs.microsoft.com/en-us/windows/win32/api/winevt/nf-winevt-evtformatmessage
-	bb.Reserve(int(bufferUsed * 2))
 
-	err = _EvtFormatMessage(ph, eventHandle, 0, 0, nil, messageFlag, bufferUsed, bb.PtrAt(0), &bufferUsed)
+	bb.Reserve(int(bufferSize * 2))
+
+	err = _EvtFormatMessage(ph, eventHandle, 0, 0, nil, messageFlag, bufferSize, bb.PtrAt(0), &bufferUsed)
 	if err != nil {
 		return fmt.Errorf("failed in EvtFormatMessage: %w", err)
 	}
 
 	// This assumes there is only a single string value to read. This will
-	// not work to read keys (when messageFlag == EvtFormatMessageKeyword).
+	// not work to read keys (when messageFlag == EvtFormatMessageKeyword)
 	return common.UTF16ToUTF8Bytes(bb.Bytes(), out)
 }