From 58762e8e088006046b177436abc7dc7ba9753204 Mon Sep 17 00:00:00 2001 From: Leszek Kubik <39905449+intxgo@users.noreply.github.com> Date: Tue, 14 May 2024 10:05:07 +0200 Subject: [PATCH 1/5] wineventlog performance improvment; avoid rendering message twice --- winlogbeat/sys/wineventlog/format_message.go | 30 ++++++++----- .../sys/wineventlog/wineventlog_windows.go | 44 ++++++++++--------- 2 files changed, 42 insertions(+), 32 deletions(-) diff --git a/winlogbeat/sys/wineventlog/format_message.go b/winlogbeat/sys/wineventlog/format_message.go index e6502d384fa..9f47719fbcc 100644 --- a/winlogbeat/sys/wineventlog/format_message.go +++ b/winlogbeat/sys/wineventlog/format_message.go @@ -75,23 +75,29 @@ func evtFormatMessage(metadataHandle EvtHandle, eventHandle EvtHandle, messageID valuesPtr = &values[0] } - // Determine the buffer size needed (given in WCHARs). - 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) - } + // 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 bufferNeeded uint32 + 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), &bufferNeeded) + if err != nil && err != windows.ERROR_INSUFFICIENT_BUFFER { //nolint:errorlint // This is an errno. + return "", fmt.Errorf("failed in EvtFormatMessage: %w", err) + } else if err == nil { + return sys.UTF16BytesToString(bb.Bytes()) + } + + bb.Reserve(int(bufferNeeded * 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), &bufferNeeded) switch err { //nolint:errorlint // This is an errno or nil. case nil: // OK diff --git a/winlogbeat/sys/wineventlog/wineventlog_windows.go b/winlogbeat/sys/wineventlog/wineventlog_windows.go index 6b4abfaf5d1..150121f2208 100644 --- a/winlogbeat/sys/wineventlog/wineventlog_windows.go +++ b/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,36 @@ func FormatEventString( defer _EvtClose(ph) //nolint:errcheck // This is just a resource release. } - // Determine the buffer size needed (given in WCHARs). - 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. + 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 bufferNeeded uint32 + bufferSize := 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. return fmt.Errorf("failed in EvtFormatMessage: %w", err) + } else if err == nil { + return common.UTF16ToUTF8Bytes(renderBuf, out) } // 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(bufferNeeded * 2)) + + err = _EvtFormatMessage(ph, eventHandle, 0, 0, nil, messageFlag, bufferSize, bb.PtrAt(0), &bufferNeeded) 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) } From 357e5d83f4ee02e5de66c1f130f973af87915932 Mon Sep 17 00:00:00 2001 From: Leszek Kubik <39905449+intxgo@users.noreply.github.com> Date: Tue, 14 May 2024 11:54:00 +0200 Subject: [PATCH 2/5] ignore missing or mismatched parameter values --- winlogbeat/sys/wineventlog/format_message.go | 19 ++++++++++++++----- 1 file changed, 14 insertions(+), 5 deletions(-) diff --git a/winlogbeat/sys/wineventlog/format_message.go b/winlogbeat/sys/wineventlog/format_message.go index 9f47719fbcc..39e8e00730e 100644 --- a/winlogbeat/sys/wineventlog/format_message.go +++ b/winlogbeat/sys/wineventlog/format_message.go @@ -89,13 +89,22 @@ func evtFormatMessage(metadataHandle EvtHandle, eventHandle EvtHandle, messageID bb.Reserve(int(bufferSize * 2)) err := _EvtFormatMessage(metadataHandle, eventHandle, messageID, valuesCount, valuesPtr, messageFlag, bufferSize, bb.PtrAt(0), &bufferNeeded) - if err != nil && err != windows.ERROR_INSUFFICIENT_BUFFER { //nolint:errorlint // This is an errno. - return "", fmt.Errorf("failed in EvtFormatMessage: %w", err) - } else if err == nil { + switch err { //nolint:errorlint // This is an errno or nil. + case nil: // OK return sys.UTF16BytesToString(bb.Bytes()) - } - bb.Reserve(int(bufferNeeded * 2)) + // Ignore some errors so it can tolerate missing or mismatched parameter values. + case windows.ERROR_EVT_UNRESOLVED_VALUE_INSERT, + windows.ERROR_EVT_UNRESOLVED_PARAMETER_INSERT, + windows.ERROR_EVT_MAX_INSERTS_REACHED: + return sys.UTF16BytesToString(bb.Bytes()) + + case windows.ERROR_INSUFFICIENT_BUFFER: + bb.Reserve(int(bufferNeeded * 2)) + + default: + return "", fmt.Errorf("failed in EvtFormatMessage: %w", err) + } err = _EvtFormatMessage(metadataHandle, eventHandle, messageID, valuesCount, valuesPtr, messageFlag, bufferSize, bb.PtrAt(0), &bufferNeeded) switch err { //nolint:errorlint // This is an errno or nil. From f9a8adf3d0ebfbf09cad3be2b260220d238ac9d3 Mon Sep 17 00:00:00 2001 From: Leszek Kubik <39905449+intxgo@users.noreply.github.com> Date: Tue, 14 May 2024 13:22:43 +0200 Subject: [PATCH 3/5] add comment --- winlogbeat/sys/wineventlog/wineventlog_windows.go | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/winlogbeat/sys/wineventlog/wineventlog_windows.go b/winlogbeat/sys/wineventlog/wineventlog_windows.go index 150121f2208..fa2765ba500 100644 --- a/winlogbeat/sys/wineventlog/wineventlog_windows.go +++ b/winlogbeat/sys/wineventlog/wineventlog_windows.go @@ -416,6 +416,11 @@ func FormatEventString( if err != nil && err != windows.ERROR_INSUFFICIENT_BUFFER { //nolint:errorlint // This is an errno. 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) } From a66a76d6059580552f90912d91bfead4f6f3ae5c Mon Sep 17 00:00:00 2001 From: Leszek Kubik <39905449+intxgo@users.noreply.github.com> Date: Tue, 14 May 2024 15:02:04 +0200 Subject: [PATCH 4/5] changelog --- CHANGELOG.next.asciidoc | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.next.asciidoc b/CHANGELOG.next.asciidoc index 2b571875e34..1312629cbff 100644 --- a/CHANGELOG.next.asciidoc +++ b/CHANGELOG.next.asciidoc @@ -308,6 +308,7 @@ https://github.com/elastic/beats/compare/v8.8.1\...main[Check the HEAD diff] *Winlogbeat* +- Use fixed size buffer at first pass for event parsing, improving throughput {issue}39530[39530] {pull}39544[39544] *Functionbeat* From be53dfb76f4e25126fa21f87c8580531671d1fad Mon Sep 17 00:00:00 2001 From: Leszek Kubik <39905449+intxgo@users.noreply.github.com> Date: Wed, 15 May 2024 10:25:26 +0200 Subject: [PATCH 5/5] actually increase the buffer --- winlogbeat/sys/wineventlog/format_message.go | 1 + winlogbeat/sys/wineventlog/wineventlog_windows.go | 1 + 2 files changed, 2 insertions(+) diff --git a/winlogbeat/sys/wineventlog/format_message.go b/winlogbeat/sys/wineventlog/format_message.go index 39e8e00730e..9c1cf8254ac 100644 --- a/winlogbeat/sys/wineventlog/format_message.go +++ b/winlogbeat/sys/wineventlog/format_message.go @@ -101,6 +101,7 @@ func evtFormatMessage(metadataHandle EvtHandle, eventHandle EvtHandle, messageID case windows.ERROR_INSUFFICIENT_BUFFER: bb.Reserve(int(bufferNeeded * 2)) + bufferSize = bufferNeeded default: return "", fmt.Errorf("failed in EvtFormatMessage: %w", err) diff --git a/winlogbeat/sys/wineventlog/wineventlog_windows.go b/winlogbeat/sys/wineventlog/wineventlog_windows.go index fa2765ba500..22495f6bda2 100644 --- a/winlogbeat/sys/wineventlog/wineventlog_windows.go +++ b/winlogbeat/sys/wineventlog/wineventlog_windows.go @@ -429,6 +429,7 @@ func FormatEventString( defer bb.Free() bb.Reserve(int(bufferNeeded * 2)) + bufferSize = bufferNeeded err = _EvtFormatMessage(ph, eventHandle, 0, 0, nil, messageFlag, bufferSize, bb.PtrAt(0), &bufferNeeded) if err != nil {