all: Refactor cmd/syncthing creating lib/syncthing (ref #4085) (#5805)

* add skeleton for lib/syncthing

* copy syncthingMain to lib/syncthing (verbatim)

* Remove code to deduplicate copies of syncthingMain

* fix simple build errors

* move stuff from main to syncthing with minimal mod

* merge runtime options

* actually use syncthing.App

* pass io.writer to lib/syncthing for auditing

* get rid of env stuff in lib/syncthing

* add .Error() and comments

* review: Remove fs interactions from lib

* and go 1.13 happened

* utility functions

lib/syncthing/auditservice.go

@@ -0,0 +1,69 @@
+// 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 https://mozilla.org/MPL/2.0/.
+
+package syncthing
+
+import (
+	"encoding/json"
+	"io"
+
+	"github.com/syncthing/syncthing/lib/events"
+)
+
+// The auditService subscribes to events and writes these in JSON format, one
+// event per line, to the specified writer.
+type auditService struct {
+	w       io.Writer     // audit destination
+	stop    chan struct{} // signals time to stop
+	started chan struct{} // signals startup complete
+	stopped chan struct{} // signals stop complete
+}
+
+func newAuditService(w io.Writer) *auditService {
+	return &auditService{
+		w:       w,
+		stop:    make(chan struct{}),
+		started: make(chan struct{}),
+		stopped: make(chan struct{}),
+	}
+}
+
+// Serve runs the audit service.
+func (s *auditService) Serve() {
+	defer close(s.stopped)
+	sub := events.Default.Subscribe(events.AllEvents)
+	defer events.Default.Unsubscribe(sub)
+	enc := json.NewEncoder(s.w)
+
+	// We're ready to start processing events.
+	close(s.started)
+
+	for {
+		select {
+		case ev := <-sub.C():
+			enc.Encode(ev)
+		case <-s.stop:
+			return
+		}
+	}
+}
+
+// Stop stops the audit service.
+func (s *auditService) Stop() {
+	close(s.stop)
+}
+
+// WaitForStart returns once the audit service is ready to receive events, or
+// immediately if it's already running.
+func (s *auditService) WaitForStart() {
+	<-s.started
+}
+
+// WaitForStop returns once the audit service has stopped.
+// (Needed by the tests.)
+func (s *auditService) WaitForStop() {
+	<-s.stopped
+}

lib/syncthing/auditservice_test.go

@@ -0,0 +1,54 @@
+// 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 https://mozilla.org/MPL/2.0/.
+
+package syncthing
+
+import (
+	"bytes"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/syncthing/syncthing/lib/events"
+)
+
+func TestAuditService(t *testing.T) {
+	buf := new(bytes.Buffer)
+	service := newAuditService(buf)
+
+	// Event sent before start, will not be logged
+	events.Default.Log(events.ConfigSaved, "the first event")
+
+	go service.Serve()
+	service.WaitForStart()
+
+	// Event that should end up in the audit log
+	events.Default.Log(events.ConfigSaved, "the second event")
+
+	// We need to give the events time to arrive, since the channels are buffered etc.
+	time.Sleep(10 * time.Millisecond)
+
+	service.Stop()
+	service.WaitForStop()
+
+	// This event should not be logged, since we have stopped.
+	events.Default.Log(events.ConfigSaved, "the third event")
+
+	result := buf.String()
+	t.Log(result)
+
+	if strings.Contains(result, "first event") {
+		t.Error("Unexpected first event")
+	}
+
+	if !strings.Contains(result, "second event") {
+		t.Error("Missing second event")
+	}
+
+	if strings.Contains(result, "third event") {
+		t.Error("Missing third event")
+	}
+}

lib/syncthing/cpuusage.go

@@ -0,0 +1,59 @@
+// Copyright (C) 2017 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 https://mozilla.org/MPL/2.0/.
+
+package syncthing
+
+import (
+	"math"
+	"time"
+
+	metrics "github.com/rcrowley/go-metrics"
+)
+
+const cpuTickRate = 5 * time.Second
+
+type cpuService struct {
+	avg  metrics.EWMA
+	stop chan struct{}
+}
+
+func newCPUService() *cpuService {
+	return &cpuService{
+		// 10 second average. Magic alpha value comes from looking at EWMA package
+		// definitions of EWMA1, EWMA5. The tick rate *must* be five seconds (hard
+		// coded in the EWMA package).
+		avg:  metrics.NewEWMA(1 - math.Exp(-float64(cpuTickRate)/float64(time.Second)/10.0)),
+		stop: make(chan struct{}),
+	}
+}
+
+func (s *cpuService) Serve() {
+	// Initialize prevUsage to an actual value returned by cpuUsage
+	// instead of zero, because at least Windows returns a huge negative
+	// number here that then slowly increments...
+	prevUsage := cpuUsage()
+	ticker := time.NewTicker(cpuTickRate)
+	defer ticker.Stop()
+	for {
+		select {
+		case <-ticker.C:
+			curUsage := cpuUsage()
+			s.avg.Update(int64((curUsage - prevUsage) / time.Millisecond))
+			prevUsage = curUsage
+			s.avg.Tick()
+		case <-s.stop:
+			return
+		}
+	}
+}
+
+func (s *cpuService) Stop() {
+	close(s.stop)
+}
+
+func (s *cpuService) Rate() float64 {
+	return s.avg.Rate()
+}

lib/syncthing/cpuusage_solaris.go

@@ -0,0 +1,78 @@
+// Copyright (C) 2014 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 https://mozilla.org/MPL/2.0/.
+
+//+build solaris
+
+package syncthing
+
+import (
+	"encoding/binary"
+	"fmt"
+	"os"
+	"time"
+)
+
+type id_t int32
+type ulong_t uint32
+
+type timestruc_t struct {
+	Tv_sec  int64
+	Tv_nsec int64
+}
+
+func (tv timestruc_t) Nano() int64 {
+	return tv.Tv_sec*1e9 + tv.Tv_nsec
+}
+
+type prusage_t struct {
+	Pr_lwpid    id_t        /* lwp id.  0: process or defunct */
+	Pr_count    int32       /* number of contributing lwps */
+	Pr_tstamp   timestruc_t /* real time stamp, time of read() */
+	Pr_create   timestruc_t /* process/lwp creation time stamp */
+	Pr_term     timestruc_t /* process/lwp termination time stamp */
+	Pr_rtime    timestruc_t /* total lwp real (elapsed) time */
+	Pr_utime    timestruc_t /* user level CPU time */
+	Pr_stime    timestruc_t /* system call CPU time */
+	Pr_ttime    timestruc_t /* other system trap CPU time */
+	Pr_tftime   timestruc_t /* text page fault sleep time */
+	Pr_dftime   timestruc_t /* data page fault sleep time */
+	Pr_kftime   timestruc_t /* kernel page fault sleep time */
+	Pr_ltime    timestruc_t /* user lock wait sleep time */
+	Pr_slptime  timestruc_t /* all other sleep time */
+	Pr_wtime    timestruc_t /* wait-cpu (latency) time */
+	Pr_stoptime timestruc_t /* stopped time */
+	Pr_minf     ulong_t     /* minor page faults */
+	Pr_majf     ulong_t     /* major page faults */
+	Pr_nswap    ulong_t     /* swaps */
+	Pr_inblk    ulong_t     /* input blocks */
+	Pr_oublk    ulong_t     /* output blocks */
+	Pr_msnd     ulong_t     /* messages sent */
+	Pr_mrcv     ulong_t     /* messages received */
+	Pr_sigs     ulong_t     /* signals received */
+	Pr_vctx     ulong_t     /* voluntary context switches */
+	Pr_ictx     ulong_t     /* involuntary context switches */
+	Pr_sysc     ulong_t     /* system calls */
+	Pr_ioch     ulong_t     /* chars read and written */
+
+}
+
+var procFile = fmt.Sprintf("/proc/%d/usage", os.Getpid())
+
+func cpuUsage() time.Duration {
+	fd, err := os.Open(procFile)
+	if err != nil {
+		return 0
+	}
+
+	var rusage prusage_t
+	err = binary.Read(fd, binary.LittleEndian, rusage)
+	fd.Close()
+	if err != nil {
+		return 0
+	}
+
+	return time.Duration(rusage.Pr_utime.Nano() + rusage.Pr_stime.Nano())
+}

lib/syncthing/cpuusage_unix.go

@@ -0,0 +1,18 @@
+// Copyright (C) 2014 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 https://mozilla.org/MPL/2.0/.
+
+//+build !windows,!solaris
+
+package syncthing
+
+import "syscall"
+import "time"
+
+func cpuUsage() time.Duration {
+	var rusage syscall.Rusage
+	syscall.Getrusage(syscall.RUSAGE_SELF, &rusage)
+	return time.Duration(rusage.Utime.Nano() + rusage.Stime.Nano())
+}

lib/syncthing/cpuusage_windows.go

@@ -0,0 +1,27 @@
+// Copyright (C) 2014 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 https://mozilla.org/MPL/2.0/.
+
+//+build windows
+
+package syncthing
+
+import "syscall"
+import "time"
+
+func cpuUsage() time.Duration {
+	handle, err := syscall.GetCurrentProcess()
+	if err != nil {
+		return 0
+	}
+	defer syscall.CloseHandle(handle)
+
+	var ctime, etime, ktime, utime syscall.Filetime
+	if err := syscall.GetProcessTimes(handle, &ctime, &etime, &ktime, &utime); err != nil {
+		return 0
+	}
+
+	return time.Duration(ktime.Nanoseconds() + utime.Nanoseconds())
+}

lib/syncthing/debug.go

@@ -0,0 +1,22 @@
+// Copyright (C) 2014 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 https://mozilla.org/MPL/2.0/.
+
+package syncthing
+
+import (
+	"os"
+	"strings"
+
+	"github.com/syncthing/syncthing/lib/logger"
+)
+
+var (
+	l = logger.DefaultLogger.NewFacility("app", "Main run facility")
+)
+
+func init() {
+	l.SetDebug("app", strings.Contains(os.Getenv("STTRACE"), "app") || os.Getenv("STTRACE") == "all")
+}

lib/syncthing/superuser_unix.go

@@ -0,0 +1,17 @@
+// Copyright (C) 2017 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 https://mozilla.org/MPL/2.0/.
+
+// +build !windows
+
+package syncthing
+
+import (
+	"os"
+)
+
+func isSuperUser() bool {
+	return os.Geteuid() == 0
+}

lib/syncthing/superuser_windows.go

@@ -0,0 +1,41 @@
+// Copyright (C) 2017 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 https://mozilla.org/MPL/2.0/.
+
+package syncthing
+
+import "syscall"
+
+// https://msdn.microsoft.com/en-us/library/windows/desktop/aa379649(v=vs.85).aspx
+const securityLocalSystemRID = "S-1-5-18"
+
+func isSuperUser() bool {
+	tok, err := syscall.OpenCurrentProcessToken()
+	if err != nil {
+		l.Debugln("OpenCurrentProcessToken:", err)
+		return false
+	}
+	defer tok.Close()
+
+	user, err := tok.GetTokenUser()
+	if err != nil {
+		l.Debugln("GetTokenUser:", err)
+		return false
+	}
+
+	if user.User.Sid == nil {
+		l.Debugln("sid is nil")
+		return false
+	}
+
+	sid, err := user.User.Sid.String()
+	if err != nil {
+		l.Debugln("Sid.String():", err)
+		return false
+	}
+
+	l.Debugf("SID: %q", sid)
+	return sid == securityLocalSystemRID
+}

lib/syncthing/syncthing.go

@@ -0,0 +1,496 @@
+// Copyright (C) 2014 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 https://mozilla.org/MPL/2.0/.
+
+package syncthing
+
+import (
+	"crypto/tls"
+	"fmt"
+	"io"
+	"net/http"
+	"runtime"
+	"strings"
+	"sync"
+	"time"
+
+	"github.com/syncthing/syncthing/lib/api"
+	"github.com/syncthing/syncthing/lib/build"
+	"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/locations"
+	"github.com/syncthing/syncthing/lib/logger"
+	"github.com/syncthing/syncthing/lib/model"
+	"github.com/syncthing/syncthing/lib/osutil"
+	"github.com/syncthing/syncthing/lib/protocol"
+	"github.com/syncthing/syncthing/lib/rand"
+	"github.com/syncthing/syncthing/lib/sha256"
+	"github.com/syncthing/syncthing/lib/tlsutil"
+	"github.com/syncthing/syncthing/lib/ur"
+
+	"github.com/thejerf/suture"
+)
+
+const (
+	bepProtocolName      = "bep/1.0"
+	tlsDefaultCommonName = "syncthing"
+	maxSystemErrors      = 5
+	initialSystemLog     = 10
+	maxSystemLog         = 250
+)
+
+type ExitStatus int
+
+const (
+	ExitSuccess ExitStatus = 0
+	ExitError   ExitStatus = 1
+	ExitRestart ExitStatus = 3
+	ExitUpgrade ExitStatus = 4
+)
+
+type Options struct {
+	AssetDir         string
+	AuditWriter      io.Writer
+	DeadlockTimeoutS int
+	NoUpgrade        bool
+	ProfilerURL      string
+	ResetDeltaIdxs   bool
+	Verbose          bool
+}
+
+type App struct {
+	myID        protocol.DeviceID
+	mainService *suture.Supervisor
+	cfg         config.Wrapper
+	ll          *db.Lowlevel
+	cert        tls.Certificate
+	opts        Options
+	exitStatus  ExitStatus
+	err         error
+	startOnce   sync.Once
+	stop        chan struct{}
+	stopped     chan struct{}
+}
+
+func New(cfg config.Wrapper, ll *db.Lowlevel, cert tls.Certificate, opts Options) *App {
+	return &App{
+		cfg:     cfg,
+		ll:      ll,
+		opts:    opts,
+		cert:    cert,
+		stop:    make(chan struct{}),
+		stopped: make(chan struct{}),
+	}
+}
+
+// Run does the same as start, but then does not return until the app stops. It
+// is equivalent to calling Start and then Wait.
+func (a *App) Run() ExitStatus {
+	a.Start()
+	return a.Wait()
+}
+
+// Start executes the app and returns once all the startup operations are done,
+// e.g. the API is ready for use.
+func (a *App) Start() {
+	a.startOnce.Do(func() {
+		if err := a.startup(); err != nil {
+			close(a.stop)
+			a.exitStatus = ExitError
+			a.err = err
+			close(a.stopped)
+			return
+		}
+		go a.run()
+	})
+}
+
+func (a *App) startup() error {
+	// Create a main service manager. We'll add things to this as we go along.
+	// We want any logging it does to go through our log system.
+	a.mainService = suture.New("main", suture.Spec{
+		Log: func(line string) {
+			l.Debugln(line)
+		},
+		PassThroughPanics: true,
+	})
+	a.mainService.ServeBackground()
+
+	// Set a log prefix similar to the ID we will have later on, or early log
+	// lines look ugly.
+	l.SetPrefix("[start] ")
+
+	if a.opts.AuditWriter != nil {
+		a.startAuditing()
+	}
+
+	if a.opts.Verbose {
+		a.mainService.Add(newVerboseService())
+	}
+
+	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. The LocalChangeDetected event might overwhelm the event
+	// receiver in some situations so we will not subscribe to it here.
+	defaultSub := events.NewBufferedSubscription(events.Default.Subscribe(api.DefaultEventMask), api.EventSubBufferSize)
+	diskSub := events.NewBufferedSubscription(events.Default.Subscribe(api.DiskEventMask), api.EventSubBufferSize)
+
+	// Attempt to increase the limit on number of open files to the maximum
+	// allowed, in case we have many peers. We don't really care enough to
+	// report the error if there is one.
+	osutil.MaximizeOpenFileLimit()
+
+	a.myID = protocol.NewDeviceID(a.cert.Certificate[0])
+	l.SetPrefix(fmt.Sprintf("[%s] ", a.myID.String()[:5]))
+
+	l.Infoln(build.LongVersion)
+	l.Infoln("My ID:", a.myID)
+
+	// Select SHA256 implementation and report. Affected by the
+	// STHASHING environment variable.
+	sha256.SelectAlgo()
+	sha256.Report()
+
+	// Emit the Starting event, now that we know who we are.
+
+	events.Default.Log(events.Starting, map[string]string{
+		"home": locations.GetBaseDir(locations.ConfigBaseDir),
+		"myID": a.myID.String(),
+	})
+
+	if err := checkShortIDs(a.cfg); err != nil {
+		l.Warnln("Short device IDs are in conflict. Unlucky!\n  Regenerate the device ID of one of the following:\n  ", err)
+		return err
+	}
+
+	if len(a.opts.ProfilerURL) > 0 {
+		go func() {
+			l.Debugln("Starting profiler on", a.opts.ProfilerURL)
+			runtime.SetBlockProfileRate(1)
+			err := http.ListenAndServe(a.opts.ProfilerURL, nil)
+			if err != nil {
+				l.Warnln(err)
+				return
+			}
+		}()
+	}
+
+	perf := ur.CpuBench(3, 150*time.Millisecond, true)
+	l.Infof("Hashing performance is %.02f MB/s", perf)
+
+	if err := db.UpdateSchema(a.ll); err != nil {
+		l.Warnln("Database schema:", err)
+		return err
+	}
+
+	if a.opts.ResetDeltaIdxs {
+		l.Infoln("Reinitializing delta index IDs")
+		db.DropDeltaIndexIDs(a.ll)
+	}
+
+	protectedFiles := []string{
+		locations.Get(locations.Database),
+		locations.Get(locations.ConfigFile),
+		locations.Get(locations.CertFile),
+		locations.Get(locations.KeyFile),
+	}
+
+	// Remove database entries for folders that no longer exist in the config
+	folders := a.cfg.Folders()
+	for _, folder := range a.ll.ListFolders() {
+		if _, ok := folders[folder]; !ok {
+			l.Infof("Cleaning data for dropped folder %q", folder)
+			db.DropFolder(a.ll, folder)
+		}
+	}
+
+	// Grab the previously running version string from the database.
+
+	miscDB := db.NewMiscDataNamespace(a.ll)
+	prevVersion, _ := miscDB.String("prevVersion")
+
+	// Strip away prerelease/beta stuff and just compare the release
+	// numbers. 0.14.44 to 0.14.45-banana is an upgrade, 0.14.45-banana to
+	// 0.14.45-pineapple is not.
+
+	prevParts := strings.Split(prevVersion, "-")
+	curParts := strings.Split(build.Version, "-")
+	if prevParts[0] != curParts[0] {
+		if prevVersion != "" {
+			l.Infoln("Detected upgrade from", prevVersion, "to", build.Version)
+		}
+
+		// Drop delta indexes in case we've changed random stuff we
+		// shouldn't have. We will resend our index on next connect.
+		db.DropDeltaIndexIDs(a.ll)
+
+		// Remember the new version.
+		miscDB.PutString("prevVersion", build.Version)
+	}
+
+	m := model.NewModel(a.cfg, a.myID, "syncthing", build.Version, a.ll, protectedFiles)
+
+	if a.opts.DeadlockTimeoutS > 0 {
+		m.StartDeadlockDetector(time.Duration(a.opts.DeadlockTimeoutS) * time.Second)
+	} else if !build.IsRelease || build.IsBeta {
+		m.StartDeadlockDetector(20 * time.Minute)
+	}
+
+	// Add and start folders
+	for _, folderCfg := range a.cfg.Folders() {
+		if folderCfg.Paused {
+			folderCfg.CreateRoot()
+			continue
+		}
+		m.AddFolder(folderCfg)
+		m.StartFolder(folderCfg.ID)
+	}
+
+	a.mainService.Add(m)
+
+	// Start discovery
+
+	cachedDiscovery := discover.NewCachingMux()
+	a.mainService.Add(cachedDiscovery)
+
+	// The TLS configuration is used for both the listening socket and outgoing
+	// connections.
+
+	tlsCfg := tlsutil.SecureDefault()
+	tlsCfg.Certificates = []tls.Certificate{a.cert}
+	tlsCfg.NextProtos = []string{bepProtocolName}
+	tlsCfg.ClientAuth = tls.RequestClientCert
+	tlsCfg.SessionTicketsDisabled = true
+	tlsCfg.InsecureSkipVerify = true
+
+	// Start connection management
+
+	connectionsService := connections.NewService(a.cfg, a.myID, m, tlsCfg, cachedDiscovery, bepProtocolName, tlsDefaultCommonName)
+	a.mainService.Add(connectionsService)
+
+	if a.cfg.Options().GlobalAnnEnabled {
+		for _, srv := range a.cfg.GlobalDiscoveryServers() {
+			l.Infoln("Using discovery server", srv)
+			gd, err := discover.NewGlobal(srv, a.cert, connectionsService)
+			if err != nil {
+				l.Warnln("Global discovery:", err)
+				continue
+			}
+
+			// 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)
+		}
+	}
+
+	if a.cfg.Options().LocalAnnEnabled {
+		// v4 broadcasts
+		bcd, err := discover.NewLocal(a.myID, fmt.Sprintf(":%d", a.cfg.Options().LocalAnnPort), connectionsService)
+		if err != nil {
+			l.Warnln("IPv4 local discovery:", err)
+		} else {
+			cachedDiscovery.Add(bcd, 0, 0)
+		}
+		// v6 multicasts
+		mcd, err := discover.NewLocal(a.myID, a.cfg.Options().LocalAnnMCAddr, connectionsService)
+		if err != nil {
+			l.Warnln("IPv6 local discovery:", err)
+		} else {
+			cachedDiscovery.Add(mcd, 0, 0)
+		}
+	}
+
+	// Candidate builds always run with usage reporting.
+
+	if opts := a.cfg.Options(); build.IsCandidate {
+		l.Infoln("Anonymous usage reporting is always enabled for candidate releases.")
+		if opts.URAccepted != ur.Version {
+			opts.URAccepted = ur.Version
+			a.cfg.SetOptions(opts)
+			a.cfg.Save()
+			// Unique ID will be set and config saved below if necessary.
+		}
+	}
+
+	// If we are going to do usage reporting, ensure we have a valid unique ID.
+	if opts := a.cfg.Options(); opts.URAccepted > 0 && opts.URUniqueID == "" {
+		opts.URUniqueID = rand.String(8)
+		a.cfg.SetOptions(opts)
+		a.cfg.Save()
+	}
+
+	usageReportingSvc := ur.New(a.cfg, m, connectionsService, a.opts.NoUpgrade)
+	a.mainService.Add(usageReportingSvc)
+
+	// GUI
+
+	if err := a.setupGUI(m, defaultSub, diskSub, cachedDiscovery, connectionsService, usageReportingSvc, errors, systemLog); err != nil {
+		l.Warnln("Failed starting API:", err)
+		return err
+	}
+
+	myDev, _ := a.cfg.Device(a.myID)
+	l.Infof(`My name is "%v"`, myDev.Name)
+	for _, device := range a.cfg.Devices() {
+		if device.DeviceID != a.myID {
+			l.Infof(`Device %s is "%v" at %v`, device.DeviceID, device.Name, device.Addresses)
+		}
+	}
+
+	if isSuperUser() {
+		l.Warnln("Syncthing should not run as a privileged or system user. Please consider using a normal user account.")
+	}
+
+	events.Default.Log(events.StartupComplete, map[string]string{
+		"myID": a.myID.String(),
+	})
+
+	if a.cfg.Options().SetLowPriority {
+		if err := osutil.SetLowPriority(); err != nil {
+			l.Warnln("Failed to lower process priority:", err)
+		}
+	}
+
+	return nil
+}
+
+func (a *App) run() {
+	<-a.stop
+
+	a.mainService.Stop()
+
+	done := make(chan struct{})
+	go func() {
+		a.ll.Close()
+		close(done)
+	}()
+	select {
+	case <-done:
+	case <-time.After(10 * time.Second):
+		l.Warnln("Database failed to stop within 10s")
+	}
+
+	l.Infoln("Exiting")
+
+	close(a.stopped)
+}
+
+// Wait blocks until the app stops running.
+func (a *App) Wait() ExitStatus {
+	<-a.stopped
+	return a.exitStatus
+}
+
+// Error returns an error if one occurred while running the app. It does not wait
+// for the app to stop before returning.
+func (a *App) Error() error {
+	select {
+	case <-a.stopped:
+		return nil
+	default:
+	}
+	return a.err
+}
+
+// Stop stops the app and sets its exit status to given reason, unless the app
+// was already stopped before. In any case it returns the effective exit status.
+func (a *App) Stop(stopReason ExitStatus) ExitStatus {
+	select {
+	case <-a.stopped:
+	case <-a.stop:
+	default:
+		close(a.stop)
+	}
+	<-a.stopped
+	// ExitSuccess is the default value for a.exitStatus. If another status
+	// was already set, ignore the stop reason given as argument to Stop.
+	if a.exitStatus == ExitSuccess {
+		a.exitStatus = stopReason
+	}
+	return a.exitStatus
+}
+
+func (a *App) startAuditing() {
+	auditService := newAuditService(a.opts.AuditWriter)
+	a.mainService.Add(auditService)
+
+	// We wait for the audit service to fully start before we return, to
+	// ensure we capture all events from the start.
+	auditService.WaitForStart()
+}
+
+func (a *App) setupGUI(m model.Model, defaultSub, diskSub events.BufferedSubscription, discoverer discover.CachingMux, connectionsService connections.Service, urService *ur.Service, errors, systemLog logger.Recorder) error {
+	guiCfg := a.cfg.GUI()
+
+	if !guiCfg.Enabled {
+		return nil
+	}
+
+	if guiCfg.InsecureAdminAccess {
+		l.Warnln("Insecure admin access is enabled.")
+	}
+
+	cpu := newCPUService()
+	a.mainService.Add(cpu)
+
+	summaryService := model.NewFolderSummaryService(a.cfg, m, a.myID)
+	a.mainService.Add(summaryService)
+
+	apiSvc := api.New(a.myID, a.cfg, a.opts.AssetDir, tlsDefaultCommonName, m, defaultSub, diskSub, discoverer, connectionsService, urService, summaryService, errors, systemLog, cpu, &controller{a}, a.opts.NoUpgrade)
+	a.mainService.Add(apiSvc)
+
+	if err := apiSvc.WaitForStart(); err != nil {
+		return err
+	}
+	return nil
+}
+
+// checkShortIDs verifies that the configuration won't result in duplicate
+// short ID:s; that is, that the devices in the cluster all have unique
+// initial 64 bits.
+func checkShortIDs(cfg config.Wrapper) error {
+	exists := make(map[protocol.ShortID]protocol.DeviceID)
+	for deviceID := range cfg.Devices() {
+		shortID := deviceID.Short()
+		if otherID, ok := exists[shortID]; ok {
+			return fmt.Errorf("%v in conflict with %v", deviceID, otherID)
+		}
+		exists[shortID] = deviceID
+	}
+	return nil
+}
+
+// Implements api.Controller
+type controller struct{ *App }
+
+func (e *controller) Restart() {
+	e.Stop(ExitRestart)
+}
+
+func (e *controller) Shutdown() {
+	e.Stop(ExitSuccess)
+}
+
+func (e *controller) ExitUpgrading() {
+	e.Stop(ExitUpgrade)
+}
+
+func LoadCertificate(certFile, keyFile string) (tls.Certificate, error) {
+	return tls.LoadX509KeyPair(certFile, keyFile)
+}
+
+func LoadConfig(path string, cert tls.Certificate) (config.Wrapper, error) {
+	return config.Load(path, protocol.NewDeviceID(cert.Certificate[0]))
+}
+
+func OpenGoleveldb(path string) (*db.Lowlevel, error) {
+	return db.Open(path)
+}

lib/syncthing/syncthing_test.go

@@ -0,0 +1,38 @@
+// Copyright (C) 2014 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 https://mozilla.org/MPL/2.0/.
+
+package syncthing
+
+import (
+	"testing"
+
+	"github.com/syncthing/syncthing/lib/config"
+	"github.com/syncthing/syncthing/lib/protocol"
+)
+
+func TestShortIDCheck(t *testing.T) {
+	cfg := config.Wrap("/tmp/test", config.Configuration{
+		Devices: []config.DeviceConfiguration{
+			{DeviceID: protocol.DeviceID{8, 16, 24, 32, 40, 48, 56, 0, 0}},
+			{DeviceID: protocol.DeviceID{8, 16, 24, 32, 40, 48, 56, 1, 1}}, // first 56 bits same, differ in the first 64 bits
+		},
+	})
+
+	if err := checkShortIDs(cfg); err != nil {
+		t.Error("Unexpected error:", err)
+	}
+
+	cfg = config.Wrap("/tmp/test", config.Configuration{
+		Devices: []config.DeviceConfiguration{
+			{DeviceID: protocol.DeviceID{8, 16, 24, 32, 40, 48, 56, 64, 0}},
+			{DeviceID: protocol.DeviceID{8, 16, 24, 32, 40, 48, 56, 64, 1}}, // first 64 bits same
+		},
+	})
+
+	if err := checkShortIDs(cfg); err == nil {
+		t.Error("Should have gotten an error")
+	}
+}

lib/syncthing/verboseservice.go

@@ -0,0 +1,201 @@
+// 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 https://mozilla.org/MPL/2.0/.
+
+package syncthing
+
+import (
+	"fmt"
+
+	"github.com/syncthing/syncthing/lib/events"
+)
+
+// The verbose logging service subscribes to events and prints these in
+// verbose format to the console using INFO level.
+type verboseService struct {
+	stop    chan struct{} // signals time to stop
+	started chan struct{} // signals startup complete
+}
+
+func newVerboseService() *verboseService {
+	return &verboseService{
+		stop:    make(chan struct{}),
+		started: make(chan struct{}),
+	}
+}
+
+// Serve runs the verbose logging service.
+func (s *verboseService) Serve() {
+	sub := events.Default.Subscribe(events.AllEvents)
+	defer events.Default.Unsubscribe(sub)
+
+	select {
+	case <-s.started:
+		// The started channel has already been closed; do nothing.
+	default:
+		// This is the first time around. Indicate that we're ready to start
+		// processing events.
+		close(s.started)
+	}
+
+	for {
+		select {
+		case ev := <-sub.C():
+			formatted := s.formatEvent(ev)
+			if formatted != "" {
+				l.Verboseln(formatted)
+			}
+		case <-s.stop:
+			return
+		}
+	}
+}
+
+// Stop stops the verbose logging service.
+func (s *verboseService) Stop() {
+	close(s.stop)
+}
+
+// WaitForStart returns once the verbose logging service is ready to receive
+// events, or immediately if it's already running.
+func (s *verboseService) WaitForStart() {
+	<-s.started
+}
+
+func (s *verboseService) formatEvent(ev events.Event) string {
+	switch ev.Type {
+	case events.DownloadProgress, events.LocalIndexUpdated:
+		// Skip
+		return ""
+
+	case events.Starting:
+		return fmt.Sprintf("Starting up (%s)", ev.Data.(map[string]string)["home"])
+
+	case events.StartupComplete:
+		return "Startup complete"
+
+	case events.DeviceDiscovered:
+		data := ev.Data.(map[string]interface{})
+		return fmt.Sprintf("Discovered device %v at %v", data["device"], data["addrs"])
+
+	case events.DeviceConnected:
+		data := ev.Data.(map[string]string)
+		return fmt.Sprintf("Connected to device %v at %v (type %s)", data["id"], data["addr"], data["type"])
+
+	case events.DeviceDisconnected:
+		data := ev.Data.(map[string]string)
+		return fmt.Sprintf("Disconnected from device %v", data["id"])
+
+	case events.StateChanged:
+		data := ev.Data.(map[string]interface{})
+		return fmt.Sprintf("Folder %q is now %v", data["folder"], data["to"])
+
+	case events.LocalChangeDetected:
+		data := ev.Data.(map[string]string)
+		return fmt.Sprintf("Local change detected in folder %q: %s %s %s", data["folder"], data["action"], data["type"], data["path"])
+
+	case events.RemoteChangeDetected:
+		data := ev.Data.(map[string]string)
+		return fmt.Sprintf("Remote change detected in folder %q: %s %s %s", data["folder"], data["action"], data["type"], data["path"])
+
+	case events.RemoteIndexUpdated:
+		data := ev.Data.(map[string]interface{})
+		return fmt.Sprintf("Device %v sent an index update for %q with %d items", data["device"], data["folder"], data["items"])
+
+	case events.DeviceRejected:
+		data := ev.Data.(map[string]string)
+		return fmt.Sprintf("Rejected connection from device %v at %v", data["device"], data["address"])
+
+	case events.FolderRejected:
+		data := ev.Data.(map[string]string)
+		return fmt.Sprintf("Rejected unshared folder %q from device %v", data["folder"], data["device"])
+
+	case events.ItemStarted:
+		data := ev.Data.(map[string]string)
+		return fmt.Sprintf("Started syncing %q / %q (%v %v)", data["folder"], data["item"], data["action"], data["type"])
+
+	case events.ItemFinished:
+		data := ev.Data.(map[string]interface{})
+		if err, ok := data["error"].(*string); ok && err != nil {
+			// If the err interface{} is not nil, it is a string pointer.
+			// Dereference it to get the actual error or Sprintf will print
+			// the pointer value....
+			return fmt.Sprintf("Finished syncing %q / %q (%v %v): %v", data["folder"], data["item"], data["action"], data["type"], *err)
+		}
+		return fmt.Sprintf("Finished syncing %q / %q (%v %v): Success", data["folder"], data["item"], data["action"], data["type"])
+
+	case events.ConfigSaved:
+		return "Configuration was saved"
+
+	case events.FolderCompletion:
+		data := ev.Data.(map[string]interface{})
+		return fmt.Sprintf("Completion for folder %q on device %v is %v%%", data["folder"], data["device"], data["completion"])
+
+	case events.FolderSummary:
+		data := ev.Data.(map[string]interface{})
+		sum := make(map[string]interface{})
+		for k, v := range data["summary"].(map[string]interface{}) {
+			if k == "invalid" || k == "ignorePatterns" || k == "stateChanged" {
+				continue
+			}
+			sum[k] = v
+		}
+		return fmt.Sprintf("Summary for folder %q is %v", data["folder"], sum)
+
+	case events.FolderScanProgress:
+		data := ev.Data.(map[string]interface{})
+		folder := data["folder"].(string)
+		current := data["current"].(int64)
+		total := data["total"].(int64)
+		rate := data["rate"].(float64) / 1024 / 1024
+		var pct int64
+		if total > 0 {
+			pct = 100 * current / total
+		}
+		return fmt.Sprintf("Scanning folder %q, %d%% done (%.01f MiB/s)", folder, pct, rate)
+
+	case events.DevicePaused:
+		data := ev.Data.(map[string]string)
+		device := data["device"]
+		return fmt.Sprintf("Device %v was paused", device)
+
+	case events.DeviceResumed:
+		data := ev.Data.(map[string]string)
+		device := data["device"]
+		return fmt.Sprintf("Device %v was resumed", device)
+
+	case events.FolderPaused:
+		data := ev.Data.(map[string]string)
+		id := data["id"]
+		label := data["label"]
+		return fmt.Sprintf("Folder %v (%v) was paused", id, label)
+
+	case events.FolderResumed:
+		data := ev.Data.(map[string]string)
+		id := data["id"]
+		label := data["label"]
+		return fmt.Sprintf("Folder %v (%v) was resumed", id, label)
+
+	case events.ListenAddressesChanged:
+		data := ev.Data.(map[string]interface{})
+		address := data["address"]
+		lan := data["lan"]
+		wan := data["wan"]
+		return fmt.Sprintf("Listen address %s resolution has changed: lan addresses: %s wan addresses: %s", address, lan, wan)
+
+	case events.LoginAttempt:
+		data := ev.Data.(map[string]interface{})
+		username := data["username"].(string)
+		var success string
+		if data["success"].(bool) {
+			success = "successful"
+		} else {
+			success = "failed"
+		}
+		return fmt.Sprintf("Login %s for username %s.", success, username)
+	}
+
+	return fmt.Sprintf("%s %#v", ev.Type, ev)
+}