From bbf25e2d02ec8f0e23e60e2ee5795dc2cb928814 Mon Sep 17 00:00:00 2001 From: Simon Frei Date: Sat, 1 Aug 2020 17:32:36 +0200 Subject: [PATCH] lib/db: Log context on panic (#6872) --- lib/db/set.go | 121 +++++++++++++++++++++++++++++++++----------------- 1 file changed, 80 insertions(+), 41 deletions(-) diff --git a/lib/db/set.go b/lib/db/set.go index 04952fa6f..8733774da 100644 --- a/lib/db/set.go +++ b/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) +}