HomePhabricator

Clean up some log spam caused by races in VersionedDraft

Description

Clean up some log spam caused by races in VersionedDraft

Summary:
Two minor issues that I caught in the log while fixing Phame permissions:

  • We had a JS bug which would cause us to immediately generate two comment previews at the exact same time -- one for loading the page, and one for "switching to desktop". Instead, only generate the "switch to desktop" preview if we really switched to desktop from a different device layout.
  • These two requests could end up reading/writing the VersionedDraft table at exactly the same time fairly often (e.g., after a comment submission, the page would load, send two preview requests at exactly the same time, and they'd race fairly reliably for me locally). If we do race, recover from the race.

Test Plan:
Submitted some Phame comments.

  • No more error log errors about VersionedDraft keys.
  • Saw only one preview request when loading the page instead of two.

Here's the specific stack trace I caught:

[Mon Sep 05 12:15:33.639930 2016] [:error] [pid 50608] [client 127.0.0.1:55278] [2016-09-05 14:15:33] EXCEPTION: (AphrontDuplicateKeyQueryException) #1062: Duplicate entry 'PHID-POST-fknnpzjnsdgc3rqobhst-PHID-USER-pr5rjpuilpfserepsd2k-13' for key 'key_object' at [<phutil>/src/aphront/storage/connection/mysql/AphrontBaseMySQLDatabaseConnection.php:314]
[Mon Sep 05 12:15:33.640801 2016] [:error] [pid 50608] [client 127.0.0.1:55278] arcanist(head=master, ref.master=9e82ef979e81), corgi(head=master, ref.master=5b9171222bc9), instances(head=stable, ref.master=485bc8128198, ref.stable=2983bc917601), ledger(head=master, ref.master=4da4a24b8779), libcore(), phabricator(head=phame2, ref.master=4b6da9735ba7, ref.phame2=4b6da9735ba7), phutil(head=stable, ref.master=97f05269fdb1, ref.stable=c14343ee620e), services(head=stable, ref.master=1fcb5cdb7582, ref.stable=2d8088a5b4b3)
[Mon Sep 05 12:15:33.640815 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #0 <#2> AphrontBaseMySQLDatabaseConnection::throwCommonException(integer, string) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontBaseMySQLDatabaseConnection.php:348]
[Mon Sep 05 12:15:33.640830 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #1 <#2> AphrontBaseMySQLDatabaseConnection::throwQueryCodeException(integer, string) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontBaseMySQLDatabaseConnection.php:289]
[Mon Sep 05 12:15:33.640833 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #2 <#2> AphrontBaseMySQLDatabaseConnection::throwQueryException(mysqli) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontBaseMySQLDatabaseConnection.php:185]
[Mon Sep 05 12:15:33.640836 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #3 <#2> AphrontBaseMySQLDatabaseConnection::executeRawQuery(string) called at [<phutil>/src/xsprintf/queryfx.php:8]
[Mon Sep 05 12:15:33.640839 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #4 <#2> queryfx(AphrontMySQLiDatabaseConnection, string, string, string, array, string)
[Mon Sep 05 12:15:33.640841 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #5 <#2> call_user_func_array(string, array) called at [<phutil>/src/aphront/storage/connection/AphrontDatabaseConnection.php:42]
[Mon Sep 05 12:15:33.640844 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #6 <#2> AphrontDatabaseConnection::query(string, string, string, array, string) called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1261]
[Mon Sep 05 12:15:33.640846 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #7 <#2> LiskDAO::insertRecordIntoDatabase(string) called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1106]
[Mon Sep 05 12:15:33.640849 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #8 <#2> LiskDAO::insert() called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1075]
[Mon Sep 05 12:15:33.640851 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #9 <#2> LiskDAO::save() called at [<phabricator>/src/applications/draft/storage/PhabricatorVersionedDraft.php:65]
[Mon Sep 05 12:15:33.640854 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #10 <#2> PhabricatorVersionedDraft::loadOrCreateDraft(string, string, integer) called at [<phabricator>/src/applications/transactions/editengine/PhabricatorEditEngine.php:1669]
[Mon Sep 05 12:15:33.640857 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #11 <#2> PhabricatorEditEngine::buildCommentResponse(PhamePost) called at [<phabricator>/src/applications/transactions/editengine/PhabricatorEditEngine.php:894]
[Mon Sep 05 12:15:33.640859 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #12 <#2> PhabricatorEditEngine::buildResponse() called at [<phabricator>/src/applications/phame/controller/post/PhamePostEditController.php:60]
[Mon Sep 05 12:15:33.640862 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #13 <#2> PhamePostEditController::handleRequest(AphrontRequest) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:237]
[Mon Sep 05 12:15:33.640865 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #14 phlog(AphrontDuplicateKeyQueryException) called at [<phabricator>/src/aphront/handler/PhabricatorAjaxRequestExceptionHandler.php:27]
[Mon Sep 05 12:15:33.640868 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #15 PhabricatorAjaxRequestExceptionHandler::handleRequestException(AphrontRequest, AphrontDuplicateKeyQueryException) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:644]
[Mon Sep 05 12:15:33.640870 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #16 AphrontApplicationConfiguration::handleException(AphrontDuplicateKeyQueryException) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:242]
[Mon Sep 05 12:15:33.640873 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #17 AphrontApplicationConfiguration::processRequest(AphrontRequest, PhutilDeferredLog, AphrontPHPHTTPSink, MultimeterControl) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:149]
[Mon Sep 05 12:15:33.640879 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #18 AphrontApplicationConfiguration::runHTTPRequest(AphrontPHPHTTPSink) called at [<phabricator>/webroot/index.php:17]

Reviewers: chad

Reviewed By: chad

Differential Revision: https://secure.phabricator.com/D16494

Details

Provenance
epriestleyAuthored on Sep 5 2016, 7:24 PM
epriestleyPushed on Sep 5 2016, 8:01 PM
Reviewer
chad
Differential Revision
D16494: Clean up some log spam caused by races in VersionedDraft
Parents
rP4b6da9735ba7: Remove overbearing policy checks in Phame
Branches
Unknown
Tags
Unknown
Build Status
Buildable 13575
Build 17482: Run Core Tests