Got rid of logrus

Updated dnscrypt and dnsstamps dependencies

go.mod

@@ -2,22 +2,22 @@ module github.com/AdguardTeam/dnsproxy
 
 require (
 	github.com/aead/chacha20 v0.0.0-20180709150244-8b13a72661da
-	github.com/ameshkov/dnscrypt v1.0.2
-	github.com/ameshkov/dnsstamps v1.0.0
+	github.com/ameshkov/dnscrypt v1.0.4
+	github.com/ameshkov/dnsstamps v1.0.1
 	github.com/beefsack/go-rate v0.0.0-20180408011153-efa7637bb9b6
 	github.com/go-test/deep v1.0.1
+	github.com/hashicorp/logutils v1.0.0
 	github.com/jessevdk/go-flags v1.4.0
 	github.com/jmcvetta/randutil v0.0.0-20150817122601-2bb1b664bcff
 	github.com/joomcode/errorx v0.1.0
 	github.com/miekg/dns v1.1.1
 	github.com/patrickmn/go-cache v2.1.0+incompatible
-	github.com/sirupsen/logrus v1.2.0
 	github.com/stretchr/testify v1.2.2
 	golang.org/x/crypto v0.0.0-20181203042331-505ab145d0a9
 	golang.org/x/exp v0.0.0-20181221233300-b68661188fbf
 	golang.org/x/image v0.0.0-20181116024801-cd38e8056d9b
 	golang.org/x/mobile v0.0.0-20181130133120-ca3c58166ed8
 	golang.org/x/net v0.0.0-20181220203305-927f97764cc3
 	golang.org/x/sync v0.0.0-20181221193216-37e7f081c4d4
-	golang.org/x/sys v0.0.0-20181221143128-b4a75ba826a6
+	golang.org/x/sys v0.0.0-20181228144115-9a3f9b0469bb
 )

go.sum

@@ -4,16 +4,20 @@ github.com/aead/poly1305 v0.0.0-20180717145839-3fee0db0b635 h1:52m0LGchQBBVqJRyY
 github.com/aead/poly1305 v0.0.0-20180717145839-3fee0db0b635/go.mod h1:lmLxL+FV291OopO93Bwf9fQLQeLyt33VJRUg5VJ30us=
 github.com/ameshkov/dnscrypt v1.0.2 h1:iMC/UApqOgDSxSEtw0W9eq99sAabnp0osXIBfiAfA40=
 github.com/ameshkov/dnscrypt v1.0.2/go.mod h1:fEeZ+/h8DTt4FxEv9sxN61ygy/8m/vFRqRJcNGJR+r0=
+github.com/ameshkov/dnscrypt v1.0.4 h1:vtwHm5m4R2dhcCx23wiI+gNBoy7qm4h7+kZ4Pucw/vE=
+github.com/ameshkov/dnscrypt v1.0.4/go.mod h1:hVW52S6r0QvUpIwsyfZ1ifYYpfGu5pewD3pl7afMJcQ=
 github.com/ameshkov/dnsstamps v1.0.0 h1:mZROsXx5tWIioNI4Z2cIdpagoCtQFa5ktB9CWuoh46M=
 github.com/ameshkov/dnsstamps v1.0.0/go.mod h1:Ii3eUu73dx4Vw5O4wjzmT5+lkCwovjzaEZZ4gKyIH5A=
+github.com/ameshkov/dnsstamps v1.0.1 h1:LhGvgWDzhNJh+kBQd/AfUlq1vfVe109huiXw4JhnPug=
+github.com/ameshkov/dnsstamps v1.0.1/go.mod h1:Ii3eUu73dx4Vw5O4wjzmT5+lkCwovjzaEZZ4gKyIH5A=
 github.com/beefsack/go-rate v0.0.0-20180408011153-efa7637bb9b6 h1:KXlsf+qt/X5ttPGEjR0tPH1xaWWoKBEg9Q1THAj2h3I=
 github.com/beefsack/go-rate v0.0.0-20180408011153-efa7637bb9b6/go.mod h1:6YNgTHLutezwnBvyneBbwvB8C82y3dcoOj5EQJIdGXA=
 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/go-test/deep v1.0.1 h1:UQhStjbkDClarlmv0am7OXXO4/GaPdCGiUiMTvi28sg=
 github.com/go-test/deep v1.0.1/go.mod h1:wGDj63lr65AM2AQyKZd/NYHGb0R+1RLqB8NKt3aSFNA=
-github.com/jedisct1/go-dnsstamps v0.0.0-20180418170050-1e4999280f86 h1:Olj4M6T1omUfx7yTTcnhLf4xo6gYMmRHSJIfeA1NZy0=
-github.com/jedisct1/go-dnsstamps v0.0.0-20180418170050-1e4999280f86/go.mod h1:j/ONpSHHmPgDwmFKXg9vhQvIjADe/ft1X4a3TVOmp9g=
+github.com/hashicorp/logutils v1.0.0 h1:dLEQVugN8vlakKOUE3ihGLTZJRB4j+M2cdTm/ORI65Y=
+github.com/hashicorp/logutils v1.0.0/go.mod h1:QIAnNjmIWmVIIkWDTG1z5v++HQmx9WQRO+LraFDTW64=
 github.com/jessevdk/go-flags v1.4.0 h1:4IU2WS7AumrZ/40jfhf4QVDMsQwqA7VEHozFRrGARJA=
 github.com/jessevdk/go-flags v1.4.0/go.mod h1:4FA24M0QyGHXBuZZK/XkWh8h0e1EYbRYJSGM75WSRxI=
 github.com/jmcvetta/randutil v0.0.0-20150817122601-2bb1b664bcff h1:6NvhExg4omUC9NfA+l4Oq3ibNNeJUdiAF3iBVB0PlDk=
@@ -28,8 +32,6 @@ github.com/patrickmn/go-cache v2.1.0+incompatible h1:HRMgzkcYKYpi3C8ajMPV8OFXaaR
 github.com/patrickmn/go-cache v2.1.0+incompatible/go.mod h1:3Qf8kWWT7OJRJbdiICTKqZju1ZixQ/KpMGzzAfe6+WQ=
 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/sirupsen/logrus v1.2.0 h1:juTguoYk5qI21pwyTXY3B3Y5cOTH3ZUyZCg1v/mihuo=
-github.com/sirupsen/logrus v1.2.0/go.mod h1:LxeOpSwHxABJmUn/MG1IvRgCAasNZTLOkJPxbbu5VWo=
 github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
 github.com/stretchr/testify v1.2.2 h1:bSDNvY7ZPG5RlJ8otE/7V6gMiyenm9RtJ7IUVIAoJ1w=
 github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
@@ -55,3 +57,5 @@ golang.org/x/sys v0.0.0-20181213200352-4d1cda033e06 h1:0oC8rFnE+74kEmuHZ46F6KHsM
 golang.org/x/sys v0.0.0-20181213200352-4d1cda033e06/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
 golang.org/x/sys v0.0.0-20181221143128-b4a75ba826a6 h1:IcgEB62HYgAhX0Nd/QrVgZlxlcyxbGQHElLUhW2X4Fo=
 golang.org/x/sys v0.0.0-20181221143128-b4a75ba826a6/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
+golang.org/x/sys v0.0.0-20181228144115-9a3f9b0469bb h1:pf3XwC90UUdNPYWZdFjhGBE7DUFuK3Ct1zWmZ65QN30=
+golang.org/x/sys v0.0.0-20181228144115-9a3f9b0469bb/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=

main.go

@@ -4,17 +4,17 @@ import (
 	"crypto/tls"
 	"fmt"
 	"io/ioutil"
+	"log"
 	"net"
 	"os"
 	"os/signal"
 	"syscall"
 	"time"
 
-	goFlags "github.com/jessevdk/go-flags"
-	log "github.com/sirupsen/logrus"
-
 	"github.com/AdguardTeam/dnsproxy/proxy"
 	"github.com/AdguardTeam/dnsproxy/upstream"
+	"github.com/hashicorp/logutils"
+	goFlags "github.com/jessevdk/go-flags"
 )
 
 // Options represents console arguments
@@ -81,19 +81,23 @@ func main() {
 }
 
 func run(options Options) {
-
+	filter := &logutils.LevelFilter{
+		Levels:   []logutils.LogLevel{"DEBUG", "INFO", "WARN", "ERROR"},
+		MinLevel: logutils.LogLevel("INFO"),
+		Writer:   os.Stderr,
+	}
 	if options.Verbose {
-		log.SetLevel(log.TraceLevel)
+		filter.MinLevel = logutils.LogLevel("DEBUG")
 	}
-
 	if options.LogOutput != "" {
 		file, err := os.OpenFile(options.LogOutput, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0755)
 		if err != nil {
 			log.Fatalf("cannot create a log file: %s", err)
 		}
 		defer file.Close()
-		log.SetOutput(file)
+		filter.Writer = file
 	}
+	log.SetOutput(filter)
 
 	// Prepare the proxy server
 	config := createProxyConfig(options)

mobile/helpers.go

@@ -9,7 +9,7 @@ import (
 	"github.com/miekg/dns"
 )
 
-// Mobile-friendly DNS stamp structure
+// DNSStamp is mobile-friendly DNS stamp structure
 type DNSStamp struct {
 	Proto        uint8  // Protocol (0x00 for plain, 0x01 for DNSCrypt, 0x02 for DOH, 0x03 for DOT
 	ServerAddr   string // Server address

mobile/mobile.go

@@ -6,6 +6,7 @@ package mobile
 import (
 	"errors"
 	"fmt"
+	"log"
 	"net"
 	"os"
 	"strings"
@@ -14,7 +15,7 @@ import (
 
 	"github.com/AdguardTeam/dnsproxy/proxy"
 	"github.com/AdguardTeam/dnsproxy/upstream"
-	log "github.com/sirupsen/logrus"
+	"github.com/hashicorp/logutils"
 )
 
 // DNSProxy represents a proxy with it's configuration
@@ -101,19 +102,22 @@ func (d *DNSProxy) Addr() string {
 
 // updateLogLevel updates log level and creates a log file
 func (d *DNSProxy) updateLogLevel(config *Config) error {
+	filter := &logutils.LevelFilter{
+		Levels:   []logutils.LogLevel{"DEBUG", "INFO", "WARN", "ERROR"},
+		MinLevel: logutils.LogLevel("INFO"),
+		Writer:   os.Stderr,
+	}
 	if config.Verbose {
-		log.SetLevel(log.TraceLevel)
+		filter.MinLevel = logutils.LogLevel("DEBUG")
 	}
-
 	if config.LogOutput != "" {
 		file, err := os.OpenFile(config.LogOutput, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0755)
 		if err != nil {
 			return fmt.Errorf("cannot create a log file: %s", err)
 		}
-		d.logFile = file
-		log.SetOutput(file)
+		filter.Writer = file
 	}
-
+	log.SetOutput(filter)
 	return nil
 }
 

proxy/cache.go

@@ -2,13 +2,13 @@ package proxy
 
 import (
 	"encoding/binary"
+	"log"
 	"math"
 	"strings"
 	"sync"
 	"time"
 
 	"github.com/miekg/dns"
-	log "github.com/sirupsen/logrus"
 )
 
 type item struct {
@@ -28,7 +28,7 @@ func (c *cache) Get(request *dns.Msg) (*dns.Msg, bool) {
 	}
 	ok, key := key(request)
 	if !ok {
-		log.Debug("Get(): key returned !ok")
+		log.Print("[DEBUG] Get(): key returned !ok")
 		return nil, false
 	}
 
@@ -87,13 +87,13 @@ func (c *cache) Set(m *dns.Msg) {
 func isRequestCacheable(m *dns.Msg) bool {
 	// truncated messages aren't valid
 	if m.Truncated {
-		log.Debugf("Refusing to cache truncated message")
+		log.Printf("[DEBUG] Refusing to cache truncated message")
 		return false
 	}
 
 	// if has wrong number of questions, also don't cache
 	if len(m.Question) != 1 {
-		log.Debugf("Refusing to cache message with wrong number of questions")
+		log.Printf("[DEBUG] Refusing to cache message with wrong number of questions")
 		return false
 	}
 
@@ -104,7 +104,7 @@ func isRequestCacheable(m *dns.Msg) bool {
 	case dns.RcodeServerFailure:
 		return false // quietly refuse, don't log
 	default:
-		log.Debugf("%s: Refusing to cache message with rcode: %s", m.Question[0].Name, dns.RcodeToString[m.Rcode])
+		log.Printf("[DEBUG] %s: Refusing to cache message with rcode: %s", m.Question[0].Name, dns.RcodeToString[m.Rcode])
 		return false
 	}
 
@@ -162,7 +162,7 @@ func getTTLIfLower(h *dns.RR_Header, ttl uint32) uint32 {
 // uint16(qtype) then uint16(qclass) then name
 func key(m *dns.Msg) (bool, string) {
 	if len(m.Question) != 1 {
-		log.Debugf("got msg with len(m.Question) != 1: %d", len(m.Question))
+		log.Printf("[DEBUG] got msg with len(m.Question) != 1: %d", len(m.Question))
 		return false, ""
 	}
 

proxy/proxy.go

@@ -4,17 +4,16 @@ import (
 	"crypto/tls"
 	"errors"
 	"fmt"
+	"log"
 	"net"
 	"sync"
 	"time"
 
+	"github.com/AdguardTeam/dnsproxy/upstream"
+	"github.com/jmcvetta/randutil"
 	"github.com/joomcode/errorx"
 	"github.com/miekg/dns"
 	gocache "github.com/patrickmn/go-cache"
-	log "github.com/sirupsen/logrus"
-
-	"github.com/AdguardTeam/dnsproxy/upstream"
-	"github.com/jmcvetta/randutil"
 )
 
 const (
@@ -180,7 +179,7 @@ func (p *Proxy) Resolve(d *DNSContext) error {
 		val, ok := p.cache.Get(d.Req)
 		if ok && val != nil {
 			d.Res = val
-			log.Debugf("Serving cached response")
+			log.Printf("[DEBUG] Serving cached response")
 			return nil
 		}
 	}
@@ -191,13 +190,13 @@ func (p *Proxy) Resolve(d *DNSContext) error {
 	startTime := time.Now()
 	reply, err := dnsUpstream.Exchange(d.Req)
 	rtt := int(time.Since(startTime) / time.Millisecond)
-	log.Debugf("RTT: %d ms", rtt)
+	log.Printf("[DEBUG] RTT: %d ms", rtt)
 
 	// Update the upstreams weight
 	p.calculateUpstreamWeights(d.UpstreamIdx, rtt)
 
 	if err != nil && p.Fallback != nil {
-		log.Debugf("Using the fallback upstream due to %s", err)
+		log.Printf("[DEBUG] Using the fallback upstream due to %s", err)
 		reply, err = p.Fallback.Exchange(d.Req)
 	}
 
@@ -319,19 +318,19 @@ func (p *Proxy) udpPacketLoop(conn *net.UDPConn) {
 				log.Printf("udpListen.ReadFrom() returned because we're reading from a closed connection, exiting loop")
 				break
 			}
-			log.Warnf("got error when reading from UDP listen: %s", err)
+			log.Printf("[WARN] got error when reading from UDP listen: %s", err)
 		}
 	}
 }
 
 // handleUDPPacket processes the incoming UDP packet and sends a DNS response
 func (p *Proxy) handleUDPPacket(packet []byte, addr net.Addr, conn *net.UDPConn) {
-	log.Debugf("Start handling new UDP packet from %s", addr)
+	log.Printf("[DEBUG] Start handling new UDP packet from %s", addr)
 
 	msg := &dns.Msg{}
 	err := msg.Unpack(packet)
 	if err != nil {
-		log.Warnf("error handling UDP packet: %s", err)
+		log.Printf("[WARN] error handling UDP packet: %s", err)
 		return
 	}
 
@@ -344,7 +343,7 @@ func (p *Proxy) handleUDPPacket(packet []byte, addr net.Addr, conn *net.UDPConn)
 
 	err = p.handleDNSRequest(d)
 	if err != nil {
-		log.Debugf("error handling DNS (%s) request: %s", d.Proto, err)
+		log.Printf("[DEBUG] error handling DNS (%s) request: %s", d.Proto, err)
 	}
 }
 
@@ -382,7 +381,7 @@ func (p *Proxy) tcpPacketLoop(l net.Listener, proto string) {
 				log.Printf("tcpListen.Accept() returned because we're reading from a closed connection, exiting loop")
 				break
 			}
-			log.Warnf("got error when reading from TCP listen: %s", err)
+			log.Printf("[WARN] got error when reading from TCP listen: %s", err)
 		} else {
 			go p.handleTCPConnection(clientConn, proto)
 		}
@@ -392,7 +391,7 @@ func (p *Proxy) tcpPacketLoop(l net.Listener, proto string) {
 // handleTCPConnection starts a loop that handles an incoming TCP connection
 // proto is either "tcp" or "tls"
 func (p *Proxy) handleTCPConnection(conn net.Conn, proto string) {
-	log.Debugf("Start handling the new TCP connection %s", conn.RemoteAddr())
+	log.Printf("[DEBUG] Start handling the new TCP connection %s", conn.RemoteAddr())
 	defer conn.Close()
 
 	for {
@@ -411,7 +410,7 @@ func (p *Proxy) handleTCPConnection(conn net.Conn, proto string) {
 		msg := &dns.Msg{}
 		err = msg.Unpack(packet)
 		if err != nil {
-			log.Warnf("error handling TCP packet: %s", err)
+			log.Printf("[WARN] error handling TCP packet: %s", err)
 			return
 		}
 
@@ -424,7 +423,7 @@ func (p *Proxy) handleTCPConnection(conn net.Conn, proto string) {
 
 		err = p.handleDNSRequest(d)
 		if err != nil {
-			log.Debugf("error handling DNS (%s) request: %s", d.Proto, err)
+			log.Printf("[DEBUG] error handling DNS (%s) request: %s", d.Proto, err)
 		}
 	}
 }
@@ -464,18 +463,18 @@ func (p *Proxy) handleDNSRequest(d *DNSContext) error {
 
 	// ratelimit based on IP only, protects CPU cycles and outbound connections
 	if d.Proto == "udp" && p.isRatelimited(d.Addr) {
-		log.Debugf("Ratelimiting %v based on IP only", d.Addr)
+		log.Printf("[DEBUG] Ratelimiting %v based on IP only", d.Addr)
 		return nil // do nothing, don't reply, we got ratelimited
 	}
 
 	if len(d.Req.Question) != 1 {
-		log.Warnf("got invalid number of questions: %v", len(d.Req.Question))
+		log.Printf("[WARN] got invalid number of questions: %v", len(d.Req.Question))
 		d.Res = p.genServerFailure(d.Req)
 	}
 
 	// refuse ANY requests (anti-DDOS measure)
 	if p.RefuseAny && d.Req.Question[0].Qtype == dns.TypeANY {
-		log.Debugf("Refusing type=ANY request")
+		log.Printf("[DEBUG] Refusing type=ANY request")
 		d.Res = p.genNotImpl(d.Req)
 	}
 
@@ -486,7 +485,7 @@ func (p *Proxy) handleDNSRequest(d *DNSContext) error {
 		dnsUpstream, upstreamIdx := p.chooseUpstream()
 		d.Upstream = dnsUpstream
 		d.UpstreamIdx = upstreamIdx
-		log.Debugf("Upstream is %s (%d)", dnsUpstream.Address(), upstreamIdx)
+		log.Printf("[DEBUG] Upstream is %s (%d)", dnsUpstream.Address(), upstreamIdx)
 
 		// execute the DNS request
 		// if there is a custom middleware configured, use it
@@ -525,7 +524,7 @@ func (p *Proxy) respond(d *DNSContext) {
 	}
 
 	if err != nil {
-		log.Warnf("error while responding to a DNS request: %s", err)
+		log.Printf("[WARN] error while responding to a DNS request: %s", err)
 	}
 }
 
@@ -599,14 +598,9 @@ func (p *Proxy) genNotImpl(request *dns.Msg) *dns.Msg {
 }
 
 func (p *Proxy) logDNSMessage(m *dns.Msg) {
-	if !log.IsLevelEnabled(log.DebugLevel) || m == nil {
-		// Avoid calling m.String() when logging level is not debug
-		return
-	}
-
 	if m.Response {
-		log.Debugf("OUT: %s", m.String())
+		log.Printf("[DEBUG] OUT: %s", m)
 	} else {
-		log.Debugf("IN: %s", m.String())
+		log.Printf("[DEBUG] IN: %s", m)
 	}
 }