Skip to content

Commit

Permalink
Revert "winlogbeat: fix event handling for Windows 2022 (elastic#30942)"
Browse files Browse the repository at this point in the history 
This reverts commit 34bdc3d.
  • Loading branch information
@efd6
efd6 committed Apr 4, 2022
1 parent 00948f3 commit 94d13fe
Show file tree
Hide file tree
Showing 29 changed files with 176 additions and 375 deletions.
2 changes: 0 additions & 2 deletions CHANGELOG.next.asciidoc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -75,8 +75,6 @@ https://github.com/elastic/beats/compare/v7.0.0-alpha2...main[Check the HEAD dif

*Winlogbeat*

- Fix evtx parsing failures. {issue}30621[30621] {pull}30942[30942]


*Functionbeat*

Expand Down
2 changes: 1 addition & 1 deletion winlogbeat/beater/winlogbeat.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -94,7 +94,7 @@ func (eb *Winlogbeat) init(b *beat.Beat) error {
if err != nil {
return fmt.Errorf("failed to create new event log: %w", err)
}
eb.log.Debugf("initialized WinEventLog[%s]", eventLog.Name())
eb.log.Debugw("Initialized EventLog", "id", eventLog.Name())

logger, err := newEventLogger(b.Info, eventLog, config, eb.log)
if err != nil {
Expand Down
47 changes: 18 additions & 29 deletions winlogbeat/eventlog/wineventlog.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -55,15 +55,6 @@ const (
eventLoggingAPIName = "eventlogging"
)

func init() {
// Register wineventlog API if it is available.
available, _ := win.IsAvailable()
if available {
Register(winEventLogAPIName, 0, newWinEventLog, win.Channels)
Register(eventLoggingAPIName, 1, newEventLogging, win.Channels)
}
}

type winEventLogConfig struct {
ConfigCommon `config:",inline"`
BatchReadSize int `config:"batch_read_size"` // Maximum number of events that Read will return.
Expand Down Expand Up @@ -169,7 +160,6 @@ type winEventLog struct {
lastRead checkpoint.EventLogState // Record number of the last read event.

render func(event win.EvtHandle, out io.Writer) error // Function for rendering the event to XML.
message func(event win.EvtHandle) (string, error) // Message fallback function.
renderBuf []byte // Buffer used for rendering event.
outputBuf *sys.ByteBuffer // Buffer for receiving XML
cache *messageFilesCache // Cached mapping of source name to event message file handles.
Expand Down Expand Up @@ -208,7 +198,7 @@ func (l *winEventLog) openChannel(bookmark win.EvtHandle) error {
if err != nil {
return err
}
defer windows.CloseHandle(signalEvent) //nolint:errcheck // This is just a resource release.
defer func() { _ = windows.CloseHandle(signalEvent) }()

var flags win.EvtSubscribeFlag
if bookmark > 0 {
Expand Down Expand Up @@ -296,12 +286,13 @@ func (l *winEventLog) Read() ([]Record, error) {
}()
detailf("%s EventHandles returned %d handles", l.logPrefix, len(handles))

var records []Record //nolint:prealloc // This linter gives bad advice and does not take into account conditionals in loops.
//nolint: prealloc // some handles can be skipped, the final size is unknown
var records []Record
for _, h := range handles {
l.outputBuf.Reset()
err := l.render(h, l.outputBuf)
var bufErr sys.InsufficientBufferError
if errors.As(err, &bufErr) {
if ok := errors.As(err, &bufErr); ok {
detailf("%s Increasing render buffer size to %d", l.logPrefix,
bufErr.RequiredSize)
l.renderBuf = make([]byte, bufErr.RequiredSize)
Expand All @@ -323,12 +314,6 @@ func (l *winEventLog) Read() ([]Record, error) {
if r.Offset.Bookmark, err = l.createBookmarkFromEvent(h); err != nil {
logp.Warn("%s failed creating bookmark: %v", l.logPrefix, err)
}
if r.Message == "" {
r.Message, err = l.message(h)
if err != nil {
logp.Err("%s error salvaging message: %v", l.logPrefix, err)
}
}
records = append(records, r)
l.lastRead = r.Offset
}
Expand All @@ -344,20 +329,20 @@ func (l *winEventLog) Close() error {

func (l *winEventLog) eventHandles(maxRead int) ([]win.EvtHandle, int, error) {
handles, err := win.EventHandles(l.subscription, maxRead)
switch err { //nolint:errorlint // This is an errno or nil.
case nil:
switch {
case err == nil:
if l.maxRead > maxRead {
debugf("%s Recovered from RPC_S_INVALID_BOUND error (errno 1734) "+
"by decreasing batch_read_size to %v", l.logPrefix, maxRead)
}
return handles, maxRead, nil
case win.ERROR_NO_MORE_ITEMS:
case errors.Is(err, win.ERROR_NO_MORE_ITEMS):
detailf("%s No more events", l.logPrefix)
if l.config.NoMoreEvents == Stop {
return nil, maxRead, io.EOF
}
return nil, maxRead, nil
case win.RPC_S_INVALID_BOUND:
case errors.Is(err, win.RPC_S_INVALID_BOUND):
incrementMetric(readErrors, err)
if err := l.Close(); err != nil {
return nil, 0, fmt.Errorf("failed to recover from RPC_S_INVALID_BOUND: %w", err)
Expand Down Expand Up @@ -396,15 +381,13 @@ func (l *winEventLog) buildRecordFromXML(x []byte, recoveredErr error) Record {
e.RenderErr = append(e.RenderErr, recoveredErr.Error())
}

// Get basic string values for raw fields.
winevent.EnrichRawValuesWithNames(nil, &e)
if e.Level == "" {
// Fallback on LevelRaw if the Level is not set in the RenderingInfo.
e.Level = win.EventLevel(e.LevelRaw).String()
}

if logp.IsDebug(detailSelector) {
detailf("%s XML=%s Event=%+v", l.logPrefix, x, e)
detailf("%s XML=%s Event=%+v", l.logPrefix, string(x), e)
}

r := Record{
Expand Down Expand Up @@ -506,9 +489,6 @@ func newWinEventLog(options *common.Config) (EventLog, error) {
return win.RenderEvent(event, c.EventLanguage, l.renderBuf, l.cache.get, out)
}
}
l.message = func(event win.EvtHandle) (string, error) {
return win.Message(event, l.renderBuf, l.cache.get)
}

return l, nil
}
Expand All @@ -523,3 +503,12 @@ func (l *winEventLog) createBookmarkFromEvent(evtHandle win.EvtHandle) (string,
win.Close(bmHandle)
return string(l.outputBuf.Bytes()), err
}

func init() {
// Register wineventlog API if it is available.
available, _ := win.IsAvailable()
if available {
Register(winEventLogAPIName, 0, newWinEventLog, win.Channels)
Register(eventLoggingAPIName, 1, newEventLogging, win.Channels)
}
}
28 changes: 15 additions & 13 deletions winlogbeat/eventlog/wineventlog_experimental.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
package eventlog

import (
"errors"
"fmt"
"io"
"os"
Expand All @@ -42,14 +43,6 @@ const (
winEventLogExpAPIName = "wineventlog-experimental"
)

func init() {
// Register wineventlog API if it is available.
available, _ := win.IsAvailable()
if available {
Register(winEventLogExpAPIName, 10, newWinEventLogExp, win.Channels)
}
}

// winEventLogExp implements the EventLog interface for reading from the Windows
// Event Log API.
type winEventLogExp struct {
Expand Down Expand Up @@ -107,7 +100,7 @@ func (l *winEventLogExp) openChannel(bookmark win.Bookmark) (win.EvtHandle, erro
if err != nil {
return win.NilHandle, err
}
defer windows.CloseHandle(signalEvent) //nolint:errcheck // This is just a resource release.
defer func() { _ = windows.CloseHandle(signalEvent) }()

var flags win.EvtSubscribeFlag
if bookmark > 0 {
Expand All @@ -127,10 +120,11 @@ func (l *winEventLogExp) openChannel(bookmark win.Bookmark) (win.EvtHandle, erro
win.EvtHandle(bookmark), // Bookmark - for resuming from a specific event
flags)

switch err { //nolint:errorlint // This is an errno or nil.
case nil:
switch {
case err == nil:
return h, nil
case win.ERROR_NOT_FOUND, win.ERROR_EVT_QUERY_RESULT_STALE, win.ERROR_EVT_QUERY_RESULT_INVALID_POSITION:
case errors.Is(err, win.ERROR_NOT_FOUND), errors.Is(err, win.ERROR_EVT_QUERY_RESULT_STALE),
errors.Is(err, win.ERROR_EVT_QUERY_RESULT_INVALID_POSITION):
// The bookmarked event was not found, we retry the subscription from the start.
incrementMetric(readErrors, err)
return win.Subscribe(0, signalEvent, "", l.query, 0, win.EvtSubscribeStartAtOldestRecord)
Expand Down Expand Up @@ -219,7 +213,7 @@ func (l *winEventLogExp) processHandle(h win.EvtHandle) (*Record, error) {
evt.RenderErr = append(evt.RenderErr, err.Error())
}

//nolint:godox // Bad linter! Keep to have a record of feature disparity between non-experimental vs experimental.
//nolint: godox // keep to have a record of feature disparity between non-experimental vs experimental
// TODO: Need to add XML when configured.

r := &Record{
Expand Down Expand Up @@ -327,3 +321,11 @@ func newWinEventLogExp(options *common.Config) (EventLog, error) {

return l, nil
}

func init() {
// Register wineventlog API if it is available.
available, _ := win.IsAvailable()
if available {
Register(winEventLogExpAPIName, 10, newWinEventLogExp, win.Channels)
}
}
23 changes: 3 additions & 20 deletions winlogbeat/eventlog/wineventlog_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,6 @@ import (

"github.com/andrewkroh/sys/windows/svc/eventlog"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"

"github.com/elastic/beats/v7/libbeat/common"
"github.com/elastic/beats/v7/winlogbeat/checkpoint"
Expand Down Expand Up @@ -183,27 +182,13 @@ func testWindowsEventLog(t *testing.T, api string) {
const messageSize = 256 // Originally 31800, such a large value resulted in an empty eventlog under Win10.
const totalEvents = 1000
for i := 0; i < totalEvents; i++ {
safeWriteEvent(t, writer, eventlog.Info, uint32(i%1000)+1, []string{strconv.Itoa(i) + " " + randomSentence(messageSize)})
safeWriteEvent(t, writer, eventlog.Info, uint32(i%1000), []string{strconv.Itoa(i) + " " + randomSentence(messageSize)})
}

openLog := func(t testing.TB, config map[string]interface{}) EventLog {
return openLog(t, api, nil, config)
}

t.Run("has_message", func(t *testing.T) {
log := openLog(t, map[string]interface{}{"name": providerName, "batch_read_size": 1})
defer log.Close()

for i := 0; i < 10; i++ {
records, err := log.Read()
require.NotEmpty(t, records)
require.NoError(t, err)

r := records[0]
require.NotEmpty(t, r.Message, "message field is empty: errors:%v\nrecord:%#v", r.Event.RenderErr, r)
}
})

// Test reading from an event log using a custom XML query.
t.Run("custom_xml_query", func(t *testing.T) {
cfg := map[string]interface{}{
Expand Down Expand Up @@ -317,18 +302,16 @@ func createLog(t testing.TB, messageFiles ...string) (log *eventlog.Log, tearDow
}

if existed {
wineventlog.EvtClearLog(wineventlog.NilHandle, name, "") //nolint:errcheck // This is just a resource release.
wineventlog.EvtClearLog(wineventlog.NilHandle, name, "")
}

log, err = eventlog.Open(source)
//nolint:errcheck // This is just a resource release.
if err != nil {
eventlog.RemoveSource(name, source)
eventlog.RemoveProvider(name)
t.Fatal(err)
}

//nolint:errcheck // This is just a resource release.
tearDown = func() {
log.Close()
wineventlog.EvtClearLog(wineventlog.NilHandle, name, "")
Expand All @@ -355,7 +338,7 @@ func safeWriteEvent(t testing.TB, log *eventlog.Log, etype uint16, eid uint32, m

// setLogSize set the maximum number of bytes that an event log can hold.
func setLogSize(t testing.TB, provider string, sizeBytes int) {
output, err := exec.Command("wevtutil.exe", "sl", "/ms:"+strconv.Itoa(sizeBytes), provider).CombinedOutput() //nolint:gosec // No possibility of command injection.
output, err := exec.Command("wevtutil.exe", "sl", "/ms:"+strconv.Itoa(sizeBytes), provider).CombinedOutput()
if err != nil {
t.Fatal("Failed to set log size", err, string(output))
}
Expand Down
30 changes: 17 additions & 13 deletions winlogbeat/sys/winevent/event.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,11 @@ var (
const (
keywordAuditFailure = 0x10000000000000
keywordAuditSuccess = 0x20000000000000

// keywordClassic indicates the log was published with the "classic" event
// logging API.
// https://docs.microsoft.com/en-us/dotnet/api/system.diagnostics.eventing.reader.standardeventkeywords?view=netframework-4.8
keywordClassic = 0x80000000000000
)

// UnmarshalXML unmarshals the given XML into a new Event.
Expand All @@ -62,7 +67,7 @@ type Event struct {
Version Version `xml:"System>Version"`
LevelRaw uint8 `xml:"System>Level"`
TaskRaw uint16 `xml:"System>Task"`
OpcodeRaw *uint8 `xml:"System>Opcode,omitempty"`
OpcodeRaw uint8 `xml:"System>Opcode"`
KeywordsRaw HexInt64 `xml:"System>Keywords"`
TimeCreated TimeCreated `xml:"System>TimeCreated"`
RecordID uint64 `xml:"System>EventRecordID"`
Expand Down Expand Up @@ -253,10 +258,7 @@ func (u *UserData) UnmarshalXML(d *xml.Decoder, start xml.StartElement) error {

u.Name = se.Name
u.Pairs = in.Pairs
err = d.Skip()
if err != nil {
return err
}
d.Skip()
break
}
}
Expand Down Expand Up @@ -307,7 +309,8 @@ func (v *Version) UnmarshalXML(d *xml.Decoder, start xml.StartElement) error {

version, err := strconv.ParseUint(s, 10, 8)
if err != nil {
return nil //nolint:nilerr // Ignore invalid version values.
// Ignore invalid version values.
return nil
}

*v = Version(version)
Expand Down Expand Up @@ -338,19 +341,20 @@ func (v *HexInt64) UnmarshalXML(d *xml.Decoder, start xml.StartElement) error {
func EnrichRawValuesWithNames(publisherMeta *WinMeta, event *Event) {
// Keywords. Each bit in the value can represent a keyword.
rawKeyword := int64(event.KeywordsRaw)
isClassic := keywordClassic&rawKeyword > 0

if len(event.Keywords) == 0 {
for mask, keyword := range defaultWinMeta.Keywords {
if rawKeyword&mask != 0 {
if rawKeyword&mask > 0 {
event.Keywords = append(event.Keywords, keyword)
rawKeyword &^= mask
rawKeyword -= mask
}
}
if publisherMeta != nil {
for mask, keyword := range publisherMeta.Keywords {
if rawKeyword&mask != 0 {
if rawKeyword&mask > 0 {
event.Keywords = append(event.Keywords, keyword)
rawKeyword &^= mask
rawKeyword -= mask
}
}
}
Expand All @@ -359,10 +363,10 @@ func EnrichRawValuesWithNames(publisherMeta *WinMeta, event *Event) {
var found bool
if event.Opcode == "" {
// Opcode (search in defaultWinMeta first).
if event.OpcodeRaw != nil {
event.Opcode, found = defaultWinMeta.Opcodes[*event.OpcodeRaw]
if !isClassic {
event.Opcode, found = defaultWinMeta.Opcodes[event.OpcodeRaw]
if !found && publisherMeta != nil {
event.Opcode = publisherMeta.Opcodes[*event.OpcodeRaw]
event.Opcode = publisherMeta.Opcodes[event.OpcodeRaw]
}
}
}
Expand Down
4 changes: 2 additions & 2 deletions winlogbeat/sys/winevent/event_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ package winevent
import (
"encoding/json"
"encoding/xml"
"fmt"
"strings"
"testing"
"time"
Expand Down Expand Up @@ -96,7 +97,6 @@ func TestXML(t *testing.T) {
EventIdentifier: EventIdentifier{ID: 91},
LevelRaw: 4,
TaskRaw: 9,
OpcodeRaw: new(uint8), // The value in the XML is 0.
KeywordsRaw: 0x8020000000000000,
TimeCreated: TimeCreated{allXMLTimeCreated},
RecordID: 100,
Expand Down Expand Up @@ -180,7 +180,7 @@ func TestXML(t *testing.T) {
if err != nil {
t.Error(err)
}
t.Logf("%s", json)
fmt.Println(string(json))
}
}
}
Expand Down
Loading

0 comments on commit 94d13fe

Please sign in to comment.