Page MenuHomeDevCentral

500 error when Phabricator sends a payload to the notifications center
Open, Needs TriagePublic

Description

Usually, when Phabricator posts a story to the notifications center, it gets a 500 HTTP response.
Sometimes, the payload is OK, like a task close.

Notifications Center log
[2022-04-20 15:20:44] production.INFO: [Gate] New payload. {"service":"Phabricator","door":"Nasqueron"}

That's the correct service and door information.

Logs don't report errors (they're configured to be sent to Sentry probably?).

Phabricator daemon log stacktrace

The stacktrace confirms a 500 error occurs at Notifications Center and it's triggered by the expected FeedPublisherHTTPWorker class.

[20-Apr-2022 15:20:44 UTC] [2022-04-20 15:20:44] EXCEPTION: (PhutilProxyException) Error while executing Task ID 1564849.
{>} (HTTPFutureHTTPResponseStatus) [HTTP/500] Internal Server Error at [<arcanist>/src/future/http/BaseHTTPFuture.php:384]
[20-Apr-2022 15:20:44 UTC] arcanist(head=master, ref.master=b50a646a3f49), phabricator(head=production, ref.production=110c5657e272)
[20-Apr-2022 15:20:44 UTC]   #0 <#2> BaseHTTPFuture::parseRawHTTPResponse(string) called at [<arcanist>/src/future/http/HTTPSFuture.php:545]                
[20-Apr-2022 15:20:44 UTC]   #1 <#2> HTTPSFuture::isReady() called at [<arcanist>/src/future/Future.php:63]
[20-Apr-2022 15:20:44 UTC]   #2 <#2> Future::updateFuture() called at [<arcanist>/src/future/FutureIterator.php:224]
[20-Apr-2022 15:20:44 UTC]   #3 <#2> FutureIterator::next() called at [<arcanist>/src/future/FutureIterator.php:190]
[20-Apr-2022 15:20:44 UTC]   #4 <#2> FutureIterator::rewind()
[20-Apr-2022 15:20:44 UTC]   #5 <#2> iterator_to_array(FutureIterator) called at [<arcanist>/src/future/FutureIterator.php:84]                                                                                                                [20-Apr-2022 15:20:44 UTC]   #6 <#2> FutureIterator::resolveAll() called at [<arcanist>/src/future/Future.php:47]
[20-Apr-2022 15:20:44 UTC]   #7 <#2> Future::resolve() called at [<arcanist>/src/future/http/BaseHTTPFuture.php:302]
[20-Apr-2022 15:20:44 UTC]   #8 <#2> BaseHTTPFuture::resolvex() called at [<phabricator>/src/applications/feed/worker/FeedPublisherHTTPWorker.php:37]
[20-Apr-2022 15:20:44 UTC]   #9 <#2> FeedPublisherHTTPWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:124]
[20-Apr-2022 15:20:44 UTC]   #10 <#2> PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:160]
[20-Apr-2022 15:20:44 UTC]   #11 <#2> PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:22]                                                               
[20-Apr-2022 15:20:44 UTC]   #12 PhabricatorTaskmasterDaemon::run() called at [<phabricator>/src/infrastructure/daemon/PhutilDaemon.php:219]

Example of payload correctly processed

{
  "storyID": "25897",
  "storyType": "PhabricatorApplicationTransactionFeedStory",
  "storyData": {
    "objectPHID": "PHID-DREV-sazqrae6zislmsictvw2",
    "transactionPHIDs": {
      "PHID-XACT-DREV-lormfebwbs4qghl": "PHID-XACT-DREV-lormfebwbs4qghl"
    }
  },
  "storyAuthorPHID": "PHID-USER-fnetlprx7zdotfm2hdrz",
  "storyText": "dereckson added a comment to D2675: Use correct class and filename for RouteServiceProviderTest.",
  "epoch": "1650467490"
}

Other correct payload should exists, as we got "null" debug information on Wearg when a payload doesn't have a value associated with the storyText field.

Event Timeline

dereckson added a project: User-Dereckson.
dereckson moved this task from Backlog to Bugs on the Notifications center board.
dereckson moved this task from Backlog to Next on the User-Dereckson board.
dereckson moved this task from Backlog to Config on the DevCentral board.

I'm not sure can still a reliable way create a map between project PHID and name. That should be the first thing to investigate.

For example, php artisan phabricator:projectsmap is suspiciously instantaneous.