From 20a8d90ad700b58a8963fb61bf72949055c892df Mon Sep 17 00:00:00 2001
From: ErickSkrauch <erickskrauch@yandex.ru>
Date: Fri, 3 Apr 2020 17:18:02 +0300
Subject: [PATCH] Add tests for requests logger

---
 eventsubscribers/logger.go      | 22 +++++++----
 eventsubscribers/logger_test.go | 70 ++++++++++++++++++++++++++++++++-
 2 files changed, 84 insertions(+), 8 deletions(-)

diff --git a/eventsubscribers/logger.go b/eventsubscribers/logger.go
index f338c3f..ad8d330 100644
--- a/eventsubscribers/logger.go
+++ b/eventsubscribers/logger.go
@@ -4,6 +4,7 @@ import (
 	"net"
 	"net/http"
 	"net/url"
+	"strings"
 	"syscall"
 
 	"github.com/mono83/slf"
@@ -25,19 +26,19 @@ func (l *Logger) ConfigureWithDispatcher(d dispatcher.EventDispatcher) {
 }
 
 func (l *Logger) handleAfterSkinsystemRequest(req *http.Request, statusCode int) {
-	forwardedIp := req.Header.Get("X-Forwarded-For")
-	if forwardedIp == "" {
-		forwardedIp = req.Header.Get("X-Real-Ip")
+	path := req.URL.Path
+	if req.URL.RawQuery != "" {
+		path += "?" + req.URL.RawQuery
 	}
 
 	l.Info(
-		":ip - - \":method :path\" :statusCode \":userAgent\" \":forwardedIp\"",
-		wd.StringParam("ip", req.RemoteAddr),
+		":ip - - \":method :path\" :statusCode - \":userAgent\" \":forwardedIp\"",
+		wd.StringParam("ip", trimPort(req.RemoteAddr)),
 		wd.StringParam("method", req.Method),
-		wd.StringParam("path", req.URL.Path),
+		wd.StringParam("path", path),
 		wd.IntParam("statusCode", statusCode),
 		wd.StringParam("userAgent", req.UserAgent()),
-		wd.StringParam("forwardedIp", forwardedIp),
+		wd.StringParam("forwardedIp", req.Header.Get("X-Forwarded-For")),
 	)
 }
 
@@ -87,3 +88,10 @@ func (l *Logger) createMojangTexturesErrorHandler(provider string) func(identity
 func (l *Logger) logMojangTexturesWarning(providerParam slf.Param, errParam slf.Param) {
 	l.Warning(":name: :err", providerParam, errParam)
 }
+
+func trimPort(ip string) string {
+	// Don't care about possible -1 result because RemoteAddr will always contain ip and port
+	cutTo := strings.LastIndexByte(ip, ':')
+
+	return ip[0:cutTo]
+}
diff --git a/eventsubscribers/logger_test.go b/eventsubscribers/logger_test.go
index 42062a9..40a3248 100644
--- a/eventsubscribers/logger_test.go
+++ b/eventsubscribers/logger_test.go
@@ -2,6 +2,8 @@ package eventsubscribers
 
 import (
 	"net"
+	"net/http"
+	"net/http/httptest"
 	"net/url"
 	"syscall"
 	"testing"
@@ -19,7 +21,73 @@ type LoggerTestCase struct {
 	ExpectedCalls [][]interface{}
 }
 
-var loggerTestCases = map[string]*LoggerTestCase{}
+var loggerTestCases = map[string]*LoggerTestCase{
+	"should log each request to the skinsystem": {
+		Events: [][]interface{}{
+			{"skinsystem:after_request",
+				(func() *http.Request {
+					req := httptest.NewRequest("GET", "http://localhost/skins/username.png", nil)
+					req.Header.Add("User-Agent", "Test user agent")
+
+					return req
+				})(),
+				201,
+			},
+		},
+		ExpectedCalls: [][]interface{}{
+			{"Info",
+				":ip - - \":method :path\" :statusCode - \":userAgent\" \":forwardedIp\"",
+				mock.MatchedBy(func(strParam params.String) bool {
+					return strParam.Key == "ip" && strParam.Value == "192.0.2.1"
+				}),
+				mock.MatchedBy(func(strParam params.String) bool {
+					return strParam.Key == "method" && strParam.Value == "GET"
+				}),
+				mock.MatchedBy(func(strParam params.String) bool {
+					return strParam.Key == "path" && strParam.Value == "/skins/username.png"
+				}),
+				mock.MatchedBy(func(strParam params.Int) bool {
+					return strParam.Key == "statusCode" && strParam.Value == 201
+				}),
+				mock.MatchedBy(func(strParam params.String) bool {
+					return strParam.Key == "userAgent" && strParam.Value == "Test user agent"
+				}),
+				mock.MatchedBy(func(strParam params.String) bool {
+					return strParam.Key == "forwardedIp" && strParam.Value == ""
+				}),
+			},
+		},
+	},
+	"should log each request to the skinsystem 2": {
+		Events: [][]interface{}{
+			{"skinsystem:after_request",
+				(func() *http.Request {
+					req := httptest.NewRequest("GET", "http://localhost/skins/username.png?authlib=1.5.2", nil)
+					req.Header.Add("User-Agent", "Test user agent")
+					req.Header.Add("X-Forwarded-For", "1.2.3.4")
+
+					return req
+				})(),
+				201,
+			},
+		},
+		ExpectedCalls: [][]interface{}{
+			{"Info",
+				":ip - - \":method :path\" :statusCode - \":userAgent\" \":forwardedIp\"",
+				mock.Anything, // Already tested
+				mock.Anything, // Already tested
+				mock.MatchedBy(func(strParam params.String) bool {
+					return strParam.Key == "path" && strParam.Value == "/skins/username.png?authlib=1.5.2"
+				}),
+				mock.Anything, // Already tested
+				mock.Anything, // Already tested
+				mock.MatchedBy(func(strParam params.String) bool {
+					return strParam.Key == "forwardedIp" && strParam.Value == "1.2.3.4"
+				}),
+			},
+		},
+	},
+}
 
 type timeoutError struct{}