From 2b2075940f73b92515205d7d1f9f9789e1617b8b Mon Sep 17 00:00:00 2001 From: Robb Kidd Date: Thu, 17 Aug 2023 06:51:33 -0400 Subject: [PATCH] feat: more better logging (#72) ## Which problem is this PR solving? - Closes #69 ## Short description of the changes - add zerolog as a fast, low-resource logging library (among those recommended by logrus) - structure our calls formerly to stdlib's `log` now to zerolog's `log` TODO: - [x] replace or remove all the `fmt.Printf()`s ## How to verify that this has the expected result - Beyond "lookit the console", TBD --------- Co-authored-by: Mike Goldsmth --- assemblers/config.go | 6 +- assemblers/log.go | 24 ------- assemblers/tcp_assembler.go | 119 +++++++++++++++---------------- assemblers/tcp_stream.go | 38 ++++++++-- assemblers/tcp_stream_factory.go | 6 +- bpf/probes/manager.go | 20 +++--- go.mod | 3 + go.sum | 17 +++++ main.go | 37 ++++++---- 9 files changed, 152 insertions(+), 118 deletions(-) delete mode 100644 assemblers/log.go diff --git a/assemblers/config.go b/assemblers/config.go index 366ae31e..08004ea4 100644 --- a/assemblers/config.go +++ b/assemblers/config.go @@ -4,6 +4,8 @@ import ( "encoding/json" "flag" "time" + + "github.com/rs/zerolog/log" ) const closeTimeout time.Duration = time.Hour * 24 @@ -74,9 +76,9 @@ func NewConfig() *config { if c.Debug { b, err := json.MarshalIndent(c, "", " ") if err != nil { - Debug("Failed to marshal agent config: %e", err) + log.Debug().Err(err).Msg("Failed to marshal agent config") } else { - Debug("Agent config: %s", string(b)) + log.Debug().RawJSON("Agent config", b) } } return c diff --git a/assemblers/log.go b/assemblers/log.go deleted file mode 100644 index e12d7899..00000000 --- a/assemblers/log.go +++ /dev/null @@ -1,24 +0,0 @@ -package assemblers - -import "fmt" - -func Error(t string, s string, a ...interface{}) { - errorsMapMutex.Lock() - errors++ - nb, _ := errorsMap[t] - errorsMap[t] = nb + 1 - errorsMapMutex.Unlock() - if logLevel >= 0 { - fmt.Printf(s, a...) - } -} -func Info(s string, a ...interface{}) { - if logLevel >= 1 { - fmt.Printf(s, a...) - } -} -func Debug(s string, a ...interface{}) { - if logLevel >= 2 { - fmt.Printf(s, a...) - } -} \ No newline at end of file diff --git a/assemblers/tcp_assembler.go b/assemblers/tcp_assembler.go index 2c56d0b2..68a55c67 100644 --- a/assemblers/tcp_assembler.go +++ b/assemblers/tcp_assembler.go @@ -2,10 +2,7 @@ package assemblers import ( "flag" - "fmt" - "log" "strings" - "sync" "time" "github.com/google/gopacket" @@ -13,6 +10,8 @@ import ( "github.com/google/gopacket/layers" "github.com/google/gopacket/pcap" "github.com/google/gopacket/reassembly" + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" ) var stats struct { @@ -33,11 +32,6 @@ var stats struct { overlapPackets int } -var logLevel int -var errorsMap map[string]uint -var errorsMapMutex sync.Mutex -var errors uint - type Context struct { CaptureInfo gopacket.CaptureInfo } @@ -60,39 +54,40 @@ func NewTcpAssembler(config config, httpEvents chan HttpEvent) tcpAssembler { var handle *pcap.Handle var err error - // Set logging level - if *debug { - logLevel = 2 - } else if *verbose { - logLevel = 1 - } else if *quiet { - logLevel = -1 - } - - errorsMap = make(map[string]uint) // Set up pcap packet capture if *fname != "" { - log.Printf("Reading from pcap dump %q", *fname) + log.Info(). + Str("filename", *fname). + Msg("Reading from pcap dump") handle, err = pcap.OpenOffline(*fname) } else { - log.Printf("Starting capture on interface %q", *iface) + log.Info(). + Str("interface", *iface). + Msg("Starting capture") handle, err = pcap.OpenLive(*iface, int32(*snaplen), true, pcap.BlockForever) } if err != nil { - log.Fatal(err) + log.Fatal(). + Err(err). + Msg("Failed to open a pcap handle") } if len(flag.Args()) > 0 { bpffilter := strings.Join(flag.Args(), " ") - Info("Using BPF filter %q\n", bpffilter) + log.Info(). + Str("bpf_filter", bpffilter). + Msg("Using BPF filter") if err = handle.SetBPFFilter(bpffilter); err != nil { - log.Fatal("BPF filter error:", err) + log.Fatal(). + Err(err). + Str("bpf_filter", bpffilter). + Msg("BPF filter error") } } packetSource := gopacket.NewPacketSource(handle, handle.LinkType()) packetSource.Lazy = *lazy packetSource.NoCopy = true - Info("Starting to read packets\n") + log.Info().Msg("Starting to read packets") streamFactory := NewTcpStreamFactory(httpEvents) streamPool := reassembly.NewStreamPool(&streamFactory) @@ -131,16 +126,16 @@ func (h *tcpAssembler) Start() { l := ip4.Length newip4, err := defragger.DefragIPv4(ip4) if err != nil { - log.Fatalln("Error while de-fragmenting", err) + log.Fatal().Err(err).Msg("Error while de-fragmenting") } else if newip4 == nil { - // Debug("Fragment...\n") - log.Printf("Fragment...\n") + log.Debug().Msg("Fragment...\n") continue // packet fragment, we don't have whole packet yet. } if newip4.Length != l { stats.ipdefrag++ - // Debug("Decoding re-assembled packet: %s\n", newip4.NextLayerType()) - log.Printf("Decoding re-assembled packet: %s\n", newip4.NextLayerType()) + log.Debug(). + Str("network_layer_type", newip4.NextLayerType().String()). + Msg("Decoding re-assembled packet") pb, ok := packet.(gopacket.PacketBuilder) if !ok { panic("Not a PacketBuilder") @@ -156,7 +151,7 @@ func (h *tcpAssembler) Start() { if h.config.Checksum { err := tcp.SetNetworkLayerForChecksum(packet.NetworkLayer()) if err != nil { - log.Fatalf("Failed to set network layer for checksum: %s\n", err) + log.Fatal().Err(err).Msg("Failed to set network layer for checksum") } } c := Context{ @@ -168,15 +163,20 @@ func (h *tcpAssembler) Start() { if count%h.config.Statsevery == 0 { ref := packet.Metadata().CaptureInfo.Timestamp flushed, closed := h.assembler.FlushWithOptions(reassembly.FlushOptions{T: ref.Add(-h.config.Timeout), TC: ref.Add(-h.config.CloseTimeout)}) - Debug("Forced flush: %d flushed, %d closed (%s)", flushed, closed, ref) + log.Debug(). + Int("flushed", flushed). + Int("closed", closed). + Time("packet_timestamp", ref). + Msg("Forced flush") } done := h.config.Maxcount > 0 && count >= h.config.Maxcount if count%h.config.Statsevery == 0 || done { - errorsMapMutex.Lock() - errorMapLen := len(errorsMap) - errorsMapMutex.Unlock() - Debug("Processed %v packets (%v bytes) in %v (errors: %v, errTypes:%v)\n", count, bytes, time.Since(start), errors, errorMapLen) + log.Info(). + Int("processed_count_since_start", count). + Int64("milliseconds_since_start", time.Since(start).Milliseconds()). + Int64("bytes", bytes). + Msg("Processed Packets") } } } @@ -184,34 +184,31 @@ func (h *tcpAssembler) Start() { func (h *tcpAssembler) Stop() { closed := h.assembler.FlushAll() // Debug("Final flush: %d closed", closed) - log.Printf("Final flush: %d closed", closed) - if logLevel >= 2 { + log.Debug(). + Int("closed", closed). + Msg("Final flush") + if zerolog.GlobalLevel() >= zerolog.DebugLevel { + // this uses stdlib's log, but oh well h.streamPool.Dump() } h.streamFactory.WaitGoRoutines() - // Debug("%s\n", h.assembler.Dump()) - log.Printf("%s\n", h.assembler.Dump()) - if !h.config.Nodefrag { - fmt.Printf("IPdefrag:\t\t%d\n", stats.ipdefrag) - } - fmt.Printf("TCP stats:\n") - fmt.Printf(" missed bytes:\t\t%d\n", stats.missedBytes) - fmt.Printf(" total packets:\t\t%d\n", stats.pkt) - fmt.Printf(" rejected FSM:\t\t%d\n", stats.rejectFsm) - fmt.Printf(" rejected Options:\t%d\n", stats.rejectOpt) - fmt.Printf(" reassembled bytes:\t%d\n", stats.sz) - fmt.Printf(" total TCP bytes:\t%d\n", stats.totalsz) - fmt.Printf(" conn rejected FSM:\t%d\n", stats.rejectConnFsm) - fmt.Printf(" reassembled chunks:\t%d\n", stats.reassembled) - fmt.Printf(" out-of-order packets:\t%d\n", stats.outOfOrderPackets) - fmt.Printf(" out-of-order bytes:\t%d\n", stats.outOfOrderBytes) - fmt.Printf(" biggest-chunk packets:\t%d\n", stats.biggestChunkPackets) - fmt.Printf(" biggest-chunk bytes:\t%d\n", stats.biggestChunkBytes) - fmt.Printf(" overlap packets:\t%d\n", stats.overlapPackets) - fmt.Printf(" overlap bytes:\t\t%d\n", stats.overlapBytes) - fmt.Printf("Errors: %d\n", errors) - for e, _ := range errorsMap { - fmt.Printf(" %s:\t\t%d\n", e, errorsMap[e]) - } + log.Debug(). + Str("assember_page_usage", h.assembler.Dump()). + Int("IPdefrag", stats.ipdefrag). + Int("missed_bytes", stats.missedBytes). + Int("total_packets", stats.pkt). + Int("rejected_FSM", stats.rejectFsm). + Int("rejected_Options", stats.rejectOpt). + Int("reassembled_bytes", stats.sz). + Int("total_TCP_bytes", stats.totalsz). + Int("conn_rejected_FSM", stats.rejectConnFsm). + Int("reassembled_chunks", stats.reassembled). + Int("out_of_order_packets", stats.outOfOrderPackets). + Int("out_of_order_bytes", stats.outOfOrderBytes). + Int("biggest_chunk_packets", stats.biggestChunkPackets). + Int("biggest_chunk_bytes", stats.biggestChunkBytes). + Int("overlap_packets", stats.overlapPackets). + Int("overlap_bytes", stats.overlapBytes). + Msg("Stop") } diff --git a/assemblers/tcp_stream.go b/assemblers/tcp_stream.go index c4367d0d..8698ea14 100644 --- a/assemblers/tcp_stream.go +++ b/assemblers/tcp_stream.go @@ -7,6 +7,7 @@ import ( "github.com/google/gopacket" "github.com/google/gopacket/layers" "github.com/google/gopacket/reassembly" + "github.com/rs/zerolog/log" ) type tcpStream struct { @@ -51,10 +52,16 @@ func (t *tcpStream) Accept(tcp *layers.TCP, ci gopacket.CaptureInfo, dir reassem if *checksum { c, err := tcp.ComputeChecksum() if err != nil { - Error("ChecksumCompute", "%s: Got error computing checksum: %s\n", t.ident, err) + log.Error(). + Err(err). + Str("tcp_stream_ident", t.ident). + Msg("ChecksumCompute") accept = false } else if c != 0x0 { - Error("Checksum", "%s: Invalid checksum: 0x%x\n", t.ident, c) + log.Error(). + Str("tcp_stream_ident", t.ident). + Uint16("checksum", c). + Msg("InvalidChecksum") accept = false } } @@ -86,7 +93,10 @@ func (t *tcpStream) ReassembledSG(sg reassembly.ScatterGather, ac reassembly.Ass stats.biggestChunkPackets = sgStats.Packets } if sgStats.OverlapBytes != 0 && sgStats.OverlapPackets == 0 { - fmt.Printf("bytes:%d, pkts:%d\n", sgStats.OverlapBytes, sgStats.OverlapPackets) + log.Fatal(). + Int("bytes", sgStats.OverlapBytes). + Int("packets", sgStats.OverlapPackets). + Msg("Invalid overlap") panic("Invalid overlap") } stats.overlapBytes += sgStats.OverlapBytes @@ -94,11 +104,23 @@ func (t *tcpStream) ReassembledSG(sg reassembly.ScatterGather, ac reassembly.Ass var ident string if dir == reassembly.TCPDirClientToServer { - ident = fmt.Sprintf("%v %v(%s): ", t.net, t.transport, dir) + ident = fmt.Sprintf("%v %v", t.net, t.transport) } else { - ident = fmt.Sprintf("%v %v(%s): ", t.net.Reverse(), t.transport.Reverse(), dir) + ident = fmt.Sprintf("%v %v", t.net.Reverse(), t.transport.Reverse()) } - Debug("%s: SG reassembled packet with %d bytes (start:%v,end:%v,skip:%d,saved:%d,nb:%d,%d,overlap:%d,%d)\n", ident, length, start, end, skip, saved, sgStats.Packets, sgStats.Chunks, sgStats.OverlapBytes, sgStats.OverlapPackets) + log.Debug(). + Str("ident", ident). // ex: "192.168.65.4->192.168.65.4 6443->38304" + Str("direction", dir.String()). // ex: "client->server" or "server->client" + Int("byte_count", length). + Bool("start", start). + Bool("end", end). + Int("skip", skip). + Int("saved", saved). + Int("packet_count", sgStats.Packets). + Int("chunk_count", sgStats.Chunks). + Int("overlap_byte_count", sgStats.OverlapBytes). + Int("overlap_packet_count", sgStats.OverlapPackets). + Msg("SG reassembled packet") if skip == -1 && *allowmissinginit { // this is allowed } else if skip != 0 { @@ -119,7 +141,9 @@ func (t *tcpStream) ReassembledSG(sg reassembly.ScatterGather, ac reassembly.Ass } func (t *tcpStream) ReassemblyComplete(ac reassembly.AssemblerContext) bool { - Debug("%s: Connection closed\n", t.ident) + log.Debug(). + Str("tcp_stream_ident", t.ident). + Msg("Connection closed") close(t.client.bytes) close(t.server.bytes) // do not remove the connection to allow last ACK diff --git a/assemblers/tcp_stream_factory.go b/assemblers/tcp_stream_factory.go index 05ba7e02..47142984 100644 --- a/assemblers/tcp_stream_factory.go +++ b/assemblers/tcp_stream_factory.go @@ -8,6 +8,7 @@ import ( "github.com/google/gopacket" "github.com/google/gopacket/layers" "github.com/google/gopacket/reassembly" + "github.com/rs/zerolog/log" ) var streamId uint64 = 0 @@ -24,7 +25,10 @@ func NewTcpStreamFactory(httpEvents chan HttpEvent) tcpStreamFactory { } func (factory *tcpStreamFactory) New(net, transport gopacket.Flow, tcp *layers.TCP, ac reassembly.AssemblerContext) reassembly.Stream { - Debug("* NEW: %s %s\n", net, transport) + log.Debug(). + Str("net", net.String()). + Str("transport", transport.String()). + Msg("NEW tcp stream") fsmOptions := reassembly.TCPSimpleFSMOptions{ SupportMissingEstablishment: true, } diff --git a/bpf/probes/manager.go b/bpf/probes/manager.go index d7b6db39..8136ced1 100644 --- a/bpf/probes/manager.go +++ b/bpf/probes/manager.go @@ -5,7 +5,6 @@ import ( "context" "encoding/binary" "errors" - "log" "net" "os" @@ -13,6 +12,7 @@ import ( "github.com/cilium/ebpf/perf" "github.com/honeycombio/ebpf-agent/utils" "github.com/honeycombio/libhoney-go" + "github.com/rs/zerolog/log" semconv "go.opentelemetry.io/otel/semconv/v1.20.0" v1 "k8s.io/api/core/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -35,28 +35,28 @@ func New(client *kubernetes.Clientset) manager { // Load pre-compiled programs and maps into the kernel. objs := bpfObjects{} if err := loadBpfObjects(&objs, nil); err != nil { - log.Fatalf("loading objects: %v", err) + log.Fatal().Err(err).Msg("failed loading objects") } defer objs.Close() // Deploy tcp_connect kprobe kprobeTcpConnect, err := link.Kprobe("tcp_connect", objs.KprobeTcpConnect, nil) if err != nil { - log.Fatalf("opening kprobe: %s", err) + log.Fatal().Err(err).Msg("failed opening kprobe") } defer kprobeTcpConnect.Close() // Deploy tcp_close kprobe kprobeTcpClose, err := link.Kprobe("tcp_close", objs.KprobeTcpClose, nil) if err != nil { - log.Fatal("failed to open kretprobe: %s", err) + log.Fatal().Err(err).Msg("failed to open kretprobe") } defer kprobeTcpClose.Close() // Setup perf event reader to read probe events reader, err := perf.NewReader(objs.Events, os.Getpagesize()) if err != nil { - log.Fatalf("failed creating perf reader: %v", err) + log.Fatal().Err(err).Msg("failed creating perf reader") } return manager{ @@ -84,12 +84,10 @@ func (m *manager) Start() { } if err := binary.Read(bytes.NewBuffer(record.RawSample), binary.LittleEndian, &event); err != nil { - log.Println("error parsing perf event", err) + log.Error().Err(err).Msg("error parsing perf event") continue } - // log.Printf("event: %+v\n", event) - sendEvent(event, m.client) } } @@ -126,7 +124,7 @@ func getServiceForPod(client *kubernetes.Clientset, inputPod v1.Pod) v1.Service listOptions := metav1.ListOptions{LabelSelector: set.AsSelector().String()} pods, err := client.CoreV1().Pods(v1.NamespaceAll).List(context.TODO(), listOptions) if err != nil { - log.Println(err) + log.Error().Err(err).Msg("Error getting pods") } for _, pod := range pods.Items { if pod.Name == inputPod.Name { @@ -164,7 +162,9 @@ func sendEvent(event bpfTcpEvent, client *kubernetes.Clientset) { err := ev.Send() if err != nil { - log.Printf("error sending event: %v\n", err) + log.Debug(). + Err(err). + Msg("error sending event") } } diff --git a/go.mod b/go.mod index 140da3d8..456bd9f3 100644 --- a/go.mod +++ b/go.mod @@ -6,6 +6,7 @@ require ( github.com/cilium/ebpf v0.11.0 github.com/google/gopacket v1.1.19 github.com/honeycombio/libhoney-go v1.20.0 + github.com/rs/zerolog v1.30.0 go.opentelemetry.io/otel v1.16.0 k8s.io/api v0.27.4 k8s.io/apimachinery v0.27.4 @@ -32,6 +33,8 @@ require ( github.com/json-iterator/go v1.1.12 // indirect github.com/klauspost/compress v1.16.6 // indirect github.com/mailru/easyjson v0.7.7 // indirect + github.com/mattn/go-colorable v0.1.13 // indirect + github.com/mattn/go-isatty v0.0.19 // indirect github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect github.com/modern-go/reflect2 v1.0.2 // indirect github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 // indirect diff --git a/go.sum b/go.sum index 15f4f9b0..929e6033 100644 --- a/go.sum +++ b/go.sum @@ -43,6 +43,7 @@ github.com/cilium/ebpf v0.11.0 h1:V8gS/bTCCjX9uUnkUFUpPsksM8n1lXBAvHcpiFk1X2Y= github.com/cilium/ebpf v0.11.0/go.mod h1:WE7CZAnqOL2RouJ4f1uyNhqr2P4CCvXFIqdRDUgWsVs= github.com/client9/misspell v0.3.4/go.mod h1:qj6jICC3Q7zFZvVWo7KLAzC3yx5G7kyvSDkc90ppPyw= github.com/cncf/udpa/go v0.0.0-20191209042840-269d4d468f6f/go.mod h1:M8M6+tZqaGXZJjfX53e64911xZQV5JYwmTeXPW+k8Sc= +github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= @@ -80,6 +81,7 @@ github.com/go-openapi/jsonreference v0.20.1/go.mod h1:Bl1zwGIM8/wsvqjsOQLJ/SH+En github.com/go-openapi/swag v0.22.3 h1:yMBqmnQ0gyZvEb/+KzuWZOXgllrXT4SADYbvDaXHv/g= github.com/go-openapi/swag v0.22.3/go.mod h1:UzaqsxGiab7freDnrUUra0MwWfN/q7tE4j+VcZ0yl14= github.com/go-task/slim-sprig v0.0.0-20210107165309-348f09dbbbc0 h1:p104kn46Q8WdvHunIJ9dAyjPVtrBPhSr3KT2yUst43I= +github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= github.com/gogo/protobuf v1.3.2 h1:Ov1cvc58UF3b5XjBnZv7+opcTcQFZebYjWzi34vdm4Q= github.com/gogo/protobuf v1.3.2/go.mod h1:P1XiOD3dCwIKUDQYPy72D8LYyHL2YPYrpS2s69NZV8Q= github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b/go.mod h1:SBH7ygxi8pfUlaOkMMuAQtPIUF8ecWP5IEl/CR7VP2Q= @@ -169,6 +171,13 @@ github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= github.com/mailru/easyjson v0.7.7 h1:UGYAvKxe3sBsEDzO8ZeWOSlIQfWFlxbzLZe7hwFURr0= github.com/mailru/easyjson v0.7.7/go.mod h1:xzfreul335JAWq5oZzymOObrkdz5UnU4kGfJJLY9Nlc= +github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4= +github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA= +github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg= +github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94= +github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM= +github.com/mattn/go-isatty v0.0.19 h1:JITubQf0MOLdlGRuRq+jtsDlekdYPia9ZFsB8h/APPA= +github.com/mattn/go-isatty v0.0.19/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= github.com/modern-go/concurrent v0.0.0-20180228061459-e0a39a4cb421/go.mod h1:6dJC0mAP4ikYIbvyc7fijjWJddQyLn8Ig3JB5CqoB9Q= github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd h1:TRLaZ9cD/w8PVh93nsPXa1VrQ6jlwL5oN8l14QlcNfg= github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd/go.mod h1:6dJC0mAP4ikYIbvyc7fijjWJddQyLn8Ig3JB5CqoB9Q= @@ -178,11 +187,15 @@ github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 h1:C3w9PqII01/Oq github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822/go.mod h1:+n7T8mK8HuQTcFwEeznm/DIxMOiR9yIdICNftLE1DvQ= github.com/onsi/ginkgo/v2 v2.9.1 h1:zie5Ly042PD3bsCvsSOPvRnFwyo3rKe64TJlD6nu0mk= github.com/onsi/gomega v1.27.4 h1:Z2AnStgsdSayCMDiCU42qIz+HLqEPcgiOCXjAU/w+8E= +github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/prometheus/client_model v0.0.0-20190812154241-14fe0d1b01d4/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFRclV5y23lUDJ4= github.com/rogpeppe/go-internal v1.11.0 h1:cWPaGQEPrBb5/AsnsZesgZZ9yb1OQ+GOISoDNXVBh4M= +github.com/rs/xid v1.5.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= +github.com/rs/zerolog v1.30.0 h1:SymVODrcRsaRaSInD9yQtKbtWqwsfoPcRff/oRXLj4c= +github.com/rs/zerolog v1.30.0/go.mod h1:/tk+P47gFdPXq4QYjvCmT5/Gsug2nagsFWBWhAiSi1w= github.com/spf13/pflag v1.0.5 h1:iy+VFUOCP1a+8yFto/drg2CJ5u0yRoB7fZw3DKv/JXA= github.com/stoewer/go-strcase v1.2.0/go.mod h1:IBiWB2sKIp3wVVQ3Y035++gc+knqhUQag1KpM8ahLw8= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= @@ -322,7 +335,11 @@ golang.org/x/sys v0.0.0-20200523222454-059865788121/go.mod h1:h1NjWce9XRLGQEsW7w golang.org/x/sys v0.0.0-20200803210538-64077c9b5642/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20211216021012-1d35b9e2eb4e/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.11.0 h1:eG7RXZHdqOJ1i+0lgLgCpSXAp6M3LYlAo6osgSi0xOM= golang.org/x/sys v0.11.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/term v0.0.0-20210927222741-03fcf44c2211/go.mod h1:jbD1KX2456YbFQfuXm/mYQcufACuNUgVhRMnK/tPxf8= diff --git a/main.go b/main.go index 897c59e2..13eb4502 100644 --- a/main.go +++ b/main.go @@ -3,7 +3,6 @@ package main import ( "fmt" "io" - "log" "os" "os/signal" "syscall" @@ -12,6 +11,8 @@ import ( "github.com/honeycombio/ebpf-agent/bpf/probes" "github.com/honeycombio/ebpf-agent/utils" "github.com/honeycombio/libhoney-go" + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" semconv "go.opentelemetry.io/otel/semconv/v1.20.0" "k8s.io/client-go/kubernetes" "k8s.io/client-go/rest" @@ -22,27 +23,35 @@ const defaultDataset = "hny-ebpf-agent" const defaultEndpoint = "https://api.honeycomb.io" func main() { - log.Printf("Starting Honeycomb eBPF agent v%s\n", Version) + // Set logging level + zerolog.SetGlobalLevel(zerolog.InfoLevel) + if os.Getenv("DEBUG") == "true" { + zerolog.SetGlobalLevel(zerolog.DebugLevel) + } + + log.Info().Str("agent_version", Version).Msg("Starting Honeycomb eBPF agent") kernelVersion, err := utils.HostKernelVersion() if err != nil { - log.Fatalf("Failed to get host kernel version: %v", err) + log.Fatal().Err(err).Msg("Failed to get host kernel version") } - log.Printf("Host kernel version: %s\n", kernelVersion) - btfEnabled := utils.HostBtfEnabled() - log.Printf("BTF enabled: %v\n", btfEnabled) + log.Info(). + Str("kernel_version", kernelVersion.String()). + Bool("btf_enabled", btfEnabled). + Msg("Detected host kernel") apikey := os.Getenv("HONEYCOMB_API_KEY") if apikey == "" { - log.Fatalf("Honeycomb API key not set, unable to send events\n") + log.Fatal().Msg("Honeycomb API key not set, unable to send events\n") } dataset := getEnvOrDefault("HONEYCOMB_DATASET", defaultDataset) - log.Printf("Honeycomb dataset: %s\n", dataset) - endpoint := getEnvOrDefault("HONEYCOMB_API_ENDPOINT", defaultEndpoint) - log.Printf("Honeycomb API endpoint: %s\n", endpoint) + log.Info(). + Str("hny_endpoint", endpoint). + Str("hny_dataset", dataset). + Msg("Honeycomb API config") // setup libhoney libhoney.Init(libhoney.Config{ @@ -88,13 +97,13 @@ func main() { go assember.Start() defer assember.Stop() - log.Println("Agent is ready!") + log.Info().Msg("Agent is ready!") signalChannel := make(chan os.Signal, 1) signal.Notify(signalChannel, os.Interrupt, syscall.SIGTERM) <-signalChannel - log.Println("Shutting down...") + log.Info().Msg("Shutting down...") } func handleHttpEvents(events chan assemblers.HttpEvent, client *kubernetes.Clientset) { @@ -144,7 +153,9 @@ func handleHttpEvents(events chan assemblers.HttpEvent, client *kubernetes.Clien err := ev.Send() if err != nil { - log.Printf("error sending event: %v\n", err) + log.Debug(). + Err(err). + Msg("error sending event") } } }