Add new flag --log-level (#73)

README.md

@@ -157,6 +157,7 @@ Flags:
   -h, --help                 help for ptcpdump
   -i, --interface strings    Interfaces to capture (default [lo])
       --list-interfaces      Print the list of the network interfaces available on the system
+      --log-level string     Set the logging level ("debug", "info", "warn", "error", "fatal") (default "warn")
       --oneline              Print parsed packet output in a single line
       --pid uint             Filter by process ID (only TCP and UDP packets are supported)
       --pname string         Filter by process name (only TCP and UDP packets are supported)

bpf/bpf.go

@@ -2,7 +2,6 @@ package bpf
 
 import (
 	"encoding/binary"
-	"log"
 	"strings"
 	"unsafe"
 
@@ -11,6 +10,7 @@ import (
 	"github.com/florianl/go-tc"
 	"github.com/florianl/go-tc/core"
 	"github.com/jschwinger233/elibpcap"
+	"github.com/mozillazg/ptcpdump/internal/log"
 	"github.com/mozillazg/ptcpdump/internal/types"
 	"golang.org/x/sys/unix"
 	"golang.org/x/xerrors"
@@ -20,6 +20,7 @@ import (
 //go:generate go run github.com/cilium/ebpf/cmd/bpf2go -cc clang -no-strip -target $TARGET -type packet_event_t -type exec_event_t -type flow_pid_key_t -type process_meta_t -type packet_event_meta_t Bpf ./ptcpdump.c -- -I./headers -I./headers/$TARGET -I. -Wall
 
 const tcFilterName = "ptcpdump"
+const logSzie = ebpf.DefaultVerifierLogSize * 32
 
 type BpfObjectsWithoutCgroup struct {
 	KprobeTcpSendmsg              *ebpf.Program `ebpf:"kprobe__tcp_sendmsg"`
@@ -100,7 +101,7 @@ func NewOptions(pid uint, comm string, followForks bool, pcapFilter string,
 }
 
 func (b *BPF) Load(opts Options) error {
-	// log.Printf("%#v", opts)
+	log.Debugf("load with opts: %#v", opts)
 	err := b.spec.RewriteConstants(map[string]interface{}{
 		"filter_pid":          opts.Pid,
 		"filter_comm":         opts.Comm,
@@ -138,19 +139,19 @@ func (b *BPF) Load(opts Options) error {
 	err = b.spec.LoadAndAssign(b.objs, &ebpf.CollectionOptions{
 		Programs: ebpf.ProgramOptions{
 			LogLevel: ebpf.LogLevelInstruction,
-			LogSize:  ebpf.DefaultVerifierLogSize * 32,
+			LogSize:  logSzie,
 		},
 	})
 	if err != nil {
 		if strings.Contains(err.Error(), "unknown func bpf_get_socket_cookie") {
-			log.Printf("will skip attach cgroup due to %s", err)
+			log.Warnf("will skip attach cgroup due to %s", err)
 
 			b.skipAttachCgroup = true
 			objs := BpfObjectsWithoutCgroup{}
 			if err = b.spec.LoadAndAssign(&objs, &ebpf.CollectionOptions{
 				Programs: ebpf.ProgramOptions{
 					LogLevel: ebpf.LogLevelInstruction,
-					LogSize:  ebpf.DefaultVerifierLogSize * 32,
+					LogSize:  logSzie,
 				},
 			}); err != nil {
 				return err
@@ -179,15 +180,15 @@ func (b *BPF) Load(opts Options) error {
 func (b *BPF) Close() {
 	for _, lk := range b.links {
 		if err := lk.Close(); err != nil {
-			log.Printf("[bpf] close link %v failed: %+v", lk, err)
+			log.Warnf("[bpf] close link %v failed: %+v", lk, err)
 		}
 	}
 	for i := len(b.closeFuncs) - 1; i >= 0; i-- {
 		f := b.closeFuncs[i]
 		f()
 	}
 	if err := b.objs.Close(); err != nil {
-		log.Printf("[bpf] close objects failed: %+v", err)
+		log.Warnf("[bpf] close objects failed: %+v", err)
 	}
 }
 
@@ -264,7 +265,7 @@ func (b *BPF) AttachKprobes() error {
 		b.objs.KprobeNfNatPacket, &link.KprobeOptions{})
 	if err != nil {
 		if strings.Contains(err.Error(), "nf_nat_packet: not found: no such file or directory") {
-			log.Println("current system doest not enable netfilter based NAT feature, skip attach kprobe/nf_nat_packet")
+			log.Warn("current system doest not enable netfilter based NAT feature, skip attach kprobe/nf_nat_packet")
 		} else {
 			return xerrors.Errorf("attach kprobe/nf_nat_packet: %w", err)
 		}
@@ -277,7 +278,7 @@ func (b *BPF) AttachKprobes() error {
 		b.objs.KprobeNfNatManipPkt, &link.KprobeOptions{})
 	if err != nil {
 		if strings.Contains(err.Error(), "nf_nat_manip_pkt: not found: no such file or directory") {
-			log.Println("current system doest not enable netfilter based NAT feature, skip attach kprobe/nf_nat_manip_pkt")
+			log.Warn("current system doest not enable netfilter based NAT feature, skip attach kprobe/nf_nat_manip_pkt")
 		} else {
 			return xerrors.Errorf("attach kprobe/nf_nat_manip_pkt: %w", err)
 		}
@@ -369,7 +370,9 @@ func attachTcHook(ifindex int, prog *ebpf.Program, ingress bool) (func(), error)
 	}
 	closeFunc := func() {
 		if err := tcnl.Close(); err != nil {
-			log.Printf("tcnl.Close() failed: %+v", err)
+			if !strings.Contains(err.Error(), "no such device") {
+				log.Warnf("tcnl.Close() failed: %+v", err)
+			}
 		}
 	}
 
@@ -402,7 +405,9 @@ func attachTcHook(ifindex int, prog *ebpf.Program, ingress bool) (func(), error)
 
 	newCloseFunc := func() {
 		if err := tcnl.Filter().Delete(&filter); err != nil {
-			log.Printf("delete tcnl filter failed: %+v", err)
+			if !strings.Contains(err.Error(), "no such device") {
+				log.Warnf("delete tcnl filter failed: %+v", err)
+			}
 		}
 		closeFunc()
 	}
@@ -416,7 +421,9 @@ func ensureTcQdisc(ifindex int) (func(), error) {
 	}
 	closeFunc := func() {
 		if err := tcnl.Close(); err != nil {
-			log.Printf("tcnl.Close() failed: %+v", err)
+			if !strings.Contains(err.Error(), "no such device") {
+				log.Warnf("tcnl.Close() failed: %+v", err)
+			}
 		}
 	}
 
@@ -438,7 +445,9 @@ func ensureTcQdisc(ifindex int) (func(), error) {
 
 	newCloseFunc := func() {
 		if err := tcnl.Qdisc().Delete(&qdisc); err != nil {
-			log.Printf("delete tcnl qdisc failed: %+v", err)
+			if !strings.Contains(err.Error(), "no such device") {
+				log.Warnf("delete tcnl qdisc failed: %+v", err)
+			}
 		}
 		closeFunc()
 	}

bpf/event.go

@@ -5,10 +5,12 @@ import (
 	"context"
 	"encoding/binary"
 	"errors"
+	"unsafe"
+
 	"github.com/cilium/ebpf/perf"
 	"golang.org/x/xerrors"
-	"log"
-	"unsafe"
+
+	"github.com/mozillazg/ptcpdump/internal/log"
 )
 
 func (b *BPF) PullPacketEvents(ctx context.Context, chanSize int) (<-chan BpfPacketEventT, error) {
@@ -39,12 +41,12 @@ func (b *BPF) handlePacketEvents(ctx context.Context, reader *perf.Reader, ch ch
 			if errors.Is(err, perf.ErrClosed) {
 				return
 			}
-			log.Printf("read packet event failed: %s", err)
+			log.Errorf("read packet event failed: %s", err)
 			continue
 		}
 		event, err := parsePacketEvent(record.RawSample)
 		if err != nil {
-			log.Printf("parse packet event failed: %s", err)
+			log.Errorf("parse packet event failed: %s", err)
 		} else {
 			ch <- *event
 		}
@@ -91,12 +93,12 @@ func (b *BPF) handleExecEvents(ctx context.Context, reader *perf.Reader, ch chan
 			if errors.Is(err, perf.ErrClosed) {
 				return
 			}
-			log.Printf("read exec event failed: %s", err)
+			log.Errorf("read exec event failed: %s", err)
 			continue
 		}
 		event, err := parseExecEvent(record.RawSample)
 		if err != nil {
-			log.Printf("parse exec event failed: %s", err)
+			log.Errorf("parse exec event failed: %s", err)
 		} else {
 			ch <- *event
 		}

bpf/report.go

@@ -2,9 +2,9 @@ package bpf
 
 import (
 	"errors"
-	"log"
 
 	"github.com/cilium/ebpf"
+	"github.com/mozillazg/ptcpdump/internal/log"
 	"github.com/mozillazg/ptcpdump/internal/types"
 )
 
@@ -13,7 +13,7 @@ func (b *BPF) CountReport() types.CountReport {
 	var value uint32
 	if err := b.objs.FilterByKernelCount.Lookup(&zero, &value); err != nil {
 		if !errors.Is(err, ebpf.ErrKeyNotExist) {
-			log.Printf("get value of filter_by_kernel_count failed: %s", err)
+			log.Errorf("get value of filter_by_kernel_count failed: %s", err)
 		}
 	}
 	b.report.Received = int(value)

cmd/capture.go

@@ -3,7 +3,6 @@ package cmd
 import (
 	"context"
 	"fmt"
-	"log"
 	"os"
 	"os/signal"
 	"strings"
@@ -12,11 +11,16 @@ import (
 
 	"github.com/mozillazg/ptcpdump/bpf"
 	"github.com/mozillazg/ptcpdump/internal/consumer"
+	"github.com/mozillazg/ptcpdump/internal/log"
 	"github.com/mozillazg/ptcpdump/internal/metadata"
 	"github.com/mozillazg/ptcpdump/internal/utils"
 )
 
 func capture(ctx context.Context, stop context.CancelFunc, opts Options) error {
+	headerTips(opts)
+	log.Info("capturing...")
+
+	log.Debug("start process and container cache")
 	pcache := metadata.NewProcessCache()
 	cc, _ := applyContainerFilter(ctx, &opts)
 	if cc != nil {
@@ -27,6 +31,7 @@ func capture(ctx context.Context, stop context.CancelFunc, opts Options) error {
 	var err error
 	var subProcessLoaderPid int
 	if len(opts.subProgArgs) > 0 {
+		log.Debug("start sub process loader")
 		subProcessLoaderPid, subProcessFinished, err = utils.StartSubProcessLoader(ctx, os.Args[0], opts.subProgArgs)
 		if err != nil {
 			return err
@@ -48,8 +53,11 @@ func capture(ctx context.Context, stop context.CancelFunc, opts Options) error {
 		}
 	}()
 	pcache.Start()
+
+	log.Debug("start get current connections")
 	conns := getCurrentConnects(ctx, pcache, opts)
 
+	log.Debug("start attach hooks")
 	bf, err := attachHooks(conns, opts)
 	if err != nil {
 		if bf != nil {
@@ -71,17 +79,17 @@ func capture(ctx context.Context, stop context.CancelFunc, opts Options) error {
 	execConsumer := consumer.NewExecEventConsumer(pcache, int(opts.execEventsWorkerNumber))
 	go execConsumer.Start(ctx, execEvensCh)
 
-	log.Println("capturing...")
-
 	var stopByInternal bool
 	packetConsumer := consumer.NewPacketEventConsumer(writers)
 	if opts.delayBeforeHandlePacketEvents > 0 {
 		time.Sleep(opts.delayBeforeHandlePacketEvents)
 	}
 	if subProcessLoaderPid > 0 {
 		go func() {
+			log.Debugf("notify loader %d to start sub process", subProcessLoaderPid)
 			syscall.Kill(subProcessLoaderPid, syscall.SIGHUP)
 			<-subProcessFinished
+			log.Debug("sub process exited")
 			time.Sleep(time.Second * 3)
 			stopByInternal = true
 			stop()
@@ -100,6 +108,19 @@ func capture(ctx context.Context, stop context.CancelFunc, opts Options) error {
 	return nil
 }
 
+func headerTips(opts Options) {
+	interfaces := opts.ifaces[0]
+	if len(opts.ifaces) > 1 {
+		interfaces = fmt.Sprintf("[%s]", strings.Join(opts.ifaces, ", "))
+	}
+	if opts.verbose < 1 {
+		log.Warn("ptcpdump: verbose output suppressed, use -v[v]... for verbose output")
+		log.Warnf("capturing on %s, link-type EN10MB (Ethernet)", interfaces)
+	} else {
+		log.Warnf("tcpdump: capturing on %s, link-type EN10MB (Ethernet)", interfaces)
+	}
+}
+
 func printCaptureCountBySignal(ctx context.Context, bf *bpf.BPF, c *consumer.PacketEventConsumer) {
 	ch := make(chan os.Signal, 1)
 	signal.Notify(ch, syscall.SIGUSR1)
@@ -161,14 +182,14 @@ func getCurrentConnects(ctx context.Context, pcache *metadata.ProcessCache, opts
 		}
 		cs, err := metadata.GetCurrentConnects(ctx, pids, false)
 		if err != nil {
-			log.Printf("get current connects failed: %s", err)
+			log.Errorf("get current connects failed: %s", err)
 		}
 		return cs
 	}
 
 	cs, err := metadata.GetCurrentConnects(ctx, nil, true)
 	if err != nil {
-		log.Printf("get current connects failed: %s", err)
+		log.Errorf("get current connects failed: %s", err)
 	}
 	return cs
 }

cmd/container.go

@@ -2,8 +2,8 @@ package cmd
 
 import (
 	"context"
-	"log"
 
+	"github.com/mozillazg/ptcpdump/internal/log"
 	"github.com/mozillazg/ptcpdump/internal/metadata"
 	"github.com/mozillazg/ptcpdump/internal/types"
 )
@@ -14,7 +14,7 @@ func applyContainerFilter(ctx context.Context, opts *Options) (*metadata.Contain
 		if opts.filterByContainer() {
 			log.Fatalf("find container failed: %s", err)
 		} else {
-			log.Printf("start container cache failed: %s, will no container and pod context", err)
+			log.Warnf("will no container and pod context due to start container cache failed: %s", err)
 			return nil, nil
 		}
 	}
@@ -43,7 +43,7 @@ func applyContainerFilter(ctx context.Context, opts *Options) (*metadata.Contain
 		break
 	}
 
-	// log.Printf("%#v", container)
+	log.Debugf("filter by container %#v", container)
 	if container.PidNamespace > 0 && container.PidNamespace != metadata.HostPidNs {
 		opts.pidns_id = uint32(container.PidNamespace)
 	}

cmd/ebpf.go

@@ -2,15 +2,14 @@ package cmd
 
 import (
 	"encoding/binary"
-	"log"
 	"net/netip"
 
-	"github.com/mozillazg/ptcpdump/internal/utils"
-
 	"github.com/cilium/ebpf/rlimit"
 	"github.com/mozillazg/ptcpdump/bpf"
 	"github.com/mozillazg/ptcpdump/internal/dev"
+	"github.com/mozillazg/ptcpdump/internal/log"
 	"github.com/mozillazg/ptcpdump/internal/metadata"
+	"github.com/mozillazg/ptcpdump/internal/utils"
 	"golang.org/x/xerrors"
 )
 
@@ -40,7 +39,7 @@ func attachHooks(currentConns []metadata.Connection, opts Options) (*bpf.BPF, er
 
 	cgroupPath, err := utils.GetCgroupV2RootDir()
 	if err != nil {
-		log.Print(err)
+		log.Warnf("skip attach cgroup due to get cgroup v2 root dir failed: %s", err)
 	}
 	if cgroupPath != "" {
 		if err := bf.AttachCgroups(cgroupPath); err != nil {