reweave/weave
1
0 Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge pull request #1044 from weaveworks/664-use-logrus

Browse Source 
Use off-the-shelf logger logrus

Closes #664.
This commit is contained in:
Matthias Radestock committed 2015-07-01 14:47:52 +01:00
2 parents 2fee0f0184 a5ddb63fca
commit edf3ec9f09
49 files changed
+360 -346
Download Patch File Download Diff File Expand all files Collapse all files

No files matched your search

common/docker/client.go
+4 -4
View File
@@ -36,7 +36,7 @@ func NewClient(apiPath string) (*Client, error) {
if err != nil {
return nil, err
}
Info.Printf("[docker] Using Docker API on %s: %v", apiPath, env)
Log.Infof("[docker] Using Docker API on %s: %v", apiPath, env)
return client, nil
}
@@ -44,7 +44,7 @@ func NewClient(apiPath string) (*Client, error) {
func (c *Client) AddObserver(ob ContainerObserver) error {
events := make(chan *docker.APIEvents)
if err := c.AddEventListener(events); err != nil {
Error.Printf("[docker] Unable to add listener to Docker API: %s", err)
Log.Errorf("[docker] Unable to add listener to Docker API: %s", err)
return err
}
@@ -63,7 +63,7 @@ func (c *Client) AddObserver(ob ContainerObserver) error {
// IsContainerNotRunning returns true if we have checked with Docker that the ID is not running
func (c *Client) IsContainerNotRunning(idStr string) bool {
if !IsContainerID(idStr) {
Debug.Printf("[docker] '%s' does not seem to be a container id", idStr)
Log.Debugf("[docker] '%s' does not seem to be a container id", idStr)
return false
}
@@ -75,6 +75,6 @@ func (c *Client) IsContainerNotRunning(idStr string) bool {
if _, notThere := err.(*docker.NoSuchContainer); notThere {
return true
}
Error.Printf("[docker] Could not check container status: %s", err)
Log.Errorf("[docker] Could not check container status: %s", err)
return false
}
common/errors.go
+2 -2
View File
@@ -2,13 +2,13 @@ package common
func CheckFatal(e error) {
if e != nil {
Error.Fatal(e)
Log.Fatal(e)
}
}
func CheckWarn(e error) {
if e != nil {
Warning.Println(e)
Log.Warningln(e)
}
}
common/init.go
+1 -6
View File
@@ -1,10 +1,5 @@
package common
import (
"io/ioutil"
"os"
)
func init() {
InitLogging(ioutil.Discard, os.Stdout, os.Stdout, os.Stderr)
InitDefaultLogging(false)
}
common/logging.go
+44 -28
View File
@@ -1,46 +1,62 @@
package common
import (
"io"
"io/ioutil"
"log"
"bytes"
"fmt"
"os"
"strings"
"github.com/Sirupsen/logrus"
)
const (
standardLogFlags = log.Ldate | log.Ltime | log.Lmicroseconds
)
type textFormatter struct {
}
// Largely taken from
// http://www.goinggo.net/2013/11/using-log-package-in-go.html
// Based off logrus.TextFormatter, which behaves completely
// differently when you don't want colored output
func (f *textFormatter) Format(entry *logrus.Entry) ([]byte, error) {
b := &bytes.Buffer{}
levelText := strings.ToUpper(entry.Level.String())[0:4]
timeStamp := entry.Time.Format("2006/01/02 15:04:05.000000")
if len(entry.Data) > 0 {
fmt.Fprintf(b, "%s: %s %-44s ", levelText, timeStamp, entry.Message)
for k, v := range entry.Data {
fmt.Fprintf(b, " %s=%v", k, v)
}
} else {
// No padding when there's no fields
fmt.Fprintf(b, "%s: %s %s", levelText, timeStamp, entry.Message)
}
b.WriteByte('\n')
return b.Bytes(), nil
}
var (
Debug *log.Logger
Info *log.Logger
Warning *log.Logger
Error *log.Logger
debugF bool
standardTextFormatter = &textFormatter{}
)
func InitLogging(debugHandle io.Writer,
infoHandle io.Writer,
warningHandle io.Writer,
errorHandle io.Writer) {
var (
Log *logrus.Logger
)
Debug = log.New(debugHandle, "DEBUG: ", standardLogFlags)
Info = log.New(infoHandle, "INFO: ", standardLogFlags)
Warning = log.New(warningHandle, "WARNING: ", standardLogFlags)
Error = log.New(errorHandle, "ERROR: ", standardLogFlags)
func InitLogging(level logrus.Level) {
if Log == nil {
Log = &logrus.Logger{
Out: os.Stderr,
Formatter: standardTextFormatter,
Hooks: make(logrus.LevelHooks),
Level: level,
}
}
Log.Level = level
}
func InitDefaultLogging(debug bool) {
if debug == debugF {
return
}
debugF = debug
debugOut := ioutil.Discard
level := logrus.InfoLevel
if debug {
debugOut = os.Stderr
level = logrus.DebugLevel
}
InitLogging(debugOut, os.Stdout, os.Stdout, os.Stderr)
InitLogging(level)
}
common/sched_queue.go
+3 -3
View File
@@ -76,7 +76,7 @@ func NewSchedQueue(clock clock.Clock) *SchedQueue {
// Start starts the scheduled queue
func (cq *SchedQueue) Start() {
go func() {
defer func() { Debug.Printf("[sched-q] Quitting (%d calls pending)", len(cq.callablesH)) }()
defer func() { Log.Debugf("[sched-q] Quitting (%d calls pending)", len(cq.callablesH)) }()
var now time.Time
timer := cq.clock.Timer(time.Duration(math.MaxInt64))
@@ -116,14 +116,14 @@ func (cq *SchedQueue) Start() {
// Stop stops the scheduled queue
func (cq *SchedQueue) Stop() {
Debug.Printf("[sched-q] Stopping...")
Log.Debugf("[sched-q] Stopping...")
cq.closeChan <- true
}
// Add schedules a call.
// The callable should not modify the scheduled queue in any way.
func (cq *SchedQueue) Add(c callable, t time.Time) {
Debug.Printf("[sched-q] Adding call at %s", t)
Log.Debugf("[sched-q] Adding call at %s", t)
ce := schedCall{c: c, t: t}
cq.schedChan <- &ce
}
common/sched_queue_test.go
+3 -3
View File
@@ -11,7 +11,7 @@ import (
// Ensure we can add new calls while forwarding the clock
func TestSchedCallsBasic(t *testing.T) {
InitDefaultLogging(testing.Verbose())
Info.Println("TestSchedCallsBasic starting")
Log.Infoln("TestSchedCallsBasic starting")
const testSecs = 1000
clk := clock.NewMock()
@@ -37,7 +37,7 @@ func TestSchedCallsBasic(t *testing.T) {
// Ensure we can create a 100 seconds gap in the middle of the time travel
func TestSchedCallsGap(t *testing.T) {
InitDefaultLogging(testing.Verbose())
Info.Println("TestSchedCallsGap starting")
Log.Infoln("TestSchedCallsGap starting")
const testSecs = 1000
clk := clock.NewMock()
@@ -65,7 +65,7 @@ func TestSchedCallsGap(t *testing.T) {
func TestSchedCallsStop(t *testing.T) {
InitDefaultLogging(testing.Verbose())
Info.Println("TestSchedCallsStop starting")
Log.Infoln("TestSchedCallsStop starting")
const testSecs = 1000
clk := clock.NewMock()
common/signals.go
+3 -3
View File
@@ -20,17 +20,17 @@ func SignalHandlerLoop(ss ...SignalReceiver) {
for {
switch <-sigs {
case syscall.SIGINT:
Info.Printf("=== received SIGINT ===\n*** exiting\n")
Log.Infof("=== received SIGINT ===\n*** exiting\n")
for _, subsystem := range ss {
subsystem.Stop()
}
return
case syscall.SIGQUIT:
stacklen := runtime.Stack(buf, true)
Info.Printf("=== received SIGQUIT ===\n*** goroutine dump...\n%s\n*** end\n", buf[:stacklen])
Log.Infof("=== received SIGQUIT ===\n*** goroutine dump...\n%s\n*** end\n", buf[:stacklen])
case syscall.SIGUSR1:
for _, subsystem := range ss {
Info.Printf("=== received SIGUSR1 ===\n*** status...\n%s\n*** end\n", subsystem.Status())
Log.Infof("=== received SIGUSR1 ===\n*** status...\n%s\n*** end\n", subsystem.Status())
}
}
}
ipam/allocator.go
+3 -3
View File
@@ -718,11 +718,11 @@ func (alloc *Allocator) findOwner(addr address.Address) string {
// Logging
func (alloc *Allocator) infof(fmt string, args ...interface{}) {
common.Info.Printf("[allocator %s] "+fmt, append([]interface{}{alloc.ourName}, args...)...)
common.Log.Infof("[allocator %s] "+fmt, append([]interface{}{alloc.ourName}, args...)...)
}
func (alloc *Allocator) debugln(args ...interface{}) {
common.Debug.Println(append([]interface{}{fmt.Sprintf("[allocator %s]:", alloc.ourName)}, args...)...)
common.Log.Debugln(append([]interface{}{fmt.Sprintf("[allocator %s]:", alloc.ourName)}, args...)...)
}
func (alloc *Allocator) debugf(fmt string, args ...interface{}) {
common.Debug.Printf("[allocator %s] "+fmt, append([]interface{}{alloc.ourName}, args...)...)
common.Log.Debugf("[allocator %s] "+fmt, append([]interface{}{alloc.ourName}, args...)...)
}
ipam/allocator_test.go
+6 -6
View File
@@ -186,9 +186,9 @@ func TestCancel(t *testing.T) {
// Get some IPs, so each allocator has some space
res1, _ := alloc1.Allocate("foo", subnet, nil)
common.Debug.Printf("res1 = %s", res1.String())
common.Log.Debugf("res1 = %s", res1.String())
res2, _ := alloc2.Allocate("bar", subnet, nil)
common.Debug.Printf("res2 = %s", res2.String())
common.Log.Debugf("res2 = %s", res2.String())
if res1 == res2 {
require.FailNow(t, "Error: got same ips!")
}
@@ -343,14 +343,14 @@ func TestAllocatorFuzz(t *testing.T) {
allocIndex := rand.Int31n(nodes)
alloc := allocs[allocIndex]
//common.Info.Printf("Allocate: asking allocator %d", allocIndex)
//common.Log.Infof("Allocate: asking allocator %d", allocIndex)
addr, err := alloc.Allocate(name, subnet, nil)
if err != nil {
panic(fmt.Sprintf("Could not allocate addr"))
}
//common.Info.Printf("Allocate: got address %s for name %s", addr, name)
//common.Log.Infof("Allocate: got address %s for name %s", addr, name)
addrStr := addr.String()
stateLock.Lock()
@@ -387,7 +387,7 @@ func TestAllocatorFuzz(t *testing.T) {
stateLock.Unlock()
alloc := allocs[res.alloc]
//common.Info.Printf("Freeing %s (%s) on allocator %d", res.name, addr, res.alloc)
//common.Log.Infof("Freeing %s (%s) on allocator %d", res.name, addr, res.alloc)
oldAddr, err := address.ParseIP(addr)
if err != nil {
@@ -412,7 +412,7 @@ func TestAllocatorFuzz(t *testing.T) {
stateLock.Unlock()
alloc := allocs[res.alloc]
//common.Info.Printf("Asking for %s (%s) on allocator %d again", res.name, addr, res.alloc)
//common.Log.Infof("Asking for %s (%s) on allocator %d again", res.name, addr, res.alloc)
newAddr, _ := alloc.Allocate(res.name, subnet, nil)
oldAddr, _ := address.ParseIP(addr)
ipam/http.go
+3 -3
View File
@@ -13,7 +13,7 @@ import (
func badRequest(w http.ResponseWriter, err error) {
http.Error(w, err.Error(), http.StatusBadRequest)
common.Warning.Println("[allocator]:", err.Error())
common.Log.Warningln("[allocator]:", err.Error())
}
// HandleHTTP wires up ipams HTTP endpoints to the provided mux.
@@ -79,7 +79,7 @@ func (alloc *Allocator) HandleHTTP(router *mux.Router, defaultSubnet address.CID
return
}
if dockerCli != nil && dockerCli.IsContainerNotRunning(ident) {
common.Info.Printf("[allocator] '%s' is not running: freeing %s", ident, addr)
common.Log.Infof("[allocator] '%s' is not running: freeing %s", ident, addr)
alloc.Free(ident, addr)
return
}
@@ -96,7 +96,7 @@ func (alloc *Allocator) HandleHTTP(router *mux.Router, defaultSubnet address.CID
return
}
if dockerCli != nil && dockerCli.IsContainerNotRunning(ident) {
common.Info.Printf("[allocator] '%s' is not running: freeing %s", ident, newAddr)
common.Log.Infof("[allocator] '%s' is not running: freeing %s", ident, newAddr)
alloc.Free(ident, newAddr)
return
}
ipam/http_test.go
+2 -2
View File
@@ -48,13 +48,13 @@ func listenHTTP(alloc *Allocator, subnet address.CIDR) int {
httpListener, err := net.Listen("tcp", ":0")
if err != nil {
common.Error.Fatal("Unable to create http listener: ", err)
common.Log.Fatal("Unable to create http listener: ", err)
}
go func() {
srv := &http.Server{Handler: router}
if err := srv.Serve(httpListener); err != nil {
common.Error.Fatal("Unable to serve http: ", err)
common.Log.Fatal("Unable to serve http: ", err)
}
}()
return httpListener.Addr().(*net.TCPAddr).Port
ipam/ring/ring.go
+1 -1
View File
@@ -217,7 +217,7 @@ func (r *Ring) Merge(gossip Ring) error {
switch {
case mine.Version >= theirs.Version:
if mine.Version == theirs.Version && !mine.Equal(theirs) {
common.Debug.Printf("Error merging entries at %s - %v != %v\n", mine.Token, mine, theirs)
common.Log.Debugf("Error merging entries at %s - %v != %v\n", mine.Token, mine, theirs)
return ErrInvalidEntry
}
addToResult(*mine)
ipam/ring/ring_test.go
+5 -5
View File
@@ -608,7 +608,7 @@ func TestFuzzRingHard(t *testing.T) {
addPeer := func() {
peer, _ := router.PeerNameFromString(fmt.Sprintf("%02d:%02d:00:00:00:00", nextPeerID/10, nextPeerID%10))
common.Debug.Printf("%s: Adding peer", peer)
common.Log.Debugf("%s: Adding peer", peer)
nextPeerID++
peers = append(peers, peer)
rings = append(rings, New(start, end, peer))
@@ -658,7 +658,7 @@ func TestFuzzRingHard(t *testing.T) {
require.NoError(t, otherRing.Merge(*ring))
}
common.Debug.Printf("%s: transferring from peer %s", otherPeername, peername)
common.Log.Debugf("%s: transferring from peer %s", otherPeername, peername)
otherRing.Transfer(peername, peername)
// And now tell everyone about the transfer - rmpeer is
@@ -687,12 +687,12 @@ func TestFuzzRingHard(t *testing.T) {
size := address.Subtract(rangeToSplit.End, rangeToSplit.Start)
ipInRange := address.Add(rangeToSplit.Start, address.Offset(rand.Intn(int(size))))
_, peerToGiveTo, _ := randomPeer(-1)
common.Debug.Printf("%s: Granting [%v, %v) to %s", ring.Peer, ipInRange, rangeToSplit.End, peerToGiveTo)
common.Log.Debugf("%s: Granting [%v, %v) to %s", ring.Peer, ipInRange, rangeToSplit.End, peerToGiveTo)
ring.GrantRangeToHost(ipInRange, rangeToSplit.End, peerToGiveTo)
// Now 'gossip' this to a random host (note, note could be same host as above)
otherIndex, _, otherRing := randomPeer(-1)
common.Debug.Printf("%s: 'Gossiping' to %s", ring.Peer, otherRing.Peer)
common.Log.Debugf("%s: 'Gossiping' to %s", ring.Peer, otherRing.Peer)
require.NoError(t, otherRing.Merge(*ring))
theRanges[indexWithRanges] = ring.OwnedRanges()
@@ -711,7 +711,7 @@ func TestFuzzRingHard(t *testing.T) {
}
ring1 := ringsWithEntries[rand.Intn(len(ringsWithEntries))]
ring2index, _, ring2 := randomPeer(-1)
common.Debug.Printf("%s: 'Gossiping' to %s", ring1.Peer, ring2.Peer)
common.Log.Debugf("%s: 'Gossiping' to %s", ring1.Peer, ring2.Peer)
require.NoError(t, ring2.Merge(*ring1))
theRanges[ring2index] = ring2.OwnedRanges()
}
ipam/testutils_test.go
+1 -1
View File
@@ -295,7 +295,7 @@ func (client TestGossipRouterClient) GossipUnicast(dstPeerName router.PeerName,
select {
case client.router.gossipChans[dstPeerName] <- unicastMessage{sender: client.sender, buf: buf}:
default: // drop the message if we cannot send it
common.Error.Printf("Dropping message")
common.Log.Errorf("Dropping message")
}
return nil
}
nameserver/addrs_test.go
+1 -1
View File
@@ -10,7 +10,7 @@ import (
func TestAddrs(t *testing.T) {
InitDefaultLogging(testing.Verbose())
Info.Println("TestAddrs starting")
Log.Infoln("TestAddrs starting")
ip, err := addrToIPv4("10.13.12.11")
require.NoError(t, err)
nameserver/cache.go
+6 -6
View File
@@ -86,7 +86,7 @@ func (e *cacheEntry) getReply(request *dns.Msg, maxLen int, now time.Time) (*dns
}
if e.ReplyLen >= maxLen {
Debug.Printf("[cache msgid %d] returning truncated reponse: %d > %d", request.MsgHdr.Id, e.ReplyLen, maxLen)
Log.Debugf("[cache msgid %d] returning truncated reponse: %d > %d", request.MsgHdr.Id, e.ReplyLen, maxLen)
return makeTruncatedReply(request), nil
}
@@ -122,7 +122,7 @@ func (e *cacheEntry) setReply(reply *dns.Msg, ttl int, flags uint8, now time.Tim
var prevValidUntil time.Time
if e.Status == stResolved {
if reply != nil {
Debug.Printf("[cache msgid %d] replacing response in cache", reply.MsgHdr.Id)
Log.Debugf("[cache msgid %d] replacing response in cache", reply.MsgHdr.Id)
}
prevValidUntil = e.validUntil
}
@@ -147,7 +147,7 @@ func (e *cacheEntry) setReply(reply *dns.Msg, ttl int, flags uint8, now time.Tim
}
e.validUntil = now.Add(time.Second * time.Duration(minTTL))
} else {
Warning.Printf("[cache] no valid TTL could be calculated")
Log.Warningf("[cache] no valid TTL could be calculated")
}
e.Status = stResolved
@@ -323,7 +323,7 @@ func (c *Cache) Get(request *dns.Msg, maxLen int) (reply *dns.Msg, err error) {
if ent, found := c.entries[key]; found {
reply, err = ent.getReply(request, maxLen, now)
if ent.hasExpired(now) {
Debug.Printf("[cache msgid %d] expired: removing", request.MsgHdr.Id)
Log.Debugf("[cache msgid %d] expired: removing", request.MsgHdr.Id)
if ent.index > 0 {
heap.Remove(&c.entriesH, ent.index)
}
@@ -332,7 +332,7 @@ func (c *Cache) Get(request *dns.Msg, maxLen int) (reply *dns.Msg, err error) {
}
} else {
// we are the first asking for this name: create an entry with no reply... the caller must wait
Debug.Printf("[cache msgid %d] addind in pending state", request.MsgHdr.Id)
Log.Debugf("[cache msgid %d] addind in pending state", request.MsgHdr.Id)
c.entries[key] = newCacheEntry(&question, now)
}
return
@@ -345,7 +345,7 @@ func (c *Cache) Remove(question *dns.Question) {
key := cacheKey(*question)
if entry, found := c.entries[key]; found {
Debug.Printf("[cache] removing %s-response for '%s'", dns.TypeToString[question.Qtype], question.Name)
Log.Debugf("[cache] removing %s-response for '%s'", dns.TypeToString[question.Qtype], question.Name)
if entry.index > 0 {
heap.Remove(&c.entriesH, entry.index)
}
nameserver/cache_test.go
+3 -3
View File
@@ -15,7 +15,7 @@ import (
// Check that the cache keeps its intended capacity constant
func TestCacheLength(t *testing.T) {
InitDefaultLogging(testing.Verbose())
Info.Println("TestCacheLength starting")
Log.Infoln("TestCacheLength starting")
const cacheLen = 128
@@ -56,9 +56,9 @@ func TestCacheLength(t *testing.T) {
// Check that the cache entries are ok
func TestCacheEntries(t *testing.T) {
InitDefaultLogging(testing.Verbose())
Info.Println("TestCacheEntries starting")
Log.Infoln("TestCacheEntries starting")
Info.Println("Checking cache consistency")
Log.Infoln("Checking cache consistency")
const cacheLen = 128
clk := clock.NewMock()
nameserver/dns_test.go
+1 -1
View File
@@ -12,7 +12,7 @@ import (
// Check that we can prune an answer
func TestPrune(t *testing.T) {
InitDefaultLogging(testing.Verbose())
Info.Println("TestPrune starting")
Log.Infoln("TestPrune starting")
questionMsg := new(dns.Msg)
questionMsg.SetQuestion("name", dns.TypeA)
nameserver/http.go
+12 -13
View File
@@ -2,7 +2,6 @@ package nameserver
import (
"fmt"
"log"
"net"
"net/http"
@@ -12,10 +11,10 @@ import (
"github.com/weaveworks/weave/common/docker"
)
func httpErrorAndLog(level *log.Logger, w http.ResponseWriter, msg string,
func httpErrorAndLog(w http.ResponseWriter, msg string,
status int, logmsg string, logargs ...interface{}) {
http.Error(w, msg, status)
level.Printf("[http] "+logmsg, logargs...)
Log.Warningf("[http] "+logmsg, logargs...)
}
func extractFQDN(r *http.Request) (string, string) {
@@ -41,7 +40,7 @@ func ServeHTTP(listener net.Listener, version string, server *DNSServer, dockerC
muxRouter.Methods("PUT").Path("/name/{id:.+}/{ip:.+}").HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
reqError := func(msg string, logmsg string, logargs ...interface{}) {
httpErrorAndLog(Warning, w, msg, http.StatusBadRequest, logmsg, logargs...)
httpErrorAndLog(w, msg, http.StatusBadRequest, logmsg, logargs...)
}
vars := mux.Vars(r)
@@ -62,21 +61,21 @@ func ServeHTTP(listener net.Listener, version string, server *DNSServer, dockerC
domain := server.Zone.Domain()
if !dns.IsSubDomain(domain, name) {
Info.Printf("[http] Ignoring name %s, not in %s", name, domain)
Log.Infof("[http] Ignoring name %s, not in %s", name, domain)
return
}
Info.Printf("[http] Adding %s -> %s", name, ipStr)
Log.Infof("[http] Adding %s -> %s", name, ipStr)
if err := server.Zone.AddRecord(idStr, name, ip); err != nil {
if _, ok := err.(DuplicateError); !ok {
httpErrorAndLog(
Error, w, "Internal error", http.StatusInternalServerError,
w, "Internal error", http.StatusInternalServerError,
"Unexpected error from DB: %s", err)
return
} // oh, I already know this. whatever.
}
if dockerCli != nil && dockerCli.IsContainerNotRunning(idStr) {
Info.Printf("[http] '%s' is not running: removing", idStr)
Log.Infof("[http] '%s' is not running: removing", idStr)
server.Zone.DeleteRecords(idStr, name, ip)
}
})
@@ -89,14 +88,14 @@ func ServeHTTP(listener net.Listener, version string, server *DNSServer, dockerC
ip := net.ParseIP(ipStr)
if ip == nil {
httpErrorAndLog(
Warning, w, "Invalid IP in request", http.StatusBadRequest,
w, "Invalid IP in request", http.StatusBadRequest,
"Invalid IP in request: %s", ipStr)
return
}
fqdnStr, fqdn := extractFQDN(r)
Info.Printf("[http] Deleting ID %s, IP %s, FQDN %s", idStr, ipStr, fqdnStr)
Log.Infof("[http] Deleting ID %s, IP %s, FQDN %s", idStr, ipStr, fqdnStr)
server.Zone.DeleteRecords(idStr, fqdn, ip)
})
@@ -106,20 +105,20 @@ func ServeHTTP(listener net.Listener, version string, server *DNSServer, dockerC
fqdnStr, fqdn := extractFQDN(r)
Info.Printf("[http] Deleting ID %s, IP *, FQDN %s", idStr, fqdnStr)
Log.Infof("[http] Deleting ID %s, IP *, FQDN %s", idStr, fqdnStr)
server.Zone.DeleteRecords(idStr, fqdn, net.IP{})
})
muxRouter.Methods("DELETE").Path("/name").HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
fqdnStr, fqdn := extractFQDN(r)
Info.Printf("[http] Deleting ID *, IP *, FQDN %s", fqdnStr)
Log.Infof("[http] Deleting ID *, IP *, FQDN %s", fqdnStr)
server.Zone.DeleteRecords("", fqdn, net.IP{})
})
http.Handle("/", muxRouter)
if err := http.Serve(listener, nil); err != nil {
Error.Fatal("[http] Unable to serve http: ", err)
Log.Fatal("[http] Unable to serve http: ", err)
}
}
nameserver/mdns_lookup.go
+2 -2
View File
@@ -12,10 +12,10 @@ func mdnsLookup(client *MDNSClient, name string, qtype uint16, insistent bool) (
for resp := range channel {
if err := resp.err; err != nil {
Debug.Printf("[mdns] Error for query type %s name %s: %s", dns.TypeToString[qtype], name, err)
Log.Debugf("[mdns] Error for query type %s name %s: %s", dns.TypeToString[qtype], name, err)
return nil, err
}
Debug.Printf("[mdns] Got response name for %s-query about name '%s': name '%s', addr '%s'",
Log.Debugf("[mdns] Got response name for %s-query about name '%s': name '%s', addr '%s'",
dns.TypeToString[qtype], name, resp.name, resp.addr)
if !insistent {
nameserver/mdns_server.go
+6 -6
View File
@@ -113,7 +113,7 @@ func (s *MDNSServer) makeHandler(qtype uint16, lookup LookupFunc) dns.HandlerFun
// answer.
remoteAddr := rw.RemoteAddr()
if s.addrIsLocal(remoteAddr) && !s.allowLocal {
Debug.Printf("[mdns] srv: mDNS query from local host ('%s'): ignored", remoteAddr)
Log.Debugf("[mdns] srv: mDNS query from local host ('%s'): ignored", remoteAddr)
return
}
@@ -121,16 +121,16 @@ func (s *MDNSServer) makeHandler(qtype uint16, lookup LookupFunc) dns.HandlerFun
if len(r.Answer) == 0 && len(r.Question) > 0 {
q := &r.Question[0]
if q.Qtype == qtype {
Debug.Printf("[mdns msgid %d] srv: trying to answer to mDNS query '%s'", r.MsgHdr.Id, q.Name)
Log.Debugf("[mdns msgid %d] srv: trying to answer to mDNS query '%s'", r.MsgHdr.Id, q.Name)
if m := lookup(s.zone, r, q); m != nil {
Debug.Printf("[mdns msgid %d] srv: found local answer to mDNS query '%s'", r.MsgHdr.Id, q.Name)
Log.Debugf("[mdns msgid %d] srv: found local answer to mDNS query '%s'", r.MsgHdr.Id, q.Name)
if err := s.sendResponse(m); err != nil {
Warning.Printf("[mdns msgid %d] srv: error writing mDNS response to %v", r.MsgHdr.Id, s.sendconn)
Log.Warningf("[mdns msgid %d] srv: error writing mDNS response to %v", r.MsgHdr.Id, s.sendconn)
} else {
Debug.Printf("[mdns msgid %d] srv: response sent: %d answers", r.MsgHdr.Id, len(m.Answer))
Log.Debugf("[mdns msgid %d] srv: response sent: %d answers", r.MsgHdr.Id, len(m.Answer))
}
} else {
Debug.Printf("[mdns msgid %d] srv: no local answer for answering mDNS query '%s'",
Log.Debugf("[mdns msgid %d] srv: no local answer for answering mDNS query '%s'",
r.MsgHdr.Id, q.Name)
}
}
nameserver/mdns_server_test.go
+7 -7
View File
@@ -18,7 +18,7 @@ func TestServerSimpleQuery(t *testing.T) {
)
InitDefaultLogging(testing.Verbose())
Info.Println("TestServerSimpleQuery starting")
Log.Infoln("TestServerSimpleQuery starting")
mzone := newMockedZoneWithRecords([]ZoneRecord{testRecord1, testRecord2})
mdnsServer, err := NewMDNSServer(mzone, true, DefaultLocalTTL)
@@ -59,11 +59,11 @@ func TestServerSimpleQuery(t *testing.T) {
require.NoError(t, err)
conn, err := net.ListenUDP("udp4", &net.UDPAddr{IP: net.IPv4zero, Port: 0})
require.NoError(t, err)
Debug.Printf("Sending UDP packet to %s", ipv4Addr)
Log.Debugf("Sending UDP packet to %s", ipv4Addr)
_, err = conn.WriteTo(buf, ipv4Addr)
require.NoError(t, err)
Debug.Printf("Waiting for response")
Log.Debugf("Waiting for response")
for {
select {
case x := <-recvChan:
@@ -80,7 +80,7 @@ func TestServerSimpleQuery(t *testing.T) {
return
}
case <-time.After(100 * time.Millisecond):
Debug.Printf("Timeout while waiting for response")
Log.Debugf("Timeout while waiting for response")
return
}
}
@@ -96,7 +96,7 @@ func TestServerSimpleQuery(t *testing.T) {
time.Sleep(100 * time.Millisecond) // Allow for server to get going
Debug.Printf("Checking that we get 2 IPs fo name '%s' [A]", testRecord1.Name())
Log.Debugf("Checking that we get 2 IPs fo name '%s' [A]", testRecord1.Name())
sendQuery(testRecord1.Name(), dns.TypeA)
if receivedCount != 2 {
t.Fatalf("Unexpected result count %d for %s", receivedCount, testRecord1.Name())
@@ -108,13 +108,13 @@ func TestServerSimpleQuery(t *testing.T) {
t.Fatalf("Unexpected result %s for %s", receivedAddrs, testRecord1.Name())
}
Debug.Printf("Checking that 'testfail.weave.' [A] gets no answers")
Log.Debugf("Checking that 'testfail.weave.' [A] gets no answers")
sendQuery("testfail.weave.", dns.TypeA)
if receivedCount != 0 {
t.Fatalf("Unexpected result count %d for testfail.weave", receivedCount)
}
Debug.Printf("Checking that '%s' [PTR] gets one name", testInAddr1)
Log.Debugf("Checking that '%s' [PTR] gets one name", testInAddr1)
sendQuery(testInAddr1, dns.TypePTR)
if receivedCount != 1 {
t.Fatalf("Expected an answer to %s, got %d answers", testInAddr1, receivedCount)
nameserver/mdns_test.go
+9 -9
View File
@@ -37,7 +37,7 @@ func TestClientServerSimpleQuery(t *testing.T) {
receivedAddr = nil
receivedName = ""
receivedCount = 0
Debug.Printf("Sending query...")
Log.Debugf("Sending query...")
switch querytype {
case dns.TypeA:
r, err := mdnsCli.LookupName(name)
@@ -60,7 +60,7 @@ func TestClientServerSimpleQuery(t *testing.T) {
time.Sleep(100 * time.Millisecond) // Allow for server to get going
Debug.Printf("Query: %s dns.TypeA", testRecord1.Name())
Log.Debugf("Query: %s dns.TypeA", testRecord1.Name())
sendQuery(testRecord1.Name(), dns.TypeA)
if receivedCount != 1 {
t.Fatalf("Unexpected result count %d for %s", receivedCount, testRecord1.Name())
@@ -69,13 +69,13 @@ func TestClientServerSimpleQuery(t *testing.T) {
t.Fatalf("Unexpected result %s for %s", receivedAddr, testRecord1.Name())
}
Debug.Printf("Query: testfail.weave. dns.TypeA")
Log.Debugf("Query: testfail.weave. dns.TypeA")
sendQuery("testfail.weave.", dns.TypeA)
if receivedCount != 0 {
t.Fatalf("Unexpected result count %d for testfail.weave", receivedCount)
}
Debug.Printf("Query: %s dns.TypePTR", testInAddr1)
Log.Debugf("Query: %s dns.TypePTR", testInAddr1)
sendQuery(testInAddr1, dns.TypePTR)
if receivedCount != 1 {
t.Fatalf("Expected an answer to %s, got %d answers", testInAddr1, receivedCount)
@@ -127,7 +127,7 @@ func TestClientServerInsistentQuery(t *testing.T) {
receivedAddrs = nil
receivedNames = nil
receivedCount = 0
Debug.Printf("Sending query...")
Log.Debugf("Sending query...")
switch querytype {
case dns.TypeA:
receivedAddrs, err = mdnsCli.InsistentLookupName(name)
@@ -144,25 +144,25 @@ func TestClientServerInsistentQuery(t *testing.T) {
time.Sleep(100 * time.Millisecond) // Allow for server to get going
Debug.Printf("Query: %s dns.TypeA", testRecord1.Name())
Log.Debugf("Query: %s dns.TypeA", testRecord1.Name())
sendQuery(testRecord1.Name(), dns.TypeA)
if receivedCount != 2 {
t.Fatalf("Unexpected result count %d for %s", receivedCount, testRecord1.Name())
}
Debug.Printf("Query: testfail.weave. dns.TypeA")
Log.Debugf("Query: testfail.weave. dns.TypeA")
sendQuery("testfail.weave.", dns.TypeA)
if receivedCount != 0 {
t.Fatalf("Unexpected result count %d for testfail.weave", receivedCount)
}
Debug.Printf("Query: %s dns.TypePTR", testInAddr1)
Log.Debugf("Query: %s dns.TypePTR", testInAddr1)
sendQuery(testInAddr1, dns.TypePTR)
if receivedCount != 1 {
t.Fatalf("Expected an answer to %s, got %d answers", testInAddr1, receivedCount)
}
Debug.Printf("Query: %s dns.TypePTR", testInAddr2)
Log.Debugf("Query: %s dns.TypePTR", testInAddr2)
sendQuery(testInAddr2, dns.TypePTR)
if receivedCount != 1 {
t.Fatalf("Expected an answer to %s, got %d answers", testInAddr2, receivedCount)
nameserver/mocks_test.go
+13 -13
View File
@@ -19,7 +19,7 @@ const (
)
// Warn about some methods that some day should be implemented...
func notImplWarn() { Warning.Printf("Mocked method. Not implemented.") }
func notImplWarn() { Log.Warningf("Mocked method. Not implemented.") }
// A mocked Zone that always returns the same records
// * it does not send/receive any mDNS query
@@ -38,7 +38,7 @@ func newMockedZoneWithRecords(zr []ZoneRecord) *mockedZoneWithRecords {
}
func (mz *mockedZoneWithRecords) Domain() string { return DefaultLocalDomain }
func (mz *mockedZoneWithRecords) LookupName(name string) ([]ZoneRecord, error) {
Debug.Printf("[mocked zone]: LookupName: returning records %s", mz.records)
Log.Debugf("[mocked zone]: LookupName: returning records %s", mz.records)
mz.Lock()
defer mz.Unlock()
@@ -53,7 +53,7 @@ func (mz *mockedZoneWithRecords) LookupName(name string) ([]ZoneRecord, error) {
}
func (mz *mockedZoneWithRecords) LookupInaddr(inaddr string) ([]ZoneRecord, error) {
Debug.Printf("[mocked zone]: LookupInaddr: returning records %s", mz.records)
Log.Debugf("[mocked zone]: LookupInaddr: returning records %s", mz.records)
mz.Lock()
defer mz.Unlock()
@@ -243,17 +243,17 @@ func newZoneDbsWithMockedMDns(num int, config ZoneConfig) zoneDbsWithMockedMDns
for i := 0; i < num; i++ {
res[i] = new(zbmEntry)
Debug.Printf("[test] Creating mocked mDNS server #%d", i)
Log.Debugf("[test] Creating mocked mDNS server #%d", i)
res[i].Server = newMockedMDNSServer(nil)
Debug.Printf("[test] Creating mocked mDNS client #%d", i)
Log.Debugf("[test] Creating mocked mDNS client #%d", i)
res[i].Client = newMockedMDNSClient([]*mockedMDNSServer{})
cfg := config
cfg.MDNSClient = res[i].Client
cfg.MDNSServer = res[i].Server
Debug.Printf("[test] Creating ZoneDb #%d", i)
Log.Debugf("[test] Creating ZoneDb #%d", i)
res[i].Zone, _ = NewZoneDb(cfg)
// link the mDNS server to its zone
@@ -270,7 +270,7 @@ func newZoneDbsWithMockedMDns(num int, config ZoneConfig) zoneDbsWithMockedMDns
// this is not what we currently do, but can be convenient in some cases
// for finding some bugs...
if i != j {
Debug.Printf("[test] Linking mocked mDNS client #%d to server #%d", i, j)
Log.Debugf("[test] Linking mocked mDNS client #%d to server #%d", i, j)
res[i].Client.AddServer(res[j].Server)
}
}
@@ -389,7 +389,7 @@ func (mf *mockedFallback) Stop() error {
// Run a UDP fallback server
func runLocalUDPServer(laddr string, handler dns.HandlerFunc) (*dns.Server, string, error) {
Debug.Printf("[mocked fallback] Starting fallback UDP server at %s", laddr)
Log.Debugf("[mocked fallback] Starting fallback UDP server at %s", laddr)
pc, err := net.ListenPacket("udp", laddr)
if err != nil {
return nil, "", err
@@ -401,13 +401,13 @@ func runLocalUDPServer(laddr string, handler dns.HandlerFunc) (*dns.Server, stri
pc.Close()
}()
Debug.Printf("[mocked fallback] Fallback UDP server listening at %s", pc.LocalAddr())
Log.Debugf("[mocked fallback] Fallback UDP server listening at %s", pc.LocalAddr())
return server, pc.LocalAddr().String(), nil
}
// Run a TCP fallback server
func runLocalTCPServer(laddr string, handler dns.HandlerFunc) (*dns.Server, string, error) {
Debug.Printf("[mocked fallback] Starting fallback TCP server at %s", laddr)
Log.Debugf("[mocked fallback] Starting fallback TCP server at %s", laddr)
laddrTCP, err := net.ResolveTCPAddr("tcp", laddr)
if err != nil {
return nil, "", err
@@ -424,7 +424,7 @@ func runLocalTCPServer(laddr string, handler dns.HandlerFunc) (*dns.Server, stri
l.Close()
}()
Debug.Printf("[mocked fallback] Fallback TCP server listening at %s", l.Addr().String())
Log.Debugf("[mocked fallback] Fallback TCP server listening at %s", l.Addr().String())
return server, l.Addr().String(), nil
}
@@ -442,9 +442,9 @@ func newMockedClock() *mockedClock {
// be waiting in channels. So your code should not depend on the channels
// for creating new timers. Otherwise, time travelling will not be reliable...
func (clk *mockedClock) Forward(secs int) {
Debug.Printf(">>>>>>> Moving clock forward %d seconds - Time traveling >>>>>>>", secs)
Log.Debugf(">>>>>>> Moving clock forward %d seconds - Time traveling >>>>>>>", secs)
clk.Add(time.Duration(secs) * time.Second)
Debug.Printf("<<<<<<< Time travel finished! We are at %s <<<<<<<", clk.Now())
Log.Debugf("<<<<<<< Time travel finished! We are at %s <<<<<<<", clk.Now())
}
//////////////////////////////////////////////////////////////////
nameserver/server.go
+23 -22
View File
@@ -74,7 +74,7 @@ func (proto dnsProtocol) String() string {
// get a new dns.Client for a protocol
func (proto dnsProtocol) GetNewClient(bufsize int, timeout time.Duration) *dns.Client {
Debug.Printf("[dns] Creating %s DNS client with %s timeout", proto, timeout)
Log.Debugf("[dns] Creating %s DNS client with %s timeout", proto, timeout)
switch proto {
case protTCP:
return &dns.Client{Net: "tcp", ReadTimeout: timeout}
@@ -188,11 +188,11 @@ func NewDNSServer(config DNSServerConfig) (s *DNSServer, err error) {
// Start the DNS server
func (s *DNSServer) Start() error {
Info.Printf("[dns] Upstream server(s): %+v", s.Upstream)
Log.Infof("[dns] Upstream server(s): %+v", s.Upstream)
if s.cacheDisabled {
Info.Printf("[dns] Cache: disabled")
Log.Infof("[dns] Cache: disabled")
} else {
Info.Printf("[dns] Cache: %d entries", s.cache.Capacity())
Log.Infof("[dns] Cache: %d entries", s.cache.Capacity())
}
pc, err := net.ListenPacket("udp", s.ListenAddr)
@@ -225,25 +225,25 @@ func (s *DNSServer) ActivateAndServe() {
go func() {
defer s.listenersWg.Done()
Info.Printf("[dns] Listening for DNS on %s (UDP)", s.ListenAddr)
Log.Infof("[dns] Listening for DNS on %s (UDP)", s.ListenAddr)
err := s.udpSrv.ActivateAndServe()
CheckFatal(err)
Debug.Printf("[dns] DNS UDP server exiting...")
Log.Debugf("[dns] DNS UDP server exiting...")
}()
go func() {
defer s.listenersWg.Done()
Info.Printf("[dns] Listening for DNS on %s (TCP)", s.ListenAddr)
Log.Infof("[dns] Listening for DNS on %s (TCP)", s.ListenAddr)
err := s.tcpSrv.ActivateAndServe()
CheckFatal(err)
Debug.Printf("[dns] DNS TCP server exiting...")
Log.Debugf("[dns] DNS TCP server exiting...")
}()
// Waiting for all goroutines to finish (otherwise they die as main routine dies)
s.listenersWg.Wait()
Info.Printf("[dns] Server exiting...")
Log.Infof("[dns] Server exiting...")
}
// Return status string
@@ -284,7 +284,7 @@ func (s *DNSServer) createMux(proto dnsProtocol) *dns.ServeMux {
}
notUsHandler := s.notUsHandler(proto)
notUsFallback := func(w dns.ResponseWriter, r *dns.Msg) {
Info.Printf("[dns msgid %d] -> sending to fallback server", r.MsgHdr.Id)
Log.Infof("[dns msgid %d] -> sending to fallback server", r.MsgHdr.Id)
notUsHandler(w, r)
}
@@ -305,7 +305,7 @@ func (s *DNSServer) localHandler(proto dnsProtocol, kind string, qtype uint16,
return func(w dns.ResponseWriter, r *dns.Msg) {
q := r.Question[0]
Debug.Printf("[dns msgid %d] %s: %+v", r.MsgHdr.Id, kind, q)
Log.Debugf("[dns msgid %d] %s: %+v", r.MsgHdr.Id, kind, q)
maxLen := getMaxReplyLen(r, proto)
// cache a response if the cache is enabled, and observe the name/IP
@@ -324,17 +324,17 @@ func (s *DNSServer) localHandler(proto dnsProtocol, kind string, qtype uint16,
reply, err := s.cache.Get(r, maxLen)
if err != nil {
if err == errNoLocalReplies {
Debug.Printf("[dns msgid %d] Cached no-local-replies", r.MsgHdr.Id)
Log.Debugf("[dns msgid %d] Cached no-local-replies", r.MsgHdr.Id)
fallback(w, r)
} else {
Debug.Printf("[dns msgid %d] Error from cache: %s", r.MsgHdr.Id, err)
Log.Debugf("[dns msgid %d] Error from cache: %s", r.MsgHdr.Id, err)
w.WriteMsg(makeDNSFailResponse(r))
}
return
}
if reply != nil {
reply.Answer = pruneAnswers(shuffleAnswers(reply.Answer), s.maxAnswers)
Debug.Printf("[dns msgid %d] Returning reply from cache: %s/%d answers",
Log.Debugf("[dns msgid %d] Returning reply from cache: %s/%d answers",
r.MsgHdr.Id, dns.RcodeToString[reply.MsgHdr.Rcode], len(reply.Answer))
w.WriteMsg(reply)
return
@@ -343,7 +343,7 @@ func (s *DNSServer) localHandler(proto dnsProtocol, kind string, qtype uint16,
// catch unsupported queries
if q.Qtype != qtype {
Debug.Printf("[dns msgid %d] Unsupported query type %s", r.MsgHdr.Id, dns.TypeToString[q.Qtype])
Log.Debugf("[dns msgid %d] Unsupported query type %s", r.MsgHdr.Id, dns.TypeToString[q.Qtype])
m := makeDNSFailResponse(r)
maybeCache(m, s.negLocalTTL, 0)
w.WriteMsg(m)
@@ -351,8 +351,9 @@ func (s *DNSServer) localHandler(proto dnsProtocol, kind string, qtype uint16,
}
if answers, err := lookup(q.Name); err != nil {
Info.Printf("[dns msgid %d] No results for type %s query for '%s' [caching no-local]",
Log.Infof("[dns msgid %d] No results for type %s query for '%s' [caching no-local]",
r.MsgHdr.Id, dns.TypeToString[q.Qtype], q.Name)
maybeCache(nil, s.negLocalTTL, CacheNoLocalReplies)
fallback(w, r)
} else {
@@ -360,7 +361,7 @@ func (s *DNSServer) localHandler(proto dnsProtocol, kind string, qtype uint16,
m.Authoritative = true
maybeCache(m, nullTTL, 0)
m.Answer = pruneAnswers(shuffleAnswers(m.Answer), s.maxAnswers)
Debug.Printf("[dns msgid %d] Sending response: %s/%d answers [code:%s]",
Log.Debugf("[dns msgid %d] Sending response: %s/%d answers [code:%s]",
m.MsgHdr.Id, dns.TypeToString[q.Qtype], len(m.Answer), dns.RcodeToString[m.Rcode])
w.WriteMsg(m)
}
@@ -380,25 +381,25 @@ func (s *DNSServer) notUsHandler(proto dnsProtocol) dns.HandlerFunc {
rcopy := r
rcopy.SetEdns0(uint16(maxLen), false)
Debug.Printf("[dns msgid %d] Fallback query: %+v [%s, max:%d bytes]", rcopy.MsgHdr.Id, q, proto, maxLen)
Log.Debugf("[dns msgid %d] Fallback query: %+v [%s, max:%d bytes]", rcopy.MsgHdr.Id, q, proto, maxLen)
for _, server := range s.Upstream.Servers {
reply, _, err := dnsClient.Exchange(rcopy, fmt.Sprintf("%s:%s", server, s.Upstream.Port))
if err != nil {
Debug.Printf("[dns msgid %d] Network error trying %s (%s)",
Log.Debugf("[dns msgid %d] Network error trying %s (%s)",
r.MsgHdr.Id, server, err)
continue
}
if reply != nil && reply.Rcode != dns.RcodeSuccess {
Debug.Printf("[dns msgid %d] Failure reported by %s for query %s",
Log.Debugf("[dns msgid %d] Failure reported by %s for query %s",
r.MsgHdr.Id, server, q.Name)
continue
}
Debug.Printf("[dns msgid %d] Given answer by %s for query %s",
Log.Debugf("[dns msgid %d] Given answer by %s for query %s",
r.MsgHdr.Id, server, q.Name)
w.WriteMsg(reply)
return
}
Warning.Printf("[dns msgid %d] Failed lookup for external name %s", r.MsgHdr.Id, q.Name)
Log.Warningf("[dns msgid %d] Failed lookup for external name %s", r.MsgHdr.Id, q.Name)
w.WriteMsg(makeDNSFailResponse(r))
}
}
nameserver/server_cache_test.go
+25 -25
View File
@@ -20,15 +20,15 @@ func TestServerDbCacheInvalidation(t *testing.T) {
)
InitDefaultLogging(testing.Verbose())
Info.Println("TestServerDbCacheInvalidation starting")
Log.Infoln("TestServerDbCacheInvalidation starting")
clk := newMockedClock()
Debug.Printf("Creating mocked mDNS client and server")
Log.Debugf("Creating mocked mDNS client and server")
mdnsServer1 := newMockedMDNSServerWithRecord(Record{testName1, net.ParseIP("10.2.2.9"), 0, 0, 0})
mdnsCli1 := newMockedMDNSClient([]*mockedMDNSServer{mdnsServer1})
Debug.Printf("Creating zone database with the mocked mDNS client and server")
Log.Debugf("Creating zone database with the mocked mDNS client and server")
zoneConfig := ZoneConfig{
MDNSServer: mdnsServer1,
MDNSClient: mdnsCli1,
@@ -40,7 +40,7 @@ func TestServerDbCacheInvalidation(t *testing.T) {
require.NoError(t, err)
defer zone.Stop()
Debug.Printf("Creating a cache")
Log.Debugf("Creating a cache")
cache, err := NewCache(1024, clk)
require.NoError(t, err)
@@ -59,7 +59,7 @@ func TestServerDbCacheInvalidation(t *testing.T) {
fallback.Start()
defer fallback.Stop()
Debug.Printf("Creating a real DNS server with a mocked cache")
Log.Debugf("Creating a real DNS server with a mocked cache")
srv, err := NewDNSServer(DNSServerConfig{
Zone: zone,
Cache: cache,
@@ -79,7 +79,7 @@ func TestServerDbCacheInvalidation(t *testing.T) {
require.NoError(t, err)
require.NotEqual(t, 0, testPort, "invalid listen port")
Debug.Printf("Adding two IPs to %s", testName1)
Log.Debugf("Adding two IPs to %s", testName1)
zone.AddRecord(containerID, testName1, net.ParseIP("10.2.2.1"))
zone.AddRecord(containerID, testName1, net.ParseIP("10.2.2.2"))
q, _ := assertExchange(t, testName1, dns.TypeA, testPort, 2, 2, 0)
@@ -93,7 +93,7 @@ func TestServerDbCacheInvalidation(t *testing.T) {
// we should have an entry in the cache for this query
// if we add another IP, that cache entry should be removed
Debug.Printf("Adding a new IP to %s: the cache entry should be removed", testName1)
Log.Debugf("Adding a new IP to %s: the cache entry should be removed", testName1)
zone.AddRecord(containerID, testName1, net.ParseIP("10.2.2.3"))
assertNotInCache(t, cache, q, fmt.Sprintf("after adding a new IP for %s", testName1))
@@ -101,10 +101,10 @@ func TestServerDbCacheInvalidation(t *testing.T) {
// first.weave.local = 10.2.2.1 10.2.2.2 10.2.2.3
// second.weave.local = 10.9.9.1
Debug.Printf("Querying again (so a cache entry will be created)")
Log.Debugf("Querying again (so a cache entry will be created)")
q, _ = assertExchange(t, testName1, dns.TypeA, testPort, 3, 4, 0)
assertInCache(t, cache, q, "after asking about the name")
Debug.Printf("... and removing one of the IP addresses")
Log.Debugf("... and removing one of the IP addresses")
zone.DeleteRecords(containerID, "", net.ParseIP("10.2.2.2"))
assertNotInCache(t, cache, q, "after deleting IP for 10.2.2.2")
@@ -113,7 +113,7 @@ func TestServerDbCacheInvalidation(t *testing.T) {
// second.weave.local = 10.9.9.1
// generate cache responses
Debug.Printf("Querying for a raddr")
Log.Debugf("Querying for a raddr")
qname, _ := assertExchange(t, testName1, dns.TypeA, testPort, 2, 2, 0)
qptr, _ := assertExchange(t, "1.2.2.10.in-addr.arpa.", dns.TypePTR, testPort, 1, 1, 0)
qotherName, _ := assertExchange(t, testName2, dns.TypeA, testPort, 1, 1, 0)
@@ -126,7 +126,7 @@ func TestServerDbCacheInvalidation(t *testing.T) {
assertNotLocalInCache(t, cache, qwrongName, "after asking for a wrong name")
// now we will check if a removal affects all the responses
Debug.Printf("... and removing an IP should invalidate both the cached responses for name and raddr")
Log.Debugf("... and removing an IP should invalidate both the cached responses for name and raddr")
zone.DeleteRecords(containerID, "", net.ParseIP("10.2.2.1"))
assertNotInCache(t, cache, qptr, "after deleting record")
assertNotInCache(t, cache, qname, "after deleting record")
@@ -137,7 +137,7 @@ func TestServerDbCacheInvalidation(t *testing.T) {
// second.weave.local = 10.9.9.1
// generate cache responses
Debug.Printf("Querying for a raddr")
Log.Debugf("Querying for a raddr")
qptr, _ = assertExchange(t, "3.2.2.10.in-addr.arpa.", dns.TypePTR, testPort, 1, 1, 0)
qname, _ = assertExchange(t, testName1, dns.TypeA, testPort, 1, 1, 0)
qotherName, _ = assertExchange(t, testName2, dns.TypeA, testPort, 1, 1, 0)
@@ -148,7 +148,7 @@ func TestServerDbCacheInvalidation(t *testing.T) {
assertInCache(t, cache, qotherPtr, "after asking for second address")
// let's repeat this, but adding an IP
Debug.Printf("... and adding a new IP should invalidate both the cached responses for the name")
Log.Debugf("... and adding a new IP should invalidate both the cached responses for the name")
zone.AddRecord(containerID, testName1, net.ParseIP("10.2.2.7"))
assertNotInCache(t, cache, qname, "after adding a new IP")
assertInCache(t, cache, qotherName, "after adding a new IP")
@@ -178,11 +178,11 @@ func TestServerCacheExpiration(t *testing.T) {
)
InitDefaultLogging(testing.Verbose())
Info.Println("TestServerCacheExpiration starting")
Log.Infoln("TestServerCacheExpiration starting")
clk := newMockedClock()
Debug.Printf("Creating 2 zone databases")
Log.Debugf("Creating 2 zone databases")
zoneConfig := ZoneConfig{
RefreshInterval: 0, // no name updates
Clock: clk,
@@ -191,11 +191,11 @@ func TestServerCacheExpiration(t *testing.T) {
dbs.Start()
defer dbs.Stop()
Debug.Printf("Creating a cache")
Log.Debugf("Creating a cache")
cache, err := NewCache(1024, clk)
require.NoError(t, err)
Debug.Printf("Creating a real DNS server for the first zone database and with the cache")
Log.Debugf("Creating a real DNS server for the first zone database and with the cache")
srv, err := NewDNSServer(DNSServerConfig{
Zone: dbs[0].Zone,
Cache: cache,
@@ -225,7 +225,7 @@ func TestServerCacheExpiration(t *testing.T) {
assertNotInCache(t, cache, qName1, fmt.Sprintf("after asking for %s", testName1))
// We add the IP in the second peer right after
Debug.Printf("Adding an IPs to %s in database #2", testName1)
Log.Debugf("Adding an IPs to %s in database #2", testName1)
dbs[1].Zone.AddRecord(containerID, testName1, net.ParseIP("10.2.2.1"))
t.Logf("Zone database #2:\n%s", dbs[1].Zone)
@@ -241,7 +241,7 @@ func TestServerCacheExpiration(t *testing.T) {
assertNotInCache(t, cache, qName1, fmt.Sprintf("after asking for %s", testName1))
// We delete the IP in the second peer right after
Debug.Printf("Removing the IPs from %s in database #2", testName1)
Log.Debugf("Removing the IPs from %s in database #2", testName1)
dbs[1].Zone.DeleteRecords(containerID, "", net.ParseIP("10.2.2.1"))
// Check that we return to the initial state: a neg-local entry in the cache
@@ -266,10 +266,10 @@ func TestServerCacheRefresh(t *testing.T) {
)
InitDefaultLogging(testing.Verbose())
Info.Println("TestServerCacheRefresh starting")
Log.Infoln("TestServerCacheRefresh starting")
clk := newMockedClock()
Debug.Printf("Creating 2 zone databases")
Log.Debugf("Creating 2 zone databases")
zoneConfig := ZoneConfig{
RefreshInterval: refreshInterval,
Clock: clk,
@@ -278,11 +278,11 @@ func TestServerCacheRefresh(t *testing.T) {
dbs.Start()
defer dbs.Stop()
Debug.Printf("Creating a cache")
Log.Debugf("Creating a cache")
cache, err := NewCache(1024, clk)
require.NoError(t, err)
Debug.Printf("Creating a real DNS server for the first zone database and with the cache")
Log.Debugf("Creating a real DNS server for the first zone database and with the cache")
srv, err := NewDNSServer(DNSServerConfig{
Zone: dbs[0].Zone,
Cache: cache,
@@ -301,7 +301,7 @@ func TestServerCacheRefresh(t *testing.T) {
require.NoError(t, err)
require.NotEqual(t, 0, testPort, "listen port")
Debug.Printf("Adding an IPs to %s", testName1)
Log.Debugf("Adding an IPs to %s", testName1)
dbs[1].Zone.AddRecord(containerID, testName1, net.ParseIP("10.2.2.1"))
dbs.Flush() // ensure the immediate refresh is done
@@ -317,7 +317,7 @@ func TestServerCacheRefresh(t *testing.T) {
clk.Forward(refreshInterval / 2)
dbs.Flush()
Debug.Printf("Adding an IP to %s and to %s", testName1, testName2)
Log.Debugf("Adding an IP to %s and to %s", testName1, testName2)
dbs[1].Zone.AddRecord(containerID, testName1, net.ParseIP("10.2.2.2"))
dbs[1].Zone.AddRecord(containerID, testName2, net.ParseIP("10.9.9.2"))
nameserver/server_test.go
+2 -2
View File
@@ -41,7 +41,7 @@ func TestUDPDNSServer(t *testing.T) {
testCIDR1 := testAddr1 + "/24"
InitDefaultLogging(testing.Verbose())
Info.Println("TestUDPDNSServer starting")
Log.Infoln("TestUDPDNSServer starting")
zone, err := NewZoneDb(ZoneConfig{})
require.NoError(t, err)
@@ -138,7 +138,7 @@ func TestTCPDNSServer(t *testing.T) {
)
InitDefaultLogging(testing.Verbose())
Info.Println("TestTCPDNSServer starting")
Log.Infoln("TestTCPDNSServer starting")
zone, err := NewZoneDb(ZoneConfig{})
require.NoError(t, err)
nameserver/zone.go
+9 -9
View File
@@ -111,7 +111,7 @@ func (re *recordEntry) addIPObserver(zro ZoneRecordObserver) {
func (re *recordEntry) notifyIPObservers() {
numObservers := len(re.observers)
if numObservers > 0 {
Debug.Printf("[zonedb] Notifying %d observers of '%s'", numObservers, re.ip)
Log.Debugf("[zonedb] Notifying %d observers of '%s'", numObservers, re.ip)
for _, observer := range re.observers {
observer()
}
@@ -257,7 +257,7 @@ func (n *name) addNameObserver(observer ZoneRecordObserver) {
func (n *name) notifyNameObservers() {
numObservers := len(n.observers)
if numObservers > 0 {
Debug.Printf("[zonedb] Notifying %d observers of '%s'", numObservers, n.name)
Log.Debugf("[zonedb] Notifying %d observers of '%s'", numObservers, n.name)
for _, observer := range n.observers {
observer()
}
@@ -373,7 +373,7 @@ func (ns *nameSet) getNameLastAccess(n string) time.Time {
// The access time is saved only for locally-introduced records (otherwise it could
// be lost when names are irrelevant...)
func (ns *nameSet) touchName(name string, now time.Time) {
Debug.Printf("[zonedb] Touching name %s", name)
Log.Debugf("[zonedb] Touching name %s", name)
n := ns.getName(name, false)
if n != nil {
n.lastAccessTime = now
@@ -506,9 +506,9 @@ func NewZoneDb(config ZoneConfig) (zone *ZoneDb, err error) {
// Start the zone database
func (zone *ZoneDb) Start() (err error) {
if zone.iface != nil {
Info.Printf("[zonedb] Using mDNS on %+v", zone.iface)
Log.Infof("[zonedb] Using mDNS on %+v", zone.iface)
} else {
Info.Printf("[zonedb] Using mDNS on all interfaces")
Log.Infof("[zonedb] Using mDNS on all interfaces")
}
if err = zone.mdnsCli.Start(zone.iface); err != nil {
@@ -527,11 +527,11 @@ func (zone *ZoneDb) Start() (err error) {
// Perform a graceful shutdown of the zone database
func (zone *ZoneDb) Stop() error {
if zone.refreshInterval > 0 {
Debug.Printf("[zonedb] Closing background updaters...")
Log.Debugf("[zonedb] Closing background updaters...")
zone.refreshScheds.Stop()
}
Debug.Printf("[zonedb] Exiting mDNS client and server...")
Log.Debugf("[zonedb] Exiting mDNS client and server...")
zone.mdnsCli.Stop()
zone.mdnsSrv.Stop()
return nil
@@ -555,7 +555,7 @@ func (zone *ZoneDb) Status() string {
func (zone *ZoneDb) AddRecord(ident string, name string, ip net.IP) (err error) {
zone.mx.Lock()
defer zone.mx.Unlock()
Debug.Printf("[zonedb] Adding record: '%s'/'%s'[%s]", ident, name, ip)
Log.Debugf("[zonedb] Adding record: '%s'/'%s'[%s]", ident, name, ip)
record := Record{dns.Fqdn(name), ip, 0, 0, 0}
_, err = zone.getNameSet(ident).addIPToName(record, zone.clock.Now())
return
@@ -638,7 +638,7 @@ func (zone *ZoneDb) String() string {
// Notify that a container has died
func (zone *ZoneDb) ContainerDied(ident string) error {
Info.Printf("[zonedb] Container %s down. Removing records", ident)
Log.Infof("[zonedb] Container %s down. Removing records", ident)
zone.DeleteRecords(ident, "", net.IP{})
return nil
}
nameserver/zone_lookup.go
+18 -18
View File
@@ -63,7 +63,7 @@ func (zone *ZoneDb) LookupName(name string) (res []ZoneRecord, err error) {
// note: LookupName() is usually called from the mDNS server, so we do not touch the name
name = dns.Fqdn(name)
Debug.Printf("[zonedb] Looking for name '%s' in local database", name)
Log.Debugf("[zonedb] Looking for name '%s' in local database", name)
return zone.lookup(name, func(ns *nameSet) []*recordEntry { return ns.getEntriesForName(name) })
}
@@ -78,23 +78,23 @@ func (zone *ZoneDb) LookupInaddr(inaddr string) (res []ZoneRecord, err error) {
if err != nil {
return nil, newParseError("lookup address", inaddr)
}
Debug.Printf("[zonedb] Looking for address in local database: '%s' (%s)", revIPv4, inaddr)
Log.Debugf("[zonedb] Looking for address in local database: '%s' (%s)", revIPv4, inaddr)
return zone.lookup(inaddr, func(ns *nameSet) []*recordEntry { return ns.getEntriesForIP(revIPv4) })
}
// Perform a domain lookup with mDNS
func (zone *ZoneDb) domainLookup(target string, lfun ZoneLookupFunc) (res []ZoneRecord, err error) {
// no local results have been obtained in the local database: try with a mDNS query
Debug.Printf("[zonedb] '%s' not in local database... trying with mDNS", target)
Log.Debugf("[zonedb] '%s' not in local database... trying with mDNS", target)
lanswers, err := lfun(target)
if err != nil {
Debug.Printf("[zonedb] mDNS lookup error for '%s': %s", target, err)
Log.Debugf("[zonedb] mDNS lookup error for '%s': %s", target, err)
return nil, err
}
// if the request has been successful, save the IP in the local database and return the corresponding ZoneRecord
// (we do not get the remote ident in the mDNS reply, so we save it in a "remote" ident)
Debug.Printf("[zonedb] adding '%s' (obtained with mDNS) to '%s'", lanswers, target)
Log.Debugf("[zonedb] adding '%s' (obtained with mDNS) to '%s'", lanswers, target)
res = make([]ZoneRecord, len(lanswers))
zone.mx.Lock()
now := zone.clock.Now()
@@ -104,7 +104,7 @@ func (zone *ZoneDb) domainLookup(target string, lfun ZoneLookupFunc) (res []Zone
r, err := remoteIdent.addIPToName(answer, now)
if err != nil {
zone.mx.Unlock()
Warning.Printf("[zonedb] '%s' insertion for %s failed: %s", answer, target, err)
Log.Warningf("[zonedb] '%s' insertion for %s failed: %s", answer, target, err)
return nil, err
}
uniq.add(r)
@@ -118,7 +118,7 @@ func (zone *ZoneDb) domainLookup(target string, lfun ZoneLookupFunc) (res []Zone
// The name can be resolved locally with the local database or with some other resolution method (eg, a mDNS query)
func (zone *ZoneDb) DomainLookupName(name string) (res []ZoneRecord, err error) {
name = dns.Fqdn(name)
Debug.Printf("[zonedb] Looking for name '%s' in local(&remote) database", name)
Log.Debugf("[zonedb] Looking for name '%s' in local(&remote) database", name)
zone.mx.Lock()
now := zone.clock.Now()
@@ -128,7 +128,7 @@ func (zone *ZoneDb) DomainLookupName(name string) (res []ZoneRecord, err error)
// filter the entries with expired TTL
// locally introduced entries are never expired: they always have TTL=0
if ze.hasExpired(now) {
Debug.Printf("[zonedb] '%s': expired entry '%s' ignored: removing", name, ze)
Log.Debugf("[zonedb] '%s': expired entry '%s' ignored: removing", name, ze)
nameset.deleteNameIP(name, net.IP{})
} else {
uniq.add(ze)
@@ -141,7 +141,7 @@ func (zone *ZoneDb) DomainLookupName(name string) (res []ZoneRecord, err error)
zone.mx.Unlock()
if len(uniq) > 0 {
Debug.Printf("[zonedb] '%s' resolved in local database", name)
Log.Debugf("[zonedb] '%s' resolved in local database", name)
res = uniq.toSlice()
} else {
res, err = zone.domainLookup(name, zone.mdnsCli.LookupName)
@@ -163,7 +163,7 @@ func (zone *ZoneDb) DomainLookupInaddr(inaddr string) (res []ZoneRecord, err err
return nil, newParseError("lookup address", inaddr)
}
Debug.Printf("[zonedb] Looking for address in local(&remote) database: '%s' (%s)", revIPv4, inaddr)
Log.Debugf("[zonedb] Looking for address in local(&remote) database: '%s' (%s)", revIPv4, inaddr)
zone.mx.Lock()
now := zone.clock.Now()
@@ -173,7 +173,7 @@ func (zone *ZoneDb) DomainLookupInaddr(inaddr string) (res []ZoneRecord, err err
// filter the entries with expired TTL
// locally introduced entries are never expired: they always have TTL=0
if ze.hasExpired(now) {
Debug.Printf("[zonedb] '%s': expired entry '%s' ignored: removing", revIPv4, ze)
Log.Debugf("[zonedb] '%s': expired entry '%s' ignored: removing", revIPv4, ze)
nameset.deleteNameIP("", revIPv4.toNetIP())
} else {
uniq.add(ze)
@@ -186,7 +186,7 @@ func (zone *ZoneDb) DomainLookupInaddr(inaddr string) (res []ZoneRecord, err err
zone.mx.Unlock()
if len(uniq) > 0 {
Debug.Printf("[zonedb] '%s' resolved in local database", inaddr)
Log.Debugf("[zonedb] '%s' resolved in local database", inaddr)
res = uniq.toSlice()
} else {
res, err = zone.domainLookup(inaddr, zone.mdnsCli.LookupInaddr)
@@ -243,7 +243,7 @@ func (zone *ZoneDb) startUpdatingName(name string) {
n.lastRefreshTime = now
zone.mx.Unlock()
Debug.Printf("[zonedb] Creating new immediate refresh request for '%s'", name)
Log.Debugf("[zonedb] Creating new immediate refresh request for '%s'", name)
zone.refreshScheds.Add(func() time.Time { return zone.updater(name) }, now)
} else {
zone.mx.Unlock()
@@ -261,7 +261,7 @@ func (zone *ZoneDb) updater(name string) (nextTime time.Time) {
// if nobody has asked for this name for long time, just forget about it...
if !zone.IsNameRelevant(name) || zone.IsNameExpired(name) {
Debug.Printf("[zonedb] '%s' seem to be irrelevant now: removing any remote information", name)
Log.Debugf("[zonedb] '%s' seem to be irrelevant now: removing any remote information", name)
deleteRemoteInfo()
return
}
@@ -269,7 +269,7 @@ func (zone *ZoneDb) updater(name string) (nextTime time.Time) {
// perform the refresh for this name
fullName := dns.Fqdn(name)
startTime := zone.clock.Now()
Debug.Printf("[zonedb] Refreshing name '%s' with mDNS...", fullName)
Log.Debugf("[zonedb] Refreshing name '%s' with mDNS...", fullName)
res, _ := zone.mdnsCli.InsistentLookupName(fullName)
if res != nil && len(res) > 0 {
numIps := len(res)
@@ -277,14 +277,14 @@ func (zone *ZoneDb) updater(name string) (nextTime time.Time) {
now := zone.clock.Now()
added, removed := zone.getNameSet(defaultRemoteIdent).getName(name, true).updateIPs(res, now)
zone.mx.Unlock()
Debug.Printf("[zonedb] Obtained %d IPs for name '%s' with mDNS: %d added, %d removed",
Log.Debugf("[zonedb] Obtained %d IPs for name '%s' with mDNS: %d added, %d removed",
numIps, name, added, removed)
// once the name has been updated, we re-schedule the update
nextTime = startTime.Add(zone.refreshInterval)
Debug.Printf("[zonedb] Rescheduling update for '%s' in %s", name, nextTime.Sub(zone.clock.Now()))
Log.Debugf("[zonedb] Rescheduling update for '%s' in %s", name, nextTime.Sub(zone.clock.Now()))
} else {
Debug.Printf("[zonedb] nobody knows about '%s'... removing", name)
Log.Debugf("[zonedb] nobody knows about '%s'... removing", name)
deleteRemoteInfo()
}
return
nameserver/zone_lookup_test.go
+22 -22
View File
@@ -24,7 +24,7 @@ func TestZoneRefresh(t *testing.T) {
)
InitDefaultLogging(testing.Verbose())
Info.Println("TestZoneRefresh starting")
Log.Infoln("TestZoneRefresh starting")
clk := newMockedClock()
@@ -40,77 +40,77 @@ func TestZoneRefresh(t *testing.T) {
time.Sleep(100 * time.Millisecond) // allow for server to get going
Debug.Printf("Adding '%s' to Db #1", name)
Log.Debugf("Adding '%s' to Db #1", name)
dbs[0].Zone.AddRecord("someident", name, net.ParseIP(addr1))
Debug.Printf("Checking that the name %s is relevant (as it has been locally inserted) and not remote", name)
Log.Debugf("Checking that the name %s is relevant (as it has been locally inserted) and not remote", name)
require.True(t, dbs[0].Zone.IsNameRelevant(name), "name relevant")
require.True(t, dbs[0].Zone.HasNameLocalInfo(name), "local name info")
require.False(t, dbs[0].Zone.HasNameRemoteInfo(name), "remote name info")
Debug.Printf("Asking for '%s' to Db #1: should get 1 IP from the local database...", name)
Log.Debugf("Asking for '%s' to Db #1: should get 1 IP from the local database...", name)
res, err := dbs[0].Zone.DomainLookupName(name)
require.NoError(t, err)
Debug.Printf("Got: %s", res)
Log.Debugf("Got: %s", res)
t.Logf("Db #1 after the lookup:\n%s", dbs[0].Zone)
require.Equal(t, 1, len(res), "lookup result")
clk.Forward(refreshInterval / 2)
dbs.Flush()
Debug.Printf("A couple of seconds later, we should still have one IP for that name")
Log.Debugf("A couple of seconds later, we should still have one IP for that name")
res, err = dbs[0].Zone.DomainLookupName(name)
require.NoError(t, err)
require.Equal(t, 1, len(res), "lookup result")
Debug.Printf("And then we add 2 IPs for that name at ZoneDb 2")
Log.Debugf("And then we add 2 IPs for that name at ZoneDb 2")
clk.Forward(1)
dbs.Flush()
Debug.Printf("Adding 2 IPs to '%s' in Db #2", name)
Log.Debugf("Adding 2 IPs to '%s' in Db #2", name)
dbs[1].Zone.AddRecord("someident", name, net.ParseIP(addr2))
dbs[1].Zone.AddRecord("someident", name, net.ParseIP(addr3))
Debug.Printf("Perform a lookup, to ensure the name will be updated in the background...")
Log.Debugf("Perform a lookup, to ensure the name will be updated in the background...")
dbs[0].Zone.DomainLookupName(name)
Debug.Printf("Wait for a while, until a refresh is performed...")
Log.Debugf("Wait for a while, until a refresh is performed...")
clk.Forward(refreshInterval + 1)
dbs.Flush()
Debug.Printf("A refresh should have been scheduled now: we should have 3 IPs:")
Debug.Printf("the first (local) IP and the others obtained from zone2 with a mDNS query")
Debug.Printf("Asking for '%s' again... we should have 3 IPs now", name)
Log.Debugf("A refresh should have been scheduled now: we should have 3 IPs:")
Log.Debugf("the first (local) IP and the others obtained from zone2 with a mDNS query")
Log.Debugf("Asking for '%s' again... we should have 3 IPs now", name)
res, err = dbs[0].Zone.DomainLookupName(name)
Debug.Printf("Got: %s", res)
Log.Debugf("Got: %s", res)
t.Logf("Db #1 after the second lookup:\n%s", dbs[0].Zone)
require.Equal(t, 3, len(res), "lookup result length")
Debug.Printf("We will not ask for `name` for a while, so it will become irrelevant and will be removed...")
Log.Debugf("We will not ask for `name` for a while, so it will become irrelevant and will be removed...")
clk.Forward(refreshInterval + relevantTime + 1)
dbs.Flush()
// the name should be irrelevant now, and all remote info should have been
// removed from the zone database
Debug.Printf("Name '%s' should not be in the remote database in ZoneDb 1", name)
Log.Debugf("Name '%s' should not be in the remote database in ZoneDb 1", name)
require.False(t, dbs[0].Zone.IsNameRelevant(name), "name still relevant after some inactivity time")
require.True(t, dbs[0].Zone.HasNameLocalInfo(name), "local name info")
require.False(t, dbs[0].Zone.HasNameRemoteInfo(name), "remote name info")
Debug.Printf("There is no remote info about this name at zone 1: a new IP appears remotely meanwhile...")
Log.Debugf("There is no remote info about this name at zone 1: a new IP appears remotely meanwhile...")
clk.Forward(1)
dbs.Flush()
Debug.Printf("Adding '%s' to Db #2", name)
Log.Debugf("Adding '%s' to Db #2", name)
dbs[1].Zone.AddRecord("someident", name, net.ParseIP(addr4))
Debug.Printf("When we ask about this name again, we get 4 IPs (1 local, 3 remote)")
Debug.Printf("Asking for '%s' again... the first lookup will return only the local results", name)
Log.Debugf("When we ask about this name again, we get 4 IPs (1 local, 3 remote)")
Log.Debugf("Asking for '%s' again... the first lookup will return only the local results", name)
res, err = dbs[0].Zone.DomainLookupName(name)
require.Equal(t, 1, len(res), "lookup result length")
Debug.Printf("... but a second lookup should return all the results in the network")
Log.Debugf("... but a second lookup should return all the results in the network")
clk.Forward(refreshInterval + 1)
dbs.Flush()
res, err = dbs[0].Zone.DomainLookupName(name)
Debug.Printf("Got: %s", res)
Log.Debugf("Got: %s", res)
require.Equal(t, 4, len(res), "lookup result length")
}
prog/weavedns/main.go
+20 -20
View File
@@ -71,17 +71,17 @@ func main() {
}
InitDefaultLogging(debug)
Info.Printf("[main] WeaveDNS version %s\n", version) // first thing in log: the version
Log.Infof("[main] WeaveDNS version %s\n", version) // first thing in log: the version
var iface *net.Interface
if ifaceName != "" {
var err error
Info.Println("[main] Waiting for mDNS interface", ifaceName, "to come up")
Log.Infoln("[main] Waiting for mDNS interface", ifaceName, "to come up")
iface, err = weavenet.EnsureInterface(ifaceName, wait)
if err != nil {
Error.Fatal(err)
Log.Fatal(err)
} else {
Info.Println("[main] Interface", ifaceName, "is up")
Log.Infoln("[main] Interface", ifaceName, "is up")
}
}
@@ -89,25 +89,25 @@ func main() {
if httpIfaceName == "" {
httpIP = "0.0.0.0"
} else {
Info.Println("[main] Waiting for HTTP interface", httpIfaceName, "to come up")
Log.Infoln("[main] Waiting for HTTP interface", httpIfaceName, "to come up")
httpIface, err := weavenet.EnsureInterface(httpIfaceName, wait)
if err != nil {
Error.Fatal(err)
Log.Fatal(err)
}
Info.Println("[main] Interface", httpIfaceName, "is up")
Log.Infoln("[main] Interface", httpIfaceName, "is up")
addrs, err := httpIface.Addrs()
if err != nil {
Error.Fatal(err)
Log.Fatal(err)
}
if len(addrs) == 0 {
Error.Fatal("[main] No addresses on HTTP interface")
Log.Fatal("[main] No addresses on HTTP interface")
}
ip, _, err := net.ParseCIDR(addrs[0].String())
if err != nil {
Error.Fatal(err)
Log.Fatal(err)
}
httpIP = ip.String()
@@ -124,22 +124,22 @@ func main() {
}
zone, err := weavedns.NewZoneDb(zoneConfig)
if err != nil {
Error.Fatal("[main] Unable to initialize the Zone database", err)
Log.Fatal("[main] Unable to initialize the Zone database", err)
}
if err := zone.Start(); err != nil {
Error.Fatal("[main] Unable to start the Zone database", err)
Log.Fatal("[main] Unable to start the Zone database", err)
}
defer zone.Stop()
dockerCli, err = docker.NewClient(apiPath)
if err != nil {
Error.Fatal("[main] Unable to start docker client: ", err)
Log.Fatal("[main] Unable to start docker client: ", err)
}
if watch {
err := dockerCli.AddObserver(zone)
if err != nil {
Error.Fatal("[main] Unable to start watcher", err)
Log.Fatal("[main] Unable to start watcher", err)
}
}
@@ -158,29 +158,29 @@ func main() {
if len(fallback) > 0 {
fallbackHost, fallbackPort, err := net.SplitHostPort(fallback)
if err != nil {
Error.Fatal("[main] Could not parse fallback host and port", err)
Log.Fatal("[main] Could not parse fallback host and port", err)
}
srvConfig.UpstreamCfg = &dns.ClientConfig{Servers: []string{fallbackHost}, Port: fallbackPort}
Debug.Printf("[main] DNS fallback at %s:%s", fallbackHost, fallbackPort)
Log.Debugf("[main] DNS fallback at %s:%s", fallbackHost, fallbackPort)
}
srv, err := weavedns.NewDNSServer(srvConfig)
if err != nil {
Error.Fatal("[main] Failed to initialize the WeaveDNS server", err)
Log.Fatal("[main] Failed to initialize the WeaveDNS server", err)
}
httpListener, err := net.Listen("tcp", httpAddr)
if err != nil {
Error.Fatal("[main] Unable to create http listener: ", err)
Log.Fatal("[main] Unable to create http listener: ", err)
}
Info.Println("[main] HTTP API listening on", httpAddr)
Log.Infoln("[main] HTTP API listening on", httpAddr)
go SignalHandlerLoop(srv)
go weavedns.ServeHTTP(httpListener, version, srv, dockerCli)
err = srv.Start()
if err != nil {
Error.Fatal("[main] Failed to start the WeaveDNS server: ", err)
Log.Fatal("[main] Failed to start the WeaveDNS server: ", err)
}
srv.ActivateAndServe()
}
prog/weaveproxy/main.go
+4 -4
View File
@@ -43,19 +43,19 @@ func main() {
}
if c.WithDNS && c.WithoutDNS {
Error.Fatalf("Cannot use both '--with-dns' and '--without-dns' flags")
Log.Fatalf("Cannot use both '--with-dns' and '--without-dns' flags")
}
if debug {
InitDefaultLogging(true)
}
Info.Println("weave proxy", version)
Info.Println("Command line arguments:", strings.Join(os.Args[1:], " "))
Log.Infoln("weave proxy", version)
Log.Infoln("Command line arguments:", strings.Join(os.Args[1:], " "))
p, err := proxy.NewProxy(c)
if err != nil {
Error.Fatalf("Could not start proxy: %s", err)
Log.Fatalf("Could not start proxy: %s", err)
}
p.ListenAndServe()
prog/weaver/main.go
+20 -25
View File
@@ -4,7 +4,6 @@ import (
"crypto/sha256"
"flag"
"fmt"
"log"
"net"
"net/http"
"os"
@@ -24,10 +23,6 @@ import (
var version = "(unreleased version)"
func main() {
log.SetPrefix(weave.Protocol + " ")
log.SetFlags(log.Ldate | log.Ltime | log.Lmicroseconds)
procs := runtime.NumCPU()
// packet sniffing can block an OS thread, so we need one thread
// for that plus at least one more.
@@ -84,33 +79,33 @@ func main() {
os.Exit(0)
}
log.Println("Command line options:", options())
log.Println("Command line peers:", peers)
Log.Println("Command line options:", options())
Log.Println("Command line peers:", peers)
var err error
if ifaceName != "" {
config.Iface, err = weavenet.EnsureInterface(ifaceName, wait)
if err != nil {
log.Fatal(err)
Log.Fatal(err)
}
}
if routerName == "" {
if config.Iface == nil {
log.Fatal("Either an interface must be specified with -iface or a name with -name")
Log.Fatal("Either an interface must be specified with -iface or a name with -name")
}
routerName = config.Iface.HardwareAddr.String()
}
name, err := weave.PeerNameFromUserInput(routerName)
if err != nil {
log.Fatal(err)
Log.Fatal(err)
}
if nickName == "" {
nickName, err = os.Hostname()
if err != nil {
log.Fatal(err)
Log.Fatal(err)
}
}
@@ -118,10 +113,10 @@ func main() {
password = os.Getenv("WEAVE_PASSWORD")
}
if password == "" {
log.Println("Communication between peers is unencrypted.")
Log.Println("Communication between peers is unencrypted.")
} else {
config.Password = []byte(password)
log.Println("Communication between peers is encrypted.")
Log.Println("Communication between peers is encrypted.")
}
if prof != "" {
@@ -136,7 +131,7 @@ func main() {
config.PeerDiscovery = !noDiscovery
router := weave.NewRouter(config, name, nickName)
log.Println("Our name is", router.Ourself)
Log.Println("Our name is", router.Ourself)
var allocator *ipam.Allocator
var defaultSubnet address.CIDR
@@ -145,18 +140,18 @@ func main() {
allocator, defaultSubnet = createAllocator(router, iprangeCIDR, ipsubnetCIDR, determineQuorum(peerCount, peers))
dockerCli, err = docker.NewClient(apiPath)
if err != nil {
Error.Fatal("Unable to start docker client: ", err)
Log.Fatal("Unable to start docker client: ", err)
}
if err = dockerCli.AddObserver(allocator); err != nil {
Error.Fatal("Unable to start watcher", err)
Log.Fatal("Unable to start watcher", err)
}
} else if peerCount > 0 {
log.Fatal("-initpeercount flag specified without -iprange")
Log.Fatal("-initpeercount flag specified without -iprange")
}
router.Start()
if errors := router.ConnectionMaker.InitiateConnections(peers, false); len(errors) > 0 {
log.Fatal(errorMessages(errors))
Log.Fatal(errorMessages(errors))
}
// The weave script always waits for a status call to succeed,
@@ -205,17 +200,17 @@ func logFrameFunc(debug bool) weave.LogFrameFunc {
}
}
log.Println(parts...)
Log.Println(parts...)
}
}
func parseAndCheckCIDR(cidrStr string) address.CIDR {
_, cidr, err := address.ParseCIDR(cidrStr)
if err != nil {
log.Fatal(err)
Log.Fatal(err)
}
if cidr.Size() < ipam.MinSubnetSize {
log.Fatalf("Allocation range smaller than minimum size %d: %s", ipam.MinSubnetSize, cidrStr)
Log.Fatalf("Allocation range smaller than minimum size %d: %s", ipam.MinSubnetSize, cidrStr)
}
return cidr
}
@@ -226,7 +221,7 @@ func createAllocator(router *weave.Router, ipRangeStr string, defaultSubnetStr s
if defaultSubnetStr != "" {
defaultSubnet = parseAndCheckCIDR(defaultSubnetStr)
if !ipRange.Range().Overlaps(defaultSubnet.Range()) {
log.Fatalf("Default subnet %s out of bounds: %s", defaultSubnet, ipRange)
Log.Fatalf("Default subnet %s out of bounds: %s", defaultSubnet, ipRange)
}
}
allocator := ipam.NewAllocator(router.Ourself.Peer.Name, router.Ourself.Peer.UID, router.Ourself.Peer.NickName, ipRange.Range(), quorum)
@@ -253,7 +248,7 @@ func determineQuorum(initPeerCountFlag int, peers []string) uint {
// specify it explicitly if that becomes a problem.
clusterSize := uint(len(peers) + 1)
quorum := clusterSize/2 + 1
log.Println("Assuming quorum size of", quorum)
Log.Println("Assuming quorum size of", quorum)
return quorum
}
@@ -303,11 +298,11 @@ func handleHTTP(router *weave.Router, httpAddr string, allocator *ipam.Allocator
}
l, err := net.Listen(protocol, httpAddr)
if err != nil {
log.Fatal("Unable to create http listener socket: ", err)
Log.Fatal("Unable to create http listener socket: ", err)
}
err = http.Serve(l, nil)
if err != nil {
log.Fatal("Unable to create http server", err)
Log.Fatal("Unable to create http server", err)
}
}
proxy/common.go
+3 -3
View File
@@ -20,7 +20,7 @@ var (
func callWeave(args ...string) ([]byte, error) {
args = append([]string{"--local"}, args...)
Debug.Print("Calling weave", args)
Log.Debug("Calling weave", args)
cmd := exec.Command("./weave", args...)
cmd.Env = []string{"PROCFS=/hostproc", "PATH=/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"}
out, err := cmd.CombinedOutput()
@@ -41,14 +41,14 @@ func inspectContainerInPath(client *docker.Client, path string) (*docker.Contain
subs := containerIDRegexp.FindStringSubmatch(path)
if subs == nil {
err := fmt.Errorf("No container id found in request with path %s", path)
Warning.Println(err)
Log.Warningln(err)
return nil, err
}
containerID := subs[2]
container, err := client.InspectContainer(containerID)
if err != nil {
Warning.Printf("Error inspecting container %s: %v", containerID, err)
Log.Warningf("Error inspecting container %s: %v", containerID, err)
}
return container, err
}
proxy/create_container_interceptor.go
+1 -1
View File
@@ -45,7 +45,7 @@ func (i *createContainerInterceptor) InterceptRequest(r *http.Request) error {
}
if cidrs, ok := i.proxy.weaveCIDRsFromConfig(container.Config); ok {
Info.Printf("Creating container with WEAVE_CIDR \"%s\"", strings.Join(cidrs, " "))
Log.Infof("Creating container with WEAVE_CIDR \"%s\"", strings.Join(cidrs, " "))
if container.HostConfig == nil {
container.HostConfig = &docker.HostConfig{}
}
proxy/create_exec_interceptor.go
+1 -1
View File
@@ -30,7 +30,7 @@ func (i *createExecInterceptor) InterceptRequest(r *http.Request) error {
}
if cidrs, ok := i.proxy.weaveCIDRsFromConfig(container.Config); ok {
Info.Printf("Exec in container %s with WEAVE_CIDR \"%s\"", container.ID, strings.Join(cidrs, " "))
Log.Infof("Exec in container %s with WEAVE_CIDR \"%s\"", container.ID, strings.Join(cidrs, " "))
cmd := append(weaveWaitEntrypoint, "-s")
options.Cmd = append(cmd, options.Cmd...)
}
proxy/proxy.go
+6 -6
View File
@@ -47,7 +47,7 @@ func NewProxy(c Config) (*Proxy, error) {
p := &Proxy{Config: c}
if err := p.TLSConfig.loadCerts(); err != nil {
Error.Fatalf("Could not configure tls for proxy: %s", err)
Log.Fatalf("Could not configure tls for proxy: %s", err)
}
client, err := docker.NewClient(dockerSockUnix)
@@ -72,7 +72,7 @@ func (proxy *Proxy) Dial() (net.Conn, error) {
}
func (proxy *Proxy) ServeHTTP(w http.ResponseWriter, r *http.Request) {
Info.Printf("%s %s", r.Method, r.URL)
Log.Infof("%s %s", r.Method, r.URL)
path := r.URL.Path
var i interceptor
switch {
@@ -94,14 +94,14 @@ func (proxy *Proxy) ListenAndServe() {
for _, addr := range proxy.ListenAddrs {
listener, normalisedAddr, err := proxy.listen(addr)
if err != nil {
Error.Fatalf("Cannot listen on %s: %s", addr, err)
Log.Fatalf("Cannot listen on %s: %s", addr, err)
}
listeners = append(listeners, listener)
addrs = append(addrs, normalisedAddr)
}
for _, addr := range addrs {
Info.Println("proxy listening on", addr)
Log.Infoln("proxy listening on", addr)
}
errs := make(chan error)
@@ -113,7 +113,7 @@ func (proxy *Proxy) ListenAndServe() {
for range listeners {
err := <-errs
if err != nil {
Error.Fatalf("Serve failed: %s", err)
Log.Fatalf("Serve failed: %s", err)
}
}
}
@@ -175,7 +175,7 @@ func (proxy *Proxy) listen(protoAndAddr string) (net.Listener, string, error) {
}
default:
Error.Fatalf("Invalid protocol format: %q", proto)
Log.Fatalf("Invalid protocol format: %q", proto)
}
return listener, fmt.Sprintf("%s://%s", proto, addr), nil
proxy/proxy_intercept.go
+11 -11
View File
@@ -23,7 +23,7 @@ func (proxy *Proxy) Intercept(i interceptor, w http.ResponseWriter, r *http.Requ
http.Error(w, err.Error(), http.StatusNotFound)
default:
http.Error(w, err.Error(), http.StatusInternalServerError)
Warning.Print("Error intercepting request: ", err)
Log.Warning("Error intercepting request: ", err)
}
return
}
@@ -31,7 +31,7 @@ func (proxy *Proxy) Intercept(i interceptor, w http.ResponseWriter, r *http.Requ
conn, err := proxy.Dial()
if err != nil {
http.Error(w, "Could not connect to target", http.StatusInternalServerError)
Warning.Print(err)
Log.Warning(err)
return
}
client := httputil.NewClientConn(conn, nil)
@@ -40,13 +40,13 @@ func (proxy *Proxy) Intercept(i interceptor, w http.ResponseWriter, r *http.Requ
resp, err := client.Do(r)
if err != nil && err != httputil.ErrPersistEOF {
http.Error(w, fmt.Sprintf("Could not make request to target: %v", err), http.StatusInternalServerError)
Warning.Print("Error forwarding request: ", err)
Log.Warning("Error forwarding request: ", err)
return
}
err = i.InterceptResponse(resp)
if err != nil {
http.Error(w, err.Error(), http.StatusInternalServerError)
Warning.Print("Error intercepting response: ", err)
Log.Warning("Error intercepting response: ", err)
return
}
@@ -56,7 +56,7 @@ func (proxy *Proxy) Intercept(i interceptor, w http.ResponseWriter, r *http.Requ
hdr.Add(k, v)
}
}
Debug.Printf("Response from target: %s %v", resp.Status, w.Header())
Log.Debugf("Response from target: %s %v", resp.Status, w.Header())
if resp.Header.Get("Content-Type") == "application/vnd.docker.raw-stream" {
doRawStream(w, resp, client)
@@ -65,7 +65,7 @@ func (proxy *Proxy) Intercept(i interceptor, w http.ResponseWriter, r *http.Requ
} else {
w.WriteHeader(resp.StatusCode)
if _, err := io.Copy(w, resp.Body); err != nil {
Warning.Print(err)
Log.Warning(err)
}
}
}
@@ -80,17 +80,17 @@ func doRawStream(w http.ResponseWriter, resp *http.Response, client *httputil.Cl
defer up.Close()
if _, err := down.Write([]byte("HTTP/1.1 200 OK\n")); err != nil {
Warning.Print(err)
Log.Warning(err)
return
}
if err := resp.Header.Write(down); err != nil {
Warning.Print(err)
Log.Warning(err)
return
}
if _, err := down.Write([]byte("\n")); err != nil {
Warning.Print(err)
Log.Warning(err)
return
}
@@ -105,13 +105,13 @@ func doRawStream(w http.ResponseWriter, resp *http.Response, client *httputil.Cl
func copyStream(dst io.Writer, src io.Reader, done chan struct{}) {
defer close(done)
if _, err := io.Copy(dst, src); err != nil {
Warning.Print(err)
Log.Warning(err)
}
if c, ok := dst.(interface {
CloseWrite() error
}); ok {
if err := c.CloseWrite(); err != nil {
Warning.Printf("Error closing connection: %s", err)
Log.Warningf("Error closing connection: %s", err)
}
}
}
proxy/start_container_interceptor.go
+3 -3
View File
@@ -23,15 +23,15 @@ func (i *startContainerInterceptor) InterceptResponse(r *http.Response) error {
cidrs, ok := i.proxy.weaveCIDRsFromConfig(container.Config)
if !ok {
Debug.Print("No Weave CIDR, ignoring")
Log.Debug("No Weave CIDR, ignoring")
return nil
}
Info.Printf("Attaching container %s with WEAVE_CIDR \"%s\" to weave network", container.ID, strings.Join(cidrs, " "))
Log.Infof("Attaching container %s with WEAVE_CIDR \"%s\" to weave network", container.ID, strings.Join(cidrs, " "))
args := []string{"attach"}
args = append(args, cidrs...)
args = append(args, "--or-die", container.ID)
if output, err := callWeave(args...); err != nil {
Warning.Printf("Attaching container %s to weave network failed: %s", container.ID, string(output))
Log.Warningf("Attaching container %s to weave network failed: %s", container.ID, string(output))
return errors.New(string(output))
}
router/connection.go
+11 -6
View File
@@ -4,10 +4,11 @@ import (
"encoding/binary"
"encoding/gob"
"fmt"
"log"
"net"
"sync"
"time"
. "github.com/weaveworks/weave/common"
)
type Connection interface {
@@ -83,7 +84,11 @@ func (conn *RemoteConnection) BreakTie(Connection) ConnectionTieBreak { return T
func (conn *RemoteConnection) Shutdown(error) {}
func (conn *RemoteConnection) Log(args ...interface{}) {
log.Println(append(append([]interface{}{}, fmt.Sprintf("->[%s|%s]:", conn.remoteTCPAddr, conn.remote)), args...)...)
Log.Println(append(append([]interface{}{}, fmt.Sprintf("->[%s|%s]:", conn.remoteTCPAddr, conn.remote)), args...)...)
}
func (conn *RemoteConnection) ErrorLog(args ...interface{}) {
Log.Errorln(append(append([]interface{}{}, fmt.Sprintf("->[%s|%s]:", conn.remoteTCPAddr, conn.remote)), args...)...)
}
func (conn *RemoteConnection) String() string {
@@ -102,7 +107,7 @@ func (conn *RemoteConnection) String() string {
// end up in the local peer's connections map.
func StartLocalConnection(connRemote *RemoteConnection, tcpConn *net.TCPConn, udpAddr *net.UDPAddr, router *Router, acceptNewPeer bool) {
if connRemote.local != router.Ourself.Peer {
log.Fatal("Attempt to create local connection from a peer which is not ourself")
Log.Fatal("Attempt to create local connection from a peer which is not ourself")
}
// NB, we're taking a copy of connRemote here.
actionChan := make(chan ConnectionAction, ChannelSize)
@@ -227,7 +232,7 @@ func (conn *LocalConnection) ReceivedHeartbeat(remoteUDPAddr *net.UDPAddr, connU
if oldRemoteUDPAddr == nil {
return conn.sendFastHeartbeats()
} else if oldRemoteUDPAddr.String() != remoteUDPAddr.String() {
log.Println("Peer", conn.remote, "moved from", old, "to", remoteUDPAddr)
Log.Println("Peer", conn.remote, "moved from", old, "to", remoteUDPAddr)
}
return nil
})
@@ -378,9 +383,9 @@ func (conn *LocalConnection) actorLoop(actionChan <-chan ConnectionAction) (err
func (conn *LocalConnection) shutdown(err error) {
if conn.remote == nil {
log.Printf("->[%s] connection shutting down due to error during handshake: %v\n", conn.remoteTCPAddr, err)
Log.Errorf("->[%s] connection shutting down due to error during handshake: %v\n", conn.remoteTCPAddr, err)
} else {
conn.Log("connection shutting down due to error:", err)
conn.ErrorLog("connection shutting down due to error:", err)
}
if conn.TCPConn != nil {
router/connection_maker.go
+4 -3
View File
@@ -3,10 +3,11 @@ package router
import (
"bytes"
"fmt"
"log"
"math/rand"
"net"
"time"
. "github.com/weaveworks/weave/common"
)
const (
@@ -298,9 +299,9 @@ func (cm *ConnectionMaker) connectToTargets(validTarget map[string]struct{}, dir
}
func (cm *ConnectionMaker) attemptConnection(address string, acceptNewPeer bool) {
log.Printf("->[%s] attempting connection\n", address)
Log.Printf("->[%s] attempting connection\n", address)
if err := cm.ourself.CreateConnection(address, acceptNewPeer); err != nil {
log.Printf("->[%s] error during connection attempt: %v\n", address, err)
Log.Errorf("->[%s] error during connection attempt: %v\n", address, err)
cm.ConnectionTerminated(address, err)
}
}
router/ethernet_decoder.go
+2 -2
View File
@@ -2,11 +2,11 @@ package router
import (
"bytes"
"log"
"net"
"code.google.com/p/gopacket"
"code.google.com/p/gopacket/layers"
. "github.com/weaveworks/weave/common"
)
type EthernetDecoder struct {
@@ -61,7 +61,7 @@ func (dec *EthernetDecoder) sendICMPFragNeeded(mtu int, sendFrame func([]byte) e
return err
}
log.Printf("Sending ICMP 3,4 (%v -> %v): PMTU= %v\n", dec.IP.DstIP, dec.IP.SrcIP, mtu)
Log.Printf("Sending ICMP 3,4 (%v -> %v): PMTU= %v\n", dec.IP.DstIP, dec.IP.SrcIP, mtu)
return sendFrame(buf.Bytes())
}
router/forwarder.go
+1 -1
View File
@@ -281,7 +281,7 @@ func (fwd *Forwarder) accumulateAndSendFrames(ch <-chan *ForwardedFrame, frame *
}
func (fwd *Forwarder) logDrop(frame *ForwardedFrame) {
fwd.conn.Log("Dropping too big frame during forwarding: frame len:", len(frame.frame), "; effective PMTU:", fwd.maxPayload+UDPOverhead-fwd.effectiveOverhead())
fwd.conn.ErrorLog("Dropping too big frame during forwarding: frame len:", len(frame.frame), "; effective PMTU:", fwd.maxPayload+UDPOverhead-fwd.effectiveOverhead())
}
func (fwd *Forwarder) appendFrame(frame *ForwardedFrame) bool {
router/gossip_channel.go
+3 -2
View File
@@ -4,8 +4,9 @@ import (
"bytes"
"encoding/gob"
"fmt"
"log"
"sync"
. "github.com/weaveworks/weave/common"
)
type GossipChannel struct {
@@ -225,5 +226,5 @@ func (c *GossipChannel) sendBroadcast(srcName PeerName, update GossipData) {
}
func (c *GossipChannel) log(args ...interface{}) {
log.Println(append(append([]interface{}{}, "[gossip "+c.name+"]:"), args...)...)
Log.Println(append(append([]interface{}{}, "[gossip "+c.name+"]:"), args...)...)
}
router/local_peer.go
+11 -10
View File
@@ -2,10 +2,11 @@ package router
import (
"fmt"
"log"
"net"
"sync"
"time"
. "github.com/weaveworks/weave/common"
)
type LocalPeer struct {
@@ -41,13 +42,13 @@ func (peer *LocalPeer) Relay(srcPeer, dstPeer *Peer, frame []byte, dec *Ethernet
if !found {
// Not necessarily an error as there could be a race with the
// dst disappearing whilst the frame is in flight
log.Println("Received packet for unknown destination:", dstPeer)
Log.Println("Received packet for unknown destination:", dstPeer)
return nil
}
conn, found := peer.ConnectionTo(relayPeerName)
if !found {
// Again, could just be a race, not necessarily an error
log.Println("Unable to find connection to relay peer", relayPeerName)
Log.Println("Unable to find connection to relay peer", relayPeerName)
return nil
}
return conn.(*LocalConnection).Forward(&ForwardedFrame{
@@ -70,9 +71,9 @@ func (peer *LocalPeer) RelayBroadcast(srcPeer *Peer, frame []byte, dec *Ethernet
dec)
if err != nil {
if ftbe, ok := err.(FrameTooBigError); ok {
log.Printf("dropping too big DF broadcast frame (%v -> %v): PMTU= %v\n", dec.IP.DstIP, dec.IP.SrcIP, ftbe.EPMTU)
Log.Warnf("dropping too big DF broadcast frame (%v -> %v): PMTU= %v\n", dec.IP.DstIP, dec.IP.SrcIP, ftbe.EPMTU)
} else {
log.Println(err)
Log.Errorln(err)
}
}
}
@@ -181,10 +182,10 @@ func (peer *LocalPeer) actorLoop(actionChan <-chan LocalPeerAction) {
func (peer *LocalPeer) handleAddConnection(conn Connection) error {
if peer.Peer != conn.Local() {
log.Fatal("Attempt made to add connection to peer where peer is not the source of connection")
Log.Fatal("Attempt made to add connection to peer where peer is not the source of connection")
}
if conn.Remote() == nil {
log.Fatal("Attempt made to add connection to peer with unknown remote peer")
Log.Fatal("Attempt made to add connection to peer with unknown remote peer")
}
toName := conn.Remote().Name
dupErr := fmt.Errorf("Multiple connections to %s added to %s", conn.Remote(), peer.String())
@@ -223,7 +224,7 @@ func (peer *LocalPeer) handleAddConnection(conn Connection) error {
func (peer *LocalPeer) handleConnectionEstablished(conn Connection) {
if peer.Peer != conn.Local() {
log.Fatal("Peer informed of active connection where peer is not the source of connection")
Log.Fatal("Peer informed of active connection where peer is not the source of connection")
}
if dupConn, found := peer.connections[conn.Remote().Name]; !found || conn != dupConn {
conn.Shutdown(fmt.Errorf("Cannot set unknown connection active"))
@@ -236,10 +237,10 @@ func (peer *LocalPeer) handleConnectionEstablished(conn Connection) {
func (peer *LocalPeer) handleDeleteConnection(conn Connection) {
if peer.Peer != conn.Local() {
log.Fatal("Attempt made to delete connection from peer where peer is not the source of connection")
Log.Fatal("Attempt made to delete connection from peer where peer is not the source of connection")
}
if conn.Remote() == nil {
log.Fatal("Attempt made to delete connection to peer with unknown remote peer")
Log.Fatal("Attempt made to delete connection to peer with unknown remote peer")
}
toName := conn.Remote().Name
if connFound, found := peer.connections[toName]; !found || connFound != conn {
router/router.go
+11 -12
View File
@@ -5,7 +5,6 @@ import (
"encoding/binary"
"fmt"
"io"
"log"
"net"
"sync"
"syscall"
@@ -67,11 +66,11 @@ type PacketSourceSink interface {
func NewRouter(config Config, name PeerName, nickName string) *Router {
router := &Router{Config: config, gossipChannels: make(GossipChannels)}
onMacExpiry := func(mac net.HardwareAddr, peer *Peer) {
log.Println("Expired MAC", mac, "at", peer)
Log.Println("Expired MAC", mac, "at", peer)
}
onPeerGC := func(peer *Peer) {
router.Macs.Delete(peer)
log.Println("Removed unreachable peer", peer)
Log.Println("Removed unreachable peer", peer)
}
router.Ourself = NewLocalPeer(name, nickName, router)
router.Macs = NewMacCache(macMaxAge, onMacExpiry)
@@ -127,12 +126,12 @@ func (router *Router) Status() string {
}
func (router *Router) sniff(pio PacketSourceSink) {
log.Println("Sniffing traffic on", router.Iface)
Log.Println("Sniffing traffic on", router.Iface)
dec := NewEthernetDecoder()
mac := router.Iface.HardwareAddr
if router.Macs.Enter(mac, router.Ourself.Peer) {
log.Println("Discovered our MAC", mac)
Log.Println("Discovered our MAC", mac)
}
go func() {
for {
@@ -159,7 +158,7 @@ func (router *Router) handleCapturedPacket(frameData []byte, dec *EthernetDecode
return
}
if router.Macs.Enter(srcMac, router.Ourself.Peer) {
log.Println("Discovered local MAC", srcMac)
Log.Println("Discovered local MAC", srcMac)
}
if dec.DropFrame() {
return
@@ -202,7 +201,7 @@ func (router *Router) listenTCP(localPort int) {
for {
tcpConn, err := ln.AcceptTCP()
if err != nil {
log.Println(err)
Log.Errorln(err)
continue
}
router.acceptTCP(tcpConn)
@@ -216,7 +215,7 @@ func (router *Router) acceptTCP(tcpConn *net.TCPConn) {
// on router.Port and we wait for them to send us something on UDP to
// start.
remoteAddrStr := tcpConn.RemoteAddr().String()
log.Printf("->[%s] connection accepted\n", remoteAddrStr)
Log.Printf("->[%s] connection accepted\n", remoteAddrStr)
connRemote := NewRemoteConnection(router.Ourself.Peer, nil, remoteAddrStr, false, false)
StartLocalConnection(connRemote, tcpConn, nil, router, true)
}
@@ -246,10 +245,10 @@ func (router *Router) udpReader(conn *net.UDPConn, po PacketSink) {
if err == io.EOF {
return
} else if err != nil {
log.Println("ignoring UDP read error", err)
Log.Warnln("ignoring UDP read error", err)
continue
} else if n < NameSize {
log.Println("ignoring too short UDP packet from", sender)
Log.Warnln("ignoring too short UDP packet from", sender)
continue
}
name := PeerNameFromBin(buf[:NameSize])
@@ -329,7 +328,7 @@ func (router *Router) handleUDPPacketFunc(relayConn *LocalConnection, dec *Ether
dstMac := dec.Eth.DstMAC
if router.Macs.Enter(srcMac, srcPeer) {
log.Println("Discovered remote MAC", srcMac, "at", srcPeer)
Log.Println("Discovered remote MAC", srcMac, "at", srcPeer)
}
if po != nil {
router.LogFrame("Injecting", frame, dec)
@@ -415,7 +414,7 @@ func (router *Router) applyTopologyUpdate(update []byte) (PeerNameSet, PeerNameS
// itself included in the update, and we didn't know about
// already. We ignore this; eventually we should receive an
// update containing a complete topology.
log.Println("Topology gossip:", err)
Log.Println("Topology gossip:", err)
return nil, nil, nil
}
if err != nil {
router/udp_sender.go
+2 -2
View File
@@ -1,12 +1,12 @@
package router
import (
"log"
"net"
"syscall"
"code.google.com/p/gopacket"
"code.google.com/p/gopacket/layers"
. "github.com/weaveworks/weave/common"
)
type UDPSender interface {
@@ -87,7 +87,7 @@ func (sender *RawUDPSender) Send(msg []byte) error {
}
defer f.Close()
fd := int(f.Fd())
log.Println("EMSGSIZE on send, expecting PMTU update (IP packet was",
Log.Println("EMSGSIZE on send, expecting PMTU update (IP packet was",
len(packet), "bytes, payload was", len(msg), "bytes)")
pmtu, err := syscall.GetsockoptInt(fd, syscall.IPPROTO_IP, syscall.IP_MTU)
if err != nil {
router/utils.go
+4 -3
View File
@@ -5,21 +5,22 @@ import (
"crypto/rand"
"encoding/gob"
"fmt"
"log"
"net"
. "github.com/weaveworks/weave/common"
)
var void = struct{}{}
func checkFatal(e error) {
if e != nil {
log.Fatal(e)
Log.Fatal(e)
}
}
func checkWarn(e error) {
if e != nil {
log.Println(e)
Log.Warnln(e)
}
}
weave
+2 -2
View File
@@ -614,7 +614,7 @@ wait_for_status() {
wait_for_log() {
fifo=/tmp/tmpfifo.$$
mkfifo $fifo || exit 1
docker logs -f $1 2>/dev/null >$fifo &
docker logs -f $1 >$fifo 2>&1 &
res=0
grep -q "$2" $fifo || res=1
kill $! 2>/dev/null || true
@@ -927,7 +927,7 @@ proxy_args() {
}
proxy_addr() {
if addr=$(docker logs $PROXY_CONTAINER_NAME 2>/dev/null | head -n3 | grep -oE "proxy listening on .*"); then
if addr=$(docker logs $PROXY_CONTAINER_NAME 2>&1 | head -n3 | grep -oE "proxy listening on .*"); then
echo "${1}${addr##* }" | sed "s/0.0.0.0/$PROXY_HOST/g"
return 0
fi