Differential D16494

Clean up some log spam caused by races in VersionedDraft
ClosedPublic
Actions

Authored by epriestley on Sep 5 2016, 7:30 PM.

Details

Reviewers

chad

Commits

rP74d5ae7bec46: 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]