[PATCH stable?] subrepo: print the status line before creating the peer for better diagnostics

[Matt Harbison]

# HG changeset patch
# User Matt Harbison <matt_harbison at yahoo.com>
# Date 1542411446 18000
#      Fri Nov 16 18:37:26 2018 -0500
# Node ID 610eb5c155df5ca300827e10cd2c3426f0ba0842
# Parent  d0895b5f51c91ea30087c0bd16a193e94d989bfb
subrepo: print the status line before creating the peer for better diagnostics

I ran into a problem where I tried updating to a different branch, and the
process appeared to hang.  It turned out that the subrepo revision wasn't
available locally, and I must have originally cloned it from an `hg serve -S` on
a machine that currently wasn't serving anything.  It took 2+ minutes to
timeout, and didn't mention what it was connecting to even then.

There are a couple of other issues in this scenario too.

  - The repo is dirty after the failed checkout because the top level repo is
    updated first.  We should probably make 2 passes- top down to pull
    everything needed, and then do an update once everything is in place.

  - Something must be reading .hgsubstate from wdir because if the same merge
    command is run after the timeout, a prompt is issued that the local and
    remote subrepo diverged, instead of hanging.  But it lists the local version
    and remote version as having the same hash.

diff --git a/mercurial/subrepo.py b/mercurial/subrepo.py
--- a/mercurial/subrepo.py
+++ b/mercurial/subrepo.py
@@ -622,7 +622,11 @@ class hgsubrepo(abstractsubrepo):
                 return True
         self._repo._subsource = source
         srcurl = _abssource(self._repo)
-        other = hg.peer(self._repo, {}, srcurl)
+
+        # Defer creating the peer until after the status message is logged, in
+        # case there are network problems.
+        getpeer = lambda: hg.peer(self._repo, {}, srcurl)
+
         if len(self._repo) == 0:
             # use self._repo.vfs instead of self.wvfs to remove .hg only
             self._repo.vfs.rmtree()
@@ -636,7 +640,7 @@ class hgsubrepo(abstractsubrepo):
                 self.ui.status(_('sharing subrepo %s from %s\n')
                                % (subrelpath(self), srcurl))
                 shared = hg.share(self._repo._subparent.baseui,
-                                  other, self._repo.root,
+                                  getpeer(), self._repo.root,
                                   update=False, bookmarks=False)
                 self._repo = shared.local()
             else:
@@ -657,7 +661,7 @@ class hgsubrepo(abstractsubrepo):
                 self.ui.status(_('cloning subrepo %s from %s\n')
                                % (subrelpath(self), util.hidepassword(srcurl)))
                 other, cloned = hg.clone(self._repo._subparent.baseui, {},
-                                         other, self._repo.root,
+                                         getpeer(), self._repo.root,
                                          update=False, shareopts=shareopts)
                 self._repo = cloned.local()
             self._initrepo(parentrepo, source, create=True)
@@ -666,7 +670,7 @@ class hgsubrepo(abstractsubrepo):
             self.ui.status(_('pulling subrepo %s from %s\n')
                            % (subrelpath(self), util.hidepassword(srcurl)))
             cleansub = self.storeclean(srcurl)
-            exchange.pull(self._repo, other)
+            exchange.pull(self._repo, getpeer())
             if cleansub:
                 # keep the repo clean after pull
                 self._cachestorehash(srcurl)
diff --git a/tests/test-http-bundle1.t b/tests/test-http-bundle1.t
--- a/tests/test-http-bundle1.t
+++ b/tests/test-http-bundle1.t
@@ -340,6 +340,7 @@ clone of serve with repo in root and uns
   added 3 changesets with 7 changes to 7 files
   new changesets 8b6053c928fe:56f9bc90cce6
   updating to branch default
+  cloning subrepo sub from http://localhost:$HGPORT/sub
   abort: HTTP Error 404: Not Found
   [255]
   $ hg clone http://localhost:$HGPORT/ slash-clone
@@ -350,6 +351,7 @@ clone of serve with repo in root and uns
   added 3 changesets with 7 changes to 7 files
   new changesets 8b6053c928fe:56f9bc90cce6
   updating to branch default
+  cloning subrepo sub from http://localhost:$HGPORT/sub
   abort: HTTP Error 404: Not Found
   [255]
 
diff --git a/tests/test-http.t b/tests/test-http.t
--- a/tests/test-http.t
+++ b/tests/test-http.t
@@ -417,6 +417,7 @@ clone of serve with repo in root and uns
   added 3 changesets with 7 changes to 7 files
   new changesets 8b6053c928fe:56f9bc90cce6
   updating to branch default
+  cloning subrepo sub from http://localhost:$HGPORT/sub
   abort: HTTP Error 404: Not Found
   [255]
   $ hg clone http://localhost:$HGPORT/ slash-clone
@@ -427,6 +428,7 @@ clone of serve with repo in root and uns
   added 3 changesets with 7 changes to 7 files
   new changesets 8b6053c928fe:56f9bc90cce6
   updating to branch default
+  cloning subrepo sub from http://localhost:$HGPORT/sub
   abort: HTTP Error 404: Not Found
   [255]
 
diff --git a/tests/test-subrepo-deep-nested-change.t b/tests/test-subrepo-deep-nested-change.t
--- a/tests/test-subrepo-deep-nested-change.t
+++ b/tests/test-subrepo-deep-nested-change.t
@@ -108,6 +108,7 @@ are also available as siblings of 'main'
   added 1 changesets with 3 changes to 3 files
   new changesets 7f491f53a367
   updating to branch default
+  cloning subrepo sub1 from http://localhost:$HGPORT/../sub1
   abort: HTTP Error 404: Not Found
   [255]
 
diff --git a/tests/test-subrepo-recursion.t b/tests/test-subrepo-recursion.t
--- a/tests/test-subrepo-recursion.t
+++ b/tests/test-subrepo-recursion.t
@@ -574,6 +574,7 @@ whereas clone should fail.
 
   $ hg --config progress.disable=True clone ../empty2 ../empty_clone
   updating to branch default
+  cloning subrepo foo from $TESTTMP/empty2/foo
   abort: repository $TESTTMP/empty2/foo not found!
   [255]
 
diff --git a/tests/test-subrepo.t b/tests/test-subrepo.t
--- a/tests/test-subrepo.t
+++ b/tests/test-subrepo.t
@@ -1889,6 +1889,7 @@ test for ssh exploit 2017-07-25
   $ cd ..
   $ hg clone malicious-proxycommand malicious-proxycommand-clone
   updating to branch default
+  cloning subrepo s from ssh://-oProxyCommand%3Dtouch%24%7BIFS%7Downed/path
   abort: potentially unsafe url: 'ssh://-oProxyCommand=touch${IFS}owned/path' (in subrepository "s")
   [255]
 
@@ -1901,6 +1902,7 @@ also check that a percent encoded '-' (%
   $ rm -r malicious-proxycommand-clone
   $ hg clone malicious-proxycommand malicious-proxycommand-clone
   updating to branch default
+  cloning subrepo s from ssh://-oProxyCommand%3Dtouch%24%7BIFS%7Downed/path
   abort: potentially unsafe url: 'ssh://-oProxyCommand=touch${IFS}owned/path' (in subrepository "s")
   [255]
 
@@ -1913,6 +1915,7 @@ also check for a pipe
   $ rm -r malicious-proxycommand-clone
   $ hg clone malicious-proxycommand malicious-proxycommand-clone
   updating to branch default
+  cloning subrepo s from ssh://fakehost%7Ctouch%24%7BIFS%7Downed/path
   abort: no suitable response from remote hg!
   [255]
   $ [ ! -f owned ] || echo 'you got owned'
@@ -1926,6 +1929,7 @@ also check that a percent encoded '|' (%
   $ rm -r malicious-proxycommand-clone
   $ hg clone malicious-proxycommand malicious-proxycommand-clone
   updating to branch default
+  cloning subrepo s from ssh://fakehost%7Ctouch%20owned/path
   abort: no suitable response from remote hg!
   [255]
   $ [ ! -f owned ] || echo 'you got owned'
@@ -1938,6 +1942,7 @@ and bad usernames:
   $ rm -r malicious-proxycommand-clone
   $ hg clone malicious-proxycommand malicious-proxycommand-clone
   updating to branch default
+  cloning subrepo s from ssh://-oProxyCommand%3Dtouch%20owned@example.com/path
   abort: potentially unsafe url: 'ssh://-oProxyCommand=touch owned at example.com/path' (in subrepository "s")
   [255]