Skip to content

Commit

Permalink
Fix L7NP packet logging (#6651)
Browse files Browse the repository at this point in the history 
Currently when enableLogging is enabled for an L7NP rule,
we enable "tagged" packet logging in the appropriate
Suricata reject rule. Unfortunately, this leads to the wrong
packet being logged: the RST packet generated by Suricata
instead of the original TCP packet containing the HTTP
request from the client.

This solution modifies the design to remove enableLogging in
L7, keep it in L4, and instead configure Suricata to log packet
info for all alert events. This is a global configuration, and no
longer a per-rule configuration. Experiments revealed that
enabling packet logging for all reject rules only had a minor
impact (5%) in performance. Therefore, logging is always
enabled, unconditionally.

Fixes #6636.

Signed-off-by: Qiyue Yao <yaoq@vmware.com>
  • Loading branch information
@qiyueyao
qiyueyao authored Sep 25, 2024
1 parent a1e0a75 commit 48ce631
Show file tree
Hide file tree
Showing 5 changed files with 82 additions and 56 deletions.
39 changes: 20 additions & 19 deletions docs/antrea-l7-network-policy.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -329,20 +329,20 @@ Allow ingress from client (10.10.1.9) to web (10.10.1.10/public/*).
}
```

Deny ingress from client (10.10.1.9) to web (10.10.1.10/admin/*)
Deny ingress from client (10.10.1.4) to web (10.10.1.3/admin/*).

```json
{
"timestamp": "2024-08-26T22:38:26.019956+0000",
"flow_id": 642636870504569,
"timestamp": "2024-09-05T22:49:24.788756+0000",
"flow_id": 1131530446896560,
"in_iface": "antrea-l7-tap0",
"event_type": "alert",
"vlan": [
2
],
"src_ip": "10.10.1.9",
"src_port": 37892,
"dest_ip": "10.10.1.10",
"src_ip": "10.10.1.4",
"src_port": 45034,
"dest_ip": "10.10.1.3",
"dest_port": 80,
"proto": "TCP",
"pkt_src": "wire/pcap",
Expand All @@ -362,36 +362,37 @@ Deny ingress from client (10.10.1.9) to web (10.10.1.10/admin/*)
"flow": {
"pkts_toserver": 3,
"pkts_toclient": 1,
"bytes_toserver": 308,
"bytes_toserver": 307,
"bytes_toclient": 78,
"start": "2024-08-26T22:38:26.018553+0000",
"src_ip": "10.10.1.9",
"dest_ip": "10.10.1.10",
"src_port": 37892,
"start": "2024-09-05T22:49:24.787742+0000",
"src_ip": "10.10.1.4",
"dest_ip": "10.10.1.3",
"src_port": 45034,
"dest_port": 80
}
}
```

Additional packet log when `enableLogging` is set
Additional packet logs are available when `enableLogging` is set, which tracks all
packets in Suricata matching the dst IP address of the packet generating the alert.

```json
{
"timestamp": "2024-08-26T22:38:26.025742+0000",
"flow_id": 642636870504569,
"timestamp": "2024-09-05T22:49:24.788756+0000",
"flow_id": 1131530446896560,
"in_iface": "antrea-l7-tap0",
"event_type": "packet",
"vlan": [
2
],
"src_ip": "10.10.1.10",
"src_port": 80,
"dest_ip": "10.10.1.9",
"dest_port": 37892,
"src_ip": "10.10.1.4",
"src_port": 45034,
"dest_ip": "10.10.1.3",
"dest_port": 80,
"proto": "TCP",
"pkt_src": "wire/pcap",
"tenant_id": 2,
"packet": "/hYGSsKknh8fnhcggQAAAggARQAAKN7MAABABoXdCgoBCgoKAQkAUJQE0EfjHLfFVXZQFAH7QroAAA==",
"packet": "dtwWezuaHlOhfWpNgQAAAggARQAAjU/0QABABtRcCgoBBAoKAQOv6gBQgOZTvPTauPuAGAH7TZcAAAEBCAouFZzsR8fBM0dFVCAvYWRtaW4vaW5kZXguaHRtbCBIVFRQLzEuMQ0KSG9zdDogMTAuMTAuMS4zDQpVc2VyLUFnZW50OiBjdXJsLzcuNzQuMA0KQWNjZXB0OiAqLyoNCg0K",
"packet_info": {
"linktype": 1
}
Expand Down
22 changes: 7 additions & 15 deletions pkg/agent/controller/networkpolicy/l7engine/reconciler.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -78,10 +78,9 @@ outputs:
enabled: no
types:
- alert:
tagged-packets: yes
packet: yes
- http:
extended: yes
tagged-packets: yes
- tls:
extended: yes
- eve-log:
Expand Down Expand Up @@ -170,19 +169,12 @@ func NewReconciler() *Reconciler {
}
}

func generateTenantRulesData(policyName string, protoKeywords map[string]sets.Set[string], enableLogging bool) *bytes.Buffer {
func generateTenantRulesData(policyName string, protoKeywords map[string]sets.Set[string]) *bytes.Buffer {
rulesData := bytes.NewBuffer(nil)
sid := 1

// Enable logging of packets in the session that set off the rule, the session is tagged for 30 seconds.
// Refer to Suricata detect engine in codebase for detailed tag keyword configuration.
var tagKeyword string
if enableLogging {
tagKeyword = " tag: session, 30, seconds;"
}

// Generate default reject rule.
allKeywords := fmt.Sprintf(`msg: "Reject by %s"; flow: to_server, established;%s sid: %d;`, policyName, tagKeyword, sid)
allKeywords := fmt.Sprintf(`msg: "Reject by %s"; flow: to_server, established; sid: %d;`, policyName, sid)
rule := fmt.Sprintf("reject ip any any -> any any (%s)\n", allKeywords)
rulesData.WriteString(rule)
sid++
Expand All @@ -193,9 +185,9 @@ func generateTenantRulesData(policyName string, protoKeywords map[string]sets.Se
// It is a convention that the sid is provided as the last keyword (or second-to-last if there is a rev)
// of a rule.
if keywords != "" {
allKeywords = fmt.Sprintf(`msg: "Allow %s by %s"; %s%s sid: %d;`, proto, policyName, keywords, tagKeyword, sid)
allKeywords = fmt.Sprintf(`msg: "Allow %s by %s"; %s sid: %d;`, proto, policyName, keywords, sid)
} else {
allKeywords = fmt.Sprintf(`msg: "Allow %s by %s";%s sid: %d;`, proto, policyName, tagKeyword, sid)
allKeywords = fmt.Sprintf(`msg: "Allow %s by %s"; sid: %d;`, proto, policyName, sid)
}
rule = fmt.Sprintf("pass %s any any -> any any (%s)\n", proto, allKeywords)
rulesData.WriteString(rule)
Expand Down Expand Up @@ -274,7 +266,7 @@ func (r *Reconciler) StartSuricataOnce() {
})
}

func (r *Reconciler) AddRule(ruleID, policyName string, vlanID uint32, l7Protocols []v1beta.L7Protocol, enableLogging bool) error {
func (r *Reconciler) AddRule(ruleID, policyName string, vlanID uint32, l7Protocols []v1beta.L7Protocol) error {
start := time.Now()
defer func() {
klog.V(5).Infof("AddRule took %v", time.Since(start))
Expand Down Expand Up @@ -304,7 +296,7 @@ func (r *Reconciler) AddRule(ruleID, policyName string, vlanID uint32, l7Protoco
klog.InfoS("Reconciling L7 rule", "RuleID", ruleID, "PolicyName", policyName)
// Write the Suricata rules to file.
rulesPath := generateTenantRulesPath(vlanID)
rulesData := generateTenantRulesData(policyName, protoKeywords, enableLogging)
rulesData := generateTenantRulesData(policyName, protoKeywords)
if err := writeConfigFile(rulesPath, rulesData); err != nil {
return fmt.Errorf("failed to write Suricata rules data to file %s for L7 rule %s of %s, err: %w", rulesPath, ruleID, policyName, err)
}
Expand Down
4 changes: 2 additions & 2 deletions pkg/agent/controller/networkpolicy/l7engine/reconciler_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -189,7 +189,7 @@ func TestRuleLifecycle(t *testing.T) {
fe.startSuricataFn = fs.startSuricataFn

// Test add a L7 NetworkPolicy.
assert.NoError(t, fe.AddRule(ruleID, policyName, vlanID, tc.l7Protocols, false))
assert.NoError(t, fe.AddRule(ruleID, policyName, vlanID, tc.l7Protocols))

rulesPath := generateTenantRulesPath(vlanID)
ok, err := afero.FileContainsBytes(defaultFS, rulesPath, []byte(tc.expectedRules))
Expand All @@ -206,7 +206,7 @@ func TestRuleLifecycle(t *testing.T) {
assert.Equal(t, expectedScCommands, fs.calledScCommands)

// Update the added L7 NetworkPolicy.
assert.NoError(t, fe.AddRule(ruleID, policyName, vlanID, tc.updatedL7Protocols, false))
assert.NoError(t, fe.AddRule(ruleID, policyName, vlanID, tc.updatedL7Protocols))
expectedScCommands.Insert("reload-tenant 1 /etc/suricata/antrea-tenant-1.yaml")
assert.Equal(t, expectedScCommands, fs.calledScCommands)

Expand Down
6 changes: 3 additions & 3 deletions pkg/agent/controller/networkpolicy/networkpolicy_controller.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -72,7 +72,7 @@ const (
)

type L7RuleReconciler interface {
AddRule(ruleID, policyName string, vlanID uint32, l7Protocols []v1beta2.L7Protocol, enableLogging bool) error
AddRule(ruleID, policyName string, vlanID uint32, l7Protocols []v1beta2.L7Protocol) error
DeleteRule(ruleID string, vlanID uint32) error
}

Expand Down Expand Up @@ -802,7 +802,7 @@ func (c *Controller) syncRule(key string) error {
vlanID := c.l7VlanIDAllocator.allocate(key)
rule.L7RuleVlanID = &vlanID

if err := c.l7RuleReconciler.AddRule(key, rule.SourceRef.ToString(), vlanID, rule.L7Protocols, rule.EnableLogging); err != nil {
if err := c.l7RuleReconciler.AddRule(key, rule.SourceRef.ToString(), vlanID, rule.L7Protocols); err != nil {
return err
}
}
Expand Down Expand Up @@ -857,7 +857,7 @@ func (c *Controller) syncRules(keys []string) error {
vlanID := c.l7VlanIDAllocator.allocate(key)
rule.L7RuleVlanID = &vlanID

if err := c.l7RuleReconciler.AddRule(key, rule.SourceRef.ToString(), vlanID, rule.L7Protocols, rule.EnableLogging); err != nil {
if err := c.l7RuleReconciler.AddRule(key, rule.SourceRef.ToString(), vlanID, rule.L7Protocols); err != nil {
return err
}
}
Expand Down
67 changes: 50 additions & 17 deletions test/e2e/l7networkpolicy_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -15,11 +15,13 @@
package e2e

import (
"bytes"
"context"
"encoding/json"
"fmt"
"net"
"reflect"
"regexp"
"slices"
"strings"
"testing"
Expand Down Expand Up @@ -396,12 +398,16 @@ func testL7NetworkPolicyLogging(t *testing.T, data *TestData) {
var l7LogMatchers []*L7LogEntry
for _, ip := range serverIPs {
clientMatcher := &L7LogEntry{
EventType: "alert",
DestIP: ip.String(),
DestPort: 8080,
Protocol: "TCP",
AppProtocol: "http",
Alert: &L7LogAlertEntry{Action: "blocked", Signature: fmt.Sprintf("Reject by AntreaNetworkPolicy:%s/%s", data.testNamespace, policyAllowPathHostname)},
EventType: "alert",
DestIP: ip.String(),
DestPort: 8080,
Protocol: "TCP",
AppProtocol: "http",
expectedPacketRegex: regexp.MustCompile(fmt.Sprintf("%s|HTTP|GET|%s", ip.String(), "/clientip")),
Alert: &L7LogAlertEntry{
Action: "blocked",
Signature: fmt.Sprintf("Reject by AntreaNetworkPolicy:%s/%s", data.testNamespace, policyAllowPathHostname),
},
}
hostMatcher := &L7LogEntry{
EventType: "http",
Expand Down Expand Up @@ -429,17 +435,44 @@ type L7LogAlertEntry struct {
}

type L7LogEntry struct {
EventType string `json:"event_type"`
DestIP string `json:"dest_ip"`
DestPort int32 `json:"dest_port"`
Protocol string `json:"proto"`
AppProtocol string `json:"app_proto,omitempty"`
Http *L7LogHttpEntry `json:"http,omitempty"`
Alert *L7LogAlertEntry `json:"alert,omitempty"`
EventType string `json:"event_type"`
DestIP string `json:"dest_ip"`
DestPort int32 `json:"dest_port"`
Protocol string `json:"proto"`
AppProtocol string `json:"app_proto,omitempty"`
PacketBytes []byte `json:"packet,omitempty"`
Http *L7LogHttpEntry `json:"http,omitempty"`
Alert *L7LogAlertEntry `json:"alert,omitempty"`
expectedPacketRegex *regexp.Regexp
}

func (e *L7LogEntry) Equal(x *L7LogEntry) bool {
return reflect.DeepEqual(e, x)
// Matches the 2 L7LogEntries. If an L7LogEntry includes an expectedPacketRegex, the
// PacketBytes field in the other L7LogEntry must match the regex. If none of the
// L7LogEntries include an expectedPacketRegex, the PacketBytes fields must be
// strictly equal for both entries.
func (e *L7LogEntry) Match(x *L7LogEntry) bool {
packetMatch := func(e, x *L7LogEntry) bool {
if e.expectedPacketRegex != nil {
if !e.expectedPacketRegex.Match(x.PacketBytes) {
return false
}
}
if x.expectedPacketRegex != nil {
if !x.expectedPacketRegex.Match(e.PacketBytes) {
return false
}
}
if e.expectedPacketRegex == nil && x.expectedPacketRegex == nil {
if !bytes.Equal(e.PacketBytes, x.PacketBytes) {
return false
}
}
return true
}

return e.EventType == x.EventType && e.DestIP == x.DestIP && e.DestPort == x.DestPort &&
e.Protocol == x.Protocol && e.AppProtocol == x.AppProtocol && packetMatch(e, x) &&
reflect.DeepEqual(e.Http, x.Http) && reflect.DeepEqual(e.Alert, x.Alert)
}

func (e *L7LogEntry) String() string {
Expand Down Expand Up @@ -469,11 +502,11 @@ func checkL7LoggingResult(t *testing.T, data *TestData, antreaPodName string, l7
return false, err
}
// ignore unexpected log entries and duplicates
if slices.ContainsFunc(expected, log.Equal) && !slices.ContainsFunc(actual, log.Equal) {
if slices.ContainsFunc(expected, log.Match) && !slices.ContainsFunc(actual, log.Match) {
actual = append(actual, log)
}
}
if !slices.EqualFunc(actual, expected, func(e1, e2 *L7LogEntry) bool { return e1.Equal(e2) }) {
if !slices.EqualFunc(actual, expected, func(e1, e2 *L7LogEntry) bool { return e1.Match(e2) }) {
t.Logf("L7NP log mismatch")
t.Logf("Expected: %v", expected)
t.Logf("Actual: %v", actual)
Expand Down

0 comments on commit 48ce631

Please sign in to comment.