Unison hangs after macfuse 5.0.7 update #1120
Description
Hello,
This might not be strictly a macfuse problem but since it happens after updating to macfuse 5.0.7 I decided to write an issue.
My setup is quite peculiar (I think), I'm using a Mac mini with Sequoia installed and the latest Unison 2.53.7 on it. Then I also have Macfuse and Gogryptfs in use.
I use Unison and Gocryptfs (using Macfuse), which I use to have an encrypted folder with the option of -plaintextnames so everything is encrypted except the filenames, that way I can see what files will be synchronized and what direction. Then I synchronized my files with Unison to a private server (FreeBSD 14 with Unison 2.53.5) which acts as a central point.
The the other day (via Macports) Macfuse was updated to the latest 5.0.7 version, and although it seems to be working fine, I can mount the folder with macfuse then and I tried to run Unison, the process got stuck right after the Reconciling changes message, here is a log with macfuse 5.0.7 and Unison 2.53.7:
Reconciling changes
[recon] reconcileAll
[recon] reconcile: 0 results
[update] Marking 0 paths equal
[update] Updating archives
[remote+] send [lockArchive-args] '\000\000\000\000\000\000\000\024\001\022...' 32 bytes
[remote+] send [rsp] '\000\000\000\000\000\000\000\014\003\001...' 22 bytes
[remote+] Sending request (id: 13)
[remote_emit+] dump: \r\000\000\000\219\025\000\000\000Grsp\000\000\000\000\000\000\000\014\003\001\011lockArchive0\000\000\000\194lockArchive-args\000\000\000\000\000\000\000\024\001\022/data1/home/xxxxx/doc
[update+] Archive name is //rubik-macmini//Users/xxxxx/.doc;//xxxxx//data1/home/xxxxx/doc, //rubik-macmini//Users/xxxxx/.doc;23; hashcode is c86567f23cab39f1e10f84b6e7ba2917
[server: remote_emit+] grab: \r\000\000\000\219\025\000\000\000Grsp\000\000\000\000\000\000\000\014\003\001\011lockArchive0\000\000\000\194lockArchive-args\000\000\000\000\000\000\000\024\001\022/data1/home/xxxxx/doc
[server: remote+] Message received (id: 13)
[server: remote+] receive 'rsp\000\000\000\000\000\000\000...' 25 bytes
[server: remote+] receive 'lockArchiv...' 48 bytes
[server: remote+] Waiting for next message
[server: update+] Archive name is //xxxxx//data1/home/xxxxx/doc;//xxxxx//data1/home/xxxxx/doc, //rubik-macmini//Users/xxxxx/.doc;23; hashcode is dd5c6ac06b0499185151ee2e4194dfcd
[server: remote+] Sending result (id: 13)
[server: remote+] send [lockArchive-res] '\000\000\000\000\000\000\000\001\000' 9 bytes
[server: remote+] send [rsp] '\000\000\000\000\000\000\000\001\000' 9 bytes
[server: remote_emit+] dump: \r\000\000\000\219\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\024\000\000\000\233lockArchive-res\000\000\000\000\000\000\000\001\000
I downgraded to Macfuse 5.0.6 and it Unison runs fine.. this is the same log with macfuse 5.0.6
Reconciling changes
[recon] reconcileAll
[recon] reconcile: 0 results
[update] Marking 0 paths equal
[update] Updating archives
[remote+] send [lockArchive-args] '\000\000\000\000\000\000\000\024\001\022...' 32 bytes
[remote+] send [rsp] '\000\000\000\000\000\000\000\014\003\001...' 22 bytes
[remote+] Sending request (id: 13)
[remote_emit+] dump: \r\000\000\000\219\025\000\000\000Grsp\000\000\000\000\000\000\000\014\003\001\011lockArchive0\000\000\000\194lockArchive-args\000\000\000\000\000\000\000\024\001\022/data1/home/xxxxxxxxx/doc
[update+] Archive name is //xxxxxxxxx//Users/xxxxxxxxx/.doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is c86567f23cab39f1e10f84b6e7ba2917
[server: remote_emit+] grab: \r\000\000\000\219\025\000\000\000Grsp\000\000\000\000\000\000\000\014\003\001\011lockArchive0\000\000\000\194lockArchive-args\000\000\000\000\000\000\000\024\001\022/data1/home/xxxxxxxxx/doc
[server: remote+] Message received (id: 13)
[server: remote+] receive 'rsp\000\000\000\000\000\000\000...' 25 bytes
[server: remote+] receive 'lockArchiv...' 48 bytes
[server: remote+] Waiting for next message
[server: update+] Archive name is //xxxxxxxxx//data1/home/xxxxxxxxx/doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is dd5c6ac06b0499185151ee2e4194dfcd
[server: remote+] Sending result (id: 13)
[server: remote+] send [lockArchive-res] '\000\000\000\000\000\000\000\001\000' 9 bytes
[server: remote+] send [rsp] '\000\000\000\000\000\000\000\001\000' 9 bytes
[server: remote_emit+] dump: \r\000\000\000\219\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\024\000\000\000\233lockArchive-res\000\000\000\000\000\000\000\001\000
[remote_emit+] grab: \r\000\000\000\219\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\024\000\000\000\233lockArchive-res\000\000\000\000\000\000\000\001\000
[remote+] Message received (id: 13)
[remote+] receive 'rsp\000\000\000\000\000\000\000...' 12 bytes
[remote+] receive 'lockArchiv...' 24 bytes
[remote+] Waiting for next message
[remote+] send [prepareCommit-args] '\000\000\000\000\000\000\000B\001\022...' 74 bytes
[remote+] send [rsp] '\000\000\000\000\000\000\000\016\003\001...' 24 bytes
[remote+] Sending request (id: 14)
[remote_emit+] dump: \014\000\000\000:\027\000\000\000\004rsp\000\000\000\000\000\000\000\016\003\001\rprepareCommit\\\000\000\000\250prepareCommit-args\000\000\000\000\000\000\000B\001\022/data1/home/xxxxxxxxx/doc\001(Unicode case insensitive\0001760548057.7164
[update+] Archive name is //xxxxxxxxx//Users/xxxxxxxxx/.doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is c86567f23cab39f1e10f84b6e7ba2917
$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>[propsdata+] Pruning shared props data...
[propsdata+] Shared props data pruning took 3.441 milliseconds
[update] Saving archive in /Volumes/doc/profiles/unison/scc86567f23cab39f1e10f84b6e7ba2917
$<>$<>$<>$<>$<>$<>$<>$<>[server: remote_emit+] grab: \014\000\000\000:\027\000\000\000\004rsp\000\000\000\000\000\000\000\016\003\001\rprepareCommit\\\000\000\000\250prepareCommit-args\000\000\000\000\000\000\000B\001\022/data1/home/xxxxxxxxx/doc\001(Unicode case insensitive\0001760548057.7164
[server: remote+] Message received (id: 14)
[server: remote+] receive 'rsp\000\000\000\000\000\000\000...' 27 bytes
[server: remote+] receive 'prepareCom...' 92 bytes
[server: remote+] Waiting for next message
[server: update+] Archive name is //xxxxxxxxx//data1/home/xxxxxxxxx/doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is dd5c6ac06b0499185151ee2e4194dfcd
$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>[server: propsdata+] Pruning shared props data...
$<>$<>$<>$<>$<>$<>$<>$<>[server: propsdata+] Shared props data pruning took 7.323 milliseconds
[server: update] Saving archive in /data1/home/xxxxxxxxx/.unison/scdd5c6ac06b0499185151ee2e4194dfcd
$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>[server: remote+] Sending result (id: 14)
[server: remote+] send [prepareCommit-res] '\000\000\000\000\000\000\000\006\001\004...' 14 bytes
[server: remote+] send [rsp] '\000\000\000\000\000\000\000\001\000' 9 bytes
[server: remote_emit+] dump: \014\000\000\000:\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\031\000\000\000~prepareCommit-res\000\000\000\000\000\000\000\006\001\0040\129\204&
[remote_emit+] grab: \014\000\000\000:\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\031\000\000\000~prepareCommit-res\000\000\000\000\000\000\000\006\001\0040\129\204&
[remote+] Message received (id: 14)
[remote+] receive 'rsp\000\000\000\000\000\000\000...' 12 bytes
[remote+] receive 'prepareCom...' 31 bytes
[remote+] Waiting for next message
[remote+] send [commitArchive-args] '\000\000\000\000\000\000\000\024\001\022...' 32 bytes
[remote+] send [rsp] '\000\000\000\000\000\000\000\016\003\001...' 24 bytes
[remote+] Sending request (id: 15)
[remote_emit+] dump: \015\000\000\000\152\027\000\000\000\004rsp\000\000\000\000\000\000\000\016\003\001\rcommitArchive2\000\000\000~commitArchive-args\000\000\000\000\000\000\000\024\001\022/data1/home/xxxxxxxxx/doc
[update+] Archive name is //xxxxxxxxx//Users/xxxxxxxxx/.doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is c86567f23cab39f1e10f84b6e7ba2917
[update+] Archive name is //xxxxxxxxx//Users/xxxxxxxxx/.doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is c86567f23cab39f1e10f84b6e7ba2917
[server: remote_emit+] grab: \015\000\000\000\152\027\000\000\000\004rsp\000\000\000\000\000\000\000\016\003\001\rcommitArchive2\000\000\000~commitArchive-args\000\000\000\000\000\000\000\024\001\022/data1/home/xxxxxxxxx/doc
[server: remote+] Message received (id: 15)
[server: remote+] receive 'rsp\000\000\000\000\000\000\000...' 27 bytes
[server: remote+] receive 'commitArch...' 50 bytes
[server: remote+] Waiting for next message
[server: update+] Archive name is //xxxxxxxxx//data1/home/xxxxxxxxx/doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is dd5c6ac06b0499185151ee2e4194dfcd
[server: update+] Archive name is //xxxxxxxxx//data1/home/xxxxxxxxx/doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is dd5c6ac06b0499185151ee2e4194dfcd
[server: remote+] Sending result (id: 15)
[server: remote+] send [commitArchive-res] '\000\000\000\000\000\000\000\000' 8 bytes
[server: remote+] send [rsp] '\000\000\000\000\000\000\000\001\000' 9 bytes
[server: remote_emit+] dump: \015\000\000\000\152\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\025\000\000\000GcommitArchive-res\000\000\000\000\000\000\000\000
[remote_emit+] grab: \015\000\000\000\152\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\025\000\000\000GcommitArchive-res\000\000\000\000\000\000\000\000
[remote+] Message received (id: 15)
[remote+] receive 'rsp\000\000\000\000\000\000\000...' 12 bytes
[remote+] receive 'commitArch...' 25 bytes
[remote+] Waiting for next message
[remote+] send [postCommitArchive-args] '\000\000\000\000\000\000\000\024\001\022...' 32 bytes
[remote+] send [rsp] '\000\000\000\000\000\000\000\020\003\001...' 28 bytes
[remote+] Sending request (id: 16)
[remote_emit+] dump: \016\000\000\000\246\031\000\000\000~rsp\000\000\000\000\000\000\000\020\003\001\017postCommitArchive6\000\000\000\248postCommitArchive-args\000\000\000\000\000\000\000\024\001\022/data1/home/xxxxxxxxx/doc
[update+] Archive name is //xxxxxxxxx//Users/xxxxxxxxx/.doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is c86567f23cab39f1e10f84b6e7ba2917
[update+] Archive name is //xxxxxxxxx//Users/xxxxxxxxx/.doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is c86567f23cab39f1e10f84b6e7ba2917
[update] Copying archive /Volumes/doc/profiles/unison/tmc86567f23cab39f1e10f84b6e7ba2917 to /Volumes/doc/profiles/unison/arc86567f23cab39f1e10f84b6e7ba2917
[server: remote_emit+] grab: \016\000\000\000\246\031\000\000\000~rsp\000\000\000\000\000\000\000\020\003\001\017postCommitArchive6\000\000\000\248postCommitArchive-args\000\000\000\000\000\000\000\024\001\022/data1/home/xxxxxxxxx/doc
[server: remote+] Message received (id: 16)
[server: remote+] receive 'rsp\000\000\000\000\000\000\000...' 31 bytes
[server: remote+] receive 'postCommit...' 54 bytes
[server: remote+] Waiting for next message
[server: update+] Archive name is //xxxxxxxxx//data1/home/xxxxxxxxx/doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is dd5c6ac06b0499185151ee2e4194dfcd
[server: update+] Archive name is //xxxxxxxxx//data1/home/xxxxxxxxx/doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is dd5c6ac06b0499185151ee2e4194dfcd
[server: update] Copying archive /data1/home/xxxxxxxxx/.unison/tmdd5c6ac06b0499185151ee2e4194dfcd to /data1/home/xxxxxxxxx/.unison/ardd5c6ac06b0499185151ee2e4194dfcd
[ser[remote_emit+] grab: \016\000\000\000\246\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\029\000\000\000\193postCommitArchive-res\000\000\000\000\000\000\000\000
[remote+] Message received (id: 16)
[remote+] receive 'rsp\000\000\000\000\000\000\000...' 12 bytes
[remote+] receive 'postCommit...' 29 bytes
[remote+] Waiting for next message
[remote+] send [removeArchive-args] '\000\000\000\000\000\000\000\025\001\022...' 33 bytes
[remote+] send [rsp] '\000\000\000\000\000\000\000\016\003\001...' 24 bytes
[remote+] Sending request (id: 17)
[remote_emit+] dump: \017\000\000\000U\027\000\000\000\004rsp\000\000\000\000\000\000\000\016\003\001\rremoveArchive3\000\000\000\221removeArchive-args\000\000\000\000\000\000\000\025\001\022/data1/home/xxxxxxxxx/doc\001
[update+] Archive name is //xxxxxxxxx//Users/xxxxxxxxx/.doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is c86567f23cab39f1e10f84b6e7ba2917
[update] Removing archive /Volumes/doc/profiles/unison/tmc86567f23cab39f1e10f84b6e7ba2917
ver: remote+] Sending result (id: 16)
[server: remote+] send [postCommitArchive-res] '\000\000\000\000\000\000\000\000' 8 bytes
[server: remote+] send [rsp] '\000\000\000\000\000\000\000\001\000' 9 bytes
[server: remote_emit+] dump: \016\000\000\000\246\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\029\000\000\000\193postCommitArchive-res\000\000\000\000\000\000\000\000
[server: remote_emit+] grab: \017\000\000\000U\027\000\000\000\004rsp\000\000\000\000\000\000\000\016\003\001\rremoveArchive3\000\000\000\221removeArchive-args\000\000\000\000\000\000\000\025\001\022/data1/home/xxxxxxxxx/doc\001
[server: remote+] Message received (id: 17)
[server: remote+] receive 'rsp\000\000\000\000\000\000\000...' 27 bytes
[server: remote+] receive 'removeArch...' 51 bytes
[server: remote+] Waiting for next message
[server: update+] Archive name is //xxxxxxxxx//data1/home/xxxxxxxxx/doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is dd5c6ac06b0499185151ee2e4194dfcd
[server: update] Removing archive /data1/home/xxxxxxxxx/.unison/tmdd5c6ac06b0499185151ee2e4194dfcd
[server: remote+] Sending result (id: 17)
[server: remote+] send [removeArchive-res] '\000\000\000\000\000\000\000\000' 8 bytes
[server: remote+] send [rsp] '\000\000\000\000\000\000\000\001\000' 9 bytes
[server: remote_emit+] dump: \017\000\000\000U\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\025\000\000\000GremoveArchive-res\000\000\000\000\000\000\000\000
[remote_emit+] grab: \017\000\000\000U\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\025\000\000\000GremoveArchive-res\000\000\000\000\000\000\000\000
[remote+] Message received (id: 17)
[remote+] receive 'rsp\000\000\000\000\000\000\000...' 12 bytes
[remote+] receive 'removeArch...' 25 bytes
[remote+] Waiting for next message
[remote+] send [unlockArchive-args] '\000\000\000\000\000\000\000\024\001\022...' 32 bytes
[remote+] send [rsp] '\000\000\000\000\000\000\000\016\003\001...' 24 bytes
[remote+] Sending request (id: 18)
[remote_emit+] dump: \018\000\000\000\179\027\000\000\000\004rsp\000\000\000\000\000\000\000\016\003\001\runlockArchive2\000\000\000~unlockArchive-args\000\000\000\000\000\000\000\024\001\022/data1/home/xxxxxxxxx/doc
[update+] Archive name is //xxxxxxxxx//Users/xxxxxxxxx/.doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is c86567f23cab39f1e10f84b6e7ba2917
[server: remote_emit+] grab: \018\000\000\000\179\027\000\000\000\004rsp\000\000\000\000\000\000\000\016\003\001\runlockArchive2\000\000\000~unlockArchive-args\000\000\000\000\000\000\000\024\001\022/data1/home/xxxxxxxxx/doc
[server: remote+] Message received (id: 18)
[server: remote+] receive 'rsp\000\000\000\000\000\000\000...' 27 bytes
[server: remote+] receive 'unlockArch...' 50 bytes
[server: remote+] Waiting for next message
[server: update+] Archive name is //xxxxxxxxx//data1/home/xxxxxxxxx/doc;//xxxxxxxxx//data1/home/xxxxxxxxx/doc, //xxxxxxxxx//Users/xxxxxxxxx/.doc;23; hashcode is dd5c6ac06b0499185151ee2e4194dfcd
[server: remote+] Sending result (id: 18)
[server: remote+] send [unlockArchive-res] '\000\000\000\000\000\000\000\000' 8 bytes
[server: remote+] send [rsp] '\000\000\000\000\000\000\000\001\000' 9 bytes
[server: remote_emit+] dump: \018\000\000\000\179\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\025\000\000\000GunlockArchive-res\000\000\000\000\000\000\000\000
[remote_emit+] grab: \018\000\000\000\179\012\000\000\000}rsp\000\000\000\000\000\000\000\001\000\025\000\000\000GunlockArchive-res\000\000\000\000\000\000\000\000
[remote+] Message received (id: 18)
[remote+] receive 'rsp\000\000\000\000\000\000\000...' 12 bytes
[remote+] receive 'unlockArch...' 25 bytes
[remote+] Waiting for next message
Nothing to do: replicas have not changed since last sync.
allocated_words: 205675013
minor_words: 205428234
promoted_words: 9127372
major_words: 9374151
minor_collections: 788
major_collections: 9
heap_words: 9432576
heap_chunks: 28
top_heap_words: 9432576
compactions: 0
forced_major_collections: 0
I have no idea whether this is an issue with macfuse or Unison maybe?.. the thing is using macfuse 5.0.7 everything runs fine, I can mount the folder with gocryptfs, I can open files.. the only issue is when synchronizing using Unison.
Any idea?
Thanks in advance.
Lluc Pallejà
Metadata
Metadata
Assignees
Labels
No labels