"POST /api/harbormaster.createartifact HTTP/1.1" 500


#1

Observed Behavior:
172.21.0.2 - - [03/Jun/2018:02:34:02 +0000] "POST /api/harbormaster.createartifact HTTP/1.1" 500 742

Expected Behavior:
Not an internal server error.

Phabricator Version:
9d0adf6563db34efa5cdc3971bfca4f15693c657 (Sat, May 19) (branched from de999af61422e4f48bd62bdf0eac46dfa72775c3 on origin)

Reproduction Steps:
This will be long so I don’t expect you to recreate it at this point. I have a docker-compose of the Bitnami Phabricator and Jenkins images and am trying to integrate using the Uber Phabricator plugin for Jenkins.
This occurs when it is trying to call back after a build fails. I assume this qualifies as a bug since it’s an internal server error though.

So, since I’m not giving you something to recreate… I’ll instead ask how I can collect more info about the request to help diagnose what the issue is.

I will admit that this is just a quick and dirty setup so I can test the integration. There’s some sort of permissions issue in the Bitnami Phabricator container so I do get this sort of thing every 5 seconds or so.

[03-Jun-2018 02:35:09 UTC]   #13 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:131],
[03-Jun-2018 02:35:09 UTC] [2018-06-03 02:35:09] EXCEPTION: (CommandException) Command failed with error #1!,
COMMAND,
mkdir -p '/opt/bitnami/phabricator/data/69/36',
,
STDOUT,
(empty),
mkdir: cannot create directory '/opt/bitnami/phabricator/data/69': Permission denied,
STDERR,
 at [<phutil>/src/future/exec/ExecFuture.php:369],
[03-Jun-2018 02:35:09 UTC]   #0 <#2> ExecFuture::resolvex() called at [<phutil>/src/future/exec/execx.php:17],
[03-Jun-2018 02:35:09 UTC]   #1 <#2> execx(string, string) called at [<phabricator>/src/applications/files/engine/PhabricatorLocalDiskFileStorageEngine.php:58],
[03-Jun-2018 02:35:09 UTC]   #2 <#2> PhabricatorLocalDiskFileStorageEngine::writeFile(string, array) called at [<phabricator>/src/applications/files/storage/PhabricatorFile.php:539],
[03-Jun-2018 02:35:09 UTC]   #3 <#2> PhabricatorFile::writeToEngine(PhabricatorLocalDiskFileStorageEngine, string, array) called at [<phabricator>/src/applications/files/storage/PhabricatorFile.php:370],
[03-Jun-2018 02:35:09 UTC]   #4 phlog(CommandException) called at [<phabricator>/src/applications/files/storage/PhabricatorFile.php:382],
[03-Jun-2018 02:35:09 UTC]   #5 PhabricatorFile::buildFromFileData(string, array) called at [<phabricator>/src/applications/files/storage/PhabricatorFile.php:436],
[03-Jun-2018 02:35:09 UTC]   #6 PhabricatorFile::newFromFileData(string, array) called at [<phabricator>/src/applications/files/uploadsource/PhabricatorFileUploadSource.php:170],
[03-Jun-2018 02:35:09 UTC]   #7 PhabricatorFileUploadSource::writeSingleFile() called at [<phabricator>/src/applications/files/uploadsource/PhabricatorFileUploadSource.php:76],
[03-Jun-2018 02:35:09 UTC]   #8 PhabricatorFileUploadSource::uploadFile() called at [<phabricator>/src/applications/harbormaster/worker/HarbormasterLogWorker.php:94],
[03-Jun-2018 02:35:09 UTC]   #9 HarbormasterLogWorker::finalizeBuildLog(HarbormasterBuildLog) called at [<phabricator>/src/applications/harbormaster/worker/HarbormasterLogWorker.php:42],
[03-Jun-2018 02:35:09 UTC]   #10 HarbormasterLogWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:123],
[03-Jun-2018 02:35:09 UTC]   #11 PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:171],
[03-Jun-2018 02:35:09 UTC]   #12 PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:22],
[03-Jun-2018 02:35:09 UTC]   #13 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:219],
[03-Jun-2018 02:35:09 UTC]   #14 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:131],
[03-Jun-2018 02:35:09 UTC] [2018-06-03 02:35:09] EXCEPTION: (PhutilProxyException) Error while executing Task ID 21572. {>} (PhutilAggregateException) All storage engines failed to write file:,
    - PhabricatorLocalDiskFileStorageEngine: CommandException: Command failed with error #1!,
      COMMAND,
      ,
      mkdir -p '/opt/bitnami/phabricator/data/69/36',
      STDOUT,
      (empty),
      STDERR,
      mkdir: cannot create directory '/opt/bitnami/phabricator/data/69': Permission denied,
       at [<phabricator>/src/applications/files/storage/PhabricatorFile.php:391],
[03-Jun-2018 02:35:09 UTC] arcanist(head=stable, ref.stable=733ac8050162), phabricator(head=stable, ref.stable=9d0adf6563db), phutil(head=stable, ref.stable=f3e10579f640),
[03-Jun-2018 02:35:09 UTC]   #0 <#3> ExecFuture::resolvex() called at [<phutil>/src/future/exec/execx.php:17],
[03-Jun-2018 02:35:09 UTC]   #1 <#3> execx(string, string) called at [<phabricator>/src/applications/files/engine/PhabricatorLocalDiskFileStorageEngine.php:58],
[03-Jun-2018 02:35:09 UTC]   #2 <#3> PhabricatorLocalDiskFileStorageEngine::writeFile(string, array) called at [<phabricator>/src/applications/files/storage/PhabricatorFile.php:539],
[03-Jun-2018 02:35:09 UTC]   #3 <#3> PhabricatorFile::writeToEngine(PhabricatorLocalDiskFileStorageEngine, string, array) called at [<phabricator>/src/applications/files/storage/PhabricatorFile.php:370],
[03-Jun-2018 02:35:09 UTC]   #4 <#2> PhabricatorFile::buildFromFileData(string, array) called at [<phabricator>/src/applications/files/storage/PhabricatorFile.php:436],
[03-Jun-2018 02:35:09 UTC]   #5 <#2> PhabricatorFile::newFromFileData(string, array) called at [<phabricator>/src/applications/files/uploadsource/PhabricatorFileUploadSource.php:170],
[03-Jun-2018 02:35:09 UTC]   #6 <#2> PhabricatorFileUploadSource::writeSingleFile() called at [<phabricator>/src/applications/files/uploadsource/PhabricatorFileUploadSource.php:76],
[03-Jun-2018 02:35:09 UTC]   #8 <#2> HarbormasterLogWorker::finalizeBuildLog(HarbormasterBuildLog) called at [<phabricator>/src/applications/harbormaster/worker/HarbormasterLogWorker.php:42],
[03-Jun-2018 02:35:09 UTC]   #7 <#2> PhabricatorFileUploadSource::uploadFile() called at [<phabricator>/src/applications/harbormaster/worker/HarbormasterLogWorker.php:94],
[03-Jun-2018 02:35:09 UTC]   #9 <#2> HarbormasterLogWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:123],
[03-Jun-2018 02:35:09 UTC]   #10 <#2> PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:171],
[03-Jun-2018 02:35:09 UTC]   #11 <#2> PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:22],
[03-Jun-2018 02:35:09 UTC]   #12 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:219]

I am not having any other apparent issues.


#2

Error logs from the bad request should show in your webserver’s error log file.
It’s possible that createartifact is running into the same issue with permissions you’re seeing in the daemon logs.


#3

The apache log didn’t actually show anything more (same thing in the access log, nothing in the error log). I did tcpdump -s 0 -vv -X 'tcp dst port 80' and something made me realize i still had phabricator set as 127.0.0.1 for the host uri but had Jenkins calling back to harbormaster via a phabricator alias in /etc/hosts. I reset Phabricator base uri to phabricator.local and updated everything and the harbormaster conduit call is working now. Thanks again. With a little luck I’m up to the level of working with the Jenkins Phabricator plugin itself.