user: use structured logging

Signed-off-by: Sumner Evans <[email protected]>

portal.go

@@ -957,7 +957,7 @@ func (portal *Portal) handleSignalNormalDataMessage(source *User, sender *Puppet
 			return
 		}
 		// FIXME hacky
-		ensureGroupPuppetsAreJoinedToPortal(context.Background(), source, portal)
+		ensureGroupPuppetsAreJoinedToPortal(log.WithContext(context.Background()), source, portal)
 		signalmeow.SendContactSyncRequest(context.TODO(), source.SignalDevice)
 	}
 

user.go

@@ -676,42 +676,48 @@ func updatePuppetWithSignalContact(ctx context.Context, user *User, puppet *Pupp
 }
 
 func ensureGroupPuppetsAreJoinedToPortal(ctx context.Context, user *User, portal *Portal) error {
+	log := zerolog.Ctx(ctx).With().
+		Str("function", "ensure group puppets are joined to portal").
+		Stringer("room_id", portal.MXID).
+		Logger()
 	// Ensure our puppet is joined to the room
 	err := portal.MainIntent().EnsureJoined(portal.MXID)
 	if err != nil {
-		user.log.Err(err).Msg("error ensuring joined")
+		log.Err(err).Msg("error ensuring joined")
 		return err
 	}
 
 	// Check if ChatID is a groupID (not a UUID), otherwise do nothing else
 	// TODO: do better than passing around strings and seeing if they are UUIDs or not
 	if _, err := uuid.Parse(portal.ChatID); err == nil {
+		log.Debug().Msg("ChatID is a UUID, not a groupID, skipping")
 		return nil
 	}
-	user.log.Info().Msgf("Ensuring everyone is joined to room %s, groupID: %s", portal.MXID, portal.ChatID)
+	log.Info().Msg("Ensuring everyone is joined to room")
 	group, err := signalmeow.RetrieveGroupByID(ctx, user.SignalDevice, types.GroupIdentifier(portal.ChatID))
 	if err != nil {
-		user.log.Err(err).Msg("error retrieving group")
+		log.Err(err).Msg("error retrieving group")
 		return err
 	}
 	for _, member := range group.Members {
+		log := log.With().Str("member_uuid", member.UserID).Logger()
 		parsedUserID, err := uuid.Parse(member.UserID)
 		if err != nil {
-			// TODO log?
+			log.Err(err).Msg("error parsing UUID")
 			continue
 		}
 		if parsedUserID == user.SignalID {
 			continue
 		}
 		memberPuppet := portal.bridge.GetPuppetBySignalID(parsedUserID)
 		if memberPuppet == nil {
-			user.log.Err(err).Msgf("no puppet found for signalID %s", member.UserID)
+			log.Err(err).Msg("no puppet found for signal ID")
 			continue
 		}
 		_ = updatePuppetWithSignalContact(context.TODO(), user, memberPuppet, nil)
 		err = memberPuppet.DefaultIntent().EnsureJoined(portal.MXID)
 		if err != nil {
-			user.log.Err(err).Msg("error ensuring joined")
+			log.Err(err).Msg("error ensuring joined")
 		}
 	}
 	return nil
@@ -859,7 +865,9 @@ func (user *User) syncPortalInfo(portal *Portal) {
 		if portal.ExpirationTime != int(group.DisappearingMessagesDuration) {
 			portal.ExpirationTime = int(group.DisappearingMessagesDuration)
 			updatePortal = true
-			portal.log.Debug().Msgf("Updating expiration time to %d (group)", group.DisappearingMessagesDuration)
+			portal.log.Debug().
+				Uint32("disappearing_messages_duration", group.DisappearingMessagesDuration).
+				Msg("Updating expiration time for group")
 			// TODO send message
 			//portal.HandleNewDisappearingMessageTime(group.DisappearingMessagesDuration)
 		}
@@ -881,7 +889,7 @@ func (user *User) syncPortalInfo(portal *Portal) {
 		if portal.MXID != "" {
 			// ensure everyone is invited to the group
 			portal.ensureUserInvited(user)
-			_ = ensureGroupPuppetsAreJoinedToPortal(context.Background(), user, portal)
+			_ = ensureGroupPuppetsAreJoinedToPortal(portal.log.WithContext(context.Background()), user, portal)
 			go portal.addToPersonalSpace(portal.log.WithContext(context.TODO()), user)
 		}
 	} else if portal.shouldSetDMRoomMetadata() {