Merge branch 'dovecot-logging' into 'master'

Fix dovecot-keylookupd logging to log a single line per request

See merge request !33

dovecot/keyproxy.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"encoding/base64"
 	"errors"
+	"fmt"
 	"log"
 	"strings"
 
@@ -153,15 +154,17 @@ func (s *KeyLookupProxy) lookupUserdb(ctx context.Context, username string) (int
 func (s *KeyLookupProxy) lookupPassdb(ctx context.Context, username, password string) (interface{}, bool, error) {
 	// The password might be a SSO token, so first of all we try
 	// to fetch the unencrypted key from the keystore daemon.
+	var keystoreStatus string
 	priv, err := s.keystore.Get(ctx, s.config.Shard, username, password)
 	switch {
 	case err == client.ErrNoKeys:
-		log.Printf("no encryption keys for %s in keystore", username)
+		keystoreStatus = "no keys available"
 	case isErr403(err):
-		log.Printf("no encryption keys for %s in keystore (no SSO token)", username)
+		keystoreStatus = "no SSO token"
 	case err != nil:
 		// This is an unexpected error.
 		log.Printf("keystore lookup for %s failed: %v", username, err)
+		keystoreStatus = fmt.Sprintf("unexpected error: %v", err)
 	default:
 		log.Printf("passdb lookup for %s (from keystore)", username)
 		return newPassDBResponse(s.b64encode(priv)), true, nil
@@ -174,20 +177,22 @@ func (s *KeyLookupProxy) lookupPassdb(ctx context.Context, username, password st
 		return nil, false, err
 	}
 	if len(encKeys) == 0 {
+		// If there are no keys in the db, the keystore status
+		// is not really relevant.
 		log.Printf("no encryption keys for %s in database", username)
 		return nil, false, nil
 	}
 	key, err := userenckey.Decrypt(encKeys, []byte(password))
 	if err != nil {
-		log.Printf("failed passdb lookup for %s (could not decrypt key)", username)
+		log.Printf("failed passdb lookup for %s (could not decrypt key), keystore status: %s", username, keystoreStatus)
 		return nil, false, err
 	}
 	priv, err = key.PEM()
 	if err != nil {
-		log.Printf("failed passdb lookup for %s (obtained invalid key: %v)", username, err)
+		log.Printf("failed passdb lookup for %s (obtained invalid key: %v), keystore status: %s", username, err, keystoreStatus)
 		return nil, false, err
 	}
-	log.Printf("passdb lookup for %s (decrypted)", username)
+	log.Printf("passdb lookup for %s (from database)", username)
 	return newPassDBResponse(s.b64encode(priv)), true, nil
 }