Merge pull request #1057 from weaveworks/329-log-level-choice

Give the user more choice of log levels

Closes #329

common/init.go

@@ -1,5 +0,0 @@
-package common
-
-func init() {
-	InitDefaultLogging(false)
-}

common/logging.go

@@ -41,22 +41,28 @@ var (
 	Log *logrus.Logger
 )
 
-func InitLogging(level logrus.Level) {
-	if Log == nil {
-		Log = &logrus.Logger{
-			Out:       os.Stderr,
-			Formatter: standardTextFormatter,
-			Hooks:     make(logrus.LevelHooks),
-			Level:     level,
-		}
+func init() {
+	Log = &logrus.Logger{
+		Out:       os.Stderr,
+		Formatter: standardTextFormatter,
+		Hooks:     make(logrus.LevelHooks),
+	}
+}
+
+func SetLogLevel(levelname string) {
+	level, err := logrus.ParseLevel(levelname)
+	if err != nil {
+		Log.Fatal(err)
 	}
 	Log.Level = level
 }
 
-func InitDefaultLogging(debug bool) {
-	level := logrus.InfoLevel
-	if debug {
-		level = logrus.DebugLevel
+// For backwards-compatibility with code that only has a boolean
+func EnableDebugLogging(flag bool) {
+	switch {
+	case flag && Log.Level < logrus.DebugLevel:
+		Log.Level = logrus.DebugLevel
+	case !flag && Log.Level >= logrus.DebugLevel:
+		Log.Level = logrus.InfoLevel
 	}
-	InitLogging(level)
 }

common/sched_queue_test.go

@@ -10,7 +10,7 @@ import (
 
 // Ensure we can add new calls while forwarding the clock
 func TestSchedCallsBasic(t *testing.T) {
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestSchedCallsBasic starting")
 
 	const testSecs = 1000
@@ -36,7 +36,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())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestSchedCallsGap starting")
 
 	const testSecs = 1000
@@ -64,7 +64,7 @@ func TestSchedCallsGap(t *testing.T) {
 }
 
 func TestSchedCallsStop(t *testing.T) {
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestSchedCallsStop starting")
 
 	const testSecs = 1000

ipam/allocator_test.go

@@ -71,7 +71,6 @@ func TestAllocFree(t *testing.T) {
 }
 
 func TestBootstrap(t *testing.T) {
-	common.InitDefaultLogging(false)
 	const (
 		donateSize     = 5
 		donateStart    = "10.0.1.7"
@@ -163,7 +162,6 @@ func (alloc *Allocator) pause() func() {
 }
 
 func TestCancel(t *testing.T) {
-	common.InitDefaultLogging(false)
 	const (
 		CIDR = "10.0.1.7/26"
 	)
@@ -276,7 +274,6 @@ func TestTransfer(t *testing.T) {
 }
 
 func TestFakeRouterSimple(t *testing.T) {
-	common.InitDefaultLogging(false)
 	const (
 		cidr = "10.0.1.7/22"
 	)
@@ -291,7 +288,6 @@ func TestFakeRouterSimple(t *testing.T) {
 }
 
 func TestAllocatorFuzz(t *testing.T) {
-	common.InitDefaultLogging(false)
 	const (
 		firstpass    = 1000
 		secondpass   = 20000

ipam/http_test.go

@@ -151,7 +151,6 @@ func TestHTTPCancel(t *testing.T) {
 }
 
 func impTestHTTPCancel(t *testing.T) {
-	common.InitDefaultLogging(true)
 	var (
 		containerID = "deadbeef"
 		testCIDR1   = "10.0.3.0/29"

nameserver/addrs_test.go

@@ -9,7 +9,7 @@ import (
 )
 
 func TestAddrs(t *testing.T) {
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestAddrs starting")
 
 	ip, err := addrToIPv4("10.13.12.11")

nameserver/cache_test.go

@@ -14,7 +14,7 @@ import (
 
 // Check that the cache keeps its intended capacity constant
 func TestCacheLength(t *testing.T) {
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestCacheLength starting")
 
 	const cacheLen = 128
@@ -55,7 +55,7 @@ func TestCacheLength(t *testing.T) {
 
 // Check that the cache entries are ok
 func TestCacheEntries(t *testing.T) {
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestCacheEntries starting")
 
 	Log.Infoln("Checking cache consistency")

nameserver/dns_test.go

@@ -11,7 +11,7 @@ import (
 
 // Check that we can prune an answer
 func TestPrune(t *testing.T) {
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestPrune starting")
 
 	questionMsg := new(dns.Msg)

nameserver/mdns_client_test.go

@@ -78,7 +78,7 @@ func RunLocalMulticastServer() (*dns.Server, error) {
 }
 
 func setup(t *testing.T) (*MDNSClient, *dns.Server, error) {
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 
 	server, err := RunLocalMulticastServer()
 	if err != nil {

nameserver/mdns_server_test.go

@@ -17,7 +17,7 @@ func TestServerSimpleQuery(t *testing.T) {
 		testInAddr1 = "10.20.20.10.in-addr.arpa."
 	)
 
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestServerSimpleQuery starting")
 
 	mzone := newMockedZoneWithRecords([]ZoneRecord{testRecord1, testRecord2})

nameserver/mdns_test.go

@@ -12,7 +12,7 @@ import (
 
 // Check that we can use a regular mDNS server with a regular mDNS client
 func TestClientServerSimpleQuery(t *testing.T) {
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 
 	testRecord1 := Record{"test.weave.local.", net.ParseIP("10.2.2.1"), 0, 0, 0}
 	testInAddr1 := "1.2.2.10.in-addr.arpa."
@@ -86,7 +86,7 @@ func TestClientServerSimpleQuery(t *testing.T) {
 
 // Check that we can use a use "insistent" queries
 func TestClientServerInsistentQuery(t *testing.T) {
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 
 	testRecord1 := Record{"test.weave.local.", net.ParseIP("10.2.2.1"), 0, 0, 0}
 	testInAddr1 := "1.2.2.10.in-addr.arpa."

nameserver/server_cache_test.go

@@ -19,7 +19,7 @@ func TestServerDbCacheInvalidation(t *testing.T) {
 		testName2   = "second.weave.local."
 	)
 
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestServerDbCacheInvalidation starting")
 
 	clk := newMockedClock()
@@ -177,7 +177,7 @@ func TestServerCacheExpiration(t *testing.T) {
 		negativeLocalTTL = 10
 	)
 
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestServerCacheExpiration starting")
 
 	clk := newMockedClock()
@@ -265,7 +265,7 @@ func TestServerCacheRefresh(t *testing.T) {
 		refreshInterval = int(DefaultLocalTTL) / 3
 	)
 
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestServerCacheRefresh starting")
 	clk := newMockedClock()
 

nameserver/server_test.go

@@ -40,7 +40,7 @@ func TestUDPDNSServer(t *testing.T) {
 	)
 	testCIDR1 := testAddr1 + "/24"
 
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestUDPDNSServer starting")
 
 	zone, err := NewZoneDb(ZoneConfig{})
@@ -137,7 +137,7 @@ func TestTCPDNSServer(t *testing.T) {
 		nonLocalName = "weave.works."
 	)
 
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestTCPDNSServer starting")
 
 	zone, err := NewZoneDb(ZoneConfig{})

nameserver/zone_lookup_test.go

@@ -23,7 +23,7 @@ func TestZoneRefresh(t *testing.T) {
 		addr4 = "10.2.8.7"
 	)
 
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 	Log.Infoln("TestZoneRefresh starting")
 
 	clk := newMockedClock()

nameserver/zone_test.go

@@ -20,7 +20,7 @@ func TestZone(t *testing.T) {
 		revName1Addr1 = "1.2.9.10.in-addr.arpa."
 	)
 
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 
 	zone, err := NewZoneDb(ZoneConfig{})
 	require.NoError(t, err)
@@ -136,7 +136,7 @@ func TestDeleteRecords(t *testing.T) {
 		addr2 = "10.2.7.8/24"
 	)
 
-	InitDefaultLogging(testing.Verbose())
+	EnableDebugLogging(testing.Verbose())
 
 	zone, err := NewZoneDb(ZoneConfig{})
 	require.NoError(t, err)

prog/weavedns/main.go

@@ -38,7 +38,7 @@ func main() {
 		cacheLen        int
 		cacheDisabled   bool
 		watch           bool
-		debug           bool
+		logLevel        string
 		err             error
 	)
 
@@ -53,7 +53,7 @@ func main() {
 	flag.IntVar(&cacheLen, "cache", weavedns.DefaultCacheLen, "cache length")
 	flag.IntVar(&ttl, "ttl", weavedns.DefaultLocalTTL, "TTL (in secs) for responses for local names")
 	flag.BoolVar(&watch, "watch", true, "watch the docker socket for container events")
-	flag.BoolVar(&debug, "debug", false, "output debugging info to stderr")
+	flag.StringVar(&logLevel, "log-level", "info", "logging level (debug, info, warning, error)")
 	// advanced options
 	flag.IntVar(&negTTL, "neg-ttl", 0, "negative TTL (in secs) for unanswered queries for local names (0=same value as -ttl")
 	flag.IntVar(&refreshInterval, "refresh", weavedns.DefaultRefreshInterval, "refresh interval (in secs) for local names (0=disable)")
@@ -70,7 +70,7 @@ func main() {
 		os.Exit(0)
 	}
 
-	InitDefaultLogging(debug)
+	SetLogLevel(logLevel)
 	Log.Infof("[main] WeaveDNS version %s\n", version) // first thing in log: the version
 
 	var iface *net.Interface

prog/weaveproxy/main.go

@@ -17,14 +17,14 @@ var (
 
 func main() {
 	var (
-		debug       bool
 		justVersion bool
+		logLevel    = "info"
 		c           = proxy.Config{ListenAddrs: defaultListenAddrs}
 	)
 
 	c.Version = version
-	getopt.BoolVarLong(&debug, "debug", 'd', "log debugging information")
 	getopt.BoolVarLong(&justVersion, "version", 0, "print version and exit")
+	getopt.StringVarLong(&logLevel, "log-level", 0, "logging level (debug, info, warning, error)", "info")
 	getopt.ListVar(&c.ListenAddrs, 'H', fmt.Sprintf("address on which to listen (default %s)", defaultListenAddrs))
 	getopt.BoolVarLong(&c.NoDefaultIPAM, "no-default-ipalloc", 0, "do not automatically allocate addresses for containers without a WEAVE_CIDR")
 	getopt.BoolVarLong(&c.NoDefaultIPAM, "no-default-ipam", 0, "do not automatically allocate addresses for containers without a WEAVE_CIDR (deprecated; please use --no-default-ipalloc")
@@ -46,9 +46,7 @@ func main() {
 		Log.Fatalf("Cannot use both '--with-dns' and '--without-dns' flags")
 	}
 
-	if debug {
-		InitDefaultLogging(true)
-	}
+	SetLogLevel(logLevel)
 
 	Log.Infoln("weave proxy", version)
 	Log.Infoln("Command line arguments:", strings.Join(os.Args[1:], " "))

prog/weaver/main.go

@@ -39,8 +39,8 @@ func main() {
 		nickName     string
 		password     string
 		wait         int
-		debug        bool
 		pktdebug     bool
+		logLevel     string
 		prof         string
 		bufSzMB      int
 		noDiscovery  bool
@@ -59,7 +59,7 @@ func main() {
 	flag.StringVar(&nickName, "nickname", "", "nickname of peer (defaults to hostname)")
 	flag.StringVar(&password, "password", "", "network password")
 	flag.IntVar(&wait, "wait", -1, "number of seconds to wait for interface to come up (0=don't wait, -1=wait forever)")
-	flag.BoolVar(&debug, "debug", false, "enable debug logging")
+	flag.StringVar(&logLevel, "log-level", "info", "logging level (debug, info, warning, error)")
 	flag.BoolVar(&pktdebug, "pktdebug", false, "enable per-packet debug logging")
 	flag.StringVar(&prof, "profile", "", "enable profiling and write profiles to given path")
 	flag.IntVar(&config.ConnLimit, "connlimit", 30, "connection limit (0 for unlimited)")
@@ -73,7 +73,7 @@ func main() {
 	flag.Parse()
 	peers = flag.Args()
 
-	InitDefaultLogging(debug)
+	SetLogLevel(logLevel)
 	if justVersion {
 		fmt.Printf("weave router %s\n", version)
 		os.Exit(0)

site/troubleshooting.md

@@ -20,9 +20,10 @@ Check the weave container logs with
 
 A reasonable amount of information, and all errors, get logged there.
 
-The log verbosity can be increased by supplying the `-debug` flag when
-launching weave. To log information on a per-packet basis use
-`-pktdebug` - be warned, this can produce a lot of output.
+The log verbosity can be increased by supplying the
+`--log-level=debug` option when launching weave. To log information on
+a per-packet basis use `-pktdebug` - be warned, this can produce a lot
+of output.
 
 Another useful debugging technique is to attach standard packet
 capture and analysis tools, such as tcpdump and wireshark, to the

test/config.sh

@@ -43,7 +43,7 @@ CHECK_ETHWE_UP="grep ^1$ /sys/class/net/ethwe/carrier"
 DOCKER_PORT=2375
 
 WEAVEDNS_ARGS="--no-cache"
-[ -n "$DEBUG" ] && WEAVEDNS_ARGS="$WEAVEDNS_ARGS --debug"
+[ -n "$DEBUG" ] && WEAVEDNS_ARGS="$WEAVEDNS_ARGS --log-level=debug"
 
 
 upload_executable() {