[Auditbeat] Handle different bad login types (elastic#10865)

Depending on the distro and the type of login attempt (e.g. ssh, local login) the `ut_type` value in `/var/log/btmp` is different. So far, the login dataset only responded to the rarer login type `7` (`USER_PROCESS`). The more common one (seems to be exclusively used on Fedora 29, but also used on Ubuntu 18.04 for failed SSH login attempts) is `6` (`LOGIN_PROCESS`) that we are currently ignoring.

This changes the code to have a separate function to process UTMP records from btmp files that treats both `USER_PROCESS` and `LOGIN_PROCESS` the same.

It also adds a unit test for failed logins including a btmp test file from Ubuntu 18.04 with three bad login attempts.

(cherry picked from commit 94666a8)

CHANGELOG.next.asciidoc

@@ -78,6 +78,7 @@ https://github.com/elastic/beats/compare/v6.6.0...6.x[Check the HEAD diff]
 
 - Enable System module config on Windows. {pull}10237[10237]
 - Package: Disable librpm signal handlers. {pull}10694[10694]
+- Login: Handle different bad login UTMP types. {pull}10865[10865]
 
 *Filebeat*
 

x-pack/auditbeat/module/system/login/login_test.go

@@ -9,10 +9,15 @@ package login
 import (
 	"encoding/binary"
 	"io/ioutil"
+	"net"
 	"os"
 	"testing"
+	"time"
+
+	"github.com/stretchr/testify/assert"
 
 	"github.com/elastic/beats/auditbeat/core"
+	"github.com/elastic/beats/libbeat/common"
 	"github.com/elastic/beats/libbeat/paths"
 	mbtest "github.com/elastic/beats/metricbeat/mb/testing"
 )
@@ -24,7 +29,10 @@ func TestData(t *testing.T) {
 
 	defer setup(t)()
 
-	f := mbtest.NewReportingMetricSetV2(t, getConfig())
+	config := getBaseConfig()
+	config["login.wtmp_file_pattern"] = "../../../tests/files/wtmp"
+	config["login.btmp_file_pattern"] = ""
+	f := mbtest.NewReportingMetricSetV2(t, config)
 
 	events, errs := mbtest.ReportingFetchV2(f)
 	if len(errs) > 0 {
@@ -34,19 +42,105 @@ func TestData(t *testing.T) {
 	if len(events) == 0 {
 		t.Fatal("no events were generated")
 	} else if len(events) != 1 {
-		t.Fatal("only one event expected")
+		t.Fatalf("only one event expected, got %d", len(events))
 	}
 
 	fullEvent := mbtest.StandardizeEvent(f, events[0], core.AddDatasetToEvent)
 	mbtest.WriteEventToDataJSON(t, fullEvent, "")
 }
 
-func getConfig() map[string]interface{} {
+func TestFailedLogins(t *testing.T) {
+	if byteOrder != binary.LittleEndian {
+		t.Skip("Test only works on little-endian systems - skipping.")
+	}
+
+	defer setup(t)()
+
+	config := getBaseConfig()
+	config["login.wtmp_file_pattern"] = ""
+	config["login.btmp_file_pattern"] = "../../../tests/files/btmp_ubuntu1804"
+	f := mbtest.NewReportingMetricSetV2(t, config)
+
+	events, errs := mbtest.ReportingFetchV2(f)
+	if len(errs) > 0 {
+		t.Fatalf("received error: %+v", errs[0])
+	}
+
+	if len(events) == 0 {
+		t.Fatal("no events were generated")
+	} else if len(events) != 4 {
+		t.Fatalf("expected 4 events, got %d", len(events))
+	}
+
+	// utmpdump: [6] [03307] [    ] [root    ] [ssh:notty   ] [10.0.2.2            ] [10.0.2.2       ] [2019-02-20T17:42:26,000000+0000]
+	checkFieldValue(t, events[0].RootFields, "event.kind", "event")
+	checkFieldValue(t, events[0].RootFields, "event.action", "user_login")
+	checkFieldValue(t, events[0].RootFields, "event.outcome", "failure")
+	checkFieldValue(t, events[0].RootFields, "process.pid", 3307)
+	checkFieldValue(t, events[0].RootFields, "source.ip", "10.0.2.2")
+	checkFieldValue(t, events[0].RootFields, "user.id", 0)
+	checkFieldValue(t, events[0].RootFields, "user.name", "root")
+	checkFieldValue(t, events[0].RootFields, "user.terminal", "ssh:notty")
+	assert.True(t, events[0].Timestamp.Equal(time.Date(2019, 2, 20, 17, 42, 26, 0, time.UTC)),
+		"Timestamp is not equal: %+v", events[0].Timestamp)
+
+	// The second UTMP entry in the btmp test file is a duplicate of the first, this is what Ubuntu 18.04 generates.
+	// utmpdump: [6] [03307] [    ] [root    ] [ssh:notty   ] [10.0.2.2            ] [10.0.2.2       ] [2019-02-20T17:42:26,000000+0000]
+	checkFieldValue(t, events[1].RootFields, "event.kind", "event")
+	checkFieldValue(t, events[1].RootFields, "event.action", "user_login")
+	checkFieldValue(t, events[1].RootFields, "event.outcome", "failure")
+	checkFieldValue(t, events[1].RootFields, "process.pid", 3307)
+	checkFieldValue(t, events[1].RootFields, "source.ip", "10.0.2.2")
+	checkFieldValue(t, events[1].RootFields, "user.id", 0)
+	checkFieldValue(t, events[1].RootFields, "user.name", "root")
+	checkFieldValue(t, events[1].RootFields, "user.terminal", "ssh:notty")
+	assert.True(t, events[1].Timestamp.Equal(time.Date(2019, 2, 20, 17, 42, 26, 0, time.UTC)),
+		"Timestamp is not equal: %+v", events[1].Timestamp)
+
+	// utmpdump: [7] [03788] [/0  ] [elastic ] [pts/0       ] [                    ] [0.0.0.0        ] [2019-02-20T17:45:08,447344+0000]
+	checkFieldValue(t, events[2].RootFields, "event.kind", "event")
+	checkFieldValue(t, events[2].RootFields, "event.action", "user_login")
+	checkFieldValue(t, events[2].RootFields, "event.outcome", "failure")
+	checkFieldValue(t, events[2].RootFields, "process.pid", 3788)
+	checkFieldValue(t, events[2].RootFields, "source.ip", "0.0.0.0")
+	checkFieldValue(t, events[2].RootFields, "user.name", "elastic")
+	checkFieldValue(t, events[2].RootFields, "user.terminal", "pts/0")
+	assert.True(t, events[2].Timestamp.Equal(time.Date(2019, 2, 20, 17, 45, 8, 447344000, time.UTC)),
+		"Timestamp is not equal: %+v", events[2].Timestamp)
+
+	// utmpdump: [7] [03788] [/0  ] [UNKNOWN ] [pts/0       ] [                    ] [0.0.0.0        ] [2019-02-20T17:45:15,765318+0000]
+	checkFieldValue(t, events[3].RootFields, "event.kind", "event")
+	checkFieldValue(t, events[3].RootFields, "event.action", "user_login")
+	checkFieldValue(t, events[3].RootFields, "event.outcome", "failure")
+	checkFieldValue(t, events[3].RootFields, "process.pid", 3788)
+	checkFieldValue(t, events[3].RootFields, "source.ip", "0.0.0.0")
+	contains, err := events[3].RootFields.HasKey("user.id")
+	if assert.NoError(t, err) {
+		assert.False(t, contains)
+	}
+	checkFieldValue(t, events[3].RootFields, "user.name", "UNKNOWN")
+	checkFieldValue(t, events[3].RootFields, "user.terminal", "pts/0")
+	assert.True(t, events[3].Timestamp.Equal(time.Date(2019, 2, 20, 17, 45, 15, 765318000, time.UTC)),
+		"Timestamp is not equal: %+v", events[3].Timestamp)
+}
+
+func checkFieldValue(t *testing.T, mapstr common.MapStr, fieldName string, fieldValue interface{}) {
+	value, err := mapstr.GetValue(fieldName)
+	if assert.NoError(t, err) {
+		switch v := value.(type) {
+		case *net.IP:
+			assert.Equal(t, fieldValue, v.String())
+		default:
+			assert.Equal(t, fieldValue, v)
+		}
+
+	}
+}
+
+func getBaseConfig() map[string]interface{} {
 	return map[string]interface{}{
-		"module":                  "system",
-		"datasets":                []string{"login"},
-		"login.wtmp_file_pattern": "../../../tests/files/wtmp",
-		"login.btmp_file_pattern": "",
+		"module":   "system",
+		"datasets": []string{"login"},
 	}
 }
 

x-pack/auditbeat/module/system/login/utmp.go

@@ -242,13 +242,19 @@ func (r *UtmpFileReader) readNewInFile(loginRecordC chan<- LoginRecord, errorC c
 				r.log.Debugf("utmp: (ut_type=%d, ut_pid=%d, ut_line=%v, ut_user=%v, ut_host=%v, ut_tv.tv_sec=%v, ut_addr_v6=%v)",
 					utmp.UtType, utmp.UtPid, utmp.UtLine, utmp.UtUser, utmp.UtHost, utmp.UtTv, utmp.UtAddrV6)
 
-				loginRecord := r.processLoginRecord(utmp)
-				if loginRecord != nil {
-					loginRecord.Origin = utmpFile.Path
-					if utmpFile.Type == Btmp && loginRecord.Type == userLoginRecord {
-						loginRecord.Type = userLoginFailedRecord
+				var loginRecord *LoginRecord
+				switch utmpFile.Type {
+				case Wtmp:
+					loginRecord = r.processGoodLoginRecord(utmp)
+				case Btmp:
+					loginRecord, err = r.processBadLoginRecord(utmp)
+					if err != nil {
+						errorC <- err
 					}
+				}
 
+				if loginRecord != nil {
+					loginRecord.Origin = utmpFile.Path
 					loginRecordC <- *loginRecord
 				}
 			} else {
@@ -275,10 +281,39 @@ func (r *UtmpFileReader) updateSavedUtmpFile(utmpFile UtmpFile, f *os.File) erro
 	return nil
 }
 
-// processLoginRecord receives UTMP login records in order and returns
+// processBadLoginRecord takes a UTMP login record from the "bad" login file (/var/log/btmp)
+// and returns a LoginRecord for it.
+func (r *UtmpFileReader) processBadLoginRecord(utmp *Utmp) (*LoginRecord, error) {
+	record := LoginRecord{
+		Utmp:      utmp,
+		Timestamp: utmp.UtTv,
+		TTY:       utmp.UtLine,
+		UID:       -1,
+		PID:       -1,
+	}
+
+	switch utmp.UtType {
+	// See utmp(5) for C constants.
+	case LOGIN_PROCESS, USER_PROCESS:
+		record.Type = userLoginFailedRecord
+
+		record.Username = utmp.UtUser
+		record.UID = lookupUsername(record.Username)
+		record.PID = utmp.UtPid
+		record.IP = newIP(utmp.UtAddrV6)
+		record.Hostname = utmp.UtHost
+	default:
+		// This should not happen.
+		return nil, errors.Errorf("UTMP record with unexpected type %v in bad login file", utmp.UtType)
+	}
+
+	return &record, nil
+}
+
+// processGoodLoginRecord receives UTMP login records in order and returns
 // a corresponding LoginRecord. Some UTMP records do not translate
 // into a LoginRecord, in this case the return value is nil.
-func (r *UtmpFileReader) processLoginRecord(utmp *Utmp) *LoginRecord {
+func (r *UtmpFileReader) processGoodLoginRecord(utmp *Utmp) *LoginRecord {
 	record := LoginRecord{
 		Utmp:      utmp,
 		Timestamp: utmp.UtTv,
@@ -358,6 +393,7 @@ func (r *UtmpFileReader) processLoginRecord(utmp *Utmp) *LoginRecord {
 			  interesting information
 			- ACCOUNTING - not implemented according to manpage
 		*/
+		r.log.Debugf("Ignoring UTMP record of type %v.", utmp.UtType)
 		return nil
 	}