From 749ff9ec2b97fcf59eca383d73ced679aa81ebcd Mon Sep 17 00:00:00 2001
From: gillespi314 <73313222+gillespi314@users.noreply.github.com>
Date: Tue, 27 Sep 2022 14:32:46 -0500
Subject: [PATCH] Add logging to capture user email upon successful login
 (#7927)

* Log user email upon successful login

* Add user email to logger context

* Use logging.With Extras for login email
---
 changes/issue-7888-login-logs             |  1 +
 server/contexts/logging/logging.go        |  1 -
 server/service/integration_logger_test.go | 57 ++++++++++++++++++++++-
 server/service/sessions.go                |  2 +-
 server/service/sessions_test.go           |  2 +-
 5 files changed, 59 insertions(+), 4 deletions(-)
 create mode 100644 changes/issue-7888-login-logs

diff --git a/changes/issue-7888-login-logs b/changes/issue-7888-login-logs
new file mode 100644
index 0000000000..8fe1be9580
--- /dev/null
+++ b/changes/issue-7888-login-logs
@@ -0,0 +1 @@
+* Added logging to capture user email upon successful login
\ No newline at end of file
diff --git a/server/contexts/logging/logging.go b/server/contexts/logging/logging.go
index 1816a2c12c..3a3abdf60c 100644
--- a/server/contexts/logging/logging.go
+++ b/server/contexts/logging/logging.go
@@ -132,7 +132,6 @@ func (l *LoggingContext) Log(ctx context.Context, logger kitlog.Logger) {
 		}
 		keyvals = append(keyvals, "user", loggedInUser)
 	}
-
 	requestMethod, ok := ctx.Value(kithttp.ContextKeyRequestMethod).(string)
 	if !ok {
 		requestMethod = ""
diff --git a/server/service/integration_logger_test.go b/server/service/integration_logger_test.go
index ae17eb2ee5..1213a7a134 100644
--- a/server/service/integration_logger_test.go
+++ b/server/service/integration_logger_test.go
@@ -86,7 +86,7 @@ func (s *integrationLoggerTestSuite) TestLogger() {
 			assert.Equal(t, "GET", kv["method"])
 			assert.Equal(t, "/api/latest/fleet/config", kv["uri"])
 			assert.Equal(t, "admin1@example.com", kv["user"])
-		case 2:
+		case 3:
 			assert.Equal(t, "debug", kv["level"])
 			assert.Equal(t, "POST", kv["method"])
 			assert.Equal(t, "/api/latest/fleet/queries", kv["uri"])
@@ -99,6 +99,61 @@ func (s *integrationLoggerTestSuite) TestLogger() {
 	}
 }
 
+func (s *integrationLoggerTestSuite) TestLoggerLogin() {
+	t := s.T()
+
+	type logEntry struct {
+		key string
+		val string
+	}
+
+	testCases := []struct {
+		loginRequest   loginRequest
+		expectedStatus int
+		expectedLogs   []logEntry
+	}{
+		{
+			loginRequest:   loginRequest{Email: testUsers["admin1"].Email, Password: testUsers["admin1"].PlaintextPassword},
+			expectedStatus: http.StatusOK,
+			expectedLogs:   []logEntry{{"email", testUsers["admin1"].Email}},
+		},
+		{
+			loginRequest:   loginRequest{Email: testUsers["admin1"].Email, Password: "n074v411dp455w02d"},
+			expectedStatus: http.StatusUnauthorized,
+			expectedLogs: []logEntry{
+				{"email", testUsers["admin1"].Email},
+				{"level", "error"},
+				{"internal", "invalid password"},
+			},
+		},
+		{
+			loginRequest:   loginRequest{Email: "h4x0r@3x4mp13.c0m", Password: "n074v411dp455w02d"},
+			expectedStatus: http.StatusUnauthorized,
+			expectedLogs: []logEntry{
+				{"email", "h4x0r@3x4mp13.c0m"},
+				{"level", "error"},
+				{"internal", "user not found"},
+			},
+		},
+	}
+	var resp loginResponse
+	for _, tt := range testCases {
+		s.DoJSON("POST", "/api/latest/fleet/login", tt.loginRequest, tt.expectedStatus, &resp)
+		logString := s.buf.String()
+		parts := strings.Split(strings.TrimSpace(logString), "\n")
+		require.Len(t, parts, 1)
+		logData := make(map[string]string)
+		require.NoError(t, json.Unmarshal([]byte(parts[0]), &logData))
+
+		require.NotContains(t, logData, "user") // logger context is set to skip user
+
+		for _, e := range tt.expectedLogs {
+			assert.Equal(t, logData[e.key], e.val)
+		}
+		s.buf.Reset()
+	}
+}
+
 func (s *integrationLoggerTestSuite) TestOsqueryEndpointsLogErrors() {
 	t := s.T()
 
diff --git a/server/service/sessions.go b/server/service/sessions.go
index 5086cf6318..d9b009dd69 100644
--- a/server/service/sessions.go
+++ b/server/service/sessions.go
@@ -153,7 +153,7 @@ func (svc *Service) Login(ctx context.Context, email, password string) (*fleet.U
 	// skipauth: No user context available yet to authorize against.
 	svc.authz.SkipAuthorization(ctx)
 
-	logging.WithLevel(logging.WithNoUser(ctx), level.Info)
+	logging.WithLevel(logging.WithExtras(logging.WithNoUser(ctx), "email", email), level.Info)
 
 	// If there is an error, sleep until the request has taken at least 1
 	// second. This means that generally a login failure for any reason will
diff --git a/server/service/sessions_test.go b/server/service/sessions_test.go
index 36305f2b4b..9a2c8d3473 100644
--- a/server/service/sessions_test.go
+++ b/server/service/sessions_test.go
@@ -98,7 +98,7 @@ func TestAuthenticate(t *testing.T) {
 	svc := newTestService(t, ds, nil, nil)
 	createTestUsers(t, ds)
 
-	var loginTests = []struct {
+	loginTests := []struct {
 		name     string
 		email    string
 		password string