Merge pull request #347 from privacybydesign/db-errors

Chore: strip unnecessary details from database errors

CHANGELOG.md

@@ -49,6 +49,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ### Changed
 - Sending the account expiry email is done when user has only valid e-mail addresses
+- Strip unnecessary details from database errors
 
 ### Fixed
 - User account expiry continues when one or more e-mail addresses are marked for revalidation

irma/cmd/keyshare-myirma.go

@@ -111,7 +111,7 @@ func configureMyirmaServer(cmd *cobra.Command) (*myirmaserver.Configuration, err
 		DBType:            myirmaserver.DBType(viper.GetString("db_type")),
 		DBConnStr:         viper.GetString("db_str"),
 		DBConnMaxIdle:     viper.GetInt("db_max_idle"),
-		DBMConnMaxOpen:    viper.GetInt("db_max_open"),
+		DBConnMaxOpen:     viper.GetInt("db_max_open"),
 		DBConnMaxIdleTime: viper.GetInt("db_max_idle_time"),
 		DBConnMaxOpenTime: viper.GetInt("db_max_open_time"),
 

revocation_db.go

@@ -21,6 +21,8 @@ import (
 	"gorm.io/gorm/schema"
 )
 
+var errRevocationDB = errors.New("revocation database error")
+
 type (
 	revocationUpdateHead struct {
 		SignedAccumulator *revocation.SignedAccumulator
@@ -178,6 +180,10 @@ func (s sqlRevStorage) Close() error {
 func (s sqlRevStorage) Exists(id CredentialTypeIdentifier, pkCounter uint) (bool, error) {
 	var c int64
 	err := s.gorm.Model((*AccumulatorRecord)(nil)).Where(map[string]interface{}{"cred_type": id, "pk_counter": pkCounter}).Count(&c).Error
+	if err != nil {
+		Logger.WithError(err).Error("Failed to check if accumulator exists in database")
+		return false, errRevocationDB
+	}
 	return c > 0, err
 }
 
@@ -188,7 +194,8 @@ func (s sqlRevStorage) Events(id CredentialTypeIdentifier, pkCounter uint, from,
 		"cred_type = ? and pk_counter = ? and eventindex >= ? and eventindex < ?",
 		id, pkCounter, from, to,
 	).Error; err != nil {
-		return nil, err
+		Logger.WithError(err).Error("Failed to retrieve revocation events from database")
+		return nil, errRevocationDB
 	}
 	if len(records) == 0 {
 		return nil, ErrRevocationStateNotFound
@@ -236,7 +243,8 @@ func (s sqlRevStorage) LatestAccumulatorUpdates(id CredentialTypeIdentifier, pkC
 		}
 		return nil
 	}); err != nil {
-		return nil, err
+		Logger.WithError(err).Error("Failed to retrieve latest accumulator updates from database")
+		return nil, errRevocationDB
 	}
 
 	return newUpdates(accsMap, eventsMap), nil
@@ -271,7 +279,7 @@ func (s sqlRevStorage) AppendAccumulatorUpdate(
 	id CredentialTypeIdentifier,
 	handler func(heads map[uint]revocationUpdateHead) (map[uint]*revocation.Update, error),
 ) error {
-	return s.gorm.Transaction(func(tx *gorm.DB) error {
+	if err := s.gorm.Transaction(func(tx *gorm.DB) error {
 		// Retrieve the current accumulator state for every public key of the credential and lock the rows for update.
 		var accs []*AccumulatorRecord
 
@@ -317,12 +325,20 @@ func (s sqlRevStorage) AppendAccumulatorUpdate(
 			}
 		}
 		return nil
-	})
+	}); err != nil {
+		Logger.WithError(err).Error("Failed to append accumulator update to database")
+		return errRevocationDB
+	}
+	return nil
 }
 
 // AddIssuanceRecord implements revocationRecordStorage interface.
 func (s sqlRevStorage) AddIssuanceRecord(r *IssuanceRecord) error {
-	return s.gorm.Create(r).Error
+	if err := s.gorm.Create(r).Error; err != nil {
+		Logger.WithError(err).Error("Failed to add issuance record to database")
+		return errRevocationDB
+	}
+	return nil
 }
 
 // IssuanceRecord implements revocationRecordStorage interface.
@@ -345,7 +361,8 @@ func (s sqlRevStorage) UpdateIssuanceRecord(id CredentialTypeIdentifier, key str
 
 		for _, r := range records {
 			if err := tx.Save(r).Error; err != nil {
-				return err
+				Logger.WithError(err).Error("Failed to update issuance record in database")
+				return errRevocationDB
 			}
 		}
 		return nil
@@ -354,7 +371,11 @@ func (s sqlRevStorage) UpdateIssuanceRecord(id CredentialTypeIdentifier, key str
 
 // DeleteExpiredIssuanceRecords implements revocationRecordStorage interface.
 func (s sqlRevStorage) DeleteExpiredIssuanceRecords() error {
-	return s.gorm.Delete(IssuanceRecord{}, "valid_until < ?", time.Now().UnixNano()).Error
+	if err := s.gorm.Delete(IssuanceRecord{}, "valid_until < ?", time.Now().UnixNano()).Error; err != nil {
+		Logger.WithError(err).Error("Failed to delete expired issuance records from database")
+		return errRevocationDB
+	}
+	return nil
 }
 
 // txIssuanceRecords returns all issuance records matching the given credential type, revocation key and issuance time within
@@ -367,7 +388,8 @@ func txIssuanceRecords(tx *gorm.DB, id CredentialTypeIdentifier, key string, iss
 
 	var r []*IssuanceRecord
 	if err := tx.Find(&r, where).Error; err != nil {
-		return nil, err
+		Logger.WithError(err).Error("Failed to retrieve issuance records from database")
+		return nil, errRevocationDB
 	}
 	if len(r) == 0 {
 		return nil, ErrUnknownRevocationKey

server/api.go

@@ -375,8 +375,8 @@ func DoResultCallback(callbackUrl string, result *SessionResult, issuer string,
 	}
 }
 
-func log(level logrus.Level, err error) error {
-	writer := Logger.WithFields(logrus.Fields{"err": TypeString(err)}).WriterLevel(level)
+func log(level logrus.Level, err error, msg ...string) error {
+	writer := Logger.WithFields(logrus.Fields{"err": TypeString(err), "msg": strings.Join(msg, " ")}).WriterLevel(level)
 	if e, ok := err.(*errors.Error); ok && Logger.IsLevelEnabled(logrus.DebugLevel) {
 		_, _ = writer.Write([]byte(e.ErrorStack()))
 	} else {
@@ -385,8 +385,8 @@ func log(level logrus.Level, err error) error {
 	return err
 }
 
-func LogFatal(err error) error {
-	logger := Logger.WithFields(logrus.Fields{"err": TypeString(err)})
+func LogFatal(err error, msg ...string) error {
+	logger := Logger.WithFields(logrus.Fields{"err": TypeString(err), "msg": strings.Join(msg, " ")})
 	// using log() for this doesn't seem to do anything
 	if e, ok := err.(*errors.Error); ok && Logger.IsLevelEnabled(logrus.DebugLevel) {
 		logger.Fatal(e.ErrorStack())
@@ -396,12 +396,12 @@ func LogFatal(err error) error {
 	return err
 }
 
-func LogError(err error) error {
-	return log(logrus.ErrorLevel, err)
+func LogError(err error, msg ...string) error {
+	return log(logrus.ErrorLevel, err, msg...)
 }
 
-func LogWarning(err error) error {
-	return log(logrus.WarnLevel, err)
+func LogWarning(err error, msg ...string) error {
+	return log(logrus.WarnLevel, err, msg...)
 }
 
 func LogRequest(typ, proto, method, url, from string, headers http.Header, message []byte) {

server/keyshare/errors.go

@@ -12,6 +12,7 @@ var (
 	// Database errors:
 
 	ErrUserNotFound = errors.New("could not find specified user")
+	ErrDB           = errors.New("database error")
 
 	// Email errors:
 
@@ -31,6 +32,8 @@ func WriteError(w http.ResponseWriter, err error) {
 	switch err {
 	case ErrUserNotFound:
 		serverError = server.ErrorUserNotRegistered
+	case ErrDB:
+		serverError = server.ErrorInternal
 	case ErrInvalidEmail:
 		serverError = server.ErrorInvalidRequest
 	case ErrInvalidEmailDomain:

server/keyshare/keyshareserver/legacy.go

@@ -13,7 +13,6 @@ import (
 	"github.com/privacybydesign/irmago/internal/keysharecore"
 	"github.com/privacybydesign/irmago/server"
 	"github.com/privacybydesign/irmago/server/keyshare"
-	"github.com/sirupsen/logrus"
 )
 
 // /users/register_publickey
@@ -41,7 +40,7 @@ func (s *Server) handleRegisterPublicKey(w http.ResponseWriter, r *http.Request)
 	// Fetch user
 	user, err := s.db.user(r.Context(), claims.Username)
 	if err != nil {
-		s.conf.Logger.WithFields(logrus.Fields{"username": claims.Username, "error": err}).Warn("Could not find user in db")
+		// Already logged
 		keyshare.WriteError(w, err)
 		return
 	}
@@ -79,17 +78,13 @@ func (s *Server) registerPublicKey(ctx context.Context, user *User, pin string,
 	}
 	user.Secrets = UserSecrets(secrets)
 
-	// Mark pincheck as success, resetting users wait and count
-	err = s.db.resetPinTries(ctx, user)
-	if err != nil {
-		s.conf.Logger.WithField("error", err).Error("Could not reset users pin check logic")
-		// Do not send to user
-	}
+	// Mark pincheck as success, resetting users wait and count. Do not send error to user.
+	_ = s.db.resetPinTries(ctx, user)
 
 	// Write user back
 	err = s.db.updateUser(ctx, user)
 	if err != nil {
-		s.conf.Logger.WithField("error", err).Error("Could not write updated user to database")
+		// Already logged
 		return irma.KeysharePinStatus{}, err
 	}
 
@@ -127,17 +122,13 @@ func (s *Server) updatePinLegacy(ctx context.Context, user *User, oldPin, newPin
 	}
 	user.Secrets = UserSecrets(secrets)
 
-	// Mark pincheck as success, resetting users wait and count
-	err = s.db.resetPinTries(ctx, user)
-	if err != nil {
-		s.conf.Logger.WithField("error", err).Error("Could not reset users pin check logic")
-		// Do not send to user
-	}
+	// Mark pincheck as success, resetting users wait and count. Do not send error to user.
+	_ = s.db.resetPinTries(ctx, user)
 
 	// Write user back
 	err = s.db.updateUser(ctx, user)
 	if err != nil {
-		s.conf.Logger.WithField("error", err).Error("Could not write updated user to database")
+		// Already logged
 		return irma.KeysharePinStatus{}, err
 	}
 
@@ -148,15 +139,15 @@ func (s *Server) handleChangePinLegacy(ctx context.Context, w http.ResponseWrite
 	username := msg.Username
 	user, err := s.db.user(ctx, username)
 	if err != nil {
-		s.conf.Logger.WithFields(logrus.Fields{"username": username, "error": err}).Warn("Could not find user in db")
+		// Already logged
 		keyshare.WriteError(w, err)
 		return
 	}
 
 	result, err := s.updatePinLegacy(ctx, user, msg.OldPin, msg.NewPin)
 
 	if err != nil {
-		// already logged
+		// Already logged
 		keyshare.WriteError(w, err)
 		return
 	}