Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ipsec: Improve logging #28642

Merged
merged 3 commits into from
Oct 31, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
54 changes: 45 additions & 9 deletions pkg/datapath/linux/ipsec/ipsec_linux.go
Original file line number Diff line number Diff line change
Expand Up @@ -67,6 +67,14 @@ const (
oldXFRMOutPolicyPriority = 50
)

type dir string
pchaigno marked this conversation as resolved.
Show resolved Hide resolved

const (
dirUnspec dir = "unspecified"
dirIngress dir = "ingress"
dirEgress dir = "egress"
)

type ipSecKey struct {
Spi uint8
ReqID int
Expand Down Expand Up @@ -192,9 +200,11 @@ func xfrmStateReplace(new *netlink.XfrmState) error {
}

scopedLog := log.WithFields(logrus.Fields{
logfields.SPI: new.Spi,
logfields.SourceIP: new.Src,
logfields.DestinationIP: new.Dst,
logfields.SPI: new.Spi,
logfields.SourceIP: new.Src,
logfields.DestinationIP: new.Dst,
logfields.TrafficDirection: getDirFromXfrmMark(new.Mark),
logfields.NodeID: getNodeIDAsHexFromXfrmMark(new.Mark),
})

// Check if the XFRM state already exists
Expand Down Expand Up @@ -293,9 +303,11 @@ func xfrmDeleteConflictingState(states []netlink.XfrmState, new *netlink.XfrmSta
}
deletedSomething = true
log.WithFields(logrus.Fields{
logfields.SPI: s.Spi,
logfields.SourceIP: s.Src,
logfields.DestinationIP: s.Dst,
logfields.SPI: s.Spi,
logfields.SourceIP: s.Src,
logfields.DestinationIP: s.Dst,
logfields.TrafficDirection: getDirFromXfrmMark(s.Mark),
logfields.NodeID: getNodeIDAsHexFromXfrmMark(s.Mark),
}).Info("Removed a conflicting XFRM state")
}
}
Expand Down Expand Up @@ -480,8 +492,10 @@ func deprioritizeOldOutPolicy(family int) {
p.Priority = oldXFRMOutPolicyPriority
if err := netlink.XfrmPolicyUpdate(&p); err != nil {
log.WithError(err).WithFields(logrus.Fields{
logfields.SourceCIDR: p.Src,
logfields.DestinationCIDR: p.Dst,
logfields.SourceCIDR: p.Src,
logfields.DestinationCIDR: p.Dst,
logfields.TrafficDirection: getDirFromXfrmMark(p.Mark),
logfields.NodeID: getNodeIDAsHexFromXfrmMark(p.Mark),
}).Error("Failed to deprioritize old XFRM policy")
}
}
Expand Down Expand Up @@ -514,6 +528,22 @@ func getNodeIDFromXfrmMark(mark *netlink.XfrmMark) uint16 {
return uint16(mark.Value >> 16)
}

func getNodeIDAsHexFromXfrmMark(mark *netlink.XfrmMark) string {
return fmt.Sprintf("0x%x", getNodeIDFromXfrmMark(mark))
}

func getDirFromXfrmMark(mark *netlink.XfrmMark) dir {
switch {
case mark == nil:
return dirUnspec
case mark.Value&linux_defaults.RouteMarkDecrypt != 0:
return dirIngress
case mark.Value&linux_defaults.RouteMarkEncrypt != 0:
return dirEgress
}
return dirUnspec
}

func generateEncryptMark(spi uint8, nodeID uint16) *netlink.XfrmMark {
val := ipSecXfrmMarkSetSPI(linux_defaults.RouteMarkEncrypt, spi)
val |= uint32(nodeID) << 16
Expand Down Expand Up @@ -1092,7 +1122,13 @@ func deleteStaleXfrmPolicies(reclaimTimestamp time.Time) error {
continue
}

scopedLog = scopedLog.WithField(logfields.OldSPI, policySPI)
scopedLog = scopedLog.WithFields(logrus.Fields{
logfields.OldSPI: policySPI,
logfields.SourceIP: p.Src,
logfields.DestinationIP: p.Dst,
logfields.TrafficDirection: getDirFromXfrmMark(p.Mark),
logfields.NodeID: getNodeIDAsHexFromXfrmMark(p.Mark),
})
scopedLog.Info("Deleting stale XFRM policy")
if err := netlink.XfrmPolicyDel(&p); err != nil {
errs.Add(fmt.Errorf("failed to delete stale xfrm policy spi (%d): %w", policySPI, err))
Expand Down
47 changes: 24 additions & 23 deletions pkg/datapath/linux/node.go
Original file line number Diff line number Diff line change
Expand Up @@ -544,12 +544,13 @@ func (n *linuxNodeHandler) NodeUpdate(oldNode, newNode nodeTypes.Node) error {
return nil
}

func upsertIPsecLog(err error, spec string, loc, rem *net.IPNet, spi uint8) error {
func upsertIPsecLog(err error, spec string, loc, rem *net.IPNet, spi uint8, nodeID uint16) error {
scopedLog := log.WithFields(logrus.Fields{
logfields.Reason: spec,
"local-ip": loc,
"remote-ip": rem,
"spi": spi,
logfields.Reason: spec,
logfields.SPI: spi,
logfields.LocalIP: loc,
logfields.RemoteIP: rem,
logfields.NodeID: fmt.Sprintf("0x%x", nodeID),
})
if err != nil {
scopedLog.WithError(err).Error("IPsec enable failed")
Expand Down Expand Up @@ -623,13 +624,13 @@ func (n *linuxNodeHandler) encryptNode(newNode *nodeTypes.Node) error {
ipsecIPv4Wildcard := &net.IPNet{IP: wildcardIP, Mask: net.IPv4Mask(0, 0, 0, 0)}
errs = errors.Join(errs, n.replaceNodeIPSecInRoute(ipsecLocal))
spi, err = ipsec.UpsertIPsecEndpoint(ipsecLocal, ipsecIPv4Wildcard, internalIPv4, wildcardIP, 0, ipsec.IPSecDirIn, false)
errs = errors.Join(errs, upsertIPsecLog(err, "EncryptNode local IPv4", ipsecLocal, ipsecIPv4Wildcard, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "EncryptNode local IPv4", ipsecLocal, ipsecIPv4Wildcard, spi, 0))
pchaigno marked this conversation as resolved.
Show resolved Hide resolved
} else {
if remoteIPv4 := newNode.GetNodeIP(false); remoteIPv4 != nil {
ipsecRemote := &net.IPNet{IP: remoteIPv4, Mask: exactMask}
errs = errors.Join(errs, n.replaceNodeExternalIPSecOutRoute(ipsecRemote))
spi, err = ipsec.UpsertIPsecEndpoint(ipsecLocal, ipsecRemote, internalIPv4, remoteIPv4, 0, ipsec.IPSecDirOutNode, false)
errs = errors.Join(errs, upsertIPsecLog(err, "EncryptNode IPv4", ipsecLocal, ipsecRemote, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "EncryptNode IPv4", ipsecLocal, ipsecRemote, spi, 0))
}
remoteIPv4 := newNode.GetCiliumInternalIP(false)
if remoteIPv4 != nil {
Expand All @@ -642,7 +643,7 @@ func (n *linuxNodeHandler) encryptNode(newNode *nodeTypes.Node) error {
if remoteIPv4T := newNode.GetNodeIP(false); remoteIPv4T != nil {
err = ipsec.UpsertIPsecEndpointPolicy(ipsecWildcard, ipsecRemote, internalIPv4, remoteIPv4T, 0, ipsec.IPSecDirOutNode)
}
errs = errors.Join(errs, upsertIPsecLog(err, "EncryptNode Cilium IPv4", ipsecWildcard, ipsecRemote, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "EncryptNode Cilium IPv4", ipsecWildcard, ipsecRemote, spi, 0))
}
}
}
Expand All @@ -656,13 +657,13 @@ func (n *linuxNodeHandler) encryptNode(newNode *nodeTypes.Node) error {
ipsecIPv6Wildcard := &net.IPNet{IP: wildcardIP, Mask: net.CIDRMask(0, 0)}
errs = errors.Join(errs, n.replaceNodeIPSecInRoute(ipsecLocal))
spi, err = ipsec.UpsertIPsecEndpoint(ipsecLocal, ipsecIPv6Wildcard, internalIPv6, wildcardIP, 0, ipsec.IPSecDirIn, false)
errs = errors.Join(errs, upsertIPsecLog(err, "EncryptNode local IPv6", ipsecLocal, ipsecIPv6Wildcard, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "EncryptNode local IPv6", ipsecLocal, ipsecIPv6Wildcard, spi, 0))
} else {
if remoteIPv6 := newNode.GetNodeIP(true); remoteIPv6 != nil {
ipsecRemote := &net.IPNet{IP: remoteIPv6, Mask: exactMask}
errs = errors.Join(errs, n.replaceNodeExternalIPSecOutRoute(ipsecRemote))
spi, err = ipsec.UpsertIPsecEndpoint(ipsecLocal, ipsecRemote, internalIPv6, remoteIPv6, 0, ipsec.IPSecDirOut, false)
errs = errors.Join(errs, upsertIPsecLog(err, "EncryptNode IPv6", ipsecLocal, ipsecRemote, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "EncryptNode IPv6", ipsecLocal, ipsecRemote, spi, 0))
}
remoteIPv6 := newNode.GetCiliumInternalIP(true)
if remoteIPv6 != nil {
Expand All @@ -675,7 +676,7 @@ func (n *linuxNodeHandler) encryptNode(newNode *nodeTypes.Node) error {
if remoteIPv6T := newNode.GetNodeIP(true); remoteIPv6T != nil {
err = ipsec.UpsertIPsecEndpointPolicy(ipsecWildcard, ipsecRemote, internalIPv6, remoteIPv6T, 0, ipsec.IPSecDirOutNode)
}
errs = errors.Join(errs, upsertIPsecLog(err, "EncryptNode Cilium IPv6", ipsecWildcard, ipsecRemote, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "EncryptNode Cilium IPv6", ipsecWildcard, ipsecRemote, spi, 0))
}
}
}
Expand Down Expand Up @@ -1088,7 +1089,7 @@ func (n *linuxNodeHandler) enableIPsecIPv4(newNode *nodeTypes.Node, nodeID uint1
wildcardCIDR := &net.IPNet{IP: wildcardIP, Mask: net.IPv4Mask(0, 0, 0, 0)}

err := ipsec.IPsecDefaultDropPolicy(false)
errs = errors.Join(errs, upsertIPsecLog(err, "default-drop IPv4", wildcardCIDR, wildcardCIDR, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "default-drop IPv4", wildcardCIDR, wildcardCIDR, spi, 0))

if newNode.IsLocal() {
localIP := newNode.GetCiliumInternalIP(false)
Expand Down Expand Up @@ -1116,10 +1117,10 @@ func (n *linuxNodeHandler) enableIPsecIPv4(newNode *nodeTypes.Node, nodeID uint1
}

spi, err := ipsec.UpsertIPsecEndpoint(wildcardCIDR, cidr, localIP, wildcardIP, 0, ipsec.IPSecDirIn, zeroMark)
errs = errors.Join(errs, upsertIPsecLog(err, "in CiliumInternalIPv4", wildcardCIDR, cidr, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "in CiliumInternalIPv4", wildcardCIDR, cidr, spi, 0))

spi, err = ipsec.UpsertIPsecEndpoint(wildcardCIDR, cidr, localNodeInternalIP, wildcardIP, 0, ipsec.IPSecDirIn, zeroMark)
errs = errors.Join(errs, upsertIPsecLog(err, "in NodeInternalIPv4", wildcardCIDR, cidr, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "in NodeInternalIPv4", wildcardCIDR, cidr, spi, 0))
}
} else {
/* Insert wildcard policy rules for traffic skipping back through host */
Expand All @@ -1130,7 +1131,7 @@ func (n *linuxNodeHandler) enableIPsecIPv4(newNode *nodeTypes.Node, nodeID uint1
localCIDR := n.nodeAddressing.IPv4().AllocationCIDR().IPNet
errs = errors.Join(errs, n.replaceNodeIPSecInRoute(localCIDR))
spi, err = ipsec.UpsertIPsecEndpoint(localCIDR, wildcardCIDR, localIP, wildcardIP, 0, ipsec.IPSecDirIn, false)
errs = errors.Join(errs, upsertIPsecLog(err, "in IPv4", localCIDR, wildcardCIDR, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "in IPv4", localCIDR, wildcardCIDR, spi, 0))
}
} else {
remoteIP := newNode.GetCiliumInternalIP(false)
Expand All @@ -1153,13 +1154,13 @@ func (n *linuxNodeHandler) enableIPsecIPv4(newNode *nodeTypes.Node, nodeID uint1

for _, cidr := range n.nodeConfig.IPv4PodSubnets {
spi, err = ipsec.UpsertIPsecEndpoint(wildcardCIDR, cidr, localIP, remoteIP, nodeID, ipsec.IPSecDirOut, zeroMark)
errs = errors.Join(errs, upsertIPsecLog(err, "out IPv4", wildcardCIDR, cidr, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "out IPv4", wildcardCIDR, cidr, spi, nodeID))
}
} else {
remoteCIDR := newNode.IPv4AllocCIDR.IPNet
n.replaceNodeIPSecOutRoute(remoteCIDR)
spi, err = ipsec.UpsertIPsecEndpoint(wildcardCIDR, remoteCIDR, localIP, remoteIP, nodeID, ipsec.IPSecDirOut, false)
errs = errors.Join(errs, upsertIPsecLog(err, "out IPv4", wildcardCIDR, remoteCIDR, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "out IPv4", wildcardCIDR, remoteCIDR, spi, nodeID))
}
}
return errs
Expand All @@ -1180,7 +1181,7 @@ func (n *linuxNodeHandler) enableIPsecIPv6(newNode *nodeTypes.Node, nodeID uint1
if err != nil {
errs = errors.Join(errs, fmt.Errorf("failed to create default drop policy IPv6: %w", err))
}
errs = errors.Join(errs, upsertIPsecLog(err, "default-drop IPv6", wildcardCIDR, wildcardCIDR, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "default-drop IPv6", wildcardCIDR, wildcardCIDR, spi, 0))

if newNode.IsLocal() {
localIP := newNode.GetCiliumInternalIP(true)
Expand All @@ -1203,16 +1204,16 @@ func (n *linuxNodeHandler) enableIPsecIPv6(newNode *nodeTypes.Node, nodeID uint1

for _, cidr := range n.nodeConfig.IPv6PodSubnets {
spi, err := ipsec.UpsertIPsecEndpoint(wildcardCIDR, cidr, localIP, wildcardIP, 0, ipsec.IPSecDirIn, zeroMark)
errs = errors.Join(errs, upsertIPsecLog(err, "in CiliumInternalIPv6", wildcardCIDR, cidr, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "in CiliumInternalIPv6", wildcardCIDR, cidr, spi, 0))

spi, err = ipsec.UpsertIPsecEndpoint(wildcardCIDR, cidr, localNodeInternalIP, wildcardIP, 0, ipsec.IPSecDirIn, zeroMark)
errs = errors.Join(errs, upsertIPsecLog(err, "in NodeInternalIPv6", wildcardCIDR, cidr, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "in NodeInternalIPv6", wildcardCIDR, cidr, spi, 0))
}
} else {
localCIDR := n.nodeAddressing.IPv6().AllocationCIDR().IPNet
errs = errors.Join(errs, n.replaceNodeIPSecInRoute(localCIDR))
spi, err = ipsec.UpsertIPsecEndpoint(localCIDR, wildcardCIDR, localIP, wildcardIP, 0, ipsec.IPSecDirIn, false)
errs = errors.Join(errs, upsertIPsecLog(err, "in IPv6", localCIDR, wildcardCIDR, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "in IPv6", localCIDR, wildcardCIDR, spi, 0))
}
} else {
remoteIP := newNode.GetCiliumInternalIP(true)
Expand All @@ -1236,13 +1237,13 @@ func (n *linuxNodeHandler) enableIPsecIPv6(newNode *nodeTypes.Node, nodeID uint1

for _, cidr := range n.nodeConfig.IPv6PodSubnets {
spi, err = ipsec.UpsertIPsecEndpoint(wildcardCIDR, cidr, localIP, remoteIP, nodeID, ipsec.IPSecDirOut, zeroMark)
errs = errors.Join(errs, upsertIPsecLog(err, "out IPv6", wildcardCIDR, cidr, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "out IPv6", wildcardCIDR, cidr, spi, nodeID))
}
} else {
remoteCIDR := newNode.IPv6AllocCIDR.IPNet
n.replaceNodeIPSecOutRoute(remoteCIDR)
spi, err := ipsec.UpsertIPsecEndpoint(wildcardCIDR, remoteCIDR, localIP, remoteIP, nodeID, ipsec.IPSecDirOut, false)
errs = errors.Join(errs, upsertIPsecLog(err, "out IPv6", wildcardCIDR, remoteCIDR, spi))
errs = errors.Join(errs, upsertIPsecLog(err, "out IPv6", wildcardCIDR, remoteCIDR, spi, nodeID))
}
}
return errs
Expand Down
4 changes: 4 additions & 0 deletions pkg/logging/logfields/logfields.go
Original file line number Diff line number Diff line change
Expand Up @@ -658,6 +658,10 @@ const (

DestinationIP = "destinationIP"

LocalIP = "localIP"

RemoteIP = "remoteIP"

SourceCIDR = "sourceCIDR"

// DestinationCIDR is a destination CIDR
Expand Down