terrible cloning performance for user, not root

[Lasse Kliemann]

Adrian Klaver <adrian.klaver <at> aklaver.com> writes:

> First what version of hg are you using?

3.2.4+518-42908c3275c6+20150104 right now, but i made similar observations
with other versions, including those included in the distributions.

> Second what filesystem?

reiserfs, it's what the provider installed.

> Third by default hg uses hardlinks(if feasible) when cloning in a 
> filesystem. You can override this with the --pull option to clone. Might 
> want to try with this option in both situations(root/normal user) to see 
> what happens.

that's it. i get essentially the same timing with clone --pull as root as i
get for normal clone as user. with the current setup, it's 8 seconds vs. 4
1/2 minutes. the repository i'm cloning from is owned by root, so obviously
hardlinks are not an option for the user. this explains it so far. question
remains: shouln't it be reasonably fast even without using hardlinks? in my
application, i'm using rsync as a workaraound now, which is sufficient for it.

in case it helps, here is the profiling output (as suggested by Simon) for a
normal clone, first as root:

          41            0      7.7129      7.6326  
mercurial.worker:76(_posixworker)
           4            0      0.0037      0.0037       <posix.fork>
           5            0      0.0006      0.0006      
mercurial.worker:147(partition)
          40            0      0.0000      0.0000       <method 'split' of
'str' objects>
           1            0      0.0000      0.0000       <posix.fdopen>
           4            0      0.0000      0.0000       <method 'append' of
'list' objects>
       10449            0      0.4858      0.4858   <posix.link>
         816            0      0.2360      0.2360   <posix.mkdir>
       15176            0      0.2270      0.2270   <posix.stat>
         812            0      0.1060      0.1060   <mercurial.osutil.listdir>
        3860            0      0.0832      0.0832   <posix.lstat>
       11270            0      0.2342      0.0737   genericpath:38(isdir)
       11270            0      0.1514      0.1514       <posix.stat>
       11268            0      0.0091      0.0061       stat:40(S_ISDIR)
          18            0      0.0733      0.0733   <method 'acquire' of
'thread.lock' objects>
        3832            0      0.1482      0.0731   genericpath:26(isfile)
        3832            0      0.0751      0.0751       <posix.stat>
           3            0      0.0000      0.0000       stat:49(S_ISREG)
          11            0      0.0704      0.0704   <method 'read' of 'file'
objects>
        3827            0      0.1657      0.0692  
mercurial.dirstate:376(normal)
        3827            0      0.0830      0.0830       <posix.lstat>
        3827            0      0.0120      0.0084      
mercurial.dirstate:358(_addpath)
        3827            0      0.0015      0.0015      
mercurial.dirstate:154(_join)
       26499            0      0.0649      0.0649   <method 'endswith' of
'str' objects>
         207            0      0.0611      0.0611  
mercurial.demandimport:62(__init__)
           1            0      0.0000      0.0000       <method 'split' of
'str' objects>
       11261        11252      1.2143      0.0455  
mercurial.util:723(copyfiles)
       10449            0      0.4858      0.4858       <posix.link>
         812            0      0.2359      0.2359       <posix.mkdir>
         812            0      0.1060      0.1060      
<mercurial.osutil.listdir>

then as user:

      409275            0     62.7799     62.7799   <zlib.compress>
      870209            0     24.9208     24.9208   <zlib.decompress>
      394525            0    134.1828      9.3880  
mercurial.revlog:1215(_addrevision)
      394525            0     15.7891      3.6185      
mercurial.revlog:1322(_writeentry)
      384226            0     58.8240      2.9459      
mercurial.revlog:1240(builddelta)
      394525            0      1.8407      1.8407      
mercurial.revlog:53(offset_type)
      394525            0      1.2921      1.2921       <method 'insert' of
'parsers.index' objects>
      394525            0      2.6258      1.1176      
mercurial.revlog:347(end)
     1214469            0     97.4695      8.5002   mercurial.util:1177(read)
     1204271            0     86.0222      1.5735      
mercurial.util:1164(splitbig)
     1214469            0      0.6826      0.6826       <method 'join' of
'str' objects>
     2429136            0      0.6538      0.6538       <len>
     1224866            0      0.5961      0.5961       <method 'popleft' of
'collections.deque' objects>
     1224866            0      0.5569      0.5569       <method 'append' of
'list' objects>
     3574398            0      8.3254      8.3254   mercurial.revlog:345(start)
          41            0      8.3029      8.1887  
mercurial.worker:76(_posixworker)
           4            0      0.0226      0.0226       <posix.fork>
           5            0      0.0011      0.0011      
mercurial.worker:147(partition)
           1            0      0.0000      0.0000       <posix.fdopen>
          40            0      0.0000      0.0000       <method 'split' of
'str' objects>
           2            0      0.0728      0.0000      
mercurial.demandimport:103(__getattribute__)
      434701            0     68.6374      7.7899  
mercurial.revlog:1028(revision)
      420406            0     39.8659      5.5714      
mercurial.revlog:969(_chunks)
      420406            0      2.0531      2.0531      
<mercurial.mpatch.patches>
      420406            0     14.0931      1.2543      
mercurial.revlog:1102(_checkhash)
      405438            0      1.7335      1.2196      
mercurial.changelog:221(flags)
      272381            0      1.7630      1.2133      
mercurial.changelog:203(node)
       10299            0    258.3115      7.4902  
mercurial.revlog:1340(addgroup)
      394525            0    134.1828      9.3880      
mercurial.revlog:1215(_addrevision)
      404824            0    107.4064      3.3076      
mercurial.changegroup:180(deltachunk)

obviously, the calls to revlog make a difference.