dvc: pretty slow on Mac

[jorgeorpinel]

I experience around 10 seconds before and another 5 to 10 after dvc version output (below) on my Macbook Air.

DVC version: 0.61.2
Python version: 3.7.3
Platform: Darwin-18.7.0-x86_64-i386-64bit
Binary: False
Cache: reflink - True, hardlink - True, symlink - True
Filesystem type (cache directory): ('apfs', '/dev/disk1s1')
Filesystem type (workspace): ('apfs', '/dev/disk1s1')

Attached are a couple logs of python3 -mcProfile -s cumtime -m dvc version, the second one after opting out from analytics:

python3 -mcProfile -s cumtime -m dvc version (with analytics).log
python3 -mcProfile -s cumtime -m dvc version (without analytics).log

[jorgeorpinel]

p.s. My connection is pretty fast, no VPN, and I've experienced this on several different networks recently (residential, WeWork, cafes, hotel).

[efiop]

Tried adding sleep(100) to places where requests is called on both mac and linux and was not able to reproduce. @jorgeorpinel Are you still able to reproduce? If so, could you check if there are any dvc processes running in the background? E.g. ps -xaf | grep dvc?

[jorgeorpinel]

Yeah still happening on my machine with the latest DVC version. I ran ps -xaf | grep dvc a bunch of times on a separate terminal and It's just ...Python /usr/local/bin/dvc version for the first 10 seconds (before output) and then both that and ...Python /usr/local/bin/dvc daemon -q analytics ... for the last 10 seconds after output.

But oh well, as long as this is a problem only on my machine then it's not really an issue, right? Feel fee to close unless you want to investigate further. Glad to give you SSH access or something.

[efiop]

@jorgeorpinel No reason to close this, we don't know if it is happening to anyone else, but they are just stopping using it without reporting the issue :) Let's have a meeting together, so I could take a look, maybe it is something obvious that I'm missing. I'll ping you in PM's. Thank you :slightly_smiling_face:

[efiop]

We've had a debugging session with @jorgeorpinel and found that it is flufl.lock -> socket.getfqdn -> socket.gethostbyaddr that is slow. On further inspection, we've found that he has some pretty unusual dns settings that seem to be the cause of this. He has now adjusted his dns settings and we are waiting for new results.

[efiop]

Ok, so turns out on Mac "Computer name" that you set in Settings -> Sharing is not recognisable by anyone until you enable "Remote Login" service. So even ping Ruslans-MacBook-Pro.local will hang and then fail. The moment you enable that service, everything starts to work instantly. /etc/hosts is not updated by that operation, so not quite sure yet about the precise mechanism. But I am able to reproduce now and I am investigating.

[efiop]

Ok, so it is a cpython bug https://bugs.python.org/issue5004 . There is a patch for it from like 9 years ago. We can either monkeypatch it or patch it in flufl.lock and or try to push this fix into cpython as well. Working on this right now.

[jorgeorpinel]

Thanks for looking at this Ruslan! Glad there's a workaround we can use in lock.py so Mac users don't have a bad experience with DVC (I guess most people don't enable Remote login) even if that cpython bug doesn't get addressed soon.

[efiop]

For the record, submitted a PR https://gitlab.com/warsaw/flufl.lock/merge_requests/12 . @jorgeorpinel confirmed that it works for him now.

[efiop]

@jorgeorpinel 0.63.3 is out. Please upgrade :slightly_smiling_face:

[jorgeorpinel]

Nice! It's fast now before output but still around 13 seconds to get back to the console prompt AFTER the command output, whether with or without analytics... Here's the profiler output: https://pastebin.com/isBDYC4E

[efiop]

@jorgeorpinel Ok, this time this seems to be OS X fault for not caching dns requests https://github.com/rust-lang/rust/issues/31665 . Will prepare a workaround ASAP.

[efiop]

Aaaand I can fully reproduce the original issue but now with getaddrinfo on my conda on mac :grimacing: Looking into that...

[efiop]

@jorgeorpinel Could you please install

pip install --force-reinstall git+https://github.com/efiop/dvc@2582

and see if that helps? It works for me, but I just want to make sure.

[jorgeorpinel]

Ran that (with pip3 in my case) and it's fast now! Under 1 sec to output dvc version and immediately back to the prompt. The installation did run into these errors though, pasting here in case it's relevant:

ERROR: awscli 1.16.215 has requirement colorama<=0.3.9,>=0.2.5, but you'll have colorama 0.4.1 which is incompatible.
ERROR: docker-compose 1.23.2 has requirement requests!=2.11.0,!=2.12.2,!=2.18.0,<2.21,>=2.6.1, but you'll have requests 2.22.0 which is incompatible.
ERROR: awsebcli 3.15.3 has requirement colorama<0.4.0,>=0.3.9, but you'll have colorama 0.4.1 which is incompatible.
ERROR: awsebcli 3.15.3 has requirement future<0.17.0,>=0.16.0, but you'll have future 0.18.1 which is incompatible.
ERROR: awsebcli 3.15.3 has requirement pathspec==0.5.9, but you'll have pathspec 0.6.0 which is incompatible.
ERROR: awsebcli 3.15.3 has requirement requests<2.21,>=2.20.1, but you'll have requests 2.22.0 which is incompatible.
ERROR: awsebcli 3.15.3 has requirement six<1.12.0,>=1.11.0, but you'll have six 1.12.0 which is incompatible.
ERROR: awsebcli 3.15.3 has requirement urllib3<1.25,>=1.24.1, but you'll have urllib3 1.25.6 which is incompatible.

[efiop]

@jorgeorpinel Thanks! I think we have a separate issue for those.