Fix panic when reading messages larger than 32K characters on Windows…

… XP and 2003. (#1498)

Winlogbeat was passing the size of the buffer to Windows using number of bytes, but Windows was expecting number of TCHAR's. This made Windows return that the number of TCHARs read was greater than the number that the buffer could hold. Winlogbeat used the return value to read from the buffer which caused a 'runtime error: slice bounds out of range' panic.

The buffer length issue has been corrected by dividing by sizeof(TCHAR) which is 2. In addition a check has been added to verify that the return value from Windows is sane before using it to slice the buffer.

CHANGELOG.asciidoc

@@ -57,6 +57,8 @@ https://github.com/elastic/beats/compare/v5.0.0-alpha1...master[Check the HEAD d
 
 *Winlogbeat*
 
+- Fix panic when reading messages larger than 32K characters on Windows XP and 2003. {pull}1498[1498]
+
 ==== Added
 
 *Affecting all Beats*

winlogbeat/eventlog/eventlogging.go

@@ -20,12 +20,15 @@ const (
 	eventLoggingAPIName = "eventlogging"
 )
 
-var eventLoggingConfigKeys = append(commonConfigKeys, "ignore_older")
+var eventLoggingConfigKeys = append(commonConfigKeys, "ignore_older",
+	"read_buffer_size", "format_buffer_size")
 
 type eventLoggingConfig struct {
-	ConfigCommon `config:",inline"`
-	IgnoreOlder  time.Duration          `config:"ignore_older"`
-	Raw          map[string]interface{} `config:",inline"`
+	ConfigCommon     `config:",inline"`
+	IgnoreOlder      time.Duration          `config:"ignore_older"`
+	ReadBufferSize   uint                   `config:"read_buffer_size"   validate:"min=1"`
+	FormatBufferSize uint                   `config:"format_buffer_size" validate:"min=1"`
+	Raw              map[string]interface{} `config:",inline"`
 }
 
 // Validate validates the eventLoggingConfig data and returns an error
@@ -36,6 +39,16 @@ func (c *eventLoggingConfig) Validate() error {
 		errs = append(errs, fmt.Errorf("event log is missing a 'name'"))
 	}
 
+	if c.ReadBufferSize > win.MaxEventBufferSize {
+		errs = append(errs, fmt.Errorf("'read_buffer_size' must be less than "+
+			"%d bytes", win.MaxEventBufferSize))
+	}
+
+	if c.FormatBufferSize > win.MaxFormatMessageBufferSize {
+		errs = append(errs, fmt.Errorf("'format_buffer_size' must be less than "+
+			"%d bytes", win.MaxFormatMessageBufferSize))
+	}
+
 	return errs.Err()
 }
 
@@ -238,7 +251,10 @@ func (l *eventLogging) ignoreOlder(r *Record) bool {
 // newEventLogging creates and returns a new EventLog for reading event logs
 // using the Event Logging API.
 func newEventLogging(options map[string]interface{}) (EventLog, error) {
-	var c eventLoggingConfig
+	c := eventLoggingConfig{
+		ReadBufferSize:   win.MaxEventBufferSize,
+		FormatBufferSize: win.MaxFormatMessageBufferSize,
+	}
 	if err := readConfig(options, &c, eventLoggingConfigKeys); err != nil {
 		return nil, err
 	}
@@ -249,8 +265,8 @@ func newEventLogging(options map[string]interface{}) (EventLog, error) {
 		handles: newMessageFilesCache(c.Name, win.QueryEventMessageFiles,
 			win.FreeLibrary),
 		logPrefix:     fmt.Sprintf("EventLogging[%s]", c.Name),
-		readBuf:       make([]byte, 0, win.MaxEventBufferSize),
-		formatBuf:     make([]byte, win.MaxFormatMessageBufferSize),
+		readBuf:       make([]byte, 0, c.ReadBufferSize),
+		formatBuf:     make([]byte, c.FormatBufferSize),
 		eventMetadata: c.EventMetadata,
 	}, nil
 }

winlogbeat/eventlog/eventlogging_test.go

@@ -205,6 +205,64 @@ func TestRead(t *testing.T) {
 	assert.Equal(t, len(messages), int(numMessages))
 }
 
+// Verify that messages whose text is larger than the read buffer cause a
+// message error to be returned. Normally Winlogbeat is run with the largest
+// possible buffer so this error should not occur.
+func TestFormatMessageWithLargeMessage(t *testing.T) {
+	configureLogp()
+	log, err := initLog(providerName, sourceName, eventCreateMsgFile)
+	if err != nil {
+		t.Fatal(err)
+	}
+	defer func() {
+		err := uninstallLog(providerName, sourceName, log)
+		if err != nil {
+			t.Fatal(err)
+		}
+	}()
+
+	message := "Hello"
+	err = log.Report(elog.Info, 1, []string{message})
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	// Messages are received as UTF-16 so we must have enough space in the read
+	// buffer for the message, a windows newline, and a null-terminator.
+	requiredBufferSize := len(message+"\r\n")*2 + 2
+
+	// Read messages:
+	eventlog, err := newEventLogging(map[string]interface{}{
+		"name": providerName,
+		// Use a buffer smaller than what is required.
+		"format_buffer_size": requiredBufferSize / 2,
+	})
+	if err != nil {
+		t.Fatal(err)
+	}
+	err = eventlog.Open(0)
+	if err != nil {
+		t.Fatal(err)
+	}
+	defer func() {
+		err := eventlog.Close()
+		if err != nil {
+			t.Fatal(err)
+		}
+	}()
+	records, err := eventlog.Read()
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	// Validate messages:
+	assert.Len(t, records, 1)
+	for _, record := range records {
+		t.Log(record)
+		assert.Equal(t, "The data area passed to a system call is too small.", record.RenderErr)
+	}
+}
+
 // Test that when an unknown Event ID is found, that a message containing the
 // insert strings (the message parameters) is returned.
 func TestReadUnknownEventId(t *testing.T) {

winlogbeat/sys/eventlogging/eventlogging_windows.go

@@ -151,7 +151,7 @@ func RenderEvents(
 		}
 
 		// Format the parametrized message using the insert strings.
-		event.Message, _, err = formatMessage(record.sourceName,
+		event.Message, err = formatMessage(record.sourceName,
 			record.eventID, lang, stringInsertPtrs, buffer, pubHandleProvider)
 		if err != nil {
 			event.RenderErr = err.Error()
@@ -173,7 +173,7 @@ func unixTime(sec uint32) time.Time {
 	return t
 }
 
-// formatmessage takes event data and formats the event message into a
+// formatMessage takes event data and formats the event message into a
 // normalized format.
 func formatMessage(
 	sourceName string,
@@ -182,7 +182,7 @@ func formatMessage(
 	stringInserts []uintptr,
 	buffer []byte,
 	pubHandleProvider func(string) sys.MessageFiles,
-) (string, int, error) {
+) (string, error) {
 	var addr uintptr
 	if len(stringInserts) > 0 {
 		addr = reflect.ValueOf(&stringInserts[0]).Pointer()
@@ -205,36 +205,44 @@ func formatMessage(
 			Handle(fh.Handle),
 			eventID,
 			lang,
-			&buffer[0],
-			uint32(len(buffer)),
+			&buffer[0],            // Max size allowed is 64k bytes.
+			uint32(len(buffer)/2), // Size of buffer in TCHARS
 			addr)
+		// bufferUsed = numChars * sizeof(TCHAR) + sizeof(null-terminator)
+		bufferUsed := int(numChars*2 + 2)
 		if err == syscall.ERROR_INSUFFICIENT_BUFFER {
-			return "", int(numChars), err
+			return "", err
 		}
 		if err != nil {
 			lastErr = err
 			continue
 		}
 
-		message, _, err = sys.UTF16BytesToString(buffer[:numChars*2])
+		if bufferUsed > len(buffer) {
+			return "", fmt.Errorf("Windows FormatMessage reported that "+
+				"message contains %d characters plus a null-terminator "+
+				"(%d bytes), but the buffer can only hold %d bytes",
+				numChars, bufferUsed, len(buffer))
+		}
+		message, _, err = sys.UTF16BytesToString(buffer[:bufferUsed])
 		if err != nil {
-			return "", 0, err
+			return "", err
 		}
 	}
 
 	if message == "" {
 		switch lastErr {
 		case nil:
-			return "", 0, messageFiles.Err
+			return "", messageFiles.Err
 		case ERROR_MR_MID_NOT_FOUND:
-			return "", 0, fmt.Errorf("The system cannot find message text for "+
+			return "", fmt.Errorf("The system cannot find message text for "+
 				"message number %d in the message file for %s.", eventID, fh.File)
 		default:
-			return "", 0, fh.Err
+			return "", fh.Err
 		}
 	}
 
-	return message, 0, nil
+	return message, nil
 }
 
 // parseEventLogRecord parses a single Windows EVENTLOGRECORD struct from the