From 61e4c623c071cc231c9aa700ac0bf6eb8e29d4fd Mon Sep 17 00:00:00 2001 From: Ulrich Hornung Date: Thu, 26 Sep 2024 08:45:35 +0200 Subject: [PATCH] fix: ignore hash on requests for encrypted virtual folder --- lib/blockstorage/gocloud_url_storage.go | 3 +- lib/blockstorage/simple_ram_block_storage.go | 12 +-- lib/hashutil/hashutil.go | 7 ++ lib/model/folder_virtual.go | 77 +++++++++++++++++--- lib/model/model.go | 24 +++++- 5 files changed, 99 insertions(+), 24 deletions(-) create mode 100644 lib/hashutil/hashutil.go diff --git a/lib/blockstorage/gocloud_url_storage.go b/lib/blockstorage/gocloud_url_storage.go index d3ed9a4dfc8..8a576ea4cf6 100644 --- a/lib/blockstorage/gocloud_url_storage.go +++ b/lib/blockstorage/gocloud_url_storage.go @@ -12,6 +12,7 @@ import ( "io" "log" + "github.com/syncthing/syncthing/lib/hashutil" "gocloud.dev/blob" "gocloud.dev/gcerrors" @@ -54,7 +55,7 @@ func NewGoCloudUrlStorage(ctx context.Context, url string) *GoCloudUrlStorage { } func getBlockStringKey(hash []byte) string { - return BlockDataSubFolder + "/" + hashToStringMapKey(hash) + return BlockDataSubFolder + "/" + hashutil.HashToStringMapKey(hash) } func getMetadataStringKey(name string) string { diff --git a/lib/blockstorage/simple_ram_block_storage.go b/lib/blockstorage/simple_ram_block_storage.go index e21095dcf9d..fda6a859b36 100644 --- a/lib/blockstorage/simple_ram_block_storage.go +++ b/lib/blockstorage/simple_ram_block_storage.go @@ -6,11 +6,7 @@ package blockstorage -import "encoding/hex" - -func hashToStringMapKey(hash []byte) string { - return hex.EncodeToString(hash) -} +import "github.com/syncthing/syncthing/lib/hashutil" type HashedBlockMapInMemory struct { blockMap map[string][]byte @@ -23,14 +19,14 @@ func NewHashedBlockMapInMemory() *HashedBlockMapInMemory { } func (hm *HashedBlockMapInMemory) Get(hash []byte) (data []byte, ok bool) { - data, ok = hm.blockMap[hashToStringMapKey(hash)] + data, ok = hm.blockMap[hashutil.HashToStringMapKey(hash)] return } func (hm *HashedBlockMapInMemory) Set(hash []byte, data []byte) { - hm.blockMap[hashToStringMapKey(hash)] = data + hm.blockMap[hashutil.HashToStringMapKey(hash)] = data } func (hm *HashedBlockMapInMemory) Delete(hash []byte) { - delete(hm.blockMap, hashToStringMapKey(hash)) + delete(hm.blockMap, hashutil.HashToStringMapKey(hash)) } diff --git a/lib/hashutil/hashutil.go b/lib/hashutil/hashutil.go new file mode 100644 index 00000000000..eb5eae2c28c --- /dev/null +++ b/lib/hashutil/hashutil.go @@ -0,0 +1,7 @@ +package hashutil + +import "encoding/hex" + +func HashToStringMapKey(hash []byte) string { + return hex.EncodeToString(hash) +} diff --git a/lib/model/folder_virtual.go b/lib/model/folder_virtual.go index 7bf0e700a12..5375113bfe4 100644 --- a/lib/model/folder_virtual.go +++ b/lib/model/folder_virtual.go @@ -10,6 +10,7 @@ import ( "bytes" "context" "encoding/json" + "fmt" "io" "io/fs" "log" @@ -21,6 +22,7 @@ import ( "github.com/syncthing/syncthing/lib/config" "github.com/syncthing/syncthing/lib/db" "github.com/syncthing/syncthing/lib/events" + "github.com/syncthing/syncthing/lib/hashutil" "github.com/syncthing/syncthing/lib/ignore" "github.com/syncthing/syncthing/lib/logger" "github.com/syncthing/syncthing/lib/protocol" @@ -156,6 +158,7 @@ func (f *virtualFolderSyncthingService) Serve_backgroundDownloadTask() { } if !all_ok { + f.evLogger.Log(events.Failure, fmt.Sprintf("failed to pull all blocks for: %v", job)) return } @@ -219,7 +222,7 @@ func (f *virtualFolderSyncthingService) Serve(ctx context.Context) error { return nil case <-f.pullScheduled: - f.PullAll() + f.PullAllMissing() continue } } @@ -242,28 +245,80 @@ func (vf *virtualFolderSyncthingService) Scan(subs []string) error { return vf.PullAll() } -func (vf *virtualFolderSyncthingService) PullAll() error { +func (vf *virtualFolderSyncthingService) PullAllMissing() error { snap, err := vf.fset.Snapshot() if err != nil { return err } defer snap.Release() + vf.setState(FolderScanning) + defer vf.setState(FolderIdle) + snap.WithNeedTruncated(protocol.LocalDeviceID, func(f protocol.FileIntf) bool /* true to continue */ { - if f.IsDirectory() { - // no work to do for directories. directly take over: - fi, ok := snap.GetGlobal(f.FileName()) - if ok { - vf.fset.UpdateOne(protocol.LocalDeviceID, &fi) - } - } else { - vf.RequestBackgroundDownload(f.FileName(), f.FileSize(), f.ModTime()) - } + vf.PullOne(snap, f, true) + return true + }) + + return nil +} + +func (vf *virtualFolderSyncthingService) PullAll() error { + snap, err := vf.fset.Snapshot() + if err != nil { + return err + } + defer snap.Release() + + vf.setState(FolderScanning) + defer vf.setState(FolderIdle) + + logger.DefaultLogger.Infof("pull all START") + + snap.WithGlobalTruncated(func(f protocol.FileIntf) bool /* true to continue */ { + vf.PullOne(snap, f, true) return true }) + logger.DefaultLogger.Infof("pull all END") + return nil } + +func (vf *virtualFolderSyncthingService) PullOne(snap *db.Snapshot, f protocol.FileIntf, synchronous bool) { + if f.IsDirectory() { + // no work to do for directories. directly take over: + fi, ok := snap.GetGlobal(f.FileName()) + if ok { + vf.fset.UpdateOne(protocol.LocalDeviceID, &fi) + } + } else { + if !synchronous { + vf.RequestBackgroundDownload(f.FileName(), f.FileSize(), f.ModTime()) + } else { + fi, ok := snap.GetGlobal(f.FileName()) + if ok { + all_ok := true + for i, bi := range fi.Blocks { + logger.DefaultLogger.Infof("synchronous check block info #%v: %+v", i, bi, hashutil.HashToStringMapKey(bi.Hash)) + _, ok := vf.GetBlockDataFromCacheOrDownload(snap, fi, bi) + all_ok = all_ok && ok + if !ok { + logger.DefaultLogger.Warnf("synchronous check block info FAILED. NOT OK: #%v: %+v", i, bi, hashutil.HashToStringMapKey(bi.Hash)) + } + } + + if all_ok { + logger.DefaultLogger.Infof("synchronous check block info (%v blocks, %v size) SUCCEEDED. ALL OK, file: %s", fi.Blocks, fi.Size, fi.Name) + vf.fset.UpdateOne(protocol.LocalDeviceID, &fi) + } else { + logger.DefaultLogger.Warnf("synchronous check block info FAILED. NOT ALL OK, file: %s", fi.Name) + } + } + } + } +} + func (f *virtualFolderSyncthingService) Errors() []FileError { return []FileError{} } func (f *virtualFolderSyncthingService) WatchError() error { return nil } func (f *virtualFolderSyncthingService) ScheduleForceRescan(path string) {} diff --git a/lib/model/model.go b/lib/model/model.go index 532c2f80ae6..5b2dc0f2b4c 100644 --- a/lib/model/model.go +++ b/lib/model/model.go @@ -32,7 +32,9 @@ import ( "github.com/syncthing/syncthing/lib/db" "github.com/syncthing/syncthing/lib/events" "github.com/syncthing/syncthing/lib/fs" + "github.com/syncthing/syncthing/lib/hashutil" "github.com/syncthing/syncthing/lib/ignore" + "github.com/syncthing/syncthing/lib/logger" "github.com/syncthing/syncthing/lib/osutil" "github.com/syncthing/syncthing/lib/protocol" "github.com/syncthing/syncthing/lib/rand" @@ -1579,10 +1581,13 @@ func (m *model) ccCheckEncryption(fcfg config.FolderConfiguration, folderDevice // hasTokenRemote == true ccToken = ccDeviceInfos.remote.EncryptionPasswordToken } + + logger.DefaultLogger.Infof("ccCheckEncryption() - check if token is already known. token: %v, folder-ID: %v", ccToken, fcfg.ID) m.mut.RLock() token, ok := m.folderEncryptionPasswordTokens[fcfg.ID] m.mut.RUnlock() if !ok { + logger.DefaultLogger.Infof("ccCheckEncryption() - token not yet set - try to read it from folder storage") runner, ok := m.folderRunners.Get(fcfg.ID) if !ok { return errEncryptionPassword @@ -1590,6 +1595,7 @@ func (m *model) ccCheckEncryption(fcfg config.FolderConfiguration, folderDevice var err error token, err = runner.ReadEncryptionToken() if err != nil && !fs.IsNotExist(err) { + logger.DefaultLogger.Infof("ccCheckEncryption() - Failure reading token. Abort") if rerr, ok := redactPathError(err); ok { return rerr } @@ -1598,12 +1604,16 @@ func (m *model) ccCheckEncryption(fcfg config.FolderConfiguration, folderDevice redacted: errEncryptionTokenRead, } } + if err == nil { + logger.DefaultLogger.Infof("ccCheckEncryption() - read token successful") m.mut.Lock() m.folderEncryptionPasswordTokens[fcfg.ID] = token m.mut.Unlock() } else { + logger.DefaultLogger.Infof("ccCheckEncryption() - couldn't read token - will write it, assuming its first time") if err := runner.WriteEncryptionToken(ccToken); err != nil { + logger.DefaultLogger.Infof("ccCheckEncryption() - write token failed! err: %v", err) if rerr, ok := redactPathError(err); ok { return rerr } else { @@ -1613,6 +1623,7 @@ func (m *model) ccCheckEncryption(fcfg config.FolderConfiguration, folderDevice } } } + logger.DefaultLogger.Infof("ccCheckEncryption() - write token succeeded.") m.mut.Lock() m.folderEncryptionPasswordTokens[fcfg.ID] = ccToken m.mut.Unlock() @@ -2035,9 +2046,9 @@ func (m *model) Request(conn protocol.Connection, req *protocol.Request) (out pr n := 0 virtualFolder, ok := folderRunner.(virtualFolderServiceI) if ok { - if len(req.Hash) == 0 { // this happens for virtual encrypted folders + if true { // len(req.Hash) == 0 { // this happens for virtual encrypted folders, sometimes there is even a hash, but its invalid l.Infof("%v REQ(in) get hash of req. block from virtual folder: %s - %s: %q / %q o=%d s=%d, blockNo=%v, hash=%v", - m, err, deviceID.Short(), req.Folder, req.Name, req.Offset, req.Size, req.BlockNo, req.Hash) + m, err, deviceID.Short(), req.Folder, req.Name, req.Offset, req.Size, req.BlockNo, hashutil.HashToStringMapKey(req.Hash)) // lookup hash: folderFiles := m.folderFiles[req.Folder] if folderFiles == nil { @@ -2060,17 +2071,22 @@ func (m *model) Request(conn protocol.Connection, req *protocol.Request) (out pr } n, err = virtualFolder.GetHashBlockData(req.Hash, res.data) l.Infof("%v REQ(in) get block from virtual folder: %s - %s: %q / %q o=%d s=%d, blockNo=%v, hash=%v", - m, err, deviceID.Short(), req.Folder, req.Name, req.Offset, req.Size, req.BlockNo, req.Hash) + m, err, deviceID.Short(), req.Folder, req.Name, req.Offset, req.Size, req.BlockNo, hashutil.HashToStringMapKey(req.Hash)) } else { filesystemFolder, ok := folderRunner.(filesystemFolderServiceI) if !ok { l.Debugf("%v REQ(in) get block FAILED - unknown folder type. %s - %s: %q / %q o=%d s=%d, blockNo=%v, hash=%v", - m, err, deviceID.Short(), req.Folder, req.Name, req.Offset, req.Size, req.BlockNo, req.Hash) + m, err, deviceID.Short(), req.Folder, req.Name, req.Offset, req.Size, req.BlockNo, hashutil.HashToStringMapKey(req.Hash)) return nil, protocol.ErrGeneric } n, err = filesystemFolder.GetFileData(deviceID, req, res.data) } + if err != nil { + l.Warnf("%v REQ(in) get block FAILED: %s - %s: %q / %q o=%d s=%d, blockNo=%v, hash=%v", + m, err, deviceID.Short(), req.Folder, req.Name, req.Offset, req.Size, req.BlockNo, hashutil.HashToStringMapKey(req.Hash)) + return nil, err + } if !folderCfg.Type.IsReceiveEncrypted() && len(req.Hash) > 0 && !scanner.Validate(res.data[:n], req.Hash, req.WeakHash) { m.recheckFile(deviceID, req.Folder, req.Name, req.Offset, req.Hash, req.WeakHash)