From 93e6d39839cc19bf1beca98419c33c9e825e6273 Mon Sep 17 00:00:00 2001 From: Mihir Sathe Date: Sat, 17 Feb 2024 06:43:42 +0000 Subject: [PATCH 1/3] Track Envoy request IDs --- wasmplugin/auditlogger.go | 103 ++++++++++++++++++++++++++++++++++++++ wasmplugin/config.go | 14 ++++-- wasmplugin/plugin.go | 36 ++++--------- 3 files changed, 124 insertions(+), 29 deletions(-) create mode 100644 wasmplugin/auditlogger.go diff --git a/wasmplugin/auditlogger.go b/wasmplugin/auditlogger.go new file mode 100644 index 0000000..eec4b62 --- /dev/null +++ b/wasmplugin/auditlogger.go @@ -0,0 +1,103 @@ +package wasmplugin + +import ( + "fmt" + "strings" + "sync" + + ctypes "github.com/corazawaf/coraza/v3/types" + "github.com/tetratelabs/proxy-wasm-go-sdk/proxywasm" +) + +// Transaction context to store against a transaction ID +type TxnContext struct { + envoyRequestId string +} + +// Logger that includes context from the request in the audit logs and owns the final formatting +type ContextualAuditLogger struct { + txnContextMap map[string]*TxnContext + lock sync.Mutex +} + +// Get the global audit logger that can be used across all requests +func NewAppAuditLogger() *ContextualAuditLogger { + return &ContextualAuditLogger{ + txnContextMap: make(map[string]*TxnContext), + } +} + +// Register a transaction with the logger +func (cal *ContextualAuditLogger) Register(txnId string, ctx *TxnContext) { + cal.lock.Lock() + defer cal.lock.Unlock() + + cal.txnContextMap[txnId] = ctx +} + +// Remove the transaction information from the context map +func (cal *ContextualAuditLogger) Unregister(txnId string) { + cal.lock.Lock() + defer cal.lock.Unlock() + + delete(cal.txnContextMap, txnId) +} + +// Emit log on the given rule and add the txn context if available +func (cal *ContextualAuditLogger) AuditLog(rule ctypes.MatchedRule) { + cal.lock.Lock() + defer cal.lock.Unlock() + + txnId := rule.TransactionID() + + var log *strings.Builder + if ctx, ok := cal.txnContextMap[txnId]; ok { + // If we have context, add it to the log + fmt.Fprintf(log, "[request-id %q] ", ctx.envoyRequestId) + } + + logError(rule, log) +} + +func logError(error ctypes.MatchedRule, log *strings.Builder) { + msg := error.ErrorLog() + fmt.Fprint(log, msg) + switch error.Rule().Severity() { + case ctypes.RuleSeverityEmergency: + proxywasm.LogCritical(msg) + case ctypes.RuleSeverityAlert: + proxywasm.LogCritical(msg) + case ctypes.RuleSeverityCritical: + proxywasm.LogCritical(msg) + case ctypes.RuleSeverityError: + proxywasm.LogError(msg) + case ctypes.RuleSeverityWarning: + proxywasm.LogWarn(msg) + case ctypes.RuleSeverityNotice: + proxywasm.LogInfo(msg) + case ctypes.RuleSeverityInfo: + proxywasm.LogInfo(msg) + case ctypes.RuleSeverityDebug: + proxywasm.LogDebug(msg) + } +} + +const ( + // This is the standard Envoy header for request IDs + envoyRequestIdHeader = "x-request-id" +) + +// A convenience method to register the request information with the audit logger if available +// on the request (else ignores). Must be called in the request context. +func registerRequestContextWithLogger(auditLogger *ContextualAuditLogger, txnId string) { + if id, err := proxywasm.GetHttpRequestHeader(envoyRequestIdHeader); err != nil { + auditLogger.Register(txnId, &TxnContext{ + envoyRequestId: id, + }) + } +} + +// Remove context for the given transaction ID +func removeRequestContextFromLogger(auditLogger *ContextualAuditLogger, txnId string) { + auditLogger.Unregister(txnId) +} diff --git a/wasmplugin/config.go b/wasmplugin/config.go index 0734524..caa3b44 100644 --- a/wasmplugin/config.go +++ b/wasmplugin/config.go @@ -12,10 +12,11 @@ import ( // pluginConfiguration is a type to represent an example configuration for this wasm plugin. type pluginConfiguration struct { - directivesMap DirectivesMap - metricLabels map[string]string - defaultDirectives string - perAuthorityDirectives map[string]string + directivesMap DirectivesMap + metricLabels map[string]string + defaultDirectives string + perAuthorityDirectives map[string]string + includeRequestIdInAuditLogs bool } type DirectivesMap map[string][]string @@ -33,6 +34,11 @@ func parsePluginConfiguration(data []byte, infoLogger func(string)) (pluginConfi } jsonData := gjson.ParseBytes(data) + includeReqId := jsonData.Get("include_request_id_in_audit_logs") + if includeReqId.Exists() && includeReqId.IsBool() && includeReqId.Bool() { + config.includeRequestIdInAuditLogs = true + } + config.directivesMap = make(DirectivesMap) jsonData.Get("directives_map").ForEach(func(key, value gjson.Result) bool { directiveName := key.String() diff --git a/wasmplugin/plugin.go b/wasmplugin/plugin.go index e2fae78..e5d1a24 100644 --- a/wasmplugin/plugin.go +++ b/wasmplugin/plugin.go @@ -30,8 +30,8 @@ func NewVMContext() types.VMContext { return &vmContext{} } -func (*vmContext) NewPluginContext(contextID uint32) types.PluginContext { - return &corazaPlugin{} +func (vc *vmContext) NewPluginContext(contextID uint32) types.PluginContext { + return &corazaPlugin{auditLogger: NewAppAuditLogger()} } type wafMap struct { @@ -80,6 +80,7 @@ type corazaPlugin struct { perAuthorityWAFs wafMap metricLabelsKV []string metrics *wafMetrics + auditLogger *ContextualAuditLogger } func (ctx *corazaPlugin) OnPluginStart(pluginConfigurationSize int) types.OnPluginStartStatus { @@ -123,7 +124,7 @@ func (ctx *corazaPlugin) OnPluginStart(pluginConfigurationSize int) types.OnPlug // First we initialize our waf and our seclang parser conf := coraza.NewWAFConfig(). - WithErrorCallback(logError). + WithErrorCallback(ctx.auditLogger.AuditLog). WithDebugLogger(debuglog.DefaultWithPrinterFactory(logPrinterFactory)). // TODO(anuraaga): Make this configurable in plugin configuration. // WithRequestBodyLimit(1024 * 1024 * 1024). @@ -181,6 +182,7 @@ func (ctx *corazaPlugin) NewHttpContext(contextID uint32) types.HttpContext { metrics: ctx.metrics, metricLabelsKV: ctx.metricLabelsKV, perAuthorityWAFs: ctx.perAuthorityWAFs, + auditLogger: ctx.auditLogger, } } @@ -228,6 +230,7 @@ type httpContext struct { interruptedAt interruptionPhase logger debuglog.Logger metricLabelsKV []string + auditLogger *ContextualAuditLogger } func (ctx *httpContext) OnHttpRequestHeaders(numHeaders int, endOfStream bool) types.Action { @@ -235,6 +238,9 @@ func (ctx *httpContext) OnHttpRequestHeaders(numHeaders int, endOfStream bool) t ctx.metrics.CountTX() + // Register context with audit logging context + registerRequestContextWithLogger(ctx.auditLogger, ctx.tx.ID()) + authority, err := proxywasm.GetHttpRequestHeader(":authority") if err != nil { proxywasm.LogDebugf("Failed to get the :authority pseudo-header: %v", err) @@ -632,6 +638,8 @@ func (ctx *httpContext) OnHttpResponseBody(bodySize int, endOfStream bool) types } func (ctx *httpContext) OnHttpStreamDone() { + // Cleanup transaction ID from the audit logging context + defer removeRequestContextFromLogger(ctx.auditLogger, ctx.tx.ID()) defer logTime("OnHttpStreamDone", currentTime()) tx := ctx.tx @@ -695,28 +703,6 @@ func (ctx *httpContext) handleInterruption(phase interruptionPhase, interruption return types.ActionPause } -func logError(error ctypes.MatchedRule) { - msg := error.ErrorLog() - switch error.Rule().Severity() { - case ctypes.RuleSeverityEmergency: - proxywasm.LogCritical(msg) - case ctypes.RuleSeverityAlert: - proxywasm.LogCritical(msg) - case ctypes.RuleSeverityCritical: - proxywasm.LogCritical(msg) - case ctypes.RuleSeverityError: - proxywasm.LogError(msg) - case ctypes.RuleSeverityWarning: - proxywasm.LogWarn(msg) - case ctypes.RuleSeverityNotice: - proxywasm.LogInfo(msg) - case ctypes.RuleSeverityInfo: - proxywasm.LogInfo(msg) - case ctypes.RuleSeverityDebug: - proxywasm.LogDebug(msg) - } -} - // retrieveAddressInfo retrieves address properties from the proxy // Expected targets are "source" or "destination" // Envoy ref: https://www.envoyproxy.io/docs/envoy/latest/intro/arch_overview/advanced/attributes#connection-attributes From e3258db0bdea69cfbc735bd5f254e3642628a8c9 Mon Sep 17 00:00:00 2001 From: Mihir Sathe Date: Sat, 17 Feb 2024 06:57:52 +0000 Subject: [PATCH 2/3] Fix nil dereference --- wasmplugin/auditlogger.go | 1 + 1 file changed, 1 insertion(+) diff --git a/wasmplugin/auditlogger.go b/wasmplugin/auditlogger.go index eec4b62..da655a7 100644 --- a/wasmplugin/auditlogger.go +++ b/wasmplugin/auditlogger.go @@ -24,6 +24,7 @@ type ContextualAuditLogger struct { func NewAppAuditLogger() *ContextualAuditLogger { return &ContextualAuditLogger{ txnContextMap: make(map[string]*TxnContext), + lock: sync.Mutex{}, } } From c28ec7a9cecd5d3accb11f42872e020424063162 Mon Sep 17 00:00:00 2001 From: Mihir Sathe Date: Sat, 17 Feb 2024 18:33:21 +0000 Subject: [PATCH 3/3] Finish the request ID propagation --- wasmplugin/auditlogger.go | 29 +++++++++++++++-------------- wasmplugin/plugin.go | 11 +++++++---- 2 files changed, 22 insertions(+), 18 deletions(-) diff --git a/wasmplugin/auditlogger.go b/wasmplugin/auditlogger.go index da655a7..8ae1ddf 100644 --- a/wasmplugin/auditlogger.go +++ b/wasmplugin/auditlogger.go @@ -2,7 +2,6 @@ package wasmplugin import ( "fmt" - "strings" "sync" ctypes "github.com/corazawaf/coraza/v3/types" @@ -16,15 +15,16 @@ type TxnContext struct { // Logger that includes context from the request in the audit logs and owns the final formatting type ContextualAuditLogger struct { - txnContextMap map[string]*TxnContext - lock sync.Mutex + IncludeRequestContext bool + txnContextMap map[string]*TxnContext + lock sync.Mutex } // Get the global audit logger that can be used across all requests -func NewAppAuditLogger() *ContextualAuditLogger { +func NewAppAuditLogger(includeRequestContext bool) *ContextualAuditLogger { return &ContextualAuditLogger{ - txnContextMap: make(map[string]*TxnContext), - lock: sync.Mutex{}, + txnContextMap: make(map[string]*TxnContext), + IncludeRequestContext: includeRequestContext, } } @@ -51,18 +51,19 @@ func (cal *ContextualAuditLogger) AuditLog(rule ctypes.MatchedRule) { txnId := rule.TransactionID() - var log *strings.Builder + logPrefix := "" if ctx, ok := cal.txnContextMap[txnId]; ok { - // If we have context, add it to the log - fmt.Fprintf(log, "[request-id %q] ", ctx.envoyRequestId) + if cal.IncludeRequestContext { + // If we have context, add it to the log + logPrefix = fmt.Sprintf("[request-id %q] ", ctx.envoyRequestId) + } } - logError(rule, log) + logError(rule, logPrefix) } -func logError(error ctypes.MatchedRule, log *strings.Builder) { - msg := error.ErrorLog() - fmt.Fprint(log, msg) +func logError(error ctypes.MatchedRule, logPrefix string) { + msg := logPrefix + error.ErrorLog() switch error.Rule().Severity() { case ctypes.RuleSeverityEmergency: proxywasm.LogCritical(msg) @@ -91,7 +92,7 @@ const ( // A convenience method to register the request information with the audit logger if available // on the request (else ignores). Must be called in the request context. func registerRequestContextWithLogger(auditLogger *ContextualAuditLogger, txnId string) { - if id, err := proxywasm.GetHttpRequestHeader(envoyRequestIdHeader); err != nil { + if id, err := proxywasm.GetHttpRequestHeader(envoyRequestIdHeader); err == nil { auditLogger.Register(txnId, &TxnContext{ envoyRequestId: id, }) diff --git a/wasmplugin/plugin.go b/wasmplugin/plugin.go index e5d1a24..3ee44ba 100644 --- a/wasmplugin/plugin.go +++ b/wasmplugin/plugin.go @@ -31,7 +31,7 @@ func NewVMContext() types.VMContext { } func (vc *vmContext) NewPluginContext(contextID uint32) types.PluginContext { - return &corazaPlugin{auditLogger: NewAppAuditLogger()} + return &corazaPlugin{} } type wafMap struct { @@ -95,6 +95,8 @@ func (ctx *corazaPlugin) OnPluginStart(pluginConfigurationSize int) types.OnPlug return types.OnPluginStartStatusFailed } + ctx.auditLogger = NewAppAuditLogger(config.includeRequestIdInAuditLogs) + // directivesAuthoritesMap is a map of directives name to the list of // authorities that reference those directives. This is used to // initialize the WAFs only for the directives that are referenced @@ -238,9 +240,6 @@ func (ctx *httpContext) OnHttpRequestHeaders(numHeaders int, endOfStream bool) t ctx.metrics.CountTX() - // Register context with audit logging context - registerRequestContextWithLogger(ctx.auditLogger, ctx.tx.ID()) - authority, err := proxywasm.GetHttpRequestHeader(":authority") if err != nil { proxywasm.LogDebugf("Failed to get the :authority pseudo-header: %v", err) @@ -251,6 +250,7 @@ func (ctx *httpContext) OnHttpRequestHeaders(numHeaders int, endOfStream bool) t } authority = string(propHostRaw) } + if waf, isDefault, resolveWAFErr := ctx.perAuthorityWAFs.getWAFOrDefault(authority); resolveWAFErr == nil { ctx.tx = waf.NewTransaction() @@ -274,6 +274,9 @@ func (ctx *httpContext) OnHttpRequestHeaders(numHeaders int, endOfStream bool) t tx := ctx.tx + // Register context with audit logging context + registerRequestContextWithLogger(ctx.auditLogger, ctx.tx.ID()) + // This currently relies on Envoy's behavior of mapping all requests to HTTP/2 semantics // and its request properties, but they may not be true of other proxies implementing // proxy-wasm.