Repository: labstack/echo (go)

Issue:
Data race in parallel test with RequestLogger middleware
### Issue Description

I get a `WARNING: DATA RACE` when running parallel tests with the "-race" flag in `RequestLoggerConfig`.



### Checklist

- [+] Dependencies installed
- [+] No typos
- [+] Searched existing issues and docs

### Expected behaviour

No data race in parallel tests

### Actual behaviour

Data race in parallel tests

### Steps to reproduce

Save code below to `bug_test.go`:

```go
package bug

import (
	"net/http"
	"net/http/httptest"
	"testing"

	"github.com/labstack/echo/v4"
	"github.com/labstack/echo/v4/middleware"
)

func New() *echo.Echo {
	e := echo.New()
	e.Pre(
		middleware.RequestLoggerWithConfig(
			middleware.RequestLoggerConfig{},  // just example
		),
	)
	return e
}

func TestB(t *testing.T) {
	t.Parallel()

	req := httptest.NewRequest(http.MethodGet, "/", nil)
	res := httptest.NewRecorder()
	New().ServeHTTP(res, req)
}

func TestA(t *testing.T) {
	t.Parallel()

	req := httptest.NewRequest(http.MethodGet, "/", nil)
	res := httptest.NewRecorder()
	New().ServeHTTP(res, req)
}
```

Run: `go test -race bug_test.go`.

### Working code to debug

See "Steps to reproduce".

### Version/commit
v4.10.2

### Reason/Solution

`RequestLoggerConfig` override global [now](https://github.com/labstack/echo/blob/v4.10.2/middleware/request_logger.go#L228) which defined in [rate_limiter.go](https://github.com/labstack/echo/blob/master/middleware/rate_limiter.go#L271) without sync. I think this operation must be safe.

Pull request:
do not use global timeNow variables
fixes #2476 . This is problematic in tests as this is only place where that global `now` variable could be mutated

Patch:
diff --git a/middleware/rate_limiter.go b/middleware/rate_limiter.go
index f7fae83..1d24df5 100644
--- a/middleware/rate_limiter.go
+++ b/middleware/rate_limiter.go
@@ -160,6 +160,8 @@ type (
 		burst       int
 		expiresIn   time.Duration
 		lastCleanup time.Time
+
+		timeNow func() time.Time
 	}
 	// Visitor signifies a unique user's limiter details
 	Visitor struct {
@@ -219,7 +221,8 @@ func NewRateLimiterMemoryStoreWithConfig(config RateLimiterMemoryStoreConfig) (s
 		store.burst = int(config.Rate)
 	}
 	store.visitors = make(map[string]*Visitor)
-	store.lastCleanup = now()
+	store.timeNow = time.Now
+	store.lastCleanup = store.timeNow()
 	return
 }
 
@@ -244,12 +247,13 @@ func (store *RateLimiterMemoryStore) Allow(identifier string) (bool, error) {
 		limiter.Limiter = rate.NewLimiter(store.rate, store.burst)
 		store.visitors[identifier] = limiter
 	}
-	limiter.lastSeen = now()
-	if now().Sub(store.lastCleanup) > store.expiresIn {
+	now := store.timeNow()
+	limiter.lastSeen = now
+	if now.Sub(store.lastCleanup) > store.expiresIn {
 		store.cleanupStaleVisitors()
 	}
 	store.mutex.Unlock()
-	return limiter.AllowN(now(), 1), nil
+	return limiter.AllowN(store.timeNow(), 1), nil
 }
 
 /*
@@ -258,14 +262,9 @@ of users who haven't visited again after the configured expiry time has elapsed
 */
 func (store *RateLimiterMemoryStore) cleanupStaleVisitors() {
 	for id, visitor := range store.visitors {
-		if now().Sub(visitor.lastSeen) > store.expiresIn {
+		if store.timeNow().Sub(visitor.lastSeen) > store.expiresIn {
 			delete(store.visitors, id)
 		}
 	}
-	store.lastCleanup = now()
+	store.lastCleanup = store.timeNow()
 }
-
-/*
-actual time method which is mocked in test file
-*/
-var now = time.Now
diff --git a/middleware/request_logger.go b/middleware/request_logger.go
index 8e312e8..ce76230 100644
--- a/middleware/request_logger.go
+++ b/middleware/request_logger.go
@@ -225,7 +225,7 @@ func (config RequestLoggerConfig) ToMiddleware() (echo.MiddlewareFunc, error) {
 	if config.Skipper == nil {
 		config.Skipper = DefaultSkipper
 	}
-	now = time.Now
+	now := time.Now
 	if config.timeNow != nil {
 		now = config.timeNow
 	}


Test patch:
diff --git a/middleware/rate_limiter_test.go b/middleware/rate_limiter_test.go
index 89d9a6e..0f7c914 100644
--- a/middleware/rate_limiter_test.go
+++ b/middleware/rate_limiter_test.go
@@ -2,7 +2,6 @@ package middleware
 
 import (
 	"errors"
-	"fmt"
 	"math/rand"
 	"net/http"
 	"net/http/httptest"
@@ -340,7 +339,7 @@ func TestRateLimiterMemoryStore_Allow(t *testing.T) {
 
 	for i, tc := range testCases {
 		t.Logf("Running testcase #%d => %v", i, time.Duration(i)*220*time.Millisecond)
-		now = func() time.Time {
+		inMemoryStore.timeNow = func() time.Time {
 			return time.Date(2009, time.November, 10, 23, 0, 0, 0, time.UTC).Add(time.Duration(i) * 220 * time.Millisecond)
 		}
 		allowed, _ := inMemoryStore.Allow(tc.id)
@@ -350,24 +349,22 @@ func TestRateLimiterMemoryStore_Allow(t *testing.T) {
 
 func TestRateLimiterMemoryStore_cleanupStaleVisitors(t *testing.T) {
 	var inMemoryStore = NewRateLimiterMemoryStoreWithConfig(RateLimiterMemoryStoreConfig{Rate: 1, Burst: 3})
-	now = time.Now
-	fmt.Println(now())
 	inMemoryStore.visitors = map[string]*Visitor{
 		"A": {
 			Limiter:  rate.NewLimiter(1, 3),
-			lastSeen: now(),
+			lastSeen: time.Now(),
 		},
 		"B": {
 			Limiter:  rate.NewLimiter(1, 3),
-			lastSeen: now().Add(-1 * time.Minute),
+			lastSeen: time.Now().Add(-1 * time.Minute),
 		},
 		"C": {
 			Limiter:  rate.NewLimiter(1, 3),
-			lastSeen: now().Add(-5 * time.Minute),
+			lastSeen: time.Now().Add(-5 * time.Minute),
 		},
 		"D": {
 			Limiter:  rate.NewLimiter(1, 3),
-			lastSeen: now().Add(-10 * time.Minute),
+			lastSeen: time.Now().Add(-10 * time.Minute),
 		},
 	}