Standardise logging of failed authentication attempts in internal SSH (#13962)

Continuing on from #13953 continue to improve and standardise
logging from internal SSH.

Also updates the fail2ban setup

Signed-off-by: Andrew Thornton <art27@cantab.net>

diff --git a/docs/content/doc/usage/fail2ban-setup.en-us.md b/docs/content/doc/usage/fail2ban-setup.en-us.md
index 5c5bdb9a2853965a5771e787084e44de7ec8a78e..790d4c020b65230efec61db6fb998f90f81b91ff 100644 (file)
--- a/docs/content/doc/usage/fail2ban-setup.en-us.md
+++ b/docs/content/doc/usage/fail2ban-setup.en-us.md
@@ -25,9 +25,27 @@ on a bad authentication from the web or CLI using SSH or HTTP respectively:
 ```log
 2018/04/26 18:15:54 [I] Failed authentication attempt for user from xxx.xxx.xxx.xxx
 ```
+
+```log
+2020/10/15 16:05:09 modules/ssh/ssh.go:143:publicKeyHandler() [W] Failed authentication attempt from xxx.xxx.xxx.xxx
+```
+
+```log
+2020/10/15 16:05:09 modules/ssh/ssh.go:155:publicKeyHandler() [W] Failed authentication attempt from xxx.xxx.xxx.xxx
+```
+
 ```log
-2020/10/15 16:05:09 modules/ssh/ssh.go:188:publicKeyHandler() [E] SearchPublicKeyByContent: public key does not exist [id: 0] Failed authentication attempt from xxx.xxx.xxx.xxx
+2020/10/15 16:05:09 modules/ssh/ssh.go:198:publicKeyHandler() [W] Failed authentication attempt from xxx.xxx.xxx.xxx
 ```
+
+```log
+2020/10/15 16:05:09 modules/ssh/ssh.go:213:publicKeyHandler() [W] Failed authentication attempt from xxx.xxx.xxx.xxx
+```
+
+```log
+2020/10/15 16:05:09 modules/ssh/ssh.go:227:publicKeyHandler() [W] Failed authentication attempt from xxx.xxx.xxx.xxx
+```
+
 ```log
 2020/10/15 16:08:44 ...s/context/context.go:204:HandleText() [E] invalid credentials from xxx.xxx.xxx.xxx
 ```

diff --git a/modules/ssh/ssh.go b/modules/ssh/ssh.go
index e8ed9029ce39c8dec57b41703f1a97870a962f2b..4ba52d56537bf93dee76dfafcc170ab3dedd8b9a 100644 (file)
--- a/modules/ssh/ssh.go
+++ b/modules/ssh/ssh.go
@@ -134,14 +134,25 @@ func sessionHandler(session ssh.Session) {
 }
 
 func publicKeyHandler(ctx ssh.Context, key ssh.PublicKey) bool {
+       if log.IsDebug() { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
+               log.Debug("Handle Public Key: Fingerprint: %s from %s", gossh.FingerprintSHA256(key), ctx.RemoteAddr())
+       }
+
        if ctx.User() != setting.SSH.BuiltinServerUser {
-               log.Warn("Permission Denied: Invalid SSH username %s - must use %s for all git operations via ssh", ctx.User(), setting.SSH.BuiltinServerUser)
+               log.Warn("Invalid SSH username %s - must use %s for all git operations via ssh", ctx.User(), setting.SSH.BuiltinServerUser)
+               log.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
                return false
        }
 
        // check if we have a certificate
        if cert, ok := key.(*gossh.Certificate); ok {
+               if log.IsDebug() { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
+                       log.Debug("Handle Certificate: %s Fingerprint: %s is a certificate", ctx.RemoteAddr(), gossh.FingerprintSHA256(key))
+               }
+
                if len(setting.SSH.TrustedUserCAKeys) == 0 {
+                       log.Warn("Certificate Rejected: No trusted certificate authorities for this server")
+                       log.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
                        return false
                }
 
@@ -151,7 +162,7 @@ func publicKeyHandler(ctx ssh.Context, key ssh.PublicKey) bool {
                        pkey, err := models.SearchPublicKeyByContentExact(principal)
                        if err != nil {
                                if models.IsErrKeyNotExist(err) {
-                                       log.Debug("Principal Rejected: Unknown Principal: %s", principal)
+                                       log.Debug("Principal Rejected: %s Unknown Principal: %s", ctx.RemoteAddr(), principal)
                                        continue principalLoop
                                }
                                log.Error("SearchPublicKeyByContentExact: %v", err)
@@ -172,33 +183,58 @@ func publicKeyHandler(ctx ssh.Context, key ssh.PublicKey) bool {
 
                        // check the CA of the cert
                        if !c.IsUserAuthority(cert.SignatureKey) {
-                               log.Debug("Principal Rejected: Untrusted Authority Signature Fingerprint %s for Principal: %s", gossh.FingerprintSHA256(cert.SignatureKey), principal)
+                               if log.IsDebug() {
+                                       log.Debug("Principal Rejected: %s Untrusted Authority Signature Fingerprint %s for Principal: %s", ctx.RemoteAddr(), gossh.FingerprintSHA256(cert.SignatureKey), principal)
+                               }
                                continue principalLoop
                        }
 
                        // validate the cert for this principal
                        if err := c.CheckCert(principal, cert); err != nil {
-                               // User is presenting an invalid cerficate - STOP any further processing
-                               log.Error("Permission Denied: Invalid Certificate KeyID %s with Signature Fingerprint %s presented for Principal: %s", cert.KeyId, gossh.FingerprintSHA256(cert.SignatureKey), principal)
+                               // User is presenting an invalid certificate - STOP any further processing
+                               if log.IsError() {
+                                       log.Error("Invalid Certificate KeyID %s with Signature Fingerprint %s presented for Principal: %s from %s", cert.KeyId, gossh.FingerprintSHA256(cert.SignatureKey), principal, ctx.RemoteAddr())
+                               }
+                               log.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
+
                                return false
                        }
 
+                       if log.IsDebug() { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
+                               log.Debug("Successfully authenticated: %s Certificate Fingerprint: %s Principal: %s", ctx.RemoteAddr(), gossh.FingerprintSHA256(key), principal)
+                       }
                        ctx.SetValue(giteaKeyID, pkey.ID)
 
                        return true
                }
+
+               if log.IsWarn() {
+                       log.Warn("From %s Fingerprint: %s is a certificate, but no valid principals found", ctx.RemoteAddr(), gossh.FingerprintSHA256(key))
+                       log.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
+               }
+               return false
+       }
+
+       if log.IsDebug() { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
+               log.Debug("Handle Public Key: %s Fingerprint: %s is not a certificate", ctx.RemoteAddr(), gossh.FingerprintSHA256(key))
        }
 
        pkey, err := models.SearchPublicKeyByContent(strings.TrimSpace(string(gossh.MarshalAuthorizedKey(key))))
        if err != nil {
                if models.IsErrKeyNotExist(err) {
-                       log.Warn("Permission Denied: Unknown public key : %s", gossh.FingerprintSHA256(key))
+                       if log.IsWarn() {
+                               log.Warn("Unknown public key: %s from %s", gossh.FingerprintSHA256(key), ctx.RemoteAddr())
+                               log.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
+                       }
                        return false
                }
-               log.Error("SearchPublicKeyByContent: %v Failed authentication attempt from %s", err, ctx.RemoteAddr())
+               log.Error("SearchPublicKeyByContent: %v", err)
                return false
        }
 
+       if log.IsDebug() { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
+               log.Debug("Successfully authenticated: %s Public Key Fingerprint: %s", ctx.RemoteAddr(), gossh.FingerprintSHA256(key))
+       }
        ctx.SetValue(giteaKeyID, pkey.ID)
 
        return true