Question: What causes lag between watchman and mirror sending a file?

[halfbusy]

I've noticed a delay of approximately 50ms between the time when watchman pickups a file change, and mirror starts sending the corresponding file.

For my tests I am running a build system on both the client and server to see which build completes first. The server is remote and has approx 300% the CPU power of my client and I have a 100Mbit 10baseT connection. Ping time is an average of ~20ms.

Timing as follows: File is saved +15ms Local build receives filechange notification from watchman and starts building. +50ms after local build starts, mirror client logs INFO Sending ....filename (75ms after file is save) +4ms mirror server logs Remote update ....filename

I am curious to know why such a delay between my local build system noticing the file change, but mirror takes longer? I was expecting mirror to start sending the file at the same time my local build system picks it up because they are both using watchman.

I tried with SSH tunnel in hopes it keeps the connection open to save connection negotition time, but still takes ~4ms between client sending and server logging remote update.

[stephenh]

@halfbusy it's hard to say off-hand, what is your local build system? Does it use watchman?

Since mirror does use watchman, the timestamps involved would be:

• T0 - file changes, OS internally starts calling notifiers/etc
• T1 - watchman daemon is notified of the change by the OS (this could be the same +15ms that your local build sees the change, depending on the notifier impl it's using)
• T2 - watchman daemon sends file change to the mirror socket (i.e. watchman I think does/could be buffering things--yeah, looks like settle defaults to 20ms https://facebook.github.io/watchman/docs/config, so that is some of it)
• T3 - mirror local receives the watchman notification and internally queues/diffs it
• T4 - mirror local's internal diff notices we should send filename to the remove, and queues it to send
• T5 - mirror local puts the change on the wire
• T6 - mirror remote sees the change on the wire, and internally queues it
• T7 - mirror remote's internal diff notices that remote change is in fact newer than it's local and queues it to save
• T8 - mirror remote actually writes the change to its local disk

So, your 50ms is T5 above. I believe if you turn on debug logging, you will probably see log statements for each of the ^ times that at least happen within mirror internally. Honestly it's been awhile since I've had to work on that aspect of the mirror codebase, so I don't know for sure.

Since this is your itch, I'll generally defer to you to poke around and find the above T values for your use case. :-) Happy to answer questions though.

Fwiw the above times don't see terrible to me, i.e. no I can't articulate off-hand why it's that slow, but I honestly don't know how fast my own local mirror usage is for those above Ts. I.e. I use mirror daily and it's "fast enough that I never notice" ... so, maybe it's 50ms? I don't actually know/need to know. Always happy to have it faster though.

[halfbusy]

Yes, the local build system (ember-cli javascript) is using watchman. The local build system logs to terminal the file change it has picked up and starts building about ~50ms before mirror log INFO Sending ....filename. So I was curious why the difference?

Thanks for the timings. Very useful.

I'll poke around and see if I can find anything useful. It could be a watchman issue and one instance takes priority over the other. Maybe if I can tie them into the same watchman process it will be faster.

[stephenh]

Cool. Fwiw the architecture of watchman, AFAIU, is fundamentally that all clients use the same watchman daemon process (which is essentially a per-machine singleton), so that they share file notifier handles/resources, which are generally limited by the OS.

...that said, I've never actually had/gotten to use a setup where watchman was driving N different build tools, so I don't have any concrete experience about whether it always does that, or sometimes does/sometimes doesn't. Just wanted to pass along that, in theory, it should. :-)

Maybe there is a wrinkle with project roots, i.e. if ember is asking watchman to watch a slightly different root directory than mirror is asking watchman to watch (i.e. different parent or child directories)...

Yeah, I dunno, let me know what you find out. :-)

[stephenh]

Happy to have more information/debugging/etc. here but otherwise closing as stale.