Page MenuHomePhabricator
Create Task
Maniphest T6093

PhabricatorTaskmasterDaemon crashes due to invalid characters in commit
Closed, DuplicatePublic
Actions

Description

Lately we have been experiencing issues with PhabricatorTaskmasterDaemon crashing and commits taking a long time to get imported into diffusion.

Daemonlog:

[2014-09-15 13:36:58] EXCEPTION: (PhutilProxyException) Error while executing task ID 578074 from queue. {>} (AphrontQueryException) #1366: Incorrect string value: '\xF0\x9F\x93\x85";...' for column 'objectTranscript' at row 1 at [<phutil>/src/aphront/storage/connection/mysql/AphrontMySQLDatabaseConnectionBase.php:308]
  #0 AphrontMySQLDatabaseConnectionBase::throwQueryCodeException(integer, string) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontMySQLDatabaseConnectionBase.php:275]
  #1 AphrontMySQLDatabaseConnectionBase::throwQueryException(mysqli) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontMySQLDatabaseConnectionBase.php:181]
  #2 AphrontMySQLDatabaseConnectionBase::executeRawQuery(string) called at [<phutil>/src/xsprintf/queryfx.php:6]
  #3 queryfx(AphrontMySQLiDatabaseConnection, string, string, string, array, string)
  #4 call_user_func_array(string, array) called at [<phutil>/src/aphront/storage/connection/AphrontDatabaseConnection.php:26]
  #5 AphrontDatabaseConnection::query(string, string, string, array, string) called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1203]
  #6 LiskDAO::insertRecordIntoDatabase(string) called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1057]
  #7 LiskDAO::insert() called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1026]
  #8 LiskDAO::save() called at [<phabricator>/src/applications/herald/engine/HeraldEngine.php:209]
  #9 HeraldEngine::getTranscript() called at [<phabricator>/src/applications/repository/worker/PhabricatorRepositoryCommitHeraldWorker.php:69]
  #10 PhabricatorRepositoryCommitHeraldWorker::applyHeraldRules(PhabricatorRepository, PhabricatorRepositoryCommit) called at [<phabricator>/src/applications/repository/worker/PhabricatorRepositoryCommitHeraldWorker.php:17]
  #11 PhabricatorRepositoryCommitHeraldWorker::parseCommit(PhabricatorRepository, PhabricatorRepositoryCommit) called at [<phabricator>/src/applications/repository/worker/PhabricatorRepositoryCommitParserWorker.php:44]
  #12 PhabricatorRepositoryCommitParserWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:87]
  #13 PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:124]
  #14 PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:19]
  #15 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:91]
  #16 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:111]

After doing some more research and running PhabricatorTaskmasterDaemon in debug mode it seems that a spesific commit is causing this, probably due to some bad characters, but i haven't been able to identify exactly what part of the content in the commit that makes phabricator unhappy.

Debugmode gives me the following output:

>>> [1752] <query> SELECT * FROM `repository` r  WHERE (r.callsign IN ('VKIOS')) ORDER BY r.id DESC
<<< [1752] <query> 384 us
>>> [1753] <exec> $ git diff -M -C --no-ext-diff --no-color --src-prefix=a/ --dst-prefix=b/ -U0 '4f35249299d052fda55b0cc1ffc2b60556b6fe21^' '4f35249299d052fda55b0cc1ffc2b60556b6fe21' -- '.'
<<< [1753] <exec> 19,418 us
<<< [1751] <conduit> 22,969 us
>>> [1754] <connect> phabricator_herald
<<< [1754] <connect> 1,132 us
>>> [1755] <query> INSERT INTO `herald_transcript` (`objectTranscript`, `ruleTranscripts`, `conditionTranscripts`, `applyTranscripts`, `time`, `host`, `duration`, `objectPHID`, `dryRun`, `phid`) VALUES ('O:22:\"HeraldObjectTranscript\":4:{s:7:\"\0*\0phid\";s:30:\"PHID-CMIT-sz7uszib6pmygz3tu3s7\";s:7:\"\0*\0type\";s:6:\"commit\";s:7:\"\0*\0name\";s:46:\"rVKIOS4f35249299d052fda55b0cc1ffc2b60556b6fe21\";s:9:\"\0*\0fields\";a:5:{s:10:\"repository\";s:30:\"PHID-REPO-bf4txspqindmpghuidr4\";s:4:\"body\";s:48:\"Updated submodules & s
<<< [1755] <query> 1,338 us
>>> [1756] <query> UPDATE `worker_activetask` SET `failureTime` = '1410776964', `taskClass` = 'PhabricatorRepositoryCommitHeraldWorker', `leaseOwner` = '21671:1410776964:phabricator:95', `leaseExpires` = '1410777264', `failureCount` = '47146', `dataID` = '578072', `priority` = '0', `id` = '578074' WHERE `id` = '578074'
<<< [1756] <query> 2,505 us
<VERB> PhabricatorTaskmasterDaemon Task 578074 failed!
[2014-09-15 12:29:24] EXCEPTION: (PhutilProxyException) Error while executing task ID 578074 from queue. {>} (AphrontQueryException) #1366: Incorrect string value: '\xF0\x9F\x93\x85";...' for column 'objectTranscript' at row 1 at [<phutil>/src/aphront/storage/connection/mysql/AphrontMySQLDatabaseConnectionBase.php:308]
  #0 AphrontMySQLDatabaseConnectionBase::throwQueryCodeException(integer, string) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontMySQLDatabaseConnectionBase.php:275]
  #1 AphrontMySQLDatabaseConnectionBase::throwQueryException(mysqli) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontMySQLDatabaseConnectionBase.php:181]
  #2 AphrontMySQLDatabaseConnectionBase::executeRawQuery(string) called at [<phutil>/src/xsprintf/queryfx.php:6]
  #3 queryfx(AphrontMySQLiDatabaseConnection, string, string, string, array, string)
  #4 call_user_func_array(string, array) called at [<phutil>/src/aphront/storage/connection/AphrontDatabaseConnection.php:26]
  #5 AphrontDatabaseConnection::query(string, string, string, array, string) called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1203]
  #6 LiskDAO::insertRecordIntoDatabase(string) called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1057]
  #7 LiskDAO::insert() called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1026]
  #8 LiskDAO::save() called at [<phabricator>/src/applications/herald/engine/HeraldEngine.php:209]
  #9 HeraldEngine::getTranscript() called at [<phabricator>/src/applications/repository/worker/PhabricatorRepositoryCommitHeraldWorker.php:69]
  #10 PhabricatorRepositoryCommitHeraldWorker::applyHeraldRules(PhabricatorRepository, PhabricatorRepositoryCommit) called at [<phabricator>/src/applications/repository/worker/PhabricatorRepositoryCommitHeraldWorker.php:17]
  #11 PhabricatorRepositoryCommitHeraldWorker::parseCommit(PhabricatorRepository, PhabricatorRepositoryCommit) called at [<phabricator>/src/applications/repository/worker/PhabricatorRepositoryCommitParserWorker.php:44]
  #12 PhabricatorRepositoryCommitParserWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:87]
  #13 PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:124]
  #14 PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:19]
  #15 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:91]
  #16 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:111]
>>> [137] <event> daemon.didLogMessage <listeners = 2>
>>> [138] <query> INSERT INTO `daemon_logevent` (`logID`, `logType`, `message`, `epoch`) VALUES ('404', 'STDE', '>>> [1751] <conduit> diffusion.rawdiffquery()\n>>> [1752] <query> SELECT * FROM `repository` r  WHERE (r.callsign IN (\'VKIOS\')) ORDER BY r.id DESC \n<<< [1752] <query> 384 us\n>>> [1753] <exec> $ git diff -M -C --no-ext-diff --no-color --src-prefix=a/ --dst-prefix=b/ -U0 \'4f35249299d052fda55b0cc1ffc2b60556b6fe21^\' \'4f35249299d052fda55b0cc1ffc2b60556b6fe21\' -- \'.\'\n<<< [1753] <exec> 19,418 us\n<<< [1751] <c
<<< [138] <query> 2,809 us
<<< [137] <event> 3,689 us
2014-09-15 12:29:24 PM [FAIL] Process exited with error 255.
>>> [139] <event> daemon.didLogMessage <listeners = 2>
>>> [140] <query> INSERT INTO `daemon_logevent` (`logID`, `logType`, `message`, `epoch`) VALUES ('404', 'FAIL', '(255) Process exited with error 255.', '1410776964')
<<< [140] <query> 1,928 us

The version we are running was checked out from the official git repositories 20th of August.

Related Objects

Event Timeline

oles created this task.Sep 15 2014, 12:19 PM
oles raised the priority of this task from to Needs Triage.
oles updated the task description. (Show Details)
oles added a project: Phabricator.
oles added a subscriber: oles.
oles added a comment.Sep 16 2014, 11:33 AM

Just to follow up with some additional info:

This is the part of the commit that causes the problem: +static NSString * const kCalendarSymbol = @"<U+1F4C5>";
Seems to be related to MySQL's UTF8 charset not being able to handle this unicode symbol.

hach-que added a subscriber: hach-que.Sep 16 2014, 2:15 PM

This sounds like it's the same issue as T1191.

epriestley closed this task as a duplicate of T1191: Comments are truncated at first non-base-plane character.Oct 3 2014, 3:41 AM
Phabricator · Built by Phacility