git » chasquid » commit 60a7932

diff --git a/chasquid.go b/chasquid.go
index b07c993..2b009d4 100644
--- a/chasquid.go
+++ b/chasquid.go
@@ -9,14 +9,13 @@ import (
 	"math/rand"
 	"net"
 	"os"
-	"os/signal"
 	"path/filepath"
 	"strconv"
-	"syscall"
 	"time"
 
 	"blitiri.com.ar/go/chasquid/internal/config"
 	"blitiri.com.ar/go/chasquid/internal/courier"
+	"blitiri.com.ar/go/chasquid/internal/log"
 	"blitiri.com.ar/go/chasquid/internal/maillog"
 	"blitiri.com.ar/go/chasquid/internal/normalize"
 	"blitiri.com.ar/go/chasquid/internal/smtpsrv"
@@ -25,8 +24,6 @@ import (
 
 	"net/http"
 	_ "net/http/pprof"
-
-	"github.com/golang/glog"
 )
 
 // Command-line flags.
@@ -53,6 +50,7 @@ var (
 
 func main() {
 	flag.Parse()
+	log.Init()
 
 	parseVersionInfo()
 	if *showVer {
@@ -60,19 +58,14 @@ func main() {
 		return
 	}
 
-	glog.Infof("chasquid starting (version %s)", version)
-
-	setupSignalHandling()
-
-	defer glog.Flush()
-	go periodicallyFlushLogs()
+	log.Infof("chasquid starting (version %s)", version)
 
 	// Seed the PRNG, just to prevent for it to be totally predictable.
 	rand.Seed(time.Now().UnixNano())
 
 	conf, err := config.Load(*configDir + "/chasquid.conf")
 	if err != nil {
-		glog.Fatalf("Error reading config: %v", err)
+		log.Fatalf("Error reading config: %v", err)
 	}
 	config.LogConfig(conf)
 
@@ -98,10 +91,10 @@ func main() {
 
 	// Load certificates from "certs/<directory>/{fullchain,privkey}.pem".
 	// The structure matches letsencrypt's, to make it easier for that case.
-	glog.Infof("Loading certificates")
+	log.Infof("Loading certificates")
 	for _, info := range mustReadDir("certs/") {
 		name := info.Name()
-		glog.Infof("  %s", name)
+		log.Infof("  %s", name)
 
 		certPath := filepath.Join("certs/", name, "fullchain.pem")
 		if _, err := os.Stat(certPath); os.IsNotExist(err) {
@@ -114,16 +107,16 @@ func main() {
 
 		err := s.AddCerts(certPath, keyPath)
 		if err != nil {
-			glog.Fatalf("    %v", err)
+			log.Fatalf("    %v", err)
 		}
 	}
 
 	// Load domains from "domains/".
-	glog.Infof("Domain config paths:")
+	log.Infof("Domain config paths:")
 	for _, info := range mustReadDir("domains/") {
 		domain, err := normalize.Domain(info.Name())
 		if err != nil {
-			glog.Fatalf("Invalid name %+q: %v", info.Name(), err)
+			log.Fatalf("Invalid name %+q: %v", info.Name(), err)
 		}
 		dir := filepath.Join("domains", info.Name())
 		loadDomain(domain, dir, s)
@@ -147,7 +140,7 @@ func main() {
 	// Load the addresses and listeners.
 	systemdLs, err := systemd.Listeners()
 	if err != nil {
-		glog.Fatalf("Error getting systemd listeners: %v", err)
+		log.Fatalf("Error getting systemd listeners: %v", err)
 	}
 
 	loadAddresses(s, conf.SmtpAddress,
@@ -173,9 +166,9 @@ func loadAddresses(srv *smtpsrv.Server, addrs []string, ls []net.Listener, mode
 	}
 
 	if acount == 0 {
-		glog.Errorf("No %v addresses/listeners", mode)
-		glog.Errorf("If using systemd, check that you named the sockets")
-		glog.Fatalf("Exiting")
+		log.Errorf("No %v addresses/listeners", mode)
+		log.Errorf("If using systemd, check that you named the sockets")
+		log.Fatalf("Exiting")
 	}
 }
 
@@ -187,64 +180,45 @@ func initMailLog(path string) {
 	} else {
 		os.MkdirAll(filepath.Dir(path), 0775)
 		var f *os.File
-		f, err = os.OpenFile(path, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0666)
+		f, err = os.OpenFile(path, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0664)
 		maillog.Default = maillog.New(f)
 	}
 
 	if err != nil {
-		glog.Fatalf("Error opening mail log: %v", err)
+		log.Fatalf("Error opening mail log: %v", err)
 	}
 }
 
 // Helper to load a single domain configuration into the server.
 func loadDomain(name, dir string, s *smtpsrv.Server) {
-	glog.Infof("  %s", name)
+	log.Infof("  %s", name)
 	s.AddDomain(name)
 
 	if _, err := os.Stat(dir + "/users"); err == nil {
-		glog.Infof("    adding users")
+		log.Infof("    adding users")
 		udb, err := userdb.Load(dir + "/users")
 		if err != nil {
-			glog.Errorf("      error: %v", err)
+			log.Errorf("      error: %v", err)
 		} else {
 			s.AddUserDB(name, udb)
 		}
 	}
 
-	glog.Infof("    adding aliases")
+	log.Infof("    adding aliases")
 	err := s.AddAliasesFile(name, dir+"/aliases")
 	if err != nil {
-		glog.Errorf("      error: %v", err)
-	}
-}
-
-// Flush logs periodically, to help troubleshooting if there isn't that much
-// traffic.
-func periodicallyFlushLogs() {
-	for range time.Tick(5 * time.Second) {
-		glog.Flush()
+		log.Errorf("      error: %v", err)
 	}
 }
 
-// Set up signal handling, to flush logs when we get killed.
-func setupSignalHandling() {
-	c := make(chan os.Signal, 1)
-	signal.Notify(c, os.Interrupt, syscall.SIGTERM)
-	go func() {
-		<-c
-		glog.Flush()
-		os.Exit(1)
-	}()
-}
-
 // Read a directory, which must have at least some entries.
 func mustReadDir(path string) []os.FileInfo {
 	dirs, err := ioutil.ReadDir(path)
 	if err != nil {
-		glog.Fatalf("Error reading %q directory: %v", path, err)
+		log.Fatalf("Error reading %q directory: %v", path, err)
 	}
 	if len(dirs) == 0 {
-		glog.Fatalf("No entries found in %q", path)
+		log.Fatalf("No entries found in %q", path)
 	}
 
 	return dirs
@@ -264,7 +238,7 @@ func parseVersionInfo() {
 }
 
 func launchMonitoringServer(addr string) {
-	glog.Infof("Monitoring HTTP server listening on %s", addr)
+	log.Infof("Monitoring HTTP server listening on %s", addr)
 
 	indexData := struct {
 		Version    string
@@ -282,7 +256,7 @@ func launchMonitoringServer(addr string) {
 			return
 		}
 		if err := monitoringHTMLIndex.Execute(w, indexData); err != nil {
-			glog.Infof("monitoring handler error: %v", err)
+			log.Infof("monitoring handler error: %v", err)
 		}
 	})
 
diff --git a/internal/config/config.go b/internal/config/config.go
index 85b284b..33c810f 100644
--- a/internal/config/config.go
+++ b/internal/config/config.go
@@ -8,7 +8,8 @@ import (
 	"io/ioutil"
 	"os"
 
-	"github.com/golang/glog"
+	"blitiri.com.ar/go/chasquid/internal/log"
+
 	"github.com/golang/protobuf/proto"
 )
 
@@ -18,14 +19,14 @@ func Load(path string) (*Config, error) {
 
 	buf, err := ioutil.ReadFile(path)
 	if err != nil {
-		glog.Errorf("Failed to read config at %q", path)
-		glog.Errorf("  (%v)", err)
+		log.Errorf("Failed to read config at %q", path)
+		log.Errorf("  (%v)", err)
 		return nil, err
 	}
 
 	err = proto.UnmarshalText(string(buf), c)
 	if err != nil {
-		glog.Errorf("Error parsing config: %v", err)
+		log.Errorf("Error parsing config: %v", err)
 		return nil, err
 	}
 
@@ -34,7 +35,7 @@ func Load(path string) (*Config, error) {
 	if c.Hostname == "" {
 		c.Hostname, err = os.Hostname()
 		if err != nil {
-			glog.Errorf("Could not get hostname: %v", err)
+			log.Errorf("Could not get hostname: %v", err)
 			return nil, err
 		}
 	}
@@ -78,15 +79,15 @@ func Load(path string) (*Config, error) {
 }
 
 func LogConfig(c *Config) {
-	glog.Infof("Configuration:")
-	glog.Infof("  Hostname: %q", c.Hostname)
-	glog.Infof("  Max data size (MB): %d", c.MaxDataSizeMb)
-	glog.Infof("  SMTP Addresses: %v", c.SmtpAddress)
-	glog.Infof("  Submission Addresses: %v", c.SubmissionAddress)
-	glog.Infof("  Monitoring address: %s", c.MonitoringAddress)
-	glog.Infof("  MDA: %s %v", c.MailDeliveryAgentBin, c.MailDeliveryAgentArgs)
-	glog.Infof("  Data directory: %s", c.DataDir)
-	glog.Infof("  Suffix separators: %s", c.SuffixSeparators)
-	glog.Infof("  Drop characters: %s", c.DropCharacters)
-	glog.Infof("  Mail log: %s", c.MailLogPath)
+	log.Infof("Configuration:")
+	log.Infof("  Hostname: %q", c.Hostname)
+	log.Infof("  Max data size (MB): %d", c.MaxDataSizeMb)
+	log.Infof("  SMTP Addresses: %v", c.SmtpAddress)
+	log.Infof("  Submission Addresses: %v", c.SubmissionAddress)
+	log.Infof("  Monitoring address: %s", c.MonitoringAddress)
+	log.Infof("  MDA: %s %v", c.MailDeliveryAgentBin, c.MailDeliveryAgentArgs)
+	log.Infof("  Data directory: %s", c.DataDir)
+	log.Infof("  Suffix separators: %s", c.SuffixSeparators)
+	log.Infof("  Drop characters: %s", c.DropCharacters)
+	log.Infof("  Mail log: %s", c.MailLogPath)
 }
diff --git a/internal/courier/smtp.go b/internal/courier/smtp.go
index 91f8bf5..1b3adb4 100644
--- a/internal/courier/smtp.go
+++ b/internal/courier/smtp.go
@@ -8,7 +8,6 @@ import (
 	"os"
 	"time"
 
-	"github.com/golang/glog"
 	"golang.org/x/net/idna"
 
 	"blitiri.com.ar/go/chasquid/internal/domaininfo"
@@ -48,7 +47,7 @@ func (s *SMTP) Deliver(from string, to string, data []byte) (error, bool) {
 	tr.Debugf("%s  ->  %s", from, to)
 
 	toDomain := envelope.DomainOf(to)
-	mx, err := lookupMX(toDomain)
+	mx, err := lookupMX(tr, toDomain)
 	if err != nil {
 		// Note this is considered a permanent error.
 		// This is in line with what other servers (Exim) do. However, the
@@ -162,7 +161,7 @@ retry:
 	return nil, false
 }
 
-func lookupMX(domain string) (string, error) {
+func lookupMX(tr *trace.Trace, domain string) (string, error) {
 	if v, ok := fakeMX[domain]; ok {
 		return v, nil
 	}
@@ -175,10 +174,11 @@ func lookupMX(domain string) (string, error) {
 	mxs, err := net.LookupMX(domain)
 	if err == nil {
 		if len(mxs) == 0 {
-			glog.Infof("domain %q has no MX, falling back to A", domain)
+			tr.Printf("domain %q has no MX, falling back to A", domain)
 			return domain, nil
 		}
 
+		tr.Printf("MX %s", mxs[0].Host)
 		return mxs[0].Host, nil
 	}
 
@@ -188,6 +188,7 @@ func lookupMX(domain string) (string, error) {
 	// For now, if the error is permanent, we assume it's because there was no
 	// MX and fall back, otherwise we return.
 	// TODO: Find a better way to do this.
+	tr.Errorf("MX lookup error: %v", err)
 	dnsErr, ok := err.(*net.DNSError)
 	if !ok {
 		return "", err
diff --git a/internal/log/log.go b/internal/log/log.go
new file mode 100644
index 0000000..9cde2d1
--- /dev/null
+++ b/internal/log/log.go
@@ -0,0 +1,249 @@
+// Package log implements a simple logger.
+//
+// It implements an API somewhat similar to "github.com/google/glog" with a
+// focus towards logging to stderr, which is useful for systemd-based
+// environments.
+//
+// There are command line flags (defined using the flag package) to control
+// the behaviour of the default logger. By default, it will write to stderr
+// without timestamps; this is suitable for systemd (or equivalent) logging.
+package log
+
+import (
+	"flag"
+	"fmt"
+	"io"
+	"log/syslog"
+	"os"
+	"path/filepath"
+	"runtime"
+	"strconv"
+	"strings"
+	"sync"
+	"time"
+)
+
+// Flags that control the default logging.
+var (
+	vLevel = flag.Int("v", 0, "Verbosity level (1 = debug)")
+
+	logFile = flag.String("logfile", "",
+		"file to log to (enables logtime)")
+
+	logToSyslog = flag.String("logtosyslog", "",
+		"log to syslog, with the given tag")
+
+	logTime = flag.Bool("logtime", false,
+		"include the time when writing the log to stderr")
+
+	alsoLogToStderr = flag.Bool("alsologtostderr", false,
+		"also log to stderr, in addition to the file")
+)
+
+// Logging levels.
+type Level int
+
+const (
+	Error = Level(-1)
+	Info  = Level(0)
+	Debug = Level(1)
+)
+
+var levelToLetter = map[Level]string{
+	Error: "E",
+	Info:  "_",
+	Debug: ".",
+}
+
+// A Logger represents a logging object that writes logs to the given writer.
+type Logger struct {
+	Level   Level
+	LogTime bool
+
+	CallerSkip int
+
+	w io.WriteCloser
+	sync.Mutex
+}
+
+func New(w io.WriteCloser) *Logger {
+	return &Logger{
+		w:          w,
+		CallerSkip: 0,
+		Level:      Info,
+		LogTime:    true,
+	}
+}
+
+func NewFile(path string) (*Logger, error) {
+	f, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0644)
+	if err != nil {
+		return nil, err
+	}
+
+	l := New(f)
+	l.LogTime = true
+	return l, nil
+}
+
+func NewSyslog(priority syslog.Priority, tag string) (*Logger, error) {
+	w, err := syslog.New(priority, tag)
+	if err != nil {
+		return nil, err
+	}
+
+	l := New(w)
+	l.LogTime = false
+	return l, nil
+}
+
+func (l *Logger) Close() {
+	l.w.Close()
+}
+
+func (l *Logger) V(level Level) bool {
+	return level <= l.Level
+}
+
+func (l *Logger) Log(level Level, skip int, format string, a ...interface{}) {
+	if !l.V(level) {
+		return
+	}
+
+	// Message.
+	msg := fmt.Sprintf(format, a...)
+
+	// Caller.
+	_, file, line, ok := runtime.Caller(1 + l.CallerSkip + skip)
+	if !ok {
+		file = "unknown"
+	}
+	fl := fmt.Sprintf("%s:%-4d", filepath.Base(file), line)
+	if len(fl) > 18 {
+		fl = fl[len(fl)-18:]
+	}
+	msg = fmt.Sprintf("%-18s", fl) + " " + msg
+
+	// Level.
+	letter, ok := levelToLetter[level]
+	if !ok {
+		letter = strconv.Itoa(int(level))
+	}
+	msg = letter + " " + msg
+
+	// Time.
+	if l.LogTime {
+		msg = time.Now().Format("20060102 15:04:05.000000 ") + msg
+	}
+
+	if !strings.HasSuffix(msg, "\n") {
+		msg += "\n"
+	}
+
+	l.Lock()
+	l.w.Write([]byte(msg))
+	l.Unlock()
+}
+
+func (l *Logger) Debugf(format string, a ...interface{}) {
+	l.Log(Debug, 1, format, a...)
+}
+
+func (l *Logger) Infof(format string, a ...interface{}) {
+	l.Log(Info, 1, format, a...)
+}
+
+func (l *Logger) Errorf(format string, a ...interface{}) error {
+	l.Log(Error, 1, format, a...)
+	return fmt.Errorf(format, a...)
+}
+
+func (l *Logger) Fatalf(format string, a ...interface{}) {
+	l.Log(-2, 1, format, a...)
+	// TODO: Log traceback?
+	os.Exit(1)
+}
+
+// The default logger, used by the top-level functions below.
+var Default = &Logger{
+	w:          os.Stderr,
+	CallerSkip: 1,
+	Level:      Info,
+	LogTime:    false,
+}
+
+// Init the default logger, based on the command-line flags.
+// Must be called after flag.Parse().
+func Init() {
+	var err error
+
+	if *logToSyslog != "" {
+		Default, err = NewSyslog(syslog.LOG_DAEMON|syslog.LOG_INFO, *logToSyslog)
+		if err != nil {
+			panic(err)
+		}
+	} else if *logFile != "" {
+		Default, err = NewFile(*logFile)
+		if err != nil {
+			panic(err)
+		}
+		*logTime = true
+	}
+
+	if *alsoLogToStderr && Default.w != os.Stderr {
+		Default.w = multiWriteCloser(Default.w, os.Stderr)
+	}
+
+	Default.CallerSkip = 1
+	Default.Level = Level(*vLevel)
+	Default.LogTime = *logTime
+}
+
+func V(level Level) bool {
+	return Default.V(level)
+}
+
+func Log(level Level, skip int, format string, a ...interface{}) {
+	Default.Log(level, skip, format, a...)
+}
+
+func Debugf(format string, a ...interface{}) {
+	Default.Debugf(format, a...)
+}
+
+func Infof(format string, a ...interface{}) {
+	Default.Infof(format, a...)
+}
+
+func Errorf(format string, a ...interface{}) error {
+	return Default.Errorf(format, a...)
+}
+
+func Fatalf(format string, a ...interface{}) {
+	Default.Fatalf(format, a...)
+}
+
+// multiWriteCloser creates a WriteCloser that duplicates its writes and
+// closes to all the provided writers.
+func multiWriteCloser(wc ...io.WriteCloser) io.WriteCloser {
+	return mwc(wc)
+}
+
+type mwc []io.WriteCloser
+
+func (m mwc) Write(p []byte) (n int, err error) {
+	for _, w := range m {
+		if n, err = w.Write(p); err != nil {
+			return
+		}
+	}
+	return
+}
+func (m mwc) Close() error {
+	for _, w := range m {
+		if err := w.Close(); err != nil {
+			return err
+		}
+	}
+	return nil
+}
diff --git a/internal/log/log_test.go b/internal/log/log_test.go
new file mode 100644
index 0000000..06764d6
--- /dev/null
+++ b/internal/log/log_test.go
@@ -0,0 +1,104 @@
+package log
+
+import (
+	"io/ioutil"
+	"os"
+	"regexp"
+	"testing"
+)
+
+func mustNewFile(t *testing.T) (string, *Logger) {
+	f, err := ioutil.TempFile("", "log_test-")
+	if err != nil {
+		t.Fatalf("failed to create temp file: %v", err)
+	}
+
+	l, err := NewFile(f.Name())
+	if err != nil {
+		t.Fatalf("failed to open new log file: %v", err)
+	}
+
+	return f.Name(), l
+}
+
+func checkContentsMatch(t *testing.T, name, path, expected string) {
+	content, err := ioutil.ReadFile(path)
+	if err != nil {
+		panic(err)
+	}
+
+	got := string(content)
+	if !regexp.MustCompile(expected).Match(content) {
+		t.Errorf("%s: regexp %q did not match %q",
+			name, expected, got)
+	}
+}
+
+func testLogger(t *testing.T, fname string, l *Logger) {
+	l.LogTime = false
+	l.Infof("message %d", 1)
+	checkContentsMatch(t, "info-no-time", fname,
+		"^_ log_test.go:....   message 1\n")
+
+	os.Truncate(fname, 0)
+	l.Infof("message %d\n", 1)
+	checkContentsMatch(t, "info-with-newline", fname,
+		"^_ log_test.go:....   message 1\n")
+
+	os.Truncate(fname, 0)
+	l.LogTime = true
+	l.Infof("message %d", 1)
+	checkContentsMatch(t, "info-with-time", fname,
+		`^\d{8} ..:..:..\.\d{6} _ log_test.go:....   message 1\n`)
+
+	os.Truncate(fname, 0)
+	l.LogTime = false
+	l.Errorf("error %d", 1)
+	checkContentsMatch(t, "error", fname, `^E log_test.go:....   error 1\n`)
+
+	if l.V(Debug) {
+		t.Fatalf("Debug level enabled by default (level: %v)", l.Level)
+	}
+
+	os.Truncate(fname, 0)
+	l.LogTime = false
+	l.Debugf("debug %d", 1)
+	checkContentsMatch(t, "debug-no-log", fname, `^$`)
+
+	os.Truncate(fname, 0)
+	l.Level = Debug
+	l.Debugf("debug %d", 1)
+	checkContentsMatch(t, "debug", fname, `^\. log_test.go:....   debug 1\n`)
+
+	if !l.V(Debug) {
+		t.Errorf("l.Level = Debug, but V(Debug) = false")
+	}
+
+	os.Truncate(fname, 0)
+	l.Level = Info
+	l.Log(Debug, 0, "log debug %d", 1)
+	l.Log(Info, 0, "log info %d", 1)
+	checkContentsMatch(t, "log", fname,
+		`^_ log_test.go:....   log info 1\n`)
+
+}
+
+func TestBasic(t *testing.T) {
+	fname, l := mustNewFile(t)
+	defer l.Close()
+	defer os.Remove(fname)
+
+	testLogger(t, fname, l)
+}
+
+func TestDefaultFile(t *testing.T) {
+	fname, l := mustNewFile(t)
+	l.Close()
+	defer os.Remove(fname)
+
+	*logFile = fname
+
+	Init()
+
+	testLogger(t, fname, Default)
+}
diff --git a/internal/maillog/maillog.go b/internal/maillog/maillog.go
index 4632793..87711b6 100644
--- a/internal/maillog/maillog.go
+++ b/internal/maillog/maillog.go
@@ -10,8 +10,7 @@ import (
 	"sync"
 	"time"
 
-	"github.com/golang/glog"
-
+	"blitiri.com.ar/go/chasquid/internal/log"
 	"blitiri.com.ar/go/chasquid/internal/trace"
 )
 
@@ -53,8 +52,8 @@ func (l *Logger) printf(format string, args ...interface{}) {
 	_, err := fmt.Fprintf(l.w, format, args...)
 	if err != nil {
 		l.once.Do(func() {
-			glog.Errorf("failed to write to maillog: %v", err)
-			glog.Error("(will not report this again)")
+			log.Errorf("failed to write to maillog: %v", err)
+			log.Errorf("(will not report this again)")
 		})
 	}
 }
diff --git a/internal/queue/queue.go b/internal/queue/queue.go
index 74635f7..140137c 100644
--- a/internal/queue/queue.go
+++ b/internal/queue/queue.go
@@ -24,12 +24,12 @@ import (
 	"blitiri.com.ar/go/chasquid/internal/aliases"
 	"blitiri.com.ar/go/chasquid/internal/courier"
 	"blitiri.com.ar/go/chasquid/internal/envelope"
+	"blitiri.com.ar/go/chasquid/internal/log"
 	"blitiri.com.ar/go/chasquid/internal/maillog"
 	"blitiri.com.ar/go/chasquid/internal/protoio"
 	"blitiri.com.ar/go/chasquid/internal/set"
 	"blitiri.com.ar/go/chasquid/internal/trace"
 
-	"github.com/golang/glog"
 	"github.com/golang/protobuf/ptypes"
 	"github.com/golang/protobuf/ptypes/timestamp"
 	"golang.org/x/net/idna"
@@ -139,7 +139,7 @@ func (q *Queue) Load() error {
 	for _, fname := range files {
 		item, err := ItemFromFile(fname)
 		if err != nil {
-			glog.Errorf("error loading queue item from %q: %v", fname, err)
+			log.Errorf("error loading queue item from %q: %v", fname, err)
 			continue
 		}
 
@@ -197,7 +197,7 @@ func (q *Queue) Put(from string, to []string, data []byte) (string, error) {
 			case aliases.PIPE:
 				r.Type = Recipient_PIPE
 			default:
-				glog.Errorf("unknown alias type %v when resolving %q",
+				log.Errorf("unknown alias type %v when resolving %q",
 					aliasRcpt.Type, t)
 				return "", fmt.Errorf("internal error - unknown alias type")
 			}
@@ -225,7 +225,7 @@ func (q *Queue) Remove(id string) {
 	path := fmt.Sprintf("%s/%s%s", q.path, itemFilePrefix, id)
 	err := os.Remove(path)
 	if err != nil {
-		glog.Errorf("failed to remove queue file %q: %v", path, err)
+		log.Errorf("failed to remove queue file %q: %v", path, err)
 	}
 
 	q.mu.Lock()
diff --git a/internal/smtpsrv/server.go b/internal/smtpsrv/server.go
index c366b70..b1378e0 100644
--- a/internal/smtpsrv/server.go
+++ b/internal/smtpsrv/server.go
@@ -11,11 +11,11 @@ import (
 	"blitiri.com.ar/go/chasquid/internal/aliases"
 	"blitiri.com.ar/go/chasquid/internal/courier"
 	"blitiri.com.ar/go/chasquid/internal/domaininfo"
+	"blitiri.com.ar/go/chasquid/internal/log"
 	"blitiri.com.ar/go/chasquid/internal/maillog"
 	"blitiri.com.ar/go/chasquid/internal/queue"
 	"blitiri.com.ar/go/chasquid/internal/set"
 	"blitiri.com.ar/go/chasquid/internal/userdb"
-	"github.com/golang/glog"
 )
 
 type Server struct {
@@ -111,12 +111,12 @@ func (s *Server) InitDomainInfo(dir string) *domaininfo.DB {
 	var err error
 	s.dinfo, err = domaininfo.New(dir)
 	if err != nil {
-		glog.Fatalf("Error opening domain info database: %v", err)
+		log.Fatalf("Error opening domain info database: %v", err)
 	}
 
 	err = s.dinfo.Load()
 	if err != nil {
-		glog.Fatalf("Error loading domain info database: %v", err)
+		log.Fatalf("Error loading domain info database: %v", err)
 	}
 
 	return s.dinfo
@@ -126,7 +126,7 @@ func (s *Server) InitQueue(path string, localC, remoteC courier.Courier) {
 	q := queue.New(path, s.localDomains, s.aliasesR, localC, remoteC, s.Hostname)
 	err := q.Load()
 	if err != nil {
-		glog.Fatalf("Error loading queue: %v", err)
+		log.Fatalf("Error loading queue: %v", err)
 	}
 	s.queue = q
 
@@ -142,13 +142,13 @@ func (s *Server) periodicallyReload() {
 	for range time.Tick(30 * time.Second) {
 		err := s.aliasesR.Reload()
 		if err != nil {
-			glog.Errorf("Error reloading aliases: %v", err)
+			log.Errorf("Error reloading aliases: %v", err)
 		}
 
 		for domain, udb := range s.userDBs {
 			err = udb.Reload()
 			if err != nil {
-				glog.Errorf("Error reloading %q user db: %v", domain, err)
+				log.Errorf("Error reloading %q user db: %v", domain, err)
 			}
 		}
 	}
@@ -165,10 +165,10 @@ func (s *Server) ListenAndServe() {
 		for _, addr := range addrs {
 			l, err := net.Listen("tcp", addr)
 			if err != nil {
-				glog.Fatalf("Error listening: %v", err)
+				log.Fatalf("Error listening: %v", err)
 			}
 
-			glog.Infof("Server listening on %s (%v)", addr, m)
+			log.Infof("Server listening on %s (%v)", addr, m)
 			maillog.Listening(addr)
 			go s.serve(l, m)
 		}
@@ -176,7 +176,7 @@ func (s *Server) ListenAndServe() {
 
 	for m, ls := range s.listeners {
 		for _, l := range ls {
-			glog.Infof("Server listening on %s (%v, via systemd)", l.Addr(), m)
+			log.Infof("Server listening on %s (%v, via systemd)", l.Addr(), m)
 			maillog.Listening(l.Addr().String())
 			go s.serve(l, m)
 		}
@@ -193,7 +193,7 @@ func (s *Server) serve(l net.Listener, mode SocketMode) {
 	for {
 		conn, err := l.Accept()
 		if err != nil {
-			glog.Fatalf("Error accepting: %v", err)
+			log.Fatalf("Error accepting: %v", err)
 		}
 
 		sc := &Conn{
diff --git a/internal/smtpsrv/server_test.go b/internal/smtpsrv/server_test.go
index 51f9286..db2150e 100644
--- a/internal/smtpsrv/server_test.go
+++ b/internal/smtpsrv/server_test.go
@@ -20,8 +20,6 @@ import (
 	"blitiri.com.ar/go/chasquid/internal/aliases"
 	"blitiri.com.ar/go/chasquid/internal/courier"
 	"blitiri.com.ar/go/chasquid/internal/userdb"
-
-	"github.com/golang/glog"
 )
 
 // Flags.
@@ -414,7 +412,6 @@ func waitForServer(addr string) error {
 // os.Exit(). We have to do this so we can use defer.
 func realMain(m *testing.M) int {
 	flag.Parse()
-	defer glog.Flush()
 
 	if *externalSMTPAddr != "" {
 		smtpAddr = *externalSMTPAddr
diff --git a/internal/trace/trace.go b/internal/trace/trace.go
index ccec62b..33cdc9c 100644
--- a/internal/trace/trace.go
+++ b/internal/trace/trace.go
@@ -5,7 +5,8 @@ import (
 	"fmt"
 	"strconv"
 
-	"github.com/golang/glog"
+	"blitiri.com.ar/go/chasquid/internal/log"
+
 	nettrace "golang.org/x/net/trace"
 )
 
@@ -28,21 +29,15 @@ func New(family, title string) *Trace {
 func (t *Trace) Printf(format string, a ...interface{}) {
 	t.t.LazyPrintf(format, a...)
 
-	if glog.V(0) {
-		msg := fmt.Sprintf("%s %s: %s", t.family, t.title,
-			quote(fmt.Sprintf(format, a...)))
-		glog.InfoDepth(1, msg)
-	}
+	log.Log(log.Info, 1, "%s %s: %s", t.family, t.title,
+		quote(fmt.Sprintf(format, a...)))
 }
 
 func (t *Trace) Debugf(format string, a ...interface{}) {
 	t.t.LazyPrintf(format, a...)
 
-	if glog.V(2) {
-		msg := fmt.Sprintf("%s %s: %s", t.family, t.title,
-			quote(fmt.Sprintf(format, a...)))
-		glog.InfoDepth(1, msg)
-	}
+	log.Log(log.Debug, 1, "%s %s: %s",
+		t.family, t.title, quote(fmt.Sprintf(format, a...)))
 }
 
 func (t *Trace) SetError() {
@@ -50,15 +45,13 @@ func (t *Trace) SetError() {
 }
 
 func (t *Trace) Errorf(format string, a ...interface{}) error {
+	// Note we can't just call t.Error here, as it breaks caller logging.
 	err := fmt.Errorf(format, a...)
 	t.t.SetError()
 	t.t.LazyPrintf("error: %v", err)
 
-	if glog.V(0) {
-		msg := fmt.Sprintf("%s %s: error: %s", t.family, t.title,
-			quote(err.Error()))
-		glog.InfoDepth(1, msg)
-	}
+	log.Log(log.Info, 1, "%s %s: error: %s", t.family, t.title,
+		quote(err.Error()))
 	return err
 }
 
@@ -66,11 +59,9 @@ func (t *Trace) Error(err error) error {
 	t.t.SetError()
 	t.t.LazyPrintf("error: %v", err)
 
-	if glog.V(0) {
-		msg := fmt.Sprintf("%s %s: error: %v", t.family, t.title,
-			quote(err.Error()))
-		glog.InfoDepth(1, msg)
-	}
+	log.Log(log.Info, 1, "%s %s: error: %s", t.family, t.title,
+		quote(err.Error()))
+
 	return err
 }
 
@@ -91,32 +82,24 @@ func NewEventLog(family, title string) *EventLog {
 func (e *EventLog) Printf(format string, a ...interface{}) {
 	e.e.Printf(format, a...)
 
-	if glog.V(0) {
-		msg := fmt.Sprintf("%s %s: %s", e.family, e.title,
-			quote(fmt.Sprintf(format, a...)))
-		glog.InfoDepth(1, msg)
-	}
+	log.Log(log.Info, 1, "%s %s: %s", e.family, e.title,
+		quote(fmt.Sprintf(format, a...)))
 }
 
 func (e *EventLog) Debugf(format string, a ...interface{}) {
 	e.e.Printf(format, a...)
 
-	if glog.V(2) {
-		msg := fmt.Sprintf("%s %s: %s", e.family, e.title,
-			quote(fmt.Sprintf(format, a...)))
-		glog.InfoDepth(1, msg)
-	}
+	log.Log(log.Debug, 1, "%s %s: %s", e.family, e.title,
+		quote(fmt.Sprintf(format, a...)))
 }
 
 func (e *EventLog) Errorf(format string, a ...interface{}) error {
 	err := fmt.Errorf(format, a...)
 	e.e.Errorf("error: %v", err)
 
-	if glog.V(0) {
-		msg := fmt.Sprintf("%s %s: error: %s", e.family, e.title,
-			quote(err.Error()))
-		glog.InfoDepth(1, msg)
-	}
+	log.Log(log.Info, 1, "%s %s: error: %s",
+		e.family, e.title, quote(err.Error()))
+
 	return err
 }
 
diff --git a/test/t-01-simple_local/run.sh b/test/t-01-simple_local/run.sh
index 116b972..3691c3e 100755
--- a/test/t-01-simple_local/run.sh
+++ b/test/t-01-simple_local/run.sh
@@ -10,7 +10,7 @@ add_user user@testserver secretpassword
 add_user someone@testserver secretpassword
 
 mkdir -p .logs
-chasquid -v=2 --log_dir=.logs --config_dir=config &
+chasquid -v=2 --logfile=.logs/chasquid.log --config_dir=config &
 wait_until_ready 1025
 
 run_msmtp someone@testserver < content
diff --git a/test/t-02-exim/run.sh b/test/t-02-exim/run.sh
index e8766e7..f0b2b87 100755
--- a/test/t-02-exim/run.sh
+++ b/test/t-02-exim/run.sh
@@ -45,7 +45,7 @@ add_user someone@srv-chasquid secretpassword
 # Use outgoing port 2025 which is where exim will be at.
 # Bypass MX lookup, so it can find srv-exim (via our host alias).
 mkdir -p .logs
-chasquid -v=2 --log_dir=.logs --config_dir=config \
+chasquid -v=2 --logfile=.logs/chasquid.log --config_dir=config \
 	--testing__outgoing_smtp_port=2025 &
 
 wait_until_ready 1025
diff --git a/test/t-03-queue_persistency/run.sh b/test/t-03-queue_persistency/run.sh
index fc08806..2ccf8fb 100755
--- a/test/t-03-queue_persistency/run.sh
+++ b/test/t-03-queue_persistency/run.sh
@@ -14,7 +14,7 @@ go run addtoqueue.go --queue_dir=.data/queue \
 generate_certs_for testserver
 
 mkdir -p .logs
-chasquid -v=2 --log_dir=.logs --config_dir=config &
+chasquid -v=2 --logfile=.logs/chasquid.log --config_dir=config &
 wait_until_ready 1025
 
 # Check that the item in the queue was delivered.
diff --git a/test/t-04-aliases/run.sh b/test/t-04-aliases/run.sh
index c497985..b8c8227 100755
--- a/test/t-04-aliases/run.sh
+++ b/test/t-04-aliases/run.sh
@@ -9,7 +9,7 @@ generate_certs_for testserver
 add_user user@testserver secretpassword
 
 mkdir -p .logs
-chasquid -v=2 --log_dir=.logs --config_dir=config &
+chasquid -v=2 --logfile=.logs/chasquid.log --config_dir=config &
 wait_until_ready 1025
 
 function send_and_check() {
diff --git a/test/t-05-null_address/run.sh b/test/t-05-null_address/run.sh
index 33681e9..fa2c6f7 100755
--- a/test/t-05-null_address/run.sh
+++ b/test/t-05-null_address/run.sh
@@ -9,7 +9,7 @@ generate_certs_for testserver
 add_user user@testserver secretpassword
 
 mkdir -p .logs
-chasquid -v=2 --log_dir=.logs --config_dir=config &
+chasquid -v=2 --logfile=.logs/chasquid.log --config_dir=config &
 wait_until_ready 1025
 
 
diff --git a/test/t-06-idna/run.sh b/test/t-06-idna/run.sh
index fa1a0df..57b08a2 100755
--- a/test/t-06-idna/run.sh
+++ b/test/t-06-idna/run.sh
@@ -23,9 +23,9 @@ CONFDIR=B add_user nadaB@nadaB nadaB
 
 mkdir -p .logs-A .logs-B
 
-chasquid -v=2 --log_dir=.logs-A --config_dir=A \
+chasquid -v=2 --logfile=.logs-A/chasquid.log --config_dir=A \
 	--testing__outgoing_smtp_port=2025 &
-chasquid -v=2 --log_dir=.logs-B --config_dir=B \
+chasquid -v=2 --logfile=.logs-B/chasquid.log --config_dir=B \
 	--testing__outgoing_smtp_port=1025 &
 
 wait_until_ready 1025
diff --git a/test/t-07-smtputf8/run.sh b/test/t-07-smtputf8/run.sh
index c7b7281..e0be8ba 100755
--- a/test/t-07-smtputf8/run.sh
+++ b/test/t-07-smtputf8/run.sh
@@ -21,7 +21,7 @@ add_user ñangapirí@ñoñOS antaño
 add_user nada@nada nada
 
 mkdir -p .logs
-chasquid -v=2 --log_dir=.logs --config_dir=config &
+chasquid -v=2 --logfile=.logs/chasquid.log --config_dir=config &
 wait_until_ready 1025
 
 # The envelope from and to are taken from the content, and use a mix of upper
diff --git a/test/t-09-loop/run.sh b/test/t-09-loop/run.sh
index 663c3de..3c51145 100755
--- a/test/t-09-loop/run.sh
+++ b/test/t-09-loop/run.sh
@@ -21,9 +21,9 @@ CONFDIR=B generate_certs_for srv-B
 
 mkdir -p .logs-A .logs-B
 
-chasquid -v=2 --log_dir=.logs-A --config_dir=A \
+chasquid -v=2 --logfile=.logs-A/chasquid.log --config_dir=A \
 	--testing__outgoing_smtp_port=2025 &
-chasquid -v=2 --log_dir=.logs-B --config_dir=B \
+chasquid -v=2 --logfile=.logs-B/chasquid.log --config_dir=B \
 	--testing__outgoing_smtp_port=1025 &
 
 wait_until_ready 1025
diff --git a/test/t-10-hooks/run.sh b/test/t-10-hooks/run.sh
index fb8244a..f9ecaa5 100755
--- a/test/t-10-hooks/run.sh
+++ b/test/t-10-hooks/run.sh
@@ -11,7 +11,7 @@ add_user someone@testserver secretpassword
 add_user blockme@testserver secretpassword
 
 mkdir -p .logs
-chasquid -v=2 --log_dir=.logs --config_dir=config &
+chasquid -v=2 --logfile=.logs/chasquid.log --config_dir=config &
 wait_until_ready 1025
 
 cp config/hooks/post-data.good config/hooks/post-data