See PHI1295. Here's a full trace of an issue I hit doing an import of an instance which was last upgraded in late 2016:
$ ./bin/storage upgrade ... Applying patch "phabricator:20180208.maniphest.02.populate.php" to host "172.30.0.175:3306"... [2019-06-05 17:03:02] EXCEPTION: (AphrontSchemaQueryException) #1054: Unknown column 'dateCreated' in 'field list' at [<phutil>/src/aphront/storage/connection/mysql/AphrontBaseMySQLDatabaseConnection.php:346] arcanist(head=stable, ref.master=fad85844314b, ref.stable=26452002a256), libcore(), phabricator(head=stable, ref.stable=3337b84073f9), phutil(head=stable, ref.master=2b7b1007bf87, ref.stable=1185300a23d9), services(head=stable, ref.master=c2aefbcd155e, ref.stable=e9147e2871e1) #0 AphrontBaseMySQLDatabaseConnection::throwCommonException(integer, string) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontBaseMySQLDatabaseConnection.php:369] #1 AphrontBaseMySQLDatabaseConnection::throwQueryCodeException(integer, string) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontBaseMySQLDatabaseConnection.php:310] #2 AphrontBaseMySQLDatabaseConnection::throwQueryException(mysqli) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontBaseMySQLDatabaseConnection.php:206] #3 AphrontBaseMySQLDatabaseConnection::executeQuery(PhutilQueryString) called at [<phutil>/src/xsprintf/queryfx.php:8] #4 queryfx(AphrontMySQLiDatabaseConnection, string, PhutilQueryString, PhabricatorWorkerActiveTask, array, array) #5 call_user_func_array(string, array) called at [<phutil>/src/aphront/storage/connection/AphrontDatabaseConnection.php:58] #6 AphrontDatabaseConnection::query(string, PhutilQueryString, PhabricatorWorkerActiveTask, array, array) called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1107] #7 LiskDAO::insertRecordIntoDatabase(string) called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:939] #8 LiskDAO::insert() called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:908] #9 LiskDAO::save() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:70] #10 PhabricatorWorkerActiveTask::forceSaveWithoutLease() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:53] #11 PhabricatorWorkerActiveTask::save() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:187] #12 PhabricatorWorker::scheduleTask(string, array, array) called at [<phabricator>/src/applications/search/worker/PhabricatorSearchWorker.php:24] #13 PhabricatorSearchWorker::queueDocumentForIndexing(string) called at [<phabricator>/src/applications/files/storage/PhabricatorFile.php:164] #14 PhabricatorFile::saveAndIndex() called at [<phabricator>/src/applications/files/storage/PhabricatorFile.php:433] #15 PhabricatorFile::buildFromFileData(string, array) called at [<phabricator>/src/applications/files/storage/PhabricatorFile.php:448] #16 PhabricatorFile::newFromFileData(string, array) called at [<phabricator>/src/applications/files/builtin/PhabricatorFilesComposeAvatarBuiltinFile.php:39] #17 PhabricatorFilesComposeAvatarBuiltinFile::updateUser(PhabricatorUser) called at [<phabricator>/src/applications/people/cache/PhabricatorUserProfileImageCacheType.php:50] #18 PhabricatorUserProfileImageCacheType::newValueForUsers(string, array) called at [<phabricator>/src/applications/people/query/PhabricatorPeopleQuery.php:610] #19 PhabricatorPeopleQuery::fillUserCaches(array) called at [<phabricator>/src/applications/people/query/PhabricatorPeopleQuery.php:205] #20 PhabricatorPeopleQuery::didFilterPage(array) called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:285] #21 PhabricatorPolicyAwareQuery::execute() called at [<phabricator>/src/applications/phid/type/PhabricatorPHIDType.php:91] #22 PhabricatorPHIDType::loadObjects(PhabricatorObjectQuery, array) called at [<phabricator>/src/applications/phid/query/PhabricatorObjectQuery.php:153] #23 PhabricatorObjectQuery::loadObjectsByPHID(array, array) called at [<phabricator>/src/applications/phid/query/PhabricatorObjectQuery.php:73] #24 PhabricatorPolicyAwareQuery::execute() called at [<phabricator>/src/applications/phid/query/PhabricatorHandleQuery.php:46] #25 PhabricatorHandleQuery::loadPage() called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:248] #26 PhabricatorPolicyAwareQuery::execute() called at [<phabricator>/src/applications/phid/handle/pool/PhabricatorHandlePool.php:73] #27 PhabricatorHandlePool::loadPHIDs(array) called at [<phabricator>/src/applications/phid/handle/pool/PhabricatorHandleList.php:44] #28 PhabricatorHandleList::loadHandles() called at [<phabricator>/src/applications/phid/handle/pool/PhabricatorHandleList.php:49] #29 PhabricatorHandleList::getHandle(string) called at [<phabricator>/src/applications/phid/handle/pool/PhabricatorHandleList.php:130] #30 PhabricatorHandleList::current() #31 iterator_to_array(PhabricatorHandleList) called at [<phabricator>/src/applications/transactions/query/PhabricatorApplicationTransactionQuery.php:150] #32 PhabricatorApplicationTransactionQuery::willFilterPage(array) called at [<phabricator>/src/infrastructure/query/policy/PhabricatorPolicyAwareQuery.php:259] #33 PhabricatorPolicyAwareQuery::execute() called at [<phabricator>/resources/sql/autopatches/20180208.maniphest.02.populate.php:34] #34 require_once(string) called at [<phabricator>/src/infrastructure/storage/management/PhabricatorStorageManagementAPI.php:287] #35 PhabricatorStorageManagementAPI::applyPatchPHP(string) called at [<phabricator>/src/infrastructure/storage/management/PhabricatorStorageManagementAPI.php:241] #36 PhabricatorStorageManagementAPI::applyPatch(PhabricatorStoragePatch) called at [<phabricator>/src/infrastructure/storage/management/workflow/PhabricatorStorageManagementWorkflow.php:1157] #37 PhabricatorStorageManagementWorkflow::doUpgradeSchemata(array, NULL, boolean, boolean) called at [<phabricator>/src/infrastructure/storage/management/workflow/PhabricatorStorageManagementWorkflow.php:903] #38 PhabricatorStorageManagementWorkflow::upgradeSchemata(array, NULL, boolean, boolean) called at [<phabricator>/src/infrastructure/storage/management/workflow/PhabricatorStorageManagementUpgradeWorkflow.php:78] #39 PhabricatorStorageManagementUpgradeWorkflow::didExecute(PhutilArgumentParser) called at [<phabricator>/src/infrastructure/storage/management/workflow/PhabricatorStorageManagementWorkflow.php:107] #40 PhabricatorStorageManagementWorkflow::execute(PhutilArgumentParser) called at [<phutil>/src/parser/argument/PhutilArgumentParser.php:457] #41 PhutilArgumentParser::parseWorkflowsFull(array) called at [<phutil>/src/parser/argument/PhutilArgumentParser.php:349] #42 PhutilArgumentParser::parseWorkflows(array) called at [<phabricator>/scripts/sql/manage_storage.php:249]
The problem is:
- This migration loads transactions to find the most recent close date for tasks. This was added by D19037 in connection with T4434.
- Loading the transactions loads their handles. This is probably not actually necessary for the migration to run, just the default behavior of TransactionQuery.
- Loading handles may generate new profile images and thumbnails for users who are missing thumbnails on-demand. I think this has caused 2-3 issues in the past (it is surprising/unexpected that loading handles can cause a write) and possibly we should try to make it proactive (migration / on edit) instead of on-demand.
- Generating new profile images may generate new File objects.
- Generating File objects may queue search engine indexing for those files.
- Queuing these indexing tasks does inserts into the worker_activetask table.
- D20200 added dateCreated to the worker_activetask table. Inserts made by code after Feb 2019 will try to INSERT a value into this column, but it won't work since the column doesn't exist until 20190220.daemon_worker.completed.02.sql executes.
The simplest fix for this is probably to add needHandles(false) to 20180208.maniphest.02.populate.php, which will make the migration run faster and nip this whole mess in the bud.
Changing the behavior of the "handles may cause a bunch of indirect writes" part of the system is also probably desirable, although more involved.