Page MenuHomePhabricator

daemon hits policy exception repeatedly
Closed, InvalidPublic

Description

Versions:

phabricator dc9eb310b568dd2bf3e0ee559523f43c62801eec (Aug 20 2016)
arcanist 89e8b48523844cc3eff8b775f8fae49e85f8fc22 (Aug 19 2016)
phutil 9c03af69571fc72d0ecbb13b8f5e243e2ba41a51 (Aug 11 2016)

I know I am out of date, so feel free to ignore. But I roughly follow the phabricator development process and don't recall any changes in this domain that seem relevant. I will try to update soon (mostly worried about scheduling the innodb fulltext reindexing).

I'm not sure how to repro yet because I'm having trouble figuring out which things is referencing. Just thought I'd throw this up here in case the stack trace is illuminating enough while I try to repro.

Daemon 82844 INIT [Sat, 10 Dec 2016 17:59:36 -0500] Starting process.
Daemon 83184 INIT [Sat, 10 Dec 2016 17:59:36 -0500] Starting process.
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500] [2016-12-10 17:58:28] EXCEPTION: (PhutilProxyException) Error while executing Task ID 2869385. {>} (PhabricatorPolicyException) [You Shall Not Pass: Restricted Differential Diff] (Can View) You do not have permission to view this object. // Subscribers can take this action. This diff is attached to a revision, and inherits its policies. at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:597]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500] arcanist(head=master, ref.master=89e8b4852384), phabricator(head=20160114, ref.master=62e129d7a6d1, ref.20160114=dc9eb310b568), phutil(head=master, ref.master=9c03af69571f)
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #0 <#2> PhabricatorPolicyFilter::rejectObject(DifferentialDiff, string, string) called at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:514]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #1 <#2> PhabricatorPolicyFilter::checkCapability(DifferentialDiff, string) called at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:214]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #2 <#2> PhabricatorPolicyFilter::apply(array) called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:247]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #3 <#2> PhabricatorPolicyAwareQuery::execute() called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:167]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #4 <#2> PhabricatorPolicyAwareQuery::executeOne() called at [<phabricator>/src/applications/differential/customfield/DifferentialChangesSinceLastUpdateField.php:43]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #5 <#2> DifferentialChangesSinceLastUpdateField::updateTransactionMailBody(PhabricatorMetaMTAMailBody, DifferentialTransactionEditor, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2899]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #6 <#2> PhabricatorApplicationTransactionEditor::addCustomFieldsToMailBody(PhabricatorMetaMTAMailBody, DifferentialRevision, array) called at [<phabricator>/src/applications/differential/editor/DifferentialTransactionEditor.php:1238]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #7 <#2> DifferentialTransactionEditor::buildMailBody(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2511]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #8 <#2> PhabricatorApplicationTransactionEditor::buildMailForTarget(DifferentialRevision, array, PhabricatorMailTarget) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2468]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #9 <#2> PhabricatorApplicationTransactionEditor::buildMail(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:1150]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #10 <#2> PhabricatorApplicationTransactionEditor::publishTransactions(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/worker/PhabricatorApplicationTransactionPublishWorker.php:21]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #11 <#2> PhabricatorApplicationTransactionPublishWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:122]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #12 <#2> PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:171]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #13 <#2> PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:22]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #14 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:184]
Daemon 82844 STDE [Sat, 10 Dec 2016 17:58:28 -0500]   #15 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:127]
Daemon 82844 FAIL [Sat, 10 Dec 2016 17:58:28 -0500] Process exited with error 255.
Daemon 82844 WAIT [Sat, 10 Dec 2016 17:58:28 -0500] Waiting to restart process.

It seems to be a consistent failure with the daemon backing off. I'm unable to tell yet if it's a single transaction/daemon task or if there are multiple similar ones all failing.

Event Timeline

chad added a subscriber: chad.

You have to be up to date and you must provide reproduction information in order to file a bug report. Please use Ponder otherwise. Thanks!

(Feel free to follow up with reproduction steps once you've sorted everything out)

Just updated to head and am seeing the same issues.

The daemon console page shows roughly 20ish similar PhabricatorApplicationTransactionPublishWorker tasks which have accrued thousands of failed attempts each.

Do you have any advice on how to get more info? From the stack trace, it looks pretty clear that the daemon is trying send an email about some differential transaction and is getting killed by a policy check. I haven't however figured out which differential ID it's working with, so I'm having trouble reproducing because I basically am guessing what the policy check it's hitting. How would I figure out which transaction the daemon is trying to mail about?

phabricator 901e3051351dec3c041c683b6d1e718e587e2b4b (Sat, Dec 17)
arcanist fad85844314b151994769a461825c90f7400c145 (Oct 21 2016)
phutil 5ac2ca1214890d865bc57fab2715a322fdf02ab6 (Tue, Dec 6)

Example stacktrace from daemon log:

phabuser@phab-vm:~/phabricator$ ./bin/phd log --id 89701
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:40 -0500]   #3 <#2> PhabricatorPolicyAwareQuery::execute() called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:168]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:40 -0500]   #4 <#2> PhabricatorPolicyAwareQuery::executeOne() called at [<phabricator>/src/applications/differential/customfield/DifferentialChangesSinceLastUpdateField.php:43]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:40 -0500]   #5 <#2> DifferentialChangesSinceLastUpdateField::updateTransactionMailBody(PhabricatorMetaMTAMailBody, DifferentialTransactionEditor, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2930]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:40 -0500]   #6 <#2> PhabricatorApplicationTransactionEditor::addCustomFieldsToMailBody(PhabricatorMetaMTAMailBody, DifferentialRevision, array) called at [<phabricator>/src/applications/differential/editor/DifferentialTransactionEditor.php:1238]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:40 -0500]   #7 <#2> DifferentialTransactionEditor::buildMailBody(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2530]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:40 -0500]   #8 <#2> PhabricatorApplicationTransactionEditor::buildMailForTarget(DifferentialRevision, array, PhabricatorMailTarget) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2487]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:41 -0500]   #9 <#2> PhabricatorApplicationTransactionEditor::buildMail(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:1169]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:41 -0500]   #10 <#2> PhabricatorApplicationTransactionEditor::publishTransactions(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/worker/PhabricatorApplicationTransactionPublishWorker.php:21]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:41 -0500]   #11 <#2> PhabricatorApplicationTransactionPublishWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:123]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:41 -0500]   #12 <#2> PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:171]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:41 -0500]   #13 <#2> PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:22]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:41 -0500]   #14 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:181]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:41 -0500]   #15 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:127]
Daemon 89701 FAIL [Sat, 17 Dec 2016 13:01:41 -0500] Process exited with error 255.
Daemon 89701 WAIT [Sat, 17 Dec 2016 13:01:41 -0500] Waiting to restart process.
Daemon 89701 INIT [Sat, 17 Dec 2016 13:01:46 -0500] Starting process.
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500] [2016-12-17 13:01:57] EXCEPTION: (PhutilProxyException) Error while executing Task ID 2884258. {>} (PhabricatorPolicyException) [You Shall Not Pass: Restricted Differential Diff] (Can View) You do not have permission to view this object. // Subscribers can take this action. This diff is attached to a revision, and inherits its policies. at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:604]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500] arcanist(head=master, ref.master=fad85844314b), phabricator(head=20160114, ref.master=62e129d7a6d1, ref.20160114=901e3051351d), phutil(head=master, ref.master=5ac2ca121489)
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #0 <#2> PhabricatorPolicyFilter::rejectObject(DifferentialDiff, string, string) called at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:514]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #1 <#2> PhabricatorPolicyFilter::checkCapability(DifferentialDiff, string) called at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:214]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #2 <#2> PhabricatorPolicyFilter::apply(array) called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:258]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #3 <#2> PhabricatorPolicyAwareQuery::execute() called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:168]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #4 <#2> PhabricatorPolicyAwareQuery::executeOne() called at [<phabricator>/src/applications/differential/customfield/DifferentialChangesSinceLastUpdateField.php:43]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #5 <#2> DifferentialChangesSinceLastUpdateField::updateTransactionMailBody(PhabricatorMetaMTAMailBody, DifferentialTransactionEditor, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2930]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #6 <#2> PhabricatorApplicationTransactionEditor::addCustomFieldsToMailBody(PhabricatorMetaMTAMailBody, DifferentialRevision, array) called at [<phabricator>/src/applications/differential/editor/DifferentialTransactionEditor.php:1238]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #7 <#2> DifferentialTransactionEditor::buildMailBody(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2530]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #8 <#2> PhabricatorApplicationTransactionEditor::buildMailForTarget(DifferentialRevision, array, PhabricatorMailTarget) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2487]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #9 <#2> PhabricatorApplicationTransactionEditor::buildMail(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:1169]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #10 <#2> PhabricatorApplicationTransactionEditor::publishTransactions(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/worker/PhabricatorApplicationTransactionPublishWorker.php:21]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #11 <#2> PhabricatorApplicationTransactionPublishWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:123]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #12 <#2> PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:171]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #13 <#2> PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:22]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #14 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:181]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:01:57 -0500]   #15 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:127]
Daemon 89701 FAIL [Sat, 17 Dec 2016 13:01:57 -0500] Process exited with error 255.
Daemon 89701 WAIT [Sat, 17 Dec 2016 13:01:57 -0500] Waiting to restart process.
Daemon 89701 INIT [Sat, 17 Dec 2016 13:02:02 -0500] Starting process.
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500] [2016-12-17 13:02:11] EXCEPTION: (PhutilProxyException) Error while executing Task ID 2890684. {>} (PhabricatorPolicyException) [You Shall Not Pass: Restricted Differential Diff] (Can View) You do not have permission to view this object. // Subscribers can take this action. This diff is attached to a revision, and inherits its policies. at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:604]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500] arcanist(head=master, ref.master=fad85844314b), phabricator(head=20160114, ref.master=62e129d7a6d1, ref.20160114=901e3051351d), phutil(head=master, ref.master=5ac2ca121489)
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #0 <#2> PhabricatorPolicyFilter::rejectObject(DifferentialDiff, string, string) called at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:514]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #1 <#2> PhabricatorPolicyFilter::checkCapability(DifferentialDiff, string) called at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:214]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #2 <#2> PhabricatorPolicyFilter::apply(array) called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:258]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #3 <#2> PhabricatorPolicyAwareQuery::execute() called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:168]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #4 <#2> PhabricatorPolicyAwareQuery::executeOne() called at [<phabricator>/src/applications/differential/customfield/DifferentialChangesSinceLastUpdateField.php:43]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #5 <#2> DifferentialChangesSinceLastUpdateField::updateTransactionMailBody(PhabricatorMetaMTAMailBody, DifferentialTransactionEditor, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2930]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #6 <#2> PhabricatorApplicationTransactionEditor::addCustomFieldsToMailBody(PhabricatorMetaMTAMailBody, DifferentialRevision, array) called at [<phabricator>/src/applications/differential/editor/DifferentialTransactionEditor.php:1238]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #7 <#2> DifferentialTransactionEditor::buildMailBody(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2530]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #8 <#2> PhabricatorApplicationTransactionEditor::buildMailForTarget(DifferentialRevision, array, PhabricatorMailTarget) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2487]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #9 <#2> PhabricatorApplicationTransactionEditor::buildMail(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:1169]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #10 <#2> PhabricatorApplicationTransactionEditor::publishTransactions(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/worker/PhabricatorApplicationTransactionPublishWorker.php:21]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #11 <#2> PhabricatorApplicationTransactionPublishWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:123]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #12 <#2> PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:171]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #13 <#2> PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:22]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #14 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:181]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:11 -0500]   #15 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:127]
Daemon 89701 FAIL [Sat, 17 Dec 2016 13:02:11 -0500] Process exited with error 255.
Daemon 89701 WAIT [Sat, 17 Dec 2016 13:02:11 -0500] Waiting to restart process.
Daemon 89701 INIT [Sat, 17 Dec 2016 13:02:16 -0500] Starting process.
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500] [2016-12-17 13:02:21] EXCEPTION: (PhutilProxyException) Error while executing Task ID 2910182. {>} (PhabricatorPolicyException) [You Shall Not Pass: Restricted Differential Diff] (Can View) You do not have permission to view this object. // Subscribers can take this action. This diff is attached to a revision, and inherits its policies. at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:604]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500] arcanist(head=master, ref.master=fad85844314b), phabricator(head=20160114, ref.master=62e129d7a6d1, ref.20160114=901e3051351d), phutil(head=master, ref.master=5ac2ca121489)
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #0 <#2> PhabricatorPolicyFilter::rejectObject(DifferentialDiff, string, string) called at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:514]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #1 <#2> PhabricatorPolicyFilter::checkCapability(DifferentialDiff, string) called at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:214]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #2 <#2> PhabricatorPolicyFilter::apply(array) called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:258]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #3 <#2> PhabricatorPolicyAwareQuery::execute() called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:168]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #4 <#2> PhabricatorPolicyAwareQuery::executeOne() called at [<phabricator>/src/applications/differential/customfield/DifferentialChangesSinceLastUpdateField.php:43]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #5 <#2> DifferentialChangesSinceLastUpdateField::updateTransactionMailBody(PhabricatorMetaMTAMailBody, DifferentialTransactionEditor, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2930]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #6 <#2> PhabricatorApplicationTransactionEditor::addCustomFieldsToMailBody(PhabricatorMetaMTAMailBody, DifferentialRevision, array) called at [<phabricator>/src/applications/differential/editor/DifferentialTransactionEditor.php:1238]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #7 <#2> DifferentialTransactionEditor::buildMailBody(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2530]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #8 <#2> PhabricatorApplicationTransactionEditor::buildMailForTarget(DifferentialRevision, array, PhabricatorMailTarget) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2487]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #9 <#2> PhabricatorApplicationTransactionEditor::buildMail(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:1169]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #10 <#2> PhabricatorApplicationTransactionEditor::publishTransactions(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/worker/PhabricatorApplicationTransactionPublishWorker.php:21]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #11 <#2> PhabricatorApplicationTransactionPublishWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:123]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #12 <#2> PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:171]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #13 <#2> PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:22]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #14 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:181]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:21 -0500]   #15 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:127]
Daemon 89701 FAIL [Sat, 17 Dec 2016 13:02:21 -0500] Process exited with error 255.
Daemon 89701 WAIT [Sat, 17 Dec 2016 13:02:22 -0500] Waiting to restart process.
Daemon 89701 INIT [Sat, 17 Dec 2016 13:02:27 -0500] Starting process.
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500] [2016-12-17 13:02:37] EXCEPTION: (PhutilProxyException) Error while executing Task ID 2922698. {>} (PhabricatorPolicyException) [You Shall Not Pass: Restricted Differential Diff] (Can View) You do not have permission to view this object. // Subscribers can take this action. This diff is attached to a revision, and inherits its policies. at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:604]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500] arcanist(head=master, ref.master=fad85844314b), phabricator(head=20160114, ref.master=62e129d7a6d1, ref.20160114=901e3051351d), phutil(head=master, ref.master=5ac2ca121489)
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #0 <#2> PhabricatorPolicyFilter::rejectObject(DifferentialDiff, string, string) called at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:514]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #1 <#2> PhabricatorPolicyFilter::checkCapability(DifferentialDiff, string) called at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:214]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #2 <#2> PhabricatorPolicyFilter::apply(array) called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:258]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #3 <#2> PhabricatorPolicyAwareQuery::execute() called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:168]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #4 <#2> PhabricatorPolicyAwareQuery::executeOne() called at [<phabricator>/src/applications/differential/customfield/DifferentialChangesSinceLastUpdateField.php:43]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #5 <#2> DifferentialChangesSinceLastUpdateField::updateTransactionMailBody(PhabricatorMetaMTAMailBody, DifferentialTransactionEditor, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2930]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #6 <#2> PhabricatorApplicationTransactionEditor::addCustomFieldsToMailBody(PhabricatorMetaMTAMailBody, DifferentialRevision, array) called at [<phabricator>/src/applications/differential/editor/DifferentialTransactionEditor.php:1238]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #7 <#2> DifferentialTransactionEditor::buildMailBody(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2530]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #8 <#2> PhabricatorApplicationTransactionEditor::buildMailForTarget(DifferentialRevision, array, PhabricatorMailTarget) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2487]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #9 <#2> PhabricatorApplicationTransactionEditor::buildMail(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:1169]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #10 <#2> PhabricatorApplicationTransactionEditor::publishTransactions(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/worker/PhabricatorApplicationTransactionPublishWorker.php:21]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #11 <#2> PhabricatorApplicationTransactionPublishWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:123]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #12 <#2> PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:171]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #13 <#2> PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:22]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #14 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:181]
Daemon 89701 STDE [Sat, 17 Dec 2016 13:02:37 -0500]   #15 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:127]
Daemon 89701 FAIL [Sat, 17 Dec 2016 13:02:37 -0500] Process exited with error 255.
Daemon 89701 WAIT [Sat, 17 Dec 2016 13:02:37 -0500] Waiting to restart process.
Daemon 89701 INIT [Sat, 17 Dec 2016 13:02:42 -0500] Starting process.
phabuser@phab-vm:~/phabricator$
  • In Daemons, find the task ID in the leftmost column of "Leased Tasks".
  • Run bin/worker execute --id <id> --trace to execute the task in the foreground.

That will give you a more detailed error information which you can paste here.

If I had to guess, I'd say that some event took place that should send an email, but by the time the daemon got there the revision or repository has become hidden from the user that should receive the email, and that's making the daemon fail.

We used to have a tool to show a task's data, but it must have gotten lost in some refactoring.

You should be able to extract it from the DB directly:

select dataID from phabricator_worker.worker_activetask where id = <task id>;
select data from phabricator_worker.worker_taskdata where id = <that dataID>;

That should give you some json, probably with a PHID for a transaction, which you may hunt down by in the right *transaction table...

Thanks for the advice. That yields the trace below. My understanding is that it was a diff with policy set to subscribers which had an author plus a single subscriber. That subscriber was added by herald upon the diff's creation, so there's certainly grounds for something going on there. I had trouble divining the exact issue, but tinkering with the permissions for the object ended up letting the emails go through.

I really appreciate your help above, especially as far as how to track down the details. I'm not sure if I was hitting the particular theory you had (mail scheduled to previously allowed user), but that certainly seems like it would be a problem in general from my brief perusal of the worker dispatch code while looking at this. I don't know if there's necessarily a clean solution in that I don't see that phabricator really has a reasonable way to check if a policy used to be satisfied at the time of the transaction, but it seems like maybe the daemon should handle policy exceptions specially instead of bundling it as a generic error and trying again ad nauseam?

Traced execution:

>>> [2] <connect> phabricator_worker
<<< [2] <connect> 2,098 us
>>> [3] <query> SELECT * FROM `worker_activetask` WHERE (id in (2863498)) ORDER BY id DESC 
<<< [3] <query> 604 us
>>> [4] <query> SELECT * FROM `worker_archivetask` WHERE (id in (2863498)) ORDER BY id DESC 
<<< [4] <query> 266 us
>>> [5] <connect> phabricator_worker
<<< [5] <connect> 922 us
>>> [6] <query> UPDATE `worker_activetask` SET `failureTime` = '1482007016', `taskClass` = 'PhabricatorApplicationTransactionPublishWorker', `leaseOwner` = NULL, `leaseExpires` = '1482007054', `failureCount` = '6705', `dataID` = '2863496', `priority` = '1000', `objectPHID` = 'PHID-DREV-f3my2swh7uwzvubxx7nx', `id` = '2863498' WHERE `id` = '2863498'
<<< [6] <query> 3,765 us
>>> [7] <query> SELECT * FROM `worker_taskdata` WHERE id = 2863496 
<<< [7] <query> 329 us
Executing task 2863498 (PhabricatorApplicationTransactionPublishWorker)...
>>> [8] <connect> phabricator_differential
<<< [8] <connect> 1,005 us
>>> [9] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.phid IN ('PHID-DREV-f3my2swh7uwzvubxx7nx'))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [9] <query> 565 us
>>> [10] <query> SELECT * FROM `differential_transaction` x WHERE (phid IN ('PHID-XACT-DREV-j5nt7cwqh47o5qp', 'PHID-XACT-DREV-bpx673mfps5aepc')) ORDER BY `id` DESC 
<<< [10] <query> 292 us
>>> [11] <query> SELECT * FROM `differential_transaction_comment` xcomment WHERE (xcomment.phid IN ('PHID-XCMT-ifcgu7vpnvmb5bfbkll5')) ORDER BY `id` DESC 
<<< [11] <query> 279 us
>>> [12] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.phid IN ('PHID-DREV-f3my2swh7uwzvubxx7nx'))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [12] <query> 226 us
>>> [13] <connect> phabricator_user
<<< [13] <connect> 875 us
>>> [14] <query> SELECT `user`.* FROM `user` user  WHERE (user.phid IN ('PHID-USER-puelk6ygoxfpw2xbe6gt'))   ORDER BY `user`.`id` DESC 
<<< [14] <query> 302 us
>>> [15] <query> SELECT * FROM `user_profile` WHERE userPHID IN ('PHID-USER-puelk6ygoxfpw2xbe6gt') 
<<< [15] <query> 272 us
>>> [16] <query> SELECT cacheKey, userPHID, cacheData, cacheType FROM `user_cache`
        WHERE cacheIndex IN ('y_FPXujT93U3') AND userPHID IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')
<<< [16] <query> 281 us
>>> [17] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.phid IN ('PHID-DREV-f3my2swh7uwzvubxx7nx'))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [17] <query> 481 us
>>> [18] <query> SELECT * FROM `differential_diff`   WHERE (phid IN ('PHID-DIFF-olncvugyowui4kqnm6cj'))   ORDER BY `id` DESC 
<<< [18] <query> 277 us
>>> [19] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.id IN (12864))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [19] <query> 265 us
>>> [20] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.id IN (12864))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [20] <query> 270 us
>>> [21] <query> SELECT revisionID, id FROM `differential_diff` WHERE revisionID IN (12864)
        ORDER BY id DESC
<<< [21] <query> 503 us
>>> [22] <query> SELECT * FROM `differential_diff` WHERE id IN (41541) 
<<< [22] <query> 264 us
>>> [23] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-DREV-f3my2swh7uwzvubxx7nx')) AND (edge.type IN ('35')) ORDER BY edge.dateCreated ASC, edge.seq ASC
<<< [23] <query> 258 us
>>> [24] <query> SELECT `user`.* FROM `user` user  WHERE (user.phid IN ('PHID-USER-puelk6ygoxfpw2xbe6gt', 'PHID-USER-ls5ap4vwni36eapamngw'))   ORDER BY `user`.`id` DESC 
<<< [24] <query> 509 us
>>> [25] <query> SELECT cacheKey, userPHID, cacheData, cacheType FROM `user_cache`
        WHERE cacheIndex IN ('DO.iHbJI32Yo') AND userPHID IN ('PHID-USER-puelk6ygoxfpw2xbe6gt', 'PHID-USER-ls5ap4vwni36eapamngw')
<<< [25] <query> 273 us
>>> [26] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [26] <query> 281 us
>>> [27] <connect> phabricator_project
<<< [27] <connect> 1,124 us
>>> [28] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-jmqofjhjb4whx3aasvj5', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-e4c2n4ga3kvjs2dlaait', 'PHID-PROJ-eo3c4wvzqjsydv2w4dww', 'PHID-PROJ-eexhfklbw6vb7ekttddw', 'PHID-PROJ-c7eapsydcmw4mrlzf3mg', 'PHID-PROJ-j6sdcfz6oo7x6vg2fhhl', 'PHID-PROJ-f2h2n76v4wwjr77zmltx', 'PHID-PROJ-bg7erbnx4lckerlmjybo', 'PHID-PROJ-lm4qredikrtj4mccpqoe', 'PHID-PROJ-k2hwd2ifvs3ikwdhbccn', 'PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('22')) AND (edge.dst IN ('PHID-DR
<<< [28] <query> 311 us
>>> [29] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-jmqofjhjb4whx3aasvj5', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-e4c2n4ga3kvjs2dlaait', 'PHID-PROJ-eo3c4wvzqjsydv2w4dww', 'PHID-PROJ-eexhfklbw6vb7ekttddw', 'PHID-PROJ-c7eapsydcmw4mrlzf3mg', 'PHID-PROJ-j6sdcfz6oo7x6vg2fhhl', 'PHID-PROJ-f2h2n76v4wwjr77zmltx', 'PHID-PROJ-bg7erbnx4lckerlmjybo', 'PHID-PROJ-lm4qredikrtj4mccpqoe', 'PHID-PROJ-k2hwd2ifvs3ikwdhbccn', 'PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('22')) AND (edge.dst IN ('PHID-DR
<<< [29] <query> 492 us
>>> [30] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-ls5ap4vwni36eapamngw')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [30] <query> 263 us
>>> [31] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-gnlxozkc5jkj6putizuz', 'PHID-PROJ-oqkxazsyba7c5muyc7yk', 'PHID-PROJ-hmojkonojnoczjfzyhy6', 'PHID-PROJ-h3qenymhs32rpv7v5hav', 'PHID-PROJ-ghlzjbxtpt7fkh4me7mb', 'PHID-PROJ-vnehv4h3ezgdyncmcjbw', 'PHID-PROJ-wpcpx5wvx42aclstlyel', 'PHID-PROJ-voxu4mkibzpmbck4dolx', 'PHID-PROJ-ahz3u5umjbxkliprdjkh', 'PHID-PROJ-gwd2tjf6vbloqgauug5h', 'PHID-PROJ-edq6la4pbk6pnkzt7b5r', 'PHID-PROJ-gmkbg73xwdtx6aoclxxr', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-6yzkqejs
<<< [31] <query> 272 us
>>> [32] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-gnlxozkc5jkj6putizuz', 'PHID-PROJ-oqkxazsyba7c5muyc7yk', 'PHID-PROJ-hmojkonojnoczjfzyhy6', 'PHID-PROJ-h3qenymhs32rpv7v5hav', 'PHID-PROJ-ghlzjbxtpt7fkh4me7mb', 'PHID-PROJ-vnehv4h3ezgdyncmcjbw', 'PHID-PROJ-wpcpx5wvx42aclstlyel', 'PHID-PROJ-voxu4mkibzpmbck4dolx', 'PHID-PROJ-ahz3u5umjbxkliprdjkh', 'PHID-PROJ-gwd2tjf6vbloqgauug5h', 'PHID-PROJ-edq6la4pbk6pnkzt7b5r', 'PHID-PROJ-gmkbg73xwdtx6aoclxxr', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-6yzkqejs
<<< [32] <query> 268 us
>>> [33] <query> SELECT `user`.* FROM `user` user  WHERE (user.phid IN ('PHID-USER-puelk6ygoxfpw2xbe6gt'))   ORDER BY `user`.`id` DESC 
<<< [33] <query> 282 us
>>> [34] <query> SELECT * FROM `user_profile` WHERE userPHID IN ('PHID-USER-puelk6ygoxfpw2xbe6gt') 
<<< [34] <query> 268 us
>>> [35] <query> SELECT cacheKey, userPHID, cacheData, cacheType FROM `user_cache`
        WHERE cacheIndex IN ('y_FPXujT93U3') AND userPHID IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')
<<< [35] <query> 270 us
>>> [36] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.phid IN ('PHID-DREV-f3my2swh7uwzvubxx7nx'))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [36] <query> 540 us
>>> [37] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [37] <query> 499 us
>>> [38] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-jmqofjhjb4whx3aasvj5', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-e4c2n4ga3kvjs2dlaait', 'PHID-PROJ-eo3c4wvzqjsydv2w4dww', 'PHID-PROJ-eexhfklbw6vb7ekttddw', 'PHID-PROJ-c7eapsydcmw4mrlzf3mg', 'PHID-PROJ-j6sdcfz6oo7x6vg2fhhl', 'PHID-PROJ-f2h2n76v4wwjr77zmltx', 'PHID-PROJ-bg7erbnx4lckerlmjybo', 'PHID-PROJ-lm4qredikrtj4mccpqoe', 'PHID-PROJ-k2hwd2ifvs3ikwdhbccn', 'PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('22')) AND (edge.dst IN ('PHID-DR
<<< [38] <query> 263 us
>>> [39] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-jmqofjhjb4whx3aasvj5', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-e4c2n4ga3kvjs2dlaait', 'PHID-PROJ-eo3c4wvzqjsydv2w4dww', 'PHID-PROJ-eexhfklbw6vb7ekttddw', 'PHID-PROJ-c7eapsydcmw4mrlzf3mg', 'PHID-PROJ-j6sdcfz6oo7x6vg2fhhl', 'PHID-PROJ-f2h2n76v4wwjr77zmltx', 'PHID-PROJ-bg7erbnx4lckerlmjybo', 'PHID-PROJ-lm4qredikrtj4mccpqoe', 'PHID-PROJ-k2hwd2ifvs3ikwdhbccn', 'PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('22')) AND (edge.dst IN ('PHID-DR
<<< [39] <query> 283 us
>>> [40] <query> SELECT * FROM `differential_diff`   WHERE (phid IN ('PHID-DIFF-olncvugyowui4kqnm6cj'))   ORDER BY `id` DESC 
<<< [40] <query> 494 us
>>> [41] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.id IN (12864))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [41] <query> 269 us
>>> [42] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [42] <query> 508 us
>>> [43] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-jmqofjhjb4whx3aasvj5', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-e4c2n4ga3kvjs2dlaait', 'PHID-PROJ-eo3c4wvzqjsydv2w4dww', 'PHID-PROJ-eexhfklbw6vb7ekttddw', 'PHID-PROJ-c7eapsydcmw4mrlzf3mg', 'PHID-PROJ-j6sdcfz6oo7x6vg2fhhl', 'PHID-PROJ-f2h2n76v4wwjr77zmltx', 'PHID-PROJ-bg7erbnx4lckerlmjybo', 'PHID-PROJ-lm4qredikrtj4mccpqoe', 'PHID-PROJ-k2hwd2ifvs3ikwdhbccn', 'PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('22')) AND (edge.dst IN ('PHID-DR
<<< [43] <query> 263 us
>>> [44] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-jmqofjhjb4whx3aasvj5', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-e4c2n4ga3kvjs2dlaait', 'PHID-PROJ-eo3c4wvzqjsydv2w4dww', 'PHID-PROJ-eexhfklbw6vb7ekttddw', 'PHID-PROJ-c7eapsydcmw4mrlzf3mg', 'PHID-PROJ-j6sdcfz6oo7x6vg2fhhl', 'PHID-PROJ-f2h2n76v4wwjr77zmltx', 'PHID-PROJ-bg7erbnx4lckerlmjybo', 'PHID-PROJ-lm4qredikrtj4mccpqoe', 'PHID-PROJ-k2hwd2ifvs3ikwdhbccn', 'PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('22')) AND (edge.dst IN ('PHID-DR
<<< [44] <query> 262 us
>>> [45] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [45] <query> 264 us
>>> [46] <connect> phabricator_auth
<<< [46] <connect> 1,258 us
>>> [47] <query> SELECT * FROM `auth_providerconfig`  ORDER BY `id` DESC 
<<< [47] <query> 305 us
>>> [48] <query> SELECT * FROM `differential_diff`   WHERE (phid IN ('PHID-DIFF-k46ahyymcmiupgvvdl74'))   ORDER BY `id` DESC 
<<< [48] <query> 322 us
>>> [49] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.id IN (12864))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [49] <query> 277 us
>>> [50] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [50] <query> 324 us
>>> [51] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-jmqofjhjb4whx3aasvj5', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-e4c2n4ga3kvjs2dlaait', 'PHID-PROJ-eo3c4wvzqjsydv2w4dww', 'PHID-PROJ-eexhfklbw6vb7ekttddw', 'PHID-PROJ-c7eapsydcmw4mrlzf3mg', 'PHID-PROJ-j6sdcfz6oo7x6vg2fhhl', 'PHID-PROJ-f2h2n76v4wwjr77zmltx', 'PHID-PROJ-bg7erbnx4lckerlmjybo', 'PHID-PROJ-lm4qredikrtj4mccpqoe', 'PHID-PROJ-k2hwd2ifvs3ikwdhbccn', 'PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('22')) AND (edge.dst IN ('PHID-DR
<<< [51] <query> 279 us
>>> [52] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-jmqofjhjb4whx3aasvj5', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-e4c2n4ga3kvjs2dlaait', 'PHID-PROJ-eo3c4wvzqjsydv2w4dww', 'PHID-PROJ-eexhfklbw6vb7ekttddw', 'PHID-PROJ-c7eapsydcmw4mrlzf3mg', 'PHID-PROJ-j6sdcfz6oo7x6vg2fhhl', 'PHID-PROJ-f2h2n76v4wwjr77zmltx', 'PHID-PROJ-bg7erbnx4lckerlmjybo', 'PHID-PROJ-lm4qredikrtj4mccpqoe', 'PHID-PROJ-k2hwd2ifvs3ikwdhbccn', 'PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('22')) AND (edge.dst IN ('PHID-DR
<<< [52] <query> 268 us
>>> [53] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [53] <query> 268 us
>>> [54] <query> SELECT * FROM `differential_diffproperty` WHERE diffID = 41541 AND name = 'arc:onto' 
<<< [54] <query> 504 us
>>> [55] <query> SELECT * FROM `differential_diff`   WHERE (phid IN ('PHID-DIFF-olncvugyowui4kqnm6cj'))   ORDER BY `id` DESC 
<<< [55] <query> 340 us
>>> [56] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.id IN (12864))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [56] <query> 326 us
>>> [57] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [57] <query> 494 us
>>> [58] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-jmqofjhjb4whx3aasvj5', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-e4c2n4ga3kvjs2dlaait', 'PHID-PROJ-eo3c4wvzqjsydv2w4dww', 'PHID-PROJ-eexhfklbw6vb7ekttddw', 'PHID-PROJ-c7eapsydcmw4mrlzf3mg', 'PHID-PROJ-j6sdcfz6oo7x6vg2fhhl', 'PHID-PROJ-f2h2n76v4wwjr77zmltx', 'PHID-PROJ-bg7erbnx4lckerlmjybo', 'PHID-PROJ-lm4qredikrtj4mccpqoe', 'PHID-PROJ-k2hwd2ifvs3ikwdhbccn', 'PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('22')) AND (edge.dst IN ('PHID-DR
<<< [58] <query> 275 us
>>> [59] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-jmqofjhjb4whx3aasvj5', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-e4c2n4ga3kvjs2dlaait', 'PHID-PROJ-eo3c4wvzqjsydv2w4dww', 'PHID-PROJ-eexhfklbw6vb7ekttddw', 'PHID-PROJ-c7eapsydcmw4mrlzf3mg', 'PHID-PROJ-j6sdcfz6oo7x6vg2fhhl', 'PHID-PROJ-f2h2n76v4wwjr77zmltx', 'PHID-PROJ-bg7erbnx4lckerlmjybo', 'PHID-PROJ-lm4qredikrtj4mccpqoe', 'PHID-PROJ-k2hwd2ifvs3ikwdhbccn', 'PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('22')) AND (edge.dst IN ('PHID-DR
<<< [59] <query> 282 us
>>> [60] <query> SELECT * FROM `differential_changeset` WHERE (diffID IN (40228)) ORDER BY `id` DESC 
<<< [60] <query> 504 us
>>> [61] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [61] <query> 542 us
>>> [62] <query> SELECT * FROM `differential_hunk_modern` WHERE (changesetID IN (307950, 307949, 307948, 307947, 307946, 307945, 307944, 307943)) ORDER BY `id` ASC 
<<< [62] <query> 524 us
>>> [63] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [63] <query> 322 us
>>> [64] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [64] <query> 270 us
>>> [65] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-DREV-f3my2swh7uwzvubxx7nx')) AND (edge.type IN ('41')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [65] <query> 493 us
>>> [66] <query> SELECT `user`.* FROM `user` user  WHERE (user.phid IN ('PHID-USER-puelk6ygoxfpw2xbe6gt', 'PHID-USER-ls5ap4vwni36eapamngw'))   ORDER BY `user`.`id` DESC 
<<< [66] <query> 495 us
>>> [67] <query> SELECT * FROM `user_profile` WHERE userPHID IN ('PHID-USER-puelk6ygoxfpw2xbe6gt', 'PHID-USER-ls5ap4vwni36eapamngw') 
<<< [67] <query> 307 us
>>> [68] <query> SELECT cacheKey, userPHID, cacheData, cacheType FROM `user_cache`
        WHERE cacheIndex IN ('y_FPXujT93U3') AND userPHID IN ('PHID-USER-puelk6ygoxfpw2xbe6gt', 'PHID-USER-ls5ap4vwni36eapamngw')
<<< [68] <query> 264 us
>>> [69] <query> SELECT `user`.* FROM `user` user  WHERE (user.phid IN ('PHID-USER-puelk6ygoxfpw2xbe6gt'))   ORDER BY `user`.`id` DESC 
<<< [69] <query> 276 us
>>> [70] <query> SELECT * FROM `user_profile` WHERE userPHID IN ('PHID-USER-puelk6ygoxfpw2xbe6gt') 
<<< [70] <query> 263 us
>>> [71] <query> SELECT cacheKey, userPHID, cacheData, cacheType FROM `user_cache`
        WHERE cacheIndex IN ('y_FPXujT93U3') AND userPHID IN ('PHID-USER-puelk6ygoxfpw2xbe6gt')
<<< [71] <query> 267 us
>>> [72] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.phid IN ('PHID-DREV-f3my2swh7uwzvubxx7nx'))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [72] <query> 506 us
>>> [73] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-ls5ap4vwni36eapamngw')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [73] <query> 389 us
>>> [74] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-gnlxozkc5jkj6putizuz', 'PHID-PROJ-oqkxazsyba7c5muyc7yk', 'PHID-PROJ-hmojkonojnoczjfzyhy6', 'PHID-PROJ-h3qenymhs32rpv7v5hav', 'PHID-PROJ-ghlzjbxtpt7fkh4me7mb', 'PHID-PROJ-vnehv4h3ezgdyncmcjbw', 'PHID-PROJ-wpcpx5wvx42aclstlyel', 'PHID-PROJ-voxu4mkibzpmbck4dolx', 'PHID-PROJ-ahz3u5umjbxkliprdjkh', 'PHID-PROJ-gwd2tjf6vbloqgauug5h', 'PHID-PROJ-edq6la4pbk6pnkzt7b5r', 'PHID-PROJ-gmkbg73xwdtx6aoclxxr', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-6yzkqejs
<<< [74] <query> 292 us
>>> [75] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-gnlxozkc5jkj6putizuz', 'PHID-PROJ-oqkxazsyba7c5muyc7yk', 'PHID-PROJ-hmojkonojnoczjfzyhy6', 'PHID-PROJ-h3qenymhs32rpv7v5hav', 'PHID-PROJ-ghlzjbxtpt7fkh4me7mb', 'PHID-PROJ-vnehv4h3ezgdyncmcjbw', 'PHID-PROJ-wpcpx5wvx42aclstlyel', 'PHID-PROJ-voxu4mkibzpmbck4dolx', 'PHID-PROJ-ahz3u5umjbxkliprdjkh', 'PHID-PROJ-gwd2tjf6vbloqgauug5h', 'PHID-PROJ-edq6la4pbk6pnkzt7b5r', 'PHID-PROJ-gmkbg73xwdtx6aoclxxr', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-6yzkqejs
<<< [75] <query> 279 us
>>> [76] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.phid IN ('PHID-DREV-f3my2swh7uwzvubxx7nx'))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [76] <query> 347 us
>>> [77] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-DREV-f3my2swh7uwzvubxx7nx')) AND (edge.type IN ('35')) ORDER BY edge.dateCreated ASC, edge.seq ASC
<<< [77] <query> 267 us
>>> [78] <query> SELECT * FROM `differential_diff`   WHERE (phid IN ('PHID-DIFF-olncvugyowui4kqnm6cj'))   ORDER BY `id` DESC 
<<< [78] <query> 272 us
>>> [79] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.id IN (12864))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [79] <query> 273 us
>>> [80] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-ls5ap4vwni36eapamngw')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [80] <query> 348 us
>>> [81] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-gnlxozkc5jkj6putizuz', 'PHID-PROJ-oqkxazsyba7c5muyc7yk', 'PHID-PROJ-hmojkonojnoczjfzyhy6', 'PHID-PROJ-h3qenymhs32rpv7v5hav', 'PHID-PROJ-ghlzjbxtpt7fkh4me7mb', 'PHID-PROJ-vnehv4h3ezgdyncmcjbw', 'PHID-PROJ-wpcpx5wvx42aclstlyel', 'PHID-PROJ-voxu4mkibzpmbck4dolx', 'PHID-PROJ-ahz3u5umjbxkliprdjkh', 'PHID-PROJ-gwd2tjf6vbloqgauug5h', 'PHID-PROJ-edq6la4pbk6pnkzt7b5r', 'PHID-PROJ-gmkbg73xwdtx6aoclxxr', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-6yzkqejs
<<< [81] <query> 275 us
>>> [82] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-gnlxozkc5jkj6putizuz', 'PHID-PROJ-oqkxazsyba7c5muyc7yk', 'PHID-PROJ-hmojkonojnoczjfzyhy6', 'PHID-PROJ-h3qenymhs32rpv7v5hav', 'PHID-PROJ-ghlzjbxtpt7fkh4me7mb', 'PHID-PROJ-vnehv4h3ezgdyncmcjbw', 'PHID-PROJ-wpcpx5wvx42aclstlyel', 'PHID-PROJ-voxu4mkibzpmbck4dolx', 'PHID-PROJ-ahz3u5umjbxkliprdjkh', 'PHID-PROJ-gwd2tjf6vbloqgauug5h', 'PHID-PROJ-edq6la4pbk6pnkzt7b5r', 'PHID-PROJ-gmkbg73xwdtx6aoclxxr', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-6yzkqejs
<<< [82] <query> 273 us
>>> [83] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.phid IN ('PHID-DREV-f3my2swh7uwzvubxx7nx'))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [83] <query> 347 us
>>> [84] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-DREV-f3my2swh7uwzvubxx7nx')) AND (edge.type IN ('35')) ORDER BY edge.dateCreated ASC, edge.seq ASC
<<< [84] <query> 280 us
>>> [85] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-ls5ap4vwni36eapamngw')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [85] <query> 366 us
>>> [86] <query> SELECT * FROM `differential_diff`   WHERE (phid IN ('PHID-DIFF-k46ahyymcmiupgvvdl74'))   ORDER BY `id` DESC 
<<< [86] <query> 347 us
>>> [87] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.id IN (12864))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [87] <query> 284 us
>>> [88] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-ls5ap4vwni36eapamngw')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [88] <query> 352 us
>>> [89] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-gnlxozkc5jkj6putizuz', 'PHID-PROJ-oqkxazsyba7c5muyc7yk', 'PHID-PROJ-hmojkonojnoczjfzyhy6', 'PHID-PROJ-h3qenymhs32rpv7v5hav', 'PHID-PROJ-ghlzjbxtpt7fkh4me7mb', 'PHID-PROJ-vnehv4h3ezgdyncmcjbw', 'PHID-PROJ-wpcpx5wvx42aclstlyel', 'PHID-PROJ-voxu4mkibzpmbck4dolx', 'PHID-PROJ-ahz3u5umjbxkliprdjkh', 'PHID-PROJ-gwd2tjf6vbloqgauug5h', 'PHID-PROJ-edq6la4pbk6pnkzt7b5r', 'PHID-PROJ-gmkbg73xwdtx6aoclxxr', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-6yzkqejs
<<< [89] <query> 276 us
>>> [90] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-gnlxozkc5jkj6putizuz', 'PHID-PROJ-oqkxazsyba7c5muyc7yk', 'PHID-PROJ-hmojkonojnoczjfzyhy6', 'PHID-PROJ-h3qenymhs32rpv7v5hav', 'PHID-PROJ-ghlzjbxtpt7fkh4me7mb', 'PHID-PROJ-vnehv4h3ezgdyncmcjbw', 'PHID-PROJ-wpcpx5wvx42aclstlyel', 'PHID-PROJ-voxu4mkibzpmbck4dolx', 'PHID-PROJ-ahz3u5umjbxkliprdjkh', 'PHID-PROJ-gwd2tjf6vbloqgauug5h', 'PHID-PROJ-edq6la4pbk6pnkzt7b5r', 'PHID-PROJ-gmkbg73xwdtx6aoclxxr', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-6yzkqejs
<<< [90] <query> 276 us
>>> [91] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.phid IN ('PHID-DREV-f3my2swh7uwzvubxx7nx'))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [91] <query> 344 us
>>> [92] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-DREV-f3my2swh7uwzvubxx7nx')) AND (edge.type IN ('35')) ORDER BY edge.dateCreated ASC, edge.seq ASC
<<< [92] <query> 268 us
>>> [93] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-ls5ap4vwni36eapamngw')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [93] <query> 349 us
>>> [94] <query> SELECT * FROM `differential_diff`   WHERE (phid IN ('PHID-DIFF-k46ahyymcmiupgvvdl74'))   ORDER BY `id` DESC 
<<< [94] <query> 350 us
>>> [95] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.id IN (12864))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [95] <query> 286 us
>>> [96] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-ls5ap4vwni36eapamngw')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [96] <query> 354 us
>>> [97] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-gnlxozkc5jkj6putizuz', 'PHID-PROJ-oqkxazsyba7c5muyc7yk', 'PHID-PROJ-hmojkonojnoczjfzyhy6', 'PHID-PROJ-h3qenymhs32rpv7v5hav', 'PHID-PROJ-ghlzjbxtpt7fkh4me7mb', 'PHID-PROJ-vnehv4h3ezgdyncmcjbw', 'PHID-PROJ-wpcpx5wvx42aclstlyel', 'PHID-PROJ-voxu4mkibzpmbck4dolx', 'PHID-PROJ-ahz3u5umjbxkliprdjkh', 'PHID-PROJ-gwd2tjf6vbloqgauug5h', 'PHID-PROJ-edq6la4pbk6pnkzt7b5r', 'PHID-PROJ-gmkbg73xwdtx6aoclxxr', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-6yzkqejs
<<< [97] <query> 311 us
>>> [98] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-PROJ-gnlxozkc5jkj6putizuz', 'PHID-PROJ-oqkxazsyba7c5muyc7yk', 'PHID-PROJ-hmojkonojnoczjfzyhy6', 'PHID-PROJ-h3qenymhs32rpv7v5hav', 'PHID-PROJ-ghlzjbxtpt7fkh4me7mb', 'PHID-PROJ-vnehv4h3ezgdyncmcjbw', 'PHID-PROJ-wpcpx5wvx42aclstlyel', 'PHID-PROJ-voxu4mkibzpmbck4dolx', 'PHID-PROJ-ahz3u5umjbxkliprdjkh', 'PHID-PROJ-gwd2tjf6vbloqgauug5h', 'PHID-PROJ-edq6la4pbk6pnkzt7b5r', 'PHID-PROJ-gmkbg73xwdtx6aoclxxr', 'PHID-PROJ-lxas2qb4md4j6xtueekf', 'PHID-PROJ-6yzkqejs
<<< [98] <query> 270 us
>>> [99] <query> (SELECT `r`.* FROM `differential_revision` r  WHERE (r.phid IN ('PHID-DREV-f3my2swh7uwzvubxx7nx'))   ORDER BY `r`.`dateModified` DESC, `r`.`id` DESC )
<<< [99] <query> 345 us
>>> [100] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-DREV-f3my2swh7uwzvubxx7nx')) AND (edge.type IN ('35')) ORDER BY edge.dateCreated ASC, edge.seq ASC
<<< [100] <query> 281 us
>>> [101] <query> SELECT edge.* FROM `edge` edge WHERE (edge.src IN ('PHID-USER-ls5ap4vwni36eapamngw')) AND (edge.type IN ('14')) ORDER BY edge.dateCreated DESC, edge.seq DESC
<<< [101] <query> 359 us
>>> [102] <query> UPDATE `worker_activetask` SET `failureTime` = '1482007055', `taskClass` = 'PhabricatorApplicationTransactionPublishWorker', `leaseOwner` = NULL, `leaseExpires` = '1482007354', `failureCount` = '6706', `dataID` = '2863496', `priority` = '1000', `objectPHID` = 'PHID-DREV-f3my2swh7uwzvubxx7nx', `id` = '2863498' WHERE `id` = '2863498'
<<< [102] <query> 3,288 us
[2016-12-17 15:37:35] EXCEPTION: (PhabricatorPolicyException) [You Shall Not Pass: Restricted Differential Diff] (Can View) You do not have permission to view this object. // Subscribers can take this action. This diff is attached to a revision, and inherits its policies. at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:604]
arcanist(head=master, ref.master=fad85844314b), phabricator(head=20160114, ref.master=62e129d7a6d1, ref.20160114=901e3051351d), phutil(head=master, ref.master=5ac2ca121489)
  #0 PhabricatorPolicyFilter::rejectObject(DifferentialDiff, string, string) called at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:514]
  #1 PhabricatorPolicyFilter::checkCapability(DifferentialDiff, string) called at [<phabricator>/src/applications/policy/filter/PhabricatorPolicyFilter.php:214]
  #2 PhabricatorPolicyFilter::apply(array) called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:258]
  #3 PhabricatorPolicyAwareQuery::execute() called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:168]
  #4 PhabricatorPolicyAwareQuery::executeOne() called at [<phabricator>/src/applications/differential/customfield/DifferentialChangesSinceLastUpdateField.php:43]
  #5 DifferentialChangesSinceLastUpdateField::updateTransactionMailBody(PhabricatorMetaMTAMailBody, DifferentialTransactionEditor, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2930]
  #6 PhabricatorApplicationTransactionEditor::addCustomFieldsToMailBody(PhabricatorMetaMTAMailBody, DifferentialRevision, array) called at [<phabricator>/src/applications/differential/editor/DifferentialTransactionEditor.php:1238]
  #7 DifferentialTransactionEditor::buildMailBody(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2530]
  #8 PhabricatorApplicationTransactionEditor::buildMailForTarget(DifferentialRevision, array, PhabricatorMailTarget) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:2487]
  #9 PhabricatorApplicationTransactionEditor::buildMail(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/editor/PhabricatorApplicationTransactionEditor.php:1169]
  #10 PhabricatorApplicationTransactionEditor::publishTransactions(DifferentialRevision, array) called at [<phabricator>/src/applications/transactions/worker/PhabricatorApplicationTransactionPublishWorker.php:21]
  #11 PhabricatorApplicationTransactionPublishWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:123]
  #12 PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:171]
  #13 PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/management/PhabricatorWorkerManagementExecuteWorkflow.php:52]
  #14 PhabricatorWorkerManagementExecuteWorkflow::execute(PhutilArgumentParser) called at [<phutil>/src/parser/argument/PhutilArgumentParser.php:438]
  #15 PhutilArgumentParser::parseWorkflowsFull(array) called at [<phutil>/src/parser/argument/PhutilArgumentParser.php:330]
  #16 PhutilArgumentParser::parseWorkflows(array) called at [<phabricator>/scripts/setup/manage_worker.php:21]

And taskdata:

| {"objectPHID":"PHID-DREV-f3my2swh7uwzvubxx7nx","actorPHID":"PHID-USER-puelk6ygoxfpw2xbe6gt","xactionPHIDs":["PHID-XACT-DREV-j5nt7cwqh47o5qp","PHID-XACT-DREV-bpx673mfps5aepc"],"state":{"parentMessageID":null,"disableEmail":null,"isNewObject":false,"heraldEmailPHIDs":[],"heraldForcedEmailPHIDs":[],"heraldHeader":"<12>, <14>, <31>, <34>, <36>, <30>","mailToPHIDs":["PHID-USER-puelk6ygoxfpw2xbe6gt"],"mailCCPHIDs":["PHID-USER-ls5ap4vwni36eapamngw"],"feedNotifyPHIDs":["PHID-USER-puelk6ygoxfpw2xbe6gt","PHID-USER-ls5ap4vwni36eapamngw"],"feedRelatedPHIDs":["PHID-DREV-f3my2swh7uwzvubxx7nx","PHID-USER-puelk6ygoxfpw2xbe6gt"],"excludeMailRecipientPHIDs":[],"custom":{"changedPriorToCommitURI":null},"custom.encoding":[]}} |

It certainly looks like a bug to me, but I don't think I have the knowledge to walk these tables and pull out a clean repro for the upstream. So let me know if you want more data or if just wanna drop it.

I've been playing with it for maybe half an hour, and couldn't reproduce:

  • Made revision public
  • stopped the daemons
  • mention a user
  • updated the revision to a new diff
  • made the revision not-visible to that user (visible only to the acting user)
  • start daemons and let them finish the queue

No failing tasks and no emails about things the user can't see.

I suspect that maybe a more surgical approach, like pausing some specific kind of workers, might lead to the error case, but I don't really want to dig into that right now.

Incidentally, I've noticed that Diff objects have a View Policy, which we ignore when the diff is attached to a Revision, and can't edit.

I did some further digging and made a little progress

Further digging:

  • This is diff with view policy set to "Subscribers"
  • As per the stack-trace, we fail the checkCapability() call at src/applications/policy/filter/PhabricatorPolicyFilter.php:514
  • The checkObjectPolicy() in this case is invoked with a $rule that has class `PhabricatorSubscriptionsSubscribersPolicyRule
  • We then call into that rule's canApplyToObject() at src/applications/policy/filter/PhabricatorPolicyFilter.php:711
  • the canApplyToObject() function of this rule ends up being invoked with with a $object of type DifferentialDiff which fails the instanceof PhabricatorSubscribeInterface check at src/applications/subscriptions/policyrule/PhabricatorSubscriptionsSubscribersPolicyRule.php:24

So it seems like the rough issue is that we're subscribed to something which isn't really subscribable, but the its view policy is based on subscriptions and the two can't be reconciled?

What version of Phabricator are you currently running?

Head as of my Dec. 17 post in this thread. Can roll forward, but was hoping to wait till the edit engine migration settled a bit.

(And again, to emphasize, I'm happy to drop this if y'all aren't interested. I have my solution and am happy ignoring this, but just thought it might be something you guys would want to check out.)

If you upgrade past 65c1c758ed261f65c8164d200ce01373ae5b822c (both stable and master have this change), does it reproduce?

You can also safely cherry-pick that to test if it resolves things, it doesn't interact with anything else.