feat: add gvisor endpoint log (#375)

cmd/kubevpn/cmds/serve.go

@@ -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())

pkg/core/gvisortcphandler.go

@@ -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:

pkg/core/gvisortunendpoint.go

@@ -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)

pkg/util/logger.go

@@ -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,
+	)
+}

vendor/gvisor.dev/gvisor/pkg/tcpip/link/sniffer/pcap.go

@@ -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
+}