From 713d781bad5c21a60e2e15be10a734cd764acedd Mon Sep 17 00:00:00 2001 From: Mechiel Lukkien Date: Wed, 31 May 2023 20:39:00 +0200 Subject: [PATCH] log a consistent log line for failed authentication attempts, with the remote ip so external tools (like fail2ban) can monitor the logs and block ip's of bots. for issue #30 by inigoserna, though i'm not sure i interpreted the suggestion correctly. --- http/account.go | 6 +++++- http/admin.go | 7 ++++++- imapserver/server.go | 9 ++++++++- smtpserver/server.go | 10 +++++++++- 4 files changed, 28 insertions(+), 4 deletions(-) diff --git a/http/account.go b/http/account.go index 1dd38ae..145f19e 100644 --- a/http/account.go +++ b/http/account.go @@ -70,11 +70,14 @@ func checkAccountAuth(ctx context.Context, log *mlog.Log, w http.ResponseWriter, }() var err error + var remoteIP net.IP addr, err = net.ResolveTCPAddr("tcp", r.RemoteAddr) if err != nil { log.Errorx("parsing remote address", err, mlog.Field("addr", r.RemoteAddr)) + } else if addr != nil { + remoteIP = addr.IP } - if addr != nil && !mox.LimiterFailedAuth.Add(addr.IP, start, 1) { + if remoteIP != nil && !mox.LimiterFailedAuth.Add(remoteIP, start, 1) { metrics.AuthenticationRatelimitedInc("httpaccount") http.Error(w, "429 - too many auth attempts", http.StatusTooManyRequests) return "" @@ -89,6 +92,7 @@ func checkAccountAuth(ctx context.Context, log *mlog.Log, w http.ResponseWriter, } else if acc, err := store.OpenEmailAuth(t[0], t[1]); err != nil { if errors.Is(err, store.ErrUnknownCredentials) { authResult = "badcreds" + log.Info("failed authentication attempt", mlog.Field("username", t[0]), mlog.Field("remote", remoteIP)) } log.Errorx("open account", err) } else { diff --git a/http/admin.go b/http/admin.go index 1dca61e..b741fff 100644 --- a/http/admin.go +++ b/http/admin.go @@ -132,11 +132,14 @@ func checkAdminAuth(ctx context.Context, passwordfile string, w http.ResponseWri }() var err error + var remoteIP net.IP addr, err = net.ResolveTCPAddr("tcp", r.RemoteAddr) if err != nil { log.Errorx("parsing remote address", err, mlog.Field("addr", r.RemoteAddr)) + } else if addr != nil { + remoteIP = addr.IP } - if addr != nil && !mox.LimiterFailedAuth.Add(addr.IP, start, 1) { + if remoteIP != nil && !mox.LimiterFailedAuth.Add(remoteIP, start, 1) { metrics.AuthenticationRatelimitedInc("httpadmin") http.Error(w, "429 - too many auth attempts", http.StatusTooManyRequests) return false @@ -164,10 +167,12 @@ func checkAdminAuth(ctx context.Context, passwordfile string, w http.ResponseWri } t := strings.SplitN(string(auth), ":", 2) if len(t) != 2 || len(t[1]) < 8 { + log.Info("failed authentication attempt", mlog.Field("username", "admin"), mlog.Field("remote", remoteIP)) return respondAuthFail() } if err := bcrypt.CompareHashAndPassword([]byte(passwordhash), []byte(t[1])); err != nil { authResult = "badcreds" + log.Info("failed authentication attempt", mlog.Field("username", "admin"), mlog.Field("remote", remoteIP)) return respondAuthFail() } authCache.lastSuccessHash = passwordhash diff --git a/imapserver/server.go b/imapserver/server.go index 20fdc50..d43c057 100644 --- a/imapserver/server.go +++ b/imapserver/server.go @@ -1538,6 +1538,7 @@ func (c *conn) cmdAuthenticate(tag, cmd string, p *parser) { if err != nil { if errors.Is(err, store.ErrUnknownCredentials) { authResult = "badcreds" + c.log.Info("authentication failed", mlog.Field("username", authc)) xusercodeErrorf("AUTHENTICATIONFAILED", "bad credentials") } xusercodeErrorf("", "error") @@ -1565,6 +1566,7 @@ func (c *conn) cmdAuthenticate(tag, cmd string, p *parser) { acc, _, err := store.OpenEmail(addr) if err != nil { if errors.Is(err, store.ErrUnknownCredentials) { + c.log.Info("failed authentication attempt", mlog.Field("username", addr), mlog.Field("remote", c.remoteIP)) xusercodeErrorf("AUTHENTICATIONFAILED", "bad credentials") } xserverErrorf("looking up address: %v", err) @@ -1580,6 +1582,7 @@ func (c *conn) cmdAuthenticate(tag, cmd string, p *parser) { err := acc.DB.Read(context.TODO(), func(tx *bstore.Tx) error { password, err := bstore.QueryTx[store.Password](tx).Get() if err == bstore.ErrAbsent { + c.log.Info("failed authentication attempt", mlog.Field("username", addr), mlog.Field("remote", c.remoteIP)) xusercodeErrorf("AUTHENTICATIONFAILED", "bad credentials") } if err != nil { @@ -1593,7 +1596,8 @@ func (c *conn) cmdAuthenticate(tag, cmd string, p *parser) { xcheckf(err, "tx read") }) if ipadhash == nil || opadhash == nil { - c.log.Info("cram-md5 auth attempt without derived secrets set, save password again to store secrets", mlog.Field("address", addr)) + c.log.Info("cram-md5 auth attempt without derived secrets set, save password again to store secrets", mlog.Field("username", addr)) + c.log.Info("failed authentication attempt", mlog.Field("username", addr), mlog.Field("remote", c.remoteIP)) xusercodeErrorf("AUTHENTICATIONFAILED", "bad credentials") } @@ -1602,6 +1606,7 @@ func (c *conn) cmdAuthenticate(tag, cmd string, p *parser) { opadhash.Write(ipadhash.Sum(nil)) digest := fmt.Sprintf("%x", opadhash.Sum(nil)) if digest != t[1] { + c.log.Info("failed authentication attempt", mlog.Field("username", addr), mlog.Field("remote", c.remoteIP)) xusercodeErrorf("AUTHENTICATIONFAILED", "bad credentials") } @@ -1675,6 +1680,7 @@ func (c *conn) cmdAuthenticate(tag, cmd string, p *parser) { c.readline(false) // Should be "*" for cancellation. if errors.Is(err, scram.ErrInvalidProof) { authResult = "badcreds" + c.log.Info("failed authentication attempt", mlog.Field("username", ss.Authentication), mlog.Field("remote", c.remoteIP)) xusercodeErrorf("AUTHENTICATIONFAILED", "bad credentials") } xuserErrorf("server final: %w", err) @@ -1744,6 +1750,7 @@ func (c *conn) cmdLogin(tag, cmd string, p *parser) { var code string if errors.Is(err, store.ErrUnknownCredentials) { code = "AUTHENTICATIONFAILED" + c.log.Info("failed authentication attempt", mlog.Field("username", userid), mlog.Field("remote", c.remoteIP)) } xusercodeErrorf(code, "login failed") } diff --git a/smtpserver/server.go b/smtpserver/server.go index d96af52..3c9b070 100644 --- a/smtpserver/server.go +++ b/smtpserver/server.go @@ -985,6 +985,7 @@ func (c *conn) cmdAuth(p *parser) { if err != nil && errors.Is(err, store.ErrUnknownCredentials) { // ../rfc/4954:274 authResult = "badcreds" + c.log.Info("failed authentication attempt", mlog.Field("username", authc), mlog.Field("remote", c.remoteIP)) xsmtpUserErrorf(smtp.C535AuthBadCreds, smtp.SePol7AuthBadCreds8, "bad user/pass") } xcheckf(err, "verifying credentials") @@ -1016,6 +1017,7 @@ func (c *conn) cmdAuth(p *parser) { acc, _, err := store.OpenEmail(addr) if err != nil { if errors.Is(err, store.ErrUnknownCredentials) { + c.log.Info("failed authentication attempt", mlog.Field("username", addr), mlog.Field("remote", c.remoteIP)) xsmtpUserErrorf(smtp.C535AuthBadCreds, smtp.SePol7AuthBadCreds8, "bad user/pass") } } @@ -1031,6 +1033,7 @@ func (c *conn) cmdAuth(p *parser) { err := acc.DB.Read(context.TODO(), func(tx *bstore.Tx) error { password, err := bstore.QueryTx[store.Password](tx).Get() if err == bstore.ErrAbsent { + c.log.Info("failed authentication attempt", mlog.Field("username", addr), mlog.Field("remote", c.remoteIP)) xsmtpUserErrorf(smtp.C535AuthBadCreds, smtp.SePol7AuthBadCreds8, "bad user/pass") } if err != nil { @@ -1044,7 +1047,8 @@ func (c *conn) cmdAuth(p *parser) { xcheckf(err, "tx read") }) if ipadhash == nil || opadhash == nil { - c.log.Info("cram-md5 auth attempt without derived secrets set, save password again to store secrets", mlog.Field("address", addr)) + c.log.Info("cram-md5 auth attempt without derived secrets set, save password again to store secrets", mlog.Field("username", addr)) + c.log.Info("failed authentication attempt", mlog.Field("username", addr), mlog.Field("remote", c.remoteIP)) xsmtpUserErrorf(smtp.C535AuthBadCreds, smtp.SePol7AuthBadCreds8, "bad user/pass") } @@ -1053,6 +1057,7 @@ func (c *conn) cmdAuth(p *parser) { opadhash.Write(ipadhash.Sum(nil)) digest := fmt.Sprintf("%x", opadhash.Sum(nil)) if digest != t[1] { + c.log.Info("failed authentication attempt", mlog.Field("username", addr), mlog.Field("remote", c.remoteIP)) xsmtpUserErrorf(smtp.C535AuthBadCreds, smtp.SePol7AuthBadCreds8, "bad user/pass") } @@ -1088,6 +1093,7 @@ func (c *conn) cmdAuth(p *parser) { // todo: we could continue scram with a generated salt, deterministically generated // from the username. that way we don't have to store anything but attackers cannot // learn if an account exists. same for absent scram saltedpassword below. + c.log.Info("failed authentication attempt", mlog.Field("username", ss.Authentication), mlog.Field("remote", c.remoteIP)) xsmtpUserErrorf(smtp.C454TempAuthFail, smtp.SeSys3Other0, "scram not possible") } defer func() { @@ -1110,6 +1116,7 @@ func (c *conn) cmdAuth(p *parser) { } if err == bstore.ErrAbsent || err == nil && (len(xscram.Salt) == 0 || xscram.Iterations == 0 || len(xscram.SaltedPassword) == 0) { c.log.Info("scram auth attempt without derived secrets set, save password again to store secrets", mlog.Field("address", ss.Authentication)) + c.log.Info("failed authentication attempt", mlog.Field("username", ss.Authentication), mlog.Field("remote", c.remoteIP)) xsmtpUserErrorf(smtp.C454TempAuthFail, smtp.SeSys3Other0, "scram not possible") } xcheckf(err, "fetching credentials") @@ -1129,6 +1136,7 @@ func (c *conn) cmdAuth(p *parser) { c.readline() // Should be "*" for cancellation. if errors.Is(err, scram.ErrInvalidProof) { authResult = "badcreds" + c.log.Info("failed authentication attempt", mlog.Field("username", ss.Authentication), mlog.Field("remote", c.remoteIP)) xsmtpUserErrorf(smtp.C535AuthBadCreds, smtp.SePol7AuthBadCreds8, "bad credentials") } xcheckf(err, "server final")