1
0

puller.go 28 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932933934935936937938939940941942943944945946947948949950951952953954955956957958959960961962963964965966967968969970971972973974975976977978979980981982983984985986987988989990991992993
  1. // Copyright (C) 2014 The Syncthing Authors.
  2. //
  3. // This program is free software: you can redistribute it and/or modify it
  4. // under the terms of the GNU General Public License as published by the Free
  5. // Software Foundation, either version 3 of the License, or (at your option)
  6. // any later version.
  7. //
  8. // This program is distributed in the hope that it will be useful, but WITHOUT
  9. // ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  10. // FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for
  11. // more details.
  12. //
  13. // You should have received a copy of the GNU General Public License along
  14. // with this program. If not, see <http://www.gnu.org/licenses/>.
  15. package model
  16. import (
  17. "errors"
  18. "fmt"
  19. "io/ioutil"
  20. "math/rand"
  21. "os"
  22. "path/filepath"
  23. "sync"
  24. "time"
  25. "github.com/AudriusButkevicius/lfu-go"
  26. "github.com/syncthing/protocol"
  27. "github.com/syncthing/syncthing/internal/config"
  28. "github.com/syncthing/syncthing/internal/db"
  29. "github.com/syncthing/syncthing/internal/events"
  30. "github.com/syncthing/syncthing/internal/ignore"
  31. "github.com/syncthing/syncthing/internal/osutil"
  32. "github.com/syncthing/syncthing/internal/scanner"
  33. "github.com/syncthing/syncthing/internal/symlinks"
  34. "github.com/syncthing/syncthing/internal/versioner"
  35. )
  36. // TODO: Stop on errors
  37. const (
  38. pauseIntv = 60 * time.Second
  39. nextPullIntv = 10 * time.Second
  40. checkPullIntv = 1 * time.Second
  41. )
  42. // A pullBlockState is passed to the puller routine for each block that needs
  43. // to be fetched.
  44. type pullBlockState struct {
  45. *sharedPullerState
  46. block protocol.BlockInfo
  47. }
  48. // A copyBlocksState is passed to copy routine if the file has blocks to be
  49. // copied.
  50. type copyBlocksState struct {
  51. *sharedPullerState
  52. blocks []protocol.BlockInfo
  53. }
  54. var (
  55. activity = newDeviceActivity()
  56. errNoDevice = errors.New("no available source device")
  57. )
  58. type Puller struct {
  59. folder string
  60. dir string
  61. scanIntv time.Duration
  62. model *Model
  63. stop chan struct{}
  64. versioner versioner.Versioner
  65. ignorePerms bool
  66. lenientMtimes bool
  67. progressEmitter *ProgressEmitter
  68. copiers int
  69. pullers int
  70. queue *jobQueue
  71. }
  72. // Serve will run scans and pulls. It will return when Stop()ed or on a
  73. // critical error.
  74. func (p *Puller) Serve() {
  75. if debug {
  76. l.Debugln(p, "starting")
  77. defer l.Debugln(p, "exiting")
  78. }
  79. p.stop = make(chan struct{})
  80. pullTimer := time.NewTimer(checkPullIntv)
  81. scanTimer := time.NewTimer(time.Millisecond) // The first scan should be done immediately.
  82. defer func() {
  83. pullTimer.Stop()
  84. scanTimer.Stop()
  85. // TODO: Should there be an actual FolderStopped state?
  86. p.model.setState(p.folder, FolderIdle)
  87. }()
  88. var prevVer int64
  89. var prevIgnoreHash string
  90. // We don't start pulling files until a scan has been completed.
  91. initialScanCompleted := false
  92. loop:
  93. for {
  94. select {
  95. case <-p.stop:
  96. return
  97. // TODO: We could easily add a channel here for notifications from
  98. // Index(), so that we immediately start a pull when new index
  99. // information is available. Before that though, I'd like to build a
  100. // repeatable benchmark of how long it takes to sync a change from
  101. // device A to device B, so we have something to work against.
  102. case <-pullTimer.C:
  103. if !initialScanCompleted {
  104. // How did we even get here?
  105. if debug {
  106. l.Debugln(p, "skip (initial)")
  107. }
  108. pullTimer.Reset(nextPullIntv)
  109. continue
  110. }
  111. p.model.fmut.RLock()
  112. curIgnores := p.model.folderIgnores[p.folder]
  113. p.model.fmut.RUnlock()
  114. if newHash := curIgnores.Hash(); newHash != prevIgnoreHash {
  115. // The ignore patterns have changed. We need to re-evaluate if
  116. // there are files we need now that were ignored before.
  117. if debug {
  118. l.Debugln(p, "ignore patterns have changed, resetting prevVer")
  119. }
  120. prevVer = 0
  121. prevIgnoreHash = newHash
  122. }
  123. // RemoteLocalVersion() is a fast call, doesn't touch the database.
  124. curVer := p.model.RemoteLocalVersion(p.folder)
  125. if curVer == prevVer {
  126. if debug {
  127. l.Debugln(p, "skip (curVer == prevVer)", prevVer)
  128. }
  129. pullTimer.Reset(checkPullIntv)
  130. continue
  131. }
  132. if debug {
  133. l.Debugln(p, "pulling", prevVer, curVer)
  134. }
  135. p.model.setState(p.folder, FolderSyncing)
  136. tries := 0
  137. for {
  138. tries++
  139. changed := p.pullerIteration(curIgnores)
  140. if debug {
  141. l.Debugln(p, "changed", changed)
  142. }
  143. if changed == 0 {
  144. // No files were changed by the puller, so we are in
  145. // sync. Remember the local version number and
  146. // schedule a resync a little bit into the future.
  147. if lv := p.model.RemoteLocalVersion(p.folder); lv < curVer {
  148. // There's a corner case where the device we needed
  149. // files from disconnected during the puller
  150. // iteration. The files will have been removed from
  151. // the index, so we've concluded that we don't need
  152. // them, but at the same time we have the local
  153. // version that includes those files in curVer. So we
  154. // catch the case that localVersion might have
  155. // decreased here.
  156. l.Debugln(p, "adjusting curVer", lv)
  157. curVer = lv
  158. }
  159. prevVer = curVer
  160. if debug {
  161. l.Debugln(p, "next pull in", nextPullIntv)
  162. }
  163. pullTimer.Reset(nextPullIntv)
  164. break
  165. }
  166. if tries > 10 {
  167. // We've tried a bunch of times to get in sync, but
  168. // we're not making it. Probably there are write
  169. // errors preventing us. Flag this with a warning and
  170. // wait a bit longer before retrying.
  171. l.Warnf("Folder %q isn't making progress - check logs for possible root cause. Pausing puller for %v.", p.folder, pauseIntv)
  172. if debug {
  173. l.Debugln(p, "next pull in", pauseIntv)
  174. }
  175. pullTimer.Reset(pauseIntv)
  176. break
  177. }
  178. }
  179. p.model.setState(p.folder, FolderIdle)
  180. // The reason for running the scanner from within the puller is that
  181. // this is the easiest way to make sure we are not doing both at the
  182. // same time.
  183. case <-scanTimer.C:
  184. if debug {
  185. l.Debugln(p, "rescan")
  186. }
  187. p.model.setState(p.folder, FolderScanning)
  188. if err := p.model.ScanFolder(p.folder); err != nil {
  189. p.model.cfg.InvalidateFolder(p.folder, err.Error())
  190. break loop
  191. }
  192. p.model.setState(p.folder, FolderIdle)
  193. if p.scanIntv > 0 {
  194. // Sleep a random time between 3/4 and 5/4 of the configured interval.
  195. sleepNanos := (p.scanIntv.Nanoseconds()*3 + rand.Int63n(2*p.scanIntv.Nanoseconds())) / 4
  196. intv := time.Duration(sleepNanos) * time.Nanosecond
  197. if debug {
  198. l.Debugln(p, "next rescan in", intv)
  199. }
  200. scanTimer.Reset(intv)
  201. }
  202. if !initialScanCompleted {
  203. l.Infoln("Completed initial scan (rw) of folder", p.folder)
  204. initialScanCompleted = true
  205. }
  206. }
  207. }
  208. }
  209. func (p *Puller) Stop() {
  210. close(p.stop)
  211. }
  212. func (p *Puller) String() string {
  213. return fmt.Sprintf("puller/%s@%p", p.folder, p)
  214. }
  215. // pullerIteration runs a single puller iteration for the given folder and
  216. // returns the number items that should have been synced (even those that
  217. // might have failed). One puller iteration handles all files currently
  218. // flagged as needed in the folder.
  219. func (p *Puller) pullerIteration(ignores *ignore.Matcher) int {
  220. pullChan := make(chan pullBlockState)
  221. copyChan := make(chan copyBlocksState)
  222. finisherChan := make(chan *sharedPullerState)
  223. var copyWg sync.WaitGroup
  224. var pullWg sync.WaitGroup
  225. var doneWg sync.WaitGroup
  226. if debug {
  227. l.Debugln(p, "c", p.copiers, "p", p.pullers)
  228. }
  229. for i := 0; i < p.copiers; i++ {
  230. copyWg.Add(1)
  231. go func() {
  232. // copierRoutine finishes when copyChan is closed
  233. p.copierRoutine(copyChan, pullChan, finisherChan)
  234. copyWg.Done()
  235. }()
  236. }
  237. for i := 0; i < p.pullers; i++ {
  238. pullWg.Add(1)
  239. go func() {
  240. // pullerRoutine finishes when pullChan is closed
  241. p.pullerRoutine(pullChan, finisherChan)
  242. pullWg.Done()
  243. }()
  244. }
  245. doneWg.Add(1)
  246. // finisherRoutine finishes when finisherChan is closed
  247. go func() {
  248. p.finisherRoutine(finisherChan)
  249. doneWg.Done()
  250. }()
  251. p.model.fmut.RLock()
  252. folderFiles := p.model.folderFiles[p.folder]
  253. p.model.fmut.RUnlock()
  254. // !!!
  255. // WithNeed takes a database snapshot (by necessity). By the time we've
  256. // handled a bunch of files it might have become out of date and we might
  257. // be attempting to sync with an old version of a file...
  258. // !!!
  259. changed := 0
  260. fileDeletions := map[string]protocol.FileInfo{}
  261. dirDeletions := []protocol.FileInfo{}
  262. buckets := map[string][]protocol.FileInfo{}
  263. folderFiles.WithNeed(protocol.LocalDeviceID, func(intf db.FileIntf) bool {
  264. // Needed items are delivered sorted lexicographically. This isn't
  265. // really optimal from a performance point of view - it would be
  266. // better if files were handled in random order, to spread the load
  267. // over the cluster. But it means that we can be sure that we fully
  268. // handle directories before the files that go inside them, which is
  269. // nice.
  270. file := intf.(protocol.FileInfo)
  271. if ignores.Match(file.Name) {
  272. // This is an ignored file. Skip it, continue iteration.
  273. return true
  274. }
  275. events.Default.Log(events.ItemStarted, map[string]string{
  276. "folder": p.folder,
  277. "item": file.Name,
  278. })
  279. if debug {
  280. l.Debugln(p, "handling", file.Name)
  281. }
  282. switch {
  283. case file.IsDeleted():
  284. // A deleted file, directory or symlink
  285. if file.IsDirectory() {
  286. dirDeletions = append(dirDeletions, file)
  287. } else {
  288. fileDeletions[file.Name] = file
  289. df, ok := p.model.CurrentFolderFile(p.folder, file.Name)
  290. // Local file can be already deleted, but with a lower version
  291. // number, hence the deletion coming in again as part of
  292. // WithNeed, furthermore, the file can simply be of the wrong
  293. // type if we haven't yet managed to pull it.
  294. if ok && !df.IsDeleted() && !df.IsSymlink() && !df.IsDirectory() {
  295. // Put files into buckets per first hash
  296. key := string(df.Blocks[0].Hash)
  297. buckets[key] = append(buckets[key], df)
  298. }
  299. }
  300. case file.IsDirectory() && !file.IsSymlink():
  301. // A new or changed directory
  302. if debug {
  303. l.Debugln("Creating directory", file.Name)
  304. }
  305. p.handleDir(file)
  306. default:
  307. // A new or changed file or symlink. This is the only case where we
  308. // do stuff concurrently in the background
  309. p.queue.Push(file.Name)
  310. }
  311. changed++
  312. return true
  313. })
  314. nextFile:
  315. for {
  316. fileName, ok := p.queue.Pop()
  317. if !ok {
  318. break
  319. }
  320. f, ok := p.model.CurrentGlobalFile(p.folder, fileName)
  321. if !ok {
  322. // File is no longer in the index. Mark it as done and drop it.
  323. p.queue.Done(fileName)
  324. continue
  325. }
  326. // Local file can be already deleted, but with a lower version
  327. // number, hence the deletion coming in again as part of
  328. // WithNeed, furthermore, the file can simply be of the wrong type if
  329. // the global index changed while we were processing this iteration.
  330. if !f.IsDeleted() && !f.IsSymlink() && !f.IsDirectory() {
  331. key := string(f.Blocks[0].Hash)
  332. for i, candidate := range buckets[key] {
  333. if scanner.BlocksEqual(candidate.Blocks, f.Blocks) {
  334. // Remove the candidate from the bucket
  335. lidx := len(buckets[key]) - 1
  336. buckets[key][i] = buckets[key][lidx]
  337. buckets[key] = buckets[key][:lidx]
  338. // candidate is our current state of the file, where as the
  339. // desired state with the delete bit set is in the deletion
  340. // map.
  341. desired := fileDeletions[candidate.Name]
  342. // Remove the pending deletion (as we perform it by renaming)
  343. delete(fileDeletions, candidate.Name)
  344. p.renameFile(desired, f)
  345. p.queue.Done(fileName)
  346. continue nextFile
  347. }
  348. }
  349. }
  350. // Not a rename or a symlink, deal with it.
  351. p.handleFile(f, copyChan, finisherChan)
  352. }
  353. // Signal copy and puller routines that we are done with the in data for
  354. // this iteration. Wait for them to finish.
  355. close(copyChan)
  356. copyWg.Wait()
  357. close(pullChan)
  358. pullWg.Wait()
  359. // Signal the finisher chan that there will be no more input.
  360. close(finisherChan)
  361. // Wait for the finisherChan to finish.
  362. doneWg.Wait()
  363. for _, file := range fileDeletions {
  364. if debug {
  365. l.Debugln("Deleting file", file.Name)
  366. }
  367. p.deleteFile(file)
  368. }
  369. for i := range dirDeletions {
  370. dir := dirDeletions[len(dirDeletions)-i-1]
  371. if debug {
  372. l.Debugln("Deleting dir", dir.Name)
  373. }
  374. p.deleteDir(dir)
  375. }
  376. return changed
  377. }
  378. // handleDir creates or updates the given directory
  379. func (p *Puller) handleDir(file protocol.FileInfo) {
  380. realName := filepath.Join(p.dir, file.Name)
  381. mode := os.FileMode(file.Flags & 0777)
  382. if p.ignorePerms {
  383. mode = 0755
  384. }
  385. if debug {
  386. curFile, _ := p.model.CurrentFolderFile(p.folder, file.Name)
  387. l.Debugf("need dir\n\t%v\n\t%v", file, curFile)
  388. }
  389. info, err := os.Lstat(realName)
  390. switch {
  391. // There is already something under that name, but it's a file/link.
  392. // Most likely a file/link is getting replaced with a directory.
  393. // Remove the file/link and fall through to directory creation.
  394. case err == nil && (!info.IsDir() || info.Mode()&os.ModeSymlink != 0):
  395. err = osutil.InWritableDir(os.Remove, realName)
  396. if err != nil {
  397. l.Infof("Puller (folder %q, dir %q): %v", p.folder, file.Name, err)
  398. return
  399. }
  400. fallthrough
  401. // The directory doesn't exist, so we create it with the right
  402. // mode bits from the start.
  403. case err != nil && os.IsNotExist(err):
  404. // We declare a function that acts on only the path name, so
  405. // we can pass it to InWritableDir. We use a regular Mkdir and
  406. // not MkdirAll because the parent should already exist.
  407. mkdir := func(path string) error {
  408. return os.Mkdir(path, mode)
  409. }
  410. if err = osutil.InWritableDir(mkdir, realName); err == nil {
  411. p.model.updateLocal(p.folder, file)
  412. } else {
  413. l.Infof("Puller (folder %q, dir %q): %v", p.folder, file.Name, err)
  414. }
  415. return
  416. // Weird error when stat()'ing the dir. Probably won't work to do
  417. // anything else with it if we can't even stat() it.
  418. case err != nil:
  419. l.Infof("Puller (folder %q, dir %q): %v", p.folder, file.Name, err)
  420. return
  421. }
  422. // The directory already exists, so we just correct the mode bits. (We
  423. // don't handle modification times on directories, because that sucks...)
  424. // It's OK to change mode bits on stuff within non-writable directories.
  425. if p.ignorePerms {
  426. p.model.updateLocal(p.folder, file)
  427. } else if err := os.Chmod(realName, mode); err == nil {
  428. p.model.updateLocal(p.folder, file)
  429. } else {
  430. l.Infof("Puller (folder %q, dir %q): %v", p.folder, file.Name, err)
  431. }
  432. }
  433. // deleteDir attempts to delete the given directory
  434. func (p *Puller) deleteDir(file protocol.FileInfo) {
  435. realName := filepath.Join(p.dir, file.Name)
  436. // Delete any temporary files lying around in the directory
  437. dir, _ := os.Open(realName)
  438. if dir != nil {
  439. files, _ := dir.Readdirnames(-1)
  440. for _, file := range files {
  441. if defTempNamer.IsTemporary(file) {
  442. osutil.InWritableDir(os.Remove, filepath.Join(realName, file))
  443. }
  444. }
  445. }
  446. err := osutil.InWritableDir(os.Remove, realName)
  447. if err == nil || os.IsNotExist(err) {
  448. p.model.updateLocal(p.folder, file)
  449. } else {
  450. l.Infof("Puller (folder %q, dir %q): delete: %v", p.folder, file.Name, err)
  451. }
  452. }
  453. // deleteFile attempts to delete the given file
  454. func (p *Puller) deleteFile(file protocol.FileInfo) {
  455. realName := filepath.Join(p.dir, file.Name)
  456. var err error
  457. if p.versioner != nil {
  458. err = osutil.InWritableDir(p.versioner.Archive, realName)
  459. } else {
  460. err = osutil.InWritableDir(os.Remove, realName)
  461. }
  462. if err != nil && !os.IsNotExist(err) {
  463. l.Infof("Puller (folder %q, file %q): delete: %v", p.folder, file.Name, err)
  464. } else {
  465. p.model.updateLocal(p.folder, file)
  466. }
  467. }
  468. // renameFile attempts to rename an existing file to a destination
  469. // and set the right attributes on it.
  470. func (p *Puller) renameFile(source, target protocol.FileInfo) {
  471. if debug {
  472. l.Debugln(p, "taking rename shortcut", source.Name, "->", target.Name)
  473. }
  474. from := filepath.Join(p.dir, source.Name)
  475. to := filepath.Join(p.dir, target.Name)
  476. var err error
  477. if p.versioner != nil {
  478. err = osutil.Copy(from, to)
  479. if err == nil {
  480. err = osutil.InWritableDir(p.versioner.Archive, from)
  481. }
  482. } else {
  483. err = osutil.TryRename(from, to)
  484. }
  485. if err != nil {
  486. l.Infof("Puller (folder %q, file %q): rename from %q: %v", p.folder, target.Name, source.Name, err)
  487. return
  488. }
  489. // Fix-up the metadata, and update the local index of the target file
  490. p.shortcutFile(target)
  491. // Source file already has the delete bit set.
  492. // Because we got rid of the file (by renaming it), we just need to update
  493. // the index, and we're done with it.
  494. p.model.updateLocal(p.folder, source)
  495. }
  496. // handleFile queues the copies and pulls as necessary for a single new or
  497. // changed file.
  498. func (p *Puller) handleFile(file protocol.FileInfo, copyChan chan<- copyBlocksState, finisherChan chan<- *sharedPullerState) {
  499. curFile, ok := p.model.CurrentFolderFile(p.folder, file.Name)
  500. if ok && len(curFile.Blocks) == len(file.Blocks) && scanner.BlocksEqual(curFile.Blocks, file.Blocks) {
  501. // We are supposed to copy the entire file, and then fetch nothing. We
  502. // are only updating metadata, so we don't actually *need* to make the
  503. // copy.
  504. if debug {
  505. l.Debugln(p, "taking shortcut on", file.Name)
  506. }
  507. p.queue.Done(file.Name)
  508. if file.IsSymlink() {
  509. p.shortcutSymlink(file)
  510. } else {
  511. p.shortcutFile(file)
  512. }
  513. return
  514. }
  515. scanner.PopulateOffsets(file.Blocks)
  516. // Figure out the absolute filenames we need once and for all
  517. tempName := filepath.Join(p.dir, defTempNamer.TempName(file.Name))
  518. realName := filepath.Join(p.dir, file.Name)
  519. reused := 0
  520. var blocks []protocol.BlockInfo
  521. // Check for an old temporary file which might have some blocks we could
  522. // reuse.
  523. tempBlocks, err := scanner.HashFile(tempName, protocol.BlockSize)
  524. if err == nil {
  525. // Check for any reusable blocks in the temp file
  526. tempCopyBlocks, _ := scanner.BlockDiff(tempBlocks, file.Blocks)
  527. // block.String() returns a string unique to the block
  528. existingBlocks := make(map[string]bool, len(tempCopyBlocks))
  529. for _, block := range tempCopyBlocks {
  530. existingBlocks[block.String()] = true
  531. }
  532. // Since the blocks are already there, we don't need to get them.
  533. for _, block := range file.Blocks {
  534. _, ok := existingBlocks[block.String()]
  535. if !ok {
  536. blocks = append(blocks, block)
  537. }
  538. }
  539. // The sharedpullerstate will know which flags to use when opening the
  540. // temp file depending if we are reusing any blocks or not.
  541. reused = len(file.Blocks) - len(blocks)
  542. if reused == 0 {
  543. // Otherwise, discard the file ourselves in order for the
  544. // sharedpuller not to panic when it fails to exlusively create a
  545. // file which already exists
  546. os.Remove(tempName)
  547. }
  548. } else {
  549. blocks = file.Blocks
  550. }
  551. s := sharedPullerState{
  552. file: file,
  553. folder: p.folder,
  554. tempName: tempName,
  555. realName: realName,
  556. copyTotal: len(blocks),
  557. copyNeeded: len(blocks),
  558. reused: reused,
  559. }
  560. if debug {
  561. l.Debugf("%v need file %s; copy %d, reused %v", p, file.Name, len(blocks), reused)
  562. }
  563. cs := copyBlocksState{
  564. sharedPullerState: &s,
  565. blocks: blocks,
  566. }
  567. copyChan <- cs
  568. }
  569. // shortcutFile sets file mode and modification time, when that's the only
  570. // thing that has changed.
  571. func (p *Puller) shortcutFile(file protocol.FileInfo) {
  572. realName := filepath.Join(p.dir, file.Name)
  573. if !p.ignorePerms {
  574. err := os.Chmod(realName, os.FileMode(file.Flags&0777))
  575. if err != nil {
  576. l.Infof("Puller (folder %q, file %q): shortcut: %v", p.folder, file.Name, err)
  577. return
  578. }
  579. }
  580. t := time.Unix(file.Modified, 0)
  581. err := os.Chtimes(realName, t, t)
  582. if err != nil {
  583. if p.lenientMtimes {
  584. // We accept the failure with a warning here and allow the sync to
  585. // continue. We'll sync the new mtime back to the other devices later.
  586. // If they have the same problem & setting, we might never get in
  587. // sync.
  588. l.Infof("Puller (folder %q, file %q): shortcut: %v (continuing anyway as requested)", p.folder, file.Name, err)
  589. } else {
  590. l.Infof("Puller (folder %q, file %q): shortcut: %v", p.folder, file.Name, err)
  591. return
  592. }
  593. }
  594. p.model.updateLocal(p.folder, file)
  595. }
  596. // shortcutSymlink changes the symlinks type if necessery.
  597. func (p *Puller) shortcutSymlink(file protocol.FileInfo) {
  598. err := symlinks.ChangeType(filepath.Join(p.dir, file.Name), file.Flags)
  599. if err != nil {
  600. l.Infof("Puller (folder %q, file %q): symlink shortcut: %v", p.folder, file.Name, err)
  601. return
  602. }
  603. p.model.updateLocal(p.folder, file)
  604. }
  605. // copierRoutine reads copierStates until the in channel closes and performs
  606. // the relevant copies when possible, or passes it to the puller routine.
  607. func (p *Puller) copierRoutine(in <-chan copyBlocksState, pullChan chan<- pullBlockState, out chan<- *sharedPullerState) {
  608. buf := make([]byte, protocol.BlockSize)
  609. for state := range in {
  610. if p.progressEmitter != nil {
  611. p.progressEmitter.Register(state.sharedPullerState)
  612. }
  613. dstFd, err := state.tempFile()
  614. if err != nil {
  615. // Nothing more to do for this failed file (the error was logged
  616. // when it happened)
  617. out <- state.sharedPullerState
  618. continue
  619. }
  620. evictionChan := make(chan lfu.Eviction)
  621. fdCache := lfu.New()
  622. fdCache.UpperBound = 50
  623. fdCache.LowerBound = 20
  624. fdCache.EvictionChannel = evictionChan
  625. go func() {
  626. for item := range evictionChan {
  627. item.Value.(*os.File).Close()
  628. }
  629. }()
  630. folderRoots := make(map[string]string)
  631. p.model.fmut.RLock()
  632. for folder, cfg := range p.model.folderCfgs {
  633. folderRoots[folder] = cfg.Path
  634. }
  635. p.model.fmut.RUnlock()
  636. for _, block := range state.blocks {
  637. buf = buf[:int(block.Size)]
  638. found := p.model.finder.Iterate(block.Hash, func(folder, file string, index int32) bool {
  639. path := filepath.Join(folderRoots[folder], file)
  640. var fd *os.File
  641. fdi := fdCache.Get(path)
  642. if fdi != nil {
  643. fd = fdi.(*os.File)
  644. } else {
  645. fd, err = os.Open(path)
  646. if err != nil {
  647. return false
  648. }
  649. fdCache.Set(path, fd)
  650. }
  651. _, err = fd.ReadAt(buf, protocol.BlockSize*int64(index))
  652. if err != nil {
  653. return false
  654. }
  655. hash, err := scanner.VerifyBuffer(buf, block)
  656. if err != nil {
  657. if hash != nil {
  658. if debug {
  659. l.Debugf("Finder block mismatch in %s:%s:%d expected %q got %q", folder, file, index, block.Hash, hash)
  660. }
  661. err = p.model.finder.Fix(folder, file, index, block.Hash, hash)
  662. if err != nil {
  663. l.Warnln("finder fix:", err)
  664. }
  665. } else if debug {
  666. l.Debugln("Finder failed to verify buffer", err)
  667. }
  668. return false
  669. }
  670. _, err = dstFd.WriteAt(buf, block.Offset)
  671. if err != nil {
  672. state.fail("dst write", err)
  673. }
  674. if file == state.file.Name {
  675. state.copiedFromOrigin()
  676. }
  677. return true
  678. })
  679. if state.failed() != nil {
  680. break
  681. }
  682. if !found {
  683. state.pullStarted()
  684. ps := pullBlockState{
  685. sharedPullerState: state.sharedPullerState,
  686. block: block,
  687. }
  688. pullChan <- ps
  689. } else {
  690. state.copyDone()
  691. }
  692. }
  693. fdCache.Evict(fdCache.Len())
  694. close(evictionChan)
  695. out <- state.sharedPullerState
  696. }
  697. }
  698. func (p *Puller) pullerRoutine(in <-chan pullBlockState, out chan<- *sharedPullerState) {
  699. for state := range in {
  700. if state.failed() != nil {
  701. continue
  702. }
  703. // Get an fd to the temporary file. Tehcnically we don't need it until
  704. // after fetching the block, but if we run into an error here there is
  705. // no point in issuing the request to the network.
  706. fd, err := state.tempFile()
  707. if err != nil {
  708. continue
  709. }
  710. var lastError error
  711. potentialDevices := p.model.availability(p.folder, state.file.Name)
  712. for {
  713. // Select the least busy device to pull the block from. If we found no
  714. // feasible device at all, fail the block (and in the long run, the
  715. // file).
  716. selected := activity.leastBusy(potentialDevices)
  717. if selected == (protocol.DeviceID{}) {
  718. if lastError != nil {
  719. state.fail("pull", lastError)
  720. } else {
  721. state.fail("pull", errNoDevice)
  722. }
  723. break
  724. }
  725. potentialDevices = removeDevice(potentialDevices, selected)
  726. // Fetch the block, while marking the selected device as in use so that
  727. // leastBusy can select another device when someone else asks.
  728. activity.using(selected)
  729. buf, lastError := p.model.requestGlobal(selected, p.folder, state.file.Name, state.block.Offset, int(state.block.Size), state.block.Hash)
  730. activity.done(selected)
  731. if lastError != nil {
  732. continue
  733. }
  734. // Verify that the received block matches the desired hash, if not
  735. // try pulling it from another device.
  736. _, lastError = scanner.VerifyBuffer(buf, state.block)
  737. if lastError != nil {
  738. continue
  739. }
  740. // Save the block data we got from the cluster
  741. _, err = fd.WriteAt(buf, state.block.Offset)
  742. if err != nil {
  743. state.fail("save", err)
  744. } else {
  745. state.pullDone()
  746. }
  747. break
  748. }
  749. out <- state.sharedPullerState
  750. }
  751. }
  752. func (p *Puller) performFinish(state *sharedPullerState) {
  753. var err error
  754. // Set the correct permission bits on the new file
  755. if !p.ignorePerms {
  756. err = os.Chmod(state.tempName, os.FileMode(state.file.Flags&0777))
  757. if err != nil {
  758. l.Warnln("puller: final:", err)
  759. return
  760. }
  761. }
  762. // Set the correct timestamp on the new file
  763. t := time.Unix(state.file.Modified, 0)
  764. err = os.Chtimes(state.tempName, t, t)
  765. if err != nil {
  766. if p.lenientMtimes {
  767. // We accept the failure with a warning here and allow the sync to
  768. // continue. We'll sync the new mtime back to the other devices later.
  769. // If they have the same problem & setting, we might never get in
  770. // sync.
  771. l.Infof("Puller (folder %q, file %q): final: %v (continuing anyway as requested)", p.folder, state.file.Name, err)
  772. } else {
  773. l.Warnln("puller: final:", err)
  774. return
  775. }
  776. }
  777. // If we should use versioning, let the versioner archive the old
  778. // file before we replace it. Archiving a non-existent file is not
  779. // an error.
  780. if p.versioner != nil {
  781. err = p.versioner.Archive(state.realName)
  782. if err != nil {
  783. l.Warnln("puller: final:", err)
  784. return
  785. }
  786. }
  787. // If the target path is a symlink or a directory, we cannot copy
  788. // over it, hence remove it before proceeding.
  789. stat, err := os.Lstat(state.realName)
  790. if err == nil && (stat.IsDir() || stat.Mode()&os.ModeSymlink != 0) {
  791. osutil.InWritableDir(os.Remove, state.realName)
  792. }
  793. // Replace the original content with the new one
  794. err = osutil.Rename(state.tempName, state.realName)
  795. if err != nil {
  796. l.Warnln("puller: final:", err)
  797. return
  798. }
  799. // If it's a symlink, the target of the symlink is inside the file.
  800. if state.file.IsSymlink() {
  801. content, err := ioutil.ReadFile(state.realName)
  802. if err != nil {
  803. l.Warnln("puller: final: reading symlink:", err)
  804. return
  805. }
  806. // Remove the file, and replace it with a symlink.
  807. err = osutil.InWritableDir(func(path string) error {
  808. os.Remove(path)
  809. return symlinks.Create(path, string(content), state.file.Flags)
  810. }, state.realName)
  811. if err != nil {
  812. l.Warnln("puller: final: creating symlink:", err)
  813. return
  814. }
  815. }
  816. // Record the updated file in the index
  817. p.model.updateLocal(p.folder, state.file)
  818. }
  819. func (p *Puller) finisherRoutine(in <-chan *sharedPullerState) {
  820. for state := range in {
  821. if closed, err := state.finalClose(); closed {
  822. if debug {
  823. l.Debugln(p, "closing", state.file.Name)
  824. }
  825. if err != nil {
  826. l.Warnln("puller: final:", err)
  827. continue
  828. }
  829. p.queue.Done(state.file.Name)
  830. if state.failed() == nil {
  831. p.performFinish(state)
  832. }
  833. p.model.receivedFile(p.folder, state.file.Name)
  834. if p.progressEmitter != nil {
  835. p.progressEmitter.Deregister(state)
  836. }
  837. }
  838. }
  839. }
  840. // Moves the given filename to the front of the job queue
  841. func (p *Puller) BringToFront(filename string) {
  842. p.queue.BringToFront(filename)
  843. }
  844. func (p *Puller) Jobs() ([]string, []string) {
  845. return p.queue.Jobs()
  846. }
  847. func invalidateFolder(cfg *config.Configuration, folderID string, err error) {
  848. for i := range cfg.Folders {
  849. folder := &cfg.Folders[i]
  850. if folder.ID == folderID {
  851. folder.Invalid = err.Error()
  852. return
  853. }
  854. }
  855. }
  856. func removeDevice(devices []protocol.DeviceID, device protocol.DeviceID) []protocol.DeviceID {
  857. for i := range devices {
  858. if devices[i] == device {
  859. devices[i] = devices[len(devices)-1]
  860. return devices[:len(devices)-1]
  861. }
  862. }
  863. return devices
  864. }