Page MenuHomePhabricator

`arc patch` is timing out
Closed, InvalidPublic

Description

We have a Differential revision with 13 diffs attached which is causing arc patch to time out. It seems that the differential.querydiffs call is taking more than 30 seconds to execute:

Exception
[cURL/28] (https://phabricator.REDACTED.com/api/differential.querydiffs) <CURLE_OPERATION_TIMEDOUT> The request took too long to complete.
(Run with `--trace` for a full exception trace.)
The full trace is
 ARGV  '/Volumes/REDACTED/phabricator/arcanist/bin/../scripts/arcanist.php' 'patch' 'D46496' '--trace'
 LOAD  Loaded "phutil" from "/Volumes/REDACTED/phabricator/libphutil/src".
 LOAD  Loaded "arcanist" from "/Volumes/REDACTED/phabricator/arcanist/src".
Config: Reading user configuration file "/Users/aboyton/.arcrc"...
Config: Did not find system configuration at "/etc/arcconfig".
Working Copy: Reading .arcconfig from "/Volumes/REDACTED/REDACTED/.arcconfig".
Working Copy: Path "/Volumes/REDACTED/REDACTED" is part of `git` working copy "/Volumes/REDACTED/REDACTED".
Working Copy: Project root is at "/Vo
lumes/REDACTED/REDACTED".
Config: Did not find local configuration at "/Volumes/REDACTED/REDACTED/.git/arc/config".
Loading phutil library from '/Volumes/REDACTED/REDACTED/support/flarc/src'...
>>> [0] <conduit> differential.querydiffs() <bytes = 76>
>>> [1] <http> https://phabricator.REDACTED.com/api/differential.querydiffs
<<< [1] <http> 1,335,062 us
<<< [0] <conduit> 1,336,836 us
>>> [2] <conduit> conduit.connect() <bytes = 503>
>>> [3] <http> https://phabricator.REDACTED.com/api/conduit.connect
<<< [3] <http> 347,044 us
<<< [2] <conduit> 347,236 us
>>> [4] <conduit> differential.querydiffs() <bytes = 204>
>>> [5] <http> https://phabricator.REDACTED.com/api/differential.querydiffs
<<< [5] <http> 300,017,402 us
<<< [4] <conduit> 300,017,547 us

[2016-09-25 23:17:40] EXCEPTION: (HTTPFutureCURLResponseStatus) [cURL/28] (https://phabricator.REDACTED.com/api/differential.querydiffs) <CURLE_OPERATION_TIMEDOUT> The request took too long to complete. at [<phutil>/src/future/http/HTTPSFuture.php:408]
arcanist(head=master, ref.master=8f69a5c378c3), flarc(), phutil(head=master, ref.master=ff84abc7d857)
  #0 HTTPSFuture::isReady() called at [<phutil>/src/future/Future.php:37]
  #1 Future::resolve(NULL) called at [<phutil>/src/future/FutureProxy.php:34]
  #2 FutureProxy::resolve() called at [<arcanist>/src/workflow/ArcanistWorkflow.php:1198]
  #3 ArcanistWorkflow::loadBundleFromConduit(ConduitClient, array) called at [<arcanist>/src/workflow/ArcanistWorkflow.php:1189]
  #4 ArcanistWorkflow::loadRevisionBundleFromConduit(ConduitClient, string) called at [<arcanist>/src/workflow/ArcanistPatchWorkflow.php:383]
  #5 ArcanistPatchWorkflow::run() called at [<arcanist>/src/workflow/ArcanistPatchWorkflow.php:397]
  #6 ArcanistPatchWorkflow::run() called at [<arcanist>/scripts/arcanist.php:394]

Event Timeline

> time echo '{"revisionIDs": [46496]}' | arc call-conduit  differential.querydiffs >/dev/null

real	0m21.990s
user	0m0.904s
sys	0m0.120s

Here are some query traces from XHProf:

xhprof.png (2×1 px, 580 KB)

In T11699#195930, @chad wrote:

The error log says July

What do you mean?

arcanist(head=master, ref.master=8f69a5c378c3), flarc(), phutil(head=master, ref.master=ff84abc7d857)

Sorry, apparently after running arc upgrade it no longer times out (although it does take a long time).