chore: refactor logging (#182)

cmd/spoof-dpi/main.go

@@ -1,12 +1,12 @@
 package main
 
 import (
+	"context"
+	"github.com/xvzc/SpoofDPI/util/log"
 	"os"
 	"os/signal"
 	"syscall"
 
-	"github.com/sirupsen/logrus"
-	log "github.com/sirupsen/logrus"
 	"github.com/xvzc/SpoofDPI/proxy"
 	"github.com/xvzc/SpoofDPI/util"
 	"github.com/xvzc/SpoofDPI/version"
@@ -22,16 +22,11 @@ func main() {
 	config := util.GetConfig()
 	config.Load(args)
 
-	pxy := proxy.New(config)
+	log.InitLogger(config)
-	if *config.Debug {
+	ctx := util.GetCtxWithScope(context.Background(), "MAIN")
-		log.SetLevel(log.DebugLevel)
+	logger := log.GetCtxLogger(ctx)
-	} else {
-		log.SetLevel(log.InfoLevel)
-	}
 
-	log.SetFormatter(&logrus.TextFormatter{
+	pxy := proxy.New(config)
-		FullTimestamp: true,
-	})
 
 	if *config.NoBanner {
 		util.PrintSimpleInfo()
@@ -41,11 +36,11 @@ func main() {
 
 	if *config.SystemProxy {
 		if err := util.SetOsProxy(*config.Port); err != nil {
-			log.Fatalf("error while changing proxy settings: %s", err)
+			logger.Fatal().Msgf("error while changing proxy settings: %s", err)
 		}
 	}
 
-	go pxy.Start()
+	go pxy.Start(context.Background())
 
 	// Handle signals
 	sigs := make(chan os.Signal, 1)
@@ -68,7 +63,7 @@ func main() {
 
 	if *config.SystemProxy {
 		if err := util.UnsetOsProxy(); err != nil {
-			log.Fatal(err)
+			logger.Fatal().Msgf("%s", err)
 		}
 	}
 }

dns/dns.go

@@ -8,11 +8,13 @@ import (
 	"time"
 
 	"github.com/miekg/dns"
-	log "github.com/sirupsen/logrus"
 	"github.com/xvzc/SpoofDPI/dns/resolver"
 	"github.com/xvzc/SpoofDPI/util"
+	"github.com/xvzc/SpoofDPI/util/log"
 )
 
+const scopeDNS = "DNS"
+
 type Resolver interface {
 	Resolve(ctx context.Context, host string, qTypes []uint16) ([]net.IPAddr, error)
 	String() string
@@ -39,16 +41,20 @@ func NewDns(config *util.Config) *Dns {
 	}
 }
 
-func (d *Dns) ResolveHost(host string, enableDoh bool, useSystemDns bool) (string, error) {
+func (d *Dns) ResolveHost(ctx context.Context, host string, enableDoh bool, useSystemDns bool) (string, error) {
+	ctx = util.GetCtxWithScope(ctx, scopeDNS)
+	logger := log.GetCtxLogger(ctx)
+
 	if ip, err := parseIpAddr(host); err == nil {
 		return ip.String(), nil
 	}
 
 	clt := d.clientFactory(enableDoh, useSystemDns)
-	ctx, cancel := context.WithTimeout(context.Background(), 3*time.Second)
+	ctx, cancel := context.WithTimeout(ctx, 3*time.Second)
 	defer cancel()
 
-	log.Debugf("[DNS] resolving %s using %s", host, clt)
+	logger.Debug().Msgf("resolving %s using %s", host, clt)
+
 	t := time.Now()
 
 	addrs, err := clt.Resolve(ctx, host, []uint16{dns.TypeAAAA, dns.TypeA})
@@ -59,7 +65,7 @@ func (d *Dns) ResolveHost(host string, enableDoh bool, useSystemDns bool) (strin
 
 	if len(addrs) > 0 {
 		d := time.Since(t).Milliseconds()
-		log.Debugf("[DNS] resolved %s from %s in %d ms", addrs[0].String(), host, d)
+		logger.Debug().Msgf("resolved %s from %s in %d ms", addrs[0].String(), host, d)
 		return addrs[0].String(), nil
 	}
 

go.mod

@@ -7,7 +7,7 @@ toolchain go1.21.5
 require (
 	github.com/miekg/dns v1.1.61
 	github.com/pterm/pterm v0.12.79
-	github.com/sirupsen/logrus v1.9.3
+	github.com/rs/zerolog v1.33.0
 )
 
 require (
@@ -17,6 +17,8 @@ require (
 	github.com/containerd/console v1.0.3 // indirect
 	github.com/gookit/color v1.5.4 // indirect
 	github.com/lithammer/fuzzysearch v1.1.8 // indirect
+	github.com/mattn/go-colorable v0.1.13 // indirect
+	github.com/mattn/go-isatty v0.0.19 // indirect
 	github.com/mattn/go-runewidth v0.0.15 // indirect
 	github.com/rivo/uniseg v0.4.4 // indirect
 	github.com/xo/terminfo v0.0.0-20220910002029-abceb7e1c41e // indirect

go.sum

@@ -18,9 +18,11 @@ github.com/MarvinJWendt/testza v0.5.2/go.mod h1:xu53QFE5sCdjtMCKk8YMQ2MnymimEctc
 github.com/atomicgo/cursor v0.0.1/go.mod h1:cBON2QmmrysudxNBFthvMtN32r3jxVRIvzkUiF/RuIk=
 github.com/containerd/console v1.0.3 h1:lIr7SlA5PxZyMV30bDW0MGbiOPXwc63yRuCP0ARubLw=
 github.com/containerd/console v1.0.3/go.mod h1:7LqA/THxQ86k76b8c/EMSiaJ3h1eZkMkXar0TQ1gf3U=
+github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
 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=
 github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
 github.com/gookit/color v1.4.2/go.mod h1:fqRyamkC1W8uxl+lxCQxOT09l/vYfZ+QeiX3rKQHCoQ=
 github.com/gookit/color v1.5.0/go.mod h1:43aQb+Zerm/BWh2GnrgOQm7ffz7tvQXEKV6BFMl7wAo=
 github.com/gookit/color v1.5.4 h1:FZmqs7XOyGgCAxmWyPslpiok1k05wmY3SJTytgvYFs0=
@@ -35,11 +37,17 @@ github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ=
 github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI=
 github.com/lithammer/fuzzysearch v1.1.8 h1:/HIuJnjHuXS8bKaiTMeeDlW2/AyIWk2brx1V8LFgLN4=
 github.com/lithammer/fuzzysearch v1.1.8/go.mod h1:IdqeyBClc3FFqSzYq/MXESsS4S0FsZ5ajtkr5xPLts4=
+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.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/mattn/go-runewidth v0.0.13/go.mod h1:Jdepj2loyihRzMpdS35Xk/zdY8IAYHsh153qUoGf23w=
 github.com/mattn/go-runewidth v0.0.15 h1:UNAjwbU9l54TA3KzvqLGxwWjHmMgBUVhBiTjelZgg3U=
 github.com/mattn/go-runewidth v0.0.15/go.mod h1:Jdepj2loyihRzMpdS35Xk/zdY8IAYHsh153qUoGf23w=
 github.com/miekg/dns v1.1.61 h1:nLxbwF3XxhwVSm8g9Dghm9MHPaUZuqhPiGL+675ZmEs=
 github.com/miekg/dns v1.1.61/go.mod h1:mnAarhS3nWaW+NVP2wTkYVIZyHNJ098SJZUki3eykwQ=
+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/pterm/pterm v0.12.27/go.mod h1:PhQ89w4i95rhgE+xedAoqous6K9X+r6aSOI2eFF7DZI=
@@ -54,10 +62,11 @@ github.com/pterm/pterm v0.12.79/go.mod h1:1v/gzOF1N0FsjbgTHZ1wVycRkKiatFvJSJC4IG
 github.com/rivo/uniseg v0.2.0/go.mod h1:J6wj4VEh+S6ZtnVlnTBMWIodfgj8LQOQFoIToxlJtxc=
 github.com/rivo/uniseg v0.4.4 h1:8TfxU8dW6PdqD27gjM8MVNuicgxIjxpm4K7x4jp8sis=
 github.com/rivo/uniseg v0.4.4/go.mod h1:FN3SvrM+Zdj16jyLfmOkMNblXMcoc8DfTHruCPUcx88=
+github.com/rs/xid v1.5.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
+github.com/rs/zerolog v1.33.0 h1:1cU2KZkvPxNyfgEmhHAz/1A9Bz+llsdYzklWFzgp0r8=
+github.com/rs/zerolog v1.33.0/go.mod h1:/7mN4D5sKwJLZQ2b/znpjC3/GQWY/xaDXUM0kKWRHss=
 github.com/sergi/go-diff v1.2.0 h1:XU+rvMAioB0UC3q1MFrIQy4Vo5/4VsRDQQXHsEya6xQ=
 github.com/sergi/go-diff v1.2.0/go.mod h1:STckp+ISIX8hZLjrqAeVduY0gWCT9IjLuqbuNXdaHfM=
-github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ=
-github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ=
 github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
 github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4=
 github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
@@ -95,9 +104,11 @@ golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBc
 golang.org/x/sys v0.0.0-20211013075003-97ac67df715c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20220319134239-a9b59b0215f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20220520151302-bc2c85ada10a/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
-golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20220722155257-8c9f86f7a55f/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.5.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/sys v0.12.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.22.0 h1:RI27ohtqKCnwULzJLqkv897zojh5/DwS/ENaMzUOaWI=
 golang.org/x/sys v0.22.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
 golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo=

proxy/http.go

@@ -1,15 +1,22 @@
 package proxy
 
 import (
+	"context"
+	"github.com/xvzc/SpoofDPI/util"
 	"net"
 	"strconv"
 
-	log "github.com/sirupsen/logrus"
+	"github.com/xvzc/SpoofDPI/util/log"
 
 	"github.com/xvzc/SpoofDPI/packet"
 )
 
-func (pxy *Proxy) handleHttp(lConn *net.TCPConn, pkt *packet.HttpRequest, ip string) {
+const protoHTTP = "HTTP"
+
+func (pxy *Proxy) handleHttp(ctx context.Context, lConn *net.TCPConn, pkt *packet.HttpRequest, ip string) {
+	ctx = util.GetCtxWithScope(ctx, protoHTTP)
+	logger := log.GetCtxLogger(ctx)
+
 	pkt.Tidy()
 
 	// Create a connection to the requested server
@@ -18,28 +25,28 @@ func (pxy *Proxy) handleHttp(lConn *net.TCPConn, pkt *packet.HttpRequest, ip str
 	if pkt.Port() != "" {
 		port, err = strconv.Atoi(pkt.Port())
 		if err != nil {
-			log.Debugf("[HTTP] error while parsing port for %s aborting..", pkt.Domain())
+			logger.Debug().Msgf("error while parsing port for %s aborting..", pkt.Domain())
 		}
 	}
 
 	rConn, err := net.DialTCP("tcp", nil, &net.TCPAddr{IP: net.ParseIP(ip), Port: port})
 	if err != nil {
 		lConn.Close()
-		log.Debug("[HTTP] ", err)
+		logger.Debug().Msgf("%s", err)
 		return
 	}
 
-	log.Debugf("[HTTP] new connection to the server %s -> %s", rConn.LocalAddr(), pkt.Domain())
+	logger.Debug().Msgf("new connection to the server %s -> %s", rConn.LocalAddr(), pkt.Domain())
 
-	go Serve(rConn, lConn, "[HTTP]", pkt.Domain(), lConn.RemoteAddr().String(), pxy.timeout)
+	go Serve(ctx, rConn, lConn, protoHTTP, pkt.Domain(), lConn.RemoteAddr().String(), pxy.timeout)
 
 	_, err = rConn.Write(pkt.Raw())
 	if err != nil {
-		log.Debugf("[HTTP] error sending request to %s: %s", pkt.Domain(), err)
+		logger.Debug().Msgf("error sending request to %s: %s", pkt.Domain(), err)
 		return
 	}
 
-	log.Debugf("[HTTP] sent a request to %s", pkt.Domain())
+	logger.Debug().Msgf("sent a request to %s", pkt.Domain())
 
-	go Serve(lConn, rConn, "[HTTP]", lConn.RemoteAddr().String(), pkt.Domain(), pxy.timeout)
+	go Serve(ctx, lConn, rConn, protoHTTP, lConn.RemoteAddr().String(), pkt.Domain(), pxy.timeout)
 }

proxy/https.go

@@ -1,77 +1,86 @@
 package proxy
 
 import (
+	"context"
+	"github.com/xvzc/SpoofDPI/util"
 	"net"
 	"strconv"
 
-	log "github.com/sirupsen/logrus"
 	"github.com/xvzc/SpoofDPI/packet"
+	"github.com/xvzc/SpoofDPI/util/log"
 )
 
-func (pxy *Proxy) handleHttps(lConn *net.TCPConn, exploit bool, initPkt *packet.HttpRequest, ip string) {
+const protoHTTPS = "HTTPS"
+
+func (pxy *Proxy) handleHttps(ctx context.Context, lConn *net.TCPConn, exploit bool, initPkt *packet.HttpRequest, ip string) {
+	ctx = util.GetCtxWithScope(ctx, protoHTTPS)
+	logger := log.GetCtxLogger(ctx)
+
 	// Create a connection to the requested server
 	var port int = 443
 	var err error
 	if initPkt.Port() != "" {
 		port, err = strconv.Atoi(initPkt.Port())
 		if err != nil {
-			log.Debugf("[HTTPS] error parsing port for %s aborting..", initPkt.Domain())
+			logger.Debug().Msgf("error parsing port for %s aborting..", initPkt.Domain())
 		}
 	}
 
 	rConn, err := net.DialTCP("tcp", nil, &net.TCPAddr{IP: net.ParseIP(ip), Port: port})
 	if err != nil {
 		lConn.Close()
-		log.Debug("[HTTPS] ", err)
+		logger.Debug().Msgf("%s", err)
 		return
 	}
 
-	log.Debugf("[HTTPS] new connection to the server %s -> %s", rConn.LocalAddr(), initPkt.Domain())
+	logger.Debug().Msgf("new connection to the server %s -> %s", rConn.LocalAddr(), initPkt.Domain())
 
 	_, err = lConn.Write([]byte(initPkt.Version() + " 200 Connection Established\r\n\r\n"))
 	if err != nil {
-		log.Debugf("[HTTPS] error sending 200 connection established to the client: %s", err)
+		logger.Debug().Msgf("error sending 200 connection established to the client: %s", err)
 		return
 	}
 
-	log.Debugf("[HTTPS] sent connection estabalished to %s", lConn.RemoteAddr())
+	logger.Debug().Msgf("sent connection estabalished to %s", lConn.RemoteAddr())
 
 	// Read client hello
 	m, err := packet.ReadTLSMessage(lConn)
 	if err != nil || !m.IsClientHello() {
-		log.Debugf("[HTTPS] error reading client hello from %s: %s", lConn.RemoteAddr().String(), err)
+		logger.Debug().Msgf("error reading client hello from %s: %s", lConn.RemoteAddr().String(), err)
 		return
 	}
 	clientHello := m.Raw
 
-	log.Debugf("[HTTPS] client sent hello %d bytes", len(clientHello))
+	logger.Debug().Msgf("client sent hello %d bytes", len(clientHello))
 
 	// Generate a go routine that reads from the server
-	go Serve(rConn, lConn, "[HTTPS]", initPkt.Domain(), lConn.RemoteAddr().String(), pxy.timeout)
+	go Serve(ctx, rConn, lConn, protoHTTPS, initPkt.Domain(), lConn.RemoteAddr().String(), pxy.timeout)
 
 	if exploit {
-		log.Debugf("[HTTPS] writing chunked client hello to %s", initPkt.Domain())
+		logger.Debug().Msgf("writing chunked client hello to %s", initPkt.Domain())
-		chunks := splitInChunks(clientHello, pxy.windowSize)
+		chunks := splitInChunks(ctx, clientHello, pxy.windowSize)
 		if _, err := writeChunks(rConn, chunks); err != nil {
-			log.Debugf("[HTTPS] error writing chunked client hello to %s: %s", initPkt.Domain(), err)
+			logger.Debug().Msgf("error writing chunked client hello to %s: %s", initPkt.Domain(), err)
 			return
 		}
 	} else {
-		log.Debugf("[HTTPS] writing plain client hello to %s", initPkt.Domain())
+		logger.Debug().Msgf("writing plain client hello to %s", initPkt.Domain())
 		if _, err := rConn.Write(clientHello); err != nil {
-			log.Debugf("[HTTPS] error writing plain client hello to %s: %s", initPkt.Domain(), err)
+			logger.Debug().Msgf("error writing plain client hello to %s: %s", initPkt.Domain(), err)
 			return
 		}
 	}
 
-	go Serve(lConn, rConn, "[HTTPS]", lConn.RemoteAddr().String(), initPkt.Domain(), pxy.timeout)
+	go Serve(ctx, lConn, rConn, protoHTTPS, lConn.RemoteAddr().String(), initPkt.Domain(), pxy.timeout)
 }
 
-func splitInChunks(bytes []byte, size int) [][]byte {
+func splitInChunks(ctx context.Context, bytes []byte, size int) [][]byte {
+	logger := log.GetCtxLogger(ctx)
+
 	var chunks [][]byte
 	var raw []byte = bytes
 
-	log.Debugf("[HTTPS] window-size: %d", size)
+	logger.Debug().Msgf("window-size: %d", size)
 
 	if size > 0 {
 		for {
@@ -98,7 +107,7 @@ func splitInChunks(bytes []byte, size int) [][]byte {
 		return [][]byte{raw}
 	}
 
-	log.Debug("[HTTPS] using legacy fragmentation")
+	logger.Debug().Msg("using legacy fragmentation")
 
 	return [][]byte{raw[:1], raw[1:]}
 }

proxy/proxy.go

@@ -1,18 +1,20 @@
 package proxy
 
 import (
-	"fmt"
+	"context"
 	"net"
 	"os"
 	"regexp"
 	"strconv"
 
-	log "github.com/sirupsen/logrus"
 	"github.com/xvzc/SpoofDPI/dns"
 	"github.com/xvzc/SpoofDPI/packet"
 	"github.com/xvzc/SpoofDPI/util"
+	"github.com/xvzc/SpoofDPI/util/log"
 )
 
+const scopeProxy = "PROXY"
+
 type Proxy struct {
 	addr           string
 	port           int
@@ -35,41 +37,46 @@ func New(config *util.Config) *Proxy {
 	}
 }
 
-func (pxy *Proxy) Start() {
+func (pxy *Proxy) Start(ctx context.Context) {
+	ctx = util.GetCtxWithScope(ctx, scopeProxy)
+	logger := log.GetCtxLogger(ctx)
+
 	l, err := net.ListenTCP("tcp", &net.TCPAddr{IP: net.ParseIP(pxy.addr), Port: pxy.port})
 	if err != nil {
-		log.Fatal("[PROXY] error creating listener: ", err)
+		logger.Fatal().Msgf("error creating listener: %s", err)
 		os.Exit(1)
 	}
 
 	if pxy.timeout > 0 {
-		log.Println(fmt.Sprintf("[PROXY] connection timeout is set to %dms", pxy.timeout))
+		logger.Debug().Msgf("connection timeout is set to %d ms", pxy.timeout)
 	}
 
-	log.Println("[PROXY] created a listener on port", pxy.port)
+	logger.Info().Msgf("created a listener on port %d", pxy.port)
 	if len(pxy.allowedPattern) > 0 {
-		log.Println("[PROXY] number of white-listed pattern:", len(pxy.allowedPattern))
+		logger.Debug().Msgf("number of white-listed pattern: %d", len(pxy.allowedPattern))
 	}
 
 	for {
 		conn, err := l.Accept()
 		if err != nil {
-			log.Fatal("[PROXY] error accepting connection: ", err)
+			logger.Fatal().Msgf("error accepting connection: %s", err)
 			continue
 		}
 
 		go func() {
+			ctx := util.GetCtxWithTraceId(ctx)
+
 			pkt, err := packet.ReadHttpRequest(conn)
 			if err != nil {
-				log.Debug("[PROXY] error while parsing request: ", err)
+				logger.Debug().Msgf("error while parsing request: %s", err)
 				conn.Close()
 				return
 			}
 
-			log.Debug("[PROXY] request from ", conn.RemoteAddr(), "\n\n", string(pkt.Raw()))
+			logger.Debug().Msgf("request from %s\n\n%s", conn.RemoteAddr(), pkt.Raw())
 
 			if !pkt.IsValidMethod() {
-				log.Debug("[PROXY] unsupported method: ", pkt.Method())
+				logger.Debug().Msgf("unsupported method: %s", pkt.Method())
 				conn.Close()
 				return
 			}
@@ -77,25 +84,25 @@ func (pxy *Proxy) Start() {
 			matched := pxy.patternMatches([]byte(pkt.Domain()))
 			useSystemDns := !matched
 
-			ip, err := pxy.resolver.ResolveHost(pkt.Domain(), pxy.enableDoh, useSystemDns)
+			ip, err := pxy.resolver.ResolveHost(ctx, pkt.Domain(), pxy.enableDoh, useSystemDns)
 			if err != nil {
-				log.Debug("[PROXY] error while dns lookup: ", pkt.Domain(), " ", err)
+				logger.Debug().Msgf("error while dns lookup: %s %s", pkt.Domain(), err)
 				conn.Write([]byte(pkt.Version() + " 502 Bad Gateway\r\n\r\n"))
 				conn.Close()
 				return
 			}
 
 			// Avoid recursively querying self
-			if pkt.Port() == strconv.Itoa(pxy.port) && isLoopedRequest(net.ParseIP(ip)) {
+			if pkt.Port() == strconv.Itoa(pxy.port) && isLoopedRequest(ctx, net.ParseIP(ip)) {
-				log.Error("[PROXY] looped request has been detected. aborting.")
+				logger.Error().Msg("looped request has been detected. aborting.")
 				conn.Close()
 				return
 			}
 
 			if pkt.IsConnectMethod() {
-				pxy.handleHttps(conn.(*net.TCPConn), matched, pkt, ip)
+				pxy.handleHttps(ctx, conn.(*net.TCPConn), matched, pkt, ip)
 			} else {
-				pxy.handleHttp(conn.(*net.TCPConn), pkt, ip)
+				pxy.handleHttp(ctx, conn.(*net.TCPConn), pkt, ip)
 			}
 		}()
 	}
@@ -115,16 +122,18 @@ func (pxy *Proxy) patternMatches(bytes []byte) bool {
 	return false
 }
 
-func isLoopedRequest(ip net.IP) bool {
+func isLoopedRequest(ctx context.Context, ip net.IP) bool {
 	if ip.IsLoopback() {
 		return true
 	}
 
+	logger := log.GetCtxLogger(ctx)
+
 	// Get list of available addresses
 	// See `ip -4 addr show`
 	addr, err := net.InterfaceAddrs() // needs AF_NETLINK on linux
 	if err != nil {
-		log.Error("[PROXY] error while getting addresses of our network interfaces: ", err)
+		logger.Error().Msgf("error while getting addresses of our network interfaces: %s", err)
 		return false
 	}
 

proxy/server.go

@@ -1,12 +1,14 @@
 package proxy
 
 import (
+	"context"
 	"errors"
+	"github.com/xvzc/SpoofDPI/util"
 	"io"
 	"net"
 	"time"
 
-	log "github.com/sirupsen/logrus"
+	"github.com/xvzc/SpoofDPI/util/log"
 )
 
 const (
@@ -14,12 +16,12 @@ const (
 	TLSHeaderLen = 5
 )
 
-func ReadBytes(conn *net.TCPConn, dest []byte) ([]byte, error) {
+func ReadBytes(ctx context.Context, conn *net.TCPConn, dest []byte) ([]byte, error) {
-	n, err := readBytesInternal(conn, dest)
+	n, err := readBytesInternal(ctx, conn, dest)
 	return dest[:n], err
 }
 
-func readBytesInternal(conn *net.TCPConn, dest []byte) (int, error) {
+func readBytesInternal(ctx context.Context, conn *net.TCPConn, dest []byte) (int, error) {
 	totalRead, err := conn.Read(dest)
 	if err != nil {
 		var opError *net.OpError
@@ -33,12 +35,15 @@ func readBytesInternal(conn *net.TCPConn, dest []byte) (int, error) {
 	return totalRead, nil
 }
 
-func Serve(from *net.TCPConn, to *net.TCPConn, proto string, fd string, td string, timeout int) {
+func Serve(ctx context.Context, from *net.TCPConn, to *net.TCPConn, proto string, fd string, td string, timeout int) {
+	ctx = util.GetCtxWithScope(ctx, proto)
+	logger := log.GetCtxLogger(ctx)
+
 	defer func() {
 		from.Close()
 		to.Close()
 
-		log.Debugf("%s closing proxy connection: %s -> %s", proto, fd, td)
+		logger.Debug().Msgf("closing proxy connection: %s -> %s", fd, td)
 	}()
 
 	buf := make([]byte, BufferSize)
@@ -49,18 +54,18 @@ func Serve(from *net.TCPConn, to *net.TCPConn, proto string, fd string, td strin
 			)
 		}
 
-		bytesRead, err := ReadBytes(from, buf)
+		bytesRead, err := ReadBytes(ctx, from, buf)
 		if err != nil {
 			if err == io.EOF {
-				log.Debugf("%s finished reading from %s", proto, fd)
+				logger.Debug().Msgf("finished reading from %s", fd)
 				return
 			}
-			log.Debugf("%s error reading from %s: %s", proto, fd, err)
+			logger.Debug().Msgf("error reading from %s: %s", fd, err)
 			return
 		}
 
 		if _, err := to.Write(bytesRead); err != nil {
-			log.Debugf("%s error Writing to %s", proto, td)
+			logger.Debug().Msgf("error Writing to %s", td)
 			return
 		}
 	}

util/context.go

@@ -0,0 +1,55 @@
+package util
+
+import (
+	"context"
+	"math/rand"
+	"strings"
+)
+
+type scopeCtxKey struct{}
+
+func GetCtxWithScope(ctx context.Context, scope string) context.Context {
+	return context.WithValue(ctx, scopeCtxKey{}, scope)
+}
+
+func GetScopeFromCtx(ctx context.Context) (string, bool) {
+	if scope, ok := ctx.Value(scopeCtxKey{}).(string); ok {
+		return scope, true
+	}
+	return "", false
+}
+
+type traceIdCtxKey struct{}
+
+func GetCtxWithTraceId(ctx context.Context) context.Context {
+	return context.WithValue(ctx, traceIdCtxKey{}, generateTraceId())
+}
+
+func GetTraceIdFromCtx(ctx context.Context) (string, bool) {
+	if traceId, ok := ctx.Value(traceIdCtxKey{}).(string); ok {
+		return traceId, true
+	}
+	return "", false
+}
+
+func generateTraceId() string {
+	sb := strings.Builder{}
+	sb.Grow(22)
+
+	var q uint64
+	var r uint8
+	for i := 0; i < 32; i++ {
+		if i%15 == 0 {
+			q = rand.Uint64()
+		}
+		q, r = q>>4, uint8(q&0xF)
+		if r > 9 {
+			r += 0x27
+		}
+		sb.WriteByte(r + 0x30)
+		if i&3 == 3 && i != 31 {
+			sb.WriteByte(0x2D)
+		}
+	}
+	return sb.String()
+}

util/log/log.go

@@ -0,0 +1,70 @@
+package log
+
+import (
+	"context"
+	"fmt"
+	"github.com/rs/zerolog"
+	"github.com/xvzc/SpoofDPI/util"
+	"os"
+	"time"
+)
+
+const (
+	scopeFieldName   = "scope"
+	traceIdFieldName = "trace_id"
+)
+
+var logger zerolog.Logger
+
+func GetCtxLogger(ctx context.Context) zerolog.Logger {
+	return logger.With().Ctx(ctx).Logger()
+}
+
+func InitLogger(cfg *util.Config) {
+	partsOrder := []string{
+		zerolog.TimestampFieldName,
+		zerolog.LevelFieldName,
+		traceIdFieldName,
+		scopeFieldName,
+		zerolog.MessageFieldName,
+	}
+
+	consoleWriter := zerolog.ConsoleWriter{
+		Out:        os.Stdout,
+		TimeFormat: time.RFC3339,
+		PartsOrder: partsOrder,
+		FormatPrepare: func(m map[string]any) error {
+			formatFieldValue[string](m, "%s", traceIdFieldName)
+			formatFieldValue[string](m, "[%s]", scopeFieldName)
+			return nil
+		},
+		FieldsExclude: []string{traceIdFieldName, scopeFieldName},
+	}
+
+	logger = zerolog.New(consoleWriter).Hook(ctxHook{})
+	if *cfg.Debug {
+		logger = logger.Level(zerolog.DebugLevel)
+	} else {
+		logger = logger.Level(zerolog.InfoLevel)
+	}
+	logger = logger.With().Timestamp().Logger()
+}
+
+func formatFieldValue[T any](vs map[string]any, format string, field string) {
+	if v, ok := vs[field].(T); ok {
+		vs[field] = fmt.Sprintf(format, v)
+	} else {
+		vs[field] = ""
+	}
+}
+
+type ctxHook struct{}
+
+func (h ctxHook) Run(e *zerolog.Event, level zerolog.Level, msg string) {
+	if scope, ok := util.GetScopeFromCtx(e.GetCtx()); ok {
+		e.Str(scopeFieldName, scope)
+	}
+	if traceId, ok := util.GetTraceIdFromCtx(e.GetCtx()); ok {
+		e.Str(traceIdFieldName, traceId)
+	}
+}