feat: add gvisor endpoint log (#375)

This commit is contained in:
naison
2024-11-22 22:06:44 +08:00
committed by GitHub
parent 17a13a2672
commit 5a0533c0fc
8 changed files with 570 additions and 1 deletions

View File

@@ -2,12 +2,14 @@ package cmds
import (
"math/rand"
"os"
"runtime"
"time"
log "github.com/sirupsen/logrus"
"github.com/spf13/cobra"
"go.uber.org/automaxprocs/maxprocs"
glog "gvisor.dev/gvisor/pkg/log"
cmdutil "k8s.io/kubectl/pkg/cmd/util"
"k8s.io/kubectl/pkg/util/i18n"
"k8s.io/kubectl/pkg/util/templates"
@@ -35,6 +37,7 @@ func CmdServe(_ cmdutil.Factory) *cobra.Command {
util.InitLoggerForServer(config.Debug)
runtime.GOMAXPROCS(0)
go util.StartupPProfForServer(config.PProfPort)
glog.SetTarget(util.ServerEmitter{Writer: &glog.Writer{Next: os.Stderr}})
},
RunE: func(cmd *cobra.Command, args []string) error {
rand.Seed(time.Now().UnixNano())

View File

@@ -8,6 +8,7 @@ import (
log "github.com/sirupsen/logrus"
"gvisor.dev/gvisor/pkg/tcpip"
"gvisor.dev/gvisor/pkg/tcpip/link/channel"
"gvisor.dev/gvisor/pkg/tcpip/link/sniffer"
"gvisor.dev/gvisor/pkg/tcpip/transport/tcp"
"github.com/wencaiwulue/kubevpn/v2/pkg/config"
@@ -46,7 +47,7 @@ func (h *gvisorTCPHandler) handle(ctx context.Context, tcpConn net.Conn) {
h.readFromEndpointWriteToTCPConn(ctx, tcpConn, endpoint)
util.SafeClose(errChan)
}()
stack := NewStack(ctx, endpoint)
stack := NewStack(ctx, sniffer.NewWithPrefix(endpoint, "[gVISOR] "))
defer stack.Destroy()
select {
case <-errChan:

View File

@@ -12,6 +12,7 @@ import (
"gvisor.dev/gvisor/pkg/tcpip"
"gvisor.dev/gvisor/pkg/tcpip/header"
"gvisor.dev/gvisor/pkg/tcpip/link/channel"
"gvisor.dev/gvisor/pkg/tcpip/link/sniffer"
"gvisor.dev/gvisor/pkg/tcpip/stack"
"github.com/wencaiwulue/kubevpn/v2/pkg/config"
@@ -29,6 +30,7 @@ func (h *gvisorTCPHandler) readFromEndpointWriteToTCPConn(ctx context.Context, c
pktBuffer := endpoint.ReadContext(ctx)
if pktBuffer != nil {
sniffer.LogPacket("[gVISOR] ", sniffer.DirectionSend, pktBuffer.NetworkProtocolNumber, pktBuffer)
buf := pktBuffer.ToView().AsSlice()
_, err := tcpConn.Write(buf)
if err != nil {
@@ -110,6 +112,7 @@ func (h *gvisorTCPHandler) readFromTCPConnWriteToEndpoint(ctx context.Context, c
Payload: buffer.MakeWithData(buf[:read]),
})
config.SPool.Put(buf[:])
sniffer.LogPacket("[gVISOR] ", sniffer.DirectionRecv, protocol, pkt)
endpoint.InjectInbound(protocol, pkt)
pkt.DecRef()
log.Tracef("[TUN-%s] Write to Gvisor IP-Protocol: %s, SRC: %s, DST: %s, Length: %d", layers.IPProtocol(ipProtocol).String(), layers.IPProtocol(ipProtocol).String(), src.String(), dst, read)

View File

@@ -4,8 +4,11 @@ import (
"fmt"
"path/filepath"
"runtime"
"strings"
"time"
log "github.com/sirupsen/logrus"
glog "gvisor.dev/gvisor/pkg/log"
"k8s.io/utils/ptr"
)
@@ -57,3 +60,35 @@ func (*serverFormat) Format(e *log.Entry) ([]byte, error) {
e.Message,
)), nil
}
type ServerEmitter struct {
*glog.Writer
}
func (g ServerEmitter) Emit(depth int, level glog.Level, timestamp time.Time, format string, args ...any) {
// 0 = this frame.
_, file, line, ok := runtime.Caller(depth + 2)
if ok {
// Trim any directory path from the file.
slash := strings.LastIndexByte(file, byte('/'))
if slash >= 0 {
file = file[slash+1:]
}
} else {
// We don't have a filename.
file = "???"
line = 0
}
// Generate the message.
message := fmt.Sprintf(format, args...)
// Emit the formatted result.
fmt.Fprintf(g.Writer, "%s %s:%d %s: %s\n",
timestamp.Format("2006-01-02 15:04:05"),
file,
line,
level.String(),
message,
)
}

View File

@@ -0,0 +1,85 @@
// Copyright 2018 The gVisor Authors.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
package sniffer
import (
"encoding"
"encoding/binary"
"time"
"gvisor.dev/gvisor/pkg/tcpip"
"gvisor.dev/gvisor/pkg/tcpip/stack"
)
type pcapHeader struct {
// MagicNumber is the file magic number.
MagicNumber uint32
// VersionMajor is the major version number.
VersionMajor uint16
// VersionMinor is the minor version number.
VersionMinor uint16
// Thiszone is the GMT to local correction.
Thiszone int32
// Sigfigs is the accuracy of timestamps.
Sigfigs uint32
// Snaplen is the max length of captured packets, in octets.
Snaplen uint32
// Network is the data link type.
Network uint32
}
var _ encoding.BinaryMarshaler = (*pcapPacket)(nil)
type pcapPacket struct {
timestamp time.Time
packet *stack.PacketBuffer
maxCaptureLen int
}
func (p *pcapPacket) MarshalBinary() ([]byte, error) {
pkt := trimmedClone(p.packet)
defer pkt.DecRef()
packetSize := pkt.Size()
captureLen := p.maxCaptureLen
if packetSize < captureLen {
captureLen = packetSize
}
b := make([]byte, 16+captureLen)
binary.LittleEndian.PutUint32(b[0:4], uint32(p.timestamp.Unix()))
binary.LittleEndian.PutUint32(b[4:8], uint32(p.timestamp.Nanosecond()/1000))
binary.LittleEndian.PutUint32(b[8:12], uint32(captureLen))
binary.LittleEndian.PutUint32(b[12:16], uint32(packetSize))
w := tcpip.SliceWriter(b[16:])
for _, v := range pkt.AsSlices() {
if captureLen == 0 {
break
}
if len(v) > captureLen {
v = v[:captureLen]
}
n, err := w.Write(v)
if err != nil {
panic(err)
}
captureLen -= n
}
return b, nil
}

View File

@@ -0,0 +1,394 @@
// Copyright 2018 The gVisor Authors.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
// Package sniffer provides the implementation of data-link layer endpoints that
// wrap another endpoint and logs inbound and outbound packets.
//
// Sniffer endpoints can be used in the networking stack by calling New(eID) to
// create a new endpoint, where eID is the ID of the endpoint being wrapped,
// and then passing it as an argument to Stack.CreateNIC().
package sniffer
import (
"encoding/binary"
"fmt"
"io"
"time"
"gvisor.dev/gvisor/pkg/atomicbitops"
"gvisor.dev/gvisor/pkg/log"
"gvisor.dev/gvisor/pkg/tcpip"
"gvisor.dev/gvisor/pkg/tcpip/header"
"gvisor.dev/gvisor/pkg/tcpip/header/parse"
"gvisor.dev/gvisor/pkg/tcpip/link/nested"
"gvisor.dev/gvisor/pkg/tcpip/stack"
)
// LogPackets is a flag used to enable or disable packet logging via the log
// package. Valid values are 0 or 1.
var LogPackets atomicbitops.Uint32 = atomicbitops.FromUint32(1)
// LogPacketsToPCAP is a flag used to enable or disable logging packets to a
// pcap writer. Valid values are 0 or 1. A writer must have been specified when the
// sniffer was created for this flag to have effect.
var LogPacketsToPCAP atomicbitops.Uint32 = atomicbitops.FromUint32(1)
// +stateify savable
type endpoint struct {
nested.Endpoint
writer io.Writer
maxPCAPLen uint32
logPrefix string
}
var _ stack.GSOEndpoint = (*endpoint)(nil)
var _ stack.LinkEndpoint = (*endpoint)(nil)
var _ stack.NetworkDispatcher = (*endpoint)(nil)
// A Direction indicates whether the packing is being sent or received.
type Direction int
const (
// DirectionSend indicates a sent packet.
DirectionSend = iota
// DirectionRecv indicates a received packet.
DirectionRecv
)
// New creates a new sniffer link-layer endpoint. It wraps around another
// endpoint and logs packets and they traverse the endpoint.
func New(lower stack.LinkEndpoint) stack.LinkEndpoint {
return NewWithPrefix(lower, "")
}
// NewWithPrefix creates a new sniffer link-layer endpoint. It wraps around
// another endpoint and logs packets prefixed with logPrefix as they traverse
// the endpoint.
//
// logPrefix is prepended to the log line without any separators.
// E.g. logPrefix = "NIC:en0/" will produce log lines like
// "NIC:en0/send udp [...]".
func NewWithPrefix(lower stack.LinkEndpoint, logPrefix string) stack.LinkEndpoint {
sniffer := &endpoint{logPrefix: logPrefix}
sniffer.Endpoint.Init(lower, sniffer)
return sniffer
}
func zoneOffset() (int32, error) {
date := time.Date(0, 0, 0, 0, 0, 0, 0, time.Local)
_, offset := date.Zone()
return int32(offset), nil
}
func writePCAPHeader(w io.Writer, maxLen uint32) error {
offset, err := zoneOffset()
if err != nil {
return err
}
return binary.Write(w, binary.LittleEndian, pcapHeader{
// From https://wiki.wireshark.org/Development/LibpcapFileFormat
MagicNumber: 0xa1b2c3d4,
VersionMajor: 2,
VersionMinor: 4,
Thiszone: offset,
Sigfigs: 0,
Snaplen: maxLen,
Network: 101, // LINKTYPE_RAW
})
}
// NewWithWriter creates a new sniffer link-layer endpoint. It wraps around
// another endpoint and logs packets as they traverse the endpoint.
//
// Each packet is written to writer in the pcap format in a single Write call
// without synchronization. A sniffer created with this function will not emit
// packets using the standard log package.
//
// snapLen is the maximum amount of a packet to be saved. Packets with a length
// less than or equal to snapLen will be saved in their entirety. Longer
// packets will be truncated to snapLen.
func NewWithWriter(lower stack.LinkEndpoint, writer io.Writer, snapLen uint32) (stack.LinkEndpoint, error) {
if err := writePCAPHeader(writer, snapLen); err != nil {
return nil, err
}
sniffer := &endpoint{
writer: writer,
maxPCAPLen: snapLen,
}
sniffer.Endpoint.Init(lower, sniffer)
return sniffer, nil
}
// DeliverNetworkPacket implements the stack.NetworkDispatcher interface. It is
// called by the link-layer endpoint being wrapped when a packet arrives, and
// logs the packet before forwarding to the actual dispatcher.
func (e *endpoint) DeliverNetworkPacket(protocol tcpip.NetworkProtocolNumber, pkt *stack.PacketBuffer) {
e.dumpPacket(DirectionRecv, protocol, pkt)
e.Endpoint.DeliverNetworkPacket(protocol, pkt)
}
func (e *endpoint) dumpPacket(dir Direction, protocol tcpip.NetworkProtocolNumber, pkt *stack.PacketBuffer) {
writer := e.writer
if LogPackets.Load() == 1 {
LogPacket(e.logPrefix, dir, protocol, pkt)
}
if writer != nil && LogPacketsToPCAP.Load() == 1 {
packet := pcapPacket{
timestamp: time.Now(),
packet: pkt,
maxCaptureLen: int(e.maxPCAPLen),
}
b, err := packet.MarshalBinary()
if err != nil {
panic(err)
}
if _, err := writer.Write(b); err != nil {
panic(err)
}
}
}
// WritePackets implements the stack.LinkEndpoint interface. It is called by
// higher-level protocols to write packets; it just logs the packet and
// forwards the request to the lower endpoint.
func (e *endpoint) WritePackets(pkts stack.PacketBufferList) (int, tcpip.Error) {
for _, pkt := range pkts.AsSlice() {
e.dumpPacket(DirectionSend, pkt.NetworkProtocolNumber, pkt)
}
return e.Endpoint.WritePackets(pkts)
}
// LogPacket logs a packet to stdout.
func LogPacket(prefix string, dir Direction, protocol tcpip.NetworkProtocolNumber, pkt *stack.PacketBuffer) {
// Figure out the network layer info.
var transProto uint8
var src tcpip.Address
var dst tcpip.Address
var size uint16
var id uint32
var fragmentOffset uint16
var moreFragments bool
var directionPrefix string
switch dir {
case DirectionSend:
directionPrefix = "send"
case DirectionRecv:
directionPrefix = "recv"
default:
panic(fmt.Sprintf("unrecognized direction: %d", dir))
}
clone := trimmedClone(pkt)
defer clone.DecRef()
switch protocol {
case header.IPv4ProtocolNumber:
if ok := parse.IPv4(clone); !ok {
return
}
ipv4 := header.IPv4(clone.NetworkHeader().Slice())
fragmentOffset = ipv4.FragmentOffset()
moreFragments = ipv4.Flags()&header.IPv4FlagMoreFragments == header.IPv4FlagMoreFragments
src = ipv4.SourceAddress()
dst = ipv4.DestinationAddress()
transProto = ipv4.Protocol()
size = ipv4.TotalLength() - uint16(ipv4.HeaderLength())
id = uint32(ipv4.ID())
case header.IPv6ProtocolNumber:
proto, fragID, fragOffset, fragMore, ok := parse.IPv6(clone)
if !ok {
return
}
ipv6 := header.IPv6(clone.NetworkHeader().Slice())
src = ipv6.SourceAddress()
dst = ipv6.DestinationAddress()
transProto = uint8(proto)
size = ipv6.PayloadLength()
id = fragID
moreFragments = fragMore
fragmentOffset = fragOffset
case header.ARPProtocolNumber:
if !parse.ARP(clone) {
return
}
arp := header.ARP(clone.NetworkHeader().Slice())
log.Infof(
"%s%s arp %s (%s) -> %s (%s) valid:%t",
prefix,
directionPrefix,
tcpip.AddrFromSlice(arp.ProtocolAddressSender()), tcpip.LinkAddress(arp.HardwareAddressSender()),
tcpip.AddrFromSlice(arp.ProtocolAddressTarget()), tcpip.LinkAddress(arp.HardwareAddressTarget()),
arp.IsValid(),
)
return
default:
log.Infof("%s%s unknown network protocol: %d", prefix, directionPrefix, protocol)
return
}
// Figure out the transport layer info.
transName := "unknown"
srcPort := uint16(0)
dstPort := uint16(0)
details := ""
switch tcpip.TransportProtocolNumber(transProto) {
case header.ICMPv4ProtocolNumber:
transName = "icmp"
hdr, ok := clone.Data().PullUp(header.ICMPv4MinimumSize)
if !ok {
break
}
icmp := header.ICMPv4(hdr)
icmpType := "unknown"
if fragmentOffset == 0 {
switch icmp.Type() {
case header.ICMPv4EchoReply:
icmpType = "echo reply"
case header.ICMPv4DstUnreachable:
icmpType = "destination unreachable"
case header.ICMPv4SrcQuench:
icmpType = "source quench"
case header.ICMPv4Redirect:
icmpType = "redirect"
case header.ICMPv4Echo:
icmpType = "echo"
case header.ICMPv4TimeExceeded:
icmpType = "time exceeded"
case header.ICMPv4ParamProblem:
icmpType = "param problem"
case header.ICMPv4Timestamp:
icmpType = "timestamp"
case header.ICMPv4TimestampReply:
icmpType = "timestamp reply"
case header.ICMPv4InfoRequest:
icmpType = "info request"
case header.ICMPv4InfoReply:
icmpType = "info reply"
}
}
log.Infof("%s%s %s %s -> %s %s len:%d id:%04x code:%d", prefix, directionPrefix, transName, src, dst, icmpType, size, id, icmp.Code())
return
case header.ICMPv6ProtocolNumber:
transName = "icmp"
hdr, ok := clone.Data().PullUp(header.ICMPv6MinimumSize)
if !ok {
break
}
icmp := header.ICMPv6(hdr)
icmpType := "unknown"
switch icmp.Type() {
case header.ICMPv6DstUnreachable:
icmpType = "destination unreachable"
case header.ICMPv6PacketTooBig:
icmpType = "packet too big"
case header.ICMPv6TimeExceeded:
icmpType = "time exceeded"
case header.ICMPv6ParamProblem:
icmpType = "param problem"
case header.ICMPv6EchoRequest:
icmpType = "echo request"
case header.ICMPv6EchoReply:
icmpType = "echo reply"
case header.ICMPv6RouterSolicit:
icmpType = "router solicit"
case header.ICMPv6RouterAdvert:
icmpType = "router advert"
case header.ICMPv6NeighborSolicit:
icmpType = "neighbor solicit"
case header.ICMPv6NeighborAdvert:
icmpType = "neighbor advert"
case header.ICMPv6RedirectMsg:
icmpType = "redirect message"
}
log.Infof("%s%s %s %s -> %s %s len:%d id:%04x code:%d", prefix, directionPrefix, transName, src, dst, icmpType, size, id, icmp.Code())
return
case header.UDPProtocolNumber:
transName = "udp"
if ok := parse.UDP(clone); !ok {
break
}
udp := header.UDP(clone.TransportHeader().Slice())
if fragmentOffset == 0 {
srcPort = udp.SourcePort()
dstPort = udp.DestinationPort()
details = fmt.Sprintf("xsum: 0x%x", udp.Checksum())
size -= header.UDPMinimumSize
}
case header.TCPProtocolNumber:
transName = "tcp"
if ok := parse.TCP(clone); !ok {
break
}
tcp := header.TCP(clone.TransportHeader().Slice())
if fragmentOffset == 0 {
offset := int(tcp.DataOffset())
if offset < header.TCPMinimumSize {
details += fmt.Sprintf("invalid packet: tcp data offset too small %d", offset)
break
}
if size := clone.Data().Size() + len(tcp); offset > size && !moreFragments {
details += fmt.Sprintf("invalid packet: tcp data offset %d larger than tcp packet length %d", offset, size)
break
}
srcPort = tcp.SourcePort()
dstPort = tcp.DestinationPort()
size -= uint16(offset)
// Initialize the TCP flags.
flags := tcp.Flags()
details = fmt.Sprintf("flags: %s seqnum: %d ack: %d win: %d xsum:0x%x", flags, tcp.SequenceNumber(), tcp.AckNumber(), tcp.WindowSize(), tcp.Checksum())
if flags&header.TCPFlagSyn != 0 {
details += fmt.Sprintf(" options: %+v", header.ParseSynOptions(tcp.Options(), flags&header.TCPFlagAck != 0))
} else {
details += fmt.Sprintf(" options: %+v", tcp.ParsedOptions())
}
}
default:
log.Infof("%s%s %s -> %s unknown transport protocol: %d", prefix, directionPrefix, src, dst, transProto)
return
}
if pkt.GSOOptions.Type != stack.GSONone {
details += fmt.Sprintf(" gso: %#v", pkt.GSOOptions)
}
log.Infof("%s%s %s %s:%d -> %s:%d len:%d id:%04x %s", prefix, directionPrefix, transName, src, srcPort, dst, dstPort, size, id, details)
}
// trimmedClone clones the packet buffer to not modify the original. It trims
// anything before the network header.
func trimmedClone(pkt *stack.PacketBuffer) *stack.PacketBuffer {
// We don't clone the original packet buffer so that the new packet buffer
// does not have any of its headers set.
//
// We trim the link headers from the cloned buffer as the sniffer doesn't
// handle link headers.
buf := pkt.ToBuffer()
buf.TrimFront(int64(len(pkt.VirtioNetHeader().Slice())))
buf.TrimFront(int64(len(pkt.LinkHeader().Slice())))
return stack.NewPacketBuffer(stack.PacketBufferOptions{Payload: buf})
}

View File

@@ -0,0 +1,47 @@
// automatically generated by stateify.
package sniffer
import (
"context"
"gvisor.dev/gvisor/pkg/state"
)
func (e *endpoint) StateTypeName() string {
return "pkg/tcpip/link/sniffer.endpoint"
}
func (e *endpoint) StateFields() []string {
return []string{
"Endpoint",
"writer",
"maxPCAPLen",
"logPrefix",
}
}
func (e *endpoint) beforeSave() {}
// +checklocksignore
func (e *endpoint) StateSave(stateSinkObject state.Sink) {
e.beforeSave()
stateSinkObject.Save(0, &e.Endpoint)
stateSinkObject.Save(1, &e.writer)
stateSinkObject.Save(2, &e.maxPCAPLen)
stateSinkObject.Save(3, &e.logPrefix)
}
func (e *endpoint) afterLoad(context.Context) {}
// +checklocksignore
func (e *endpoint) StateLoad(ctx context.Context, stateSourceObject state.Source) {
stateSourceObject.Load(0, &e.Endpoint)
stateSourceObject.Load(1, &e.writer)
stateSourceObject.Load(2, &e.maxPCAPLen)
stateSourceObject.Load(3, &e.logPrefix)
}
func init() {
state.Register((*endpoint)(nil))
}

1
vendor/modules.txt vendored
View File

@@ -1743,6 +1743,7 @@ gvisor.dev/gvisor/pkg/tcpip/internal/tcp
gvisor.dev/gvisor/pkg/tcpip/link/channel
gvisor.dev/gvisor/pkg/tcpip/link/nested
gvisor.dev/gvisor/pkg/tcpip/link/packetsocket
gvisor.dev/gvisor/pkg/tcpip/link/sniffer
gvisor.dev/gvisor/pkg/tcpip/network/hash
gvisor.dev/gvisor/pkg/tcpip/network/internal/fragmentation
gvisor.dev/gvisor/pkg/tcpip/network/internal/ip