Pull request 1815: 5701-log-ip

Updates #5701.

Squashed commit of the following:

commit 332530cbae602e9b0e4c89351bde6b0da017fc67
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Tue Apr 11 18:56:27 2023 +0300

    home: imp docs

commit 35a649ffed9ca736e63842f077411c5f5cbb57f3
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Tue Apr 11 18:27:25 2023 +0300

    home: fix login attempt logging

CHANGELOG.md

@@ -133,6 +133,10 @@ In this release, the schema version has changed from 17 to 20.
 - The `POST /control/querylog_config` HTTP API; use the new `PUT
   /control/querylog/config/update` API instead.
 
+### Fixed
+
+- Logging of the client's IP address after failed login attempts ([#5701]).
+
 [#1163]: https://github.com/AdguardTeam/AdGuardHome/issues/1163
 [#1333]: https://github.com/AdguardTeam/AdGuardHome/issues/1333
 [#1163]: https://github.com/AdguardTeam/AdGuardHome/issues/1717
@@ -142,6 +146,7 @@ In this release, the schema version has changed from 17 to 20.
 [#4262]: https://github.com/AdguardTeam/AdGuardHome/issues/4262
 [#3290]: https://github.com/AdguardTeam/AdGuardHome/issues/4299
 [#5567]: https://github.com/AdguardTeam/AdGuardHome/issues/5567
+[#5701]: https://github.com/AdguardTeam/AdGuardHome/issues/5701
 
 [rfc6761]: https://www.rfc-editor.org/rfc/rfc6761
 

internal/home/auth.go

@@ -412,6 +412,21 @@ func realIP(r *http.Request) (ip net.IP, err error) {
 	return net.ParseIP(ipStr), nil
 }
 
+// writeErrorWithIP is like [aghhttp.Error], but includes the remote IP address
+// when it writes to the log.
+func writeErrorWithIP(
+	r *http.Request,
+	w http.ResponseWriter,
+	code int,
+	remoteIP string,
+	format string,
+	args ...any,
+) {
+	text := fmt.Sprintf(format, args...)
+	log.Error("%s %s %s: from ip %s: %s", r.Method, r.Host, r.URL, remoteIP, text)
+	http.Error(w, text, code)
+}
+
 func handleLogin(w http.ResponseWriter, r *http.Request) {
 	req := loginJSON{}
 	err := json.NewDecoder(r.Body).Decode(&req)
@@ -421,31 +436,45 @@ func handleLogin(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	var remoteAddr string
+	var remoteIP string
 	// realIP cannot be used here without taking TrustedProxies into account due
 	// to security issues.
 	//
 	// See https://github.com/AdguardTeam/AdGuardHome/issues/2799.
 	//
 	// TODO(e.burkov): Use realIP when the issue will be fixed.
-	if remoteAddr, err = netutil.SplitHost(r.RemoteAddr); err != nil {
-		aghhttp.Error(r, w, http.StatusBadRequest, "auth: getting remote address: %s", err)
+	if remoteIP, err = netutil.SplitHost(r.RemoteAddr); err != nil {
+		writeErrorWithIP(
+			r,
+			w,
+			http.StatusBadRequest,
+			r.RemoteAddr,
+			"auth: getting remote address: %s",
+			err,
+		)
 
 		return
 	}
 
 	if rateLimiter := Context.auth.raleLimiter; rateLimiter != nil {
-		if left := rateLimiter.check(remoteAddr); left > 0 {
+		if left := rateLimiter.check(remoteIP); left > 0 {
 			w.Header().Set(httphdr.RetryAfter, strconv.Itoa(int(left.Seconds())))
-			aghhttp.Error(r, w, http.StatusTooManyRequests, "auth: blocked for %s", left)
+			writeErrorWithIP(
+				r,
+				w,
+				http.StatusTooManyRequests,
+				remoteIP,
+				"auth: blocked for %s",
+				left,
+			)
 
 			return
 		}
 	}
 
-	cookie, err := Context.auth.newCookie(req, remoteAddr)
+	cookie, err := Context.auth.newCookie(req, remoteIP)
 	if err != nil {
-		aghhttp.Error(r, w, http.StatusForbidden, "%s", err)
+		writeErrorWithIP(r, w, http.StatusForbidden, remoteIP, "%s", err)
 
 		return
 	}
@@ -453,10 +482,7 @@ func handleLogin(w http.ResponseWriter, r *http.Request) {
 	// Use realIP here, since this IP address is only used for logging.
 	ip, err := realIP(r)
 	if err != nil {
-		log.Error("auth: getting real ip from request: %s", err)
-	} else if ip == nil {
-		// Technically shouldn't happen.
-		log.Error("auth: unknown ip")
+		log.Error("auth: getting real ip from request with remote ip %s: %s", remoteIP, err)
 	}
 
 	log.Info("auth: user %q successfully logged in from ip %v", req.Name, ip)
@@ -544,8 +570,7 @@ func optionalAuthThird(w http.ResponseWriter, r *http.Request) (mustAuth bool) {
 			log.Debug("auth: redirected to login page by GL-Inet submodule")
 		} else {
 			log.Debug("auth: redirected to login page")
-			w.Header().Set(httphdr.Location, "/login.html")
-			w.WriteHeader(http.StatusFound)
+			http.Redirect(w, r, "login.html", http.StatusFound)
 		}
 	} else {
 		log.Debug("auth: responded with forbidden to %s %s", r.Method, p)
@@ -570,8 +595,7 @@ func optionalAuth(
 				// Redirect to the dashboard if already authenticated.
 				res := Context.auth.checkSession(cookie.Value)
 				if res == checkSessionOK {
-					w.Header().Set(httphdr.Location, "/")
-					w.WriteHeader(http.StatusFound)
+					http.Redirect(w, r, "", http.StatusFound)
 
 					return
 				}

internal/home/control.go

@@ -399,7 +399,7 @@ func postInstall(handler func(http.ResponseWriter, *http.Request)) func(http.Res
 		path := r.URL.Path
 		if Context.firstRun && !strings.HasPrefix(path, "/install.") &&
 			!strings.HasPrefix(path, "/assets/") {
-			http.Redirect(w, r, "/install.html", http.StatusFound)
+			http.Redirect(w, r, "install.html", http.StatusFound)
 
 			return
 		}