Page MenuHomePhabricator

"(Exception) Expected nonempty 'cmds' specification!" when trying to clone or pull mercurial repository
Closed, InvalidPublic

Description

Hi,

I recently made an update on my phabricator instance. I had no big issues with anything until I tried to use a newly created mercurial repo, that returned this weird error 500 after the auth.
I tried access an older mercurial repo, also with no success.

C:\repo>hg pull
pulling from http://server.com/diffusion/REPO/repo/
http authorization required for http://server.com/diffusion/REPO/repo/
realm: Phabricator Repositories
user: myuser
password:
abort: HTTP Error 500: Error 1: ** unknown exception encountered, please report by visiting

Git repos are ok (and thats why I didnt get the error early)

by the logs on error_logs:

[2017-04-07 22:49:34] EXCEPTION: (Exception) Expected nonempty 'cmds' specification! at [<phabricator>/src/applications/diffusion/protocol/DiffusionMercurialWireProtocol.php:68]
arcanist(head=master, ref.master=3b6b523c2b23), phabricator(head=master, ref.master=8ce25838f541), phutil(head=master, ref.master=c26f7b429f71)
  #0 <#2> DiffusionMercurialWireProtocol::isReadOnlyBatchCommand(NULL) called at [<phabricator>/src/applications/diffusion/controller/DiffusionServeController.php:480]
  #1 <#2> DiffusionServeController::isReadOnlyRequest(PhabricatorRepository) called at [<phabricator>/src/applications/diffusion/controller/DiffusionServeController.php:262]
  #2 <#2> DiffusionServeController::serveRequest(AphrontRequest) called at [<phabricator>/src/applications/diffusion/controller/DiffusionServeController.php:99]
  #3 <#2> DiffusionServeController::handleRequest(AphrontRequest) called at [<phabricator>/src/aphront/AphrontController.php:71]
  #4 <#2> AphrontController::delegateToController(DiffusionServeController) called at [<phabricator>/src/applications/diffusion/controller/DiffusionController.php:27]
  #5 <#2> DiffusionController::willBeginExecution() called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:256]
  #6 phlog(Exception) called at [<phabricator>/src/aphront/handler/PhabricatorDefaultRequestExceptionHandler.php:41]
  #7 PhabricatorDefaultRequestExceptionHandler::handleRequestException(AphrontRequest, Exception) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:678]
  #8 AphrontApplicationConfiguration::handleException(Exception) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:274]
  #9 AphrontApplicationConfiguration::processRequest(AphrontRequest, PhutilDeferredLog, AphrontPHPHTTPSink, MultimeterControl) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:177]
  #10 AphrontApplicationConfiguration::runHTTPRequest(AphrontPHPHTTPSink) called at [<phabricator>/webroot/index.php:17]
[2017-04-07 22:49:34] EXCEPTION: (Exception) Expected nonempty 'cmds' specification! at [<phabricator>/src/applications/diffusion/protocol/DiffusionMercurialWireProtocol.php:68]
arcanist(head=master, ref.master=3b6b523c2b23), phabricator(head=master, ref.master=8ce25838f541), phutil(head=master, ref.master=c26f7b429f71)
  #0 <#2> DiffusionMercurialWireProtocol::isReadOnlyBatchCommand(NULL) called at [<phabricator>/src/applications/diffusion/controller/DiffusionServeController.php:480]
  #1 <#2> DiffusionServeController::isReadOnlyRequest(PhabricatorRepository) called at [<phabricator>/src/applications/diffusion/controller/DiffusionServeController.php:262]
  #2 <#2> DiffusionServeController::serveRequest(AphrontRequest) called at [<phabricator>/src/applications/diffusion/controller/DiffusionServeController.php:99]
  #3 <#2> DiffusionServeController::handleRequest(AphrontRequest) called at [<phabricator>/src/aphront/AphrontController.php:71]
  #4 <#2> AphrontController::delegateToController(DiffusionServeController) called at [<phabricator>/src/applications/diffusion/controller/DiffusionController.php:27]
  #5 <#2> DiffusionController::willBeginExecution() called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:256]
  #6 <#2> AphrontApplicationConfiguration::processRequest(AphrontRequest, PhutilDeferredLog, AphrontPHPHTTPSink, MultimeterControl) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:177]
  #7 <#2> AphrontApplicationConfiguration::runHTTPRequest(AphrontPHPHTTPSink) called at [<phabricator>/webroot/index.php:17]
  #8 phlog(Exception) called at [<phabricator>/src/aphront/response/AphrontUnhandledExceptionResponse.php:20]
  #9 AphrontUnhandledExceptionResponse::setException(Exception) called at [<phabricator>/webroot/index.php:21]

It apears that I'm missing some GET param on the request
But the cmd var is present in the request, by the looks of the entry on access log:

"GET /diffusion/REPO/repo/?cmd=capabilities HTTP/1.1" 200 114
"GET /diffusion/REPO/repo/?cmd=listkeys&namespace=bookmarks HTTP/1.1" 500 73

I tried with different mercurial clients (tortoisehg, sourcetree), and nothing so it cant be on the client side.
We had this working in our setup, so it can't be any misconfiguration or anything.
Tried to update phabricator again, and the issue persists
Also tried to restart services (httpd, phd)

The strange part is not fiding anything about this here already, as it seems so easy to reproduce.

Reproduction steps:

Create a Mercurial repository and activate it
Try to clone or pull

Expected result:

Clone repository

Actual result:

Error 500 after credentials

Versions

phabricator 7707685733d26bf1c7278a2f338416a038c2709b (Fri, Apr 7) 
arcanist a59cfca5f190c44403dfc7449c678a2aa1626bb4 (Tue, Apr 4) 
phutil c581e769f10c6d2b427900897edba74e01a572bd (Sat, Mar 25)
Server version: Apache/2.4.25 (Unix)
Server built:   Dec 20 2016 13:02:22
PHP 7.1.2 (cli) (built: Feb 14 2017 21:24:49) ( NTS )
Copyright (c) 1997-2017 The PHP Group
Zend Engine v3.1.0, Copyright (c) 1998-2017 Zend Technologies
    with Zend OPcache v7.1.2, Copyright (c) 1999-2017, by Zend Technologies

Thanks in advance, for any help.

Event Timeline

Does this reproduce against a Phacility instance or our test mercurial repository here?

Please indicate the versions of mercurial on client/server as well as any extensions you have enabled on client/server

In T12521#218608, @chad wrote:

Does this reproduce against a Phacility instance or our test mercurial repository here?

It doesn't replicate in a Phachility test instance, but I wasn't able to disable https to replicate my setup correctly


Please indicate the versions of mercurial on client/server as well as any extensions you have enabled on client/server

mercurial server (Arch server) version

Mercurial Distributed SCM (version 4.1.1)
(see https://mercurial-scm.org for more information)

Copyright (C) 2005-2017 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.

mercurial client (Windows 10 desktop) version

Mercurial Distributed SCM (version 4.1)
(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.

and no extensions

This still needs complete reproduction steps to be accepted into the upstream. My suggestion is find another VM and load out what you expect the issue is with, and give us those details. Right now it sounds like you're just guessing and that's outside of what we expect when following Contributing Bug Reports. See https://secure.phabricator.com/book/phabcontrib/article/reproduction_steps/ if you need more guidance on providing these steps.

Just faced that problem on my micro hosting. I've updated some software and then started to get the same error as OP when cloning/pulling/pushing mercurial repos. Here is the list of software, that got updated back then: https://paste.kde.org/pqelvuhjf

After fiddling with some more upgrades, I started to get

HTTP Error: 500 (Error 255: abort: potentially unsafe serve --stdio invocation: ['serve', '--stdio'])

This seems to be related with T9548.

epriestley added a subscriber: epriestley.

This is possibly connected to T9548 but we don't know how to reproduce this and can't fix issues we can't reproduce.

The --stdio invocation was not related to T9548 and was fixed by D18616.

I still having this problem. @rafaelrabeloit, had you chance to fix or work-around this?

I've managed to find the root of the problem, I think. Here is the actual error message that arises somwhere deep in Phabricator and then gets cut turning into non-informative ** unknown exception encountered, please report by visiting:

** unknown exception encountered, please report by visiting
** https://mercurial-scm.org/wiki/BugTracker
** Python 2.7.15 (default, Nov 13 2018, 01:16:37) [GCC 4.2.1 Compatible FreeBSD Clang 6.0.0 (tags/RELEASE_600/final 326565)]
** Mercurial Distributed SCM (version 4.8)
** Extensions loaded: 
Traceback (most recent call last):
  File "/usr/local/bin/hg", line 43, in <module>
    dispatch.run()
  File "/usr/local/lib/python2.7/site-packages/mercurial/dispatch.py", line 96, in run
    status = dispatch(req)
  File "/usr/local/lib/python2.7/site-packages/mercurial/dispatch.py", line 220, in dispatch
    ret = _runcatch(req) or 0
  File "/usr/local/lib/python2.7/site-packages/mercurial/dispatch.py", line 363, in _runcatch
    return _callcatch(ui, _runcatchfunc)
  File "/usr/local/lib/python2.7/site-packages/mercurial/dispatch.py", line 371, in _callcatch
    return scmutil.callcatch(ui, func)
  File "/usr/local/lib/python2.7/site-packages/mercurial/scmutil.py", line 166, in callcatch
    return func()
  File "/usr/local/lib/python2.7/site-packages/mercurial/dispatch.py", line 354, in _runcatchfunc
    return _dispatch(req)
  File "/usr/local/lib/python2.7/site-packages/mercurial/dispatch.py", line 994, in _dispatch
    cmdpats, cmdoptions)
  File "/usr/local/lib/python2.7/site-packages/mercurial/dispatch.py", line 737, in runcommand
    ret = _runcommand(ui, options, cmd, d)
  File "/usr/local/lib/python2.7/site-packages/mercurial/dispatch.py", line 1003, in _runcommand
    return cmdfunc()
  File "/usr/local/lib/python2.7/site-packages/mercurial/dispatch.py", line 991, in <lambda>
    d = lambda: util.checksignature(func)(ui, *args, **strcmdopt)
  File "/usr/local/lib/python2.7/site-packages/mercurial/util.py", line 1644, in check
    return func(*args, **kwargs)
  File "/usr/local/lib/python2.7/site-packages/mercurial/commands.py", line 5206, in serve
    s.serve_forever()
  File "/usr/local/lib/python2.7/site-packages/mercurial/wireprotoserver.py", line 797, in serve_forever
    self.serveuntil(threading.Event())
  File "/usr/local/lib/python2.7/site-packages/mercurial/wireprotoserver.py", line 804, in serveuntil
    _runsshserver(self._ui, self._repo, self._fin, self._fout, ev)
  File "/usr/local/lib/python2.7/site-packages/mercurial/wireprotoserver.py", line 656, in _runsshserver
    rsp = wireprotov1server.dispatch(repo, proto, request)
  File "/usr/local/lib/python2.7/site-packages/mercurial/wireprotov1server.py", line 72, in dispatch
    args = proto.getargs(spec)
  File "/usr/local/lib/python2.7/site-packages/mercurial/wireprotoserver.py", line 505, in getargs
    arg, l = argline.split()
ValueError: need more than 0 values to unpack

This is a Mercurial bug, then?

Ok, I think the problem is here: https://github.com/phacility/phabricator/blob/master/src/applications/diffusion/controller/DiffusionServeController.php#L816

Comment in this function says that Mercurial passes args via HTTP headers, but dumping $_SERVER in my case yields

array (
  'SCRIPT_URL' => '/source/www',
  'SCRIPT_URI' => 'https://ph.redborder.ru/source/www',
  'HTTPS' => 'on',
  'SSL_TLS_SNI' => 'ph.redborder.ru',
  'HTTP_ACCEPT_ENCODING' => 'identity',
  'HTTP_VARY' => 'X-HgProto-1',
  'HTTP_X_HGPROTO_1' => 'partial-pull',
  'HTTP_ACCEPT' => 'application/mercurial-0.1',
  'HTTP_HOST' => 'ph.redborder.ru',
  'HTTP_USER_AGENT' => 'mercurial/proto-1.0 (Mercurial 4.8)',
  'PATH' => '/sbin:/bin:/usr/sbin:/usr/bin:/usr/games:/usr/local/sbin:/usr/local/bin:/root/bin',
  'LD_LIBRARY_PATH' => '/usr/local/lib',
  'SERVER_SIGNATURE' => '',
  'SERVER_SOFTWARE' => 'Apache/2.4.37 (FreeBSD) OpenSSL/1.0.2o-freebsd PHP/7.2.12',
  'SERVER_NAME' => 'ph.redborder.ru',
  'SERVER_ADDR' => '80.87.201.59',
  'SERVER_PORT' => '443',
  'REMOTE_ADDR' => '94.233.39.8',
  'DOCUMENT_ROOT' => '/usr/local/lib/php/phabricator/webroot',
  'REQUEST_SCHEME' => 'https',
  'CONTEXT_PREFIX' => '',
  'CONTEXT_DOCUMENT_ROOT' => '/usr/local/lib/php/phabricator/webroot',
  'SERVER_ADMIN' => 'you@example.com',
  'SCRIPT_FILENAME' => '/usr/local/lib/php/phabricator/webroot/index.php',
  'REMOTE_PORT' => '20528',
  'GATEWAY_INTERFACE' => 'CGI/1.1',
  'SERVER_PROTOCOL' => 'HTTP/1.1',
  'REQUEST_METHOD' => 'GET',
  'QUERY_STRING' => '__path__=%2fsource%2fwww&cmd=listkeys&namespace=bookmarks',
  'REQUEST_URI' => '/source/www?cmd=listkeys&namespace=bookmarks',
  'SCRIPT_NAME' => '/source/www',
  'PHP_SELF' => '/source/www',
  'PHP_AUTH_USER' => 'arrowdodger',
  'REQUEST_TIME_FLOAT' => 1543922710.3670001,
  'REQUEST_TIME' => 1543922710,
)

This causes $args in serveMercurialRequest() to be empty when calling listkeys Mercurial command.

Running echo listkeys | /usr/local/bin/hg -R /home/phabricator/repos/21/ serve --stdio returns the same error I posted above. Passing listkeys bookmarks instead returns 0.

@epriestley I have seen you working on Mercurial stuff. Can you take a look at my findings above?

If you want me to look at something, file a report on Discourse with reproduction steps that I can follow to reproduce the issue. I don't need any other discussion or context. I do need working reproduction steps.

If you don't want to do that or can't identify reproduction steps, I'm happy to help you work through problems that aren't reproducible if you buy a support pact -- see Support Pacts.