Merge pull request #2354 from eipiminus1/issue1361

Add trailing folder seperator to allow symlinks as folder path (fixes #1361)

AUTHORS

@@ -1,6 +1,7 @@
 # This is the official list of Syncthing authors for copyright purposes.
 
 Aaron Bieber <qbit@deftly.net>
+Adam Piggott	<aD@simplypeachy.co.uk> <simplypeachy@users.noreply.github.com>
 Alexander Graf <register-github@alex-graf.de>
 Andrew Dunham <andrew@du.nham.ca>
 Antony Male <antony.male@gmail.com>
@@ -47,6 +48,7 @@ Lord Landon Agahnim <lordlandon@gmail.com>
 Marc Laporte <marc@marclaporte.com> <marc@laporte.name>
 Marc Pujol <kilburn@la3.org>
 Marcin Dziadus <dziadus.marcin@gmail.com>
+Mateon1 <matin1111@wp.pl>
 Matt Burke <mburke@amplify.com>
 Michael Jephcote <rewt0r@gmx.com> <Rewt0r@users.noreply.github.com>
 Michael Tilli <pyfisch@gmail.com>
@@ -64,3 +66,4 @@ Tomas Cerveny <kozec@kozec.com>
 Tully Robinson <tully@tojr.org>
 Veeti Paananen <veeti.paananen@rojekti.fi>
 Vil Brekin <vilbrekin@gmail.com>
+Yannic A. <eipiminusone+github@gmail.com> <eipiminus1@users.noreply.github.com>

Godeps/Godeps.json

@@ -13,10 +13,6 @@
 			"ImportPath": "github.com/calmh/du",
 			"Rev": "3c0690cca16228b97741327b1b6781397afbdb24"
 		},
-		{
-			"ImportPath": "github.com/calmh/logger",
-			"Rev": "c96f6a1a8c7b6bf2f4860c667867d90174799eb2"
-		},
 		{
 			"ImportPath": "github.com/calmh/luhn",
 			"Rev": "0c8388ff95fa92d4094011e5a04fc99dea3d1632"

Godeps/_workspace/src/github.com/calmh/logger/README.md

@@ -1,15 +0,0 @@
-logger
-======
-
-A small wrapper around `log` to provide log levels.
-
-Documentation
--------------
-
-http://godoc.org/github.com/calmh/logger
-
-License
--------
-
-MIT
-

Godeps/_workspace/src/github.com/calmh/logger/logger.go

@@ -1,187 +0,0 @@
-// Copyright (C) 2014 Jakob Borg. All rights reserved. Use of this source code
-// is governed by an MIT-style license that can be found in the LICENSE file.
-
-// Package logger implements a standardized logger with callback functionality
-package logger
-
-import (
-	"fmt"
-	"io/ioutil"
-	"log"
-	"os"
-	"strings"
-	"sync"
-)
-
-type LogLevel int
-
-const (
-	LevelDebug LogLevel = iota
-	LevelVerbose
-	LevelInfo
-	LevelOK
-	LevelWarn
-	LevelFatal
-	NumLevels
-)
-
-// A MessageHandler is called with the log level and message text.
-type MessageHandler func(l LogLevel, msg string)
-
-type Logger struct {
-	logger   *log.Logger
-	handlers [NumLevels][]MessageHandler
-	mut      sync.Mutex
-}
-
-// The default logger logs to standard output with a time prefix.
-var DefaultLogger = New()
-
-func New() *Logger {
-	if os.Getenv("LOGGER_DISCARD") != "" {
-		// Hack to completely disable logging, for example when running benchmarks.
-		return &Logger{
-			logger: log.New(ioutil.Discard, "", 0),
-		}
-	}
-
-	return &Logger{
-		logger: log.New(os.Stdout, "", log.Ltime),
-	}
-}
-
-// AddHandler registers a new MessageHandler to receive messages with the
-// specified log level or above.
-func (l *Logger) AddHandler(level LogLevel, h MessageHandler) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	l.handlers[level] = append(l.handlers[level], h)
-}
-
-// See log.SetFlags
-func (l *Logger) SetFlags(flag int) {
-	l.logger.SetFlags(flag)
-}
-
-// See log.SetPrefix
-func (l *Logger) SetPrefix(prefix string) {
-	l.logger.SetPrefix(prefix)
-}
-
-func (l *Logger) callHandlers(level LogLevel, s string) {
-	for _, h := range l.handlers[level] {
-		h(level, strings.TrimSpace(s))
-	}
-}
-
-// Debugln logs a line with a DEBUG prefix.
-func (l *Logger) Debugln(vals ...interface{}) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	s := fmt.Sprintln(vals...)
-	l.logger.Output(2, "DEBUG: "+s)
-	l.callHandlers(LevelDebug, s)
-}
-
-// Debugf logs a formatted line with a DEBUG prefix.
-func (l *Logger) Debugf(format string, vals ...interface{}) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	s := fmt.Sprintf(format, vals...)
-	l.logger.Output(2, "DEBUG: "+s)
-	l.callHandlers(LevelDebug, s)
-}
-
-// Infoln logs a line with a VERBOSE prefix.
-func (l *Logger) Verboseln(vals ...interface{}) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	s := fmt.Sprintln(vals...)
-	l.logger.Output(2, "VERBOSE: "+s)
-	l.callHandlers(LevelVerbose, s)
-}
-
-// Infof logs a formatted line with a VERBOSE prefix.
-func (l *Logger) Verbosef(format string, vals ...interface{}) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	s := fmt.Sprintf(format, vals...)
-	l.logger.Output(2, "VERBOSE: "+s)
-	l.callHandlers(LevelVerbose, s)
-}
-
-// Infoln logs a line with an INFO prefix.
-func (l *Logger) Infoln(vals ...interface{}) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	s := fmt.Sprintln(vals...)
-	l.logger.Output(2, "INFO: "+s)
-	l.callHandlers(LevelInfo, s)
-}
-
-// Infof logs a formatted line with an INFO prefix.
-func (l *Logger) Infof(format string, vals ...interface{}) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	s := fmt.Sprintf(format, vals...)
-	l.logger.Output(2, "INFO: "+s)
-	l.callHandlers(LevelInfo, s)
-}
-
-// Okln logs a line with an OK prefix.
-func (l *Logger) Okln(vals ...interface{}) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	s := fmt.Sprintln(vals...)
-	l.logger.Output(2, "OK: "+s)
-	l.callHandlers(LevelOK, s)
-}
-
-// Okf logs a formatted line with an OK prefix.
-func (l *Logger) Okf(format string, vals ...interface{}) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	s := fmt.Sprintf(format, vals...)
-	l.logger.Output(2, "OK: "+s)
-	l.callHandlers(LevelOK, s)
-}
-
-// Warnln logs a formatted line with a WARNING prefix.
-func (l *Logger) Warnln(vals ...interface{}) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	s := fmt.Sprintln(vals...)
-	l.logger.Output(2, "WARNING: "+s)
-	l.callHandlers(LevelWarn, s)
-}
-
-// Warnf logs a formatted line with a WARNING prefix.
-func (l *Logger) Warnf(format string, vals ...interface{}) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	s := fmt.Sprintf(format, vals...)
-	l.logger.Output(2, "WARNING: "+s)
-	l.callHandlers(LevelWarn, s)
-}
-
-// Fatalln logs a line with a FATAL prefix and exits the process with exit
-// code 1.
-func (l *Logger) Fatalln(vals ...interface{}) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	s := fmt.Sprintln(vals...)
-	l.logger.Output(2, "FATAL: "+s)
-	l.callHandlers(LevelFatal, s)
-	os.Exit(1)
-}
-
-// Fatalf logs a formatted line with a FATAL prefix and exits the process with
-// exit code 1.
-func (l *Logger) Fatalf(format string, vals ...interface{}) {
-	l.mut.Lock()
-	defer l.mut.Unlock()
-	s := fmt.Sprintf(format, vals...)
-	l.logger.Output(2, "FATAL: "+s)
-	l.callHandlers(LevelFatal, s)
-	os.Exit(1)
-}

Godeps/_workspace/src/github.com/calmh/logger/logger_test.go

@@ -1,58 +0,0 @@
-// Copyright (C) 2014 Jakob Borg. All rights reserved. Use of this source code
-// is governed by an MIT-style license that can be found in the LICENSE file.
-
-package logger
-
-import (
-	"strings"
-	"testing"
-)
-
-func TestAPI(t *testing.T) {
-	l := New()
-	l.SetFlags(0)
-	l.SetPrefix("testing")
-
-	debug := 0
-	l.AddHandler(LevelDebug, checkFunc(t, LevelDebug, "test 0", &debug))
-	info := 0
-	l.AddHandler(LevelInfo, checkFunc(t, LevelInfo, "test 1", &info))
-	warn := 0
-	l.AddHandler(LevelWarn, checkFunc(t, LevelWarn, "test 2", &warn))
-	ok := 0
-	l.AddHandler(LevelOK, checkFunc(t, LevelOK, "test 3", &ok))
-
-	l.Debugf("test %d", 0)
-	l.Debugln("test", 0)
-	l.Infof("test %d", 1)
-	l.Infoln("test", 1)
-	l.Warnf("test %d", 2)
-	l.Warnln("test", 2)
-	l.Okf("test %d", 3)
-	l.Okln("test", 3)
-
-	if debug != 2 {
-		t.Errorf("Debug handler called %d != 2 times", debug)
-	}
-	if info != 2 {
-		t.Errorf("Info handler called %d != 2 times", info)
-	}
-	if warn != 2 {
-		t.Errorf("Warn handler called %d != 2 times", warn)
-	}
-	if ok != 2 {
-		t.Errorf("Ok handler called %d != 2 times", ok)
-	}
-}
-
-func checkFunc(t *testing.T, expectl LogLevel, expectmsg string, counter *int) func(LogLevel, string) {
-	return func(l LogLevel, msg string) {
-		*counter++
-		if l != expectl {
-			t.Errorf("Incorrect message level %d != %d", l, expectl)
-		}
-		if !strings.HasSuffix(msg, expectmsg) {
-			t.Errorf("%q does not end with %q", msg, expectmsg)
-		}
-	}
-}

NICKS

@@ -27,6 +27,7 @@ ceh		<emil@hessman.se>
 cqcallaw	<enlightened.despot@gmail.com>
 dva	<denisva@gmail.com>
 dzarda		<dzardacz@gmail.com>
+eipiminus1	<eipiminusone+github@gmail.com> <eipiminus1@users.noreply.github.com>
 facastagnini	<federico.castagnini@gmail.com>
 filoozoom	<philippe@schommers.be>
 frioux		<frew@afoolishmanifesto.com> <frioux@gmail.com>
@@ -42,6 +43,7 @@ kozec		<kozec@kozec.com>
 krozycki	<rozycki.karol@gmail.com>
 marcindziadus	<dziadus.marcin@gmail.com>
 marclaporte <marc@marclaporte.com>
+mateon1	<matin1111@wp.pl>
 mogwa1	<devriesb@gmail.com>
 moshen		<moshen.colin@gmail.com>
 mvdan		<mvdan@mvdan.cc>
@@ -57,6 +59,7 @@ rumpelsepp	<stefan@sevenbyte.org> <rumpelsepp@sevenbyte.org>
 sciurius	<jvromans@squirrel.nl>
 seehuhn		<voss@seehuhn.de>
 snnd		<dw@risu.io>
+simplypeachy	<aD@simplypeachy.co.uk> <simplypeachy@users.noreply.github.com>
 timabell	<tim@timwise.co.uk>
 tnn2		<tnn@nygren.pp.se>
 tojrobinson	<tully@tojr.org>

build.go

@@ -186,7 +186,7 @@ func setup() {
 
 func test(pkg string) {
 	setBuildEnv()
-	runPrint("go", "test", "-short", "-timeout", "60s", pkg)
+	runPrint("go", "test", "-short", "-race", "-timeout", "60s", pkg)
 }
 
 func bench(pkg string) {

build.sh

@@ -108,10 +108,10 @@ case "${1:-default}" in
 		# For every package in the repo
 		for dir in $(go list ./...) ; do
 			# run the tests
-			godep go test -coverprofile=profile.out $dir
+			godep go test -race -coverprofile=profile.out $dir
 			if [ -f profile.out ] ; then
 				# and if there was test output, append it to coverage.out
-				grep -v "mode: set" profile.out >> coverage.out
+				grep -v "mode: " profile.out >> coverage.out
 				rm profile.out
 			fi
 		done

cmd/syncthing/debug.go

@@ -9,10 +9,24 @@ package main
 import (
 	"os"
 	"strings"
+
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debugNet    = strings.Contains(os.Getenv("STTRACE"), "net") || os.Getenv("STTRACE") == "all"
-	debugHTTP   = strings.Contains(os.Getenv("STTRACE"), "http") || os.Getenv("STTRACE") == "all"
-	debugSuture = strings.Contains(os.Getenv("STTRACE"), "suture") || os.Getenv("STTRACE") == "all"
+	l     = logger.DefaultLogger.NewFacility("main", "Main package")
+	httpl = logger.DefaultLogger.NewFacility("http", "REST API")
 )
+
+func init() {
+	l.SetDebug("main", strings.Contains(os.Getenv("STTRACE"), "main") || os.Getenv("STTRACE") == "all")
+	l.SetDebug("http", strings.Contains(os.Getenv("STTRACE"), "http") || os.Getenv("STTRACE") == "all")
+}
+
+func shouldDebugMain() bool {
+	return l.ShouldDebug("main")
+}
+
+func shouldDebugHTTP() bool {
+	return l.ShouldDebug("http")
+}

cmd/syncthing/gui.go

@@ -20,16 +20,17 @@ import (
 	"path/filepath"
 	"reflect"
 	"runtime"
+	"sort"
 	"strconv"
 	"strings"
 	"time"
 
-	"github.com/calmh/logger"
 	"github.com/syncthing/syncthing/lib/auto"
 	"github.com/syncthing/syncthing/lib/config"
 	"github.com/syncthing/syncthing/lib/db"
 	"github.com/syncthing/syncthing/lib/discover"
 	"github.com/syncthing/syncthing/lib/events"
+	"github.com/syncthing/syncthing/lib/logger"
 	"github.com/syncthing/syncthing/lib/model"
 	"github.com/syncthing/syncthing/lib/osutil"
 	"github.com/syncthing/syncthing/lib/protocol"
@@ -41,21 +42,14 @@ import (
 	"golang.org/x/crypto/bcrypt"
 )
 
-type guiError struct {
-	Time  time.Time `json:"time"`
-	Error string    `json:"error"`
-}
-
 var (
 	configInSync = true
-	guiErrors    = []guiError{}
-	guiErrorsMut = sync.NewMutex()
 	startTime    = time.Now()
 )
 
 type apiSvc struct {
 	id              protocol.DeviceID
-	cfg             config.GUIConfiguration
+	cfg             *config.Wrapper
 	assetDir        string
 	model           *model.Model
 	eventSub        *events.BufferedSubscription
@@ -65,9 +59,12 @@ type apiSvc struct {
 	fss             *folderSummarySvc
 	stop            chan struct{}
 	systemConfigMut sync.Mutex
+
+	guiErrors *logger.Recorder
+	systemLog *logger.Recorder
 }
 
-func newAPISvc(id protocol.DeviceID, cfg config.GUIConfiguration, assetDir string, m *model.Model, eventSub *events.BufferedSubscription, discoverer *discover.CachingMux, relaySvc *relay.Svc) (*apiSvc, error) {
+func newAPISvc(id protocol.DeviceID, cfg *config.Wrapper, assetDir string, m *model.Model, eventSub *events.BufferedSubscription, discoverer *discover.CachingMux, relaySvc *relay.Svc, errors, systemLog *logger.Recorder) (*apiSvc, error) {
 	svc := &apiSvc{
 		id:              id,
 		cfg:             cfg,
@@ -77,14 +74,16 @@ func newAPISvc(id protocol.DeviceID, cfg config.GUIConfiguration, assetDir strin
 		discoverer:      discoverer,
 		relaySvc:        relaySvc,
 		systemConfigMut: sync.NewMutex(),
+		guiErrors:       errors,
+		systemLog:       systemLog,
 	}
 
 	var err error
-	svc.listener, err = svc.getListener(cfg)
+	svc.listener, err = svc.getListener(cfg.GUI())
 	return svc, err
 }
 
-func (s *apiSvc) getListener(cfg config.GUIConfiguration) (net.Listener, error) {
+func (s *apiSvc) getListener(guiCfg config.GUIConfiguration) (net.Listener, error) {
 	cert, err := tls.LoadX509KeyPair(locations[locHTTPSCertFile], locations[locHTTPSKeyFile])
 	if err != nil {
 		l.Infoln("Loading HTTPS certificate:", err)
@@ -121,7 +120,7 @@ func (s *apiSvc) getListener(cfg config.GUIConfiguration) (net.Listener, error)
 		},
 	}
 
-	rawListener, err := net.Listen("tcp", cfg.Address)
+	rawListener, err := net.Listen("tcp", guiCfg.Address())
 	if err != nil {
 		return nil, err
 	}
@@ -133,8 +132,6 @@ func (s *apiSvc) getListener(cfg config.GUIConfiguration) (net.Listener, error)
 func (s *apiSvc) Serve() {
 	s.stop = make(chan struct{})
 
-	l.AddHandler(logger.LevelWarn, s.showGuiError)
-
 	// The GET handlers
 	getRestMux := http.NewServeMux()
 	getRestMux.HandleFunc("/rest/db/completion", s.getDBCompletion)              // device folder
@@ -159,6 +156,9 @@ func (s *apiSvc) Serve() {
 	getRestMux.HandleFunc("/rest/system/status", s.getSystemStatus)              // -
 	getRestMux.HandleFunc("/rest/system/upgrade", s.getSystemUpgrade)            // -
 	getRestMux.HandleFunc("/rest/system/version", s.getSystemVersion)            // -
+	getRestMux.HandleFunc("/rest/system/debug", s.getSystemDebug)                // -
+	getRestMux.HandleFunc("/rest/system/log", s.getSystemLog)                    // [since]
+	getRestMux.HandleFunc("/rest/system/log.txt", s.getSystemLogTxt)             // [since]
 
 	// The POST handlers
 	postRestMux := http.NewServeMux()
@@ -176,6 +176,7 @@ func (s *apiSvc) Serve() {
 	postRestMux.HandleFunc("/rest/system/upgrade", s.postSystemUpgrade)        // -
 	postRestMux.HandleFunc("/rest/system/pause", s.postSystemPause)            // device
 	postRestMux.HandleFunc("/rest/system/resume", s.postSystemResume)          // device
+	postRestMux.HandleFunc("/rest/system/debug", s.postSystemDebug)            // [enable] [disable]
 
 	// Debug endpoints, not for general use
 	getRestMux.HandleFunc("/rest/debug/peerCompletion", s.getPeerCompletion)
@@ -195,37 +196,38 @@ func (s *apiSvc) Serve() {
 		assets:   auto.Assets(),
 	})
 
+	guiCfg := s.cfg.GUI()
+
 	// Wrap everything in CSRF protection. The /rest prefix should be
 	// protected, other requests will grant cookies.
-	handler := csrfMiddleware(s.id.String()[:5], "/rest", s.cfg.APIKey, mux)
+	handler := csrfMiddleware(s.id.String()[:5], "/rest", guiCfg.APIKey(), mux)
 
 	// Add our version and ID as a header to responses
 	handler = withDetailsMiddleware(s.id, handler)
 
 	// Wrap everything in basic auth, if user/password is set.
-	if len(s.cfg.User) > 0 && len(s.cfg.Password) > 0 {
-		handler = basicAuthAndSessionMiddleware("sessionid-"+s.id.String()[:5], s.cfg, handler)
+	if len(guiCfg.User) > 0 && len(guiCfg.Password) > 0 {
+		handler = basicAuthAndSessionMiddleware("sessionid-"+s.id.String()[:5], guiCfg, handler)
 	}
 
 	// Redirect to HTTPS if we are supposed to
-	if s.cfg.UseTLS {
+	if guiCfg.UseTLS() {
 		handler = redirectToHTTPSMiddleware(handler)
 	}
 
-	if debugHTTP {
-		handler = debugMiddleware(handler)
-	}
+	handler = debugMiddleware(handler)
 
 	srv := http.Server{
 		Handler:     handler,
 		ReadTimeout: 10 * time.Second,
 	}
 
-	s.fss = newFolderSummarySvc(s.model)
+	s.fss = newFolderSummarySvc(s.cfg, s.model)
 	defer s.fss.Stop()
 	s.fss.ServeBackground()
 
 	l.Infoln("API listening on", s.listener.Addr())
+	l.Infoln("GUI URL is", guiCfg.URL())
 	err := srv.Serve(s.listener)
 
 	// The return could be due to an intentional close. Wait for the stop
@@ -273,7 +275,6 @@ func (s *apiSvc) CommitConfiguration(from, to config.Configuration) bool {
 		// method.
 		return false
 	}
-	s.cfg = to.GUI
 
 	close(s.stop)
 
@@ -369,6 +370,36 @@ func (s *apiSvc) getSystemVersion(w http.ResponseWriter, r *http.Request) {
 	})
 }
 
+func (s *apiSvc) getSystemDebug(w http.ResponseWriter, r *http.Request) {
+	w.Header().Set("Content-Type", "application/json; charset=utf-8")
+	names := l.Facilities()
+	enabled := l.FacilityDebugging()
+	sort.Strings(enabled)
+	json.NewEncoder(w).Encode(map[string]interface{}{
+		"facilities": names,
+		"enabled":    enabled,
+	})
+}
+
+func (s *apiSvc) postSystemDebug(w http.ResponseWriter, r *http.Request) {
+	w.Header().Set("Content-Type", "application/json; charset=utf-8")
+	q := r.URL.Query()
+	for _, f := range strings.Split(q.Get("enable"), ",") {
+		if f == "" {
+			continue
+		}
+		l.SetDebug(f, true)
+		l.Infof("Enabled debug data for %q", f)
+	}
+	for _, f := range strings.Split(q.Get("disable"), ",") {
+		if f == "" {
+			continue
+		}
+		l.SetDebug(f, false)
+		l.Infof("Disabled debug data for %q", f)
+	}
+}
+
 func (s *apiSvc) getDBBrowse(w http.ResponseWriter, r *http.Request) {
 	qs := r.URL.Query()
 	folder := qs.Get("folder")
@@ -409,12 +440,12 @@ func (s *apiSvc) getDBCompletion(w http.ResponseWriter, r *http.Request) {
 func (s *apiSvc) getDBStatus(w http.ResponseWriter, r *http.Request) {
 	qs := r.URL.Query()
 	folder := qs.Get("folder")
-	res := folderSummary(s.model, folder)
+	res := folderSummary(s.cfg, s.model, folder)
 	w.Header().Set("Content-Type", "application/json; charset=utf-8")
 	json.NewEncoder(w).Encode(res)
 }
 
-func folderSummary(m *model.Model, folder string) map[string]interface{} {
+func folderSummary(cfg *config.Wrapper, m *model.Model, folder string) map[string]interface{} {
 	var res = make(map[string]interface{})
 
 	res["invalid"] = cfg.Folders()[folder].Invalid
@@ -524,7 +555,7 @@ func (s *apiSvc) getDBFile(w http.ResponseWriter, r *http.Request) {
 
 func (s *apiSvc) getSystemConfig(w http.ResponseWriter, r *http.Request) {
 	w.Header().Set("Content-Type", "application/json; charset=utf-8")
-	json.NewEncoder(w).Encode(cfg.Raw())
+	json.NewEncoder(w).Encode(s.cfg.Raw())
 }
 
 func (s *apiSvc) postSystemConfig(w http.ResponseWriter, r *http.Request) {
@@ -539,7 +570,7 @@ func (s *apiSvc) postSystemConfig(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	if to.GUI.Password != cfg.GUI().Password {
+	if to.GUI.Password != s.cfg.GUI().Password {
 		if to.GUI.Password != "" {
 			hash, err := bcrypt.GenerateFromPassword([]byte(to.GUI.Password), 0)
 			if err != nil {
@@ -554,7 +585,7 @@ func (s *apiSvc) postSystemConfig(w http.ResponseWriter, r *http.Request) {
 
 	// Fixup usage reporting settings
 
-	if curAcc := cfg.Options().URAccepted; to.Options.URAccepted > curAcc {
+	if curAcc := s.cfg.Options().URAccepted; to.Options.URAccepted > curAcc {
 		// UR was enabled
 		to.Options.URAccepted = usageReportVersion
 		to.Options.URUniqueID = randomString(8)
@@ -566,9 +597,9 @@ func (s *apiSvc) postSystemConfig(w http.ResponseWriter, r *http.Request) {
 
 	// Activate and save
 
-	resp := cfg.Replace(to)
+	resp := s.cfg.Replace(to)
 	configInSync = !resp.RequiresRestart
-	cfg.Save()
+	s.cfg.Save()
 }
 
 func (s *apiSvc) getSystemConfigInsync(w http.ResponseWriter, r *http.Request) {
@@ -586,7 +617,7 @@ func (s *apiSvc) postSystemReset(w http.ResponseWriter, r *http.Request) {
 	folder := qs.Get("folder")
 
 	if len(folder) > 0 {
-		if _, ok := cfg.Folders()[folder]; !ok {
+		if _, ok := s.cfg.Folders()[folder]; !ok {
 			http.Error(w, "Invalid folder ID", 500)
 			return
 		}
@@ -594,7 +625,7 @@ func (s *apiSvc) postSystemReset(w http.ResponseWriter, r *http.Request) {
 
 	if len(folder) == 0 {
 		// Reset all folders.
-		for folder := range cfg.Folders() {
+		for folder := range s.cfg.Folders() {
 			s.model.ResetFolder(folder)
 		}
 		s.flushResponse(`{"ok": "resetting database"}`, w)
@@ -632,7 +663,7 @@ func (s *apiSvc) getSystemStatus(w http.ResponseWriter, r *http.Request) {
 	res["alloc"] = m.Alloc
 	res["sys"] = m.Sys - m.HeapReleased
 	res["tilde"] = tilde
-	if cfg.Options().LocalAnnEnabled || cfg.Options().GlobalAnnEnabled {
+	if s.cfg.Options().LocalAnnEnabled || s.cfg.Options().GlobalAnnEnabled {
 		res["discoveryEnabled"] = true
 		discoErrors := make(map[string]string)
 		discoMethods := 0
@@ -674,30 +705,41 @@ func (s *apiSvc) getSystemStatus(w http.ResponseWriter, r *http.Request) {
 
 func (s *apiSvc) getSystemError(w http.ResponseWriter, r *http.Request) {
 	w.Header().Set("Content-Type", "application/json; charset=utf-8")
-	guiErrorsMut.Lock()
-	json.NewEncoder(w).Encode(map[string][]guiError{"errors": guiErrors})
-	guiErrorsMut.Unlock()
+	json.NewEncoder(w).Encode(map[string][]logger.Line{
+		"errors": s.guiErrors.Since(time.Time{}),
+	})
 }
 
 func (s *apiSvc) postSystemError(w http.ResponseWriter, r *http.Request) {
 	bs, _ := ioutil.ReadAll(r.Body)
 	r.Body.Close()
-	s.showGuiError(0, string(bs))
+	l.Warnln(string(bs))
 }
 
 func (s *apiSvc) postSystemErrorClear(w http.ResponseWriter, r *http.Request) {
-	guiErrorsMut.Lock()
-	guiErrors = []guiError{}
-	guiErrorsMut.Unlock()
+	s.guiErrors.Clear()
 }
 
-func (s *apiSvc) showGuiError(l logger.LogLevel, err string) {
-	guiErrorsMut.Lock()
-	guiErrors = append(guiErrors, guiError{time.Now(), err})
-	if len(guiErrors) > 5 {
-		guiErrors = guiErrors[len(guiErrors)-5:]
+func (s *apiSvc) getSystemLog(w http.ResponseWriter, r *http.Request) {
+	q := r.URL.Query()
+	since, err := time.Parse(time.RFC3339, q.Get("since"))
+	l.Debugln(err)
+	w.Header().Set("Content-Type", "application/json; charset=utf-8")
+
+	json.NewEncoder(w).Encode(map[string][]logger.Line{
+		"messages": s.systemLog.Since(since),
+	})
+}
+
+func (s *apiSvc) getSystemLogTxt(w http.ResponseWriter, r *http.Request) {
+	q := r.URL.Query()
+	since, err := time.Parse(time.RFC3339, q.Get("since"))
+	l.Debugln(err)
+	w.Header().Set("Content-Type", "text/plain; charset=utf-8")
+
+	for _, line := range s.systemLog.Since(since) {
+		fmt.Fprintf(w, "%s: %s\n", line.When.Format(time.RFC3339), line.Message)
 	}
-	guiErrorsMut.Unlock()
 }
 
 func (s *apiSvc) getSystemDiscovery(w http.ResponseWriter, r *http.Request) {
@@ -718,7 +760,7 @@ func (s *apiSvc) getSystemDiscovery(w http.ResponseWriter, r *http.Request) {
 
 func (s *apiSvc) getReport(w http.ResponseWriter, r *http.Request) {
 	w.Header().Set("Content-Type", "application/json; charset=utf-8")
-	json.NewEncoder(w).Encode(reportData(s.model))
+	json.NewEncoder(w).Encode(reportData(s.cfg, s.model))
 }
 
 func (s *apiSvc) getDBIgnores(w http.ResponseWriter, r *http.Request) {
@@ -787,7 +829,7 @@ func (s *apiSvc) getSystemUpgrade(w http.ResponseWriter, r *http.Request) {
 		http.Error(w, upgrade.ErrUpgradeUnsupported.Error(), 500)
 		return
 	}
-	rel, err := upgrade.LatestRelease(cfg.Options().ReleasesURL, Version)
+	rel, err := upgrade.LatestRelease(s.cfg.Options().ReleasesURL, Version)
 	if err != nil {
 		http.Error(w, err.Error(), 500)
 		return
@@ -830,7 +872,7 @@ func (s *apiSvc) getLang(w http.ResponseWriter, r *http.Request) {
 }
 
 func (s *apiSvc) postSystemUpgrade(w http.ResponseWriter, r *http.Request) {
-	rel, err := upgrade.LatestRelease(cfg.Options().ReleasesURL, Version)
+	rel, err := upgrade.LatestRelease(s.cfg.Options().ReleasesURL, Version)
 	if err != nil {
 		l.Warnln("getting latest release:", err)
 		http.Error(w, err.Error(), 500)
@@ -928,7 +970,7 @@ func (s *apiSvc) getPeerCompletion(w http.ResponseWriter, r *http.Request) {
 	tot := map[string]float64{}
 	count := map[string]float64{}
 
-	for _, folder := range cfg.Folders() {
+	for _, folder := range s.cfg.Folders() {
 		for _, device := range folder.DeviceIDs() {
 			deviceStr := device.String()
 			if s.model.ConnectedTo(device) {

cmd/syncthing/gui_auth.go

@@ -25,9 +25,9 @@ var (
 )
 
 func basicAuthAndSessionMiddleware(cookieName string, cfg config.GUIConfiguration, next http.Handler) http.Handler {
-
+	apiKey := cfg.APIKey()
 	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
-		if cfg.APIKey != "" && r.Header.Get("X-API-Key") == cfg.APIKey {
+		if apiKey != "" && r.Header.Get("X-API-Key") == apiKey {
 			next.ServeHTTP(w, r)
 			return
 		}
@@ -43,9 +43,7 @@ func basicAuthAndSessionMiddleware(cookieName string, cfg config.GUIConfiguratio
 			}
 		}
 
-		if debugHTTP {
-			l.Debugln("Sessionless HTTP request with authentication; this is expensive.")
-		}
+		httpl.Debugln("Sessionless HTTP request with authentication; this is expensive.")
 
 		error := func() {
 			time.Sleep(time.Duration(rand.Intn(100)+100) * time.Millisecond)

cmd/syncthing/main.go

@@ -7,6 +7,7 @@
 package main
 
 import (
+	"bytes"
 	"crypto/tls"
 	"flag"
 	"fmt"
@@ -21,17 +22,17 @@ import (
 	"regexp"
 	"runtime"
 	"runtime/pprof"
+	"sort"
 	"strconv"
 	"strings"
 	"time"
 
-	"github.com/calmh/logger"
-	"github.com/juju/ratelimit"
 	"github.com/syncthing/syncthing/lib/config"
 	"github.com/syncthing/syncthing/lib/connections"
 	"github.com/syncthing/syncthing/lib/db"
 	"github.com/syncthing/syncthing/lib/discover"
 	"github.com/syncthing/syncthing/lib/events"
+	"github.com/syncthing/syncthing/lib/logger"
 	"github.com/syncthing/syncthing/lib/model"
 	"github.com/syncthing/syncthing/lib/osutil"
 	"github.com/syncthing/syncthing/lib/protocol"
@@ -44,7 +45,6 @@ import (
 	"github.com/syndtr/goleveldb/leveldb/errors"
 	"github.com/syndtr/goleveldb/leveldb/opt"
 	"github.com/thejerf/suture"
-	"golang.org/x/crypto/bcrypt"
 )
 
 var (
@@ -73,9 +73,17 @@ const (
 	tlsDefaultCommonName = "syncthing"
 	tlsRSABits           = 3072
 	pingEventInterval    = time.Minute
+	maxSystemErrors      = 5
+	initialSystemLog     = 10
+	maxSystemLog         = 250
 )
 
-var l = logger.DefaultLogger
+// The discovery results are sorted by their source priority.
+const (
+	ipv6LocalDiscoveryPriority = iota
+	ipv4LocalDiscoveryPriority
+	globalDiscoveryPriority
+)
 
 func init() {
 	if Version != "unknown-dev" {
@@ -108,15 +116,12 @@ func init() {
 }
 
 var (
-	cfg            *config.Wrapper
-	myID           protocol.DeviceID
-	confDir        string
-	logFlags       = log.Ltime
-	writeRateLimit *ratelimit.Bucket
-	readRateLimit  *ratelimit.Bucket
-	stop           = make(chan int)
-	cert           tls.Certificate
-	lans           []*net.IPNet
+	myID     protocol.DeviceID
+	confDir  string
+	logFlags = log.Ltime
+	stop     = make(chan int)
+	cert     tls.Certificate
+	lans     []*net.IPNet
 )
 
 const (
@@ -146,25 +151,11 @@ Development Settings
 The following environment variables modify syncthing's behavior in ways that
 are mostly useful for developers. Use with care.
 
- STGUIASSETS     Directory to load GUI assets from. Overrides compiled in assets.
+ STGUIASSETS     Directory to load GUI assets from. Overrides compiled in
+                 assets.
 
  STTRACE         A comma separated string of facilities to trace. The valid
-                 facility strings are:
-
-                 - "beacon"   (the beacon package)
-                 - "discover" (the discover package)
-                 - "events"   (the events package)
-                 - "files"    (the files package)
-                 - "http"     (the main package; HTTP requests)
-                 - "locks"    (the sync package; trace long held locks)
-                 - "net"      (the main package; connections & network messages)
-                 - "model"    (the model package)
-                 - "scanner"  (the scanner package)
-                 - "stats"    (the stats package)
-                 - "suture"   (the suture package; service management)
-                 - "upnp"     (the upnp package)
-                 - "xdr"      (the xdr package)
-                 - "all"      (all of the above)
+                 facility strings listed below.
 
  STPROFILER      Set to a listen address such as "127.0.0.1:9090" to start the
                  profiler with HTTP access.
@@ -187,33 +178,38 @@ are mostly useful for developers. Use with care.
 
  GOGC            Percentage of heap growth at which to trigger GC. Default is
                  100. Lower numbers keep peak memory usage down, at the price
-                 of CPU usage (ie. performance).`
+                 of CPU usage (ie. performance).
+
+
+Debugging Facilities
+--------------------
+
+The following are valid values for the STTRACE variable:
+
+%s`
 )
 
 // Command line and environment options
 var (
-	reset             bool
-	showVersion       bool
-	doUpgrade         bool
-	doUpgradeCheck    bool
-	upgradeTo         string
-	noBrowser         bool
-	noConsole         bool
-	generateDir       string
-	logFile           string
-	auditEnabled      bool
-	verbose           bool
-	paused            bool
-	noRestart         = os.Getenv("STNORESTART") != ""
-	noUpgrade         = os.Getenv("STNOUPGRADE") != ""
-	guiAddress        = os.Getenv("STGUIADDRESS") // legacy
-	guiAuthentication = os.Getenv("STGUIAUTH")    // legacy
-	guiAPIKey         = os.Getenv("STGUIAPIKEY")  // legacy
-	profiler          = os.Getenv("STPROFILER")
-	guiAssets         = os.Getenv("STGUIASSETS")
-	cpuProfile        = os.Getenv("STCPUPROFILE") != ""
-	stRestarting      = os.Getenv("STRESTART") != ""
-	innerProcess      = os.Getenv("STNORESTART") != "" || os.Getenv("STMONITORED") != ""
+	reset          bool
+	showVersion    bool
+	doUpgrade      bool
+	doUpgradeCheck bool
+	upgradeTo      string
+	noBrowser      bool
+	noConsole      bool
+	generateDir    string
+	logFile        string
+	auditEnabled   bool
+	verbose        bool
+	paused         bool
+	noRestart      = os.Getenv("STNORESTART") != ""
+	noUpgrade      = os.Getenv("STNOUPGRADE") != ""
+	profiler       = os.Getenv("STPROFILER")
+	guiAssets      = os.Getenv("STGUIASSETS")
+	cpuProfile     = os.Getenv("STCPUPROFILE") != ""
+	stRestarting   = os.Getenv("STRESTART") != ""
+	innerProcess   = os.Getenv("STNORESTART") != "" || os.Getenv("STMONITORED") != ""
 )
 
 func main() {
@@ -228,9 +224,9 @@ func main() {
 		flag.StringVar(&logFile, "logfile", "-", "Log file name (use \"-\" for stdout)")
 	}
 
+	var guiAddress, guiAPIKey string
 	flag.StringVar(&generateDir, "generate", "", "Generate key and config in specified dir, then exit")
 	flag.StringVar(&guiAddress, "gui-address", guiAddress, "Override GUI address")
-	flag.StringVar(&guiAuthentication, "gui-authentication", guiAuthentication, "Override GUI authentication; username:password")
 	flag.StringVar(&guiAPIKey, "gui-apikey", guiAPIKey, "Override GUI API key")
 	flag.StringVar(&confDir, "home", "", "Set configuration directory")
 	flag.IntVar(&logFlags, "logflags", logFlags, "Select information in log line prefix")
@@ -245,9 +241,19 @@ func main() {
 	flag.BoolVar(&verbose, "verbose", false, "Print verbose log output")
 	flag.BoolVar(&paused, "paused", false, "Start with all devices paused")
 
-	flag.Usage = usageFor(flag.CommandLine, usage, fmt.Sprintf(extraUsage, baseDirs["config"]))
+	longUsage := fmt.Sprintf(extraUsage, baseDirs["config"], debugFacilities())
+	flag.Usage = usageFor(flag.CommandLine, usage, longUsage)
 	flag.Parse()
 
+	if guiAddress != "" {
+		// The config picks this up from the environment.
+		os.Setenv("STGUIADDRESS", guiAddress)
+	}
+	if guiAPIKey != "" {
+		// The config picks this up from the environment.
+		os.Setenv("STGUIAPIKEY", guiAPIKey)
+	}
+
 	if noConsole {
 		osutil.HideConsole()
 	}
@@ -346,7 +352,11 @@ func main() {
 	}
 
 	if doUpgrade || doUpgradeCheck {
-		rel, err := upgrade.LatestRelease(cfg.Options().ReleasesURL, Version)
+		releasesURL := "https://api.github.com/repos/syncthing/syncthing/releases?per_page=30"
+		if cfg, _, err := loadConfig(locations[locConfigFile]); err == nil {
+			releasesURL = cfg.Options().ReleasesURL
+		}
+		rel, err := upgrade.LatestRelease(releasesURL, Version)
 		if err != nil {
 			l.Fatalln("Upgrade:", err) // exits 1
 		}
@@ -393,19 +403,36 @@ func main() {
 	}
 }
 
+func debugFacilities() string {
+	facilities := l.Facilities()
+
+	// Get a sorted list of names
+	var names []string
+	maxLen := 0
+	for name := range facilities {
+		names = append(names, name)
+		if len(name) > maxLen {
+			maxLen = len(name)
+		}
+	}
+	sort.Strings(names)
+
+	// Format the choices
+	b := new(bytes.Buffer)
+	for _, name := range names {
+		fmt.Fprintf(b, " %-*s - %s\n", maxLen, name, facilities[name])
+	}
+	return b.String()
+}
+
 func upgradeViaRest() error {
 	cfg, err := config.Load(locations[locConfigFile], protocol.LocalDeviceID)
 	if err != nil {
 		return err
 	}
-	target := cfg.GUI().Address
-	if cfg.GUI().UseTLS {
-		target = "https://" + target
-	} else {
-		target = "http://" + target
-	}
+	target := cfg.GUI().URL()
 	r, _ := http.NewRequest("POST", target+"/rest/system/upgrade", nil)
-	r.Header.Set("X-API-Key", cfg.GUI().APIKey)
+	r.Header.Set("X-API-Key", cfg.GUI().APIKey())
 
 	tr := &http.Transport{
 		TLSClientConfig: &tls.Config{InsecureSkipVerify: true},
@@ -435,9 +462,7 @@ func syncthingMain() {
 	// We want any logging it does to go through our log system.
 	mainSvc := suture.New("main", suture.Spec{
 		Log: func(line string) {
-			if debugSuture {
-				l.Debugln(line)
-			}
+			l.Debugln(line)
 		},
 	})
 	mainSvc.ServeBackground()
@@ -454,6 +479,9 @@ func syncthingMain() {
 		mainSvc.Add(newVerboseSvc())
 	}
 
+	errors := logger.NewRecorder(l, logger.LevelWarn, maxSystemErrors, 0)
+	systemLog := logger.NewRecorder(l, logger.LevelDebug, maxSystemLog, initialSystemLog)
+
 	// Event subscription for the API; must start early to catch the early events.
 	apiSub := events.NewBufferedSubscription(events.Default.Subscribe(events.AllEvents), 1000)
 
@@ -497,33 +525,21 @@ func syncthingMain() {
 
 	cfgFile := locations[locConfigFile]
 
-	var myName string
-
 	// Load the configuration file, if it exists.
 	// If it does not, create a template.
 
-	if info, err := os.Stat(cfgFile); err == nil {
-		if !info.Mode().IsRegular() {
-			l.Fatalln("Config file is not a file?")
-		}
-		cfg, err = config.Load(cfgFile, myID)
-		if err == nil {
-			myCfg := cfg.Devices()[myID]
-			if myCfg.Name == "" {
-				myName, _ = os.Hostname()
-			} else {
-				myName = myCfg.Name
-			}
+	cfg, myName, err := loadConfig(cfgFile)
+	if err != nil {
+		if os.IsNotExist(err) {
+			l.Infoln("No config file; starting with empty defaults")
+			myName, _ = os.Hostname()
+			newCfg := defaultConfig(myName)
+			cfg = config.Wrap(cfgFile, newCfg)
+			cfg.Save()
+			l.Infof("Edit %s to taste or use the GUI\n", cfgFile)
 		} else {
-			l.Fatalln("Configuration:", err)
+			l.Fatalln("Loading config:", err)
 		}
-	} else {
-		l.Infoln("No config file; starting with empty defaults")
-		myName, _ = os.Hostname()
-		newCfg := defaultConfig(myName)
-		cfg = config.Wrap(cfgFile, newCfg)
-		cfg.Save()
-		l.Infof("Edit %s to taste or use the GUI\n", cfgFile)
 	}
 
 	if cfg.Raw().OriginalVersion != config.CurrentVersion {
@@ -596,9 +612,10 @@ func syncthingMain() {
 	}
 
 	dbFile := locations[locDatabase]
-	ldb, err := leveldb.OpenFile(dbFile, dbOpts())
+	dbOpts := dbOpts(cfg)
+	ldb, err := leveldb.OpenFile(dbFile, dbOpts)
 	if leveldbIsCorrupted(err) {
-		ldb, err = leveldb.RecoverFile(dbFile, dbOpts())
+		ldb, err = leveldb.RecoverFile(dbFile, dbOpts)
 	}
 	if leveldbIsCorrupted(err) {
 		// The database is corrupted, and we've tried to recover it but it
@@ -608,7 +625,7 @@ func syncthingMain() {
 		if err := resetDB(); err != nil {
 			l.Fatalln("Remove database:", err)
 		}
-		ldb, err = leveldb.OpenFile(dbFile, dbOpts())
+		ldb, err = leveldb.OpenFile(dbFile, dbOpts)
 	}
 	if err != nil {
 		l.Fatalln("Cannot open database:", err, "- Is another copy of Syncthing already running?")
@@ -717,7 +734,7 @@ func syncthingMain() {
 			// Each global discovery server gets its results cached for five
 			// minutes, and is not asked again for a minute when it's returned
 			// unsuccessfully.
-			cachedDiscovery.Add(gd, 5*time.Minute, time.Minute)
+			cachedDiscovery.Add(gd, 5*time.Minute, time.Minute, globalDiscoveryPriority)
 		}
 	}
 
@@ -727,20 +744,20 @@ func syncthingMain() {
 		if err != nil {
 			l.Warnln("IPv4 local discovery:", err)
 		} else {
-			cachedDiscovery.Add(bcd, 0, 0)
+			cachedDiscovery.Add(bcd, 0, 0, ipv4LocalDiscoveryPriority)
 		}
 		// v6 multicasts
 		mcd, err := discover.NewLocal(myID, cfg.Options().LocalAnnMCAddr, addrList, relaySvc)
 		if err != nil {
 			l.Warnln("IPv6 local discovery:", err)
 		} else {
-			cachedDiscovery.Add(mcd, 0, 0)
+			cachedDiscovery.Add(mcd, 0, 0, ipv6LocalDiscoveryPriority)
 		}
 	}
 
 	// GUI
 
-	setupGUI(mainSvc, cfg, m, apiSub, cachedDiscovery, relaySvc)
+	setupGUI(mainSvc, cfg, m, apiSub, cachedDiscovery, relaySvc, errors, systemLog)
 
 	// Start connection management
 
@@ -780,7 +797,7 @@ func syncthingMain() {
 	// The usageReportingManager registers itself to listen to configuration
 	// changes, and there's nothing more we need to tell it from the outside.
 	// Hence we don't keep the returned pointer.
-	newUsageReportingManager(m, cfg)
+	newUsageReportingManager(cfg, m)
 
 	if opts.RestartOnWakeup {
 		go standbyMonitor()
@@ -790,7 +807,7 @@ func syncthingMain() {
 		if noUpgrade {
 			l.Infof("No automatic upgrades; STNOUPGRADE environment variable defined.")
 		} else if IsRelease {
-			go autoUpgrade()
+			go autoUpgrade(cfg)
 		} else {
 			l.Infof("No automatic upgrades; %s is not a release version.", Version)
 		}
@@ -816,7 +833,30 @@ func syncthingMain() {
 	os.Exit(code)
 }
 
-func dbOpts() *opt.Options {
+func loadConfig(cfgFile string) (*config.Wrapper, string, error) {
+	info, err := os.Stat(cfgFile)
+	if err != nil {
+		return nil, "", err
+	}
+	if !info.Mode().IsRegular() {
+		return nil, "", errors.New("configuration is not a file")
+	}
+
+	cfg, err := config.Load(cfgFile, myID)
+	if err != nil {
+		return nil, "", err
+	}
+
+	myCfg := cfg.Devices()[myID]
+	myName := myCfg.Name
+	if myName == "" {
+		myName, _ = os.Hostname()
+	}
+
+	return cfg, myName, nil
+}
+
+func dbOpts(cfg *config.Wrapper) *opt.Options {
 	// Calculate a suitable database block cache capacity.
 
 	// Default is 8 MiB.
@@ -867,49 +907,24 @@ func startAuditing(mainSvc *suture.Supervisor) {
 	l.Infoln("Audit log in", auditFile)
 }
 
-func setupGUI(mainSvc *suture.Supervisor, cfg *config.Wrapper, m *model.Model, apiSub *events.BufferedSubscription, discoverer *discover.CachingMux, relaySvc *relay.Svc) {
-	opts := cfg.Options()
-	guiCfg := overrideGUIConfig(cfg.GUI(), guiAddress, guiAuthentication, guiAPIKey)
+func setupGUI(mainSvc *suture.Supervisor, cfg *config.Wrapper, m *model.Model, apiSub *events.BufferedSubscription, discoverer *discover.CachingMux, relaySvc *relay.Svc, errors, systemLog *logger.Recorder) {
+	guiCfg := cfg.GUI()
 
-	if guiCfg.Enabled && guiCfg.Address != "" {
-		addr, err := net.ResolveTCPAddr("tcp", guiCfg.Address)
-		if err != nil {
-			l.Fatalf("Cannot start GUI on %q: %v", guiCfg.Address, err)
-		} else {
-			var hostOpen, hostShow string
-			switch {
-			case addr.IP == nil:
-				hostOpen = "localhost"
-				hostShow = "0.0.0.0"
-			case addr.IP.IsUnspecified():
-				hostOpen = "localhost"
-				hostShow = addr.IP.String()
-			default:
-				hostOpen = addr.IP.String()
-				hostShow = hostOpen
-			}
+	if !guiCfg.Enabled {
+		return
+	}
 
-			var proto = "http"
-			if guiCfg.UseTLS {
-				proto = "https"
-			}
+	api, err := newAPISvc(myID, cfg, guiAssets, m, apiSub, discoverer, relaySvc, errors, systemLog)
+	if err != nil {
+		l.Fatalln("Cannot start GUI:", err)
+	}
+	cfg.Subscribe(api)
+	mainSvc.Add(api)
 
-			urlShow := fmt.Sprintf("%s://%s/", proto, net.JoinHostPort(hostShow, strconv.Itoa(addr.Port)))
-			l.Infoln("Starting web GUI on", urlShow)
-			api, err := newAPISvc(myID, guiCfg, guiAssets, m, apiSub, discoverer, relaySvc)
-			if err != nil {
-				l.Fatalln("Cannot start GUI:", err)
-			}
-			cfg.Subscribe(api)
-			mainSvc.Add(api)
-
-			if opts.StartBrowser && !noBrowser && !stRestarting {
-				urlOpen := fmt.Sprintf("%s://%s/", proto, net.JoinHostPort(hostOpen, strconv.Itoa(addr.Port)))
-				// Can potentially block if the utility we are invoking doesn't
-				// fork, and just execs, hence keep it in it's own routine.
-				go openURL(urlOpen)
-			}
-		}
+	if cfg.Options().StartBrowser && !noBrowser && !stRestarting {
+		// Can potentially block if the utility we are invoking doesn't
+		// fork, and just execs, hence keep it in it's own routine.
+		go openURL(guiCfg.URL())
 	}
 }
 
@@ -936,7 +951,7 @@ func defaultConfig(myName string) config.Configuration {
 	if err != nil {
 		l.Fatalln("get free port (GUI):", err)
 	}
-	newCfg.GUI.Address = fmt.Sprintf("127.0.0.1:%d", port)
+	newCfg.GUI.RawAddress = fmt.Sprintf("127.0.0.1:%d", port)
 
 	port, err = getFreePort("0.0.0.0", 22000)
 	if err != nil {
@@ -1004,48 +1019,6 @@ func getFreePort(host string, ports ...int) (int, error) {
 	return addr.Port, nil
 }
 
-func overrideGUIConfig(cfg config.GUIConfiguration, address, authentication, apikey string) config.GUIConfiguration {
-	if address != "" {
-		cfg.Enabled = true
-
-		if !strings.Contains(address, "//") {
-			// Assume just an IP was given. Don't touch he TLS setting.
-			cfg.Address = address
-		} else {
-			parsed, err := url.Parse(address)
-			if err != nil {
-				l.Fatalln(err)
-			}
-			cfg.Address = parsed.Host
-			switch parsed.Scheme {
-			case "http":
-				cfg.UseTLS = false
-			case "https":
-				cfg.UseTLS = true
-			default:
-				l.Fatalln("Unknown scheme:", parsed.Scheme)
-			}
-		}
-	}
-
-	if authentication != "" {
-		authenticationParts := strings.SplitN(authentication, ":", 2)
-
-		hash, err := bcrypt.GenerateFromPassword([]byte(authenticationParts[1]), 0)
-		if err != nil {
-			l.Fatalln("Invalid GUI password:", err)
-		}
-
-		cfg.User = authenticationParts[0]
-		cfg.Password = string(hash)
-	}
-
-	if apikey != "" {
-		cfg.APIKey = apikey
-	}
-	return cfg
-}
-
 func standbyMonitor() {
 	restartDelay := time.Duration(60 * time.Second)
 	now := time.Now()
@@ -1066,7 +1039,7 @@ func standbyMonitor() {
 	}
 }
 
-func autoUpgrade() {
+func autoUpgrade(cfg *config.Wrapper) {
 	timer := time.NewTimer(0)
 	sub := events.Default.Subscribe(events.DeviceConnected)
 	for {

cmd/syncthing/summarysvc.go

@@ -9,6 +9,7 @@ package main
 import (
 	"time"
 
+	"github.com/syncthing/syncthing/lib/config"
 	"github.com/syncthing/syncthing/lib/events"
 	"github.com/syncthing/syncthing/lib/model"
 	"github.com/syncthing/syncthing/lib/sync"
@@ -20,6 +21,7 @@ import (
 type folderSummarySvc struct {
 	*suture.Supervisor
 
+	cfg       *config.Wrapper
 	model     *model.Model
 	stop      chan struct{}
 	immediate chan string
@@ -33,9 +35,10 @@ type folderSummarySvc struct {
 	lastEventReqMut sync.Mutex
 }
 
-func newFolderSummarySvc(m *model.Model) *folderSummarySvc {
+func newFolderSummarySvc(cfg *config.Wrapper, m *model.Model) *folderSummarySvc {
 	svc := &folderSummarySvc{
 		Supervisor:      suture.NewSimple("folderSummarySvc"),
+		cfg:             cfg,
 		model:           m,
 		stop:            make(chan struct{}),
 		immediate:       make(chan string),
@@ -162,13 +165,13 @@ func (c *folderSummarySvc) foldersToHandle() []string {
 func (c *folderSummarySvc) sendSummary(folder string) {
 	// The folder summary contains how many bytes, files etc
 	// are in the folder and how in sync we are.
-	data := folderSummary(c.model, folder)
+	data := folderSummary(c.cfg, c.model, folder)
 	events.Default.Log(events.FolderSummary, map[string]interface{}{
 		"folder":  folder,
 		"summary": data,
 	})
 
-	for _, devCfg := range cfg.Folders()[folder].Devices {
+	for _, devCfg := range c.cfg.Folders()[folder].Devices {
 		if devCfg.DeviceID.Equals(myID) {
 			// We already know about ourselves.
 			continue

cmd/syncthing/upnpsvc.go

@@ -98,9 +98,7 @@ func (s *upnpSvc) tryIGDs(igds []upnp.IGD, prevExtPort int) int {
 			l.Infof("New UPnP port mapping: external port %d to local port %d.", extPort, s.localPort)
 			events.Default.Log(events.ExternalPortMappingChanged, map[string]int{"port": extPort})
 		}
-		if debugNet {
-			l.Debugf("Created/updated UPnP port mapping for external port %d on device %s.", extPort, igd.FriendlyIdentifier())
-		}
+		l.Debugf("Created/updated UPnP port mapping for external port %d on device %s.", extPort, igd.FriendlyIdentifier())
 		return extPort
 	}
 

cmd/syncthing/usage_report.go

@@ -32,12 +32,14 @@ import (
 const usageReportVersion = 2
 
 type usageReportingManager struct {
+	cfg   *config.Wrapper
 	model *model.Model
 	sup   *suture.Supervisor
 }
 
-func newUsageReportingManager(m *model.Model, cfg *config.Wrapper) *usageReportingManager {
+func newUsageReportingManager(cfg *config.Wrapper, m *model.Model) *usageReportingManager {
 	mgr := &usageReportingManager{
+		cfg:   cfg,
 		model: m,
 	}
 
@@ -58,9 +60,7 @@ func (m *usageReportingManager) VerifyConfiguration(from, to config.Configuratio
 func (m *usageReportingManager) CommitConfiguration(from, to config.Configuration) bool {
 	if to.Options.URAccepted >= usageReportVersion && m.sup == nil {
 		// Usage reporting was turned on; lets start it.
-		svc := &usageReportingService{
-			model: m.model,
-		}
+		svc := newUsageReportingService(m.cfg, m.model)
 		m.sup = suture.NewSimple("usageReporting")
 		m.sup.Add(svc)
 		m.sup.ServeBackground()
@@ -79,7 +79,7 @@ func (m *usageReportingManager) String() string {
 
 // reportData returns the data to be sent in a usage report. It's used in
 // various places, so not part of the usageReportingSvc object.
-func reportData(m *model.Model) map[string]interface{} {
+func reportData(cfg *config.Wrapper, m *model.Model) map[string]interface{} {
 	res := make(map[string]interface{})
 	res["urVersion"] = usageReportVersion
 	res["uniqueID"] = cfg.Options().URUniqueID
@@ -238,12 +238,21 @@ func stringIn(needle string, haystack []string) bool {
 }
 
 type usageReportingService struct {
+	cfg   *config.Wrapper
 	model *model.Model
 	stop  chan struct{}
 }
 
+func newUsageReportingService(cfg *config.Wrapper, model *model.Model) *usageReportingService {
+	return &usageReportingService{
+		cfg:   cfg,
+		model: model,
+		stop:  make(chan struct{}),
+	}
+}
+
 func (s *usageReportingService) sendUsageReport() error {
-	d := reportData(s.model)
+	d := reportData(s.cfg, s.model)
 	var b bytes.Buffer
 	json.NewEncoder(&b).Encode(d)
 
@@ -256,12 +265,12 @@ func (s *usageReportingService) sendUsageReport() error {
 		}
 	}
 
-	if cfg.Options().URPostInsecurely {
+	if s.cfg.Options().URPostInsecurely {
 		transp.TLSClientConfig = &tls.Config{
 			InsecureSkipVerify: true,
 		}
 	}
-	_, err := client.Post(cfg.Options().URURL, "application/json", &b)
+	_, err := client.Post(s.cfg.Options().URURL, "application/json", &b)
 	return err
 }
 
@@ -271,7 +280,7 @@ func (s *usageReportingService) Serve() {
 	l.Infoln("Starting usage reporting")
 	defer l.Infoln("Stopping usage reporting")
 
-	t := time.NewTimer(time.Duration(cfg.Options().URInitialDelayS) * time.Second) // time to initial report at start
+	t := time.NewTimer(time.Duration(s.cfg.Options().URInitialDelayS) * time.Second) // time to initial report at start
 	for {
 		select {
 		case <-s.stop:

gui/assets/css/overrides.css

@@ -21,6 +21,10 @@ ul+h5 {
     margin-top: 1.5em;
 }
 
+#content {
+    margin-bottom: 50px;
+}
+
 .panel-progress {
     background: #3498db;
     height: 3px;
@@ -64,6 +68,7 @@ identicon {
 
 .popover {
     max-width: none;
+    min-width: 250px;
 }
 
 .panel-heading .fa, .modal-header .fa {
@@ -249,7 +254,3 @@ ul.three-columns li, ul.two-columns li {
         position: static;
     }
 }
-
-.popover {
-    min-width: 250px;
-}

gui/index.html

@@ -70,7 +70,7 @@
     </div>
   </nav>
 
-  <div class="container">
+  <div class="container" id="content">
 
     <!-- Panel: Restart Needed -->
 
@@ -171,7 +171,7 @@
         <div class="panel panel-warning">
           <div class="panel-heading"><h3 class="panel-title"><span class="fa fa-exclamation-circle"></span><span translate>Notice</span></h3></div>
           <div class="panel-body">
-            <p ng-repeat="err in errorList()"><small>{{err.time | date:"yyyy-MM-dd HH:mm:ss"}}:</small> {{friendlyDevices(err.error)}}</p>
+            <p ng-repeat="err in errorList()"><small>{{err.when | date:"yyyy-MM-dd HH:mm:ss"}}:</small> {{friendlyDevices(err.message)}}</p>
           </div>
           <div class="panel-footer">
             <button type="button" class="btn btn-sm btn-default pull-right" ng-click="clearErrors()">
@@ -239,7 +239,7 @@
                       <td class="text-right">{{model[folder.id].localFiles | alwaysNumber}} <span translate>items</span>, ~{{model[folder.id].localBytes | binary}}B</td>
                     </tr>
                     <tr ng-if="model[folder.id].needFiles > 0">
-                      <th><span class="fa fa-fw fa-cloud-download"></span>&nbsp;<span translate>Out of Sync</span></th>
+                      <th><span class="fa fa-fw fa-cloud-download"></span>&nbsp;<span translate>Out of Sync Items</span></th>
                       <td class="text-right">
                         <a href="" ng-click="showNeed(folder.id)">{{model[folder.id].needFiles | alwaysNumber}} <span translate>items</span>, ~{{model[folder.id].needBytes | binary}}B</a>
                       </td>

gui/syncthing/core/aboutModalView.html

@@ -13,6 +13,7 @@
     <div class="col-md-12">
       <ul class="list-unstyled three-columns" id="contributor-list">
         <li class="auto-generated">Aaron Bieber</li>
+        <li class="auto-generated">Adam Piggott</li>
         <li class="auto-generated">Alexander Graf</li>
         <li class="auto-generated">Andrew Dunham</li>
         <li class="auto-generated">Antony Male</li>
@@ -59,6 +60,7 @@
         <li class="auto-generated">Marc Laporte</li>
         <li class="auto-generated">Marc Pujol</li>
         <li class="auto-generated">Marcin Dziadus</li>
+        <li class="auto-generated">Mateon1</li>
         <li class="auto-generated">Matt Burke</li>
         <li class="auto-generated">Michael Jephcote</li>
         <li class="auto-generated">Michael Tilli</li>
@@ -76,6 +78,7 @@
         <li class="auto-generated">Tully Robinson</li>
         <li class="auto-generated">Veeti Paananen</li>
         <li class="auto-generated">Vil Brekin</li>
+        <li class="auto-generated">Yannic A.</li>
       </ul>
     </div>
   </div>

gui/syncthing/core/syncthingController.js

@@ -1043,13 +1043,16 @@ angular.module('syncthing.core')
         };
 
         $scope.errorList = function () {
+            if (!$scope.errors) {
+                return [];
+            }
             return $scope.errors.filter(function (e) {
-                return e.time > $scope.seenError;
+                return e.when > $scope.seenError;
             });
         };
 
         $scope.clearErrors = function () {
-            $scope.seenError = $scope.errors[$scope.errors.length - 1].time;
+            $scope.seenError = $scope.errors[$scope.errors.length - 1].when;
             $http.post(urlbase + '/system/error/clear');
         };
 

gui/syncthing/device/editDeviceModalView.html

@@ -15,7 +15,7 @@
             <datalist id="discovery-list" ng-if="!editingExisting">
               <option ng-repeat="(id, data) in discovery" value="{{id}}" />
             </datalist>
-            <div ng-if="editingExisting" class="well well-sm text-monospace">{{currentDevice.deviceID}}</div>
+            <div ng-if="editingExisting" class="well well-sm text-monospace" select-on-click>{{currentDevice.deviceID}}</div>
             <p class="help-block">
               <span translate ng-if="deviceEditor.deviceID.$valid || deviceEditor.deviceID.$pristine">The device ID to enter here can be found in the "Edit > Show ID" dialog on the other device. Spaces and dashes are optional (ignored).</span>
               <span translate ng-show="!editingExisting && (deviceEditor.deviceID.$valid || deviceEditor.deviceID.$pristine)">When adding a new device, keep in mind that this device must be added on the other side too.</span>

gui/syncthing/device/idqrModalView.html

@@ -1,4 +1,4 @@
 <modal id="idqr" status="info" icon="qrcode" title="{{'Device Identification' | translate}} - {{deviceName(thisDevice())}}" large="yes" close="yes">
-  <div class="well well-sm text-monospace text-center">{{myID}}</div>
+  <div class="well well-sm text-monospace text-center" select-on-click>{{myID}}</div>
   <img ng-if="myID" class="center-block img-thumbnail" ng-src="qr/?text={{myID}}"/>
 </modal>

gui/syncthing/settings/settingsModalView.html

@@ -108,7 +108,7 @@
 
             <div class="form-group">
               <label translate>API Key</label>
-              <div class="well well-sm text-monospace">{{tmpGUI.apiKey || "-"}}</div>
+              <div class="well well-sm text-monospace" select-on-click>{{tmpGUI.apiKey || "-"}}</div>
               <button type="button" class="btn btn-sm btn-default" ng-click="setAPIKey(tmpGUI)">
                 <span class="fa fa-repeat"></span>&nbsp;<span translate>Generate</span>
               </button>

lib/beacon/broadcast.go

@@ -33,9 +33,7 @@ func NewBroadcast(port int) *Broadcast {
 			FailureBackoff:   60 * time.Second,
 			// Only log restarts in debug mode.
 			Log: func(line string) {
-				if debug {
-					l.Debugln(line)
-				}
+				l.Debugln(line)
 			},
 		}),
 		port:   port,
@@ -81,17 +79,13 @@ type broadcastWriter struct {
 }
 
 func (w *broadcastWriter) Serve() {
-	if debug {
-		l.Debugln(w, "starting")
-		defer l.Debugln(w, "stopping")
-	}
+	l.Debugln(w, "starting")
+	defer l.Debugln(w, "stopping")
 
 	var err error
 	w.conn, err = net.ListenUDP("udp4", nil)
 	if err != nil {
-		if debug {
-			l.Debugln(err)
-		}
+		l.Debugln(err)
 		w.setError(err)
 		return
 	}
@@ -100,9 +94,7 @@ func (w *broadcastWriter) Serve() {
 	for bs := range w.inbox {
 		addrs, err := net.InterfaceAddrs()
 		if err != nil {
-			if debug {
-				l.Debugln(err)
-			}
+			l.Debugln(err)
 			w.setError(err)
 			continue
 		}
@@ -120,9 +112,7 @@ func (w *broadcastWriter) Serve() {
 			dsts = append(dsts, net.IP{0xff, 0xff, 0xff, 0xff})
 		}
 
-		if debug {
-			l.Debugln("addresses:", dsts)
-		}
+		l.Debugln("addresses:", dsts)
 
 		success := 0
 		for _, ip := range dsts {
@@ -135,34 +125,25 @@ func (w *broadcastWriter) Serve() {
 			if err, ok := err.(net.Error); ok && err.Timeout() {
 				// Write timeouts should not happen. We treat it as a fatal
 				// error on the socket.
-				if debug {
-					l.Debugln(err)
-				}
+				l.Debugln(err)
 				w.setError(err)
 				return
 			}
 
 			if err, ok := err.(net.Error); ok && err.Temporary() {
 				// A transient error. Lets hope for better luck in the future.
-				if debug {
-					l.Debugln(err)
-				}
+				l.Debugln(err)
 				continue
 			}
 
 			if err != nil {
 				// Some other error that we don't expect. Bail and retry.
-				if debug {
-					l.Debugln(err)
-				}
+				l.Debugln(err)
 				w.setError(err)
 				return
 			}
 
-			if debug {
-				l.Debugf("sent %d bytes to %s", len(bs), dst)
-			}
-
+			l.Debugf("sent %d bytes to %s", len(bs), dst)
 			success++
 		}
 
@@ -188,17 +169,13 @@ type broadcastReader struct {
 }
 
 func (r *broadcastReader) Serve() {
-	if debug {
-		l.Debugln(r, "starting")
-		defer l.Debugln(r, "stopping")
-	}
+	l.Debugln(r, "starting")
+	defer l.Debugln(r, "stopping")
 
 	var err error
 	r.conn, err = net.ListenUDP("udp4", &net.UDPAddr{Port: r.port})
 	if err != nil {
-		if debug {
-			l.Debugln(err)
-		}
+		l.Debugln(err)
 		r.setError(err)
 		return
 	}
@@ -208,27 +185,21 @@ func (r *broadcastReader) Serve() {
 	for {
 		n, addr, err := r.conn.ReadFrom(bs)
 		if err != nil {
-			if debug {
-				l.Debugln(err)
-			}
+			l.Debugln(err)
 			r.setError(err)
 			return
 		}
 
 		r.setError(nil)
 
-		if debug {
-			l.Debugf("recv %d bytes from %s", n, addr)
-		}
+		l.Debugf("recv %d bytes from %s", n, addr)
 
 		c := make([]byte, n)
 		copy(c, bs)
 		select {
 		case r.outbox <- recv{c, addr}:
 		default:
-			if debug {
-				l.Debugln("dropping message")
-			}
+			l.Debugln("dropping message")
 		}
 	}
 

lib/beacon/debug.go

@@ -10,10 +10,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "beacon") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("beacon", "Multicast and broadcast discovery")
 )
+
+func init() {
+	l.SetDebug("beacon", strings.Contains(os.Getenv("STTRACE"), "beacon") || os.Getenv("STTRACE") == "all")
+}

lib/beacon/multicast.go

@@ -35,9 +35,7 @@ func NewMulticast(addr string) *Multicast {
 			FailureBackoff:   60 * time.Second,
 			// Only log restarts in debug mode.
 			Log: func(line string) {
-				if debug {
-					l.Debugln(line)
-				}
+				l.Debugln(line)
 			},
 		}),
 		inbox:  make(chan []byte),
@@ -85,25 +83,19 @@ type multicastWriter struct {
 }
 
 func (w *multicastWriter) Serve() {
-	if debug {
-		l.Debugln(w, "starting")
-		defer l.Debugln(w, "stopping")
-	}
+	l.Debugln(w, "starting")
+	defer l.Debugln(w, "stopping")
 
 	gaddr, err := net.ResolveUDPAddr("udp6", w.addr)
 	if err != nil {
-		if debug {
-			l.Debugln(err)
-		}
+		l.Debugln(err)
 		w.setError(err)
 		return
 	}
 
 	conn, err := net.ListenPacket("udp6", ":0")
 	if err != nil {
-		if debug {
-			l.Debugln(err)
-		}
+		l.Debugln(err)
 		w.setError(err)
 		return
 	}
@@ -117,9 +109,7 @@ func (w *multicastWriter) Serve() {
 	for bs := range w.inbox {
 		intfs, err := net.Interfaces()
 		if err != nil {
-			if debug {
-				l.Debugln(err)
-			}
+			l.Debugln(err)
 			w.setError(err)
 			return
 		}
@@ -132,16 +122,12 @@ func (w *multicastWriter) Serve() {
 			pconn.SetWriteDeadline(time.Time{})
 
 			if err != nil {
-				if debug {
-					l.Debugln(err, "on write to", gaddr, intf.Name)
-				}
+				l.Debugln(err, "on write to", gaddr, intf.Name)
 				w.setError(err)
 				continue
 			}
 
-			if debug {
-				l.Debugf("sent %d bytes to %v on %s", len(bs), gaddr, intf.Name)
-			}
+			l.Debugf("sent %d bytes to %v on %s", len(bs), gaddr, intf.Name)
 
 			success++
 		}
@@ -149,9 +135,7 @@ func (w *multicastWriter) Serve() {
 		if success > 0 {
 			w.setError(nil)
 		} else {
-			if debug {
-				l.Debugln(err)
-			}
+			l.Debugln(err)
 			w.setError(err)
 		}
 	}
@@ -173,34 +157,26 @@ type multicastReader struct {
 }
 
 func (r *multicastReader) Serve() {
-	if debug {
-		l.Debugln(r, "starting")
-		defer l.Debugln(r, "stopping")
-	}
+	l.Debugln(r, "starting")
+	defer l.Debugln(r, "stopping")
 
 	gaddr, err := net.ResolveUDPAddr("udp6", r.addr)
 	if err != nil {
-		if debug {
-			l.Debugln(err)
-		}
+		l.Debugln(err)
 		r.setError(err)
 		return
 	}
 
 	conn, err := net.ListenPacket("udp6", r.addr)
 	if err != nil {
-		if debug {
-			l.Debugln(err)
-		}
+		l.Debugln(err)
 		r.setError(err)
 		return
 	}
 
 	intfs, err := net.Interfaces()
 	if err != nil {
-		if debug {
-			l.Debugln(err)
-		}
+		l.Debugln(err)
 		r.setError(err)
 		return
 	}
@@ -209,20 +185,16 @@ func (r *multicastReader) Serve() {
 	joined := 0
 	for _, intf := range intfs {
 		err := pconn.JoinGroup(&intf, &net.UDPAddr{IP: gaddr.IP})
-		if debug {
-			if err != nil {
-				l.Debugln("IPv6 join", intf.Name, "failed:", err)
-			} else {
-				l.Debugln("IPv6 join", intf.Name, "success")
-			}
+		if err != nil {
+			l.Debugln("IPv6 join", intf.Name, "failed:", err)
+		} else {
+			l.Debugln("IPv6 join", intf.Name, "success")
 		}
 		joined++
 	}
 
 	if joined == 0 {
-		if debug {
-			l.Debugln("no multicast interfaces available")
-		}
+		l.Debugln("no multicast interfaces available")
 		r.setError(errors.New("no multicast interfaces available"))
 		return
 	}
@@ -231,24 +203,18 @@ func (r *multicastReader) Serve() {
 	for {
 		n, _, addr, err := pconn.ReadFrom(bs)
 		if err != nil {
-			if debug {
-				l.Debugln(err)
-			}
+			l.Debugln(err)
 			r.setError(err)
 			continue
 		}
-		if debug {
-			l.Debugf("recv %d bytes from %s", n, addr)
-		}
+		l.Debugf("recv %d bytes from %s", n, addr)
 
 		c := make([]byte, n)
 		copy(c, bs)
 		select {
 		case r.outbox <- recv{c, addr}:
 		default:
-			if debug {
-				l.Debugln("dropping message")
-			}
+			l.Debugln("dropping message")
 		}
 	}
 }

lib/config/config.go

@@ -12,6 +12,7 @@ import (
 	"fmt"
 	"io"
 	"math/rand"
+	"net/url"
 	"os"
 	"path/filepath"
 	"reflect"
@@ -108,7 +109,9 @@ type FolderConfiguration struct {
 	Hashers               int                         `xml:"hashers" json:"hashers"` // Less than one sets the value to the number of cores. These are CPU bound due to hashing.
 	Order                 PullOrder                   `xml:"order" json:"order"`
 	IgnoreDelete          bool                        `xml:"ignoreDelete" json:"ignoreDelete"`
-	ScanProgressIntervalS int                         `xml:"scanProgressInterval" json:"scanProgressInterval"` // Set to a negative value to disable. Value of 0 will get replaced with value of 2 (default value)
+	ScanProgressIntervalS int                         `xml:"scanProgressIntervalS" json:"scanProgressIntervalS"` // Set to a negative value to disable. Value of 0 will get replaced with value of 2 (default value)
+	PullerSleepS          int                         `xml:"pullerSleepS" json:"pullerSleepS"`
+	PullerPauseS          int                         `xml:"pullerPauseS" json:"pullerPauseS"`
 
 	Invalid string `xml:"-" json:"invalid"` // Set at runtime when there is an error, not saved
 }
@@ -286,12 +289,72 @@ func (orig OptionsConfiguration) Copy() OptionsConfiguration {
 }
 
 type GUIConfiguration struct {
-	Enabled  bool   `xml:"enabled,attr" json:"enabled" default:"true"`
-	Address  string `xml:"address" json:"address" default:"127.0.0.1:8384"`
-	User     string `xml:"user,omitempty" json:"user"`
-	Password string `xml:"password,omitempty" json:"password"`
-	UseTLS   bool   `xml:"tls,attr" json:"useTLS"`
-	APIKey   string `xml:"apikey,omitempty" json:"apiKey"`
+	Enabled    bool   `xml:"enabled,attr" json:"enabled" default:"true"`
+	RawAddress string `xml:"address" json:"address" default:"127.0.0.1:8384"`
+	User       string `xml:"user,omitempty" json:"user"`
+	Password   string `xml:"password,omitempty" json:"password"`
+	RawUseTLS  bool   `xml:"tls,attr" json:"useTLS"`
+	RawAPIKey  string `xml:"apikey,omitempty" json:"apiKey"`
+}
+
+func (c GUIConfiguration) Address() string {
+	if override := os.Getenv("STGUIADDRESS"); override != "" {
+		// This value may be of the form "scheme://address:port" or just
+		// "address:port". We need to chop off the scheme. We try to parse it as
+		// an URL if it contains a slash. If that fails, return it as is and let
+		// some other error handling handle it.
+
+		if strings.Contains(override, "/") {
+			url, err := url.Parse(override)
+			if err != nil {
+				return override
+			}
+			return url.Host
+		}
+
+		return override
+	}
+
+	return c.RawAddress
+}
+
+func (c GUIConfiguration) UseTLS() bool {
+	if override := os.Getenv("STGUIADDRESS"); override != "" {
+		return strings.HasPrefix(override, "https:")
+	}
+	return c.RawUseTLS
+}
+
+func (c GUIConfiguration) URL() string {
+	u := url.URL{
+		Scheme: "http",
+		Host:   c.Address(),
+		Path:   "/",
+	}
+
+	if c.UseTLS() {
+		u.Scheme = "https"
+	}
+
+	if strings.HasPrefix(u.Host, ":") {
+		// Empty host, i.e. ":port", use IPv4 localhost
+		u.Host = "127.0.0.1" + u.Host
+	} else if strings.HasPrefix(u.Host, "0.0.0.0:") {
+		// IPv4 all zeroes host, convert to IPv4 localhost
+		u.Host = "127.0.0.1" + u.Host[7:]
+	} else if strings.HasPrefix(u.Host, "[::]:") {
+		// IPv6 all zeroes host, convert to IPv6 localhost
+		u.Host = "[::1]" + u.Host[4:]
+	}
+
+	return u.String()
+}
+
+func (c GUIConfiguration) APIKey() string {
+	if override := os.Getenv("STGUIAPIKEY"); override != "" {
+		return override
+	}
+	return c.RawAPIKey
 }
 
 func New(myID protocol.DeviceID) Configuration {
@@ -361,6 +424,9 @@ func (cfg *Configuration) prepare(myID protocol.DeviceID) {
 		// This way in the tests, we get away without OS specific separators
 		// in the test configs.
 		folder.RawPath = filepath.Dir(folder.RawPath + string(filepath.Separator))
+		if folder.RawPath[len(folder.RawPath)-1] != filepath.Separator {
+			folder.RawPath = folder.RawPath + string(filepath.Separator)
+		}
 
 		if folder.ID == "" {
 			folder.ID = "default"
@@ -461,8 +527,8 @@ func (cfg *Configuration) prepare(myID protocol.DeviceID) {
 		cfg.Options.ReconnectIntervalS = 5
 	}
 
-	if cfg.GUI.APIKey == "" {
-		cfg.GUI.APIKey = randomString(32)
+	if cfg.GUI.RawAPIKey == "" {
+		cfg.GUI.RawAPIKey = randomString(32)
 	}
 }
 

lib/config/config_test.go

@@ -91,7 +91,7 @@ func TestDeviceConfig(t *testing.T) {
 		expectedFolders := []FolderConfiguration{
 			{
 				ID:              "test",
-				RawPath:         "testdata",
+				RawPath:         "testdata" + string(filepath.Separator),
 				Devices:         []FolderDeviceConfiguration{{DeviceID: device1}, {DeviceID: device4}},
 				ReadOnly:        true,
 				RescanIntervalS: 600,
@@ -326,7 +326,7 @@ func TestIssue1262(t *testing.T) {
 	}
 
 	actual := cfg.Folders()["test"].RawPath
-	expected := "e:"
+	expected := "e:/"
 	if runtime.GOOS == "windows" {
 		expected = `e:\`
 	}
@@ -528,7 +528,7 @@ func TestRequiresRestart(t *testing.T) {
 	}
 
 	newCfg = cfg
-	newCfg.GUI.UseTLS = !cfg.GUI.UseTLS
+	newCfg.GUI.RawUseTLS = !cfg.GUI.RawUseTLS
 	if !ChangeRequiresRestart(cfg, newCfg) {
 		t.Error("Changing GUI options requires restart")
 	}
@@ -551,7 +551,7 @@ func TestCopy(t *testing.T) {
 	cfg.Devices[0].Addresses[0] = "wrong"
 	cfg.Folders[0].Devices[0].DeviceID = protocol.DeviceID{0, 1, 2, 3}
 	cfg.Options.ListenAddress[0] = "wrong"
-	cfg.GUI.APIKey = "wrong"
+	cfg.GUI.RawAPIKey = "wrong"
 
 	bsChanged, err := json.MarshalIndent(cfg, "", "  ")
 	if err != nil {
@@ -634,3 +634,25 @@ func TestLargeRescanInterval(t *testing.T) {
 		t.Error("negative rescan interval should become zero")
 	}
 }
+
+func TestGUIConfigURL(t *testing.T) {
+	testcases := [][2]string{
+		{"192.0.2.42:8080", "http://192.0.2.42:8080/"},
+		{":8080", "http://127.0.0.1:8080/"},
+		{"0.0.0.0:8080", "http://127.0.0.1:8080/"},
+		{"127.0.0.1:8080", "http://127.0.0.1:8080/"},
+		{"127.0.0.2:8080", "http://127.0.0.2:8080/"},
+		{"[::]:8080", "http://[::1]:8080/"},
+		{"[2001::42]:8080", "http://[2001::42]:8080/"},
+	}
+
+	for _, tc := range testcases {
+		c := GUIConfiguration{
+			RawAddress: tc[0],
+		}
+		u := c.URL()
+		if u != tc[1] {
+			t.Errorf("Incorrect URL %s != %s for addr %s", u, tc[1], tc[0])
+		}
+	}
+}

lib/config/debug.go

@@ -10,10 +10,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "config") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("config", "Configuration loading and saving")
 )
+
+func init() {
+	l.SetDebug("config", strings.Contains(os.Getenv("STTRACE"), "config") || os.Getenv("STTRACE") == "all")
+}

lib/config/wrapper.go

@@ -142,13 +142,9 @@ func (w *Wrapper) replaceLocked(to Configuration) CommitResponse {
 	from := w.cfg
 
 	for _, sub := range w.subs {
-		if debug {
-			l.Debugln(sub, "verifying configuration")
-		}
+		l.Debugln(sub, "verifying configuration")
 		if err := sub.VerifyConfiguration(from, to); err != nil {
-			if debug {
-				l.Debugln(sub, "rejected config:", err)
-			}
+			l.Debugln(sub, "rejected config:", err)
 			return CommitResponse{
 				ValidationError: err,
 			}
@@ -157,14 +153,10 @@ func (w *Wrapper) replaceLocked(to Configuration) CommitResponse {
 
 	allOk := true
 	for _, sub := range w.subs {
-		if debug {
-			l.Debugln(sub, "committing configuration")
-		}
+		l.Debugln(sub, "committing configuration")
 		ok := sub.CommitConfiguration(from, to)
 		if !ok {
-			if debug {
-				l.Debugln(sub, "requires restart")
-			}
+			l.Debugln(sub, "requires restart")
 			allOk = false
 		}
 	}

lib/connections/connections.go

@@ -121,9 +121,7 @@ func NewConnectionSvc(cfg *config.Wrapper, myID protocol.DeviceID, mdl Model, tl
 			continue
 		}
 
-		if debug {
-			l.Debugln("listening on", uri.String())
-		}
+		l.Debugln("listening on", uri)
 
 		svc.Add(serviceFunc(func() {
 			listener(uri, svc.tlsCfg, svc.conns)
@@ -178,9 +176,7 @@ next:
 		ct, ok := s.connType[remoteID]
 		s.mut.RUnlock()
 		if ok && !ct.IsDirect() && c.Type.IsDirect() {
-			if debug {
-				l.Debugln("Switching connections", remoteID)
-			}
+			l.Debugln("Switching connections", remoteID)
 			s.model.Close(remoteID, fmt.Errorf("switching connections"))
 		} else if s.model.ConnectedTo(remoteID) {
 			// We should not already be connected to the other party. TODO: This
@@ -236,9 +232,7 @@ next:
 				protoConn := protocol.NewConnection(remoteID, rd, wr, s.model, name, deviceCfg.Compression)
 
 				l.Infof("Established secure connection to %s at %s", remoteID, name)
-				if debug {
-					l.Debugf("cipher suite: %04X in lan: %t", c.Conn.ConnectionState().CipherSuite, !limit)
-				}
+				l.Debugf("cipher suite: %04X in lan: %t", c.Conn.ConnectionState().CipherSuite, !limit)
 
 				s.model.AddConnection(model.Connection{
 					c.Conn,
@@ -311,18 +305,14 @@ func (s *connectionSvc) connect() {
 
 				dialer, ok := dialers[uri.Scheme]
 				if !ok {
-					l.Infoln("Unknown address schema", uri.String())
+					l.Infoln("Unknown address schema", uri)
 					continue
 				}
 
-				if debug {
-					l.Debugln("dial", deviceCfg.DeviceID, uri.String())
-				}
+				l.Debugln("dial", deviceCfg.DeviceID, uri)
 				conn, err := dialer(uri, s.tlsCfg)
 				if err != nil {
-					if debug {
-						l.Debugln("dial failed", deviceCfg.DeviceID, uri.String(), err)
-					}
+					l.Debugln("dial failed", deviceCfg.DeviceID, uri, err)
 					continue
 				}
 
@@ -347,11 +337,9 @@ func (s *connectionSvc) connect() {
 
 			reconIntv := time.Duration(s.cfg.Options().RelayReconnectIntervalM) * time.Minute
 			if last, ok := s.lastRelayCheck[deviceID]; ok && time.Since(last) < reconIntv {
-				if debug {
-					l.Debugln("Skipping connecting via relay to", deviceID, "last checked at", last)
-				}
+				l.Debugln("Skipping connecting via relay to", deviceID, "last checked at", last)
 				continue nextDevice
-			} else if debug {
+			} else {
 				l.Debugln("Trying relay connections to", deviceID, relays)
 			}
 
@@ -366,21 +354,17 @@ func (s *connectionSvc) connect() {
 
 				inv, err := client.GetInvitationFromRelay(uri, deviceID, s.tlsCfg.Certificates)
 				if err != nil {
-					if debug {
-						l.Debugf("Failed to get invitation for %s from %s: %v", deviceID, uri, err)
-					}
+					l.Debugf("Failed to get invitation for %s from %s: %v", deviceID, uri, err)
 					continue
-				} else if debug {
+				} else {
 					l.Debugln("Succesfully retrieved relay invitation", inv, "from", uri)
 				}
 
 				conn, err := client.JoinSession(inv)
 				if err != nil {
-					if debug {
-						l.Debugf("Failed to join relay session %s: %v", inv, err)
-					}
+					l.Debugf("Failed to join relay session %s: %v", inv, err)
 					continue
-				} else if debug {
+				} else {
 					l.Debugln("Sucessfully joined relay session", inv)
 				}
 

lib/connections/connections_tcp.go

@@ -33,17 +33,13 @@ func tcpDialer(uri *url.URL, tlsCfg *tls.Config) (*tls.Conn, error) {
 
 	raddr, err := net.ResolveTCPAddr("tcp", uri.Host)
 	if err != nil {
-		if debug {
-			l.Debugln(err)
-		}
+		l.Debugln(err)
 		return nil, err
 	}
 
 	conn, err := net.DialTCP("tcp", nil, raddr)
 	if err != nil {
-		if debug {
-			l.Debugln(err)
-		}
+		l.Debugln(err)
 		return nil, err
 	}
 
@@ -81,9 +77,7 @@ func tcpListener(uri *url.URL, tlsCfg *tls.Config, conns chan<- model.Intermedia
 			continue
 		}
 
-		if debug {
-			l.Debugln("connect from", conn.RemoteAddr())
-		}
+		l.Debugln("connect from", conn.RemoteAddr())
 
 		err = osutil.SetTCPOptions(conn.(*net.TCPConn))
 		if err != nil {

lib/connections/debug.go

@@ -10,10 +10,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "connections") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("connections", "Connection handling")
 )
+
+func init() {
+	l.SetDebug("connections", strings.Contains(os.Getenv("STTRACE"), "connections") || os.Getenv("STTRACE") == "all")
+}

lib/db/debug.go

@@ -10,11 +10,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug   = strings.Contains(os.Getenv("STTRACE"), "files") || os.Getenv("STTRACE") == "all"
-	debugDB = strings.Contains(os.Getenv("STTRACE"), "db") || os.Getenv("STTRACE") == "all"
-	l       = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("db", "The database layer")
 )
+
+func init() {
+	l.SetDebug("db", strings.Contains(os.Getenv("STTRACE"), "db") || os.Getenv("STTRACE") == "all")
+}

lib/db/leveldb.go

@@ -178,20 +178,14 @@ func ldbGenericReplace(db *leveldb.DB, folder, device []byte, fs []protocol.File
 	limit := deviceKey(folder, device, []byte{0xff, 0xff, 0xff, 0xff}) // after all folder/device files
 
 	batch := new(leveldb.Batch)
-	if debugDB {
-		l.Debugf("new batch %p", batch)
-	}
+	l.Debugf("new batch %p", batch)
 	snap, err := db.GetSnapshot()
 	if err != nil {
 		panic(err)
 	}
-	if debugDB {
-		l.Debugf("created snapshot %p", snap)
-	}
+	l.Debugf("created snapshot %p", snap)
 	defer func() {
-		if debugDB {
-			l.Debugf("close snapshot %p", snap)
-		}
+		l.Debugf("close snapshot %p", snap)
 		snap.Release()
 	}()
 
@@ -220,15 +214,11 @@ func ldbGenericReplace(db *leveldb.DB, folder, device []byte, fs []protocol.File
 
 		cmp := bytes.Compare(newName, oldName)
 
-		if debugDB {
-			l.Debugf("generic replace; folder=%q device=%v moreFs=%v moreDb=%v cmp=%d newName=%q oldName=%q", folder, protocol.DeviceIDFromBytes(device), moreFs, moreDb, cmp, newName, oldName)
-		}
+		l.Debugf("generic replace; folder=%q device=%v moreFs=%v moreDb=%v cmp=%d newName=%q oldName=%q", folder, protocol.DeviceIDFromBytes(device), moreFs, moreDb, cmp, newName, oldName)
 
 		switch {
 		case moreFs && (!moreDb || cmp == -1):
-			if debugDB {
-				l.Debugln("generic replace; missing - insert")
-			}
+			l.Debugln("generic replace; missing - insert")
 			// Database is missing this file. Insert it.
 			if lv := ldbInsert(batch, folder, device, fs[fsi]); lv > maxLocalVer {
 				maxLocalVer = lv
@@ -244,15 +234,11 @@ func ldbGenericReplace(db *leveldb.DB, folder, device []byte, fs []protocol.File
 			// File exists on both sides - compare versions. We might get an
 			// update with the same version and different flags if a device has
 			// marked a file as invalid, so handle that too.
-			if debugDB {
-				l.Debugln("generic replace; exists - compare")
-			}
+			l.Debugln("generic replace; exists - compare")
 			var ef FileInfoTruncated
 			ef.UnmarshalXDR(dbi.Value())
 			if !fs[fsi].Version.Equal(ef.Version) || fs[fsi].Flags != ef.Flags {
-				if debugDB {
-					l.Debugln("generic replace; differs - insert")
-				}
+				l.Debugln("generic replace; differs - insert")
 				if lv := ldbInsert(batch, folder, device, fs[fsi]); lv > maxLocalVer {
 					maxLocalVer = lv
 				}
@@ -261,7 +247,7 @@ func ldbGenericReplace(db *leveldb.DB, folder, device []byte, fs []protocol.File
 				} else {
 					ldbUpdateGlobal(snap, batch, folder, device, fs[fsi])
 				}
-			} else if debugDB {
+			} else {
 				l.Debugln("generic replace; equal - ignore")
 			}
 
@@ -269,9 +255,7 @@ func ldbGenericReplace(db *leveldb.DB, folder, device []byte, fs []protocol.File
 			moreDb = dbi.Next()
 
 		case moreDb && (!moreFs || cmp == 1):
-			if debugDB {
-				l.Debugln("generic replace; exists - remove")
-			}
+			l.Debugln("generic replace; exists - remove")
 			if lv := deleteFn(snap, batch, folder, device, oldName, dbi); lv > maxLocalVer {
 				maxLocalVer = lv
 			}
@@ -281,9 +265,7 @@ func ldbGenericReplace(db *leveldb.DB, folder, device []byte, fs []protocol.File
 		// Write out and reuse the batch every few records, to avoid the batch
 		// growing too large and thus allocating unnecessarily much memory.
 		if batch.Len() > batchFlushSize {
-			if debugDB {
-				l.Debugf("db.Write %p", batch)
-			}
+			l.Debugf("db.Write %p", batch)
 
 			err = db.Write(batch, nil)
 			if err != nil {
@@ -294,9 +276,7 @@ func ldbGenericReplace(db *leveldb.DB, folder, device []byte, fs []protocol.File
 		}
 	}
 
-	if debugDB {
-		l.Debugf("db.Write %p", batch)
-	}
+	l.Debugf("db.Write %p", batch)
 	err = db.Write(batch, nil)
 	if err != nil {
 		panic(err)
@@ -309,13 +289,9 @@ func ldbReplace(db *leveldb.DB, folder, device []byte, fs []protocol.FileInfo) i
 	// TODO: Return the remaining maxLocalVer?
 	return ldbGenericReplace(db, folder, device, fs, func(db dbReader, batch dbWriter, folder, device, name []byte, dbi iterator.Iterator) int64 {
 		// Database has a file that we are missing. Remove it.
-		if debugDB {
-			l.Debugf("delete; folder=%q device=%v name=%q", folder, protocol.DeviceIDFromBytes(device), name)
-		}
+		l.Debugf("delete; folder=%q device=%v name=%q", folder, protocol.DeviceIDFromBytes(device), name)
 		ldbRemoveFromGlobal(db, batch, folder, device, name)
-		if debugDB {
-			l.Debugf("batch.Delete %p %x", batch, dbi.Key())
-		}
+		l.Debugf("batch.Delete %p %x", batch, dbi.Key())
 		batch.Delete(dbi.Key())
 		return 0
 	})
@@ -325,20 +301,14 @@ func ldbUpdate(db *leveldb.DB, folder, device []byte, fs []protocol.FileInfo) in
 	runtime.GC()
 
 	batch := new(leveldb.Batch)
-	if debugDB {
-		l.Debugf("new batch %p", batch)
-	}
+	l.Debugf("new batch %p", batch)
 	snap, err := db.GetSnapshot()
 	if err != nil {
 		panic(err)
 	}
-	if debugDB {
-		l.Debugf("created snapshot %p", snap)
-	}
+	l.Debugf("created snapshot %p", snap)
 	defer func() {
-		if debugDB {
-			l.Debugf("close snapshot %p", snap)
-		}
+		l.Debugf("close snapshot %p", snap)
 		snap.Release()
 	}()
 
@@ -347,9 +317,7 @@ func ldbUpdate(db *leveldb.DB, folder, device []byte, fs []protocol.FileInfo) in
 	for _, f := range fs {
 		name := []byte(f.Name)
 		fk = deviceKeyInto(fk[:cap(fk)], folder, device, name)
-		if debugDB {
-			l.Debugf("snap.Get %p %x", snap, fk)
-		}
+		l.Debugf("snap.Get %p %x", snap, fk)
 		bs, err := snap.Get(fk, nil)
 		if err == leveldb.ErrNotFound {
 			if lv := ldbInsert(batch, folder, device, f); lv > maxLocalVer {
@@ -384,9 +352,7 @@ func ldbUpdate(db *leveldb.DB, folder, device []byte, fs []protocol.FileInfo) in
 		// Write out and reuse the batch every few records, to avoid the batch
 		// growing too large and thus allocating unnecessarily much memory.
 		if batch.Len() > batchFlushSize {
-			if debugDB {
-				l.Debugf("db.Write %p", batch)
-			}
+			l.Debugf("db.Write %p", batch)
 
 			err = db.Write(batch, nil)
 			if err != nil {
@@ -397,9 +363,7 @@ func ldbUpdate(db *leveldb.DB, folder, device []byte, fs []protocol.FileInfo) in
 		}
 	}
 
-	if debugDB {
-		l.Debugf("db.Write %p", batch)
-	}
+	l.Debugf("db.Write %p", batch)
 	err = db.Write(batch, nil)
 	if err != nil {
 		panic(err)
@@ -409,9 +373,7 @@ func ldbUpdate(db *leveldb.DB, folder, device []byte, fs []protocol.FileInfo) in
 }
 
 func ldbInsert(batch dbWriter, folder, device []byte, file protocol.FileInfo) int64 {
-	if debugDB {
-		l.Debugf("insert; folder=%q device=%v %v", folder, protocol.DeviceIDFromBytes(device), file)
-	}
+	l.Debugf("insert; folder=%q device=%v %v", folder, protocol.DeviceIDFromBytes(device), file)
 
 	if file.LocalVersion == 0 {
 		file.LocalVersion = clock(0)
@@ -419,9 +381,7 @@ func ldbInsert(batch dbWriter, folder, device []byte, file protocol.FileInfo) in
 
 	name := []byte(file.Name)
 	nk := deviceKey(folder, device, name)
-	if debugDB {
-		l.Debugf("batch.Put %p %x", batch, nk)
-	}
+	l.Debugf("batch.Put %p %x", batch, nk)
 	batch.Put(nk, file.MustMarshalXDR())
 
 	return file.LocalVersion
@@ -431,9 +391,7 @@ func ldbInsert(batch dbWriter, folder, device []byte, file protocol.FileInfo) in
 // file. If the device is already present in the list, the version is updated.
 // If the file does not have an entry in the global list, it is created.
 func ldbUpdateGlobal(db dbReader, batch dbWriter, folder, device []byte, file protocol.FileInfo) bool {
-	if debugDB {
-		l.Debugf("update global; folder=%q device=%v file=%q version=%d", folder, protocol.DeviceIDFromBytes(device), file.Name, file.Version)
-	}
+	l.Debugf("update global; folder=%q device=%v file=%q version=%d", folder, protocol.DeviceIDFromBytes(device), file.Name, file.Version)
 	name := []byte(file.Name)
 	gk := globalKey(folder, name)
 	svl, err := db.Get(gk, nil)
@@ -499,10 +457,8 @@ func ldbUpdateGlobal(db dbReader, batch dbWriter, folder, device []byte, file pr
 	fl.versions = append(fl.versions, nv)
 
 done:
-	if debugDB {
-		l.Debugf("batch.Put %p %x", batch, gk)
-		l.Debugf("new global after update: %v", fl)
-	}
+	l.Debugf("batch.Put %p %x", batch, gk)
+	l.Debugf("new global after update: %v", fl)
 	batch.Put(gk, fl.MustMarshalXDR())
 
 	return true
@@ -519,9 +475,7 @@ func insertVersion(vl []fileVersion, i int, v fileVersion) []fileVersion {
 // given file. If the version list is empty after this, the file entry is
 // removed entirely.
 func ldbRemoveFromGlobal(db dbReader, batch dbWriter, folder, device, file []byte) {
-	if debugDB {
-		l.Debugf("remove from global; folder=%q device=%v file=%q", folder, protocol.DeviceIDFromBytes(device), file)
-	}
+	l.Debugf("remove from global; folder=%q device=%v file=%q", folder, protocol.DeviceIDFromBytes(device), file)
 
 	gk := globalKey(folder, file)
 	svl, err := db.Get(gk, nil)
@@ -545,15 +499,11 @@ func ldbRemoveFromGlobal(db dbReader, batch dbWriter, folder, device, file []byt
 	}
 
 	if len(fl.versions) == 0 {
-		if debugDB {
-			l.Debugf("batch.Delete %p %x", batch, gk)
-		}
+		l.Debugf("batch.Delete %p %x", batch, gk)
 		batch.Delete(gk)
 	} else {
-		if debugDB {
-			l.Debugf("batch.Put %p %x", batch, gk)
-			l.Debugf("new global after remove: %v", fl)
-		}
+		l.Debugf("batch.Put %p %x", batch, gk)
+		l.Debugf("new global after remove: %v", fl)
 		batch.Put(gk, fl.MustMarshalXDR())
 	}
 }
@@ -565,13 +515,9 @@ func ldbWithHave(db *leveldb.DB, folder, device []byte, truncate bool, fn Iterat
 	if err != nil {
 		panic(err)
 	}
-	if debugDB {
-		l.Debugf("created snapshot %p", snap)
-	}
+	l.Debugf("created snapshot %p", snap)
 	defer func() {
-		if debugDB {
-			l.Debugf("close snapshot %p", snap)
-		}
+		l.Debugf("close snapshot %p", snap)
 		snap.Release()
 	}()
 
@@ -598,13 +544,9 @@ func ldbWithAllFolderTruncated(db *leveldb.DB, folder []byte, fn func(device []b
 	if err != nil {
 		panic(err)
 	}
-	if debugDB {
-		l.Debugf("created snapshot %p", snap)
-	}
+	l.Debugf("created snapshot %p", snap)
 	defer func() {
-		if debugDB {
-			l.Debugf("close snapshot %p", snap)
-		}
+		l.Debugf("close snapshot %p", snap)
 		snap.Release()
 	}()
 
@@ -659,19 +601,13 @@ func ldbGetGlobal(db *leveldb.DB, folder, file []byte, truncate bool) (FileIntf,
 	if err != nil {
 		panic(err)
 	}
-	if debugDB {
-		l.Debugf("created snapshot %p", snap)
-	}
+	l.Debugf("created snapshot %p", snap)
 	defer func() {
-		if debugDB {
-			l.Debugf("close snapshot %p", snap)
-		}
+		l.Debugf("close snapshot %p", snap)
 		snap.Release()
 	}()
 
-	if debugDB {
-		l.Debugf("snap.Get %p %x", snap, k)
-	}
+	l.Debugf("snap.Get %p %x", snap, k)
 	bs, err := snap.Get(k, nil)
 	if err == leveldb.ErrNotFound {
 		return nil, false
@@ -691,9 +627,7 @@ func ldbGetGlobal(db *leveldb.DB, folder, file []byte, truncate bool) (FileIntf,
 	}
 
 	k = deviceKey(folder, vl.versions[0].device, file)
-	if debugDB {
-		l.Debugf("snap.Get %p %x", snap, k)
-	}
+	l.Debugf("snap.Get %p %x", snap, k)
 	bs, err = snap.Get(k, nil)
 	if err != nil {
 		panic(err)
@@ -713,13 +647,9 @@ func ldbWithGlobal(db *leveldb.DB, folder, prefix []byte, truncate bool, fn Iter
 	if err != nil {
 		panic(err)
 	}
-	if debugDB {
-		l.Debugf("created snapshot %p", snap)
-	}
+	l.Debugf("created snapshot %p", snap)
 	defer func() {
-		if debugDB {
-			l.Debugf("close snapshot %p", snap)
-		}
+		l.Debugf("close snapshot %p", snap)
 		snap.Release()
 	}()
 
@@ -739,9 +669,7 @@ func ldbWithGlobal(db *leveldb.DB, folder, prefix []byte, truncate bool, fn Iter
 		}
 		name := globalKeyName(dbi.Key())
 		fk = deviceKeyInto(fk[:cap(fk)], folder, vl.versions[0].device, name)
-		if debugDB {
-			l.Debugf("snap.Get %p %x", snap, fk)
-		}
+		l.Debugf("snap.Get %p %x", snap, fk)
 		bs, err := snap.Get(fk, nil)
 		if err != nil {
 			l.Debugf("folder: %q (%x)", folder, folder)
@@ -802,13 +730,9 @@ func ldbWithNeed(db *leveldb.DB, folder, device []byte, truncate bool, fn Iterat
 	if err != nil {
 		panic(err)
 	}
-	if debugDB {
-		l.Debugf("created snapshot %p", snap)
-	}
+	l.Debugf("created snapshot %p", snap)
 	defer func() {
-		if debugDB {
-			l.Debugf("close snapshot %p", snap)
-		}
+		l.Debugf("close snapshot %p", snap)
 		snap.Release()
 	}()
 
@@ -854,9 +778,7 @@ nextFile:
 					continue nextFile
 				}
 				fk = deviceKeyInto(fk[:cap(fk)], folder, vl.versions[i].device, name)
-				if debugDB {
-					l.Debugf("snap.Get %p %x", snap, fk)
-				}
+				l.Debugf("snap.Get %p %x", snap, fk)
 				bs, err := snap.Get(fk, nil)
 				if err != nil {
 					var id protocol.DeviceID
@@ -886,9 +808,7 @@ nextFile:
 					continue nextFile
 				}
 
-				if debugDB {
-					l.Debugf("need folder=%q device=%v name=%q need=%v have=%v haveV=%d globalV=%d", folder, protocol.DeviceIDFromBytes(device), name, need, have, haveVersion, vl.versions[0].version)
-				}
+				l.Debugf("need folder=%q device=%v name=%q need=%v have=%v haveV=%d globalV=%d", folder, protocol.DeviceIDFromBytes(device), name, need, have, haveVersion, vl.versions[0].version)
 
 				if cont := fn(gf); !cont {
 					return
@@ -908,13 +828,9 @@ func ldbListFolders(db *leveldb.DB) []string {
 	if err != nil {
 		panic(err)
 	}
-	if debugDB {
-		l.Debugf("created snapshot %p", snap)
-	}
+	l.Debugf("created snapshot %p", snap)
 	defer func() {
-		if debugDB {
-			l.Debugf("close snapshot %p", snap)
-		}
+		l.Debugf("close snapshot %p", snap)
 		snap.Release()
 	}()
 
@@ -945,13 +861,9 @@ func ldbDropFolder(db *leveldb.DB, folder []byte) {
 	if err != nil {
 		panic(err)
 	}
-	if debugDB {
-		l.Debugf("created snapshot %p", snap)
-	}
+	l.Debugf("created snapshot %p", snap)
 	defer func() {
-		if debugDB {
-			l.Debugf("close snapshot %p", snap)
-		}
+		l.Debugf("close snapshot %p", snap)
 		snap.Release()
 	}()
 
@@ -995,13 +907,9 @@ func ldbCheckGlobals(db *leveldb.DB, folder []byte) {
 	if err != nil {
 		panic(err)
 	}
-	if debugDB {
-		l.Debugf("created snapshot %p", snap)
-	}
+	l.Debugf("created snapshot %p", snap)
 	defer func() {
-		if debugDB {
-			l.Debugf("close snapshot %p", snap)
-		}
+		l.Debugf("close snapshot %p", snap)
 		snap.Release()
 	}()
 
@@ -1011,9 +919,7 @@ func ldbCheckGlobals(db *leveldb.DB, folder []byte) {
 	defer dbi.Release()
 
 	batch := new(leveldb.Batch)
-	if debugDB {
-		l.Debugf("new batch %p", batch)
-	}
+	l.Debugf("new batch %p", batch)
 
 	var fk []byte
 	for dbi.Next() {
@@ -1033,9 +939,7 @@ func ldbCheckGlobals(db *leveldb.DB, folder []byte) {
 		var newVL versionList
 		for _, version := range vl.versions {
 			fk = deviceKeyInto(fk[:cap(fk)], folder, version.device, name)
-			if debugDB {
-				l.Debugf("snap.Get %p %x", snap, fk)
-			}
+			l.Debugf("snap.Get %p %x", snap, fk)
 			_, err := snap.Get(fk, nil)
 			if err == leveldb.ErrNotFound {
 				continue
@@ -1051,8 +955,6 @@ func ldbCheckGlobals(db *leveldb.DB, folder []byte) {
 			batch.Put(dbi.Key(), newVL.MustMarshalXDR())
 		}
 	}
-	if debugDB {
-		l.Infoln("db check completed for %q", folder)
-	}
+	l.Debugf("db check completed for %q", folder)
 	db.Write(batch, nil)
 }

lib/db/set.go

@@ -62,18 +62,14 @@ func NewFileSet(folder string, db *leveldb.DB) *FileSet {
 		}
 		return true
 	})
-	if debug {
-		l.Debugf("loaded localVersion for %q: %#v", folder, s.localVersion)
-	}
+	l.Debugf("loaded localVersion for %q: %#v", folder, s.localVersion)
 	clock(s.localVersion[protocol.LocalDeviceID])
 
 	return &s
 }
 
 func (s *FileSet) Replace(device protocol.DeviceID, fs []protocol.FileInfo) {
-	if debug {
-		l.Debugf("%s Replace(%v, [%d])", s.folder, device, len(fs))
-	}
+	l.Debugf("%s Replace(%v, [%d])", s.folder, device, len(fs))
 	normalizeFilenames(fs)
 	s.mutex.Lock()
 	defer s.mutex.Unlock()
@@ -89,9 +85,7 @@ func (s *FileSet) Replace(device protocol.DeviceID, fs []protocol.FileInfo) {
 }
 
 func (s *FileSet) Update(device protocol.DeviceID, fs []protocol.FileInfo) {
-	if debug {
-		l.Debugf("%s Update(%v, [%d])", s.folder, device, len(fs))
-	}
+	l.Debugf("%s Update(%v, [%d])", s.folder, device, len(fs))
 	normalizeFilenames(fs)
 	s.mutex.Lock()
 	defer s.mutex.Unlock()
@@ -114,51 +108,37 @@ func (s *FileSet) Update(device protocol.DeviceID, fs []protocol.FileInfo) {
 }
 
 func (s *FileSet) WithNeed(device protocol.DeviceID, fn Iterator) {
-	if debug {
-		l.Debugf("%s WithNeed(%v)", s.folder, device)
-	}
+	l.Debugf("%s WithNeed(%v)", s.folder, device)
 	ldbWithNeed(s.db, []byte(s.folder), device[:], false, nativeFileIterator(fn))
 }
 
 func (s *FileSet) WithNeedTruncated(device protocol.DeviceID, fn Iterator) {
-	if debug {
-		l.Debugf("%s WithNeedTruncated(%v)", s.folder, device)
-	}
+	l.Debugf("%s WithNeedTruncated(%v)", s.folder, device)
 	ldbWithNeed(s.db, []byte(s.folder), device[:], true, nativeFileIterator(fn))
 }
 
 func (s *FileSet) WithHave(device protocol.DeviceID, fn Iterator) {
-	if debug {
-		l.Debugf("%s WithHave(%v)", s.folder, device)
-	}
+	l.Debugf("%s WithHave(%v)", s.folder, device)
 	ldbWithHave(s.db, []byte(s.folder), device[:], false, nativeFileIterator(fn))
 }
 
 func (s *FileSet) WithHaveTruncated(device protocol.DeviceID, fn Iterator) {
-	if debug {
-		l.Debugf("%s WithHaveTruncated(%v)", s.folder, device)
-	}
+	l.Debugf("%s WithHaveTruncated(%v)", s.folder, device)
 	ldbWithHave(s.db, []byte(s.folder), device[:], true, nativeFileIterator(fn))
 }
 
 func (s *FileSet) WithGlobal(fn Iterator) {
-	if debug {
-		l.Debugf("%s WithGlobal()", s.folder)
-	}
+	l.Debugf("%s WithGlobal()", s.folder)
 	ldbWithGlobal(s.db, []byte(s.folder), nil, false, nativeFileIterator(fn))
 }
 
 func (s *FileSet) WithGlobalTruncated(fn Iterator) {
-	if debug {
-		l.Debugf("%s WithGlobalTruncated()", s.folder)
-	}
+	l.Debugf("%s WithGlobalTruncated()", s.folder)
 	ldbWithGlobal(s.db, []byte(s.folder), nil, true, nativeFileIterator(fn))
 }
 
 func (s *FileSet) WithPrefixedGlobalTruncated(prefix string, fn Iterator) {
-	if debug {
-		l.Debugf("%s WithPrefixedGlobalTruncated()", s.folder, prefix)
-	}
+	l.Debugf("%s WithPrefixedGlobalTruncated()", s.folder, prefix)
 	ldbWithGlobal(s.db, []byte(s.folder), []byte(osutil.NormalizedFilename(prefix)), true, nativeFileIterator(fn))
 }
 

lib/db/virtualmtime.go

@@ -34,9 +34,7 @@ func NewVirtualMtimeRepo(ldb *leveldb.DB, folder string) *VirtualMtimeRepo {
 }
 
 func (r *VirtualMtimeRepo) UpdateMtime(path string, diskMtime, actualMtime time.Time) {
-	if debug {
-		l.Debugf("virtual mtime: storing values for path:%s disk:%v actual:%v", path, diskMtime, actualMtime)
-	}
+	l.Debugf("virtual mtime: storing values for path:%s disk:%v actual:%v", path, diskMtime, actualMtime)
 
 	diskBytes, _ := diskMtime.MarshalBinary()
 	actualBytes, _ := actualMtime.MarshalBinary()
@@ -63,15 +61,11 @@ func (r *VirtualMtimeRepo) GetMtime(path string, diskMtime time.Time) time.Time
 			panic(fmt.Sprintf("Can't unmarshal stored mtime at path %s: %v", path, err))
 		}
 
-		if debug {
-			l.Debugf("virtual mtime: return %v instead of %v for path: %s", mtime, diskMtime, path)
-		}
+		l.Debugf("virtual mtime: return %v instead of %v for path: %s", mtime, diskMtime, path)
 		return mtime
 	}
 
-	if debug {
-		l.Debugf("virtual mtime: record exists, but mismatch inDisk: %v dbDisk: %v for path: %s", diskMtime, mtime, path)
-	}
+	l.Debugf("virtual mtime: record exists, but mismatch inDisk: %v dbDisk: %v for path: %s", diskMtime, mtime, path)
 	return diskMtime
 }
 

lib/discover/cache.go

@@ -7,6 +7,7 @@
 package discover
 
 import (
+	"sort"
 	stdsync "sync"
 	"time"
 
@@ -33,6 +34,14 @@ type cachedFinder struct {
 	Finder
 	cacheTime    time.Duration
 	negCacheTime time.Duration
+	priority     int
+}
+
+// A prioritizedAddress is what we use to sort addresses returned from
+// different sources with different priorities.
+type prioritizedAddress struct {
+	priority int
+	addr     string
 }
 
 func NewCachingMux() *CachingMux {
@@ -43,9 +52,9 @@ func NewCachingMux() *CachingMux {
 }
 
 // Add registers a new Finder, with associated cache timeouts.
-func (m *CachingMux) Add(finder Finder, cacheTime, negCacheTime time.Duration) {
+func (m *CachingMux) Add(finder Finder, cacheTime, negCacheTime time.Duration, priority int) {
 	m.mut.Lock()
-	m.finders = append(m.finders, cachedFinder{finder, cacheTime, negCacheTime})
+	m.finders = append(m.finders, cachedFinder{finder, cacheTime, negCacheTime, priority})
 	m.caches = append(m.caches, newCache())
 	m.mut.Unlock()
 
@@ -57,6 +66,8 @@ func (m *CachingMux) Add(finder Finder, cacheTime, negCacheTime time.Duration) {
 // Lookup attempts to resolve the device ID using any of the added Finders,
 // while obeying the cache settings.
 func (m *CachingMux) Lookup(deviceID protocol.DeviceID) (direct []string, relays []Relay, err error) {
+	var pdirect []prioritizedAddress
+
 	m.mut.Lock()
 	for i, finder := range m.finders {
 		if cacheEntry, ok := m.caches[i].Get(deviceID); ok {
@@ -64,11 +75,11 @@ func (m *CachingMux) Lookup(deviceID protocol.DeviceID) (direct []string, relays
 
 			if cacheEntry.found && time.Since(cacheEntry.when) < finder.cacheTime {
 				// It's a positive, valid entry. Use it.
-				if debug {
-					l.Debugln("cached discovery entry for", deviceID, "at", finder.String())
-					l.Debugln("   ", cacheEntry)
+				l.Debugln("cached discovery entry for", deviceID, "at", finder)
+				l.Debugln("  cache:", cacheEntry)
+				for _, addr := range cacheEntry.Direct {
+					pdirect = append(pdirect, prioritizedAddress{finder.priority, addr})
 				}
-				direct = append(direct, cacheEntry.Direct...)
 				relays = append(relays, cacheEntry.Relays...)
 				continue
 			}
@@ -76,9 +87,7 @@ func (m *CachingMux) Lookup(deviceID protocol.DeviceID) (direct []string, relays
 			if !cacheEntry.found && time.Since(cacheEntry.when) < finder.negCacheTime {
 				// It's a negative, valid entry. We should not make another
 				// attempt right now.
-				if debug {
-					l.Debugln("negative cache entry for", deviceID, "at", finder.String())
-				}
+				l.Debugln("negative cache entry for", deviceID, "at", finder)
 				continue
 			}
 
@@ -87,12 +96,12 @@ func (m *CachingMux) Lookup(deviceID protocol.DeviceID) (direct []string, relays
 
 		// Perform the actual lookup and cache the result.
 		if td, tr, err := finder.Lookup(deviceID); err == nil {
-			if debug {
-				l.Debugln("lookup for", deviceID, "at", finder.String())
-				l.Debugln("   ", td)
-				l.Debugln("   ", tr)
+			l.Debugln("lookup for", deviceID, "at", finder)
+			l.Debugln("  direct:", td)
+			l.Debugln("  relays:", tr)
+			for _, addr := range td {
+				pdirect = append(pdirect, prioritizedAddress{finder.priority, addr})
 			}
-			direct = append(direct, td...)
 			relays = append(relays, tr...)
 			m.caches[i].Set(deviceID, CacheEntry{
 				Direct: td,
@@ -104,11 +113,11 @@ func (m *CachingMux) Lookup(deviceID protocol.DeviceID) (direct []string, relays
 	}
 	m.mut.Unlock()
 
-	if debug {
-		l.Debugln("lookup results for", deviceID)
-		l.Debugln("   ", direct)
-		l.Debugln("   ", relays)
-	}
+	direct = uniqueSortedAddrs(pdirect)
+	relays = uniqueSortedRelays(relays)
+	l.Debugln("lookup results for", deviceID)
+	l.Debugln("  direct: ", direct)
+	l.Debugln("  relays: ", relays)
 
 	return direct, relays, nil
 }
@@ -196,3 +205,65 @@ func (c *cache) Cache() map[protocol.DeviceID]CacheEntry {
 	c.mut.Unlock()
 	return m
 }
+
+func uniqueSortedAddrs(ss []prioritizedAddress) []string {
+	// We sort the addresses by priority, then filter them based on seen
+	// (first time seen is the on kept, so we retain priority).
+	sort.Sort(prioritizedAddressList(ss))
+	filtered := make([]string, 0, len(ss))
+	seen := make(map[string]struct{}, len(ss))
+	for _, s := range ss {
+		if _, ok := seen[s.addr]; !ok {
+			filtered = append(filtered, s.addr)
+			seen[s.addr] = struct{}{}
+		}
+	}
+	return filtered
+}
+
+func uniqueSortedRelays(rs []Relay) []Relay {
+	m := make(map[string]Relay, len(rs))
+	for _, r := range rs {
+		m[r.URL] = r
+	}
+
+	var ur = make([]Relay, 0, len(m))
+	for _, r := range m {
+		ur = append(ur, r)
+	}
+
+	sort.Sort(relayList(ur))
+
+	return ur
+}
+
+type relayList []Relay
+
+func (l relayList) Len() int {
+	return len(l)
+}
+
+func (l relayList) Swap(a, b int) {
+	l[a], l[b] = l[b], l[a]
+}
+
+func (l relayList) Less(a, b int) bool {
+	return l[a].URL < l[b].URL
+}
+
+type prioritizedAddressList []prioritizedAddress
+
+func (l prioritizedAddressList) Len() int {
+	return len(l)
+}
+
+func (l prioritizedAddressList) Swap(a, b int) {
+	l[a], l[b] = l[b], l[a]
+}
+
+func (l prioritizedAddressList) Less(a, b int) bool {
+	if l[a].priority != l[b].priority {
+		return l[a].priority < l[b].priority
+	}
+	return l[a].addr < l[b].addr
+}

lib/discover/cache_test.go

@@ -0,0 +1,93 @@
+// Copyright (C) 2015 The Syncthing Authors.
+//
+// This Source Code Form is subject to the terms of the Mozilla Public
+// License, v. 2.0. If a copy of the MPL was not distributed with this file,
+// You can obtain one at http://mozilla.org/MPL/2.0/.
+
+package discover
+
+import (
+	"reflect"
+	"testing"
+	"time"
+
+	"github.com/syncthing/syncthing/lib/protocol"
+)
+
+func TestCacheUnique(t *testing.T) {
+	direct0 := []string{"tcp://192.0.2.44:22000", "tcp://192.0.2.42:22000"} // prio 0
+	direct1 := []string{"tcp://192.0.2.43:22000", "tcp://192.0.2.42:22000"} // prio 1
+
+	// what we expect from just direct0
+	direct0Sorted := []string{"tcp://192.0.2.42:22000", "tcp://192.0.2.44:22000"}
+
+	// what we expect from direct0+direct1
+	totalSorted := []string{
+		// first prio 0, sorted
+		"tcp://192.0.2.42:22000", "tcp://192.0.2.44:22000",
+		// then prio 1
+		"tcp://192.0.2.43:22000",
+		// no duplicate .42
+	}
+
+	relays := []Relay{{URL: "relay://192.0.2.44:443"}, {URL: "tcp://192.0.2.45:443"}}
+
+	c := NewCachingMux()
+	c.ServeBackground()
+	defer c.Stop()
+
+	// Add a fake discovery service and verify we get it's answers through the
+	// cache.
+
+	f1 := &fakeDiscovery{direct0, relays}
+	c.Add(f1, time.Minute, 0, 0)
+
+	dir, rel, err := c.Lookup(protocol.LocalDeviceID)
+	if err != nil {
+		t.Fatal(err)
+	}
+	if !reflect.DeepEqual(dir, direct0Sorted) {
+		t.Errorf("Incorrect direct; %+v != %+v", dir, direct0Sorted)
+	}
+	if !reflect.DeepEqual(rel, relays) {
+		t.Errorf("Incorrect relays; %+v != %+v", rel, relays)
+	}
+
+	// Add one more that answers in the same way and check that we don't
+	// duplicate or otherwise mess up the responses now.
+
+	f2 := &fakeDiscovery{direct1, relays}
+	c.Add(f2, time.Minute, 0, 1)
+
+	dir, rel, err = c.Lookup(protocol.LocalDeviceID)
+	if err != nil {
+		t.Fatal(err)
+	}
+	if !reflect.DeepEqual(dir, totalSorted) {
+		t.Errorf("Incorrect direct; %+v != %+v", dir, totalSorted)
+	}
+	if !reflect.DeepEqual(rel, relays) {
+		t.Errorf("Incorrect relays; %+v != %+v", rel, relays)
+	}
+}
+
+type fakeDiscovery struct {
+	direct []string
+	relays []Relay
+}
+
+func (f *fakeDiscovery) Lookup(deviceID protocol.DeviceID) (direct []string, relays []Relay, err error) {
+	return f.direct, f.relays, nil
+}
+
+func (f *fakeDiscovery) Error() error {
+	return nil
+}
+
+func (f *fakeDiscovery) String() string {
+	return "fake"
+}
+
+func (f *fakeDiscovery) Cache() map[protocol.DeviceID]CacheEntry {
+	return nil
+}

lib/discover/debug.go

@@ -10,10 +10,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "discover") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("discover", "Remote device discovery")
 )
+
+func init() {
+	l.SetDebug("discover", strings.Contains(os.Getenv("STTRACE"), "discover") || os.Getenv("STTRACE") == "all")
+}

lib/discover/global.go

@@ -124,16 +124,12 @@ func (c *globalClient) Lookup(device protocol.DeviceID) (direct []string, relays
 
 	resp, err := c.queryClient.Get(qURL.String())
 	if err != nil {
-		if debug {
-			l.Debugln("globalClient.Lookup", qURL.String(), err)
-		}
+		l.Debugln("globalClient.Lookup", qURL, err)
 		return nil, nil, err
 	}
 	if resp.StatusCode != 200 {
 		resp.Body.Close()
-		if debug {
-			l.Debugln("globalClient.Lookup", qURL.String(), resp.Status)
-		}
+		l.Debugln("globalClient.Lookup", qURL, resp.Status)
 		return nil, nil, errors.New(resp.Status)
 	}
 
@@ -198,9 +194,7 @@ func (c *globalClient) sendAnnouncement(timer *time.Timer) {
 
 	if len(ann.Direct)+len(ann.Relays) == 0 {
 		c.setError(errors.New("nothing to announce"))
-		if debug {
-			l.Debugln("Nothing to announce")
-		}
+		l.Debugln("Nothing to announce")
 		timer.Reset(announceErrorRetryInterval)
 		return
 	}
@@ -208,37 +202,27 @@ func (c *globalClient) sendAnnouncement(timer *time.Timer) {
 	// The marshal doesn't fail, I promise.
 	postData, _ := json.Marshal(ann)
 
-	if debug {
-		l.Debugf("Announcement: %s", postData)
-	}
+	l.Debugf("Announcement: %s", postData)
 
 	resp, err := c.announceClient.Post(c.server, "application/json", bytes.NewReader(postData))
 	if err != nil {
-		if debug {
-			l.Debugln("announce POST:", err)
-		}
+		l.Debugln("announce POST:", err)
 		c.setError(err)
 		timer.Reset(announceErrorRetryInterval)
 		return
 	}
-	if debug {
-		l.Debugln("announce POST:", resp.Status)
-	}
+	l.Debugln("announce POST:", resp.Status)
 	resp.Body.Close()
 
 	if resp.StatusCode < 200 || resp.StatusCode > 299 {
-		if debug {
-			l.Debugln("announce POST:", resp.Status)
-		}
+		l.Debugln("announce POST:", resp.Status)
 		c.setError(errors.New(resp.Status))
 
 		if h := resp.Header.Get("Retry-After"); h != "" {
 			// The server has a recommendation on when we should
 			// retry. Follow it.
 			if secs, err := strconv.Atoi(h); err == nil && secs > 0 {
-				if debug {
-					l.Debugln("announce Retry-After:", secs, err)
-				}
+				l.Debugln("announce Retry-After:", secs, err)
 				timer.Reset(time.Duration(secs) * time.Second)
 				return
 			}
@@ -254,9 +238,7 @@ func (c *globalClient) sendAnnouncement(timer *time.Timer) {
 		// The server has a recommendation on when we should
 		// reannounce. Follow it.
 		if secs, err := strconv.Atoi(h); err == nil && secs > 0 {
-			if debug {
-				l.Debugln("announce Reannounce-After:", secs, err)
-			}
+			l.Debugln("announce Reannounce-After:", secs, err)
 			timer.Reset(time.Duration(secs) * time.Second)
 			return
 		}

lib/discover/local.go

@@ -166,15 +166,11 @@ func (c *localClient) recvAnnouncements(b beacon.Interface) {
 		var pkt Announce
 		err := pkt.UnmarshalXDR(buf)
 		if err != nil && err != io.EOF {
-			if debug {
-				l.Debugf("discover: Failed to unmarshal local announcement from %s:\n%s", addr, hex.Dump(buf))
-			}
+			l.Debugf("discover: Failed to unmarshal local announcement from %s:\n%s", addr, hex.Dump(buf))
 			continue
 		}
 
-		if debug {
-			l.Debugf("discover: Received local announcement from %s for %s", addr, protocol.DeviceIDFromBytes(pkt.This.ID))
-		}
+		l.Debugf("discover: Received local announcement from %s for %s", addr, protocol.DeviceIDFromBytes(pkt.This.ID))
 
 		var newDevice bool
 		if bytes.Compare(pkt.This.ID, c.myID[:]) != 0 {

lib/events/debug.go

@@ -10,10 +10,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "events") || os.Getenv("STTRACE") == "all"
-	dl    = logger.DefaultLogger
+	dl = logger.DefaultLogger.NewFacility("events", "Event generation and logging")
 )
+
+func init() {
+	dl.SetDebug("events", strings.Contains(os.Getenv("STTRACE"), "events") || os.Getenv("STTRACE") == "all")
+}

lib/events/events.go

@@ -105,7 +105,7 @@ func (t EventType) MarshalText() ([]byte, error) {
 const BufferSize = 64
 
 type Logger struct {
-	subs   map[int]*Subscription
+	subs   []*Subscription
 	nextID int
 	mutex  sync.Mutex
 }
@@ -119,7 +119,6 @@ type Event struct {
 
 type Subscription struct {
 	mask    EventType
-	id      int
 	events  chan Event
 	timeout *time.Timer
 }
@@ -133,23 +132,20 @@ var (
 
 func NewLogger() *Logger {
 	return &Logger{
-		subs:  make(map[int]*Subscription),
 		mutex: sync.NewMutex(),
 	}
 }
 
 func (l *Logger) Log(t EventType, data interface{}) {
 	l.mutex.Lock()
-	if debug {
-		dl.Debugln("log", l.nextID, t.String(), data)
-	}
+	dl.Debugln("log", l.nextID, t, data)
+	l.nextID++
 	e := Event{
 		ID:   l.nextID,
 		Time: time.Now(),
 		Type: t,
 		Data: data,
 	}
-	l.nextID++
 	for _, s := range l.subs {
 		if s.mask&t != 0 {
 			select {
@@ -164,27 +160,29 @@ func (l *Logger) Log(t EventType, data interface{}) {
 
 func (l *Logger) Subscribe(mask EventType) *Subscription {
 	l.mutex.Lock()
-	if debug {
-		dl.Debugln("subscribe", mask)
-	}
+	dl.Debugln("subscribe", mask)
 	s := &Subscription{
 		mask:    mask,
-		id:      l.nextID,
 		events:  make(chan Event, BufferSize),
 		timeout: time.NewTimer(0),
 	}
-	l.nextID++
-	l.subs[s.id] = s
+	l.subs = append(l.subs, s)
 	l.mutex.Unlock()
 	return s
 }
 
 func (l *Logger) Unsubscribe(s *Subscription) {
 	l.mutex.Lock()
-	if debug {
-		dl.Debugln("unsubscribe")
+	dl.Debugln("unsubscribe")
+	for i, ss := range l.subs {
+		if s == ss {
+			last := len(l.subs) - 1
+			l.subs[i] = l.subs[last]
+			l.subs[last] = nil
+			l.subs = l.subs[:last]
+			break
+		}
 	}
-	delete(l.subs, s.id)
 	close(s.events)
 	l.mutex.Unlock()
 }
@@ -193,9 +191,7 @@ func (l *Logger) Unsubscribe(s *Subscription) {
 // out of the event channel is closed. Poll should not be called concurrently
 // from multiple goroutines for a single subscription.
 func (s *Subscription) Poll(timeout time.Duration) (Event, error) {
-	if debug {
-		dl.Debugln("poll", timeout)
-	}
+	dl.Debugln("poll", timeout)
 
 	if !s.timeout.Reset(timeout) {
 		select {

lib/events/events_test.go

@@ -134,6 +134,7 @@ func TestIDs(t *testing.T) {
 	s := l.Subscribe(events.AllEvents)
 	defer l.Unsubscribe(s)
 	l.Log(events.DeviceConnected, "foo")
+	_ = l.Subscribe(events.AllEvents)
 	l.Log(events.DeviceConnected, "bar")
 
 	ev, err := s.Poll(timeout)
@@ -152,8 +153,8 @@ func TestIDs(t *testing.T) {
 	if ev.Data.(string) != "bar" {
 		t.Fatal("Incorrect event:", ev)
 	}
-	if !(ev.ID > id) {
-		t.Fatalf("ID not incremented (%d !> %d)", ev.ID, id)
+	if ev.ID != id+1 {
+		t.Fatalf("ID not incremented (%d != %d)", ev.ID, id+1)
 	}
 }
 

lib/ignore/ignore.go

@@ -12,7 +12,6 @@ import (
 	"crypto/md5"
 	"fmt"
 	"io"
-	"log"
 	"os"
 	"path/filepath"
 	"regexp"
@@ -217,28 +216,28 @@ func parseIgnoreFile(fd io.Reader, currentFile string, seen map[string]bool) ([]
 			// Pattern is rooted in the current dir only
 			exp, err := fnmatch.Convert(line[1:], flags)
 			if err != nil {
-				return fmt.Errorf("Invalid pattern %q in ignore file", line)
+				return fmt.Errorf("invalid pattern %q in ignore file", line)
 			}
 			patterns = append(patterns, Pattern{exp, include})
 		} else if strings.HasPrefix(line, "**/") {
 			// Add the pattern as is, and without **/ so it matches in current dir
 			exp, err := fnmatch.Convert(line, flags)
 			if err != nil {
-				return fmt.Errorf("Invalid pattern %q in ignore file", line)
+				return fmt.Errorf("invalid pattern %q in ignore file", line)
 			}
 			patterns = append(patterns, Pattern{exp, include})
 
 			exp, err = fnmatch.Convert(line[3:], flags)
 			if err != nil {
-				return fmt.Errorf("Invalid pattern %q in ignore file", line)
+				return fmt.Errorf("invalid pattern %q in ignore file", line)
 			}
 			patterns = append(patterns, Pattern{exp, include})
 		} else if strings.HasPrefix(line, "#include ") {
-			includeFile := filepath.Join(filepath.Dir(currentFile), line[len("#include "):])
+			includeRel := line[len("#include "):]
+			includeFile := filepath.Join(filepath.Dir(currentFile), includeRel)
 			includes, err := loadIgnoreFile(includeFile, seen)
 			if err != nil {
-				log.Println(err)
-				return err
+				return fmt.Errorf("include of %q: %v", includeRel, err)
 			}
 			patterns = append(patterns, includes...)
 		} else {
@@ -246,13 +245,13 @@ func parseIgnoreFile(fd io.Reader, currentFile string, seen map[string]bool) ([]
 			// current directory and subdirs.
 			exp, err := fnmatch.Convert(line, flags)
 			if err != nil {
-				return fmt.Errorf("Invalid pattern %q in ignore file", line)
+				return fmt.Errorf("invalid pattern %q in ignore file", line)
 			}
 			patterns = append(patterns, Pattern{exp, include})
 
 			exp, err = fnmatch.Convert("**/"+line, flags)
 			if err != nil {
-				return fmt.Errorf("Invalid pattern %q in ignore file", line)
+				return fmt.Errorf("invalid pattern %q in ignore file", line)
 			}
 			patterns = append(patterns, Pattern{exp, include})
 		}

lib/logger/logger.go

@@ -0,0 +1,379 @@
+// Copyright (C) 2014 Jakob Borg. All rights reserved. Use of this source code
+// is governed by an MIT-style license that can be found in the LICENSE file.
+
+// Package logger implements a standardized logger with callback functionality
+package logger
+
+import (
+	"fmt"
+	"io/ioutil"
+	"log"
+	"os"
+	"strings"
+	"sync"
+	"time"
+)
+
+// This package uses stdlib sync as it may be used to debug syncthing/lib/sync
+// and that would cause an implosion of the universe.
+
+type LogLevel int
+
+const (
+	LevelDebug LogLevel = iota
+	LevelVerbose
+	LevelInfo
+	LevelOK
+	LevelWarn
+	LevelFatal
+	NumLevels
+)
+
+// A MessageHandler is called with the log level and message text.
+type MessageHandler func(l LogLevel, msg string)
+
+type Logger interface {
+	AddHandler(level LogLevel, h MessageHandler)
+	SetFlags(flag int)
+	SetPrefix(prefix string)
+	Debugln(vals ...interface{})
+	Debugf(format string, vals ...interface{})
+	Verboseln(vals ...interface{})
+	Verbosef(format string, vals ...interface{})
+	Infoln(vals ...interface{})
+	Infof(format string, vals ...interface{})
+	Okln(vals ...interface{})
+	Okf(format string, vals ...interface{})
+	Warnln(vals ...interface{})
+	Warnf(format string, vals ...interface{})
+	Fatalln(vals ...interface{})
+	Fatalf(format string, vals ...interface{})
+	ShouldDebug(facility string) bool
+	SetDebug(facility string, enabled bool)
+	Facilities() map[string]string
+	FacilityDebugging() []string
+	NewFacility(facility, description string) Logger
+}
+
+type logger struct {
+	logger     *log.Logger
+	handlers   [NumLevels][]MessageHandler
+	facilities map[string]string // facility name => description
+	debug      map[string]bool   // facility name => debugging enabled
+	mut        sync.Mutex
+}
+
+// The default logger logs to standard output with a time prefix.
+var DefaultLogger = New()
+
+func New() Logger {
+	if os.Getenv("LOGGER_DISCARD") != "" {
+		// Hack to completely disable logging, for example when running benchmarks.
+		return &logger{
+			logger: log.New(ioutil.Discard, "", 0),
+		}
+	}
+
+	return &logger{
+		logger: log.New(os.Stdout, "", log.Ltime),
+	}
+}
+
+// AddHandler registers a new MessageHandler to receive messages with the
+// specified log level or above.
+func (l *logger) AddHandler(level LogLevel, h MessageHandler) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	l.handlers[level] = append(l.handlers[level], h)
+}
+
+// See log.SetFlags
+func (l *logger) SetFlags(flag int) {
+	l.logger.SetFlags(flag)
+}
+
+// See log.SetPrefix
+func (l *logger) SetPrefix(prefix string) {
+	l.logger.SetPrefix(prefix)
+}
+
+func (l *logger) callHandlers(level LogLevel, s string) {
+	for ll := LevelDebug; ll <= level; ll++ {
+		for _, h := range l.handlers[ll] {
+			h(level, strings.TrimSpace(s))
+		}
+	}
+}
+
+// Debugln logs a line with a DEBUG prefix.
+func (l *logger) Debugln(vals ...interface{}) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	s := fmt.Sprintln(vals...)
+	l.logger.Output(2, "DEBUG: "+s)
+	l.callHandlers(LevelDebug, s)
+}
+
+// Debugf logs a formatted line with a DEBUG prefix.
+func (l *logger) Debugf(format string, vals ...interface{}) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	s := fmt.Sprintf(format, vals...)
+	l.logger.Output(2, "DEBUG: "+s)
+	l.callHandlers(LevelDebug, s)
+}
+
+// Infoln logs a line with a VERBOSE prefix.
+func (l *logger) Verboseln(vals ...interface{}) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	s := fmt.Sprintln(vals...)
+	l.logger.Output(2, "VERBOSE: "+s)
+	l.callHandlers(LevelVerbose, s)
+}
+
+// Infof logs a formatted line with a VERBOSE prefix.
+func (l *logger) Verbosef(format string, vals ...interface{}) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	s := fmt.Sprintf(format, vals...)
+	l.logger.Output(2, "VERBOSE: "+s)
+	l.callHandlers(LevelVerbose, s)
+}
+
+// Infoln logs a line with an INFO prefix.
+func (l *logger) Infoln(vals ...interface{}) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	s := fmt.Sprintln(vals...)
+	l.logger.Output(2, "INFO: "+s)
+	l.callHandlers(LevelInfo, s)
+}
+
+// Infof logs a formatted line with an INFO prefix.
+func (l *logger) Infof(format string, vals ...interface{}) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	s := fmt.Sprintf(format, vals...)
+	l.logger.Output(2, "INFO: "+s)
+	l.callHandlers(LevelInfo, s)
+}
+
+// Okln logs a line with an OK prefix.
+func (l *logger) Okln(vals ...interface{}) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	s := fmt.Sprintln(vals...)
+	l.logger.Output(2, "OK: "+s)
+	l.callHandlers(LevelOK, s)
+}
+
+// Okf logs a formatted line with an OK prefix.
+func (l *logger) Okf(format string, vals ...interface{}) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	s := fmt.Sprintf(format, vals...)
+	l.logger.Output(2, "OK: "+s)
+	l.callHandlers(LevelOK, s)
+}
+
+// Warnln logs a formatted line with a WARNING prefix.
+func (l *logger) Warnln(vals ...interface{}) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	s := fmt.Sprintln(vals...)
+	l.logger.Output(2, "WARNING: "+s)
+	l.callHandlers(LevelWarn, s)
+}
+
+// Warnf logs a formatted line with a WARNING prefix.
+func (l *logger) Warnf(format string, vals ...interface{}) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	s := fmt.Sprintf(format, vals...)
+	l.logger.Output(2, "WARNING: "+s)
+	l.callHandlers(LevelWarn, s)
+}
+
+// Fatalln logs a line with a FATAL prefix and exits the process with exit
+// code 1.
+func (l *logger) Fatalln(vals ...interface{}) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	s := fmt.Sprintln(vals...)
+	l.logger.Output(2, "FATAL: "+s)
+	l.callHandlers(LevelFatal, s)
+	os.Exit(1)
+}
+
+// Fatalf logs a formatted line with a FATAL prefix and exits the process with
+// exit code 1.
+func (l *logger) Fatalf(format string, vals ...interface{}) {
+	l.mut.Lock()
+	defer l.mut.Unlock()
+	s := fmt.Sprintf(format, vals...)
+	l.logger.Output(2, "FATAL: "+s)
+	l.callHandlers(LevelFatal, s)
+	os.Exit(1)
+}
+
+// ShouldDebug returns true if the given facility has debugging enabled.
+func (l *logger) ShouldDebug(facility string) bool {
+	l.mut.Lock()
+	res := l.debug[facility]
+	l.mut.Unlock()
+	return res
+}
+
+// SetDebug enabled or disables debugging for the given facility name.
+func (l *logger) SetDebug(facility string, enabled bool) {
+	l.mut.Lock()
+	l.debug[facility] = enabled
+	l.mut.Unlock()
+}
+
+// FacilityDebugging returns the set of facilities that have debugging
+// enabled.
+func (l *logger) FacilityDebugging() []string {
+	var enabled []string
+	l.mut.Lock()
+	for facility, isEnabled := range l.debug {
+		if isEnabled {
+			enabled = append(enabled, facility)
+		}
+	}
+	l.mut.Unlock()
+	return enabled
+}
+
+// Facilities returns the currently known set of facilities and their
+// descriptions.
+func (l *logger) Facilities() map[string]string {
+	l.mut.Lock()
+	res := make(map[string]string, len(l.facilities))
+	for facility, descr := range l.facilities {
+		res[facility] = descr
+	}
+	l.mut.Unlock()
+	return res
+}
+
+// NewFacility returns a new logger bound to the named facility.
+func (l *logger) NewFacility(facility, description string) Logger {
+	l.mut.Lock()
+	if l.facilities == nil {
+		l.facilities = make(map[string]string)
+	}
+	if description != "" {
+		l.facilities[facility] = description
+	}
+
+	if l.debug == nil {
+		l.debug = make(map[string]bool)
+	}
+	l.debug[facility] = false
+	l.mut.Unlock()
+
+	return &facilityLogger{
+		logger:   l,
+		facility: facility,
+	}
+}
+
+// A facilityLogger is a regular logger but bound to a facility name. The
+// Debugln and Debugf methods are no-ops unless debugging has been enabled for
+// this facility on the parent logger.
+type facilityLogger struct {
+	*logger
+	facility string
+}
+
+// Debugln logs a line with a DEBUG prefix.
+func (l *facilityLogger) Debugln(vals ...interface{}) {
+	if !l.ShouldDebug(l.facility) {
+		return
+	}
+	l.logger.Debugln(vals...)
+}
+
+// Debugf logs a formatted line with a DEBUG prefix.
+func (l *facilityLogger) Debugf(format string, vals ...interface{}) {
+	if !l.ShouldDebug(l.facility) {
+		return
+	}
+	l.logger.Debugf(format, vals...)
+}
+
+// A Recorder keeps a size limited record of log events.
+type Recorder struct {
+	lines   []Line
+	initial int
+	mut     sync.Mutex
+}
+
+// A Line represents a single log entry.
+type Line struct {
+	When    time.Time
+	Message string
+}
+
+func NewRecorder(l Logger, level LogLevel, size, initial int) *Recorder {
+	r := &Recorder{
+		lines:   make([]Line, 0, size),
+		initial: initial,
+	}
+	l.AddHandler(level, r.append)
+	return r
+}
+
+func (r *Recorder) Since(t time.Time) []Line {
+	r.mut.Lock()
+	defer r.mut.Unlock()
+
+	res := r.lines
+	for i := 0; i < len(res) && res[i].When.Before(t); i++ {
+		// nothing, just incrementing i
+	}
+	if len(res) == 0 {
+		return nil
+	}
+
+	// We must copy the result as r.lines can be mutated as soon as the lock
+	// is released.
+	cp := make([]Line, len(res))
+	copy(cp, res)
+	return cp
+}
+
+func (r *Recorder) Clear() {
+	r.mut.Lock()
+	r.lines = r.lines[:0]
+	r.mut.Unlock()
+}
+
+func (r *Recorder) append(l LogLevel, msg string) {
+	line := Line{
+		When:    time.Now(),
+		Message: msg,
+	}
+
+	r.mut.Lock()
+	defer r.mut.Unlock()
+
+	if len(r.lines) == cap(r.lines) {
+		if r.initial > 0 {
+			// Shift all lines one step to the left, keeping the "initial" first intact.
+			copy(r.lines[r.initial+1:], r.lines[r.initial+2:])
+		} else {
+			copy(r.lines, r.lines[1:])
+		}
+		// Add the new one at the end
+		r.lines[len(r.lines)-1] = line
+		return
+	}
+
+	r.lines = append(r.lines, line)
+	if len(r.lines) == r.initial {
+		r.lines = append(r.lines, Line{time.Now(), "..."})
+	}
+}

lib/logger/logger_test.go

@@ -0,0 +1,140 @@
+// Copyright (C) 2014 Jakob Borg. All rights reserved. Use of this source code
+// is governed by an MIT-style license that can be found in the LICENSE file.
+
+package logger
+
+import (
+	"fmt"
+	"strings"
+	"testing"
+	"time"
+)
+
+func TestAPI(t *testing.T) {
+	l := New()
+	l.SetFlags(0)
+	l.SetPrefix("testing")
+
+	debug := 0
+	l.AddHandler(LevelDebug, checkFunc(t, LevelDebug, &debug))
+	info := 0
+	l.AddHandler(LevelInfo, checkFunc(t, LevelInfo, &info))
+	ok := 0
+	l.AddHandler(LevelOK, checkFunc(t, LevelOK, &ok))
+	warn := 0
+	l.AddHandler(LevelWarn, checkFunc(t, LevelWarn, &warn))
+
+	l.Debugf("test %d", 0)
+	l.Debugln("test", 0)
+	l.Infof("test %d", 1)
+	l.Infoln("test", 1)
+	l.Okf("test %d", 2)
+	l.Okln("test", 2)
+	l.Warnf("test %d", 3)
+	l.Warnln("test", 3)
+
+	if debug != 8 {
+		t.Errorf("Debug handler called %d != 8 times", debug)
+	}
+	if info != 6 {
+		t.Errorf("Info handler called %d != 6 times", info)
+	}
+	if ok != 4 {
+		t.Errorf("Ok handler called %d != 4 times", ok)
+	}
+	if warn != 2 {
+		t.Errorf("Warn handler called %d != 2 times", warn)
+	}
+}
+
+func checkFunc(t *testing.T, expectl LogLevel, counter *int) func(LogLevel, string) {
+	return func(l LogLevel, msg string) {
+		*counter++
+		if l < expectl {
+			t.Errorf("Incorrect message level %d < %d", l, expectl)
+		}
+	}
+}
+
+func TestFacilityDebugging(t *testing.T) {
+	l := New()
+	l.SetFlags(0)
+
+	msgs := 0
+	l.AddHandler(LevelDebug, func(l LogLevel, msg string) {
+		msgs++
+		if strings.Contains(msg, "f1") {
+			t.Fatal("Should not get message for facility f1")
+		}
+	})
+
+	f0 := l.NewFacility("f0", "foo#0")
+	f1 := l.NewFacility("f1", "foo#1")
+
+	l.SetDebug("f0", true)
+	l.SetDebug("f1", false)
+
+	f0.Debugln("Debug line from f0")
+	f1.Debugln("Debug line from f1")
+
+	if msgs != 1 {
+		t.Fatalf("Incorrent number of messages, %d != 1", msgs)
+	}
+}
+
+func TestRecorder(t *testing.T) {
+	l := New()
+	l.SetFlags(0)
+
+	// Keep the last five warnings or higher, no special initial handling.
+	r0 := NewRecorder(l, LevelWarn, 5, 0)
+	// Keep the last ten infos or higher, with the first three being permanent.
+	r1 := NewRecorder(l, LevelInfo, 10, 3)
+
+	// Log a bunch of messages.
+	for i := 0; i < 15; i++ {
+		l.Debugf("Debug#%d", i)
+		l.Infof("Info#%d", i)
+		l.Warnf("Warn#%d", i)
+	}
+
+	// r0 should contain the last five warnings
+	lines := r0.Since(time.Time{})
+	if len(lines) != 5 {
+		t.Fatalf("Incorrect length %d != 5", len(lines))
+	}
+	for i := 0; i < 5; i++ {
+		expected := fmt.Sprintf("Warn#%d", i+10)
+		if lines[i].Message != expected {
+			t.Error("Incorrect warning in r0:", lines[i].Message, "!=", expected)
+		}
+	}
+
+	// r0 should contain:
+	// - The first three messages
+	// - A "..." marker
+	// - The last six messages
+	// (totalling ten)
+	lines = r1.Since(time.Time{})
+	if len(lines) != 10 {
+		t.Fatalf("Incorrect length %d != 10", len(lines))
+	}
+	expected := []string{
+		"Info#0",
+		"Warn#0",
+		"Info#1",
+		"...",
+		"Info#12",
+		"Warn#12",
+		"Info#13",
+		"Warn#13",
+		"Info#14",
+		"Warn#14",
+	}
+	for i := 0; i < 10; i++ {
+		if lines[i].Message != expected[i] {
+			t.Error("Incorrect warning in r0:", lines[i].Message, "!=", expected[i])
+		}
+	}
+
+}

lib/model/debug.go

@@ -10,10 +10,17 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "model") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("model", "The root hub")
 )
+
+func init() {
+	l.SetDebug("model", strings.Contains(os.Getenv("STTRACE"), "model") || os.Getenv("STTRACE") == "all")
+}
+
+func shouldDebug() bool {
+	return l.ShouldDebug("model")
+}

lib/model/model.go

@@ -107,9 +107,7 @@ func NewModel(cfg *config.Wrapper, id protocol.DeviceID, deviceName, clientName,
 	m := &Model{
 		Supervisor: suture.New("model", suture.Spec{
 			Log: func(line string) {
-				if debug {
-					l.Debugln(line)
-				}
+				l.Debugln(line)
 			},
 		}),
 		cfg:                cfg,
@@ -335,9 +333,7 @@ func (m *Model) Completion(device protocol.DeviceID, folder string) float64 {
 	})
 
 	res := 100 * (1 - float64(need)/float64(tot))
-	if debug {
-		l.Debugf("%v Completion(%s, %q): %f (%d / %d)", m, device, folder, res, need, tot)
-	}
+	l.Debugf("%v Completion(%s, %q): %f (%d / %d)", m, device, folder, res, need, tot)
 
 	return res
 }
@@ -412,9 +408,7 @@ func (m *Model) NeedSize(folder string) (nfiles int, bytes int64) {
 		})
 	}
 	bytes -= m.progressEmitter.BytesCompleted(folder)
-	if debug {
-		l.Debugf("%v NeedSize(%q): %d %d", m, folder, nfiles, bytes)
-	}
+	l.Debugf("%v NeedSize(%q): %d %d", m, folder, nfiles, bytes)
 	return
 }
 
@@ -493,9 +487,7 @@ func (m *Model) Index(deviceID protocol.DeviceID, folder string, fs []protocol.F
 		return
 	}
 
-	if debug {
-		l.Debugf("IDX(in): %s %q: %d files", deviceID, folder, len(fs))
-	}
+	l.Debugf("IDX(in): %s %q: %d files", deviceID, folder, len(fs))
 
 	if !m.folderSharedWith(folder, deviceID) {
 		events.Default.Log(events.FolderRejected, map[string]string{
@@ -541,9 +533,7 @@ func (m *Model) IndexUpdate(deviceID protocol.DeviceID, folder string, fs []prot
 		return
 	}
 
-	if debug {
-		l.Debugf("%v IDXUP(in): %s / %q: %d files", m, deviceID, folder, len(fs))
-	}
+	l.Debugf("%v IDXUP(in): %s / %q: %d files", m, deviceID, folder, len(fs))
 
 	if !m.folderSharedWith(folder, deviceID) {
 		l.Infof("Update for unexpected folder ID %q sent from device %q; ensure that the folder exists and that this device is selected under \"Share With\" in the folder configuration.", folder, deviceID)
@@ -766,16 +756,12 @@ func (m *Model) Request(deviceID protocol.DeviceID, folder, name string, offset
 		}
 
 		if lf.IsInvalid() || lf.IsDeleted() {
-			if debug {
-				l.Debugf("%v REQ(in): %s: %q / %q o=%d s=%d; invalid: %v", m, deviceID, folder, name, offset, len(buf), lf)
-			}
+			l.Debugf("%v REQ(in): %s: %q / %q o=%d s=%d; invalid: %v", m, deviceID, folder, name, offset, len(buf), lf)
 			return protocol.ErrInvalid
 		}
 
 		if offset > lf.Size() {
-			if debug {
-				l.Debugf("%v REQ(in; nonexistent): %s: %q o=%d s=%d", m, deviceID, name, offset, len(buf))
-			}
+			l.Debugf("%v REQ(in; nonexistent): %s: %q o=%d s=%d", m, deviceID, name, offset, len(buf))
 			return protocol.ErrNoSuchFile
 		}
 
@@ -806,7 +792,7 @@ func (m *Model) Request(deviceID protocol.DeviceID, folder, name string, offset
 		m.rvmut.Unlock()
 	}
 
-	if debug && deviceID != protocol.LocalDeviceID {
+	if deviceID != protocol.LocalDeviceID {
 		l.Debugf("%v REQ(in): %s: %q / %q o=%d s=%d", m, deviceID, folder, name, offset, len(buf))
 	}
 	m.fmut.RLock()
@@ -1033,9 +1019,8 @@ func sendIndexes(conn protocol.Connection, folder string, fs *db.FileSet, ignore
 	name := conn.Name()
 	var err error
 
-	if debug {
-		l.Debugf("sendIndexes for %s-%s/%q starting", deviceID, name, folder)
-	}
+	l.Debugf("sendIndexes for %s-%s/%q starting", deviceID, name, folder)
+	defer l.Debugf("sendIndexes for %s-%s/%q exiting: %v", deviceID, name, folder, err)
 
 	minLocalVer, err := sendIndexTo(true, 0, conn, folder, fs, ignores)
 
@@ -1060,9 +1045,6 @@ func sendIndexes(conn protocol.Connection, folder string, fs *db.FileSet, ignore
 		time.Sleep(250 * time.Millisecond)
 	}
 
-	if debug {
-		l.Debugf("sendIndexes for %s-%s/%q exiting: %v", deviceID, name, folder, err)
-	}
 }
 
 func sendIndexTo(initial bool, minLocalVer int64, conn protocol.Connection, folder string, fs *db.FileSet, ignores *ignore.Matcher) (int64, error) {
@@ -1084,9 +1066,7 @@ func sendIndexTo(initial bool, minLocalVer int64, conn protocol.Connection, fold
 		}
 
 		if ignores.Match(f.Name) || symlinkInvalid(folder, f) {
-			if debug {
-				l.Debugln("not sending update for ignored/unsupported symlink", f)
-			}
+			l.Debugln("not sending update for ignored/unsupported symlink", f)
 			return true
 		}
 
@@ -1095,17 +1075,13 @@ func sendIndexTo(initial bool, minLocalVer int64, conn protocol.Connection, fold
 				if err = conn.Index(folder, batch, 0, nil); err != nil {
 					return false
 				}
-				if debug {
-					l.Debugf("sendIndexes for %s-%s/%q: %d files (<%d bytes) (initial index)", deviceID, name, folder, len(batch), currentBatchSize)
-				}
+				l.Debugf("sendIndexes for %s-%s/%q: %d files (<%d bytes) (initial index)", deviceID, name, folder, len(batch), currentBatchSize)
 				initial = false
 			} else {
 				if err = conn.IndexUpdate(folder, batch, 0, nil); err != nil {
 					return false
 				}
-				if debug {
-					l.Debugf("sendIndexes for %s-%s/%q: %d files (<%d bytes) (batched update)", deviceID, name, folder, len(batch), currentBatchSize)
-				}
+				l.Debugf("sendIndexes for %s-%s/%q: %d files (<%d bytes) (batched update)", deviceID, name, folder, len(batch), currentBatchSize)
 			}
 
 			batch = make([]protocol.FileInfo, 0, indexBatchSize)
@@ -1119,12 +1095,12 @@ func sendIndexTo(initial bool, minLocalVer int64, conn protocol.Connection, fold
 
 	if initial && err == nil {
 		err = conn.Index(folder, batch, 0, nil)
-		if debug && err == nil {
+		if err == nil {
 			l.Debugf("sendIndexes for %s-%s/%q: %d files (small initial index)", deviceID, name, folder, len(batch))
 		}
 	} else if len(batch) > 0 && err == nil {
 		err = conn.IndexUpdate(folder, batch, 0, nil)
-		if debug && err == nil {
+		if err == nil {
 			l.Debugf("sendIndexes for %s-%s/%q: %d files (last batch)", deviceID, name, folder, len(batch))
 		}
 	}
@@ -1160,9 +1136,7 @@ func (m *Model) requestGlobal(deviceID protocol.DeviceID, folder, name string, o
 		return nil, fmt.Errorf("requestGlobal: no such device: %s", deviceID)
 	}
 
-	if debug {
-		l.Debugf("%v REQ(out): %s: %q / %q o=%d s=%d h=%x f=%x op=%s", m, deviceID, folder, name, offset, size, hash, flags, options)
-	}
+	l.Debugf("%v REQ(out): %s: %q / %q o=%d s=%d h=%x f=%x op=%s", m, deviceID, folder, name, offset, size, hash, flags, options)
 
 	return nc.Request(folder, name, offset, size, hash, flags, options)
 }
@@ -1183,7 +1157,9 @@ func (m *Model) AddFolder(cfg config.FolderConfiguration) {
 	}
 
 	ignores := ignore.New(m.cacheIgnoredFiles)
-	_ = ignores.Load(filepath.Join(cfg.Path(), ".stignore")) // Ignore error, there might not be an .stignore
+	if err := ignores.Load(filepath.Join(cfg.Path(), ".stignore")); err != nil && !os.IsNotExist(err) {
+		l.Warnln("Loading ignores:", err)
+	}
 	m.folderIgnores[cfg.ID] = ignores
 
 	m.fmut.Unlock()
@@ -1270,10 +1246,17 @@ func (m *Model) internalScanFolderSubs(folder string, subs []string) error {
 	}
 
 	if err := m.CheckFolderHealth(folder); err != nil {
+		runner.setError(err)
+		l.Infof("Stopping folder %s due to error: %s", folder, err)
 		return err
 	}
 
-	_ = ignores.Load(filepath.Join(folderCfg.Path(), ".stignore")) // Ignore error, there might not be an .stignore
+	if err := ignores.Load(filepath.Join(folderCfg.Path(), ".stignore")); err != nil && !os.IsNotExist(err) {
+		err = fmt.Errorf("loading ignores: %v", err)
+		runner.setError(err)
+		l.Infof("Stopping folder %s due to error: %s", folder, err)
+		return err
+	}
 
 	// Required to make sure that we start indexing at a directory we're already
 	// aware off.
@@ -1394,9 +1377,7 @@ nextSub:
 
 			if ignores.Match(f.Name) || symlinkInvalid(folder, f) {
 				// File has been ignored or an unsupported symlink. Set invalid bit.
-				if debug {
-					l.Debugln("setting invalid bit on ignored", f)
-				}
+				l.Debugln("setting invalid bit on ignored", f)
 				nf := protocol.FileInfo{
 					Name:     f.Name,
 					Flags:    f.Flags | protocol.FlagInvalid,
@@ -1811,9 +1792,7 @@ func (m *Model) CommitConfiguration(from, to config.Configuration) bool {
 	for folderID, cfg := range toFolders {
 		if _, ok := fromFolders[folderID]; !ok {
 			// A folder was added.
-			if debug {
-				l.Debugln(m, "adding folder", folderID)
-			}
+			l.Debugln(m, "adding folder", folderID)
 			m.AddFolder(cfg)
 			if cfg.ReadOnly {
 				m.StartFolderRO(folderID)
@@ -1837,9 +1816,7 @@ func (m *Model) CommitConfiguration(from, to config.Configuration) bool {
 		toCfg, ok := toFolders[folderID]
 		if !ok {
 			// A folder was removed. Requires restart.
-			if debug {
-				l.Debugln(m, "requires restart, removing folder", folderID)
-			}
+			l.Debugln(m, "requires restart, removing folder", folderID)
 			return false
 		}
 
@@ -1851,9 +1828,7 @@ func (m *Model) CommitConfiguration(from, to config.Configuration) bool {
 		for dev := range fromDevs {
 			if _, ok := toDevs[dev]; !ok {
 				// A device was removed. Requires restart.
-				if debug {
-					l.Debugln(m, "requires restart, removing device", dev, "from folder", folderID)
-				}
+				l.Debugln(m, "requires restart, removing device", dev, "from folder", folderID)
 				return false
 			}
 		}
@@ -1886,9 +1861,7 @@ func (m *Model) CommitConfiguration(from, to config.Configuration) bool {
 		fromCfg.Devices = nil
 		toCfg.Devices = nil
 		if !reflect.DeepEqual(fromCfg, toCfg) {
-			if debug {
-				l.Debugln(m, "requires restart, folder", folderID, "configuration differs")
-			}
+			l.Debugln(m, "requires restart, folder", folderID, "configuration differs")
 			return false
 		}
 	}
@@ -1897,18 +1870,14 @@ func (m *Model) CommitConfiguration(from, to config.Configuration) bool {
 	toDevs := mapDeviceCfgs(from.Devices)
 	for _, dev := range from.Devices {
 		if _, ok := toDevs[dev.DeviceID]; !ok {
-			if debug {
-				l.Debugln(m, "requires restart, device", dev.DeviceID, "was removed")
-			}
+			l.Debugln(m, "requires restart, device", dev.DeviceID, "was removed")
 			return false
 		}
 	}
 
 	// All of the generic options require restart
 	if !reflect.DeepEqual(from.Options, to.Options) {
-		if debug {
-			l.Debugln(m, "requires restart, options differ")
-		}
+		l.Debugln(m, "requires restart, options differ")
 		return false
 	}
 
@@ -1948,21 +1917,15 @@ func mapDeviceCfgs(devices []config.DeviceConfiguration) map[protocol.DeviceID]s
 func filterIndex(folder string, fs []protocol.FileInfo, dropDeletes bool) []protocol.FileInfo {
 	for i := 0; i < len(fs); {
 		if fs[i].Flags&^protocol.FlagsAll != 0 {
-			if debug {
-				l.Debugln("dropping update for file with unknown bits set", fs[i])
-			}
+			l.Debugln("dropping update for file with unknown bits set", fs[i])
 			fs[i] = fs[len(fs)-1]
 			fs = fs[:len(fs)-1]
 		} else if fs[i].IsDeleted() && dropDeletes {
-			if debug {
-				l.Debugln("dropping update for undesired delete", fs[i])
-			}
+			l.Debugln("dropping update for undesired delete", fs[i])
 			fs[i] = fs[len(fs)-1]
 			fs = fs[:len(fs)-1]
 		} else if symlinkInvalid(folder, fs[i]) {
-			if debug {
-				l.Debugln("dropping update for unsupported symlink", fs[i])
-			}
+			l.Debugln("dropping update for unsupported symlink", fs[i])
 			fs[i] = fs[len(fs)-1]
 			fs = fs[:len(fs)-1]
 		} else {

lib/model/progressemitter.go

@@ -51,15 +51,11 @@ func (t *ProgressEmitter) Serve() {
 	for {
 		select {
 		case <-t.stop:
-			if debug {
-				l.Debugln("progress emitter: stopping")
-			}
+			l.Debugln("progress emitter: stopping")
 			return
 		case <-t.timer.C:
 			t.mut.Lock()
-			if debug {
-				l.Debugln("progress emitter: timer - looking after", len(t.registry))
-			}
+			l.Debugln("progress emitter: timer - looking after", len(t.registry))
 			output := make(map[string]map[string]*pullerProgress)
 			for _, puller := range t.registry {
 				if output[puller.folder] == nil {
@@ -70,10 +66,8 @@ func (t *ProgressEmitter) Serve() {
 			if !reflect.DeepEqual(t.last, output) {
 				events.Default.Log(events.DownloadProgress, output)
 				t.last = output
-				if debug {
-					l.Debugf("progress emitter: emitting %#v", output)
-				}
-			} else if debug {
+				l.Debugf("progress emitter: emitting %#v", output)
+			} else {
 				l.Debugln("progress emitter: nothing new")
 			}
 			if len(t.registry) != 0 {
@@ -95,9 +89,7 @@ func (t *ProgressEmitter) CommitConfiguration(from, to config.Configuration) boo
 	defer t.mut.Unlock()
 
 	t.interval = time.Duration(to.Options.ProgressUpdateIntervalS) * time.Second
-	if debug {
-		l.Debugln("progress emitter: updated interval", t.interval)
-	}
+	l.Debugln("progress emitter: updated interval", t.interval)
 
 	return true
 }
@@ -112,9 +104,7 @@ func (t *ProgressEmitter) Stop() {
 func (t *ProgressEmitter) Register(s *sharedPullerState) {
 	t.mut.Lock()
 	defer t.mut.Unlock()
-	if debug {
-		l.Debugln("progress emitter: registering", s.folder, s.file.Name)
-	}
+	l.Debugln("progress emitter: registering", s.folder, s.file.Name)
 	if len(t.registry) == 0 {
 		t.timer.Reset(t.interval)
 	}
@@ -125,9 +115,7 @@ func (t *ProgressEmitter) Register(s *sharedPullerState) {
 func (t *ProgressEmitter) Deregister(s *sharedPullerState) {
 	t.mut.Lock()
 	defer t.mut.Unlock()
-	if debug {
-		l.Debugln("progress emitter: deregistering", s.folder, s.file.Name)
-	}
+	l.Debugln("progress emitter: deregistering", s.folder, s.file.Name)
 	delete(t.registry, filepath.Join(s.folder, s.file.Name))
 }
 
@@ -141,9 +129,7 @@ func (t *ProgressEmitter) BytesCompleted(folder string) (bytes int64) {
 			bytes += s.Progress().BytesDone
 		}
 	}
-	if debug {
-		l.Debugf("progress emitter: bytes completed for %s: %d", folder, bytes)
-	}
+	l.Debugf("progress emitter: bytes completed for %s: %d", folder, bytes)
 	return
 }
 

lib/model/rofolder.go

@@ -48,10 +48,8 @@ func newROFolder(model *Model, folder string, interval time.Duration) *roFolder
 }
 
 func (s *roFolder) Serve() {
-	if debug {
-		l.Debugln(s, "starting")
-		defer l.Debugln(s, "exiting")
-	}
+	l.Debugln(s, "starting")
+	defer l.Debugln(s, "exiting")
 
 	defer func() {
 		s.timer.Stop()
@@ -79,9 +77,7 @@ func (s *roFolder) Serve() {
 				continue
 			}
 
-			if debug {
-				l.Debugln(s, "rescan")
-			}
+			l.Debugln(s, "rescan")
 
 			if err := s.model.internalScanFolderSubs(s.folder, nil); err != nil {
 				// Potentially sets the error twice, once in the scanner just
@@ -111,9 +107,7 @@ func (s *roFolder) Serve() {
 				continue
 			}
 
-			if debug {
-				l.Debugln(s, "forced rescan")
-			}
+			l.Debugln(s, "forced rescan")
 
 			if err := s.model.internalScanFolderSubs(s.folder, req.subs); err != nil {
 				// Potentially sets the error twice, once in the scanner just

lib/model/rwfolder.go

@@ -30,12 +30,6 @@ import (
 
 // TODO: Stop on errors
 
-const (
-	pauseIntv     = 60 * time.Second
-	nextPullIntv  = 10 * time.Second
-	shortPullIntv = time.Second
-)
-
 // A pullBlockState is passed to the puller routine for each block that needs
 // to be fetched.
 type pullBlockState struct {
@@ -67,8 +61,10 @@ const (
 )
 
 const (
-	defaultCopiers = 1
-	defaultPullers = 16
+	defaultCopiers     = 1
+	defaultPullers     = 16
+	defaultPullerSleep = 10 * time.Second
+	defaultPullerPause = 60 * time.Second
 )
 
 type dbUpdateJob struct {
@@ -92,6 +88,8 @@ type rwFolder struct {
 	pullers     int
 	shortID     uint64
 	order       config.PullOrder
+	sleep       time.Duration
+	pause       time.Duration
 
 	stop        chan struct{}
 	queue       *jobQueue
@@ -128,7 +126,7 @@ func newRWFolder(m *Model, shortID uint64, cfg config.FolderConfiguration) *rwFo
 
 		stop:        make(chan struct{}),
 		queue:       newJobQueue(),
-		pullTimer:   time.NewTimer(shortPullIntv),
+		pullTimer:   time.NewTimer(time.Second),
 		scanTimer:   time.NewTimer(time.Millisecond), // The first scan should be done immediately.
 		delayScan:   make(chan time.Duration),
 		scanNow:     make(chan rescanRequest),
@@ -144,6 +142,18 @@ func newRWFolder(m *Model, shortID uint64, cfg config.FolderConfiguration) *rwFo
 		p.pullers = defaultPullers
 	}
 
+	if cfg.PullerPauseS == 0 {
+		p.pause = defaultPullerPause
+	} else {
+		p.pause = time.Duration(cfg.PullerPauseS) * time.Second
+	}
+
+	if cfg.PullerSleepS == 0 {
+		p.sleep = defaultPullerSleep
+	} else {
+		p.sleep = time.Duration(cfg.PullerSleepS) * time.Second
+	}
+
 	return p
 }
 
@@ -157,10 +167,8 @@ func (p *rwFolder) ignorePermissions(file protocol.FileInfo) bool {
 // Serve will run scans and pulls. It will return when Stop()ed or on a
 // critical error.
 func (p *rwFolder) Serve() {
-	if debug {
-		l.Debugln(p, "starting")
-		defer l.Debugln(p, "exiting")
-	}
+	l.Debugln(p, "starting")
+	defer l.Debugln(p, "exiting")
 
 	defer func() {
 		p.pullTimer.Stop()
@@ -182,9 +190,7 @@ func (p *rwFolder) Serve() {
 		sleepNanos := (p.scanIntv.Nanoseconds()*3 + rand.Int63n(2*p.scanIntv.Nanoseconds())) / 4
 		intv := time.Duration(sleepNanos) * time.Nanosecond
 
-		if debug {
-			l.Debugln(p, "next rescan in", intv)
-		}
+		l.Debugln(p, "next rescan in", intv)
 		p.scanTimer.Reset(intv)
 	}
 
@@ -198,23 +204,13 @@ func (p *rwFolder) Serve() {
 
 		case <-p.remoteIndex:
 			prevVer = 0
-			p.pullTimer.Reset(shortPullIntv)
-			if debug {
-				l.Debugln(p, "remote index updated, rescheduling pull")
-			}
+			p.pullTimer.Reset(0)
+			l.Debugln(p, "remote index updated, rescheduling pull")
 
 		case <-p.pullTimer.C:
 			if !initialScanCompleted {
-				if debug {
-					l.Debugln(p, "skip (initial)")
-				}
-				p.pullTimer.Reset(nextPullIntv)
-				continue
-			}
-
-			if err := p.model.CheckFolderHealth(p.folder); err != nil {
-				l.Infoln("Skipping folder", p.folder, "pull due to folder error:", err)
-				p.pullTimer.Reset(nextPullIntv)
+				l.Debugln(p, "skip (initial)")
+				p.pullTimer.Reset(p.sleep)
 				continue
 			}
 
@@ -225,9 +221,7 @@ func (p *rwFolder) Serve() {
 			if newHash := curIgnores.Hash(); newHash != prevIgnoreHash {
 				// The ignore patterns have changed. We need to re-evaluate if
 				// there are files we need now that were ignored before.
-				if debug {
-					l.Debugln(p, "ignore patterns have changed, resetting prevVer")
-				}
+				l.Debugln(p, "ignore patterns have changed, resetting prevVer")
 				prevVer = 0
 				prevIgnoreHash = newHash
 			}
@@ -235,17 +229,19 @@ func (p *rwFolder) Serve() {
 			// RemoteLocalVersion() is a fast call, doesn't touch the database.
 			curVer, ok := p.model.RemoteLocalVersion(p.folder)
 			if !ok || curVer == prevVer {
-				if debug {
-					l.Debugln(p, "skip (curVer == prevVer)", prevVer, ok)
-				}
-				p.pullTimer.Reset(nextPullIntv)
+				l.Debugln(p, "skip (curVer == prevVer)", prevVer, ok)
+				p.pullTimer.Reset(p.sleep)
 				continue
 			}
 
-			if debug {
-				l.Debugln(p, "pulling", prevVer, curVer)
+			if err := p.model.CheckFolderHealth(p.folder); err != nil {
+				l.Infoln("Skipping folder", p.folder, "pull due to folder error:", err)
+				p.pullTimer.Reset(p.sleep)
+				continue
 			}
 
+			l.Debugln(p, "pulling", prevVer, curVer)
+
 			p.setState(FolderSyncing)
 			p.clearErrors()
 			tries := 0
@@ -254,9 +250,7 @@ func (p *rwFolder) Serve() {
 				tries++
 
 				changed := p.pullerIteration(curIgnores)
-				if debug {
-					l.Debugln(p, "changed", changed)
-				}
+				l.Debugln(p, "changed", changed)
 
 				if changed == 0 {
 					// No files were changed by the puller, so we are in
@@ -276,10 +270,8 @@ func (p *rwFolder) Serve() {
 						curVer = lv
 					}
 					prevVer = curVer
-					if debug {
-						l.Debugln(p, "next pull in", nextPullIntv)
-					}
-					p.pullTimer.Reset(nextPullIntv)
+					l.Debugln(p, "next pull in", p.sleep)
+					p.pullTimer.Reset(p.sleep)
 					break
 				}
 
@@ -288,10 +280,8 @@ func (p *rwFolder) Serve() {
 					// we're not making it. Probably there are write
 					// errors preventing us. Flag this with a warning and
 					// wait a bit longer before retrying.
-					l.Infof("Folder %q isn't making progress. Pausing puller for %v.", p.folder, pauseIntv)
-					if debug {
-						l.Debugln(p, "next pull in", pauseIntv)
-					}
+					l.Infof("Folder %q isn't making progress. Pausing puller for %v.", p.folder, p.pause)
+					l.Debugln(p, "next pull in", p.pause)
 
 					if folderErrors := p.currentErrors(); len(folderErrors) > 0 {
 						events.Default.Log(events.FolderErrors, map[string]interface{}{
@@ -300,7 +290,7 @@ func (p *rwFolder) Serve() {
 						})
 					}
 
-					p.pullTimer.Reset(pauseIntv)
+					p.pullTimer.Reset(p.pause)
 					break
 				}
 			}
@@ -316,9 +306,7 @@ func (p *rwFolder) Serve() {
 				continue
 			}
 
-			if debug {
-				l.Debugln(p, "rescan")
-			}
+			l.Debugln(p, "rescan")
 
 			if err := p.model.internalScanFolderSubs(p.folder, nil); err != nil {
 				// Potentially sets the error twice, once in the scanner just
@@ -345,9 +333,7 @@ func (p *rwFolder) Serve() {
 				continue
 			}
 
-			if debug {
-				l.Debugln(p, "forced rescan")
-			}
+			l.Debugln(p, "forced rescan")
 
 			if err := p.model.internalScanFolderSubs(p.folder, req.subs); err != nil {
 				// Potentially sets the error twice, once in the scanner just
@@ -409,9 +395,7 @@ func (p *rwFolder) pullerIteration(ignores *ignore.Matcher) int {
 	pullWg := sync.NewWaitGroup()
 	doneWg := sync.NewWaitGroup()
 
-	if debug {
-		l.Debugln(p, "c", p.copiers, "p", p.pullers)
-	}
+	l.Debugln(p, "c", p.copiers, "p", p.pullers)
 
 	p.dbUpdates = make(chan dbUpdateJob)
 	updateWg.Add(1)
@@ -474,9 +458,7 @@ func (p *rwFolder) pullerIteration(ignores *ignore.Matcher) int {
 			return true
 		}
 
-		if debug {
-			l.Debugln(p, "handling", file.Name)
-		}
+		l.Debugln(p, "handling", file.Name)
 
 		switch {
 		case file.IsDeleted():
@@ -498,9 +480,7 @@ func (p *rwFolder) pullerIteration(ignores *ignore.Matcher) int {
 			}
 		case file.IsDirectory() && !file.IsSymlink():
 			// A new or changed directory
-			if debug {
-				l.Debugln("Creating directory", file.Name)
-			}
+			l.Debugln("Creating directory", file.Name)
 			p.handleDir(file)
 		default:
 			// A new or changed file or symlink. This is the only case where we
@@ -591,17 +571,13 @@ nextFile:
 	doneWg.Wait()
 
 	for _, file := range fileDeletions {
-		if debug {
-			l.Debugln("Deleting file", file.Name)
-		}
+		l.Debugln("Deleting file", file.Name)
 		p.deleteFile(file)
 	}
 
 	for i := range dirDeletions {
 		dir := dirDeletions[len(dirDeletions)-i-1]
-		if debug {
-			l.Debugln("Deleting dir", dir.Name)
-		}
+		l.Debugln("Deleting dir", dir.Name)
 		p.deleteDir(dir)
 	}
 
@@ -638,7 +614,7 @@ func (p *rwFolder) handleDir(file protocol.FileInfo) {
 		mode = 0777
 	}
 
-	if debug {
+	if shouldDebug() {
 		curFile, _ := p.model.CurrentFolderFile(p.folder, file.Name)
 		l.Debugf("need dir\n\t%v\n\t%v", file, curFile)
 	}
@@ -836,9 +812,7 @@ func (p *rwFolder) renameFile(source, target protocol.FileInfo) {
 		})
 	}()
 
-	if debug {
-		l.Debugln(p, "taking rename shortcut", source.Name, "->", target.Name)
-	}
+	l.Debugln(p, "taking rename shortcut", source.Name, "->", target.Name)
 
 	from := filepath.Join(p.dir, source.Name)
 	to := filepath.Join(p.dir, target.Name)
@@ -926,9 +900,7 @@ func (p *rwFolder) handleFile(file protocol.FileInfo, copyChan chan<- copyBlocks
 		// We are supposed to copy the entire file, and then fetch nothing. We
 		// are only updating metadata, so we don't actually *need* to make the
 		// copy.
-		if debug {
-			l.Debugln(p, "taking shortcut on", file.Name)
-		}
+		l.Debugln(p, "taking shortcut on", file.Name)
 
 		events.Default.Log(events.ItemStarted, map[string]string{
 			"folder": p.folder,
@@ -965,7 +937,7 @@ func (p *rwFolder) handleFile(file protocol.FileInfo, copyChan chan<- copyBlocks
 	}
 
 	if free, err := osutil.DiskFreeBytes(p.dir); err == nil && free < file.Size() {
-		l.Warnf(`Folder "%s": insufficient disk space in %s for %s: have %.2f MiB, need %.2f MiB`, p.dir, file.Name, float64(free)/1024/1024, float64(file.Size())/1024/1024)
+		l.Warnf(`Folder "%s": insufficient disk space in %s for %s: have %.2f MiB, need %.2f MiB`, p.folder, p.dir, file.Name, float64(free)/1024/1024, float64(file.Size())/1024/1024)
 		p.newError(file.Name, errors.New("insufficient space"))
 		return
 	}
@@ -1033,9 +1005,7 @@ func (p *rwFolder) handleFile(file protocol.FileInfo, copyChan chan<- copyBlocks
 		mut:         sync.NewMutex(),
 	}
 
-	if debug {
-		l.Debugf("%v need file %s; copy %d, reused %v", p, file.Name, len(blocks), reused)
-	}
+	l.Debugf("%v need file %s; copy %d, reused %v", p, file.Name, len(blocks), reused)
 
 	cs := copyBlocksState{
 		sharedPullerState: &s,
@@ -1135,14 +1105,12 @@ func (p *rwFolder) copierRoutine(in <-chan copyBlocksState, pullChan chan<- pull
 				hash, err := scanner.VerifyBuffer(buf, block)
 				if err != nil {
 					if hash != nil {
-						if debug {
-							l.Debugf("Finder block mismatch in %s:%s:%d expected %q got %q", folder, file, index, block.Hash, hash)
-						}
+						l.Debugf("Finder block mismatch in %s:%s:%d expected %q got %q", folder, file, index, block.Hash, hash)
 						err = p.model.finder.Fix(folder, file, index, block.Hash, hash)
 						if err != nil {
 							l.Warnln("finder fix:", err)
 						}
-					} else if debug {
+					} else {
 						l.Debugln("Finder failed to verify buffer", err)
 					}
 					return false
@@ -1217,9 +1185,7 @@ func (p *rwFolder) pullerRoutine(in <-chan pullBlockState, out chan<- *sharedPul
 			buf, lastError := p.model.requestGlobal(selected, p.folder, state.file.Name, state.block.Offset, int(state.block.Size), state.block.Hash, 0, nil)
 			activity.done(selected)
 			if lastError != nil {
-				if debug {
-					l.Debugln("request:", p.folder, state.file.Name, state.block.Offset, state.block.Size, "returned error:", lastError)
-				}
+				l.Debugln("request:", p.folder, state.file.Name, state.block.Offset, state.block.Size, "returned error:", lastError)
 				continue
 			}
 
@@ -1227,9 +1193,7 @@ func (p *rwFolder) pullerRoutine(in <-chan pullBlockState, out chan<- *sharedPul
 			// try pulling it from another device.
 			_, lastError = scanner.VerifyBuffer(buf, state.block)
 			if lastError != nil {
-				if debug {
-					l.Debugln("request:", p.folder, state.file.Name, state.block.Offset, state.block.Size, "hash mismatch")
-				}
+				l.Debugln("request:", p.folder, state.file.Name, state.block.Offset, state.block.Size, "hash mismatch")
 				continue
 			}
 
@@ -1339,9 +1303,7 @@ func (p *rwFolder) performFinish(state *sharedPullerState) error {
 func (p *rwFolder) finisherRoutine(in <-chan *sharedPullerState) {
 	for state := range in {
 		if closed, err := state.finalClose(); closed {
-			if debug {
-				l.Debugln(p, "closing", state.file.Name)
-			}
+			l.Debugln(p, "closing", state.file.Name)
 
 			p.queue.Done(state.file.Name)
 

lib/model/rwfolder_test.go

@@ -445,11 +445,18 @@ func TestDeregisterOnFailInCopy(t *testing.T) {
 		finisherChan <- state
 		time.Sleep(100 * time.Millisecond)
 
-		if state.fd != nil {
+		state.mut.Lock()
+		stateFd := state.fd
+		state.mut.Unlock()
+		if stateFd != nil {
 			t.Fatal("File not closed?")
 		}
 
-		if len(p.progressEmitter.registry) != 0 || len(p.queue.progress) != 0 || len(p.queue.queued) != 0 {
+		p.queue.mut.Lock()
+		lenQProgr := len(p.queue.progress)
+		lenQQueued := len(p.queue.queued)
+		p.queue.mut.Unlock()
+		if len(p.progressEmitter.registry) != 0 || lenQProgr != 0 || lenQQueued != 0 {
 			t.Fatal("Still registered", len(p.progressEmitter.registry), len(p.queue.progress), len(p.queue.queued))
 		}
 
@@ -457,7 +464,11 @@ func TestDeregisterOnFailInCopy(t *testing.T) {
 		finisherChan <- state
 		time.Sleep(100 * time.Millisecond)
 
-		if len(p.progressEmitter.registry) != 0 || len(p.queue.progress) != 0 || len(p.queue.queued) != 0 {
+		p.queue.mut.Lock()
+		lenQProgr = len(p.queue.progress)
+		lenQQueued = len(p.queue.queued)
+		p.queue.mut.Unlock()
+		if len(p.progressEmitter.registry) != 0 || lenQProgr != 0 || lenQQueued != 0 {
 			t.Fatal("Still registered")
 		}
 	case <-time.After(time.Second):
@@ -527,12 +538,19 @@ func TestDeregisterOnFailInPull(t *testing.T) {
 		finisherChan <- state
 		time.Sleep(100 * time.Millisecond)
 
-		if state.fd != nil {
+		state.mut.Lock()
+		stateFd := state.fd
+		state.mut.Unlock()
+		if stateFd != nil {
 			t.Fatal("File not closed?")
 		}
 
-		if len(p.progressEmitter.registry) != 0 || len(p.queue.progress) != 0 || len(p.queue.queued) != 0 {
-			t.Fatal("Still registered", len(p.progressEmitter.registry), len(p.queue.progress), len(p.queue.queued))
+		p.queue.mut.Lock()
+		lenQProgr := len(p.queue.progress)
+		lenQQueued := len(p.queue.queued)
+		p.queue.mut.Unlock()
+		if len(p.progressEmitter.registry) != 0 || lenQProgr != 0 || lenQQueued != 0 {
+			t.Fatal("Still registered", len(p.progressEmitter.registry), lenQProgr, lenQQueued)
 		}
 
 		// Doing it again should have no effect

lib/model/sharedpullerstate.go

@@ -86,8 +86,24 @@ func (s *sharedPullerState) tempFile() (io.WriterAt, error) {
 	// here.
 	dir := filepath.Dir(s.tempName)
 	if info, err := os.Stat(dir); err != nil {
-		s.failLocked("dst stat dir", err)
-		return nil, err
+		if os.IsNotExist(err) {
+			// XXX: This works around a bug elsewhere, a race condition when
+			// things are deleted while being synced. However that happens, we
+			// end up with a directory for "foo" with the delete bit, but a
+			// file "foo/bar" that we want to sync. We never create the
+			// directory, and hence fail to create the file and end up looping
+			// forever on it. This breaks that by creating the directory; on
+			// next scan it'll be found and the delete bit on it is removed.
+			// The user can then clean up as they like...
+			l.Infoln("Resurrecting directory", dir)
+			if err := os.MkdirAll(dir, 0755); err != nil {
+				s.failLocked("resurrect dir", err)
+				return nil, err
+			}
+		} else {
+			s.failLocked("dst stat dir", err)
+			return nil, err
+		}
 	} else if info.Mode()&0200 == 0 {
 		err := os.Chmod(dir, 0755)
 		if !s.ignorePerms && err == nil {
@@ -177,9 +193,7 @@ func (s *sharedPullerState) failed() error {
 func (s *sharedPullerState) copyDone() {
 	s.mut.Lock()
 	s.copyNeeded--
-	if debug {
-		l.Debugln("sharedPullerState", s.folder, s.file.Name, "copyNeeded ->", s.copyNeeded)
-	}
+	l.Debugln("sharedPullerState", s.folder, s.file.Name, "copyNeeded ->", s.copyNeeded)
 	s.mut.Unlock()
 }
 
@@ -195,18 +209,14 @@ func (s *sharedPullerState) pullStarted() {
 	s.copyNeeded--
 	s.pullTotal++
 	s.pullNeeded++
-	if debug {
-		l.Debugln("sharedPullerState", s.folder, s.file.Name, "pullNeeded start ->", s.pullNeeded)
-	}
+	l.Debugln("sharedPullerState", s.folder, s.file.Name, "pullNeeded start ->", s.pullNeeded)
 	s.mut.Unlock()
 }
 
 func (s *sharedPullerState) pullDone() {
 	s.mut.Lock()
 	s.pullNeeded--
-	if debug {
-		l.Debugln("sharedPullerState", s.folder, s.file.Name, "pullNeeded done ->", s.pullNeeded)
-	}
+	l.Debugln("sharedPullerState", s.folder, s.file.Name, "pullNeeded done ->", s.pullNeeded)
 	s.mut.Unlock()
 }
 

lib/protocol/debug.go

@@ -6,10 +6,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "protocol") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("protocol", "The BEP protocol")
 )
+
+func init() {
+	l.SetDebug("protocol", strings.Contains(os.Getenv("STTRACE"), "protocol") || os.Getenv("STTRACE") == "all")
+}

lib/protocol/protocol.go

@@ -369,9 +369,7 @@ func (c *rawConnection) readMessage() (hdr header, msg encodable, err error) {
 	hdr = decodeHeader(binary.BigEndian.Uint32(c.rdbuf0[0:4]))
 	msglen := int(binary.BigEndian.Uint32(c.rdbuf0[4:8]))
 
-	if debug {
-		l.Debugf("read header %v (msglen=%d)", hdr, msglen)
-	}
+	l.Debugf("read header %v (msglen=%d)", hdr, msglen)
 
 	if msglen > MaxMessageLen {
 		err = fmt.Errorf("message length %d exceeds maximum %d", msglen, MaxMessageLen)
@@ -393,9 +391,7 @@ func (c *rawConnection) readMessage() (hdr header, msg encodable, err error) {
 		return
 	}
 
-	if debug {
-		l.Debugf("read %d bytes", len(c.rdbuf0))
-	}
+	l.Debugf("read %d bytes", len(c.rdbuf0))
 
 	msgBuf := c.rdbuf0
 	if hdr.compression && msglen > 0 {
@@ -405,17 +401,13 @@ func (c *rawConnection) readMessage() (hdr header, msg encodable, err error) {
 			return
 		}
 		msgBuf = c.rdbuf1
-		if debug {
-			l.Debugf("decompressed to %d bytes", len(msgBuf))
-		}
+		l.Debugf("decompressed to %d bytes", len(msgBuf))
 	}
 
-	if debug {
-		if len(msgBuf) > 1024 {
-			l.Debugf("message data:\n%s", hex.Dump(msgBuf[:1024]))
-		} else {
-			l.Debugf("message data:\n%s", hex.Dump(msgBuf))
-		}
+	if len(msgBuf) > 1024 {
+		l.Debugf("message data:\n%s", hex.Dump(msgBuf[:1024]))
+	} else {
+		l.Debugf("message data:\n%s", hex.Dump(msgBuf))
 	}
 
 	// We check each returned error for the XDRError.IsEOF() method.
@@ -477,16 +469,12 @@ func (c *rawConnection) readMessage() (hdr header, msg encodable, err error) {
 }
 
 func (c *rawConnection) handleIndex(im IndexMessage) {
-	if debug {
-		l.Debugf("Index(%v, %v, %d file, flags %x, opts: %s)", c.id, im.Folder, len(im.Files), im.Flags, im.Options)
-	}
+	l.Debugf("Index(%v, %v, %d file, flags %x, opts: %s)", c.id, im.Folder, len(im.Files), im.Flags, im.Options)
 	c.receiver.Index(c.id, im.Folder, filterIndexMessageFiles(im.Files), im.Flags, im.Options)
 }
 
 func (c *rawConnection) handleIndexUpdate(im IndexMessage) {
-	if debug {
-		l.Debugf("queueing IndexUpdate(%v, %v, %d files, flags %x, opts: %s)", c.id, im.Folder, len(im.Files), im.Flags, im.Options)
-	}
+	l.Debugf("queueing IndexUpdate(%v, %v, %d files, flags %x, opts: %s)", c.id, im.Folder, len(im.Files), im.Flags, im.Options)
 	c.receiver.IndexUpdate(c.id, im.Folder, filterIndexMessageFiles(im.Files), im.Flags, im.Options)
 }
 
@@ -636,9 +624,7 @@ func (c *rawConnection) writerLoop() {
 					binary.BigEndian.PutUint32(msgBuf[4:8], uint32(len(tempBuf)))
 					msgBuf = msgBuf[0 : len(tempBuf)+8]
 
-					if debug {
-						l.Debugf("write compressed message; %v (len=%d)", hm.hdr, len(tempBuf))
-					}
+					l.Debugf("write compressed message; %v (len=%d)", hm.hdr, len(tempBuf))
 				} else {
 					// No point in compressing very short messages
 					hm.hdr.compression = false
@@ -652,14 +638,10 @@ func (c *rawConnection) writerLoop() {
 					msgBuf = msgBuf[0 : len(uncBuf)+8]
 					copy(msgBuf[8:], uncBuf)
 
-					if debug {
-						l.Debugf("write uncompressed message; %v (len=%d)", hm.hdr, len(uncBuf))
-					}
+					l.Debugf("write uncompressed message; %v (len=%d)", hm.hdr, len(uncBuf))
 				}
 			} else {
-				if debug {
-					l.Debugf("write empty message; %v", hm.hdr)
-				}
+				l.Debugf("write empty message; %v", hm.hdr)
 				binary.BigEndian.PutUint32(msgBuf[4:8], 0)
 				msgBuf = msgBuf[:8]
 			}
@@ -669,9 +651,7 @@ func (c *rawConnection) writerLoop() {
 			if err == nil {
 				var n int
 				n, err = c.cw.Write(msgBuf)
-				if debug {
-					l.Debugf("wrote %d bytes on the wire", n)
-				}
+				l.Debugf("wrote %d bytes on the wire", n)
 			}
 			if err != nil {
 				c.close(err)
@@ -725,15 +705,11 @@ func (c *rawConnection) pingSender() {
 		case <-ticker:
 			d := time.Since(c.cw.Last())
 			if d < PingSendInterval/2 {
-				if debug {
-					l.Debugln(c.id, "ping skipped after wr", d)
-				}
+				l.Debugln(c.id, "ping skipped after wr", d)
 				continue
 			}
 
-			if debug {
-				l.Debugln(c.id, "ping -> after", d)
-			}
+			l.Debugln(c.id, "ping -> after", d)
 			c.ping()
 
 		case <-c.closed:
@@ -753,15 +729,11 @@ func (c *rawConnection) pingReceiver() {
 		case <-ticker:
 			d := time.Since(c.cr.Last())
 			if d > ReceiveTimeout {
-				if debug {
-					l.Debugln(c.id, "ping timeout", d)
-				}
+				l.Debugln(c.id, "ping timeout", d)
 				c.close(ErrTimeout)
 			}
 
-			if debug {
-				l.Debugln(c.id, "last read within", d)
-			}
+			l.Debugln(c.id, "last read within", d)
 
 		case <-c.closed:
 			return

lib/rc/debug.go

@@ -10,10 +10,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "rc") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("rc", "Remote control package")
 )
+
+func init() {
+	l.SetDebug("rc", strings.Contains(os.Getenv("STTRACE"), "rc") || os.Getenv("STTRACE") == "all")
+}

lib/rc/rc.go

@@ -351,9 +351,7 @@ func (p *Process) Model(folder string) (Model, error) {
 		return Model{}, err
 	}
 
-	if debug {
-		l.Debugf("%+v", res)
-	}
+	l.Debugf("%+v", res)
 
 	return res, nil
 }
@@ -506,9 +504,7 @@ func (p *Process) eventLoop() {
 				m[p.id.String()] = version
 				p.localVersion[folder] = m
 				p.done[folder] = false
-				if debug {
-					l.Debugf("LocalIndexUpdated %v %v done=false\n\t%+v", p.id, folder, m)
-				}
+				l.Debugf("LocalIndexUpdated %v %v done=false\n\t%+v", p.id, folder, m)
 				p.eventMut.Unlock()
 
 			case "RemoteIndexUpdated":
@@ -524,9 +520,7 @@ func (p *Process) eventLoop() {
 				m[device] = version
 				p.localVersion[folder] = m
 				p.done[folder] = false
-				if debug {
-					l.Debugf("RemoteIndexUpdated %v %v done=false\n\t%+v", p.id, folder, m)
-				}
+				l.Debugf("RemoteIndexUpdated %v %v done=false\n\t%+v", p.id, folder, m)
 				p.eventMut.Unlock()
 
 			case "FolderSummary":
@@ -537,9 +531,7 @@ func (p *Process) eventLoop() {
 				done := need == 0
 				p.eventMut.Lock()
 				p.done[folder] = done
-				if debug {
-					l.Debugf("Foldersummary %v %v\n\t%+v", p.id, folder, p.done)
-				}
+				l.Debugf("Foldersummary %v %v\n\t%+v", p.id, folder, p.done)
 				p.eventMut.Unlock()
 			}
 		}

lib/relay/client/client.go

@@ -5,7 +5,6 @@ package client
 import (
 	"crypto/tls"
 	"fmt"
-	"log"
 	"net"
 	"net/url"
 	"time"
@@ -66,15 +65,11 @@ func (c *ProtocolClient) Serve() {
 	defer close(c.stopped)
 
 	if err := c.connect(); err != nil {
-		if debug {
-			l.Debugln("Relay connect:", err)
-		}
+		l.Debugln("Relay connect:", err)
 		return
 	}
 
-	if debug {
-		l.Debugln(c, "connected", c.conn.RemoteAddr())
-	}
+	l.Debugln(c, "connected", c.conn.RemoteAddr())
 
 	if err := c.join(); err != nil {
 		c.conn.Close()
@@ -83,13 +78,12 @@ func (c *ProtocolClient) Serve() {
 	}
 
 	if err := c.conn.SetDeadline(time.Time{}); err != nil {
+		c.conn.Close()
 		l.Infoln("Relay set deadline:", err)
 		return
 	}
 
-	if debug {
-		l.Debugln(c, "joined", c.conn.RemoteAddr(), "via", c.conn.LocalAddr())
-	}
+	l.Debugln(c, "joined", c.conn.RemoteAddr(), "via", c.conn.LocalAddr())
 
 	defer c.cleanup()
 	c.mut.Lock()
@@ -107,9 +101,7 @@ func (c *ProtocolClient) Serve() {
 		select {
 		case message := <-messages:
 			timeout.Reset(c.timeout)
-			if debug {
-				log.Printf("%s received message %T", c, message)
-			}
+			l.Debugf("%s received message %T", c, message)
 
 			switch msg := message.(type) {
 			case protocol.Ping:
@@ -118,9 +110,7 @@ func (c *ProtocolClient) Serve() {
 					return
 
 				}
-				if debug {
-					l.Debugln(c, "sent pong")
-				}
+				l.Debugln(c, "sent pong")
 
 			case protocol.SessionInvitation:
 				ip := net.IP(msg.Address)
@@ -135,9 +125,7 @@ func (c *ProtocolClient) Serve() {
 			}
 
 		case <-c.stop:
-			if debug {
-				l.Debugln(c, "stopping")
-			}
+			l.Debugln(c, "stopping")
 			return
 
 		case err := <-errors:
@@ -145,9 +133,7 @@ func (c *ProtocolClient) Serve() {
 			return
 
 		case <-timeout.C:
-			if debug {
-				l.Debugln(c, "timed out")
-			}
+			l.Debugln(c, "timed out")
 			return
 		}
 	}
@@ -220,9 +206,7 @@ func (c *ProtocolClient) cleanup() {
 		c.Invitations = make(chan protocol.SessionInvitation)
 	}
 
-	if debug {
-		l.Debugln(c, "cleaning up")
-	}
+	l.Debugln(c, "cleaning up")
 
 	c.mut.Lock()
 	c.connected = false

lib/relay/client/debug.go

@@ -6,10 +6,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "relay") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("relay", "")
 )
+
+func init() {
+	l.SetDebug("relay", strings.Contains(os.Getenv("STTRACE"), "relay") || os.Getenv("STTRACE") == "all")
+}

lib/relay/client/methods.go

@@ -49,9 +49,7 @@ func GetInvitationFromRelay(uri *url.URL, id syncthingprotocol.DeviceID, certs [
 	case protocol.Response:
 		return protocol.SessionInvitation{}, fmt.Errorf("Incorrect response code %d: %s", msg.Code, msg.Message)
 	case protocol.SessionInvitation:
-		if debug {
-			l.Debugln("Received invitation", msg, "via", conn.LocalAddr())
-		}
+		l.Debugln("Received invitation", msg, "via", conn.LocalAddr())
 		ip := net.IP(msg.Address)
 		if len(ip) == 0 || ip.IsUnspecified() {
 			msg.Address = conn.RemoteAddr().(*net.TCPAddr).IP[:]

lib/relay/debug.go

@@ -10,10 +10,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "relay") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("relay", "Relay connection handling")
 )
+
+func init() {
+	l.SetDebug("relay", strings.Contains(os.Getenv("STTRACE"), "relay") || os.Getenv("STTRACE") == "all")
+}

lib/relay/relay.go

@@ -47,9 +47,7 @@ func NewSvc(cfg *config.Wrapper, tlsCfg *tls.Config) *Svc {
 	svc := &Svc{
 		Supervisor: suture.New("Svc", suture.Spec{
 			Log: func(log string) {
-				if debug {
-					l.Debugln(log)
-				}
+				l.Debugln(log)
 			},
 			FailureBackoff:   5 * time.Minute,
 			FailureDecay:     float64((10 * time.Minute) / time.Second),
@@ -102,9 +100,7 @@ func (s *Svc) CommitConfiguration(from, to config.Configuration) bool {
 	for _, addr := range to.Options.RelayServers {
 		uri, err := url.Parse(addr)
 		if err != nil {
-			if debug {
-				l.Debugln("Failed to parse relay address", addr, err)
-			}
+			l.Debugln("Failed to parse relay address", addr, err)
 			continue
 		}
 		existing[uri.String()] = uri
@@ -120,15 +116,11 @@ func (s *Svc) CommitConfiguration(from, to config.Configuration) bool {
 		// Trim off the `dynamic+` prefix
 		uri.Scheme = uri.Scheme[8:]
 
-		if debug {
-			l.Debugln("Looking up dynamic relays from", uri)
-		}
+		l.Debugln("Looking up dynamic relays from", uri)
 
 		data, err := http.Get(uri.String())
 		if err != nil {
-			if debug {
-				l.Debugln("Failed to lookup dynamic relays", err)
-			}
+			l.Debugln("Failed to lookup dynamic relays", err)
 			continue
 		}
 
@@ -136,9 +128,7 @@ func (s *Svc) CommitConfiguration(from, to config.Configuration) bool {
 		err = json.NewDecoder(data.Body).Decode(&ann)
 		data.Body.Close()
 		if err != nil {
-			if debug {
-				l.Debugln("Failed to lookup dynamic relays", err)
-			}
+			l.Debugln("Failed to lookup dynamic relays", err)
 			continue
 		}
 
@@ -146,26 +136,20 @@ func (s *Svc) CommitConfiguration(from, to config.Configuration) bool {
 		for _, relayAnn := range ann.Relays {
 			ruri, err := url.Parse(relayAnn.URL)
 			if err != nil {
-				if debug {
-					l.Debugln("Failed to parse dynamic relay address", relayAnn.URL, err)
-				}
+				l.Debugln("Failed to parse dynamic relay address", relayAnn.URL, err)
 				continue
 			}
-			if debug {
-				l.Debugln("Found", ruri, "via", uri)
-			}
+			l.Debugln("Found", ruri, "via", uri)
 			dynRelayAddrs = append(dynRelayAddrs, ruri.String())
 		}
 
 		if len(dynRelayAddrs) > 0 {
 			dynRelayAddrs = relayAddressesSortedByLatency(dynRelayAddrs)
 			closestRelay := dynRelayAddrs[0]
-			if debug {
-				l.Debugln("Picking", closestRelay, "as closest dynamic relay from", uri)
-			}
+			l.Debugln("Picking", closestRelay, "as closest dynamic relay from", uri)
 			ruri, _ := url.Parse(closestRelay)
 			existing[closestRelay] = ruri
-		} else if debug {
+		} else {
 			l.Debugln("No dynamic relay found on", uri)
 		}
 	}
@@ -175,9 +159,7 @@ func (s *Svc) CommitConfiguration(from, to config.Configuration) bool {
 	for key, uri := range existing {
 		_, ok := s.tokens[key]
 		if !ok {
-			if debug {
-				l.Debugln("Connecting to relay", uri)
-			}
+			l.Debugln("Connecting to relay", uri)
 			c := client.NewProtocolClient(uri, s.tlsCfg.Certificates, s.invitations)
 			s.tokens[key] = s.Add(c)
 			s.clients[key] = c
@@ -190,9 +172,7 @@ func (s *Svc) CommitConfiguration(from, to config.Configuration) bool {
 			err := s.Remove(token)
 			delete(s.tokens, key)
 			delete(s.clients, key)
-			if debug {
-				l.Debugln("Disconnecting from relay", key, err)
-			}
+			l.Debugln("Disconnecting from relay", key, err)
 		}
 	}
 
@@ -262,14 +242,10 @@ func (r *invitationReceiver) Serve() {
 	for {
 		select {
 		case inv := <-r.invitations:
-			if debug {
-				l.Debugln("Received relay invitation", inv)
-			}
+			l.Debugln("Received relay invitation", inv)
 			conn, err := client.JoinSession(inv)
 			if err != nil {
-				if debug {
-					l.Debugf("Failed to join relay session %s: %v", inv, err)
-				}
+				l.Debugf("Failed to join relay session %s: %v", inv, err)
 				continue
 			}
 

lib/scanner/blockqueue.go

@@ -42,9 +42,7 @@ func newParallelHasher(dir string, blockSize, workers int, outbox, inbox chan pr
 func HashFile(path string, blockSize int, sizeHint int64, counter *int64) ([]protocol.BlockInfo, error) {
 	fd, err := os.Open(path)
 	if err != nil {
-		if debug {
-			l.Debugln("open:", err)
-		}
+		l.Debugln("open:", err)
 		return []protocol.BlockInfo{}, err
 	}
 	defer fd.Close()
@@ -52,9 +50,7 @@ func HashFile(path string, blockSize int, sizeHint int64, counter *int64) ([]pro
 	if sizeHint == 0 {
 		fi, err := fd.Stat()
 		if err != nil {
-			if debug {
-				l.Debugln("stat:", err)
-			}
+			l.Debugln("stat:", err)
 			return []protocol.BlockInfo{}, err
 		}
 		sizeHint = fi.Size()
@@ -71,9 +67,7 @@ func hashFiles(dir string, blockSize int, outbox, inbox chan protocol.FileInfo,
 
 		blocks, err := HashFile(filepath.Join(dir, f.Name), blockSize, f.CachedSize, counter)
 		if err != nil {
-			if debug {
-				l.Debugln("hash error:", f.Name, err)
-			}
+			l.Debugln("hash error:", f.Name, err)
 			continue
 		}
 

lib/scanner/debug.go

@@ -10,10 +10,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "scanner") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("scanner", "File change detection and hashing")
 )
+
+func init() {
+	l.SetDebug("scanner", strings.Contains(os.Getenv("STTRACE"), "scanner") || os.Getenv("STTRACE") == "all")
+}

lib/scanner/walk.go

@@ -94,9 +94,7 @@ type IgnoreMatcher interface {
 // Walk returns the list of files found in the local folder by scanning the
 // file system. Files are blockwise hashed.
 func (w *Walker) Walk() (chan protocol.FileInfo, error) {
-	if debug {
-		l.Debugln("Walk", w.Dir, w.Subs, w.BlockSize, w.Matcher)
-	}
+	l.Debugln("Walk", w.Dir, w.Subs, w.BlockSize, w.Matcher)
 
 	err := checkDir(w.Dir)
 	if err != nil {
@@ -143,7 +141,7 @@ func (w *Walker) Walk() (chan protocol.FileInfo, error) {
 	// which it receives the files we ask it to hash.
 	go func() {
 		var filesToHash []protocol.FileInfo
-		var total, progress int64
+		var total, progress int64 = 1, 0
 		for file := range toHashChan {
 			filesToHash = append(filesToHash, file)
 			total += int64(file.CachedSize)
@@ -159,16 +157,12 @@ func (w *Walker) Walk() (chan protocol.FileInfo, error) {
 			for {
 				select {
 				case <-done:
-					if debug {
-						l.Debugln("Walk progress done", w.Dir, w.Subs, w.BlockSize, w.Matcher)
-					}
+					l.Debugln("Walk progress done", w.Dir, w.Subs, w.BlockSize, w.Matcher)
 					ticker.Stop()
 					return
 				case <-ticker.C:
 					current := atomic.LoadInt64(&progress)
-					if debug {
-						l.Debugf("Walk %s %s current progress %d/%d (%d%%)", w.Dir, w.Subs, current, total, current*100/total)
-					}
+					l.Debugf("Walk %s %s current progress %d/%d (%d%%)", w.Dir, w.Subs, current, total, current*100/total)
 					events.Default.Log(events.FolderScanProgress, map[string]interface{}{
 						"folder":  w.Folder,
 						"current": current,
@@ -179,9 +173,7 @@ func (w *Walker) Walk() (chan protocol.FileInfo, error) {
 		}()
 
 		for _, file := range filesToHash {
-			if debug {
-				l.Debugln("real to hash:", file.Name)
-			}
+			l.Debugln("real to hash:", file.Name)
 			realToHashChan <- file
 		}
 		close(realToHashChan)
@@ -202,17 +194,13 @@ func (w *Walker) walkAndHashFiles(fchan, dchan chan protocol.FileInfo) filepath.
 		}
 
 		if err != nil {
-			if debug {
-				l.Debugln("error:", p, info, err)
-			}
+			l.Debugln("error:", p, info, err)
 			return skip
 		}
 
 		rn, err := filepath.Rel(w.Dir, p)
 		if err != nil {
-			if debug {
-				l.Debugln("rel error:", p, err)
-			}
+			l.Debugln("rel error:", p, err)
 			return skip
 		}
 
@@ -227,14 +215,10 @@ func (w *Walker) walkAndHashFiles(fchan, dchan chan protocol.FileInfo) filepath.
 
 		if w.TempNamer != nil && w.TempNamer.IsTemporary(rn) {
 			// A temporary file
-			if debug {
-				l.Debugln("temporary:", rn)
-			}
+			l.Debugln("temporary:", rn)
 			if info.Mode().IsRegular() && mtime.Add(w.TempLifetime).Before(now) {
 				os.Remove(p)
-				if debug {
-					l.Debugln("removing temporary:", rn, mtime)
-				}
+				l.Debugln("removing temporary:", rn, mtime)
 			}
 			return nil
 		}
@@ -242,9 +226,7 @@ func (w *Walker) walkAndHashFiles(fchan, dchan chan protocol.FileInfo) filepath.
 		if sn := filepath.Base(rn); sn == ".stignore" || sn == ".stfolder" ||
 			strings.HasPrefix(rn, ".stversions") || (w.Matcher != nil && w.Matcher.Match(rn)) {
 			// An ignored file
-			if debug {
-				l.Debugln("ignored:", rn)
-			}
+			l.Debugln("ignored:", rn)
 			return skip
 		}
 
@@ -313,17 +295,13 @@ func (w *Walker) walkAndHashFiles(fchan, dchan chan protocol.FileInfo) filepath.
 
 			target, targetType, err := symlinks.Read(p)
 			if err != nil {
-				if debug {
-					l.Debugln("readlink error:", p, err)
-				}
+				l.Debugln("readlink error:", p, err)
 				return skip
 			}
 
 			blocks, err := Blocks(strings.NewReader(target), w.BlockSize, 0, nil)
 			if err != nil {
-				if debug {
-					l.Debugln("hash link error:", p, err)
-				}
+				l.Debugln("hash link error:", p, err)
 				return skip
 			}
 
@@ -349,9 +327,7 @@ func (w *Walker) walkAndHashFiles(fchan, dchan chan protocol.FileInfo) filepath.
 				Blocks:   blocks,
 			}
 
-			if debug {
-				l.Debugln("symlink changedb:", p, f)
-			}
+			l.Debugln("symlink changedb:", p, f)
 
 			dchan <- f
 
@@ -386,9 +362,7 @@ func (w *Walker) walkAndHashFiles(fchan, dchan chan protocol.FileInfo) filepath.
 				Flags:    flags,
 				Modified: mtime.Unix(),
 			}
-			if debug {
-				l.Debugln("dir:", p, f)
-			}
+			l.Debugln("dir:", p, f)
 			dchan <- f
 			return nil
 		}
@@ -416,9 +390,7 @@ func (w *Walker) walkAndHashFiles(fchan, dchan chan protocol.FileInfo) filepath.
 					return nil
 				}
 
-				if debug {
-					l.Debugln("rescan:", cf, mtime.Unix(), info.Mode()&os.ModePerm)
-				}
+				l.Debugln("rescan:", cf, mtime.Unix(), info.Mode()&os.ModePerm)
 			}
 
 			var flags = curMode & uint32(maskModePerm)
@@ -433,9 +405,7 @@ func (w *Walker) walkAndHashFiles(fchan, dchan chan protocol.FileInfo) filepath.
 				Modified:   mtime.Unix(),
 				CachedSize: info.Size(),
 			}
-			if debug {
-				l.Debugln("to hash:", p, f)
-			}
+			l.Debugln("to hash:", p, f)
 			fchan <- f
 		}
 
@@ -448,7 +418,7 @@ func checkDir(dir string) error {
 		return err
 	} else if !info.IsDir() {
 		return errors.New(dir + ": not a directory")
-	} else if debug {
+	} else {
 		l.Debugln("checkDir", dir, info)
 	}
 	return nil

lib/stats/debug.go

@@ -10,10 +10,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "stats") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("stats", "Persistent device and folder statistics")
 )
+
+func init() {
+	l.SetDebug("stats", strings.Contains(os.Getenv("STTRACE"), "stats") || os.Getenv("STTRACE") == "all")
+}

lib/stats/device.go

@@ -37,16 +37,12 @@ func (s *DeviceStatisticsReference) GetLastSeen() time.Time {
 		// time.Time{} from s.ns
 		return time.Unix(0, 0)
 	}
-	if debug {
-		l.Debugln("stats.DeviceStatisticsReference.GetLastSeen:", s.device, t)
-	}
+	l.Debugln("stats.DeviceStatisticsReference.GetLastSeen:", s.device, t)
 	return t
 }
 
 func (s *DeviceStatisticsReference) WasSeen() {
-	if debug {
-		l.Debugln("stats.DeviceStatisticsReference.WasSeen:", s.device)
-	}
+	l.Debugln("stats.DeviceStatisticsReference.WasSeen:", s.device)
 	s.ns.PutTime("lastSeen", time.Now())
 }
 

lib/stats/folder.go

@@ -54,9 +54,7 @@ func (s *FolderStatisticsReference) GetLastFile() LastFile {
 }
 
 func (s *FolderStatisticsReference) ReceivedFile(file string, deleted bool) {
-	if debug {
-		l.Debugln("stats.FolderStatisticsReference.ReceivedFile:", s.folder, file)
-	}
+	l.Debugln("stats.FolderStatisticsReference.ReceivedFile:", s.folder, file)
 	s.ns.PutTime("lastFileAt", time.Now())
 	s.ns.PutString("lastFileName", file)
 	s.ns.PutBool("lastFileDeleted", deleted)

lib/sync/debug.go

@@ -12,20 +12,28 @@ import (
 	"strings"
 	"time"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug     = strings.Contains(os.Getenv("STTRACE"), "locks") || os.Getenv("STTRACE") == "all"
 	threshold = time.Duration(100 * time.Millisecond)
-	l         = logger.DefaultLogger
+	l         = logger.DefaultLogger.NewFacility("sync", "Mutexes")
+
+	// We make an exception in this package and have an actual "if debug { ...
+	// }" variable, as it may be rather performance critical and does
+	// nonstandard things (from a debug logging PoV).
+	debug = strings.Contains(os.Getenv("STTRACE"), "sync") || os.Getenv("STTRACE") == "all"
 )
 
 func init() {
-	if n, err := strconv.Atoi(os.Getenv("STLOCKTHRESHOLD")); debug && err == nil {
+	l.SetDebug("sync", strings.Contains(os.Getenv("STTRACE"), "sync") || os.Getenv("STTRACE") == "all")
+
+	if n, err := strconv.Atoi(os.Getenv("STLOCKTHRESHOLD")); err == nil {
 		threshold = time.Duration(n) * time.Millisecond
 	}
-	if debug {
-		l.Debugf("Enabling lock logging at %v threshold", threshold)
-	}
+	l.Debugf("Enabling lock logging at %v threshold", threshold)
+}
+
+func shouldDebug() bool {
+	return l.ShouldDebug("sync")
 }

lib/sync/sync_test.go

@@ -12,7 +12,7 @@ import (
 	"testing"
 	"time"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 const (
@@ -23,6 +23,7 @@ const (
 
 func TestTypes(t *testing.T) {
 	debug = false
+	l.SetDebug("sync", false)
 
 	if _, ok := NewMutex().(*sync.Mutex); !ok {
 		t.Error("Wrong type")
@@ -37,6 +38,7 @@ func TestTypes(t *testing.T) {
 	}
 
 	debug = true
+	l.SetDebug("sync", true)
 
 	if _, ok := NewMutex().(*loggedMutex); !ok {
 		t.Error("Wrong type")
@@ -51,10 +53,12 @@ func TestTypes(t *testing.T) {
 	}
 
 	debug = false
+	l.SetDebug("sync", false)
 }
 
 func TestMutex(t *testing.T) {
 	debug = true
+	l.SetDebug("sync", true)
 	threshold = logThreshold
 
 	msgmut := sync.Mutex{}
@@ -84,10 +88,12 @@ func TestMutex(t *testing.T) {
 	}
 
 	debug = false
+	l.SetDebug("sync", false)
 }
 
 func TestRWMutex(t *testing.T) {
 	debug = true
+	l.SetDebug("sync", true)
 	threshold = logThreshold
 
 	msgmut := sync.Mutex{}
@@ -142,10 +148,12 @@ func TestRWMutex(t *testing.T) {
 	mut.RUnlock()
 
 	debug = false
+	l.SetDebug("sync", false)
 }
 
 func TestWaitGroup(t *testing.T) {
 	debug = true
+	l.SetDebug("sync", true)
 	threshold = logThreshold
 
 	msgmut := sync.Mutex{}
@@ -182,4 +190,5 @@ func TestWaitGroup(t *testing.T) {
 	}
 
 	debug = false
+	l.SetDebug("sync", false)
 }

lib/upgrade/debug.go

@@ -10,10 +10,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "upgrade") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("upgrade", "Binary upgrades")
 )
+
+func init() {
+	l.SetDebug("upgrade", strings.Contains(os.Getenv("STTRACE"), "upgrade") || os.Getenv("STTRACE") == "all")
+}

lib/upgrade/upgrade_supported.go

@@ -96,12 +96,8 @@ func SelectLatestRelease(version string, rels []Release) (Release, error) {
 			assetName := path.Base(asset.Name)
 			// Check for the architecture
 			expectedRelease := releaseName(rel.Tag)
-			if debug {
-				l.Debugf("expected release asset %q", expectedRelease)
-			}
-			if debug {
-				l.Debugln("considering release", assetName)
-			}
+			l.Debugf("expected release asset %q", expectedRelease)
+			l.Debugln("considering release", assetName)
 			if strings.HasPrefix(assetName, expectedRelease) {
 				return rel, nil
 			}
@@ -113,14 +109,10 @@ func SelectLatestRelease(version string, rels []Release) (Release, error) {
 // Upgrade to the given release, saving the previous binary with a ".old" extension.
 func upgradeTo(binary string, rel Release) error {
 	expectedRelease := releaseName(rel.Tag)
-	if debug {
-		l.Debugf("expected release asset %q", expectedRelease)
-	}
+	l.Debugf("expected release asset %q", expectedRelease)
 	for _, asset := range rel.Assets {
 		assetName := path.Base(asset.Name)
-		if debug {
-			l.Debugln("considering release", assetName)
-		}
+		l.Debugln("considering release", assetName)
 
 		if strings.HasPrefix(assetName, expectedRelease) {
 			return upgradeToURL(binary, asset.URL)
@@ -151,9 +143,7 @@ func upgradeToURL(binary string, url string) error {
 }
 
 func readRelease(dir, url string) (string, error) {
-	if debug {
-		l.Debugf("loading %q", url)
-	}
+	l.Debugf("loading %q", url)
 
 	req, err := http.NewRequest("GET", url, nil)
 	if err != nil {
@@ -199,9 +189,7 @@ func readTarGz(dir string, r io.Reader) (string, error) {
 
 		shortName := path.Base(hdr.Name)
 
-		if debug {
-			l.Debugf("considering file %q", shortName)
-		}
+		l.Debugf("considering file %q", shortName)
 
 		err = archiveFileVisitor(dir, &tempName, &sig, shortName, tr)
 		if err != nil {
@@ -238,9 +226,7 @@ func readZip(dir string, r io.Reader) (string, error) {
 	for _, file := range archive.File {
 		shortName := path.Base(file.Name)
 
-		if debug {
-			l.Debugf("considering file %q", shortName)
-		}
+		l.Debugf("considering file %q", shortName)
 
 		inFile, err := file.Open()
 		if err != nil {
@@ -271,18 +257,14 @@ func archiveFileVisitor(dir string, tempFile *string, signature *[]byte, filenam
 	var err error
 	switch filename {
 	case "syncthing", "syncthing.exe":
-		if debug {
-			l.Debugln("reading binary")
-		}
+		l.Debugln("reading binary")
 		*tempFile, err = writeBinary(dir, filedata)
 		if err != nil {
 			return err
 		}
 
 	case "syncthing.sig", "syncthing.exe.sig":
-		if debug {
-			l.Debugln("reading signature")
-		}
+		l.Debugln("reading signature")
 		*signature, err = ioutil.ReadAll(filedata)
 		if err != nil {
 			return err
@@ -300,9 +282,7 @@ func verifyUpgrade(tempName string, sig []byte) error {
 		return fmt.Errorf("no signature found")
 	}
 
-	if debug {
-		l.Debugf("checking signature\n%s", sig)
-	}
+	l.Debugf("checking signature\n%s", sig)
 
 	fd, err := os.Open(tempName)
 	if err != nil {

lib/upnp/debug.go

@@ -10,10 +10,17 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "upnp") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("upnp", "UPnP discovery and port mapping")
 )
+
+func init() {
+	l.SetDebug("upnp", strings.Contains(os.Getenv("STTRACE"), "upnp") || os.Getenv("STTRACE") == "all")
+}
+
+func shouldDebug() bool {
+	return l.ShouldDebug("upnp")
+}

lib/upnp/upnp.go

@@ -129,7 +129,7 @@ nextResult:
 	for result := range resultChan {
 		for _, existingResult := range results {
 			if existingResult.uuid == result.uuid {
-				if debug {
+				if shouldDebug() {
 					l.Debugf("Skipping duplicate result %s with services:", result.uuid)
 					for _, svc := range result.services {
 						l.Debugf("* [%s] %s", svc.serviceID, svc.serviceURL)
@@ -140,7 +140,7 @@ nextResult:
 		}
 
 		results = append(results, result)
-		if debug {
+		if shouldDebug() {
 			l.Debugf("UPnP discovery result %s with services:", result.uuid)
 			for _, svc := range result.services {
 				l.Debugf("* [%s] %s", svc.serviceID, svc.serviceURL)
@@ -167,15 +167,11 @@ Mx: %d
 
 	search := []byte(strings.Replace(searchStr, "\n", "\r\n", -1))
 
-	if debug {
-		l.Debugln("Starting discovery of device type " + deviceType + " on " + intf.Name)
-	}
+	l.Debugln("Starting discovery of device type", deviceType, "on", intf.Name)
 
 	socket, err := net.ListenMulticastUDP("udp4", intf, &net.UDPAddr{IP: ssdp.IP})
 	if err != nil {
-		if debug {
-			l.Debugln(err)
-		}
+		l.Debugln(err)
 		return
 	}
 	defer socket.Close() // Make sure our socket gets closed
@@ -186,9 +182,7 @@ Mx: %d
 		return
 	}
 
-	if debug {
-		l.Debugln("Sending search request for device type " + deviceType + " on " + intf.Name)
-	}
+	l.Debugln("Sending search request for device type", deviceType, "on", intf.Name)
 
 	_, err = socket.WriteTo(search, ssdp)
 	if err != nil {
@@ -196,9 +190,7 @@ Mx: %d
 		return
 	}
 
-	if debug {
-		l.Debugln("Listening for UPnP response for device type " + deviceType + " on " + intf.Name)
-	}
+	l.Debugln("Listening for UPnP response for device type", deviceType, "on", intf.Name)
 
 	// Listen for responses until a timeout is reached
 	for {
@@ -217,15 +209,11 @@ Mx: %d
 		}
 		results <- igd
 	}
-	if debug {
-		l.Debugln("Discovery for device type " + deviceType + " on " + intf.Name + " finished.")
-	}
+	l.Debugln("Discovery for device type", deviceType, "on", intf.Name, "finished.")
 }
 
 func parseResponse(deviceType string, resp []byte) (IGD, error) {
-	if debug {
-		l.Debugln("Handling UPnP response:\n\n" + string(resp))
-	}
+	l.Debugln("Handling UPnP response:\n\n" + string(resp))
 
 	reader := bufio.NewReader(bytes.NewBuffer(resp))
 	request := &http.Request{}
@@ -368,7 +356,7 @@ func getIGDServices(rootURL string, device upnpDevice, wanDeviceURN string, wanC
 	devices := getChildDevices(device, wanDeviceURN)
 
 	if len(devices) < 1 {
-		l.Infoln("[" + rootURL + "] Malformed InternetGatewayDevice description: no WANDevices specified.")
+		l.Infoln(rootURL, "- malformed InternetGatewayDevice description: no WANDevices specified.")
 		return result
 	}
 
@@ -376,27 +364,23 @@ func getIGDServices(rootURL string, device upnpDevice, wanDeviceURN string, wanC
 		connections := getChildDevices(device, wanConnectionURN)
 
 		if len(connections) < 1 {
-			l.Infoln("[" + rootURL + "] Malformed " + wanDeviceURN + " description: no WANConnectionDevices specified.")
+			l.Infoln(rootURL, "- malformed ", wanDeviceURN, "description: no WANConnectionDevices specified.")
 		}
 
 		for _, connection := range connections {
 			for _, serviceURN := range serviceURNs {
 				services := getChildServices(connection, serviceURN)
 
-				if len(services) < 1 && debug {
-					l.Debugln("[" + rootURL + "] No services of type " + serviceURN + " found on connection.")
-				}
+				l.Debugln(rootURL, "- no services of type", serviceURN, " found on connection.")
 
 				for _, service := range services {
 					if len(service.ControlURL) == 0 {
-						l.Infoln("[" + rootURL + "] Malformed " + service.ServiceType + " description: no control URL.")
+						l.Infoln(rootURL+"- malformed", service.ServiceType, "description: no control URL.")
 					} else {
 						u, _ := url.Parse(rootURL)
 						replaceRawPath(u, service.ControlURL)
 
-						if debug {
-							l.Debugln("[" + rootURL + "] Found " + service.ServiceType + " with URL " + u.String())
-						}
+						l.Debugln(rootURL, "- found", service.ServiceType, "with URL", u)
 
 						service := IGDService{serviceID: service.ServiceID, serviceURL: u.String(), serviceURN: service.ServiceType}
 
@@ -456,24 +440,18 @@ func soapRequest(url, service, function, message string) ([]byte, error) {
 	req.Header.Set("Cache-Control", "no-cache")
 	req.Header.Set("Pragma", "no-cache")
 
-	if debug {
-		l.Debugln("SOAP Request URL: " + url)
-		l.Debugln("SOAP Action: " + req.Header.Get("SOAPAction"))
-		l.Debugln("SOAP Request:\n\n" + body)
-	}
+	l.Debugln("SOAP Request URL: " + url)
+	l.Debugln("SOAP Action: " + req.Header.Get("SOAPAction"))
+	l.Debugln("SOAP Request:\n\n" + body)
 
 	r, err := http.DefaultClient.Do(req)
 	if err != nil {
-		if debug {
-			l.Debugln(err)
-		}
+		l.Debugln(err)
 		return resp, err
 	}
 
 	resp, _ = ioutil.ReadAll(r.Body)
-	if debug {
-		l.Debugf("SOAP Response: %v\n\n%v\n\n", r.StatusCode, string(resp))
-	}
+	l.Debugf("SOAP Response: %s\n\n%s\n\n", r.Status, resp)
 
 	r.Body.Close()
 

lib/versioner/debug.go

@@ -10,10 +10,13 @@ import (
 	"os"
 	"strings"
 
-	"github.com/calmh/logger"
+	"github.com/syncthing/syncthing/lib/logger"
 )
 
 var (
-	debug = strings.Contains(os.Getenv("STTRACE"), "versioner") || os.Getenv("STTRACE") == "all"
-	l     = logger.DefaultLogger
+	l = logger.DefaultLogger.NewFacility("versioner", "File versioning")
 )
+
+func init() {
+	l.SetDebug("versioner", strings.Contains(os.Getenv("STTRACE"), "versioner") || os.Getenv("STTRACE") == "all")
+}

lib/versioner/external.go

@@ -34,9 +34,7 @@ func NewExternal(folderID, folderPath string, params map[string]string) Versione
 		folderPath: folderPath,
 	}
 
-	if debug {
-		l.Debugf("instantiated %#v", s)
-	}
+	l.Debugf("instantiated %#v", s)
 	return s
 }
 
@@ -45,17 +43,13 @@ func NewExternal(folderID, folderPath string, params map[string]string) Versione
 func (v External) Archive(filePath string) error {
 	_, err := osutil.Lstat(filePath)
 	if os.IsNotExist(err) {
-		if debug {
-			l.Debugln("not archiving nonexistent file", filePath)
-		}
+		l.Debugln("not archiving nonexistent file", filePath)
 		return nil
 	} else if err != nil {
 		return err
 	}
 
-	if debug {
-		l.Debugln("archiving", filePath)
-	}
+	l.Debugln("archiving", filePath)
 
 	inFolderPath, err := filepath.Rel(v.folderPath, filePath)
 	if err != nil {

lib/versioner/simple.go

@@ -35,9 +35,7 @@ func NewSimple(folderID, folderPath string, params map[string]string) Versioner
 		folderPath: folderPath,
 	}
 
-	if debug {
-		l.Debugf("instantiated %#v", s)
-	}
+	l.Debugf("instantiated %#v", s)
 	return s
 }
 
@@ -46,9 +44,7 @@ func NewSimple(folderID, folderPath string, params map[string]string) Versioner
 func (v Simple) Archive(filePath string) error {
 	fileInfo, err := osutil.Lstat(filePath)
 	if os.IsNotExist(err) {
-		if debug {
-			l.Debugln("not archiving nonexistent file", filePath)
-		}
+		l.Debugln("not archiving nonexistent file", filePath)
 		return nil
 	} else if err != nil {
 		return err
@@ -58,9 +54,7 @@ func (v Simple) Archive(filePath string) error {
 	_, err = os.Stat(versionsDir)
 	if err != nil {
 		if os.IsNotExist(err) {
-			if debug {
-				l.Debugln("creating versions dir", versionsDir)
-			}
+			l.Debugln("creating versions dir", versionsDir)
 			osutil.MkdirAll(versionsDir, 0755)
 			osutil.HideFile(versionsDir)
 		} else {
@@ -68,9 +62,7 @@ func (v Simple) Archive(filePath string) error {
 		}
 	}
 
-	if debug {
-		l.Debugln("archiving", filePath)
-	}
+	l.Debugln("archiving", filePath)
 
 	file := filepath.Base(filePath)
 	inFolderPath, err := filepath.Rel(v.folderPath, filepath.Dir(filePath))
@@ -86,9 +78,7 @@ func (v Simple) Archive(filePath string) error {
 
 	ver := taggedFilename(file, fileInfo.ModTime().Format(TimeFormat))
 	dst := filepath.Join(dir, ver)
-	if debug {
-		l.Debugln("moving to", dst)
-	}
+	l.Debugln("moving to", dst)
 	err = osutil.Rename(filePath, dst)
 	if err != nil {
 		return err
@@ -114,9 +104,7 @@ func (v Simple) Archive(filePath string) error {
 
 	if len(versions) > v.keep {
 		for _, toRemove := range versions[:len(versions)-v.keep] {
-			if debug {
-				l.Debugln("cleaning out", toRemove)
-			}
+			l.Debugln("cleaning out", toRemove)
 			err = os.Remove(toRemove)
 			if err != nil {
 				l.Warnln("removing old version:", err)

lib/versioner/staggered.go

@@ -47,14 +47,10 @@ func NewStaggered(folderID, folderPath string, params map[string]string) Version
 	// Use custom path if set, otherwise .stversions in folderPath
 	var versionsDir string
 	if params["versionsPath"] == "" {
-		if debug {
-			l.Debugln("using default dir .stversions")
-		}
+		l.Debugln("using default dir .stversions")
 		versionsDir = filepath.Join(folderPath, ".stversions")
 	} else {
-		if debug {
-			l.Debugln("using dir", params["versionsPath"])
-		}
+		l.Debugln("using dir", params["versionsPath"])
 		versionsDir = params["versionsPath"]
 	}
 
@@ -71,9 +67,7 @@ func NewStaggered(folderID, folderPath string, params map[string]string) Version
 		mutex: sync.NewMutex(),
 	}
 
-	if debug {
-		l.Debugf("instantiated %#v", s)
-	}
+	l.Debugf("instantiated %#v", s)
 
 	go func() {
 		s.clean()
@@ -86,14 +80,10 @@ func NewStaggered(folderID, folderPath string, params map[string]string) Version
 }
 
 func (v Staggered) clean() {
-	if debug {
-		l.Debugln("Versioner clean: Waiting for lock on", v.versionsPath)
-	}
+	l.Debugln("Versioner clean: Waiting for lock on", v.versionsPath)
 	v.mutex.Lock()
 	defer v.mutex.Unlock()
-	if debug {
-		l.Debugln("Versioner clean: Cleaning", v.versionsPath)
-	}
+	l.Debugln("Versioner clean: Cleaning", v.versionsPath)
 
 	if _, err := os.Stat(v.versionsPath); os.IsNotExist(err) {
 		// There is no need to clean a nonexistent dir.
@@ -144,30 +134,22 @@ func (v Staggered) clean() {
 		}
 
 		if path == v.versionsPath {
-			if debug {
-				l.Debugln("Cleaner: versions dir is empty, don't delete", path)
-			}
+			l.Debugln("Cleaner: versions dir is empty, don't delete", path)
 			continue
 		}
 
-		if debug {
-			l.Debugln("Cleaner: deleting empty directory", path)
-		}
+		l.Debugln("Cleaner: deleting empty directory", path)
 		err = os.Remove(path)
 		if err != nil {
 			l.Warnln("Versioner: can't remove directory", path, err)
 		}
 	}
 
-	if debug {
-		l.Debugln("Cleaner: Finished cleaning", v.versionsPath)
-	}
+	l.Debugln("Cleaner: Finished cleaning", v.versionsPath)
 }
 
 func (v Staggered) expire(versions []string) {
-	if debug {
-		l.Debugln("Versioner: Expiring versions", versions)
-	}
+	l.Debugln("Versioner: Expiring versions", versions)
 	var prevAge int64
 	firstFile := true
 	for _, file := range versions {
@@ -185,18 +167,14 @@ func (v Staggered) expire(versions []string) {
 		loc, _ := time.LoadLocation("Local")
 		versionTime, err := time.ParseInLocation(TimeFormat, filenameTag(file), loc)
 		if err != nil {
-			if debug {
-				l.Debugf("Versioner: file name %q is invalid: %v", file, err)
-			}
+			l.Debugf("Versioner: file name %q is invalid: %v", file, err)
 			continue
 		}
 		age := int64(time.Since(versionTime).Seconds())
 
 		// If the file is older than the max age of the last interval, remove it
 		if lastIntv := v.interval[len(v.interval)-1]; lastIntv.end > 0 && age > lastIntv.end {
-			if debug {
-				l.Debugln("Versioner: File over maximum age -> delete ", file)
-			}
+			l.Debugln("Versioner: File over maximum age -> delete ", file)
 			err = os.Remove(file)
 			if err != nil {
 				l.Warnf("Versioner: can't remove %q: %v", file, err)
@@ -220,9 +198,7 @@ func (v Staggered) expire(versions []string) {
 		}
 
 		if prevAge-age < usedInterval.step {
-			if debug {
-				l.Debugln("too many files in step -> delete", file)
-			}
+			l.Debugln("too many files in step -> delete", file)
 			err = os.Remove(file)
 			if err != nil {
 				l.Warnf("Versioner: can't remove %q: %v", file, err)
@@ -237,17 +213,13 @@ func (v Staggered) expire(versions []string) {
 // Archive moves the named file away to a version archive. If this function
 // returns nil, the named file does not exist any more (has been archived).
 func (v Staggered) Archive(filePath string) error {
-	if debug {
-		l.Debugln("Waiting for lock on ", v.versionsPath)
-	}
+	l.Debugln("Waiting for lock on ", v.versionsPath)
 	v.mutex.Lock()
 	defer v.mutex.Unlock()
 
 	_, err := osutil.Lstat(filePath)
 	if os.IsNotExist(err) {
-		if debug {
-			l.Debugln("not archiving nonexistent file", filePath)
-		}
+		l.Debugln("not archiving nonexistent file", filePath)
 		return nil
 	} else if err != nil {
 		return err
@@ -255,9 +227,7 @@ func (v Staggered) Archive(filePath string) error {
 
 	if _, err := os.Stat(v.versionsPath); err != nil {
 		if os.IsNotExist(err) {
-			if debug {
-				l.Debugln("creating versions dir", v.versionsPath)
-			}
+			l.Debugln("creating versions dir", v.versionsPath)
 			osutil.MkdirAll(v.versionsPath, 0755)
 			osutil.HideFile(v.versionsPath)
 		} else {
@@ -265,9 +235,7 @@ func (v Staggered) Archive(filePath string) error {
 		}
 	}
 
-	if debug {
-		l.Debugln("archiving", filePath)
-	}
+	l.Debugln("archiving", filePath)
 
 	file := filepath.Base(filePath)
 	inFolderPath, err := filepath.Rel(v.folderPath, filepath.Dir(filePath))
@@ -283,9 +251,7 @@ func (v Staggered) Archive(filePath string) error {
 
 	ver := taggedFilename(file, time.Now().Format(TimeFormat))
 	dst := filepath.Join(dir, ver)
-	if debug {
-		l.Debugln("moving to", dst)
-	}
+	l.Debugln("moving to", dst)
 	err = osutil.Rename(filePath, dst)
 	if err != nil {
 		return err

lib/versioner/trashcan.go

@@ -37,9 +37,7 @@ func NewTrashcan(folderID, folderPath string, params map[string]string) Versione
 		stop:         make(chan struct{}),
 	}
 
-	if debug {
-		l.Debugf("instantiated %#v", s)
-	}
+	l.Debugf("instantiated %#v", s)
 	return s
 }
 
@@ -48,9 +46,7 @@ func NewTrashcan(folderID, folderPath string, params map[string]string) Versione
 func (t *Trashcan) Archive(filePath string) error {
 	_, err := osutil.Lstat(filePath)
 	if os.IsNotExist(err) {
-		if debug {
-			l.Debugln("not archiving nonexistent file", filePath)
-		}
+		l.Debugln("not archiving nonexistent file", filePath)
 		return nil
 	} else if err != nil {
 		return err
@@ -62,18 +58,14 @@ func (t *Trashcan) Archive(filePath string) error {
 			return err
 		}
 
-		if debug {
-			l.Debugln("creating versions dir", versionsDir)
-		}
+		l.Debugln("creating versions dir", versionsDir)
 		if err := osutil.MkdirAll(versionsDir, 0777); err != nil {
 			return err
 		}
 		osutil.HideFile(versionsDir)
 	}
 
-	if debug {
-		l.Debugln("archiving", filePath)
-	}
+	l.Debugln("archiving", filePath)
 
 	relativePath, err := filepath.Rel(t.folderPath, filePath)
 	if err != nil {
@@ -85,9 +77,7 @@ func (t *Trashcan) Archive(filePath string) error {
 		return err
 	}
 
-	if debug {
-		l.Debugln("moving to", archivedPath)
-	}
+	l.Debugln("moving to", archivedPath)
 
 	if err := osutil.Rename(filePath, archivedPath); err != nil {
 		return err
@@ -102,10 +92,8 @@ func (t *Trashcan) Archive(filePath string) error {
 }
 
 func (t *Trashcan) Serve() {
-	if debug {
-		l.Debugln(t, "starting")
-		defer l.Debugln(t, "stopping")
-	}
+	l.Debugln(t, "starting")
+	defer l.Debugln(t, "stopping")
 
 	// Do the first cleanup one minute after startup.
 	timer := time.NewTimer(time.Minute)

man/refresh.sh

@@ -1,7 +1,20 @@
 #!/bin/sh
 
 base=http://docs.syncthing.net/man/
-pages=(syncthing-config.5 syncthing-device-ids.7 syncthing-event-api.7 syncthing-faq.7 syncthing-networking.7 syncthing-rest-api.7 syncthing-security.7 syncthing-stignore.5 syncthing-versioning.7 syncthing.1)
+pages=(
+	syncthing.1
+	syncthing-config.5
+	syncthing-stignore.5
+	syncthing-device-ids.7
+	syncthing-event-api.7
+	syncthing-faq.7
+	syncthing-networking.7
+	syncthing-rest-api.7
+	syncthing-security.7
+	syncthing-versioning.7
+	syncthing-bep.7
+	syncthing-localdisco.7
+)
 
 for page in "${pages[@]}" ; do
 	curl -sLO "$base$page"