Merge pull request #179 from cryptix/improveLogging

Improve logging

cmd/ipfs/ipfs.go

@@ -63,6 +63,7 @@ Use "ipfs help <command>" for more information about a command.
 		cmdIpfsBootstrap,
 		cmdIpfsDiag,
 		cmdIpfsBlock,
+		cmdIpfsLog,
 	},
 	Flag: *flag.NewFlagSet("ipfs", flag.ExitOnError),
 }
@@ -73,7 +74,7 @@ var log = u.Logger("cmd/ipfs")
 func init() {
 	config, err := config.PathRoot()
 	if err != nil {
-		u.POut("Failure initializing the default Config Directory: ", err)
+		fmt.Fprintln(os.Stderr, "Failure initializing the default Config Directory: ", err)
 		os.Exit(1)
 	}
 	CmdIpfs.Flag.String("c", config, "specify config directory")
@@ -85,10 +86,7 @@ func ipfsCmd(c *commander.Command, args []string) error {
 }
 
 func main() {
-	u.Debug = false
-
-	// setup logging
-	// u.SetupLogging() done in an init() block now.
+	u.Debug = u.GetenvBool("IPFS_DEBUG")
 
 	// if debugging, setup profiling.
 	if u.Debug {

cmd/ipfs/log.go

+package main
+
+import (
+	flag "github.com/jbenet/go-ipfs/Godeps/_workspace/src/github.com/gonuts/flag"
+	commander "github.com/jbenet/go-ipfs/Godeps/_workspace/src/github.com/jbenet/commander"
+	"github.com/jbenet/go-ipfs/core/commands"
+)
+
+var cmdIpfsLog = &commander.Command{
+	UsageLine: "log <name> <level> ",
+	Short:     "switch logging levels of a running daemon",
+	Long: `ipfs log <name> <level> - switch logging levels of a running daemon
+
+   <name> is a the subsystem logging identifier. Use * for all subsystems.
+   <level> is one of: debug, info, notice, warning, error, critical
+
+ipfs log is a utility command used to change the logging output of a running daemon.
+`,
+	Run:  logCmd,
+	Flag: *flag.NewFlagSet("ipfs-log", flag.ExitOnError),
+}
+
+var logCmd = makeCommand(command{
+	name:   "log",
+	args:   2,
+	flags:  nil,
+	online: true,
+	cmdFn:  commands.Log,
+})

core/commands/log.go

+package commands
+
+import (
+	"io"
+
+	"github.com/jbenet/go-ipfs/core"
+	u "github.com/jbenet/go-ipfs/util"
+)
+
+// Log changes the log level of a subsystem
+func Log(n *core.IpfsNode, args []string, opts map[string]interface{}, out io.Writer) error {
+	if err := u.SetLogLevel(args[0], args[1]); err != nil {
+		return err
+	}
+
+	log.Info("Changed LogLevel of %q to %q", args[0], args[1])
+	return nil
+}

core/commands/refs.go

@@ -43,7 +43,7 @@ func printRefs(n *core.IpfsNode, nd *mdag.Node, refSeen map[u.Key]bool, recursiv
 		if recursive {
 			nd, err := n.DAG.Get(u.Key(link.Hash))
 			if err != nil {
-				u.PErr("error: cannot retrieve %s (%s)\n", link.Hash.B58String(), err)
+				log.Error("error: cannot retrieve %s (%s)\n", link.Hash.B58String(), err)
 				return
 			}
 

daemon/daemon.go

@@ -137,10 +137,13 @@ func (dl *DaemonListener) handleConnection(conn manet.Conn) {
 		err = commands.BlockGet(dl.node, command.Args, command.Opts, conn)
 	case "blockPut":
 		err = commands.BlockPut(dl.node, command.Args, command.Opts, conn)
+	case "log":
+		err = commands.Log(dl.node, command.Args, command.Opts, conn)
 	default:
 		err = fmt.Errorf("Invalid Command: '%s'", command.Command)
 	}
 	if err != nil {
+		log.Error("%s: %s", command.Command, err)
 		fmt.Fprintln(conn, err)
 	}
 }

updates/updates.go

@@ -37,7 +37,7 @@ func init() {
 	var err error
 	currentVersion, err = semver.NewVersion(Version)
 	if err != nil {
-		u.PErr("The const Version literal in version.go needs to be in semver format: %s \n", Version)
+		log.Error("The const Version literal in version.go needs to be in semver format: %s \n", Version)
 		os.Exit(1)
 	}
 }

util/log.go

@@ -11,17 +11,14 @@ func init() {
 	SetupLogging()
 }
 
+var log = Logger("util")
+
 // LogFormat is the format used for our logger.
 var LogFormat = "%{color}%{time:2006-01-02 15:04:05.999999} %{shortfile} %{level}: %{color:reset}%{message}"
 
 // loggers is the set of loggers in the system
 var loggers = map[string]*logging.Logger{}
 
-// PErr is a shorthand printing function to output to Stderr.
-func PErr(format string, a ...interface{}) {
-	fmt.Fprintf(os.Stderr, format, a...)
-}
-
 // POut is a shorthand printing function to output to Stdout.
 func POut(format string, a ...interface{}) {
 	fmt.Fprintf(os.Stdout, format, a...)
@@ -35,31 +32,61 @@ func SetupLogging() {
 
 	lvl := logging.ERROR
 
-	var err error
 	if logenv := os.Getenv("IPFS_LOGGING"); logenv != "" {
+		var err error
 		lvl, err = logging.LogLevel(logenv)
 		if err != nil {
-			PErr("invalid logging level: %s\n", logenv)
-			PErr("using logging.DEBUG\n")
-			lvl = logging.DEBUG
+			log.Error("logging.LogLevel() Error: %q", err)
+			lvl = logging.ERROR // reset to ERROR, could be undefined now(?)
 		}
 	}
 
+	if Debug {
+		lvl = logging.DEBUG
+	}
+
 	SetAllLoggers(lvl)
+
 }
 
+// SetAllLoggers changes the logging.Level of all loggers to lvl
 func SetAllLoggers(lvl logging.Level) {
 	logging.SetLevel(lvl, "")
 	for n, log := range loggers {
 		logging.SetLevel(lvl, n)
-		log.Error("setting logger: %s to %v", n, lvl)
+		log.Notice("setting logger: %q to %v", n, lvl)
 	}
 }
 
-// Logger retrieves a particular logger + initializes it at a particular level
+// Logger retrieves a particular logger
 func Logger(name string) *logging.Logger {
 	log := logging.MustGetLogger(name)
-	// logging.SetLevel(lvl, name) // can't set level here.
 	loggers[name] = log
 	return log
 }
+
+// SetLogLevel changes the log level of a specific subsystem
+// name=="*" changes all subsystems
+func SetLogLevel(name, level string) error {
+	lvl, err := logging.LogLevel(level)
+	if err != nil {
+		return err
+	}
+
+	// wildcard, change all
+	if name == "*" {
+		SetAllLoggers(lvl)
+		return nil
+	}
+
+	// Check if we have a logger by that name
+	// logging.SetLevel() can't tell us...
+	_, ok := loggers[name]
+	if !ok {
+		return ErrNoSuchLogger
+	}
+
+	logging.SetLevel(lvl, name)
+
+	return nil
+}

util/util.go

@@ -4,17 +4,15 @@ import (
 	"errors"
 	"io"
 	"math/rand"
+	"os"
 	"path/filepath"
+	"strings"
 	"time"
 
 	ds "github.com/jbenet/go-ipfs/Godeps/_workspace/src/github.com/jbenet/datastore.go"
 	"github.com/jbenet/go-ipfs/Godeps/_workspace/src/github.com/mitchellh/go-homedir"
 )
 
-func init() {
-	SetupLogging()
-}
-
 // Debug is a global flag for debugging.
 var Debug bool
 
@@ -31,6 +29,9 @@ var ErrSearchIncomplete = errors.New("Error: Search Incomplete.")
 // ErrNotFound is returned when a search fails to find anything
 var ErrNotFound = ds.ErrNotFound
 
+// ErrNoSuchLogger is returned when the util pkg is asked for a non existant logger
+var ErrNoSuchLogger = errors.New("Error: No such logger")
+
 // TildeExpansion expands a filename, which may begin with a tilde.
 func TildeExpansion(filename string) (string, error) {
 	return homedir.Expand(filename)
@@ -121,3 +122,9 @@ func (r *randGen) Read(p []byte) (n int, err error) {
 
 	panic("unreachable")
 }
+
+// GetenvBool is the way to check an env var as a boolean
+func GetenvBool(name string) bool {
+	v := strings.ToLower(os.Getenv(name))
+	return v == "true" || v == "t" || v == "1"
+}