Reorganize logging

- Move the opening/closing of logs to the log package
- Use conditional compilation for redirecting stdout/err to logfile,
  Unix allows a superior method to Windows
- Panic output will now to go log file on Unix platforms

inbucket.go

@@ -5,7 +5,6 @@ import (
 	"expvar"
 	"flag"
 	"fmt"
-	golog "log"
 	"os"
 	"os/signal"
 	"syscall"
@@ -35,9 +34,6 @@ var (
 	// startTime is used to calculate uptime of Inbucket
 	startTime = time.Now()
 
-	// The file we send log output to, will be nil for stderr or stdout
-	logf *os.File
-
 	// Server instances
 	smtpServer *smtpd.Server
 	pop3Server *pop3d.Server
@@ -69,40 +65,14 @@ func main() {
 	signal.Notify(sigChan, syscall.SIGHUP, syscall.SIGTERM, syscall.SIGINT)
 	go signalProcessor(sigChan)
 
-	// Configure logging, close std* fds
+	// Initialize logging
 	level, _ := config.Config.String("logging", "level")
 	log.SetLogLevel(level)
-
-	if *logfile != "stderr" {
-		// stderr is the go logging default
-		if *logfile == "stdout" {
-			// set to stdout
-			golog.SetOutput(os.Stdout)
-		} else {
-			err = openLogFile()
-			if err != nil {
+	if err := log.Initialize(*logfile); err != nil {
 		fmt.Fprintf(os.Stderr, "%v", err)
 		os.Exit(1)
 	}
-			defer closeLogFile()
-
-			// Close std* streams to prevent accidental output, they will be redirected to
-			// our logfile below
-			if err := os.Stdout.Close(); err != nil {
-				log.Errorf("Failed to close os.Stdout during log setup")
-			}
-			// Warning: this will hide panic() output
-			// TODO Replace with syscall.Dup2 per https://github.com/golang/go/issues/325
-			if err := os.Stderr.Close(); err != nil {
-				log.Errorf("Failed to close os.Stderr during log setup")
-			}
-			if err := os.Stdin.Close(); err != nil {
-				log.Errorf("Failed to close os.Stdin during log setup")
-			}
-			os.Stdout = logf
-			os.Stderr = logf
-		}
-	}
+	defer log.Close()
 
 	log.Infof("Inbucket %v (%v) starting...", config.Version, config.BuildDate)
 
@@ -148,41 +118,14 @@ func main() {
 	}
 }
 
-// openLogFile creates or appends to the logfile passed on commandline
-func openLogFile() error {
-	// use specified log file
-	var err error
-	logf, err = os.OpenFile(*logfile, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0666)
-	if err != nil {
-		return fmt.Errorf("Failed to create %v: %v\n", *logfile, err)
-	}
-	golog.SetOutput(logf)
-	log.Tracef("Opened new logfile")
-	return nil
-}
-
-// closeLogFile closes the current logfile
-func closeLogFile() {
-	log.Tracef("Closing logfile")
-	// We are never in a situation where we can do anything about failing to close
-	_ = logf.Close()
-}
-
 // signalProcessor is a goroutine that handles OS signals
 func signalProcessor(c <-chan os.Signal) {
 	for {
 		sig := <-c
 		switch sig {
 		case syscall.SIGHUP:
-			// Rotate logs if configured
-			if logf != nil {
 			log.Infof("Recieved SIGHUP, cycling logfile")
-				closeLogFile()
-				// There is nothing we can do if the log open fails
-				_ = openLogFile()
-			} else {
-				log.Infof("Ignoring SIGHUP, logfile not configured")
-			}
+			log.Rotate()
 		case syscall.SIGINT:
 			// Initiate shutdown
 			log.Infof("Received SIGINT, shutting down")

log/logging.go

@@ -1,7 +1,9 @@
 package log
 
 import (
+	"fmt"
 	golog "log"
+	"os"
 	"strings"
 )
 
@@ -19,8 +21,37 @@ const (
 	TRACE
 )
 
+var (
 	// MaxLevel is the highest Level we will log (max TRACE, min ERROR)
-var MaxLevel = TRACE
+	MaxLevel = TRACE
+
+	// logfname is the name of the logfile
+	logfname string
+
+	// logf is the file we send log output to, will be nil for stderr or stdout
+	logf *os.File
+)
+
+// Initialize logging.  If logfile is equal to "stderr" or "stdout", then
+// we will log to that output stream.  Otherwise the specificed file will
+// opened for writing, and all log data will be placed in it.
+func Initialize(logfile string) error {
+	if logfile != "stderr" {
+		// stderr is the go logging default
+		if logfile == "stdout" {
+			// set to stdout
+			golog.SetOutput(os.Stdout)
+		} else {
+			logfname = logfile
+			if err := openLogFile(); err != nil {
+				return err
+			}
+			// Platform specific
+			closeStdin()
+		}
+	}
+	return nil
+}
 
 // SetLogLevel sets MaxLevel based on the provided string
 func SetLogLevel(level string) (ok bool) {
@@ -69,3 +100,46 @@ func Tracef(msg string, args ...interface{}) {
 		golog.Printf(msg, args...)
 	}
 }
+
+// Rotate closes the current log file, then reopens it.  This gives an external
+// log rotation system the opportunity to move the existing log file out of the
+// way and have Inbucket create a new one.
+func Rotate() {
+	// Rotate logs if configured
+	if logf != nil {
+		closeLogFile()
+		// There is nothing we can do if the log open fails
+		_ = openLogFile()
+	} else {
+		Infof("Ignoring SIGHUP, logfile not configured")
+	}
+}
+
+// Close the log file if we have one open
+func Close() {
+	if logf != nil {
+		closeLogFile()
+	}
+}
+
+// openLogFile creates or appends to the logfile passed on commandline
+func openLogFile() error {
+	// use specified log file
+	var err error
+	logf, err = os.OpenFile(logfname, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0666)
+	if err != nil {
+		return fmt.Errorf("Failed to create %v: %v\n", logfname, err)
+	}
+	golog.SetOutput(logf)
+	Tracef("Opened new logfile")
+	// Platform specific
+	reassignStdout()
+	return nil
+}
+
+// closeLogFile closes the current logfile
+func closeLogFile() {
+	Tracef("Closing logfile")
+	// We are never in a situation where we can do anything about failing to close
+	_ = logf.Close()
+}

log/stdout_unix.go

@@ -0,0 +1,31 @@
+// +build !windows
+
+package log
+
+import (
+	"golang.org/x/sys/unix"
+	"os"
+)
+
+// closeStdin will close stdin on Unix platforms - this is standard practice
+// for daemons
+func closeStdin() {
+	if err := os.Stdin.Close(); err != nil {
+		// Not a fatal error
+		Errorf("Failed to close os.Stdin during log setup")
+	}
+}
+
+// reassignStdout points stdout/stderr to our logfile on systems that support
+// the Dup2 syscall per https://github.com/golang/go/issues/325
+func reassignStdout() {
+	Tracef("Unix reassignStdout()")
+	if err := unix.Dup2(int(logf.Fd()), 1); err != nil {
+		// Not considered fatal
+		Errorf("Failed to re-assign stdout to logfile: %v", err)
+	}
+	if err := unix.Dup2(int(logf.Fd()), 2); err != nil {
+		// Not considered fatal
+		Errorf("Failed to re-assign stderr to logfile: %v", err)
+	}
+}

log/stdout_windows.go

@@ -0,0 +1,37 @@
+// +build windows
+
+package log
+
+import (
+	"os"
+)
+
+var stdOutsClosed = false
+
+// closeStdin does nothing on Windows, it would always fail
+func closeStdin() {
+	// Nop
+}
+
+// reassignStdout points stdout/stderr to our logfile on systems that do not
+// support the Dup2 syscall
+func reassignStdout() {
+	Tracef("Windows reassignStdout()")
+	if !stdOutsClosed {
+		// Close std* streams to prevent accidental output, they will be redirected to
+		// our logfile below
+
+		// Warning: this will hide panic() output, sorry Windows users
+		if err := os.Stderr.Close(); err != nil {
+			// Not considered fatal
+			Errorf("Failed to close os.Stderr during log setup")
+		}
+		if err := os.Stdin.Close(); err != nil {
+			// Not considered fatal
+			Errorf("Failed to close os.Stdin during log setup")
+		}
+		os.Stdout = logf
+		os.Stderr = logf
+		stdOutsClosed = true
+	}
+}