Merge pull request #78 from uswitch/airship-2978-customisable-log-format

AIRSHIP-2978 Customisable Access Log formats

README.md

@@ -169,6 +169,7 @@ The Yggdrasil-specific metrics which are available from the API are:
 --ca string                                   trustedCA
 --cert string                                 certfile
 --config string                               config file
+--config-dump                                 Enable config dump endpoint at /configdump on the health-address HTTP server
 --debug                                       Log at debug level
 --envoy-listener-ipv4-address string          IPv4 address by the envoy proxy to accept incoming connections (default "0.0.0.0")
 --envoy-port uint32                           port by the envoy proxy to accept incoming connections (default 10000)

cmd/root.go

@@ -45,6 +45,7 @@ type config struct {
 	UseRemoteAddress           bool                      `json:"useRemoteAddress"`
 	HttpExtAuthz               envoy.HttpExtAuthz        `json:"httpExtAuthz"`
 	HttpGrpcLogger             envoy.HttpGrpcLogger      `json:"httpGrpcLogger"`
+	AccessLogger               envoy.AccessLogger        `json:"accessLogger"`
 }
 
 // Hasher returns node ID as an ID
@@ -62,7 +63,7 @@ var rootCmd = &cobra.Command{
 	RunE:  main,
 }
 
-//Execute runs the function
+// Execute runs the function
 func Execute() {
 	if err := rootCmd.Execute(); err != nil {
 		log.Fatal(err)
@@ -82,6 +83,7 @@ func init() {
 	rootCmd.PersistentFlags().StringSlice("ingress-classes", nil, "Ingress classes to watch")
 	rootCmd.PersistentFlags().StringArrayVar(&kubeConfig, "kube-config", nil, "Path to kube config")
 	rootCmd.PersistentFlags().Bool("debug", false, "Log at debug level")
+	rootCmd.PersistentFlags().Bool("config-dump", false, "Enable config dump endpoint at /configdump on the health-address HTTP server")
 	rootCmd.PersistentFlags().Uint32("upstream-port", 443, "port used to connect to the upstream ingresses")
 	rootCmd.PersistentFlags().String("envoy-listener-ipv4-address", "0.0.0.0", "IPv4 address by the envoy proxy to accept incoming connections")
 	rootCmd.PersistentFlags().Uint32("envoy-port", 10000, "port by the envoy proxy to accept incoming connections")
@@ -104,7 +106,9 @@ func init() {
 	rootCmd.PersistentFlags().Bool("http-ext-authz-allow-partial-message", true, "When this field is true, Envoy will buffer the message until max_request_bytes is reached")
 	rootCmd.PersistentFlags().Bool("http-ext-authz-pack-as-bytes", false, "When this field is true, Envoy will send the body as raw bytes.")
 	rootCmd.PersistentFlags().Bool("http-ext-authz-failure-mode-allow", true, "Changes filters behaviour on errors")
+
 	viper.BindPFlag("debug", rootCmd.PersistentFlags().Lookup("debug"))
+	viper.BindPFlag("configDump", rootCmd.PersistentFlags().Lookup("config-dump"))
 	viper.BindPFlag("address", rootCmd.PersistentFlags().Lookup("address"))
 	viper.BindPFlag("healthAddress", rootCmd.PersistentFlags().Lookup("health-address"))
 	viper.BindPFlag("nodeName", rootCmd.PersistentFlags().Lookup("node-name"))
@@ -230,14 +234,15 @@ func main(*cobra.Command, []string) error {
 		envoy.WithHttpExtAuthzCluster(c.HttpExtAuthz),
 		envoy.WithHttpGrpcLogger(c.HttpGrpcLogger),
 		envoy.WithDefaultRetryOn(viper.GetString("retryOn")),
+		envoy.WithAccessLog(c.AccessLogger),
 	)
 	snapshotter := envoy.NewSnapshotter(envoyCache, configurator, aggregator)
 
 	go snapshotter.Run(aggregator)
 	go aggregator.Run()
 
 	envoyServer := server.NewServer(ctx, envoyCache, &callbacks{})
-	go runEnvoyServer(envoyServer, viper.GetString("address"), viper.GetString("healthAddress"), ctx.Done())
+	go runEnvoyServer(envoyServer, snapshotter, viper.GetBool("configDump"), viper.GetString("address"), viper.GetString("healthAddress"), ctx.Done())
 
 	<-stopCh
 	return nil

cmd/server.go

@@ -2,6 +2,7 @@ package cmd
 
 import (
 	"context"
+	"encoding/json"
 	"fmt"
 	"net"
 	"net/http"
@@ -16,6 +17,8 @@ import (
 	"github.com/prometheus/client_golang/prometheus/promhttp"
 	log "github.com/sirupsen/logrus"
 	"google.golang.org/grpc"
+
+	"github.com/uswitch/yggdrasil/pkg/envoy"
 )
 
 type callbacks struct {
@@ -49,7 +52,7 @@ func (c *callbacks) OnFetchResponse(*discovery.DiscoveryRequest, *discovery.Disc
 	c.fetchResp++
 }
 
-func runEnvoyServer(envoyServer server.Server, address string, healthAddress string, stopCh <-chan struct{}) {
+func runEnvoyServer(envoyServer server.Server, snapshotter *envoy.Snapshotter, enableConfigDump bool, address string, healthAddress string, stopCh <-chan struct{}) {
 
 	grpcServer := grpc.NewServer(
 		grpc.StreamInterceptor(grpc_prometheus.StreamServerInterceptor),
@@ -76,6 +79,9 @@ func runEnvoyServer(envoyServer server.Server, address string, healthAddress str
 
 	healthMux.Handle("/metrics", promhttp.Handler())
 	healthMux.HandleFunc("/healthz", health)
+	if enableConfigDump {
+		healthMux.HandleFunc("/configdump", handleConfigDump(snapshotter))
+	}
 
 	go func() {
 		if err = grpcServer.Serve(lis); err != nil {
@@ -97,3 +103,34 @@ func runEnvoyServer(envoyServer server.Server, address string, healthAddress str
 func health(w http.ResponseWriter, r *http.Request) {
 	w.WriteHeader(200)
 }
+
+type ConfigDumpError struct {
+	Error   error
+	Message string
+}
+
+func handleConfigDump(snapshotter *envoy.Snapshotter) http.HandlerFunc {
+	return func(w http.ResponseWriter, r *http.Request) {
+		if r.Method != http.MethodGet {
+			w.WriteHeader(http.StatusMethodNotAllowed)
+			return
+		}
+
+		snapshot, err := snapshotter.ConfigDump()
+		if err != nil {
+			respErr := ConfigDumpError{
+				Error:   err,
+				Message: "Unable to get current snapshot from snapshotter, see error for details.",
+			}
+
+			w.Header().Add("Content-Type", "application/json")
+			w.WriteHeader(http.StatusInternalServerError)
+			json.NewEncoder(w).Encode(respErr)
+			return
+		}
+
+		w.Header().Add("Content-Type", "application/json")
+		w.WriteHeader(http.StatusOK)
+		json.NewEncoder(w).Encode(snapshot)
+	}
+}

docs/ACCESSLOG.md

@@ -0,0 +1,37 @@
+# Access Log
+
+The Access log format is configurable via the Yggdrasil config file only. It is defined as a json object as follows:
+
+```json
+{
+    "accessLogger": {
+        "format": {
+            "bytes_received":            "%BYTES_RECEIVED%",
+            "bytes_sent":                "%BYTES_SENT%",
+            "downstream_local_address":  "%DOWNSTREAM_LOCAL_ADDRESS%",
+            "downstream_remote_address": "%DOWNSTREAM_REMOTE_ADDRESS%",
+            "duration":                  "%DURATION%",
+            "forwarded_for":             "%REQ(X-FORWARDED-FOR)%",
+            "protocol":                  "%PROTOCOL%",
+            "request_id":                "%REQ(X-REQUEST-ID)%",
+            "request_method":            "%REQ(:METHOD)%",
+            "request_path":              "%REQ(X-ENVOY-ORIGINAL-PATH?:PATH)%",
+            "response_code":             "%RESPONSE_CODE%",
+            "response_flags":            "%RESPONSE_FLAGS%",
+            "start_time":                "%START_TIME(%s.%3f)%",
+            "upstream_cluster":          "%UPSTREAM_CLUSTER%",
+            "upstream_host":             "%UPSTREAM_HOST%",
+            "upstream_local_address":    "%UPSTREAM_LOCAL_ADDRESS%",
+            "upstream_service_time":     "%RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)%",
+            "user_agent":                "%REQ(USER-AGENT)%"
+        }
+    }
+}
+
+```
+
+The config above would be the same as the default access logger config shipped with Yggdasil. Thus if no format is provided this will be the format used.
+
+[See Envoy docs for more on access log formats](https://www.envoyproxy.io/docs/envoy/latest/configuration/observability/access_log/usage#config-access-log-default-format)
+
+The access log is written to `/var/log/envoy/access.log` which is not currently configurable.

pkg/envoy/boilerplate.go

@@ -32,35 +32,30 @@ import (
 var (
 	jsonFormat      *structpb.Struct
 	allowedRetryOns map[string]bool
-)
 
-func init() {
-	format := map[string]interface{}{
-		"start_time":                "%START_TIME(%s.%3f)%",
+	DefaultAccessLogFormat = map[string]interface{}{
 		"bytes_received":            "%BYTES_RECEIVED%",
-		"protocol":                  "%PROTOCOL%",
-		"response_code":             "%RESPONSE_CODE%",
 		"bytes_sent":                "%BYTES_SENT%",
+		"downstream_local_address":  "%DOWNSTREAM_LOCAL_ADDRESS%",
+		"downstream_remote_address": "%DOWNSTREAM_REMOTE_ADDRESS%",
 		"duration":                  "%DURATION%",
+		"forwarded_for":             "%REQ(X-FORWARDED-FOR)%",
+		"protocol":                  "%PROTOCOL%",
+		"request_id":                "%REQ(X-REQUEST-ID)%",
+		"request_method":            "%REQ(:METHOD)%",
+		"request_path":              "%REQ(X-ENVOY-ORIGINAL-PATH?:PATH)%",
+		"response_code":             "%RESPONSE_CODE%",
 		"response_flags":            "%RESPONSE_FLAGS%",
-		"upstream_host":             "%UPSTREAM_HOST%",
+		"start_time":                "%START_TIME(%s.%3f)%",
 		"upstream_cluster":          "%UPSTREAM_CLUSTER%",
+		"upstream_host":             "%UPSTREAM_HOST%",
 		"upstream_local_address":    "%UPSTREAM_LOCAL_ADDRESS%",
-		"downstream_remote_address": "%DOWNSTREAM_REMOTE_ADDRESS%",
-		"downstream_local_address":  "%DOWNSTREAM_LOCAL_ADDRESS%",
-		"request_method":            "%REQ(:METHOD)%",
-		"request_path":              "%REQ(X-ENVOY-ORIGINAL-PATH?:PATH)%",
 		"upstream_service_time":     "%RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)%",
-		"forwarded_for":             "%REQ(X-FORWARDED-FOR)%",
 		"user_agent":                "%REQ(USER-AGENT)%",
-		"request_id":                "%REQ(X-REQUEST-ID)%",
 	}
-	b, err := structpb.NewValue(format)
-	if err != nil {
-		log.Fatal(err)
-	}
-	jsonFormat = b.GetStructValue()
+)
 
+func init() {
 	allowedRetryOns = map[string]bool{
 		"5xx":                        true,
 		"gateway-error":              true,
@@ -184,8 +179,18 @@ func makeGrpcLoggerConfig(cfg HttpGrpcLogger) *gal.HttpGrpcAccessLogConfig {
 	}
 }
 
-func (c *KubernetesConfigurator) makeConnectionManager(virtualHosts []*route.VirtualHost) (*hcm.HttpConnectionManager, error) {
-	// Access Logs
+func makeFileAccessLog(cfg AccessLogger) *eal.FileAccessLog {
+	format := DefaultAccessLogFormat
+	if len(cfg.Format) > 0 {
+		format = cfg.Format
+	}
+
+	b, err := structpb.NewValue(format)
+	if err != nil {
+		log.Fatal(err)
+	}
+	jsonFormat = b.GetStructValue()
+
 	accessLogConfig := &eal.FileAccessLog{
 		Path: "/var/log/envoy/access.log",
 		AccessLogFormat: &eal.FileAccessLog_LogFormat{
@@ -196,6 +201,13 @@ func (c *KubernetesConfigurator) makeConnectionManager(virtualHosts []*route.Vir
 			},
 		},
 	}
+
+	return accessLogConfig
+}
+
+func (c *KubernetesConfigurator) makeConnectionManager(virtualHosts []*route.VirtualHost) (*hcm.HttpConnectionManager, error) {
+	// Access Logs
+	accessLogConfig := makeFileAccessLog(c.accessLogger)
 	anyAccessLogConfig, err := anypb.New(accessLogConfig)
 	if err != nil {
 		log.Fatalf("failed to marshal access log config struct to typed struct: %s", err)

pkg/envoy/boilerplate_test.go

@@ -2,10 +2,12 @@ package envoy
 
 import (
 	"fmt"
+	"reflect"
 	"testing"
 	"time"
 
 	core "github.com/envoyproxy/go-control-plane/envoy/config/core/v3"
+	eal "github.com/envoyproxy/go-control-plane/envoy/extensions/access_loggers/file/v3"
 	"github.com/golang/protobuf/ptypes/duration"
 )
 
@@ -56,6 +58,48 @@ func TestMakeHealthChecksValidPath(t *testing.T) {
 
 }
 
+type accessLoggerTestCase struct {
+	name   string
+	format map[string]interface{}
+	custom bool
+}
+
+func TestAccessLoggerConfig(t *testing.T) {
+	testCases := []accessLoggerTestCase{
+		{name: "default log format", format: DefaultAccessLogFormat, custom: false},
+		{name: "custom log format", format: map[string]interface{}{"a-key": "a-format-specifier"}, custom: true},
+	}
+
+	for _, tc := range testCases {
+		t.Run(tc.name, func(t *testing.T) {
+			cfg := AccessLogger{}
+			if tc.custom {
+				cfg.Format = tc.format
+			}
+
+			fileAccessLog := makeFileAccessLog(cfg)
+			if fileAccessLog.Path != "/var/log/envoy/access.log" {
+				t.Errorf("Expected access log to use default path but was, %s", fileAccessLog.Path)
+			}
+
+			alf, ok := fileAccessLog.AccessLogFormat.(*eal.FileAccessLog_LogFormat)
+			if !ok {
+				t.Fatalf("File Access Log Format had incorrect type, should be FileAccessLog_LogFormat")
+			}
+
+			lf, ok := alf.LogFormat.Format.(*core.SubstitutionFormatString_JsonFormat)
+			if !ok {
+				t.Fatalf("LogFormat had incorrect type, should be SubstitutionFormatString_JsonFormat")
+			}
+
+			format := lf.JsonFormat.AsMap()
+			if !reflect.DeepEqual(format, tc.format) {
+				t.Errorf("Log format map should match configuration")
+			}
+		})
+	}
+}
+
 func mustParseDuration(dur string) time.Duration {
 	d, err := time.ParseDuration(dur)
 	if err != nil {

pkg/envoy/config_dump.go

@@ -0,0 +1,26 @@
+package envoy
+
+import (
+	types "github.com/envoyproxy/go-control-plane/pkg/cache/types"
+	resource "github.com/envoyproxy/go-control-plane/pkg/resource/v3"
+)
+
+type EnvoySnapshot struct {
+	Listeners map[string]types.Resource
+	Clusters  map[string]types.Resource
+}
+
+func (s *Snapshotter) ConfigDump() (EnvoySnapshot, error) {
+	snapshot, err := s.CurrentSnapshot()
+	if err != nil {
+		return EnvoySnapshot{}, err
+	}
+
+	listeners := snapshot.GetResources(resource.ListenerType)
+	clusters := snapshot.GetResources(resource.ClusterType)
+
+	return EnvoySnapshot{
+		Listeners: listeners,
+		Clusters:  clusters,
+	}, nil
+}