Other: Add more user-level logs

internal/bridge/imap.go

@@ -129,13 +129,18 @@ func (bridge *Bridge) addIMAPUser(ctx context.Context, user *user.User) error {
 }
 
 // removeIMAPUser disconnects the given user from gluon, optionally also removing its files.
-func (bridge *Bridge) removeIMAPUser(ctx context.Context, user *user.User, withFiles bool) error {
+func (bridge *Bridge) removeIMAPUser(ctx context.Context, user *user.User, withData bool) error {
+	logrus.WithFields(logrus.Fields{
+		"userID":   user.ID(),
+		"withData": withData,
+	}).Debug("Removing IMAP user")
+
 	for addrID, gluonID := range user.GetGluonIDs() {
-		if err := bridge.imapServer.RemoveUser(ctx, gluonID, withFiles); err != nil {
+		if err := bridge.imapServer.RemoveUser(ctx, gluonID, withData); err != nil {
 			return fmt.Errorf("failed to remove IMAP user: %w", err)
 		}
 
-		if withFiles {
+		if withData {
 			if err := user.RemoveGluonID(addrID, gluonID); err != nil {
 				return fmt.Errorf("failed to remove IMAP user ID: %w", err)
 			}

internal/bridge/user.go

@@ -515,6 +515,12 @@ func (bridge *Bridge) newVaultUser(
 
 // logout logs out the given user, optionally logging them out from the API too.
 func (bridge *Bridge) logoutUser(ctx context.Context, user *user.User, withAPI, withData bool) {
+	logrus.WithFields(logrus.Fields{
+		"userID":   user.ID(),
+		"withAPI":  withAPI,
+		"withData": withData,
+	}).Debug("Logging out user")
+
 	if err := bridge.removeIMAPUser(ctx, user, withData); err != nil {
 		logrus.WithError(err).Error("Failed to remove IMAP user")
 	}

internal/user/user.go

@@ -34,6 +34,7 @@ import (
 	"github.com/ProtonMail/gopenpgp/v2/crypto"
 	"github.com/ProtonMail/proton-bridge/v2/internal/async"
 	"github.com/ProtonMail/proton-bridge/v2/internal/events"
+	"github.com/ProtonMail/proton-bridge/v2/internal/logging"
 	"github.com/ProtonMail/proton-bridge/v2/internal/safe"
 	"github.com/ProtonMail/proton-bridge/v2/internal/vault"
 	"github.com/ProtonMail/proton-bridge/v2/pkg/message"
@@ -252,6 +253,8 @@ func (user *User) GetAddressMode() vault.AddressMode {
 
 // SetAddressMode sets the user's address mode.
 func (user *User) SetAddressMode(_ context.Context, mode vault.AddressMode) error {
+	user.log.WithField("mode", mode).Info("Setting address mode")
+
 	user.abortable.Abort()
 	defer user.goSync()
 
@@ -270,6 +273,13 @@ func (user *User) SetAddressMode(_ context.Context, mode vault.AddressMode) erro
 	}, user.apiAddrsLock, user.updateChLock)
 }
 
+// SetShowAllMail sets whether to show the All Mail mailbox.
+func (user *User) SetShowAllMail(show bool) {
+	user.log.WithField("show", show).Info("Setting show all mail")
+
+	atomic.StoreUint32(&user.showAllMail, b32(show))
+}
+
 // GetGluonIDs returns the users gluon IDs.
 func (user *User) GetGluonIDs() map[string]string {
 	return user.vault.GetGluonIDs()
@@ -287,11 +297,21 @@ func (user *User) GetGluonID(addrID string) (string, bool) {
 
 // SetGluonID sets the gluon ID for the given address.
 func (user *User) SetGluonID(addrID, gluonID string) error {
+	user.log.WithFields(logrus.Fields{
+		"addrID":  addrID,
+		"gluonID": gluonID,
+	}).Info("Setting gluon ID")
+
 	return user.vault.SetGluonID(addrID, gluonID)
 }
 
 // RemoveGluonID removes the gluon ID for the given address.
 func (user *User) RemoveGluonID(addrID, gluonID string) error {
+	user.log.WithFields(logrus.Fields{
+		"addrID":  addrID,
+		"gluonID": gluonID,
+	}).Info("Removing gluon ID")
+
 	return user.vault.RemoveGluonID(addrID, gluonID)
 }
 
@@ -477,6 +497,8 @@ func (user *User) SendMail(authID string, from string, to []string, r io.Reader)
 // CheckAuth returns whether the given email and password can be used to authenticate over IMAP or SMTP with this user.
 // It returns the address ID of the authenticated address.
 func (user *User) CheckAuth(email string, password []byte) (string, error) {
+	user.log.WithField("email", logging.Sensitive(email)).Debug("Checking authentication")
+
 	if email == "crash@bandicoot" {
 		panic("your wish is my command.. I crash")
 	}
@@ -503,24 +525,36 @@ func (user *User) CheckAuth(email string, password []byte) (string, error) {
 
 // OnStatusUp is called when the connection goes up.
 func (user *User) OnStatusUp(context.Context) {
+	user.log.Info("Connection is up")
+
 	user.goSync()
 }
 
 // OnStatusDown is called when the connection goes down.
 func (user *User) OnStatusDown(context.Context) {
+	user.log.Info("Connection is down")
+
 	user.abortable.Abort()
 }
 
 // Logout logs the user out from the API.
 func (user *User) Logout(ctx context.Context, withAPI bool) error {
+	user.log.WithField("withAPI", withAPI).Info("Logging out user")
+
+	user.log.Debug("Canceling ongoing tasks")
+
 	user.tasks.CancelAndWait()
 
 	if withAPI {
+		user.log.Debug("Logging out from API")
+
 		if err := user.client.AuthDelete(ctx); err != nil {
 			user.log.WithError(err).Warn("Failed to delete auth")
 		}
 	}
 
+	user.log.Debug("Clearing vault secrets")
+
 	if err := user.vault.Clear(); err != nil {
 		return fmt.Errorf("failed to clear vault: %w", err)
 	}
@@ -530,6 +564,8 @@ func (user *User) Logout(ctx context.Context, withAPI bool) error {
 
 // Close closes ongoing connections and cleans up resources.
 func (user *User) Close() {
+	user.log.Info("Closing user")
+
 	// Stop any ongoing background tasks.
 	user.tasks.CancelAndWait()
 
@@ -552,11 +588,6 @@ func (user *User) Close() {
 	}
 }
 
-// SetShowAllMail sets whether to show the All Mail mailbox.
-func (user *User) SetShowAllMail(show bool) {
-	atomic.StoreUint32(&user.showAllMail, b32(show))
-}
-
 // initUpdateCh initializes the user's update channels in the given address mode.
 // It is assumed that user.apiAddrs and user.updateCh are already locked.
 func (user *User) initUpdateCh(mode vault.AddressMode) {

internal/vault/vault.go

@@ -128,18 +128,26 @@ func (vault *Vault) ForUser(fn func(*User) error) error {
 // AddUser creates a new user in the vault with the given ID and username.
 // A bridge password and gluon key are generated using the package's token generator.
 func (vault *Vault) AddUser(userID, username, authUID, authRef string, keyPass []byte) (*User, error) {
-	if idx := xslices.IndexFunc(vault.get().Users, func(user UserData) bool {
-		return user.UserID == userID
-	}); idx >= 0 {
-		return nil, errors.New("user already exists")
-	}
+	logrus.WithField("userID", userID).Info("Adding vault user")
+
+	var exists bool
 
 	if err := vault.mod(func(data *Data) {
-		data.Users = append(data.Users, newDefaultUser(userID, username, authUID, authRef, keyPass))
+		if idx := xslices.IndexFunc(data.Users, func(user UserData) bool {
+			return user.UserID == userID
+		}); idx >= 0 {
+			exists = true
+		} else {
+			data.Users = append(data.Users, newDefaultUser(userID, username, authUID, authRef, keyPass))
+		}
 	}); err != nil {
 		return nil, err
 	}
 
+	if exists {
+		return nil, errors.New("user already exists")
+	}
+
 	return vault.NewUser(userID)
 }
 
@@ -148,6 +156,8 @@ func (vault *Vault) DeleteUser(userID string) error {
 	vault.refLock.Lock()
 	defer vault.refLock.Unlock()
 
+	logrus.WithField("userID", userID).Info("Deleting vault user")
+
 	if _, ok := vault.ref[userID]; ok {
 		return fmt.Errorf("user %s is currently in use", userID)
 	}