cmd/syncthing: Print version information early (fixes #5891) (#5893)

Bumps [github.com/maruel/panicparse](https://github.com/maruel/panicparse) from 1.2.1 to 1.3.0.
- [Release notes](https://github.com/maruel/panicparse/releases)
- [Commits](https://github.com/maruel/panicparse/compare/v1.2.1...v1.3.0)

Signed-off-by: dependabot-preview[bot] <support@dependabot.com>

cmd/syncthing/main.go

@@ -548,6 +548,14 @@ func upgradeViaRest() error {
 }
 
 func syncthingMain(runtimeOptions RuntimeOptions) {
+	// Set a log prefix similar to the ID we will have later on, or early log
+	// lines look ugly.
+	l.SetPrefix("[start] ")
+
+	// Print our version information up front, so any crash that happens
+	// early etc. will have it available.
+	l.Infoln(build.LongVersion)
+
 	// Ensure that we have a certificate and key.
 	cert, err := tls.LoadX509KeyPair(
 		locations.Get(locations.CertFile),

go.mod

@@ -19,9 +19,9 @@ require (
 	github.com/jackpal/gateway v0.0.0-20161225004348-5795ac81146e
 	github.com/kballard/go-shellquote v0.0.0-20170619183022-cd60e84ee657
 	github.com/kr/pretty v0.1.0 // indirect
-	github.com/lib/pq v1.1.1
+	github.com/lib/pq v1.2.0
 	github.com/lucas-clemente/quic-go v0.11.2
-	github.com/maruel/panicparse v1.2.1
+	github.com/maruel/panicparse v1.3.0
 	github.com/mattn/go-isatty v0.0.7
 	github.com/minio/sha256-simd v0.0.0-20190117184323-cc1980cb0338
 	github.com/onsi/ginkgo v1.8.0 // indirect

go.sum

@@ -72,18 +72,24 @@ github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE=
 github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI=
 github.com/lib/pq v1.1.1 h1:sJZmqHoEaY7f+NPP8pgLB/WxulyR3fewgCM2qaSlBb4=
 github.com/lib/pq v1.1.1/go.mod h1:5WUZQaWbwv1U+lTReE5YruASi9Al49XbQIvNi/34Woo=
+github.com/lib/pq v1.2.0 h1:LXpIM/LZ5xGFhOpXAQUIMM1HdyqzVYM13zNdjCEEcA0=
+github.com/lib/pq v1.2.0/go.mod h1:5WUZQaWbwv1U+lTReE5YruASi9Al49XbQIvNi/34Woo=
 github.com/lucas-clemente/quic-go v0.11.2 h1:Mop0ac3zALaBR3wGs6j8OYe/tcFvFsxTUFMkE/7yUOI=
 github.com/lucas-clemente/quic-go v0.11.2/go.mod h1:PpMmPfPKO9nKJ/psF49ESTAGQSdfXxlg1otPbEB2nOw=
 github.com/marten-seemann/qtls v0.2.3 h1:0yWJ43C62LsZt08vuQJDK1uC1czUc3FJeCLPoNAI4vA=
 github.com/marten-seemann/qtls v0.2.3/go.mod h1:xzjG7avBwGGbdZ8dTGxlBnLArsVKLvwmjgmPuiQEcYk=
 github.com/maruel/panicparse v1.2.1 h1:mNlHGiakrixj+AwF/qRpTwnj+zsWYPRLQ7wRqnJsfO0=
 github.com/maruel/panicparse v1.2.1/go.mod h1:vszMjr5QQ4F5FSRfraldcIA/BCw5xrdLL+zEcU2nRBs=
+github.com/maruel/panicparse v1.3.0 h1:1Ep/RaYoSL1r5rTILHQQbyzHG8T4UP5ZbQTYTo4bdDc=
+github.com/maruel/panicparse v1.3.0/go.mod h1:vszMjr5QQ4F5FSRfraldcIA/BCw5xrdLL+zEcU2nRBs=
+github.com/mattn/go-colorable v0.1.1 h1:G1f5SKeVxmagw/IyvzvtZE4Gybcc4Tr1tf7I8z0XgOg=
 github.com/mattn/go-colorable v0.1.1/go.mod h1:FuOcm+DKB9mbwrcAfNl7/TZVBZ6rcnceauSikq3lYCQ=
 github.com/mattn/go-isatty v0.0.5/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hdxcsrc5s=
 github.com/mattn/go-isatty v0.0.7 h1:UvyT9uN+3r7yLEYSlJsbQGdsaB/a0DlgWP3pql6iwOc=
 github.com/mattn/go-isatty v0.0.7/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hdxcsrc5s=
 github.com/matttproud/golang_protobuf_extensions v1.0.1 h1:4hp9jkHxhMHkqkrB3Ix0jegS5sx/RkqARlsWZ6pIwiU=
 github.com/matttproud/golang_protobuf_extensions v1.0.1/go.mod h1:D8He9yQNgCq6Z5Ld7szi9bcBfOoFv/3dc6xSMkL2PC0=
+github.com/mgutz/ansi v0.0.0-20170206155736-9520e82c474b h1:j7+1HpAFS1zy5+Q4qx1fWh90gTKwiN4QCGoY9TWyyO4=
 github.com/mgutz/ansi v0.0.0-20170206155736-9520e82c474b/go.mod h1:01TrycV0kFyexm33Z7vhZRXopbI8J3TDReVlkTgMUxE=
 github.com/minio/sha256-simd v0.0.0-20190117184323-cc1980cb0338 h1:USW1+zAUkUSvk097CAX/i8KR3r6f+DHNhk6Xe025Oyw=
 github.com/minio/sha256-simd v0.0.0-20190117184323-cc1980cb0338/go.mod h1:2FMWW+8GMoPweT6+pI63m9YE3Lmw4J71hV56Chs1E/U=

lib/fs/basicfs_watch_eventtypes_kqueue.go

@@ -11,7 +11,9 @@ package fs
 import "github.com/syncthing/notify"
 
 const (
-	subEventMask  = notify.NoteDelete | notify.NoteWrite | notify.NoteRename
-	permEventMask = notify.NoteAttrib
+	// Platform independent notify.Create is required, as kqueue does not have
+	// any event signalling file creation, but notify does generate those internally.
+	subEventMask  = notify.NoteDelete | notify.NoteWrite | notify.NoteRename | notify.Create
+	permEventMask = notify.NoteAttrib | notify.NoteExtend
 	rmEventMask   = notify.NoteDelete | notify.NoteRename
 )

lib/model/folder.go

@@ -423,6 +423,12 @@ func (f *folder) scanSubdirs(subDirs []string) error {
 		var iterError error
 
 		f.fset.WithPrefixedHaveTruncated(protocol.LocalDeviceID, sub, func(fi db.FileIntf) bool {
+			select {
+			case <-f.ctx.Done():
+				return false
+			default:
+			}
+
 			file := fi.(db.FileInfoTruncated)
 
 			if err := batch.flushIfFull(); err != nil {
@@ -507,6 +513,12 @@ func (f *folder) scanSubdirs(subDirs []string) error {
 			return true
 		})
 
+		select {
+		case <-f.ctx.Done():
+			return f.ctx.Err()
+		default:
+		}
+
 		if iterError == nil && len(toIgnore) > 0 {
 			for _, file := range toIgnore {
 				l.Debugln("marking file as ignored", f)

lib/model/folder_sendonly.go

@@ -68,7 +68,7 @@ func (f *sendOnlyFolder) pull() bool {
 		curFile, ok := f.fset.Get(protocol.LocalDeviceID, intf.FileName())
 		if !ok {
 			if intf.IsDeleted() {
-				panic("Should never get a deleted file as needed when we don't have it")
+				l.Debugln("Should never get a deleted file as needed when we don't have it")
 			}
 			return true
 		}

lib/model/model.go

@@ -248,10 +248,8 @@ func (m *model) StartFolder(folder string) {
 
 // Need to hold lock on m.fmut when calling this.
 func (m *model) startFolderLocked(cfg config.FolderConfiguration) {
-	if err := m.checkFolderRunningLocked(cfg.ID); err == errFolderMissing {
-		l.Warnln("Cannot start nonexistent folder", cfg.Description())
-		panic("cannot start nonexistent folder")
-	} else if err == nil {
+	_, ok := m.folderRunners[cfg.ID]
+	if ok {
 		l.Warnln("Cannot start already running folder", cfg.Description())
 		panic("cannot start already running folder")
 	}
@@ -461,18 +459,16 @@ func (m *model) RestartFolder(from, to config.FolderConfiguration) {
 		errMsg = "restarting"
 	}
 
-	var fset *db.FileSet
-	if !to.Paused {
-		// Creating the fileset can take a long time (metadata calculation)
-		// so we do it outside of the lock.
-		fset = db.NewFileSet(to.ID, to.Filesystem(), m.db)
-	}
-
 	m.fmut.Lock()
 	defer m.fmut.Unlock()
 
 	m.tearDownFolderLocked(from, fmt.Errorf("%v folder %v", errMsg, to.Description()))
 	if !to.Paused {
+		// Creating the fileset can take a long time (metadata calculation)
+		// so we do it outside of the lock.
+		m.fmut.Unlock()
+		fset := db.NewFileSet(to.ID, to.Filesystem(), m.db)
+		m.fmut.Lock()
 		m.addFolderLocked(to, fset)
 		m.startFolderLocked(to)
 	}

lib/nat/service.go

@@ -225,7 +225,7 @@ func (s *Service) verifyExistingMappings(mapping *Mapping, nats map[string]Devic
 
 			l.Debugf("Renewing %s -> %s mapping on %s", mapping, address, id)
 
-			addr, err := s.tryNATDevice(nat, mapping.address.Port, address.Port, leaseTime)
+			addr, err := s.tryNATDevice(nat, mapping.address.Port, address.Port, leaseTime, stop)
 			if err != nil {
 				l.Debugf("Failed to renew %s -> mapping on %s", mapping, address, id)
 				mapping.removeAddress(id)
@@ -274,7 +274,7 @@ func (s *Service) acquireNewMappings(mapping *Mapping, nats map[string]Device, s
 
 		l.Debugf("Acquiring %s mapping on %s", mapping, id)
 
-		addr, err := s.tryNATDevice(nat, mapping.address.Port, 0, leaseTime)
+		addr, err := s.tryNATDevice(nat, mapping.address.Port, 0, leaseTime, stop)
 		if err != nil {
 			l.Debugf("Failed to acquire %s mapping on %s", mapping, id)
 			continue
@@ -291,7 +291,7 @@ func (s *Service) acquireNewMappings(mapping *Mapping, nats map[string]Device, s
 
 // tryNATDevice tries to acquire a port mapping for the given internal address to
 // the given external port. If external port is 0, picks a pseudo-random port.
-func (s *Service) tryNATDevice(natd Device, intPort, extPort int, leaseTime time.Duration) (Address, error) {
+func (s *Service) tryNATDevice(natd Device, intPort, extPort int, leaseTime time.Duration, stop chan struct{}) (Address, error) {
 	var err error
 	var port int
 
@@ -312,6 +312,12 @@ func (s *Service) tryNATDevice(natd Device, intPort, extPort int, leaseTime time
 	}
 
 	for i := 0; i < 10; i++ {
+		select {
+		case <-stop:
+			return Address{}, nil
+		default:
+		}
+
 		// Then try up to ten random ports.
 		extPort = 1024 + predictableRand.Intn(65535-1024)
 		name := fmt.Sprintf("syncthing-%d", extPort)

lib/syncthing/auditservice.go

@@ -10,42 +10,38 @@ import (
 	"encoding/json"
 	"io"
 
+	"github.com/thejerf/suture"
+
 	"github.com/syncthing/syncthing/lib/events"
+	"github.com/syncthing/syncthing/lib/util"
 )
 
 // 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
+	suture.Service
+	w   io.Writer // audit destination
+	sub *events.Subscription
 }
 
 func newAuditService(w io.Writer) *auditService {
-	return &auditService{
-		w:       w,
-		stop:    make(chan struct{}),
-		started: make(chan struct{}),
-		stopped: make(chan struct{}),
+	s := &auditService{
+		w:   w,
+		sub: events.Default.Subscribe(events.AllEvents),
 	}
+	s.Service = util.AsService(s.serve)
+	return s
 }
 
-// Serve runs the audit service.
-func (s *auditService) Serve() {
-	defer close(s.stopped)
-	sub := events.Default.Subscribe(events.AllEvents)
-	defer events.Default.Unsubscribe(sub)
+// serve runs the audit service.
+func (s *auditService) serve(stop chan struct{}) {
 	enc := json.NewEncoder(s.w)
 
-	// We're ready to start processing events.
-	close(s.started)
-
 	for {
 		select {
-		case ev := <-sub.C():
+		case ev := <-s.sub.C():
 			enc.Encode(ev)
-		case <-s.stop:
+		case <-stop:
 			return
 		}
 	}
@@ -53,17 +49,6 @@ func (s *auditService) Serve() {
 
 // 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
+	s.Service.Stop()
+	events.Default.Unsubscribe(s.sub)
 }

lib/syncthing/auditservice_test.go

@@ -17,13 +17,12 @@ import (
 
 func TestAuditService(t *testing.T) {
 	buf := new(bytes.Buffer)
-	service := newAuditService(buf)
 
-	// Event sent before start, will not be logged
+	// Event sent before construction, will not be logged
 	events.Default.Log(events.ConfigSaved, "the first event")
 
+	service := newAuditService(buf)
 	go service.Serve()
-	service.WaitForStart()
 
 	// Event that should end up in the audit log
 	events.Default.Log(events.ConfigSaved, "the second event")
@@ -32,7 +31,6 @@ func TestAuditService(t *testing.T) {
 	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")

lib/syncthing/syncthing.go

@@ -121,12 +121,8 @@ func (a *App) startup() error {
 	})
 	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()
+		a.mainService.Add(newAuditService(a.opts.AuditWriter))
 	}
 
 	if a.opts.Verbose {
@@ -147,10 +143,9 @@ func (a *App) startup() error {
 	// report the error if there is one.
 	osutil.MaximizeOpenFileLimit()
 
+	// Figure out our device ID, set it as the log prefix and log it.
 	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
@@ -418,15 +413,6 @@ func (a *App) Stop(stopReason ExitStatus) ExitStatus {
 	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()
 

lib/syncthing/verboseservice.go

@@ -9,45 +9,37 @@ package syncthing
 import (
 	"fmt"
 
+	"github.com/thejerf/suture"
+
 	"github.com/syncthing/syncthing/lib/events"
+	"github.com/syncthing/syncthing/lib/util"
 )
 
 // 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
+	suture.Service
+	sub *events.Subscription
 }
 
 func newVerboseService() *verboseService {
-	return &verboseService{
-		stop:    make(chan struct{}),
-		started: make(chan struct{}),
+	s := &verboseService{
+		sub: events.Default.Subscribe(events.AllEvents),
 	}
+	s.Service = util.AsService(s.serve)
+	return s
 }
 
-// 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)
-	}
-
+// serve runs the verbose logging service.
+func (s *verboseService) serve(stop chan struct{}) {
 	for {
 		select {
-		case ev := <-sub.C():
+		case ev := <-s.sub.C():
 			formatted := s.formatEvent(ev)
 			if formatted != "" {
 				l.Verboseln(formatted)
 			}
-		case <-s.stop:
+		case <-stop:
 			return
 		}
 	}
@@ -55,13 +47,9 @@ func (s *verboseService) Serve() {
 
 // Stop stops the verbose logging service.
 func (s *verboseService) Stop() {
-	close(s.stop)
-}
+	s.Service.Stop()
+	events.Default.Unsubscribe(s.sub)
 
-// 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 {