From 74515f102df44de90cc4598f4f4a9c9b1b50690e Mon Sep 17 00:00:00 2001
From: andres-portainer <91705312+andres-portainer@users.noreply.github.com>
Date: Wed, 5 Jul 2023 09:25:05 -0300
Subject: [PATCH] fix(docker-proxy): reduce DB writes to optimize the proxy
 calls EE-5516 (#9148)

---
 api/http/middlewares/slow_request_logger.go  | 36 ++++++++++++++++
 api/http/proxy/factory/utils/json.go         | 18 ++------
 api/http/proxy/factory/utils/request.go      | 45 --------------------
 api/http/proxy/factory/utils/response.go     |  9 ++--
 api/http/security/bouncer.go                 |  8 ++--
 api/http/server.go                           |  4 ++
 api/internal/authorization/access_control.go | 14 +++---
 7 files changed, 61 insertions(+), 73 deletions(-)
 create mode 100644 api/http/middlewares/slow_request_logger.go
 delete mode 100644 api/http/proxy/factory/utils/request.go

diff --git a/api/http/middlewares/slow_request_logger.go b/api/http/middlewares/slow_request_logger.go
new file mode 100644
index 000000000..4bc2ae34b
--- /dev/null
+++ b/api/http/middlewares/slow_request_logger.go
@@ -0,0 +1,36 @@
+package middlewares
+
+import (
+	"net/http"
+	"time"
+
+	"github.com/rs/zerolog"
+	"github.com/rs/zerolog/log"
+)
+
+func WithSlowRequestsLogger(next http.Handler) http.Handler {
+	if zerolog.GlobalLevel() > zerolog.DebugLevel {
+		return next
+	}
+
+	burstSampler := &zerolog.BurstSampler{
+		Burst:  1,
+		Period: time.Minute,
+	}
+
+	log := log.With().Logger().Sample(burstSampler)
+
+	return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
+		t0 := time.Now()
+
+		next.ServeHTTP(w, req)
+
+		if d := time.Since(t0); d > 100*time.Millisecond {
+			log.Debug().
+				Dur("elapsed_ms", d).
+				Str("method", req.Method).
+				Str("url", req.URL.String()).
+				Msg("slow request")
+		}
+	})
+}
diff --git a/api/http/proxy/factory/utils/json.go b/api/http/proxy/factory/utils/json.go
index 7d12567e0..7f215a685 100644
--- a/api/http/proxy/factory/utils/json.go
+++ b/api/http/proxy/factory/utils/json.go
@@ -49,18 +49,8 @@ func getBody(body io.ReadCloser, contentType string, isGzip bool) (interface{},
 
 	defer reader.Close()
 
-	bodyBytes, err := io.ReadAll(reader)
-	if err != nil {
-		return nil, err
-	}
-
-	err = body.Close()
-	if err != nil {
-		return nil, err
-	}
-
 	var data interface{}
-	err = unmarshal(contentType, bodyBytes, &data)
+	err := unmarshal(contentType, reader, &data)
 	if err != nil {
 		return nil, err
 	}
@@ -85,7 +75,7 @@ func marshal(contentType string, data interface{}) ([]byte, error) {
 	return nil, fmt.Errorf("content type is not supported for marshaling: %s", contentType)
 }
 
-func unmarshal(contentType string, body []byte, returnBody interface{}) error {
+func unmarshal(contentType string, body io.Reader, returnBody interface{}) error {
 	// Note: contentType can look like: "application/json" or "application/json; charset=utf-8"
 	mediaType, _, err := mime.ParseMediaType(contentType)
 	if err != nil {
@@ -94,9 +84,9 @@ func unmarshal(contentType string, body []byte, returnBody interface{}) error {
 
 	switch mediaType {
 	case "application/yaml":
-		return yaml.Unmarshal(body, returnBody)
+		return yaml.NewDecoder(body).Decode(returnBody)
 	case "application/json", "":
-		return json.Unmarshal(body, returnBody)
+		return json.NewDecoder(body).Decode(returnBody)
 	}
 
 	return fmt.Errorf("content type is not supported for unmarshaling: %s", contentType)
diff --git a/api/http/proxy/factory/utils/request.go b/api/http/proxy/factory/utils/request.go
deleted file mode 100644
index 9f809fc20..000000000
--- a/api/http/proxy/factory/utils/request.go
+++ /dev/null
@@ -1,45 +0,0 @@
-package utils
-
-import (
-	"bytes"
-	"io"
-	"net/http"
-	"strconv"
-)
-
-// GetRequestAsMap returns the response content as a generic JSON object
-func GetRequestAsMap(request *http.Request) (map[string]interface{}, error) {
-	data, err := getRequestBody(request)
-	if err != nil {
-		return nil, err
-	}
-
-	return data.(map[string]interface{}), nil
-}
-
-// RewriteRequest will replace the existing request body with the one specified
-// in parameters
-func RewriteRequest(request *http.Request, newData interface{}) error {
-	data, err := marshal(getContentType(request.Header), newData)
-	if err != nil {
-		return err
-	}
-
-	body := io.NopCloser(bytes.NewReader(data))
-
-	request.Body = body
-	request.ContentLength = int64(len(data))
-
-	if request.Header == nil {
-		request.Header = make(http.Header)
-	}
-	request.Header.Set("Content-Length", strconv.Itoa(len(data)))
-
-	return nil
-}
-
-func getRequestBody(request *http.Request) (interface{}, error) {
-	isGzip := request.Header.Get("Content-Encoding") == "gzip"
-
-	return getBody(request.Body, getContentType(request.Header), isGzip)
-}
diff --git a/api/http/proxy/factory/utils/response.go b/api/http/proxy/factory/utils/response.go
index 868590295..455cd9e4a 100644
--- a/api/http/proxy/factory/utils/response.go
+++ b/api/http/proxy/factory/utils/response.go
@@ -77,7 +77,7 @@ func RewriteAccessDeniedResponse(response *http.Response) error {
 // RewriteResponse will replace the existing response body and status code with the one specified
 // in parameters
 func RewriteResponse(response *http.Response, newResponseData interface{}, statusCode int) error {
-	data, err := marshal(getContentType(response.Header), newResponseData)
+	data, err := marshal(getContentType(response), newResponseData)
 	if err != nil {
 		return err
 	}
@@ -98,14 +98,13 @@ func RewriteResponse(response *http.Response, newResponseData interface{}, statu
 
 func getResponseBody(response *http.Response) (interface{}, error) {
 	isGzip := response.Header.Get("Content-Encoding") == "gzip"
-
 	if isGzip {
 		response.Header.Del("Content-Encoding")
 	}
 
-	return getBody(response.Body, getContentType(response.Header), isGzip)
+	return getBody(response.Body, getContentType(response), isGzip)
 }
 
-func getContentType(headers http.Header) string {
-	return headers.Get("Content-type")
+func getContentType(response *http.Response) string {
+	return response.Header.Get("Content-type")
 }
diff --git a/api/http/security/bouncer.go b/api/http/security/bouncer.go
index 9291aaa8a..052a639e7 100644
--- a/api/http/security/bouncer.go
+++ b/api/http/security/bouncer.go
@@ -347,9 +347,11 @@ func (bouncer *RequestBouncer) apiKeyLookup(r *http.Request) *portainer.TokenDat
 		return nil
 	}
 
-	// update the last used time of the key
-	apiKey.LastUsed = time.Now().UTC().Unix()
-	bouncer.apiKeyService.UpdateAPIKey(&apiKey)
+	if now := time.Now().UTC().Unix(); now-apiKey.LastUsed > 60 { // [seconds]
+		// update the last used time of the key
+		apiKey.LastUsed = now
+		bouncer.apiKeyService.UpdateAPIKey(&apiKey)
+	}
 
 	return tokenData
 }
diff --git a/api/http/server.go b/api/http/server.go
index a2c2b6cfc..0bdd62ad9 100644
--- a/api/http/server.go
+++ b/api/http/server.go
@@ -52,6 +52,7 @@ import (
 	"github.com/portainer/portainer/api/http/handler/users"
 	"github.com/portainer/portainer/api/http/handler/webhooks"
 	"github.com/portainer/portainer/api/http/handler/websocket"
+	"github.com/portainer/portainer/api/http/middlewares"
 	"github.com/portainer/portainer/api/http/offlinegate"
 	"github.com/portainer/portainer/api/http/proxy"
 	"github.com/portainer/portainer/api/http/proxy/factory/kubernetes"
@@ -330,6 +331,9 @@ func (server *Server) Start() error {
 	errorLogger := NewHTTPLogger()
 
 	handler := adminMonitor.WithRedirect(offlineGate.WaitingMiddleware(time.Minute, server.Handler))
+
+	handler = middlewares.WithSlowRequestsLogger(handler)
+
 	if server.HTTPEnabled {
 		go func() {
 			log.Info().Str("bind_address", server.BindAddress).Msg("starting HTTP server")
diff --git a/api/internal/authorization/access_control.go b/api/internal/authorization/access_control.go
index 543fecb51..e6982d447 100644
--- a/api/internal/authorization/access_control.go
+++ b/api/internal/authorization/access_control.go
@@ -187,15 +187,17 @@ func UserCanAccessResource(userID portainer.UserID, userTeamIDs []portainer.Team
 // GetResourceControlByResourceIDAndType retrieves the first matching resource control in a set of resource controls
 // based on the specified id and resource type parameters.
 func GetResourceControlByResourceIDAndType(resourceID string, resourceType portainer.ResourceControlType, resourceControls []portainer.ResourceControl) *portainer.ResourceControl {
-	for _, resourceControl := range resourceControls {
-		if resourceID == resourceControl.ResourceID && resourceType == resourceControl.Type {
-			return &resourceControl
+	for i := range resourceControls {
+		if resourceID == resourceControls[i].ResourceID && resourceType == resourceControls[i].Type {
+			return &resourceControls[i]
 		}
-		for _, subResourceID := range resourceControl.SubResourceIDs {
-			if resourceID == subResourceID {
-				return &resourceControl
+
+		for j := range resourceControls[i].SubResourceIDs {
+			if resourceID == resourceControls[i].SubResourceIDs[j] {
+				return &resourceControls[i]
 			}
 		}
 	}
+
 	return nil
 }