From 893aa3b1414f46a44900e7377b5b471cb2aff0f3 Mon Sep 17 00:00:00 2001
From: Neil Alexander <neilalexander@users.noreply.github.com>
Date: Mon, 31 Jan 2022 16:01:54 +0000
Subject: [PATCH] More logging tweaks

---
 roomserver/internal/input/input_missing.go   |  8 ++++----
 roomserver/internal/perform/perform_join.go  | 14 +++++++++-----
 roomserver/internal/perform/perform_leave.go | 12 ++++++++----
 3 files changed, 21 insertions(+), 13 deletions(-)

diff --git a/roomserver/internal/input/input_missing.go b/roomserver/internal/input/input_missing.go
index 02ff0f8d..d401fa0e 100644
--- a/roomserver/internal/input/input_missing.go
+++ b/roomserver/internal/input/input_missing.go
@@ -666,7 +666,7 @@ func (t *missingStateReq) createRespStateFromStateIDs(stateIDs gomatrixserverlib
 	for i := range stateIDs.StateEventIDs {
 		ev, ok := t.haveEvents[stateIDs.StateEventIDs[i]]
 		if !ok {
-			logrus.Warnf("Missing state event in createRespStateFromStateIDs: %s", stateIDs.StateEventIDs[i])
+			logrus.Tracef("Missing state event in createRespStateFromStateIDs: %s", stateIDs.StateEventIDs[i])
 			continue
 		}
 		respState.StateEvents = append(respState.StateEvents, ev.Unwrap())
@@ -674,7 +674,7 @@ func (t *missingStateReq) createRespStateFromStateIDs(stateIDs gomatrixserverlib
 	for i := range stateIDs.AuthEventIDs {
 		ev, ok := t.haveEvents[stateIDs.AuthEventIDs[i]]
 		if !ok {
-			logrus.Warnf("Missing auth event in createRespStateFromStateIDs: %s", stateIDs.AuthEventIDs[i])
+			logrus.Tracef("Missing auth event in createRespStateFromStateIDs: %s", stateIDs.AuthEventIDs[i])
 			continue
 		}
 		respState.AuthEvents = append(respState.AuthEvents, ev.Unwrap())
@@ -718,7 +718,7 @@ func (t *missingStateReq) lookupEvent(ctx context.Context, roomVersion gomatrixs
 		}
 		event, err = gomatrixserverlib.NewEventFromUntrustedJSON(txn.PDUs[0], roomVersion)
 		if err != nil {
-			util.GetLogger(ctx).WithError(err).WithField("event_id", missingEventID).Warnf("Transaction: Failed to parse event JSON of event")
+			util.GetLogger(ctx).WithError(err).WithField("event_id", missingEventID).Warnf("Failed to parse event JSON of event returned from /event")
 			continue
 		}
 		found = true
@@ -729,7 +729,7 @@ func (t *missingStateReq) lookupEvent(ctx context.Context, roomVersion gomatrixs
 		return nil, fmt.Errorf("wasn't able to find event via %d server(s)", len(t.servers))
 	}
 	if err := event.VerifyEventSignatures(ctx, t.keys); err != nil {
-		util.GetLogger(ctx).WithError(err).Warnf("Transaction: Couldn't validate signature of event %q", event.EventID())
+		util.GetLogger(ctx).WithError(err).Warnf("Couldn't validate signature of event %q from /event", event.EventID())
 		return nil, verifySigError{event.EventID(), err}
 	}
 	return t.cacheAndReturn(event.Headered(roomVersion)), nil
diff --git a/roomserver/internal/perform/perform_join.go b/roomserver/internal/perform/perform_join.go
index dfa21bcb..9d2a66d4 100644
--- a/roomserver/internal/perform/perform_join.go
+++ b/roomserver/internal/perform/perform_join.go
@@ -51,13 +51,15 @@ func (r *Joiner) PerformJoin(
 	req *rsAPI.PerformJoinRequest,
 	res *rsAPI.PerformJoinResponse,
 ) {
+	logger := logrus.WithContext(ctx).WithFields(logrus.Fields{
+		"room_id": req.RoomIDOrAlias,
+		"user_id": req.UserID,
+		"servers": req.ServerNames,
+	})
+	logger.Info("User requested to room join")
 	roomID, joinedVia, err := r.performJoin(context.Background(), req)
 	if err != nil {
-		logrus.WithContext(ctx).WithFields(logrus.Fields{
-			"room_id": req.RoomIDOrAlias,
-			"user_id": req.UserID,
-			"servers": req.ServerNames,
-		}).WithError(err).Error("Failed to join room")
+		logger.WithError(err).Error("Failed to join room")
 		sentry.CaptureException(err)
 		perr, ok := err.(*rsAPI.PerformError)
 		if ok {
@@ -67,7 +69,9 @@ func (r *Joiner) PerformJoin(
 				Msg: err.Error(),
 			}
 		}
+		return
 	}
+	logger.Info("User joined room successfully")
 	res.RoomID = roomID
 	res.JoinedVia = joinedVia
 }
diff --git a/roomserver/internal/perform/perform_leave.go b/roomserver/internal/perform/perform_leave.go
index 3c46e657..12784e5f 100644
--- a/roomserver/internal/perform/perform_leave.go
+++ b/roomserver/internal/perform/perform_leave.go
@@ -51,13 +51,17 @@ func (r *Leaver) PerformLeave(
 	if domain != r.Cfg.Matrix.ServerName {
 		return nil, fmt.Errorf("user %q does not belong to this homeserver", req.UserID)
 	}
+	logger := logrus.WithContext(ctx).WithFields(logrus.Fields{
+		"room_id": req.RoomID,
+		"user_id": req.UserID,
+	})
+	logger.Info("User requested to leave join")
 	if strings.HasPrefix(req.RoomID, "!") {
 		output, err := r.performLeaveRoomByID(context.Background(), req, res)
 		if err != nil {
-			logrus.WithContext(ctx).WithFields(logrus.Fields{
-				"room_id": req.RoomID,
-				"user_id": req.UserID,
-			}).WithError(err).Error("Failed to leave room")
+			logger.WithError(err).Error("Failed to leave room")
+		} else {
+			logger.Info("User left room successfully")
 		}
 		return output, err
 	}