mutagen-io / mutagen

Fast file synchronization and network forwarding for remote development
https://mutagen.io
Other
3.47k stars 153 forks source link

Really slow scan/staging on NFS mount #488

Open scruel opened 8 months ago

scruel commented 8 months ago

I want to sync folder between remote and local WSL, the folder on WSL is NFS mounted rather than actual, when I create a file on remote host, mutagen will be able to detect it quite quick, however it will take lots of time to apply the change on WSL's nfs mounted folder. And for creating new files on WSL, mutagen also won't detect such modification change immediately. The delay is basically more than a minute, which is not acceptable. I think its the problem happened on the WSL side along with the NFS protocol (NFS 4.1).

Config

Name: learn
Identifier: sync_OGLNOkm7X78Y0eq5T3Xx84Yvt7kXoh8UeBc4Zi1EJ4G
Configuration:
        Synchronization mode: Default (Two Way Safe)
        Hashing algorithm: Default (SHA-1)
        Maximum allowed entry count: Default (2⁶⁴−1)
        Maximum staging file size: 1024000000 (1.0 GB)
        Symbolic link mode: POSIX Raw
        Ignore VCS mode: Default (Propagate)
        Ignores:
                .env
        Permissions mode: Default (Portable)
Alpha:
        URL: /mnt/n/test
        Configuration:
                Watch mode: Default (Portable)
                Watch polling interval: Default (10 seconds)
                Probe mode: Default (Probe)
                Scan mode: Default (Accelerated)
                Stage mode: Neighboring
                File mode: 0660
                Directory mode: 0770
                Default file/directory owner: scruel
                Default file/directory group: Default
        Connected: Yes
        Synchronizable contents:
                7522 directories
                47201 files (15 GB)
                0 symbolic links
Beta:
        URL: scruel@remote.host/home/test
        Configuration:
                Watch mode: Default (Portable)
                Watch polling interval: Default (10 seconds)
                Probe mode: Default (Probe)
                Scan mode: Default (Accelerated)
                Stage mode: Neighboring
                File mode: 0660
                Directory mode: 0770
                Default file/directory owner: scruel
                Default file/directory group: Default
                Compression: Default (DEFLATE)
        Connected: Yes
        Synchronizable contents:
                7522 directories
                47201 files (15 GB)
                0 symbolic links
Status: Watching for changes

Related Log:

$ mount -t nfs nas.host:/volume2/test /mnt/n/test
$ mutagen daemon run
2024-03-27 23:25:44.008865 [D] [sync.sync_OGLNOkm7.beta] [polling] Modifications detected
2024-03-27 23:25:44.257601 [D] [sync.sync_OGLNOkm7] Triggered by beta endpoint
2024-03-27 23:25:44.257722 [D] [sync.sync_OGLNOkm7] Scanning endpoints
2024-03-27 23:25:44.257887 [D] [sync.sync_OGLNOkm7.beta] Using last snapshot bytes as baseline
2024-03-27 23:25:44.049261 [D] [sync.sync_OGLNOkm7.beta] Performing accelerated scan with existing snapshot
2024-03-27 23:25:44.284054 [D] [sync.sync_OGLNOkm7.beta] Snapshot delta yielded 310437 bytes using 1 block operation(s) and 2 data operation(s) totaling 4789 byte(s)
2024-03-27 23:26:01.318181 [D] [sync.sync_OGLNOkm7] Staging 1 file(s) on alpha
2024-03-27 23:26:38.365876 [D] [sync.sync_OGLNOkm7] Alpha pre-staged 1/1 files
2024-03-27 23:26:38.365945 [D] [sync.sync_OGLNOkm7] Transitioning alpha
2024-03-27 23:28:21.599477 [D] [sync.sync_OGLNOkm7] Saving ancestor
2024-03-27 23:28:21.604478 [D] [sync.sync_OGLNOkm7] Triggered by alpha endpoint
2024-03-27 23:28:21.612459 [D] [sync.sync_OGLNOkm7] Scanning endpoints
2024-03-27 23:28:21.612545 [D] [sync.sync_OGLNOkm7.beta] Using last snapshot bytes as baseline
Full log: ```shell $ mutagen daemon run 2024-03-27 23:22:09.896945 [I] [forward] Looking for existing sessions 2024-03-27 23:22:09.897403 [I] [forward] Session manager initialized 2024-03-27 23:22:09.897533 [I] [sync] Looking for existing sessions 2024-03-27 23:22:09.898100 [I] [sync] Loading session sync_OGLNOkm7X78Y0eq5T3Xx84Yvt7kXoh8UeBc4Zi1EJ4G 2024-03-27 23:22:09.898517 [I] [sync.sync_OGLNOkm7] Session loaded 2024-03-27 23:22:09.898541 [I] [sync] Session manager initialized 2024-03-27 23:22:09.898571 [D] [sync.sync_OGLNOkm7] Run loop commencing 2024-03-27 23:22:09.942255 [D] [sync.sync_OGLNOkm7.alpha.polling] Creating non-recursive watcher 2024-03-27 23:22:09.942495 [D] [sync.sync_OGLNOkm7.alpha.polling] Successfully created non-recursive watcher 2024-03-27 23:22:09.942545 [D] [sync.sync_OGLNOkm7.alpha.polling] Performing filesystem scan 2024-03-27 23:22:11.252596 [I] [sync.sync_OGLNOkm7.beta] [housekeeping] Performing initial housekeeping 2024-03-27 23:22:11.533054 [D] [sync.sync_OGLNOkm7] Entering synchronization loop 2024-03-27 23:22:11.294817 [D] [sync.sync_OGLNOkm7.beta] [polling] Creating non-recursive watcher 2024-03-27 23:22:11.297369 [D] [sync.sync_OGLNOkm7.beta] [polling] Successfully created non-recursive watcher 2024-03-27 23:22:11.297497 [D] [sync.sync_OGLNOkm7.beta] [polling] Performing filesystem scan 2024-03-27 23:22:11.548792 [D] [sync.sync_OGLNOkm7] Skipping polling 2024-03-27 23:22:11.548836 [D] [sync.sync_OGLNOkm7] Scanning endpoints 2024-03-27 23:22:11.548909 [D] [sync.sync_OGLNOkm7.beta] Using ancestor-based snapshot as baseline 2024-03-27 23:22:11.336090 [D] [sync.sync_OGLNOkm7.beta] [polling] Accelerated scanning now available 2024-03-27 23:22:11.336159 [D] [sync.sync_OGLNOkm7.beta] [polling] No unignored modifications detected 2024-03-27 23:22:11.336144 [D] [sync.sync_OGLNOkm7.beta] Saving cache to disk 2024-03-27 23:22:11.352674 [D] [sync.sync_OGLNOkm7.beta] Performing accelerated scan with existing snapshot 2024-03-27 23:22:11.610994 [D] [sync.sync_OGLNOkm7.beta] Snapshot delta yielded 310406 bytes using 1 block operation(s) and 2 data operation(s) totaling 4758 byte(s) 2024-03-27 23:22:59.960494 [D] [sync.sync_OGLNOkm7] Performing reconciliation 2024-03-27 23:25:11.579305 [D] [sync.sync_OGLNOkm7.alpha.polling] Accelerated scanning now available 2024-03-27 23:25:11.582330 [D] [sync.sync_OGLNOkm7.alpha.polling] No unignored modifications detected 2024-03-27 23:25:19.942814 [D] [sync.sync_OGLNOkm7.alpha.polling] Received timer-based polling signal 2024-03-27 23:25:19.942853 [D] [sync.sync_OGLNOkm7.alpha.polling] Performing filesystem scan 2024-03-27 23:25:31.379852 [D] [sync.sync_OGLNOkm7.beta] Saving cache to disk 2024-03-27 23:25:41.357492 [D] [sync.sync_OGLNOkm7.beta] [polling] No unignored modifications detected 2024-03-27 23:25:43.937614 [D] [sync.sync_OGLNOkm7.beta] [polling] Received event-driven polling signal 2024-03-27 23:25:43.937645 [D] [sync.sync_OGLNOkm7.beta] [polling] Performing filesystem scan 2024-03-27 23:25:44.005129 [D] [sync.sync_OGLNOkm7.beta] [polling] Accelerated scanning now available 2024-03-27 23:25:44.008865 [D] [sync.sync_OGLNOkm7.beta] [polling] Modifications detected 2024-03-27 23:25:44.257601 [D] [sync.sync_OGLNOkm7] Triggered by beta endpoint 2024-03-27 23:25:44.257722 [D] [sync.sync_OGLNOkm7] Scanning endpoints 2024-03-27 23:25:44.257887 [D] [sync.sync_OGLNOkm7.beta] Using last snapshot bytes as baseline 2024-03-27 23:25:44.049261 [D] [sync.sync_OGLNOkm7.beta] Performing accelerated scan with existing snapshot 2024-03-27 23:25:44.284054 [D] [sync.sync_OGLNOkm7.beta] Snapshot delta yielded 310437 bytes using 1 block operation(s) and 2 data operation(s) totaling 4789 byte(s) 2024-03-27 23:25:51.301428 [D] [sync.sync_OGLNOkm7.beta] [polling] Received timer-based polling signal 2024-03-27 23:25:51.301468 [D] [sync.sync_OGLNOkm7.beta] [polling] Performing filesystem scan 2024-03-27 23:25:51.347372 [D] [sync.sync_OGLNOkm7.beta] [polling] Accelerated scanning now available 2024-03-27 23:25:51.350825 [D] [sync.sync_OGLNOkm7.beta] [polling] No unignored modifications detected 2024-03-27 23:26:01.304197 [D] [sync.sync_OGLNOkm7.alpha.polling] Accelerated scanning now available 2024-03-27 23:26:01.304372 [D] [sync.sync_OGLNOkm7.alpha] Performing accelerated scan with existing snapshot 2024-03-27 23:26:01.308470 [D] [sync.sync_OGLNOkm7.alpha.polling] No unignored modifications detected 2024-03-27 23:26:01.308525 [D] [sync.sync_OGLNOkm7.alpha.polling] Received timer-based polling signal 2024-03-27 23:26:01.308528 [D] [sync.sync_OGLNOkm7.alpha.polling] Performing filesystem scan 2024-03-27 23:26:01.314005 [D] [sync.sync_OGLNOkm7] Performing reconciliation 2024-03-27 23:26:01.318181 [D] [sync.sync_OGLNOkm7] Staging 1 file(s) on alpha 2024-03-27 23:26:01.304556 [D] [sync.sync_OGLNOkm7.beta] [polling] Received timer-based polling signal 2024-03-27 23:26:01.304597 [D] [sync.sync_OGLNOkm7.beta] [polling] Performing filesystem scan 2024-03-27 23:26:01.373591 [D] [sync.sync_OGLNOkm7.beta] [polling] Accelerated scanning now available 2024-03-27 23:26:01.378406 [D] [sync.sync_OGLNOkm7.beta] [polling] No unignored modifications detected 2024-03-27 23:26:38.152751 [D] [sync.sync_OGLNOkm7.alpha.polling] Accelerated scanning now available 2024-03-27 23:26:38.152848 [D] [sync.sync_OGLNOkm7.alpha] Saving cache to disk 2024-03-27 23:26:38.155833 [D] [sync.sync_OGLNOkm7.alpha.polling] No unignored modifications detected 2024-03-27 23:26:38.155860 [D] [sync.sync_OGLNOkm7.alpha.polling] Received timer-based polling signal 2024-03-27 23:26:38.158911 [D] [sync.sync_OGLNOkm7.alpha.polling] Performing filesystem scan 2024-03-27 23:26:38.365876 [D] [sync.sync_OGLNOkm7] Alpha pre-staged 1/1 files 2024-03-27 23:26:38.365945 [D] [sync.sync_OGLNOkm7] Transitioning alpha 2024-03-27 23:26:41.304098 [D] [sync.sync_OGLNOkm7.beta] [polling] Received timer-based polling signal 2024-03-27 23:26:41.304169 [D] [sync.sync_OGLNOkm7.beta] [polling] Performing filesystem scan 2024-03-27 23:26:41.374794 [D] [sync.sync_OGLNOkm7.beta] Saving cache to disk 2024-03-27 23:27:45.290996 [D] [sync.sync_OGLNOkm7.alpha] Saving cache to disk 2024-03-27 23:28:21.364022 [D] [sync.sync_OGLNOkm7.beta] [polling] Accelerated scanning now available 2024-03-27 23:28:21.368636 [D] [sync.sync_OGLNOkm7.beta] [polling] No unignored modifications detected 2024-03-27 23:28:21.597604 [D] [sync.sync_OGLNOkm7.alpha.polling] Performing filesystem scan 2024-03-27 23:28:21.599477 [D] [sync.sync_OGLNOkm7] Saving ancestor 2024-03-27 23:28:21.604478 [D] [sync.sync_OGLNOkm7] Triggered by alpha endpoint 2024-03-27 23:28:21.612459 [D] [sync.sync_OGLNOkm7] Scanning endpoints 2024-03-27 23:28:21.612545 [D] [sync.sync_OGLNOkm7.beta] Using last snapshot bytes as baseline 2024-03-27 23:28:21.407085 [D] [sync.sync_OGLNOkm7.beta] Performing accelerated scan with existing snapshot 2024-03-27 23:28:21.636473 [D] [sync.sync_OGLNOkm7.beta] Snapshot delta yielded 310437 bytes using 1 block operation(s) and 0 data operation(s) totaling 0 byte(s) 2024-03-27 23:28:31.304185 [D] [sync.sync_OGLNOkm7.beta] [polling] Received timer-based polling signal 2024-03-27 23:28:31.304320 [D] [sync.sync_OGLNOkm7.beta] [polling] Performing filesystem scan 2024-03-27 23:28:31.368359 [D] [sync.sync_OGLNOkm7.beta] [polling] Accelerated scanning now available 2024-03-27 23:28:31.372889 [D] [sync.sync_OGLNOkm7.beta] [polling] No unignored modifications detected 2024-03-27 23:28:31.622620 [D] [sync.sync_OGLNOkm7.alpha.polling] Accelerated scanning now available 2024-03-27 23:28:31.622869 [D] [sync.sync_OGLNOkm7.alpha] Performing accelerated scan with existing snapshot 2024-03-27 23:28:31.626366 [D] [sync.sync_OGLNOkm7] Performing reconciliation 2024-03-27 23:28:31.630049 [D] [sync.sync_OGLNOkm7.alpha.polling] Modifications detected 2024-03-27 23:28:31.630112 [D] [sync.sync_OGLNOkm7.alpha.polling] Received event-driven polling signal 2024-03-27 23:28:31.630134 [D] [sync.sync_OGLNOkm7.alpha.polling] Performing filesystem scan 2024-03-27 23:28:31.650480 [D] [sync.sync_OGLNOkm7] Triggered by alpha endpoint 2024-03-27 23:28:31.655558 [D] [sync.sync_OGLNOkm7] Scanning endpoints 2024-03-27 23:28:31.655650 [D] [sync.sync_OGLNOkm7.beta] Using last snapshot bytes as baseline 2024-03-27 23:28:31.450117 [D] [sync.sync_OGLNOkm7.beta] Performing accelerated scan with existing snapshot 2024-03-27 23:28:31.674902 [D] [sync.sync_OGLNOkm7.beta] Snapshot delta yielded 310437 bytes using 1 block operation(s) and 0 data operation(s) totaling 0 byte(s) 2024-03-27 23:28:33.758286 [D] [sync.sync_OGLNOkm7.alpha.polling] Accelerated scanning now available 2024-03-27 23:28:33.758416 [D] [sync.sync_OGLNOkm7.alpha] Performing accelerated scan with existing snapshot 2024-03-27 23:28:33.761333 [D] [sync.sync_OGLNOkm7] Performing reconciliation 2024-03-27 23:28:33.762369 [D] [sync.sync_OGLNOkm7.alpha.polling] No unignored modifications detected ```