git » dnss » commit 52a1c54

Replace query logging with tracing

author Alberto Bertogli
2015-09-11 15:02:18 UTC
committer Alberto Bertogli
2015-09-11 15:02:18 UTC
parent a90cf72af800971f3466b57d2b87b3d81a436562

Replace query logging with tracing

dnss.go +3 -0
dnstogrpc/dnstogrpc.go +15 -14
grpctodns/grpctodns.go +18 -10
util/strings.go +13 -2

diff --git a/dnss.go b/dnss.go
index 44404e0..d3d33e3 100644
--- a/dnss.go
+++ b/dnss.go
@@ -12,6 +12,7 @@ import (
 	"github.com/golang/glog"
 
 	// Make GRPC log to glog.
+	"google.golang.org/grpc"
 	_ "google.golang.org/grpc/grpclog/glogger"
 
 	"blitiri.com.ar/go/dnss/dnstogrpc"
@@ -60,9 +61,11 @@ func main() {
 
 	go flushLogs()
 
+	grpc.EnableTracing = false
 	if *monitoringListenAddr != "" {
 		glog.Infof("Monitoring HTTP server listening on %s",
 			*monitoringListenAddr)
+		grpc.EnableTracing = true
 		go http.ListenAndServe(*monitoringListenAddr, nil)
 	}
 
diff --git a/dnstogrpc/dnstogrpc.go b/dnstogrpc/dnstogrpc.go
index 5cc8497..084b069 100644
--- a/dnstogrpc/dnstogrpc.go
+++ b/dnstogrpc/dnstogrpc.go
@@ -3,7 +3,6 @@
 package dnstogrpc
 
 import (
-	"fmt"
 	"sync"
 	"time"
 
@@ -12,6 +11,7 @@ import (
 	"github.com/golang/glog"
 	"github.com/miekg/dns"
 	"golang.org/x/net/context"
+	"golang.org/x/net/trace"
 	"google.golang.org/grpc"
 	"google.golang.org/grpc/credentials"
 )
@@ -81,10 +81,13 @@ func New(addr, upstream, caFile string) *Server {
 }
 
 func (s *Server) Handler(w dns.ResponseWriter, r *dns.Msg) {
-	prefix := ""
+	tr := trace.New("dnstogrpc", "Handler")
+	defer tr.Finish()
+
+	tr.LazyPrintf("from:%v   id:%v", w.RemoteAddr(), r.Id)
+
 	if glog.V(3) {
-		prefix = fmt.Sprintf("%v %v", w.RemoteAddr(), r.Id)
-		glog.Infof("DNS  %v %v", prefix, util.QuestionsToString(r.Question))
+		tr.LazyPrintf(util.QuestionsToString(r.Question))
 	}
 
 	// TODO: we should create our own IDs, in case different users pick the
@@ -92,19 +95,17 @@ func (s *Server) Handler(w dns.ResponseWriter, r *dns.Msg) {
 
 	from_up, err := s.client.Query(r)
 	if err != nil {
-		glog.V(3).Infof("DNS  %v  ERR: %v", prefix, err)
+		glog.Infof(err.Error())
+		tr.LazyPrintf(err.Error())
+		tr.SetError()
+		return
 	}
 
-	if from_up != nil {
-		if from_up.Rcode != dns.RcodeSuccess {
-			rcode := dns.RcodeToString[from_up.Rcode]
-			glog.V(3).Infof("DNS  %v  !->  %v", prefix, rcode)
-		}
-		for _, rr := range from_up.Answer {
-			glog.V(3).Infof("DNS  %v  ->  %v", prefix, rr)
-		}
-		w.WriteMsg(from_up)
+	if glog.V(3) {
+		util.TraceAnswer(tr, from_up)
 	}
+
+	w.WriteMsg(from_up)
 }
 
 func (s *Server) ListenAndServe() {
diff --git a/grpctodns/grpctodns.go b/grpctodns/grpctodns.go
index 98d4f0f..57004d1 100644
--- a/grpctodns/grpctodns.go
+++ b/grpctodns/grpctodns.go
@@ -12,6 +12,7 @@ import (
 	"github.com/golang/glog"
 	"github.com/miekg/dns"
 	"golang.org/x/net/context"
+	"golang.org/x/net/trace"
 	"google.golang.org/grpc"
 	"google.golang.org/grpc/credentials"
 )
@@ -42,6 +43,9 @@ type Server struct {
 }
 
 func (s *Server) Query(ctx context.Context, in *pb.RawMsg) (*pb.RawMsg, error) {
+	tr := trace.New("grpctodns", "Query")
+	defer tr.Finish()
+
 	r := &dns.Msg{}
 	err := r.Unpack(in.Data)
 	if err != nil {
@@ -49,32 +53,36 @@ func (s *Server) Query(ctx context.Context, in *pb.RawMsg) (*pb.RawMsg, error) {
 	}
 
 	if glog.V(3) {
-		glog.Infof("GRPC %v", util.QuestionsToString(r.Question))
+		tr.LazyPrintf(util.QuestionsToString(r.Question))
 	}
 
 	// TODO: we should create our own IDs, in case different users pick the
 	// same id and we pass that upstream.
 	from_up, err := dns.Exchange(r, s.Upstream)
 	if err != nil {
-		glog.V(3).Infof("GRPC   ERR: %v", err)
+		msg := fmt.Sprintf("dns exchange error: %v", err)
+		glog.Info(msg)
+		tr.LazyPrintf(msg)
+		tr.SetError()
 		return nil, err
 	}
 
 	if from_up == nil {
-		return nil, fmt.Errorf("No response from upstream")
+		err = fmt.Errorf("no response from upstream")
+		tr.LazyPrintf(err.Error())
+		tr.SetError()
+		return nil, err
 	}
 
-	if from_up.Rcode != dns.RcodeSuccess {
-		rcode := dns.RcodeToString[from_up.Rcode]
-		glog.V(3).Infof("GPRC   !->  %v", rcode)
-	}
-	for _, rr := range from_up.Answer {
-		glog.V(3).Infof("GRPC   ->  %v", rr)
+	if glog.V(3) {
+		util.TraceAnswer(tr, from_up)
 	}
 
 	buf, err := from_up.Pack()
 	if err != nil {
-		glog.V(3).Infof("GRPC   ERR: %v", err)
+		glog.Infof("   error packing: %v", err)
+		tr.LazyPrintf("error packing: %v", err)
+		tr.SetError()
 		return nil, err
 	}
 
diff --git a/util/strings.go b/util/strings.go
index 76ac24f..5624cc3 100644
--- a/util/strings.go
+++ b/util/strings.go
@@ -1,12 +1,13 @@
 package util
 
-// Utility functions for printing DNS messages.
+// Utility functions for logging DNS messages.
 
 import (
 	"fmt"
 	"strings"
 
 	"github.com/miekg/dns"
+	"golang.org/x/net/trace"
 )
 
 func QuestionsToString(qs []dns.Question) string {
@@ -15,5 +16,15 @@ func QuestionsToString(qs []dns.Question) string {
 		s = append(s, fmt.Sprintf("(%s %s %s)", q.Name,
 			dns.TypeToString[q.Qtype], dns.ClassToString[q.Qclass]))
 	}
-	return "Q[" + strings.Join(s, " ") + "]"
+	return "Q: " + strings.Join(s, " ; ")
+}
+
+func TraceAnswer(tr trace.Trace, m *dns.Msg) {
+	if m.Rcode != dns.RcodeSuccess {
+		rcode := dns.RcodeToString[m.Rcode]
+		tr.LazyPrintf(rcode)
+	}
+	for _, rr := range m.Answer {
+		tr.LazyPrintf(rr.String())
+	}
 }