[Bug 4834] New: hg clone over http is slower on Windows than Linux by a factor of 10
mercurial-bugs at selenic.com
mercurial-bugs at selenic.com
Mon Sep 21 11:25:26 UTC 2015
http://bz.selenic.com/show_bug.cgi?id=4834
Bug ID: 4834
Summary: hg clone over http is slower on Windows than Linux by
a factor of 10
Product: Mercurial
Version: 3.5.1
Hardware: PC
OS: Windows
Status: UNCONFIRMED
Severity: feature
Priority: wish
Component: Mercurial
Assignee: bugzilla at selenic.com
Reporter: rthijssen at gmail.com
CC: mercurial-devel at selenic.com
I've been investigating an issue with slow clones from Windows vs Linux. I've
found that under identical network conditions on Amazon EC2, cloning the
large-ish (1.5gb) mozilla-central repository, takes on average, 10 times as
long to complete on Windows compared to Linux. For clarity, I have run these
tests many times, so while the output evidence is rather anecdotal, it is
fairly consistent on subsequent runs (eg Windows is always slower to clone than
Linux by a factor of at least 8). I compare using similar virtual ram, disks,
etc. and use instances within the same ec2 subregion (output below is from
us-east-1a for both Windows and Linux)
My rudimentary test to discount network performance as a factor, is to time the
curl call to download the 15gb bundleclone stream bundle from within the same
ec2 region:
- Windows: curl -s -w "%{time_total}\n" -o NUL -k
https://s3-external-1.amazonaws.com/moz-hg-bundles-us-east-1/mozilla-central/d9724506c66754540416e8435ad3c1feabf29590.stream.hg
38.953
- Linux: curl -s -w "%{time_total}\n" -o /dev/null -k
https://s3-external-1.amazonaws.com/moz-hg-bundles-us-east-1/mozilla-central/d9724506c66754540416e8435ad3c1feabf29590.stream.hg
32.374
(repeating the curl test above, results in faster download times on both os'es,
presumably due to http caching somewhere, but no such joy with the clones
below)
For my most recent tests, I used:
- vanilla Windows Server 2012 instance from Amazon stock AMIs
- c3.2xlarge (ec2 instance size)
- 16gb ram, 80gb standard ssd
- hg 3.5.1
(https://bitbucket.org/tortoisehg/files/downloads/mercurial-3.5.1-x64.msi), I
have previously had similar results with 3.2.1
- with and without latest bundleclone from
https://hg.mozilla.org/hgcustom/version-control-tools/file/default/hgext/bundleclone/__init__.py
- vanilla Ubuntu 14.04.2 LTS (trusty) from Amazon stock AMIs
- c3.2xlarge (ec2 instance size)
- 16gb ram, 80gb standard ssd
- hg 3.3.2 (from apt-repository ppa:mercurial-ppa/releases)
- with and without latest bundleclone
Without bundleclone:
- Windows:
C:\Users\Administrator>hg clone -U --traceback --verbose --profile --time
https://hg.mozilla.org/mozilla-central m-c\b
requesting all changes
adding changesets
adding manifests
adding file changes
added 263468 changesets with 1482397 changes to 218359 files
CallCount Recursive Total(s) Inline(s) module:lineno(function)
8585182 1902763 705.3025 245.3113
<mercurial\util.pyc>:1282(read)
63332392 4938531 260.6234 226.5606 <len>
1939891 0 166.6314 166.6314 <zlib.compress>
611230 0 252.2447 134.3125
<mercurial\util.pyc>:862(checkwinfilename)
2009109 0 887.2913 108.6815
<mercurial\revlog.pyc>:1238(_addrevision)
8585179 1902761 941.8916 101.8231
<mercurial\changegroup.pyc>:18(readexactly)
6682410 0 849.4750 101.3104
<mercurial\bundle2.pyc>:1065(read)
27801362 0 88.6193 88.6193 <ord>
218361 0 2667.1520 75.5181
<mercurial\revlog.pyc>:1382(addgroup)
6533279 0 65.8236 65.8236 <method 'write' of 'file'
objects>
831243 0 62.9566 62.9566
<mercurial.osutil.posixfile>
17186914 0 58.7791 58.7791 <method 'append' of 'list'
objects>
2009109 0 203.3802 57.5517
<mercurial\revlog.pyc>:1364(_writeentry)
2227470 0 1083.4444 50.2429
<mercurial\changegroup.pyc>:213(deltachunk)
1790748 0 235.4545 42.9438
<mercurial\revlog.pyc>:1277(builddelta)
8014932 0 38.7721 38.7721
<mercurial\revlog.pyc>:354(start)
9960283 0 40.3384 36.5957 <method 'join' of 'str'
objects>
9160971 0 36.4394 36.4394
<mercurial\revlog.pyc>:321(rev)
4938501 0 50.3103 34.0622
<mercurial\revlog.pyc>:287(__len__)
3892134 0 49.8966 33.0275
<mercurial\changelog.pyc>:192(rev)
1482397 0 68.5509 32.8800
<mercurial\filelog.pyc>:111(_peek_iscensored)
10073423 0 32.5827 32.5827 <method 'popleft' of
'collections.deque' objects>
2969605 0 56.6572 32.0381
<mercurial\revlog.pyc>:356(end)
2145476 0 242.1651 31.4955
<mercurial\revlog.pyc>:1209(compress)
2445830 0 302.5913 30.7192
<mercurial\changegroup.pyc>:178(chunklength)
916 0 30.4992 30.4992 <built-in method compress>
951383 0 392.3380 28.7774
<mercurial\bundle2.pyc>:989(_payloadchunks)
8570430 0 28.3200 28.3200 <method 'appendleft' of
'collections.deque' objects>
1759092 0 72.2197 28.1953
<mercurial\ui.pyc>:241(config)
395329 0 28.0406 28.0406 <method 'close' of 'file'
objects>
time: real 3439.561 secs (user 871.438+0.000 sys 2520.172+0.000)
- Linux:
$ hg clone -U --traceback --verbose --profile --time
https://hg.mozilla.org/mozilla-central
requesting all changes
adding changesets
adding manifests
adding file changes
added 263468 changesets with 1482397 changes to 218359 files
CallCount Recursive Total(s) Inline(s) module:lineno(function)
1456147 0 171.2241 171.2241 <built-in method read>
1939891 0 112.5278 112.5278 <zlib.compress>
6682407 0 271.1561 71.5821 mercurial.util:1196(read)
6693204 0 1.8279 1.8279 <method 'append' of
'list' objects>
6682407 0 1.6846 1.6846 <method 'join' of 'str'
objects>
6669257 0 1.3605 1.3605 <method 'appendleft' of
'collections.deque' objects>
6693204 0 1.2374 1.2374 <method 'popleft' of
'collections.deque' objects>
6717152 0 1.1863 1.1863 <len>
916 0 24.6091 24.6091 <built-in method compress>
2009109 0 258.0016 19.0431
mercurial.revlog:1217(_addrevision)
2009109 0 28.3245 7.7681
mercurial.revlog:1327(_writeentry)
1790748 0 98.2398 6.0020
mercurial.revlog:1246(builddelta)
2009109 0 2.5624 2.5624
mercurial.revlog:55(offset_type)
2009109 0 5.4910 2.3054
mercurial.revlog:349(end)
2009109 0 4.6250 2.0674
mercurial.revlog:164(packentry)
218361 0 595.1040 16.5394
mercurial.revlog:1345(addgroup)
2009109 0 258.0016 19.0431
mercurial.revlog:1217(_addrevision)
2227470 0 289.0773 7.8434
mercurial.changegroup:212(deltachunk)
220009 0 3.5644 3.5644 <method 'close' of
'file' objects>
1745641 0 6.8773 1.3634
mercurial.changegroup:708(revmap)
220008 0 13.7087 0.9964
mercurial.store:452(__call__)
23947 0 15.0317 15.0317 <built-in method
decompress>
1125701 0 13.4403 13.4403 <zlib.decompress>
37321750 4938535 12.9488 10.1777 <len>
4938505 0 3.7150 2.7710
mercurial.revlog:280(__len__)
9 0 0.0001 0.0000
mercurial.localrepo:472(__len__)
17 0 0.0000 0.0000 sre_parse:126(__len__)
787727 0 8.9021 8.9021 <open>
6682407 0 280.9417 8.6578
mercurial.changegroup:18(readexactly)
6682407 0 271.1561 71.5821
mercurial.util:1196(read)
time: real 691.430 secs (user 459.660+0.000 sys 62.170+0.000)
With bundleclone:
- Windows:
C:\Users\Administrator>hg clone -U --traceback --verbose --profile --time
https://hg.mozilla.org/mozilla-central m-c\a
downloading bundle
https://s3-external-1.amazonaws.com/moz-hg-bundles-us-east-1/mozilla-central/d9724506c66754540416e8435ad3c1feabf29590.stream.hg
streaming all changes
219187 files to transfer, 1.50 GB of data
transferred 1.50 GB in 449.2 seconds (3.42 MB/sec)
finishing applying bundle; pulling
searching for changes
all local heads known remotely
adding changesets
adding manifests
adding file changes
added 1 changesets with 2 changes to 2 files
CallCount Recursive Total(s) Inline(s) module:lineno(function)
220286 0 61.4750 61.4750
<mercurial.osutil.posixfile>
220274 0 110.8829 58.9090
<mercurial\util.pyc>:862(checkwinfilename)
12369068 0 39.3438 39.3438 <ord>
220262 0 22.1281 22.1281 <method 'close' of 'file'
objects>
454326 0 17.6722 17.6722 <nt._isdir>
1 0 449.2164 16.9312
hgext_bundleclone:254(consumestreamclone)
220274 0 49.9401 15.2021
<mercurial\pathutil.pyc>:33(__call__)
1627945 0 30.4409 12.2527 <method 'decode' of 'str'
objects>
790412 0 56.5724 11.5664
<mercurial\encoding.pyc>:83(tolocal)
2913086 0 11.5066 11.5066 <method 'split' of 'str'
objects>
3407929 164 11.1247 11.1178 <len>
942730 0 17.3573 10.7878 <ntpath.pyc>:95(splitdrive)
263470 0 125.4575 10.5211
<mercurial\changelog.pyc>:310(read)
220274 0 303.7373 9.9957
<mercurial\scmutil.pyc>:467(__call__)
263470 0 70.3555 9.8101
<mercurial\revlog.pyc>:1040(revision)
209668 0 8.7224 8.7224 <method 'read' of
'_ssl._SSLSocket' objects>
877324 658041 9.7835 7.3264
<mercurial\demandimport.pyc>:111(__getattribute__)
219239 0 7.1884 7.1884 <nt.rename>
263468 0 15.8832 6.8870
<mercurial\branchmap.pyc>:389(_setcachedata)
263958 0 15.5043 6.3974
<mercurial\ancestor.pyc>:296(__iter__)
263469 0 28.6323 6.3473
<mercurial\revlog.pyc>:981(_chunks)
1862999 0 6.2659 6.2659 <method 'lower' of 'str'
objects>
219217 0 25.6026 6.1501
<mercurial\win32.pyc>:439(unlink)
790553 0 14.9748 6.1443 <method 'encode' of
'unicode' objects>
453339 0 28.6132 5.5526
<mercurial\util.pyc>:1313(filechunkiter)
802526 0 9.0284 5.5003
<encodings\cp1252.pyc>:14(decode)
790412 0 9.1592 5.4893
<encodings\utf_8.pyc>:15(decode)
790436 0 8.8304 5.4378
<encodings\cp1252.pyc>:11(encode)
1399449 0 5.3445 5.3445 <method 'replace' of 'str'
objects>
263468 0 178.3781 5.2531
<mercurial\branchmap.pyc>:373(_branchinfo)
time: real 653.507 secs (user 115.891+0.000 sys 486.922+0.000)
- Linux:
$ hg clone -U --traceback --verbose --profile --time
https://hg.mozilla.org/mozilla-central
(your Python is older than 2.7.9 and does not support modern and secure
SSL/TLS; please consider upgrading your Python to a secure version)
(ignoring URL on server that requires SNI)
(ignoring URL on server that requires SNI)
(ignoring URL on server that requires SNI)
downloading bundle
https://s3-external-1.amazonaws.com/moz-hg-bundles-us-east-1/mozilla-central/d9724506c66754540416e8435ad3c1feabf29590.stream.hg
streaming all changes
219187 files to transfer, 1.50 GB of data
transferred 1.50 GB in 50.3 seconds (30.5 MB/sec)
finishing applying bundle; pulling
searching for changes
all local heads known remotely
adding changesets
adding manifests
adding file changes
added 1 changesets with 2 changes to 2 files
CallCount Recursive Total(s) Inline(s) module:lineno(function)
292874 0 14.6933 14.6933 <built-in method read>
220288 0 3.6664 3.6664 <open>
1 0 50.2898 3.6134
hgext_bundleclone:254(consumestreamclone)
234150 0 3.1305 3.1305 <method 'write' of
'file' objects>
219187 0 3.0306 3.0306 <method 'close' of
'file' objects>
219187 0 18.3584 0.9955
mercurial.store:452(__call__)
453337 0 16.1424 0.8204
mercurial.util:1227(filechunkiter)
219188 0 3.2453 0.7754
mercurial.keepalive:481(readline)
234291 0 3.1401 3.1401 <method 'write' of 'file'
objects>
220268 0 3.0937 3.0937 <method 'close' of 'file'
objects>
220272 0 16.5042 2.2954
mercurial.scmutil:375(__call__)
220279 0 3.6663 3.6663 <open>
220272 0 4.7814 2.1818
mercurial.pathutil:33(__call__)
219207 0 1.7677 1.7677 <posix.unlink>
219222 0 0.6396 0.3468
mercurial.posix:24(split)
219211 0 2.4477 0.3135
mercurial.util:1133(ensuredirs)
220272 0 4.7814 2.1818
mercurial.pathutil:33(__call__)
438440 0 0.7635 0.4374
mercurial.pathutil:7(_lowerclean)
438420 0 0.6241 0.2586
mercurial.util:1016(splitpath)
219210 0 0.3092 0.2059
mercurial.util:1012(endswithsep)
470162 0 0.1794 0.1794 <method 'join' of 'str'
objects>
470212 0 0.1609 0.1609 <method 'pop' of 'list'
objects>
262913 0 2.0052 2.0052 <zlib.decompress>
219215 0 1.7678 1.7678 <posix.unlink>
263470 0 15.2029 1.7363
mercurial.changelog:299(read)
263470 0 10.6013 1.4602
mercurial.revlog:1030(revision)
526940 0 0.4882 0.4882 <method 'split' of
'str' objects>
526940 0 1.7455 0.3243
mercurial.encoding:83(tolocal)
263470 0 0.2224 0.2224 <method 'index' of
'str' objects>
263470 0 0.1874 0.1874 <binascii.unhexlify>
time: real 72.740 secs (user 43.950+0.000 sys 17.130+0.000)
I am quite happy to provide further testing or if anyone can point me at the
likely cause of the problem, I will get to work on a patch to submit for
review.
--
You are receiving this mail because:
You are on the CC list for the bug.
More information about the Mercurial-devel
mailing list