Skip to content

Commit

Permalink
pkg/config: support custom Envoy JSON fields
Browse files Browse the repository at this point in the history 
Add support for custon Envoy JSON fields via use of `=` in the field
name.

See [design doc](design/envoy-json-logging-custom-fields-design.md) for
more information.

Fixes projectcontour#3032

Signed-off-by: Mikael Manukyan <mmanukyan@vmware.com>
Co-authored-by: Mikael Manukyan <mmanukyan@vmware.com>
Co-authored-by: Alexander Standke <astandke@vmware.com>
  • Loading branch information
@KauzClay @mike1808
3 people committed Oct 26, 2020
1 parent d00e113 commit f7094b2
Show file tree
Hide file tree
Showing 4 changed files with 216 additions and 28 deletions.
2 changes: 1 addition & 1 deletion cmd/contour/serve.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -365,7 +365,7 @@ func doServe(log logrus.FieldLogger, ctx *serveContext) error {
HTTPSPort: ctx.httpsPort,
HTTPSAccessLog: ctx.httpsAccessLog,
AccessLogType: ctx.Config.AccessLogFormat,
AccessLogFields: ctx.Config.AccessLogFields,
AccessLogFields: ctx.Config.ParsedAccessLogFields,
MinimumTLSVersion: globalMinTLSVersion,
RequestTimeout: requestTimeout,
ConnectionIdleTimeout: connectionIdleTimeout,
Expand Down
127 changes: 104 additions & 23 deletions pkg/config/accesslog.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,29 +4,59 @@ package config
//used for specifying fields for Envoy to log when JSON logging is enabled.
//Only fields specified in this map may be used for JSON logging.
var JSONFields = map[string]string{
"@timestamp": "%START_TIME%",
"ts": "%START_TIME%",
"authority": "%REQ(:AUTHORITY)%",
"bytes_received": "%BYTES_RECEIVED%",
"bytes_sent": "%BYTES_SENT%",
"downstream_local_address": "%DOWNSTREAM_LOCAL_ADDRESS%",
"downstream_remote_address": "%DOWNSTREAM_REMOTE_ADDRESS%",
"duration": "%DURATION%",
"method": "%REQ(:METHOD)%",
"path": "%REQ(X-ENVOY-ORIGINAL-PATH?:PATH)%",
"protocol": "%PROTOCOL%",
"request_id": "%REQ(X-REQUEST-ID)%",
"requested_server_name": "%REQUESTED_SERVER_NAME%",
"response_code": "%RESPONSE_CODE%",
"response_flags": "%RESPONSE_FLAGS%",
"uber_trace_id": "%REQ(UBER-TRACE-ID)%",
"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)%",
"x_forwarded_for": "%REQ(X-FORWARDED-FOR)%",
"x_trace_id": "%REQ(X-TRACE-ID)%",
"@timestamp": "%START_TIME%",
"ts": "%START_TIME%",
"authority": "%REQ(:AUTHORITY)%",
"bytes_received": "%BYTES_RECEIVED%",
"bytes_sent": "%BYTES_SENT%",
"connection_id": "%CONNECTION_ID%",
"connection_termination_details": "%CONNECTION_TERMINATION_DETAILS%",
"downstream_direct_remote_address": "%DOWNSTREAM_DIRECT_REMOTE_ADDRESS%",
"downstream_direct_remote_address_without_port": "%DOWNSTREAM_DIRECT_REMOTE_ADDRESS_WITHOUT_PORT%",
"downstream_local_address": "%DOWNSTREAM_LOCAL_ADDRESS%",
"downstream_local_address_without_port": "%DOWNSTREAM_LOCAL_ADDRESS_WITHOUT_PORT%",
"downstream_local_port": "%DOWNSTREAM_LOCAL_PORT%",
"downstream_local_subject": "%DOWNSTREAM_LOCAL_SUBJECT%",
"downstream_local_uri_san": "%DOWNSTREAM_LOCAL_URI_SAN%",
"downstream_peer_cert": "%DOWNSTREAM_PEER_CERT%",
"downstream_peer_cert_v_end": "%DOWNSTREAM_PEER_CERT_V_END%",
"downstream_peer_cert_v_start": "%DOWNSTREAM_PEER_CERT_V_START%",
"downstream_peer_fingerprint_1": "%DOWNSTREAM_PEER_FINGERPRINT_1%",
"downstream_peer_fingerprint_256": "%DOWNSTREAM_PEER_FINGERPRINT_256%",
"downstream_peer_issuer": "%DOWNSTREAM_PEER_ISSUER%",
"downstream_peer_serial": "%DOWNSTREAM_PEER_SERIAL%",
"downstream_peer_subject": "%DOWNSTREAM_PEER_SUBJECT%",
"downstream_peer_uri_san": "%DOWNSTREAM_PEER_URI_SAN%",
"downstream_remote_address": "%DOWNSTREAM_REMOTE_ADDRESS%",
"downstream_remote_address_without_port": "%DOWNSTREAM_REMOTE_ADDRESS_WITHOUT_PORT%",
"downstream_tls_cipher": "%DOWNSTREAM_TLS_CIPHER%",
"downstream_tls_session_id": "%DOWNSTREAM_TLS_SESSION_ID%",
"downstream_tls_version": "%DOWNSTREAM_TLS_VERSION%",
"duration": "%DURATION%",
"grpc_status": "%GRPC_STATUS%",
"hostname": "%HOSTNAME%",
"method": "%REQ(:METHOD)%",
"path": "%REQ(X-ENVOY-ORIGINAL-PATH?:PATH)%",
"protocol": "%PROTOCOL%",
"request_duration": "%REQUEST_DURATION%",
"request_id": "%REQ(X-REQUEST-ID)%",
"requested_server_name": "%REQUESTED_SERVER_NAME%",
"response_code": "%RESPONSE_CODE%",
"response_code_details": "%RESPONSE_CODE_DETAILS%",
"response_duration": "%RESPONSE_DURATION%",
"response_flags": "%RESPONSE_FLAGS%",
"response_tx_duration": "%RESPONSE_TX_DURATION%",
"route_name": "%ROUTE_NAME%",
"start_time": "%START_TIME%",
"uber_trace_id": "%REQ(UBER-TRACE-ID)%",
"upstream_cluster": "%UPSTREAM_CLUSTER%",
"upstream_host": "%UPSTREAM_HOST%",
"upstream_local_address": "%UPSTREAM_LOCAL_ADDRESS%",
"upstream_service_time": "%RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)%",
"upstream_transport_failure_reason": "%UPSTREAM_TRANSPORT_FAILURE_REASON%",
"user_agent": "%REQ(USER-AGENT)%",
"x_forwarded_for": "%REQ(X-FORWARDED-FOR)%",
"x_trace_id": "%REQ(X-TRACE-ID)%",
}

// DefaultFields are fields that will be included by default when JSON logging is enabled.
Expand Down Expand Up @@ -54,5 +84,56 @@ var DefaultFields = []string{
"x_forwarded_for",
}

var ParsedDefaultFields = parseAccessLogFields(DefaultFields)

var EnvoyOperators = map[string]struct{}{
"START_TIME": {},
"BYTES_RECEIVED": {},
"PROTOCOL": {},
"RESPONSE_CODE": {},
"RESPONSE_CODE_DETAILS": {},
"CONNECTION_TERMINATION_DETAILS": {},
"BYTES_SENT": {},
"DURATION": {},
"REQUEST_DURATION": {},
"RESPONSE_DURATION": {},
"RESPONSE_TX_DURATION": {},
"RESPONSE_FLAGS": {},
"ROUTE_NAME": {},
"UPSTREAM_HOST": {},
"UPSTREAM_CLUSTER": {},
"UPSTREAM_LOCAL_ADDRESS": {},
"UPSTREAM_TRANSPORT_FAILURE_REASON": {},
"DOWNSTREAM_REMOTE_ADDRESS": {},
"DOWNSTREAM_REMOTE_ADDRESS_WITHOUT_PORT": {},
"DOWNSTREAM_DIRECT_REMOTE_ADDRESS": {},
"DOWNSTREAM_DIRECT_REMOTE_ADDRESS_WITHOUT_PORT": {},
"DOWNSTREAM_LOCAL_ADDRESS": {},
"DOWNSTREAM_LOCAL_ADDRESS_WITHOUT_PORT": {},
"CONNECTION_ID": {},
"GRPC_STATUS": {},
"DOWNSTREAM_LOCAL_PORT": {},
"REQ": {},
"RESP": {},
"TRAILER": {},
"REQUESTED_SERVER_NAME": {},
"DOWNSTREAM_LOCAL_URI_SAN": {},
"DOWNSTREAM_PEER_URI_SAN": {},
"DOWNSTREAM_LOCAL_SUBJECT": {},
"DOWNSTREAM_PEER_SUBJECT": {},
"DOWNSTREAM_PEER_ISSUER": {},
"DOWNSTREAM_TLS_SESSION_ID": {},
"DOWNSTREAM_TLS_CIPHER": {},
"DOWNSTREAM_TLS_VERSION": {},
"DOWNSTREAM_PEER_FINGERPRINT_256": {},
"DOWNSTREAM_PEER_FINGERPRINT_1": {},
"DOWNSTREAM_PEER_SERIAL": {},
"DOWNSTREAM_PEER_CERT": {},
"DOWNSTREAM_PEER_CERT_V_START": {},
"DOWNSTREAM_PEER_CERT_V_END": {},
"HOSTNAME": {},
"LOCAL_REPLY_BODY": {},
}

// DEFAULT_ACCESS_LOG_TYPE is the default access log format.
const DEFAULT_ACCESS_LOG_TYPE = EnvoyAccessLog
76 changes: 72 additions & 4 deletions pkg/config/parameters.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ import (
"io"
"os"
"path/filepath"
"regexp"
"strings"
"time"

Expand Down Expand Up @@ -89,6 +90,53 @@ func (a AccessLogType) Validate() error {
const EnvoyAccessLog AccessLogType = "envoy"
const JSONAccessLog AccessLogType = "json"

type AccessLogFields map[string]string

func (a AccessLogFields) Validate() error {
// Capture Groups:
// Given string "the start time is %START_TIME(%s):3% wow!"
//
// 0. Whole match "%START_TIME(%s):3%"
// 1. Full operator: "START_TIME(%s):3%"
// 2. Operator Name: "START_TIME"
// 3. Arguments: "(%s)"
// 4. Truncation length: ":3"
re := regexp.MustCompile(`%(([A-Z_]+)(\([^)]+\)(:[0-9]+)?)?%)?`)

for key, val := range a {
fmt.Printf("key=%q, val=%q\n", key, val)
if val == "" {
return fmt.Errorf("invalid JSON log field name %s", key)
}

if JSONFields[key] == val {
continue
}

tokens := re.FindAllStringSubmatch(val, -1)
if len(tokens) == 0 {
continue
}

for _, f := range tokens {
op := f[2]
if op == "" {
return fmt.Errorf("invalid JSON field: %s, invalid Envoy format: %s", val, f)
}

if _, ok := EnvoyOperators[op]; !ok {
return fmt.Errorf("invalid JSON field: %s, invalid Envoy format: %s, invalid Envoy operator: %s", val, f, op)
}

if (op == "REQ" || op == "RESP" || op == "TRAILER") && f[3] == "" {
return fmt.Errorf("invalid JSON field: %s, invalid Envoy format: %s, arguments required for operator: %s", val, f, op)
}
}
}

return nil
}

// HTTPVersionType is the name of a supported HTTP version.
type HTTPVersionType string

Expand Down Expand Up @@ -290,6 +338,9 @@ type Parameters struct {
// output when AccessLogFormat is json.
AccessLogFields []string `yaml:"json-fields,omitempty"`

// ParsedAccessLogFields holds AccessLogFields that have been separated into key/value pairs
ParsedAccessLogFields AccessLogFields `yaml:"-"`

// TLS contains TLS policy parameters.
TLS TLSParameters `yaml:"tls,omitempty"`

Expand Down Expand Up @@ -341,10 +392,8 @@ func (p *Parameters) Validate() error {
return err
}

for _, f := range p.AccessLogFields {
if _, ok := JSONFields[f]; !ok {
return fmt.Errorf("invalid JSON log field name %s", f)
}
if err := p.ParsedAccessLogFields.Validate(); err != nil {
return err
}

// Check TLS secret names.
Expand Down Expand Up @@ -384,6 +433,7 @@ func Defaults() Parameters {
IngressStatusAddress: "",
AccessLogFormat: DEFAULT_ACCESS_LOG_TYPE,
AccessLogFields: DefaultFields,
ParsedAccessLogFields: ParsedDefaultFields,
TLS: TLSParameters{},
DisablePermitInsecure: false,
LeaderElection: LeaderElectionParameters{
Expand Down Expand Up @@ -424,6 +474,9 @@ func Parse(in io.Reader) (*Parameters, error) {
}
}

// Parse AccessLogFields into key/value pairs
conf.ParsedAccessLogFields = parseAccessLogFields(conf.AccessLogFields)

// Force the version string to match the lowercase version
// constants (assuming that it will match).
for i, v := range conf.DefaultHTTPVersions {
Expand All @@ -441,3 +494,18 @@ func GetenvOr(key string, defaultVal string) string {

return defaultVal
}

func parseAccessLogFields(fields []string) AccessLogFields {
parsedFields := AccessLogFields{}

for _, val := range fields {
parts := strings.SplitN(val, "=", 2)
if len(parts) == 1 {
parsedFields[val] = JSONFields[val]
} else {
parsedFields[parts[0]] = parts[1]
}
}

return parsedFields
}
39 changes: 39 additions & 0 deletions pkg/config/parameters_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -126,6 +126,45 @@ func TestValidateAccessLogType(t *testing.T) {
assert.NoError(t, JSONAccessLog.Validate())
}

func TestValidateAccessLogFields(t *testing.T) {
errorCases := [][]string{
{"dog", "cat"},
{"@timestamp", "dog"},
{"@timestamp", "content-id=%REQ=dog%"},
{"@timestamp", "content-id=%dog(%"},
{"@timestamp", "content-id=%REQ()%"},
{"@timestamp", "content-id=%DOG%"},
{"@timestamp", "duration=my durations % are %DURATION%.0 and %REQ(:METHOD)%"},
{"invalid=%REQ%"},
{"invalid=%TRAILER%"},
{"invalid=%RESP%"},
}

for _, c := range errorCases {
parsedFields := parseAccessLogFields(c)
assert.Error(t, parsedFields.Validate(), c)
}

successCases := [][]string{
{"@timestamp", "method"},
{"@timestamp", "response_duration"},
{"@timestamp", "duration=%DURATION%.0"},
{"@timestamp", "duration=My duration=%DURATION%.0"},
{"@timestamp", "duratin=%START_TIME(%s.%6f)%"},
{"@timestamp", "content-id=%REQ(X-CONTENT-ID)%"},
{"@timestamp", "content-id=%REQ(X-CONTENT-ID):10%"},
{"@timestamp", "length=%RESP(CONTENT-LENGTH):10%"},
{"@timestamp", "trailer=%TRAILER(CONTENT-LENGTH):10%"},
{"@timestamp", "duration=my durations are %DURATION%.0 and method is %REQ(:METHOD)%"},
{"dog=pug", "cat=black"},
}

for _, c := range successCases {
parsedFields := parseAccessLogFields(c)
assert.NoError(t, parsedFields.Validate(), c)
}
}

func TestValidateHTTPVersionType(t *testing.T) {
assert.Error(t, HTTPVersionType("").Validate())
assert.Error(t, HTTPVersionType("foo").Validate())
Expand Down

0 comments on commit f7094b2

Please sign in to comment.