added trace logs for packets and ebpf

- Log packets.
 - Log special case.
 - Updated information on some rare cases when intercepting connections
   via eBPF.
This commit is contained in:
Gustavo Iñiguez Goia 2025-01-22 01:06:10 +01:00
parent 7a32f32f7a
commit f7803ebdcb
Failed to generate hash of commit
2 changed files with 24 additions and 9 deletions

View file

@ -41,6 +41,7 @@ var showUnknownCons = false
// process generated a connection. // process generated a connection.
func Parse(nfp netfilter.Packet, interceptUnknown bool) *Connection { func Parse(nfp netfilter.Packet, interceptUnknown bool) *Connection {
showUnknownCons = interceptUnknown showUnknownCons = interceptUnknown
log.Trace("Connection.Parse(): %v", nfp)
if nfp.IsIPv4() { if nfp.IsIPv4() {
con, err := NewConnection(&nfp) con, err := NewConnection(&nfp)
@ -70,7 +71,7 @@ func Parse(nfp netfilter.Packet, interceptUnknown bool) *Connection {
func newConnectionImpl(nfp *netfilter.Packet, c *Connection, protoType string) (cr *Connection, err error) { func newConnectionImpl(nfp *netfilter.Packet, c *Connection, protoType string) (cr *Connection, err error) {
// no errors but not enough info neither // no errors but not enough info neither
if c.parseDirection(protoType) == false { if c.parseDirection(protoType) == false {
log.Debug("discarding conn: %+v", c) log.Trace("discarding connection (proto %s): %+v", protoType, c)
return nil, nil return nil, nil
} }
log.Debug("new connection %s => %d:%v -> %v (%s):%d uid: %d, mark: %x", c.Protocol, c.SrcPort, c.SrcIP, c.DstIP, c.DstHost, c.DstPort, nfp.UID, nfp.Mark) log.Debug("new connection %s => %d:%v -> %v (%s):%d uid: %d, mark: %x", c.Protocol, c.SrcPort, c.SrcIP, c.DstIP, c.DstHost, c.DstPort, nfp.UID, nfp.Mark)

View file

@ -26,12 +26,11 @@ func GetPid(proto string, srcPort uint, srcIP net.IP, dstIP net.IP, dstPort uint
} }
if findAddressInLocalAddresses(dstIP) { if findAddressInLocalAddresses(dstIP) {
// NOTE: // NOTE:
// Sometimes every outbound connection has the fields swapped: // Sometimes outbound connections may have the fields swapped:
// 443:public-ip -> local-ip:local-port , like if it was a response (but it's not). // 443:public-ip -> local-ip:local-port.
// @see: e090833d29738274c1d171eba53e239c1c49ea7c
// Swapping connection fields helps to identify the connection + pid + process, and continue working as usual // Swapping connection fields helps to identify the connection + pid + process, and continue working as usual
// when systemd-resolved is being used. // when systemd-resolved is being used.
// This seems to be the case when using conntrack to intercept outbound connections, specially for TCP.
// @see: e090833d29738274c1d171eba53e239c1c49ea7c
if proc := getPidFromEbpf(proto, dstPort, dstIP, srcIP, srcPort); proc != nil { if proc := getPidFromEbpf(proto, dstPort, dstIP, srcIP, srcPort); proc != nil {
return proc, true, fmt.Errorf("[ebpf conn] FIXME: found swapping fields, systemd-resolved is that you? set DNS=x.x.x.x to your DNS server in /etc/systemd/resolved.conf to workaround this problem") return proc, true, fmt.Errorf("[ebpf conn] FIXME: found swapping fields, systemd-resolved is that you? set DNS=x.x.x.x to your DNS server in /etc/systemd/resolved.conf to workaround this problem")
@ -121,7 +120,12 @@ func getPidFromEbpf(proto string, srcPort uint, srcIP net.IP, dstIP net.IP, dstP
if err != nil { if err != nil {
// key not found // key not found
// sometimes srcIP is 0.0.0.0. Happens especially with UDP sendto() // sometimes srcIP is 0.0.0.0. Happens especially with UDP sendto()
// for example: 57621:10.0.3.1 -> 10.0.3.255:57621 , reported as: 0.0.0.0 -> 10.0.3.255 // for example:
// - 57621:10.0.3.1 -> 10.0.3.255:57621 , reported as: 0.0.0.0 -> 10.0.3.255
// - 58306:192.168.11.241 -> 1.2.3.4:54703, reported as: 58306:0.0.0.0 -> 1.2.3.4:54703
// ^ incoming connection to port 58306
// ---
// Sometimes the srcIP is specified in ancillary messages, using IP_PKTINFO.
if isIP4 { if isIP4 {
zeroes := make([]byte, 4) zeroes := make([]byte, 4)
copy(key[8:12], zeroes) copy(key[8:12], zeroes)
@ -131,17 +135,27 @@ func getPidFromEbpf(proto string, srcPort uint, srcIP net.IP, dstIP net.IP, dstP
} }
err = m.LookupElement(ebpfMaps[proto].bpfmap, unsafe.Pointer(&key[0]), unsafe.Pointer(&value)) err = m.LookupElement(ebpfMaps[proto].bpfmap, unsafe.Pointer(&key[0]), unsafe.Pointer(&value))
if err == nil { if err == nil {
log.Trace("[eBPF] found in srcIP 0.0.0.0 (%s): %+v -> %+v", proto, srcIP, dstIP)
delItemIfFound = false delItemIfFound = false
} }
} }
if err != nil && proto == "udp" && srcIP.String() == dstIP.String() { if err != nil && proto == "udp" && srcIP.String() == dstIP.String() {
// very rarely I see this connection. It has srcIP and dstIP == 0.0.0.0 in ebpf map // Sometimes we may intercept srcIP and dstIP == 0.0.0.0 in ebpf.
// it is a localhost to localhost connection
// srcIP was already set to 0, set dstIP to zero also
// TODO try to reproduce it and look for srcIP/dstIP in other kernel structures // TODO try to reproduce it and look for srcIP/dstIP in other kernel structures
//
// entries like 1234:0.0.0.0 -> 0.0.0.0:0 can be of a listening port:
// 38673:0.0.0.0 -> 0.0.0.0:0
// ss -lupn|grep 36523
// UNCONN 0 0 *:36523 *:* users:(("python3",pid=6075,fd=32))
// 6075 ? S 0:00 python3 /usr/bin/wsdd
// srcIP was already set to 0, set dstIP to zero also
zeroes := make([]byte, 4) zeroes := make([]byte, 4)
copy(key[2:6], zeroes) copy(key[2:6], zeroes)
err = m.LookupElement(ebpfMaps[proto].bpfmap, unsafe.Pointer(&key[0]), unsafe.Pointer(&value)) err = m.LookupElement(ebpfMaps[proto].bpfmap, unsafe.Pointer(&key[0]), unsafe.Pointer(&value))
if err == nil {
log.Trace("[eBPF] found in 0.0.0.0 -> 0.0.0.0 (%s): %+v -> %+v", proto, srcIP, dstIP)
}
} }
if err != nil { if err != nil {