Break out logging / metrics for functions in forwarding_proxy

Signed-off-by: Alex Ellis (VMware) <alexellis2@gmail.com>

gateway/Dockerfile

 FROM golang:1.9.4 as build
 WORKDIR /go/src/github.com/openfaas/faas/gateway
 
-RUN curl -sL https://github.com/alexellis/license-check/releases/download/0.1/license-check > /usr/bin/license-check && chmod +x /usr/bin/license-check
+RUN curl -sL https://github.com/alexellis/license-check/releases/download/0.2.2/license-check \
+      > /usr/bin/license-check \
+      && chmod +x /usr/bin/license-check
 
 COPY vendor         vendor
 
@@ -16,7 +18,7 @@ COPY plugin         plugin
 COPY server.go      .
 
 # Run a gofmt and exclude all vendored code.
-RUN license-check -path ./ --verbose=false \
+RUN license-check -path ./ --verbose=false "Alex Ellis" "OpenFaaS Project" \
     && test -z "$(gofmt -l $(find . -type f -name '*.go' -not -path "./vendor/*"))" \
     && go test $(go list ./... | grep -v integration | grep -v /vendor/ | grep -v /template/) -cover \
     && CGO_ENABLED=0 GOOS=linux go build -a -installsuffix cgo -o gateway .

gateway/handlers/forwarding_proxy.go

@@ -14,8 +14,12 @@ import (
 	"github.com/prometheus/client_golang/prometheus"
 )
 
+type HTTPNotifier interface {
+	Notify(method string, URL string, statusCode int, duration time.Duration)
+}
+
 // MakeForwardingProxyHandler create a handler which forwards HTTP requests
-func MakeForwardingProxyHandler(proxy *types.HTTPClientReverseProxy, metrics *metrics.MetricOptions) http.HandlerFunc {
+func MakeForwardingProxyHandler(proxy *types.HTTPClientReverseProxy, notifiers []HTTPNotifier) http.HandlerFunc {
 	baseURL := proxy.BaseURL.String()
 	if strings.HasSuffix(baseURL, "/") {
 		baseURL = baseURL[0 : len(baseURL)-1]
@@ -24,34 +28,18 @@ func MakeForwardingProxyHandler(proxy *types.HTTPClientReverseProxy, metrics *me
 	return func(w http.ResponseWriter, r *http.Request) {
 
 		requestURL := r.URL.String()
-		serviceName := getServiceName(requestURL)
-
-		log.Printf("> Forwarding [%s] to %s", r.Method, requestURL)
 
 		start := time.Now()
 
 		statusCode, err := forwardRequest(w, r, proxy.Client, baseURL, requestURL, proxy.Timeout)
 
+		seconds := time.Since(start)
 		if err != nil {
 			log.Printf("error with upstream request to: %s, %s\n", requestURL, err.Error())
 		}
-
-		seconds := time.Since(start).Seconds()
-		log.Printf("< [%s] - %d took %f seconds\n", r.URL.String(),
-			statusCode, seconds)
-
-		if len(serviceName) > 0 {
-			metrics.GatewayFunctionsHistogram.
-				WithLabelValues(serviceName).
-				Observe(seconds)
-
-			code := strconv.Itoa(statusCode)
-
-			metrics.GatewayFunctionInvocation.
-				With(prometheus.Labels{"function_name": serviceName, "code": code}).
-				Inc()
+		for _, notifier := range notifiers {
+			notifier.Notify(r.Method, requestURL, statusCode, seconds)
 		}
-
 	}
 }
 
@@ -102,6 +90,25 @@ func copyHeaders(destination http.Header, source *http.Header) {
 	}
 }
 
+type PrometheusFunctionNotifier struct {
+	Metrics *metrics.MetricOptions
+}
+
+func (p PrometheusFunctionNotifier) Notify(method string, URL string, statusCode int, duration time.Duration) {
+	seconds := duration.Seconds()
+	serviceName := getServiceName(URL)
+
+	p.Metrics.GatewayFunctionsHistogram.
+		WithLabelValues(serviceName).
+		Observe(seconds)
+
+	code := strconv.Itoa(statusCode)
+
+	p.Metrics.GatewayFunctionInvocation.
+		With(prometheus.Labels{"function_name": serviceName, "code": code}).
+		Inc()
+}
+
 func getServiceName(urlValue string) string {
 	var serviceName string
 	forward := "/function/"
@@ -114,3 +121,10 @@ func getServiceName(urlValue string) string {
 func startsWith(value, token string) bool {
 	return len(value) > len(token) && strings.Index(value, token) == 0
 }
+
+type LoggingNotifier struct {
+}
+
+func (LoggingNotifier) Notify(method string, URL string, statusCode int, duration time.Duration) {
+	log.Printf("Forwarded [%s] to %s - [%d] - %f seconds", method, URL, statusCode, duration.Seconds())
+}

gateway/server.go

@@ -10,8 +10,8 @@ import (
 	"time"
 
 	"github.com/gorilla/mux"
+	"github.com/openfaas/faas/gateway/handlers"
 
-	internalHandlers "github.com/openfaas/faas/gateway/handlers"
 	"github.com/openfaas/faas/gateway/metrics"
 	"github.com/openfaas/faas/gateway/plugin"
 	"github.com/openfaas/faas/gateway/types"
@@ -42,17 +42,24 @@ func main() {
 
 	reverseProxy := types.NewHTTPClientReverseProxy(config.FunctionsProviderURL, config.UpstreamTimeout)
 
-	faasHandlers.Proxy = internalHandlers.MakeForwardingProxyHandler(reverseProxy, &metricsOptions)
-	faasHandlers.RoutelessProxy = internalHandlers.MakeForwardingProxyHandler(reverseProxy, &metricsOptions)
-	faasHandlers.ListFunctions = internalHandlers.MakeForwardingProxyHandler(reverseProxy, &metricsOptions)
-	faasHandlers.DeployFunction = internalHandlers.MakeForwardingProxyHandler(reverseProxy, &metricsOptions)
-	faasHandlers.DeleteFunction = internalHandlers.MakeForwardingProxyHandler(reverseProxy, &metricsOptions)
-	faasHandlers.UpdateFunction = internalHandlers.MakeForwardingProxyHandler(reverseProxy, &metricsOptions)
+	loggingNotifier := handlers.LoggingNotifier{}
+	prometheusNotifier := handlers.PrometheusFunctionNotifier{
+		Metrics: &metricsOptions,
+	}
+	functionNotifiers := []handlers.HTTPNotifier{loggingNotifier, prometheusNotifier}
+	forwardingNotifiers := []handlers.HTTPNotifier{loggingNotifier, prometheusNotifier}
+
+	faasHandlers.Proxy = handlers.MakeForwardingProxyHandler(reverseProxy, functionNotifiers)
+	faasHandlers.RoutelessProxy = handlers.MakeForwardingProxyHandler(reverseProxy, forwardingNotifiers)
+	faasHandlers.ListFunctions = handlers.MakeForwardingProxyHandler(reverseProxy, forwardingNotifiers)
+	faasHandlers.DeployFunction = handlers.MakeForwardingProxyHandler(reverseProxy, forwardingNotifiers)
+	faasHandlers.DeleteFunction = handlers.MakeForwardingProxyHandler(reverseProxy, forwardingNotifiers)
+	faasHandlers.UpdateFunction = handlers.MakeForwardingProxyHandler(reverseProxy, forwardingNotifiers)
 
-	queryFunction := internalHandlers.MakeForwardingProxyHandler(reverseProxy, &metricsOptions)
+	queryFunction := handlers.MakeForwardingProxyHandler(reverseProxy, forwardingNotifiers)
 
 	alertHandler := plugin.NewExternalServiceQuery(*config.FunctionsProviderURL)
-	faasHandlers.Alert = internalHandlers.MakeAlertHandler(alertHandler)
+	faasHandlers.Alert = handlers.MakeAlertHandler(alertHandler)
 
 	metrics.AttachExternalWatcher(*config.FunctionsProviderURL, metricsOptions, "func", servicePollInterval)
 
@@ -63,13 +70,13 @@ func main() {
 			log.Fatalln(queueErr)
 		}
 
-		faasHandlers.QueuedProxy = internalHandlers.MakeQueuedProxy(metricsOptions, true, natsQueue)
-		faasHandlers.AsyncReport = internalHandlers.MakeAsyncReport(metricsOptions)
+		faasHandlers.QueuedProxy = handlers.MakeQueuedProxy(metricsOptions, true, natsQueue)
+		faasHandlers.AsyncReport = handlers.MakeAsyncReport(metricsOptions)
 	}
 
 	prometheusQuery := metrics.NewPrometheusQuery(config.PrometheusHost, config.PrometheusPort, &http.Client{})
 	listFunctions := metrics.AddMetricsHandler(faasHandlers.ListFunctions, prometheusQuery)
-	faasHandlers.Proxy = internalHandlers.MakeCallIDMiddleware(faasHandlers.Proxy)
+	faasHandlers.Proxy = handlers.MakeCallIDMiddleware(faasHandlers.Proxy)
 	r := mux.NewRouter()
 
 	// r.StrictSlash(false)	// This didn't work, so register routes twice.
@@ -95,7 +102,7 @@ func main() {
 
 	// This URL allows access from the UI to the OpenFaaS store
 	allowedCORSHost := "raw.githubusercontent.com"
-	fsCORS := internalHandlers.DecorateWithCORS(fs, allowedCORSHost)
+	fsCORS := handlers.DecorateWithCORS(fs, allowedCORSHost)
 
 	r.PathPrefix("/ui/").Handler(http.StripPrefix("/ui", fsCORS)).Methods("GET")