Transaction abort when pushing via SSH to a Mercurial repository
Closed, DuplicatePublic
Actions

Assigned To

None

Authored By

	urzds
	Feb 18 2016, 3:27 PM

Description

Whenever I try to push to a Mercurial repository in Phabricator via SSH, the remote end aborts the transaction:

# hg push --debug
Übertrage nach ssh://phab@...
running ssh phab@... 'hg -R diffusion/... serve --stdio'
sending hello command
sending between command
remote: 145
remote: capabilities: lookup changegroupsubset branchmap pushkey known getbundle unbundlehash batch stream unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024
remote: 1
query 1; heads
sending batch command
Suche nach Änderungen
all remote heads known locally
preparing listkeys for "phases"
sending listkeys command
received listkey for "phases": 15 bytes
checking for updated bookmarks
preparing listkeys for "bookmarks"
sending listkeys command
received listkey for "bookmarks": 0 bytes
sending branchmap command
sending branchmap command
preparing listkeys for "bookmarks"
sending listkeys command
received listkey for "bookmarks": 0 bytes
10 Änderungssätze gefunden
list of changesets:
...
sending unbundle command
Gegenseite: adding changesets
Gegenseite: adding manifests
Gegenseite: adding file changes
Gegenseite: transaction abort!
Gegenseite: rollback completed
Gegenseite: abort: stream ended unexpectedly (got 13645 bytes, expected 363789)
Gegenseite: Exception: Writing to a closed pipe!

Pushing to a freshly created repository works without any issues.

Is there any way I can figure out why Phabricator/Mercurial aborts the transaction?

sshd logs:

sshd[5199]: Accepted publickey for phab from ... port ... ssh2: ECDSA ...
sudo[5212]: phab : TTY=unknown ; PWD=/home/phab ; USER=phd ; COMMAND=/usr/bin/hg -R /var/repo/.../ serve --stdio
sudo[5212]: pam_unix(sudo:session): session opened for user phd by (uid=0)
sudo[5212]: pam_unix(sudo:session): session closed for user phd
sshd[5205]: Received disconnect from ...: 11: disconnected by user

The issue happens with Mercurial 3.6.3 and 3.7.1 locally and 3.1.2 (Debian Jessie) on the Phabricator machine.

I am running current stable Phabricator:

phabricator
    d51001a4d208d4ad5b30e353e99f3f9d69c4a57b (Tue, Feb 16) 
arcanist
    ed476cf8489c4bf41b7a0075f15d40820d640fe4 (Sat, Feb 13) 
phutil
    c0cf996fe3119d6c158586b2a959e57401daf212 (Tue, Feb 9) 
libphremoteuser
    53b5b5064ff787802a4180ca47b5d135d937a265 (Aug 19 2015) 
sprint
    1ddd5084a80d6a2aa239670c1a6557f800eb553d (Sun, Feb 14)

With minor and likely unrelated patches mostly to the server default language and login, but also adding a few images:
https://github.com/phacility/libphutil/compare/stable...uhd-urz:urz/stable
https://github.com/phacility/phabricator/compare/stable...uhd-urz:urz/stable

Related Objects

Mentioned Here: T6171: Transaction abort on first push via SSH to empty Mercurial repository
T9548: Support Mercurial's bundle2 wire protocol
D14241: Added an intercept to Mercurial's `capabilities` command to remove bundle2.

Event Timeline

urzds created this task.Feb 18 2016, 3:27 PM

I updated the server-side Mercurial to 3.5.2 and now get following output on the client-side:

# hg push --debug                                                                                                                                                                                                    
Übertrage nach ssh://phab@.../diffusion/.../
running ssh phab@... 'hg -R diffusion/.../ serve --stdio'
sending hello command
sending between command
remote: 345
remote: capabilities: lookup changegroupsubset branchmap pushkey known getbundle unbundlehash batch stream bundle2=HG20%0Achangegroup%3D01%2C02%0Adigests%3Dmd5%2Csha1%2Csha512%0Aerror%3Dabort%2Cunsupportedcontent%2Cpushraced%2Cpushkey%0Ahgtagsfnodes%0Alistkeys%0Apushkey%0$
remote-changegroup%3Dhttp%2Chttps unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024
remote: 1
query 1; heads
sending batch command
Suche nach Änderungen
all remote heads known locally
preparing listkeys for "phases"
sending listkeys command
received listkey for "phases": 15 bytes
checking for updated bookmarks
preparing listkeys for "bookmarks"
sending listkeys command
received listkey for "bookmarks": 0 bytes
sending branchmap command
sending branchmap command
preparing listkeys for "bookmarks"
sending listkeys command
received listkey for "bookmarks": 0 bytes
15 Änderungssätze gefunden
list of changesets:
[...]
sending unbundle command
bundle2-output-bundle: "HG20", 4 parts total
bundle2-output-part: "replycaps" 155 bytes payload
bundle2-output-part: "check:heads" streamed payload
bundle2-output-part: "changegroup" (params: 1 mandatory) streamed payload
Gegenseite: abort: stream ended unexpectedly (got 0 bytes, expected 4)
Gegenseite: ** unknown exception encountered, please report by visiting
Gegenseite: ** http://mercurial.selenic.com/wiki/BugTracker
Gegenseite: ** Python 2.7.9 (default, Mar  1 2015, 12:57:24) [GCC 4.9.2]
Gegenseite: ** Mercurial Distributed SCM (version 3.5.2)
Gegenseite: ** Extensions loaded: 
Gegenseite: Traceback (most recent call last):
Gegenseite:   File "/usr/bin/hg", line 43, in <module>
Gegenseite:     mercurial.dispatch.run()
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 30, in run
Gegenseite:     sys.exit((dispatch(request(sys.argv[1:])) or 0) & 255)
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 92, in dispatch
Gegenseite:     ret = _runcatch(req)
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 163, in _runcatch
Gegenseite:     return _dispatch(req)
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 895, in _dispatch
Gegenseite:     cmdpats, cmdoptions)
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 656, in runcommand
Gegenseite:     ret = _runcommand(ui, options, cmd, d)
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 1013, in _runcommand
Gegenseite:     return checkargs()
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 982, in checkargs
Gegenseite:     return cmdfunc()
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 892, in <lambda>
Gegenseite:     d = lambda: util.checksignature(func)(ui, *args, **cmdoptions)
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/util.py", line 794, in check
Gegenseite:     return func(*args, **kwargs)
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/commands.py", line 5713, in serve
Gegenseite:     s.serve_forever()
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/sshserver.py", line 94, in serve_forever
Gegenseite:     while self.serve_one():
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/sshserver.py", line 112, in serve_one
Gegenseite:     rsp = wireproto.dispatch(self.repo, self, cmd)
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/wireproto.py", line 515, in dispatch
Gegenseite:     args = proto.getargs(spec)
Gegenseite:   File "/usr/lib/python2.7/dist-packages/mercurial/sshserver.py", line 32, in getargs
Gegenseite:     arg, l = argline.split()
Gegenseite: ValueError: need more than 1 value to unpack
Gegenseite: Exception: Writing to a closed pipe!
bundle2-generatorexit

The issue with 3.5.2 on the server-side might be different from the original problem and instead be related to D14241 and T9548.

chad added a project: Mercurial.Feb 18 2016, 4:23 PM

Herald added a subscriber: cspeckmim. · View Herald TranscriptFeb 18 2016, 4:23 PM

Reading the code around /usr/lib/python2.7/dist-packages/mercurial/sshserver.py:32:

def getargs(self, args):
    data = {}
    keys = args.split()
    for n in xrange(len(keys)):
        argline = self.fin.readline()[:-1]
        arg, l = argline.split()
        if arg not in keys:
            raise util.Abort("unexpected parameter %r" % arg)
        if arg == '*':
            star = {}
            for k in xrange(int(l)):
                argline = self.fin.readline()[:-1]
                arg, l = argline.split()
                val = self.fin.read(int(l))
                star[arg] = val
            data['*'] = star
        else:
            val = self.fin.read(int(l))
            data[arg] = val
    return [data[k] for k in keys]

I assume that the server expects each argument to be of following form:

<argument name> <#raw bytes>
<raw bytes>

For whatever reason, my client (or Phabricator?) sends a malformed stream, which does not adhere to this scheme:

pushkey

I use following patch to get a transcript:

--- /usr/lib/python2.7/dist-packages/mercurial/sshserver.py.orig        2016-02-20 01:02:15.096842874 +0100
+++ /usr/lib/python2.7/dist-packages/mercurial/sshserver.py     2016-02-20 01:01:29.889233485 +0100
@@ -29,6 +29,8 @@
         keys = args.split()
         for n in xrange(len(keys)):
             argline = self.fin.readline()[:-1]
+            with open("/tmp/mercurial.log", "a") as f:
+                f.write(argline)
             arg, l = argline.split()
             if arg not in keys:
                 raise util.Abort("unexpected parameter %r" % arg)

The result is:

# cat /tmp/mercurial.log
pairs 81
* 0
cmds 59
namespace 6
namespace 9
namespace 9
heads 10
pushkey

This implies a question: Could it be Phabricator which modifies the stream between the client and the server in an illegal way? Or is this some bug in Mercurial itself?

(I previously accidentally added this comment to T6171, which is another instance of a similar issue.)

fcoelho added a subscriber: fcoelho.Apr 7 2016, 1:40 AM

@fcoelho - Would you be able to test your log change with pushing to a mercurial repository not hosted by Phabricator, to compare with the log from your previous comment?

@cspeckmim I think you probably confused me with @urzds, I didn't post any logs here yet.

One of my users got the same error, but he "solved" it by downgrading his mercurial client to 3.4.x - he was having issues regardless of the version of Mercurial on the server.

I'll ask him tomorrow to try pushing to both Phabricator and something like Bitbucket with a newer version of mercurial and will post back with the results

@fcoelho oops sorry about the mixup. I've previously had success by downgrading the client to 3.4 or less.

@urzds - would you be able to test your log change with pushing to a mercurial repository not hosted on Phabricator?

@cspeckmim Sadly I don't have any Mercurial host that is not Phabricator.

epriestley merged a task: T11100: transaction abort! when push a lot of changes with mercurial.Jun 6 2016, 1:51 PM

epriestley added subscribers: richardvanvelzen, PhoneixS.

Could someone create a Mercurial bug (https://bz.mercurial-scm.org) with explanation about how Phabricator handles the bundle2 ssh stream? They might be able to give some hints.
I would like to do it, but I'm not sure how Phabricator handles the stream exactly.

See T9548#139908 for some discussion.

So, yes, the bundle2 thing is definitely orthogonal to this. For now, I'd suggest that if phabricator breaks bundle2, filter the response to the capabilities command and omit bundle2=.* from the response.

The wire protocol is...special. Assuming that the framing over http /in any way/ resembles the framing over ssh is going to end extremely badly for you. Is there any chance we can accomplish what phabricator needs using hooks instead of trying to mitm the wireproto?

Not sure if this is the same issue, this is on a new phacility hosted phabricator instance, when attempting to push to a new mercurial repo:

gabe@xps:~/src/kids$ hg push --debug
pushing to ssh://lifewaza@vault.phacility.com/source/kids/
running ssh lifewaza@vault.phacility.com 'hg -R source/kids/ serve --stdio'
sending hello command
sending between command
remote: Host key fingerprint is SHA256:VzmNPyDCO0pzncqcO32zV1r2M0VubRrD71c8AhIaibI
remote: +---[RSA 2048]----+
remote: |      . .        |
remote: |   . . + .   +   |
remote: |    o   = o * .  |
remote: |   E   . = = +  .|
remote: |      o S = ..o+.|
remote: |     . * =   .+o%|
remote: |      . =.    .%=|
remote: |        ... o +o+|
remote: |        .. ..+ .=|
remote: +----[SHA256]-----+
remote: 145
remote: capabilities: lookup changegroupsubset branchmap pushkey known getbundle unbundlehash batch stream unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024
remote: 1
query 1; heads
sending batch command
searching for changes
1 total queries
preparing listkeys for "phases"
sending listkeys command
received listkey for "phases": 15 bytes
checking for updated bookmarks
preparing listkeys for "bookmarks"
sending listkeys command
received listkey for "bookmarks": 0 bytes
1 changesets found
list of changesets:
6b79cfbf84d319f23137906c0968e0e5fe22c8e8
sending unbundle command
remote: abort: stream ended unexpectedly (got 0 bytes, expected 6)
remote: Exception: Unknown Mercurial command '462!
abort: unexpected response: empty string

gabe@xps:~/src/kids$ hg version
Mercurial Distributed SCM (version 3.8.3)
(see https://mercurial-scm.org for more information)

Copyright (C) 2005-2016 Matt Mackall and others
This is free software; see the source for copying conditions. There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

@gabe - That's the same issue, I believe. You should be able to push using Mercurial 3.4. I've been meaning to do some testing to try and fix this over the winter break but a day is no longer what it used to be.

chad merged a task: T12036: hg push fails (remote: Exception: Unknown Mercurial command '448!).Dec 21 2016, 6:05 PM

chad added a subscriber: marco-m.

So reading through all of this, am I understanding correctly that Phabricator and Mercurial > 3.4 aren't compatible with each other? I've spent the past couple days attempting to push an existing repository with a few thousand changesets into a Phabricator hosted instance to no avail (using mercurial 4.0.1 for both the client and server).

@jeremy.norris - You should be able to push if you use a mercurial client 3.4 or below. What I did is download the hg-3.4 sources and do make local, then moved the renamed binary into my path (/usr/local/bin/ I think), and I use hg-3.4 push -r master when pushing.

The sources can be downloaded from here: https://www.mercurial-scm.org/release/
Specifically: https://www.mercurial-scm.org/release/mercurial-3.4.2.tar.gz

Check the README but I believe all that's needed is make local which makes a standalone binary hg.

I have been doing so with a hosted mercurial repository on a phacility instance. I've been meaning to get around to investigating this but haven't had a chance. The workaround is sufficient for my purposes so I haven't been pressed to dig further into it.

Running vanilla Mercurial 3.4 should not be recommended as all vanilla versions older than 3.7.3 are vulnerable to a trio of CVEs, the most likely exploitable being CVE-2016-3630. Instead, Mercurial <4.0 can be configured to disable bundle2 via the experimental.bundle2-exp=false config option and Mercurial >=4.0 can do the same via devel.legacy.exchange=bundle1. Both of these options are undocumented. I discourage their use. But as a workaround for Phabricator, they are preferred to exposing clients to known security bugs.

Note that my suggestion in https://secure.phabricator.com/T10382#191728 is still what I think /should/ happen: if Phabricator insists on trying to parse the Mercurial protocol, it should absolutely not include capabilities it doesn't understand when queried by the client.

To be clear my suggestion was only for using 3.4 from client machines. Server machines can still be kept up to date.

In T10382#191728, @durin42 wrote:

For now, I'd suggest that if phabricator breaks bundle2, filter the response to the capabilities command and omit bundle2=.* from the response.

That is the current behavior but it's possible that the current implementation is not fully correct and causing the issues with not being able to push. I was not aware of the undocumented configurations that @indygreg mentioned and maybe that should be used instead?

I believe there's more to it than just the bundle2 setting that causes it to not work. It still breaks for me even with devel.legacy.exchange=bundle1:

File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/dispatch.py", line 205, in _runcatchfunc
  return _dispatch(req)
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/dispatch.py", line 901, in _dispatch
  cmdpats, cmdoptions)
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/dispatch.py", line 650, in runcommand
  ret = _runcommand(ui, options, cmd, d)
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/dispatch.py", line 909, in _runcommand
  return cmdfunc()
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/dispatch.py", line 898, in <lambda>
  d = lambda: util.checksignature(func)(ui, *args, **cmdoptions)
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/util.py", line 1037, in check
  return func(*args, **kwargs)
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/commands.py", line 6043, in push
  opargs=opts.get('opargs'))
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/exchange.py", line 474, in push
  _pushchangeset(pushop)
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/exchange.py", line 948, in _pushchangeset
  pushop.repo.url())
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/wireproto.py", line 443, in unbundle
  ret, output = self._callpush("unbundle", cg, heads=heads)
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/sshpeer.py", line 290, in _callpush
  self._send(d)
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/sshpeer.py", line 323, in _send
  self.pipeo.write("%d\n" % len(data))
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/sshpeer.py", line 91, in write
  return self._call('write', data)
File "/usr/local/Cellar/mercurial/4.0.2/lib/python2.7/site-packages/mercurial/sshpeer.py", line 115, in _call
  return meth(data)

All evidence points to this and T9548 being the same task, right? I'm just going to merge them.

epriestley closed this task as a duplicate of T9548: Support Mercurial's bundle2 wire protocol.Jan 9 2017, 3:14 PM

arend.danielek added a subscriber: arend.danielek.Jul 27 2017, 5:00 PM

Transaction abort when pushing via SSH to a Mercurial repositoryClosed, DuplicatePublicActions

Description

Related Objects

Event Timeline

Transaction abort when pushing via SSH to a Mercurial repository
Closed, DuplicatePublic
Actions