lib/db: Log context on panic (#6872)

lib/db/set.go

@@ -13,6 +13,8 @@
 package db
 
 import (
+	"fmt"
+
 	"github.com/syncthing/syncthing/lib/db/backend"
 	"github.com/syncthing/syncthing/lib/fs"
 	"github.com/syncthing/syncthing/lib/osutil"
@@ -45,7 +47,8 @@ func NewFileSet(folder string, fs fs.Filesystem, db *Lowlevel) *FileSet {
 }
 
 func (s *FileSet) Drop(device protocol.DeviceID) {
-	l.Debugf("%s Drop(%v)", s.folder, device)
+	opStr := fmt.Sprintf("%s Drop(%v)", s.folder, device)
+	l.Debugf(opStr)
 
 	s.updateMutex.Lock()
 	defer s.updateMutex.Unlock()
@@ -53,7 +56,7 @@ func (s *FileSet) Drop(device protocol.DeviceID) {
 	if err := s.db.dropDeviceFolder(device[:], []byte(s.folder), s.meta); backend.IsClosed(err) {
 		return
 	} else if err != nil {
-		panic(err)
+		fatalError(err, opStr)
 	}
 
 	if device == protocol.LocalDeviceID {
@@ -75,24 +78,25 @@ func (s *FileSet) Drop(device protocol.DeviceID) {
 	if backend.IsClosed(err) {
 		return
 	} else if err != nil {
-		panic(err)
+		fatalError(err, opStr)
 	}
 	defer t.close()
 
 	if err := s.meta.toDB(t, []byte(s.folder)); backend.IsClosed(err) {
 		return
 	} else if err != nil {
-		panic(err)
+		fatalError(err, opStr)
 	}
 	if err := t.Commit(); backend.IsClosed(err) {
 		return
 	} else if err != nil {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
 func (s *FileSet) Update(device protocol.DeviceID, fs []protocol.FileInfo) {
-	l.Debugf("%s Update(%v, [%d])", s.folder, device, len(fs))
+	opStr := fmt.Sprintf("%s Update(%v, [%d])", s.folder, device, len(fs))
+	l.Debugf(opStr)
 
 	// do not modify fs in place, it is still used in outer scope
 	fs = append([]protocol.FileInfo(nil), fs...)
@@ -111,13 +115,13 @@ func (s *FileSet) Update(device protocol.DeviceID, fs []protocol.FileInfo) {
 	if device == protocol.LocalDeviceID {
 		// For the local device we have a bunch of metadata to track.
 		if err := s.db.updateLocalFiles([]byte(s.folder), fs, s.meta); err != nil && !backend.IsClosed(err) {
-			panic(err)
+			fatalError(err, opStr)
 		}
 		return
 	}
 	// Easy case, just update the files and we're done.
 	if err := s.db.updateRemoteFiles([]byte(s.folder), device[:], fs, s.meta); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
@@ -128,9 +132,11 @@ type Snapshot struct {
 }
 
 func (s *FileSet) Snapshot() *Snapshot {
+	opStr := fmt.Sprintf("%s Snapshot()", s.folder)
+	l.Debugf(opStr)
 	t, err := s.db.newReadOnlyTransaction()
 	if err != nil {
-		panic(err)
+		fatalError(err, opStr)
 	}
 	return &Snapshot{
 		folder: s.folder,
@@ -144,89 +150,102 @@ func (s *Snapshot) Release() {
 }
 
 func (s *Snapshot) WithNeed(device protocol.DeviceID, fn Iterator) {
-	l.Debugf("%s WithNeed(%v)", s.folder, device)
+	opStr := fmt.Sprintf("%s WithNeed(%v)", s.folder, device)
+	l.Debugf(opStr)
 	if err := s.t.withNeed([]byte(s.folder), device[:], false, nativeFileIterator(fn)); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
 func (s *Snapshot) WithNeedTruncated(device protocol.DeviceID, fn Iterator) {
-	l.Debugf("%s WithNeedTruncated(%v)", s.folder, device)
+	opStr := fmt.Sprintf("%s WithNeedTruncated(%v)", s.folder, device)
+	l.Debugf(opStr)
 	if err := s.t.withNeed([]byte(s.folder), device[:], true, nativeFileIterator(fn)); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
 func (s *Snapshot) WithHave(device protocol.DeviceID, fn Iterator) {
-	l.Debugf("%s WithHave(%v)", s.folder, device)
+	opStr := fmt.Sprintf("%s WithHave(%v)", s.folder, device)
+	l.Debugf(opStr)
 	if err := s.t.withHave([]byte(s.folder), device[:], nil, false, nativeFileIterator(fn)); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
 func (s *Snapshot) WithHaveTruncated(device protocol.DeviceID, fn Iterator) {
-	l.Debugf("%s WithHaveTruncated(%v)", s.folder, device)
+	opStr := fmt.Sprintf("%s WithHaveTruncated(%v)", s.folder, device)
+	l.Debugf(opStr)
 	if err := s.t.withHave([]byte(s.folder), device[:], nil, true, nativeFileIterator(fn)); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
 func (s *Snapshot) WithHaveSequence(startSeq int64, fn Iterator) {
-	l.Debugf("%s WithHaveSequence(%v)", s.folder, startSeq)
+	opStr := fmt.Sprintf("%s WithHaveSequence(%v)", s.folder, startSeq)
+	l.Debugf(opStr)
 	if err := s.t.withHaveSequence([]byte(s.folder), startSeq, nativeFileIterator(fn)); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
 // Except for an item with a path equal to prefix, only children of prefix are iterated.
 // E.g. for prefix "dir", "dir/file" is iterated, but "dir.file" is not.
 func (s *Snapshot) WithPrefixedHaveTruncated(device protocol.DeviceID, prefix string, fn Iterator) {
-	l.Debugf(`%s WithPrefixedHaveTruncated(%v, "%v")`, s.folder, device, prefix)
+	opStr := fmt.Sprintf(`%s WithPrefixedHaveTruncated(%v, "%v")`, s.folder, device, prefix)
+	l.Debugf(opStr)
 	if err := s.t.withHave([]byte(s.folder), device[:], []byte(osutil.NormalizedFilename(prefix)), true, nativeFileIterator(fn)); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
 func (s *Snapshot) WithGlobal(fn Iterator) {
-	l.Debugf("%s WithGlobal()", s.folder)
+	opStr := fmt.Sprintf("%s WithGlobal()", s.folder)
+	l.Debugf(opStr)
 	if err := s.t.withGlobal([]byte(s.folder), nil, false, nativeFileIterator(fn)); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
 func (s *Snapshot) WithGlobalTruncated(fn Iterator) {
-	l.Debugf("%s WithGlobalTruncated()", s.folder)
+	opStr := fmt.Sprintf("%s WithGlobalTruncated()", s.folder)
+	l.Debugf(opStr)
 	if err := s.t.withGlobal([]byte(s.folder), nil, true, nativeFileIterator(fn)); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
 // Except for an item with a path equal to prefix, only children of prefix are iterated.
 // E.g. for prefix "dir", "dir/file" is iterated, but "dir.file" is not.
 func (s *Snapshot) WithPrefixedGlobalTruncated(prefix string, fn Iterator) {
-	l.Debugf(`%s WithPrefixedGlobalTruncated("%v")`, s.folder, prefix)
+	opStr := fmt.Sprintf(`%s WithPrefixedGlobalTruncated("%v")`, s.folder, prefix)
+	l.Debugf(opStr)
 	if err := s.t.withGlobal([]byte(s.folder), []byte(osutil.NormalizedFilename(prefix)), true, nativeFileIterator(fn)); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
 func (s *Snapshot) Get(device protocol.DeviceID, file string) (protocol.FileInfo, bool) {
+	opStr := fmt.Sprintf("%s Get(%v)", s.folder, file)
+	l.Debugf(opStr)
 	f, ok, err := s.t.getFile([]byte(s.folder), device[:], []byte(osutil.NormalizedFilename(file)))
 	if backend.IsClosed(err) {
 		return protocol.FileInfo{}, false
 	} else if err != nil {
-		panic(err)
+		fatalError(err, opStr)
 	}
 	f.Name = osutil.NativeFilename(f.Name)
 	return f, ok
 }
 
 func (s *Snapshot) GetGlobal(file string) (protocol.FileInfo, bool) {
+	opStr := fmt.Sprintf("%s GetGlobal(%v)", s.folder, file)
+	l.Debugf(opStr)
 	_, fi, ok, err := s.t.getGlobal(nil, []byte(s.folder), []byte(osutil.NormalizedFilename(file)), false)
 	if backend.IsClosed(err) {
 		return protocol.FileInfo{}, false
 	} else if err != nil {
-		panic(err)
+		fatalError(err, opStr)
 	}
 	if !ok {
 		return protocol.FileInfo{}, false
@@ -237,11 +256,13 @@ func (s *Snapshot) GetGlobal(file string) (protocol.FileInfo, bool) {
 }
 
 func (s *Snapshot) GetGlobalTruncated(file string) (FileInfoTruncated, bool) {
+	opStr := fmt.Sprintf("%s GetGlobalTruncated(%v)", s.folder, file)
+	l.Debugf(opStr)
 	_, fi, ok, err := s.t.getGlobal(nil, []byte(s.folder), []byte(osutil.NormalizedFilename(file)), true)
 	if backend.IsClosed(err) {
 		return FileInfoTruncated{}, false
 	} else if err != nil {
-		panic(err)
+		fatalError(err, opStr)
 	}
 	if !ok {
 		return FileInfoTruncated{}, false
@@ -252,11 +273,13 @@ func (s *Snapshot) GetGlobalTruncated(file string) (FileInfoTruncated, bool) {
 }
 
 func (s *Snapshot) Availability(file string) []protocol.DeviceID {
+	opStr := fmt.Sprintf("%s Availability(%v)", s.folder, file)
+	l.Debugf(opStr)
 	av, err := s.t.availability([]byte(s.folder), []byte(osutil.NormalizedFilename(file)))
 	if backend.IsClosed(err) {
 		return nil
 	} else if err != nil {
-		panic(err)
+		fatalError(err, opStr)
 	}
 	return av
 }
@@ -343,9 +366,10 @@ func (s *Snapshot) RemoteNeedFolderFiles(device protocol.DeviceID, page, perpage
 }
 
 func (s *Snapshot) WithBlocksHash(hash []byte, fn Iterator) {
-	l.Debugf(`%s WithBlocksHash("%x")`, s.folder, hash)
+	opStr := fmt.Sprintf(`%s WithBlocksHash("%x")`, s.folder, hash)
+	l.Debugf(opStr)
 	if err := s.t.withBlocksHash([]byte(s.folder), hash, nativeFileIterator(fn)); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
@@ -354,11 +378,13 @@ func (s *FileSet) Sequence(device protocol.DeviceID) int64 {
 }
 
 func (s *FileSet) IndexID(device protocol.DeviceID) protocol.IndexID {
+	opStr := fmt.Sprintf("%s IndexID(%v)", s.folder, device)
+	l.Debugf(opStr)
 	id, err := s.db.getIndexID(device[:], []byte(s.folder))
 	if backend.IsClosed(err) {
 		return 0
 	} else if err != nil {
-		panic(err)
+		fatalError(err, opStr)
 	}
 	if id == 0 && device == protocol.LocalDeviceID {
 		// No index ID set yet. We create one now.
@@ -367,7 +393,7 @@ func (s *FileSet) IndexID(device protocol.DeviceID) protocol.IndexID {
 		if backend.IsClosed(err) {
 			return 0
 		} else if err != nil {
-			panic(err)
+			fatalError(err, opStr)
 		}
 	}
 	return id
@@ -377,17 +403,21 @@ func (s *FileSet) SetIndexID(device protocol.DeviceID, id protocol.IndexID) {
 	if device == protocol.LocalDeviceID {
 		panic("do not explicitly set index ID for local device")
 	}
+	opStr := fmt.Sprintf("%s SetIndexID(%v, %v)", s.folder, device, id)
+	l.Debugf(opStr)
 	if err := s.db.setIndexID(device[:], []byte(s.folder), id); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
 func (s *FileSet) MtimeFS() *fs.MtimeFS {
+	opStr := fmt.Sprintf("%s MtimeFS()", s.folder)
+	l.Debugf(opStr)
 	prefix, err := s.db.keyer.GenerateMtimesKey(nil, []byte(s.folder))
 	if backend.IsClosed(err) {
 		return nil
 	} else if err != nil {
-		panic(err)
+		fatalError(err, opStr)
 	}
 	kv := NewNamespacedKV(s.db, string(prefix))
 	return fs.NewMtimeFS(s.fs, kv)
@@ -412,6 +442,8 @@ func (s *FileSet) updateAndGCMutexLock() {
 // DropFolder clears out all information related to the given folder from the
 // database.
 func DropFolder(db *Lowlevel, folder string) {
+	opStr := fmt.Sprintf("DropFolder(%v)", folder)
+	l.Debugf(opStr)
 	droppers := []func([]byte) error{
 		db.dropFolder,
 		db.dropMtimes,
@@ -422,7 +454,7 @@ func DropFolder(db *Lowlevel, folder string) {
 		if err := drop([]byte(folder)); backend.IsClosed(err) {
 			return
 		} else if err != nil {
-			panic(err)
+			fatalError(err, opStr)
 		}
 	}
 }
@@ -430,20 +462,22 @@ func DropFolder(db *Lowlevel, folder string) {
 // DropDeltaIndexIDs removes all delta index IDs from the database.
 // This will cause a full index transmission on the next connection.
 func DropDeltaIndexIDs(db *Lowlevel) {
+	opStr := "DropDeltaIndexIDs"
+	l.Debugf(opStr)
 	dbi, err := db.NewPrefixIterator([]byte{KeyTypeIndexID})
 	if backend.IsClosed(err) {
 		return
 	} else if err != nil {
-		panic(err)
+		fatalError(err, opStr)
 	}
 	defer dbi.Release()
 	for dbi.Next() {
 		if err := db.Delete(dbi.Key()); err != nil && !backend.IsClosed(err) {
-			panic(err)
+			fatalError(err, opStr)
 		}
 	}
 	if err := dbi.Error(); err != nil && !backend.IsClosed(err) {
-		panic(err)
+		fatalError(err, opStr)
 	}
 }
 
@@ -481,3 +515,8 @@ func nativeFileIterator(fn Iterator) Iterator {
 		}
 	}
 }
+
+func fatalError(err error, opStr string) {
+	l.Warnf("Fatal error: %v: %v", opStr, err)
+	panic(err)
+}