From 7d414a355c70a636649d57c467a3bf6403a30a15 Mon Sep 17 00:00:00 2001
From: Yael Genish <62285310+yaelgen@users.noreply.github.com>
Date: Mon, 4 Jul 2022 16:01:02 +0300
Subject: [PATCH] Reduce logs for scaler-dlx [0.4.x] (#53)

---
 .github/workflows/ci.yaml |  2 +-
 pkg/dlx/handler.go        | 24 ++++++++++++++++++------
 2 files changed, 19 insertions(+), 7 deletions(-)

diff --git a/.github/workflows/ci.yaml b/.github/workflows/ci.yaml
index 34b410f..ed68022 100644
--- a/.github/workflows/ci.yaml
+++ b/.github/workflows/ci.yaml
@@ -31,7 +31,7 @@ jobs:
 
       - uses: actions/setup-go@v2
         with:
-          go-version: "^1.14.3"
+          go-version: "1.14"
 
       - uses: actions/cache@v2
         with:
diff --git a/pkg/dlx/handler.go b/pkg/dlx/handler.go
index 54e212f..0a02378 100644
--- a/pkg/dlx/handler.go
+++ b/pkg/dlx/handler.go
@@ -6,6 +6,7 @@ import (
 	"net/http/httputil"
 	"net/url"
 	"strings"
+	"sync"
 	"time"
 
 	"github.com/v3io/scaler/pkg/common"
@@ -25,6 +26,7 @@ type Handler struct {
 	targetPathHeader   string
 	targetPort         int
 	targetURLCache     *cache.LRUExpireCache
+	proxyLock          sync.Locker
 	lastProxyErrorTime time.Time
 }
 
@@ -42,6 +44,7 @@ func NewHandler(parentLogger logger.Logger,
 		targetPathHeader:   targetPathHeader,
 		targetPort:         targetPort,
 		targetURLCache:     cache.NewLRUExpireCache(100),
+		proxyLock:          &sync.Mutex{},
 		lastProxyErrorTime: time.Now(),
 	}
 	h.HandleFunc = h.handleRequest
@@ -98,31 +101,40 @@ func (h *Handler) handleRequest(res http.ResponseWriter, req *http.Request) {
 	}
 
 	targetURL := h.selectTargetURL(resourceNames, resourceTargetURLMap)
+	h.proxyLock.Lock()
+	targetURLCacheKey := targetURL.String()
 
-	//if in cache, do not log
-	if _, found := h.targetURLCache.Get("targetURLCache"); !found {
+	// if in cache, do not log to avoid multiple identical log lines.
+	if _, found := h.targetURLCache.Get(targetURLCacheKey); !found {
 		h.logger.DebugWith("Creating reverse proxy", "targetURLCache", targetURL)
+
+		// store in cache
+		h.targetURLCache.Add(targetURLCacheKey, true, 5*time.Second)
 	}
+	h.proxyLock.Unlock()
 
 	proxy := httputil.NewSingleHostReverseProxy(targetURL)
+
+	// override the proxy's error handler in order to make the "context canceled" log appear once every hour at most,
+	// because it occurs frequently and spams the logs file, but we didn't want to remove it entirely.
 	proxy.ErrorHandler = func(rw http.ResponseWriter, req *http.Request, err error) {
+		if err == nil {
+			return
+		}
 		timeSinceLastCtxErr := time.Since(h.lastProxyErrorTime).Hours() > 1
 		if strings.Contains(err.Error(), "context canceled") && timeSinceLastCtxErr {
 			h.lastProxyErrorTime = time.Now()
 		}
 		if !strings.Contains(err.Error(), "context canceled") || timeSinceLastCtxErr {
-			proxy.ErrorLog.Printf("http: proxy error: %v", err)
+			h.logger.DebugWith("http: proxy error", "error", err)
 		}
 		rw.WriteHeader(http.StatusBadGateway)
 	}
 
-	// store in cache
-	h.targetURLCache.Add("targetURLCache", true, time.Second)
 	proxy.ServeHTTP(res, req)
 }
 
 func (h *Handler) parseTargetURL(resourceName, path string) (*url.URL, int) {
-	h.logger.DebugWith("Resolving service name", "resourceName", resourceName)
 	serviceName, err := h.resourceScaler.ResolveServiceName(scaler_types.Resource{Name: resourceName})
 	if err != nil {
 		h.logger.WarnWith("Failed resolving service name",